dwp-forge / refnotes

4 stars 6 forks source link

Fatal error: Memory exhausted when caching #10

Closed dwp-forge closed 9 years ago

dwp-forge commented 9 years ago
What steps will reproduce the problem?
1. Add a new reference to the default refnotes database.
2. Add a reference from the database to a page.
3. Save the page.

What is the expected output? What do you see instead?
The page should save with the new reference.

Instead, I see the error: 
Allowed memory size of 67108864 bytes exhausted (tried to allocate 40 bytes) in 
/Users/xxx/Sites/Wiki/inc/cache.php on line 286

What version of the product are you using? On what operating system?
I am using refnotes-2009-10-11 on DokuWiki Release 2009-12-25c "Lemming" on 
Apache/2.0.63 (Unix) PHP/5.2.11 DAV/2, using Mac OS X 10.5.8.

Please provide any additional information below.
No other plugins or changes were made to the DokuWiki environment or to the Apache/PHP

server that I can recall. My DokuWiki didn't have this problem yesterday.

Original issue reported on code.google.com by jamesbondsv on 2010-03-08 05:30:58

dwp-forge commented 9 years ago
How big is your reference database (number of pages, notes per page)?

Is it any note from the database that causes the problem or a specific one?

If you move the offending note to a separate page, can you reproduce the problem?

Does it also crash when you preview the page in the editor?

Original issue reported on code.google.com by dwp-forge on 2010-03-08 07:21:42

dwp-forge commented 9 years ago
How big is your reference database (number of pages, notes per page)?
A: I have 29 notes stored in one page in four categories.

Is it any note from the database that causes the problem or a specific one?
A: No. All notes in the database will cause the problem. Also, inserting inline notes
will cause the problem: 
[(inline reference here)].

If you move the offending note to a separate page, can you reproduce the problem?
A: Yes. No matter where the note sits or in which page, the page will produce the error.

Does it also crash when you preview the page in the editor?
A: Yes, it occurs on a preview.

I gave up troubleshooting the problem after I submitted this bug report. The next day
(today), I tried again. I 
received a different error:

"Allowed memory size of 67108864 bytes exhausted (tried to allocate 46929 bytes) in

/Users/stevevance/Sites/MasterProjectWiki/inc/io.php on line 104"

However, this error appears only once and all subsequent errors are "Allowed memory
size of 67108864 bytes 
exhausted (tried to allocate 40 bytes) in 
/Users/xxx/Sites/Wiki/inc/cache.php on line 286"

Original issue reported on code.google.com by jamesbondsv on 2010-03-09 01:56:50

dwp-forge commented 9 years ago
Well, I switched to 5.2.11 and sure enough I still cannot reproduce the problem. That
would be too easy, right? ;)

I could also try to use your PHP config but I seriously doubt that PHP setup is the
source of the problem. It's got to be something stupid in my code. But just in case,
could you try to change memory_limit in your PHP config to, say, 128M to see if I can
eat all the memory you throw at me.

> Also, inserting inline notes will cause the problem

I don't know if you are handy with SVN but if you are, you could try the latest code.
I recently fixed a couple of problems in handling of predefined notes (both inline
and database references are internally handled very similarly). But those problems
were related to predefined references in the lists. Which gets us to the next questions:

What else is on the page that *uses* the predefined note?

If you make a page that contains only "Test[(todo)]." does it trigger the problem?

> I gave up troubleshooting the problem after I submitted this bug report.

I'm not sure how much time you are willing to invest into this, but if you *really*
want to get it fixed, I could come up with some hacks that potentially could help to
localize the problem. It seems that we have quite inconvenient time zone difference
but maybe over the weekend I could do some remote debugging with your assistance.

Original issue reported on code.google.com by dwp-forge on 2010-03-09 19:13:03

dwp-forge commented 9 years ago
I changed my memory size to 128M. No change, same error.

I've tried SVN in the past and I'm still confused about how it works. However, I'm
willing to give a shot to the 
latest code. 

If you make a page that contains only "Test[(todo)]." does it trigger the problem?
A: Yes, that triggers the problem.

I really want to get this fixed because my masters project is in my DokuWiki and I
need references. For now, 
I've just been using my DokuWiki with RefNotes disabled (but still inputting the syntax
where references are 
needed).

I am willing to assist you.

Original issue reported on code.google.com by jamesbondsv on 2010-03-10 00:58:12

dwp-forge commented 9 years ago
How do I access the latest code?

Original issue reported on code.google.com by jamesbondsv on 2010-03-10 01:00:29

