872316 - release runner doesn't include enough context for some errors

Status: RESOLVED FIXED

(Release Engineering :: Release Automation: Other, defect, P3)

Description

[Aki Sasaki (not active)]

This is a snippet from the release runner email, which is missing the actual mozconfig errors that needed fixing:

2013-05-14 16:20:15,744 : CRITICAL : Tests Failed! Not running sendchange!
2013-05-14 16:20:15,744 : CRITICAL : Failed tests (run with -b to skip) :
2013-05-14 16:20:15,744 : CRITICAL : verify_mozconfig
2013-05-14 16:20:15,762 - INFO - mark as failed Fennec-22.0b1-build1
2013-05-14 16:20:15,923 - INFO - mark as failed Firefox-22.0b1-build1
Traceback (most recent call last):
  File "release-runner.py", line 349, in <module>
    ssh_username=hg_username, ssh_key=hg_ssh_key)
  File "/home/cltbld/release-runner/tools/lib/python/util/hg.py", line 469, in apply_and_push
    changer(localrepo, 1)
  File "release-runner.py", line 338, in process_configs
    ['--dry-run'])
  File "/home/cltbld/release-runner/tools/lib/python/util/commands.py", line 40, in run_cmd
    return subprocess.check_call(cmd, **kwargs)
  File "/usr/lib64/python2.6/subprocess.py", line 498, in check_call
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['python', '../../buildbot-helpers/release_sanity.py', '--branch', 'mozilla-beta', '--username', '[e-mail]', '--version', '22.0b1', '--build-number', '1', '--release-config', 'release-firefox-mozilla-beta.py', '--skip-verify-configs', '--masters-json-file', 'http://hg.mozilla.org/build/tools/raw-file/default/buildfarm/maintenance/production-masters.json', '--configs-dir', 'buildbot-configs', '--configs-branch', 'production', '--bypass-l10n-dashboard-check', '--dry-run']' returned non-zero exit status 1

The full log is available on buildbot-master36 in /var/log/supervisor/release-runner.log
I'll sleep for 60 seconds before retry

Comment 1

[[e-mail] (:bhearsum)]

Bumping up the number of lines we grab from the log here might help:
https://github.com/mozilla/build-tools/blob/master/buildfarm/release/release-runner.sh#L28

No guarantee that you'll get every error though. If one locale fails at the start of release sanity and everything else passes, you might need to look 100 lines up. If you always include 100 lines of context, you may end up with output from a previous run. Maybe we should be logging to a different file on every run or something, so we can include the entire output?

Comment 2

[Aki Sasaki (not active)]

Including https://wiki.mozilla.org/Release:Release_Automation_on_Mercurial:Troubleshooting in the email (just the url) might help :)

Comment 3

[[e-mail] (:bhearsum)]

