I ran into an odd problem with the way Cake is coded that tripped me up for a couple of days. Because I hate it when things don’t work the way I think they should, I spent way more time debugging this than anybody should.

I got my basic RESTful service working for the VolunteerCake project, and everything was working swimmingly, until I needed to turn on debug to figure something out …

When I had the debug level set to less than two (2) calling the action I was interested in with an extension of “.xml” was working fine. I got back the XML representation of the data in the action I was interested in returned with content-type of “application/xml”. In Cake, if you turn debug to 2 (or 3) it will dump out the SQL that was run in an HTML table.

The problem is that this HTML table is actually spit out  after the rest of the view, meaning that my RESTful service no longer has a well formed document to display. Additionally (for reasons I’ve yet to isolate), when this happens, the document is returned with a content-type of “text/html” instead of “application/xml” as expected. Neither of these things would be acceptable if the site is to provide web services, since it would mean the web services would be broken as soon as somebody needed to debug.

The workaround for this is to manually reset the debug level when the extension of “xml” is detected. Since the debug data is useful, and it’s just the SQL that appears to break the XML, I asked on the IRC channel what the last place I could set the debug might be. The suggestion was to put it either in the afterFilter, or the end of the view itself.

I found that if I put the following code into the beforeFilter method, I could prevent the problem with the price of losing my debug output:

if ($this->params['url']['ext'] == 'xml'){
    Configure::write('debug',1);
    $this->RequestHandler->respondAs('xml');
}

That same code placed in the afterFilter method gave me the debug output in a well formed XML document (excluding the SQL table), as did placing it in the view itself. This leads me to believe that when debug > 1 there is some code that happens after the beforeFilter that is not setting the content type to “application/xml” as would be expected from our routing rules.

Being the bulldog that I am, I dug into the Cake source code to see if I could figure this out. I found the spot where the SQL table was being built, which turned out to be in the showLog() method of the dbo_source.php, which is called by the close() method. Since the close() is called after the view is finished, and the showLog() method simply prints the data, that explains why it breaks the XML. It definitely breaks the MVC encapsulation, since the data gets dumped into an HTML table and spit out after the view is complete.

On the IRC channel, it was suggested that I try creating a data source that would override the showLog method and spit that table out to a table, which might be worth trying.

I posted my question on the CakePHP Google Group and got the useful suggestion to use the FirePHP plugin which basically writes the log data to the FirePHP plugin so it can be displayed in FireBug. So my approach will be to write a dbo_mysql_firephp.php class that does just that. This will at least resolve the MVC encapsulation issue and keep my view relatively clean.

I still want to figure out exactly why the content-type isn’t getting set properly, but for now I have a workaround that I’ll use, and I’ll add the FirePHP debugging to solve the well-formed XML issue if I ever do figure out the content-type problem.

Off to set up my FirePHP plugin and build the dbo class now …