Undefined index: i in … FileJournal.php

5 years ago

hubipe
Member | 26
+
0
-

Hello,
from time to time (it happened 3 times since web was launched 2 months ago), FileJournal got corrupted. I don't know how does it happend, but result is, that users got Error 500 page.

In log it starts like this:

[2014-11-05 10-23-03] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:616  @  http://...
[2014-11-05 10-23-03] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:728  @  http://...
[2014-11-05 10-23-10] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:797  @  http://...
[2014-11-05 10-23-10] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:728  @  http://...
[2014-11-05 10-23-16] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:797  @  http://...
[2014-11-05 10-23-16] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:728  @  http://...
[2014-11-05 10-23-42] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:797  @  http://...
[2014-11-05 10-23-42] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:728  @  http://...
[2014-11-05 10-24-31] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:797  @  http://...
[2014-11-05 10-24-31] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:728  @  http://...
[2014-11-05 10-25-07] PHP Notice: Undefined index: i in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:797  @  http://...

then, always few logs after, it starts filling with FatalExceptions:

[2014-11-10 12-24-19] PHP Warning: Illegal offset type in isset or empty in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:569  @  http://...
[2014-11-10 12-24-19] Fatal error: Unsupported operand types in ...\libs\_vendors\nette\nette\Nette\Caching\Storages\FileJournal.php:573  @  http://...

Some system info:

Apache/2.4.9 (Win32) OpenSSL/1.0.1g PHP/5.5.11
Windows Server 2012
FileSystem NTFS
Nette Framework 2.1.2 (revision released on 2014-03-17)

Does anybody else experienced the same problem? I'm not sure why is this happening in such a rare occassions (it's not public server, maybe when simultaneous write to cache is performed? Does NTFS supports File locking?)

5 years ago

xificurk
Member | 119
+
0
-

We ran into this on one of our projects. Since it was isolated occurrence, we did not investigate the underlying cause and simply deleted the cache.

Our system info is:
Ubuntu Linux
ext4 FS
PHP 5.3.10–1ubuntu3.15
Nette 2.1.4

5 years ago

cubic
Member | 48
+
0
-

I had similar problems last year. For some reason file btfj.dat wasn't saved complete. There was no obvious reason but memcached / redis solved the problem..

5 years ago

hubipe
Member | 26
+
0
-

If this occured only once, I'd be happy, but explain to your client, that Error 500 occured due to some error I can't handle and I don't know how it happened :)

5 years ago

Jan Tvrdík
Nette guru | 2556
+
0
-

I would blame this on Windows. You may try to enable FileJournal::$debug.

BTW: Probably a lot more interesting than your system info is how exactly do you use cache? What kind of dependencies do you use? Do you use priority? Do you use tags? etc.

Last edited by Jan Tvrdík (2014-11-11 09:55)

5 years ago

Michalek
Member | 192
+
0
-

Same problem on Nette 2.1, don't know why. Just sometimes.

This works, but I think it's not good solution :)

ErrorPresenter.php

    public function renderDefault($exception)
    {
        if($exception instanceof Nette\InvalidStateException) {
            $temp = $this->context->parameters['tempDir'];
            unlink($temp . '/btfj.dat');
        }
    }

Last edited by Michalek (2014-11-11 09:58)

5 years ago

Milo
Nette Core | 1149
+
0
-

@Michalek In your workaround… could you rename btfj file instead of removing? For example:

rename($temp . '/btfj.dat', $temp . '/btfj.dat' . microtime(TRUE));

And send me such malformed files? It is very hard to solve this issue and any feed back is very appreciated.

https://github.com/…ng/issues/11

5 years ago

Michalek
Member | 192
+
0
-

Ok, changed, we will see.

5 years ago

hubipe
Member | 26
+
0
-

Here are three corrupted btfj.dat I could restore from recycle bin (at least I thing they're corrupted):

http://filejournal.hubik.net/btfj1.dat
http://filejournal.hubik.net/btfj2.dat
http://filejournal.hubik.net/btfj3.dat

Last edited by hubipe (2014-11-12 00:37)

5 years ago

hubipe
Member | 26
+
+1
-

@JanTvrdík I use only TAGS to be able to expire cache by those tags. (Plus EXPIRE, but that doesn't have anything to do with FileJournal.)

5 years ago

Milo
Nette Core | 1149
+
0
-

@hubipe Thank you! I reuploaded files (links in Github issue) so you can delete them if you wish.

If you can, could you replace your FileJournal.php by this one from Gist? It adds simple logging functionality into file btfj.dat.log in the same directory. It does not solve the issues, but it tries to log situations you mentioned in your first post. So, you should still get PHP notices, but Fatal Error should be suppressed.

Before sending a log, please, check the privacy content. It will contain variable dumps and stack traces.

5 years ago

hubipe
Member | 26
+
0
-

I uploaded your FileJournal, now I can only wait.

5 years ago

Milo
Nette Core | 1149
+
0
-

@hubipe Some catches in log file?

5 years ago

hubipe
Member | 26
+
0
-

None yet, it can take a while (even a month), until the error occures again. I'll keep you updated

5 years ago

hubipe
Member | 26
+
0
-

Ok – it happened again (I wasn't able to upload it sooner, sorry):

http://filejournal.hubik.net/btfj4.dat
http://filejournal.hubik.net/btfj4.dat.log

5 years ago

Milo
Nette Core | 1149
+
0
-

Thanks! I'll analyze it and report it to the FileJournal author.

If you want to prevent FileJournal buggy behaviour, you can use SQLiteStorage instead of FileStorage. It works with TAGS and PRIORITY too, but it is slower.