Exceptions only showing up as "unknown error" on fly.io

[marvinosswald]

please let me know if this should rather be posted in the community forum.

If i trigger an exception all i see in the fly logs is: ERROR unknown error

more precisely:

no details about it. i tested this locally with frankenphp and stderr and did see the exception in frankenphp's log

logging.php

'stderr' => [
    'driver' => 'monolog',
    'level' => env('LOG_LEVEL', 'debug'),
    'handler' => StreamHandler::class,
    'formatter' => env('LOG_STDERR_FORMATTER'),
    'formatter_with' => [
        'includeStacktraces' => true,
    ],
    'with' => [
        'stream' => 'php://stderr',
    ],
    'processors' => [PsrLogMessageProcessor::class],
],

fly.toml

[build]
  [build.args]
    NODE_VERSION = '18'
    PHP_VERSION = '8.3'

[env]
    APP_ENV = 'production'
    LOG_CHANNEL = 'stderr'
    LOG_LEVEL = 'info'
    LOG_STDERR_FORMATTER = 'Monolog\Formatter\JsonFormatter'
    SESSION_DRIVER = 'cookie'
    SESSION_SECURE_COOKIE = 'true'

[http_service]
  internal_port = 8000
  force_https = true
  auto_stop_machines = true
  auto_start_machines = true
  min_machines_running = 0
  processes = ['app']

[processes]
  app = ""
#  cron = "cron -f"
#  worker = "php artisan queue:listen"

[[vm]]
  size = 'shared-cpu-1x'
  memory = "512MB"

[KTanAug21]

Hi @marvinosswald!

I'm trying to replicate the behavior you are experiencing re: fly logs is: ERROR unknown error.

So in a Laravel 11 project, I added the same stderr config you have, and same fly.toml [env] keys you've shared. Added a route that's bound to throw an error:

Route::get('/test', function () {
    dd($kathryn);
});

And did a fly deploy. Visited the test route that throwed a 500 error. And checked out my logs at https://fly.io/apps/<app-name>/monitoring: And the stack trace is there!

Are there other configurations you think will help me replicate the issue you're experiencing? Like:

1. How did you configure your app with frankenphp?
2. Where did you find the first image in your post( that showed the unknown error log )? I usually check my app's monitoring dashboard to see logs: https://fly.io/apps/<app-name>/monitoring

[marvinosswald]

Hi @KTanAug21, thank you for looking into this. I'll attach a couple of hopefully relevant files. The first image is just the grafana view of the monitoring link you mentioned. It shows the same thing in fly live logs as well.

Dockerfile

```Dockerfile # syntax = docker/dockerfile:experimental ARG PHP_VERSION=8.3 ARG NODE_VERSION=18 FROM fideloper/fly-laravel:${PHP_VERSION} as base # PHP_VERSION needs to be repeated here # See https://docs.docker.com/engine/reference/builder/#understand-how-arg-and-from-interact ARG PHP_VERSION LABEL fly_launch_runtime="laravel" # copy application code, skipping files based on .dockerignore COPY . /var/www/html RUN composer install --optimize-autoloader --no-dev \ && mkdir -p storage/logs \ && php artisan optimize:clear \ && chown -R www-data:www-data /var/www/html \ && echo "MAILTO=\"\"\n* * * * * www-data /usr/bin/php /var/www/html/artisan schedule:run" > /etc/cron.d/laravel \ && sed -i='' '/->withMiddleware(function (Middleware \$middleware) {/a\ \$middleware->trustProxies(at: "*");\ ' bootstrap/app.php; \ if [ -d .fly ]; then cp .fly/entrypoint.sh /entrypoint; chmod +x /entrypoint; fi; RUN rm -rf /etc/supervisor/conf.d/fpm.conf; \ mv /etc/supervisor/octane-franken.conf /etc/supervisor/conf.d/octane-franken.conf; \ rm -f frankenphp; \ php artisan octane:install --no-interaction --server=frankenphp; \ rm /etc/nginx/sites-enabled/default; \ ln -sf /etc/nginx/sites-available/default-octane /etc/nginx/sites-enabled/default; # Multi-stage build: Build static assets # This allows us to not include Node within the final container FROM node:${NODE_VERSION} as node_modules_go_brrr RUN mkdir /app RUN mkdir -p /app WORKDIR /app COPY . . COPY --from=base /var/www/html/vendor /app/vendor # Use yarn or npm depending on what type of # lock file we might find. Defaults to # NPM if no lock file is found. # Note: We run "production" for Mix and "build" for Vite RUN if [ -f "vite.config.js" ]; then \ ASSET_CMD="build"; \ else \ ASSET_CMD="production"; \ fi; \ if [ -f "yarn.lock" ]; then \ yarn install --frozen-lockfile; \ yarn $ASSET_CMD; \ elif [ -f "pnpm-lock.yaml" ]; then \ corepack enable && corepack prepare pnpm@latest-8 --activate; \ pnpm install --frozen-lockfile; \ pnpm run $ASSET_CMD; \ elif [ -f "package-lock.json" ]; then \ npm ci --no-audit; \ npm run $ASSET_CMD; \ else \ npm install; \ npm run $ASSET_CMD; \ fi; # From our base container created above, we # create our final image, adding in static # assets that we generated above FROM base # Packages like Laravel Nova may have added assets to the public directory # or maybe some custom assets were added manually! Either way, we merge # in the assets we generated above rather than overwrite them COPY --from=node_modules_go_brrr /app/public /var/www/html/public-npm RUN rsync -ar /var/www/html/public-npm/ /var/www/html/public/ \ && rm -rf /var/www/html/public-npm \ && chown -R www-data:www-data /var/www/html/public EXPOSE 8080 ```

