Currently the watchdog() function is logging events using REQUEST_TIME constant which is just $_SERVER['REQUEST_TIME']. This works fine in most cases but processes that take an extended period of time all get logged at the time the process began, and not when the event actually happened. For example when running data migration scripts that can take much longer to process all of the errors get logged at the time the process began. It seems that watchdog would be more accurate if it logged the time with time() instead.

Files: 
CommentFileSizeAuthor
#19 watchdog-time.patch731 bytesjbrown
PASSED: [[SimpleTest]]: [MySQL] 39,407 pass(es).
[ View ]
#12 1239410-12.patch667 bytesswentel
PASSED: [[SimpleTest]]: [MySQL] 41,106 pass(es).
[ View ]
#8 drupal-1239410-8.x.patch660 bytescangeceiro
PASSED: [[SimpleTest]]: [MySQL] 35,645 pass(es).
[ View ]
#5 drupal-1239410-8.x.patch660 bytescangeceiro
FAILED: [[SimpleTest]]: [MySQL] 35,636 pass(es), 9 fail(s), and 1 exception(s).
[ View ]
#3 drupal-1239410-7.x.patch569 bytescangeceiro
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch drupal-1239410-7.x.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]
#2 drupal-1239410-8.x.patch589 bytescangeceiro
PASSED: [[SimpleTest]]: [MySQL] 35,644 pass(es).
[ View ]

Comments

Version:8.x-dev» 7.x-dev

same for d7, this causes unwanted issues with drupal queue and long running cronjobs. One could also log the REQUEST_TIME in an additional field, but from my point of view timestamp should contain the time the function has been called.

Version:7.x-dev» 8.x-dev
Status:Active» Needs review
StatusFileSize
new589 bytes
PASSED: [[SimpleTest]]: [MySQL] 35,644 pass(es).
[ View ]

attached is a patch for d8

StatusFileSize
new569 bytes
FAILED: [[SimpleTest]]: [MySQL] Unable to apply patch drupal-1239410-7.x.patch. Unable to apply patch. See the log in the details link for more information.
[ View ]

and a backport to d7

Status:Needs review» Needs work

Makes sense, but we should add a comment so this doesn't get reverted again later.

StatusFileSize
new660 bytes
FAILED: [[SimpleTest]]: [MySQL] 35,636 pass(es), 9 fail(s), and 1 exception(s).
[ View ]

like so?

Status:Needs work» Needs review

status change

Status:Needs review» Needs work

The last submitted patch, drupal-1239410-8.x.patch, failed testing.

StatusFileSize
new660 bytes
PASSED: [[SimpleTest]]: [MySQL] 35,645 pass(es).
[ View ]

reroll of patch.

Status:Needs work» Needs review

Status:Needs review» Reviewed & tested by the community

Tested an working.

Status:Reviewed & tested by the community» Needs work

+      'timestamp'   => time(), // Request time isn't accurate for long processes.  Use time() instead

This comment doesn't confirm to the coding standards, it should be above the line and be a full sentence with a period at the end. See http://drupal.org/coding-standards

Status:Needs work» Needs review
StatusFileSize
new667 bytes
PASSED: [[SimpleTest]]: [MySQL] 41,106 pass(es).
[ View ]

Move the comment above the line.

Status:Needs review» Needs work

The last submitted patch, 1239410-12.patch, failed testing.

Status:Needs work» Needs review

#12: 1239410-12.patch queued for re-testing.

#12: 1239410-12.patch queued for re-testing.

#12: 1239410-12.patch queued for re-testing.

Category:feature» bug
Status:Needs review» Reviewed & tested by the community

Version:8.x-dev» 7.x-dev
Status:Reviewed & tested by the community» Patch (to be ported)
Issue tags:+needs backport to D7

I think this makes sense, as a valid use of time(). Thanks!

Committed and pushed to 8.x. Probably makes sense to backport to 7.x, too.

Status:Patch (to be ported)» Needs review
StatusFileSize
new731 bytes
PASSED: [[SimpleTest]]: [MySQL] 39,407 pass(es).
[ View ]

Status:Needs review» Reviewed & tested by the community

Same patch as D8.

Status:Reviewed & tested by the community» Fixed

Automatically closed -- issue fixed for 2 weeks with no activity.