Processing file downloads failed: failed to download file: unexpected status code: actual=404 expected=200

Hi,

I'm running the custom template deployment from [
azure-quickstart-templates/nextflow-genomics-cluster-ubuntu](https://github.com/Azure/azure-quickstart-templates/tree/master/nextflow-genomics-cluster-ubuntu) which includes a Linux VM and a Linux-based VMSS.

Both operations (VM creation and VMSS creation) involves the CustomScriptExtension.
The scripts used for post-configuration are the same for VM and VMSS.
They have the same reference inside the template.

However, the deployment for VM is completed succesfully but for VMSS is ended with an error.

When checking resource group in Azure portal, VMSS is created successfully and shows activity (CPU, memory etc), in "Extensions" blade I can see my predefined extension, however the state is "Failed".
When clicking on "Failed" to see the details the following error is shown:
```
Message: VM has reported a failure when processing extension 'filesextension'.
Error message: "Enable failed: processing file downloads failed: failed to download file[1]: f
ailed to download file: unexpected status code: actual=404 expected=200"
More information on troubleshooting is available at https://aka.ms/VMExtensionCSELinuxTroubleshoot
```
Azure portal deployment error:

```
{
"status": "Failed",
"error": {
"code": "ResourceDeploymentFailure",
"message": "The resource operation completed with terminal provisioning state 'Failed'.",
"details": [
{
"code": "VMExtensionProvisioningError",
"message": "VM has reported a failure when processing extension 'filesextension'. Error message: \"Enable failed: processing file downloads failed: failed to download file[1]: failed to download file: unexpected status code: actual=404 expected=200\"\r\n\r\nMore information on troubleshooting is available at https://aka.ms/VMExtensionCSELinuxTroubleshoot "
}
]
}
}

```

Below are the required log files from the VM after the deployment:

**- /var/log/azure/custom-script/handler.log**

```+ /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension install
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 event=start
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 status="not reported for operation (by design)"
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 event="migrate to mrseq" error="Can't find out seqnum from /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status, not enough files."
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 event="created data dir" path=/var/lib/waagent/custom-script
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 event=installed
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 status="not reported for operation (by design)"
time=2020-04-22T04:21:26Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=1 event=end
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status/1.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension enable
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=start
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=pre-check
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="comparing seqnum" path=mrseq
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="seqnum saved" path=mrseq
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="reading configuration"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="read configuration"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="validating json schema"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="json schema valid"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="parsing configuration json"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="parsed configuration json"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="validating configuration logically"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="validated configuration"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="creating output directory" path=/var/lib/waagent/custom-script/download/1
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="created output directory"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 files=2
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 event="download start"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 retry=0 error="unexpected status code: actual=404 expected=200"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 retry=0 info="downloader download.urlDownload returned 404, skipping retries"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 event="download failed" error="failed to download file: unexpected status code: actual=404 expected=200"
time=2020-04-22T04:21:29Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="failed to handle" error="processing file downloads failed: failed to download file[0]: failed to download file: unexpected status code: actual=404 expected=200"
Not writing a placeholder status file, already exists: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status/1.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension enable
time=2020-04-22T04:21:37Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=start
time=2020-04-22T04:21:37Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=pre-check
time=2020-04-22T04:21:37Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="comparing seqnum" path=mrseq
time=2020-04-22T04:21:37Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=exit message="the script configuration has already been processed, will not run again"
```

**- /var/log/waagent.log**

```
020/04/22 04:21:13.361838 INFO Daemon Azure Linux Agent Version:2.2.45
2020/04/22 04:21:13.369303 INFO Daemon OS: ubuntu 16.04
2020/04/22 04:21:13.373158 INFO Daemon Python: 3.5.2
2020/04/22 04:21:13.378189 INFO Daemon CGroups Status: The cgroup filesystem is ready to use
2020/04/22 04:21:13.388367 INFO Daemon Run daemon
2020/04/22 04:21:13.396179 INFO Daemon cloud-init is enabled: True
2020/04/22 04:21:13.400826 INFO Daemon Using cloud-init for provisioning
2020/04/22 04:21:13.406328 INFO Daemon Clean protocol
2020/04/22 04:21:13.411189 INFO Daemon Running CloudInit provisioning handler
2020/04/22 04:21:13.419476 INFO Daemon Detect protocol endpoints
2020/04/22 04:21:13.424574 INFO Daemon Clean protocol
2020/04/22 04:21:13.428247 INFO Daemon WireServer endpoint is not found. Rerun dhcp handler
2020/04/22 04:21:13.435637 INFO Daemon Test for route to 168.63.129.16
2020/04/22 04:21:13.440519 INFO Daemon Route to 168.63.129.16 exists
2020/04/22 04:21:13.445030 INFO Daemon Wire server endpoint:168.63.129.16
2020/04/22 04:21:13.454413 INFO Daemon Fabric preferred wire protocol version:2015-04-05
2020/04/22 04:21:13.461723 INFO Daemon Wire protocol version:2012-11-30
2020/04/22 04:21:13.466763 INFO Daemon Server preferred version:2015-04-05
2020/04/22 04:21:13.899950 INFO Daemon Found private key matching thumbprint 025321D002E50F14AD52E54B8545912F7DB34F38
2020/04/22 04:21:13.919268 INFO Daemon Waiting for ssh host key be generated at /etc/ssh/ssh_host_rsa_key.pub [1800 attempts remaining, sleeping 1s]
2020/04/22 04:21:14.933109 INFO Daemon Waiting for ssh host key be generated at /etc/ssh/ssh_host_rsa_key.pub [1799 attempts remaining, sleeping 1s]
2020/04/22 04:21:15.945832 INFO Daemon Waiting for ssh host key be generated at /etc/ssh/ssh_host_rsa_key.pub [1798 attempts remaining, sleeping 1s]
2020/04/22 04:21:16.960205 INFO Daemon Waiting for ssh host key be generated at /etc/ssh/ssh_host_rsa_key.pub [1797 attempts remaining, sleeping 1s]
2020/04/22 04:21:17.972202 INFO Daemon Waiting for ssh host key be generated at /etc/ssh/ssh_host_rsa_key.pub [1796 attempts remaining, sleeping 1s]
2020/04/22 04:21:18.985003 INFO Daemon Waiting for ssh host key be generated at /etc/ssh/ssh_host_rsa_key.pub [1795 attempts remaining, sleeping 1s]
2020/04/22 04:21:20.009969 INFO Daemon ssh host key found at: /etc/ssh/ssh_host_rsa_key.pub
2020/04/22 04:21:20.088411 INFO Daemon Thumbprint obtained from : /etc/ssh/ssh_host_rsa_key.pub
2020/04/22 04:21:20.128760 INFO Daemon Finished provisioning
2020/04/22 04:21:23.560078 INFO Daemon RDMA capabilities are not enabled, skipping
2020/04/22 04:21:23.566458 INFO Daemon Installed Agent WALinuxAgent-2.2.45 is the most current agent
2020/04/22 04:21:23.705561 INFO ExtHandler Agent WALinuxAgent-2.2.45 is running as the goal state agent
2020/04/22 04:21:23.712842 INFO ExtHandler Distro info: ubuntu 16.04, osutil class being used: Ubuntu16OSUtil, agent service name: walinuxagent
2020/04/22 04:21:23.724328 INFO ExtHandler Wire server endpoint:168.63.129.16
2020/04/22 04:21:23.740466 INFO ExtHandler Start env monitor service.
2020/04/22 04:21:23.746623 INFO ExtHandler Configure routes
2020/04/22 04:21:23.752755 INFO ExtHandler Gateway:None
2020/04/22 04:21:23.756930 INFO ExtHandler Routes:None
2020/04/22 04:21:23.761318 INFO ExtHandler Hostname record does not exist, creating [/var/lib/waagent/published_hostname] with hostname [clustern5ikrxlo55ggo000000]
2020/04/22 04:21:23.777886 INFO ExtHandler Wire server endpoint:168.63.129.16
2020/04/22 04:21:23.807707 INFO ExtHandler WALinuxAgent-2.2.45 running as process 1773
2020/04/22 04:21:23.815655 INFO ExtHandler CGroups Status: The cgroup filesystem is ready to use
2020/04/22 04:21:23.828558 INFO ExtHandler Started tracking new cgroup: walinuxagent.service, path: /sys/fs/cgroup/cpu/system.slice/walinuxagent.service
2020/04/22 04:21:23.840003 INFO ExtHandler Started tracking new cgroup: walinuxagent.service, path: /sys/fs/cgroup/memory/system.slice/walinuxagent.service
2020/04/22 04:21:23.939402 INFO ExtHandler Route table: [{"Iface": "eth0", "Destination": "0.0.0.0", "Gateway": "10.0.0.1", "Mask": "0.0.0.0", "Flags": "0x0003", "Metric": "0"},{"Iface": "eth0", "Destination": "10.0.0.0", "Gateway": "0.0.0.0", "Mask": "255.255.255.0", "Flags": "0x0001", "Metric": "0"},{"Iface": "eth0", "Destination": "168.63.129.16", "Gateway": "10.0.0.1", "Mask": "255.255.255.255", "Flags": "0x0007", "Metric": "0"},{"Iface": "eth0", "Destination": "169.254.169.254", "Gateway": "10.0.0.1", "Mask": "255.255.255.255", "Flags": "0x0007", "Metric": "0"}]
2020/04/22 04:21:24.053315 INFO ExtHandler Initial NIC state: [{ "name": "lo", "link": " mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000\ link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00" }, { "name": "eth0", "link": " mtu 1500 qdisc mq state UP mode DEFAULT group default qlen 1000\ link/ether 00:0d:3a:7d:b7:bf brd ff:ff:ff:ff:ff:ff" }]
2020/04/22 04:21:24.104843 INFO ExtHandler Created slice for walinuxagent extensions system-walinuxagent.extensions.slice
2020/04/22 04:21:24.115156 INFO ExtHandler Successfully added Azure fabric firewall rules
2020/04/22 04:21:24.122397 INFO ExtHandler Wire server endpoint:168.63.129.16
2020/04/22 04:21:24.132285 INFO ExtHandler Firewall rules:
Chain INPUT (policy ACCEPT 6 packets, 13228 bytes)
pkts bytes target prot opt in out source destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination

Chain OUTPUT (policy ACCEPT 1 packets, 52 bytes)
pkts bytes target prot opt in out source destination
2 112 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 owner UID match 0
0 0 DROP tcp -- * * 0.0.0.0/0 168.63.129.16 ctstate INVALID,NEW

2020/04/22 04:21:24.201386 INFO ExtHandler Set block dev timeout: sdb with timeout: 300
2020/04/22 04:21:24.208357 INFO ExtHandler Set block dev timeout: sda with timeout: 300
2020/04/22 04:21:24.335098 INFO ExtHandler Agent WALinuxAgent-2.2.45 discovered update WALinuxAgent-2.2.46 -- exiting
2020/04/22 04:21:24.577728 INFO Daemon Agent WALinuxAgent-2.2.45 launched with command 'python3 -u /usr/sbin/waagent -run-exthandlers' is successfully running
2020/04/22 04:21:24.600245 INFO Daemon Determined Agent WALinuxAgent-2.2.46 to be the latest agent
2020-04-22T04:21:24.981439Z INFO ExtHandler Agent WALinuxAgent-2.2.46 is running as the goal state agent
2020-04-22T04:21:25.005639Z INFO ExtHandler Distro info: ubuntu 16.04, osutil class being used: Ubuntu16OSUtil, agent service name: walinuxagent
2020-04-22T04:21:25.071272Z INFO ExtHandler WireServer endpoint 168.63.129.16 read from file
2020-04-22T04:21:25.086776Z INFO ExtHandler Wire server endpoint:168.63.129.16
2020-04-22T04:21:25.122679Z INFO ExtHandler Start env monitor service.
2020-04-22T04:21:25.137771Z INFO ExtHandler Configure routes
2020-04-22T04:21:25.166207Z INFO ExtHandler Gateway:None
2020-04-22T04:21:25.185484Z INFO ExtHandler Routes:None
2020-04-22T04:21:25.215105Z INFO ExtHandler WireServer endpoint 168.63.129.16 read from file
2020-04-22T04:21:25.227517Z INFO ExtHandler WALinuxAgent-2.2.46 running as process 1853
2020-04-22T04:21:25.242868Z INFO ExtHandler Wire server endpoint:168.63.129.16
2020-04-22T04:21:25.255369Z INFO ExtHandler Route table: [{"Iface": "eth0", "Destination": "0.0.0.0", "Gateway": "10.0.0.1", "Mask": "0.0.0.0", "Flags": "0x0003", "Metric": "0"},{"Iface": "eth0", "Destination": "10.0.0.0", "Gateway": "0.0.0.0", "Mask": "255.255.255.0", "Flags": "0x0001", "Metric": "0"},{"Iface": "eth0", "Destination": "168.63.129.16", "Gateway": "10.0.0.1", "Mask": "255.255.255.255", "Flags": "0x0007", "Metric": "0"},{"Iface": "eth0", "Destination": "169.254.169.254", "Gateway": "10.0.0.1", "Mask": "255.255.255.255", "Flags": "0x0007", "Metric": "0"}]
2020-04-22T04:21:25.257535Z INFO ExtHandler CGroups Status: The cgroup filesystem is ready to use
2020-04-22T04:21:25.354137Z INFO ExtHandler Started tracking new cgroup: walinuxagent.service, path: /sys/fs/cgroup/cpu/system.slice/walinuxagent.service
2020-04-22T04:21:25.395084Z INFO ExtHandler Initial NIC state: [{ "name": "lo", "link": " mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000\ link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00" }, { "name": "eth0", "link": " mtu 1500 qdisc mq state UP mode DEFAULT group default qlen 1000\ link/ether 00:0d:3a:7d:b7:bf brd ff:ff:ff:ff:ff:ff" }]
2020-04-22T04:21:25.451063Z INFO ExtHandler Started tracking new cgroup: walinuxagent.service, path: /sys/fs/cgroup/memory/system.slice/walinuxagent.service
2020-04-22T04:21:25.553644Z INFO ExtHandler Successfully added Azure fabric firewall rules
2020-04-22T04:21:25.593068Z INFO ExtHandler Firewall rules:
Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination
0 0 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 owner UID match 0
0 0 DROP tcp -- * * 0.0.0.0/0 168.63.129.16 ctstate INVALID,NEW

2020-04-22T04:21:25.670715Z INFO ExtHandler Created slice for walinuxagent extensions system-walinuxagent.extensions.slice
2020-04-22T04:21:25.771892Z INFO ExtHandler WireServer endpoint 168.63.129.16 read from file
2020-04-22T04:21:25.783463Z INFO ExtHandler Wire server endpoint:168.63.129.16
2020-04-22T04:21:25.893769Z INFO ExtHandler Found private key matching thumbprint 025321D002E50F14AD52E54B8545912F7DB34F38
2020-04-22T04:21:25.944240Z INFO ExtHandler WireServer endpoint 168.63.129.16 read from file
2020-04-22T04:21:25.952187Z INFO ExtHandler Wire server endpoint:168.63.129.16
2020-04-22T04:21:26.047115Z INFO ExtHandler Found private key matching thumbprint 025321D002E50F14AD52E54B8545912F7DB34F38
2020-04-22T04:21:26.129072Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Target handler state: enabled
2020-04-22T04:21:26.143579Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] [Enable] current handler state is: notinstalled
2020-04-22T04:21:26.154684Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Downloading extension package: https://zrdfepirv2bz6prdstr09a.blob.core.windows.net/708cdbbfb9ad4802ac80a012992930b1/Microsoft.Azure.Extensions__CustomScript__2.1.3
2020-04-22T04:21:26.256672Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Unzipping extension package: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript__2.1.3.zip
2020-04-22T04:21:26.408003Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Initializing extension Microsoft.Azure.Extensions.CustomScript-2.1.3
2020-04-22T04:21:26.660029Z INFO ExtHandler Created slice for system-walinuxagent.extensions-Microsoft.Azure.Extensions.CustomScript_2.1.3.slice
2020-04-22T04:21:26.670401Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Update settings file: 1.settings
2020-04-22T04:21:26.683621Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Install extension [bin/custom-script-shim install]
2020-04-22T04:21:26.705424Z INFO ExtHandler Started extension using scope 'Microsoft.Azure.Extensions.CustomScript_2.1.3_894ef03f-398d-49d3-b117-ca9638286b61'
2020-04-22T04:21:26.747394Z INFO ExtHandler Started tracking new cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/cpu/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_894ef03f-398d-49d3-b117-ca9638286b61.scope
2020-04-22T04:21:26.779005Z INFO ExtHandler Started tracking new cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/memory/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_894ef03f-398d-49d3-b117-ca9638286b61.scope
2020-04-22T04:21:28.815169Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Enable extension [bin/custom-script-shim enable]
2020-04-22T04:21:28.833619Z INFO ExtHandler Started extension using scope 'Microsoft.Azure.Extensions.CustomScript_2.1.3_7d4ccfed-8319-4da2-8933-834e79036f86'
2020-04-22T04:21:28.863559Z INFO ExtHandler Started tracking new cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/cpu/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_7d4ccfed-8319-4da2-8933-834e79036f86.scope
2020-04-22T04:21:28.895564Z INFO ExtHandler Started tracking new cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/memory/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_7d4ccfed-8319-4da2-8933-834e79036f86.scope
2020-04-22T04:21:30.968460Z INFO ExtHandler WireServer endpoint 168.63.129.16 read from file
2020-04-22T04:21:30.975010Z INFO ExtHandler Wire server endpoint:168.63.129.16
2020-04-22T04:21:30.981325Z INFO ExtHandler ProcessGoalState completed [incarnation 1; 5037 ms]
2020-04-22T04:21:37.111626Z INFO ExtHandler Found private key matching thumbprint 025321D002E50F14AD52E54B8545912F7DB34F38
2020-04-22T04:21:37.149063Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Target handler state: enabled
2020-04-22T04:21:37.156705Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] [Enable] current handler state is: enabled
2020-04-22T04:21:37.164521Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Update settings file: 1.settings
2020-04-22T04:21:37.172505Z INFO [Microsoft.Azure.Extensions.CustomScript-2.1.3] Enable extension [bin/custom-script-shim enable]
2020-04-22T04:21:37.182747Z INFO ExtHandler Started extension using scope 'Microsoft.Azure.Extensions.CustomScript_2.1.3_f95f4556-5afb-4825-acb1-c9319c721083'
2020-04-22T04:21:37.212070Z INFO ExtHandler Started tracking new cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/cpu/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_f95f4556-5afb-4825-acb1-c9319c721083.scope
2020-04-22T04:21:37.251877Z INFO ExtHandler Started tracking new cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/memory/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_f95f4556-5afb-4825-acb1-c9319c721083.scope
2020-04-22T04:21:38.300037Z INFO ExtHandler ProcessGoalState completed [incarnation 2; 1252 ms]
2020-04-22T04:26:25.834696Z INFO ExtHandler Stopped tracking cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/cpu/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_894ef03f-398d-49d3-b117-ca9638286b61.scope
2020-04-22T04:26:25.852915Z INFO ExtHandler Stopped tracking cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/memory/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_894ef03f-398d-49d3-b117-ca9638286b61.scope
2020-04-22T04:26:25.866794Z INFO ExtHandler Stopped tracking cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/cpu/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_7d4ccfed-8319-4da2-8933-834e79036f86.scope
2020-04-22T04:26:25.876865Z INFO ExtHandler Stopped tracking cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/memory/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_7d4ccfed-8319-4da2-8933-834e79036f86.scope
2020-04-22T04:26:25.877312Z INFO ExtHandler Stopped tracking cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/cpu/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_f95f4556-5afb-4825-acb1-c9319c721083.scope
2020-04-22T04:26:25.877675Z INFO ExtHandler Stopped tracking cgroup: Microsoft.Azure.Extensions.CustomScript-2.1.3, path: /sys/fs/cgroup/memory/system.slice/Microsoft.Azure.Extensions.CustomScript_2.1.3_f95f4556-5afb-4825-acb1-c9319c721083.scope
2020/04/22 04:36:24.613128 INFO Daemon Agent WALinuxAgent-2.2.46 launched with command 'python3 -u bin/WALinuxAgent-2.2.46-py2.7.egg -run-exthandlers' is successfully running`
```
To confirm, I've logged on to the deployed VM.
When checking the VM log, everything is okay but from the second try.
**- /var/log/azure/custom-script/handler.log**

```
+ /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension install
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 event=start
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 status="not reported for operation (by design)"
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 event="migrate to mrseq" error="Can't find out seqnum from /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status, not enough files."
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 event="created data dir" path=/var/lib/waagent/custom-script
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 event=installed
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 status="not reported for operation (by design)"
time=2020-04-22T04:20:51Z version=v2.1.3/git@4cd2b9f-clean operation=install seq=0 event=end
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status/0.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension enable
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event=start
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event=pre-check
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="comparing seqnum" path=mrseq
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="seqnum saved" path=mrseq
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="reading configuration"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="read configuration"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="validating json schema"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="json schema valid"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="parsing configuration json"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="parsed configuration json"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="validating configuration logically"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="validated configuration"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="creating output directory" path=/var/lib/waagent/custom-script/download/0
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="created output directory"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 files=2
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 file=0 event="download start"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 file=0 retry=0 error="unexpected status code: actual=404 expected=200"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 file=0 retry=0 info="downloader download.urlDownload returned 404, skipping retries"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 file=0 event="download failed" error="failed to download file: unexpected status code: actual=404 expected=200"
time=2020-04-22T04:20:53Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="failed to handle" error="processing file downloads failed: failed to download file[0]: failed to download file: unexpected status code: actual=404 expected=200"
Not writing a placeholder status file, already exists: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status/0.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension enable
time=2020-04-22T04:42:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event=start
time=2020-04-22T04:42:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event=pre-check
time=2020-04-22T04:42:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event="comparing seqnum" path=mrseq
time=2020-04-22T04:42:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=0 event=exit message="the script configuration has already been processed, will not run again"
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status/1.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension enable
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=start
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event=pre-check
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="comparing seqnum" path=mrseq
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="seqnum saved" path=mrseq
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="reading configuration"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="read configuration"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="validating json schema"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="json schema valid"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="parsing configuration json"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="parsed configuration json"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="validating configuration logically"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="validated configuration"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="creating output directory" path=/var/lib/waagent/custom-script/download/1
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="created output directory"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 files=2
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 event="download start"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 retry=0 error="unexpected status code: actual=404 expected=200"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 retry=0 info="downloader download.urlDownload returned 404, skipping retries"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 file=0 event="download failed" error="failed to download file: unexpected status code: actual=404 expected=200"
time=2020-04-22T08:48:06Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=1 event="failed to handle" error="processing file downloads failed: failed to download file[0]: failed to download file: unexpected status code: actual=404 expected=200"
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/status/2.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.1.3/bin/custom-script-extension enable
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event=start
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event=pre-check
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="comparing seqnum" path=mrseq
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="seqnum saved" path=mrseq
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="reading configuration"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="read configuration"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="validating json schema"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="json schema valid"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="parsing configuration json"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="parsed configuration json"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="validating configuration logically"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="validated configuration"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="creating output directory" path=/var/lib/waagent/custom-script/download/2
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="created output directory"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 files=2
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 file=0 event="download start"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 file=0 event="download complete" output=/var/lib/waagent/custom-script/download/2
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 file=1 event="download start"
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 file=1 event="download complete" output=/var/lib/waagent/custom-script/download/2
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="executing command" output=/var/lib/waagent/custom-script/download/2
time=2020-04-23T05:38:27Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="executing protected commandToExecute" output=/var/lib/waagent/custom-script/download/2
time=2020-04-23T05:41:56Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event="executed command" output=/var/lib/waagent/custom-script/download/2
time=2020-04-23T05:41:56Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event=enabled
time=2020-04-23T05:41:56Z version=v2.1.3/git@4cd2b9f-clean operation=enable seq=2 event=end
```

I have only one suggestion that the extensionProfile part of the template isn't working as expected however was unable to find any proofs.

```
"extensionProfile": {
"extensions": [
{
"name": "filesextension",
"properties": {
"publisher": "Microsoft.Azure.Extensions",
"type": "CustomScript",
"typeHandlerVersion": "2.0",
"autoUpgradeMinorVersion": true,
"forceUpdateTag": "rerunnow",
"settings": {
"fileUris": [
"[variables('nextflowInitScript')]",
"[variables('diskInitScript')]"
]
},
"protectedSettings": {
"commandToExecute": "[concat('bash init.sh ', variables('storageAccountName'), ' ', listKeys(resourceId('Microsoft.Storage/storageAccounts', variables('storageAccountName')), '2016-01-01').keys[0].value, ' ', parameters('shareName'), ' ', parameters('mountpointPath'), ' true ', parameters('adminUsername'), ' ', parameters('nodeMaxCpus'), ' ', parameters('nextflowInstallUrl'), ' ', parameters('vmAdditionalInstallScriptUrl'), ' ', parameters('vmAdditionalInstallScriptArgument'))]"
}
}
}
]
}
}

```
Thanks.