Not logged in. · Lost password · Register
Forum: General Help and Support General Stuff RSS
Dokuwiki attempting to allocate 8000 petabytes of ram in init.php
Not all the time, just occassionally
Avatar
TheGarnet #1
User title: TheGarnet
Member for 2 weeks · 6 posts
Group memberships: Members
Show profile · Link to this post
Subject: Dokuwiki attempting to allocate 8000 petabytes of ram in init.php
Dokuwiki occasionally trying to allocate 8000 petabytes of ram

Randomly on going to the home page of my wiki, I get error in red,

DokuWiki Setup Error

The datadir ('pages') at ./data/pages is not found, isn't accessible or writable. You should check your config and permission settings. Or maybe you want to run the installer?

I had been using the wiki all day, and for several days, entering dozens of pages, hundreds of edits.  I already went through all the webhosting to enter in password protected directories into plesk settings, and setting all the windows sharing permissions for the IIS website account.  I normally get none of the security or permission warnings when doing configuration changes, installing plugins, or installing templates.

When I hit refresh, then the wiki displays ok.

Or sometimes I will get an error 500. Or sometimes just the page HTML displays, apparently missing all the CSS, javascript, etc.  
I see this in my php_error.log:
[10-Jun-2019 04:32:03 UTC] PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 8241982478306532552 bytes) in C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\init.php on line 605

Always that same huge number number.

After several refreshes, then it seems like everything is ok. But sometimes when editing, I noticed the editor buttons are missing, or I notice that javascript helpers for things like indenting an outline when I hit space don’t seem to be happening (probably the javascript helpers didn’t get loaded?)

Two of the other Dokuwiki that I setup, have similar error occurring in their logs:
2019/6/9 - lots of problems with 500 error during skepticon conference editing: php_error.log  [09-Jun-2019 17:22:59 UTC] PHP Fatal error:  Allowed memory size of 134217728 bytes exhausted (tried to allocate 7811895298027379920 bytes) in C:\Inetpub\vhosts\domain.com\sub.domain2.com\inc\init.php on line 605

The get a different, but always the same, huge number in that sites error log.

Sometimes after a couple of refreshes, the site displays normally (other than occasionally problem with editor I described). Site seems to be mostly ok, unless I don’t interact with it for a while.

I tried boosting PHP setting memory_limit from 128M to 512M, but that didn’t seem to help this problem, as the ram allocation attempt is a few orders of magnitude higher than either of these numbers.

Plesk Onyx Virtual Windows Server 17.8.11
Windows Server 2016 Datacenter
4GB of ram (546MB available)
PHP 7.2.19
Dokuwiki - Greebo -   (or I think I might have taken a 2019 development snapshot, not sure) snapshot update 51
Template: arctic
Avatar
TheGarnet #2
User title: TheGarnet
Member for 2 weeks · 6 posts
Group memberships: Members
Show profile · Link to this post
I did a register_shutdown_function right before init.php 605, and it found something else to catch:


Array
(
    [type] => 8
    [message] => Undefined index: __background_alt__
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\Manifest.php
    [line] => 40
)

It catches this a lot of times for each wiki page. Maybe this has to do with arctic theme?  No, switched to the dokuwiki theme, and still see this a lot.

Seeing other things being caught.... I refresh one of my wiki pages, then I see a whole series of a certain error being caught many times. Then 10 or 20 minutes later, I will see a whole series of some new problem caught over and over....  Here are some examples:

[10-Jun-2019 12:52:24 UTC] shutDownFunction: Array
(
    [type] => 2
    [message] => filemtime(): stat failed for C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\exe/../../conf/local.protected.php
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\cache.php
    [line] => 84
)

Repeated 23 times. The file referenced does not exist

Next refresh of same page gave this a bunch of times repeatedly:

[10-Jun-2019 12:48:04 UTC] shutDownFunction: Array
(
    [type] => 2
    [message] => filemtime(): stat failed for C:/Inetpub/vhosts/thegarnet.net/httpdocs/data/cache/sessionpurge
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\plugins\auth.php
    [line] => 436
)

