PHP's display_error, not always a good thing!

I just hit an interesting issue while trying to upgrade a Drupal 5.18 site to Drupal 6.12. I went to the update.php page and noticed an error at the top implying the url_alias table was having issues due to Drupal 6 expecting a language column which wasn't present in Drupal 5. "No problem" I thought, "That'll get fixed during the update!". This was the beginning of a long learning curve through the new Batch API system!

Whenever I ran the update, it sat there for a minute and eventually display a message to the effect "There was unrecoverable error. See Below for more details" and the details read "An error occurred". This didn't give a lot of clues! So I started debugging and eventually found out the error occurred after system_update_6005.

Why 6005? Well, when the Batch API is initially started, it resets a time counter. It will keep going through the list of operations (in this case, update_do_onefor each module/number needing doing) and keeping track of how long this particular round has been going. If the sum of the time for the operations is less than 1 second, then it doesn't bother ending, it does another op (and another, and another… until the sum of the time taken is more than 1 second). Once the 1 second is up, this "round" then it ends and returns a JSON object to the page callback. This page then uses the progress JavaScript system in Drupal to display the animated bar to let you know how it's getting on. The bar updates and then posts back to the site to, essentially, say "you may now continue from where you left off" and the next round starts. This keeps going until the operations array is empty.

Remember earlier, I said I had display_errors enabled (a common practice for a development environment)… Well when the JSON object got returned, there was a non-JSON line tagged at the top which was meant to be there to tell me about the MySQL error caused by the broken url_aliastable. The JavaScript JSON engine didn't like that so threw the error message. This is also why, if I restarted the updates, they worked fine.

So… Debugging… Not always a good thing!