Bug 57501 - abort_page does not stop page execution after a call to ::rivet::parse
Summary: abort_page does not stop page execution after a call to ::rivet::parse
Status: RESOLVED FIXED
Alias: None
Product: Rivet
Classification: Unclassified
Component: Rivet Core Commands (show other bugs)
Version: 2.2.2
Hardware: PC FreeBSD
: P2 normal
Target Milestone: mod_rivet
Assignee: Apache Rivet Mailing list account
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-01-26 15:33 UTC by james.sulak
Modified: 2015-05-25 12:39 UTC (History)
2 users (show)



Attachments
Tcl error status propagates to the caller when ::rivet::parse is called (5.25 KB, patch)
2015-01-27 23:09 UTC, Massimo Manghi
Details | Diff
fix for improper handling of error code returned by parse command (5.44 KB, patch)
2015-01-28 08:35 UTC, Massimo Manghi
Details | Diff
3rd patch for ::rivet::abort_page handling (5.45 KB, patch)
2015-01-28 15:40 UTC, Massimo Manghi
Details | Diff
extended error handling (5.57 KB, patch)
2015-04-18 17:16 UTC, Massimo Manghi
Details | Diff
New handling of abort script if abort_page is called but no AbortScript defined (5.78 KB, application/x-tcl)
2015-04-21 13:48 UTC, Massimo Manghi
Details
Error handling further improved (8.52 KB, patch)
2015-04-27 15:20 UTC, Massimo Manghi
Details | Diff
Checking abort condition when rolling back through the call stack to prevent spurious error handling (8.09 KB, patch)
2015-05-01 00:41 UTC, Massimo Manghi
Details | Diff
Also we don't report abort_page generated errors (8.54 KB, patch)
2015-05-04 16:42 UTC, Massimo Manghi
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description james.sulak 2015-01-26 15:33:15 UTC
Version 2.2 on FreeBSD.

After calling ::rivet::parse, a call to abort_page does not stop the execution of the page, if the included rvt calls abort_page.  If the included rvt does *not* call abort_page, the call in the outer rvt functions as expected.

I'm unclear as to what the intended behavior is.  Is the intention that the rvt executed by ::rivet::parse is independent, with an independent lifecycle, or is it simply meant as a "function call" inside the outer rvt page?


Test case:

test_parse.rvt:

<?
parse test_parse2.rvt
abort_page

puts "Execution continued."
?>

test_parse2.rvt:

<?
puts "Parsed rvt."
abort_page
?>


As a secondary issue, note that in a rivet + Tcl 8.5 installation, this can be worked around by placing a "return" call after the parse statement.  However, with Tcl 8.6, this results in the following error:

"errorCode 'TCL UNEXPECTED_RESULT_CODE 0', errorInfo 'command returned bad code: 0    while executing "namespace eval request { puts -nonewline "" ..."
Comment 1 Massimo Manghi 2015-01-27 16:16:33 UTC
Thank you for reporting this issue. I think you hit something more relevant than a simple bug, the way mod_rivet does script parsing and execution has to be reconsidered and ironed out
Comment 2 Massimo Manghi 2015-01-27 23:09:39 UTC
Created attachment 32403 [details]
Tcl error status propagates to the caller when ::rivet::parse is called

Tcl return error propagates up to the toplevel script and script execution finalized in Rivet_SendContent
Comment 3 Massimo Manghi 2015-01-28 08:35:26 UTC
Created attachment 32404 [details]
fix for improper handling of error code returned by parse command

Not only the Tcl status didn't unwind the whole calls stack but after_every_script was called inconditionately after *each* parse
Comment 4 james.sulak 2015-01-28 13:56:13 UTC
Thank you for the quick response.  We'll test and see how it works.

I had noticed that after_every_script was called after every parse - which is in fact how I discovered the bug, since our after_every_script calls abort_page.  That seemed wrong, which is why I asked about intended behavior.
Comment 5 Massimo Manghi 2015-01-28 14:32:33 UTC
In case abort_page gets called from within after_every_script it won't trigger the AbortScript. AfterEveryScript was executed after AbortScript before I made this patch anyway. And now it works this way all the more so because it gets executed really as very last script. So it must be changed again. Let me check the documentation but I suspect we have been having a quite haphazard setup for these procedures. If I understand you want to have AbortScript to be run whenever ::rivet::abort_page is called (perhaps only ErrorScript shouldn't run it) which makes sense but it's going to add here and there a few more 

