Azure / azure-functions-nodejs-worker

The Node.js worker for the Azure Functions runtime - https://functions.azure.com
MIT License
107 stars 44 forks source link

Tweak lstat bug retry logic #712

Closed ejizba closed 1 year ago

ejizba commented 1 year ago

Related to https://github.com/Azure/azure-functions-nodejs-worker/issues/693

I'm seeing evidence of the original retry logic helping in some cases, but the earliest the retry has ever helped is the 5th attempt and for the majority it's not until the 10th attempt that it actually works. For that reason, I'm spacing the attempts out more at the beginning and extending the overall time from about 25 seconds to 4.5 minutes. Lastly, I cleaned up the logs because it gets very cluttered especially if you have multiple functions in an app.

Here are example logs for an app that has 3 functions. Note the reduction in clutter and the timestamps

Before ``` [2023-08-14T20:56:14.353Z] Worker a405001c-43ea-4e14-988d-9e1229fc5400 received FunctionLoadRequest [2023-08-14T20:56:14.353Z] Worker a405001c-43ea-4e14-988d-9e1229fc5400 received FunctionLoadRequest [2023-08-14T20:56:14.353Z] Worker a405001c-43ea-4e14-988d-9e1229fc5400 received FunctionLoadRequest [2023-08-14T20:56:14.353Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.353Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.353Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.402Z] Retrying load of file "index.js". Attempt 2/10 [2023-08-14T20:56:14.402Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.402Z] Retrying load of file "index.js". Attempt 2/10 [2023-08-14T20:56:14.402Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.403Z] Retrying load of file "index.js". Attempt 2/10 [2023-08-14T20:56:14.403Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.504Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.504Z] Retrying load of file "index.js". Attempt 3/10 [2023-08-14T20:56:14.506Z] Retrying load of file "index.js". Attempt 3/10 [2023-08-14T20:56:14.506Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.506Z] Retrying load of file "index.js". Attempt 3/10 [2023-08-14T20:56:14.506Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.708Z] Retrying load of file "index.js". Attempt 4/10 [2023-08-14T20:56:14.708Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.708Z] Retrying load of file "index.js". Attempt 4/10 [2023-08-14T20:56:14.709Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.709Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:14.709Z] Retrying load of file "index.js". Attempt 4/10 [2023-08-14T20:56:15.107Z] Retrying load of file "index.js". Attempt 5/10 [2023-08-14T20:56:15.107Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:15.109Z] Retrying load of file "index.js". Attempt 5/10 [2023-08-14T20:56:15.109Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:15.109Z] Retrying load of file "index.js". Attempt 5/10 [2023-08-14T20:56:15.109Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:15.911Z] Retrying load of file "index.js". Attempt 6/10 [2023-08-14T20:56:15.913Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:15.913Z] Retrying load of file "index.js". Attempt 6/10 [2023-08-14T20:56:15.913Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:15.913Z] Retrying load of file "index.js". Attempt 6/10 [2023-08-14T20:56:15.914Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:17.512Z] Retrying load of file "index.js". Attempt 7/10 [2023-08-14T20:56:17.512Z] Retrying load of file "index.js". Attempt 7/10 [2023-08-14T20:56:17.512Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:17.512Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:17.512Z] Retrying load of file "index.js". Attempt 7/10 [2023-08-14T20:56:17.512Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:20.714Z] Retrying load of file "index.js". Attempt 8/10 [2023-08-14T20:56:20.714Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:20.714Z] Retrying load of file "index.js". Attempt 8/10 [2023-08-14T20:56:20.714Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:20.715Z] Retrying load of file "index.js". Attempt 8/10 [2023-08-14T20:56:20.715Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:27.116Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:27.116Z] Retrying load of file "index.js". Attempt 9/10 [2023-08-14T20:56:27.116Z] Retrying load of file "index.js". Attempt 9/10 [2023-08-14T20:56:27.117Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:27.117Z] Retrying load of file "index.js". Attempt 9/10 [2023-08-14T20:56:27.117Z] Warning: Failed to load file "index.js" with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:56:39.924Z] Retrying load of file "index.js". Attempt 10/10 [2023-08-14T20:56:39.924Z] Worker was unable to load function HttpTrigger1: 'UNKNOWN: unknown error, lstat 'D:\home'' [2023-08-14T20:56:39.926Z] Worker was unable to load function HttpTrigger2: 'UNKNOWN: unknown error, lstat 'D:\home'' [2023-08-14T20:56:39.926Z] Retrying load of file "index.js". Attempt 10/10 [2023-08-14T20:56:39.926Z] Retrying load of file "index.js". Attempt 10/10 [2023-08-14T20:56:39.926Z] Worker was unable to load function HttpTrigger3: 'UNKNOWN: unknown error, lstat 'D:\home'' ```
After ``` [2023-08-14T20:50:08.142Z] Worker d99508d0-7834-4fd0-b5f4-e2eb9ed971f7 received FunctionLoadRequest [2023-08-14T20:50:08.142Z] Worker d99508d0-7834-4fd0-b5f4-e2eb9ed971f7 received FunctionLoadRequest [2023-08-14T20:50:08.142Z] Worker d99508d0-7834-4fd0-b5f4-e2eb9ed971f7 received FunctionLoadRequest [2023-08-14T20:50:08.142Z] Warning: Failed to load file with error "UNKNOWN: unknown error, lstat 'D:\home'" [2023-08-14T20:50:08.639Z] Retrying file load. Attempt 2/10 [2023-08-14T20:50:09.641Z] Retrying file load. Attempt 3/10 [2023-08-14T20:50:11.641Z] Retrying file load. Attempt 4/10 [2023-08-14T20:50:15.643Z] Retrying file load. Attempt 5/10 [2023-08-14T20:50:23.647Z] Retrying file load. Attempt 6/10 [2023-08-14T20:50:39.648Z] Retrying file load. Attempt 7/10 [2023-08-14T20:51:11.652Z] Retrying file load. Attempt 8/10 [2023-08-14T20:52:15.659Z] Retrying file load. Attempt 9/10 [2023-08-14T20:54:23.667Z] Retrying file load. Attempt 10/10 [2023-08-14T20:54:23.668Z] Worker was unable to load function HttpTrigger1: 'UNKNOWN: unknown error, lstat 'D:\home'' [2023-08-14T20:54:23.671Z] Worker was unable to load function HttpTrigger2: 'UNKNOWN: unknown error, lstat 'D:\home'' [2023-08-14T20:54:23.671Z] Worker was unable to load function HttpTrigger3: 'UNKNOWN: unknown error, lstat 'D:\home'' ```