watchdog() does not always work - or am I missing something?
I'm debugging a situation where one of my drupal menu items is being called via javascript, AJAX style. To debug a problem, I've added watchdog() calls to the callback - as a sanity check that the callback is being reached, and so I can inspect some values. The problem is that the log entries never show the messages I'm trying to write. Its as if the menu callback is never called. However the apache log shows that the path is being requested. Let's say the path is /drupal/my/callback. Now, when I explicitly point a browser to the URL, lets say http://example.com/drupal/my/callback, then the watchdog messages are written to the log! It's as if watchdog only succeeds when the browser explicitly makes the request. I've tried disabling drupal's cache. I've tried refreshing the cache. No matter what I do, either my callback is not being called (despite apache logs to the contrary) or the watchdog calls fail without error (which would be crazy). But only fail when the call is made via javascript. When made explicitly from the browser everything works as expected. BTW, the apache logs indicate the proper number of bytes is returned by the request, and I've changed the size of the page returned to confirm this - evidence that caching is not the cause of this. Has anyone seen this or have any ideas? Many thanks. -Dave
I will presume you run Drupal 6. Visit admin/build/modules to rebuild you rmenu.
Try using syslog to debug -- add one to your call and to the watchdog call itself. -marco On Tue, Apr 21, 2009 at 9:03 PM, Karoly Negyesi <karoly@negyesi.net> wrote:
I will presume you run Drupal 6. Visit admin/build/modules to rebuild you rmenu.
Another useful tool is firebug and the net tab, you should see the request go out and see how the server responds. My first thought is the path the js uses is relative (no leading slash for example) and not resolving as expected.
You can also change the size of the field in mysql, for the moment it's set as varchar(128) -----Original Message----- From: development-bounces@drupal.org [mailto:development-bounces@drupal.org] On Behalf Of Steve Ringwood Sent: woensdag 22 april 2009 06:25 To: development@drupal.org Subject: Re: [development] watchdog() does not always work - or am I missing something? Another useful tool is firebug and the net tab, you should see the request go out and see how the server responds. My first thought is the path the js uses is relative (no leading slash for example) and not resolving as expected.
As Frédéric described, this sounds like a bug in watchdog. On Wed, Apr 22, 2009 at 2:03 AM, Peter Droogmans <Peter@attiks.com> wrote:
You can also change the size of the field in mysql, for the moment it's set as varchar(128)
I've seen a similar case, where watchdog wouldn't work because the referer field was too long and the insert request in dblog failed almost silently instead of truncating that field (innodb engine, not checked with myisam engine): the request wasn't logged and the failure of that request wasn't stored either, IIRC for the same reason. Had to see it in a debugger to understand what was going on. You might want to try a debugger too. ----- Original Message ----- From: "David Cohen" <drupal@dave-cohen.com> To: <development@drupal.org> Sent: Wednesday, April 22, 2009 5:58 AM Subject: [development] watchdog() does not always work - or am I missingsomething? I'm debugging a situation where one of my drupal menu items is being called via javascript, AJAX style. To debug a problem, I've added watchdog() calls to the callback - as a sanity check that the callback is being reached, and so I can inspect some values. The problem is that the log entries never show the messages I'm trying to write. Its as if the menu callback is never called. However the apache log shows that the path is being requested. Let's say the path is /drupal/my/callback. Now, when I explicitly point a browser to the URL, lets say http://example.com/drupal/my/callback, then the watchdog messages are written to the log! It's as if watchdog only succeeds when the browser explicitly makes the request. I've tried disabling drupal's cache. I've tried refreshing the cache. No matter what I do, either my callback is not being called (despite apache logs to the contrary) or the watchdog calls fail without error (which would be crazy). But only fail when the call is made via javascript. When made explicitly from the browser everything works as expected. BTW, the apache logs indicate the proper number of bytes is returned by the request, and I've changed the size of the page returned to confirm this - evidence that caching is not the cause of this. Has anyone seen this or have any ideas? Many thanks. -Dave -------------------------------------------------------------------------------- No virus found in this incoming message. Checked by AVG - www.avg.com Version: 8.5.287 / Virus Database: 270.12.1/2071 - Release Date: 04/21/09 08:30:00
Good call Frédéric. I just found messages in my /var/log/messages.log... query: INSERT INTO watchdog (uid, type, message, severity, link, location, referer, hostname, timestamp) VALUES(1, 'php', '<em>Data too long for column &#039;referer&#039; at row 1 I recently added sql_mode=STRICT_ALL_TABLES to my.cnf, in order to catch issues like this in my own modules. And that's the setting that tells mysql to fail rather than truncate the long values. -Dave On Tuesday 21 April 2009 23:16:02 Frédéric G. MARAND wrote:
I've seen a similar case, where watchdog wouldn't work because the referer field was too long and the insert request in dblog failed almost silently instead of truncating that field (innodb engine, not checked with myisam engine): the request wasn't logged and the failure of that request wasn't stored either, IIRC for the same reason. Had to see it in a debugger to understand what was going on. You might want to try a debugger too.
What is the issue link you filed for this bug then on drupal.org? :) On Wed, Apr 22, 2009 at 9:51 AM, Dave Cohen <drupal@dave-cohen.com> wrote:
Good call Frédéric. I just found messages in my /var/log/messages.log...
query: INSERT INTO watchdog (uid, type, message, severity, link, location, referer, hostname, timestamp) VALUES(1, 'php', '<em>Data too long for column &#039;referer&#039; at row 1
I recently added sql_mode=STRICT_ALL_TABLES to my.cnf, in order to catch issues like this in my own modules. And that's the setting that tells mysql to fail rather than truncate the long values.
-Dave
On Tuesday 21 April 2009 23:16:02 Frédéric G. MARAND wrote:
I've seen a similar case, where watchdog wouldn't work because the referer field was too long and the insert request in dblog failed almost silently instead of truncating that field (innodb engine, not checked with myisam engine): the request wasn't logged and the failure of that request wasn't stored either, IIRC for the same reason. Had to see it in a debugger to understand what was going on. You might want to try a debugger too.
<div><br></div>
While the hate for WYSIWYG is well place, this is http://www.google.com/support/forum/p/gmail/thread?tid=1e986c013a16a9bb&hl=e... On Wed, Apr 22, 2009 at 10:32 AM, Daniel F. Kudwien <news@unleashedmind.com> wrote:
<div><br></div>
This is why I love WYSIWYG.
On Wednesday 22 April 2009 10:26:09 Karoly Negyesi wrote:
What is the issue link you filed for this bug then on drupal.org? :)
http://drupal.org/node/443182 Thanks for asking! :)
participants (9)
-
Chris Johnson -
Daniel F. Kudwien -
Dave Cohen -
David Cohen
-
Frédéric G. MARAND -
Karoly Negyesi -
Marco Carbone -
Peter Droogmans -
Steve Ringwood