Bug #97062
closed
PHP Warning: filemtime(): stat failed ... in FileSessionHandler.php line 204
0%
Description
I have about 10 such entries per day in the log:
Sat, 26 Feb 2022 17:37:27 +0100 [WARNING] request="a2ab16ea9d6ba" component="TYPO3.CMS.Core.Error.ErrorHandler": Core: Error handler (FE): PHP Warning: filemtime(): stat failed for /www/htdocs/typo3temp/var/session/965e817f98876f860f9b3fd9c6b522f0aa9aaf6d/hash_c845ed11a7dc29cfab61d133e4aaf948 in /www/htdocs/typo3_src-10.4.25/typo3/sysext/install/Classes/Service/Session/FileSessionHandler.php line 204
File FileSessionHandler.php:
196 public function gc($maxLifeTime)
197 {
198 $sessionSavePath = $this->getSessionSavePath();
199 $files = glob($sessionSavePath . '/hash_*');
200 if (!is_array($files)) {
201 return true;
202 }
203 foreach ($files as $filename) {
204 if (filemtime($filename) + $this->expirationTimeInMinutes * 60 < time()) {
205 @unlink($filename);
206 }
207 }
208 return true;
209 }
However, the function has a very simple structure. Glob searches for the files, which are then deleted in a foreach loop. I don't understand how files are found here that are no longer available shortly afterwards.
(First of all no problem, the argument $maxLifeTime is not used within the function.)
I have been using this typo3 installation for years without any errors. Unfortunately I don't know the exact time since the problem started. Probably typo3 versions 10.4.21 - 10.4.23. Version 10.4.25 is currently in use with PHP 7.4.3 (fpm/Apache) on Ubuntu-Server 20.04.4.
The directory exists, there are also session files:
$ ls -l /www/htdocs/typo3temp/var/session/965e817f98876f860f9b3fd9c6b522f0aa9aaf6d total 592K drwxrwsr-x 2 www-user www-user 48K Feb 28 12:50 . drwxrwsr-x 3 www-user www-user 4,0K Jan 27 14:02 .. -rw-rw-r-- 1 www-user www-user 11 Feb 28 12:40 hash_031a442747c706b9e92087b3097e8cb0 -rw-rw-r-- 1 www-user www-user 10K Feb 28 12:36 hash_03db333aa9563b4ee7ccb225d5000a75 -rw-rw-r-- 1 www-user www-user 11 Feb 28 12:36 hash_068c1cbd2ff5873af4da2d695338664f -rw-rw-r-- 1 www-user www-user 10K Feb 28 12:40 hash_09ded894bea3b1d9d9373b0814f68321 -rw-rw-r-- 1 www-user www-user 10K Feb 28 12:40 hash_0d0e1f6329f1fee0c175b87c882f161f -rw-rw-r-- 1 www-user www-user 10K Feb 28 12:44 hash_0d77a82d9e26d49a95cc1cfb0e920d40
According to github, there hasn't been any change to this gc() function for a long time.
Now I have no more ideas. Maybe a php problem? The Ext4 file system has been checked and is ok.
Thanks.
Updated by Markus Klein over 2 years ago
- Status changed from New to Needs Feedback
I don't understand how files are found here that are no longer available shortly afterwards.
That is called race condition. You have probably high load and your gc-code is executed in parallel by multiple requests.
Hence two (or more) search the files basically in parallel and one of them deletes a file, which might then be "missing" for the other requests.
That's so far expected, as there are no means of synchronization between those requests.
Updated by Markus Klein over 2 years ago
Note that this session handler is called by PHP, so please check your session* config options of PHP, those might be related as well.
Updated by Peter Friesen over 2 years ago
Okay, I know the race condition. I hadn't even considered that in this case. I checked the Apache log file with the timestamp of the error. Actually four identical requests at this time. So that will be the cause.
[26/Feb/2022:17:37:27 +0100] "GET /news/abcd.html HTTP/1.1" 206 16274 "-" "facebookexternalhit/1.1" [26/Feb/2022:17:37:27 +0100] "GET /news/abcd.html HTTP/1.1" 206 16265 "-" "facebookexternalhit/1.1" [26/Feb/2022:17:37:27 +0100] "GET /news/abcd.html HTTP/1.1" 206 16258 "-" "facebookexternalhit/1.1" [26/Feb/2022:17:37:27 +0100] "GET /news/abcd.html HTTP/1.1" 206 16278 "-" "facebookexternalhit/1.1" [26/Feb/2022:17:37:27 +0100] "GET /news/abcd.html HTTP/1.1" 206 16283 "-" "facebookexternalhit/1.1"
My PHP session.* configuration is default. I have never changed anything here.
But then the problem must also occur on other sites?! Would an easy solution be to make the warning silent with @filemtime?
Updated by Markus Klein over 2 years ago
This for sure must happen elsewhere too, but I am a bit unsure why the Install Tool Session Management (!) is triggered for those requests you posted. This seems a bit unusual to me. Maybe you have an explanation for that as well?
Updated by Peter Friesen over 2 years ago
Hm, i have no idea. This is a page with tx_news and a news-comment extension. There is no install-tool related in apache logfile.
Updated by Markus Klein over 2 years ago
I guess you need to debug then somehow why and when SessionService is called, because it's the one which actually registers the session handling with PHP. (Choose whatever fits your system best: From real debugging to a die statement, or similar)
Updated by Peter Friesen over 2 years ago
Ok i tried something on the fly. I added a die() in FileSessionHandler.php and found out that only with the news-comment extension the die() will be executed. I'll examine the extension more closely tomorrow and let you know.
Updated by Markus Klein over 2 years ago
- Priority changed from Should have to -- undefined --
I didn't want to speculate, but I already suspected this extension. We tried to use it some years ago, it ended with the tryout.
Updated by Peter Friesen over 2 years ago
No more words.
Classes/Controller/CommentController.php
public function initializeAction()
{
$sessionService = GeneralUtility::makeInstance(\TYPO3\CMS\Install\Service\SessionService::class);
$sessionService->startSession();
...
Thank you for your help :-)
Updated by Markus Klein over 2 years ago
- Status changed from Needs Feedback to Closed
Yup... lack of understanding by the programmer.