dwp-forge commented 9 years ago
In absence of local SVN installation you can use source browser on the top of this
page. Go to svn/trunk/refnotes/syntax [1], open references.php file and save it using
"View raw file" link on the right [2].

[1] http://code.google.com/p/dwp-forge/source/browse/trunk/refnotes/syntax/
[2] http://dwp-forge.googlecode.com/svn/trunk/refnotes/syntax/references.php

Original issue reported on code.google.com by dwp-forge on 2010-03-10 07:24:31

dwp-forge commented 9 years ago
Do you also have problems with named notes? For example:

Test[(name>test)].

Original issue reported on code.google.com by dwp-forge on 2010-03-10 07:32:39

dwp-forge commented 9 years ago
Do you also have problems with named notes?
A: Yes, the same problem occurs. However, before the cache.php error occurred, an error
in io.php occurred:
"Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 49423
bytes) in 
/Users/stevevance/Sites/MasterProjectWiki/inc/io.php on line 104"

Original issue reported on code.google.com by jamesbondsv on 2010-03-10 07:46:28

dwp-forge commented 9 years ago
I installed the references.php from Feb 21, 2010. The problem with both cache.php and
io.php (same lines) still 
occurs.

Interestingly, it seems to alternate between cache.php and io.php, but the error in
cache.php seems to occur 
more often.

Original issue reported on code.google.com by jamesbondsv on 2010-03-10 07:51:47

dwp-forge commented 9 years ago
Getting warmer. What about disabling reference database on the configuration page?
Does the problem go away?

Original issue reported on code.google.com by dwp-forge on 2010-03-10 07:52:52

dwp-forge commented 9 years ago
What about disabling reference database on the configuration page?
Does the problem go away?
A: Yes. Inline and inline named notes work when I disable the reference database.

Original issue reported on code.google.com by jamesbondsv on 2010-03-10 08:02:42

dwp-forge commented 9 years ago
I guess it's time to do some hacking. Enable the database back and then try to
comment out loading of the database pages at line 395 of references.php. Hopefully
it
should behave the same way as with disabled database.

If it does, revert the change and try to disable the page cache by always returning
false from isCached() at the line 749. I think the best way to do this is to comment
out the if statement. The assignment after the if should still be executed. Just in
case.

I would expect that the memory exhaustion will come back at this point, but it's
better to know for sure before we start to dig deeper.

BTW, I assume that you know a thing or two about programming, so I don't have to
explain what "comment out" means ;)

Original issue reported on code.google.com by dwp-forge on 2010-03-10 18:55:34

dwp-forge commented 9 years ago
I will try what you say. 
I do know what "comment out" means. I love PHP.
This website is my pride and joy: http://www.chicagobikes.org/bikeparking/advanced.php?
ward=2&commArea=&status=&sort=0

Original issue reported on code.google.com by jamesbondsv on 2010-03-11 01:01:33

dwp-forge commented 9 years ago
I commented out line 395 [$this->loadPages();] which had the same effect of disabling
the database (that is, 
references from the database were not loaded, but inline references still worked).

Commenting out the if statement on line 795 does not improve the situation. Like you
predicted, the memory 
exhaustion comes back.

Original issue reported on code.google.com by jamesbondsv on 2010-03-11 18:51:19

dwp-forge commented 9 years ago
I think we could speed the thing up a bit. Instead of guessing which code branch
triggers the error let's try to see at the point of error how did we get there. I
attached a little wrapper around debug_backtrace() function, which makes its output
a
bit more readable. Include it in doku.php and sprinkle some calls to it around places
where PHP usually runs out of memory.

Note that the function uses error_log(), so you better have your error_log file name
configured properly.

And, of course, I can't wait to see the log. I would expect it to be rather big but
with lots of repetitions. Please don't send all 10 megabytes of it, first 100
kilobytes should be sufficient ;)

Original issue reported on code.google.com by dwp-forge on 2010-03-11 19:36:54


dwp-forge commented 9 years ago
I don't think it's working.
I included the file you attached.
I enabled embedded PHP in the configuration.
I wrote <php>dbg_tracedump();</php> at the end of several pages with references. 
I verified the error_log points to the right file. I can also verify this by seeing
that the memory exhaustion errors 
are being written to the error_log.

Yet none of the entries in the error_log are different than the ones I've already posted.

Original issue reported on code.google.com by jamesbondsv on 2010-03-11 21:34:17

dwp-forge commented 9 years ago
This is odd.

