fuel / core

Fuel PHP Framework - The core of the Fuel v1 framework
http://fuelphp.com
813 stars 345 forks source link

1.5.1 ‘Fatal error: Call to a member function log()’ #1295

Closed zoe-edwards closed 11 years ago

zoe-edwards commented 11 years ago

Fatal error: Call to a member function log() on a non-object in .../fuel/core/base.php on line 91

91 being...

return \Log::instance()->log($level, (empty($method) ? '' : $method.' - ').$msg);
it-can commented 11 years ago

Error is existing in 1.6/develop:

Fatal error: Call to a member function log() on a non-object in /fuel/core/base.php on line 89

WanWizard commented 11 years ago

For 1.6/develop that bug was fixed here: https://github.com/fuel/core/commit/6c4a46229d81f4bb9ebc15ae637e17ffc87a4d15 so update your installation.

For 1.5.1 I wouldn't know what the reason would be, can you check if you have the 'Log' package available, installed, and loaded?

it-can commented 11 years ago

Hi i tested some more but it doesn't work for 1.6... It seems that the _init() function is not called when doing \Log::instance() So static::$monolog is always null...

WanWizard commented 11 years ago

Are you sure this is the case?

This also happens if there is no write access to the log file, which will trigger an error before it gets to that line. The error handler in turn will want to log the error, which it can't because the instance isn't there.

This issue has been fixed on the 24th (both for 1.6. and for 1.5.1), Log to dies with a fatal error when it can't write to the logfile. Are you sure your code is up to date?

it-can commented 11 years ago

Jeah i updated to the latest and have monolog in place... And folders have the right permissions...

it-can commented 11 years ago

To reproduce, create a controller and put a character somewhere, then php will raise an error and you get the error message

WanWizard commented 11 years ago

On a new stock 1.6 install, if I do that, I get the standard

Parsing error: ErrorException [ Parsing Error ]: syntax error, unexpected 'x' (T_STRING), expecting function (T_FUNCTION)

screen, and

ERROR - 2013-01-26 16:38:45 --> Parsing Error - syntax error, unexpected 'x' (T_STRING), expecting function (T_FUNCTION) in APPPATH/classes/controller/welcome.php on line 14

in the logfile.

it-can commented 11 years ago

Mmm this weird...

WanWizard commented 11 years ago

And if I remove write rights from the log file or folder, I get

Fatal error: could not create or access the log file (APPPATH/logs/2013/01/26.php) check your file system permissions!

WanWizard commented 11 years ago

You don't have the old Log package still installed in 1.6? Because that would overload the new core class...

it-can commented 11 years ago

I removed the log package en updated the core submodule..

it-can commented 11 years ago

I get this also with a fresh 1.6/develop install...

Parse error: syntax error, unexpected 'g' (T_STRING), expecting function (T_FUNCTION) in /websites/fuel/fuel/app/classes/controller/welcome.php on line 24

Fatal error: Call to a member function log() on a non-object in /websites/fuel/fuel/core/base.php on line 89

the error in my controller:

class Controller_Welcome extends Controller
{
g
public function action_index()
{
    return Response::forge(View::forge('welcome/index'));
}
}

I also did a php oil refine install, but still the same error... If I add the following in base.php (on line 88)

\Log::_init();

It works... So it seems that the Log class is not initialized at that point?

WanWizard commented 11 years ago

I don't know why I can't reproduce it, but I think I know what causes your issue. Fix is on the way.

it-can commented 11 years ago

Thanks

it-can commented 11 years ago

What do you think causes this issue?

WanWizard commented 11 years ago

I'm not sure, but it looks like an issue with the autoloader in an error or shutdown situation.

I went through the rest of the error handling code, and I noticed Dan fixed similar issues by just manually loading the classes, and manually aliassing them. But though that loads fine, that will not call _init().

foxhound87 commented 11 years ago

same error here, im my app this issue is produced when I set assets form the theme class

WanWizard commented 11 years ago

See https://github.com/fuel/core/issues/1308

adamwaite commented 11 years ago

I got this on a fresh install of 1.5.1 too. I need to build this site quick so I downgraded to 1.4. Just thought I'd let you know.

