TYPO3 Core

Problem¶

I experience random logouts using the install tool on 7.6 and master.

Do some extensive tracing, I discovered a race-condition in the custom session file handling implemented for the Install Tool.
The issue occurs for the ajax requests fired to create the overlay badges of the menu items.
Those requests are fired very close to each other, causing the session-file to be read by each request within a very close time frame.

Due to the nature of the implementation, the current session file is written back to disk immediately after being read.

...
$content = (string)(@file_get_contents($sessionFile));
$this->write($id, $content);
...

In the write() method the GeneralUtility::writeFile() function is used to write the file.
writeFile() internally uses PHP's fopen($file, 'wb'), which truncates the file upon opening it.

At precisely this moment the second ajax request reads the session file.
The first ajax request now writes the content to the file, but the second ajax request overwrites this again with the empty content, ultimately resulting in a missing session.

Analysis¶

This is the debug code used to trace the behaviour:

Log-Code in session write() method:

$result = GeneralUtility::writeFile($sessionFile, $sessionData);
file_put_contents(PATH_site . 'typo3temp/it.log', microtime() . ' ' . $_REQUEST['install']['controller'] . ' ## '. $_REQUEST['install']['action'] . ' ## write: ' . $id . ' ## '. strlen($sessionData) . LF, FILE_APPEND);

Log-Code in session read() method:

$content = (string)(@file_get_contents($sessionFile));
$this->write($id, $content);
file_put_contents(PATH_site . 'typo3temp/it.log', microtime() . ' ' . $_REQUEST['install']['controller'] . ' ## '. $_REQUEST['install']['action'] . ' ## read: ' . $id . LF, FILE_APPEND);

Log-Code in isAuthorized() method:

if (!$_SESSION['authorized']) {
   file_put_contents(PATH_site . 'typo3temp/it.log', microtime() . ' ' . $_REQUEST['install']['controller'] . ' ## '. $_REQUEST['install']['action'] . ' ## !!!auth!!! ' . session_id() . LF, FILE_APPEND);
   return false;
}

According to these logs, each request is expected to log values in this order:

• write (called via the session read() method)
• read
• write (finally persisting the session after request is finished)

This is log trace:

Format of each line is:
microtime() controller ## action ## session-action: session-id ## content length written
1) 0.61857400 1455732947 ajax ## folderStatus ## write: qftq51s8qo80iuhv00chsuglo2 ## 187
2) 0.61859600 1455732947 ajax ## environmentStatus ## write: qftq51s8qo80iuhv00chsuglo2 ## 0
3) 0.61861800 1455732947 ajax ## environmentStatus ## read: qftq51s8qo80iuhv00chsuglo2
4) 0.61890200 1455732947 ajax ## folderStatus ## read: qftq51s8qo80iuhv00chsuglo2
5) 0.61896800 1455732947 ajax ## environmentStatus ## write: qftq51s8qo80iuhv00chsuglo2 ## 11
6) 0.61930100 1455732947 ajax ## environmentStatus ## write: uu8k4eip42il7c45iska14f177 ## 0
7) 0.61932900 1455732947 ajax ## environmentStatus ## read: uu8k4eip42il7c45iska14f177
8) 0.61937900 1455732947 ajax ## environmentStatus ## !!!auth!!! uu8k4eip42il7c45iska14f177
9) 0.61951600 1455732947 ajax ## environmentStatus ## write: uu8k4eip42il7c45iska14f177 ## 11
A) 0.64124100 1455732947 ajax ## folderStatus ## write: qftq51s8qo80iuhv00chsuglo2 ## 187

These three ajax request are obviously handled in a very close time frame, as the logged call - specifically the first write+read - are interleaved.
In line 1 the first ajax request correctly reads the full session data (length 187 bytes) and writes it back.
Really shortly after that, in line 2, the second request obviously read the same session, but with length zero and also writes that empty content back to the session file.
The full session-read process of ajax request 2 finished before the session-read of request 1 finished, even if it started earlier.
In line 5 the second request writes a new (unauthenticated) session (length 11) to the session file.
In line 6 another ajax request comes in and starts a completely new session causing a redirect to the login form.

Mitigation¶

On my dev machine it was enough to add a small delay usleep(100) to get rid of the problem. Clearly this is not a good solution as it only moves the problem to a machine, where the execution speed again causes the same race-condition.

The real solution is to exclusively lock the session file before writing to it.