file did not seem to exist

Also am noticing a small graphic I put in the sidebar comes up as broken image about half the time I refresh the page.
This post was edited 2 times, last on 2019-06-10, 18:06 by TheGarnet.
Avatar
Michaelsy #3
Member since Jun 2015 · 940 posts · Location: Düsseldorf, Germany
Group memberships: Members
Show profile · Link to this post
BTW: You should surround your printout with the <code>...</code> tag:

Array
(
    [type] => 8
    [message] => Undefined index: __background_alt__
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\Manifest.php
    [line] => 40
)
By Patreon.com a few eurons can be fed into the code phasers of
the DokuWiki engine. Besides, Andi's posts are worth reading.
Avatar
TheGarnet #4
User title: TheGarnet
Member for 2 weeks · 6 posts
Group memberships: Members
Show profile · Link to this post
In init.php, realpath(),

     print_r($newpath, true)

is blowing up just before

$finalpath = $root.implode('/',$newpath);

[10-Jun-2019 16:24:37 UTC] PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 2264098279424 bytes) in C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\init.php on line (of the print_r)

I am trying to filter out the spurious errors from elsewhere that I mentioned above, but came across this one that seemed interesting. Why is indexer.php trying to open a tmp file with a * in the name????

[10-Jun-2019 16:50:34 UTC] shutDownFunction(d): Array
(
    [type] => 2
    [message] => fopen(C:/Inetpub/vhosts/thegarnet.net/httpdocs/data/index/i5*2.tmp): failed to open stream: Operation not permitted
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\indexer.php
    [line] => 1096
)

Repeatedly refreshing the same short page in the wiki, just got me a rare 500 internal server error page.  Of course nothing shows up in the php_error.log for this....  in the directory domain\logs\iis\W3SVC14 I have a 9MB u_extend14.log started 3 hours ago.

2019-06-10 16:50:33 74.208.247.98 GET /doku.php id=archive:old_websites:start 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:garnetchaney.com:start&do=admin&page=config www.thegarnet.net 200 0 0 26353 953 892

2019-06-10 16:50:33 74.208.247.98 GET /lib/exe/fetch.php media=wiki:spider.256.jpg 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 500 0 3221225477 13116 886 836

2019-06-10 16:50:35 74.208.247.98 GET /lib/exe/taskrunner.php id=archive%3Aold_websites%3Astart&1560185433 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 0 367 809 1149

2019-06-10 16:50:35 74.208.247.98 GET /lib/exe/css.php t=dokuwiki&tseed=24dc6c145d52ed0ddff8e7552d274c93 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 0 171475 786 1153

2019-06-10 16:50:35 74.208.247.98 GET /lib/tpl/dokuwiki/images/favicon.ico - 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 0 7707 820 62

2019-06-10 16:50:35 74.208.247.98 GET /lib/exe/manifest.php - 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 500 0 3221225477 13116 386 384

-----

2019-06-10 16:56:47 74.208.247.98 GET /doku.php id=archive:old_websites:start 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:garnetchaney.com:start&do=admin&page=config www.thegarnet.net 200 0 0 26369 953 1121

2019-06-10 16:56:47 74.208.247.98 GET /lib/exe/fetch.php media=wiki:spider.256.jpg 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 0 9539 785 265

2019-06-10 16:56:47 74.208.247.98 GET /lib/exe/taskrunner.php id=archive%3Aold_websites%3Astart&1560185807 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 500 0 3221225477 13116 809 888

2019-06-10 16:56:47 74.208.247.98 GET /lib/tpl/dokuwiki/images/favicon.ico - 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 0 7707 820 80

2019-06-10 16:56:49 74.208.247.98 GET /lib/exe/manifest.php - 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 0 858 386 219

-----

2019-06-10 16:57:08 74.208.247.98 GET /doku.php id=archive:old_websites:start 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:garnetchaney.com:start&do=admin&page=config www.thegarnet.net 200 0 0 26369 953 706