kenjis commented 11 years ago

@adamwaite Mac OS X?

kenjis commented 11 years ago

I can't reproduce it, but a few users in Japan got the error on Fuel 1.5.1. And confirmed workaround https://github.com/fuel/core/commit/c8dd475e52debe40c4ebd3a0a8ba48a9f791a235 to packages/log/classes/log.php solved the problem.

@WanWizard I hope the workaround to packages/log/classes/log.php on 1.5, too.

WanWizard commented 11 years ago

Well, it solves this specific issue. It doesn't solve the problem. The problem is a nasty bug in the autoloader, which seems to have been there since day 1, but only now surfaces.

I'm currently designing a fix, and if that works, we'll probably release 1.5.2.

adamwaite commented 11 years ago

Yeah it was Mac OSX but I run my dev server through a Vagrant box running Ubuntu Precise. Thanks, keep up the great work. Fuel is the best!

WanWizard commented 11 years ago

I think this will fix these issues: https://github.com/fuel/core/commit/974281dde67345ca8d7cfa27bcf4aa55c984d48e. Is someone in a position to test this (I still can not reproduce these errors properly).

adamwaite commented 11 years ago

I'll have a try tonight.

WanWizard commented 11 years ago

Thanks.

knitinr commented 11 years ago

@WanWizard , @kenjis

I had the error: Fatal error: Call to a member function log() on a non-object in /var/www/fuelphp-1.5.1/fuel/core/base.php on line 91 The error message appears twice, if that's any clue to solving the problem.

I had a go at using c8dd475 on a FuelPHP 1.5.1 fresh install from the website (manual install from http://fuelphp.com/files/download/19 ) i.e. I made the necessary changes to fuel/packages/log/classes/log.php after which my instance function looks like this: public static function instance() { // make sure we have an instance, create one if needed static::$monolog or static::_init(); // return the created instance
return static::$monolog; }

It did give me more clarity on what I missed earlier with the error:

Fatal error: Uncaught exception 'Fuel\Core\PhpErrorException' with message 'mkdir(): Permission denied' in /var/www/fuelphp-1.5.1/fuel/packages/log/classes/log.php:56 Stack trace: #0 /var/www/fuelphp-1.5.1/fuel/core/bootstrap.php(48): Fuel\Core\Error::error_handler(2, 'mkdir(): Permis...', '/var/www/fuelph...', 56) #1 [internal function]: {closure}(2, 'mkdir(): Permis...', '/var/www/fuelph...', 56, Array) #2 /var/www/fuelphp-1.5.1/fuel/packages/log/classes/log.php(56): mkdir('/var/www/fuelph...', 511, true) #3 /var/www/fuelphp-1.5.1/fuel/packages/log/classes/log.php(83): Log\Log::_init() #4 /var/www/fuelphp-1.5.1/fuel/core/base.php(91): Log\Log::instance() #5 /var/www/fuelphp-1.5.1/fuel/core/classes/error.php(27): logger(400, '2 - mkdir(): Pe...') #6 /var/www/fuelphp-1.5.1/fuel/core/classes/error.php(110): Fuel\Core\PhpErrorException->handle() #7 /var/www/fuelphp-1.5.1/fuel/core/bootstrap.php(42): Fuel\Core\Error::exception_handler(Object(Fuel\Core\PhpErrorException)) #8 [internal function]: {closure}(Object(Fuel\Core\Php in /var/www/fuelphp-1.5.1/fuel/packages/log/classes/log.php on line 56

After setting the filesystem permissions correctly, I no longer have the error.

knitinr commented 11 years ago

P.S.: I also wanted to mention that with my filesystem permissions set correctly, I tried again after rolling back the change from c8dd475 , and still no error.

Perhaps all we need is a filesystem permission check (?).

WanWizard commented 11 years ago

It's difficult to come up with a check that always works, and since this runs for each page request, from a performance point of view you don't want this check. What you want is a proper error message, so you can fix the permission issue.

You get the current mess instead because of a bug in the autoloader. This bug has been fixed, and the fix has been backported to 1.5/develop.

inexcii commented 11 years ago