if (rsc->after_every_script != NULL)

   Tcl_Exec....



please hold on a few more hours then...
Comment 6 Massimo Manghi 2015-01-28 15:40:56 UTC
Created attachment 32406 [details]
3rd patch for ::rivet::abort_page handling

it turned out to be easier then I thought at first, but I haven't tested it. Please let me know
Comment 7 Massimo Manghi 2015-02-05 09:12:09 UTC
the patch aimed at fixing bug #57501 was applied (a bit further elaborated to move the charset handling into TclWeb_PrintHeaders) and committed to branches/2.2

I'm going to allow a few more dayes after which if no further problems will surface I will close the bug 

 -- Massimo
Comment 8 james.sulak 2015-02-05 16:36:20 UTC
I apologize, we haven't had a chance to test yet, since we've been using the version of Rivet in FreeBSD ports, and haven't had a chance to patch and build.

We are going to test the 2.2 branch tomorrow and will update this thread with our results.
Comment 9 Massimo Manghi 2015-02-14 08:53:58 UTC
Please, let us know when you've done your tests, I wish to roll another version of rivet including the fix of this bug
Comment 10 james.sulak 2015-03-03 21:39:14 UTC
I apologize for the delay again.  We have done a test, which unfortunately resulted in an apache core dump.  Since the test was conducted on an active dev environment, we have yet to analyze the dump or isolate the problem more thoroughly.  I'll keep this bug updated as we proceed.
Comment 11 Massimo Manghi 2015-03-11 10:46:04 UTC
A possible cause of segfaults was found in the 2.2 branch and in trunk as well. The 2.2 branch has been patched and trunk will follow soon. I don't know if it can help to find the source of the segfault you observed in your test environment
Comment 12 Massimo Manghi 2015-03-17 10:14:21 UTC
Any news from your test environments?
Comment 13 james.sulak 2015-04-17 15:13:13 UTC
Apologies again for the delay.  

For a clean install of the 2.2 branch on FreeBSD, I don't get a segfault, and it looks like the initial problem is fixed.

However, if I set the AfterEveryScript to abort_page, I get:

Rivet AfterEveryScript failed!

Page generation terminated by abort_page directive
    invoked from within
"abort_page"

Is this expected, or should we not be attempting to call abort_page in the AfterEveryScript?   Note of course in production we don't use abort_page as the actual AfterEveryScript, but it is called from it.
Comment 14 Massimo Manghi 2015-04-17 16:28:47 UTC
AfterEveryScript was meant to be exactly that: the last resort for catching anything left dangling. It has no ErrorScript or AbortScript but it makes sense it should be caught by an ErrorScript in case of Tcl errors. I'm not sure AbortScript should be triggered from AfterEveryScript (which won't be run after-every-script anymore), but for uniformity of behavior it might be the case we also assume abort_page to be able to trigger an exception even during this very final stage. I would be glad to add it, I just have a feeling like we are forcing and overloading AbortScript of tasks that should probably be carried out withing AfterEveryScript itself. But I'm a bit too conservative at times

Thoughts?
Comment 15 james.sulak 2015-04-17 17:54:06 UTC
>  I'm not sure AbortScript should be triggered from AfterEveryScript (which won't be run after-every-script anymore)

This is where my understanding of Rivet is a bit limited.  My understanding is that abort_page is not meant to trigger an error, but simply as an exit statement from the rivet page.  Or is your point that since AfterEveryScript is run after the script is aborted, then calling abort_page is nonsensical and unnecessary?

