1576470 - Intermittent iscript.exceptions.IScriptError: ('%s in %s exited %s!\n%s', ['sudo', 'su', 'notary1', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/0-app_path0.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754580.0" -

Status: RESOLVED FIXED

(Release Engineering :: Release Automation, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=263387755&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/AItt6OUlTa-UzOF_c-H5ug/runs/0/artifacts/public/logs/live_backing.log

---

2019-08-25 11:31:00,702 - scriptworker_client.utils - INFO - adding: Firefox Nightly.app/Contents/Library/LaunchServices/ (stored 0%)
2019-08-25 11:31:00,709 - scriptworker_client.utils - INFO - ['zip', '-r', '/builds/scriptworker/work/4-app_path4.zip', 'Firefox Nightly.app'] in /builds/scriptworker/work/4 exited 0
2019-08-25 11:31:00,710 - scriptworker_client.utils - INFO - adding: Firefox Nightly.app/Contents/Library/LaunchServices/org.mozilla.updater (deflated 59%)
2019-08-25 11:31:00,710 - scriptworker_client.utils - INFO - adding: Firefox Nightly.app/Contents/Info.plist (deflated 81%)
2019-08-25 11:31:00,710 - scriptworker_client.utils - INFO - adding: Firefox Nightly.app/Contents/PkgInfo (stored 0%)
2019-08-25 11:31:00,754 - scriptworker_client.utils - INFO - ['zip', '-r', '/builds/scriptworker/work/1-app_path1.zip', 'Firefox Nightly.app'] in /builds/scriptworker/work/1 exited 0
2019-08-25 11:31:00,755 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary1', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/0-app_path0.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754580.0" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:00,760 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary2', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/1-app_path1.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754784.1" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:00,767 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary3', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/2-app_path2.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754830.2" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:00,777 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary4', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/3-app_path3.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754859.3" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:00,792 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary5', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/4-app_path4.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754924.4" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:00,808 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:00,820 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 14.630120503057505 seconds before retry
2019-08-25 11:31:00,831 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:00,839 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 12.095981322394598 seconds before retry
2019-08-25 11:31:00,851 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:00,859 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 11.175493604444151 seconds before retry
2019-08-25 11:31:00,871 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:00,879 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 12.729726748831565 seconds before retry
2019-08-25 11:31:00,890 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:00,898 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 12.741316787155569 seconds before retry
2019-08-25 11:31:12,046 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary5', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/4-app_path4.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754924.4" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:12,083 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:12,091 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 28.02986643143467 seconds before retry
2019-08-25 11:31:12,946 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary4', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/3-app_path3.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754859.3" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:12,983 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:12,991 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 28.495467475775243 seconds before retry
2019-08-25 11:31:13,620 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary3', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/2-app_path2.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754830.2" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:13,643 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary2', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/1-app_path1.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754784.1" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:13,658 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:13,667 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 26.8810839730211 seconds before retry
2019-08-25 11:31:13,683 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:13,690 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 21.724321410280435 seconds before retry
2019-08-25 11:31:15,461 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary1', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/0-app_path0.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754580.0" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:15,498 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:15,505 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 23.831123386868242 seconds before retry
2019-08-25 11:31:35,426 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary2', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/1-app_path1.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754784.1" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:35,463 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:35,471 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 46.07814591976577 seconds before retry
2019-08-25 11:31:39,347 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary1', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/0-app_path0.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754580.0" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:39,384 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:39,392 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 56.32213895411052 seconds before retry
2019-08-25 11:31:40,132 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary5', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/4-app_path4.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754924.4" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:40,169 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:40,177 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 51.875345764396 seconds before retry
2019-08-25 11:31:40,559 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary3', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/2-app_path2.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754830.2" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:40,596 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:40,603 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 54.46659450663209 seconds before retry
2019-08-25 11:31:41,498 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary4', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/3-app_path3.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754859.3" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:31:41,534 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:31:41,542 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 56.396845772158116 seconds before retry
2019-08-25 11:32:21,561 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary2', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/1-app_path1.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754784.1" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:32:21,598 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:32:21,606 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 85.59856295497092 seconds before retry
2019-08-25 11:32:32,064 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary5', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/4-app_path4.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754924.4" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:32:32,101 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:32:32,109 - scriptworker_client.aio - DEBUG - retry_async: run_command: sleeping 80.46497449012477 seconds before retry
2019-08-25 11:32:35,082 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary3', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/2-app_path2.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754830.2" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:32:35,119 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
....
2019-08-25 11:44:23,569 - scriptworker_client.aio - WARNING - retry_async: run_command: too many retries!
2019-08-25 11:44:33,812 - scriptworker_client.utils - INFO - Running ['sudo', 'su', 'notary3', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/2-app_path2.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754830.2" -u [e-mail] --asc-provider MozillaCorporation --password ********'] in /builds/scriptworker ...
2019-08-25 11:44:33,849 - scriptworker_client.utils - INFO - sudo: no tty present and no askpass program specified
2019-08-25 11:44:33,867 - scriptworker_client.aio - WARNING - retry_async: run_command: too many retries!
2019-08-25 11:44:33,867 - scriptworker_client.client - ERROR - Failed to run async_main
Traceback (most recent call last):
File "/builds/scriptworker/scriptworker-scripts/scriptworker_client/src/scriptworker_client/client.py", line 156, in _handle_asyncio_loop
await async_main(config, task)
File "/builds/scriptworker/scriptworker-scripts/iscript/src/iscript/script.py", line 47, in async_main
await notarize_behavior(config, task)
File "/builds/scriptworker/scriptworker-scripts/iscript/src/iscript/mac.py", line 1187, in notarize_behavior
config, key_config, all_paths, path_attr="zip_path"
File "/builds/scriptworker/scriptworker-scripts/iscript/src/iscript/mac.py", line 836, in wrap_notarization_with_sudo
await raise_future_exceptions(futures)
File "/builds/scriptworker/scriptworker-scripts/scriptworker_client/src/scriptworker_client/aio.py", line 55, in raise_future_exceptions
raise exceptions[0]
File "/builds/scriptworker/scriptworker-scripts/scriptworker_client/src/scriptworker_client/aio.py", line 154, in retry_async
return await func(*args, **kwargs)
File "/builds/scriptworker/scriptworker-scripts/scriptworker_client/src/scriptworker_client/utils.py", line 230, in run_command
"%s in %s exited %s!\n%s", log_cmd, cwd, exitcode, log_contents
iscript.exceptions.IScriptError: ('%s in %s exited %s!\n%s', ['sudo', 'su', 'notary1', '-c', 'xcrun altool --notarize-app -f /builds/scriptworker/work/0-app_path0.zip --primary-bundle-id "org.mozilla.firefox-mac-nightly.1566732660.754580.0" -u [e-mail] --asc-provider MozillaCorporation --password ********'], '/builds/scriptworker', 1, '')
exit code: 1

Comment 1

[Intermittent Failures Robot]

4 failures in 5073 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform breakdown:

• osx-shippable: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-08-19&endday=2019-08-25&tree=all

Comment 2

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

This is limited to mac-v3-signing2, which I've quarantined.

Aki, do you know if anyone was working on this machine ?

Comment 3

[Aki Sasaki (not active)]

We moved it (uptime 4 days). For some reason we lost our sudoers changes. Once I put those back, it seems to be working, which is good. We lost the sudoers changes in the first place, which isn't great.

I put it back into rotation, but we should keep our eyes on it.

Comment 4

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

This will be due to /Library/LaunchDaemons/com.mozilla.atboot_puppet.plist running puppet on boot. The logs in /var/log/puppet confirm that it ran and updated sudoers, although we could do with some proper timestamps in there.

We also rebooted dep-mac-v3-signing1.srv.releng.mdc1 in bug 1575615 but it doesn't need to sudo to dep.

Comment 5

[Intermittent Failures Robot]

12 failures in 5047 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4
• mozilla-esr60: 1
• mozilla-esr68: 3
• mozilla-beta: 2
• mozilla-release: 2

Platform breakdown:

• osx-shippable: 11
• osx-cross: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-08-26&endday=2019-09-01&tree=all

Comment 6

[Intermittent Failures Robot]

11 failures in 3801 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 11

Platform breakdown:

• osx-shippable: 11

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-10-07&endday=2019-10-13&tree=all

Comment 7

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

The failures are all on mac-v3-signing8 which has been used as as testbed for puppet changes. It's currently quarantined to avoid further bustage.

Comment 8

[Intermittent Failures Robot]

2 failures in 3964 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2

Platform breakdown:

• osx-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-10-14&endday=2019-10-20&tree=all

Comment 9

[Intermittent Failures Robot]

6 failures in 4314 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 6

Platform breakdown:

• osx-shippable: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-10-28&endday=2019-11-03&tree=all

Comment 10

[Intermittent Failures Robot]

2 failures in 4850 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2

Platform breakdown:

• osx-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-11-04&endday=2019-11-10&tree=all

Comment 11

[Intermittent Failures Robot]

4 failures in 4207 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• mozilla-release: 1
• mozilla-beta: 1

Platform breakdown:

• osx-shippable: 3
• osx-cross-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-11-11&endday=2019-11-17&tree=all

Comment 12

[Intermittent Failures Robot]

1 failures in 4867 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• osx-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2019-12-09&endday=2019-12-15&tree=all

Comment 13

[Intermittent Failures Robot]

4 failures in 5233 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr68: 1
• mozilla-beta: 3

Platform breakdown:

• osx-shippable: 3
• osx-cross-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2020-02-24&endday=2020-03-01&tree=all

Comment 14

[Aki Sasaki (not active)]

mac-v3-signing{1,2} had extra cltbld entries in their sudoers files.... cleaned up, puppet isn't running. Not sure about the others. The fact that it was a spike tells me it's possible that it was due to manual maintenance, but I don't see a login at that time in last. Seems like this is rarer than before, since the previous comment is 3 months ago.

Comment 15

[Intermittent Failures Robot]

1 failures in 5276 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform breakdown:

• osx-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576470&startday=2020-05-04&endday=2020-05-10&tree=all

Comment 16

[Aki Sasaki (not active)]

I think we've stabilized here with puppet making our updates more standardized.