2019-06-10 16:57:08 74.208.247.98 GET /lib/exe/fetch.php media=wiki:spider.256.jpg 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 304 0 0 396 886 348

2019-06-10 16:57:10 74.208.247.98 GET /lib/exe/taskrunner.php id=archive%3Aold_websites%3Astart&1560185828 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:start www.thegarnet.net 200 0 64 0 809 2456

-----

2019-06-10 16:57:11 74.208.247.98 GET /doku.php id=archive:old_websites:start 443 - 98.248.142.26 HTTP/2.0 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_14_4)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/74.0.3729.169+Safari/537.36 https://www.thegarnet.net/doku.php?id=archive:old_websites:garnetchaney.com:start&do=admin&page=config www.thegarnet.net 500 0 3221225477 13116 953 404

It looks like there is about a random 20% chance of dieing with 500 server error any of the 4 or 5 requests of the server to browse a single page.  It seems like each of the scripts involved has died in one request or another.
This post was edited 2 times, last on 2019-06-10, 19:12 by TheGarnet.
Avatar
TheGarnet #5
User title: TheGarnet
Member for 2 weeks · 6 posts
Group memberships: Members
Show profile · Link to this post
So just trying to do count($newpath) is sometimes blowing things up....

[10-Jun-2019 17:27:11 UTC] PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 8241982478306532552 bytes) in C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\init.php on line 642
[10-Jun-2019 17:27:11 UTC] shutDownFunction(a): root:C:/
[10-Jun-2019 17:27:12 UTC] PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 8241982478306532528 bytes) in C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\init.php on line 560

Notice that error_log message shutdown(b) is never shown, it results in the exhaustion on line 560.
 
Here is the shutdown function I added to init.php

// Some global copies so we can see what is going on when implode fails
$debug_root = '';
$debug_newpath = '';
$debug_doing_implode = 0;

function shutDownFunction() {
   $error = error_get_last();

   global $debug_root, $debug_newpath,$debug_doing_implode;
   if ($debug_doing_implode)
   {
     error_log('shutDownFunction(a): root:'.print_r($debug_root,true),0);
     error_log('shutDownFunction(b): newpath length:'.count($debug_newpath),0);
     error_log('shutDownFunction(c): newpath:'.print_r($debug_newpath,true),0);
   }

   // Filter some stuff we dont want to be bothered with
   if (($error['line'] == 40) || ($error['line'] == 329) || ($error['line'] == 436) || ($error['line'] == 84)
      || ($error['line'] == 1096) || ($error['line'] == 106)) {}
   else  {
   error_log('shutDownFunction(d1): type='.$error['type']);
   error_log('shutDownFunction(d2): file='.$error['file']);
   error_log('shutDownFunction(d3): line='.$error['line']);
   error_log('shutDownFunction(d4): message='.$error['message']);
   error_log('shutDownFunction(d5): '.print_r($error,true) ,0); }

}


in fullpath(), at line 642, implode, wrapped this around it:


    register_shutdown_function('shutDownFunction');

    try { // This doesnt catch fatal out of memory error!
    global $debug_root, $debug_newpath,$debug_doing_implode;
    $debug_root = $root;
    $debug_newpath = $newpath;
    $debug_doing_implode = 1;

    // The original statement
    $finalpath = $root.implode('/', $newpath);

    $debug_doing_implode = 0;

    } catch (Exception $e) {
      error_log('init.php(605) failed'.$e->getMessage() ,0);
    }
This post was edited on 2019-06-10, 19:50 by TheGarnet.
Avatar
TheGarnet #6
User title: TheGarnet
Member for 2 weeks · 6 posts
Group memberships: Members
Show profile · Link to this post
Switching from PHP 7.2.19 to 7.1.30 seems to have cured the random http 500 errors. 

The shutDownFunction is still getting called repeatedly for all kinds of other errors, just for one browser refresh:  (the mess in the log was bigger than what can go in one message here!)

(Repeated 13 times)
[10-Jun-2019 19:20:02 UTC] shutDownFunction(e1): skipping file=C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\plugins\discussion\action.php line=329 message=Undefined index: comment