Composer.json

```json "require": { "php": "^8.3", "laravel/cashier-paddle": "^2.4", "laravel/framework": "11.3.0", "laravel/octane": "^2.3", "laravel/pulse": "^1.0@beta", "laravel/reverb": "@beta", "laravel/tinker": "^2.9", "livewire/livewire": "3.4.10", "lorisleiva/laravel-actions": "^2.8", "nick-potts/laravel-libsql-driver": "^0.1.2", "spatie/dns": "2.6.0", "staudenmeir/belongs-to-through": "^2.5", "torann/geoip": "^3.0" }, "require-dev": { "fakerphp/faker": "^1.23", "fly-apps/dockerfile-laravel": "^1.0", "larastan/larastan": "^2.0", "laravel/pint": "^1.13", "laravel/sail": "^1.26", "mockery/mockery": "^1.6", "nunomaduro/collision": "^8.0", "pestphp/pest": "^2.34", "pestphp/pest-plugin-laravel": "^2.3", "spatie/laravel-ignition": "^2.4" }, ```

[marvinosswald]

I also just confirmed it has nothing to do with Livewire, happens on this route as well:

Route::get('/ex', function () {
   throw new Exception("ex");
});

as well as a logs screenshot:

[KTanAug21]

Hi again @marvinosswald!

First of, thank you for adding an issue here( you're def free to add any issues in our fly community forumas well! )--I should have added that thanks in my earlier comment( but better late than never right )! Reporting issues like this really help the Laravel team at Fly.io work on our goal of making Fly.io the best place to deploy Laravel apps in.

Next, let's get back into the issue at hand. Thanks to sharing your Dockerfile configuration, I've finally replicated the same behavior you're experiencing. I now also get the same "unknown error" log. I've located where this message is orginating from, to be exact, in octane/frankenphp, exactly in this line here.. It goes like this: $message = $debug['msg'] ?? 'unknown error';

Upon further inspection, it turns out that the $debug variable really does not contain the msg key. Because, as an alternative, it contains $debug['message']. One weird fix to get our logs out, is to use message instead of msg. But, of course this isn't good at all, we'll have to manually copy the StartFrankenPhpCommand.php in the base directory, revise that to ALSO use the message key if msg is not available, then in our Dockerfile use that revised file in our vendor folder. Like so:

RUN mv StartFrankenPhpCommand.php vendor/laravel/octane/src/Commands/StartFrankenPhpCommand.php

Not so neat. Of course this isn't the only solution! See a few lines above the line I mentioned above, is this line . Which is :

if ($this->option('log-level') !== null) {
            return $errorOutput->each(fn ($output) => $this->raw($output));
}

Now, if we pass a log-level option when starting octane, this will proceed with sending the output to the raw method, which results in neatly logging our errors as we want! So, create a file revising our supervisor config for octane-frankenphp here .fly/supervisor/octane-franken.conf and add that log-level option in:

[program:octane]
priority=5
command=php -d variables_order=EGPCS /var/www/html/artisan octane:start --server=frankenphp --log-level="INFO" --admin-port=2019 --port=8000
user=www-data
autostart=true
autorestart=true
stdout_events_enabled=true
stderr_events_enabled=true
stdout_logfile=/dev/stdout
stdout_logfile_maxbytes=0
stderr_logfile=/dev/stderr
stderr_logfile_maxbytes=0

Then revise our Dockerfile to use the new config at .fly/supervisor/octane-franken.conf instead of the default one:

RUN rm -rf /etc/supervisor/conf.d/fpm.conf; \
    mv .fly/supervisor/octane-franken.conf /etc/supervisor/conf.d/octane-franken.conf; \
    rm -f frankenphp; \
    php artisan octane:install --no-interaction --server=frankenphp; \
    rm /etc/nginx/sites-enabled/default; \
    ln -sf /etc/nginx/sites-available/default-octane /etc/nginx/sites-enabled/default;

I'm thinking of adding the second solution as a PR here, but I'm not sure if it's the best solution yet. Can you test it out and let me know if you get your log? Hope it helps!

[marvinosswald]

Hi @KTanAug21,

thank you so much for figuring this out. Your provided solution absolutely works for me. Seems like a weird behaviour to me why it uses message or msg and am not sure from your message where this originates from but your supervisor fix looks good for a downstream fix to me 👍

[KTanAug21]

Hi @KTanAug21,

thank you so much for figuring this out. Your provided solution absolutely works for me. Seems like a weird behaviour to me why it uses message or msg and am not sure from your message where this originates from but your supervisor fix looks good for a downstream fix to me 👍

Awesome! That's great to read.

footnote: For the "message" attribute, I've logged the value of the $debug variable in this line like: Log::info(json_encode($debug)). And found it instead of the msg attribute