Also to confirm, is the error on abort_page in AfterEveryScript new with your recent changes?  It's in our current AfterEveryScript, which operates without issues.
Comment 16 Massimo Manghi 2015-04-17 18:58:30 UTC
Forget about my comment. I misinterpreted the code. I don't even know how I did it, not very accurate but I checked rather carelessly.

 ::rivet::abort_page with AfterEveryScript fires the execution of AbortScript. Sorry for confusing it and sorry for getting you on the wrong track. 

I generally refer to abort_page as a way to generate exceptions because it's the closer analogy I have in mind. It's not exactly like in Java or C++, but the logic behind it is quite similar, you stop the execution and jump to where the a condition can be caught. And abort_page accepts an argument for driving the response of AbortScript. But to add more confusion to the issue...well...yes, abort_page returns a TCL_ERROR code with a reserved error code that triggers the execution of an AbortScript if exists. This is the way the mechanism was designed.

The bottom line is: we need also to check if an ErrorScript must be run. Your error is caused by something that failed in the AfterEveryScript. Perhaps the error message could be also improved
Comment 17 Massimo Manghi 2015-04-18 13:52:39 UTC
I did some more accurate analysis of the problem, yesterday wasn't the right time for doing it, today I have more time and less things going on around me.

Scripts execution was already changed and performed by calling Rivet_ExecuteAndCheck. Within this function error conditions are examined and in case handled by AbortScript or ErrorScript. These scripts cannot be run through Rivet_ExecuteAndCheck for obvious reasons and their errors must be handled directly. Ideally these scripts must not fail.

I spotted a problem in Rivet_ExecuteAndCheck: the error code returned by an ErrorScript has no effect on the code returned by Rivet_ExecuteAndCheck whereas in case of successful execution it simply should return TCL_OK to the caller. 

This is a problem I'm going to fix right away.
Comment 18 Massimo Manghi 2015-04-18 17:16:57 UTC
Created attachment 32659 [details]
extended error handling

This patch extends the error handling. The central procedure in mod_rivet for script execution (Rivet_ExecuteAndCheck) has been modified and it's now sided by a new procedure Rivet_ExecuteErrorHandler. This procedure runs for both a URL referenced script and for an AbortScript in case of errors. I did some tests and it worked but needs to be tested on a wider set of cases. This patch should also fix the problem you're observing: if an AbortScript or ErrorScript exits successfully it the whole procedure should return TCL_OK. Please let me know what's the result of your tests now
Comment 19 james.sulak 2015-04-20 19:52:44 UTC
Thanks for the patch.  When we apply it to the 2.2 branch, the unmodified index.rvt rivet test page gives the same error as previously listed:

Rivet AfterEveryScript failed!

Page generation terminated by abort_page directive
    invoked from within
"abort_page"
GET HTTP 
responds with code two hundred
page loads, YOU GOT SERVED
Comment 20 Massimo Manghi 2015-04-21 13:48:26 UTC
Created attachment 32672 [details]
New handling of abort script if abort_page is called but no AbortScript defined

calling abort_page it breaks execution but doesn't return TCL_ERROR if no AbortScript is defined
Comment 21 Massimo Manghi 2015-04-22 06:50:12 UTC
Comment on attachment 32672 [details]
New handling of abort script if abort_page is called but no AbortScript defined

The patch has the wrong extension (.tcl instead of .diff). Sorry for the prolonged messing about this issue. I definitely need some time off work
Comment 22 Massimo Manghi 2015-04-27 15:20:35 UTC
Created attachment 32688 [details]
Error handling further improved

Improved handling of AbortScript and ErrorScript. ErrorScripts are always run when any other script fails (if defined). If an ErrorScript is defined it's left to the programmer the task of generating a suitable error message if needed
Comment 23 james.sulak 2015-04-29 16:28:07 UTC
Thanks for the latest patch.

With this patch, I get the following behavior:

- abort_page within a parsed file "test_parse2.rvt" in this instance, does abort the execution of the parsed page, but not the calling page.  
- Subsequent calls to abort_page from the calling page also have no effect, page execution continues.
- Abort_page works properly when no parse is involved.
Comment 24 Massimo Manghi 2015-05-01 00:41:26 UTC
Created attachment 32709 [details]
Checking abort condition when rolling back through the call stack to prevent spurious error handling

