December 2011 Archives

What does CATALYST_DEBUG do?

Introduction

I used to think that CATALYST_DEBUG was an all-reaching magical environment variable that somehow affected the ‘Come back Later’ screen as well as what messages were output via $c->log->...().

I’ve educated myself since then but I’ve always thought it would be an interesting exercise explicitly exploring and documenting the various behaviour under different conditions.

The Code

Code for this example can be found in the catalyst_debug branch.

After each change we run ./script/demo_server.pl with various settings and note the results.

Basic Death

What do we see if we have an action that dies?

Edit lib/Controller/Root.pm so that the index() dies (af2a29e):

sub index :Path :Args(0) {
    my ( $self, $c ) = @_;
    die 'Shot through the heart!';
    $c->response->body( $c->welcome_message );
}
ENV variables script options Result
    Error Screen
CATALYST_DEBUG=0   Come Back Later
CATALYST_DEBUG=0 -d Error Screen
CATALYST_DEBUG=1   Error Screen

Remove ‘-Debug’ plugin

What happens if we don’t force the -Debug plugin?

Edit lib/Demo.pm and remove the -Debug Catalyst plugin (4fa87c0):

use Catalyst qw/
    ConfigLoader
    Static::Simple
/;
ENV variables script options Result
    Come Back Later
CATALYST_DEBUG=0   Come Back Later
CATALYST_DEBUG=0 -d Error Screen
CATALYST_DEBUG=1   Error Screen

Add StackTrace plugin

What happens if we want to see stack trace information on the Error Screen?

Edit lib/Demo.pm and add the StackTrace Catalyst plugin (20a6dd0):

use Catalyst qw/
    ConfigLoader
    Static::Simple
    StackTrace
/;
ENV variables script options Result
    Come Back Later
CATALYST_DEBUG=0   Come Back Later
CATALYST_DEBUG=0 -d Error Screen w/StackTrace
CATALYST_DEBUG=1   Error Screen w/StackTrace

Add ErrorCatcher plugin

What happens if we add ErrorCatcher to the mix?

Edit lib/Demo.pm and add the StackTrace Catalyst plugin (95b1fc4):

use Catalyst qw/
    ConfigLoader
    Static::Simple
    StackTrace
    ErrorCatcher
/;
ENV variables script options Result
    Come Back Later
CATALYST_DEBUG=0   Come Back Later
CATALYST_DEBUG=0 -d Error Screen w/StackTrace + console ErrorCatcher
CATALYST_DEBUG=1   Error Screen w/StackTrace + console ErrorCatcher

Test debug() with default settings

How do the variations affect logging output?

Edit lib/Controller/Root.pm and replace the death wih debugging into the log (24d7b65).

ENV variables script options Result
    Welcome Screen + console [debug]
CATALYST_DEBUG=0   Welcome Screen + console [debug]
CATALYST_DEBUG=0 -d Welcome Screen + console [debug]
CATALYST_DEBUG=1   Welcome Screen + console [debug]

Remove debug from log levels

Do any of the options add the debug log level?

Edit lib/Demo.pm and configure the log levels after calling setup() (83eb502).

ENV variables script options Result
    Welcome Screen
CATALYST_DEBUG=0   Welcome Screen
CATALYST_DEBUG=0 -d Welcome Screen
CATALYST_DEBUG=1   Welcome Screen

Conclusion

  • -Debug isn’t necessary in a Catalyst application
  • error debugging output can be controlled with either CATALYST_DEBUG or the -d script option
  • Neither CATALYST_DEBUG or the -d have any affect on the behaviour of $c->log->debug(...)

Because you may wish to run your application using alternative servers you should consider using CATALYST_DEBUG as you primary method for enabling error debugging output. If you happen to my using myapp_sewrver.pl you can export this for perma-debugging, or use the -d switch as required.

If you wish to control the logging levels for $c->log->...() don’t even consider CATALYST_DEBUG or the -d switch - you’re confusing different types of debugging.

Don’t use CATALYST_DEBUG

Throughout this experiment I’ve used CATALYST_DEBUG. Ideally you’d be a thoughtful developer and use MYAPP_DEBUG to ensure that you don’t inadvertently alter the error debugging of other Catalyst based applications in mysterious and unexpected ways.

Module Versions Used

During this experiment the following modules were used:

[Catalyst::Runtime]              5.90007
[Catalyst::Devel]                1.33
[Catalyst::Plugin::StackTrace]   0.11
[Catalyst::Plugin::ErrorCatcher] 0.0.8.10

