From: [EMAIL PROTECTED]
Operating system: Linux - RH7.0
PHP version: 4.0.4pl1
PHP Bug Type: *Session related
Bug description: Timing issue - new page reads session before old page has saved it
Summary: On a high-speed network system, a page with a header(Location: ...) call
does not always write the session file before the referred-to page reads it. The
result is a loss of session continuity. I have not been able to reproduce this
behavior across the internet. Additionally, I have not been able to reproduce this
behavior on the local net with IE as the client, but it is reproducable with NS 4.7
running on Linux 6.0 and win98.
My PHP configuration line: ./configure --with-apxs --enable-bcmath --with-bz2
--with-config-file-path=/etc --disable-debug --enable-debugger --enable-ftp --with-gd
--with-gettext --enable-inline-optimization --with-jpeg-dir=/usr --with-mysql=/usr
--enable-magic-quotes --with-png --with-regex=system --enable-safe-mode
--disable-short-tags --disable-static --enable-sysvsem --enable-sysvshm
--enable-track-vars --enable-trans-sid --enable-yp --with-zlib
The server is an Athlon 600 with 128MB, running a stock RH7.0 system with apache
1.13.12 as installed with RH7.0. The php.ini file is identical to php.ini-dist. I
compiled MySQL 3.23.33 (relevant for the session-based variant discussed later). The
clients are an Athlon 600 with 384 MB (Linux) and a K6-200 with 128MB (win98), each
with NS4.7. The network is switched at 100 Mb/s.
The three following files can reproduce the behavior. I'm sorry that they're so long,
but this is the minimum set. The originals were much, much longer.
begin index.html +++++++++++++++++++++++++++++++++++++
<HTML>
<HEAD>
<TITLE>Home Page</TITLE>
</HEAD>
<BODY>
<HR>
<a href="foo.html"><IMG SRC="foo.gif"></a>
<HR>
Home<BR>
<a href="users.php">Users</a><BR>
<HR>
<HR>
</BODY>
</HTML>
end index.html ++++++++++++++++++++++++++++++++++++++++
begin users.php +++++++++++++++++++++++++++++++++++++++
<?php
$fd = fopen("/tmp/debuglog", "a");
fwrite($fd , "=====================================================\n");
# fire up the session tracking and register the
# session variables
session_start();
session_register(array('user' , 'pass' , 'returnfromlogin' , 'loginfailures'));
session_register("count");
$count++;
$returnfromlogin=$PHP_SELF;
if(TRUE) {
$sessdata = session_encode();
fwrite($fd , " PHPSESSID:$PHPSESSID:\n");
fwrite($fd , " sessid:" . session_id() . ":\n");
fwrite($fd , " user:$user:\n");
fwrite($fd , " pass:$pass:\n");
fwrite($fd , "returnfromlogin:$returnfromlogin:\n");
fwrite($fd , " loginfailures:$loginfailures:\n");
fwrite($fd , " session_encode:" . session_encode() . ":\n");
fwrite($fd , " microtime:" . microtime() . ":\n");
header("Location: login.php");
# without this exit, PHP keeps running and wastes cpu
# and bandwidth
exit;
}
?>
<HTML>
<HEAD>
<TITLE>Administration - Users</TITLE>
</HEAD>
<BODY >
<P>The body goes here</P>
</BODY>
</HTML>
end users.php ++++++++++++++++++++++++++++++++++++++++
begin login.php ++++++++++++++++++++++++++++++++++++++
<?php
# if PHPSESSID is set, investigate the session state
# file (/tmp/sess_...)
# when things are not working properly, the session
# state file will be of
# zero length because the write from the previous page
# has not completed yet
if(isset($PHPSESSID)) {
$sfilename = "/tmp/sess_" . $PHPSESSID;
clearstatcache();
$mtime = microtime();
if(file_exists($sfilename)) {
$exists = "True";
$length = filesize($sfilename);
$sfile = fopen($sfilename , "r");
$scontent = fread($sfile , filesize($sfilename));
fclose($sfile);
if($exists=="True" && $length==0) {
# the usleep fixes everything
# usleep(1);
}
} else {
$exists = "False";
}
}
# open the debugging log and write out the current state
$fd = fopen("/tmp/debuglog", "a");
fwrite($fd , "---------------------------------------------\n");
fwrite($fd , "Initial\n");
fwrite($fd , " PHPSESSID:$PHPSESSID:\n");
fwrite($fd , " sessfileexists:$exists:\n");
fwrite($fd , " sessfilelength:$length:\n");
fwrite($fd , "sessfilecontent:$scontent:\n");
# fire up the session tracking
session_start();
$count++;
# clear the stat cache and re-investigate the session
# state file now that
# session_start has been called
clearstatcache();
if(file_exists($sfilename)) {
$exists = "True";
$length = filesize($sfilename);
}
fwrite($fd , "--------------------------\n");
fwrite($fd , "After session_start\n");
fwrite($fd , " PHPSESSID:$PHPSESSID:\n");
fwrite($fd , " sessid:" . session_id() . ":\n");
fwrite($fd , " user:$user:\n");
fwrite($fd , " pass:$pass:\n");
fwrite($fd , "returnfromlogin:$returnfromlogin:\n");
fwrite($fd , " loginfailures:$loginfailures:\n");
fwrite($fd , " sessfileexists:$exists:\n");
fwrite($fd , " sessfilelength:$length:\n");
fwrite($fd , " session_encode:" . session_encode() . ":\n");
usleep(1);
# clear the stat cache and re-investigate the session
# state file now that
# usleep(1) has been called
clearstatcache();
if(file_exists($sfilename)) {
$exists = "True";
$length = filesize($sfilename);
$sfile = fopen($sfilename , "r");
$scontent = fread($sfile , filesize($sfilename));
fclose($sfile);
}
fwrite($fd , "--------------------------\n");
fwrite($fd , "After usleep(1)\n");
fwrite($fd , " sessfileexists:$exists:\n");
fwrite($fd , " sessfilelength:$length:\n");
fwrite($fd , "sessfilecontent:$scontent:\n");
?>
<HTML>
<HEAD>
<TITLE>Administration - Login</TITLE>
</HEAD>
<BODY >
<TABLE border="5">
<TR>
<TD>
<center><font size="+3">Administration - Login</font></center>
<?php
# the next line should hold 'user.php', but it doesn't
# most of the time
print "<P>Return to: $returnfromlogin</P>\n";
print "<P>Loginpage: $loginpage</P>\n";
?>
<FORM METHOD="POST">
<P>Usename: <INPUT TYPE="text" SIZE=16 NAME="username"></P>
<P>Password: <INPUT TYPE="password" SIZE=16 NAME="password"></P>
<INPUT TYPE="hidden" NAME="validate" VALUE=1>
<P><INPUT TYPE="submit" VALUE="Login"></P>
</FORM>
</TD>
</TR>
</TABLE>
</BODY>
</HTML>
end login.php ++++++++++++++++++++++++++++++++++++++++++
The original idea was that I would store the desired page uri in a session variable
and redirect un-authenticated users to the login page. Upon successfully login in,
the user could be redirected back to the page they really wanted. For debugging
purposes, the login.php page shows the name of the page that dumped the user to the
login page. With the files provided above, it should always show "Return to:
somepath/users.php", but will often be "Return to:" - thus indicating a failure.
I have not been able to reproduce the behavior by either typing in the uri "users.php"
or creating a bookmark to it. It is reproducible if you start from the index.html and
click on the 'Users' link. Adding a 'foo.gif' image to load on the index.html page
increases the failure rate to 4 out of 5. Without the foo.gif image, the failure rate
is about 1 out of 10. I start a fresh copy of netscape for each test, thus removing
the session cookie.
There are debugging statements in the php code which log to the file /tmp/debuglog.
The log when the session functions properly looks like:
=====================================================
PHPSESSID::
sessid:1ed96ede8bcb57ebe228d3d72778f786:
user::
pass::
returnfromlogin:/lyons/session-bug-demo-file/users.php:
loginfailures::
session_encode:!user|!pass|returnfromlogin|s:38:"/lyons/session-bug-demo-file/users.php";!loginfailures|count|i:1;:
microtime:0.19839100 987667153:
---------------------------------------------
Initial
PHPSESSID:1ed96ede8bcb57ebe228d3d72778f786:
sessfileexists:True:
sessfilelength:99:
sessfilecontent:!user|!pass|returnfromlogin|s:38:"/lyons/session-bug-demo-file/users.php";!loginfailures|count|i:1;:
--------------------------
After session_start
PHPSESSID:1ed96ede8bcb57ebe228d3d72778f786:
sessid:1ed96ede8bcb57ebe228d3d72778f786:
user::
pass::
returnfromlogin:/lyons/session-bug-demo-file/users.php:
loginfailures::
sessfileexists:True:
sessfilelength:99:
session_encode:!user|!pass|returnfromlogin|s:38:"/lyons/session-bug-demo-file/users.php";!loginfailures|count|i:2;:
--------------------------
After usleep(1)
sessfileexists:True:
sessfilelength:99:
sessfilecontent:!user|!pass|returnfromlogin|s:38:"/lyons/session-bug-demo-file/users.php";!loginfailures|count|i:1;:
users.php write the first block between the === and the ---. It shows that the
session id has been created, the returnfromlogin variable has a value, and that
session_encode knows about all of the session variables.
login.php writes the remaining blocks. The 'Initial' block shows that the session id
has been retrieved from the cookie, that the session file exists and that it is 99
bytes long. It also reads the file which has the appropriate contents.
The 'After session_start' block shows that the variables have been successfully
recovered by session_start, and then re-confirms the session file's existence, length,
and contents.
The 'After usleep(1)' block confirms once-again the session file's existence, length,
and contents.
But, when the session doesn't work properly, here is what the log shows:
=====================================================
PHPSESSID::
sessid:42ea7fe7ec4d1bfec7732b5e6c425d92:
user::
pass::
returnfromlogin:/lyons/session-bug-demo-file/users.php:
loginfailures::
session_encode:!user|!pass|returnfromlogin|s:38:"/lyons/session-bug-demo-file/users.php";!loginfailures|count|i:1;:
microtime:0.18177800 987667522:
---------------------------------------------
Initial
PHPSESSID:42ea7fe7ec4d1bfec7732b5e6c425d92:
sessfileexists:True:
sessfilelength:0:
sessfilecontent::
--------------------------
After session_start
PHPSESSID:42ea7fe7ec4d1bfec7732b5e6c425d92:
sessid:42ea7fe7ec4d1bfec7732b5e6c425d92:
user::
pass::
returnfromlogin::
loginfailures::
sessfileexists:True:
sessfilelength:0:
session_encode::
--------------------------
After usleep(1)
sessfileexists:True:
sessfilelength:99:
sessfilecontent:!user|!pass|returnfromlogin|s:38:"/lyons/session-bug-demo-file/users.php";!loginfailures|count|i:1;:
The users.php write of the first block between the === and the --- is just as before.
The 'Initial' block shows that the session file exists, but is of 0 length. That
certainly explains why the login.php page isn't able to load the session variables.
The 'After session_start' block shows that the session_start was not able to load the
session variables, and that the session file is still 0 length.
The 'After usleep(1)' block (which really does follow a 1 micro-second sleep), shows
that the session file has finally been written by the first page, but long after the
second page needed it. The session file shows up with the proper length and contents,
only to be overwritten an instant later when the login.php page saves a 0 length file
because it doesn't know about the variables previously registered or their values.
It is so interesting that a 1 microsecond sleep gives the first page enough of a kick
to get its session information written. A quick-and-dirty fix has been to add a
usleep(1) before the session_start in login.php, which gets the users.php session
write to finish before the new session loads.
I hope that you are able to reproduce this on your local networks. It doesn't appear
to be an issue when the latency of the internet is involved, but it could certainly
become an issue on high-speed internal company networks.
My thinking is that there are two solutions. The first is a rigorous flushing setup
that guarantees the first page is finished before the second one begins. It would
probably slow down the whole php session system. The second solution revolves around
removing the ambiguity between a session with no registered values and a session file
that has yet to be written - both are 0 length. Session files that are yet to be
written will always be 0 length, so maybe the answer is to put some content into the
session file for a session with no registered variables, maybe just 2 bytes of content
"!!", which could never occur in a real session file, would allow the session_start to
differentiate between these two situations. If session_start sees a 0 length file, it
sleeps and checks again a few times before giving up. If session_start sees !!, it
knows there are no registered variables and it keeps on going.
I've also tested the behavior with the PHP4 MySQL Session Handler, Version 1.00, by
Ying Zhang. I was surprised that the behavior is worse, failing almost 100% of the
time - and no amount of usleep seems to help in the least.
I really am sorry that this posting is so long, but this is a very sensitive behavior
that is difficult to reproduce, and may be entirely fine on your systems. I am
certain that you can see how this behavior could occur, even if you are not able to
reproduce it.
I will be happy to assist in any way that I can. I think PHP is awesome and hope to
help it grow by fortifying it against this behavior.
Sincerely,
Bryan
--
Edit Bug report at: http://bugs.php.net/?id=10404&edit=1
--
PHP Development Mailing List <http://www.php.net/>
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
To contact the list administrators, e-mail: [EMAIL PROTECTED]