(Repeated 22 times)
[10-Jun-2019 19:20:03 UTC] shutDownFunction(e1): skipping file=C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\plugins\auth.php line=436 message=filemtime(): stat failed for C:/Inetpub/vhosts/thegarnet.net/httpdocs/data/cache/sessionpurge

(Repeated 23 times)
[10-Jun-2019 19:20:03 UTC] shutDownFunction(e1): skipping file=C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\cache.php line=84 message=filemtime(): stat failed for C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\exe/../../conf/local.protected.php

(Repeated 46 times)
[10-Jun-2019 19:20:03 UTC] shutDownFunction(e1): skipping file=C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\cache.php line=84 message=filemtime(): stat failed for C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\exe/../../lib/plugins/wrap/speech.less

(Repeated 23 times)
[10-Jun-2019 19:20:03 UTC] shutDownFunction(e1): skipping file=C:\Inetpub\vhosts\thegarnet.net\httpdocs\lib\plugins\popularity\helper.php line=106 message=filemtime(): stat failed for C:/Inetpub/vhosts/thegarnet.net/httpdocs/data/cache/lastSubmitTime.txt

(Repeated 23 times)
[10-Jun-2019 19:20:04 UTC] shutDownFunction(e1): skipping file=C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\Manifest.php line=40 message=Undefined index: __background_alt__

Interesting the occurrence of the number 23......

Here is some other random stuff rolling by, due to URLs from mj12bot.com


(
    [type] => 8
    [message] => Undefined offset: 1
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\parser\xhtml.php
    [line] => 913
)

(
    [type] => 8
    [message] => Undefined offset: 3
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\form.php
    [line] => 1083
)

(
    [type] => 8
    [message] => Undefined index: conf
    [file] => C:\Inetpub\vhosts\thegarnet.net\httpdocs\inc\StyleUtils.php
    [line] => 37
)
This post was edited 3 times, last on 2019-06-10, 21:39 by TheGarnet.
Avatar
turnermm (Moderator) #7
Member since Oct 2009 · 4646 posts · Location: Canada
Group memberships: Global Moderators, Members, Super Mods
Show profile · Link to this post
While you are tying yourself into knots trying to solve this, have you considered the possibility that there is a misconfiguration in the server?  It's beyond belief that php is trying to allocate billions of gigabytes.
Myron Turner
github: https://github.com/turnermm
plugins, templates: http://www.mturner.org/devel
This post was edited on 2019-06-10, 22:00 by turnermm.
Avatar
TheGarnet #8
User title: TheGarnet
Member for 2 weeks · 6 posts
Group memberships: Members
Show profile · Link to this post
Quote by turnermm on 2019-06-10, 21:48:
While you are tying yourself into knots trying to solve this, have you considered the possibility that there is a misconfiguration in the server?  It's beyond belief that php is trying to allocate billions of gigabytes.

Switching from PHP 7.2.19 to 7.1.30 seems to have cured the random http 500 errors. 

Yeah, I am a little embarrassed I spent so much time going down that rabbit hole, when it was easy enough to go to Plesk control panel and change the version of PHP used.... But, when you are dealing with an intermittent problem (didn't see this at all during several days of testing and loading content, then one day while trying to show things to a potential investor, things started failing right and left), you kinda want to get to the bottom and have a better idea where things are going wrong.

By the way, the 23 ocurrences of errors was my fault for registering the shutdown handler inside the routine. Move that registration outside of the routine to the global level.
Close Smaller – Larger + Reply to this post:
Verification code: VeriCode Please enter the word from the image into the text field below. (Type the letters only, lower case is okay.)
Smileys: :-) ;-) :-D :-p :blush: :cool: :rolleyes: :huh: :-/ <_< :-( :'( :#: :scared: 8-( :nuts: :-O
Special characters:
Go to forum
Imprint
This board is powered by the Unclassified NewsBoard software, 20150713-dev, © 2003-2015 by Yves Goergen
Current time: 2019-06-25, 22:12:02 (UTC +02:00)