extension failures can sometimes take over an hour to get retried

[dougclayton]

For instance, this was observed with 2.2.18 upgraded to 2.2.26:

2018/07/19 18:13:13.339454 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Target handler state: enabled
2018/07/19 18:13:13.347322 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] [Enable] current handler state is: notinstalled
2018/07/19 18:13:13.490002 INFO Event: name=Microsoft.Azure.Extensions.CustomScript, op=Download, message=Download succeeded, duration=132
2018/07/19 18:13:13.490520 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Initialize extension directory
2018/07/19 18:13:13.491622 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Update settings file: 1.settings
2018/07/19 18:13:13.492289 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Install extension [bin/custom-script-shim install]
2018/07/19 18:13:14.496545 ERROR Event: name=Microsoft.Azure.Extensions.CustomScript, op=Install, message=[ExtensionError] Non-zero exit code: 1, bin/custom-script-shim install, duration=0
2018/07/19 18:13:14.590861 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Remove extension handler directory: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.0.6
2018/07/19 18:13:14.606529 INFO Event: name=WALinuxAgent, op=ProcessGoalState, message=Incarnation 1, duration=1374
2018/07/19 18:28:13.351674 INFO Agent WALinuxAgent-2.2.26 launched with command 'python -u bin/WALinuxAgent-2.2.26-py2.7.egg -run-exthandlers' is successfully running
2018/07/19 18:28:13.357100 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.2.26 launched with command 'python -u bin/WALinuxAgent-2.2.26-py2.7.egg -run-exthandlers' is suc
cessfully running, duration=0
2018/07/19 20:17:32.318822 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Target handler state: enabled
2018/07/19 20:17:32.320108 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] [Enable] current handler state is: notinstalled
2018/07/19 20:17:32.474781 INFO Event: name=Microsoft.Azure.Extensions.CustomScript, op=Download, message=Download succeeded, duration=153
2018/07/19 20:17:32.475263 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Initialize extension directory
2018/07/19 20:17:32.476400 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Update settings file: 1.settings
2018/07/19 20:17:32.476887 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Install extension [bin/custom-script-shim install]
2018/07/19 20:17:33.480842 INFO Event: name=Microsoft.Azure.Extensions.CustomScript, op=Install, message=Launch command succeeded: bin/custom-script-shim install, duration=1003

Note the gap in between each run: 1 hour and 45 minutes. Surely this should be re-run less than a minute after the first failure.
(This issue is not about the fact that the extension failed, just about how long it took to be re-run.)

[boumenot]

What does the status file indicate?
What distro are you running on the install failed? The install success rate (in our telemetry) is extremely high, so having a case that we can explore deeper would be great.

[hglkrijger]

Should be fixed in 2.2.31 with #1160