CODEWITHSUNDEEP
phpexceptionsilexerror-logging
Yury
Yury

Reputation: 11

Silex, exceptions caught by error handler, still leave CRITICAL log message

I have URL /init-stream?id=... in my app, it is used by some external application(s). It should answer OK or some error code. If id parameter is absent, the response should be ERROR_NO_ID. So, my code is

$app->get('/init-stream', function(Request $request) use ($app) {
    $idParam = $request->get('id');
    if ($idParam === NULL) {
        return new Response('ERROR_NO_ID', 400);
    }
    ...
});

Everything is ok, but I want to log this situation as WARNING, because it can help me to debug the application that invokes this request. So, I change the code to:

$app->get('/init-stream', function(Request $request) use ($app) {
    $idParam = $request->get('id');
    if ($idParam === NULL) {
        throw new App\Exception\BadRequestException('ERROR_NO_ID', 400);
    }
    ...
});

$app->error(function(App\Exception\BadRequestException $e) use ($app) {
    $app['logger']->addWarning(...);
    return new Response($e->getMessage(), $e->getCode);
});

Everything works, but there is one thing I do not like. My log looks like:

[2015-12-22 16:20:00] myapp.CRITICAL: App\Exception\BadRequestException: ERROR_NO_ID (uncaught exception) at C:\Users\yy\onetimelink\public\index.php line 166 {"exception":"[object] (App\\Exception\\BadRequestException(code: 400): ERROR_NO_ID at C:\\Users\\yy\\onetimelink\\public\\index.php:166)"} []
[2015-12-22 16:20:00] myapp.WARNING: GET /init-stream?sex=male&age=33 : ERROR_NO_ID (C:\Users\yy\onetimelink\public\index.php:166) [] []

There is nothing critical in my app. How can I get rid of this CRITICAL message?

Upvotes: 1

Views: 470

Answers (2)

user1765334
user1765334

Reputation: 93

Short answer: the priority of the error-callback is to low. You have to use a priority >= -4. For example:

$app->error(function(App\Exception\BadRequestException $e) use ($app) {
     $app['logger']->addWarning(...);
     return new Response($e->getMessage(), $e->getCode);}, -4); // <= !!!this

Info: The KernelEvents::EXCEPTION is earlier then your error callback. This will trigger the class Silex\EventListener\LogListener::onKernelException, and so on

Upvotes: 1

sonam
sonam

Reputation: 3760

This is due to the monolog log level. The current log levels supported are:

  1. DEBUG (100): Detailed debug information.
  2. INFO (200): Interesting events. Examples: User logs in, SQL logs.
  3. NOTICE (250): Normal but significant events.
  4. WARNING (300): Exceptional occurrences that are not errors. Examples: Use of deprecated APIs, poor use of an API, undesirable things that are not necessarily wrong.
  5. ERROR (400): Runtime errors that do not require immediate action but should typically be logged and monitored.
  6. CRITICAL (500): Critical conditions. Example: Application component unavailable, unexpected exception.
  7. ALERT (550): Action must be taken immediately. Example: Entire website down, database unavailable, etc. This should trigger the SMS alerts and wake you up.
  8. EMERGENCY (600): Emergency: system is unusable.

Documentation

DEBUG will log everything, INFO will log everything except DEBUG, NOTICE will log everthing except DEBUG and INFO and so on with the chain.

So to avoid CRITICAL log messages, log level should be set to ALERT or EMERGENCY.

Monolog classifies exception under CRITICAL log level and adds it to your log file whenever exception occurs and you have log level set to include CRITICAL log messages. I recommend to use DEBUG level for development and from ERROR level downwards for production. Also set $app['debug']=false on production.

Upvotes: 0

Related Questions