I had the same issue and after I specified the "date.timezone" value in php.ini file, it is solved.

axelitus commented 11 years ago

I can confirm this is still an issue in FuelPHP 1.6.1; I'm afraid it has something to do with when the dir does not exists and maybe to some permission issues because the script fails when creating the dir (though no error is raised, nor the mkdir return an error... maybe it's my configuration, I'll dig deeper into this. For me the script fails between the lines 61 and 71 from the fuel/core/log.php file, so a monolog instance is never created....

axelitus commented 11 years ago

Ok now, I confirm this is an issue with permissions. The user apache2 was running on was www-data, which is not the user that had the permissions on the folder. I just added www-data to the correct group for the folder and it worked. The thing is mkdir fails silently (it actually breaks the script as it stops executing the script right there, not raising exceptions or otherwise...). I'm running Ubuntu 13.04 fresh installed and configured.

As I think this is an issue with the underlying platform (either PHP or Ubuntu or both) and NOT a problem with FuelPHP this issue can remain closed, just thought that I should leave this here for anyone having the same issue and not getting any error message to have a starting point.

WanWizard commented 11 years ago

I develop on Fedora, and I can't reproduce it. If I deny the apache user write rights to the logs folder, it bails out with an Execption, as it should (on the mkdir()), I just had it tonight when I was testing the 2.0 Log code.

It is important to get to the bottom of this, as 2.0 will use the same base code to setup the Log instance...

ghost commented 11 years ago

