Azure / Azure/custom-script-extension-linux

Large file download fails

Open
#128 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
113
Forks
46
Avg merge
6d 3h
Merged PRs (30d)
3

Description

Hi,

I am pulling a list of files to CentOS 7.3 VM (OpenLogic) all files are created however the last few thousand bytes of the larges files are missing.
The file is 1.2GB and is stored on Azure Blob Storage.
I see the following error in the log: "fork/exec /bin/sh: cannot allocate memory"
Is there a limit in downloaded file size?

Regards,
Balint

cat /var/log/azure/custom-script/handler.log
--------------------------------------------
+ /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.0.6/bin/custom-script-extension install
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 event=start
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 status="not reported for operation (by design)"
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 event="migrate to mrseq" error="Can't find out seqnum from /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.0.6/status, not enough files."
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 event="created data dir" path=/var/lib/waagent/custom-script
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 event=installed
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 status="not reported for operation (by design)"
time=2018-03-16T10:30:21Z version=v2.0.6/git@1008306-clean operation=install seq=0 event=end
Writing a placeholder status file indicating progress before forking: /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.0.6/status/0.status
+ nohup /var/lib/waagent/Microsoft.Azure.Extensions.CustomScript-2.0.6/bin/custom-script-extension enable
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event=start
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event=pre-check
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="comparing seqnum" path=mrseq
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="seqnum saved" path=mrseq
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="reading configuration"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="read configuration"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="validating json schema"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="json schema valid"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="parsing configuration json"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="parsed configuration json"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="validating configuration logically"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="validated configuration"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="creating output directory" path=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="created output directory"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 files=13
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=0 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=0 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=1 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=1 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=2 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=2 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=3 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=3 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=4 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=4 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=5 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=5 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=6 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=6 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=7 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=7 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=8 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=8 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=9 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=9 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=10 event="download start"
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=10 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:22Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=11 event="download start"
time=2018-03-16T10:30:23Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=11 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:23Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=12 event="download start"
time=2018-03-16T10:30:58Z version=v2.0.6/git@1008306-clean operation=enable seq=0 file=12 event="download complete" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:30:58Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="executing command" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:31:41Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="executing protected commandToExecute" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:31:45Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="failed to execute command" error="failed to execute command: fork/exec /bin/sh: cannot allocate memory" output=/var/lib/waagent/custom-script/download/0
time=2018-03-16T10:31:45Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="enable failed"
time=2018-03-16T10:31:45Z version=v2.0.6/git@1008306-clean operation=enable seq=0 event="failed to handle" error="failed to execute command: failed to execute command: fork/exec /bin/sh: cannot allocate memory"

