search

Azure / azure-linux-extensions

Linux Virtual Machine Extensions for Azure
Apache License 2.0
307 stars 254 forks source link

Extension fails to install on Debian 8 (20170315) #361

Open alfpark opened 7 years ago

alfpark commented 7 years ago

Extension fails to install on credativ:debian:8:8.0.201703150 image.

My guess is that python has no mapping in this version of the image. For example:

$ ./customscript.py -install
/usr/bin/env: python: No such file or directory
$ echo $?
127

WALA logs:

2017/03/25 02:07:31.231113 INFO Activate resource disk
2017/03/25 02:07:31.280661 INFO Examining partition table
2017/03/25 02:07:31.301111 INFO GPT not detected, determining filesystem
2017/03/25 02:07:31.321489 INFO The partition is formatted with ntfs, updating partition type to 83
2017/03/25 02:07:31.405615 INFO Format partition [mkfs.ext4 /dev/sdb1 -F]
2017/03/25 02:07:49.007700 INFO Mount resource disk [mount /dev/sdb1 /mnt/resource]
2017/03/25 02:07:49.278264 INFO Resource disk /dev/sdb is mounted at /mnt/resource with ext4
2017/03/25 02:07:56.929515 INFO Running provisioning handler
2017/03/25 02:07:56.950533 INFO Copying ovf-env.xml
2017/03/25 02:07:57.106432 INFO Successfully mounted dvd
2017/03/25 02:07:57.619762 INFO Detect protocol by file
2017/03/25 02:07:57.635226 INFO Clean protocol
2017/03/25 02:07:57.647254 INFO WireServer endpoint is not found. Rerun dhcp handler
2017/03/25 02:07:57.667693 INFO test for route to 168.63.129.16
2017/03/25 02:07:57.687357 INFO route to 168.63.129.16 exists
2017/03/25 02:07:57.708723 INFO Wire server endpoint:168.63.129.16
2017/03/25 02:07:57.747093 INFO Fabric preferred wire protocol version:2015-04-05
2017/03/25 02:07:57.765158 INFO Wire protocol version:2012-11-30
2017/03/25 02:07:57.777521 WARNING Server prefered version:2015-04-05
2017/03/25 02:08:02.793252 INFO Starting provisioning
2017/03/25 02:08:02.800801 INFO Handle ovf-env.xml.
2017/03/25 02:08:02.808543 INFO Set host name.
2017/03/25 02:08:02.838545 INFO Publish host name.
2017/03/25 02:08:02.845988 INFO examine /proc/net/route for primary interface
2017/03/25 02:08:02.855748 INFO primary interface is [eth0]
2017/03/25 02:08:02.863957 INFO interface [b'lo'] has flags [73], is loopback [True]
2017/03/25 02:08:02.874530 INFO interface [b'lo'] skipped
2017/03/25 02:08:02.882847 INFO interface [b'eth0'] has flags [4163], is loopback [False]
2017/03/25 02:08:02.894697 INFO interface [b'eth0'] selected
2017/03/25 02:08:09.500438 INFO Create user account if not exists
2017/03/25 02:08:10.393279 INFO Set user password.
2017/03/25 02:08:10.624369 INFO Configure sudoer
2017/03/25 02:08:10.640190 INFO Configure sshd
2017/03/25 02:08:10.656313 INFO Enabled SSH password-based authentication methods.
2017/03/25 02:08:10.676208 INFO Configured SSH client probing to keep connections alive.
2017/03/25 02:08:11.368991 INFO Event: name=WALA, op=Provision, message=Provision succeed
2017/03/25 02:08:13.830117 INFO Provisioning complete
2017/03/25 02:08:14.766041 INFO Azure Linux Agent Version:2.2.2
2017/03/25 02:08:14.780388 INFO OS: debian 8.7
2017/03/25 02:08:14.793948 INFO Python: 3.4.2
2017/03/25 02:08:14.804170 INFO Run daemon
2017/03/25 02:08:14.818943 INFO No RDMA handler exists for distro='debian' version='8.7'
2017/03/25 02:08:14.835688 INFO Activate resource disk
2017/03/25 02:08:14.864129 INFO Resource disk [/dev/sdb1] is already mounted [/mnt/resource]
2017/03/25 02:08:14.881248 INFO Clean protocol
2017/03/25 02:08:14.891764 INFO Provisioning already completed, skipping.
2017/03/25 02:08:14.907497 INFO RDMA capabilities are not enabled, skipping
2017/03/25 02:08:14.920904 INFO Installed Agent WALinuxAgent-2.2.2 is the most current agent
2017/03/25 02:08:14.976151 INFO Agent WALinuxAgent-2.2.2 launched with command 'python3 -u /usr/sbin/waagent -run-exthandlers'
2017/03/25 02:08:15.413238 INFO Agent WALinuxAgent-2.2.2 is running as the goal state agent
2017/03/25 02:08:15.441195 INFO Detect protocol endpoints
2017/03/25 02:08:15.461588 INFO Clean protocol
2017/03/25 02:08:15.468425 INFO WireServer endpoint is not found. Rerun dhcp handler
2017/03/25 02:08:15.483497 INFO test for route to 168.63.129.16
2017/03/25 02:08:15.500139 INFO route to 168.63.129.16 exists
2017/03/25 02:08:15.512056 INFO Wire server endpoint:168.63.129.16
2017/03/25 02:08:15.557818 INFO Fabric preferred wire protocol version:2015-04-05
2017/03/25 02:08:15.571830 INFO Wire protocol version:2012-11-30
2017/03/25 02:08:15.589275 WARNING Server prefered version:2015-04-05
2017/03/25 02:08:20.687258 INFO Event: name=WALinuxAgent-2.2.2, op=HeartBeat, message=
2017/03/25 02:08:20.703033 INFO Start env monitor service.
2017/03/25 02:08:20.713714 INFO Configure routes
2017/03/25 02:08:20.726253 INFO Gateway:None
2017/03/25 02:08:20.731054 INFO Routes:None
2017/03/25 02:08:20.854438 INFO WALinuxAgent-2.2.2 running as process 495
2017/03/25 02:08:20.862291 INFO Set block dev timeout: sda with timeout: 300
2017/03/25 02:08:20.873628 INFO Checking for agent family Prod updates
2017/03/25 02:08:20.884557 INFO Set block dev timeout: sdb with timeout: 300
2017/03/25 02:08:20.895775 INFO Wire server endpoint:168.63.129.16
2017/03/25 02:08:20.976879 INFO Instantiating Agent WALinuxAgent-2.2.1 from package
2017/03/25 02:08:20.994225 INFO Agent WALinuxAgent-2.2.1 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.017209 INFO Ensuring Agent WALinuxAgent-2.2.1 is downloaded
2017/03/25 02:08:21.096648 INFO Agent WALinuxAgent-2.2.1 downloaded from https://brdfepirv2by3prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.1
2017/03/25 02:08:21.158679 INFO Agent WALinuxAgent-2.2.1 unpacked successfully to /var/lib/waagent/WALinuxAgent-2.2.1
2017/03/25 02:08:21.192721 INFO Agent WALinuxAgent-2.2.1 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.1/HandlerManifest.json
2017/03/25 02:08:21.213111 INFO Agent WALinuxAgent-2.2.1 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.245519 INFO Agent WALinuxAgent-2.2.1 downloaded successfully
2017/03/25 02:08:21.255739 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.1 downloaded successfully
2017/03/25 02:08:21.275410 INFO Instantiating Agent WALinuxAgent-2.2.2 from package
2017/03/25 02:08:21.302110 INFO Agent WALinuxAgent-2.2.2 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.316286 INFO Ensuring Agent WALinuxAgent-2.2.2 is downloaded
2017/03/25 02:08:21.422029 INFO Agent WALinuxAgent-2.2.2 downloaded from https://brdfepirv2by3prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.2
2017/03/25 02:08:21.472241 INFO Agent WALinuxAgent-2.2.2 unpacked successfully to /var/lib/waagent/WALinuxAgent-2.2.2
2017/03/25 02:08:21.490276 INFO Agent WALinuxAgent-2.2.2 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.2/HandlerManifest.json
2017/03/25 02:08:21.529712 INFO Agent WALinuxAgent-2.2.2 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.550549 INFO Agent WALinuxAgent-2.2.2 downloaded successfully
2017/03/25 02:08:21.575573 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.2 downloaded successfully
2017/03/25 02:08:21.593339 INFO Instantiating Agent WALinuxAgent-2.2.5 from package
2017/03/25 02:08:21.622768 INFO Agent WALinuxAgent-2.2.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.636951 INFO Ensuring Agent WALinuxAgent-2.2.5 is downloaded
2017/03/25 02:08:21.769485 INFO Agent WALinuxAgent-2.2.5 downloaded from https://brdfepirv2by3prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.5
2017/03/25 02:08:21.842944 INFO Agent WALinuxAgent-2.2.5 unpacked successfully to /var/lib/waagent/WALinuxAgent-2.2.5
2017/03/25 02:08:21.860068 INFO Agent WALinuxAgent-2.2.5 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.5/HandlerManifest.json
2017/03/25 02:08:21.881205 INFO Agent WALinuxAgent-2.2.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.910867 INFO Agent WALinuxAgent-2.2.5 downloaded successfully
2017/03/25 02:08:21.920051 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.5 downloaded successfully
2017/03/25 02:08:21.938078 INFO Instantiating Agent WALinuxAgent-2.2.6 from package
2017/03/25 02:08:21.966859 INFO Agent WALinuxAgent-2.2.6 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:21.980467 INFO Ensuring Agent WALinuxAgent-2.2.6 is downloaded
2017/03/25 02:08:22.091122 INFO Agent WALinuxAgent-2.2.6 downloaded from https://brdfepirv2by3prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.6
2017/03/25 02:08:22.144034 INFO Agent WALinuxAgent-2.2.6 unpacked successfully to /var/lib/waagent/WALinuxAgent-2.2.6
2017/03/25 02:08:22.166077 INFO Agent WALinuxAgent-2.2.6 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.6/HandlerManifest.json
2017/03/25 02:08:22.191784 INFO Agent WALinuxAgent-2.2.6 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:08:22.209643 INFO Agent WALinuxAgent-2.2.6 downloaded successfully
2017/03/25 02:08:22.245929 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.6 downloaded successfully
2017/03/25 02:08:22.262234 INFO Agent WALinuxAgent-2.2.2 discovered WALinuxAgent-2.2.6 as an update and will exit
2017/03/25 02:09:15.083839 INFO Agent WALinuxAgent-2.2.2 launched with command 'python3 -u /usr/sbin/waagent -run-exthandlers' is successfully running
2017/03/25 02:09:15.101182 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.2.2 launched with command 'python3 -u /usr/sbin/waagent -run-exthandlers' is successfully running
2017/03/25 02:09:15.124278 INFO Instantiating Agent WALinuxAgent-2.2.1 from disk
2017/03/25 02:09:15.134776 INFO Agent WALinuxAgent-2.2.1 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:15.149031 INFO Ensuring Agent WALinuxAgent-2.2.1 is downloaded
2017/03/25 02:09:15.158847 INFO Agent WALinuxAgent-2.2.1 was previously downloaded - skipping download
2017/03/25 02:09:15.171622 INFO Agent WALinuxAgent-2.2.1 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.1/HandlerManifest.json
2017/03/25 02:09:15.188173 INFO Instantiating Agent WALinuxAgent-2.2.2 from disk
2017/03/25 02:09:15.198048 INFO Agent WALinuxAgent-2.2.2 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:15.212044 INFO Ensuring Agent WALinuxAgent-2.2.2 is downloaded
2017/03/25 02:09:15.221069 INFO Agent WALinuxAgent-2.2.2 was previously downloaded - skipping download
2017/03/25 02:09:15.232327 INFO Agent WALinuxAgent-2.2.2 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.2/HandlerManifest.json
2017/03/25 02:09:15.248563 INFO Instantiating Agent WALinuxAgent-2.2.5 from disk
2017/03/25 02:09:15.258828 INFO Agent WALinuxAgent-2.2.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:15.272923 INFO Ensuring Agent WALinuxAgent-2.2.5 is downloaded
2017/03/25 02:09:15.282095 INFO Agent WALinuxAgent-2.2.5 was previously downloaded - skipping download
2017/03/25 02:09:15.293663 INFO Agent WALinuxAgent-2.2.5 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.5/HandlerManifest.json
2017/03/25 02:09:15.308546 INFO Instantiating Agent WALinuxAgent-2.2.6 from disk
2017/03/25 02:09:15.317782 INFO Agent WALinuxAgent-2.2.6 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:15.330913 INFO Ensuring Agent WALinuxAgent-2.2.6 is downloaded
2017/03/25 02:09:15.340152 INFO Agent WALinuxAgent-2.2.6 was previously downloaded - skipping download
2017/03/25 02:09:15.351675 INFO Agent WALinuxAgent-2.2.6 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.6/HandlerManifest.json
2017/03/25 02:09:15.367358 INFO Determined Agent WALinuxAgent-2.2.6 to be the latest agent
2017/03/25 02:09:15.379825 INFO Agent WALinuxAgent-2.2.6 launched with command 'python3 -u bin/WALinuxAgent-2.2.6-py2.7.egg -run-exthandlers'
2017/03/25 02:09:16.080018 INFO Agent WALinuxAgent-2.2.6 is running as the goal state agent
2017/03/25 02:09:16.124716 INFO Wire server endpoint:168.63.129.16
2017/03/25 02:09:16.154061 INFO Start env monitor service.
2017/03/25 02:09:16.152755 INFO Event: name=WALinuxAgent-2.2.6, op=HeartBeat, message=
2017/03/25 02:09:16.165720 INFO Configure routes
2017/03/25 02:09:16.195709 INFO Gateway:None
2017/03/25 02:09:16.203258 INFO Routes:None
2017/03/25 02:09:16.215101 WARNING Hostname record does not exist, creating [/var/lib/waagent/published_hostname] with hostname [batchnode-0]
2017/03/25 02:09:16.258920 WARNING Dhcp client is not running.
2017/03/25 02:09:16.268117 INFO WALinuxAgent-2.2.6 running as process 513
2017/03/25 02:09:16.294145 INFO Checking for agent family Prod updates
2017/03/25 02:09:16.309180 INFO Wire server endpoint:168.63.129.16
2017/03/25 02:09:16.404672 INFO Instantiating Agent WALinuxAgent-2.2.1 from package
2017/03/25 02:09:16.418301 INFO Agent WALinuxAgent-2.2.1 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:16.441203 INFO Ensuring Agent WALinuxAgent-2.2.1 is downloaded
2017/03/25 02:09:16.457387 INFO Agent WALinuxAgent-2.2.1 was previously downloaded - skipping download
2017/03/25 02:09:16.478500 INFO Agent WALinuxAgent-2.2.1 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.1/HandlerManifest.json
2017/03/25 02:09:16.499440 INFO Instantiating Agent WALinuxAgent-2.2.2 from package
2017/03/25 02:09:16.523125 INFO Agent WALinuxAgent-2.2.2 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:16.541782 INFO Ensuring Agent WALinuxAgent-2.2.2 is downloaded
2017/03/25 02:09:16.564603 INFO Agent WALinuxAgent-2.2.2 was previously downloaded - skipping download
2017/03/25 02:09:16.603466 INFO Agent WALinuxAgent-2.2.2 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.2/HandlerManifest.json
2017/03/25 02:09:16.634749 INFO Instantiating Agent WALinuxAgent-2.2.5 from package
2017/03/25 02:09:16.660447 INFO Agent WALinuxAgent-2.2.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:16.674802 INFO Ensuring Agent WALinuxAgent-2.2.5 is downloaded
2017/03/25 02:09:16.700667 INFO Agent WALinuxAgent-2.2.5 was previously downloaded - skipping download
2017/03/25 02:09:16.717317 INFO Agent WALinuxAgent-2.2.5 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.5/HandlerManifest.json
2017/03/25 02:09:16.748166 INFO Instantiating Agent WALinuxAgent-2.2.6 from package
2017/03/25 02:09:16.757824 INFO Agent WALinuxAgent-2.2.6 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/03/25 02:09:16.777167 INFO Ensuring Agent WALinuxAgent-2.2.6 is downloaded
2017/03/25 02:09:16.797375 INFO Agent WALinuxAgent-2.2.6 was previously downloaded - skipping download
2017/03/25 02:09:16.813744 INFO Agent WALinuxAgent-2.2.6 loaded manifest from /var/lib/waagent/WALinuxAgent-2.2.6/HandlerManifest.json
2017/03/25 02:09:16.844312 INFO Wire server endpoint:168.63.129.16
2017/03/25 02:09:16.959683 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Expected handler state: enabled
2017/03/25 02:09:16.987932 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Current handler state is: NotInstalled
2017/03/25 02:09:17.002335 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Download extension package
2017/03/25 02:09:17.079047 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Unpack extension package
2017/03/25 02:09:17.153192 INFO Event: name=Microsoft.OSTCExtensions.CustomScriptForLinux, op=Download, message=Download succeeded
2017/03/25 02:09:17.174601 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Initialize extension directory
2017/03/25 02:09:17.199354 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Update settings file: 0.settings
2017/03/25 02:09:17.218290 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Install extension.
2017/03/25 02:09:17.247488 INFO [Microsoft.OSTCExtensions.CustomScriptForLinux-1.5.2.1] Launch command:customscript.py -install
2017/03/25 02:09:18.272756 ERROR Event: name=Microsoft.OSTCExtensions.CustomScriptForLinux, op=Install, message=(000003)Non-zero exit code: 127, customscript.py -install
2017/03/25 02:09:18.369199 INFO Event: name=WALinuxAgent, op=HealthCheck, message=Blob type match [BlockBlob]
2017/03/25 02:24:16.134562 INFO Agent WALinuxAgent-2.2.6 launched with command 'python3 -u bin/WALinuxAgent-2.2.6-py2.7.egg -run-exthandlers' is successfully running
2017/03/25 02:24:16.146524 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.2.6 launched with command 'python3 -u bin/WALinuxAgent-2.2.6-py2.7.egg -run-exthandlers' is successfully running
2017/03/25 02:24:16.146524 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.2.6 launched with command 'python3 -u bin/WALinuxAgent-2.2.6-py2.7.egg -run-exthandlers' is successfully running
2017/03/25 02:39:18.977621 INFO Event: name=WALinuxAgent-2.2.6, op=HeartBeat, message=

config/HandlerState:

NotInstalled

config/HandlerStatus:

{"version": "1.5.2.1", "name": "Microsoft.OSTCExtensions.CustomScriptForLinux", "code": -1, "extensions": [], "status": "NotReady", "message": "(000003)Non-zero exit code: 127, customscript.py -install"}

status: directory is empty

boumenot commented 7 years ago

It looks like CustomScriptForLinux is being invoked with Python3, which it is not compatible with. The fastest way to mitigate this is to ensure Python2 is installed, and use that as the default interpreter.

Another option is newer version of CustomScript that is based on Go, so it should not have this issue. It is a drop in replacement (just change the publisher and type), but I still consider it to be beta.