I now see the dbg_tracedump() entries in the error_log coming from pages that DON'T
HAVE references from the 
database. The following only appears on pages with inline notes:

eval (/Users/stevevance/Sites/MasterProjectWiki/inc/parser/xhtml.php, 328)
Doku_Renderer_xhtml->php (, )
call_user_func_array (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php,
562)
p_render (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php, 152)
p_cached_output (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php, 41)
p_wiki_xhtml (/Users/stevevance/Sites/MasterProjectWiki/inc/html.php, 226)
html_show (/Users/stevevance/Sites/MasterProjectWiki/inc/template.php, 61)
tpl_content_core (/Users/stevevance/Sites/MasterProjectWiki/inc/events.php, 91)
Doku_Event->trigger (/Users/stevevance/Sites/MasterProjectWiki/inc/events.php, 197)
trigger_event (/Users/stevevance/Sites/MasterProjectWiki/inc/template.php, 44)
tpl_content (/Users/stevevance/Sites/MasterProjectWiki/lib/tpl/vance1/main.php, 91)
include (/Users/stevevance/Sites/MasterProjectWiki/inc/actions.php, 157)
act_dispatch (/Users/stevevance/Sites/MasterProjectWiki/doku.php, 86)

Original issue reported on code.google.com by jamesbondsv on 2010-03-11 21:45:04

dwp-forge commented 9 years ago
> I wrote <php>dbg_tracedump();</php> at the end of several pages with references. 

I suspect that you hit the memory problem earlier that the <php> tag is evaluated.
Regardless, what I meant by "places where PHP usually runs out of memory" is not the
wiki pages but DokuWiki source code. For example, line 286 of cache.php.

Original issue reported on code.google.com by dwp-forge on 2010-03-11 21:49:33

dwp-forge commented 9 years ago
> This is odd.

No it's okay. Please revert the changes as close as possible to the original state
(I
believe inline notes also were crashing) and insert the dbg_tracedump() calls in DW
sources (i.e. cache.php and io.php).

Original issue reported on code.google.com by dwp-forge on 2010-03-11 21:55:13

dwp-forge commented 9 years ago
Okay, I thought you may have meant that. Here goes:

io_readFile (, )
call_user_func_array (/Users/stevevance/Sites/MasterProjectWiki/inc/io.php, 80)
_io_readWikiPage_action (/Users/stevevance/Sites/MasterProjectWiki/inc/events.php,
91)
Doku_Event->trigger (/Users/stevevance/Sites/MasterProjectWiki/inc/events.php, 197)
trigger_event (/Users/stevevance/Sites/MasterProjectWiki/inc/io.php, 71)
io_readWikiPage (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php, 184)
p_cached_instructions (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
546)
refnotes_reference_database_page->parse (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
535)
refnotes_reference_database_page->__construct (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
448)
refnotes_reference_database->loadPages (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
395)
refnotes_reference_database->__construct (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
220)
syntax_plugin_refnotes_references->getDatabase (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
198)
syntax_plugin_refnotes_references->handleEnter (/Users/stevevance/Sites/MasterProjectWiki/lib/plugins/refnotes/syntax/references.php,
144)
syntax_plugin_refnotes_references->handle (/Users/stevevance/Sites/MasterProjectWiki/inc/parser/handler.php,
82)
Doku_Handler->plugin (/Users/stevevance/Sites/MasterProjectWiki/inc/parser/lexer.php,
517)
Doku_Lexer->_invokeParser (/Users/stevevance/Sites/MasterProjectWiki/inc/parser/lexer.php,
453)
Doku_Lexer->_dispatchTokens (/Users/stevevance/Sites/MasterProjectWiki/inc/parser/lexer.php,
405)
Doku_Lexer->parse (/Users/stevevance/Sites/MasterProjectWiki/inc/parser/parser.php,
115)
Doku_Parser->parse (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php,
219)

The lines p_cached_instructions through Doku_Parser repeat 50 times and then:

