none
Strange error messages in PHP log on azure website RRS feed

  • Question

  • Hi,

    I have a PHP website (SMF Forum) that runs for more than a year now (not in one run,  but I never experienced this error before). After complaints about time-outs, blank pages and other odd behavior I found this in the log files:

    lots of error messages like this one:

    PHP Fatal error:  Failure in Wincache[4280] free_memory: Block 0x3c1827c not in use

    And this one:

    PHP Fatal error:  WINCACHE: lock_readlock: acquired abandoned mutex Global\FILELIST_CACHE_5.4_1.3.7.4_1_0_850133_X. Something bad happend in another process! in Unknown on line 0

    Stopping/starting the website did solve the problem but I am curious what could cause this and if there is something I can do to prevent this.

    Best regards,

    Arthur

    Friday, May 1, 2015 8:42 AM

Answers

  • In WinCache 1.3.7.4, I improved the diagnostics & tracing surrounding issues which previously led to memory corruptions in the shared memory segments of the WinCache caches (File, Session, User, Opcode).  Further, I improved detection and avoidance of AVs in this same area.  The trace messageyou're seeing,  "free_memory: Block <N> not in use", is proof that WinCache detected a corruption (it was attempting to free a shared memory block that wasn't in use), and avoided further corruption (it didn't try to free the not-free memory block, which would have led to even greater corruption).

    The second message, "lock_readlock: acquired abandoned mutex..." indicates that another php-cgi.exe process crashed while holding a mutex that WinCache uses.  In this case, it's the lock for the File cache.

    To diagnose, look at the line of PHP code mentioned in the "free_memory: Block <N> not in use" message.  If one of the following functions is on that line, there is a work around:

    ◦ file_exists 
    ◦ file_get_contents 
    ◦ readfile 
    ◦ is_readable 
    ◦ is_writable 
    ◦ is_dir 
    ◦ realpath 
    ◦ filesize

    If it's one of these functions, then I would recommend setting wincache.reroute_enabled=0 in your .user.ini.

    Thx!

        --E.

    Friday, May 1, 2015 3:39 PM

All replies

  • In WinCache 1.3.7.4, I improved the diagnostics & tracing surrounding issues which previously led to memory corruptions in the shared memory segments of the WinCache caches (File, Session, User, Opcode).  Further, I improved detection and avoidance of AVs in this same area.  The trace messageyou're seeing,  "free_memory: Block <N> not in use", is proof that WinCache detected a corruption (it was attempting to free a shared memory block that wasn't in use), and avoided further corruption (it didn't try to free the not-free memory block, which would have led to even greater corruption).

    The second message, "lock_readlock: acquired abandoned mutex..." indicates that another php-cgi.exe process crashed while holding a mutex that WinCache uses.  In this case, it's the lock for the File cache.

    To diagnose, look at the line of PHP code mentioned in the "free_memory: Block <N> not in use" message.  If one of the following functions is on that line, there is a work around:

    ◦ file_exists 
    ◦ file_get_contents 
    ◦ readfile 
    ◦ is_readable 
    ◦ is_writable 
    ◦ is_dir 
    ◦ realpath 
    ◦ filesize

    If it's one of these functions, then I would recommend setting wincache.reroute_enabled=0 in your .user.ini.

    Thx!

        --E.

    Friday, May 1, 2015 3:39 PM
  • It is indeed a file_exists statement, so I entered wincache.reroute_enabled=0 in .user.ini

    What does it actually do?

    Arthur

    Saturday, May 2, 2015 8:47 AM
  • I also get this error now:

    PHP Fatal error:  Failure in PHP_MINIT_FUNCTION(Wincache): 403 in Unknown on line 0


    Sunday, May 3, 2015 9:11 AM
  • What does it actually do?


    In WinCache 1.3.7.4, I added the ability to reroute certain PHP functions to use the WinCache file cache, which then avoids hitting the disk.  This yields a measurable performance improvement for some PHP frameworks that, uh, shall we say, are a bit "abusive" of the file system.   

    Thx!

    --E.

    Sunday, May 3, 2015 10:55 PM
  • I also get this error now:

    PHP Fatal error:  Failure in PHP_MINIT_FUNCTION(Wincache): 403 in Unknown on line 0


    403 is FATAL_APLIST_OCACHE_INIT_EVENT, an error that indicates there was a problem creating the cross-process shared memory cache for the opcode cache.  The specific error indicates that another process was holding the initialization lock that WinCache uses to synchronize the creation of the opcode cache.  It can happen if one php-cgi.exe is taking a long time to initialize, or if the machine is heavily loaded and WinCache is taking longer than 20 seconds to perform startup & initialization code.

    Normally restarting the site will fix this problem.  If that doesn't do it, then you may need to scale up to a larger worker or add more dedicated workers.

    You should also review the PHP Error log for other application errors, or anything that indicates that IIS is forcibly terminating your php-cgi.exe's.  That would indicate an application error, and could leave WinCache in a bad state.

    The good news is that if WinCache fails to initialize, your PHP script(s) will still run, just without the benefit of WinCache.

    If you're not tied to PHP 5.4 (which, I'm guessing you're on PHP 5.4 if you get this error message), you might try moving up to PHP 5.5 or PHP 5.6, if your application supports it.  In PHP 5.5 and later, Azure Web Services uses the Zend Opcache for opcode caching.

    Thx!

        --E.

    Sunday, May 3, 2015 11:10 PM
  • I thought that the autoscale option would automatically add instances when it ran out of mem, but I am not sure if that happens. I scaled to a larger instance size for Azure Websites, maybe that helps. I noticed a large amount of FastCGI errors (timeouts when loading), so maybe the system was running out of memory, so it could very well be possible that the problem is a lack of memory.

    Thanks for your help,

    Arthur

    Monday, May 4, 2015 7:37 AM