My tests indicate that this is an issue with the permissions. I'm not a linux hardcore user, in fact I'm just "starting" so I don't know how to do an exhaustive debugging of this. The steps I took to fix this were this if it helps you:

  1. I cloned my source code using git to ~/Develop/Web/axelitus.mx-src. (The app's log folder is empty, just with the .gitkeep file)
  2. I configured a vhost entry in apache (along the corresponding entry in my /etc/hosts file). Virtual host entry:
<VirtualHost *:80>
    ServerAdmin webmaster@axelitus.mx
    DocumentRoot ~/Develop/Web/axelitus.mx-src/public
    ServerName axelitus.mx.local
    ServerAlias axelitus.mx.local
    ErrorLog logs/axelitus.mx-error_log
    CustomLog logs/axelitus.mx-access_log common

    <Directory ~/Develop/Web/axelitus.mx-src/public>
        Options Indexes FollowSymLinks MultiViews
        AllowOverride All
        Order allow,deny
        Allow from all
        Require all granted
    </Directory>
</VirtualHost>
  1. Installed Fuel packages running composer update (I have a global composer installation) in the root folder ~/Develop/Web/axelitus.mx-src
  2. Installed my own packages running composer update in the app folder ~/Develop/Web/axelitus.mx-src/fuel/app
  3. Restarted apache service with sudo service apache2 restart
  4. Loaded the webpage and got the Fatal error: Call to a member function log() on a non-object in /home/axel/Develop/Web/project-src/fuel/core/base.php on line 91 (and now I'm realizing maybe there was a misunderstanding, I got this exception from the start on... but when debugging, the mkdir call did not return anything, in fact it stopped the script's execution right there). Image: screenshot01
  5. Runned the following commands in the terminal (added user www-data to group axel [my user's default group]) and restarted apache service:
axel@freyr:~$ groups www-data
www-data : www-data
axel@freyr:~$ sudo usermod -G axel www-data
axel@freyr:~$ groups www-data
www-data : www-data axel
axel@freyr:~$ sudo service apache2 restart
 * Restarting web server apache2                                                apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1 for ServerName
 ... waiting apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1 for ServerName
                                                                         [ OK ]
axel@freyr:~$

Image: screenshot02

  1. After all that I reloaded the webpage and it worked fine. Image: screenshot03

So this surely has to do with the permissions of the user that the apache2 service is running with.

If you need anything more to be tested please let me know!

ghost commented 11 years ago

Another thing I just realized (and it is somewhat stupid so sorry) is that I was running in production mode (my .htaccess has the SetEnv FUEL_ENV production statment).

Maybe that was why I didn't get errors or some response form the mkdir call?

WanWizard commented 11 years ago

Given the fact that you got a fatal error, and not a Fuel error message, is a big clue.

What I think happens, is that Log fails on the mkdir(), generates an exception, which is caught because you're running in production mode and that doesn't show exceptions. Instead it will log the exception and displays a generic error message. It is this log entry that fails, and because you're already in the exception handler, you see a plain PHP error.

Now, what I don't understand: in the Log class init, that mkdir() is in a try/catch block. If the mkdir() causes a PHP error, Fuel will convert that to a PHPErrorException. Which should be caught by that catch, and display a message asking you to check your permissions. So why did that not happen?

ghost commented 11 years ago

I don't know... it seemed strange to me too. I'm debugging the code (installed xdebug and got a "nice" error coloring shown at the screenshot) it is indeed strange. When I reach the line 63 [mkdir($rootpath, 0777, true);] the next step in the debugger just ends the script as I've been telling. screenshot04

Maybe the mkdir function triggers an apocalyptic-error and it does not get handled even by the try/catch block, it just stops the execution. I've prepared a screencast of the debugging process to show you more clearly what happens: http://ge.tt/2qzf6jn/v/0?c

I'm "Stepping over" each statement. As you can see, when I reach the line 63 and hit F8 to step over it, the execution stops and the error is displayed in the browser. The debug session didn't stop, it just "lost the connection". The catch part in the try/catch block is never reached.

WanWizard commented 11 years ago

In your backtrace you see that Fuel's init() calls logger(), which loads the Log class, and trips over the mkdir. It does call the Fuel error handler, which does convert it to a PhpErrorException (so that bit works), but then it tries to recover and call logger() again, which will now fail since the Log::init() was aborted without creating a log instance.

Looking at the code, it recovers when the error is listed in the config key "errors.continue_on". I'm pretty sure fatal errors are not the ones you want to recover from, and by default no PHP error type is defined as recoverable. Did you change this key in your application?

ghost commented 11 years ago

I'm 99% percent certain that I haven't touched the errors configuration in the config.php file. Here's what I have:

    'errors'  => array(
        // Which errors should we show, but continue execution?
        'continue_on'  => array(E_NOTICE, E_WARNING, E_DEPRECATED, E_STRICT),
        // 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,
    )

Comparing it to the current base code in the 1.6/master branch I can see that this part of the code is commented out:

    // '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' => false,
    // ),

I have been updating Fuel from version 1.2 I think in this project and I do so without touching the app folder (I just update the fuel/core and fuel/public folder), so maybe it is something I miss when it changed? I'm gonna comment it out and run the tests again.

ghost commented 11 years ago

Ok, now I've got a nice FuelPHP Exception page with a DESCRIPTIVE error of what it's really happening :) screenshot05

I was expecting this error from the start and now it's working. So, somehwere along the way you change that config part and I missed the changed and thus it was working not as you guys intented (As claims your own statement: "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."

So I'm gonna go through the config file again and compare it with the current base code to see what else I'm missing...

WanWizard commented 11 years ago

Undocumented by our PHP friends, but appearantly mkdir() can give a "Permission denied" and "File does not exist" (huh?), both of which are E_WARNING. Which explained why it tried to continue.

I presonally think you should never be allowed to continue, no matter what the error is. Fuel v2 will not have this option anymore, not even on a NOTICE. Even that is something a dev should fix.

Glad we've got this sorted!

WanWizard commented 11 years ago

To be complete:

It was changed for 1.3, https://github.com/fuel/fuel/commit/9a7141e6f2cbfea4aab1a60fab62898ce7494cff

ghost commented 11 years ago

Yes you are right and I completely agree with you. Every error, notice, warning should be addressed by the developer or it should trigger an exception/error page as to continue does so in an "unstable app environment".

I did miss the config update to comment this things out (in fact I've seen almost the whole config file was commented out, which is as it should be when not changing default behavior).

I'm gonna be more careful when changing FuelPHP versions as to see the config changes and so...

Glad I was of help to get to the bottom of this!

axelitus commented 11 years ago

BTW, sorry about the "ghost" user... I just had a mess with my account (in fact I had two accounts, I "merged" them...)