File: /var/log/installer/subiquity-debug.log
2019-02-18 16:35:30,428 subiquity:103 Starting SUbiquity v0.0.5
2019-02-18 16:35:30,428 subiquity:104 Arguments passed: ['/snap/subiquity/664/usr/bin/subiquity']
2019-02-18 16:35:30,428 subiquitycore.utils:30 Checking environment for installer requirements...
2019-02-18 16:35:30,434 subiquitycore.prober:44 Prober() init finished, data:None
2019-02-18 16:35:30,434 subiquitycore.core:79 KDGKBTYPE returned b'\x02'
2019-02-18 16:35:30,435 subiquitycore.core:261 is_linux_tty
2019-02-18 16:35:30,435 subiquitycore.core:79 KDGKBTYPE returned b'\x02'
2019-02-18 16:35:30,437 subiquitycore.core:414 Running event loop: <urwid.main_loop.SelectEventLoop object at 0x7f813820c390>
2019-02-18 16:35:30,712 subiquitycore.core:423 Importing controller: Welcome
2019-02-18 16:35:30,712 subiquity.controllers.welcome:29 Welcome: answers={}
2019-02-18 16:35:30,713 subiquitycore.core:423 Importing controller: Keyboard
2019-02-18 16:35:30,713 subiquitycore.core:423 Importing controller: Installpath
2019-02-18 16:35:30,713 subiquitycore.core:423 Importing controller: Network
2019-02-18 16:35:30,716 subiquitycore.netplan:80 config for all-en = {'match': {'name': 'en*'}, 'dhcp4': True}
2019-02-18 16:35:30,716 subiquitycore.netplan:80 config for all-eth = {'match': {'name': 'eth*'}, 'dhcp4': True}
2019-02-18 16:35:30,726 probert.network:569 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2019-02-18 16:35:30,726 probert.network:569 event for link_change: NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'ens32'}
2019-02-18 16:35:30,726 probert.network:569 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'}
2019-02-18 16:35:30,727 probert.network:569 event for addr_change: NEW {'ifindex': 2, 'flags': 0, 'family': 2, 'scope': 0, 'local': b'192.168.15.30/24'}
2019-02-18 16:35:30,727 probert.network:569 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2019-02-18 16:35:30,727 probert.network:569 event for addr_change: NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::250:56ff:fea9:75b/64'}
2019-02-18 16:35:30,727 probert.network:650 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2019-02-18 16:35:30,776 subiquitycore.models.network:234 new_link 1 lo lo
2019-02-18 16:35:30,776 probert.network:650 link_change NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'ens32'}
2019-02-18 16:35:30,823 subiquitycore.models.network:234 new_link 2 ens32 eth
2019-02-18 16:35:30,823 subiquitycore.models.network:261 new_link 2 ens32 with config {'dhcp4': True}
2019-02-18 16:35:30,824 probert.network:694 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'}
2019-02-18 16:35:30,824 probert.network:694 addr_change NEW {'ifindex': 2, 'flags': 0, 'family': 2, 'scope': 0, 'local': b'192.168.15.30/24'}
2019-02-18 16:35:30,824 probert.network:694 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2019-02-18 16:35:30,824 probert.network:694 addr_change NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::250:56ff:fea9:75b/64'}
2019-02-18 16:35:30,824 probert.network:706 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2}
2019-02-18 16:35:30,824 subiquitycore.controller.network:161 default routes {2}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.15.0/24', 'ifindex': 2}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.15.1', 'ifindex': 2}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.0.0.0', 'ifindex': 1}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.15.0', 'ifindex': 2}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'192.168.15.30', 'ifindex': 2}
2019-02-18 16:35:30,825 probert.network:706 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.15.255', 'ifindex': 2}
2019-02-18 16:35:30,826 probert.network:706 route_change NEW {'family': 10, 'type': 2, 'table': 254, 'dst': b'::1', 'ifindex': 1}
2019-02-18 16:35:30,826 probert.network:706 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fe80::/64', 'ifindex': 2}
2019-02-18 16:35:30,826 probert.network:706 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1}
2019-02-18 16:35:30,826 probert.network:706 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fe80::250:56ff:fea9:75b', 'ifindex': 2}
2019-02-18 16:35:30,826 probert.network:706 route_change NEW {'family': 10, 'type': 1, 'table': 255, 'dst': b'ff00::/8', 'ifindex': 2}
2019-02-18 16:35:30,889 subiquitycore.core:423 Importing controller: Proxy
2019-02-18 16:35:30,890 subiquitycore.core:423 Importing controller: Mirror
2019-02-18 16:35:30,890 subiquitycore.core:423 Importing controller: Filesystem
2019-02-18 16:35:30,890 subiquitycore.prober:68 get_storage: no storage in probe_data, fetching
2019-02-18 16:35:30,902 subiquity.models.filesystem:886 fs probe /dev/sr0
2019-02-18 16:35:30,903 subiquity.models.filesystem:886 fs probe /dev/sda
2019-02-18 16:35:30,903 probert.storage:50 Failed to get key ID_SERIAL from interface /dev/sda
2019-02-18 16:35:30,903 probert.storage:50 Failed to get key ID_SERIAL_SHORT from interface /dev/sda
2019-02-18 16:35:30,903 probert.storage:50 Failed to get key ID_MODEL_FROM_DATABASE from interface /dev/sda
2019-02-18 16:35:30,903 subiquity.models.filesystem:886 fs probe /dev/fd0
2019-02-18 16:35:30,903 subiquitycore.core:423 Importing controller: Identity
2019-02-18 16:35:30,903 subiquitycore.core:423 Importing controller: SSH
2019-02-18 16:35:30,904 subiquitycore.core:423 Importing controller: SnapList
2019-02-18 16:35:30,904 subiquity.controllers.snaplist:77 loading list of snaps
2019-02-18 16:35:30,905 subiquitycore.core:423 Importing controller: InstallProgress
2019-02-18 16:35:30,905 subiquitycore.core:426 *** {'Welcome': <subiquity.controllers.welcome.WelcomeController object at 0x7f81371d1630>, 'Keyboard': <subiquity.controllers.keyboard.KeyboardController object at 0x7f81371d1710>, 'Installpath': <subiquity.controllers.installpath.InstallpathController object at 0x7f81371d17b8>, 'Network': <subiquitycore.controllers.network.NetworkController object at 0x7f81371d17f0>, 'Proxy': <subiquity.controllers.proxy.ProxyController object at 0x7f8137192fd0>, 'Mirror': <subiquity.controllers.mirror.MirrorController object at 0x7f8137192f60>, 'Filesystem': <subiquity.controllers.filesystem.FilesystemController object at 0x7f8137192f28>, 'Identity': <subiquity.controllers.identity.IdentityController object at 0x7f81371a8f98>, 'SSH': <subiquity.controllers.ssh.SSHController object at 0x7f81371bb0f0>, 'SnapList': <subiquity.controllers.snaplist.SnapListController object at 0x7f81371bb128>, 'InstallProgress': <subiquity.controllers.installprogress.InstallProgressController object at 0x7f81371bb940>}
2019-02-18 16:35:30,905 subiquity.signals:92 Emitter Connection: quit, <bound method Application.exit of <subiquity.core.Subiquity object at 0x7f813820c940>>, {}
2019-02-18 16:35:30,905 subiquity.signals:92 Emitter Connection: refresh, <bound method Application.redraw_screen of <subiquity.core.Subiquity object at 0x7f813820c940>>, {}
2019-02-18 16:35:30,905 subiquity.signals:92 Emitter Connection: next-screen, <bound method Application.next_screen of <subiquity.core.Subiquity object at 0x7f813820c940>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: prev-screen, <bound method Application.prev_screen of <subiquity.core.Subiquity object at 0x7f813820c940>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: l10n:language-selected, <bound method KeyboardController.language_selected of <subiquity.controllers.keyboard.KeyboardController object at 0x7f81371d1710>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: menu:network:main:set-default-v4-route, <bound method NetworkController.set_default_v4_route of <subiquitycore.controllers.network.NetworkController object at 0x7f81371d17f0>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: menu:network:main:set-default-v6-route, <bound method NetworkController.set_default_v6_route of <subiquitycore.controllers.network.NetworkController object at 0x7f81371d17f0>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: network-config-written, <bound method SnapListController.network_config_done of <subiquity.controllers.snaplist.SnapListController object at 0x7f81371bb128>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: network-proxy-set, <bound method SnapListController.proxy_config_done of <subiquity.controllers.snaplist.SnapListController object at 0x7f81371bb128>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: installprogress:filesystem-config-done, <bound method InstallProgressController.filesystem_config_done of <subiquity.controllers.installprogress.InstallProgressController object at 0x7f81371bb940>>, {}
2019-02-18 16:35:30,906 subiquity.signals:92 Emitter Connection: installprogress:identity-config-done, <bound method InstallProgressController.identity_config_done of <subiquity.controllers.installprogress.InstallProgressController object at 0x7f81371bb940>>, {}
2019-02-18 16:35:30,907 subiquity.signals:92 Emitter Connection: installprogress:ssh-config-done, <bound method InstallProgressController.ssh_config_done of <subiquity.controllers.installprogress.InstallProgressController object at 0x7f81371bb940>>, {}
2019-02-18 16:35:30,907 subiquity.signals:92 Emitter Connection: installprogress:snap-config-done, <bound method InstallProgressController.snap_config_done of <subiquity.controllers.installprogress.InstallProgressController object at 0x7f81371bb940>>, {}
2019-02-18 16:35:30,907 subiquitycore.core:299 Known Signals: ['quit', 'refresh', 'next-screen', 'prev-screen', 'l10n:language-selected', 'menu:network:main:set-default-v4-route', 'menu:network:main:set-default-v6-route', 'network-config-written', 'network-proxy-set', 'installprogress:filesystem-config-done', 'installprogress:identity-config-done', 'installprogress:ssh-config-done', 'installprogress:snap-config-done']
2019-02-18 16:35:30,907 subiquitycore.core:307 moving to screen Welcome
2019-02-18 16:35:32,193 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?section=server HTTP/1.1" 200 None
2019-02-18 16:35:32,198 subiquity.controllers.snaplist:84 fetched list of 23 snaps
2019-02-18 16:35:32,199 subiquity.controllers.snaplist:133 starting fetch for microk8s
2019-02-18 16:35:32,581 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=microk8s HTTP/1.1" 200 None
2019-02-18 16:35:32,583 subiquity.controllers.snaplist:133 starting fetch for nextcloud
2019-02-18 16:35:33,010 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=nextcloud HTTP/1.1" 200 None
2019-02-18 16:35:33,011 subiquity.controllers.snaplist:133 starting fetch for kata-containers
2019-02-18 16:35:33,261 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=kata-containers HTTP/1.1" 200 None
2019-02-18 16:35:33,262 subiquity.controllers.snaplist:133 starting fetch for docker
2019-02-18 16:35:33,475 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=docker HTTP/1.1" 200 None
2019-02-18 16:35:33,477 subiquity.controllers.snaplist:133 starting fetch for canonical-livepatch
2019-02-18 16:35:34,055 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=canonical-livepatch HTTP/1.1" 200 1699
2019-02-18 16:35:34,056 subiquity.controllers.snaplist:133 starting fetch for rocketchat-server
2019-02-18 16:35:34,333 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=rocketchat-server HTTP/1.1" 200 None
2019-02-18 16:35:34,335 subiquity.controllers.snaplist:133 starting fetch for mosquitto
2019-02-18 16:35:34,546 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=mosquitto HTTP/1.1" 200 None
2019-02-18 16:35:34,547 subiquity.controllers.snaplist:133 starting fetch for etcd
2019-02-18 16:35:34,906 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=etcd HTTP/1.1" 200 None
2019-02-18 16:35:34,908 subiquity.controllers.snaplist:133 starting fetch for powershell
2019-02-18 16:35:35,175 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=powershell HTTP/1.1" 200 None
2019-02-18 16:35:35,176 subiquity.controllers.snaplist:133 starting fetch for stress-ng
2019-02-18 16:35:35,596 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=stress-ng HTTP/1.1" 200 None
2019-02-18 16:35:35,598 subiquity.controllers.snaplist:133 starting fetch for sabnzbd
2019-02-18 16:35:35,919 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=sabnzbd HTTP/1.1" 200 None
2019-02-18 16:35:35,920 subiquity.controllers.snaplist:133 starting fetch for wormhole
2019-02-18 16:35:36,183 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=wormhole HTTP/1.1" 200 None
2019-02-18 16:35:36,184 subiquity.controllers.snaplist:133 starting fetch for aws-cli
2019-02-18 16:35:36,457 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=aws-cli HTTP/1.1" 200 1957
2019-02-18 16:35:36,459 subiquity.controllers.keyboard:38 language_selected es_ES
2019-02-18 16:35:36,689 subiquity.controllers.keyboard:43 loading launguage es
2019-02-18 16:35:36,689 subiquity.views.welcome:60 calling installpath
2019-02-18 16:35:36,690 subiquitycore.core:307 moving to screen Keyboard
2019-02-18 16:35:36,694 subiquity.ui.views.keyboard:476 latam
2019-02-18 16:35:36,697 subiquity.controllers.snaplist:133 starting fetch for google-cloud-sdk
2019-02-18 16:35:37,266 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=google-cloud-sdk HTTP/1.1" 200 1613
2019-02-18 16:35:37,268 subiquity.controllers.snaplist:133 starting fetch for slcli
2019-02-18 16:35:37,481 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=slcli HTTP/1.1" 200 None
2019-02-18 16:35:37,483 subiquity.controllers.snaplist:133 starting fetch for doctl
2019-02-18 16:35:37,687 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=doctl HTTP/1.1" 200 1126
2019-02-18 16:35:37,688 subiquity.controllers.snaplist:133 starting fetch for conjure-up
2019-02-18 16:35:37,949 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=conjure-up HTTP/1.1" 200 None
2019-02-18 16:35:37,951 subiquity.controllers.snaplist:133 starting fetch for minidlna-escoand
2019-02-18 16:35:38,570 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=minidlna-escoand HTTP/1.1" 200 1912
2019-02-18 16:35:38,572 subiquity.controllers.snaplist:133 starting fetch for postgresql10
2019-02-18 16:35:38,807 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=postgresql10 HTTP/1.1" 200 1370
2019-02-18 16:35:38,809 subiquity.controllers.snaplist:133 starting fetch for heroku
2019-02-18 16:35:39,462 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=heroku HTTP/1.1" 200 None
2019-02-18 16:35:39,464 subiquity.controllers.snaplist:133 starting fetch for keepalived
2019-02-18 16:35:39,702 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=keepalived HTTP/1.1" 200 1654
2019-02-18 16:35:39,703 subiquity.controllers.snaplist:133 starting fetch for prometheus
2019-02-18 16:35:39,784 subiquitycore.utils:117 run_command called: ['setupcon', '--save', '--force', '--keyboard-only']
2019-02-18 16:35:39,905 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=prometheus HTTP/1.1" 200 None
2019-02-18 16:35:39,908 subiquity.controllers.snaplist:133 starting fetch for juju
2019-02-18 16:35:40,192 urllib3.connectionpool:396 http://localhost:None "GET /v2/find?name=juju HTTP/1.1" 200 None
2019-02-18 16:35:40,867 subiquitycore.utils:130 run_command ['setupcon', '--save', '--force', '--keyboard-only'] exited with code 0
2019-02-18 16:35:40,867 subiquitycore.utils:117 run_command called: ['/snap/bin/subiquity.subiquity-loadkeys']
2019-02-18 16:35:40,889 subiquitycore.utils:130 run_command ['/snap/bin/subiquity.subiquity-loadkeys'] exited with code 0
2019-02-18 16:35:40,890 subiquitycore.core:307 moving to screen Installpath
2019-02-18 16:35:40,891 subiquity.installpath:74 Building inputs: ubuntu
2019-02-18 16:35:40,891 subiquity.installpath:74 Building inputs: maas_region
2019-02-18 16:35:40,891 subiquity.installpath:74 Building inputs: maas_rack
2019-02-18 16:35:45,170 subiquity.controller.installpath:54 Installing Ubuntu path chosen.
2019-02-18 16:35:45,171 subiquitycore.core:307 moving to screen Network
2019-02-18 16:35:58,190 subiquitycore.controller.network:362 network config:
network:
ethernets:
ens32:
dhcp4: true
version: 2
2019-02-18 16:35:58,198 subiquitycore.netplan:80 config for ens32 = {'dhcp4': True}
2019-02-18 16:35:58,201 subiquitycore.tasksequence:214 running BackgroundProcess(['netplan', 'apply']) for stage apply
2019-02-18 16:35:58,201 subiquitycore.utils:141 start_command called: ['netplan', 'apply']
2019-02-18 16:35:58,938 subiquitycore.tasksequence:219 apply ended
NoneType: None
2019-02-18 16:35:58,940 subiquitycore.tasksequence:214 running WaitForDefaultRouteTask(30) for stage timeout
2019-02-18 16:35:58,952 subiquitycore.tasksequence:219 timeout ended
NoneType: None
2019-02-18 16:35:58,953 subiquitycore.core:307 moving to screen Proxy
2019-02-18 16:35:58,983 subiquitycore.utils:117 run_command called: ['udevadm', 'settle', '-t', '0']
2019-02-18 16:35:59,013 subiquitycore.utils:130 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2019-02-18 16:35:59,014 probert.network:569 event for addr_change: DEL {'ifindex': 2, 'flags': 0, 'family': 2, 'scope': 0, 'local': b'192.168.15.30/24'}
2019-02-18 16:35:59,014 probert.network:694 addr_change DEL {'ifindex': 2, 'flags': 0, 'family': 2, 'scope': 0, 'local': b'192.168.15.30/24'}
2019-02-18 16:35:59,014 probert.network:706 route_change DEL {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.15.0/24', 'ifindex': 2}
2019-02-18 16:35:59,015 probert.network:706 route_change DEL {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.15.255', 'ifindex': 2}
2019-02-18 16:35:59,015 probert.network:706 route_change DEL {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.15.0', 'ifindex': 2}
2019-02-18 16:35:59,015 probert.network:706 route_change DEL {'family': 2, 'type': 2, 'table': 255, 'dst': b'192.168.15.30', 'ifindex': 2}
2019-02-18 16:35:59,029 subiquitycore.utils:117 run_command called: ['udevadm', 'settle', '-t', '0']
2019-02-18 16:35:59,057 subiquitycore.utils:130 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2019-02-18 16:35:59,058 probert.network:569 event for addr_change: NEW {'ifindex': 2, 'flags': 0, 'family': 2, 'scope': 0, 'local': b'192.168.15.30/24'}
2019-02-18 16:35:59,058 probert.network:694 addr_change NEW {'ifindex': 2, 'flags': 0, 'family': 2, 'scope': 0, 'local': b'192.168.15.30/24'}
2019-02-18 16:35:59,059 probert.network:706 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'192.168.15.30', 'ifindex': 2}
2019-02-18 16:35:59,059 probert.network:706 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.15.255', 'ifindex': 2}
2019-02-18 16:35:59,059 probert.network:706 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.15.0/24', 'ifindex': 2}
2019-02-18 16:35:59,059 probert.network:706 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.15.0', 'ifindex': 2}
2019-02-18 16:36:01,916 subiquity.installpath:64 User input: {'url': ''}
2019-02-18 16:36:01,916 subiquitycore.core:307 moving to screen Mirror
2019-02-18 16:36:10,295 subiquity.ui.mirror:62 User input: {'url': 'http://archive.ubuntu.com/ubuntu'}
2019-02-18 16:36:10,296 subiquitycore.core:307 moving to screen Filesystem
2019-02-18 16:36:20,886 subiquitycore.controller.filesystem:290 partition_disk_handler: Disk(id='disk-0', type='disk', ptable=None, serial=None, path='/dev/sda', model='Virtual_disk', wipe='superblock', preserve=False, name='', grub_device=False, _info=<probert.storage.StorageInfo object at 0x7f8137192470>) None {'size': 42947575808, 'fstype': FS(label='ext4', is_mounted=True), 'mount': '/'}
2019-02-18 16:36:20,886 subiquitycore.controller.filesystem:291 disk.freespace: 42947575808
2019-02-18 16:36:20,886 subiquitycore.controller.filesystem:302 model needs a bootloader partition? True
2019-02-18 16:36:20,887 subiquitycore.controller.filesystem:231 Adding grub_bios gpt partition first
2019-02-18 16:36:20,887 subiquity.models.filesystem:928 add_partition: rounded size from 1048576 to 1048576
2019-02-18 16:36:20,887 subiquitycore.controller.filesystem:312 Adjusting request down: 42947575808 - 1048576 = 42946527232
2019-02-18 16:36:20,887 subiquity.models.filesystem:928 add_partition: rounded size from 42946527232 to 42946527232
2019-02-18 16:36:20,887 subiquity.models.filesystem:999 adding ext4 to Partition(id='part-1', type='partition', device=Disk(id='disk-0', type='disk', ptable='gpt', serial=None, path='/dev/sda', model='Virtual_disk', wipe='superblock', preserve=False, name='', grub_device=True, _info=<probert.storage.StorageInfo object at 0x7f8137192470>), size=42946527232, wipe=None, flag='', preserve=False)
2019-02-18 16:36:20,888 subiquitycore.controller.filesystem:317 Successfully added partition
2019-02-18 16:36:20,888 subiquity.ui.filesystem.filesystem:480 FileSystemView init start()
2019-02-18 16:36:20,890 subiquity.ui.filesystem.filesystem:527 FileSystemView: building buttons
2019-02-18 16:36:20,892 subiquity.ui.filesystem.filesystem:179 FileSystemView: building mount list
2019-02-18 16:36:20,896 subiquity.ui.filesystem.filesystem:375 FileSystemView: building device list
2019-02-18 16:36:20,907 subiquity.ui.filesystem.filesystem:524 FileSystemView init complete()
2019-02-18 16:36:29,980 subiquitycore.controller.installprogress:237 Curtin Install: starting curtin
2019-02-18 16:36:30,010 subiquitycore.controller.installprogress:224 Installprogress: this is the *REAL* thing
2019-02-18 16:36:30,030 subiquitycore.controller.installprogress:255 Curtin install cmd: ['/snap/subiquity/664/usr/bin/python3', '-m', 'curtin', '--showtrace', '-c', '/var/log/installer/subiquity-curtin-install.conf', 'install']
2019-02-18 16:36:30,030 subiquitycore.core:307 moving to screen Identity
2019-02-18 16:36:30,031 subiquitycore.utils:117 run_command called: ['systemd-cat', '--level-prefix=false', '--identifier=curtin_log.1781', '/snap/subiquity/664/usr/bin/python3', '-m', 'curtin', '--showtrace', '-c', '/var/log/installer/subiquity-curtin-install.conf', 'install']
2019-02-18 16:36:32,070 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'curtin command install', 'CURTIN_NAME': 'cmd-install'}
2019-02-18 16:36:32,071 subiquitycore.controller.installprogress:165 _install_event_start curtin command install
2019-02-18 16:36:32,075 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'preparing for installation', 'CURTIN_NAME': 'cmd-install/stage-early'}
2019-02-18 16:36:32,075 subiquitycore.controller.installprogress:165 _install_event_start preparing for installation
2019-02-18 16:36:32,077 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_MESSAGE': 'preparing for installation', 'CURTIN_NAME': 'cmd-install/stage-early', 'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS'}
2019-02-18 16:36:32,077 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:32,078 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring storage', 'CURTIN_NAME': 'cmd-install/stage-partitioning'}
2019-02-18 16:36:32,079 subiquitycore.controller.installprogress:165 _install_event_start configuring storage
2019-02-18 16:36:32,080 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'curtin block-meta simple'", 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin'}
2019-02-18 16:36:32,080 subiquitycore.controller.installprogress:165 _install_event_start running 'curtin block-meta simple'
2019-02-18 16:36:35,633 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'curtin command block-meta', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta'}
2019-02-18 16:36:35,633 subiquitycore.controller.installprogress:165 _install_event_start curtin command block-meta
2019-02-18 16:36:35,637 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'removing previous storage devices', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders'}
2019-02-18 16:36:35,637 subiquitycore.controller.installprogress:165 _install_event_start removing previous storage devices
2019-02-18 16:36:38,042 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'removing previous storage devices', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders'}
2019-02-18 16:36:38,042 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:38,044 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring disk: disk-0'}
2019-02-18 16:36:38,045 subiquitycore.controller.installprogress:165 _install_event_start configuring disk: disk-0
2019-02-18 16:36:38,053 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring disk: disk-0'}
2019-02-18 16:36:38,053 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:38,055 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring partition: part-0'}
2019-02-18 16:36:38,055 subiquitycore.controller.installprogress:165 _install_event_start configuring partition: part-0
2019-02-18 16:36:39,506 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring partition: part-0'}
2019-02-18 16:36:39,506 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:39,507 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring partition: part-1'}
2019-02-18 16:36:39,507 subiquitycore.controller.installprogress:165 _install_event_start configuring partition: part-1
2019-02-18 16:36:40,819 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring partition: part-1'}
2019-02-18 16:36:40,820 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:40,821 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring format: fs-0'}
2019-02-18 16:36:40,821 subiquitycore.controller.installprogress:165 _install_event_start configuring format: fs-0
2019-02-18 16:36:42,509 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring format: fs-0'}
2019-02-18 16:36:42,509 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:42,510 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring mount: mount-0'}
2019-02-18 16:36:42,510 subiquitycore.controller.installprogress:165 _install_event_start configuring mount: mount-0
2019-02-18 16:36:43,320 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta', 'CURTIN_MESSAGE': 'configuring mount: mount-0'}
2019-02-18 16:36:43,320 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:43,322 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'curtin command block-meta', 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin/cmd-block-meta'}
2019-02-18 16:36:43,322 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:43,323 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'curtin block-meta simple'", 'CURTIN_NAME': 'cmd-install/stage-partitioning/builtin'}
2019-02-18 16:36:43,323 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:43,325 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring storage', 'CURTIN_NAME': 'cmd-install/stage-partitioning'}
2019-02-18 16:36:43,326 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:43,327 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring network', 'CURTIN_NAME': 'cmd-install/stage-network'}
2019-02-18 16:36:43,327 subiquitycore.controller.installprogress:165 _install_event_start configuring network
2019-02-18 16:36:43,328 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'curtin net-meta auto'", 'CURTIN_NAME': 'cmd-install/stage-network/builtin'}
2019-02-18 16:36:43,328 subiquitycore.controller.installprogress:165 _install_event_start running 'curtin net-meta auto'
2019-02-18 16:36:45,319 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'curtin command net-meta', 'CURTIN_NAME': 'cmd-install/stage-network/builtin/cmd-net-meta'}
2019-02-18 16:36:45,319 subiquitycore.controller.installprogress:165 _install_event_start curtin command net-meta
2019-02-18 16:36:45,320 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'curtin command net-meta', 'CURTIN_NAME': 'cmd-install/stage-network/builtin/cmd-net-meta'}
2019-02-18 16:36:45,320 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:45,322 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'curtin net-meta auto'", 'CURTIN_NAME': 'cmd-install/stage-network/builtin'}
2019-02-18 16:36:45,322 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:45,323 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring network', 'CURTIN_NAME': 'cmd-install/stage-network'}
2019-02-18 16:36:45,323 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:36:45,323 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'writing install sources to disk', 'CURTIN_NAME': 'cmd-install/stage-extract'}
2019-02-18 16:36:45,323 subiquitycore.controller.installprogress:165 _install_event_start writing install sources to disk
2019-02-18 16:36:45,324 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'curtin extract'", 'CURTIN_NAME': 'cmd-install/stage-extract/builtin'}
2019-02-18 16:36:45,324 subiquitycore.controller.installprogress:165 _install_event_start running 'curtin extract'
2019-02-18 16:36:47,569 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'curtin command extract', 'CURTIN_NAME': 'cmd-install/stage-extract/builtin/cmd-extract'}
2019-02-18 16:36:47,569 subiquitycore.controller.installprogress:165 _install_event_start curtin command extract
2019-02-18 16:36:47,570 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_NAME': 'cmd-install/stage-extract/builtin/cmd-extract', 'CURTIN_MESSAGE': 'acquiring and extracting image from cp:///media/filesystem'}
2019-02-18 16:36:47,571 subiquitycore.controller.installprogress:165 _install_event_start acquiring and extracting image from cp:///media/filesystem
2019-02-18 16:37:23,319 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_NAME': 'cmd-install/stage-extract/builtin/cmd-extract', 'CURTIN_MESSAGE': 'acquiring and extracting image from cp:///media/filesystem'}
2019-02-18 16:37:23,319 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,319 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'curtin command extract', 'CURTIN_NAME': 'cmd-install/stage-extract/builtin/cmd-extract'}
2019-02-18 16:37:23,319 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,320 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'curtin extract'", 'CURTIN_NAME': 'cmd-install/stage-extract/builtin'}
2019-02-18 16:37:23,320 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,321 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'writing install sources to disk', 'CURTIN_NAME': 'cmd-install/stage-extract'}
2019-02-18 16:37:23,321 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,322 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring installed system', 'CURTIN_NAME': 'cmd-install/stage-curthooks'}
2019-02-18 16:37:23,322 subiquitycore.controller.installprogress:165 _install_event_start configuring installed system
2019-02-18 16:37:23,323 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'mount -t tmpfs tmpfs /target/run'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/000-setup-tmpfs'}
2019-02-18 16:37:23,323 subiquitycore.controller.installprogress:165 _install_event_start running 'mount -t tmpfs tmpfs /target/run'
2019-02-18 16:37:23,324 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'mount -t tmpfs tmpfs /target/run'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/000-setup-tmpfs'}
2019-02-18 16:37:23,324 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,325 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'mkdir -p /target/run/cdrom'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/001-create-run-cdrom'}
2019-02-18 16:37:23,325 subiquitycore.controller.installprogress:165 _install_event_start running 'mkdir -p /target/run/cdrom'
2019-02-18 16:37:23,325 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'mkdir -p /target/run/cdrom'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/001-create-run-cdrom'}
2019-02-18 16:37:23,325 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,326 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'mount --bind /cdrom /target/run/cdrom'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/002-mount-run-cdrom'}
2019-02-18 16:37:23,326 subiquitycore.controller.installprogress:165 _install_event_start running 'mount --bind /cdrom /target/run/cdrom'
2019-02-18 16:37:23,327 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'mount --bind /cdrom /target/run/cdrom'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/002-mount-run-cdrom'}
2019-02-18 16:37:23,327 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:23,328 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'curtin curthooks'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin'}
2019-02-18 16:37:23,328 subiquitycore.controller.installprogress:165 _install_event_start running 'curtin curthooks'
2019-02-18 16:37:25,820 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'curtin command curthooks', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks'}
2019-02-18 16:37:25,820 subiquitycore.controller.installprogress:165 _install_event_start curtin command curthooks
2019-02-18 16:37:25,822 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring apt configuring apt', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-apt-config'}
2019-02-18 16:37:25,823 subiquitycore.controller.installprogress:165 _install_event_start configuring apt configuring apt
2019-02-18 16:37:32,466 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring apt configuring apt', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-apt-config'}
2019-02-18 16:37:32,467 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:32,468 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'installing missing packages', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-missing-packages'}
2019-02-18 16:37:32,468 subiquitycore.controller.installprogress:165 _install_event_start installing missing packages
2019-02-18 16:37:32,469 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'installing missing packages', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-missing-packages'}
2019-02-18 16:37:32,469 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:32,470 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring iscsi service', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-iscsi-service'}
2019-02-18 16:37:32,470 subiquitycore.controller.installprogress:165 _install_event_start configuring iscsi service
2019-02-18 16:37:32,471 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring iscsi service', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-iscsi-service'}
2019-02-18 16:37:32,471 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:32,471 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring raid (mdadm) service', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-mdadm-service'}
2019-02-18 16:37:32,471 subiquitycore.controller.installprogress:165 _install_event_start configuring raid (mdadm) service
2019-02-18 16:37:32,471 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring raid (mdadm) service', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-mdadm-service'}
2019-02-18 16:37:32,472 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:37:32,473 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'installing kernel', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-kernel'}
2019-02-18 16:37:32,473 subiquitycore.controller.installprogress:165 _install_event_start installing kernel
2019-02-18 16:37:33,116 subiquity.controllers.identity:50 User input: {'hostname': 'bareserver', 'realname': 'tono', 'username': 'tono', 'password': '<REDACTED>'}
2019-02-18 16:37:33,116 subiquitycore.core:307 moving to screen SSH
2019-02-18 16:37:47,735 subiquity.ui.ssh:301 User input: {'install_server': True, 'ssh_import_id': None}
2019-02-18 16:37:47,735 subiquity.controllers.ssh:122 SSHController result {'install_server': True, 'ssh_import_id': None}
2019-02-18 16:37:47,735 subiquitycore.core:307 moving to screen SnapList
2019-02-18 16:38:08,646 subiquity.views.snaplist:353 snaps to install {}
2019-02-18 16:38:08,646 subiquitycore.core:307 moving to screen InstallProgress
2019-02-18 16:38:51,572 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'installing kernel', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-kernel'}
2019-02-18 16:38:51,572 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:51,573 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'setting up swap', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/setting-up-swap'}
2019-02-18 16:38:51,573 subiquitycore.controller.installprogress:165 _install_event_start setting up swap
2019-02-18 16:38:51,577 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'setting up swap', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/setting-up-swap'}
2019-02-18 16:38:51,577 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:51,578 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'apply networking config', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/apply-networking-config'}
2019-02-18 16:38:51,578 subiquitycore.controller.installprogress:165 _install_event_start apply networking config
2019-02-18 16:38:52,822 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'apply networking config', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/apply-networking-config'}
2019-02-18 16:38:52,822 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:52,823 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'writing etc/fstab', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-etc-fstab'}
2019-02-18 16:38:52,823 subiquitycore.controller.installprogress:165 _install_event_start writing etc/fstab
2019-02-18 16:38:52,824 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'writing etc/fstab', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-etc-fstab'}
2019-02-18 16:38:52,824 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:52,824 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring multipath', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-multipath'}
2019-02-18 16:38:52,824 subiquitycore.controller.installprogress:165 _install_event_start configuring multipath
2019-02-18 16:38:53,279 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring multipath', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-multipath'}
2019-02-18 16:38:53,280 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:53,282 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'updating packages on target system', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/system-upgrade'}
2019-02-18 16:38:53,283 subiquitycore.controller.installprogress:165 _install_event_start updating packages on target system
2019-02-18 16:38:53,284 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'updating packages on target system', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/system-upgrade'}
2019-02-18 16:38:53,284 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:53,285 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'configuring pollinate user-agent on target', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/pollinate-user-agent'}
2019-02-18 16:38:53,285 subiquitycore.controller.installprogress:165 _install_event_start configuring pollinate user-agent on target
2019-02-18 16:38:53,286 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring pollinate user-agent on target', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks/pollinate-user-agent'}
2019-02-18 16:38:53,286 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:59,076 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'curtin command curthooks', 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin/cmd-curthooks'}
2019-02-18 16:38:59,076 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:59,077 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': "running 'curtin curthooks'", 'CURTIN_NAME': 'cmd-install/stage-curthooks/builtin'}
2019-02-18 16:38:59,077 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:59,078 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'finish', 'CURTIN_RESULT': 'SUCCESS', 'CURTIN_MESSAGE': 'configuring installed system', 'CURTIN_NAME': 'cmd-install/stage-curthooks'}
2019-02-18 16:38:59,078 subiquitycore.controller.installprogress:173 _install_event_finish ' '
2019-02-18 16:38:59,079 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': 'finalizing installation', 'CURTIN_NAME': 'cmd-install/stage-hook'}
2019-02-18 16:38:59,079 subiquitycore.controller.installprogress:165 _install_event_start finalizing installation
2019-02-18 16:38:59,080 subiquitycore.controller.installprogress:181 curtin_event received {'CURTIN_EVENT_TYPE': 'start', 'CURTIN_MESSAGE': "running 'curtin hook'", 'CURTIN_NAME': 'cmd-install/stage-hook/builtin'}
2019-02-18 16:38:59,081 subiquitycore.controller.installprogress:165 _install_event_start running 'curtin hook'
2019-02-18 16:39:00,791 subiquitycore.utils:130 run_command ['systemd-cat', '--level-prefix=false', '--identifier=curtin_log.1781', '/snap/subiquity/664/usr/bin/python3', '-m', 'curtin', '--showtrace', '-c', '/var/log/installer/subiquity-curtin-install.conf', 'install'] exited with code 0
2019-02-18 16:39:00,791 subiquitycore.controller.installprogress:262 curtin_install completed: 0
2019-02-18 16:39:00,791 subiquitycore.controller.installprogress:267 After curtin install OK
2019-02-18 16:39:00,791 subiquitycore.utils:117 run_command called: ['cp', '-aT', '/var/log/installer', '/target/var/log/installer']