Better idea, from bug 1042056:
(In reply to Ben Hearsum [:bhearsum] from comment #2)
> (In reply to Rail Aliiev [:rail] from comment #1)
> > Maybe use last 1000 lines and attach as text? 100 won't be enough I bet.
> 
> Yeah, maybe. My only concern is that you may end up with context from a
> previous run of release runner. Maybe we can have max 1000, but walk
> backwards only until we see "Fetching release requests" to avoid getting a
> previous run?

Comment 4

[[e-mail] (:bhearsum)]

Attachment: crazy bash magic

Pete, in addition to Rail being away, you are our resident bash expert. Someone in #bash gave this to me, and it seems to be working. I'm not sure if there's caveats that I'm not aware of though. It seems to work fine on the current logs in buildbot-master81:/builds/releaserunner - so you can poke around that if you want some sample data. Please make sure not to run release-runner.sh itself though.

Comment 5

[Pete Moore [:pmoore][:pete]]

Just the name of the patch has got me all excited!!

Comment 6

[Pete Moore [:pmoore][:pete]]

Comment on attachment 8462801 [details] [diff] [review]
crazy bash magic

Review of attachment 8462801 [details] [diff] [review]:
-----------------------------------------------------------------

Awesome stuff. Nice to see you using sed. May it rule the world. Forever.

::: buildfarm/release/release-runner.sh
@@ +58,5 @@
>      sleep $SLEEP_TIME;
>  # Any other non-zero exit code is some other issue, and we should send mail
>  # about it.
>  elif [[ $RETVAL != 0 ]]; then
> +    # Super crazy sed magic below to grab everything from the last run.

Technically, this is not bash magic (e.g. you could run the same sed from csh) - it is wonderful, beautiful, and dignified sed magic!! :D

@@ +63,3 @@
>      (
>          echo "Release runner encountered a runtime error: "
> +        sed -n 'H;/Fetching release requests/x; ${;g;p;}' $LOGFILE

This works fine, but the I think h command would be better (clearer) than x, and some comments might help. 'x' is exchanging the hold and pattern space, but pattern space does not need to be updated (it is replaced as soon as next line is read anyway). 'h' instead just updates hold space with contents of pattern space, which is all that we need to do.

sed -n '
    # append each line to the hold space as we iterate through the file
    H
    # if we find "Fetching release requests" text somewhere in a line,
    # ditch hold space buffer and replace with just the new line read
    /Fetching release requests/ h
    # when we reach end of file ($) we need to output hold space
    $ {
        # copy hold space into pattern space
        g
        # print pattern space
        p
    }
'

Comment 7

[Pete Moore [:pmoore][:pete]]

As you see above, you can put comments directly in the sed code, which I think would make it more readable. Also see you can run the sed command over several lines, because bash allows you to open a string with a ' on one line, and close it several lines later with the closing '. With the formatting, and the commenting together, it might be clearer to a bash novice, what is going on.

Another point I forgot to mention - you could add a comment to explain the sed "-n" option, i.e. to prevent each pattern space being printed with each iteration, so the only output is when you reach the end of the file, and explicitly output the hold space (by first copying it to the pattern space, and then printing that - no command to directly print hold space in sed).

Comment 8

[Pete Moore [:pmoore][:pete]]

Lastly, if the log file could be *massive*, it may be cheaper to run
tail -r "${LOGFILE}" | sed -n '1,/Fetching release requests/p' | tail -r

If it isn't massive (i.e. hundreds of megabytes or more) you don't need to read ahead. :)

In this alternative implementation, tail -r is outputting the lines of the log file in reverse order, the sed is matching all lines up-to-and-including the first line containing "Fetching release requests", and the second tail -r is then reversing the output again, back into the correct order - so in the end you get the same thing - everything from the *last* line containing "Fetching release requests" to the end of the file.

Personally, I think the sed solution is prettier, but this may be more efficient (assuming tail -r is reading/outputting on the fly and does not read the entire file into memory before outputting content). Another advantage of this approach, is that when sed finishes, it will cut tail -r off - so if there are millions of lines in the file but only 10 to be read, shortly after tail -r has read the last 10 lines of the log file in reverse order, it will stop reading earlier ones. In the sed implementation it will read the entire log file, dumping each "run" into memory (into its hold space) even if it only outputs 1% of the log file in the end.

Comment 9

[[e-mail] (:bhearsum)]

Attachment: documented crazy sed magic

I actually find it easier to read this as a sed one liner...I also don't think I can embed docs because this is within a (), so I've put the docs above that. I even realized an edge case in writing them, wheee!

Comment 10

[Pete Moore [:pmoore][:pete]]

Comment on attachment 8463381 [details] [diff] [review]
documented crazy sed magic

Review of attachment 8463381 [details] [diff] [review]:
-----------------------------------------------------------------

Awesome. :)

Comment 11

[[e-mail] (:bhearsum)]

Comment on attachment 8463381 [details] [diff] [review]
documented crazy sed magic

Landed, and updated the checkout on bm81 to make it live.

Comment 12

[[e-mail] (:bhearsum)]

We won't be able to fully confirm this until we hit another error, but it's landed.