513763 - Create a log of generated complete/partial patches

Status: RESOLVED FIXED

(Release Engineering :: General, defect, P1)

Description

[Chris Cooper [:coop] (he/him)]

Updates aside, the update generation script doesn't produce much useful output. Current issues we're trying to debug are:

* did an update get generated for a given locale on a particular day?
* when did a given update get generated in relation to the source mar, i.e. what was the turnaround time from when the source complete.mar was posted to when the partial patch was generated?

This should become a non-issue with bug 511967, but in the interim, some simple logging in patch-packager.pl will give us a quick health check on the update generation.

Basic pieces of info we need:
* when update was created -> sortable timestamp (YYYYMMDDhhmmss)
* when source mar was created -> sortable timestamp (based on file creation time of complete mar?)
* branch/version
* locale
* from build ID
* to build ID

Comment 1

[Chris Cooper [:coop] (he/him)]

Depending on how we want to look at these stats, we could break the logs up by branch or by day. We could also just keep appending to the same log file and logrotate it.

Comment 2

[Armen [:armenzg]]

Attachment: logs which updates gets generated locally by grouping the logs per day

Comment 3

[Armen [:armenzg]]

Comment on attachment 398211 [details] [diff] [review]
logs which updates gets generated locally by grouping the logs per day

I will be running this overnight and see how it behaves

Comment 4

[Armen [:armenzg]]

Attachment: logs which updates gets generated locally by grouping the logs per day (v1)

This is running on staging-nightly-updates. I have added the timestamping to wget since we were getting incorrect date/time for the files and using mtime rather than ctime which is the correct one to use.
I am also using get_build_info instead of the regex matching.
The delta between when the locale was created and when the update is pushed live is calculated.

This is how the log looks like:
[cltbld@staging-nightly-updates app]$ cat /tmp/20090904.log 
This file logs the updates that have been generated following this format:
currentTime; elapsed time since locale's generation; product; version; branch; locale; fromBuildID;toBuildID;
200909041216 53:38:42 Firefox mozilla-central en-US 20090901043907 20090902045931

I have added as well on staging-nightly-updates a cron job that gets called few minutes before midnight that looks like this:
[cltbld@staging-nightly-updates app]$ cat /builds/nightly-partial-generation/app/daily-update-report.sh 
#!/bin/sh
#RCPT="[e-mail]"
RCPT="[e-mail]"

mail -s "AUS2 Daily report" [e-mail] < /tmp/`date +"%Y%m%d"`.log

Comment 5

[Chris Cooper [:coop] (he/him)]

Comment on attachment 398753 [details] [diff] [review]
logs which updates gets generated locally by grouping the logs per day (v1)

Um, is this the right patch? There's no logging code here.

Comment 6

[Armen [:armenzg]]

Attachment: logs which updates gets generated locally by grouping the logs per day (v1)

Wrong upload! Sorry for that

Comment 7

[Nick Thomas [:nthomas] (UTC+12)]

Comment on attachment 398769 [details] [diff] [review]
logs which updates gets generated locally by grouping the logs per day (v1)

