Now that #326197: Empty data for latest week is fixed and deployed, there are a handful of cleanups to the new project-usage-process.php script I'd like to do:

A) The log messages when each process is completed should print out exactly how long each step took. We can figure out minute granularity from the watchdog, but it'd be nice to see seconds and just have it right there in the message.

B) The log messages about removing old data that timed out should include the number of rows effected.

C) The error messages when it fails to insert something should print out the SQL of the failed query.

Comments

dww’s picture

Status: Active » Needs review
StatusFileSize
new9.55 KB

Totally untested, but I think this will do it.

dww’s picture

Tested it and found some bugs in the previous patch. Running this one on p.d.o using the mysqldumps from before we processed the 6 week backlog of weekly data (along with #342546-2: Optimizing processing usage data) to see it all in action on real data. If that all looks good, and the resulting pages look the same as what's on d.o, I'll commit this.

dww’s picture

The daily processing finished on p.d.o and the messages look good (although the story they reveal is unfortunate):

  • Starting to process daily usage data for 2008-12-04.
  • Assigned API version term IDs for 297519 rows (12 sec).
  • Assigned project and release node IDs to 303329 rows (40 sec).
  • Moved usage from raw to daily: 1567730 rows added to {project_usage_day}, 1568706 rows deleted from {project_usage_raw} (1 min 25 sec).
  • Removed 25243498 old daily rows (5 min 23 sec).
  • Completed daily usage data processing (total time: 7 min 40 sec).

(The timestamps on the watchdog messages themselves agree it it was 7 minutes total...)

There was 1 minor bug in the log messages for the weekly processing, but otherwise those look ok: I ended up having the p.d.o DB in an inconsistent state, so things don't make normal sense, but here's a sample of the messages, anyway (at least we get to see the SQL query error messages in their full glory):

  • Starting to process weekly usage data.
  • Computed weekly project tallies for 2008-10-19 for 0 projects (31 sec).
  • Computed weekly release tallies for 2008-10-19 for 0 releases (23 sec).
  • Computed weekly project tallies for 2008-10-26 for 0 projects (16 sec).
  • Computed weekly release tallies for 2008-10-26 for 0 releases (16 sec).
  • Computed weekly project tallies for 2008-11-02 for 3308 projects (6 sec).
  • Computed weekly release tallies for 2008-11-02 for 7766 releases (5 sec).
  • Computed weekly project tallies for 2008-11-09 for 3477 projects (30 sec).
  • Query failed inserting weekly release tallies for 2008-11-09, query: INSERT INTO {project_usage_week_release} (nid, timestamp, count) SELECT nid, 1226188800, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= 1226188800 AND timestamp < 1226793600 AND nid <> 0 GROUP BY nid (9 sec).
  • Query failed inserting weekly project tallies for 2008-11-16, query: INSERT INTO {project_usage_week_project} (nid, timestamp, tid, count) SELECT pid, 1226793600, tid, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= 1226793600 AND timestamp < 1227398400 AND pid <> 0 GROUP BY pid, tid (7 sec).
  • Query failed inserting weekly release tallies for 2008-11-16, query: INSERT INTO {project_usage_week_release} (nid, timestamp, count) SELECT nid, 1226793600, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= 1226793600 AND timestamp < 1227398400 AND nid <> 0 GROUP BY nid (9 sec).
  • Query failed inserting weekly project tallies for 2008-11-23, query: INSERT INTO {project_usage_week_project} (nid, timestamp, tid, count) SELECT pid, 1227398400, tid, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= 1227398400 AND timestamp < 1228003200 AND pid <> 0 GROUP BY pid, tid (24 sec).
  • Query failed inserting weekly release tallies for 2008-11-23, query: INSERT INTO {project_usage_week_release} (nid, timestamp, count) SELECT nid, 1227398400, COUNT(DISTINCT site_key) FROM {project_usage_day} WHERE timestamp >= 1227398400 AND timestamp < 1228003200 AND nid <> 0 GROUP BY nid (15 sec).
  • Removed !rows (!delta).
  • Removed 0 old weekly release rows (0 sec).
  • Completed weekly usage data processing (total time: 3 min 12 sec).

That "Removed !rows (!delta)." is the dumb bug mentioned above, fixed with the attached patch.

Any final objections to the approach taken in this patch before I commit?

dww’s picture

Status: Needs review » Fixed

Committed to HEAD, DRUPAL-5, and deployed on d.o and p.d.o.

drewish’s picture

i'd love to see a followup that logs the db error message.

drewish’s picture

Status: Fixed » Needs review
StatusFileSize
new5.63 KB

here's a follow up.

dww’s picture

Mostly looks good, with a few adjustments. I'm resetting p.d.o so I can try running this again and see how it looks.

dww’s picture

Heh, this time, without the PHP syntax error. ;)

drewish’s picture

Status: Needs review » Needs work

i think the whole last db error message isn't feasible. when the query fails _db_query() calls trigger_error() which in turn invokes drupal_error_handler() which calls watchdog() which in turn ends up writing a record and overwriting the last error message. i think logging the queries is a good idea though.

perhaps we can do a full clone of d.o to p.d.o and run this against a clean slate?

dww’s picture

Status: Needs work » Fixed

Removed the attempts to capture and print the SQL errors, committed to HEAD + DRUPAL-5, and deployed on d.o and p.d.o.

Status: Fixed » Closed (fixed)

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