cat /var/log/waagent.log
------------------------
2018/03/16 10:26:16.319819 INFO Azure Linux Agent Version:2.2.18
2018/03/16 10:26:16.343051 INFO OS: centos 7.3.1611
2018/03/16 10:26:16.368388 INFO Python: 2.7.5
2018/03/16 10:26:16.390189 INFO Run daemon
2018/03/16 10:26:16.404315 INFO Activate resource disk
2018/03/16 10:26:16.431111 INFO Examining partition table
2018/03/16 10:26:16.509470 INFO GPT not detected, determining filesystem
2018/03/16 10:26:16.583426 INFO sfdisk with --part-type failed [1], retrying with -c
2018/03/16 10:26:16.614353 INFO sfdisk -c -f /dev/sdb 1 -n succeeded
2018/03/16 10:26:16.632848 INFO The partition is formatted with ntfs, updating partition type to 83
2018/03/16 10:26:16.659105 INFO sfdisk with --part-type failed [1], retrying with -c
2018/03/16 10:26:16.684001 INFO sfdisk -c /dev/sdb 1 83 succeeded
2018/03/16 10:26:16.720908 INFO Format partition [mkfs.ext4 -F /dev/sdb1]
2018/03/16 10:26:19.000452 INFO Mount resource disk [mount /dev/sdb1 /mnt/resource]
2018/03/16 10:26:19.149228 INFO Resource disk /dev/sdb is mounted at /mnt/resource with ext4
2018/03/16 10:26:19.178010 INFO Clean protocol
2018/03/16 10:26:19.195908 INFO Running default provisioning handler
2018/03/16 10:26:19.227372 INFO Copying ovf-env.xml
2018/03/16 10:26:19.288696 INFO Successfully mounted dvd
2018/03/16 10:26:19.337566 INFO Detect protocol by file
2018/03/16 10:26:19.338093 INFO Clean protocol
2018/03/16 10:26:19.338301 INFO WireServer endpoint is not found. Rerun dhcp handler
2018/03/16 10:26:19.342117 INFO Test for route to 168.63.129.16
2018/03/16 10:26:19.347106 INFO Route to 168.63.129.16 exists
2018/03/16 10:26:19.354218 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:19.437591 INFO Fabric preferred wire protocol version:2015-04-05
2018/03/16 10:26:19.459795 INFO Wire protocol version:2012-11-30
2018/03/16 10:26:19.479226 WARNING Server preferred version:2015-04-05
2018/03/16 10:26:23.940085 INFO Starting provisioning
2018/03/16 10:26:23.968509 INFO Handle ovf-env.xml.
2018/03/16 10:26:23.993378 INFO Set hostname [vm-coll-0]
2018/03/16 10:26:24.036144 INFO Publish hostname [vm-coll-0]
2018/03/16 10:26:24.156515 INFO Examine /proc/net/route for primary interface
2018/03/16 10:26:24.183131 INFO Primary interface is [eth0]
2018/03/16 10:26:24.199809 INFO interface [lo] has flags [73], is loopback [True]
2018/03/16 10:26:24.246423 INFO Interface [lo] skipped
2018/03/16 10:26:24.262633 INFO interface [eth0] has flags [4163], is loopback [False]
2018/03/16 10:26:24.286363 INFO Interface [eth0] selected
2018/03/16 10:26:24.306399 INFO Examine /proc/net/route for primary interface
2018/03/16 10:26:24.314351 INFO Primary interface is [eth0]
2018/03/16 10:26:24.316688 INFO interface [lo] has flags [73], is loopback [True]
2018/03/16 10:26:24.325382 INFO Interface [lo] skipped
2018/03/16 10:26:24.332618 INFO interface [eth0] has flags [4163], is loopback [False]
2018/03/16 10:26:24.342216 INFO Interface [eth0] selected
2018/03/16 10:26:27.560863 INFO Create user account if not exists
2018/03/16 10:26:27.803104 INFO Set user password.
2018/03/16 10:26:27.899583 INFO Configure sudoer
2018/03/16 10:26:27.912380 INFO Configure sshd
2018/03/16 10:26:27.925572 INFO Enabled SSH password-based authentication methods.
2018/03/16 10:26:27.945000 INFO Configured SSH client probing to keep connections alive.
2018/03/16 10:26:28.227074 INFO Event: name=WALinuxAgent, op=Provision, message=Provision succeed, duration=9031
2018/03/16 10:26:32.410583 INFO Provisioning complete
2018/03/16 10:26:32.414749 INFO RDMA capabilities are not enabled, skipping
2018/03/16 10:26:32.419603 INFO Installed Agent WALinuxAgent-2.2.18 is the most current agent
2018/03/16 10:26:32.559883 INFO Agent WALinuxAgent-2.2.18 is running as the goal state agent
2018/03/16 10:26:32.585662 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:32.603984 INFO Event: name=WALinuxAgent, op=HeartBeat, message=, duration=0
2018/03/16 10:26:32.628453 INFO Start env monitor service.
2018/03/16 10:26:32.633569 INFO Configure routes
2018/03/16 10:26:32.637621 INFO Gateway:None
2018/03/16 10:26:32.645340 INFO Routes:None
2018/03/16 10:26:32.682395 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:32.682663 INFO WALinuxAgent-2.2.18 running as process 1437
2018/03/16 10:26:32.703102 INFO Event: name=WALinuxAgent, op=AutoUpdate, message=, duration=0
2018/03/16 10:26:32.706738 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:32.816274 INFO Set block dev timeout: sda with timeout: 300
2018/03/16 10:26:32.820613 INFO Set block dev timeout: sdb with timeout: 300
2018/03/16 10:26:32.840831 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.17 downloaded successfully, duration=0
2018/03/16 10:26:32.938221 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.18 downloaded successfully, duration=0
2018/03/16 10:26:33.015407 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.20 downloaded successfully, duration=0
2018/03/16 10:26:33.237536 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.2.22 downloaded successfully, duration=0
2018/03/16 10:26:33.247696 INFO Agent WALinuxAgent-2.2.18 discovered WALinuxAgent-2.2.22 as an update and will exit
2018/03/16 10:26:33.464397 INFO Agent WALinuxAgent-2.2.18 launched with command 'python -u /usr/sbin/waagent -run-exthandlers' is successfully running
2018/03/16 10:26:33.503278 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.2.18 launched with command 'python -u /usr/sbin/waagent -run-exthandlers' is successfully running, duration=0
2018/03/16 10:26:33.557244 INFO Determined Agent WALinuxAgent-2.2.22 to be the latest agent
2018/03/16 10:26:33.669757 INFO Agent WALinuxAgent-2.2.22 is running as the goal state agent
2018/03/16 10:26:33.702118 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:33.718844 INFO Start env monitor service.
2018/03/16 10:26:33.723335 INFO Configure routes
2018/03/16 10:26:33.727793 INFO Gateway:None
2018/03/16 10:26:33.734654 INFO Routes:None
2018/03/16 10:26:33.772391 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:33.782851 INFO WALinuxAgent-2.2.22 running as process 1448
2018/03/16 10:26:33.790581 INFO Event: name=WALinuxAgent, op=Partition, message=79, duration=0
2018/03/16 10:26:33.800741 INFO Event: name=WALinuxAgent, op=AutoUpdate, message=, duration=0
2018/03/16 10:26:33.809309 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:33.888139 INFO Wire server endpoint:168.63.129.16
2018/03/16 10:26:33.992758 INFO Successfully added Azure fabric firewall rules
2018/03/16 10:26:34.014092 INFO 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 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 ctstate INVALID,NEW

