sorry! Totally misunderstood your clear directions.
config: {}
api_extensions:
- storage_zfs_remove_snapshots
- container_host_shutdown_timeout
- container_stop_priority
- container_syscall_filtering
- auth_pki
- container_last_used_at
- etag
- patch
- usb_devices
- https_allowed_credentials
- image_compression_algorithm
- directory_manipulation
- container_cpu_time
- storage_zfs_use_refquota
- storage_lvm_mount_options
- network
- profile_usedby
- container_push
- container_exec_recording
- certificate_update
- container_exec_signal_handling
- gpu_devices
- container_image_properties
- migration_progress
- id_map
- network_firewall_filtering
- network_routes
- storage
- file_delete
- file_append
- network_dhcp_expiry
- storage_lvm_vg_rename
- storage_lvm_thinpool_rename
- network_vlan
- image_create_aliases
- container_stateless_copy
- container_only_migration
- storage_zfs_clone_copy
- unix_device_rename
- storage_lvm_use_thinpool
- storage_rsync_bwlimit
- network_vxlan_interface
- storage_btrfs_mount_options
- entity_description
- image_force_refresh
- storage_lvm_lv_resizing
- id_map_base
- file_symlinks
- container_push_target
- network_vlan_physical
- storage_images_delete
- container_edit_metadata
- container_snapshot_stateful_migration
- storage_driver_ceph
- storage_ceph_user_name
- resource_limits
- storage_volatile_initial_source
- storage_ceph_force_osd_reuse
- storage_block_filesystem_btrfs
- resources
- kernel_limits
- storage_api_volume_rename
- macaroon_authentication
- network_sriov
- console
- restrict_devlxd
- migration_pre_copy
- infiniband
- maas_network
- devlxd_events
- proxy
- network_dhcp_gateway
- file_get_symlink
- network_leases
- unix_device_hotplug
- storage_api_local_volume_handling
- operation_description
- clustering
- event_lifecycle
- storage_api_remote_volume_handling
- nvidia_runtime
- container_mount_propagation
- container_backup
- devlxd_images
- container_local_cross_pool_handling
- proxy_unix
- proxy_udp
- clustering_join
- proxy_tcp_udp_multi_port_handling
- network_state
- proxy_unix_dac_properties
- container_protection_delete
- unix_priv_drop
- pprof_http
- proxy_haproxy_protocol
- network_hwaddr
- proxy_nat
- network_nat_order
- container_full
- candid_authentication
- backup_compression
- candid_config
- nvidia_runtime_config
- storage_api_volume_snapshots
- storage_unmapped
- projects
- candid_config_key
- network_vxlan_ttl
- container_incremental_copy
- usb_optional_vendorid
- snapshot_scheduling
- container_copy_project
- clustering_server_address
- clustering_image_replication
- container_protection_shift
- snapshot_expiry
- container_backup_override_pool
- snapshot_expiry_creation
- network_leases_location
- resources_cpu_socket
- resources_gpu
- resources_numa
- kernel_features
- id_map_current
- event_location
- storage_api_remote_volume_snapshots
- network_nat_address
- container_nic_routes
- rbac
- cluster_internal_copy
- seccomp_notify
- lxc_features
- container_nic_ipvlan
- network_vlan_sriov
- storage_cephfs
- container_nic_ipfilter
- resources_v2
- container_exec_user_group_cwd
- container_syscall_intercept
- container_disk_shift
- storage_shifted
- resources_infiniband
- daemon_storage
- instances
- image_types
- resources_disk_sata
- clustering_roles
- images_expiry
- resources_network_firmware
- backup_compression_algorithm
- ceph_data_pool_name
- container_syscall_intercept_mount
- compression_squashfs
- container_raw_mount
- container_nic_routed
- container_syscall_intercept_mount_fuse
- container_disk_ceph
- virtual-machines
- image_profiles
- clustering_architecture
- resources_disk_id
- storage_lvm_stripes
- vm_boot_priority
- unix_hotplug_devices
- api_filtering
- instance_nic_network
- clustering_sizing
- firewall_driver
- projects_limits
- container_syscall_intercept_hugetlbfs
- limits_hugepages
- container_nic_routed_gateway
- projects_restrictions
- custom_volume_snapshot_expiry
- volume_snapshot_scheduling
- trust_ca_certificates
- snapshot_disk_usage
- clustering_edit_roles
- container_nic_routed_host_address
- container_nic_ipvlan_gateway
- resources_usb_pci
- resources_cpu_threads_numa
- resources_cpu_core_die
api_status: stable
api_version: "1.0"
auth: trusted
public: false
auth_methods:
- tls
environment:
addresses: []
architectures:
- x86_64
- i686
certificate: |
-----BEGIN CERTIFICATE-----
MIICBDCCAYqgAwIBAgIRAMLRiN03egvrlTnIBkuStjAwCgYIKoZIzj0EAwMwNDEc
MBoGA1UEChMTbGludXhjb250YWluZXJzLm9yZzEUMBIGA1UEAwwLcm9vdEBjb2Jh
bHQwHhcNMjAwMjEwMjM1NzM2WhcNMzAwMjA3MjM1NzM2WjA0MRwwGgYDVQQKExNs
aW51eGNvbnRhaW5lcnMub3JnMRQwEgYDVQQDDAtyb290QGNvYmFsdDB2MBAGByqG
SM49AgEGBSuBBAAiA2IABMgB0TAVI2n/bBDs9i4/EWVqd+kAVh48nAokdFvSv3nG
PwrfQapQdMoFySYeOoQ7ZSGS7L5kvO7qHd44THBn1rXiIr74rCkKitOSkxGj21cK
eN/i04YlNq7Bs6Bvz/VGu6NgMF4wDgYDVR0PAQH/BAQDAgWgMBMGA1UdJQQMMAoG
CCsGAQUFBwMBMAwGA1UdEwEB/wQCMAAwKQYDVR0RBCIwIIIGY29iYWx0hwR/AAAB
hxAAAAAAAAAAAAAAAAAAAAABMAoGCCqGSM49BAMDA2gAMGUCMFVWNqXJlM21d4jt
ZKwoPz5TYhhaXEk0kwBfphRPHHVJcipSXxT8V4jKO8cuG0PfAAIxAM0q6eEQVJO9
+qB9zoygF/cGxHC2BX2ymG3Z4jJOwcKzcH5okniydXVPThMhgkA3gQ==
-----END CERTIFICATE-----
certificate_fingerprint: 877ad7b541c8fb69e0daf413cc4d91dc39245f80545d3b48232dabc4f34c5edd
driver: lxc
driver_version: 4.0.0
firewall: xtables
kernel: Linux
kernel_architecture: x86_64
kernel_features:
netnsid_getifaddrs: "true"
seccomp_listener: "true"
seccomp_listener_continue: "true"
shiftfs: "false"
uevent_injection: "true"
unpriv_fscaps: "true"
kernel_version: 5.3.0-7629-generic
lxc_features:
cgroup2: "true"
mount_injection_file: "true"
network_gateway_device_route: "true"
network_ipvlan: "true"
network_l2proxy: "true"
network_phys_macvlan_mtu: "true"
network_veth_router: "true"
seccomp_notify: "true"
project: default
server: lxd
server_clustered: false
server_name: cobalt
server_pid: 5019
server_version: 4.0.0
storage: zfs
storage_version: 0.8.1-1ubuntu14.3
stgraber
April 6, 2020, 11:41pm
6
Thanks.
So I’m not sure why it happens to that one container and not others, that’s a bit confusing.
@tomp can we tweak the backup.yaml logic further so this can’t happen?
tomp
April 7, 2020, 12:17pm
7
I will take a look at this now.
tomp
April 7, 2020, 1:00pm
8
Please can you enable LXD debug mode in the snap:
sudo snap set lxd daemon.debug=true
sudo systemctl reload snap.lxd.daemon
Then look in the logs when starting and stopping the problem container until you hit the issue again.
I’d like to see what the logs say during both startup and shutdown of the container.
I would expect to see entries like this:
DBUG[04-07|13:58:04] MountInstance started driver=zfs pool=default project=test instance=c1
DBUG[04-07|13:58:04] Mounted ZFS dataset driver=zfs pool=default dev=default/containers/test_c1 path=/var/lib/lxd/storage-pools/default/containers/test_c1
DBUG[04-07|13:58:04] MountInstance finished driver=zfs pool=default project=test instance=c1
DBUG[04-07|13:58:04] UpdateInstanceBackupFile started driver=zfs pool=default project=test instance=c1
DBUG[04-07|13:58:04] UpdateInstanceBackupFile finished driver=zfs pool=default project=test instance=c1
1 Like
tomp
April 7, 2020, 1:01pm
9
@stgraber as far as I can see all occurrences of writing the backup.yaml happen inside a MountTask() so the volume should be mounted. I’d like to see the system logs when it happens to see if there is some sort of ordering or race condition issue.
give me the command(s) you’d like me to run and I’ll post the output. (just to be sure I hit the things).
tomp
April 7, 2020, 5:27pm
11
Normally its sudo journalctl -f to tail the logs then just need the bits that are generated when u start and stop the container before and as the issue occurs. Once debug mode is enabled.
forgive the incredibly stupid question… how do I enable debug mode?
tomp
April 7, 2020, 5:49pm
13
I posted the commands to do that earlier in this thread.
@tomp I followed the directions, but my confusion was coming from the fact that they didn’t seem to me to produce the debug log items. I’ve seen other cases where setting snap settings seemed to not have an effect; not sure if that’s happening here too.
In any case, I realized contrary to what I originally stated, it’s not on the shutdown where it it is happening, but rather on on the startup. Once it happens and I delete the backup.yaml file, the next time I try to start up the container it seems to always be successful.
Here is the log output for startup. I edited out some obviously unrelated entries, but left the rest. Like I said, I don’t see any “DBUG” items. I verified that daemon.debug is true for lxd and I rebooted after setting it to be sure. I can provide the stop logs next if you still want them. If you want to continue to chase this, I’ll stay with it. On the other hand, I can also recreate the container since it seems that I am the only one seeing it.
Apr 10 22:13:26 cobalt audit[16703]: AVC apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=16703 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:26 cobalt kernel: audit: type=1400 audit(1586571206.355:264): apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=16703 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:26 cobalt audit[16703]: AVC apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=16703 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:26 cobalt kernel: audit: type=1400 audit(1586571206.359:265): apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=16703 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:26 cobalt NetworkManager[1574]: <info> [1586571206.4169] manager: (vethdf47ddd8): new Veth device (/org/freedesktop/NetworkManager/Devices/19)
Apr 10 22:13:26 cobalt systemd-udevd[16747]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 10 22:13:26 cobalt systemd-udevd[16747]: Using default interface naming scheme 'v240'.
Apr 10 22:13:26 cobalt systemd-udevd[16747]: vethdf47ddd8: Could not generate persistent MAC: No data available
Apr 10 22:13:26 cobalt systemd-udevd[16749]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 10 22:13:26 cobalt systemd-udevd[16749]: Using default interface naming scheme 'v240'.
Apr 10 22:13:26 cobalt systemd-udevd[16749]: vethe4372744: Could not generate persistent MAC: No data available
Apr 10 22:13:26 cobalt NetworkManager[1574]: <info> [1586571206.4183] manager: (vethe4372744): new Veth device (/org/freedesktop/NetworkManager/Devices/20)
Apr 10 22:13:26 cobalt kernel: lxdbr0: port 1(vethe4372744) entered blocking state
Apr 10 22:13:26 cobalt kernel: lxdbr0: port 1(vethe4372744) entered disabled state
Apr 10 22:13:26 cobalt kernel: device vethe4372744 entered promiscuous mode
Apr 10 22:13:26 cobalt audit[16800]: AVC apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="lxd-applications_</var/snap/lxd/common/lxd>" pid=16800 comm="apparmor_parser"
Apr 10 22:13:26 cobalt kernel: audit: type=1400 audit(1586571206.495:266): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="lxd-applications_</var/snap/lxd/common/lxd>" pid=16800 comm="apparmor_parser"
Apr 10 22:13:26 cobalt kernel: eth0: renamed from vethdf47ddd8
Apr 10 22:13:26 cobalt kernel: lxdbr0: port 1(vethe4372744) entered disabled state
Apr 10 22:13:26 cobalt kernel: device vethe4372744 left promiscuous mode
Apr 10 22:13:26 cobalt kernel: lxdbr0: port 1(vethe4372744) entered disabled state
Apr 10 22:13:26 cobalt NetworkManager[1574]: <info> [1586571206.6282] device (vethe4372744): released from master device lxdbr0
Apr 10 22:13:26 cobalt lxd.daemon[27943]: t=2020-04-10T22:13:26-0400 lvl=eror msg="Failed starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-04-08T08:17:19-0400
Apr 10 22:13:27 cobalt lxd.daemon[27943]: t=2020-04-10T22:13:27-0400 lvl=eror msg="The stop hook failed" container=applications err="Failed to run: zfs unmount default/containers/applications: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/applications: not mounted\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/applications': umount failed"
Apr 10 22:13:34 cobalt audit[16864]: AVC apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=16864 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:34 cobalt kernel: audit: type=1400 audit(1586571214.695:267): apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=16864 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:34 cobalt audit[16864]: AVC apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=16864 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:34 cobalt kernel: audit: type=1400 audit(1586571214.699:268): apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=16864 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:34 cobalt audit[16910]: AVC apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=16910 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:34 cobalt audit[16910]: AVC apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=16910 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:34 cobalt kernel: audit: type=1400 audit(1586571214.751:269): apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=16910 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:34 cobalt kernel: audit: type=1400 audit(1586571214.751:270): apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=16910 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:34 cobalt NetworkManager[1574]: <info> [1586571214.8229] manager: (veth46590781): new Veth device (/org/freedesktop/NetworkManager/Devices/21)
Apr 10 22:13:34 cobalt systemd-udevd[16954]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 10 22:13:34 cobalt systemd-udevd[16954]: Using default interface naming scheme 'v240'.
Apr 10 22:13:34 cobalt systemd-udevd[16954]: veth46590781: Could not generate persistent MAC: No data available
Apr 10 22:13:34 cobalt systemd-udevd[16956]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 10 22:13:34 cobalt systemd-udevd[16956]: Using default interface naming scheme 'v240'.
Apr 10 22:13:34 cobalt systemd-udevd[16956]: vethbc785f11: Could not generate persistent MAC: No data available
Apr 10 22:13:34 cobalt NetworkManager[1574]: <info> [1586571214.8240] manager: (vethbc785f11): new Veth device (/org/freedesktop/NetworkManager/Devices/22)
Apr 10 22:13:34 cobalt kernel: lxdbr0: port 1(vethbc785f11) entered blocking state
Apr 10 22:13:34 cobalt kernel: lxdbr0: port 1(vethbc785f11) entered disabled state
Apr 10 22:13:34 cobalt kernel: device vethbc785f11 entered promiscuous mode
Apr 10 22:13:34 cobalt audit[17009]: AVC apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="lxd-applications_</var/snap/lxd/common/lxd>" pid=17009 comm="apparmor_parser"
Apr 10 22:13:34 cobalt kernel: audit: type=1400 audit(1586571214.903:271): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="lxd-applications_</var/snap/lxd/common/lxd>" pid=17009 comm="apparmor_parser"
Apr 10 22:13:34 cobalt kernel: eth0: renamed from veth46590781
Apr 10 22:13:35 cobalt kernel: lxdbr0: port 1(vethbc785f11) entered disabled state
Apr 10 22:13:35 cobalt kernel: device vethbc785f11 left promiscuous mode
Apr 10 22:13:35 cobalt kernel: lxdbr0: port 1(vethbc785f11) entered disabled state
Apr 10 22:13:35 cobalt NetworkManager[1574]: <info> [1586571215.0966] device (vethbc785f11): released from master device lxdbr0
Apr 10 22:13:35 cobalt lxd.daemon[27943]: t=2020-04-10T22:13:35-0400 lvl=eror msg="Failed starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-04-10T22:13:26-0400
Apr 10 22:13:35 cobalt audit[17049]: AVC apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=17049 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:35 cobalt kernel: audit: type=1400 audit(1586571215.227:272): apparmor="DENIED" operation="open" profile="/snap/core/8935/usr/lib/snapd/snap-confine" name="/etc/pop-os/os-release" pid=17049 comm="snap-confine" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 10 22:13:35 cobalt audit[17049]: AVC apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=17049 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:35 cobalt kernel: audit: type=1400 audit(1586571215.231:273): apparmor="DENIED" operation="open" profile="snap.lxd.lxc" name="/var/lib/snapd/hostfs/etc/pop-os/os-release" pid=17049 comm="snap-exec" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
Apr 10 22:13:35 cobalt lxd.daemon[27943]: t=2020-04-10T22:13:35-0400 lvl=eror msg="The stop hook failed" container=applications err="Failed to run: zfs unmount default/containers/applications: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/applications: not mounted\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/applications': umount failed"
tomp
April 14, 2020, 9:56am
15
Hrm weird you are seeing some lxd logs but not the debug ones.
That unmount error at the bottom looks interesting though, do you see that only when the error occurs?
Can you also look in /var/snap/lxd/common/lxd/logs/ and see if there is a log file for your container?
tomp
April 20, 2020, 4:44pm
16
There’s a good chance this PR will fix the issue (it may have been that issuing a restart command was what was causing this problem):
lxc:master ← tomponline:tp-vm-restart
opened 04:37PM - 20 Apr 20 UTC
stgraber
April 20, 2020, 4:57pm
17
But this issue was about containers, not VMs though
tomp
April 20, 2020, 5:06pm
18
Mmm true, id forgotten that. Ive not been able to reproduce it.
So, some more information: Interestingly enough, another container started manifesting the same problem suddenly. What is different though is that once I see the problem, where I can’t start the container and the backup.yaml file gets created, it stays consistent. The container will not start. After a reboot of the system, however, I am once again able to start the container.
Looking at those logs I didn’t find anything that looked particularly interesting. Here is some of what I did find:
t=2020-04-13T08:26:30-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
t=2020-04-13T08:26:34-0400 lvl=eror msg="The stop hook failed" container=applications err="Failed to run: zfs unmount default/containers/applications: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/applications: not mounted\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/applications': umount failed"
t=2020-04-13T08:26:34-0400 lvl=info msg="Shut down container" action=shutdown created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default timeout=15s used=2020-04-10T22:23:28-0400
t=2020-04-13T08:26:49-0400 lvl=info msg="Starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-04-10T22:23:28-0400
t=2020-04-13T08:26:49-0400 lvl=eror msg="Failed starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-04-10T22:23:28-0400
At the time of this occurring, this is my lxd snap version info:
lxd 4.0.1 14804 latest/stable canonical✓ -
tomp
April 24, 2020, 12:40pm
20
Can you confirm you have done:
sudo snap set lxd daemon.debug=true
sudo systemctl reload snap.lxd.daemon
As your system is still not apparently producing debug level logs.
Can you run journalctl -u snap.lxd.daemon -n 300 the next time it happens please.
Can you confirm you have done:
Yes. I actually rebooted once I saw that the logs were not being generated. The output of sudo snap get lxd daemon.debug is true
Here is the latest snap info in case it matters:lxd 4.0.1 14954 latest/stable canonical✓ -
Here is the output of journalctl -u snap.lxd.daemon -n 300. The container that just failed is called dev-dwk:
-- Logs begin at Tue 2019-12-24 17:44:54 -03, end at Thu 2020-05-07 11:10:55 -04. --
May 01 09:16:57 cobalt lxd.daemon[3396]: t=2020-05-01T09:16:57-0400 lvl=eror msg="Failed starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-05-01T09:15:06-0400
May 01 09:16:57 cobalt lxd.daemon[3396]: t=2020-05-01T09:16:57-0400 lvl=eror msg="The stop hook failed" container=applications err="Failed to run: zfs unmount default/containers/applications: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/applications: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/applications': umount failed"
May 01 09:17:09 cobalt lxd.daemon[3396]: t=2020-05-01T09:17:09-0400 lvl=eror msg="Failed starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-05-01T09:16:56-0400
May 01 09:17:09 cobalt lxd.daemon[3396]: t=2020-05-01T09:17:09-0400 lvl=eror msg="The stop hook failed" container=applications err="Failed to run: zfs unmount default/containers/applications: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/applications: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/applications': umount failed"
May 01 09:17:21 cobalt lxd.daemon[3396]: t=2020-05-01T09:17:21-0400 lvl=eror msg="Failed starting container" action=start created=2020-02-10T08:08:03-0300 ephemeral=false name=applications project=default stateful=false used=2020-05-01T09:17:08-0400
May 01 09:17:21 cobalt lxd.daemon[3396]: t=2020-05-01T09:17:21-0400 lvl=eror msg="The stop hook failed" container=applications err="Failed to run: zfs unmount default/containers/applications: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/applications: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/applications': umount failed"
May 01 09:17:28 cobalt lxd.daemon[3396]: t=2020-05-01T09:17:28-0400 lvl=eror msg="Failed starting container" action=start created=2020-01-19T10:43:11-0300 ephemeral=false name=dev-dwk project=default stateful=false used=2020-05-01T09:10:20-0400
May 01 09:17:29 cobalt lxd.daemon[3396]: t=2020-05-01T09:17:29-0400 lvl=eror msg="The stop hook failed" container=dev-dwk err="Failed to run: zfs unmount default/containers/dev-dwk: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk': umount failed"
May 01 09:18:46 cobalt systemd[1]: Stopping Service for snap application lxd.daemon...
May 01 09:18:47 cobalt lxd.daemon[21064]: => Stop reason is: host shutdown
May 01 09:18:47 cobalt lxd.daemon[21064]: => Stopping LXD (with container shutdown)
May 01 09:18:47 cobalt lxd.daemon[3396]: => LXD exited cleanly
May 01 09:18:48 cobalt lxd.daemon[21064]: ==> Stopped LXD
May 01 09:18:48 cobalt lxd.daemon[21064]: => Stopping LXCFS
May 01 09:18:48 cobalt lxd.daemon[2301]: Running destructor lxcfs_exit
May 01 09:18:49 cobalt lxd.daemon[21064]: ==> Stopped LXCFS
May 01 09:18:49 cobalt lxd.daemon[21064]: => Cleaning up PID files
May 01 09:18:49 cobalt lxd.daemon[21064]: => Cleaning up namespaces
May 01 09:18:49 cobalt lxd.daemon[21064]: => All done
May 01 09:18:49 cobalt systemd[1]: snap.lxd.daemon.service: Succeeded.
May 01 09:18:49 cobalt systemd[1]: Stopped Service for snap application lxd.daemon.
-- Reboot --
May 01 09:20:45 cobalt systemd[1]: Started Service for snap application lxd.daemon.
May 01 09:20:45 cobalt lxd.daemon[3612]: => Preparing the system (14890)
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Loading snap configuration
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up mntns symlink (mnt:[4026532795])
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up persistent shmounts path
May 01 09:20:45 cobalt lxd.daemon[3612]: ====> Making LXD shmounts use the persistent path
May 01 09:20:45 cobalt lxd.daemon[3612]: ====> Making LXCFS use the persistent path
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up kmod wrapper
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Preparing /boot
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Preparing a clean copy of /run
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Preparing a clean copy of /etc
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Preparing a clean copy of /usr/share/misc
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up ceph configuration
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up LVM configuration
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Rotating logs
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Setting up ZFS (0.8)
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Escaping the systemd cgroups
May 01 09:20:45 cobalt lxd.daemon[3612]: ====> Detected cgroup V1
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Escaping the systemd process resource limits
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Increasing the number of inotify user instances
May 01 09:20:45 cobalt lxd.daemon[3612]: ==> Disabling shiftfs on this kernel (auto)
May 01 09:20:45 cobalt lxd.daemon[3612]: => Starting LXCFS
May 01 09:20:45 cobalt lxd.daemon[3612]: Running constructor lxcfs_init to reload liblxcfs
May 01 09:20:45 cobalt lxd.daemon[3612]: mount namespace: 4
May 01 09:20:45 cobalt lxd.daemon[3612]: hierarchies:
May 01 09:20:45 cobalt lxd.daemon[3612]: 0: fd: 5:
May 01 09:20:45 cobalt lxd.daemon[3612]: 1: fd: 6: name=systemd
May 01 09:20:45 cobalt lxd.daemon[3612]: 2: fd: 7: rdma
May 01 09:20:45 cobalt lxd.daemon[3612]: 3: fd: 8: cpu,cpuacct
May 01 09:20:45 cobalt lxd.daemon[3612]: 4: fd: 9: memory
May 01 09:20:45 cobalt lxd.daemon[3612]: 5: fd: 10: devices
May 01 09:20:45 cobalt lxd.daemon[3612]: 6: fd: 11: freezer
May 01 09:20:45 cobalt lxd.daemon[3612]: 7: fd: 12: net_cls,net_prio
May 01 09:20:45 cobalt lxd.daemon[3612]: 8: fd: 13: blkio
May 01 09:20:45 cobalt lxd.daemon[3612]: 9: fd: 14: cpuset
May 01 09:20:45 cobalt lxd.daemon[3612]: 10: fd: 15: perf_event
May 01 09:20:45 cobalt lxd.daemon[3612]: 11: fd: 16: pids
May 01 09:20:45 cobalt lxd.daemon[3612]: 12: fd: 17: hugetlb
May 01 09:20:45 cobalt lxd.daemon[3612]: Kernel supports pidfds
May 01 09:20:45 cobalt lxd.daemon[3612]: api_extensions:
May 01 09:20:45 cobalt lxd.daemon[3612]: - cgroups
May 01 09:20:45 cobalt lxd.daemon[3612]: - sys_cpu_online
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_cpuinfo
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_diskstats
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_loadavg
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_meminfo
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_stat
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_swaps
May 01 09:20:45 cobalt lxd.daemon[3612]: - proc_uptime
May 01 09:20:45 cobalt lxd.daemon[3612]: - shared_pidns
May 01 09:20:45 cobalt lxd.daemon[3612]: - cpuview_daemon
May 01 09:20:45 cobalt lxd.daemon[3612]: - loadavg_daemon
May 01 09:20:45 cobalt lxd.daemon[3612]: - pidfds
May 01 09:20:46 cobalt lxd.daemon[3612]: => Starting LXD
May 01 09:20:47 cobalt lxd.daemon[3612]: t=2020-05-01T09:20:47-0400 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
May 01 09:20:47 cobalt lxd.daemon[3612]: t=2020-05-01T09:20:47-0400 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
May 01 09:20:47 cobalt lxd.daemon[3612]: t=2020-05-01T09:20:47-0400 lvl=eror msg="Firewall nftables unable to parse existing ruleset: invalid character '^' looking for beginning of value"
May 01 09:20:49 cobalt lxd.daemon[3612]: => LXD is ready
May 01 09:28:33 cobalt lxd.daemon[3612]: t=2020-05-01T09:28:33-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 02 07:19:08 cobalt lxd.daemon[3612]: proc_fuse.c: 877: proc_stat_read: cpu1 from /lxc.payload.dev-dwk has unexpected cpu time: 1127694 in /proc/stat, 1128451 in cpuacct.usage_all; unable to determine idle time
May 02 07:19:08 cobalt lxd.daemon[3612]: proc_fuse.c: 877: proc_stat_read: cpu2 from /lxc.payload.dev-dwk has unexpected cpu time: 1112896 in /proc/stat, 1172677 in cpuacct.usage_all; unable to determine idle time
May 05 10:47:42 cobalt lxd.daemon[3612]: t=2020-05-05T10:47:42-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 10:48:48 cobalt lxd.daemon[3612]: t=2020-05-05T10:48:48-0400 lvl=eror msg="Failed shutting down container" action=shutdown created=2020-04-21T12:04:33-0400 ephemeral=false name=dev-ppe project=default timeout=15s used=2020-05-02T10:53:41-0400
May 05 10:54:19 cobalt systemd[1]: Stopping Service for snap application lxd.daemon...
May 05 10:54:19 cobalt lxd.daemon[23601]: => Stop reason is: host shutdown
May 05 10:54:19 cobalt lxd.daemon[23601]: => Stopping LXD (with container shutdown)
May 05 10:54:20 cobalt lxd.daemon[3612]: => LXD exited cleanly
May 05 10:54:20 cobalt lxd.daemon[23601]: ==> Stopped LXD
May 05 10:54:20 cobalt lxd.daemon[23601]: => Stopping LXCFS
May 05 10:54:20 cobalt lxd.daemon[3612]: Running destructor lxcfs_exit
May 05 10:54:21 cobalt lxd.daemon[23601]: ==> Stopped LXCFS
May 05 10:54:21 cobalt lxd.daemon[23601]: => Cleaning up PID files
May 05 10:54:21 cobalt lxd.daemon[23601]: => Cleaning up namespaces
May 05 10:54:21 cobalt lxd.daemon[23601]: => All done
May 05 10:54:21 cobalt systemd[1]: snap.lxd.daemon.service: Succeeded.
May 05 10:54:21 cobalt systemd[1]: Stopped Service for snap application lxd.daemon.
-- Reboot --
May 05 10:55:49 cobalt systemd[1]: Started Service for snap application lxd.daemon.
May 05 10:55:49 cobalt lxd.daemon[3442]: => Preparing the system (14890)
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Loading snap configuration
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up mntns symlink (mnt:[4026532805])
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up persistent shmounts path
May 05 10:55:49 cobalt lxd.daemon[3442]: ====> Making LXD shmounts use the persistent path
May 05 10:55:49 cobalt lxd.daemon[3442]: ====> Making LXCFS use the persistent path
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up kmod wrapper
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Preparing /boot
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Preparing a clean copy of /run
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Preparing a clean copy of /etc
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Preparing a clean copy of /usr/share/misc
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up ceph configuration
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up LVM configuration
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Rotating logs
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Setting up ZFS (0.8)
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Escaping the systemd cgroups
May 05 10:55:49 cobalt lxd.daemon[3442]: ====> Detected cgroup V1
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Escaping the systemd process resource limits
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Increasing the number of inotify user instances
May 05 10:55:49 cobalt lxd.daemon[3442]: ==> Disabling shiftfs on this kernel (auto)
May 05 10:55:49 cobalt lxd.daemon[3442]: => Starting LXCFS
May 05 10:55:49 cobalt lxd.daemon[3442]: Running constructor lxcfs_init to reload liblxcfs
May 05 10:55:49 cobalt lxd.daemon[3442]: mount namespace: 4
May 05 10:55:49 cobalt lxd.daemon[3442]: hierarchies:
May 05 10:55:49 cobalt lxd.daemon[3442]: 0: fd: 5:
May 05 10:55:49 cobalt lxd.daemon[3442]: 1: fd: 6: name=systemd
May 05 10:55:49 cobalt lxd.daemon[3442]: 2: fd: 7: pids
May 05 10:55:49 cobalt lxd.daemon[3442]: 3: fd: 8: devices
May 05 10:55:49 cobalt lxd.daemon[3442]: 4: fd: 9: blkio
May 05 10:55:49 cobalt lxd.daemon[3442]: 5: fd: 10: perf_event
May 05 10:55:49 cobalt lxd.daemon[3442]: 6: fd: 11: memory
May 05 10:55:49 cobalt lxd.daemon[3442]: 7: fd: 12: net_cls,net_prio
May 05 10:55:49 cobalt lxd.daemon[3442]: 8: fd: 13: rdma
May 05 10:55:49 cobalt lxd.daemon[3442]: 9: fd: 14: hugetlb
May 05 10:55:49 cobalt lxd.daemon[3442]: 10: fd: 15: cpu,cpuacct
May 05 10:55:49 cobalt lxd.daemon[3442]: 11: fd: 16: freezer
May 05 10:55:49 cobalt lxd.daemon[3442]: 12: fd: 17: cpuset
May 05 10:55:49 cobalt lxd.daemon[3442]: Kernel supports pidfds
May 05 10:55:49 cobalt lxd.daemon[3442]: api_extensions:
May 05 10:55:49 cobalt lxd.daemon[3442]: - cgroups
May 05 10:55:49 cobalt lxd.daemon[3442]: - sys_cpu_online
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_cpuinfo
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_diskstats
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_loadavg
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_meminfo
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_stat
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_swaps
May 05 10:55:49 cobalt lxd.daemon[3442]: - proc_uptime
May 05 10:55:49 cobalt lxd.daemon[3442]: - shared_pidns
May 05 10:55:49 cobalt lxd.daemon[3442]: - cpuview_daemon
May 05 10:55:49 cobalt lxd.daemon[3442]: - loadavg_daemon
May 05 10:55:49 cobalt lxd.daemon[3442]: - pidfds
May 05 10:55:50 cobalt lxd.daemon[3442]: => Starting LXD
May 05 10:55:50 cobalt lxd.daemon[3442]: t=2020-05-05T10:55:50-0400 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
May 05 10:55:50 cobalt lxd.daemon[3442]: t=2020-05-05T10:55:50-0400 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
May 05 10:55:51 cobalt lxd.daemon[3442]: t=2020-05-05T10:55:51-0400 lvl=eror msg="Firewall nftables unable to parse existing ruleset: invalid character '^' looking for beginning of value"
May 05 10:55:53 cobalt lxd.daemon[3442]: => LXD is ready
May 05 11:00:28 cobalt lxd.daemon[3442]: t=2020-05-05T11:00:28-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:21:49 cobalt lxd.daemon[3442]: t=2020-05-05T11:21:49-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:25:13 cobalt lxd.daemon[3442]: t=2020-05-05T11:25:13-0400 lvl=eror msg="Error getting source image" err="No such object" fp=d158b6b8ddb791e2efa66c9c623c479388d6b01b32a11785b251c4daad723146
May 05 11:25:26 cobalt lxd.daemon[3442]: t=2020-05-05T11:25:26-0400 lvl=eror msg="Error getting source image" err="No such object" fp=d158b6b8ddb791e2efa66c9c623c479388d6b01b32a11785b251c4daad723146
May 05 11:25:30 cobalt lxd.daemon[3442]: t=2020-05-05T11:25:30-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 05 11:27:36 cobalt lxd.daemon[3442]: t=2020-05-05T11:27:36-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:27:36 cobalt lxd.daemon[3442]: t=2020-05-05T11:27:36-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:27:49 cobalt lxd.daemon[3442]: t=2020-05-05T11:27:49-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:27:49 cobalt lxd.daemon[3442]: t=2020-05-05T11:27:49-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:30:30 cobalt lxd.daemon[3442]: t=2020-05-05T11:30:30-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:30:44 cobalt lxd.daemon[3442]: t=2020-05-05T11:30:44-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:30:44 cobalt lxd.daemon[3442]: t=2020-05-05T11:30:44-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:32:55 cobalt lxd.daemon[3442]: t=2020-05-05T11:32:55-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:33:11 cobalt lxd.daemon[3442]: t=2020-05-05T11:33:11-0400 lvl=eror msg="Failed shutting down container" action=shutdown created=2020-05-05T11:30:25-0400 ephemeral=false name=test project=default timeout=15s used=2020-05-05T11:32:50-0400
May 05 11:33:55 cobalt lxd.daemon[3442]: t=2020-05-05T11:33:55-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 11:33:55 cobalt lxd.daemon[3442]: t=2020-05-05T11:33:55-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:10:37 cobalt lxd.daemon[3442]: t=2020-05-05T14:10:37-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:10:37 cobalt lxd.daemon[3442]: t=2020-05-05T14:10:37-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:12:08 cobalt lxd.daemon[3442]: t=2020-05-05T14:12:08-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:14:26 cobalt lxd.daemon[3442]: t=2020-05-05T14:14:26-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:24:34 cobalt lxd.daemon[3442]: t=2020-05-05T14:24:34-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:24:55 cobalt lxd.daemon[3442]: t=2020-05-05T14:24:55-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:29:06 cobalt lxd.daemon[3442]: t=2020-05-05T14:29:06-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:29:48 cobalt lxd.daemon[3442]: t=2020-05-05T14:29:48-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:32:32 cobalt lxd.daemon[3442]: t=2020-05-05T14:32:32-0400 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
May 05 14:33:03 cobalt lxd.daemon[3442]: t=2020-05-05T14:33:03-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:36:59 cobalt lxd.daemon[3442]: t=2020-05-05T14:36:59-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:37:09 cobalt lxd.daemon[3442]: t=2020-05-05T14:37:09-0400 lvl=eror msg="Error getting disk usage" err="Failed to run: zfs get -H -p -o value used default/containers/dev-xnerds: cannot open 'default/containers/dev-xnerds': dataset does not exist" instance=dev-xnerds project=default
May 05 14:38:33 cobalt lxd.daemon[3442]: t=2020-05-05T14:38:33-0400 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
May 05 14:42:06 cobalt lxd.daemon[3442]: t=2020-05-05T14:42:06-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:42:06 cobalt lxd.daemon[3442]: t=2020-05-05T14:42:06-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:42:24 cobalt lxd.daemon[3442]: t=2020-05-05T14:42:24-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:42:24 cobalt lxd.daemon[3442]: t=2020-05-05T14:42:24-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:45:21 cobalt lxd.daemon[3442]: t=2020-05-05T14:45:21-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:46:21 cobalt lxd.daemon[3442]: t=2020-05-05T14:46:21-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:47:50 cobalt lxd.daemon[3442]: t=2020-05-05T14:47:50-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:47:50 cobalt lxd.daemon[3442]: t=2020-05-05T14:47:50-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:51:56 cobalt lxd.daemon[3442]: t=2020-05-05T14:51:56-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:53:55 cobalt lxd.daemon[3442]: t=2020-05-05T14:53:55-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 14:54:19 cobalt lxd.daemon[3442]: t=2020-05-05T14:54:19-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:06:09 cobalt lxd.daemon[3442]: t=2020-05-05T15:06:09-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:07:05 cobalt lxd.daemon[3442]: t=2020-05-05T15:07:05-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:07:08 cobalt lxd.daemon[3442]: t=2020-05-05T15:07:08-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:07:14 cobalt lxd.daemon[3442]: t=2020-05-05T15:07:14-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:07:14 cobalt lxd.daemon[3442]: t=2020-05-05T15:07:14-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:07:34 cobalt lxd.daemon[3442]: t=2020-05-05T15:07:34-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:19:39 cobalt lxd.daemon[3442]: t=2020-05-05T15:19:39-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:21:36 cobalt lxd.daemon[3442]: t=2020-05-05T15:21:36-0400 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
May 05 15:26:31 cobalt lxd.daemon[3442]: t=2020-05-05T15:26:31-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:29:50 cobalt lxd.daemon[3442]: t=2020-05-05T15:29:50-0400 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
May 05 15:30:28 cobalt lxd.daemon[3442]: t=2020-05-05T15:30:28-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:31:21 cobalt lxd.daemon[3442]: t=2020-05-05T15:31:21-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:33:48 cobalt lxd.daemon[3442]: t=2020-05-05T15:33:48-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 15:36:52 cobalt lxd.daemon[3442]: t=2020-05-05T15:36:52-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 05 16:55:52 cobalt lxd.daemon[3442]: t=2020-05-05T16:55:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 05 20:30:32 cobalt systemd[1]: Stopping Service for snap application lxd.daemon...
May 05 20:30:32 cobalt lxd.daemon[18100]: => Stop reason is: snap refresh
May 05 20:30:32 cobalt lxd.daemon[18100]: => Stopping LXD
May 05 20:30:32 cobalt lxd.daemon[3442]: => LXD exited cleanly
May 05 20:30:33 cobalt systemd[1]: snap.lxd.daemon.service: Succeeded.
May 05 20:30:33 cobalt systemd[1]: Stopped Service for snap application lxd.daemon.
May 05 20:30:50 cobalt systemd[1]: Started Service for snap application lxd.daemon.
May 05 20:30:50 cobalt lxd.daemon[18863]: => Preparing the system (14954)
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Loading snap configuration
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up mntns symlink (mnt:[4026532805])
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/storage-pools
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up mount propagation on /var/snap/lxd/common/lxd/devices
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up kmod wrapper
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Preparing /boot
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Preparing a clean copy of /run
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Preparing a clean copy of /etc
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Preparing a clean copy of /usr/share/misc
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up ceph configuration
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up LVM configuration
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Rotating logs
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Setting up ZFS (0.8)
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Escaping the systemd cgroups
May 05 20:30:50 cobalt lxd.daemon[18863]: ====> Detected cgroup V1
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Escaping the systemd process resource limits
May 05 20:30:50 cobalt lxd.daemon[18863]: ==> Disabling shiftfs on this kernel (auto)
May 05 20:30:50 cobalt lxd.daemon[18863]: => Re-using existing LXCFS
May 05 20:30:50 cobalt lxd.daemon[18863]: => Starting LXD
May 05 20:30:50 cobalt lxd.daemon[18863]: t=2020-05-05T20:30:50-0400 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, I/O weight limits will be ignored"
May 05 20:30:50 cobalt lxd.daemon[18863]: t=2020-05-05T20:30:50-0400 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
May 05 20:30:51 cobalt lxd.daemon[18863]: t=2020-05-05T20:30:51-0400 lvl=eror msg="Firewall nftables unable to parse existing ruleset: invalid character '^' looking for beginning of value"
May 05 20:30:52 cobalt lxd.daemon[18863]: t=2020-05-05T20:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 05 20:30:52 cobalt lxd.daemon[18863]: => LXD is ready
May 05 20:31:47 cobalt lxd.daemon[3442]: Closed liblxcfs.so
May 05 20:31:47 cobalt lxd.daemon[3442]: Running destructor lxcfs_exit
May 05 20:31:47 cobalt lxd.daemon[3442]: Running constructor lxcfs_init to reload liblxcfs
May 05 20:31:47 cobalt lxd.daemon[3442]: mount namespace: 5
May 05 20:31:47 cobalt lxd.daemon[3442]: hierarchies:
May 05 20:31:47 cobalt lxd.daemon[3442]: 0: fd: 6:
May 05 20:31:47 cobalt lxd.daemon[3442]: 1: fd: 7: name=systemd
May 05 20:31:47 cobalt lxd.daemon[3442]: 2: fd: 8: pids
May 05 20:31:47 cobalt lxd.daemon[3442]: 3: fd: 9: devices
May 05 20:31:47 cobalt lxd.daemon[3442]: 4: fd: 10: blkio
May 05 20:31:47 cobalt lxd.daemon[3442]: 5: fd: 11: perf_event
May 05 20:31:47 cobalt lxd.daemon[3442]: 6: fd: 12: memory
May 05 20:31:47 cobalt lxd.daemon[3442]: 7: fd: 13: net_cls,net_prio
May 05 20:31:47 cobalt lxd.daemon[3442]: 8: fd: 14: rdma
May 05 20:31:47 cobalt lxd.daemon[3442]: 9: fd: 15: hugetlb
May 05 20:31:47 cobalt lxd.daemon[3442]: 10: fd: 16: cpu,cpuacct
May 05 20:31:47 cobalt lxd.daemon[3442]: 11: fd: 17: freezer
May 05 20:31:47 cobalt lxd.daemon[3442]: 12: fd: 19: cpuset
May 05 20:31:47 cobalt lxd.daemon[3442]: Kernel supports pidfds
May 05 20:31:47 cobalt lxd.daemon[3442]: api_extensions:
May 05 20:31:47 cobalt lxd.daemon[3442]: - cgroups
May 05 20:31:47 cobalt lxd.daemon[3442]: - sys_cpu_online
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_cpuinfo
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_diskstats
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_loadavg
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_meminfo
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_stat
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_swaps
May 05 20:31:47 cobalt lxd.daemon[3442]: - proc_uptime
May 05 20:31:47 cobalt lxd.daemon[3442]: - shared_pidns
May 05 20:31:47 cobalt lxd.daemon[3442]: - cpuview_daemon
May 05 20:31:47 cobalt lxd.daemon[3442]: - loadavg_daemon
May 05 20:31:47 cobalt lxd.daemon[3442]: - pidfds
May 05 20:31:47 cobalt lxd.daemon[3442]: Reloaded LXCFS
May 05 21:57:40 cobalt lxd.daemon[18863]: t=2020-05-05T21:57:40-0400 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
May 06 02:30:52 cobalt lxd.daemon[18863]: t=2020-05-06T02:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 06 08:30:52 cobalt lxd.daemon[18863]: t=2020-05-06T08:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 06 10:41:09 cobalt lxd.daemon[18863]: t=2020-05-06T10:41:09-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 06 14:30:52 cobalt lxd.daemon[18863]: t=2020-05-06T14:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 06 20:30:52 cobalt lxd.daemon[18863]: t=2020-05-06T20:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 07 02:30:52 cobalt lxd.daemon[18863]: t=2020-05-07T02:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 07 08:30:52 cobalt lxd.daemon[18863]: t=2020-05-07T08:30:52-0400 lvl=eror msg="Error getting source image" err="No such object" fp=db68e16f19f5b6e54300949335c35c3037a0bb07866633ae3835c733a9bac11d
May 07 09:31:00 cobalt lxd.daemon[18863]: t=2020-05-07T09:31:00-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 07 10:36:00 cobalt lxd.daemon[18863]: t=2020-05-07T10:36:00-0400 lvl=warn msg="Detected poll(POLLNVAL) event: exiting."
May 07 10:36:00 cobalt lxd.daemon[18863]: t=2020-05-07T10:36:00-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 07 10:42:07 cobalt lxd.daemon[18863]: t=2020-05-07T10:42:07-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 07 11:05:24 cobalt lxd.daemon[18863]: t=2020-05-07T11:05:24-0400 lvl=warn msg="Detected poll(POLLNVAL) event."
May 07 11:05:33 cobalt lxd.daemon[18863]: t=2020-05-07T11:05:33-0400 lvl=eror msg="The stop hook failed" container=dev-dwk err="Failed to run: zfs unmount default/containers/dev-dwk: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk': umount failed"
May 07 11:05:34 cobalt lxd.daemon[18863]: t=2020-05-07T11:05:34-0400 lvl=eror msg="Failed starting container" action=start created=2020-01-19T10:43:11-0300 ephemeral=false name=dev-dwk project=default stateful=false used=2020-05-05T15:35:48-0400
May 07 11:05:34 cobalt lxd.daemon[18863]: t=2020-05-07T11:05:34-0400 lvl=eror msg="The stop hook failed" container=dev-dwk err="Failed to run: zfs unmount default/containers/dev-dwk: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk': umount failed"
May 07 11:10:05 cobalt lxd.daemon[18863]: t=2020-05-07T11:10:05-0400 lvl=eror msg="Failed starting container" action=start created=2020-01-19T10:43:11-0300 ephemeral=false name=dev-dwk project=default stateful=false used=2020-05-07T11:05:34-0400
May 07 11:10:06 cobalt lxd.daemon[18863]: t=2020-05-07T11:10:06-0400 lvl=eror msg="The stop hook failed" container=dev-dwk err="Failed to run: zfs unmount default/containers/dev-dwk: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk': umount failed"
May 07 11:10:54 cobalt lxd.daemon[18863]: t=2020-05-07T11:10:54-0400 lvl=eror msg="Failed starting container" action=start created=2020-01-19T10:43:11-0300 ephemeral=false name=dev-dwk project=default stateful=false used=2020-05-07T11:10:05-0400
May 07 11:10:55 cobalt lxd.daemon[18863]: t=2020-05-07T11:10:55-0400 lvl=eror msg="The stop hook failed" container=dev-dwk err="Failed to run: zfs unmount default/containers/dev-dwk: umount: /home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk: not mounted.\ncannot unmount '/home/snap/lxd/common/lxd/storage-pools/default/containers/dev-dwk': umount failed"
tomp
May 7, 2020, 4:35pm
22
Thanks.
Its strange you’re still not seeing debug messages. @stgraber any ideas on where these debug messages may be going?
Anyway, I think we can certainly see an issue here with the ZFS unmount failing.
@stgraber maybe your commit https://github.com/lxc/lxd/commit/7de16487fb69bd3c4895a76627e2302829433151 from the other day may help this situation? Perhaps it is still busy.
Regarding the debug messages, I suspect that for some weird reason, sudo snap set ... seems to not convey the values to the snap on my system. I say that because I tried to enable CRIU before, following the directions to run sudo snap set lxd criu.enable=true and the snap never recoginzed it as enabled. It feels like the same thing is happening here.
I’m on Pop OS, which (as you probably know) is a lightly modified derivative of Ubuntu, in case it makes a difference (which I doubt).
I’m not sure if because of recent code changes or some other reason, but this seems to have stabilized recently. I’m not seeing it like I used to. If it continues good for a while longer, I’ll close the thread.
1 Like