Second instance of script runs the exact same code as the first one

[crankyslap]

Whenever I run a script twice at the same time, it's as if the second instance simply outputs what the first did. The second instance also does not detect any files the first one made etc.

First instance started at 14:37:59 outputs:

Started at: 2012-04-12 14:37:59 
OK

Second instance started at 14:38:03 outputs:

Started at: 2012-04-12 14:37:59 
OK

What gives?

<?php
function Weblog_debug($input)
{
    echo $input."<br/>";
}
$curtime = time();
$startedat = date('Y-m-d',$curtime) . "\t" . date('H:i:s', $curtime) .  "\t";
Weblog_debug("Started at: $startedat");

$timediff = time() - $curtime;
while($timediff < 5)
{
    $timediff = time() - $curtime;
}

Weblog_debug("OK");
?>

[pritaeas]

I think your browser shows you the previously cached page.

[crankyslap]

I wish. The reason I found this out, is because I'm trying to run a script that uses lock-files, as I said;

The second instance also does not detect any files the first one made etc.

This essentially breaks the script altogether.

If instance #1 of the script makes the lock file, and instance #2 doesn't recognize it, they will both end up writing to the same file.

I also tried running the script on 2 other webhosts using different software (apache2/lighttpd) and it happens on all of them.

Edit:

Also, as you can see the while loop takes ~5 seconds. If I start script instance #2 while #1 is ~3 seconds in, they both finish at the same time... it's really as if #2 just tags along with #1. Highly strange!

Full script:

<?php
function Weblog_debug($input)
{
    echo $input."<br/>";
}
function Weblog($directory, $logfile, $message)
{
    // Created 15 september 2010: Mirco Babin
    $curtime = time();

    $startedat = date('Y-m-d',$curtime) . "\t" . date('H:i:s', $curtime) .  "\t";
    Weblog_debug("Started at: $startedat");

    $logfile = date('Ymd',$curtime) . $logfile;

    //Set directory correctly
    if (!isset($directory) || $directory === false)
    $directory = './';
    if (substr($directory,-1) !== '/')
    $directory = $directory . '/';

    $count = 1;
    while(1)
    {
        //*dir*/*file*.*count*
        $logfilename = $directory . $logfile . '.' . $count;

        //*dir*/*file*.*count*.lock
        $lockfile = $logfilename . '.wlock';
        $lockhandle = false;
        Weblog_debug("Checking if $lockfile exists");
        if (!file_exists($lockfile))
        {
            $lockhandle = @fopen($lockfile, 'xb'); //lock handle true if lock file opened
            Weblog_debug("Got lock: $lockfile");
        }
        if ($lockhandle !== false) break; //break loop if we got lock

        $count++;
        if ($count > 100) return false;
    }

    //log file exists, append
    if (file_exists($logfilename))
    {
        Weblog_debug("log file exists, append");
        $created   = false;
        $loghandle = @fopen($logfilename, 'ab');
    }
    //log file not exists, make new
    else
    {
        Weblog_debug("log file not exists, make new");
        $loghandle = @fopen($logfilename, 'xb');
        if ($loghandle !== false) //Did we make it?
        {
            $created = true;

            $str = '#version: 1.0' . "\r\n" .
            '#Fields: date time c-ip x-msg' . "\r\n";
            fwrite($loghandle,$str);
        }
    }

    //was log file either appended to or create anew?
    if ($loghandle !== false)
    {
        Weblog_debug("log file was either appended to or create anew");
        $str = date('Y-m-d',$curtime) . "\t" . 
        date('H:i:s', $curtime) .  "\t" .
        (isset($_SERVER['REMOTE_ADDR']) ? $_SERVER['REMOTE_ADDR'] : '-') . "\t" .
        '"' . str_replace('"', '""', $message) . '"' . "\r\n";
        fwrite($loghandle,$str);

        Weblog_debug("Wrote: $str");

        fclose($loghandle);
        //Only chmod if new file
        if ($created) chmod($logfilename,0644); // Read and write for owner, read for everybody else

        $result = true;
    }
    else
    {
        Weblog_debug("log file was not appended to or create anew");
        $result = false;
    }

    /**
    Sleep & disable unlinking of lock file, both for testing purposes.
    */
    //Sleep for 10sec to allow other instance(s) of script to run while this one still in progress.
    sleep(10);
    //fclose($lockhandle);
    //@unlink($lockfile);

    return $result;
}

echo Weblog("weblog", "test.txt", "testmsg");
?>

First instance started at 11:21:00 outputs:

Started at: 2012-04-12 11:21:00 
Checking if weblog/20120412test.txt.1.wlock exists
Got lock: weblog/20120412test.txt.1.wlock
log file not exists, make new
log file was either appended to or create anew
Wrote: 2012-04-12 11:21:00 xx.xx.xx.xxx "testmsg" 
1

Second instance started at 11:21:03 outputs:

Started at: 2012-04-12 11:21:00 
Checking if weblog/20120412test.txt.1.wlock exists
Got lock: weblog/20120412test.txt.1.wlock
log file not exists, make new
log file was either appended to or create anew
Wrote: 2012-04-12 11:21:00 xx.xx.xx.xxx "testmsg" 
1

[pritaeas]

Have your tried to use flock after fopen?

[crankyslap]

It was a problem with Opera... for some reason it syncs up two identical pages.

Couple of hours down the drain, nice. Thanks, though!