>--- /home/cltbld/release/patcher/patch-packager.pl      2009-09-04 01:57:27.000000000 -0700
>+sub log_processed_locale {
...
>+    my $elapsed_time = "$hours_elapsed:$time_elapsed_array[1]:$time_elapsed_array[0]";

You can use a sprintf to make sure the hours and minutes are zero-padded, eg 0:03:05 instead of 0:3:5. Like this
  my $elapsed_time = sprintf("%d:%02d:%02d", $hours_elapsed, $time_elapsed_array[1], $time_elapsed_array[0]);

>+    print "elapsed time:\t\t\t$hours_elapsed:$time_elapsed_array[1]:$time_elapsed_array[0]\n"
>+          if ($verbose); 

Use $elapsed_time here since you already constructed it.
    
>+        die "create_complete_patch: 'wget --timestamping -O to.mar $to_url' returned non-zero!";

You can leave the --timestamping out of this error message, it doesn't add anything.

>-    #system("wget --progress=dot:mega -O from.mar $from_url >&/dev/null");
>-    $rc = system("wget --progress=dot:mega -O from.mar $from_url");
>+    #system("wget --timestamping --progress=dot:mega -O from.mar $from_url >&/dev/null");
>+    $rc = system("wget --timestamping --progress=dot:mega -O from.mar $from_url");

The #system line can just get removed, it's just an leftover.

>+        die "create_partial_patch: 'wget --timestamping -O from.mar $from_url' returned non-zero!";

As above, no need to modify this comment.

>     # double check we have the to.mar from create_complete_patch()
>     if ( ! -r "to.mar" ) {
>         die "create_partial_patch: to.mar doesn't exist!";
>     }
> 
>+    # The creation time of the today's complete mar file gives us
>+    # an idea of when the locale was processed and to determine
>+    # how much time passed since it was created until the update is live
>+    my $completeMAR = "$patchdir/to.mar";
>+    my $mtime = (stat($completeMAR))->mtime;

'my $mtime = (stat("to.mar"))->mtime;' would be fine given the code just above, no ?

These are mostly nits but r- for the time display issue.

Comment 8

[Chris Cooper [:coop] (he/him)]

Comment on attachment 398769 [details] [diff] [review]
logs which updates gets generated locally by grouping the logs per day (v1)

Nick's already covered the display errors. Canceling review.

Comment 9

[Armen [:armenzg]]

Attachment: logs which updates gets generated locally by grouping the logs per day

Comment 10

[Armen [:armenzg]]

Attachment: logs which updates gets generated locally by grouping the logs per day (v2)

I addressed all your comments but my own comment. I have removed "branch;" and added a space between the two buildid's on the header of the log file.

Comment 11

[Armen [:armenzg]]

Attachment: emails daily log of the updates that have been generated

This line in the cronjob is to be added to make it work:
# email the daily log of updates pushed live
55 23 * * *     /builds/nightly-partial-generation/app/daily-update-report.sh

Comment 12

[Nick Thomas [:nthomas] (UTC+12)]

Comment on attachment 399263 [details] [diff] [review]
logs which updates gets generated locally by grouping the logs per day (v2)

>+    my $elapsed_time = "$hours_elapsed:$time_elapsed_array[1]:$time_elapsed_array[0]";
>+    my $elapsed_time = sprintf("%d:%02d:%02d", $hours_elapsed, 

r+ if the first assignment is removed on checkin.

Comment 13

[Nick Thomas [:nthomas] (UTC+12)]

Comment on attachment 399265 [details] [diff] [review]
emails daily log of the updates that have been generated

A shame to not use $notification_email from the cfg, but it's not worth converting this to perl just for that.

Comment 14

[Chris Cooper [:coop] (he/him)]

Comment on attachment 399263 [details] [diff] [review]
logs which updates gets generated locally by grouping the logs per day (v2)

Checking in patch-packager.pl;
/mofo/release/patcher/patch-packager.pl,v  <--  patch-packager.pl
new revision: 1.27; previous revision: 1.26
done

Comment 15

[Chris Cooper [:coop] (he/him)]

Comment on attachment 399265 [details] [diff] [review]
emails daily log of the updates that have been generated

Checking in daily-update-report.pl;
/mofo/release/patcher/daily-update-report.pl,v  <--  daily-update-report.pl
initial revision: 1.1
done

Comment 16

[Armen [:armenzg]]

(In reply to comment #13)
> (From update of attachment 399265 [details] [diff] [review])
> A shame to not use $notification_email from the cfg, but it's not worth
> converting this to perl just for that.
>
Happy times! We turned into a perl script that uses it!

The changes have been deployed on prometheus-vm and staging-nightly-updates.

The first is already there:
[cltbld@prometheus-vm cltbld]$ cat /tmp/20090909.log 
This file logs the updates that have been generated following this format:
currentTime; elapsed time since locale's generation; product; version; locale; fromBuildID; toBuildID;
200909090656 1:40:16 Firefox mozilla-1.9.2 zh-CN 20090908033644 20090909033859
200909090657 1:52:09 Firefox mozilla-1.9.2 zh-TW 20090908033644 20090909033859

Comment 17

[Armen [:armenzg]]

Running well.

Comment 18

[Nick Thomas [:nthomas] (UTC+12)]

In some (very weird) way the changes here caused bug 515542 ("size=" in partial snippets). While I should have backed it out I have just used cvs up -D on prometheus-vm to get the code before this landed.

I'd also note that the log should also include the platform so that we can tell Linux from Mac etc.

Comment 19

[Armen [:armenzg]]

The only thing that could be is the stat() function used to get the modification time that might require some closing/handling after that so it doesn't stay in a weird state the file being consulted.

I will look into it.

Comment 20

[Armen [:armenzg]]

Attachment: use stat()->size instead of stat()[7] and "platform" to logging

This:
http://perldoc.perl.org/functions/stat.html
is not the same as this:
http://perldoc.perl.org/File/stat.html
where (stat($path))[7] cannot be used but only this (stat($path))->size

This is running on staging-nightly-updates and I used "grep -rl 'size=$' aus/0/ | wc -l" to verify that it doesn't happen anymore.

Comment 21

[Chris Cooper [:coop] (he/him)]

Comment on attachment 399747 [details] [diff] [review]
use stat()->size instead of stat()[7] and "platform" to logging

>-         . "locale; fromBuildID; toBuildID;\n";
>+         . "platform: locale; fromBuildID; toBuildID;\n";

Colon show be a semicolon here for consistency.
 
>-    $size = (stat($path))[7];
>+    $size = (stat($path))->size;

Bah, I totally missed the module import of File::stat on the first-pass review. When I see stat() calls, I just assume the vanilla version.

r+, I can fix the nit on landing.

Comment 22

[Chris Cooper [:coop] (he/him)]

Comment on attachment 399747 [details] [diff] [review]
use stat()->size instead of stat()[7] and "platform" to logging

Updated the script on prometheus-vm and the release checkout on staging-nightly-updates.

Armen: you'll need to update your own checkouts (which are still the active scripts) on the staging box.

Checking in patch-packager.pl;
/mofo/release/patcher/patch-packager.pl,v  <--  patch-packager.pl
new revision: 1.29; previous revision: 1.28
done

Comment 23

[Armen [:armenzg]]

(In reply to comment #22)
> Armen: you'll need to update your own checkouts (which are still the active
> scripts) on the staging box.
>
done here as well

Sweet! one more down for real!