The Ten Minute Thinking Rule

What’s the problem?

This idea was shared with me during a retrospective session at $employer when I was expressing some frustration at people starting to:

Ask first, think never

I’m at least as busy as the next person and I have my own mountain of work to complete. Despite being regularly cantankerous, grumpy, cranky and disagreeable people still come to me with a variety of questions … I think I have a good combination of detective skills, google-fu and luck that makes me appear more magical than I really am.

The Ten Minute Thinking Rule

Simply put:

You may only interrupt another co-worker to ask a question if you have sat on your own for ten minutes and tried to figure out the solution yourself

Corollary

When asked, you must be able to demonstrate that you’ve made some effort

The Ten Minute Thinking Rule isn’t an exercise in pretending you’re thinking.

Some ‘thinking’

Thinking also includes basic investigations. Consider some of the following:

  • You have an error message - what results do you get from $search_engine?
  • You have a code/SQL/… snippet - what results do you get from grep or ack?
  • You sit nearer to other smart people - what did they say when you asked them? — The Ten Minute Thinking Rule is generic - don’t mindlessly interrupt anyone
  • What other thoughts and questions have you processed in your ten minutes? — Do you vaguely remember seeing an email/bug report/internal wiki page that might have been relevant? Did you find it? Why wasn’t it helpful?

In Conclusion

Don’t get me wrong; I am more than happy to help people with problems where I can. I just get frustrated at the (apparent) lack of effort on the interrupting-person’s part.

Demonstrating that you’ve made some effort to solve your own problem is likely to encourage much higher levels of response and helpfulness.

Demonstrating that you’ve made no effort at all will likely result in very little help at all, deflection somewhere else and loss of karma in my internal tally chart.

CPAN Testers - "Can't locate FindBin/libs.pm in @INC"

Following my recent update to Catalyst::Plugin::ErrorCatcher I’ve taken some time to scan through the CPAN Testers Reports for the module.

I have to admit to being somewhat perplexed at one of the common test failures [example report]:

Can't locate FindBin/libs.pm in @INC

I’ve specified the library as a ‘TestRequires’ dependency in my Dist::Zilla dist.ini file:

[Prereqs / TestRequires]
DateTime = 0
File::Slurp = 0
FindBin::libs = 0
...

The generated Makefile.PL contains this as a ‘BUILD_REQUIRES’ dependency:

"BUILD_REQUIRES" => {
    # ...
    "File::Slurp" => 0,
    "FindBin::libs" => 0,
    "HTTP::Request::Common" => 0,
    "IO::File" => 0,
    # ...

I’ve also installed ErrorCatcher via cpanm on a perlbrew setup with FindBin::libs missing … and it was installed as a dependency.

There are so many of these reports that it can’t be one or two ‘unusual setups’ as the root cause. Either something has changed, or I’ve done something really stupid during the development of the module.

It’s slightly frustrating only being able to see the output of ‘make test’ and not anything from ‘perl Makefile.PL’.

Previous releases:

  • v0.0.8.9 has the dependency and exhibits the problem
  • v0.0.8.8 lists the dependency and does not exhibit this problem

I like to do as much as I can to resolve issues with my modules installing on various configurations but I’m not really sure where to go next with this one.

Catalyst::Plugin::ErrorCatcher - now with parameters

Following on from a recent feature request I’ve released version 0.0.8.10 of Catalyst::Plugin::ErrorCatcher.

The reports from the module now include POST and GET parameters for the request. Also included, if present, is the referer header value.

The new information looks like this:

     URI: http://localhost/foo/referer?fruit=banana&animal=kangaroo
  Method: POST
 Referer: http://garlic-weapons.tv

Params (GET):
  animal: kangaroo
   fruit: banana

Params (POST):
   slayer: kendra
  vampire: joe random

I’ve included some support for ‘long’ values. Anything longer than an arbitrary length chosen by me for no good reason other than it felt right will:

  • be checked with File::Type to see if it’s likely to be a file of some kind
  • truncated (and marked as such) if it’s text (application/octet-stream)

Output including these checks looks like this:

Params (GET):
  fruit: bananabananabananabananabananabananabana...[truncated]

Params (POST):
  image_gif: image/gif
  image_png: image/x-png
  long_text: kangarookangarookangarookangarookangaroo...[truncated]
   pdf_file: application/pdf

I haven’t provided any options or methods to:

  • change the value of ‘too long’
  • view the full value of something that’s ‘too long’

If they become necessary I’ll consider them as required.

About Chisel

user-pic I blog about Perl.