Jul 10 13:48:21 localhost kernel: [ 0.000000] Initializing cgroup subsys cpuset Jul 10 13:48:21 localhost kernel: [ 0.000000] Initializing cgroup subsys cpu Jul 10 13:48:21 localhost kernel: [ 0.000000] Initializing cgroup subsys cpuacct Jul 10 13:48:21 localhost kernel: [ 0.000000] Linux version 3.19.0-22-generic (buildd@allspice) (gcc version 4.9.2 (Ubuntu 4.9.2-10ubuntu13) ) #22-Ubuntu SMP Tue Jun 16 17:15:15 UTC 2015 (Ubuntu 3.19.0-22.22-generic 3.19.8-ckt1) Jul 10 13:48:21 localhost kernel: [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.19.0-22-generic root=LABEL=system-a ro init=/lib/systemd/systemd console=tty1 console=ttyS0 panic=-1 Jul 10 13:48:21 localhost kernel: [ 0.000000] KERNEL supported cpus: Jul 10 13:48:21 localhost kernel: [ 0.000000] Intel GenuineIntel Jul 10 13:48:21 localhost kernel: [ 0.000000] AMD AuthenticAMD Jul 10 13:48:21 localhost kernel: [ 0.000000] Centaur CentaurHauls Jul 10 13:48:21 localhost kernel: [ 0.000000] e820: BIOS-provided physical RAM map: Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001ffdffff] usable Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x000000001ffe0000-0x000000001fffffff] reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] NX (Execute Disable) protection: active Jul 10 13:48:21 localhost kernel: [ 0.000000] SMBIOS 2.8 present. Jul 10 13:48:21 localhost kernel: [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20150306_163512-brownie 04/01/2014 Jul 10 13:48:21 localhost kernel: [ 0.000000] Hypervisor detected: KVM Jul 10 13:48:21 localhost kernel: [ 0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable Jul 10 13:48:21 localhost kernel: [ 0.000000] AGP: No AGP bridge found Jul 10 13:48:21 localhost kernel: [ 0.000000] e820: last_pfn = 0x1ffe0 max_arch_pfn = 0x400000000 Jul 10 13:48:21 localhost kernel: [ 0.000000] MTRR default type: write-back Jul 10 13:48:21 localhost kernel: [ 0.000000] MTRR fixed ranges enabled: Jul 10 13:48:21 localhost kernel: [ 0.000000] 00000-9FFFF write-back Jul 10 13:48:21 localhost kernel: [ 0.000000] A0000-BFFFF uncachable Jul 10 13:48:21 localhost kernel: [ 0.000000] C0000-FFFFF write-protect Jul 10 13:48:21 localhost kernel: [ 0.000000] MTRR variable ranges enabled: Jul 10 13:48:21 localhost kernel: [ 0.000000] 0 base 0080000000 mask FF80000000 uncachable Jul 10 13:48:21 localhost kernel: [ 0.000000] 1 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] 2 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] 3 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] 4 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] 5 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] 6 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] 7 disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] PAT not supported by CPU. Jul 10 13:48:21 localhost kernel: [ 0.000000] found SMP MP-table at [mem 0x000f1090-0x000f109f] mapped at [ffff8800000f1090] Jul 10 13:48:21 localhost kernel: [ 0.000000] Scanning 1 areas for low memory corruption Jul 10 13:48:21 localhost kernel: [ 0.000000] Base memory trampoline at [ffff880000099000] 99000 size 24576 Jul 10 13:48:21 localhost kernel: [ 0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] [mem 0x00000000-0x000fffff] page 4k Jul 10 13:48:21 localhost kernel: [ 0.000000] BRK [0x01fe5000, 0x01fe5fff] PGTABLE Jul 10 13:48:21 localhost kernel: [ 0.000000] BRK [0x01fe6000, 0x01fe6fff] PGTABLE Jul 10 13:48:21 localhost kernel: [ 0.000000] BRK [0x01fe7000, 0x01fe7fff] PGTABLE Jul 10 13:48:21 localhost kernel: [ 0.000000] init_memory_mapping: [mem 0x1fc00000-0x1fdfffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] [mem 0x1fc00000-0x1fdfffff] page 2M Jul 10 13:48:21 localhost kernel: [ 0.000000] init_memory_mapping: [mem 0x00100000-0x1fbfffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] [mem 0x00100000-0x001fffff] page 4k Jul 10 13:48:21 localhost kernel: [ 0.000000] [mem 0x00200000-0x1fbfffff] page 2M Jul 10 13:48:21 localhost kernel: [ 0.000000] init_memory_mapping: [mem 0x1fe00000-0x1ffdffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] [mem 0x1fe00000-0x1ffdffff] page 4k Jul 10 13:48:21 localhost kernel: [ 0.000000] BRK [0x01fe8000, 0x01fe8fff] PGTABLE Jul 10 13:48:21 localhost kernel: [ 0.000000] RAMDISK: [mem 0x1ea56000-0x1f824fff] Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: Early table checksum verification disabled Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: RSDP 0x00000000000F0EA0 000014 (v00 BOCHS ) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: RSDT 0x000000001FFE1853 000034 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: FACP 0x000000001FFE0E48 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: DSDT 0x000000001FFE0040 000E08 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: FACS 0x000000001FFE0000 000040 Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: SSDT 0x000000001FFE0EBC 0008E7 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: APIC 0x000000001FFE17A3 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: HPET 0x000000001FFE181B 000038 (v01 BOCHS BXPCHPET 00000001 BXPC 00000001) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: Local APIC address 0xfee00000 Jul 10 13:48:21 localhost kernel: [ 0.000000] No NUMA configuration found Jul 10 13:48:21 localhost kernel: [ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001ffdffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] NODE_DATA(0) allocated [mem 0x1ffdb000-0x1ffdffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 Jul 10 13:48:21 localhost kernel: [ 0.000000] kvm-clock: cpu 0, msr 0:1ffd7001, primary cpu clock Jul 10 13:48:21 localhost kernel: [ 0.000000] [ffffea0000000000-ffffea00007fffff] PMD -> [ffff88001de00000-ffff88001e5fffff] on node 0 Jul 10 13:48:21 localhost kernel: [ 0.000000] Zone ranges: Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA [mem 0x00001000-0x00ffffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA32 [mem 0x01000000-0x1ffdffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] Normal empty Jul 10 13:48:21 localhost kernel: [ 0.000000] Movable zone start for each node Jul 10 13:48:21 localhost kernel: [ 0.000000] Early memory node ranges Jul 10 13:48:21 localhost kernel: [ 0.000000] node 0: [mem 0x00001000-0x0009efff] Jul 10 13:48:21 localhost kernel: [ 0.000000] node 0: [mem 0x00100000-0x1ffdffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] Initmem setup node 0 [mem 0x00001000-0x1ffdffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] On node 0 totalpages: 130942 Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA zone: 64 pages used for memmap Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA zone: 21 pages reserved Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA zone: 3998 pages, LIFO batch:0 Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA32 zone: 1984 pages used for memmap Jul 10 13:48:21 localhost kernel: [ 0.000000] DMA32 zone: 126944 pages, LIFO batch:31 Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: PM-Timer IO Port: 0x608 Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: Local APIC address 0xfee00000 Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0]) Jul 10 13:48:21 localhost kernel: [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: IRQ0 used by override. Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: IRQ5 used by override. Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: IRQ9 used by override. Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: IRQ10 used by override. Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: IRQ11 used by override. Jul 10 13:48:21 localhost kernel: [ 0.000000] Using ACPI (MADT) for SMP configuration information Jul 10 13:48:21 localhost kernel: [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 Jul 10 13:48:21 localhost kernel: [ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs Jul 10 13:48:21 localhost kernel: [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] Jul 10 13:48:21 localhost kernel: [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] Jul 10 13:48:21 localhost kernel: [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] Jul 10 13:48:21 localhost kernel: [ 0.000000] e820: [mem 0x20000000-0xfeffbfff] available for PCI devices Jul 10 13:48:21 localhost kernel: [ 0.000000] Booting paravirtualized kernel on KVM Jul 10 13:48:21 localhost kernel: [ 0.000000] setup_percpu: NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:1 nr_node_ids:1 Jul 10 13:48:21 localhost kernel: [ 0.000000] PERCPU: Embedded 31 pages/cpu @ffff88001fc00000 s87040 r8192 d31744 u2097152 Jul 10 13:48:21 localhost kernel: [ 0.000000] pcpu-alloc: s87040 r8192 d31744 u2097152 alloc=1*2097152 Jul 10 13:48:21 localhost kernel: [ 0.000000] pcpu-alloc: [0] 0 Jul 10 13:48:21 localhost kernel: [ 0.000000] KVM setup async PF for cpu 0 Jul 10 13:48:21 localhost kernel: [ 0.000000] kvm-stealtime: cpu 0, msr 1fc0e1c0 Jul 10 13:48:21 localhost kernel: [ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 128873 Jul 10 13:48:21 localhost kernel: [ 0.000000] Policy zone: DMA32 Jul 10 13:48:21 localhost kernel: [ 0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-3.19.0-22-generic root=LABEL=system-a ro init=/lib/systemd/systemd console=tty1 console=ttyS0 panic=-1 Jul 10 13:48:21 localhost kernel: [ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes) Jul 10 13:48:21 localhost kernel: [ 0.000000] AGP: Checking aperture... Jul 10 13:48:21 localhost kernel: [ 0.000000] AGP: No AGP bridge found Jul 10 13:48:21 localhost kernel: [ 0.000000] Calgary: detecting Calgary via BIOS EBDA area Jul 10 13:48:21 localhost kernel: [ 0.000000] Calgary: Unable to locate Rio Grande table in EBDA - bailing! Jul 10 13:48:21 localhost kernel: [ 0.000000] Memory: 484656K/523768K available (8001K kernel code, 1232K rwdata, 3752K rodata, 1408K init, 1300K bss, 39112K reserved, 0K cma-reserved) Jul 10 13:48:21 localhost kernel: [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 Jul 10 13:48:21 localhost kernel: [ 0.000000] Hierarchical RCU implementation. Jul 10 13:48:21 localhost kernel: [ 0.000000] RCU dyntick-idle grace-period acceleration is enabled. Jul 10 13:48:21 localhost kernel: [ 0.000000] RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=1. Jul 10 13:48:21 localhost kernel: [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1 Jul 10 13:48:21 localhost kernel: [ 0.000000] NR_IRQS:16640 nr_irqs:256 16 Jul 10 13:48:21 localhost kernel: [ 0.000000] Offload RCU callbacks from all CPUs Jul 10 13:48:21 localhost kernel: [ 0.000000] Offload RCU callbacks from CPUs: 0. Jul 10 13:48:21 localhost kernel: [ 0.000000] Console: colour VGA+ 80x25 Jul 10 13:48:21 localhost kernel: [ 0.000000] console [tty1] enabled Jul 10 13:48:21 localhost kernel: [ 0.000000] console [ttyS0] enabled Jul 10 13:48:21 localhost kernel: [ 0.000000] hpet clockevent registered Jul 10 13:48:21 localhost kernel: [ 0.000000] tsc: Detected 1995.379 MHz processor Jul 10 13:48:21 localhost kernel: [ 0.008000] Calibrating delay loop (skipped) preset value.. 3990.75 BogoMIPS (lpj=7981516) Jul 10 13:48:21 localhost kernel: [ 0.008000] pid_max: default: 32768 minimum: 301 Jul 10 13:48:21 localhost kernel: [ 0.008000] ACPI: Core revision 20141107 Jul 10 13:48:21 localhost kernel: [ 0.008000] ACPI: All ACPI Tables successfully acquired Jul 10 13:48:21 localhost kernel: [ 0.008566] Security Framework initialized Jul 10 13:48:21 localhost kernel: [ 0.009170] AppArmor: AppArmor initialized Jul 10 13:48:21 localhost kernel: [ 0.009752] Yama: becoming mindful. Jul 10 13:48:21 localhost kernel: [ 0.010351] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes) Jul 10 13:48:21 localhost kernel: [ 0.011229] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes) Jul 10 13:48:21 localhost kernel: [ 0.012037] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes) Jul 10 13:48:21 localhost kernel: [ 0.012958] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes) Jul 10 13:48:21 localhost kernel: [ 0.014151] Initializing cgroup subsys memory Jul 10 13:48:21 localhost kernel: [ 0.014793] Initializing cgroup subsys devices Jul 10 13:48:21 localhost kernel: [ 0.015376] Initializing cgroup subsys freezer Jul 10 13:48:21 localhost kernel: [ 0.016005] Initializing cgroup subsys net_cls Jul 10 13:48:21 localhost kernel: [ 0.016586] Initializing cgroup subsys blkio Jul 10 13:48:21 localhost kernel: [ 0.017170] Initializing cgroup subsys perf_event Jul 10 13:48:21 localhost kernel: [ 0.017773] Initializing cgroup subsys net_prio Jul 10 13:48:21 localhost kernel: [ 0.018360] Initializing cgroup subsys hugetlb Jul 10 13:48:21 localhost kernel: [ 0.018984] mce: CPU supports 10 MCE banks Jul 10 13:48:21 localhost kernel: [ 0.019557] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 Jul 10 13:48:21 localhost kernel: [ 0.019557] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 Jul 10 13:48:21 localhost kernel: [ 0.029537] Freeing SMP alternatives memory: 32K (ffffffff81e96000 - ffffffff81e9e000) Jul 10 13:48:21 localhost kernel: [ 0.032000] ftrace: allocating 30088 entries in 118 pages Jul 10 13:48:21 localhost kernel: [ 0.044216] Enabling x2apic Jul 10 13:48:21 localhost kernel: [ 0.044724] Enabled x2apic Jul 10 13:48:21 localhost kernel: [ 0.045357] Switched APIC routing to physical x2apic. Jul 10 13:48:21 localhost kernel: [ 0.048540] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Jul 10 13:48:21 localhost kernel: [ 0.049253] smpboot: CPU0: Intel QEMU Virtual CPU version 2.2.0 (fam: 06, model: 06, stepping: 03) Jul 10 13:48:21 localhost kernel: [ 0.052000] Performance Events: Broken PMU hardware detected, using software events only. Jul 10 13:48:21 localhost kernel: [ 0.052000] Failed to access perfctr msr (MSR c1 is 0) Jul 10 13:48:21 localhost kernel: [ 0.052000] x86: Booted up 1 node, 1 CPUs Jul 10 13:48:21 localhost kernel: [ 0.052000] smpboot: Total of 1 processors activated (3990.75 BogoMIPS) Jul 10 13:48:21 localhost kernel: [ 0.052000] devtmpfs: initialized Jul 10 13:48:21 localhost kernel: [ 0.053205] evm: security.selinux Jul 10 13:48:21 localhost kernel: [ 0.053681] evm: security.SMACK64 Jul 10 13:48:21 localhost kernel: [ 0.054153] evm: security.SMACK64EXEC Jul 10 13:48:21 localhost kernel: [ 0.054656] evm: security.SMACK64TRANSMUTE Jul 10 13:48:21 localhost kernel: [ 0.055195] evm: security.SMACK64MMAP Jul 10 13:48:21 localhost kernel: [ 0.056001] evm: security.ima Jul 10 13:48:21 localhost kernel: [ 0.056502] evm: security.capability Jul 10 13:48:21 localhost kernel: [ 0.057046] NMI watchdog: disabled (cpu0): hardware events not enabled Jul 10 13:48:21 localhost kernel: [ 0.057946] pinctrl core: initialized pinctrl subsystem Jul 10 13:48:21 localhost kernel: [ 0.058734] RTC time: 13:48:17, date: 07/10/15 Jul 10 13:48:21 localhost kernel: [ 0.059370] NET: Registered protocol family 16 Jul 10 13:48:21 localhost kernel: [ 0.060124] cpuidle: using governor ladder Jul 10 13:48:21 localhost kernel: [ 0.060669] cpuidle: using governor menu Jul 10 13:48:21 localhost kernel: [ 0.061232] ACPI: bus type PCI registered Jul 10 13:48:21 localhost kernel: [ 0.061782] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Jul 10 13:48:21 localhost kernel: [ 0.062652] PCI: Using configuration type 1 for base access Jul 10 13:48:21 localhost kernel: [ 0.064408] ACPI: Added _OSI(Module Device) Jul 10 13:48:21 localhost kernel: [ 0.064966] ACPI: Added _OSI(Processor Device) Jul 10 13:48:21 localhost kernel: [ 0.065536] ACPI: Added _OSI(3.0 _SCP Extensions) Jul 10 13:48:21 localhost kernel: [ 0.068006] ACPI: Added _OSI(Processor Aggregator Device) Jul 10 13:48:21 localhost kernel: [ 0.069582] ACPI: Interpreter enabled Jul 10 13:48:21 localhost kernel: [ 0.070360] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S1_] (20141107/hwxface-580) Jul 10 13:48:21 localhost kernel: [ 0.072449] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S2_] (20141107/hwxface-580) Jul 10 13:48:21 localhost kernel: [ 0.073860] ACPI: (supports S0 S3 S4 S5) Jul 10 13:48:21 localhost kernel: [ 0.074400] ACPI: Using IOAPIC for interrupt routing Jul 10 13:48:21 localhost kernel: [ 0.075071] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Jul 10 13:48:21 localhost kernel: [ 0.077557] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Jul 10 13:48:21 localhost kernel: [ 0.078331] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI] Jul 10 13:48:21 localhost kernel: [ 0.079160] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM Jul 10 13:48:21 localhost kernel: [ 0.080054] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. Jul 10 13:48:21 localhost kernel: [ 0.081599] acpiphp: Slot [3] registered Jul 10 13:48:21 localhost kernel: [ 0.082157] acpiphp: Slot [4] registered Jul 10 13:48:21 localhost kernel: [ 0.082713] acpiphp: Slot [5] registered Jul 10 13:48:21 localhost kernel: [ 0.083269] acpiphp: Slot [6] registered Jul 10 13:48:21 localhost kernel: [ 0.084014] acpiphp: Slot [7] registered Jul 10 13:48:21 localhost kernel: [ 0.084591] acpiphp: Slot [8] registered Jul 10 13:48:21 localhost kernel: [ 0.085181] acpiphp: Slot [9] registered Jul 10 13:48:21 localhost kernel: [ 0.085788] acpiphp: Slot [10] registered Jul 10 13:48:21 localhost kernel: [ 0.086413] acpiphp: Slot [11] registered Jul 10 13:48:21 localhost kernel: [ 0.086987] acpiphp: Slot [12] registered Jul 10 13:48:21 localhost kernel: [ 0.088026] acpiphp: Slot [13] registered Jul 10 13:48:21 localhost kernel: [ 0.088895] acpiphp: Slot [14] registered Jul 10 13:48:21 localhost kernel: [ 0.089747] acpiphp: Slot [15] registered Jul 10 13:48:21 localhost kernel: [ 0.091496] acpiphp: Slot [16] registered Jul 10 13:48:21 localhost kernel: [ 0.092039] acpiphp: Slot [17] registered Jul 10 13:48:21 localhost kernel: [ 0.092659] acpiphp: Slot [18] registered Jul 10 13:48:21 localhost kernel: [ 0.093221] acpiphp: Slot [19] registered Jul 10 13:48:21 localhost kernel: [ 0.093784] acpiphp: Slot [20] registered Jul 10 13:48:21 localhost kernel: [ 0.094346] acpiphp: Slot [21] registered Jul 10 13:48:21 localhost kernel: [ 0.094907] acpiphp: Slot [22] registered Jul 10 13:48:21 localhost kernel: [ 0.095467] acpiphp: Slot [23] registered Jul 10 13:48:21 localhost kernel: [ 0.096014] acpiphp: Slot [24] registered Jul 10 13:48:21 localhost kernel: [ 0.096593] acpiphp: Slot [25] registered Jul 10 13:48:21 localhost kernel: [ 0.097173] acpiphp: Slot [26] registered Jul 10 13:48:21 localhost kernel: [ 0.100021] acpiphp: Slot [27] registered Jul 10 13:48:21 localhost kernel: [ 0.100632] acpiphp: Slot [28] registered Jul 10 13:48:21 localhost kernel: [ 0.101219] acpiphp: Slot [29] registered Jul 10 13:48:21 localhost kernel: [ 0.101805] acpiphp: Slot [30] registered Jul 10 13:48:21 localhost kernel: [ 0.102393] acpiphp: Slot [31] registered Jul 10 13:48:21 localhost kernel: [ 0.102948] PCI host bridge to bus 0000:00 Jul 10 13:48:21 localhost kernel: [ 0.103546] pci_bus 0000:00: root bus resource [bus 00-ff] Jul 10 13:48:21 localhost kernel: [ 0.104003] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7] Jul 10 13:48:21 localhost kernel: [ 0.104769] pci_bus 0000:00: root bus resource [io 0x0d00-0xadff] Jul 10 13:48:21 localhost kernel: [ 0.105511] pci_bus 0000:00: root bus resource [io 0xae0f-0xaeff] Jul 10 13:48:21 localhost kernel: [ 0.106275] pci_bus 0000:00: root bus resource [io 0xaf20-0xafdf] Jul 10 13:48:21 localhost kernel: [ 0.107017] pci_bus 0000:00: root bus resource [io 0xafe4-0xffff] Jul 10 13:48:21 localhost kernel: [ 0.108002] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff] Jul 10 13:48:21 localhost kernel: [ 0.108837] pci_bus 0000:00: root bus resource [mem 0x20000000-0xfebfffff] Jul 10 13:48:21 localhost kernel: [ 0.109730] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 Jul 10 13:48:21 localhost kernel: [ 0.110059] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 Jul 10 13:48:21 localhost kernel: [ 0.110404] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 Jul 10 13:48:21 localhost kernel: [ 0.112582] pci 0000:00:01.1: reg 0x20: [io 0xc040-0xc04f] Jul 10 13:48:21 localhost kernel: [ 0.113339] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] Jul 10 13:48:21 localhost kernel: [ 0.114185] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] Jul 10 13:48:21 localhost kernel: [ 0.114982] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] Jul 10 13:48:21 localhost kernel: [ 0.115828] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] Jul 10 13:48:21 localhost kernel: [ 0.116106] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 Jul 10 13:48:21 localhost kernel: [ 0.116344] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI Jul 10 13:48:21 localhost kernel: [ 0.117448] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB Jul 10 13:48:21 localhost kernel: [ 0.118484] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 Jul 10 13:48:21 localhost kernel: [ 0.119282] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref] Jul 10 13:48:21 localhost kernel: [ 0.120968] pci 0000:00:02.0: reg 0x18: [mem 0xfebf0000-0xfebf0fff] Jul 10 13:48:21 localhost kernel: [ 0.123598] pci 0000:00:02.0: reg 0x30: [mem 0xfebe0000-0xfebeffff pref] Jul 10 13:48:21 localhost kernel: [ 0.124093] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000 Jul 10 13:48:21 localhost kernel: [ 0.124709] pci 0000:00:03.0: reg 0x10: [mem 0xfebc0000-0xfebdffff] Jul 10 13:48:21 localhost kernel: [ 0.125354] pci 0000:00:03.0: reg 0x14: [io 0xc000-0xc03f] Jul 10 13:48:21 localhost kernel: [ 0.128658] pci 0000:00:03.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] Jul 10 13:48:21 localhost kernel: [ 0.131293] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) Jul 10 13:48:21 localhost kernel: [ 0.132435] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11) Jul 10 13:48:21 localhost kernel: [ 0.133446] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11) Jul 10 13:48:21 localhost kernel: [ 0.134455] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11) Jul 10 13:48:21 localhost kernel: [ 0.135437] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) Jul 10 13:48:21 localhost kernel: [ 0.136431] ACPI: Enabled 16 GPEs in block 00 to 0F Jul 10 13:48:21 localhost kernel: [ 0.137269] vgaarb: setting as boot device: PCI:0000:00:02.0 Jul 10 13:48:21 localhost kernel: [ 0.137962] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none Jul 10 13:48:21 localhost kernel: [ 0.139015] vgaarb: loaded Jul 10 13:48:21 localhost kernel: [ 0.139452] vgaarb: bridge control possible 0000:00:02.0 Jul 10 13:48:21 localhost kernel: [ 0.140174] SCSI subsystem initialized Jul 10 13:48:21 localhost kernel: [ 0.140737] libata version 3.00 loaded. Jul 10 13:48:21 localhost kernel: [ 0.140754] ACPI: bus type USB registered Jul 10 13:48:21 localhost kernel: [ 0.141318] usbcore: registered new interface driver usbfs Jul 10 13:48:21 localhost kernel: [ 0.142030] usbcore: registered new interface driver hub Jul 10 13:48:21 localhost kernel: [ 0.142721] usbcore: registered new device driver usb Jul 10 13:48:21 localhost kernel: [ 0.143818] PCI: Using ACPI for IRQ routing Jul 10 13:48:21 localhost kernel: [ 0.144003] PCI: pci_cache_line_size set to 64 bytes Jul 10 13:48:21 localhost kernel: [ 0.144077] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff] Jul 10 13:48:21 localhost kernel: [ 0.144079] e820: reserve RAM buffer [mem 0x1ffe0000-0x1fffffff] Jul 10 13:48:21 localhost kernel: [ 0.144210] NetLabel: Initializing Jul 10 13:48:21 localhost kernel: [ 0.144710] NetLabel: domain hash size = 128 Jul 10 13:48:21 localhost kernel: [ 0.145284] NetLabel: protocols = UNLABELED CIPSOv4 Jul 10 13:48:21 localhost kernel: [ 0.145927] NetLabel: unlabeled traffic allowed by default Jul 10 13:48:21 localhost kernel: [ 0.146672] HPET: 3 timers in total, 0 timers will be used for per-cpu timer Jul 10 13:48:21 localhost kernel: [ 0.148011] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 Jul 10 13:48:21 localhost kernel: [ 0.148828] hpet0: 3 comparators, 64-bit 100.000000 MHz counter Jul 10 13:48:21 localhost kernel: [ 0.152043] Switched to clocksource kvm-clock Jul 10 13:48:21 localhost kernel: [ 0.156179] AppArmor: AppArmor Filesystem Enabled Jul 10 13:48:21 localhost kernel: [ 0.156894] pnp: PnP ACPI init Jul 10 13:48:21 localhost kernel: [ 0.157416] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active) Jul 10 13:48:21 localhost kernel: [ 0.157449] pnp 00:01: Plug and Play ACPI device, IDs PNP0303 (active) Jul 10 13:48:21 localhost kernel: [ 0.157474] pnp 00:02: Plug and Play ACPI device, IDs PNP0f13 (active) Jul 10 13:48:21 localhost kernel: [ 0.157500] pnp 00:03: [dma 2] Jul 10 13:48:21 localhost kernel: [ 0.157511] pnp 00:03: Plug and Play ACPI device, IDs PNP0700 (active) Jul 10 13:48:21 localhost kernel: [ 0.157563] pnp 00:04: Plug and Play ACPI device, IDs PNP0400 (active) Jul 10 13:48:21 localhost kernel: [ 0.157608] pnp 00:05: Plug and Play ACPI device, IDs PNP0501 (active) Jul 10 13:48:21 localhost kernel: [ 0.157749] pnp: PnP ACPI: found 6 devices Jul 10 13:48:21 localhost kernel: [ 0.166269] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7] Jul 10 13:48:21 localhost kernel: [ 0.166272] pci_bus 0000:00: resource 5 [io 0x0d00-0xadff] Jul 10 13:48:21 localhost kernel: [ 0.166273] pci_bus 0000:00: resource 6 [io 0xae0f-0xaeff] Jul 10 13:48:21 localhost kernel: [ 0.166274] pci_bus 0000:00: resource 7 [io 0xaf20-0xafdf] Jul 10 13:48:21 localhost kernel: [ 0.166275] pci_bus 0000:00: resource 8 [io 0xafe4-0xffff] Jul 10 13:48:21 localhost kernel: [ 0.166276] pci_bus 0000:00: resource 9 [mem 0x000a0000-0x000bffff] Jul 10 13:48:21 localhost kernel: [ 0.166278] pci_bus 0000:00: resource 10 [mem 0x20000000-0xfebfffff] Jul 10 13:48:21 localhost kernel: [ 0.166297] NET: Registered protocol family 2 Jul 10 13:48:21 localhost kernel: [ 0.167019] TCP established hash table entries: 4096 (order: 3, 32768 bytes) Jul 10 13:48:21 localhost kernel: [ 0.167854] TCP bind hash table entries: 4096 (order: 4, 65536 bytes) Jul 10 13:48:21 localhost kernel: [ 0.168660] TCP: Hash tables configured (established 4096 bind 4096) Jul 10 13:48:21 localhost kernel: [ 0.169497] TCP: reno registered Jul 10 13:48:21 localhost kernel: [ 0.170000] UDP hash table entries: 256 (order: 1, 8192 bytes) Jul 10 13:48:21 localhost kernel: [ 0.170743] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes) Jul 10 13:48:21 localhost kernel: [ 0.171526] NET: Registered protocol family 1 Jul 10 13:48:21 localhost kernel: [ 0.172127] pci 0000:00:00.0: Limiting direct PCI/PCI transfers Jul 10 13:48:21 localhost kernel: [ 0.172853] pci 0000:00:01.0: PIIX3: Enabling Passive Release Jul 10 13:48:21 localhost kernel: [ 0.173584] pci 0000:00:01.0: Activating ISA DMA hang workarounds Jul 10 13:48:21 localhost kernel: [ 0.174370] pci 0000:00:02.0: Video device with shadowed ROM Jul 10 13:48:21 localhost kernel: [ 0.174381] PCI: CLS 0 bytes, default 64 Jul 10 13:48:21 localhost kernel: [ 0.174421] Trying to unpack rootfs image as initramfs... Jul 10 13:48:21 localhost kernel: [ 2.457869] Freeing initrd memory: 14140K (ffff88001ea56000 - ffff88001f825000) Jul 10 13:48:21 localhost kernel: [ 2.459041] microcode: CPU0 sig=0x663, pf=0x1, revision=0x1 Jul 10 13:48:21 localhost kernel: [ 2.459750] microcode: Microcode Update Driver: v2.00 , Peter Oruba Jul 10 13:48:21 localhost kernel: [ 2.460881] Scanning for low memory corruption every 60 seconds Jul 10 13:48:21 localhost kernel: [ 2.461906] futex hash table entries: 256 (order: 2, 16384 bytes) Jul 10 13:48:21 localhost kernel: [ 2.462693] Initialise system trusted keyring Jul 10 13:48:21 localhost kernel: [ 2.463345] audit: initializing netlink subsys (disabled) Jul 10 13:48:21 localhost kernel: [ 2.464070] audit: type=2000 audit(1436536099.716:1): initialized Jul 10 13:48:21 localhost kernel: [ 2.465084] HugeTLB registered 2 MB page size, pre-allocated 0 pages Jul 10 13:48:21 localhost kernel: [ 2.467029] zpool: loaded Jul 10 13:48:21 localhost kernel: [ 2.467504] zbud: loaded Jul 10 13:48:21 localhost kernel: [ 2.468086] VFS: Disk quotas dquot_6.5.2 Jul 10 13:48:21 localhost kernel: [ 2.468693] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Jul 10 13:48:21 localhost kernel: [ 2.469881] fuse init (API version 7.23) Jul 10 13:48:21 localhost kernel: [ 2.470571] Key type big_key registered Jul 10 13:48:21 localhost kernel: [ 2.471230] Key type asymmetric registered Jul 10 13:48:21 localhost kernel: [ 2.471802] Asymmetric key parser 'x509' registered Jul 10 13:48:21 localhost kernel: [ 2.472470] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252) Jul 10 13:48:21 localhost kernel: [ 2.473462] io scheduler noop registered Jul 10 13:48:21 localhost kernel: [ 2.474027] io scheduler deadline registered (default) Jul 10 13:48:21 localhost kernel: [ 2.477794] io scheduler cfq registered Jul 10 13:48:21 localhost kernel: [ 2.478510] pci_hotplug: PCI Hot Plug PCI Core version: 0.5 Jul 10 13:48:21 localhost kernel: [ 2.479706] pciehp: PCI Express Hot Plug Controller Driver version: 0.4 Jul 10 13:48:21 localhost kernel: [ 2.481053] intel_idle: does not run on family 6 model 6 Jul 10 13:48:21 localhost kernel: [ 2.481159] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 Jul 10 13:48:21 localhost kernel: [ 2.482281] ACPI: Power Button [PWRF] Jul 10 13:48:21 localhost kernel: [ 2.482927] GHES: HEST is not enabled! Jul 10 13:48:21 localhost kernel: [ 2.483530] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled Jul 10 13:48:21 localhost kernel: [ 2.510415] 00:05: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Jul 10 13:48:21 localhost kernel: [ 2.512350] Linux agpgart interface v0.103 Jul 10 13:48:21 localhost kernel: [ 2.513763] brd: module loaded Jul 10 13:48:21 localhost kernel: [ 2.516083] loop: module loaded Jul 10 13:48:21 localhost kernel: [ 2.516692] ata_piix 0000:00:01.1: version 2.13 Jul 10 13:48:21 localhost kernel: [ 2.517306] scsi host0: ata_piix Jul 10 13:48:21 localhost kernel: [ 2.518187] scsi host1: ata_piix Jul 10 13:48:21 localhost kernel: [ 2.519001] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc040 irq 14 Jul 10 13:48:21 localhost kernel: [ 2.520048] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc048 irq 15 Jul 10 13:48:21 localhost kernel: [ 2.521185] libphy: Fixed MDIO Bus: probed Jul 10 13:48:21 localhost kernel: [ 2.521736] tun: Universal TUN/TAP device driver, 1.6 Jul 10 13:48:21 localhost kernel: [ 2.522359] tun: (C) 1999-2004 Max Krasnyansky Jul 10 13:48:21 localhost kernel: [ 2.523339] PPP generic driver version 2.4.2 Jul 10 13:48:21 localhost kernel: [ 2.523996] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver Jul 10 13:48:21 localhost kernel: [ 2.524824] ehci-pci: EHCI PCI platform driver Jul 10 13:48:21 localhost kernel: [ 2.525442] ehci-platform: EHCI generic platform driver Jul 10 13:48:21 localhost kernel: [ 2.526177] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver Jul 10 13:48:21 localhost kernel: [ 2.526896] ohci-pci: OHCI PCI platform driver Jul 10 13:48:21 localhost kernel: [ 2.527506] ohci-platform: OHCI generic platform driver Jul 10 13:48:21 localhost kernel: [ 2.528177] uhci_hcd: USB Universal Host Controller Interface driver Jul 10 13:48:21 localhost kernel: [ 2.528973] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 Jul 10 13:48:21 localhost kernel: [ 2.530495] serio: i8042 KBD port at 0x60,0x64 irq 1 Jul 10 13:48:21 localhost kernel: [ 2.531137] serio: i8042 AUX port at 0x60,0x64 irq 12 Jul 10 13:48:21 localhost kernel: [ 2.531895] mousedev: PS/2 mouse device common for all mice Jul 10 13:48:21 localhost kernel: [ 2.532770] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 Jul 10 13:48:21 localhost kernel: [ 2.534081] rtc_cmos 00:00: RTC can wake from S4 Jul 10 13:48:21 localhost kernel: [ 2.534834] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0 Jul 10 13:48:21 localhost kernel: [ 2.535666] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram, hpet irqs Jul 10 13:48:21 localhost kernel: [ 2.536567] i2c /dev entries driver Jul 10 13:48:21 localhost kernel: [ 2.537121] device-mapper: uevent: version 1.0.3 Jul 10 13:48:21 localhost kernel: [ 2.538015] device-mapper: ioctl: 4.29.0-ioctl (2014-10-28) initialised: dm-devel@redhat.com Jul 10 13:48:21 localhost kernel: [ 2.541333] ledtrig-cpu: registered to indicate activity on CPUs Jul 10 13:48:21 localhost kernel: [ 2.542141] PCCT header not found. Jul 10 13:48:21 localhost kernel: [ 2.542655] ACPI PCC probe failed. Jul 10 13:48:21 localhost kernel: [ 2.543240] TCP: cubic registered Jul 10 13:48:21 localhost kernel: [ 2.543828] NET: Registered protocol family 10 Jul 10 13:48:21 localhost kernel: [ 2.544596] NET: Registered protocol family 17 Jul 10 13:48:21 localhost kernel: [ 2.545238] Key type dns_resolver registered Jul 10 13:48:21 localhost kernel: [ 2.546010] Loading compiled-in X.509 certificates Jul 10 13:48:21 localhost kernel: [ 2.547320] Loaded X.509 cert 'Magrathea: Glacier signing key: c7d440344c0b3ac2a3cec2aeb9722ecf6cae7391' Jul 10 13:48:21 localhost kernel: [ 2.548596] registered taskstats version 1 Jul 10 13:48:21 localhost kernel: [ 2.550276] Key type trusted registered Jul 10 13:48:21 localhost kernel: [ 2.554415] Key type encrypted registered Jul 10 13:48:21 localhost kernel: [ 2.555103] AppArmor: AppArmor sha1 policy hashing enabled Jul 10 13:48:21 localhost kernel: [ 2.555981] ima: No TPM chip found, activating TPM-bypass! Jul 10 13:48:21 localhost kernel: [ 2.556707] evm: HMAC attrs: 0x1 Jul 10 13:48:21 localhost kernel: [ 2.557293] Magic number: 7:921:836 Jul 10 13:48:21 localhost kernel: [ 2.557916] rtc_cmos 00:00: setting system clock to 2015-07-10 13:48:19 UTC (1436536099) Jul 10 13:48:21 localhost kernel: [ 2.559126] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found Jul 10 13:48:21 localhost kernel: [ 2.559889] EDD information not available. Jul 10 13:48:21 localhost kernel: [ 2.560465] PM: Hibernation image not present or could not be loaded. Jul 10 13:48:21 localhost kernel: [ 2.676546] ata2.01: NODEV after polling detection Jul 10 13:48:21 localhost kernel: [ 2.676720] ata1.01: NODEV after polling detection Jul 10 13:48:21 localhost kernel: [ 2.676905] ata2.00: ATAPI: QEMU DVD-ROM, 2.2.0, max UDMA/100 Jul 10 13:48:21 localhost kernel: [ 2.677883] ata1.00: ATA-7: QEMU HARDDISK, 2.2.0, max UDMA/100 Jul 10 13:48:21 localhost kernel: [ 2.678581] ata1.00: 7617188 sectors, multi 16: LBA48 Jul 10 13:48:21 localhost kernel: [ 2.679524] ata2.00: configured for MWDMA2 Jul 10 13:48:21 localhost kernel: [ 2.680335] ata1.00: configured for MWDMA2 Jul 10 13:48:21 localhost kernel: [ 2.680938] scsi 0:0:0:0: Direct-Access ATA QEMU HARDDISK 0 PQ: 0 ANSI: 5 Jul 10 13:48:21 localhost kernel: [ 2.682058] sd 0:0:0:0: [sda] 7617188 512-byte logical blocks: (3.90 GB/3.63 GiB) Jul 10 13:48:21 localhost kernel: [ 2.683108] sd 0:0:0:0: [sda] Write Protect is off Jul 10 13:48:21 localhost kernel: [ 2.683731] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00 Jul 10 13:48:21 localhost kernel: [ 2.683794] sd 0:0:0:0: Attached scsi generic sg0 type 0 Jul 10 13:48:21 localhost kernel: [ 2.684498] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jul 10 13:48:21 localhost kernel: [ 2.685870] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.2. PQ: 0 ANSI: 5 Jul 10 13:48:21 localhost kernel: [ 2.690985] GPT:Primary header thinks Alt. header is not at the end of the disk. Jul 10 13:48:21 localhost kernel: [ 2.692029] GPT:7617186 != 7617187 Jul 10 13:48:21 localhost kernel: [ 2.692528] GPT:Alternate GPT header not at the end of the disk. Jul 10 13:48:21 localhost kernel: [ 2.693257] GPT:7617186 != 7617187 Jul 10 13:48:21 localhost kernel: [ 2.693754] GPT: Use GNU Parted to correct GPT errors. Jul 10 13:48:21 localhost kernel: [ 2.697231] sda: sda1 sda2 sda3 sda4 sda5 Jul 10 13:48:21 localhost kernel: [ 2.699218] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray Jul 10 13:48:21 localhost kernel: [ 2.700134] cdrom: Uniform CD-ROM driver Revision: 3.20 Jul 10 13:48:21 localhost kernel: [ 2.700938] sr 1:0:0:0: Attached scsi CD-ROM sr0 Jul 10 13:48:21 localhost kernel: [ 2.701158] sr 1:0:0:0: Attached scsi generic sg1 type 5 Jul 10 13:48:21 localhost kernel: [ 2.702059] sd 0:0:0:0: [sda] Attached SCSI disk Jul 10 13:48:21 localhost kernel: [ 2.702857] Freeing unused kernel memory: 1408K (ffffffff81d36000 - ffffffff81e96000) Jul 10 13:48:21 localhost kernel: [ 2.703870] Write protecting the kernel read-only data: 12288k Jul 10 13:48:21 localhost kernel: [ 2.704736] Freeing unused kernel memory: 180K (ffff8800017d3000 - ffff880001800000) Jul 10 13:48:21 localhost kernel: [ 2.705810] Freeing unused kernel memory: 344K (ffff880001baa000 - ffff880001c00000) Jul 10 13:48:21 localhost kernel: [ 2.713921] random: systemd-udevd urandom read with 11 bits of entropy available Jul 10 13:48:21 localhost kernel: [ 2.739009] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI Jul 10 13:48:21 localhost kernel: [ 2.739977] e1000: Copyright (c) 1999-2006 Intel Corporation. Jul 10 13:48:21 localhost kernel: [ 2.833924] initrd: mounting /dev/sda3 Jul 10 13:48:21 localhost kernel: [ 2.837752] EXT4-fs (sda3): couldn't mount as ext3 due to feature incompatibilities Jul 10 13:48:21 localhost kernel: [ 2.844246] EXT4-fs (sda3): couldn't mount as ext2 due to feature incompatibilities Jul 10 13:48:21 localhost kernel: [ 2.845542] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11 Jul 10 13:48:21 localhost kernel: [ 2.848284] EXT4-fs (sda3): mounted filesystem with ordered data mode. Opts: (null) Jul 10 13:48:21 localhost kernel: [ 2.849817] initrd: mounting /run Jul 10 13:48:21 localhost kernel: [ 2.857777] initrd: checking filesystem for writable partition Jul 10 13:48:21 localhost kernel: [ 2.859365] EXT4-fs (sda5): couldn't mount as ext3 due to feature incompatibilities Jul 10 13:48:21 localhost kernel: [ 2.860698] EXT4-fs (sda5): couldn't mount as ext2 due to feature incompatibilities Jul 10 13:48:21 localhost kernel: [ 2.870617] EXT4-fs (sda5): recovery complete Jul 10 13:48:21 localhost kernel: [ 3.125930] EXT4-fs (sda5): mounted filesystem with ordered data mode. Opts: errors=remount-ro Jul 10 13:48:21 localhost kernel: [ 3.138509] initrd: mounting writable partition Jul 10 13:48:21 localhost kernel: [ 3.142761] EXT4-fs (sda5): couldn't mount as ext3 due to feature incompatibilities Jul 10 13:48:21 localhost kernel: [ 3.144061] EXT4-fs (sda5): couldn't mount as ext2 due to feature incompatibilities Jul 10 13:48:21 localhost kernel: [ 3.146659] EXT4-fs (sda5): mounted filesystem with ordered data mode. Opts: discard Jul 10 13:48:21 localhost kernel: [ 3.162506] e1000 0000:00:03.0 eth0: (PCI:33MHz:32-bit) 52:54:00:12:34:56 Jul 10 13:48:21 localhost kernel: [ 3.163407] e1000 0000:00:03.0 eth0: Intel(R) PRO/1000 Network Connection Jul 10 13:48:21 localhost kernel: [ 3.230479] systemd[1]: Inserted module 'autofs4' Jul 10 13:48:21 localhost kernel: [ 3.234288] systemd[1]: systemd 219 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN) Jul 10 13:48:21 localhost kernel: [ 3.236453] systemd[1]: Detected virtualization kvm. Jul 10 13:48:21 localhost kernel: [ 3.237082] systemd[1]: Detected architecture x86-64. Jul 10 13:48:21 localhost kernel: [ 3.238886] systemd[1]: Set hostname to . Jul 10 13:48:21 localhost kernel: [ 3.239851] systemd[1]: Initializing machine ID from random generator. Jul 10 13:48:21 localhost kernel: [ 3.240669] systemd[1]: Installed transient /etc/machine-id file. Jul 10 13:48:21 localhost kernel: [ 3.293996] systemd[1]: Unit writable.mount is bound to inactive unit dev-sda5.device. Stopping, too. Jul 10 13:48:21 localhost kernel: [ 3.304068] systemd[1]: Cannot add dependency job for unit webdm_snappyd_0.9.service, ignoring: Unit webdm_snappyd_0.9.service is masked. Jul 10 13:48:21 localhost kernel: [ 3.305541] systemd[1]: Cannot add dependency job for unit sshd-keygen.service, ignoring: Unit sshd-keygen.service failed to load: No such file or directory. Jul 10 13:48:21 localhost kernel: [ 3.307187] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory. Jul 10 13:48:21 localhost kernel: [ 3.309166] systemd[1]: Startup finished in 3.221s (kernel) + 87ms (userspace) = 3.309s. Jul 10 13:48:21 localhost kernel: [ 3.313379] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Jul 10 13:48:21 localhost kernel: [ 3.315054] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point. Jul 10 13:48:21 localhost kernel: [ 3.316426] systemd[1]: Reached target Remote File Systems (Pre). Jul 10 13:48:21 localhost kernel: [ 3.317179] systemd[1]: Starting Remote File Systems (Pre). Jul 10 13:48:21 localhost kernel: [ 3.317910] systemd[1]: Started Forward Password Requests to Wall Directory Watch. Jul 10 13:48:21 localhost kernel: [ 3.318942] systemd[1]: Starting Forward Password Requests to Wall Directory Watch. Jul 10 13:48:21 localhost kernel: [ 3.320454] systemd[1]: Reached target Encrypted Volumes. Jul 10 13:48:21 localhost kernel: [ 3.321142] systemd[1]: Starting Encrypted Volumes. Jul 10 13:48:21 localhost kernel: [ 3.321805] systemd[1]: Created slice Root Slice. Jul 10 13:48:21 localhost kernel: [ 3.322455] systemd[1]: Starting Root Slice. Jul 10 13:48:21 localhost kernel: [ 3.323062] systemd[1]: Listening on Journal Socket (/dev/log). Jul 10 13:48:21 localhost kernel: [ 3.323850] systemd[1]: Starting Journal Socket (/dev/log). Jul 10 13:48:21 localhost kernel: [ 3.324693] systemd[1]: Created slice User and Session Slice. Jul 10 13:48:21 localhost kernel: [ 3.325422] systemd[1]: Starting User and Session Slice. Jul 10 13:48:21 localhost kernel: [ 3.326112] systemd[1]: Listening on fsck to fsckd communication Socket. Jul 10 13:48:21 localhost kernel: [ 3.326917] systemd[1]: Starting fsck to fsckd communication Socket. Jul 10 13:48:21 localhost kernel: [ 3.327707] systemd[1]: Listening on udev Control Socket. Jul 10 13:48:21 localhost kernel: [ 3.328469] systemd[1]: Starting udev Control Socket. Jul 10 13:48:21 localhost kernel: [ 3.329277] systemd[1]: Listening on Journal Socket. Jul 10 13:48:21 localhost kernel: [ 3.329933] systemd[1]: Starting Journal Socket. Jul 10 13:48:21 localhost kernel: [ 3.330563] systemd[1]: Listening on Delayed Shutdown Socket. Jul 10 13:48:21 localhost kernel: [ 3.331308] systemd[1]: Starting Delayed Shutdown Socket. Jul 10 13:48:21 localhost kernel: [ 3.332064] systemd[1]: Created slice System Slice. Jul 10 13:48:21 localhost kernel: [ 3.332809] systemd[1]: Starting System Slice. Jul 10 13:48:21 localhost kernel: [ 3.333967] systemd[1]: Mounting Huge Pages File System... Jul 10 13:48:21 localhost kernel: [ 3.335122] systemd[1]: Created slice system-serial\x2dgetty.slice. Jul 10 13:48:21 localhost kernel: [ 3.336207] systemd[1]: Starting system-serial\x2dgetty.slice. Jul 10 13:48:21 localhost kernel: [ 3.337242] systemd[1]: Starting Increase datagram queue length... Jul 10 13:48:21 localhost kernel: [ 3.338080] systemd[1]: Created slice system-getty.slice. Jul 10 13:48:21 localhost kernel: [ 3.338780] systemd[1]: Starting system-getty.slice. Jul 10 13:48:21 localhost kernel: [ 3.339737] systemd[1]: Starting Remount Root and Kernel File Systems... Jul 10 13:48:21 localhost kernel: [ 3.343664] systemd[1]: Starting Nameserver information manager... Jul 10 13:48:21 localhost kernel: [ 3.351484] EXT4-fs (sda3): re-mounted. Opts: (null) Jul 10 13:48:21 localhost kernel: [ 3.354134] systemd[1]: Starting Create list of required static device nodes for the current kernel... Jul 10 13:48:21 localhost kernel: [ 3.358981] systemd[1]: Mounting Debug File System... Jul 10 13:48:21 localhost kernel: [ 3.362693] systemd[1]: Started Set Up Additional Binary Formats. Jul 10 13:48:21 localhost kernel: [ 3.363547] systemd[1]: Created slice system-systemd\x2dfsck.slice. Jul 10 13:48:21 localhost kernel: [ 3.364347] systemd[1]: Starting system-systemd\x2dfsck.slice. Jul 10 13:48:21 localhost kernel: [ 3.365080] systemd[1]: Reached target Slices. Jul 10 13:48:21 localhost kernel: [ 3.365765] systemd[1]: Starting Slices. Jul 10 13:48:21 localhost kernel: [ 3.366319] systemd[1]: Listening on udev Kernel Socket. Jul 10 13:48:21 localhost kernel: [ 3.366981] systemd[1]: Starting udev Kernel Socket. Jul 10 13:48:21 localhost kernel: [ 3.367906] systemd[1]: Starting udev Coldplug all Devices... Jul 10 13:48:21 localhost kernel: [ 3.375610] systemd[1]: Starting Load Kernel Modules... Jul 10 13:48:21 localhost kernel: [ 3.379459] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. Jul 10 13:48:21 localhost kernel: [ 3.380590] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch. Jul 10 13:48:21 localhost kernel: [ 3.381663] systemd[1]: Reached target Paths. Jul 10 13:48:21 localhost kernel: [ 3.382319] systemd[1]: Starting Paths. Jul 10 13:48:21 localhost kernel: [ 3.383143] systemd[1]: Mounting POSIX Message Queue File System... Jul 10 13:48:21 localhost kernel: [ 3.383976] systemd[1]: Listening on Journal Audit Socket. Jul 10 13:48:21 localhost kernel: [ 3.386027] systemd[1]: Starting Journal Audit Socket. Jul 10 13:48:21 localhost kernel: [ 3.386734] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe. Jul 10 13:48:21 localhost kernel: [ 3.387797] systemd[1]: Starting /dev/initctl Compatibility Named Pipe. Jul 10 13:48:21 localhost kernel: [ 3.389275] systemd[1]: Reached target Swap. Jul 10 13:48:21 localhost kernel: [ 3.389904] systemd[1]: Starting Swap. Jul 10 13:48:21 localhost kernel: [ 3.391497] systemd[1]: Mounted Huge Pages File System. Jul 10 13:48:21 localhost kernel: [ 3.392202] systemd[1]: Mounted Debug File System. Jul 10 13:48:21 localhost kernel: [ 3.392827] systemd[1]: Mounted POSIX Message Queue File System. Jul 10 13:48:21 localhost kernel: [ 3.393723] systemd[1]: Started Increase datagram queue length. Jul 10 13:48:21 localhost kernel: [ 3.394623] systemd[1]: Started Remount Root and Kernel File Systems. Jul 10 13:48:21 localhost kernel: [ 3.395751] systemd[1]: Started Create list of required static device nodes for the current kernel. Jul 10 13:48:21 localhost kernel: [ 3.398454] systemd[1]: Started Load Kernel Modules. Jul 10 13:48:21 localhost kernel: [ 3.403907] systemd[1]: Started Nameserver information manager. Jul 10 13:48:21 localhost kernel: [ 3.414863] systemd[1]: Started udev Coldplug all Devices. Jul 10 13:48:21 localhost kernel: [ 3.446450] systemd[1]: Starting Apply Kernel Variables... Jul 10 13:48:21 localhost kernel: [ 3.447517] systemd[1]: Mounting FUSE Control File System... Jul 10 13:48:21 localhost kernel: [ 3.448322] systemd[1]: Mounted Configuration File System. Jul 10 13:48:21 localhost kernel: [ 3.449423] systemd[1]: Starting Create Static Device Nodes in /dev... Jul 10 13:48:21 localhost kernel: [ 3.450244] systemd[1]: Started Various fixups to make systemd work better on Debian. Jul 10 13:48:21 localhost kernel: [ 3.456105] tsc: Refined TSC clocksource calibration: 1995.378 MHz Jul 10 13:48:21 localhost kernel: [ 3.458485] systemd[1]: Started Rebuild Hardware Database. Jul 10 13:48:21 localhost kernel: [ 3.458686] systemd[1]: Listening on Syslog Socket. Jul 10 13:48:21 localhost kernel: [ 3.459210] systemd[1]: Starting Syslog Socket. Jul 10 13:48:21 localhost kernel: [ 3.460871] systemd[1]: Starting Journal Service... Jul 10 13:48:21 localhost kernel: [ 3.461372] systemd[1]: Started Apply Kernel Variables. Jul 10 13:48:21 localhost kernel: [ 3.461590] systemd[1]: Started Create Static Device Nodes in /dev. Jul 10 13:48:21 localhost kernel: [ 3.462049] systemd[1]: Starting udev Kernel Device Manager... Jul 10 13:48:21 localhost kernel: [ 3.462073] systemd[1]: Reached target Local File Systems (Pre). Jul 10 13:48:21 localhost kernel: [ 3.462092] systemd[1]: Starting Local File Systems (Pre). Jul 10 13:48:21 localhost kernel: [ 3.465191] systemd[1]: etc-cloud-cloud.cfg.d.mount: Directory /etc/cloud/cloud.cfg.d to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.473665] systemd[1]: Mounting /etc/cloud/cloud.cfg.d... Jul 10 13:48:21 localhost kernel: [ 3.480803] systemd[1]: Mounting /root... Jul 10 13:48:21 localhost kernel: [ 3.484199] systemd[1]: var-lib-dhcp.mount: Directory /var/lib/dhcp to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.484525] systemd[1]: Mounting /var/lib/dhcp... Jul 10 13:48:21 localhost kernel: [ 3.484888] systemd[1]: etc-network-interfaces.d.mount: Directory /etc/network/interfaces.d to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.485206] systemd[1]: Mounting /etc/network/interfaces.d... Jul 10 13:48:21 localhost kernel: [ 3.485509] systemd[1]: home.mount: Directory /home to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.486743] systemd[1]: Mounting /home... Jul 10 13:48:21 localhost kernel: [ 3.488261] systemd[1]: var-lib-apps.mount: Directory /var/lib/apps to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.488590] systemd[1]: Mounting /var/lib/apps... Jul 10 13:48:21 localhost kernel: [ 3.495856] systemd[1]: Mounting /var/tmp... Jul 10 13:48:21 localhost kernel: [ 3.503989] systemd[1]: etc-sudoers.d.mount: Directory /etc/sudoers.d to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.504353] systemd[1]: Mounting /etc/sudoers.d... Jul 10 13:48:21 localhost kernel: [ 3.508176] systemd[1]: usr-share-click-frameworks.mount: Directory /usr/share/click/frameworks to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.508462] systemd[1]: Mounting /usr/share/click/frameworks... Jul 10 13:48:21 localhost kernel: [ 3.512496] systemd[1]: Mounting /var/lib/waagent... Jul 10 13:48:21 localhost kernel: [ 3.515191] systemd[1]: Mounting /etc/apparmor.d/cache... Jul 10 13:48:21 localhost kernel: [ 3.515222] systemd[1]: etc-sysctl.d.mount: Directory /etc/sysctl.d to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.515547] systemd[1]: Mounting /etc/sysctl.d... Jul 10 13:48:21 localhost kernel: [ 3.523186] systemd[1]: var-lib-initramfs\x2dtools.mount: Directory /var/lib/initramfs-tools to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.523466] systemd[1]: Mounting /var/lib/initramfs-tools... Jul 10 13:48:21 localhost kernel: [ 3.525461] systemd[1]: Mounting /mnt... Jul 10 13:48:21 localhost kernel: [ 3.528350] systemd[1]: Mounting /tmp... Jul 10 13:48:21 localhost kernel: [ 3.531458] systemd[1]: etc-dbus\x2d1-system.d.mount: Directory /etc/dbus-1/system.d to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.531747] systemd[1]: Mounting /etc/dbus-1/system.d... Jul 10 13:48:21 localhost kernel: [ 3.534498] systemd[1]: var-lib-system\x2dimage.mount: Directory /var/lib/system-image to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.534786] systemd[1]: Mounting /var/lib/system-image... Jul 10 13:48:21 localhost kernel: [ 3.538940] systemd[1]: var-lib-snappy.mount: Directory /var/lib/snappy to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.539461] systemd[1]: Mounting /var/lib/snappy... Jul 10 13:48:21 localhost kernel: [ 3.539503] systemd[1]: MESSAGE=Failed to check directory /etc/hosts: Not a directory Jul 10 13:48:21 localhost kernel: [ 3.539855] systemd[1]: Mounting /etc/hosts... Jul 10 13:48:21 localhost kernel: [ 3.546692] systemd[1]: var-lib-extrausers.mount: Directory /var/lib/extrausers to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.547199] systemd[1]: Mounting /var/lib/extrausers... Jul 10 13:48:21 localhost kernel: [ 3.551383] systemd[1]: oem.mount: Directory /oem to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.551640] systemd[1]: Mounting /oem... Jul 10 13:48:21 localhost kernel: [ 3.554268] systemd[1]: Mounting /var/lib/logrotate... Jul 10 13:48:21 localhost kernel: [ 3.554297] systemd[1]: etc-writable.mount: Directory /etc/writable to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.554544] systemd[1]: Mounting /etc/writable... Jul 10 13:48:21 localhost kernel: [ 3.561313] systemd[1]: var-lib-apparmor.mount: Directory /var/lib/apparmor to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.561575] systemd[1]: Mounting /var/lib/apparmor... Jul 10 13:48:21 localhost kernel: [ 3.563837] parport_pc 00:04: reported by Plug and Play ACPI Jul 10 13:48:21 localhost kernel: [ 3.563907] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE] Jul 10 13:48:21 localhost kernel: [ 3.564145] systemd[1]: etc-ssh.mount: Directory /etc/ssh to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.564416] systemd[1]: Mounting /etc/ssh... Jul 10 13:48:21 localhost kernel: [ 3.565172] systemd[1]: Mounting /var/lib/sudo... Jul 10 13:48:21 localhost kernel: [ 3.569265] systemd[1]: etc-ufw.mount: Directory /etc/ufw to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.569794] systemd[1]: Mounting /etc/ufw... Jul 10 13:48:21 localhost kernel: [ 3.576297] systemd[1]: apps.mount: Directory /apps to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.576576] systemd[1]: Mounting /apps... Jul 10 13:48:21 localhost kernel: [ 3.576609] systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost kernel: [ 3.576862] systemd[1]: Mounting /var/log... Jul 10 13:48:21 localhost kernel: [ 3.583604] systemd[1]: Mounting /var/lib/cloud... Jul 10 13:48:21 localhost kernel: [ 3.583627] systemd[1]: MESSAGE=Failed to check directory /var/lib/systemd/random-seed: Not a directory Jul 10 13:48:21 localhost kernel: [ 3.583893] systemd[1]: Mounting /var/lib/systemd/random-seed... Jul 10 13:48:21 localhost kernel: [ 3.586129] systemd[1]: Mounting /etc/udev/rules.d... Jul 10 13:48:21 localhost kernel: [ 3.586407] systemd[1]: Mounting /var/lib/dbus... Jul 10 13:48:21 localhost kernel: [ 3.595906] systemd[1]: Mounting /var/cache/apparmor... Jul 10 13:48:21 localhost kernel: [ 3.605293] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 Jul 10 13:48:21 localhost kernel: [ 3.607003] systemd[1]: Mounted FUSE Control File System. Jul 10 13:48:21 localhost kernel: [ 3.607023] systemd[1]: Mounted /home. Jul 10 13:48:21 localhost kernel: [ 3.607032] systemd[1]: Mounted /apps. Jul 10 13:48:21 localhost kernel: [ 3.607040] systemd[1]: Mounted /oem. Jul 10 13:48:21 localhost kernel: [ 3.607047] systemd[1]: Mounted /tmp. Jul 10 13:48:21 localhost kernel: [ 3.607054] systemd[1]: Mounted /mnt. Jul 10 13:48:21 localhost kernel: [ 3.607061] systemd[1]: Mounted /var/lib/apps. Jul 10 13:48:21 localhost kernel: [ 3.607069] systemd[1]: Mounted /var/lib/cloud. Jul 10 13:48:21 localhost kernel: [ 3.607076] systemd[1]: Mounted /var/lib/waagent. Jul 10 13:48:21 localhost kernel: [ 3.607083] systemd[1]: Mounted /var/lib/dbus. Jul 10 13:48:21 localhost kernel: [ 3.607090] systemd[1]: Mounted /var/lib/dhcp. Jul 10 13:48:21 localhost kernel: [ 3.607098] systemd[1]: Mounted /var/lib/logrotate. Jul 10 13:48:21 localhost kernel: [ 3.607105] systemd[1]: Mounted /var/lib/sudo. Jul 10 13:48:21 localhost kernel: [ 3.607112] systemd[1]: Mounted /var/lib/system-image. Jul 10 13:48:21 localhost kernel: [ 3.607119] systemd[1]: Mounted /var/log. Jul 10 13:48:21 localhost kernel: [ 3.607127] systemd[1]: Mounted /etc/sysctl.d. Jul 10 13:48:21 localhost kernel: [ 3.607142] systemd[1]: Mounted /etc/ufw. Jul 10 13:48:21 localhost kernel: [ 3.607149] systemd[1]: Mounted /etc/apparmor.d/cache. Jul 10 13:48:21 localhost kernel: [ 3.607157] systemd[1]: Mounted /var/lib/apparmor. Jul 10 13:48:21 localhost kernel: [ 3.607164] systemd[1]: Mounted /var/tmp. Jul 10 13:48:21 localhost kernel: [ 3.607171] systemd[1]: Mounted /etc/ssh. Jul 10 13:48:21 localhost kernel: [ 3.607178] systemd[1]: Mounted /etc/writable. Jul 10 13:48:21 localhost kernel: [ 3.607186] systemd[1]: Mounted /var/lib/initramfs-tools. Jul 10 13:48:21 localhost kernel: [ 3.607194] systemd[1]: Mounted /usr/share/click/frameworks. Jul 10 13:48:21 localhost kernel: [ 3.607201] systemd[1]: Mounted /root. Jul 10 13:48:21 localhost kernel: [ 3.607209] systemd[1]: Mounted /etc/sudoers.d. Jul 10 13:48:21 localhost kernel: [ 3.607216] systemd[1]: Mounted /etc/hosts. Jul 10 13:48:21 localhost kernel: [ 3.607223] systemd[1]: Mounted /var/lib/extrausers. Jul 10 13:48:21 localhost kernel: [ 3.607230] systemd[1]: Mounted /etc/network/interfaces.d. Jul 10 13:48:21 localhost kernel: [ 3.607237] systemd[1]: Mounted /var/lib/snappy. Jul 10 13:48:21 localhost kernel: [ 3.607244] systemd[1]: Mounted /etc/udev/rules.d. Jul 10 13:48:21 localhost kernel: [ 3.607252] systemd[1]: Mounted /var/lib/systemd/random-seed. Jul 10 13:48:21 localhost kernel: [ 3.607259] systemd[1]: Mounted /etc/dbus-1/system.d. Jul 10 13:48:21 localhost kernel: [ 3.607267] systemd[1]: Mounted /etc/cloud/cloud.cfg.d. Jul 10 13:48:21 localhost kernel: [ 3.610439] systemd[1]: Mounted /var/cache/apparmor. Jul 10 13:48:21 localhost kernel: [ 3.610529] systemd[1]: Started Journal Service. Jul 10 13:48:21 localhost kernel: [ 3.798488] systemd-journald[331]: Received request to flush runtime journal from PID 1 Jul 10 13:48:21 localhost kernel: [ 3.804088] EXT4-fs (sda4): mounted filesystem with ordered data mode. Opts: (null) Jul 10 13:48:21 localhost kernel: [ 3.833966] ppdev: user-space parallel port driver Jul 10 13:48:21 localhost kernel: [ 3.952609] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3 Jul 10 13:48:21 localhost kernel: [ 4.123317] audit: type=1400 audit(1436536101.060:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/sbin/dhclient" pid=466 comm="apparmor_parser" Jul 10 13:48:21 localhost kernel: [ 4.123578] audit: type=1400 audit(1436536101.060:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=466 comm="apparmor_parser" Jul 10 13:48:21 localhost kernel: [ 4.123767] audit: type=1400 audit(1436536101.060:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=466 comm="apparmor_parser" Jul 10 13:48:21 localhost kernel: [ 4.123951] audit: type=1400 audit(1436536101.060:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=466 comm="apparmor_parser" Jul 10 13:48:21 localhost kernel: [ 4.137511] audit: type=1400 audit(1436536101.076:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/ubuntu-core-launcher" pid=468 comm="apparmor_parser" Jul 10 13:48:21 localhost rsyslogd-2039: Could no open output pipe '/dev/xconsole': Permission denied [try http://www.rsyslog.com/e/2039 ] Jul 10 13:48:21 localhost systemd-udevd[332]: starting version 219 Jul 10 13:48:21 localhost systemd[1]: Started udev Kernel Device Manager. Jul 10 13:48:21 localhost systemd[1]: Found device QEMU_HARDDISK system-b. Jul 10 13:48:21 localhost systemd[1]: Found device /dev/ttyS0. Jul 10 13:48:21 localhost systemd[1]: Found device QEMU_HARDDISK system-boot. Jul 10 13:48:21 localhost systemd[1]: Starting File System Check on /dev/sda2... Jul 10 13:48:21 localhost systemd[1]: Mounting /writable/cache/system... Jul 10 13:48:21 localhost systemd[1]: Created slice system-ifup.slice. Jul 10 13:48:21 localhost systemd[1]: Starting system-ifup.slice. Jul 10 13:48:21 localhost systemd[1]: Starting Copy rules generated while the root was ro... Jul 10 13:48:21 localhost systemd[1]: Starting Load/Save Random Seed... Jul 10 13:48:21 localhost systemd[1]: Starting Set the hostname to the value stored on the writable partition... Jul 10 13:48:21 localhost systemd[1]: Starting Flush Journal to Persistent Storage... Jul 10 13:48:21 localhost systemd[1]: Started Copy rules generated while the root was ro. Jul 10 13:48:21 localhost systemd[1]: Started Load/Save Random Seed. Jul 10 13:48:21 localhost systemd[1]: Started Set the hostname to the value stored on the writable partition. Jul 10 13:48:21 localhost systemd[1]: Started Flush Journal to Persistent Storage. Jul 10 13:48:21 localhost systemd-fsck[416]: fsck.fat 3.0.27 (2014-11-12) Jul 10 13:48:21 localhost systemd-fsck[416]: 0x41: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Jul 10 13:48:21 localhost systemd-fsck[416]: Automatically removing dirty bit. Jul 10 13:48:21 localhost systemd-fsck[416]: Performing changes. Jul 10 13:48:21 localhost systemd-fsck[416]: /dev/sda2: 547 files, 14618/129022 clusters Jul 10 13:48:21 localhost systemd[1]: Started File System Check on /dev/sda2. Jul 10 13:48:21 localhost systemd[1]: Mounted /writable/cache/system. Jul 10 13:48:21 localhost systemd[1]: Mounting /boot/efi... Jul 10 13:48:21 localhost systemd[1]: Started File System Check Daemon to report status. Jul 10 13:48:21 localhost systemd[1]: Starting File System Check Daemon to report status... Jul 10 13:48:21 localhost systemd[1]: Mounted /boot/efi. Jul 10 13:48:21 localhost systemd[1]: boot-grub.mount: Directory /boot/grub to mount over is not empty, mounting anyway. Jul 10 13:48:21 localhost systemd[1]: Mounting /boot/grub... Jul 10 13:48:21 localhost systemd[1]: Mounted /boot/grub. Jul 10 13:48:21 localhost systemd[1]: Reached target Local File Systems. Jul 10 13:48:21 localhost systemd[1]: Starting Local File Systems. Jul 10 13:48:21 localhost systemd[1]: Starting Wait for all "auto" /etc/network/interfaces to be up for network-online.target... Jul 10 13:48:21 localhost systemd[1]: Reached target Remote File Systems. Jul 10 13:48:21 localhost systemd[1]: Starting Remote File Systems. Jul 10 13:48:21 localhost systemd[1]: Starting Create Volatile Files and Directories... Jul 10 13:48:21 localhost systemd[1]: Starting LSB: AppArmor initialization... Jul 10 13:48:21 localhost systemd[1]: Started Commit a transient machine-id on disk. Jul 10 13:48:21 localhost systemd-tmpfiles[442]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring. Jul 10 13:48:21 localhost systemd[1]: Started Create Volatile Files and Directories. Jul 10 13:48:21 localhost systemd[1]: Starting Network Time Synchronization... Jul 10 13:48:21 localhost systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jul 10 13:48:21 localhost apparmor[443]: * Starting AppArmor profiles Jul 10 13:48:21 localhost systemd[1]: Started Wait for all "auto" /etc/network/interfaces to be up for network-online.target. Jul 10 13:48:21 localhost systemd[1]: Started Update UTMP about System Boot/Shutdown. Jul 10 13:48:21 localhost systemd[1]: Started Network Time Synchronization. Jul 10 13:48:21 localhost systemd[1]: Reached target System Time Synchronized. Jul 10 13:48:21 localhost systemd[1]: Starting System Time Synchronized. Jul 10 13:48:21 localhost apparmor[443]: Skipping profile in /etc/apparmor.d/disable: usr.sbin.rsyslogd Jul 10 13:48:21 localhost apparmor[443]: ...done. Jul 10 13:48:21 localhost systemd[1]: Started LSB: AppArmor initialization. Jul 10 13:48:21 localhost systemd[1]: Started ifup for eth0. Jul 10 13:48:21 localhost systemd[1]: Starting ifup for eth0... Jul 10 13:48:21 localhost systemd[1]: Starting LSB: Raise network interfaces.... Jul 10 13:48:21 localhost sh[488]: Unknown interface eth0 Jul 10 13:48:21 localhost networking[489]: * Configuring network interfaces... Jul 10 13:48:21 localhost networking[489]: ...done. Jul 10 13:48:21 localhost systemd[1]: Started LSB: Raise network interfaces.. Jul 10 13:48:21 localhost systemd[1]: Reached target Network. Jul 10 13:48:21 localhost systemd[1]: Starting Network. Jul 10 13:48:21 localhost systemd[1]: Reached target Network is Online. Jul 10 13:48:21 localhost systemd[1]: Starting Network is Online. Jul 10 13:48:21 localhost systemd[1]: Reached target System Initialization. Jul 10 13:48:21 localhost systemd[1]: Starting System Initialization. Jul 10 13:48:21 localhost systemd[1]: Started Ubuntu Core Snappy Autopilot. Jul 10 13:48:21 localhost systemd[1]: Starting Ubuntu Core Snappy Autopilot. Jul 10 13:48:21 localhost systemd[1]: Listening on D-Bus System Message Bus Socket. Jul 10 13:48:21 localhost systemd[1]: Starting D-Bus System Message Bus Socket. Jul 10 13:48:21 localhost systemd[1]: Reached target Sockets. Jul 10 13:48:21 localhost systemd[1]: Starting Sockets. Jul 10 13:48:21 localhost systemd[1]: Reached target Basic System. Jul 10 13:48:21 localhost systemd[1]: Starting Basic System. Jul 10 13:48:21 localhost systemd[1]: Starting Initial cloud-init job (pre-networking)... Jul 10 13:48:21 localhost systemd[1]: Starting /etc/rc.local Compatibility... Jul 10 13:48:21 localhost systemd[1]: Starting System Logging Service... Jul 10 13:48:21 localhost systemd[1]: Started Regular background program processing daemon. Jul 10 13:48:21 localhost systemd[1]: Starting Regular background program processing daemon... Jul 10 13:48:21 localhost cron[540]: (CRON) INFO (pidfile fd = 3) Jul 10 13:48:21 localhost cron[540]: (CRON) INFO (Running @reboot jobs) Jul 10 13:48:21 localhost systemd[1]: Starting LSB: Set the CPU Frequency Scaling governor to "ondemand"... Jul 10 13:48:21 localhost systemd[1]: Starting Run snappy firstboot setup... Jul 10 13:48:21 localhost systemd[1]: Started getty on tty2-tty6 if dbus and logind are not available. Jul 10 13:48:21 localhost systemd[1]: Starting Notify bootloader that boot was successful... Jul 10 13:48:21 localhost systemd[1]: Starting Login Service... Jul 10 13:48:21 localhost systemd[1]: Starting D-Bus System Message Bus... Jul 10 13:48:21 localhost systemd[1]: Started Daily Cleanup of Temporary Directories. Jul 10 13:48:21 localhost systemd[1]: Starting Daily Cleanup of Temporary Directories. Jul 10 13:48:21 localhost systemd[1]: Reached target Timers. Jul 10 13:48:21 localhost systemd[1]: Starting Timers. Jul 10 13:48:21 localhost systemd[1]: Started System Logging Service. Jul 10 13:48:21 localhost systemd[1]: Started /etc/rc.local Compatibility. Jul 10 13:48:21 localhost systemd[1]: Started LSB: Set the CPU Frequency Scaling governor to "ondemand". Jul 10 13:48:21 localhost systemd[1]: Started D-Bus System Message Bus. Jul 10 13:48:21 localhost snappy[542]: First boot has already run Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.systemd1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.systemd1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.network1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.network1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/wpa_supplicant.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/wpa_supplicant.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.resolve1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.resolve1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.timedate1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.timedate1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.hostname1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.hostname1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.locale1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.locale1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.login1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.login1.conf' Jul 10 13:48:21 localhost dbus-daemon: Encountered error 'Error in file /etc/dbus-1/system.d/org.freedesktop.machine1.conf, line 1, column 0: no element found#012' while parsing '/etc/dbus-1/system.d/org.freedesktop.machine1.conf' Jul 10 13:48:21 localhost dbus[565]: [system] AppArmor D-Bus mediation is enabled Jul 10 13:48:21 localhost systemd[1]: Failed to register name: Permission denied Jul 10 13:48:21 localhost systemd[1]: Failed to set up API bus: Permission denied Jul 10 13:48:21 localhost systemd[1]: Started Run snappy firstboot setup. Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199:invalid package on system Jul 10 13:48:21 localhost systemd[1]: Starting Run snappy compatibility hooks... Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199:Stack trace: Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:94 (0x43acee) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:89 (0x43ab10) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/github.com/juju/loggo/writer.go:132 (0x50b8b6) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/github.com/juju/loggo/logger.go:350 (0x50ac2c) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/github.com/juju/loggo/logger.go:310 (0x50a9af) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/github.com/juju/loggo/logger.go:360 (0x50ad31) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199 (0x43b87c) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/cmd/snappy/cmd_booted.go:46 (0x401d47) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/github.com/jessevdk/go-flags/parser.go:241 (0x4d8ecd) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/github.com/jessevdk/go-flags/parser.go:126 (0x4d86b3) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/cmd/snappy/main.go:47 (0x40b3f2) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /usr/lib/go/src/pkg/runtime/proc.c:247 (0x41ea3a) Jul 10 13:48:21 localhost snappy[554]: ERROR:snappy:/build/ubuntu-snappy-3mwxMu/ubuntu-snappy-1.0.1/obj-x86_64-linux-gnu/src/launchpad.net/snappy/logger/logger.go:199: /usr/lib/go/src/pkg/runtime/proc.c:1445 (0x421200) Jul 10 13:48:21 localhost snappy[554]: invalid package on system Jul 10 13:48:21 localhost systemd[1]: ubuntu-snappy.boot-ok.service: main process exited, code=exited, status=1/FAILURE Jul 10 13:48:21 localhost systemd[1]: Failed to start Notify bootloader that boot was successful. Jul 10 13:48:21 localhost systemd[1]: Unit ubuntu-snappy.boot-ok.service entered failed state. Jul 10 13:48:21 localhost systemd[1]: ubuntu-snappy.boot-ok.service failed. Jul 10 13:48:21 localhost systemd[1]: Started Run snappy compatibility hooks. Jul 10 13:48:21 localhost kernel: [ 4.933593] random: nonblocking pool is initialized Jul 10 13:48:22 localhost cloud-init[536]: WARN: no logging configured! (tried 0 configs) Jul 10 13:48:22 localhost cloud-init[536]: Setting up basic logging... Jul 10 13:48:22 localhost cloud-init[536]: Cloud-init v. 0.7.7 running 'init-local' at Fri, 10 Jul 2015 13:48:22 +0000. Up 5.20 seconds. Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,161 - util.py[DEBUG]: Cloud-init v. 0.7.7 running 'init-local' at Fri, 10 Jul 2015 13:48:22 +0000. Up 5.20 seconds. Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,168 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,168 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 108:4 Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,169 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,169 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,169 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,169 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,175 - stages.py[DEBUG]: Using distro class Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,175 - __init__.py[DEBUG]: Looking for for data source in: ['NoCloud', 'ConfigDrive', 'OpenNebula', 'Azure', 'AltCloud', 'OVF', 'MAAS', 'GCE', 'OpenStack', 'Ec2', 'CloudSigma', 'CloudStack', 'SmartOS', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM'] Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,293 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceNoCloud', 'DataSourceConfigDrive', 'DataSourceOpenNebula', 'DataSourceOVF'] Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,296 - __init__.py[DEBUG]: Seeing if we can get any data from Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,297 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,298 - util.py[DEBUG]: Read 128 bytes from /proc/cmdline Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,298 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/user-data (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,298 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/meta-data (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,298 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/vendor-data (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,298 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,326 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,328 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,371 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,403 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,435 - __init__.py[DEBUG]: Seeing if we can get any data from Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,437 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,463 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,468 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/cd0'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,471 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/cd1'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,474 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,503 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,535 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=config-2', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,567 - __init__.py[DEBUG]: Seeing if we can get any data from Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,569 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CONTEXT', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,598 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CDROM', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,631 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,663 - __init__.py[DEBUG]: Seeing if we can get any data from Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,665 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,668 - util.py[DEBUG]: Read 4789 bytes from /proc/mounts Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,669 - util.py[DEBUG]: Fetched {'securityfs': {'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'securityfs', 'mountpoint': '/sys/kernel/security'}, 'udev': {'opts': 'rw,relatime,size=242344k,nr_inodes=60586,mode=755', 'fstype': 'devtmpfs', 'mountpoint': '/dev'}, '/dev/sda3': {'opts': 'ro,relatime,data=ordered', 'fstype': 'ext4', 'mountpoint': '/'}, 'hugetlbfs': {'opts': 'rw,relatime', 'fstype': 'hugetlbfs', 'mountpoint': '/dev/hugepages'}, '/dev/sda2': {'opts': 'rw,sync,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=iso8859-1,shortname=mixed,errors=remount-ro', 'fstype': 'vfat', 'mountpoint': '/boot/grub'}, 'pstore': {'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'pstore', 'mountpoint': '/sys/fs/pstore'}, 'debugfs': {'opts': 'rw,relatime', 'fstype': 'debugfs', 'mountpoint': '/sys/kernel/debug'}, '/dev/sda4': {'opts': 'ro,relatime,data=ordered', 'fstype': 'ext4', 'mountpoint': '/writable/cache/system'}, 'systemd-1': {'opts': 'rw,relatime,fd=21,pgrp=1,timeout=300,minproto=5,maxproto=5,direct', 'fstype': 'autofs', 'mountpoint': '/proc/sys/fs/binfmt_misc'}, 'proc': {'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'proc', 'mountpoint': '/proc'}, 'sysfs': {'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'sysfs', 'mountpoint': '/sys'}, '/dev/sda5': {'opts': 'rw,relatime,discard,data=ordered', 'fstype': 'ext4', 'mountpoint': '/var/cache/apparmor'}, 'fusectl': {'opts': 'rw,relatime', 'fstype': 'fusectl', 'mountpoint': '/sys/fs/fuse/connections'}, 'mqueue': {'opts': 'rw,relatime', 'fstype': 'mqueue', 'mountpoint': '/dev/mqueue'}, 'tmpfs': {'opts': 'rw,relatime,mode=700', 'fstype': 'tmpfs', 'mountpoint': '/var/lib/sudo'}, 'devpts': {'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000', 'fstype': 'devpts', 'mountpoint': '/dev/pts'}, 'cgroup': {'opts': 'rw,nosuid,nodev,noexec,relatime,memory', 'fstype': 'cgroup', 'mountpoint': '/sys/fs/cgroup/memory'}} mounts from proc Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,669 - util.py[DEBUG]: Peeking at /dev/sr0 (max_bytes=512) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,703 - cloud-init[DEBUG]: No local datasource found Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,704 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,705 - util.py[DEBUG]: Read 10 bytes from /proc/uptime Jul 10 13:48:22 localhost cloud-init[536]: 2015-07-10 13:48:22,705 - util.py[DEBUG]: cloud-init mode 'init' took 0.562 seconds (0.56) Jul 10 13:48:22 localhost systemd[1]: Started Initial cloud-init job (pre-networking). Jul 10 13:48:22 localhost systemd[1]: Starting Initial cloud-init job (metadata service crawler)... Jul 10 13:48:23 localhost cloud-init[605]: WARN: no logging configured! (tried 0 configs) Jul 10 13:48:23 localhost cloud-init[605]: Setting up basic logging... Jul 10 13:48:23 localhost cloud-init[605]: Cloud-init v. 0.7.7 running 'init' at Fri, 10 Jul 2015 13:48:23 +0000. Up 6.36 seconds. Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,317 - util.py[DEBUG]: Cloud-init v. 0.7.7 running 'init' at Fri, 10 Jul 2015 13:48:23 +0000. Up 6.36 seconds. Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,323 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,323 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 108:4 Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,323 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,332 - util.py[DEBUG]: Running command ['netstat', '-rn'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,338 - util.py[WARNING]: Route info failed: Unexpected error while running command. Jul 10 13:48:23 localhost cloud-init[605]: Command: ['netstat', '-rn'] Jul 10 13:48:23 localhost cloud-init[605]: Exit code: 1 Jul 10 13:48:23 localhost cloud-init[605]: Reason: - Jul 10 13:48:23 localhost cloud-init[605]: Stdout: 'Kernel IP routing table\nDestination Gateway Genmask Flags MSS Window irtt Iface\n' Jul 10 13:48:23 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,338 - util.py[DEBUG]: Route info failed: Unexpected error while running command. Jul 10 13:48:23 localhost cloud-init[605]: Command: ['netstat', '-rn'] Jul 10 13:48:23 localhost cloud-init[605]: Exit code: 1 Jul 10 13:48:23 localhost cloud-init[605]: Reason: - Jul 10 13:48:23 localhost cloud-init[605]: Stdout: 'Kernel IP routing table\nDestination Gateway Genmask Flags MSS Window irtt Iface\n' Jul 10 13:48:23 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:23 localhost cloud-init[605]: Traceback (most recent call last): Jul 10 13:48:23 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/netinfo.py", line 199, in route_pformat Jul 10 13:48:23 localhost cloud-init[605]: routes = route_info() Jul 10 13:48:23 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/netinfo.py", line 99, in route_info Jul 10 13:48:23 localhost cloud-init[605]: (route_out, _err) = util.subp(["netstat", "-rn"]) Jul 10 13:48:23 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/util.py", line 1683, in subp Jul 10 13:48:23 localhost cloud-init[605]: cmd=args) Jul 10 13:48:23 localhost cloud-init[605]: cloudinit.util.ProcessExecutionError: Unexpected error while running command. Jul 10 13:48:23 localhost cloud-init[605]: Command: ['netstat', '-rn'] Jul 10 13:48:23 localhost cloud-init[605]: Exit code: 1 Jul 10 13:48:23 localhost cloud-init[605]: Reason: - Jul 10 13:48:23 localhost cloud-init[605]: Stdout: 'Kernel IP routing table\nDestination Gateway Genmask Flags MSS Window irtt Iface\n' Jul 10 13:48:23 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:23 localhost cloud-init[605]: ci-info: +++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++ Jul 10 13:48:23 localhost cloud-init[605]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+ Jul 10 13:48:23 localhost cloud-init[605]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | Jul 10 13:48:23 localhost cloud-init[605]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+ Jul 10 13:48:23 localhost cloud-init[605]: ci-info: | eth0 | False | . | . | . | 52:54:00:12:34:56 | Jul 10 13:48:23 localhost cloud-init[605]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | . | . | Jul 10 13:48:23 localhost cloud-init[605]: ci-info: | lo | True | ::1/128 | . | host | . | Jul 10 13:48:23 localhost cloud-init[605]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+ Jul 10 13:48:23 localhost cloud-init[605]: ci-info: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!Route info failed!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,339 - cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early. Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,339 - util.py[DEBUG]: Reading from /var/lib/cloud/data/no-net (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,339 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,339 - cloud-init[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early. Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,339 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,345 - stages.py[DEBUG]: Using distro class Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,347 - __init__.py[DEBUG]: Looking for for data source in: ['NoCloud', 'ConfigDrive', 'OpenNebula', 'Azure', 'AltCloud', 'OVF', 'MAAS', 'GCE', 'OpenStack', 'Ec2', 'CloudSigma', 'CloudStack', 'SmartOS', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK'] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,484 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceNoCloudNet', 'DataSourceConfigDriveNet', 'DataSourceOpenNebulaNet', 'DataSourceAzureNet', 'DataSourceAltCloud', 'DataSourceOVFNet', 'DataSourceMAAS', 'DataSourceGCE', 'DataSourceOpenStack', 'DataSourceEc2', 'DataSourceCloudSigmaNet', 'DataSourceCloudStack', 'DataSourceSmartOS', 'DataSourceNone'] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,487 - __init__.py[DEBUG]: Seeing if we can get any data from Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,487 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,488 - util.py[DEBUG]: Read 128 bytes from /proc/cmdline Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,488 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/user-data (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,490 - util.py[DEBUG]: Read 158 bytes from /var/lib/cloud/seed/nocloud-net/user-data Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,490 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/meta-data (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,490 - util.py[DEBUG]: Read 28 bytes from /var/lib/cloud/seed/nocloud-net/meta-data Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,490 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/vendor-data (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,490 - DataSourceNoCloud.py[DEBUG]: Using seeded data from /var/lib/cloud/seed/nocloud-net Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,490 - util.py[DEBUG]: Attempting to load yaml from string of length 28 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,491 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,519 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,521 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,551 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,582 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,615 - stages.py[INFO]: Loaded datasource DataSourceNoCloudNet - DataSourceNoCloudNet [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,617 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,619 - util.py[DEBUG]: Read 128 bytes from /proc/cmdline Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,619 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,619 - util.py[DEBUG]: Read 2927 bytes from /etc/cloud/cloud.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,619 - util.py[DEBUG]: Attempting to load yaml from string of length 2927 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,636 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/99-snappy-azure.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,638 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/99-snappy-azure.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_snappy.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,640 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/10_snappy.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,641 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud-static' Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,644 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud-static/datasource (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,645 - util.py[DEBUG]: Read 94 bytes from /var/lib/cloud/instances/nocloud-static/datasource Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,645 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud-static/datasource - wb: [420] 94 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,646 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [420] 94 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,646 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,648 - util.py[DEBUG]: Read 15 bytes from /var/lib/cloud/data/instance-id Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,648 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [420] 15 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,649 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [420] 15 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,649 - cloud-init[DEBUG]: init will now be targeting instance id: nocloud-static Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,649 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,650 - util.py[DEBUG]: Read 128 bytes from /proc/cmdline Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,651 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,651 - util.py[DEBUG]: Read 2927 bytes from /etc/cloud/cloud.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,651 - util.py[DEBUG]: Attempting to load yaml from string of length 2927 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/99-snappy-azure.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/99-snappy-azure.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_snappy.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/10_snappy.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,669 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,670 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: Read 189 bytes from /var/lib/cloud/instance/cloud-config.txt Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,674 - util.py[DEBUG]: Attempting to load yaml from string of length 189 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,676 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [256] 4072 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,677 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud-static/user-data.txt - wb: [384] 158 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,678 - util.py[DEBUG]: Attempting to load yaml from string of length 158 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,696 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud-static/user-data.txt.i - wb: [384] 463 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,696 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud-static/vendor-data.txt - wb: [384] 0 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,697 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud-static/vendor-data.txt.i - wb: [384] 0 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,697 - stages.py[DEBUG]: Using distro class Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,699 - helpers.py[DEBUG]: consume_data already ran (freq=once-per-instance) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,700 - stages.py[DEBUG]: Added default handler for {'text/cloud-config-jsonp', 'text/cloud-config'} from CloudConfigPartHandler: [['text/cloud-config-jsonp', 'text/cloud-config']] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,700 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,700 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,700 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,700 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,700 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,701 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config-jsonp', 'text/cloud-config']] (__begin__, None, 3) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,701 - __init__.py[DEBUG]: {'Content-Disposition': 'attachment; filename="part-001"', 'MIME-Version': '1.0', 'Content-Type': 'text/cloud-config'} Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,701 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config-jsonp', 'text/cloud-config']] (text/cloud-config, part-001, 3) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,701 - util.py[DEBUG]: Attempting to load yaml from string of length 158 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,705 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])] Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,705 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,705 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,705 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config-jsonp', 'text/cloud-config']] (__end__, None, 3) with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,707 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud-static/cloud-config.txt - wb: [384] 189 bytes Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,709 - stages.py[DEBUG]: no vendordata from datasource Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,709 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,709 - util.py[DEBUG]: Read 128 bytes from /proc/cmdline Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,709 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,709 - util.py[DEBUG]: Read 2927 bytes from /etc/cloud/cloud.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,709 - util.py[DEBUG]: Attempting to load yaml from string of length 2927 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,733 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/99-snappy-azure.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,733 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/99-snappy-azure.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,733 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,733 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,734 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,735 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg Jul 10 13:48:23 localhost systemd[1]: Started Initial cloud-init job (metadata service crawler). Jul 10 13:48:23 localhost systemd[1]: Starting Permit User Sessions... Jul 10 13:48:23 localhost systemd[1]: Reached target Cloud-config availability. Jul 10 13:48:23 localhost systemd[1]: Starting Cloud-config availability. Jul 10 13:48:23 localhost systemd[1]: Starting Apply the settings specified in cloud-config... Jul 10 13:48:23 localhost systemd[1]: Started OpenBSD Secure Shell server. Jul 10 13:48:23 localhost systemd[1]: Starting OpenBSD Secure Shell server... Jul 10 13:48:23 localhost systemd[1]: Started Permit User Sessions. Jul 10 13:48:23 localhost systemd[1]: Started Getty on tty1. Jul 10 13:48:23 localhost systemd[1]: Starting Getty on tty1... Jul 10 13:48:23 localhost systemd[1]: Started Serial Getty on ttyS0. Jul 10 13:48:23 localhost systemd[1]: Reached target Login Prompts. Jul 10 13:48:23 localhost systemd[1]: Starting Login Prompts. Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,735 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,735 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,735 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_snappy.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,735 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/10_snappy.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Read 0 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: load_yaml given empty string, returning default Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Read 189 bytes from /var/lib/cloud/instance/cloud-config.txt Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,736 - util.py[DEBUG]: Attempting to load yaml from string of length 189 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,739 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,740 - util.py[DEBUG]: Read 189 bytes from /var/lib/cloud/instance/cloud-config.txt Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,740 - util.py[DEBUG]: Attempting to load yaml from string of length 189 with allowed root types (,) Jul 10 13:48:23 localhost cloud-init[605]: WARN: no logging configured! (tried 0 configs) Jul 10 13:48:23 localhost cloud-init[605]: Setting up basic logging... Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,772 - stages.py[DEBUG]: Using distro class Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,772 - stages.py[DEBUG]: Using distro class Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,773 - stages.py[DEBUG]: Running module migrator () with frequency always Jul 10 13:48:23 localhost cloud-init[605]: 2015-07-10 13:48:23,773 - stages.py[DEBUG]: Running module migrator () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,773 - helpers.py[DEBUG]: Running config-migrator using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,773 - helpers.py[DEBUG]: Running config-migrator using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,775 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,775 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module ubuntu-init-switch () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module ubuntu-init-switch () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - helpers.py[DEBUG]: config-ubuntu-init-switch already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - helpers.py[DEBUG]: config-ubuntu-init-switch already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module seed_random () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module seed_random () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - helpers.py[DEBUG]: config-seed_random already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - helpers.py[DEBUG]: config-seed_random already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module bootcmd () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module bootcmd () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - helpers.py[DEBUG]: Running config-bootcmd using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - helpers.py[DEBUG]: Running config-bootcmd using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module write-files () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,776 - stages.py[DEBUG]: Running module write-files () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - helpers.py[DEBUG]: config-write-files already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - helpers.py[DEBUG]: config-write-files already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - stages.py[DEBUG]: Running module growpart () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - stages.py[DEBUG]: Running module growpart () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - helpers.py[DEBUG]: Running config-growpart using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - helpers.py[DEBUG]: Running config-growpart using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg. Using default: {'mode': 'auto', 'ignore_growroot_disabled': False, 'devices': ['/']} Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg. Using default: {'mode': 'auto', 'ignore_growroot_disabled': False, 'devices': ['/']} Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,777 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,787 - util.py[DEBUG]: Reading from /proc/605/mountinfo (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,787 - util.py[DEBUG]: Reading from /proc/605/mountinfo (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,788 - util.py[DEBUG]: Read 7202 bytes from /proc/605/mountinfo Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,788 - util.py[DEBUG]: Read 7202 bytes from /proc/605/mountinfo Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Reading from /sys/class/block/sda3/partition (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Reading from /sys/class/block/sda3/partition (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/sda3/partition Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/sda3/partition Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Reading from /sys/devices/pci0000:00/0000:00:01.1/ata1/host0/target0:0:0/0:0:0:0/block/sda/dev (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Reading from /sys/devices/pci0000:00/0000:00:01.1/ata1/host0/target0:0:0/0:0:0:0/block/sda/dev (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Read 4 bytes from /sys/devices/pci0000:00/0000:00:01.1/ata1/host0/target0:0:0/0:0:0:0/block/sda/dev Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Read 4 bytes from /sys/devices/pci0000:00/0000:00:01.1/ata1/host0/target0:0:0/0:0:0:0/block/sda/dev Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/sda', '3'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,790 - util.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/sda', '3'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,807 - util.py[WARNING]: Failed growpart --dry-run for (/dev/sda, 3) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,807 - util.py[WARNING]: Failed growpart --dry-run for (/dev/sda, 3) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,807 - util.py[DEBUG]: Failed growpart --dry-run for (/dev/sda, 3) Jul 10 13:48:24 localhost cloud-init[605]: Traceback (most recent call last): Jul 10 13:48:24 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/config/cc_growpart.py", line 100, in resize Jul 10 13:48:24 localhost cloud-init[605]: util.subp(["growpart", '--dry-run', diskdev, partnum]) Jul 10 13:48:24 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/util.py", line 1683, in subp Jul 10 13:48:24 localhost cloud-init[605]: cmd=args) Jul 10 13:48:24 localhost cloud-init[605]: cloudinit.util.ProcessExecutionError: Unexpected error while running command. Jul 10 13:48:24 localhost cloud-init[605]: Command: ['growpart', '--dry-run', '/dev/sda', '3'] Jul 10 13:48:24 localhost cloud-init[605]: Exit code: 2 Jul 10 13:48:24 localhost cloud-init[605]: Reason: - Jul 10 13:48:24 localhost cloud-init[605]: Stdout: 'FAILED: GPT partition found but no sgdisk\n' Jul 10 13:48:24 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,807 - util.py[DEBUG]: Failed growpart --dry-run for (/dev/sda, 3) Jul 10 13:48:24 localhost cloud-init[605]: Traceback (most recent call last): Jul 10 13:48:24 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/config/cc_growpart.py", line 100, in resize Jul 10 13:48:24 localhost cloud-init[605]: util.subp(["growpart", '--dry-run', diskdev, partnum]) Jul 10 13:48:24 localhost cloud-init[605]: File "/usr/lib/python3/dist-packages/cloudinit/util.py", line 1683, in subp Jul 10 13:48:24 localhost cloud-init[605]: cmd=args) Jul 10 13:48:24 localhost cloud-init[605]: cloudinit.util.ProcessExecutionError: Unexpected error while running command. Jul 10 13:48:24 localhost cloud-init[605]: Command: ['growpart', '--dry-run', '/dev/sda', '3'] Jul 10 13:48:24 localhost cloud-init[605]: Exit code: 2 Jul 10 13:48:24 localhost cloud-init[605]: Reason: - Jul 10 13:48:24 localhost cloud-init[605]: Stdout: 'FAILED: GPT partition found but no sgdisk\n' Jul 10 13:48:24 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - util.py[DEBUG]: resize_devices took 0.020 seconds Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - util.py[DEBUG]: resize_devices took 0.020 seconds Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - cc_growpart.py[DEBUG]: '/' FAILED: failed to resize: disk=/dev/sda, ptnum=3: Unexpected error while running command. Jul 10 13:48:24 localhost cloud-init[605]: Command: ['growpart', '--dry-run', '/dev/sda', '3'] Jul 10 13:48:24 localhost cloud-init[605]: Exit code: 2 Jul 10 13:48:24 localhost cloud-init[605]: Reason: - Jul 10 13:48:24 localhost cloud-init[605]: Stdout: 'FAILED: GPT partition found but no sgdisk\n' Jul 10 13:48:24 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - cc_growpart.py[DEBUG]: '/' FAILED: failed to resize: disk=/dev/sda, ptnum=3: Unexpected error while running command. Jul 10 13:48:24 localhost cloud-init[605]: Command: ['growpart', '--dry-run', '/dev/sda', '3'] Jul 10 13:48:24 localhost cloud-init[605]: Exit code: 2 Jul 10 13:48:24 localhost cloud-init[605]: Reason: - Jul 10 13:48:24 localhost cloud-init[605]: Stdout: 'FAILED: GPT partition found but no sgdisk\n' Jul 10 13:48:24 localhost cloud-init[605]: Stderr: '' Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - stages.py[DEBUG]: Running module resizefs () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - stages.py[DEBUG]: Running module resizefs () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - helpers.py[DEBUG]: Running config-resizefs using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - helpers.py[DEBUG]: Running config-resizefs using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - util.py[DEBUG]: Reading from /proc/605/mountinfo (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - util.py[DEBUG]: Reading from /proc/605/mountinfo (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - util.py[DEBUG]: Read 7202 bytes from /proc/605/mountinfo Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,808 - util.py[DEBUG]: Read 7202 bytes from /proc/605/mountinfo Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,809 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/sda3 mnt_point=/ path=/ Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,809 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/sda3 mnt_point=/ path=/ Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,809 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,809 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,816 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,816 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Read 152 bytes from /proc/1/environ Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Read 152 bytes from /proc/1/environ Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Read 772 bytes from /proc/self/status Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,819 - util.py[DEBUG]: Read 772 bytes from /proc/self/status Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,820 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/sda3 Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,820 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/sda3 Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,820 - util.py[DEBUG]: Running command ('resize2fs', '/dev/sda3') with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,820 - util.py[DEBUG]: Running command ('resize2fs', '/dev/sda3') with allowed return codes [0] (shell=False, capture=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - util.py[DEBUG]: Resizing took 0.007 seconds Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - util.py[DEBUG]: Resizing took 0.007 seconds Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - stages.py[DEBUG]: Running module set_hostname () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - stages.py[DEBUG]: Running module set_hostname () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - helpers.py[DEBUG]: config-set_hostname already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - helpers.py[DEBUG]: config-set_hostname already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - stages.py[DEBUG]: Running module update_hostname () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,827 - stages.py[DEBUG]: Running module update_hostname () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - helpers.py[DEBUG]: Running config-update_hostname using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - helpers.py[DEBUG]: Running config-update_hostname using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Read 0 bytes from /etc/hosts Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Read 0 bytes from /etc/hosts Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Read 0 bytes from /etc/hosts Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Read 0 bytes from /etc/hosts Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - cc_update_hostname.py[DEBUG]: Updating hostname to localhost.localdomain (localhost.localdomain) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - cc_update_hostname.py[DEBUG]: Updating hostname to localhost.localdomain (localhost.localdomain) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Read 22 bytes from /var/lib/cloud/data/previous-hostname Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,828 - util.py[DEBUG]: Read 22 bytes from /var/lib/cloud/data/previous-hostname Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - util.py[DEBUG]: Read 22 bytes from /etc/hostname Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - util.py[DEBUG]: Read 22 bytes from /etc/hostname Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - __init__.py[DEBUG]: Attempting to update hostname to localhost.localdomain in 0 files Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - __init__.py[DEBUG]: Attempting to update hostname to localhost.localdomain in 0 files Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - stages.py[DEBUG]: Running module update_etc_hosts () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - stages.py[DEBUG]: Running module update_etc_hosts () with frequency always Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock () Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - stages.py[DEBUG]: Running module ca-certs () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - stages.py[DEBUG]: Running module ca-certs () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - helpers.py[DEBUG]: config-ca-certs already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - helpers.py[DEBUG]: config-ca-certs already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - stages.py[DEBUG]: Running module rsyslog () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,829 - stages.py[DEBUG]: Running module rsyslog () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,831 - helpers.py[DEBUG]: config-rsyslog already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,831 - helpers.py[DEBUG]: config-rsyslog already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,831 - stages.py[DEBUG]: Running module users-groups () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,831 - stages.py[DEBUG]: Running module users-groups () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - helpers.py[DEBUG]: config-users-groups already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - helpers.py[DEBUG]: config-users-groups already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - stages.py[DEBUG]: Running module ssh () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - stages.py[DEBUG]: Running module ssh () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - helpers.py[DEBUG]: config-ssh already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - helpers.py[DEBUG]: config-ssh already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - cloud-init[DEBUG]: Ran 14 modules with 0 failures Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,832 - cloud-init[DEBUG]: Ran 14 modules with 0 failures Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,833 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,833 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,833 - util.py[DEBUG]: Read 10 bytes from /proc/uptime Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,833 - util.py[DEBUG]: Read 10 bytes from /proc/uptime Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,833 - util.py[DEBUG]: cloud-init mode 'init' took 0.530 seconds (0.53) Jul 10 13:48:24 localhost sshd[635]: key_load_public: invalid format Jul 10 13:48:24 localhost sshd[635]: Could not load host key: /etc/ssh/ssh_host_rsa_key Jul 10 13:48:24 localhost sshd[635]: key_load_public: invalid format Jul 10 13:48:24 localhost sshd[635]: Could not load host key: /etc/ssh/ssh_host_dsa_key Jul 10 13:48:24 localhost sshd[635]: key_load_public: invalid format Jul 10 13:48:24 localhost sshd[635]: Could not load host key: /etc/ssh/ssh_host_ecdsa_key Jul 10 13:48:24 localhost sshd[635]: key_load_public: invalid format Jul 10 13:48:24 localhost sshd[635]: Could not load host key: /etc/ssh/ssh_host_ed25519_key Jul 10 13:48:24 localhost cloud-init[633]: WARN: no logging configured! (tried 0 configs) Jul 10 13:48:24 localhost cloud-init[633]: Setting up basic logging... Jul 10 13:48:24 localhost cloud-init[633]: Cloud-init v. 0.7.7 running 'modules:config' at Fri, 10 Jul 2015 13:48:24 +0000. Up 7.84 seconds. Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,819 - util.py[DEBUG]: Cloud-init v. 0.7.7 running 'modules:config' at Fri, 10 Jul 2015 13:48:24 +0000. Up 7.84 seconds. Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,868 - stages.py[DEBUG]: Using distro class Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,870 - stages.py[DEBUG]: Running module emit_upstart () with frequency always Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,872 - helpers.py[DEBUG]: Running config-emit_upstart using lock () Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,872 - cc_emit_upstart.py[DEBUG]: no /sbin/initctl located Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - cc_emit_upstart.py[DEBUG]: not upstart system, '%s' disabled Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - stages.py[DEBUG]: Running module disk_setup () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - helpers.py[DEBUG]: config-disk_setup already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - stages.py[DEBUG]: Running module mounts () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - helpers.py[DEBUG]: config-mounts already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - stages.py[DEBUG]: Running module ssh-import-id () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - helpers.py[DEBUG]: config-ssh-import-id already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - stages.py[DEBUG]: Running module locale () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - helpers.py[DEBUG]: config-locale already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,873 - stages.py[DEBUG]: Running module set-passwords () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,874 - helpers.py[DEBUG]: config-set-passwords already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,875 - stages.py[DEBUG]: Running module snappy () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,875 - helpers.py[DEBUG]: config-snappy already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,875 - stages.py[DEBUG]: Running module grub-dpkg () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - helpers.py[DEBUG]: config-grub-dpkg already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - stages.py[DEBUG]: Running module apt-pipelining () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - helpers.py[DEBUG]: config-apt-pipelining already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[605]: 2015-07-10 13:48:23,833 - util.py[DEBUG]: cloud-init mode 'init' took 0.530 seconds (0.53) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - stages.py[DEBUG]: Running module apt-configure () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - helpers.py[DEBUG]: config-apt-configure already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - stages.py[DEBUG]: Running module package-update-upgrade-install () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - helpers.py[DEBUG]: config-package-update-upgrade-install already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - stages.py[DEBUG]: Running module landscape () with frequency once-per-instance Jul 10 13:48:24 localhost systemd[1]: Started Apply the settings specified in cloud-config. Jul 10 13:48:24 localhost systemd[1]: Starting Execute cloud user/final scripts... Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - helpers.py[DEBUG]: config-landscape already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,876 - stages.py[DEBUG]: Running module timezone () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - helpers.py[DEBUG]: config-timezone already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - stages.py[DEBUG]: Running module puppet () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - helpers.py[DEBUG]: config-puppet already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - stages.py[DEBUG]: Running module chef () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - helpers.py[DEBUG]: config-chef already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - stages.py[DEBUG]: Running module salt-minion () with frequency once-per-instance Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - helpers.py[DEBUG]: config-salt-minion already ran (freq=once-per-instance) Jul 10 13:48:24 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - stages.py[DEBUG]: Running module mcollective () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - helpers.py[DEBUG]: config-mcollective already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,877 - stages.py[DEBUG]: Running module disable-ec2-metadata () with frequency always Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,878 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock () Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,880 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,880 - stages.py[DEBUG]: Running module runcmd () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,880 - helpers.py[DEBUG]: config-runcmd already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,880 - stages.py[DEBUG]: Running module byobu () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,881 - helpers.py[DEBUG]: config-byobu already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,881 - cloud-init[DEBUG]: Ran 20 modules with 0 failures Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,881 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,881 - util.py[DEBUG]: Read 10 bytes from /proc/uptime Jul 10 13:48:25 localhost cloud-init[633]: 2015-07-10 13:48:24,882 - util.py[DEBUG]: cloud-init mode 'modules' took 0.097 seconds (0.09) Jul 10 13:48:25 localhost cloud-init[640]: WARN: no logging configured! (tried 0 configs) Jul 10 13:48:25 localhost cloud-init[640]: Setting up basic logging... Jul 10 13:48:25 localhost cloud-init[640]: Cloud-init v. 0.7.7 running 'modules:final' at Fri, 10 Jul 2015 13:48:25 +0000. Up 8.57 seconds. Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,546 - util.py[DEBUG]: Cloud-init v. 0.7.7 running 'modules:final' at Fri, 10 Jul 2015 13:48:25 +0000. Up 8.57 seconds. Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,563 - stages.py[DEBUG]: Using distro class Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,565 - stages.py[DEBUG]: Running module rightscale_userdata () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - helpers.py[DEBUG]: config-rightscale_userdata already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - stages.py[DEBUG]: Running module scripts-vendor () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - helpers.py[DEBUG]: config-scripts-vendor already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - stages.py[DEBUG]: Running module scripts-per-once () with frequency once Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - helpers.py[DEBUG]: config-scripts-per-once already ran (freq=once) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - stages.py[DEBUG]: Running module scripts-per-boot () with frequency always Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,568 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock () Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,570 - stages.py[DEBUG]: Running module scripts-per-instance () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,570 - helpers.py[DEBUG]: config-scripts-per-instance already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,570 - stages.py[DEBUG]: Running module scripts-user () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,570 - helpers.py[DEBUG]: config-scripts-user already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,570 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - helpers.py[DEBUG]: config-ssh-authkey-fingerprints already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - stages.py[DEBUG]: Running module keys-to-console () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - helpers.py[DEBUG]: config-keys-to-console already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - stages.py[DEBUG]: Running module phone-home () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - helpers.py[DEBUG]: config-phone-home already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - stages.py[DEBUG]: Running module final-message () with frequency always Jul 10 13:48:25 localhost systemd[1]: Started Execute cloud user/final scripts. Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - helpers.py[DEBUG]: Running config-final-message using lock () Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,571 - util.py[DEBUG]: Read 10 bytes from /proc/uptime Jul 10 13:48:25 localhost cloud-init[640]: Cloud-init v. 0.7.7 finished at Fri, 10 Jul 2015 13:48:25 +0000. Datasource DataSourceNoCloudNet [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net]. Up 8.62 seconds Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,573 - util.py[DEBUG]: Cloud-init v. 0.7.7 finished at Fri, 10 Jul 2015 13:48:25 +0000. Datasource DataSourceNoCloudNet [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net]. Up 8.62 seconds Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,573 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [420] 50 bytes Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,578 - stages.py[DEBUG]: Running module power-state-change () with frequency once-per-instance Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,578 - helpers.py[DEBUG]: config-power-state-change already ran (freq=once-per-instance) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,578 - cloud-init[DEBUG]: Ran 11 modules with 0 failures Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,579 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json' Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,579 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,579 - util.py[DEBUG]: Read 10 bytes from /proc/uptime Jul 10 13:48:25 localhost cloud-init[640]: 2015-07-10 13:48:25,579 - util.py[DEBUG]: cloud-init mode 'modules' took 0.069 seconds (0.07) Jul 10 13:48:46 localhost dbus[565]: [system] Failed to activate service 'org.freedesktop.systemd1': timed out Jul 10 13:48:46 localhost systemd[1]: systemd-logind.service: main process exited, code=exited, status=1/FAILURE Jul 10 13:48:46 localhost systemd[1]: Failed to start Login Service. Jul 10 13:48:46 localhost systemd[1]: Unit systemd-logind.service entered failed state. Jul 10 13:48:46 localhost systemd[1]: systemd-logind.service failed. Jul 10 13:48:46 localhost systemd[1]: systemd-logind.service has no holdoff time, scheduling restart. Jul 10 13:48:46 localhost systemd[1]: Starting Login Service... Jul 10 13:49:11 localhost systemd[1]: systemd-logind.service: main process exited, code=exited, status=1/FAILURE Jul 10 13:49:11 localhost systemd[1]: Failed to start Login Service. Jul 10 13:49:11 localhost systemd[1]: Unit systemd-logind.service entered failed state. Jul 10 13:49:11 localhost systemd[1]: systemd-logind.service failed. Jul 10 13:49:11 localhost systemd[1]: systemd-logind.service has no holdoff time, scheduling restart. Jul 10 13:49:11 localhost systemd[1]: Starting Login Service... Jul 10 13:49:36 localhost systemd[1]: systemd-logind.service: main process exited, code=exited, status=1/FAILURE Jul 10 13:49:36 localhost systemd[1]: Failed to start Login Service. Jul 10 13:49:36 localhost systemd[1]: Unit systemd-logind.service entered failed state. Jul 10 13:49:36 localhost systemd[1]: systemd-logind.service failed. Jul 10 13:49:36 localhost systemd[1]: systemd-logind.service has no holdoff time, scheduling restart. Jul 10 13:49:36 localhost systemd[1]: Starting Login Service... Jul 10 13:49:39 localhost systemd[1]: getty@tty1.service has no holdoff time, scheduling restart. Jul 10 13:49:39 localhost systemd[1]: Started Getty on tty1. Jul 10 13:49:39 localhost systemd[1]: Starting Getty on tty1... Jul 10 13:50:01 localhost systemd[1]: systemd-logind.service: main process exited, code=exited, status=1/FAILURE Jul 10 13:50:01 localhost systemd[1]: Failed to start Login Service. Jul 10 13:50:01 localhost systemd[1]: Unit systemd-logind.service entered failed state. Jul 10 13:50:01 localhost systemd[1]: systemd-logind.service failed. Jul 10 13:50:01 localhost systemd[1]: systemd-logind.service has no holdoff time, scheduling restart. Jul 10 13:50:01 localhost systemd[1]: Starting Login Service...