Error during unserialize

[Lumeriol]

Version: 3.x-dev

Bug Description

unserialize(): Error at offset 0 of 145 bytes (variable number of bytes)

File: ...\nette\caching\src\Caching\Storages\FileStorage.php:333

$variable_representation | "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00a:2:{s:2:"id";b:1;s:4:"code";b:1;}" (127)

Steps To Reproduce

Problem is with PHP 7.3 (rc3) on some pages only. After refresh page there is this problem. Cache is deleted. It seems that data is from Sessions - problem start on with this code: $this->currency = $this->facade->getById($this->sessionSection->currency['id']);

Facade: $data = $this->db->table($this->repository)->wherePrimary($id)->fetch();

Stack trace: 2) ...\nette\caching\src\Caching\Storages\FileStorage.php:85

$meta | array (4) time => "0.78053500 1540276060" serialized => true file => "../temp/cache/_Nette.Database.83a928a729900849010020b112a30316/_6034dbe4a271e54806a0513243994932"

handle => unknown type

Content of file: 000068a:2:{s:4:"time";s:21:"0.09111900 1540276063";s:10:"serialized";b:1;} a:0:{}

3. ...\vendor\nette\caching\src\Caching\Cache.php
4. ...\database\src\Database\Table\ColumnAccessCache.php:128

Possible Solution

There is maybe dependency with solution of https://github.com/nette/database/issues/208#issue-366541206

[milo]

Accordingly to provided message:

"\x00\x00\x00\x00 ... a:2:{s:2:"id";b:1;s:4:"code";b:1;}"

I thing that cache writing fails here. Not sure why, but the malformed file should be deleted anyway by delete() call after that. But it is not, cache file is still present and unserialization failes on next calls.

[JanTvrdik]

likely same error as https://github.com/nette/caching/issues/45

[milo]

The code itself looks atomic to me. My idea is, that malformed cache contents cames with script interruption. Any other theory?

When thinking about it in common, the only safe way is file system rename() call.

[milo]

@Lumeriol Do you have any notice/warning/error with FileStorage.php source in log before this event?

[JanTvrdik]

that malformed cache contents cames with script interruption

Yes, that's what usually called non-atomic. Atomic write requires writing to another file and renaming it after.

[milo]

that malformed cache contents cames with script interruption

Yes, that's what usually called non-atomic. Atomic write requires writing to another file and renaming it after.

IMHO not necessarily. It can be done by writing "done" byte sequence and verify validity when reading header.

[milo]

What I don't understand... How is unserialize() called when there is a check.

@Lumeriol Do you have Tracy log for that? Could you post is somewhere whole?

[milo]

Maybe related to PHP bug 77081 fixed in 7.3RC5

[mrceperka]

I've got the same problem on PHP 7.1.1, OS alpine:3.6

[milo]

Could you provide Tracy dump file?

[milo]

@mrceperka Btw, which nette/cahing version?

[mrceperka]

Version: v2.5.8. Can't provide Tracy dump file because, there is not any... Error message was:

PHP Notice: unserialize(): Error at offset 18 of 61 bytes in /some/path/vendor/nette/caching/src/Caching/Storages/FileStorage.php:339  @  url

[Lumeriol]

@milo I think that this bug was during development of new DI for Nette 3, but I don't remember it. But today I try it again with release of 7.3.0 stable and it seems everything is okay. So this topic could be closed for this problem (that was maybe in RC versions), or stay opened until fix of @mrceperka problem :)