notarytool takes a long time (2h+) breaking our CI/CD pipeline

Hi,

Since about 2 weeks notarytool is not very reliable on our CI/CD server. The tool either exists without printing any reason (killed by a signal; not caused by timeout - we have 6h timeouts and the tool gets killed after about 30 mins) or the process takes a very long time e.g. 2h to complete.

We use the same pipeline since at least 2 years and we did not have this problem before.

Some problematic calls:

    createdDate: 2025-01-15T14:50:22.545Z
    id: ca0faad3-789a-4842-a8c9-14aa7c2297a9
    name: xxxxxx
    status: In Progress
    --------------------------------------------------
    createdDate: 2025-01-15T14:33:06.813Z
    id: 22df0da8-70de-4dd9-935d-a26055242014
    name: xxxxxx
    status: In Progress
    --------------------------------------------------
    createdDate: 2025-01-15T14:18:36.436Z
    id: 5729b836-69f0-4526-b1d2-7743bd4d57a6
    name: xxxxxx
    status: In Progress
    --------------------------------------------------
    createdDate: 2025-01-15T14:18:31.716Z
    id: 58f3c7a1-96bd-4f5d-8a3c-6860f925659e
    name: xxxxxx
    status: In Progress

Can anyone check why the tool is taking now way more time than before to process a submission? The app that we are notarizing did not change that much.

Since about 2 weeks notarytool

There was a recent outage on the notary service (see this thread) but it was resolved quickly. The fact that you’ve been having problems for 2 weeks suggests that something else in in play.

Regarding your issue, do you only see this problem on your CI/CD server? If you attempt to notarise from your desk, do you encounter the same issue?

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Hi, thanks for answering.

So far I have only managed to reproduce it twice on my macbook - in those runs the notary tool took a long time to execute. Once I managed to run notarytool with verbose logging, there was no errors - only waiting for the service to process the request.

Example part of the logs:

[16:46:07.911Z] Info [API] Preparing GET request to URL: https://appstoreconnect.apple.com/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9?, Parameters: [:], Custom Headers: private<Dictionary<String, String>>
[16:46:07.912Z] Debug [AUTHENTICATION] Using cached token value for app-specific password request: EDITED:edited@example.com
[16:46:07.913Z] Debug [AUTHENTICATION] Authenticating request to '/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9' with WebServices Token. AppleID: edited@example.com, Team ID: EDITED, Token: private<String>
[16:46:07.914Z] Debug [TASKMANAGER] Starting Task Manager loop to wait for asynchronous HTTP calls.
[16:46:08.456Z] Debug [API] Received response status code: 200, message: no error, URL: https://appstoreconnect.apple.com/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9?, Correlation Key: UYBCFOJLQHV5S7UONBMYTGRQ5M
[16:46:08.456Z] Debug [TASKMANAGER] Completed Task with ID 351 has received a parsable response.
[16:46:08.456Z] Debug [TASKMANAGER] Ending Task Manager loop.
[16:46:08.456Z] Info [API] Received new status: In Progress
[16:46:08.457Z] Info [API] Waiting 20 seconds before next poll...
[16:46:28.462Z] Info [API] Preparing GET request to URL: https://appstoreconnect.apple.com/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9?, Parameters: [:], Custom Headers: private<Dictionary<String, String>>
[16:46:28.463Z] Debug [CACHE] Cached value will expire in the next 120 seconds, removing key: EDITED:edited@example.com
[16:46:28.464Z] Debug [AUTHENTICATION] Delaying current request to refresh app-specific password token.
[16:46:28.465Z] Info [API] Preparing GET request to URL: https://appstoreconnect.apple.com/notary/v2/asp?, Parameters: [:], Custom Headers: private<Dictionary<String, String>>
[16:46:28.465Z] Debug [AUTHENTICATION] Authenticating request to '/notary/v2/asp' with Basic Auth. Username: edited@example.com, Password: private<String>, Team ID: EDITED
[16:46:28.467Z] Debug [TASKMANAGER] Starting Task Manager loop to wait for asynchronous HTTP calls.
[16:46:29.114Z] Debug [API] Received response status code: 200, message: no error, URL: https://appstoreconnect.apple.com/notary/v2/asp?, Correlation Key: QQOLNQPZOCJI77EA5AY557EU5E
[16:46:29.115Z] Debug [TASKMANAGER] Completed Task with ID 353 has received a parsable response.
[16:46:29.115Z] Debug [TASKMANAGER] Ending Task Manager loop.
[16:46:29.115Z] Info [AUTHENTICATION] Caching retrieved app-specific password token. ID: EDITED:edited@example.com, token: private<String>
[16:46:29.115Z] Debug [AUTHENTICATION] Authenticating request to '/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9' with WebServices Token. AppleID: edited@example.com, Team ID: EDITED, Token: private<String>
[16:46:29.116Z] Debug [TASKMANAGER] Starting Task Manager loop to wait for asynchronous HTTP calls.
[16:46:29.729Z] Debug [API] Received response status code: 200, message: no error, URL: https://appstoreconnect.apple.com/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9?, Correlation Key: RREKIITO7TMYXW4QHEKSGFMFNY
[16:46:29.730Z] Debug [TASKMANAGER] Completed Task with ID 352 has received a parsable response.
[16:46:29.730Z] Debug [TASKMANAGER] Ending Task Manager loop.
[16:46:29.730Z] Info [API] Received new status: In Progress
[16:46:29.730Z] Info [API] Waiting 20 seconds before next poll...
[16:46:49.736Z] Info [API] Preparing GET request to URL: https://appstoreconnect.apple.com/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9?, Parameters: [:], Custom Headers: private<Dictionary<String, String>>
[16:46:49.737Z] Debug [AUTHENTICATION] Using cached token value for app-specific password request: EDITED:edited@example.com
[16:46:49.737Z] Debug [AUTHENTICATION] Authenticating request to '/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9' with WebServices Token. AppleID: edited@example.com, Team ID: EDITED, Token: private<String>
[16:46:49.739Z] Debug [TASKMANAGER] Starting Task Manager loop to wait for asynchronous HTTP calls.
[16:46:50.188Z] Debug [API] Received response status code: 200, message: no error, URL: https://appstoreconnect.apple.com/notary/v2/submissions/ca0faad3-789a-4842-a8c9-14aa7c2297a9?, Correlation Key: U2URNNLKP4VRCALY4I3TC37RCE
[16:46:50.188Z] Debug [TASKMANAGER] Completed Task with ID 354 has received a parsable response.
[16:46:50.189Z] Debug [TASKMANAGER] Ending Task Manager loop.

The entire log looks like this - just waiting for the status.

On our CI/CD (we use GitHub Actions for our project) notarization usually takes about 20mins. It was only recently that notarization either took a very long time (2h) or the tool just crashed without printing anything to console.

Since about the last 24h everything seems to be working again. But we still want to investigate in case the problem returns.

Hmmm, I’m not sure what’s going on here, but let’s start with this:

or the tool just crashed without printing anything to console.

Did that generate a crash report? If so, please post it here. See Posting a Crash Report for advice on how to do that.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

notarytool takes a long time (2h+) breaking our CI/CD pipeline
 
 
Q