Re: Would like mod_perl 1.29 to include more information on fatal errors
Hello Perrin,
Thank you for your response.
PH You could:
PH - Make s $SIG{__DIE__} handler
PH - Wrap your application in an eval {}
PH The data you want is available from either the standard apache log
PH formats or perl code in Apache::Status, so there's no need to worry
PH about writing C here.
The trouble is, our code isn't getting invoked at all. Mod_perl (or
something lower-level like that) is dying complaining that our code
can't be found on the hits where this happens. As an aside, we already
have similar eval traps, including one over the main handler code in
an attempt to provide the best error handling for our clients as
possible.
A mod_perl handler is set up (in apache conf), such as a content
handler, like this:
PerlHandler XX::Clients::YY::ContentHandler
When that resource is invoked by via a web request (GET or POST,
usually), mod_perl will load the module
XX::Clients::YY::ContentHandler and then attempt to call a method
named handler. It is this invocation of handler by mod_perl that
is randomly failing and we're trying to find more information about.
We added an ErrorDocument 500 statement in the Apache config, and
set it to a CGI program, which dumps out the symbol table using
Devel::Symdump as well as dumping out %INC.
The symbol dump shows (only relevant lines copied, there were hundreds
of lines output)
arrays
[nothing related to this]
functions
XX::Clients::YY::ContentHandler::handler
hashes
[nothing related to this]
ios
[nothing related to this]
packages
XX::Clients::YY
XX::Clients::YY::ContentHandler
scalars
XX::Clients::YY::
XX::Clients::YY::ContentHandler::
XX::Clients::YY::ContentHandler::AUTOLOAD
XX::Clients::YY::ContentHandler::DESTROY
XX::Clients::YY::ContentHandler::handler
**NOTE** The last item listed under functions is is what mod_perl
complained was undefined in the error log; so it seems like it was
partially defined (since some things exist for it in the symbol
table).
%INC shows many, many modules, with the module's relative path as the
key and the full path as the value. However, NOTHING exists in it
regarding XX::Clients::YY, even though there are entries for other
working clients and has normal entries on normal hits.
-
When everything is working normally, here is what we see in the Symbol
table related to our module for client YY (tons of stuff related to
this module, as before, the unrelated content was omitted from this
post):
arrays
XX::Clients::YY::ContentHandler::EXPORT
XX::Clients::YY::ContentHandler::EXPORT_FAIL
XX::Clients::YY::ContentHandler::ISA
XX::Clients::YY::ContentHandler::SUPER::ISA
functions
XX::Clients::YY::Custom::display_home
XX::Clients::YY::ContentHandler::_find_element
XX::Clients::YY::ContentHandler::_fix_menu
XX::Clients::YY::ContentHandler::_get_category_ids
XX::Clients::YY::ContentHandler::_num_spreads
XX::Clients::YY::ContentHandler::_record_audit_trail
XX::Clients::YY::ContentHandler::add_to_cart
XX::Clients::YY::ContentHandler::ceil
XX::Clients::YY::ContentHandler::check_children
XX::Clients::YY::ContentHandler::classes
XX::Clients::YY::ContentHandler::cleanup
XX::Clients::YY::ContentHandler::display_approval
XX::Clients::YY::ContentHandler::display_asset_management
XX::Clients::YY::ContentHandler::display_asset_search
XX::Clients::YY::ContentHandler::display_asset_search_cart
XX::Clients::YY::ContentHandler::display_asset_search_results
XX::Clients::YY::ContentHandler::display_asset_tree
XX::Clients::YY::ContentHandler::display_customized_preview
XX::Clients::YY::ContentHandler::display_dealer_info
XX::Clients::YY::ContentHandler::display_export
XX::Clients::YY::ContentHandler::display_forgot_password
XX::Clients::YY::ContentHandler::display_load
XX::Clients::YY::ContentHandler::display_photo
XX::Clients::YY::ContentHandler::display_product_results
XX::Clients::YY::ContentHandler::display_profile
XX::Clients::YY::ContentHandler::display_resize
XX::Clients::YY::ContentHandler::display_saved_documents
XX::Clients::YY::ContentHandler::display_step
XX::Clients::YY::ContentHandler::display_text
XX::Clients::YY::ContentHandler::display_tree
XX::Clients::YY::ContentHandler::display_welcome
XX::Clients::YY::ContentHandler::display_work_area
XX::Clients::YY::ContentHandler::do_nothing
XX::Clients::YY::ContentHandler::document_export
XX::Clients::YY::ContentHandler::download_zip
XX::Clients::YY::ContentHandler::fields
XX::Clients::YY::ContentHandler::funcs
XX::Clients::YY::ContentHandler::generate_preview
XX::Clients::YY::ContentHandler::handler
XX::Clients::YY::ContentHandler::new
XX::Clients::YY::ContentHandler::process_approval
XX::Clients::YY::ContentHandler::process_approval_request
Re: Would like mod_perl 1.29 to include more information on fatal errors
On Fri, Sep 4, 2009 at 12:00 PM, James Olsenjame...@planetolsen.com wrote:
The trouble is, our code isn't getting invoked at all. Mod_perl (or
something lower-level like that) is dying complaining that our code
can't be found on the hits where this happens.
Did you try $SIG{__DIE__}? It's a global setting for that perl
interpreter. I expect it will catch this. But it sounds like you
already got what you needed from your 500 intercept.
Does anyone have any ideas what would possibly cause items to be in
the symbol table for a module, but the module wouldn't be in %INC or
seemingly in memory at all (since we got an 'Undefined subroutine'
error when mod_perl tried to invoke the handler method)?
Sure. You can just say $XX::Clients::YY::ContentHandler::foo = 1 to
put something in the symbol table. It doesn't mean the module is
loaded.
I suggest you set your logging so you can see the exact set of
requests the process received in order (by following the PID), before
having this problem, and then try to recreate it by sending those same
requests with a WWW::Mechanize script. Maybe that will show you how
your code skipped loading this module.
- Perrin
Would like mod_perl 1.29 to include more information on fatal errors
Hello, We are running Apache/1.3.37 with mod_perl/1.29. We use the regular mod_perl API to install custom access, authentication, authorization, fixup, content, and logging handlers. Once in a great while we run into random Undefined subroutine XX::Clients::YY::ContentHandler::handler called.\n messages, where XX represents our internal namespace for our packages and YY a specific client. A snippet of typical Apache configuration is something like this for a virtual host: PerlAuthenHandler XX::Account::AuthenHandler PerlAuthzHandlerXX::Account::AuthzHandler Files blah SetHandler perl-script PerlHandler XX::Clients::YY::ContentHandler /Files When we get the undefined subroutine message, it looks like this: [Wed Sep 2 08:43:30 2009] [error] Undefined subroutine XX::Clients::YY::ContentHandler::handler called.\n The user sees a white page when this happens. No error message... but no content either. Usually hitting refresh will bring up the page they wanted, but it's obviously bad to have users experience random empty/white pages. The literal backslash and literal n are both (literally) in the logged message in the error log, which is why I think this error is coming from Perl and is just getting passed through by mod_perl to Apache; nothing is interpreting the line and translating the two characters \ and n into a newline. Usually we can track this down in our QA and production environments to a module that relies on a different module that we failed to use. It works most of the time because some earlier hit caused the Apache process to load one of our custom modules that in-turn use'd the module the later module referenced, so it was in coincidentally in memory the vast majority of the time it was referenced. The problem is when a clean/new Apache process served the faulty module *first*, before serving any other custom content, and then we would get the Undefined subroutine type of message. However, we've checked everything we can think of and we're unable to track down the problem in a particular set of custom modules for a client where this problem keeps happening for a small percentage of the hits. Sometimes the problem will also happen in our development environment, but then it is usually due to a compilation error (like bad syntax) where StatINC tried to load the new version of the module from disk and it failed to compile. When that happens, there is nothing in memory for that module so the handler function is not defined. Once the syntax error is fixed the problem goes away (in our development environment; this cause of the problem is never in our QA or production environments) We've ran out of ideas on why the main handler method--in a module that mod_perl should be loading directly--would generate this message. There are no preceeding error messages that we can attribute this error to. We are hoping if we spat out more information about the request (URI, params, etc) and the state of the process (pid, modules loaded, etc) we might be able to see what is going on and fix the problem. I would like to know if someone has a patch that will dump out more information about the hit, such as the requested URI, any parameters that are passed, what perl modules are in memory, the process ID, or anything at all that might help. I'm rusty on my C and I've never dug into mod_perl guts before, so I'm not sure where to even begin to look at adding the output of information myself on a fatal error (one that prevents a properly handled response). From what I can tell, it seems like mod_perl is taking an error from PERL and passing it directly to Apache's error logging mechanism. I'd like to intercept that call and dump out the extra information as well as the original error. Any guidance on patching/hacking mod_perl 1.29 to have more verbose error messages would be greatly appreciated. -- James Funny quotes: There are 10 types of people in the world. Those who understand binary, and those who don't. -- Unknown A computer once beat me at chess, but it was no match for me at kick boxing. -- Emo Philips
Re: Would like mod_perl 1.29 to include more information on fatal errors
On Thu, Sep 3, 2009 at 11:32 AM, James Olsenjame...@planetolsen.com wrote:
I would like to know if someone has a patch that will dump out more
information about the hit, such as the requested URI, any parameters
that are passed, what perl modules are in memory, the process ID, or
anything at all that might help.
I'm rusty on my C and I've never dug into mod_perl guts before, so I'm
not sure where to even begin to look at adding the output of
information myself on a fatal error (one that prevents a properly
handled response).
You could:
- Make s $SIG{__DIE__} handler
- Wrap your application in an eval {}
The data you want is available from either the standard apache log
formats or perl code in Apache::Status, so there's no need to worry
about writing C here.
- Perrin
