I can’t include code in this post because I don’t own it, but I think I can discuss the concept, which I found really interesting.

A coworker had the idea to extend the PDO prepare() method to aid in debugging. I’m not sure if he implemented something he found on the net or it was an original idea, but I really like the results. It prepends, to every query executed, an SQL comment (ala “/* comment */“) including the username of the logged in user and the URL of the current request. This usually makes no difference, but if you’re in a really tough spot in debugging you can turn on mysql general_log, run the session that is having problems, and easily see every query that the was executed on behalf of the user having problems.

This has been working for over a year, and through three software releases.

Yesterday a support engineer brought me a problem involving a little-used corner of our software. This particular function would ultimately make a GET with a piece of (properly encoded) arbitrary text (something along the lines of “append this string to this log”, something so simple there wasn’t any reason not to make it a GET).

The engineer found that on some strings we would get PHP errors. Specifically “SQLSTATE[HY093]: Invalid parameter number: mixed named and positional parameters“. I dug in and found two things. First, the text in question that was causing this looked something like “foo_:_bar“. The colon was the key. Second, the actual query that was blowing up did not have the URL in it, it was a very innocent query looking up session data. It did have one positional parameter in it (‘?’). I temporarily rewrote the query to embed the single param instead, and the error changed to “SQLSTATE[HY093]: Invalid parameter number: no parameters were bound“.

Clearly the PDO parser thought there was a named param in my query, and just as clearly I could see that there wasn’t. I then found the debugDumpParams() function, and prepare thought my query looked something like this:

/* https://server/path/to/code/arbitrary_foo_:_bar */
SELECT count(*)
  FROM Foo

Ah. That’d explain it then.

The solution was very simple, just wrap the URL in parent::quote() in the extended prepare() function. It was very interesting to me though that PDO still scans SQL comments and at first glance I thought it was a bug. I decided that this was actually a feature though. It allows you to comment out portions of your SQL without having to alter the execute() to match.

One open question I have through all of this is “what is the canonical definition of what a named parameter looks like and where it can be used?” I can’t find this documented anywhere. If you know please let me know. It is not as simple as saying “a colon causes this problem”, because it doesn’t. Here’s my empirical findings:

• foo_:_bar – IS considered a named parameter
• foo:bar – IS NOT considered a named parameter
• foo_:bar – IS
• foo:_bar – IS NOT
• foo):bar – IS
• foo:(bar – IS NOT

I took a look at the pdo source (ext/pdo/pdo_sql_parser.c), but the actual scanner is a state machine that made my head hurt. I do think I got far enough to decide that a colon following alphanum is appended to the preceeding string by the machine, which is why we get the variability above. In other words:

• foo:bar -> scans to (“foo:”, “bar”)
• foo_:bar -> scans to (“foo_”, “:bar”)

I don’t have a moral to this story, I just found it to be an interesting example of an action-at-a-distance bug (both time and code-spatial) and I wanted to remember the details. Let’s be careful out there!