launchpad-reviewers team mailing list archive

[Stuart Bishop <stuart.bishop@xxxxxxxxxxxxx>]

Stuart Bishop has proposed merging lp:~stub/launchpad/pending-db-changes into lp:launchpad.

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)
Related bugs:
  #678289 log the time db patch application takes in developer accessible location
  https://bugs.launchpad.net/bugs/678289


Store and report database patch application times.

The reported times are the time spent running the actual SQL. There are also overheads involved, but this should be constant. Given a total of these times for a rollout, the actual time will be "num_nodes * (db_time + x * num_patches + y)", where x and y are as yet unknown constants representing overhead per patch and extra overhead (trusted.sql, comments.sql, merging new table replication set into main replication set etc.)
-- 
https://code.launchpad.net/~stub/launchpad/pending-db-changes/+merge/41691
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~stub/launchpad/pending-db-changes into lp:launchpad.

=== added file 'database/schema/patch-2208-01-1.sql'
--- database/schema/patch-2208-01-1.sql	1970-01-01 00:00:00 +0000
+++ database/schema/patch-2208-01-1.sql	2010-11-24 08:39:00 +0000
@@ -0,0 +1,10 @@
+SET client_min_messages=ERROR;
+
+ALTER TABLE LaunchpadDatabaseRevision
+    ADD start_time timestamp without time zone DEFAULT (
+        transaction_timestamp() AT TIME ZONE 'UTC'),
+    ADD end_time timestamp without time zone DEFAULT (
+        statement_timestamp() AT TIME ZONE 'UTC');
+
+INSERT INTO LaunchpadDatabaseRevision VALUES (2208, 01, 1);
+

=== modified file 'database/schema/upgrade.py'
--- database/schema/upgrade.py	2010-05-19 18:07:56 +0000
+++ database/schema/upgrade.py	2010-11-24 08:39:00 +0000
@@ -32,19 +32,65 @@
 
 def main():
     con = connect(options.dbuser)
+    patches = get_patchlist(con)
+
     if replication.helpers.slony_installed(con):
         con.close()
         if options.commit is False:
             parser.error("--dry-run does not make sense with replicated db")
         log.info("Applying patches to Slony-I environment.")
         apply_patches_replicated()
+        con = connect(options.dbuser)
     else:
         log.info("Applying patches to unreplicated environment.")
         apply_patches_normal(con)
 
+    report_patch_times(con, patches)
+
     return 0
 
 
+def to_seconds(td):
+    """Convert a timedelta to seconds."""
+    return td.days * (24*60*60) + td.seconds + td.microseconds/1000000.0
+
+
+def report_patch_times(con, todays_patches):
+    """Report how long it took to apply the given patches."""
+    cur = con.cursor()
+
+    todays_patches = [patch_tuple for patch_tuple, patch_file
+        in todays_patches]
+
+    cur.execute("""
+        SELECT
+            major, minor, patch, start_time, end_time - start_time AS db_time
+        FROM LaunchpadDatabaseRevision
+        WHERE start_time > CURRENT_TIMESTAMP AT TIME ZONE 'UTC'
+            - CAST('1 month' AS interval)
+        ORDER BY major, minor, patch
+        """)
+    for major, minor, patch, start_time, db_time in cur.fetchall():
+        if (major, minor, patch) in todays_patches:
+            continue
+        db_time = to_seconds(db_time)
+        start_time = start_time.strftime('%Y-%m-%d')
+        log.info(
+            "%d-%02d-%d applied %s in %0.1f seconds"
+            % (major, minor, patch, start_time, db_time))
+
+    for major, minor, patch in todays_patches:
+        cur.execute("""
+            SELECT end_time - start_time AS db_time
+            FROM LaunchpadDatabaseRevision
+            WHERE major = %s AND minor = %s AND patch = %s
+            """, (major, minor, patch))
+        db_time = cur.fetchone()[0]
+        log.info(
+            "%d-%02d-%d applied just now in %0.1f seconds",
+            major, minor, patch, to_seconds(db_time))
+
+
 def apply_patches_normal(con):
     """Update a non replicated database."""
     # trusted.sql contains all our stored procedures, which may