In this two issues

http://drupal.org/node/92503
http://drupal.org/node/92430

is mentioned problem about inproper blob handling. If i applied patch from http://drupal.org/node/92430 caching work correctly but i have new errors looks like:

Warning: pg_query() [function.pg-query]: Query failed: ERROR: value for domain int_unsigned violates check constraint "$1" in /data/www/htdocs.cms/drupal/includes/database.pgsql.inc on line 125

Warning: ERROR: value for domain int_unsigned violates check constraint "$1" query: statistics_init INSERT INTO drupal_accesslog (title, path, url, hostname, uid, sid, timer, timestamp) values('', 'node', 'http://www.fem.uniag.sk/drupal5/?q=admin/build/modules', '217.144.19.169', 0, '5a66e03780ed81070702f6a741b4de58', -1007089557, 1162929047) in /data/www/htdocs.cms/drupal/includes/database.pgsql.inc on line 144

Problem is in statistics.module - in function statistics_init(). Function timer_read() here return negative value, which is not correct.

If i disable statistics.module whole page work correct. Maybe this is related with full page caching function?

CommentFileSizeAuthor
#3 timer_start_empty.patch822 byteschx

Comments

Jo Wouters’s picture

There is indeed something wrong with timer_read()
In some occasions both $timers['page']['start'] and $timers['page']['time'] are not set, so $diff becomes very big ($stop * 1000) which gives something like 1162937764105.4 (more then 10 digits)

If $timers['page'] is not set, it indicates that DRUPAL_BOOTSTRAP_LATE_PAGE_CACHE had not been executed (DRUPAL_BOOTSTRAP_LATE_PAGE_CACHE contains timer_start('page');).
Is this normal in certain occasions ?? No idea. This should be investigated. (it would mean that this is a bootsrap.inc issue, and not a statistics.module issue.)

This only seem to happen when enabling 'access log' (so disabling should be a temporary solution).

This is the timer_read function:

<?php
function timer_read($name) {
  global $timers;
  list($usec, $sec) = explode(' ', microtime());
  $stop = (float)$usec + (float)$sec;
  $diff = round(($stop - $timers[$name]['start']) * 1000, 2);

  if (isset($timers[$name]['time'])) {
    $diff += $timers[$name]['time'];
  }
  return $diff;
}
?>

BTW, I think the round(x, 2) should be replaced by round(x, 0) There does not seem to be any use for the extra decimals if we are going to store it in a int field.

havran’s picture

Possible is timer_read() called before timer_start() ? I have tried print $timers variable and i get nothing (empty variable)...

How to reproduce error:

I have PostgreSQL 7.4.

Install clean installation of Drupal 5.0 beta 1.
Enable page caching (i have set Caching mode normal and Minimum cache lifetime to 1min.)
(Now i get (as anonymous page host) numerous PostgreSQL errors.)
Apply patch for correct handling blob caching from http://drupal.org/node/92430
Enable Statistics module -> Enable access log
Logout

chx’s picture

Status: Active » Needs review
StatusFileSize
new822 bytes

An easy fix to this is not to do anything in timer read if said timer is not stared.

havran’s picture

I apply patch and my page now running without problem.

Jo Wouters’s picture

Patch is working. Looks like a good solution to me.

chx’s picture

Priority: Critical » Normal
Status: Needs review » Reviewed & tested by the community

Why is this critical??

havran’s picture

Because my web not working with this bug. I give only page full of errors and binary data from cache...

drumm’s picture

Status: Reviewed & tested by the community » Fixed

Committed to HEAD.

Anonymous’s picture

Status: Fixed » Closed (fixed)