Container-OS not starting container with cloud-init

1,566 views
Skip to first unread message

Rodrigo Manyari

unread,
May 13, 2017, 12:27:30 PM5/13/17
to gce-discussion
I'm trying to start a container when the VM boots using the user-data metadata key.

When I first create the vm docker ps, docker ps -a and docker images are all empty. If I run /usr/share/cloud/rerun-cloudinit.sh the container specified starts. If I restart the VM I have to run the script again...

This happens both in the dev and stable version.

e.g. (after a restart and having run the rerun script)

rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ Connected, host fingerprint: ssh-rsa 2048 7F:45:C9:A6:C4:44:BD:20:70:6E:63:BB:EE:EA:76:D8:DF:DD:68:D2:74:9F:A9:30:34:BC:2A:B4:92:C2:C7:BD
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ docker ps
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ docker ps -a
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ docker images
REPOSITORY          TAG                 IMAGE ID            CREATED             SIZE
busybox             latest              00f017a8c2a6        9 weeks ago         1.11 MB
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ sudo /usr/share/cloud/rerun-cloudinit.sh 
Cloud-init v. 0.7.6 running 'init' at Sat, 13 May 2017 03:18:04 +0000. Up 101.14 seconds.
ci-info: +++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++
ci-info: +----------+------+------------+-----------------+-------------------+
ci-info: |  Device  |  Up  |  Address   |       Mask      |     Hw-Address    |
ci-info: +----------+------+------------+-----------------+-------------------+
ci-info: |   lo:    | True | 127.0.0.1  |    255.0.0.0    |         .         |
ci-info: |  eth0:   | True | 10.142.0.3 | 255.255.255.255 | 42:01:0a:8e:00:03 |
ci-info: | docker0: | True | 172.17.0.1 |   255.255.0.0   | 02:42:32:1d:0f:1b |
ci-info: +----------+------+------------+-----------------+-------------------+
ci-info: ++++++++++++++++++++++++++++++++Route info++++++++++++++++++++++++++++++++
ci-info: +-------+-------------+------------+-----------------+-----------+-------+
ci-info: | Route | Destination |  Gateway   |     Genmask     | Interface | Flags |
ci-info: +-------+-------------+------------+-----------------+-----------+-------+
ci-info: |   0   |   0.0.0.0   | 10.142.0.1 |     0.0.0.0     |    eth0   |   UG  |
ci-info: |   1   |   0.0.0.0   | 10.142.0.1 |     0.0.0.0     |    eth0   |   UG  |
ci-info: |   2   |  10.142.0.1 |  0.0.0.0   | 255.255.255.255 |    eth0   |   UH  |
ci-info: |   3   |  10.142.0.1 |  0.0.0.0   | 255.255.255.255 |    eth0   |   UH  |
ci-info: |   4   |  172.17.0.0 |  0.0.0.0   |   255.255.0.0   |  docker0  |   U   |
ci-info: +-------+-------------+------------+-----------------+-----------+-------+
Cloud-init v. 0.7.6 running 'modules:config' at Sat, 13 May 2017 03:18:04 +0000. Up 101.53 seconds.
Cloud-init v. 0.7.6 running 'modules:final' at Sat, 13 May 2017 03:18:05 +0000. Up 101.78 seconds.
Cloud-init v. 0.7.6 finished at Sat, 13 May 2017 03:18:05 +0000. Datasource DataSourceGCE.  Up 101.91 seconds
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ docker ps
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES
d353cdce96a6        busybox:latest      "/bin/sleep 3600"   1 seconds ago       Up 1 seconds                            mycloudservice
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ 
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ uname -a
Linux latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 4.4.21+ #1 SMP Tue Jan 17 21:41:52 PST 2017 x86_64 Intel(R) Xeon(R) CPU @ 2.30GHz GenuineIntel GNU/Linux
rmanyari10@latency-node-dc06df29-2254-4667-8b9e-b60ca5ebd513 ~ $ cat /etc/*-release
CHROMEOS_AUSERVER=https://tools.google.com/service/update2
CHROMEOS_BOARD_APPID={76E245CF-C0D0-444D-BA50-36739C18EB00}
CHROMEOS_CANARY_APPID={90F229CE-83E2-4FAF-8479-E368A34938B1}
CHROMEOS_DEVSERVER=
CHROMEOS_RELEASE_APPID={76E245CF-C0D0-444D-BA50-36739C18EB00}
CHROMEOS_RELEASE_BOARD=lakitu-signed-mpkeys
CHROMEOS_RELEASE_BRANCH_NUMBER=66
CHROMEOS_RELEASE_BUILDER_PATH=lakitu-release/R56-9000.66.0
CHROMEOS_RELEASE_BUILD_NUMBER=9000
CHROMEOS_RELEASE_BUILD_TYPE=Official Build
CHROMEOS_RELEASE_CHROME_MILESTONE=56
CHROMEOS_RELEASE_DESCRIPTION=9000.66.0 (Official Build) beta-channel lakitu 
CHROMEOS_RELEASE_NAME=Chrome OS
CHROMEOS_RELEASE_PATCH_NUMBER=0
CHROMEOS_RELEASE_TRACK=beta-channel
CHROMEOS_RELEASE_VERSION=9000.66.0
DEVICETYPE=OTHER
GOOGLE_RELEASE=9000.66.0
HWID_OVERRIDE=LAKITU DEFAULT
BUILD_ID=9000.66.0
NAME="Container-Optimized OS"
GOOGLE_CRASH_ID=Lakitu
VERSION_ID=56
BUG_REPORT_URL=https://crbug.com/new
PRETTY_NAME="Container-Optimized OS from Google"
VERSION=56
GOOGLE_METRICS_PRODUCT_ID=26
HOME_URL="https://cloud.google.com/compute/docs/containers/vm-image/"
ID=gci


Rodrigo

Kamran (Google Cloud Support)

unread,
May 13, 2017, 2:41:08 PM5/13/17
to gce-discussion

Hello Rodrigo,

If possible, can you share the value of user-data metadata key?

Sincerely,

Rodrigo Manyari

unread,
May 14, 2017, 10:48:24 AM5/14/17
to gce-discussion
Hey Kamran,

I'm using the nodejs api to create the VMs. Here is the result of the "Equivalent Rest" call

{
  "kind": "compute#instance",
  "id": "8032063985143894976",
  "creationTimestamp": "2017-05-14T07:43:59.819-07:00",
  "name": "latency-node-5532b797-2c64-49c6-90ce-3776b59bb519",
  "tags": {
    "fingerprint": "42WmSpB8rSM="
  },
  "machineType": "projects/cloud-latency-167422/zones/us-east1-b/machineTypes/f1-micro",
  "status": "RUNNING",
  "zone": "projects/cloud-latency-167422/zones/us-east1-b",
  "networkInterfaces": [
    {
      "kind": "compute#networkInterface",
      "network": "projects/cloud-latency-167422/global/networks/default",
      "subnetwork": "projects/cloud-latency-167422/regions/us-east1/subnetworks/default",
      "networkIP": "10.142.0.2",
      "name": "nic0",
      "accessConfigs": [
        {
          "kind": "compute#accessConfig",
          "type": "ONE_TO_ONE_NAT",
          "name": "External NAT",
          "natIP": "35.185.28.24"
        }
      ]
    }
  ],
  "disks": [
    {
      "kind": "compute#attachedDisk",
      "type": "PERSISTENT",
      "mode": "READ_WRITE",
      "source": "projects/cloud-latency-167422/zones/us-east1-b/disks/latency-node-5532b797-2c64-49c6-90ce-3776b59bb519",
      "deviceName": "persistent-disk-0",
      "index": 0,
      "boot": true,
      "autoDelete": true,
      "licenses": [
        "projects/cos-cloud/global/licenses/cos"
      ],
      "interface": "SCSI"
    }
  ],
  "metadata": {
    "kind": "compute#metadata",
    "fingerprint": "i-uJXhQRGPg=",
    "items": [
      {
        "key": "user-data",
        "value": "#cloud-config\n\nusers:\n- name: cloudservice\n  uid: 2000\n\nwrite_files:\n- path: /etc/systemd/system/cloudservice.service\n  permissions: 0644\n  owner: root\n  content: |\n    [Unit]\n    Description=Start a simple docker container\n\n    [Service]\n    ExecStart=/usr/bin/docker run --rm -u 2000 --name=mycloudservice busybox:latest /bin/sleep 3600\n    ExecStop=/usr/bin/docker stop mycloudservice\n    ExecStopPost=/usr/bin/docker rm mycloudservice\n\nruncmd:\n- systemctl daemon-reload\n- systemctl start cloudservice.service"
      }
    ]
  },
  "selfLink": "projects/cloud-latency-167422/zones/us-east1-b/instances/latency-node-5532b797-2c64-49c6-90ce-3776b59bb519",
  "scheduling": {
    "onHostMaintenance": "TERMINATE",
    "automaticRestart": false,
    "preemptible": true
  },
  "cpuPlatform": "Intel Haswell",
  "labelFingerprint": "42WmSpB8rSM="
}

Kamran (Google Cloud Support)

unread,
May 14, 2017, 8:44:34 PM5/14/17
to gce-discussion

Thank you for providing the requested information. It looks like cloud-init is not able to parse the value you're using for "user-data" key. It throws the following error:

cloud-init[719]: [CLOUDINIT] util.py[DEBUG]: Failed loading yaml blob
                 Traceback (most recent call last):
                   File "/usr/lib64/python2.7/site-packages/cloudinit/util.py", line 717, in load_yaml
                      (allowed, type_utils.obj_name(converted)))
                   TypeError: Yaml load allows (<type 'dict'>,) root types, but got NoneType instead


I will look into the issue further and will write back to you.

Sincerely,

Rodrigo Manyari

unread,
May 17, 2017, 7:21:11 AM5/17/17
to gce-discussion
Not sure which yaml payload you are trying to parse (if it's the one in the HTTP request it's obviously not going to work)

On the other hand I'm not 100% positive that cloud-init is even being kicked off when I boot the VM (this is on a fresh VM):

latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # pwd
/var/lib/cloud/instance
latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # ls
boot-finished     datasource  obj.pkl  sem            user-data.txt.i  vendor-data.txt.i
cloud-config.txt  handlers    scripts  user-data.txt  vendor-data.txt
latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # cat user-data.txt
#cloud-config

users:
- name: cloudservice
  uid: 2000

write_files:
- path: /etc/systemd/system/cloudservice.service
  permissions: 0644
  owner: root
  content: |
    [Unit]
    Description=Start a simple docker container

    [Service]
    ExecStart=/usr/bin/docker run --rm -u 2000 --name=mycloudservice busybox:latest /bin/sleep 3600
    ExecStop=/usr/bin/docker stop mycloudservice
    ExecStopPost=/usr/bin/docker rm mycloudservice

runcmd:
- systemctl daemon-reload
- systemctl start cloudservice.servicelatency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # 
latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # 
latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # tail /var/log/cloud-init.log 
latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance #

The user-data.txt looks fine. The logs are empty which seems odd to me considering that the logging level seems to be debug:

latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 instance # cat /etc/cloud/cloud.cfg.d/05_logging.cfg

 < omitted for simplicity >

 - &log_file |
   [handler_cloudLogHandler]
   class=FileHandler
   level=DEBUG
   formatter=arg0Formatter
   args=('/var/log/cloud-init.log',)

 < omitted for simplicity >

Rodrigo Manyari

unread,
May 17, 2017, 7:32:39 AM5/17/17
to gce-discussion
Actually I tried loading user-data.txt with the same python script that you tried and it looked fine. I just copied the script to /tmp and added a few lines to read/parse the file:

< right below the load_yaml function in line 727 >
with open('/var/lib/cloud/instance/user-data.txt', 'r') as content_file:
    content = content_file.read()
    print(load_yaml(content))


And then run:

latency-node-ce990c94-bbb3-458c-ad26-9a8a242693b0 tmp # python util.py 
{'users': [{'name': 'cloudservice', 'uid': 2000}], 'write_files': [{'owner': 'root', 'path': '/etc/systemd/system/cloudservice.service', 'content': '[Unit]\nDescription=Start a simple docker container\n\n[Service]\nExecStart=/usr/bin/docker run --rm -u 2000 --name=mycloudservice busybox:latest /bin/sleep 3600\nExecStop=/usr/bin/docker stop mycloudservice\nExecStopPost=/usr/bin/docker rm mycloudservice\n', 'permissions': 420}], 'runcmd': ['systemctl daemon-reload', 'systemctl start cloudservice.service']}


No error...

Kamran (Google Cloud Support)

unread,
May 17, 2017, 8:37:04 PM5/17/17
to gce-discussion

For seeing clound-init logs try the following command:

sudo journalctl -u cloud-init


Please let me know if you see any errors.

Sincerely,

Rodrigo Manyari

unread,
May 18, 2017, 9:58:50 AM5/18/17
to gce-discussion
Nothing too exciting...

rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $ sudo journalctl -u cloud-init > cloud-init
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $ cat cloud-init 
-- Logs begin at Thu 2017-05-18 13:54:13 UTC, end at Thu 2017-05-18 13:56:54 UTC. --
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: Cloud-init v. 0.7.6 running 'init' at Thu, 18 May 2017 13:54:16 +0000. Up 4.12 seconds.
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.6 running 'init' at Thu, 18 May 2017 13:54:16 +0000. Up 4.12 seconds.
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 202:4
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Running command ['netstat', '-rn'] with allowed return codes [0] (shell=False, capture=True)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: ++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: +--------+------+------------+-----------------+-------------------+
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: | Device |  Up  |  Address   |       Mask      |     Hw-Address    |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: +--------+------+------------+-----------------+-------------------+
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: |  lo:   | True | 127.0.0.1  |    255.0.0.0    |         .         |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: | eth0:  | True | 10.142.0.3 | 255.255.255.255 | 42:01:0a:8e:00:03 |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: +--------+------+------------+-----------------+-------------------+
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: ++++++++++++++++++++++++++++++++Route info++++++++++++++++++++++++++++++++
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: +-------+-------------+------------+-----------------+-----------+-------+
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: | Route | Destination |  Gateway   |     Genmask     | Interface | Flags |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: +-------+-------------+------------+-----------------+-----------+-------+
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: |   0   |   0.0.0.0   | 10.142.0.1 |     0.0.0.0     |    eth0   |   UG  |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: |   1   |   0.0.0.0   | 10.142.0.1 |     0.0.0.0     |    eth0   |   UG  |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: |   2   |  10.142.0.1 |  0.0.0.0   | 255.255.255.255 |    eth0   |   UH  |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: |   3   |  10.142.0.1 |  0.0.0.0   | 255.255.255.255 |    eth0   |   UH  |
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: ci-info: +-------+-------------+------------+-----------------+-----------+-------+
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/data/no-net (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cloud-init[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early.
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Looking for for data source in: ['GCE', 'NoCloud', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Searching for data source in: ['DataSourceGCE', 'DataSourceNoCloudNet', 'DataSourceNone']
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceGCE.DataSourceGCE'>
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://metadata.google.internal/computeMetadata/v1/instance/id' with {'url': 'http://metadata.google.internal/computeMetadata/v1/instance/id', 'headers': {'X-Google-Metadata-Request': True}, 'allow_redirects': True, 'method': 'GET'} configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://metadata.google.internal/computeMetadata/v1/instance/id (200, 19b) after 1 attempts
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://metadata.google.internal/computeMetadata/v1/instance/zone' with {'url': 'http://metadata.google.internal/computeMetadata/v1/instance/zone', 'headers': {'X-Google-Metadata-Request': True}, 'allow_redirects': True, 'method': 'GET'} configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://metadata.google.internal/computeMetadata/v1/instance/zone (200, 38b) after 1 attempts
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://metadata.google.internal/computeMetadata/v1/instance/hostname' with {'url': 'http://metadata.google.internal/computeMetadata/v1/instance/hostname', 'headers': {'X-Google-Metadata-Request': True}, 'allow_redirects': True, 'method': 'GET'} configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://metadata.google.internal/computeMetadata/v1/instance/hostname (200, 81b) after 1 attempts
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://metadata.google.internal/computeMetadata/v1/project/attributes/sshKeys' with {'url': 'http://metadata.google.internal/computeMetadata/v1/project/attributes/sshKeys', 'headers': {'X-Google-Metadata-Request': True}, 'allow_redirects': True, 'method': 'GET'} configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://metadata.google.internal/computeMetadata/v1/project/attributes/sshKeys (200, 1468b) after 1 attempts
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: [0/1] open 'http://metadata.google.internal/computeMetadata/v1/instance/attributes/user-data' with {'url': 'http://metadata.google.internal/computeMetadata/v1/instance/attributes/user-data', 'headers': {'X-Google-Metadata-Request': True}, 'allow_redirects': True, 'method': 'GET'} configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] url_helper.py[DEBUG]: Read from http://metadata.google.internal/computeMetadata/v1/instance/attributes/user-data (200, 512b) after 1 attempts
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[INFO]: Loaded datasource DataSourceGCE - DataSourceGCE
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 566 bytes from /proc/cmdline
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 2338 bytes from /etc/cloud/cloud.cfg
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 2338 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 1910 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 1910 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/2113797500219431322'
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instances/2113797500219431322/datasource (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/datasource - wb: [420] 29 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [420] 29 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [420] 20 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [420] 20 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cloud-init[DEBUG]: init will now be targeting instance id: 2113797500219431322
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 566 bytes from /proc/cmdline
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 2338 bytes from /etc/cloud/cloud.cfg
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 2338 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 1910 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 1910 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [256] 6394 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/user-data.txt - wb: [384] 512 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 512 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/user-data.txt.i - wb: [384] 854 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/vendor-data.txt - wb: [384] 4 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/vendor-data.txt.i - wb: [384] 345 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/sem/consume_data - wb: [420] 19 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/2113797500219431322/sem/consume_data'>)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Added default handler for set(['text/cloud-config-jsonp', 'text/cloud-config']) from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Added default handler for set(['text/x-shellscript']) from ShellScriptPartHandler: [['text/x-shellscript']]
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Added default handler for set(['text/cloud-boothook']) from BootHookPartHandler: [['text/cloud-boothook']]
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Added default handler for set(['text/upstart-job']) from UpstartJobPartHandler: [['text/upstart-job']]
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: {'Content-Type': 'text/cloud-config', 'Content-Disposition': 'attachment; filename="part-001"', 'MIME-Version': '1.0'}
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 512 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/2113797500219431322/cloud-config.txt - wb: [384] 596 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: no vendordata from datasource
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 566 bytes from /proc/cmdline
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 2338 bytes from /etc/cloud/cloud.cfg
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 2338 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 1910 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 1910 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 596 bytes from /var/lib/cloud/instance/cloud-config.txt
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 596 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 596 bytes from /var/lib/cloud/instance/cloud-config.txt
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 596 with allowed root types (<type 'dict'>,)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/lib64/python2.7/site-packages/cloudinit/config/cc_bootcmd.pyc'>) with frequency once
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_bootcmd.once - wb: [420] 19 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] helpers.py[DEBUG]: Running config-bootcmd using lock (<FileLock using file '/var/lib/cloud/sem/config_bootcmd.once'>)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Running module update_etc_hosts (<module 'cloudinit.config.cc_update_etc_hosts' from '/usr/lib64/python2.7/site-packages/cloudinit/config/cc_update_etc_hosts.pyc'>) with frequency always
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x7ff8380c04d0>)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/lib64/python2.7/site-packages/cloudinit/config/cc_users_groups.pyc'>) with frequency once
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_users_groups.once - wb: [420] 19 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/sem/config_users_groups.once'>)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] __init__.py[DEBUG]: Adding user cloudservice
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['useradd', 'cloudservice', '-K', 'UID_MIN=2000', '-K', 'UID_MAX=4999', '--uid', '2000', '-m']
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 useradd[811]: new group: name=cloudservice, GID=2000
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 useradd[811]: new user: name=cloudservice, UID=2000, GID=2000, home=/home/cloudservice, shell=/bin/bash
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Running command ['passwd', '-l', 'cloudservice'] with allowed return codes [0] (shell=False, capture=True)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 passwd[816]: password for 'cloudservice' changed by 'root'
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/lib64/python2.7/site-packages/cloudinit/config/cc_write_files.pyc'>) with frequency always
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] helpers.py[DEBUG]: Running config-write-files using lock (<cloudinit.helpers.DummyLock object at 0x7ff8380c0c50>)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /etc/systemd/system/cloudservice.service - wb: [420] 250 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Changing the ownership of /etc/systemd/system/cloudservice.service to 0:-1
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] stages.py[DEBUG]: Running module rsyslog (<module 'cloudinit.config.cc_rsyslog' from '/usr/lib64/python2.7/site-packages/cloudinit/config/cc_rsyslog.pyc'>) with frequency once
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_rsyslog.once - wb: [420] 19 bytes
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/sem/config_rsyslog.once'>)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] cloud-init[DEBUG]: Ran 5 modules with 0 failures
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: Read 10 bytes from /proc/uptime
May 18 13:54:16 latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 cloud-init[787]: [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'init' took 0.250 seconds (0.25)
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $ docker images
REPOSITORY          TAG                 IMAGE ID            CREATED             SIZE
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $ docker ps -a
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $

Rodrigo Manyari

unread,
May 18, 2017, 10:00:11 AM5/18/17
to gce-discussion
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $ uname -a
Linux latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 4.4.35+ #1 SMP Wed Apr 5 13:00:57 PDT 2017 x86_64 Intel(R) Xeon(R) CPU @ 2.30GHz GenuineIntel GNU/Linux
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $ cat /etc/*-release
CHROMEOS_AUSERVER=https://tools.google.com/service/update2
CHROMEOS_BOARD_APPID={76E245CF-C0D0-444D-BA50-36739C18EB00}
CHROMEOS_CANARY_APPID={90F229CE-83E2-4FAF-8479-E368A34938B1}
CHROMEOS_DEVSERVER=
CHROMEOS_RELEASE_APPID={76E245CF-C0D0-444D-BA50-36739C18EB00}
CHROMEOS_RELEASE_BOARD=lakitu-signed-mpkeys
CHROMEOS_RELEASE_BRANCH_NUMBER=64
CHROMEOS_RELEASE_BUILDER_PATH=lakitu-release/R57-9202.64.0
CHROMEOS_RELEASE_BUILD_NUMBER=9202
CHROMEOS_RELEASE_BUILD_TYPE=Official Build
CHROMEOS_RELEASE_CHROME_MILESTONE=57
CHROMEOS_RELEASE_DESCRIPTION=9202.64.0 (Official Build) stable-channel lakitu 
CHROMEOS_RELEASE_NAME=Chrome OS
CHROMEOS_RELEASE_PATCH_NUMBER=0
CHROMEOS_RELEASE_TRACK=stable-channel
CHROMEOS_RELEASE_VERSION=9202.64.0
DEVICETYPE=OTHER
GOOGLE_RELEASE=9202.64.0
HWID_OVERRIDE=LAKITU DEFAULT
BUILD_ID=9202.64.0
NAME="Container-Optimized OS"
GOOGLE_CRASH_ID=Lakitu
VERSION_ID=57
BUG_REPORT_URL=https://crbug.com/new
PRETTY_NAME="Container-Optimized OS from Google"
VERSION=57
GOOGLE_METRICS_PRODUCT_ID=26
HOME_URL="https://cloud.google.com/compute/docs/containers/vm-image/"
ID=cos
rmanyari10@latency-node-f686a85b-075d-4c7a-9764-c516d7a2f803 ~ $

Kamran (Google Cloud Support)

unread,
May 24, 2017, 9:01:54 PM5/24/17
to gce-discussion

Hello Rodrigo,

Can you try that cloud-init script on a VM created from latest cos-dev image (currently the latest is Container-Optimized OS, 60-9565.0.0 dev) and let me if it resolves the issue?

Sincerely,

Rodrigo Manyari

unread,
May 29, 2017, 1:26:07 PM5/29/17
to gce-discussion
Same problem. I'll just use something else, you can close this thread on your end. Thanks

Kamran (Google Cloud Support)

unread,
May 30, 2017, 9:03:33 PM5/30/17
to gce-dis...@googlegroups.com
Thank you for your feedback. Unfortunately I was not able to reproduce this issue to be helpful. The script runs fine on my side. If you're still interested in debugging the issue you may take a look at /etc/systemd/system/ path to see if cloudservice.service has been created by script or not. If it's created but not running, then use the following command to see the logs that are specific to this service:

$ sudo journalctl -u cloudservice.service

You may also try the script that are described in this article that runs some docker pre-configuration script.

Sincerely,
Reply all
Reply to author
Forward
0 new messages