I spent this week debug­ging an issue with an inter­nal web tool that our company’s sup­port team relies upon to pull up infor­ma­tion about our cus­tomers, mak­ing changes on their behalf to their sub­scrip­tions of the var­i­ous pack­ages and ser­vices that we offer. Trying to view one par­tic­u­lar cus­tomer — one! — would always crash the appli­ca­tion, leav­ing an unhelp­ful mes­sage that said, ​“Internal Server Error: Please con­tact the serv­er admin­is­tra­tor. More infor­ma­tion about this error may be avail­able in the serv­er error log.” Unfortunately, there was only a sin­gle line in the log, ​“Error 500,” which only indi­cat­ed that yes, an error had hap­pened on the serv­er. No details from the application.

Luckily, this appli­ca­tion was writ­ten in Perl, an expres­sive pro­gram­ming lan­guage with a rich ecosys­tem of open-​source libraries. It also has a built-​in debug­ger mode that can run your pro­gram step by step, line by line. Any pro­gram that can be run from the text com­mand line can be paused, have its vari­ables and objects exam­ined, new code inter­ac­tive­ly entered, and then con­tin­ue its exe­cu­tion as if noth­ing had happened.

However, this was a web appli­ca­tion that assumed it was run­ning in a web serv­er envi­ron­ment, and the customer’s infor­ma­tion was in our pro­duc­tion data­base, safe from pry­ing eyes (includ­ing curi­ous devel­op­ers like me) due to finan­cial com­pli­ance rules. I could not sim­ply run this pro­gram on my desk­top and repro­duce the prob­lem with this one cus­tomer — I had to some­how tease out more infor­ma­tion from a run­ning sys­tem and report it back using the only tool avail­able: the serv­er error log men­tioned above.

But still, the Perl debug­ger approach was appeal­ing. Could I some­how get the appli­ca­tion to log each line of code as it was exe­cut­ed? Could I then see what was run­ning the moment before it crashed, the offend­ing line print­ed in the log like a smok­ing gun that had just mur­dered its vic­tim? And assum­ing that the prob­lem was in our code and not in the mil­lions of lines of third-​party code it depend­ed upon, could I fil­ter out all the noise?

The answer, thank­ful­ly, was yes; since the debug­ger itself is writ­ten in Perl and designed to be extend­ed or replaced, I could add code at the begin­ning of our appli­ca­tion that inter­cept­ed each line as it was run, throw out any­thing that came from a file out­side of our application’s direc­to­ry fold­er, and then report the rest (along with help­ful line num­bers) to the error log. Then turn on the ​“debug” switch on the web serv­er run­ning the appli­ca­tion, and voilà, the log would duti­ful­ly fill up with (slow­er, more memory-​consuming) code report­ed by the debugger.

We set up our stag­ing serv­er to use the branch of code with debug­ging enabled, and then instruct­ed the appli­ca­tion to dis­play the prob­lem­at­ic cus­tomer’s records. As expect­ed, the error log imme­di­ate­ly began fill­ing up with line after line of our application’s code and then bang, crashed right after issu­ing a par­tic­u­lar data­base query for ser­vices tied to the account. I had my smok­ing gun! After extract­ing the query and run­ning it on a redact­ed copy of our data­base, I found that it was return­ing some 1.9 mil­lion rows of data as it retrieved pro­vi­sion­ing, billing, and renew­al his­to­ry for every ser­vice owned by the cus­tomer. This was far too many than nec­es­sary — the appli­ca­tion only cares about cur­rent sta­tus, and it was run­ning out of mem­o­ry as it cre­at­ed ser­vice objects for each row.

The data­base expert on my team was able to adjust the query to return only cur­rent infor­ma­tion, and after a quick test on the redact­ed data­base, the change is now wait­ing for qual­i­ty assur­ance test­ing before launch­ing to our pro­duc­tion servers. The debug­ging code branch will be saved until it’s need­ed again, and our team was once again grate­ful that we were work­ing in such a pow­er­ful pro­gram­ming lan­guage as Perl.