Love Fuel?    Donate

FuelPHP Forums

Ask your question about FuelPHP in the appropriate forum, or help others by answering their questions.
log_threshold doesnt work for oil
  • Hi there,

    Don't know if this is some sort of bug, but it looks like log_treshold doesn't work for all the routes executed via oil. The main config file has log_threshold set to Fuel::L_ALL and it works fine when executing regular http call.

    When it is execuced as an oil call, it logs only fatal errors, ignoring the setting above.

    Is this a bug or is there something else in the config that I've missed ?

    Thanks
  • The configured log_threshold is processed by the Log class when it initializes, no matter where it is used.

    Are you sure your webserver and oil are using the same environment, and therefore read the same config file? Oil by default runs in development, if you want to use a different one, you need to set it:

    env FUEL_ENV=production php oil some command here
  • Hi,

    What I have is a test file with intended error (attempt to echo undeclared variable). When I access controller / method I get in the logs:

    ERROR - 2017-07-24 12:16:39 --> Notice - Undefined variable: sfsafsdf in /var/www/vhosts/

    Now, I have test task file with a method as follows:

        public static function error_test()
        {
            echo 'test';
            echo \Cli::new_line(1);
            echo \Request::forge('/dev/test')->execute();
        }

    What I get in the output:
    test
    Uncaught exception Fuel\Core\PhpErrorException: Undefined variable: sfsafsdf
    You have new mail in /var/mail/root

    and in the logs:
    INFO - 2017-07-24 12:18:48 --> Fuel\Core\Request::__construct - Creating a new main Request with URI = "dev/test"
    INFO - 2017-07-24 12:18:48 --> Fuel\Core\Request::execute - Called
    INFO - 2017-07-24 12:18:48 --> Fuel\Core\Request::execute - Setting main Request

    But no information about the error is logged in the log. I've tried to change default logging level by changing core config but no effect. I'm also quite sure that everything runs under production (db connection works as defined in the config for production) also this bit of code indicates correct environment setting:

    echo \Fuel::$env gives me 'production' so it is not that.

    Don't know what else should I try ?

  • PS. Sorry but it looks like I have 2 accounts on the forum :)
  • I've checked the code.

    It doesn't log anything if error_reporting() returns zero.

    If it is not zero:
    - if the error count is equal to the throttle value in the config, it doesn't log but throws an exception
    - if the error count is lower, and the evironment isn't "production", it doesn't log but throws an exception
    if the error count is lower, and the error type isn't set in error_reporting(). it doesn't log but throws an exception

    So my gut feeling is the default error_reporting() settings in your php.ini, because for http requests, it is explicitly set to -1 (all errors) in your index.php, but oil doesn't set anything.
  • You could add

    error_reporting(-1);

    at the top of the oil script, and see if that changes things? I think that should have been there all along. 

    edit: hmm... That already seems to be there, at least in my test environment it is.
  • Ok, tried it here:

    [ /data/www/mvhosts/fuel.catwoman.flexcoders.local/19develop ] 
    [ wanwizard@catwoman] $ FUEL_ENV=production oil r test:error_test
    test
    Notice - Undefined variable: jhajkdh in APPPATH/views/welcome/index.php on line 1

    Method used:

        public static function error_test()
        {
            echo 'test';
            echo \Cli::new_line(1);
            echo \Request::forge('/')->execute();
        }


    First line of the welcome view:

    <?php echo $jhajkdh; ?>

    The log file contains:

    [wanwizard@catwoman] $ cat 24.php 
    <?php defined('COREPATH') or exit('No direct script access allowed'); ?>

    INFO - 2017-07-24 14:38:56 --> Fuel\Core\Request::__construct - Creating a new main Request with URI = ""
    INFO - 2017-07-24 14:38:56 --> Fuel\Core\Request::execute - Called
    INFO - 2017-07-24 14:38:56 --> Fuel\Core\Request::execute - Setting main Request
    ERROR - 2017-07-24 14:38:56 --> Notice - Undefined variable: jhajkdh in /data/www/mvhosts/fuel.catwoman.flexcoders.local/19develop/fuel/app/views/welcome/index.php on line 1

    So I can't reproduce your problem?
  • p.s. config.php:

        'errors'  => array(
            // Which errors should we show, but continue execution? You can add the following:
            // E_NOTICE, E_WARNING, E_DEPRECATED, E_STRICT to mimic PHP's default behaviour
            // (which is to continue on non-fatal errors). We consider this bad practice.
            // 'continue_on'  => array(),
            // How many errors should we show before we stop showing them? (prevents out-of-memory errors)
            // 'throttle'     => 10,
            // Should notices from Error::notice() be shown?
            // 'notices'      => true,
            // Render previous contents or show it as HTML?
            'render_prior' => true,
        ),

        /**
         * Logging Threshold.  Can be set to any of the following:
         *
         * Fuel::L_NONE
         * Fuel::L_ERROR
         * Fuel::L_WARNING
         * Fuel::L_DEBUG
         * Fuel::L_INFO
         * Fuel::L_ALL
         */
        'log_threshold'    => Fuel::L_ALL,
        'log_path'         => APPPATH.'logs/',
        'log_date_format'  => 'Y-m-d H:i:s',

  • Hi,

    It looks like error_reporting returns -1 on both cases, however only http request gets logged as an error in the logs. :(
  • Is there any other PHP setting which may get involved into the problem (eg. php error log etc ? )
  • PS. One difference I see so far in the test output I've provided is that on the console I get 'uncaught exception' :

    web1:~# php /var/www/vhosts/app/oil r automerge:error_test
    testUncaught exception Fuel\Core\PhpErrorException: Undefined variable: sfsafsdf

  • What Fuel version are you on?

    It just looks like the error handler isn't running at all.
  • btw, where do you set the environment for that call?

        web1:~# php /var/www/vhosts/app/oil r automerge:error_test

    will always run in development, not in production mode. You need to use

        web1:~# env FUEL_ENV=production php /var/www/vhosts/app/oil r automerge:error_test
  • It's on 1.8
  • Then it must be your environment setting.
  • I've tried to force env to production on command line and it gives me same results and I've also confirmed that it runs on production by default (it is set on vhost definition level).
  • Don't know if that's any important informaton, but all environments share single main config file (app/config/config.php) and error logging treshold is set to E_ALL. The only setting different between environments is db.php files, but I've also tried to alter core config and set the flag there, but results were exactly the same
  • Oil doesn't use the vhost definition. You have to use the command format I gave you.

    And yes, it is important, the code checks in several places if the environment is set to \Fuel::PRODUCTION, to prevent leakage of sensitive information, and that includes the way errors are handled.

    If the environment is not set to \Fuel::PRODUCTION, the log entries will not be created but the execution will be aborted, which is why you see the exception being returned, and I don't. 
  • Ay yes, what you have said makes more sense now. I think that was an issue last time when we wanted to simplify deployment process and environment is also set in application's bootstrap file :

    \Fuel::$env = \Arr::get($_SERVER, 'FUEL_ENV', \Arr::get($_ENV, 'FUEL_ENV', \Fuel::PRODUCTION));

    Is that something that may potentially interfere with logging as everything else works as expected in this case ?
  • No, that should work.

    If you start the console:

        php oil console

    it will tell you what it thinks the environment is.
  • Its only giving me this :

    Fuel 1.8 - PHP 5.5.9-1ubuntu4.21 (cli) (Feb  9 2017 20:49:23) [Linux]

    But I'm pretty sure it is on production as \Fuel::$env -> production also it connects correctly to the production database and it would not on any other case.
  • Ah, yeah. 1.8 doesn't display that. Try this:

    [wanwizard@catwoman] $ php oil console
    Fuel 1.8 - PHP 7.1.7 (cli) (Jul  6 2017 12:10:30) [Linux]
    >>> \Fuel::$env;
    development
    >>> ^C

    But if you're running 1,8, it might also be a bug that has already been fixed, as I am testing with 1.9-dev.

    You might want to switch your app over to 1.9-dev to check that (we run all our production apps on 1.9-dev, so it is very stable ;-)).
  • I'm pretty sure it is ! :)

    Yes it says it is in production mode. Will try to upgrade our app to 1.9
  • Just run the same test in 1.8:

    <?php defined('COREPATH') or exit('No direct script access allowed'); ?>

    INFO - 2017-07-25 15:59:14 --> Fuel\Core\Request::__construct - Creating a new main Request with URI = ""
    INFO - 2017-07-25 15:59:14 --> Fuel\Core\Request::execute - Called
    INFO - 2017-07-25 15:59:14 --> Fuel\Core\Request::execute - Setting main Request
    ERROR - 2017-07-25 15:59:14 --> Notice - Undefined variable: hjagdjga in /data/www/mvhosts/fuel.catwoman.flexcoders.local/18develop/fuel/app/views/welcome/index.php on line 1

    works fine here too, no exception from the oil command, and a correct log entry.

    Your app doesn't have something overloaded that can interfere with the error handling? 
  • I also tried to test 1.7, but that doesn't run on PHP 7.1, which I have on my development machine.
  • I've upgraded core to 1.9, however problem still exists. Notice errors are correctly logged when request comes through http call, anything executed via oil is logged above warning level.

    I'll try to dig deeper into the problem and let you know about my findings,  thank you for all the help so far.

Howdy, Stranger!

It looks like you're new here. If you want to get involved, click one of these buttons!

In this Discussion