CODEWITHSUNDEEP
phpfilefopen
Darryl Severn
Darryl Severn

Reputation: 68

PHP fopen can't open file but still writes to it

This is driving me crazy. I have a standard routine to write log files that has worked so well that I have almost forgotten what was in the code. Transferred it into a new project, made one change and it is behaving really weirdly. The error messages say that fopen() is failing to open the log file, however the entries are still being written in the log file. I don't like having errors or warnings of any description so I do not intend to ignore this error just because it appears to be working despite the error.

The change I made was in the way $_SESSION['base_dir_prefix'] was set. In previous projects, that had been set in the context of the home page, and set to the absolute path to that directory. This had a weakness where you couldn't go straight to a page without going through index.php. I couldn't do that in this project, so I set it to a relative path - e.g. $_SESSION['base_dir_prefix'] = "../" ; As far as I can see, the prefix is set correctly. In fact, as far as I can see, everything is set correctly, but there is obviously a needle in there somewhere that will need another pair of eyes to see!

One of my biggest questions is, if fopen() is failing to open the file, then why is is being written to?

Exhibit 1 - source code of the actual writelog function. Note that the echo statements are purely for debug purposes and are not part of normal execution.

function writelog($str=" ")
{
    if (isset($_SESSION['base_dir_prefix']))
    {
        $prepend = $_SESSION['base_dir_prefix'] ;
    }
    else
    {
        $prepend = $_SERVER['DOCUMENT_ROOT'] ;
    }

    if ( substr($prepend, -1, 1) <>  DIRECTORY_SEPARATOR )
    {
        $prepend .= DIRECTORY_SEPARATOR ;
    }
    $fname = $prepend."log/log.txt" ;
    $mode = "a" ;

    echo getcwd(). "\n" ;           // debug code
    echo $fname." Files exists?:".file_exists($fname) ."\n";
    echo $str."\n" ;

    $fp = fopen($fname, $mode) ;

    fwrite( $fp, date("Y-m-d H:i:s").": " ) ;
    fwrite( $fp, $str."\n" ) ;
    fclose( $fp ) ;
}

Exhibit 2 - the code that calls the function

    $u->writelog ("SA OLU entering Option List Users function") ;
    $u->writelog ("Current dir:".getcwd()." ") ;

    $usr_list = array(array( "None", "None") ); 
    $sc->user_list($usr_list) ; 
    $i = 0 ; 
    $res = "" ;
    $actv_flag = strtoupper($active) ;

    if ($usr_list[0][0] != "None" ) 
    { 
        while ($i < count($usr_list)) 
        {
            if ((bool)$usr_list[$i][2] == true && $actv_flag == "YES")   //only active users
            {
                $i++ ;
                continue ;
            }
            $res .= sprintf( "<option value=\"%s\"> %s (%s) </option> \n", 
                             $usr_list[$i][0], 
                             $usr_list[$i][1], 
                             $usr_list[$i][0]
                           ); 
            $i++ ; 
        } 
     } else 
     { 
            $res = sprintf( "<option value=\"no_recs\"> No Program Records </option> \n" ) ; 
     }
     $u->writelog ("SA OLU leaving Option List Users function") ;

Exhibit 3 - the log file itself. Entries created by exhibit 1. Note that the timestamp on this file is 1 hour later than actual time. Not sure why and since I am the only person who looks at this file, I have not been overly concerned.

2014-11-21 16:29:58: SA OLU entering Option List Users function
2014-11-21 16:29:58: Current dir:/srv/www/dev/gillies/security
2014-11-21 16:29:58: SA OLU leaving Option List Users function
2014-11-21 16:29:58: SA OLU entering Option List Users function
2014-11-21 16:29:58: Current dir:/srv/www/dev/gillies/security
2014-11-21 16:29:58: SA OLU leaving Option List Users function
2014-11-21 16:29:58: SA OLU entering Option List Users function
2014-11-21 16:29:58: Current dir:/srv/www/dev/gillies/security
2014-11-21 16:29:58: SA OLU leaving Option List Users function

Exhibit 4 - the Apache error log file

[Fri Nov 21 15:29:25.047732 2014] [:error] [pid 20588] [client 192.168.0.19:62116] PHP Warning:  fwrite() expects parameter 1 to be resource, boolean given in /srv/www/dev/gillies/php/utilities.php on line 72
[Fri Nov 21 15:29:25.047746 2014] [:error] [pid 20588] [client 192.168.0.19:62116] PHP Warning:  fclose() expects parameter 1 to be resource, boolean given in /srv/www/dev/gillies/php/utilities.php on line 73
[Fri Nov 21 15:29:58.721627 2014] [:error] [pid 17084] [client 192.168.0.19:62141] PHP Warning:  fopen(../log/log.txt): failed to open stream: No such file or directory in /srv/www/dev/gillies/php/utilities.php on line 69
[Fri Nov 21 15:29:58.721698 2014] [:error] [pid 17084] [client 192.168.0.19:62141] PHP Warning:  fwrite() expects parameter 1 to be resource, boolean given in /srv/www/dev/gillies/php/utilities.php on line 71
[Fri Nov 21 15:29:58.721711 2014] [:error] [pid 17084] [client 192.168.0.19:62141] PHP Warning:  fwrite() expects parameter 1 to be resource, boolean given in /srv/www/dev/gillies/php/utilities.php on line 72
[Fri Nov 21 15:29:58.721720 2014] [:error] [pid 17084] [client 192.168.0.19:62141] PHP Warning:  fclose() expects parameter 1 to be resource, boolean given in /srv/www/dev/gillies/php/utilities.php on line 73

Exhibit 5 - a snippet of the generated html code showing the results of the echo. Entries created by Exhibit 2. Again this is only for diagnostic purposes and is not part of the production file.

                    </h4><select name="users" size="5">
                      /srv/www/dev/gillies/security
../log/log.txt Files exists?:1
SA OLU entering Option List Users function
/srv/www/dev/gillies/security
../log/log.txt Files exists?:1
Current dir:/srv/www/dev/gillies/security 
/srv/www/dev/gillies/security
../log/log.txt Files exists?:1
SA OLU leaving Option List Users function
        <option value="loginid"> name (loginid) </option>

Exhibit 6 - the directory structure for the log file

darryl@thedoctor:/srv/www/dev/gillies/log$ pwd
/srv/www/dev/gillies/log
darryl@thedoctor:/srv/www/dev/gillies/log$ ls -l
total 8
-rw-rw-rw- 1 www-data www-data 4743 Nov 21 15:33 log.txt

Any clues anyone? Thanks.

Upvotes: 3

Views: 1354

Answers (1)

Darryl Severn
Darryl Severn

Reputation: 68

I have found the answer and it was in the relative path supplied to fopen(). I rewrote the code to create a prefix that was absolute rather than relative and all the errors went away. I needed to do some string manipulation to get the right directory, and the new code now looks like this:

$here = getcwd() ;
$posn = strrpos($here, "/") ;
if($posn === false) {
    $_SESSION['base_dir_prefix'] = "../" ;
}
else {
    $_SESSION['base_dir_prefix'] = substr($here, 0, $posn) ;
}

Thanks for the ideas, Darren. I was going around in circles trying to work out what else to try.

The new code gets the absolute path of the directory which is at the second level in the hierarchy, and trims the path back one level so that it points to the document root.

For those who may be wondering why all this trouble to get the directory, this makes the code fully relocatable. There is no guarantee that the document root will be at the same level relative to the web server document root as the website moves through development, testing, acceptance, and production phases. This allows the website to be put anywhere within the directory hierarchy without having to change references to files etc.

Upvotes: 1

Related Questions