Path Variable Being "Unset"

We had an interesting bug recently that affected the Less Accounting website. One of the functions in Less Accounting is the ability to send invoices and proposals. The system let's you send them as an email or as a PDF file attached to an email, or you can download a PDF of the invoice. Recently we started seeing some problems with the PDF generator process. After a seemingly random period of time a mongrel would stop generating PDFs. Wait a little longer and another mongrel would fail until they were all failing. This also started happening more frequently; two weeks ago this was a rare occurrence, but a few days ago it would start failing almost immediately. Restarting the mongrels always fixed the problem, but obviously setting them to restart every five minutes was not acceptable.

Besides nil exceptions, the only other exception raised was a Broken Pipe Exception. Since no output was being generated by the PDF service for these failed PDFs I started adding all kinds of debug info. Due to the Broken Pipe Exception I started to suspect a problem with file descriptors. I even rewrote the generation code to use files as input and output instead of stdin and stdout. Once I had the raw input as files I could run the PDF generation manually which always worked. The oddest part was that this happened over time, the same input would succeed after a restart, but not a short time later.

Lourens Naudé took some time with me to help sort this out. We used strace on the mongrels and when that didn't help I added strace to the PDF generator. What was odd was that strace didn't log anything when there was a failure, just as the PDF generator didn't log anything on failure. I decided to log the command that calls the PDF generator and discovered that the failures were caused by the PDF generator not being called at all.

The lib shelled out `which` to get the path to the generator and at some point `which` could no longer find the command. It acted as if the $PATH variable was being unset. The generator is in the same location in dev and production, so hard coding the path fixed the problem.

I'm not sure why the path variable would be unset and didn't have time to investigate further. If you have any insights, please share them.

4 Comments

Lourens Naude said on January 16, 2009

Steve,

Could also cache the path on the first run ( memoize ) … piggy backing on your Mongrels not starting sleep walking either, off course.

Mark Turner said on January 17, 2009

Does it happen to newly spawned Mongrels or do you restart them and eventually $path gets unset?

Mark Turner said on January 17, 2009

Have you tried dumping out ‘env’ right before you call the PDF generation code?

Something like: logger.info “Environment: #{`env`}”

Steven Bristol said on January 18, 2009

@Mark,

I could have continued to debug, but honestly I can’t afford to spend anymore time on this.