2018/03/16 10:26:34.020333 INFO Purging disk cache, current incarnation is 1
2018/03/16 10:26:34.217922 INFO Event: name=WALinuxAgent, op=ProcessGoalState, message=Incarnation 1, duration=329
2018/03/16 10:28:19.613652 INFO Event: name=WALinuxAgent, op=ProcessGoalState, message=Incarnation 2, duration=207
2018/03/16 10:30:21.085233 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Target handler state: enabled
2018/03/16 10:30:21.111741 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] [Enable] current handler state is: notinstalled
2018/03/16 10:30:21.321021 INFO Event: name=Microsoft.Azure.Extensions.CustomScript, op=Download, message=Download succeeded, duration=179
2018/03/16 10:30:21.357459 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Initialize extension directory
2018/03/16 10:30:21.384665 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Update settings file: 0.settings
2018/03/16 10:30:21.417500 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Install extension [bin/custom-script-shim install]
2018/03/16 10:30:22.458572 INFO Event: name=Microsoft.Azure.Extensions.CustomScript, op=Install, message=Launch command succeeded: bin/custom-script-shim install, duration=1003
2018/03/16 10:30:22.469614 INFO [Microsoft.Azure.Extensions.CustomScript-2.0.6] Enable extension [bin/custom-script-shim enable]
2018/03/16 10:30:23.540679 INFO Event: name=Microsoft.Azure.Extensions.CustomScript, op=Enable, message=Launch command succeeded: bin/custom-script-shim enable, duration=1068
2018/03/16 10:30:23.686656 INFO Event: name=WALinuxAgent, op=ProcessGoalState, message=Incarnation 3, duration=2754
2018/03/16 10:41:34.023475 INFO Agent WALinuxAgent-2.2.22 launched with command 'python -u bin/WALinuxAgent-2.2.22-py2.7.egg -run-exthandlers' is successfully running
2018/03/16 10:41:34.031516 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.2.22 launched with command 'python -u bin/WALinuxAgent-2.2.22-py2.7.egg -run-exthandlers' is successfully running, duration=0

Contributor guide

No contributing guide indexed for this repository

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.