p_get_instructions (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php,
184)
p_cached_instructions (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php,
412)
p_render_metadata (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php, 278)
p_set_metadata (/Users/stevevance/Sites/MasterProjectWiki/inc/cache.php, 209)
cache_renderer->useCache (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php,
148)
p_cached_output (/Users/stevevance/Sites/MasterProjectWiki/inc/parserutils.php, 41)
p_wiki_xhtml (/Users/stevevance/Sites/MasterProjectWiki/inc/html.php, 226)
html_show (/Users/stevevance/Sites/MasterProjectWiki/inc/template.php, 61)
tpl_content_core (/Users/stevevance/Sites/MasterProjectWiki/inc/events.php, 91)
Doku_Event->trigger (/Users/stevevance/Sites/MasterProjectWiki/inc/events.php, 197)
trigger_event (/Users/stevevance/Sites/MasterProjectWiki/inc/template.php, 44)
tpl_content (/Users/stevevance/Sites/MasterProjectWiki/lib/tpl/vance1/main.php, 91)
include (/Users/stevevance/Sites/MasterProjectWiki/inc/actions.php, 157)
act_dispatch (/Users/stevevance/Sites/MasterProjectWiki/doku.php, 86)

And then: PHP Fatal error:  Maximum execution time of 30 seconds exceeded in /Users/stevevance/Sites/MasterProjectWiki/dbg_tracedump.php
on line 29

Original issue reported on code.google.com by jamesbondsv on 2010-03-12 03:16:39

dwp-forge commented 9 years ago
That's more like it. But I would rather prefer to take a look at the log file myself.
Could you delete the log, so we have a clean start, run into the problem again and
send the result (or part of it) to me?

At the first glance it looks like we have a recursion. Could it bee that you
reference notes from the database on the database page? May I see your reference
database page?

Original issue reported on code.google.com by dwp-forge on 2010-03-12 07:20:53

dwp-forge commented 9 years ago
> Could it bee that you reference notes from the database on the database page?

I tried that and it doesn't look pretty.

Original issue reported on code.google.com by dwp-forge on 2010-03-12 07:51:12

dwp-forge commented 9 years ago
There are two files attached.

The first, php_error.log.zip contains the error log dump for a SINGLE page load with
the errors from 
dbg_tracedump().

The second, refnotes_database.txt, contains my complete reference notes database.

Original issue reported on code.google.com by jamesbondsv on 2010-03-12 08:14:58


dwp-forge commented 9 years ago
Could it bee that you reference notes from the database on the database page?
A: I looked through my reference database and didn't find any references to notes in
the database. I searched for 
"[("

Original issue reported on code.google.com by jamesbondsv on 2010-03-12 08:15:47

dwp-forge commented 9 years ago
Try the latest references.php from the SVN repository.

Original issue reported on code.google.com by dwp-forge on 2010-03-12 18:32:34

dwp-forge commented 9 years ago
It works. The memory exhaustion error doesn't occur.
This is great news. 
What was causing the error?

Thank you!

Original issue reported on code.google.com by jamesbondsv on 2010-03-12 19:29:41

dwp-forge commented 9 years ago
> What was causing the error?

The problem was caused by recursion during the database loading. When we have a named
note reference we want to check if it is defined in the database, so we load the
database pages. When we load the pages we let DW parser to do the heavy lifting and
use already parsed instructions instead of raw wiki text, so the parser kicks in and
starts to do its thing. When the parser finds our syntax it calls us back to figure
out what that means. If it happens to be a named reference we want to check if it is
defined in the database, so we load the database pages... You get the idea.

I'm still not sure how you got into the trouble. Could it be that you store your
reference database in the same DW namespace as the "normal" pages?

Thanks for helping to nail it down!

Original issue reported on code.google.com by dwp-forge on 2010-03-12 19:49:40

dwp-forge commented 9 years ago
My reference database has always been here:
DokuWiki:refnotes:refdb

Original issue reported on code.google.com by jamesbondsv on 2010-03-12 20:29:21

dwp-forge commented 9 years ago
And I understand that in this namespace you have only one page, right?

And there are no subnamespaces like DokuWiki:refnotes:refdb:allmypages.

And in the RefNotes configuration you have DokuWiki:refnotes:refdb specified as the
reference database namespace.

Well, then it must be magic ;)

From the log files you can clearly see that an attempt to load the database results
in an infinite (well, while there is free memory) recursion. So far I could come up
with only one explanation for this, being that we come across a named reference while
parsing the database pages. And the fix I made to properly handle this situation
seems to help in your case. I'm not sure how but it has to be it.

One more thing you could try (if you are *really* eager to figure that out) is to
insert error_log($id) call inside the refnotes_reference_database_page constructor
(line 524 in the latest references.php). This way in the log file you will see which
pages are considered as part of the reference database. Maybe there you will see
something odd. For the best results I would recommend to clear the entire cache and
to delete database.dat file in the RefNotes plugin directory.

Original issue reported on code.google.com by dwp-forge on 2010-03-12 21:55:11