This patch uses the globals->page_aborting flag to check if the TCL_ERROR status was returned after calling abort_page. Thus calling abort_page within a nested template shouldn't result in a Tcl error. Please let me know
Comment 25 james.sulak 2015-05-04 14:27:56 UTC
Thanks.

The actual behavior of the pages is correct, and behaves as I expect.  However, when abort_page is called, either in the calling page, the called page, or in the AfterEveryScript, mod_rivet records an error in the httpd-error.log, for example:

[Mon May 04 14:25:35 2015] [error] (20014)Internal error: mod_rivet: Error in Rivet_ParseExecFile exec file '/usr/local/www/apache22/data/test.rvt': Page generation terminated by abort_page directive\n    invoked from within\n"abort_page"\n    invoked from within\n"parse test_parse2.rvt"\n    (in namespace eval "::request" script line 5)\n    invoked from within\n"namespace eval request {\nputs -nonewline ""\n\n\nparse test_parse2.rvt\n\n\nputs "Execution continued."\n\n# abort_page\n\nputs -nonewline "\n\n\n \n"\n\n}"
Comment 26 Massimo Manghi 2015-05-04 16:42:42 UTC
Created attachment 32713 [details]
Also we don't report abort_page generated errors

Yes! top level script execution mustn't report errors generate by abort_page calls. Please check this out, it works for me
Comment 27 Massimo Manghi 2015-05-04 17:12:31 UTC
The latest patch prevents spurious error logging by checking the flag globals->page_aborting (Tcl interpreter associated data) but there also cases when you want to print an error even when abort_page has been called

After abort_page is called execution is interrupted and control passed on to AbortScript and AfterEveryScript. If any of these scripts fail for some reason logging must be re-enabled and therefore that flag must be reset each time an error handler is called (Rivet_ExecuteErrorHandler)

This simple change is in my working box, I'm certain your AbortScript is fail proof ;) so it won't change your tests. I will check it more closely and commit it in a day or two
Comment 28 james.sulak 2015-05-06 14:09:32 UTC
Thanks for the patch.  All my tests pass, and I'm no longer seeing errors in httpd.log when calling abort_page.

abort_page, when called from within a parsed parsed, aborts the entire page, including the caller.

To make sure we're on the same page, AfterEveryScript is not called (I believe) when a parsed page finishes.  My test is using abort_page as the AfterEveryScript.  When I do that, if I do not call abort_page explicitly from within the parsed page, page execution continues in the caller.

I think that's reasonable behavior, although I could see the argument for calling AfterEveryScript after the parsed page, since it too is a script.
Comment 29 Massimo Manghi 2015-05-10 20:16:59 UTC
I'm not sure I understand all the details in your last comment.

If you look at the function Rivet_SendContent in src/apache-2/mod_rivet.c you will see the AfterEveryScript (stored in rsc->after_every_script, where rsc is the configuration record) is executed right after Rivet_ParseExecFile regardless the status code returned by this function. The pointer storing the script has to be non NULL to be fired.

abort_page sets an internal status flag and subsequent calls to abort_page have no effect until the request has been served. The rationale for this is that the parsed template (or also pure Tcl script for what it matters) is supposed to interrupt execution immediately and hand the control on to the AbortScript from where I don't see the point of calling abort_page again.

Then AfterEveryScript was introduced and now we passed it throught Rivet_ExecuteAndCheck, which runs rsc->rivet_abort_script if abort_page is called, so we should have two cases

 1) abort_page is invoked from the parsed page and then it should be uneffective from that point on to the end a single request
 2) abort_oage is invoked from rsc->after_every_script and it should fire rsc->rivet_abort_page anyway

 Does it match your tests? Do we want AbortPage scripts to be treated differently when called from AfterEveryScript?
Comment 30 james.sulak 2015-05-12 16:43:07 UTC
I apologize- the current behavior works for us, I was just confused about the implementation details.