Re: Would like mod_perl 1.29 to include more information on fatal errors
On Fri, Sep 4, 2009 at 12:00 PM, James Olsen 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
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 XX::Clients::YY::ContentHandler::proce
Re: Would like mod_perl 1.29 to include more information on fatal errors
On Thu, Sep 3, 2009 at 11:32 AM, James Olsen 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
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 SetHandler perl-script PerlHandler XX::Clients::YY::ContentHandler 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