Apr 12 00:13:22 foo anacron[28211]: Job `cron.daily' terminated Apr 12 00:13:54 foo NetworkManager[678]: sleep requested (sleeping: no enabled: yes) Apr 12 00:13:54 foo NetworkManager[678]: sleeping... Apr 12 00:13:54 foo NetworkManager[678]: (wlp58s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37] Apr 12 00:13:54 foo NetworkManager[678]: (wlp58s0): canceled DHCP transaction, DHCP client pid 28224 Apr 12 00:13:54 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> done Apr 12 00:13:54 foo kernel: [117687.953966] wlp58s0: deauthenticating from e0:3f:49:9b:18:7a by local choice (Reason: 3=DEAUTH_LEAVING) Apr 12 00:13:54 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-DISCONNECTED bssid=e0:3f:49:9b:18:7a reason=3 locally_generated=1 Apr 12 00:13:54 foo NetworkManager[678]: NetworkManager state is now ASLEEP Apr 12 00:13:54 foo dnsmasq[930]: no servers found in /etc/resolv.conf, will retry Apr 12 00:13:54 foo avahi-daemon[635]: Withdrawing address record for 192.168.1.103 on wlp58s0. Apr 12 00:13:54 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv4 with address 192.168.1.103. Apr 12 00:13:54 foo avahi-daemon[635]: Interface wlp58s0.IPv4 no longer relevant for mDNS. Apr 12 00:13:54 foo avahi-daemon[635]: Withdrawing address record for fe80::de53:60ff:fecc:254a on wlp58s0. Apr 12 00:13:54 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 00:13:54 foo avahi-daemon[635]: Interface wlp58s0.IPv6 no longer relevant for mDNS. Apr 12 00:13:54 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 00:13:54 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 00:13:54 foo systemd[1]: Reached target Sleep. Apr 12 00:13:54 foo systemd[1]: Starting Suspend... Apr 12 00:13:54 foo systemd-sleep[28691]: Suspending system... Apr 12 00:13:54 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 00:13:54 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 00:13:54 foo nm-dispatcher: #1 'down' [wlp58s0]: new request (1 scripts) Apr 12 00:13:54 foo nm-dispatcher: #1 'down' [wlp58s0]: start running ordered scripts... Apr 12 09:18:44 foo kernel: [117688.019510] PM: Syncing filesystems ... done. Apr 12 09:18:44 foo kernel: [117688.053738] PM: Preparing system for sleep (mem) Apr 12 09:18:44 foo kernel: [117688.054154] Freezing user space processes ... (elapsed 0.001 seconds) done. Apr 12 09:18:44 foo kernel: [117688.055988] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Apr 12 09:18:44 foo kernel: [117688.057288] PM: Suspending system (mem) Apr 12 09:18:44 foo kernel: [117688.057305] Suspending console(s) (use no_console_suspend to debug) Apr 12 09:18:44 foo kernel: [117688.388690] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun Apr 12 09:18:44 foo kernel: [117688.412281] PM: suspend of devices complete after 339.892 msecs Apr 12 09:18:44 foo kernel: [117688.432382] PM: late suspend of devices complete after 20.093 msecs Apr 12 09:18:44 foo kernel: [117688.432766] pcieport 0000:01:00.0: System wakeup enabled by ACPI Apr 12 09:18:44 foo kernel: [117688.433506] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI Apr 12 09:18:44 foo kernel: [117688.464192] PM: noirq suspend of devices complete after 31.792 msecs Apr 12 09:18:44 foo kernel: [117688.464440] ACPI: Preparing to enter system sleep state S3 Apr 12 09:18:44 foo kernel: [117688.484334] ACPI : EC: EC stopped Apr 12 09:18:44 foo kernel: [117688.484334] PM: Saving platform NVS memory Apr 12 09:18:44 foo kernel: [117688.484352] Disabling non-boot CPUs ... Apr 12 09:18:44 foo kernel: [117688.485625] smpboot: CPU 1 is now offline Apr 12 09:18:44 foo kernel: [117688.496774] Broke affinity for irq 286 Apr 12 09:18:44 foo kernel: [117688.496777] Broke affinity for irq 287 Apr 12 09:18:44 foo kernel: [117688.497805] smpboot: CPU 2 is now offline Apr 12 09:18:44 foo kernel: [117688.512628] Broke affinity for irq 1 Apr 12 09:18:44 foo kernel: [117688.512631] Broke affinity for irq 8 Apr 12 09:18:44 foo kernel: [117688.512633] Broke affinity for irq 9 Apr 12 09:18:44 foo kernel: [117688.512635] Broke affinity for irq 12 Apr 12 09:18:44 foo kernel: [117688.512637] Broke affinity for irq 14 Apr 12 09:18:44 foo kernel: [117688.512639] Broke affinity for irq 16 Apr 12 09:18:44 foo kernel: [117688.512641] Broke affinity for irq 17 Apr 12 09:18:44 foo kernel: [117688.512643] Broke affinity for irq 51 Apr 12 09:18:44 foo kernel: [117688.512646] Broke affinity for irq 124 Apr 12 09:18:44 foo kernel: [117688.512662] Broke affinity for irq 125 Apr 12 09:18:44 foo kernel: [117688.512675] Broke affinity for irq 286 Apr 12 09:18:44 foo kernel: [117688.512678] Broke affinity for irq 287 Apr 12 09:18:44 foo kernel: [117688.513691] smpboot: CPU 3 is now offline Apr 12 09:18:44 foo kernel: [117688.528869] ACPI: Low-level resume complete Apr 12 09:18:44 foo kernel: [117688.529013] ACPI : EC: EC started Apr 12 09:18:44 foo kernel: [117688.529015] PM: Restoring platform NVS memory Apr 12 09:18:44 foo kernel: [117688.530041] Enabling non-boot CPUs ... Apr 12 09:18:44 foo kernel: [117688.550059] x86: Booting SMP configuration: Apr 12 09:18:44 foo kernel: [117688.550061] smpboot: Booting Node 0 Processor 1 APIC 0x2 Apr 12 09:18:44 foo kernel: [117688.553767] cache: parent cpu1 should not be sleeping Apr 12 09:18:44 foo kernel: [117688.554089] CPU1 is up Apr 12 09:18:44 foo kernel: [117688.574059] smpboot: Booting Node 0 Processor 2 APIC 0x1 Apr 12 09:18:44 foo kernel: [117688.577589] cache: parent cpu2 should not be sleeping Apr 12 09:18:44 foo kernel: [117688.577882] CPU2 is up Apr 12 09:18:44 foo kernel: [117688.598065] smpboot: Booting Node 0 Processor 3 APIC 0x3 Apr 12 09:18:44 foo kernel: [117688.601608] cache: parent cpu3 should not be sleeping Apr 12 09:18:44 foo kernel: [117688.601863] CPU3 is up Apr 12 09:18:44 foo kernel: [117688.610982] ACPI: Waking up from system sleep state S3 Apr 12 09:18:44 foo kernel: [117689.297865] pcieport 0000:01:00.0: System wakeup disabled by ACPI Apr 12 09:18:44 foo kernel: [117689.313509] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI Apr 12 09:18:44 foo kernel: [117689.313593] PM: noirq resume of devices complete after 31.541 msecs Apr 12 09:18:44 foo kernel: [117689.338646] PM: early resume of devices complete after 25.021 msecs Apr 12 09:18:44 foo kernel: [117689.339401] usb usb3: root hub lost power or was reset Apr 12 09:18:44 foo kernel: [117689.339402] usb usb4: root hub lost power or was reset Apr 12 09:18:44 foo kernel: [117689.340615] rtc_cmos 00:01: System wakeup disabled by ACPI Apr 12 09:18:44 foo kernel: [117689.379906] xhci_hcd 0000:00:14.0: port 2 resume PLC timeout Apr 12 09:18:44 foo kernel: [117689.558111] usb 2-1: reset SuperSpeed USB device number 4 using xhci_hcd Apr 12 09:18:44 foo kernel: [117689.629272] ------------[ cut here ]------------ Apr 12 09:18:44 foo kernel: [117689.629291] WARNING: CPU: 0 PID: 28780 at drivers/gpu/drm/i915/intel_pm.c:3553 skl_update_other_pipe_wm+0x147/0x150 [i915]() Apr 12 09:18:44 foo kernel: [117689.629292] WARN_ON(!wm_changed) Apr 12 09:18:44 foo kernel: [117689.629315] Modules linked in: nls_utf8 btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c drbg ansi_cprng ctr ccm xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_hda_codec_hdmi bnep binfmt_misc dell_led snd_hda_codec_realtek snd_hda_codec_generic hid_multitouch intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp arc4 kvm_intel kvm dell_laptop irqbypass dcdbas i2c_designware_platform nls_iso8859_1 dell_wmi crct10dif_pclmul i2c_designware_core sparse_keymap crc32_pclmul ghash_clmulni_intel snd_soc_skl iwlmvm snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp aesni_intel mac80211 snd_hda_ext_core aes_x86_64 lrw snd_soc_sst_match gf128mul snd_soc_core glue_helper ablk_helper cryptd snd_compress iwlwifi ac97_bus snd_pcm_dmaengine dw_dmac_core rtsx_pci_ms cfg80211 memstick pcspkr i915 snd_hda_intel snd_hda_codec snd_hda_core uvcvideo serio_raw snd_hwdep videobuf2_vmalloc snd_pcm videobuf2_memops videobuf2_v4l2 snd_timer videobuf2_core snd videodev i2c_i801 soundcore drm_kms_helper media drm joydev input_leds idma64 i2c_algo_bit virt_dma fb_sys_fops btusb mei_me syscopyarea btrtl sysfillrect mei sysimgblt shpchp processor_thermal_device intel_soc_dts_iosf intel_lpss_pci wmi hci_uart btbcm btqca btintel bluetooth video intel_lpss_acpi intel_lpss int3403_thermal int340x_thermal_zone int3400_thermal acpi_thermal_rel acpi_pad mac_hid acpi_als kfifo_buf industrialio parport_pc ppdev lp parport autofs4 hid_generic usbhid rtsx_pci_sdmmc psmouse rtsx_pci nvme i2c_hid hid pinctrl_sunrisepoint pinctrl_intel fjes Apr 12 09:18:44 foo kernel: [117689.629344] CPU: 0 PID: 28780 Comm: kworker/u8:79 Tainted: G U W 4.5.0intsusp #1 Apr 12 09:18:44 foo kernel: [117689.629345] Hardware name: Dell Inc. XPS 13 9350/07TYC2, BIOS 1.0.0 09/10/2015 Apr 12 09:18:44 foo kernel: [117689.629348] Workqueue: events_unbound async_run_entry_fn Apr 12 09:18:44 foo kernel: [117689.629350] 0000000000000286 00000000483a850d ffff88002422f948 ffffffff813d9213 Apr 12 09:18:44 foo kernel: [117689.629351] ffff88002422f990 ffffffffc05797f0 ffff88002422f980 ffffffff8107ebf2 Apr 12 09:18:44 foo kernel: [117689.629352] ffff8802b68ab000 ffff88002422fa0c ffff880036179bd4 ffff8802b52f0000 Apr 12 09:18:44 foo kernel: [117689.629353] Call Trace: Apr 12 09:18:44 foo kernel: [117689.629357] [] dump_stack+0x63/0x90 Apr 12 09:18:44 foo kernel: [117689.629359] [] warn_slowpath_common+0x82/0xc0 Apr 12 09:18:44 foo kernel: [117689.629360] [] warn_slowpath_fmt+0x5c/0x80 Apr 12 09:18:44 foo kernel: [117689.629370] [] skl_update_other_pipe_wm+0x147/0x150 [i915] Apr 12 09:18:44 foo kernel: [117689.629380] [] skl_update_wm+0x16a/0x5d0 [i915] Apr 12 09:18:44 foo kernel: [117689.629395] [] ? intel_ddi_enable_transcoder_func+0x17f/0x260 [i915] Apr 12 09:18:44 foo kernel: [117689.629405] [] intel_update_watermarks+0x1e/0x20 [i915] Apr 12 09:18:44 foo kernel: [117689.629419] [] haswell_crtc_enable+0x321/0x8c0 [i915] Apr 12 09:18:44 foo kernel: [117689.629433] [] intel_atomic_commit+0x73e/0x1880 [i915] Apr 12 09:18:44 foo kernel: [117689.629446] [] ? drm_atomic_check_only+0x181/0x600 [drm] Apr 12 09:18:44 foo kernel: [117689.629455] [] drm_atomic_commit+0x37/0x60 [drm] Apr 12 09:18:44 foo kernel: [117689.629469] [] intel_display_resume+0x10f/0x150 [i915] Apr 12 09:18:44 foo kernel: [117689.629477] [] i915_drm_resume+0xdd/0x170 [i915] Apr 12 09:18:44 foo kernel: [117689.629485] [] i915_pm_resume+0x25/0x30 [i915] Apr 12 09:18:44 foo kernel: [117689.629487] [] pci_pm_resume+0x64/0xa0 Apr 12 09:18:44 foo kernel: [117689.629488] [] ? pci_pm_thaw+0x90/0x90 Apr 12 09:18:44 foo kernel: [117689.629491] [] dpm_run_callback+0x4e/0x130 Apr 12 09:18:44 foo kernel: [117689.629492] [] device_resume+0xd3/0x1f0 Apr 12 09:18:44 foo kernel: [117689.629494] [] async_resume+0x1d/0x50 Apr 12 09:18:44 foo kernel: [117689.629495] [] async_run_entry_fn+0x48/0x150 Apr 12 09:18:44 foo kernel: [117689.629497] [] process_one_work+0x165/0x480 Apr 12 09:18:44 foo kernel: [117689.629498] [] worker_thread+0x4b/0x500 Apr 12 09:18:44 foo kernel: [117689.629499] [] ? process_one_work+0x480/0x480 Apr 12 09:18:44 foo kernel: [117689.629501] [] kthread+0xd8/0xf0 Apr 12 09:18:44 foo kernel: [117689.629502] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 09:18:44 foo kernel: [117689.629504] [] ret_from_fork+0x3f/0x70 Apr 12 09:18:44 foo kernel: [117689.629506] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 09:18:44 foo kernel: [117689.629514] ---[ end trace 3cc60a24822ab8da ]--- Apr 12 09:18:44 foo kernel: [117689.661666] usb 1-3: reset full-speed USB device number 3 using xhci_hcd Apr 12 09:18:44 foo kernel: [117689.669562] usb 3-1: reset full-speed USB device number 2 using xhci_hcd Apr 12 09:18:44 foo kernel: [117690.013969] usb 1-1: reset high-speed USB device number 12 using xhci_hcd Apr 12 09:18:44 foo kernel: [117690.194435] usb 2-1.1: reset SuperSpeed USB device number 5 using xhci_hcd Apr 12 09:18:44 foo kernel: [117690.366028] usb 1-5: reset high-speed USB device number 5 using xhci_hcd Apr 12 09:18:44 foo kernel: [117690.603233] restoring control 00000000-0000-0000-0000-000000000101/10/5 Apr 12 09:18:44 foo kernel: [117690.705713] [drm] RC6 on Apr 12 09:18:44 foo kernel: [117690.865717] usb 1-1.2: reset low-speed USB device number 14 using xhci_hcd Apr 12 09:18:44 foo kernel: [117691.278067] usb 1-1.1: reset high-speed USB device number 13 using xhci_hcd Apr 12 09:18:44 foo kernel: [117691.905987] usb 1-1.1.3: reset low-speed USB device number 15 using xhci_hcd Apr 12 09:18:44 foo kernel: [117692.246439] PM: resume of devices complete after 2907.747 msecs Apr 12 09:18:44 foo kernel: [117692.246519] usb 1-3:1.0: rebind failed: -517 Apr 12 09:18:44 foo kernel: [117692.246520] usb 1-3:1.1: rebind failed: -517 Apr 12 09:18:44 foo kernel: [117692.246752] PM: Finishing wakeup. Apr 12 09:18:44 foo kernel: [117692.246754] Restarting tasks ... Apr 12 09:18:44 foo kernel: [117692.246961] pci_bus 0000:02: Allocating resources Apr 12 09:18:44 foo kernel: [117692.247416] pci_bus 0000:02: Allocating resources Apr 12 09:18:44 foo systemd[1]: Time has been changed Apr 12 09:18:44 foo kernel: [117692.257731] done. Apr 12 09:18:44 foo rtkit-daemon[1286]: The canary thread is apparently starving. Taking action. Apr 12 09:18:44 foo systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 12 09:18:44 foo rtkit-daemon[1286]: Demoting known real-time threads. Apr 12 09:18:44 foo kernel: [117692.265038] Bluetooth: hci0: read Intel version: 370810011003110e00 Apr 12 09:18:44 foo kernel: [117692.265044] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq Apr 12 09:18:44 foo systemd[860]: Time has been changed Apr 12 09:18:44 foo rtkit-daemon[1286]: Successfully demoted thread 1301 of process 1285 (n/a). Apr 12 09:18:44 foo systemd[1067]: Time has been changed Apr 12 09:18:44 foo rtkit-daemon[1286]: Successfully demoted thread 1300 of process 1285 (n/a). Apr 12 09:18:44 foo rtkit-daemon[1286]: Successfully demoted thread 1285 of process 1285 (n/a). Apr 12 09:18:44 foo rtkit-daemon[1286]: Demoted 3 threads. Apr 12 09:18:44 foo systemd[1]: Started Load/Save RF Kill Switch Status. Apr 12 09:18:44 foo systemd[1]: bluetooth.target: Unit not needed anymore. Stopping. Apr 12 09:18:44 foo systemd[1]: Stopped target Bluetooth. Apr 12 09:18:44 foo systemd-sleep[28691]: System resumed. Apr 12 09:18:44 foo systemd[1]: Started Suspend. Apr 12 09:18:44 foo systemd[1]: sleep.target: Unit not needed anymore. Stopping. Apr 12 09:18:44 foo systemd[1]: Stopped target Sleep. Apr 12 09:18:44 foo systemd[1]: Reached target Suspend. Apr 12 09:18:44 foo systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too. Apr 12 09:18:44 foo systemd[1]: Stopped target Suspend. Apr 12 09:18:44 foo NetworkManager[678]: wake requested (sleeping: yes enabled: yes) Apr 12 09:18:44 foo kernel: [117692.292964] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 09:18:44 foo kernel: [117692.293218] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 09:18:44 foo kernel: [117692.293401] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 09:18:44 foo NetworkManager[678]: waking up... Apr 12 09:18:44 foo NetworkManager[678]: (wlp58s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Apr 12 09:18:44 foo systemd[1]: Started Run anacron jobs at resume. Apr 12 09:18:44 foo systemd[1]: Started Run anacron jobs. Apr 12 09:18:44 foo kernel: [117692.353298] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 09:18:44 foo kernel: [117692.353555] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 09:18:44 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 09:18:44 foo kernel: [117692.366723] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 09:18:44 foo NetworkManager[678]: (wlp58s0) supports 5 scan SSIDs Apr 12 09:18:44 foo NetworkManager[678]: (wlp58s0): supplicant interface state: starting -> ready Apr 12 09:18:44 foo NetworkManager[678]: (wlp58s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Apr 12 09:18:44 foo kernel: [117692.407466] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 09:18:44 foo kernel: [117692.505198] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated Apr 12 09:18:44 foo bluetoothd[683]: Failed to obtain handles for "Service Changed" characteristic Apr 12 09:18:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 09:18:44 foo bluetoothd[683]: Error adding Link Loss service Apr 12 09:18:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 09:18:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 09:18:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 09:18:44 foo bluetoothd[683]: Current Time Service could not be registered Apr 12 09:18:44 foo bluetoothd[683]: gatt-time-server: Input/output error (5) Apr 12 09:18:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 09:18:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 09:18:44 foo bluetoothd[683]: Sap driver initialization failed. Apr 12 09:18:44 foo bluetoothd[683]: sap-server: Operation not permitted (1) Apr 12 09:18:44 foo systemd[1]: Reached target Bluetooth. Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: ready -> inactive Apr 12 09:18:47 foo NetworkManager[678]: Auto-activating connection 'eyrie 1'. Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): Activation: starting connection 'eyrie 1' (409e1be3-0c73-4b85-a584-18582397aee8) Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Apr 12 09:18:47 foo NetworkManager[678]: NetworkManager state is now CONNECTING Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) access point 'eyrie 1' has security, but secrets are required. Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): device state change: config -> need-auth (reason 'none') [50 60 0] Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) connection 'eyrie 1' has security, and secrets exist. No new secrets needed. Apr 12 09:18:47 foo NetworkManager[678]: Config: added 'ssid' value 'eyrie' Apr 12 09:18:47 foo NetworkManager[678]: Config: added 'scan_ssid' value '1' Apr 12 09:18:47 foo NetworkManager[678]: Config: added 'key_mgmt' value 'WPA-PSK' Apr 12 09:18:47 foo NetworkManager[678]: Config: added 'auth_alg' value 'OPEN' Apr 12 09:18:47 foo NetworkManager[678]: Config: added 'psk' value '' Apr 12 09:18:47 foo NetworkManager[678]: Config: set interface ap_scan to 1 Apr 12 09:18:47 foo wpa_supplicant[776]: wlp58s0: SME: Trying to authenticate with e0:3f:49:9b:18:7a (SSID='eyrie' freq=2412 MHz) Apr 12 09:18:47 foo kernel: [117695.771434] wlp58s0: authenticate with e0:3f:49:9b:18:7a Apr 12 09:18:47 foo wpa_supplicant[776]: wlp58s0: Trying to associate with e0:3f:49:9b:18:7a (SSID='eyrie' freq=2412 MHz) Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: inactive -> associating Apr 12 09:18:47 foo kernel: [117695.774138] wlp58s0: send auth to e0:3f:49:9b:18:7a (try 1/3) Apr 12 09:18:47 foo kernel: [117695.775940] wlp58s0: authenticated Apr 12 09:18:47 foo kernel: [117695.777540] wlp58s0: associate with e0:3f:49:9b:18:7a (try 1/3) Apr 12 09:18:47 foo kernel: [117695.784729] wlp58s0: RX AssocResp from e0:3f:49:9b:18:7a (capab=0x411 status=0 aid=3) Apr 12 09:18:47 foo wpa_supplicant[776]: wlp58s0: Associated with e0:3f:49:9b:18:7a Apr 12 09:18:47 foo kernel: [117695.795262] wlp58s0: associated Apr 12 09:18:47 foo kernel: [117695.795321] IPv6: ADDRCONF(NETDEV_CHANGE): wlp58s0: link becomes ready Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associating -> associated Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associated -> 4-way handshake Apr 12 09:18:47 foo wpa_supplicant[776]: wlp58s0: WPA: Key negotiation completed with e0:3f:49:9b:18:7a [PTK=CCMP GTK=CCMP] Apr 12 09:18:47 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to e0:3f:49:9b:18:7a completed [id=0 id_str=] Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: 4-way handshake -> completed Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'eyrie'. Apr 12 09:18:47 foo NetworkManager[678]: (wlp58s0): device state change: config -> ip-config (reason 'none') [50 70 0] Apr 12 09:18:47 foo NetworkManager[678]: Activation (wlp58s0) Beginning DHCPv4 transaction (timeout in 45 seconds) Apr 12 09:18:48 foo NetworkManager[678]: dhclient started with pid 28826 Apr 12 09:18:48 foo dhclient[28826]: DHCPREQUEST of 192.168.1.103 on wlp58s0 to 255.255.255.255 port 67 Apr 12 09:18:49 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 09:18:49 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv6 for mDNS. Apr 12 09:18:49 foo avahi-daemon[635]: Registering new address record for fe80::de53:60ff:fecc:254a on wlp58s0.*. Apr 12 09:18:54 foo dhclient[28826]: DHCPREQUEST of 192.168.1.103 on wlp58s0 to 255.255.255.255 port 67 Apr 12 09:18:54 foo dhclient[28826]: DHCPACK of 192.168.1.103 from 192.168.1.1 Apr 12 09:18:54 foo NetworkManager[678]: address 192.168.1.103 Apr 12 09:18:54 foo NetworkManager[678]: plen 24 (255.255.255.0) Apr 12 09:18:54 foo NetworkManager[678]: gateway 192.168.1.1 Apr 12 09:18:54 foo NetworkManager[678]: server identifier 192.168.1.1 Apr 12 09:18:54 foo NetworkManager[678]: lease time 86400 Apr 12 09:18:54 foo NetworkManager[678]: hostname 'foo' Apr 12 09:18:54 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv4 with address 192.168.1.103. Apr 12 09:18:54 foo NetworkManager[678]: nameserver '192.168.1.1' Apr 12 09:18:54 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv4 for mDNS. Apr 12 09:18:54 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 09:18:54 foo avahi-daemon[635]: Registering new address record for 192.168.1.103 on wlp58s0.IPv4. Apr 12 09:18:54 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed unknown -> bound Apr 12 09:18:54 foo dhclient[28826]: bound to 192.168.1.103 -- renewal in 41586 seconds. Apr 12 09:18:54 foo NetworkManager[678]: (wlp58s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Apr 12 09:18:54 foo NetworkManager[678]: (wlp58s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Apr 12 09:18:54 foo NetworkManager[678]: (wlp58s0): device state change: secondaries -> activated (reason 'none') [90 100 0] Apr 12 09:18:54 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 09:18:54 foo NetworkManager[678]: NetworkManager state is now CONNECTED_GLOBAL Apr 12 09:18:54 foo NetworkManager[678]: Policy set 'eyrie 1' (wlp58s0) as default for IPv4 routing and DNS. Apr 12 09:18:54 foo dnsmasq[930]: reading /etc/resolv.conf Apr 12 09:18:54 foo dnsmasq[930]: using nameserver 192.168.1.1#53 Apr 12 09:18:54 foo NetworkManager[678]: (wlp58s0): Activation: successful, device activated. Apr 12 09:18:54 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 09:18:54 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 09:18:54 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 09:18:54 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 09:18:54 foo nm-dispatcher: #1 'up' [wlp58s0]: new request (1 scripts) Apr 12 09:18:54 foo nm-dispatcher: #1 'up' [wlp58s0]: start running ordered scripts... Apr 12 09:18:55 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 09:18:55 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 09:18:55 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 09:18:55 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 09:23:07 foo anacron[28211]: Job `cron.weekly' started Apr 12 09:23:07 foo anacron[29081]: Updated timestamp for job `cron.weekly' to 2016-04-12 Apr 12 09:23:08 foo anacron[28211]: Job `cron.weekly' terminated Apr 12 09:23:08 foo anacron[28211]: Normal exit (2 jobs run) Apr 12 09:31:11 foo wpa_supplicant[776]: wlp58s0: WPA: Group rekeying completed with e0:3f:49:9b:18:7a [GTK=CCMP] Apr 12 09:47:54 foo NetworkManager[678]: sleep requested (sleeping: no enabled: yes) Apr 12 09:47:54 foo NetworkManager[678]: sleeping... Apr 12 09:47:55 foo NetworkManager[678]: (wlp58s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37] Apr 12 09:47:55 foo NetworkManager[678]: (wlp58s0): canceled DHCP transaction, DHCP client pid 28826 Apr 12 09:47:55 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> done Apr 12 09:47:55 foo avahi-daemon[635]: Withdrawing address record for 192.168.1.103 on wlp58s0. Apr 12 09:47:55 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv4 with address 192.168.1.103. Apr 12 09:47:55 foo dnsmasq[930]: no servers found in /etc/resolv.conf, will retry Apr 12 09:47:55 foo kernel: [119442.910679] wlp58s0: deauthenticating from e0:3f:49:9b:18:7a by local choice (Reason: 3=DEAUTH_LEAVING) Apr 12 09:47:55 foo NetworkManager[678]: NetworkManager state is now ASLEEP Apr 12 09:47:55 foo avahi-daemon[635]: Interface wlp58s0.IPv4 no longer relevant for mDNS. Apr 12 09:47:55 foo avahi-daemon[635]: Withdrawing address record for fe80::de53:60ff:fecc:254a on wlp58s0. Apr 12 09:47:55 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 09:47:55 foo avahi-daemon[635]: Interface wlp58s0.IPv6 no longer relevant for mDNS. Apr 12 09:47:55 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-DISCONNECTED bssid=e0:3f:49:9b:18:7a reason=3 locally_generated=1 Apr 12 09:47:55 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 09:47:55 foo systemd[1]: Reached target Sleep. Apr 12 09:47:55 foo systemd[1]: Starting Suspend... Apr 12 09:47:55 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 09:47:55 foo systemd-sleep[29249]: Suspending system... Apr 12 09:47:55 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 09:47:55 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 09:47:55 foo nm-dispatcher: #1 'down' [wlp58s0]: new request (1 scripts) Apr 12 09:47:55 foo nm-dispatcher: #1 'down' [wlp58s0]: start running ordered scripts... Apr 12 13:08:07 foo kernel: [119442.981061] PM: Syncing filesystems ... done. Apr 12 13:08:07 foo kernel: [119442.996511] PM: Preparing system for sleep (mem) Apr 12 13:08:07 foo kernel: [119442.996955] Freezing user space processes ... (elapsed 0.004 seconds) done. Apr 12 13:08:07 foo kernel: [119443.001122] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Apr 12 13:08:07 foo kernel: [119443.002416] PM: Suspending system (mem) Apr 12 13:08:07 foo kernel: [119443.002437] Suspending console(s) (use no_console_suspend to debug) Apr 12 13:08:07 foo kernel: [119443.332455] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun Apr 12 13:08:07 foo kernel: [119443.355832] PM: suspend of devices complete after 339.915 msecs Apr 12 13:08:07 foo kernel: [119443.375952] PM: late suspend of devices complete after 20.115 msecs Apr 12 13:08:07 foo kernel: [119443.376309] pcieport 0000:01:00.0: System wakeup enabled by ACPI Apr 12 13:08:07 foo kernel: [119443.377352] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI Apr 12 13:08:07 foo kernel: [119443.407726] PM: noirq suspend of devices complete after 31.770 msecs Apr 12 13:08:07 foo kernel: [119443.407958] ACPI: Preparing to enter system sleep state S3 Apr 12 13:08:07 foo kernel: [119443.427883] ACPI : EC: EC stopped Apr 12 13:08:07 foo kernel: [119443.427884] PM: Saving platform NVS memory Apr 12 13:08:07 foo kernel: [119443.427901] Disabling non-boot CPUs ... Apr 12 13:08:07 foo kernel: [119443.429196] smpboot: CPU 1 is now offline Apr 12 13:08:07 foo kernel: [119443.440270] Broke affinity for irq 124 Apr 12 13:08:07 foo kernel: [119443.440301] Broke affinity for irq 286 Apr 12 13:08:07 foo kernel: [119443.441320] smpboot: CPU 2 is now offline Apr 12 13:08:07 foo kernel: [119443.452206] Broke affinity for irq 1 Apr 12 13:08:07 foo kernel: [119443.452209] Broke affinity for irq 8 Apr 12 13:08:07 foo kernel: [119443.452210] Broke affinity for irq 9 Apr 12 13:08:07 foo kernel: [119443.452212] Broke affinity for irq 12 Apr 12 13:08:07 foo kernel: [119443.452214] Broke affinity for irq 14 Apr 12 13:08:07 foo kernel: [119443.452216] Broke affinity for irq 16 Apr 12 13:08:07 foo kernel: [119443.452218] Broke affinity for irq 17 Apr 12 13:08:07 foo kernel: [119443.452221] Broke affinity for irq 51 Apr 12 13:08:07 foo kernel: [119443.452224] Broke affinity for irq 124 Apr 12 13:08:07 foo kernel: [119443.452226] Broke affinity for irq 125 Apr 12 13:08:07 foo kernel: [119443.452239] Broke affinity for irq 286 Apr 12 13:08:07 foo kernel: [119443.452241] Broke affinity for irq 287 Apr 12 13:08:07 foo kernel: [119443.453252] smpboot: CPU 3 is now offline Apr 12 13:08:07 foo kernel: [119443.474406] ACPI: Low-level resume complete Apr 12 13:08:07 foo kernel: [119443.474498] ACPI : EC: EC started Apr 12 13:08:07 foo kernel: [119443.474499] PM: Restoring platform NVS memory Apr 12 13:08:07 foo kernel: [119443.475309] Enabling non-boot CPUs ... Apr 12 13:08:07 foo kernel: [119443.495036] x86: Booting SMP configuration: Apr 12 13:08:07 foo kernel: [119443.495036] smpboot: Booting Node 0 Processor 1 APIC 0x2 Apr 12 13:08:07 foo kernel: [119443.497698] cache: parent cpu1 should not be sleeping Apr 12 13:08:07 foo kernel: [119443.497819] CPU1 is up Apr 12 13:08:07 foo kernel: [119443.515059] smpboot: Booting Node 0 Processor 2 APIC 0x1 Apr 12 13:08:07 foo kernel: [119443.517732] cache: parent cpu2 should not be sleeping Apr 12 13:08:07 foo kernel: [119443.517851] CPU2 is up Apr 12 13:08:07 foo kernel: [119443.535114] smpboot: Booting Node 0 Processor 3 APIC 0x3 Apr 12 13:08:07 foo kernel: [119443.537801] cache: parent cpu3 should not be sleeping Apr 12 13:08:07 foo kernel: [119443.537904] CPU3 is up Apr 12 13:08:07 foo kernel: [119443.541454] ACPI: Waking up from system sleep state S3 Apr 12 13:08:07 foo kernel: [119444.384230] pcieport 0000:01:00.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.385889] pcieport 0000:02:00.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.385890] pcieport 0000:02:01.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.389214] pcieport 0000:02:02.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.406851] xhci_hcd 0000:39:00.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.468201] pcieport 0000:01:00.0: System wakeup disabled by ACPI Apr 12 13:08:07 foo kernel: [119444.468259] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI Apr 12 13:08:07 foo kernel: [119444.482855] xhci_hcd 0000:39:00.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.482890] PM: noirq resume of devices complete after 99.423 msecs Apr 12 13:08:07 foo kernel: [119444.487326] PM: early resume of devices complete after 4.405 msecs Apr 12 13:08:07 foo kernel: [119444.487565] usb usb1: root hub lost power or was reset Apr 12 13:08:07 foo kernel: [119444.487567] usb usb2: root hub lost power or was reset Apr 12 13:08:07 foo kernel: [119444.490275] rtc_cmos 00:01: System wakeup disabled by ACPI Apr 12 13:08:07 foo kernel: [119444.502820] xhci_hcd 0000:39:00.0: Refused to change power state, currently in D3 Apr 12 13:08:07 foo kernel: [119444.502865] xhci_hcd 0000:39:00.0: WARN: xHC restore state timeout Apr 12 13:08:07 foo kernel: [119444.502867] xhci_hcd 0000:39:00.0: PCI post-resume error -110! Apr 12 13:08:07 foo kernel: [119444.502867] xhci_hcd 0000:39:00.0: HC died; cleaning up Apr 12 13:08:07 foo kernel: [119444.502869] xhci_hcd 0000:39:00.0: HC died; cleaning up Apr 12 13:08:07 foo kernel: [119444.502875] dpm_run_callback(): pci_pm_resume+0x0/0xa0 returns -110 Apr 12 13:08:07 foo kernel: [119444.502878] PM: Device 0000:39:00.0 failed to resume async: error -110 Apr 12 13:08:07 foo kernel: [119444.766577] ------------[ cut here ]------------ Apr 12 13:08:07 foo kernel: [119444.766596] WARNING: CPU: 1 PID: 29311 at drivers/gpu/drm/i915/intel_pm.c:3553 skl_update_other_pipe_wm+0x147/0x150 [i915]() Apr 12 13:08:07 foo kernel: [119444.766596] WARN_ON(!wm_changed) Apr 12 13:08:07 foo kernel: [119444.766620] Modules linked in: nls_utf8 btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c drbg ansi_cprng ctr ccm xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_hda_codec_hdmi bnep binfmt_misc dell_led snd_hda_codec_realtek snd_hda_codec_generic hid_multitouch intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp arc4 kvm_intel kvm dell_laptop irqbypass dcdbas i2c_designware_platform nls_iso8859_1 dell_wmi crct10dif_pclmul i2c_designware_core sparse_keymap crc32_pclmul ghash_clmulni_intel snd_soc_skl iwlmvm snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp aesni_intel mac80211 snd_hda_ext_core aes_x86_64 lrw snd_soc_sst_match gf128mul snd_soc_core glue_helper ablk_helper cryptd snd_compress iwlwifi ac97_bus snd_pcm_dmaengine dw_dmac_core rtsx_pci_ms cfg80211 memstick pcspkr i915 snd_hda_intel snd_hda_codec snd_hda_core uvcvideo serio_raw snd_hwdep videobuf2_vmalloc snd_pcm videobuf2_memops videobuf2_v4l2 snd_timer videobuf2_core snd videodev i2c_i801 soundcore drm_kms_helper media drm joydev input_leds idma64 i2c_algo_bit virt_dma fb_sys_fops btusb mei_me syscopyarea btrtl sysfillrect mei sysimgblt shpchp processor_thermal_device intel_soc_dts_iosf intel_lpss_pci wmi hci_uart btbcm btqca btintel bluetooth video intel_lpss_acpi intel_lpss int3403_thermal int340x_thermal_zone int3400_thermal acpi_thermal_rel acpi_pad mac_hid acpi_als kfifo_buf industrialio parport_pc ppdev lp parport autofs4 hid_generic usbhid rtsx_pci_sdmmc psmouse rtsx_pci nvme i2c_hid hid pinctrl_sunrisepoint pinctrl_intel fjes Apr 12 13:08:07 foo kernel: [119444.766650] CPU: 1 PID: 29311 Comm: kworker/u8:46 Tainted: G U W 4.5.0intsusp #1 Apr 12 13:08:07 foo kernel: [119444.766651] Hardware name: Dell Inc. XPS 13 9350/07TYC2, BIOS 1.0.0 09/10/2015 Apr 12 13:08:07 foo kernel: [119444.766654] Workqueue: events_unbound async_run_entry_fn Apr 12 13:08:07 foo kernel: [119444.766656] 0000000000000286 00000000c279b6c0 ffff88024da0f948 ffffffff813d9213 Apr 12 13:08:07 foo kernel: [119444.766657] ffff88024da0f990 ffffffffc05797f0 ffff88024da0f980 ffffffff8107ebf2 Apr 12 13:08:07 foo kernel: [119444.766658] ffff8802b68ab000 ffff88024da0fa0c ffff880036179bd4 ffff8802b52f0000 Apr 12 13:08:07 foo kernel: [119444.766658] Call Trace: Apr 12 13:08:07 foo kernel: [119444.766661] [] dump_stack+0x63/0x90 Apr 12 13:08:07 foo kernel: [119444.766663] [] warn_slowpath_common+0x82/0xc0 Apr 12 13:08:07 foo kernel: [119444.766665] [] warn_slowpath_fmt+0x5c/0x80 Apr 12 13:08:07 foo kernel: [119444.766675] [] skl_update_other_pipe_wm+0x147/0x150 [i915] Apr 12 13:08:07 foo kernel: [119444.766684] [] skl_update_wm+0x16a/0x5d0 [i915] Apr 12 13:08:07 foo kernel: [119444.766699] [] ? intel_ddi_enable_transcoder_func+0x17f/0x260 [i915] Apr 12 13:08:07 foo kernel: [119444.766708] [] intel_update_watermarks+0x1e/0x20 [i915] Apr 12 13:08:07 foo kernel: [119444.766723] [] haswell_crtc_enable+0x321/0x8c0 [i915] Apr 12 13:08:07 foo kernel: [119444.766736] [] intel_atomic_commit+0x73e/0x1880 [i915] Apr 12 13:08:07 foo kernel: [119444.766749] [] ? drm_atomic_check_only+0x181/0x600 [drm] Apr 12 13:08:07 foo kernel: [119444.766758] [] drm_atomic_commit+0x37/0x60 [drm] Apr 12 13:08:07 foo kernel: [119444.766772] [] intel_display_resume+0x10f/0x150 [i915] Apr 12 13:08:07 foo kernel: [119444.766781] [] i915_drm_resume+0xdd/0x170 [i915] Apr 12 13:08:07 foo kernel: [119444.766789] [] i915_pm_resume+0x25/0x30 [i915] Apr 12 13:08:07 foo kernel: [119444.766791] [] pci_pm_resume+0x64/0xa0 Apr 12 13:08:07 foo kernel: [119444.766792] [] ? pci_pm_thaw+0x90/0x90 Apr 12 13:08:07 foo kernel: [119444.766795] [] dpm_run_callback+0x4e/0x130 Apr 12 13:08:07 foo kernel: [119444.766796] [] device_resume+0xd3/0x1f0 Apr 12 13:08:07 foo kernel: [119444.766798] [] async_resume+0x1d/0x50 Apr 12 13:08:07 foo kernel: [119444.766799] [] async_run_entry_fn+0x48/0x150 Apr 12 13:08:07 foo kernel: [119444.766800] [] process_one_work+0x165/0x480 Apr 12 13:08:07 foo kernel: [119444.766802] [] worker_thread+0x4b/0x500 Apr 12 13:08:07 foo kernel: [119444.766803] [] ? process_one_work+0x480/0x480 Apr 12 13:08:07 foo kernel: [119444.766804] [] kthread+0xd8/0xf0 Apr 12 13:08:07 foo kernel: [119444.766806] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 13:08:07 foo kernel: [119444.766808] [] ret_from_fork+0x3f/0x70 Apr 12 13:08:07 foo kernel: [119444.766810] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 13:08:07 foo kernel: [119444.766817] ---[ end trace 3cc60a24822ab8db ]--- Apr 12 13:08:07 foo kernel: [119444.874974] usb 1-1: reset high-speed USB device number 12 using xhci_hcd Apr 12 13:08:07 foo kernel: [119445.059120] usb 1-1: device firmware changed Apr 12 13:08:07 foo kernel: [119445.227085] usb 1-3: reset full-speed USB device number 3 using xhci_hcd Apr 12 13:08:07 foo kernel: [119445.579055] usb 1-5: reset high-speed USB device number 5 using xhci_hcd Apr 12 13:08:07 foo kernel: [119445.723253] [drm] RC6 on Apr 12 13:08:07 foo kernel: [119445.815008] restoring control 00000000-0000-0000-0000-000000000101/10/5 Apr 12 13:08:07 foo kernel: [119446.992237] PM: resume of devices complete after 2504.870 msecs Apr 12 13:08:07 foo kernel: [119446.992338] usb 1-3:1.0: rebind failed: -517 Apr 12 13:08:07 foo kernel: [119446.992340] usb 1-3:1.1: rebind failed: -517 Apr 12 13:08:07 foo kernel: [119446.992590] PM: Finishing wakeup. Apr 12 13:08:07 foo kernel: [119446.992591] Restarting tasks ... Apr 12 13:08:07 foo kernel: [119446.992603] xhci_hcd 0000:39:00.0: remove, state 4 Apr 12 13:08:07 foo kernel: [119446.992610] usb usb4: USB disconnect, device number 1 Apr 12 13:08:07 foo kernel: [119446.992734] usb 1-1: USB disconnect, device number 12 Apr 12 13:08:07 foo kernel: [119446.992738] usb 1-1.1: USB disconnect, device number 13 Apr 12 13:08:07 foo kernel: [119446.992740] usb 1-1.1.3: USB disconnect, device number 15 Apr 12 13:08:07 foo kernel: [119446.997671] usb 2-1.1: USB disconnect, device number 5 Apr 12 13:08:07 foo kernel: [119446.997995] usb 2-1: USB disconnect, device number 4 Apr 12 13:08:07 foo kernel: [119446.998576] usb 3-1: USB disconnect, device number 2 Apr 12 13:08:07 foo kernel: [119447.001808] xhci_hcd 0000:39:00.0: Host not halted after 16000 microseconds. Apr 12 13:08:07 foo kernel: [119447.003090] done. Apr 12 13:08:07 foo kernel: [119447.003345] usb 1-1.2: USB disconnect, device number 14 Apr 12 13:08:07 foo kernel: [119447.006704] xhci_hcd 0000:39:00.0: USB bus 4 deregistered Apr 12 13:08:07 foo kernel: [119447.006715] xhci_hcd 0000:39:00.0: remove, state 4 Apr 12 13:08:07 foo kernel: [119447.006722] usb usb3: USB disconnect, device number 1 Apr 12 13:08:07 foo kernel: [119447.007085] xhci_hcd 0000:39:00.0: USB bus 3 deregistered Apr 12 13:08:07 foo kernel: [119447.014330] pci_bus 0000:03: busn_res: [bus 03] is released Apr 12 13:08:07 foo kernel: [119447.014397] pci_bus 0000:04: busn_res: [bus 04-38] is released Apr 12 13:08:07 foo systemd[1]: Time has been changed Apr 12 13:08:07 foo systemd[860]: Time has been changed Apr 12 13:08:07 foo systemd[1067]: Time has been changed Apr 12 13:08:07 foo systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 12 13:08:07 foo systemd[1]: bluetooth.target: Unit not needed anymore. Stopping. Apr 12 13:08:07 foo systemd[1]: Stopped target Bluetooth. Apr 12 13:08:07 foo systemd[1]: Started Load/Save RF Kill Switch Status. Apr 12 13:08:07 foo kernel: [119447.030921] pci_bus 0000:39: busn_res: [bus 39] is released Apr 12 13:08:07 foo kernel: [119447.030998] pci_bus 0000:02: busn_res: [bus 02-39] is released Apr 12 13:08:07 foo systemd-sleep[29249]: System resumed. Apr 12 13:08:07 foo systemd[1]: Started Suspend. Apr 12 13:08:07 foo systemd[1]: sleep.target: Unit not needed anymore. Stopping. Apr 12 13:08:07 foo systemd[1]: Stopped target Sleep. Apr 12 13:08:07 foo systemd[1]: Reached target Suspend. Apr 12 13:08:07 foo kernel: [119447.056513] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 13:08:07 foo kernel: [119447.056635] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 13:08:07 foo kernel: [119447.056821] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 13:08:07 foo NetworkManager[678]: wake requested (sleeping: yes enabled: yes) Apr 12 13:08:07 foo NetworkManager[678]: waking up... Apr 12 13:08:07 foo NetworkManager[678]: (wlp58s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Apr 12 13:08:07 foo systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too. Apr 12 13:08:07 foo systemd[1]: Stopped target Suspend. Apr 12 13:08:07 foo systemd[1]: Started Run anacron jobs at resume. Apr 12 13:08:07 foo systemd[1]: Started Run anacron jobs. Apr 12 13:08:07 foo anacron[29385]: Anacron 2.3 started on 2016-04-12 Apr 12 13:08:07 foo anacron[29385]: Normal exit (0 jobs run) Apr 12 13:08:07 foo kernel: [119447.119234] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 13:08:07 foo kernel: [119447.119423] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 13:08:07 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 13:08:07 foo kernel: [119447.132598] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 13:08:07 foo NetworkManager[678]: (wlp58s0) supports 5 scan SSIDs Apr 12 13:08:07 foo NetworkManager[678]: (wlp58s0): supplicant interface state: starting -> ready Apr 12 13:08:07 foo NetworkManager[678]: (wlp58s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Apr 12 13:08:07 foo kernel: [119447.173399] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 13:08:07 foo kernel: [119447.202877] usb 1-1: new high-speed USB device number 16 using xhci_hcd Apr 12 13:08:07 foo kernel: [119447.387362] usb 1-1: New USB device found, idVendor=1a40, idProduct=0101 Apr 12 13:08:07 foo kernel: [119447.387366] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 12 13:08:07 foo kernel: [119447.387386] usb 1-1: Product: USB 2.0 Hub Apr 12 13:08:07 foo kernel: [119447.387889] hub 1-1:1.0: USB hub found Apr 12 13:08:07 foo kernel: [119447.387948] hub 1-1:1.0: 4 ports detected Apr 12 13:08:07 foo kernel: [119447.410754] Bluetooth: hci0: read Intel version: 370810011003110e00 Apr 12 13:08:07 foo kernel: [119447.410796] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq Apr 12 13:08:07 foo kernel: [119447.661863] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated Apr 12 13:08:07 foo kernel: [119447.674917] usb 1-1.1: new low-speed USB device number 17 using xhci_hcd Apr 12 13:08:07 foo bluetoothd[683]: Failed to obtain handles for "Service Changed" characteristic Apr 12 13:08:07 foo bluetoothd[683]: Not enough free handles to register service Apr 12 13:08:07 foo bluetoothd[683]: Error adding Link Loss service Apr 12 13:08:07 foo bluetoothd[683]: Not enough free handles to register service Apr 12 13:08:07 foo bluetoothd[683]: Not enough free handles to register service Apr 12 13:08:07 foo bluetoothd[683]: Not enough free handles to register service Apr 12 13:08:07 foo bluetoothd[683]: Current Time Service could not be registered Apr 12 13:08:07 foo bluetoothd[683]: gatt-time-server: Input/output error (5) Apr 12 13:08:07 foo bluetoothd[683]: Not enough free handles to register service Apr 12 13:08:07 foo bluetoothd[683]: Not enough free handles to register service Apr 12 13:08:07 foo bluetoothd[683]: Sap driver initialization failed. Apr 12 13:08:07 foo bluetoothd[683]: sap-server: Operation not permitted (1) Apr 12 13:08:07 foo systemd[1]: Reached target Bluetooth. Apr 12 13:08:08 foo kernel: [119447.788424] usb 1-1.1: New USB device found, idVendor=04ca, idProduct=005b Apr 12 13:08:08 foo kernel: [119447.788427] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 13:08:08 foo kernel: [119447.788428] usb 1-1.1: Product: Goldtouch USB Keyboard Apr 12 13:08:08 foo kernel: [119447.788429] usb 1-1.1: Manufacturer: Lite-On Technology Corp. Apr 12 13:08:08 foo kernel: [119447.792997] input: Lite-On Technology Corp. Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1:1.0/0003:04CA:005B.000D/input/input48 Apr 12 13:08:08 foo kernel: [119447.847345] hid-generic 0003:04CA:005B.000D: input,hidraw0: USB HID v1.10 Keyboard [Lite-On Technology Corp. Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1/input0 Apr 12 13:08:08 foo kernel: [119447.852881] input: Lite-On Technology Corp. Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1:1.1/0003:04CA:005B.000E/input/input49 Apr 12 13:08:08 foo kernel: [119447.907722] hid-generic 0003:04CA:005B.000E: input,hiddev0,hidraw1: USB HID v1.10 Device [Lite-On Technology Corp. Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1/input1 Apr 12 13:08:08 foo kernel: [119447.998888] usb 1-1.3: new low-speed USB device number 18 using xhci_hcd Apr 12 13:08:08 foo kernel: [119448.111091] usb 1-1.3: New USB device found, idVendor=047d, idProduct=2048 Apr 12 13:08:08 foo kernel: [119448.111094] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 13:08:08 foo kernel: [119448.111095] usb 1-1.3: Product: Kensington Eagle Trackball Apr 12 13:08:08 foo kernel: [119448.111096] usb 1-1.3: Manufacturer: Primax Apr 12 13:08:08 foo kernel: [119448.116194] input: Primax Kensington Eagle Trackball as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.3/1-1.3:1.0/0003:047D:2048.000F/input/input50 Apr 12 13:08:08 foo kernel: [119448.116603] hid-generic 0003:047D:2048.000F: input,hidraw2: USB HID v1.11 Mouse [Primax Kensington Eagle Trackball] on usb-0000:00:14.0-1.3/input0 Apr 12 13:08:08 foo kernel: [119448.203058] usb 1-1.4: new low-speed USB device number 19 using xhci_hcd Apr 12 13:08:08 foo kernel: [119448.315431] usb 1-1.4: New USB device found, idVendor=24f0, idProduct=0137 Apr 12 13:08:08 foo kernel: [119448.315434] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 13:08:08 foo kernel: [119448.315435] usb 1-1.4: Product: Das Keyboard Model S Apr 12 13:08:08 foo kernel: [119448.315437] usb 1-1.4: Manufacturer: Das Keyboard Model S Apr 12 13:08:08 foo kernel: [119448.337249] input: Das Keyboard Model S Das Keyboard Model S as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.4/1-1.4:1.0/0003:24F0:0137.0010/input/input51 Apr 12 13:08:08 foo kernel: [119448.391199] hid-generic 0003:24F0:0137.0010: input,hidraw4: USB HID v1.10 Keyboard [Das Keyboard Model S Das Keyboard Model S] on usb-0000:00:14.0-1.4/input0 Apr 12 13:08:08 foo kernel: [119448.404548] input: Das Keyboard Model S Das Keyboard Model S as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.4/1-1.4:1.1/0003:24F0:0137.0011/input/input52 Apr 12 13:08:08 foo kernel: [119448.459130] hid-generic 0003:24F0:0137.0011: input,hidraw5: USB HID v1.10 Device [Das Keyboard Model S Das Keyboard Model S] on usb-0000:00:14.0-1.4/input1 Apr 12 13:08:08 foo mtp-probe: checking bus 1, device 19: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.4" Apr 12 13:08:08 foo mtp-probe: checking bus 1, device 18: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.3" Apr 12 13:08:08 foo mtp-probe: checking bus 1, device 17: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1" Apr 12 13:08:08 foo mtp-probe: bus: 1, device: 18 was not an MTP device Apr 12 13:08:08 foo mtp-probe: bus: 1, device: 17 was not an MTP device Apr 12 13:08:08 foo mtp-probe: bus: 1, device: 19 was not an MTP device Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): supplicant interface state: ready -> inactive Apr 12 13:08:10 foo NetworkManager[678]: Auto-activating connection 'eduroam'. Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): Activation: starting connection 'eduroam' (d2eafde8-5191-4378-91ae-92c47e774947) Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Apr 12 13:08:10 foo NetworkManager[678]: NetworkManager state is now CONNECTING Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) access point 'eduroam' has security, but secrets are required. Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): device state change: config -> need-auth (reason 'none') [50 60 0] Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) connection 'eduroam' has security, and secrets exist. No new secrets needed. Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'ssid' value 'eduroam' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'scan_ssid' value '1' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'key_mgmt' value 'WPA-EAP' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'password' value '' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'eap' value 'TTLS' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'fragment_size' value '1266' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'phase2' value 'auth=PAP' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'identity' value 'dcw2131' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'bgscan' value 'simple:30:-65:300' Apr 12 13:08:10 foo NetworkManager[678]: Config: added 'proactive_key_caching' value '1' Apr 12 13:08:10 foo NetworkManager[678]: Config: set interface ap_scan to 1 Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: SME: Trying to authenticate with d8:c7:c8:3e:58:62 (SSID='eduroam' freq=2437 MHz) Apr 12 13:08:10 foo kernel: [119450.340366] wlp58s0: authenticate with d8:c7:c8:3e:58:62 Apr 12 13:08:10 foo kernel: [119450.342650] wlp58s0: send auth to d8:c7:c8:3e:58:62 (try 1/3) Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: Trying to associate with d8:c7:c8:3e:58:62 (SSID='eduroam' freq=2437 MHz) Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): supplicant interface state: inactive -> associating Apr 12 13:08:10 foo kernel: [119450.344702] wlp58s0: authenticated Apr 12 13:08:10 foo kernel: [119450.346953] wlp58s0: associate with d8:c7:c8:3e:58:62 (try 1/3) Apr 12 13:08:10 foo kernel: [119450.350189] wlp58s0: RX AssocResp from d8:c7:c8:3e:58:62 (capab=0x431 status=0 aid=2) Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: Associated with d8:c7:c8:3e:58:62 Apr 12 13:08:10 foo kernel: [119450.351098] wlp58s0: associated Apr 12 13:08:10 foo kernel: [119450.351144] IPv6: ADDRCONF(NETDEV_CHANGE): wlp58s0: link becomes ready Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-STARTED EAP authentication started Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associating -> associated Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=4 -> NAK Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21 Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root' Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root' Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority' Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=US/ST=MI/L=Ann Arbor/O=Internet2/OU=InCommon/CN=InCommon RSA Server CA' Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=US/ST=NY/L=New York/O=Columbia University/OU=Information Technology/CN=radius.cc.columbia.edu' Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associated -> 4-way handshake Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: WPA: Key negotiation completed with d8:c7:c8:3e:58:62 [PTK=CCMP GTK=CCMP] Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to d8:c7:c8:3e:58:62 completed [id=0 id_str=] Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): supplicant interface state: 4-way handshake -> completed Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'eduroam'. Apr 12 13:08:10 foo NetworkManager[678]: (wlp58s0): device state change: config -> ip-config (reason 'none') [50 70 0] Apr 12 13:08:10 foo NetworkManager[678]: Activation (wlp58s0) Beginning DHCPv4 transaction (timeout in 45 seconds) Apr 12 13:08:10 foo NetworkManager[678]: dhclient started with pid 29506 Apr 12 13:08:10 foo dhclient[29506]: DHCPDISCOVER on wlp58s0 to 255.255.255.255 port 67 interval 7 Apr 12 13:08:10 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-47 noise=9999 txrate=144400 Apr 12 13:08:11 foo dhclient[29506]: DHCPREQUEST of 160.39.10.34 on wlp58s0 to 255.255.255.255 port 67 Apr 12 13:08:11 foo dhclient[29506]: DHCPOFFER of 160.39.10.34 from 160.39.10.2 Apr 12 13:08:11 foo dhclient[29506]: DHCPACK of 160.39.10.34 from 160.39.10.2 Apr 12 13:08:11 foo NetworkManager[678]: address 160.39.10.34 Apr 12 13:08:11 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 13:08:11 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 13:08:11 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 13:08:11 foo NetworkManager[678]: lease time 1800 Apr 12 13:08:11 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 13:08:11 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 13:08:11 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv4 with address 160.39.10.34. Apr 12 13:08:11 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 13:08:11 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv4 for mDNS. Apr 12 13:08:11 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 13:08:11 foo avahi-daemon[635]: Registering new address record for 160.39.10.34 on wlp58s0.IPv4. Apr 12 13:08:11 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed unknown -> bound Apr 12 13:08:11 foo NetworkManager[678]: (wlp58s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Apr 12 13:08:11 foo NetworkManager[678]: (wlp58s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Apr 12 13:08:11 foo NetworkManager[678]: (wlp58s0): device state change: secondaries -> activated (reason 'none') [90 100 0] Apr 12 13:08:11 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 13:08:11 foo dhclient[29506]: bound to 160.39.10.34 -- renewal in 754 seconds. Apr 12 13:08:11 foo NetworkManager[678]: NetworkManager state is now CONNECTED_GLOBAL Apr 12 13:08:11 foo NetworkManager[678]: Policy set 'eduroam' (wlp58s0) as default for IPv4 routing and DNS. Apr 12 13:08:11 foo NetworkManager[678]: (wlp58s0): Activation: successful, device activated. Apr 12 13:08:11 foo dnsmasq[930]: reading /etc/resolv.conf Apr 12 13:08:11 foo dnsmasq[930]: using nameserver 128.59.1.3#53 Apr 12 13:08:11 foo dnsmasq[930]: using nameserver 128.59.1.4#53 Apr 12 13:08:11 foo nm-dispatcher: #2 'up' [wlp58s0]: new request (1 scripts) Apr 12 13:08:11 foo nm-dispatcher: #2 'up' [wlp58s0]: start running ordered scripts... Apr 12 13:08:11 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 13:08:11 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 13:08:12 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 13:08:12 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 13:08:12 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 13:08:12 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv6 for mDNS. Apr 12 13:08:12 foo avahi-daemon[635]: Registering new address record for fe80::de53:60ff:fecc:254a on wlp58s0.*. Apr 12 13:09:01 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 13:09:31 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 13:17:01 foo CRON[29762]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Apr 12 13:20:45 foo dhclient[29506]: DHCPREQUEST of 160.39.10.34 on wlp58s0 to 128.59.1.23 port 67 Apr 12 13:20:45 foo dhclient[29506]: DHCPACK of 160.39.10.34 from 128.59.1.23 Apr 12 13:20:45 foo NetworkManager[678]: address 160.39.10.34 Apr 12 13:20:45 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 13:20:45 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 13:20:45 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 13:20:45 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 13:20:45 foo NetworkManager[678]: lease time 1800 Apr 12 13:20:45 foo dhclient[29506]: bound to 160.39.10.34 -- renewal in 891 seconds. Apr 12 13:20:45 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 13:20:45 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 13:20:45 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 13:20:45 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 13:20:45 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 13:20:45 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 13:20:45 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 13:20:45 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 13:20:45 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 13:20:45 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 13:35:36 foo dhclient[29506]: DHCPREQUEST of 160.39.10.34 on wlp58s0 to 128.59.1.23 port 67 Apr 12 13:35:36 foo dhclient[29506]: DHCPACK of 160.39.10.34 from 128.59.1.23 Apr 12 13:35:36 foo NetworkManager[678]: address 160.39.10.34 Apr 12 13:35:36 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 13:35:36 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 13:35:36 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 13:35:36 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 13:35:36 foo dhclient[29506]: bound to 160.39.10.34 -- renewal in 818 seconds. Apr 12 13:35:36 foo NetworkManager[678]: lease time 1800 Apr 12 13:35:36 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 13:35:36 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 13:35:36 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 13:35:36 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 13:35:36 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 13:35:36 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 13:35:36 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 13:35:36 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 13:35:36 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 13:35:36 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 13:41:21 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 13:41:52 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 13:42:15 foo systemd-timesyncd[562]: Synchronized to time server 52.0.56.137:123 (0.debian.pool.ntp.org). Apr 12 13:49:14 foo dhclient[29506]: DHCPREQUEST of 160.39.10.34 on wlp58s0 to 128.59.1.23 port 67 Apr 12 13:49:14 foo dhclient[29506]: DHCPACK of 160.39.10.34 from 128.59.1.23 Apr 12 13:49:14 foo NetworkManager[678]: address 160.39.10.34 Apr 12 13:49:14 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 13:49:14 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 13:49:14 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 13:49:14 foo NetworkManager[678]: lease time 1800 Apr 12 13:49:14 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 13:49:14 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 13:49:14 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 13:49:14 foo dhclient[29506]: bound to 160.39.10.34 -- renewal in 855 seconds. Apr 12 13:49:14 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 13:49:14 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 13:49:14 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 13:49:14 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 13:49:14 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 13:49:14 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 13:49:14 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 13:49:14 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 13:58:01 foo NetworkManager[678]: sleep requested (sleeping: no enabled: yes) Apr 12 13:58:01 foo NetworkManager[678]: sleeping... Apr 12 13:58:01 foo NetworkManager[678]: (wlp58s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37] Apr 12 13:58:01 foo NetworkManager[678]: (wlp58s0): canceled DHCP transaction, DHCP client pid 29506 Apr 12 13:58:01 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> done Apr 12 13:58:01 foo kernel: [122441.326019] wlp58s0: deauthenticating from d8:c7:c8:3e:58:62 by local choice (Reason: 3=DEAUTH_LEAVING) Apr 12 13:58:01 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-DISCONNECTED bssid=d8:c7:c8:3e:58:62 reason=3 locally_generated=1 Apr 12 13:58:01 foo NetworkManager[678]: NetworkManager state is now ASLEEP Apr 12 13:58:01 foo avahi-daemon[635]: Withdrawing address record for 160.39.10.34 on wlp58s0. Apr 12 13:58:01 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv4 with address 160.39.10.34. Apr 12 13:58:01 foo dnsmasq[930]: no servers found in /etc/resolv.conf, will retry Apr 12 13:58:01 foo avahi-daemon[635]: Interface wlp58s0.IPv4 no longer relevant for mDNS. Apr 12 13:58:01 foo avahi-daemon[635]: Withdrawing address record for fe80::de53:60ff:fecc:254a on wlp58s0. Apr 12 13:58:01 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 13:58:01 foo avahi-daemon[635]: Interface wlp58s0.IPv6 no longer relevant for mDNS. Apr 12 13:58:01 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 13:58:01 foo systemd[1]: Reached target Sleep. Apr 12 13:58:01 foo systemd[1]: Starting Suspend... Apr 12 13:58:01 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 13:58:01 foo systemd-sleep[30005]: Suspending system... Apr 12 16:08:05 foo kernel: [122441.384565] PM: Syncing filesystems ... done. Apr 12 16:08:05 foo kernel: [122441.423120] PM: Preparing system for sleep (mem) Apr 12 16:08:05 foo kernel: [122441.423695] Freezing user space processes ... (elapsed 0.001 seconds) done. Apr 12 16:08:05 foo kernel: [122441.425555] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Apr 12 16:08:05 foo kernel: [122441.426828] PM: Suspending system (mem) Apr 12 16:08:05 foo kernel: [122441.426845] Suspending console(s) (use no_console_suspend to debug) Apr 12 16:08:05 foo kernel: [122441.756349] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun Apr 12 16:08:05 foo kernel: [122441.780183] PM: suspend of devices complete after 340.871 msecs Apr 12 16:08:05 foo kernel: [122441.799086] PM: late suspend of devices complete after 18.901 msecs Apr 12 16:08:05 foo kernel: [122441.800252] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI Apr 12 16:08:05 foo kernel: [122441.831028] PM: noirq suspend of devices complete after 31.940 msecs Apr 12 16:08:05 foo kernel: [122441.831260] ACPI: Preparing to enter system sleep state S3 Apr 12 16:08:05 foo kernel: [122441.851194] ACPI : EC: EC stopped Apr 12 16:08:05 foo kernel: [122441.851194] PM: Saving platform NVS memory Apr 12 16:08:05 foo kernel: [122441.851212] Disabling non-boot CPUs ... Apr 12 16:08:05 foo kernel: [122441.852509] smpboot: CPU 1 is now offline Apr 12 16:08:05 foo kernel: [122441.863551] Broke affinity for irq 124 Apr 12 16:08:05 foo kernel: [122441.863582] Broke affinity for irq 286 Apr 12 16:08:05 foo kernel: [122441.864603] smpboot: CPU 2 is now offline Apr 12 16:08:05 foo kernel: [122441.875461] Broke affinity for irq 1 Apr 12 16:08:05 foo kernel: [122441.875464] Broke affinity for irq 8 Apr 12 16:08:05 foo kernel: [122441.875466] Broke affinity for irq 9 Apr 12 16:08:05 foo kernel: [122441.875468] Broke affinity for irq 12 Apr 12 16:08:05 foo kernel: [122441.875470] Broke affinity for irq 14 Apr 12 16:08:05 foo kernel: [122441.875472] Broke affinity for irq 16 Apr 12 16:08:05 foo kernel: [122441.875474] Broke affinity for irq 17 Apr 12 16:08:05 foo kernel: [122441.875476] Broke affinity for irq 51 Apr 12 16:08:05 foo kernel: [122441.875479] Broke affinity for irq 124 Apr 12 16:08:05 foo kernel: [122441.875494] Broke affinity for irq 286 Apr 12 16:08:05 foo kernel: [122441.875496] Broke affinity for irq 287 Apr 12 16:08:05 foo kernel: [122441.876529] smpboot: CPU 3 is now offline Apr 12 16:08:05 foo kernel: [122441.893726] ACPI: Low-level resume complete Apr 12 16:08:05 foo kernel: [122441.893819] ACPI : EC: EC started Apr 12 16:08:05 foo kernel: [122441.893820] PM: Restoring platform NVS memory Apr 12 16:08:05 foo kernel: [122441.894621] Enabling non-boot CPUs ... Apr 12 16:08:05 foo kernel: [122441.914323] x86: Booting SMP configuration: Apr 12 16:08:05 foo kernel: [122441.914324] smpboot: Booting Node 0 Processor 1 APIC 0x2 Apr 12 16:08:05 foo kernel: [122441.916981] cache: parent cpu1 should not be sleeping Apr 12 16:08:05 foo kernel: [122441.917106] CPU1 is up Apr 12 16:08:05 foo kernel: [122441.934341] smpboot: Booting Node 0 Processor 2 APIC 0x1 Apr 12 16:08:05 foo kernel: [122441.937005] cache: parent cpu2 should not be sleeping Apr 12 16:08:05 foo kernel: [122441.937104] CPU2 is up Apr 12 16:08:05 foo kernel: [122441.954394] smpboot: Booting Node 0 Processor 3 APIC 0x3 Apr 12 16:08:05 foo kernel: [122441.957069] cache: parent cpu3 should not be sleeping Apr 12 16:08:05 foo kernel: [122441.957167] CPU3 is up Apr 12 16:08:05 foo kernel: [122441.960715] ACPI: Waking up from system sleep state S3 Apr 12 16:08:05 foo kernel: [122442.834165] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI Apr 12 16:08:05 foo kernel: [122442.834229] PM: noirq resume of devices complete after 31.487 msecs Apr 12 16:08:05 foo kernel: [122442.838623] PM: early resume of devices complete after 4.363 msecs Apr 12 16:08:05 foo kernel: [122442.840563] rtc_cmos 00:01: System wakeup disabled by ACPI Apr 12 16:08:05 foo kernel: [122442.880654] xhci_hcd 0000:00:14.0: port 2 resume PLC timeout Apr 12 16:08:05 foo kernel: [122443.126792] ------------[ cut here ]------------ Apr 12 16:08:05 foo kernel: [122443.126810] WARNING: CPU: 3 PID: 30067 at drivers/gpu/drm/i915/intel_pm.c:3553 skl_update_other_pipe_wm+0x147/0x150 [i915]() Apr 12 16:08:05 foo kernel: [122443.126811] WARN_ON(!wm_changed) Apr 12 16:08:05 foo kernel: [122443.126834] Modules linked in: nls_utf8 btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c drbg ansi_cprng ctr ccm xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_hda_codec_hdmi bnep binfmt_misc dell_led snd_hda_codec_realtek snd_hda_codec_generic hid_multitouch intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp arc4 kvm_intel kvm dell_laptop irqbypass dcdbas i2c_designware_platform nls_iso8859_1 dell_wmi crct10dif_pclmul i2c_designware_core sparse_keymap crc32_pclmul ghash_clmulni_intel snd_soc_skl iwlmvm snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp aesni_intel mac80211 snd_hda_ext_core aes_x86_64 lrw snd_soc_sst_match gf128mul snd_soc_core glue_helper ablk_helper cryptd snd_compress iwlwifi ac97_bus snd_pcm_dmaengine dw_dmac_core rtsx_pci_ms cfg80211 memstick pcspkr i915 snd_hda_intel snd_hda_codec snd_hda_core uvcvideo serio_raw snd_hwdep videobuf2_vmalloc snd_pcm videobuf2_memops videobuf2_v4l2 snd_timer videobuf2_core snd videodev i2c_i801 soundcore drm_kms_helper media drm joydev input_leds idma64 i2c_algo_bit virt_dma fb_sys_fops btusb mei_me syscopyarea btrtl sysfillrect mei sysimgblt shpchp processor_thermal_device intel_soc_dts_iosf intel_lpss_pci wmi hci_uart btbcm btqca btintel bluetooth video intel_lpss_acpi intel_lpss int3403_thermal int340x_thermal_zone int3400_thermal acpi_thermal_rel acpi_pad mac_hid acpi_als kfifo_buf industrialio parport_pc ppdev lp parport autofs4 hid_generic usbhid rtsx_pci_sdmmc psmouse rtsx_pci nvme i2c_hid hid pinctrl_sunrisepoint pinctrl_intel fjes Apr 12 16:08:05 foo kernel: [122443.126865] CPU: 3 PID: 30067 Comm: kworker/u8:55 Tainted: G U W 4.5.0intsusp #1 Apr 12 16:08:05 foo kernel: [122443.126865] Hardware name: Dell Inc. XPS 13 9350/07TYC2, BIOS 1.0.0 09/10/2015 Apr 12 16:08:05 foo kernel: [122443.126869] Workqueue: events_unbound async_run_entry_fn Apr 12 16:08:05 foo kernel: [122443.126870] 0000000000000286 00000000c04f6c76 ffff88018b6cb948 ffffffff813d9213 Apr 12 16:08:05 foo kernel: [122443.126871] ffff88018b6cb990 ffffffffc05797f0 ffff88018b6cb980 ffffffff8107ebf2 Apr 12 16:08:05 foo kernel: [122443.126872] ffff8802b68ab000 ffff88018b6cba0c ffff880036179bd4 ffff8802b52f0000 Apr 12 16:08:05 foo kernel: [122443.126873] Call Trace: Apr 12 16:08:05 foo kernel: [122443.126876] [] dump_stack+0x63/0x90 Apr 12 16:08:05 foo kernel: [122443.126878] [] warn_slowpath_common+0x82/0xc0 Apr 12 16:08:05 foo kernel: [122443.126879] [] warn_slowpath_fmt+0x5c/0x80 Apr 12 16:08:05 foo kernel: [122443.126889] [] skl_update_other_pipe_wm+0x147/0x150 [i915] Apr 12 16:08:05 foo kernel: [122443.126899] [] skl_update_wm+0x16a/0x5d0 [i915] Apr 12 16:08:05 foo kernel: [122443.126914] [] ? intel_ddi_enable_transcoder_func+0x17f/0x260 [i915] Apr 12 16:08:05 foo kernel: [122443.126923] [] intel_update_watermarks+0x1e/0x20 [i915] Apr 12 16:08:05 foo kernel: [122443.126937] [] haswell_crtc_enable+0x321/0x8c0 [i915] Apr 12 16:08:05 foo kernel: [122443.126952] [] intel_atomic_commit+0x73e/0x1880 [i915] Apr 12 16:08:05 foo kernel: [122443.126965] [] ? drm_atomic_check_only+0x181/0x600 [drm] Apr 12 16:08:05 foo kernel: [122443.126973] [] drm_atomic_commit+0x37/0x60 [drm] Apr 12 16:08:05 foo kernel: [122443.126987] [] intel_display_resume+0x10f/0x150 [i915] Apr 12 16:08:05 foo kernel: [122443.126996] [] i915_drm_resume+0xdd/0x170 [i915] Apr 12 16:08:05 foo kernel: [122443.127004] [] i915_pm_resume+0x25/0x30 [i915] Apr 12 16:08:05 foo kernel: [122443.127006] [] pci_pm_resume+0x64/0xa0 Apr 12 16:08:05 foo kernel: [122443.127007] [] ? pci_pm_thaw+0x90/0x90 Apr 12 16:08:05 foo kernel: [122443.127009] [] dpm_run_callback+0x4e/0x130 Apr 12 16:08:05 foo kernel: [122443.127011] [] device_resume+0xd3/0x1f0 Apr 12 16:08:05 foo kernel: [122443.127013] [] async_resume+0x1d/0x50 Apr 12 16:08:05 foo kernel: [122443.127014] [] async_run_entry_fn+0x48/0x150 Apr 12 16:08:05 foo kernel: [122443.127015] [] process_one_work+0x165/0x480 Apr 12 16:08:05 foo kernel: [122443.127016] [] worker_thread+0x4b/0x500 Apr 12 16:08:05 foo kernel: [122443.127018] [] ? process_one_work+0x480/0x480 Apr 12 16:08:05 foo kernel: [122443.127019] [] kthread+0xd8/0xf0 Apr 12 16:08:05 foo kernel: [122443.127021] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 16:08:05 foo kernel: [122443.127023] [] ret_from_fork+0x3f/0x70 Apr 12 16:08:05 foo kernel: [122443.127024] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 16:08:05 foo kernel: [122443.127025] ---[ end trace 3cc60a24822ab8dc ]--- Apr 12 16:08:05 foo kernel: [122443.162228] usb 1-3: reset full-speed USB device number 3 using xhci_hcd Apr 12 16:08:05 foo kernel: [122443.514594] usb 1-1: reset high-speed USB device number 16 using xhci_hcd Apr 12 16:08:05 foo kernel: [122443.866303] usb 1-5: reset high-speed USB device number 5 using xhci_hcd Apr 12 16:08:05 foo kernel: [122444.102978] restoring control 00000000-0000-0000-0000-000000000101/10/5 Apr 12 16:08:05 foo kernel: [122444.310557] usb 1-1.1: reset low-speed USB device number 17 using xhci_hcd Apr 12 16:08:05 foo kernel: [122444.374461] [drm] RC6 on Apr 12 16:08:05 foo kernel: [122444.846533] usb 1-1.3: reset low-speed USB device number 18 using xhci_hcd Apr 12 16:08:05 foo kernel: [122445.382574] usb 1-1.4: reset low-speed USB device number 19 using xhci_hcd Apr 12 16:08:05 foo kernel: [122445.684506] PM: resume of devices complete after 2845.989 msecs Apr 12 16:08:05 foo kernel: [122445.684565] usb 1-3:1.0: rebind failed: -517 Apr 12 16:08:05 foo kernel: [122445.684567] usb 1-3:1.1: rebind failed: -517 Apr 12 16:08:05 foo kernel: [122445.684788] PM: Finishing wakeup. Apr 12 16:08:05 foo systemd[1]: Time has been changed Apr 12 16:08:05 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 16:08:05 foo systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 12 16:08:05 foo nm-dispatcher: #1 'down' [wlp58s0]: new request (1 scripts) Apr 12 16:08:05 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 16:08:05 foo nm-dispatcher: #1 'down' [wlp58s0]: start running ordered scripts... Apr 12 16:08:05 foo systemd[860]: Time has been changed Apr 12 16:08:05 foo systemd[1067]: Time has been changed Apr 12 16:08:05 foo systemd[1]: Started Load/Save RF Kill Switch Status. Apr 12 16:08:05 foo kernel: [122445.684789] Restarting tasks ... done. Apr 12 16:08:05 foo systemd[1]: bluetooth.target: Unit not needed anymore. Stopping. Apr 12 16:08:05 foo systemd[1]: Stopped target Bluetooth. Apr 12 16:08:05 foo systemd-sleep[30005]: System resumed. Apr 12 16:08:05 foo systemd[1]: Started Suspend. Apr 12 16:08:05 foo systemd[1]: sleep.target: Unit not needed anymore. Stopping. Apr 12 16:08:05 foo systemd[1]: Stopped target Sleep. Apr 12 16:08:05 foo systemd[1]: Reached target Suspend. Apr 12 16:08:05 foo systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too. Apr 12 16:08:05 foo kernel: [122445.871544] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 16:08:05 foo kernel: [122445.871716] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 16:08:05 foo kernel: [122445.871903] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 16:08:05 foo systemd[1]: Stopped target Suspend. Apr 12 16:08:05 foo NetworkManager[678]: wake requested (sleeping: yes enabled: yes) Apr 12 16:08:05 foo NetworkManager[678]: waking up... Apr 12 16:08:05 foo NetworkManager[678]: (wlp58s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Apr 12 16:08:05 foo systemd[1]: Started Run anacron jobs at resume. Apr 12 16:08:05 foo systemd[1]: Started Run anacron jobs. Apr 12 16:08:05 foo anacron[30115]: Anacron 2.3 started on 2016-04-12 Apr 12 16:08:05 foo anacron[30115]: Normal exit (0 jobs run) Apr 12 16:08:05 foo kernel: [122445.934586] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 16:08:05 foo kernel: [122445.934768] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 16:08:05 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 16:08:05 foo kernel: [122445.948464] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 16:08:05 foo NetworkManager[678]: (wlp58s0) supports 5 scan SSIDs Apr 12 16:08:05 foo NetworkManager[678]: (wlp58s0): supplicant interface state: starting -> ready Apr 12 16:08:05 foo NetworkManager[678]: (wlp58s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Apr 12 16:08:05 foo kernel: [122445.991693] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 16:08:05 foo kernel: [122446.111605] Bluetooth: hci0: read Intel version: 370810011003110e00 Apr 12 16:08:05 foo kernel: [122446.111609] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq Apr 12 16:08:06 foo kernel: [122446.326450] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated Apr 12 16:08:06 foo bluetoothd[683]: Failed to obtain handles for "Service Changed" characteristic Apr 12 16:08:06 foo bluetoothd[683]: Not enough free handles to register service Apr 12 16:08:06 foo bluetoothd[683]: Error adding Link Loss service Apr 12 16:08:06 foo bluetoothd[683]: Not enough free handles to register service Apr 12 16:08:06 foo bluetoothd[683]: Not enough free handles to register service Apr 12 16:08:06 foo bluetoothd[683]: Not enough free handles to register service Apr 12 16:08:06 foo bluetoothd[683]: Current Time Service could not be registered Apr 12 16:08:06 foo bluetoothd[683]: gatt-time-server: Input/output error (5) Apr 12 16:08:06 foo bluetoothd[683]: Not enough free handles to register service Apr 12 16:08:06 foo bluetoothd[683]: Not enough free handles to register service Apr 12 16:08:06 foo bluetoothd[683]: Sap driver initialization failed. Apr 12 16:08:06 foo systemd[1]: Reached target Bluetooth. Apr 12 16:08:06 foo bluetoothd[683]: sap-server: Operation not permitted (1) Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): supplicant interface state: ready -> inactive Apr 12 16:08:08 foo NetworkManager[678]: Auto-activating connection 'eduroam'. Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): Activation: starting connection 'eduroam' (d2eafde8-5191-4378-91ae-92c47e774947) Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Apr 12 16:08:08 foo NetworkManager[678]: NetworkManager state is now CONNECTING Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) access point 'eduroam' has security, but secrets are required. Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): device state change: config -> need-auth (reason 'none') [50 60 0] Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) connection 'eduroam' has security, and secrets exist. No new secrets needed. Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'ssid' value 'eduroam' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'scan_ssid' value '1' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'key_mgmt' value 'WPA-EAP' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'password' value '' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'eap' value 'TTLS' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'fragment_size' value '1266' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'phase2' value 'auth=PAP' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'identity' value 'dcw2131' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'bgscan' value 'simple:30:-65:300' Apr 12 16:08:08 foo NetworkManager[678]: Config: added 'proactive_key_caching' value '1' Apr 12 16:08:08 foo NetworkManager[678]: Config: set interface ap_scan to 1 Apr 12 16:08:08 foo wpa_supplicant[776]: wlp58s0: SME: Trying to authenticate with d8:c7:c8:3e:58:62 (SSID='eduroam' freq=2437 MHz) Apr 12 16:08:08 foo kernel: [122449.183932] wlp58s0: authenticate with d8:c7:c8:3e:58:62 Apr 12 16:08:08 foo wpa_supplicant[776]: wlp58s0: Trying to associate with d8:c7:c8:3e:58:62 (SSID='eduroam' freq=2437 MHz) Apr 12 16:08:08 foo kernel: [122449.186643] wlp58s0: send auth to d8:c7:c8:3e:58:62 (try 1/3) Apr 12 16:08:08 foo kernel: [122449.188648] wlp58s0: authenticated Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): supplicant interface state: inactive -> associating Apr 12 16:08:08 foo kernel: [122449.189892] wlp58s0: associate with d8:c7:c8:3e:58:62 (try 1/3) Apr 12 16:08:08 foo kernel: [122449.193061] wlp58s0: RX AssocResp from d8:c7:c8:3e:58:62 (capab=0x431 status=0 aid=1) Apr 12 16:08:08 foo wpa_supplicant[776]: wlp58s0: Associated with d8:c7:c8:3e:58:62 Apr 12 16:08:08 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-STARTED EAP authentication started Apr 12 16:08:08 foo kernel: [122449.195596] wlp58s0: associated Apr 12 16:08:08 foo kernel: [122449.195661] IPv6: ADDRCONF(NETDEV_CHANGE): wlp58s0: link becomes ready Apr 12 16:08:08 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associating -> associated Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=4 -> NAK Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21 Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root' Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root' Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority' Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=US/ST=MI/L=Ann Arbor/O=Internet2/OU=InCommon/CN=InCommon RSA Server CA' Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=US/ST=NY/L=New York/O=Columbia University/OU=Information Technology/CN=radius.cc.columbia.edu' Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: WPA: Key negotiation completed with d8:c7:c8:3e:58:62 [PTK=CCMP GTK=CCMP] Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to d8:c7:c8:3e:58:62 completed [id=0 id_str=] Apr 12 16:08:09 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associated -> completed Apr 12 16:08:09 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'eduroam'. Apr 12 16:08:09 foo NetworkManager[678]: (wlp58s0): device state change: config -> ip-config (reason 'none') [50 70 0] Apr 12 16:08:09 foo NetworkManager[678]: Activation (wlp58s0) Beginning DHCPv4 transaction (timeout in 45 seconds) Apr 12 16:08:09 foo NetworkManager[678]: dhclient started with pid 30139 Apr 12 16:08:09 foo dhclient[30139]: DHCPDISCOVER on wlp58s0 to 255.255.255.255 port 67 interval 3 Apr 12 16:08:09 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-45 noise=9999 txrate=144400 Apr 12 16:08:10 foo dhclient[30139]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 255.255.255.255 port 67 Apr 12 16:08:10 foo dhclient[30139]: DHCPOFFER of 160.39.10.177 from 160.39.10.2 Apr 12 16:08:10 foo dhclient[30139]: DHCPACK of 160.39.10.177 from 160.39.10.2 Apr 12 16:08:10 foo NetworkManager[678]: address 160.39.10.177 Apr 12 16:08:10 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 16:08:10 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 16:08:10 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv4 with address 160.39.10.177. Apr 12 16:08:10 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 16:08:10 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv4 for mDNS. Apr 12 16:08:10 foo NetworkManager[678]: lease time 1800 Apr 12 16:08:10 foo avahi-daemon[635]: Registering new address record for 160.39.10.177 on wlp58s0.IPv4. Apr 12 16:08:10 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 16:08:10 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 16:08:10 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 16:08:10 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 16:08:10 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed unknown -> bound Apr 12 16:08:10 foo NetworkManager[678]: (wlp58s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Apr 12 16:08:10 foo NetworkManager[678]: (wlp58s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Apr 12 16:08:10 foo dhclient[30139]: bound to 160.39.10.177 -- renewal in 789 seconds. Apr 12 16:08:10 foo NetworkManager[678]: (wlp58s0): device state change: secondaries -> activated (reason 'none') [90 100 0] Apr 12 16:08:10 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 16:08:10 foo NetworkManager[678]: NetworkManager state is now CONNECTED_GLOBAL Apr 12 16:08:10 foo NetworkManager[678]: Policy set 'eduroam' (wlp58s0) as default for IPv4 routing and DNS. Apr 12 16:08:10 foo dnsmasq[930]: reading /etc/resolv.conf Apr 12 16:08:10 foo dnsmasq[930]: using nameserver 128.59.1.3#53 Apr 12 16:08:10 foo dnsmasq[930]: using nameserver 128.59.1.4#53 Apr 12 16:08:10 foo NetworkManager[678]: (wlp58s0): Activation: successful, device activated. Apr 12 16:08:10 foo nm-dispatcher: #2 'up' [wlp58s0]: new request (1 scripts) Apr 12 16:08:10 foo nm-dispatcher: #2 'up' [wlp58s0]: start running ordered scripts... Apr 12 16:08:10 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 16:08:10 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 16:08:10 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 16:08:10 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 16:08:10 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 16:08:10 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv6 for mDNS. Apr 12 16:08:10 foo avahi-daemon[635]: Registering new address record for fe80::de53:60ff:fecc:254a on wlp58s0.*. Apr 12 16:08:26 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 16:08:56 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 16:16:42 foo systemd-timesyncd[562]: Synchronized to time server 24.56.178.140:123 (0.debian.pool.ntp.org). Apr 12 16:17:01 foo CRON[30346]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Apr 12 16:21:19 foo dhclient[30139]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 128.59.1.23 port 67 Apr 12 16:21:19 foo dhclient[30139]: DHCPACK of 160.39.10.177 from 128.59.1.23 Apr 12 16:21:19 foo NetworkManager[678]: address 160.39.10.177 Apr 12 16:21:19 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 16:21:19 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 16:21:19 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 16:21:19 foo NetworkManager[678]: lease time 1800 Apr 12 16:21:19 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 16:21:19 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 16:21:19 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 16:21:19 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 16:21:19 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 16:21:19 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 16:21:19 foo dhclient[30139]: bound to 160.39.10.177 -- renewal in 679 seconds. Apr 12 16:21:19 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 16:21:19 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 16:21:19 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 16:21:19 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 16:21:19 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 16:32:38 foo dhclient[30139]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 128.59.1.23 port 67 Apr 12 16:32:38 foo dhclient[30139]: DHCPACK of 160.39.10.177 from 128.59.1.23 Apr 12 16:32:38 foo NetworkManager[678]: address 160.39.10.177 Apr 12 16:32:38 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 16:32:38 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 16:32:38 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 16:32:38 foo NetworkManager[678]: lease time 1800 Apr 12 16:32:38 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 16:32:38 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 16:32:38 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 16:32:38 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 16:32:38 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 16:32:38 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 16:32:38 foo dhclient[30139]: bound to 160.39.10.177 -- renewal in 682 seconds. Apr 12 16:32:38 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 16:32:38 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 16:32:38 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 16:32:38 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 16:32:38 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 16:40:15 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 16:40:46 foo wpa_supplicant[776]: wlp58s0: WNM: Preferred List Available Apr 12 16:44:00 foo dhclient[30139]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 128.59.1.23 port 67 Apr 12 16:44:08 foo dhclient[30139]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 128.59.1.23 port 67 Apr 12 16:44:08 foo dhclient[30139]: DHCPACK of 160.39.10.177 from 128.59.1.23 Apr 12 16:44:08 foo NetworkManager[678]: address 160.39.10.177 Apr 12 16:44:08 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 16:44:08 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 16:44:08 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 16:44:08 foo NetworkManager[678]: lease time 1792 Apr 12 16:44:08 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 16:44:08 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 16:44:08 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 16:44:08 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 16:44:08 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 16:44:08 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 16:44:08 foo dhclient[30139]: bound to 160.39.10.177 -- renewal in 889 seconds. Apr 12 16:44:08 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 16:44:08 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 16:44:08 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 16:44:08 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 16:44:08 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 16:58:58 foo dhclient[30139]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 128.59.1.23 port 67 Apr 12 16:58:58 foo dhclient[30139]: DHCPACK of 160.39.10.177 from 128.59.1.23 Apr 12 16:58:58 foo NetworkManager[678]: address 160.39.10.177 Apr 12 16:58:58 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 16:58:58 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 16:58:58 foo NetworkManager[678]: server identifier 128.59.1.23 Apr 12 16:58:58 foo NetworkManager[678]: lease time 1800 Apr 12 16:58:58 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 16:58:58 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 16:58:58 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 16:58:58 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 16:58:58 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> bound Apr 12 16:58:58 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 16:58:58 foo dhclient[30139]: bound to 160.39.10.177 -- renewal in 706 seconds. Apr 12 16:58:58 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 16:58:58 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 16:58:58 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 16:58:58 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: new request (1 scripts) Apr 12 16:58:58 foo nm-dispatcher: #1 'dhcp4-change' [wlp58s0]: start running ordered scripts... Apr 12 17:02:12 foo NetworkManager[678]: sleep requested (sleeping: no enabled: yes) Apr 12 17:02:12 foo NetworkManager[678]: sleeping... Apr 12 17:02:12 foo NetworkManager[678]: (wlp58s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37] Apr 12 17:02:12 foo NetworkManager[678]: (wlp58s0): canceled DHCP transaction, DHCP client pid 30139 Apr 12 17:02:12 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> done Apr 12 17:02:12 foo kernel: [125692.309208] wlp58s0: deauthenticating from d8:c7:c8:3e:58:62 by local choice (Reason: 3=DEAUTH_LEAVING) Apr 12 17:02:12 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-DISCONNECTED bssid=d8:c7:c8:3e:58:62 reason=3 locally_generated=1 Apr 12 17:02:12 foo NetworkManager[678]: NetworkManager state is now ASLEEP Apr 12 17:02:12 foo avahi-daemon[635]: Withdrawing address record for 160.39.10.177 on wlp58s0. Apr 12 17:02:12 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv4 with address 160.39.10.177. Apr 12 17:02:12 foo avahi-daemon[635]: Interface wlp58s0.IPv4 no longer relevant for mDNS. Apr 12 17:02:12 foo avahi-daemon[635]: Withdrawing address record for fe80::de53:60ff:fecc:254a on wlp58s0. Apr 12 17:02:12 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 17:02:12 foo avahi-daemon[635]: Interface wlp58s0.IPv6 no longer relevant for mDNS. Apr 12 17:02:12 foo dnsmasq[930]: no servers found in /etc/resolv.conf, will retry Apr 12 17:02:12 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 17:02:12 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 17:02:12 foo systemd[1]: Reached target Sleep. Apr 12 17:02:12 foo systemd[1]: Starting Suspend... Apr 12 17:02:12 foo systemd-sleep[30677]: Suspending system... Apr 12 17:02:12 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 17:02:12 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 17:02:12 foo nm-dispatcher: #1 'down' [wlp58s0]: new request (1 scripts) Apr 12 17:02:12 foo nm-dispatcher: #1 'down' [wlp58s0]: start running ordered scripts... Apr 12 17:15:12 foo kernel: [125692.389474] PM: Syncing filesystems ... done. Apr 12 17:15:12 foo kernel: [125692.400883] PM: Preparing system for sleep (mem) Apr 12 17:15:12 foo kernel: [125692.401275] Freezing user space processes ... (elapsed 0.001 seconds) done. Apr 12 17:15:12 foo kernel: [125692.403110] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Apr 12 17:15:12 foo kernel: [125692.404340] PM: Suspending system (mem) Apr 12 17:15:12 foo kernel: [125692.404358] Suspending console(s) (use no_console_suspend to debug) Apr 12 17:15:12 foo kernel: [125692.738513] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun Apr 12 17:15:12 foo kernel: [125692.762369] PM: suspend of devices complete after 343.823 msecs Apr 12 17:15:12 foo kernel: [125692.782540] PM: late suspend of devices complete after 20.151 msecs Apr 12 17:15:12 foo kernel: [125692.783764] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI Apr 12 17:15:12 foo kernel: [125692.814426] PM: noirq suspend of devices complete after 31.883 msecs Apr 12 17:15:12 foo kernel: [125692.814658] ACPI: Preparing to enter system sleep state S3 Apr 12 17:15:12 foo kernel: [125692.834596] ACPI : EC: EC stopped Apr 12 17:15:12 foo kernel: [125692.834596] PM: Saving platform NVS memory Apr 12 17:15:12 foo kernel: [125692.834614] Disabling non-boot CPUs ... Apr 12 17:15:12 foo kernel: [125692.834864] Broke affinity for irq 287 Apr 12 17:15:12 foo kernel: [125692.835882] smpboot: CPU 1 is now offline Apr 12 17:15:12 foo kernel: [125692.846977] Broke affinity for irq 124 Apr 12 17:15:12 foo kernel: [125692.847009] Broke affinity for irq 287 Apr 12 17:15:12 foo kernel: [125692.848027] smpboot: CPU 2 is now offline Apr 12 17:15:12 foo kernel: [125692.858853] Broke affinity for irq 1 Apr 12 17:15:12 foo kernel: [125692.858855] Broke affinity for irq 8 Apr 12 17:15:12 foo kernel: [125692.858857] Broke affinity for irq 9 Apr 12 17:15:12 foo kernel: [125692.858859] Broke affinity for irq 12 Apr 12 17:15:12 foo kernel: [125692.858861] Broke affinity for irq 14 Apr 12 17:15:12 foo kernel: [125692.858863] Broke affinity for irq 16 Apr 12 17:15:12 foo kernel: [125692.858865] Broke affinity for irq 17 Apr 12 17:15:12 foo kernel: [125692.858867] Broke affinity for irq 51 Apr 12 17:15:12 foo kernel: [125692.858870] Broke affinity for irq 124 Apr 12 17:15:12 foo kernel: [125692.858897] Broke affinity for irq 286 Apr 12 17:15:12 foo kernel: [125692.858899] Broke affinity for irq 287 Apr 12 17:15:12 foo kernel: [125692.859919] smpboot: CPU 3 is now offline Apr 12 17:15:12 foo kernel: [125692.880484] ACPI: Low-level resume complete Apr 12 17:15:12 foo kernel: [125692.880666] ACPI : EC: EC started Apr 12 17:15:12 foo kernel: [125692.880668] PM: Restoring platform NVS memory Apr 12 17:15:12 foo kernel: [125692.881845] Enabling non-boot CPUs ... Apr 12 17:15:12 foo kernel: [125692.902149] x86: Booting SMP configuration: Apr 12 17:15:12 foo kernel: [125692.902153] smpboot: Booting Node 0 Processor 1 APIC 0x2 Apr 12 17:15:12 foo kernel: [125692.906979] cache: parent cpu1 should not be sleeping Apr 12 17:15:12 foo kernel: [125692.907530] CPU1 is up Apr 12 17:15:12 foo kernel: [125692.926405] smpboot: Booting Node 0 Processor 2 APIC 0x1 Apr 12 17:15:12 foo kernel: [125692.931404] cache: parent cpu2 should not be sleeping Apr 12 17:15:12 foo kernel: [125692.931971] CPU2 is up Apr 12 17:15:12 foo kernel: [125692.950561] smpboot: Booting Node 0 Processor 3 APIC 0x3 Apr 12 17:15:12 foo kernel: [125692.955763] cache: parent cpu3 should not be sleeping Apr 12 17:15:12 foo kernel: [125692.956325] CPU3 is up Apr 12 17:15:12 foo kernel: [125692.975856] ACPI: Waking up from system sleep state S3 Apr 12 17:15:12 foo kernel: [125693.849504] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI Apr 12 17:15:12 foo kernel: [125693.849881] PM: noirq resume of devices complete after 28.526 msecs Apr 12 17:15:12 foo kernel: [125693.855529] PM: early resume of devices complete after 5.501 msecs Apr 12 17:15:12 foo kernel: [125693.862099] rtc_cmos 00:01: System wakeup disabled by ACPI Apr 12 17:15:12 foo kernel: [125693.899407] xhci_hcd 0000:00:14.0: port 2 resume PLC timeout Apr 12 17:15:12 foo kernel: [125694.140722] ------------[ cut here ]------------ Apr 12 17:15:12 foo kernel: [125694.140812] WARNING: CPU: 1 PID: 30743 at drivers/gpu/drm/i915/intel_pm.c:3553 skl_update_other_pipe_wm+0x147/0x150 [i915]() Apr 12 17:15:12 foo kernel: [125694.140817] WARN_ON(!wm_changed) Apr 12 17:15:12 foo kernel: [125694.140929] Modules linked in: nls_utf8 btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c drbg ansi_cprng ctr ccm xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_hda_codec_hdmi bnep binfmt_misc dell_led snd_hda_codec_realtek snd_hda_codec_generic hid_multitouch intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp arc4 kvm_intel kvm dell_laptop irqbypass dcdbas i2c_designware_platform nls_iso8859_1 dell_wmi crct10dif_pclmul i2c_designware_core sparse_keymap crc32_pclmul ghash_clmulni_intel snd_soc_skl iwlmvm snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp aesni_intel mac80211 snd_hda_ext_core aes_x86_64 lrw snd_soc_sst_match gf128mul snd_soc_core glue_helper ablk_helper cryptd snd_compress iwlwifi ac97_bus snd_pcm_dmaengine dw_dmac_core rtsx_pci_ms cfg80211 memstick pcspkr i915 snd_hda_intel snd_hda_codec snd_hda_core uvcvideo serio_raw snd_hwdep videobuf2_vmalloc snd_pcm videobuf2_memops videobuf2_v4l2 snd_timer videobuf2_core snd videodev i2c_i801 soundcore drm_kms_helper media drm joydev input_leds idma64 i2c_algo_bit virt_dma fb_sys_fops btusb mei_me syscopyarea btrtl sysfillrect mei sysimgblt shpchp processor_thermal_device intel_soc_dts_iosf intel_lpss_pci wmi hci_uart btbcm btqca btintel bluetooth video intel_lpss_acpi intel_lpss int3403_thermal int340x_thermal_zone int3400_thermal acpi_thermal_rel acpi_pad mac_hid acpi_als kfifo_buf industrialio parport_pc ppdev lp parport autofs4 hid_generic usbhid rtsx_pci_sdmmc psmouse rtsx_pci nvme i2c_hid hid pinctrl_sunrisepoint pinctrl_intel fjes Apr 12 17:15:12 foo kernel: [125694.141077] CPU: 1 PID: 30743 Comm: kworker/u8:55 Tainted: G U W 4.5.0intsusp #1 Apr 12 17:15:12 foo kernel: [125694.141080] Hardware name: Dell Inc. XPS 13 9350/07TYC2, BIOS 1.0.0 09/10/2015 Apr 12 17:15:12 foo kernel: [125694.141096] Workqueue: events_unbound async_run_entry_fn Apr 12 17:15:12 foo kernel: [125694.141107] 0000000000000286 000000000f1bf9fe ffff88018b75f948 ffffffff813d9213 Apr 12 17:15:12 foo kernel: [125694.141114] ffff88018b75f990 ffffffffc05797f0 ffff88018b75f980 ffffffff8107ebf2 Apr 12 17:15:12 foo kernel: [125694.141121] ffff8802b68ab000 ffff88018b75fa0c ffff880036179bd4 ffff8802b52f0000 Apr 12 17:15:12 foo kernel: [125694.141123] Call Trace: Apr 12 17:15:12 foo kernel: [125694.141140] [] dump_stack+0x63/0x90 Apr 12 17:15:12 foo kernel: [125694.141152] [] warn_slowpath_common+0x82/0xc0 Apr 12 17:15:12 foo kernel: [125694.141160] [] warn_slowpath_fmt+0x5c/0x80 Apr 12 17:15:12 foo kernel: [125694.141229] [] skl_update_other_pipe_wm+0x147/0x150 [i915] Apr 12 17:15:12 foo kernel: [125694.141295] [] skl_update_wm+0x16a/0x5d0 [i915] Apr 12 17:15:12 foo kernel: [125694.141400] [] ? intel_ddi_enable_transcoder_func+0x17f/0x260 [i915] Apr 12 17:15:12 foo kernel: [125694.141465] [] intel_update_watermarks+0x1e/0x20 [i915] Apr 12 17:15:12 foo kernel: [125694.141566] [] haswell_crtc_enable+0x321/0x8c0 [i915] Apr 12 17:15:12 foo kernel: [125694.141662] [] intel_atomic_commit+0x73e/0x1880 [i915] Apr 12 17:15:12 foo kernel: [125694.141739] [] ? drm_atomic_check_only+0x181/0x600 [drm] Apr 12 17:15:12 foo kernel: [125694.141803] [] drm_atomic_commit+0x37/0x60 [drm] Apr 12 17:15:12 foo kernel: [125694.141904] [] intel_display_resume+0x10f/0x150 [i915] Apr 12 17:15:12 foo kernel: [125694.141961] [] i915_drm_resume+0xdd/0x170 [i915] Apr 12 17:15:12 foo kernel: [125694.142018] [] i915_pm_resume+0x25/0x30 [i915] Apr 12 17:15:12 foo kernel: [125694.142027] [] pci_pm_resume+0x64/0xa0 Apr 12 17:15:12 foo kernel: [125694.142034] [] ? pci_pm_thaw+0x90/0x90 Apr 12 17:15:12 foo kernel: [125694.142047] [] dpm_run_callback+0x4e/0x130 Apr 12 17:15:12 foo kernel: [125694.142057] [] device_resume+0xd3/0x1f0 Apr 12 17:15:12 foo kernel: [125694.142068] [] async_resume+0x1d/0x50 Apr 12 17:15:12 foo kernel: [125694.142077] [] async_run_entry_fn+0x48/0x150 Apr 12 17:15:12 foo kernel: [125694.142086] [] process_one_work+0x165/0x480 Apr 12 17:15:12 foo kernel: [125694.142094] [] worker_thread+0x4b/0x500 Apr 12 17:15:12 foo kernel: [125694.142102] [] ? process_one_work+0x480/0x480 Apr 12 17:15:12 foo kernel: [125694.142112] [] kthread+0xd8/0xf0 Apr 12 17:15:12 foo kernel: [125694.142124] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 17:15:12 foo kernel: [125694.142134] [] ret_from_fork+0x3f/0x70 Apr 12 17:15:12 foo kernel: [125694.142145] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 17:15:12 foo kernel: [125694.142197] ---[ end trace 3cc60a24822ab8dd ]--- Apr 12 17:15:12 foo kernel: [125694.181440] usb 1-5: reset high-speed USB device number 5 using xhci_hcd Apr 12 17:15:12 foo kernel: [125694.419154] restoring control 00000000-0000-0000-0000-000000000101/10/5 Apr 12 17:15:12 foo kernel: [125694.533942] usb 1-3: reset full-speed USB device number 3 using xhci_hcd Apr 12 17:15:12 foo kernel: [125694.885911] usb 1-1: reset high-speed USB device number 16 using xhci_hcd Apr 12 17:15:12 foo kernel: [125695.177661] [drm] RC6 on Apr 12 17:15:12 foo kernel: [125695.537955] usb 1-1.1: reset low-speed USB device number 17 using xhci_hcd Apr 12 17:15:12 foo kernel: [125696.073989] usb 1-1.3: reset low-speed USB device number 18 using xhci_hcd Apr 12 17:15:12 foo kernel: [125696.610061] usb 1-1.4: reset low-speed USB device number 19 using xhci_hcd Apr 12 17:15:12 foo kernel: [125696.912507] PM: resume of devices complete after 3056.823 msecs Apr 12 17:15:12 foo kernel: [125696.912769] usb 1-3:1.0: rebind failed: -517 Apr 12 17:15:12 foo kernel: [125696.912778] usb 1-3:1.1: rebind failed: -517 Apr 12 17:15:12 foo kernel: [125696.913844] PM: Finishing wakeup. Apr 12 17:15:12 foo kernel: [125696.913850] Restarting tasks ... done. Apr 12 17:15:12 foo systemd[1]: Time has been changed Apr 12 17:15:12 foo systemd[860]: Time has been changed Apr 12 17:15:12 foo systemd[1067]: Time has been changed Apr 12 17:15:12 foo kernel: [125696.977827] Bluetooth: hci0: read Intel version: 370810011003110e00 Apr 12 17:15:12 foo kernel: [125696.977979] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq Apr 12 17:15:12 foo systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 12 17:15:12 foo systemd[1]: Started Load/Save RF Kill Switch Status. Apr 12 17:15:12 foo systemd[1]: bluetooth.target: Unit not needed anymore. Stopping. Apr 12 17:15:12 foo systemd[1]: Stopped target Bluetooth. Apr 12 17:15:12 foo systemd-sleep[30677]: System resumed. Apr 12 17:15:12 foo systemd[1]: Started Suspend. Apr 12 17:15:12 foo systemd[1]: sleep.target: Unit not needed anymore. Stopping. Apr 12 17:15:12 foo systemd[1]: Stopped target Sleep. Apr 12 17:15:12 foo kernel: [125697.150735] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 17:15:12 foo kernel: [125697.152038] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 17:15:12 foo kernel: [125697.152277] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 17:15:12 foo systemd[1]: Reached target Suspend. Apr 12 17:15:12 foo NetworkManager[678]: wake requested (sleeping: yes enabled: yes) Apr 12 17:15:12 foo NetworkManager[678]: waking up... Apr 12 17:15:12 foo NetworkManager[678]: (wlp58s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Apr 12 17:15:12 foo systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too. Apr 12 17:15:12 foo systemd[1]: Stopped target Suspend. Apr 12 17:15:12 foo systemd[1]: Started Run anacron jobs at resume. Apr 12 17:15:13 foo kernel: [125697.212878] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 17:15:13 foo kernel: [125697.213117] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 17:15:13 foo kernel: [125697.229218] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 17:15:13 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 17:15:13 foo kernel: [125697.240800] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated Apr 12 17:15:13 foo systemd[1]: Started Run anacron jobs. Apr 12 17:15:13 foo anacron[30777]: Anacron 2.3 started on 2016-04-12 Apr 12 17:15:13 foo anacron[30777]: Normal exit (0 jobs run) Apr 12 17:15:13 foo bluetoothd[683]: Failed to obtain handles for "Service Changed" characteristic Apr 12 17:15:13 foo bluetoothd[683]: Not enough free handles to register service Apr 12 17:15:13 foo bluetoothd[683]: Error adding Link Loss service Apr 12 17:15:13 foo bluetoothd[683]: Not enough free handles to register service Apr 12 17:15:13 foo bluetoothd[683]: Not enough free handles to register service Apr 12 17:15:13 foo bluetoothd[683]: Not enough free handles to register service Apr 12 17:15:13 foo bluetoothd[683]: Current Time Service could not be registered Apr 12 17:15:13 foo bluetoothd[683]: gatt-time-server: Input/output error (5) Apr 12 17:15:13 foo bluetoothd[683]: Not enough free handles to register service Apr 12 17:15:13 foo bluetoothd[683]: Not enough free handles to register service Apr 12 17:15:13 foo bluetoothd[683]: Sap driver initialization failed. Apr 12 17:15:13 foo systemd[1]: Reached target Bluetooth. Apr 12 17:15:13 foo bluetoothd[683]: sap-server: Operation not permitted (1) Apr 12 17:15:13 foo NetworkManager[678]: (wlp58s0) supports 5 scan SSIDs Apr 12 17:15:13 foo NetworkManager[678]: (wlp58s0): supplicant interface state: starting -> ready Apr 12 17:15:13 foo NetworkManager[678]: (wlp58s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Apr 12 17:15:13 foo kernel: [125697.379628] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: Reject scan trigger since one is already pending Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): supplicant interface state: ready -> inactive Apr 12 17:15:16 foo NetworkManager[678]: Auto-activating connection 'eduroam'. Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): Activation: starting connection 'eduroam' (d2eafde8-5191-4378-91ae-92c47e774947) Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Apr 12 17:15:16 foo NetworkManager[678]: NetworkManager state is now CONNECTING Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) access point 'eduroam' has security, but secrets are required. Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: config -> need-auth (reason 'none') [50 60 0] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) connection 'eduroam' has security, and secrets exist. No new secrets needed. Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'ssid' value 'eduroam' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'scan_ssid' value '1' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'key_mgmt' value 'WPA-EAP' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'password' value '' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'eap' value 'TTLS' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'fragment_size' value '1266' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'phase2' value 'auth=PAP' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'identity' value 'dcw2131' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'bgscan' value 'simple:30:-65:300' Apr 12 17:15:16 foo NetworkManager[678]: Config: added 'proactive_key_caching' value '1' Apr 12 17:15:16 foo NetworkManager[678]: Config: set interface ap_scan to 1 Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: SME: Trying to authenticate with d8:c7:c8:3e:58:62 (SSID='eduroam' freq=2437 MHz) Apr 12 17:15:16 foo kernel: [125700.637809] wlp58s0: authenticate with d8:c7:c8:3e:58:62 Apr 12 17:15:16 foo kernel: [125700.640372] wlp58s0: send auth to d8:c7:c8:3e:58:62 (try 1/3) Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): supplicant interface state: inactive -> authenticating Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: Trying to associate with d8:c7:c8:3e:58:62 (SSID='eduroam' freq=2437 MHz) Apr 12 17:15:16 foo kernel: [125700.643731] wlp58s0: authenticated Apr 12 17:15:16 foo kernel: [125700.645514] wlp58s0: associate with d8:c7:c8:3e:58:62 (try 1/3) Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): supplicant interface state: authenticating -> associating Apr 12 17:15:16 foo kernel: [125700.649935] wlp58s0: RX AssocResp from d8:c7:c8:3e:58:62 (capab=0x431 status=0 aid=2) Apr 12 17:15:16 foo kernel: [125700.653076] wlp58s0: associated Apr 12 17:15:16 foo kernel: [125700.653118] IPv6: ADDRCONF(NETDEV_CHANGE): wlp58s0: link becomes ready Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: Associated with d8:c7:c8:3e:58:62 Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-STARTED EAP authentication started Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associating -> associated Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=4 -> NAK Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21 Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root' Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root' Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/C=US/ST=New Jersey/L=Jersey City/O=The USERTRUST Network/CN=USERTrust RSA Certification Authority' Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=US/ST=MI/L=Ann Arbor/O=Internet2/OU=InCommon/CN=InCommon RSA Server CA' Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=US/ST=NY/L=New York/O=Columbia University/OU=Information Technology/CN=radius.cc.columbia.edu' Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associated -> 4-way handshake Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: WPA: Key negotiation completed with d8:c7:c8:3e:58:62 [PTK=CCMP GTK=CCMP] Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to d8:c7:c8:3e:58:62 completed [id=0 id_str=] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): supplicant interface state: 4-way handshake -> completed Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'eduroam'. Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: config -> ip-config (reason 'none') [50 70 0] Apr 12 17:15:16 foo NetworkManager[678]: Activation (wlp58s0) Beginning DHCPv4 transaction (timeout in 45 seconds) Apr 12 17:15:16 foo NetworkManager[678]: dhclient started with pid 30786 Apr 12 17:15:16 foo dhclient[30786]: DHCPREQUEST of 160.39.10.177 on wlp58s0 to 255.255.255.255 port 67 Apr 12 17:15:16 foo dhclient[30786]: DHCPACK of 160.39.10.177 from 160.39.10.2 Apr 12 17:15:16 foo NetworkManager[678]: address 160.39.10.177 Apr 12 17:15:16 foo NetworkManager[678]: plen 23 (255.255.254.0) Apr 12 17:15:16 foo NetworkManager[678]: gateway 160.39.10.1 Apr 12 17:15:16 foo NetworkManager[678]: server identifier 128.59.1.38 Apr 12 17:15:16 foo NetworkManager[678]: lease time 1800 Apr 12 17:15:16 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv4 with address 160.39.10.177. Apr 12 17:15:16 foo NetworkManager[678]: nameserver '128.59.1.4' Apr 12 17:15:16 foo NetworkManager[678]: nameserver '128.59.1.3' Apr 12 17:15:16 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 17:15:16 foo NetworkManager[678]: wins '128.59.93.74' Apr 12 17:15:16 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv4 for mDNS. Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed unknown -> bound Apr 12 17:15:16 foo avahi-daemon[635]: Registering new address record for 160.39.10.177 on wlp58s0.IPv4. Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): device state change: secondaries -> activated (reason 'none') [90 100 0] Apr 12 17:15:16 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 17:15:16 foo dhclient[30786]: bound to 160.39.10.177 -- renewal in 733 seconds. Apr 12 17:15:16 foo NetworkManager[678]: NetworkManager state is now CONNECTED_GLOBAL Apr 12 17:15:16 foo NetworkManager[678]: Policy set 'eduroam' (wlp58s0) as default for IPv4 routing and DNS. Apr 12 17:15:16 foo NetworkManager[678]: (wlp58s0): Activation: successful, device activated. Apr 12 17:15:16 foo dnsmasq[930]: reading /etc/resolv.conf Apr 12 17:15:16 foo dnsmasq[930]: using nameserver 128.59.1.4#53 Apr 12 17:15:16 foo dnsmasq[930]: using nameserver 128.59.1.3#53 Apr 12 17:15:16 foo nm-dispatcher: #2 'up' [wlp58s0]: new request (1 scripts) Apr 12 17:15:16 foo nm-dispatcher: #2 'up' [wlp58s0]: start running ordered scripts... Apr 12 17:15:16 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-49 noise=9999 txrate=144400 Apr 12 17:15:16 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 17:15:16 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 17:15:16 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 17:15:16 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 17:15:18 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 17:15:18 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv6 for mDNS. Apr 12 17:15:18 foo avahi-daemon[635]: Registering new address record for fe80::de53:60ff:fecc:254a on wlp58s0.*. Apr 12 17:15:19 foo NetworkManager[678]: sleep requested (sleeping: no enabled: yes) Apr 12 17:15:19 foo NetworkManager[678]: sleeping... Apr 12 17:15:19 foo NetworkManager[678]: (wlp58s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37] Apr 12 17:15:19 foo NetworkManager[678]: (wlp58s0): canceled DHCP transaction, DHCP client pid 30786 Apr 12 17:15:19 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed bound -> done Apr 12 17:15:19 foo avahi-daemon[635]: Withdrawing address record for 160.39.10.177 on wlp58s0. Apr 12 17:15:19 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv4 with address 160.39.10.177. Apr 12 17:15:19 foo avahi-daemon[635]: Interface wlp58s0.IPv4 no longer relevant for mDNS. Apr 12 17:15:19 foo avahi-daemon[635]: Withdrawing address record for fe80::de53:60ff:fecc:254a on wlp58s0. Apr 12 17:15:19 foo avahi-daemon[635]: Leaving mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 17:15:19 foo avahi-daemon[635]: Interface wlp58s0.IPv6 no longer relevant for mDNS. Apr 12 17:15:19 foo NetworkManager[678]: NetworkManager state is now ASLEEP Apr 12 17:15:19 foo kernel: [125703.281875] wlp58s0: deauthenticating from d8:c7:c8:3e:58:62 by local choice (Reason: 3=DEAUTH_LEAVING) Apr 12 17:15:19 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-DISCONNECTED bssid=d8:c7:c8:3e:58:62 reason=3 locally_generated=1 Apr 12 17:15:19 foo dnsmasq[930]: no servers found in /etc/resolv.conf, will retry Apr 12 17:15:19 foo nm-dispatcher: #3 'down' [wlp58s0]: new request (1 scripts) Apr 12 17:15:19 foo systemd[1]: Reached target Sleep. Apr 12 17:15:19 foo nm-dispatcher: #3 'down' [wlp58s0]: start running ordered scripts... Apr 12 17:15:19 foo systemd[1]: Starting Suspend... Apr 12 17:15:19 foo systemd-sleep[30956]: Suspending system... Apr 12 20:44:44 foo kernel: [125703.355692] PM: Syncing filesystems ... done. Apr 12 20:44:44 foo kernel: [125703.376820] PM: Preparing system for sleep (mem) Apr 12 20:44:44 foo kernel: [125703.377053] Freezing user space processes ... (elapsed 0.001 seconds) done. Apr 12 20:44:44 foo kernel: [125703.378966] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Apr 12 20:44:44 foo kernel: [125703.380249] PM: Suspending system (mem) Apr 12 20:44:44 foo kernel: [125703.380267] Suspending console(s) (use no_console_suspend to debug) Apr 12 20:44:44 foo kernel: [125703.717886] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun Apr 12 20:44:44 foo kernel: [125703.741783] PM: suspend of devices complete after 347.838 msecs Apr 12 20:44:44 foo kernel: [125703.761641] PM: late suspend of devices complete after 19.854 msecs Apr 12 20:44:44 foo kernel: [125703.762824] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI Apr 12 20:44:44 foo kernel: [125703.793668] PM: noirq suspend of devices complete after 32.024 msecs Apr 12 20:44:44 foo kernel: [125703.793900] ACPI: Preparing to enter system sleep state S3 Apr 12 20:44:44 foo kernel: [125703.813839] ACPI : EC: EC stopped Apr 12 20:44:44 foo kernel: [125703.813839] PM: Saving platform NVS memory Apr 12 20:44:44 foo kernel: [125703.813857] Disabling non-boot CPUs ... Apr 12 20:44:44 foo kernel: [125703.814138] Broke affinity for irq 287 Apr 12 20:44:44 foo kernel: [125703.815155] smpboot: CPU 1 is now offline Apr 12 20:44:44 foo kernel: [125703.826201] Broke affinity for irq 124 Apr 12 20:44:44 foo kernel: [125703.826232] Broke affinity for irq 287 Apr 12 20:44:44 foo kernel: [125703.827251] smpboot: CPU 2 is now offline Apr 12 20:44:44 foo kernel: [125703.838106] Broke affinity for irq 1 Apr 12 20:44:44 foo kernel: [125703.838109] Broke affinity for irq 8 Apr 12 20:44:44 foo kernel: [125703.838111] Broke affinity for irq 9 Apr 12 20:44:44 foo kernel: [125703.838113] Broke affinity for irq 12 Apr 12 20:44:44 foo kernel: [125703.838115] Broke affinity for irq 14 Apr 12 20:44:44 foo kernel: [125703.838117] Broke affinity for irq 16 Apr 12 20:44:44 foo kernel: [125703.838119] Broke affinity for irq 17 Apr 12 20:44:44 foo kernel: [125703.838121] Broke affinity for irq 51 Apr 12 20:44:44 foo kernel: [125703.838124] Broke affinity for irq 124 Apr 12 20:44:44 foo kernel: [125703.838151] Broke affinity for irq 286 Apr 12 20:44:44 foo kernel: [125703.838153] Broke affinity for irq 287 Apr 12 20:44:44 foo kernel: [125703.839174] smpboot: CPU 3 is now offline Apr 12 20:44:44 foo kernel: [125703.856373] ACPI: Low-level resume complete Apr 12 20:44:44 foo kernel: [125703.856466] ACPI : EC: EC started Apr 12 20:44:44 foo kernel: [125703.856466] PM: Restoring platform NVS memory Apr 12 20:44:44 foo kernel: [125703.857277] Enabling non-boot CPUs ... Apr 12 20:44:44 foo kernel: [125703.876985] x86: Booting SMP configuration: Apr 12 20:44:44 foo kernel: [125703.876986] smpboot: Booting Node 0 Processor 1 APIC 0x2 Apr 12 20:44:44 foo kernel: [125703.879643] cache: parent cpu1 should not be sleeping Apr 12 20:44:44 foo kernel: [125703.879765] CPU1 is up Apr 12 20:44:44 foo kernel: [125703.897009] smpboot: Booting Node 0 Processor 2 APIC 0x1 Apr 12 20:44:44 foo kernel: [125703.899677] cache: parent cpu2 should not be sleeping Apr 12 20:44:44 foo kernel: [125703.899805] CPU2 is up Apr 12 20:44:44 foo kernel: [125703.917045] smpboot: Booting Node 0 Processor 3 APIC 0x3 Apr 12 20:44:44 foo kernel: [125703.919731] cache: parent cpu3 should not be sleeping Apr 12 20:44:44 foo kernel: [125703.919834] CPU3 is up Apr 12 20:44:44 foo kernel: [125703.923368] ACPI: Waking up from system sleep state S3 Apr 12 20:44:44 foo kernel: [125704.864904] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI Apr 12 20:44:44 foo kernel: [125704.864970] PM: noirq resume of devices complete after 39.532 msecs Apr 12 20:44:44 foo kernel: [125704.899640] PM: early resume of devices complete after 34.635 msecs Apr 12 20:44:44 foo kernel: [125704.899896] usb usb1: root hub lost power or was reset Apr 12 20:44:44 foo kernel: [125704.899897] usb usb2: root hub lost power or was reset Apr 12 20:44:44 foo kernel: [125704.903910] rtc_cmos 00:01: System wakeup disabled by ACPI Apr 12 20:44:44 foo kernel: [125705.196800] ------------[ cut here ]------------ Apr 12 20:44:44 foo kernel: [125705.196818] WARNING: CPU: 1 PID: 30705 at drivers/gpu/drm/i915/intel_pm.c:3553 skl_update_other_pipe_wm+0x147/0x150 [i915]() Apr 12 20:44:44 foo kernel: [125705.196819] WARN_ON(!wm_changed) Apr 12 20:44:44 foo kernel: [125705.196843] Modules linked in: nls_utf8 btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c drbg ansi_cprng ctr ccm xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_hda_codec_hdmi bnep binfmt_misc dell_led snd_hda_codec_realtek snd_hda_codec_generic hid_multitouch intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp arc4 kvm_intel kvm dell_laptop irqbypass dcdbas i2c_designware_platform nls_iso8859_1 dell_wmi crct10dif_pclmul i2c_designware_core sparse_keymap crc32_pclmul ghash_clmulni_intel snd_soc_skl iwlmvm snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp aesni_intel mac80211 snd_hda_ext_core aes_x86_64 lrw snd_soc_sst_match gf128mul snd_soc_core glue_helper ablk_helper cryptd snd_compress iwlwifi ac97_bus snd_pcm_dmaengine dw_dmac_core rtsx_pci_ms cfg80211 memstick pcspkr i915 snd_hda_intel snd_hda_codec snd_hda_core uvcvideo serio_raw snd_hwdep videobuf2_vmalloc snd_pcm videobuf2_memops videobuf2_v4l2 snd_timer videobuf2_core snd videodev i2c_i801 soundcore drm_kms_helper media drm joydev input_leds idma64 i2c_algo_bit virt_dma fb_sys_fops btusb mei_me syscopyarea btrtl sysfillrect mei sysimgblt shpchp processor_thermal_device intel_soc_dts_iosf intel_lpss_pci wmi hci_uart btbcm btqca btintel bluetooth video intel_lpss_acpi intel_lpss int3403_thermal int340x_thermal_zone int3400_thermal acpi_thermal_rel acpi_pad mac_hid acpi_als kfifo_buf industrialio parport_pc ppdev lp parport autofs4 hid_generic usbhid rtsx_pci_sdmmc psmouse rtsx_pci nvme i2c_hid hid pinctrl_sunrisepoint pinctrl_intel fjes Apr 12 20:44:44 foo kernel: [125705.196873] CPU: 1 PID: 30705 Comm: kworker/u8:17 Tainted: G U W 4.5.0intsusp #1 Apr 12 20:44:44 foo kernel: [125705.196874] Hardware name: Dell Inc. XPS 13 9350/07TYC2, BIOS 1.0.0 09/10/2015 Apr 12 20:44:44 foo kernel: [125705.196877] Workqueue: events_unbound async_run_entry_fn Apr 12 20:44:44 foo kernel: [125705.196879] 0000000000000286 00000000c5dc1ff8 ffff880100b5b948 ffffffff813d9213 Apr 12 20:44:44 foo kernel: [125705.196880] ffff880100b5b990 ffffffffc05797f0 ffff880100b5b980 ffffffff8107ebf2 Apr 12 20:44:44 foo kernel: [125705.196881] ffff8802b68ab000 ffff880100b5ba0c ffff880036179bd4 ffff8802b52f0000 Apr 12 20:44:44 foo kernel: [125705.196882] Call Trace: Apr 12 20:44:44 foo kernel: [125705.196885] [] dump_stack+0x63/0x90 Apr 12 20:44:44 foo kernel: [125705.196888] [] warn_slowpath_common+0x82/0xc0 Apr 12 20:44:44 foo kernel: [125705.196889] [] warn_slowpath_fmt+0x5c/0x80 Apr 12 20:44:44 foo kernel: [125705.196899] [] skl_update_other_pipe_wm+0x147/0x150 [i915] Apr 12 20:44:44 foo kernel: [125705.196908] [] skl_update_wm+0x16a/0x5d0 [i915] Apr 12 20:44:44 foo kernel: [125705.196923] [] ? intel_ddi_enable_transcoder_func+0x17f/0x260 [i915] Apr 12 20:44:44 foo kernel: [125705.196933] [] intel_update_watermarks+0x1e/0x20 [i915] Apr 12 20:44:44 foo kernel: [125705.196947] [] haswell_crtc_enable+0x321/0x8c0 [i915] Apr 12 20:44:44 foo kernel: [125705.196961] [] intel_atomic_commit+0x73e/0x1880 [i915] Apr 12 20:44:44 foo kernel: [125705.196975] [] ? drm_atomic_check_only+0x181/0x600 [drm] Apr 12 20:44:44 foo kernel: [125705.196984] [] drm_atomic_commit+0x37/0x60 [drm] Apr 12 20:44:44 foo kernel: [125705.196998] [] intel_display_resume+0x10f/0x150 [i915] Apr 12 20:44:44 foo kernel: [125705.197006] [] i915_drm_resume+0xdd/0x170 [i915] Apr 12 20:44:44 foo kernel: [125705.197014] [] i915_pm_resume+0x25/0x30 [i915] Apr 12 20:44:44 foo kernel: [125705.197016] [] pci_pm_resume+0x64/0xa0 Apr 12 20:44:44 foo kernel: [125705.197017] [] ? pci_pm_thaw+0x90/0x90 Apr 12 20:44:44 foo kernel: [125705.197020] [] dpm_run_callback+0x4e/0x130 Apr 12 20:44:44 foo kernel: [125705.197021] [] device_resume+0xd3/0x1f0 Apr 12 20:44:44 foo kernel: [125705.197023] [] async_resume+0x1d/0x50 Apr 12 20:44:44 foo kernel: [125705.197024] [] async_run_entry_fn+0x48/0x150 Apr 12 20:44:44 foo kernel: [125705.197025] [] process_one_work+0x165/0x480 Apr 12 20:44:44 foo kernel: [125705.197027] [] worker_thread+0x4b/0x500 Apr 12 20:44:44 foo kernel: [125705.197028] [] ? process_one_work+0x480/0x480 Apr 12 20:44:44 foo kernel: [125705.197030] [] kthread+0xd8/0xf0 Apr 12 20:44:44 foo kernel: [125705.197031] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 20:44:44 foo kernel: [125705.197034] [] ret_from_fork+0x3f/0x70 Apr 12 20:44:44 foo kernel: [125705.197035] [] ? kthread_create_on_node+0x1a0/0x1a0 Apr 12 20:44:44 foo kernel: [125705.197036] ---[ end trace 3cc60a24822ab8de ]--- Apr 12 20:44:44 foo kernel: [125705.284846] usb 1-3: reset full-speed USB device number 3 using xhci_hcd Apr 12 20:44:44 foo kernel: [125705.637091] usb 1-5: reset high-speed USB device number 5 using xhci_hcd Apr 12 20:44:44 foo kernel: [125705.873932] restoring control 00000000-0000-0000-0000-000000000101/10/5 Apr 12 20:44:44 foo kernel: [125705.989077] usb 1-1: reset high-speed USB device number 16 using xhci_hcd Apr 12 20:44:44 foo kernel: [125706.174185] usb 1-1: device firmware changed Apr 12 20:44:44 foo kernel: [125706.174429] PM: resume of devices complete after 1274.728 msecs Apr 12 20:44:44 foo kernel: [125706.174518] usb 1-3:1.0: rebind failed: -517 Apr 12 20:44:44 foo kernel: [125706.174519] usb 1-3:1.1: rebind failed: -517 Apr 12 20:44:44 foo kernel: [125706.174768] PM: Finishing wakeup. Apr 12 20:44:44 foo kernel: [125706.174770] Restarting tasks ... Apr 12 20:44:44 foo kernel: [125706.174885] pci 0000:01:00.0: [8086:1576] type 01 class 0x060400 Apr 12 20:44:44 foo kernel: [125706.175025] pci 0000:01:00.0: supports D1 D2 Apr 12 20:44:44 foo kernel: [125706.175029] pci 0000:01:00.0: PME# supported from D0 D1 D2 D3hot D3cold Apr 12 20:44:44 foo kernel: [125706.175195] pci 0000:01:00.0: System wakeup disabled by ACPI Apr 12 20:44:44 foo kernel: [125706.182376] usb 1-1: USB disconnect, device number 16 Apr 12 20:44:44 foo kernel: [125706.182381] usb 1-1.1: USB disconnect, device number 17 Apr 12 20:44:44 foo kernel: [125706.182737] [drm] RC6 on Apr 12 20:44:44 foo kernel: [125706.185292] pci 0000:02:00.0: [8086:1576] type 01 class 0x060400 Apr 12 20:44:44 foo kernel: [125706.185431] pci 0000:02:00.0: supports D1 D2 Apr 12 20:44:44 foo kernel: [125706.185433] pci 0000:02:00.0: PME# supported from D0 D1 D2 D3hot D3cold Apr 12 20:44:44 foo kernel: [125706.185544] pci 0000:02:01.0: [8086:1576] type 01 class 0x060400 Apr 12 20:44:44 foo kernel: [125706.185670] pci 0000:02:01.0: supports D1 D2 Apr 12 20:44:44 foo kernel: [125706.185672] pci 0000:02:01.0: PME# supported from D0 D1 D2 D3hot D3cold Apr 12 20:44:44 foo kernel: [125706.185683] done. Apr 12 20:44:44 foo kernel: [125706.185774] pci 0000:02:02.0: [8086:1576] type 01 class 0x060400 Apr 12 20:44:44 foo systemd[1]: Time has been changed Apr 12 20:44:44 foo systemd[860]: Time has been changed Apr 12 20:44:44 foo systemd[1067]: Time has been changed Apr 12 20:44:44 foo systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 12 20:44:44 foo systemd[1]: Started Load/Save RF Kill Switch Status. Apr 12 20:44:44 foo kernel: [125706.201674] pci 0000:02:02.0: supports D1 D2 Apr 12 20:44:44 foo kernel: [125706.201679] pci 0000:02:02.0: PME# supported from D0 D1 D2 D3hot D3cold Apr 12 20:44:44 foo kernel: [125706.201843] pci 0000:01:00.0: PCI bridge to [bus 02-39] Apr 12 20:44:44 foo kernel: [125706.201854] pci 0000:01:00.0: bridge window [mem 0xc4000000-0xda0fffff] Apr 12 20:44:44 foo kernel: [125706.201861] pci 0000:01:00.0: bridge window [mem 0xa0000000-0xc1ffffff 64bit pref] Apr 12 20:44:44 foo kernel: [125706.201928] pci 0000:02:00.0: PCI bridge to [bus 03] Apr 12 20:44:44 foo kernel: [125706.201939] pci 0000:02:00.0: bridge window [mem 0xda000000-0xda0fffff] Apr 12 20:44:44 foo kernel: [125706.202003] pci 0000:02:01.0: PCI bridge to [bus 04-38] Apr 12 20:44:44 foo kernel: [125706.202013] pci 0000:02:01.0: bridge window [mem 0xc4000000-0xd9efffff] Apr 12 20:44:44 foo kernel: [125706.202020] pci 0000:02:01.0: bridge window [mem 0xa0000000-0xc1ffffff 64bit pref] Apr 12 20:44:44 foo kernel: [125706.202121] pci 0000:39:00.0: [8086:15b5] type 00 class 0x0c0330 Apr 12 20:44:44 foo kernel: [125706.202145] pci 0000:39:00.0: reg 0x10: [mem 0xd9f00000-0xd9f0ffff] Apr 12 20:44:44 foo kernel: [125706.202329] pci 0000:39:00.0: supports D1 D2 Apr 12 20:44:44 foo kernel: [125706.202331] pci 0000:39:00.0: PME# supported from D0 D1 D2 D3hot D3cold Apr 12 20:44:44 foo kernel: [125706.202472] pci 0000:02:02.0: PCI bridge to [bus 39] Apr 12 20:44:44 foo kernel: [125706.202482] pci 0000:02:02.0: bridge window [mem 0xd9f00000-0xd9ffffff] Apr 12 20:44:44 foo kernel: [125706.202515] pci_bus 0000:02: Allocating resources Apr 12 20:44:44 foo kernel: [125706.202549] pci 0000:02:01.0: bridge window [io 0x1000-0x0fff] to [bus 04-38] add_size 1000 Apr 12 20:44:44 foo kernel: [125706.202567] pci 0000:02:01.0: res[13]=[io 0x1000-0x0fff] res_to_dev_res add_size 1000 min_align 1000 Apr 12 20:44:44 foo kernel: [125706.202570] pci 0000:01:00.0: bridge window [io 0x1000-0x0fff] to [bus 02-39] add_size 1000 Apr 12 20:44:44 foo kernel: [125706.202573] pci 0000:01:00.0: res[13]=[io 0x1000-0x0fff] res_to_dev_res add_size 1000 min_align 1000 Apr 12 20:44:44 foo kernel: [125706.202575] pci 0000:01:00.0: res[13]=[io 0x1000-0x1fff] res_to_dev_res add_size 1000 min_align 1000 Apr 12 20:44:44 foo kernel: [125706.202578] pci 0000:01:00.0: BAR 13: assigned [io 0x2000-0x2fff] Apr 12 20:44:44 foo kernel: [125706.202581] pci 0000:02:01.0: res[13]=[io 0x1000-0x0fff] res_to_dev_res add_size 1000 min_align 1000 Apr 12 20:44:44 foo kernel: [125706.202582] pci 0000:02:01.0: res[13]=[io 0x1000-0x1fff] res_to_dev_res add_size 1000 min_align 1000 Apr 12 20:44:44 foo kernel: [125706.202584] pci 0000:02:01.0: BAR 13: assigned [io 0x2000-0x2fff] Apr 12 20:44:44 foo kernel: [125706.202586] pci 0000:02:00.0: PCI bridge to [bus 03] Apr 12 20:44:44 foo kernel: [125706.202592] pci 0000:02:00.0: bridge window [mem 0xda000000-0xda0fffff] Apr 12 20:44:44 foo kernel: [125706.202602] pci 0000:02:01.0: PCI bridge to [bus 04-38] Apr 12 20:44:44 foo kernel: [125706.202605] pci 0000:02:01.0: bridge window [io 0x2000-0x2fff] Apr 12 20:44:44 foo kernel: [125706.202611] pci 0000:02:01.0: bridge window [mem 0xc4000000-0xd9efffff] Apr 12 20:44:44 foo kernel: [125706.202615] pci 0000:02:01.0: bridge window [mem 0xa0000000-0xc1ffffff 64bit pref] Apr 12 20:44:44 foo kernel: [125706.202623] pci 0000:02:02.0: PCI bridge to [bus 39] Apr 12 20:44:44 foo kernel: [125706.202629] pci 0000:02:02.0: bridge window [mem 0xd9f00000-0xd9ffffff] Apr 12 20:44:44 foo kernel: [125706.202638] pci 0000:01:00.0: PCI bridge to [bus 02-39] Apr 12 20:44:44 foo kernel: [125706.202641] pci 0000:01:00.0: bridge window [io 0x2000-0x2fff] Apr 12 20:44:44 foo kernel: [125706.202646] pci 0000:01:00.0: bridge window [mem 0xc4000000-0xda0fffff] Apr 12 20:44:44 foo kernel: [125706.202651] pci 0000:01:00.0: bridge window [mem 0xa0000000-0xc1ffffff 64bit pref] Apr 12 20:44:44 foo kernel: [125706.203525] pcieport 0000:01:00.0: enabling device (0006 -> 0007) Apr 12 20:44:44 foo kernel: [125706.203926] pcieport 0000:02:01.0: enabling device (0006 -> 0007) Apr 12 20:44:44 foo kernel: [125706.204463] xhci_hcd 0000:39:00.0: xHCI Host Controller Apr 12 20:44:44 foo kernel: [125706.204470] xhci_hcd 0000:39:00.0: new USB bus registered, assigned bus number 3 Apr 12 20:44:44 foo kernel: [125706.205637] xhci_hcd 0000:39:00.0: hcc params 0x200077c1 hci version 0x100 quirks 0x00009810 Apr 12 20:44:44 foo kernel: [125706.207070] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002 Apr 12 20:44:44 foo kernel: [125706.207073] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Apr 12 20:44:44 foo kernel: [125706.207075] usb usb3: Product: xHCI Host Controller Apr 12 20:44:44 foo kernel: [125706.207077] usb usb3: Manufacturer: Linux 4.5.0intsusp xhci-hcd Apr 12 20:44:44 foo kernel: [125706.207079] usb usb3: SerialNumber: 0000:39:00.0 Apr 12 20:44:44 foo kernel: [125706.207295] hub 3-0:1.0: USB hub found Apr 12 20:44:44 foo kernel: [125706.207317] hub 3-0:1.0: 2 ports detected Apr 12 20:44:44 foo kernel: [125706.207424] xhci_hcd 0000:39:00.0: xHCI Host Controller Apr 12 20:44:44 foo kernel: [125706.207428] xhci_hcd 0000:39:00.0: new USB bus registered, assigned bus number 4 Apr 12 20:44:44 foo kernel: [125706.207466] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003 Apr 12 20:44:44 foo kernel: [125706.207468] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Apr 12 20:44:44 foo kernel: [125706.207470] usb usb4: Product: xHCI Host Controller Apr 12 20:44:44 foo kernel: [125706.207472] usb usb4: Manufacturer: Linux 4.5.0intsusp xhci-hcd Apr 12 20:44:44 foo kernel: [125706.207474] usb usb4: SerialNumber: 0000:39:00.0 Apr 12 20:44:44 foo kernel: [125706.207622] hub 4-0:1.0: USB hub found Apr 12 20:44:44 foo kernel: [125706.207641] hub 4-0:1.0: 2 ports detected Apr 12 20:44:44 foo kernel: [125706.208182] pci_bus 0000:02: Allocating resources Apr 12 20:44:44 foo kernel: [125706.211916] Bluetooth: hci0: read Intel version: 370810011003110e00 Apr 12 20:44:44 foo kernel: [125706.211922] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq Apr 12 20:44:44 foo systemd[1]: bluetooth.target: Unit not needed anymore. Stopping. Apr 12 20:44:44 foo systemd[1]: Stopped target Bluetooth. Apr 12 20:44:44 foo systemd-sleep[30956]: System resumed. Apr 12 20:44:44 foo systemd[1]: Started Suspend. Apr 12 20:44:44 foo systemd[1]: sleep.target: Unit not needed anymore. Stopping. Apr 12 20:44:44 foo systemd[1]: Stopped target Sleep. Apr 12 20:44:44 foo systemd[1]: Reached target Suspend. Apr 12 20:44:44 foo systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too. Apr 12 20:44:44 foo kernel: [125706.249987] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 20:44:44 foo kernel: [125706.250106] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 20:44:44 foo kernel: [125706.250292] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 20:44:44 foo systemd[1]: Stopped target Suspend. Apr 12 20:44:44 foo NetworkManager[678]: wake requested (sleeping: yes enabled: yes) Apr 12 20:44:44 foo NetworkManager[678]: waking up... Apr 12 20:44:44 foo NetworkManager[678]: (wlp58s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Apr 12 20:44:44 foo systemd[1]: Started Run anacron jobs at resume. Apr 12 20:44:44 foo systemd[1]: Started Run anacron jobs. Apr 12 20:44:44 foo anacron[31002]: Anacron 2.3 started on 2016-04-12 Apr 12 20:44:44 foo anacron[31002]: Normal exit (0 jobs run) Apr 12 20:44:44 foo kernel: [125706.293144] usb 2-1: new SuperSpeed USB device number 6 using xhci_hcd Apr 12 20:44:44 foo kernel: [125706.296953] usb 1-1.3: USB disconnect, device number 18 Apr 12 20:44:44 foo kernel: [125706.310426] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 20:44:44 foo kernel: [125706.310609] iwlwifi 0000:3a:00.0: L1 Enabled - LTR Disabled Apr 12 20:44:44 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 20:44:44 foo kernel: [125706.325100] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 20:44:44 foo kernel: [125706.341171] usb 1-1.4: USB disconnect, device number 19 Apr 12 20:44:44 foo NetworkManager[678]: (wlp58s0) supports 5 scan SSIDs Apr 12 20:44:44 foo NetworkManager[678]: (wlp58s0): supplicant interface state: starting -> ready Apr 12 20:44:44 foo NetworkManager[678]: (wlp58s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Apr 12 20:44:44 foo kernel: [125706.371070] IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready Apr 12 20:44:44 foo kernel: [125706.455088] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated Apr 12 20:44:44 foo bluetoothd[683]: Failed to obtain handles for "Service Changed" characteristic Apr 12 20:44:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 20:44:44 foo bluetoothd[683]: Error adding Link Loss service Apr 12 20:44:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 20:44:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 20:44:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 20:44:44 foo bluetoothd[683]: Current Time Service could not be registered Apr 12 20:44:44 foo bluetoothd[683]: gatt-time-server: Input/output error (5) Apr 12 20:44:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 20:44:44 foo bluetoothd[683]: Not enough free handles to register service Apr 12 20:44:44 foo bluetoothd[683]: Sap driver initialization failed. Apr 12 20:44:44 foo bluetoothd[683]: sap-server: Operation not permitted (1) Apr 12 20:44:44 foo systemd[1]: Reached target Bluetooth. Apr 12 20:44:44 foo kernel: [125706.524886] usb 3-1: new full-speed USB device number 2 using xhci_hcd Apr 12 20:44:44 foo kernel: [125706.548406] usb 2-1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 20:44:44 foo kernel: [125706.548409] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 20:44:44 foo kernel: [125706.548410] usb 2-1: Product: USB3.0 Hub Apr 12 20:44:44 foo kernel: [125706.548412] usb 2-1: Manufacturer: VIA Labs, Inc. Apr 12 20:44:44 foo kernel: [125706.551315] hub 2-1:1.0: USB hub found Apr 12 20:44:44 foo kernel: [125706.551512] hub 2-1:1.0: 4 ports detected Apr 12 20:44:44 foo kernel: [125706.636957] usb 1-1: new high-speed USB device number 20 using xhci_hcd Apr 12 20:44:44 foo kernel: [125706.654679] usb 3-1: New USB device found, idVendor=1fc9, idProduct=5002 Apr 12 20:44:44 foo kernel: [125706.654681] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 12 20:44:44 foo kernel: [125706.654682] usb 3-1: Product: PTN5002 Apr 12 20:44:44 foo kernel: [125706.654683] usb 3-1: Manufacturer: NXP Apr 12 20:44:44 foo kernel: [125706.654684] usb 3-1: SerialNumber: 0000064ef495 Apr 12 20:44:44 foo mtp-probe: checking bus 3, device 2: "/sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1" Apr 12 20:44:44 foo mtp-probe: bus: 3, device: 2 was not an MTP device Apr 12 20:44:44 foo kernel: [125706.824166] usb 1-1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 20:44:44 foo kernel: [125706.824170] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 20:44:44 foo kernel: [125706.824171] usb 1-1: Product: USB2.0 Hub Apr 12 20:44:44 foo kernel: [125706.824190] usb 1-1: Manufacturer: VIA Labs, Inc. Apr 12 20:44:44 foo kernel: [125706.824840] hub 1-1:1.0: USB hub found Apr 12 20:44:44 foo kernel: [125706.825186] hub 1-1:1.0: 4 ports detected Apr 12 20:44:44 foo kernel: [125706.925198] usb 2-1.1: new SuperSpeed USB device number 7 using xhci_hcd Apr 12 20:44:44 foo kernel: [125707.116975] usb 1-1.1: new high-speed USB device number 21 using xhci_hcd Apr 12 20:44:45 foo kernel: [125707.180591] usb 2-1.1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 20:44:45 foo kernel: [125707.180595] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 20:44:45 foo kernel: [125707.180597] usb 2-1.1: Product: USB3.0 Hub Apr 12 20:44:45 foo kernel: [125707.180599] usb 2-1.1: Manufacturer: VIA Labs, Inc. Apr 12 20:44:45 foo kernel: [125707.182933] hub 2-1.1:1.0: USB hub found Apr 12 20:44:45 foo kernel: [125707.183092] hub 2-1.1:1.0: 4 ports detected Apr 12 20:44:45 foo kernel: [125707.220008] usb 1-1.1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 20:44:45 foo kernel: [125707.220011] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 20:44:45 foo kernel: [125707.220012] usb 1-1.1: Product: USB2.0 Hub Apr 12 20:44:45 foo kernel: [125707.220031] usb 1-1.1: Manufacturer: VIA Labs, Inc. Apr 12 20:44:45 foo kernel: [125707.220926] hub 1-1.1:1.0: USB hub found Apr 12 20:44:45 foo kernel: [125707.221210] hub 1-1.1:1.0: 4 ports detected Apr 12 20:44:45 foo kernel: [125707.353083] usb 1-1.2: new low-speed USB device number 22 using xhci_hcd Apr 12 20:44:45 foo kernel: [125707.501461] usb 1-1.2: New USB device found, idVendor=047d, idProduct=2048 Apr 12 20:44:45 foo kernel: [125707.501464] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 20:44:45 foo kernel: [125707.501466] usb 1-1.2: Product: Kensington Eagle Trackball Apr 12 20:44:45 foo kernel: [125707.501467] usb 1-1.2: Manufacturer: Primax Apr 12 20:44:45 foo kernel: [125707.507042] input: Primax Kensington Eagle Trackball as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:047D:2048.0012/input/input59 Apr 12 20:44:45 foo kernel: [125707.507401] hid-generic 0003:047D:2048.0012: input,hidraw0: USB HID v1.11 Mouse [Primax Kensington Eagle Trackball] on usb-0000:00:14.0-1.2/input0 Apr 12 20:44:45 foo mtp-probe: checking bus 1, device 22: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2" Apr 12 20:44:45 foo mtp-probe: bus: 1, device: 22 was not an MTP device Apr 12 20:44:45 foo kernel: [125707.621100] usb 1-1.1.3: new low-speed USB device number 23 using xhci_hcd Apr 12 20:44:45 foo kernel: [125707.769748] usb 1-1.1.3: New USB device found, idVendor=04ca, idProduct=005d Apr 12 20:44:45 foo kernel: [125707.769751] usb 1-1.1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 20:44:45 foo kernel: [125707.769753] usb 1-1.1.3: Product: Goldtouch USB Keyboard Apr 12 20:44:45 foo kernel: [125707.769754] usb 1-1.1.3: Manufacturer: Lite-On Apr 12 20:44:45 foo kernel: [125707.774722] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.0/0003:04CA:005D.0013/input/input60 Apr 12 20:44:45 foo kernel: [125707.829674] hid-generic 0003:04CA:005D.0013: input,hidraw1: USB HID v1.10 Keyboard [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input0 Apr 12 20:44:45 foo kernel: [125707.834328] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.1/0003:04CA:005D.0014/input/input61 Apr 12 20:44:45 foo kernel: [125707.889088] hid-generic 0003:04CA:005D.0014: input,hidraw2: USB HID v1.10 Device [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input1 Apr 12 20:44:45 foo mtp-probe: checking bus 1, device 23: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3" Apr 12 20:44:45 foo mtp-probe: bus: 1, device: 23 was not an MTP device Apr 12 20:44:47 foo wpa_supplicant[776]: wlp58s0: Reject scan trigger since one is already pending Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: ready -> inactive Apr 12 20:44:47 foo NetworkManager[678]: Auto-activating connection 'eyrie 1'. Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): Activation: starting connection 'eyrie 1' (409e1be3-0c73-4b85-a584-18582397aee8) Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Apr 12 20:44:47 foo NetworkManager[678]: NetworkManager state is now CONNECTING Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) access point 'eyrie 1' has security, but secrets are required. Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): device state change: config -> need-auth (reason 'none') [50 60 0] Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): device state change: prepare -> config (reason 'none') [40 50 0] Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) connection 'eyrie 1' has security, and secrets exist. No new secrets needed. Apr 12 20:44:47 foo NetworkManager[678]: Config: added 'ssid' value 'eyrie' Apr 12 20:44:47 foo NetworkManager[678]: Config: added 'scan_ssid' value '1' Apr 12 20:44:47 foo NetworkManager[678]: Config: added 'key_mgmt' value 'WPA-PSK' Apr 12 20:44:47 foo NetworkManager[678]: Config: added 'auth_alg' value 'OPEN' Apr 12 20:44:47 foo NetworkManager[678]: Config: added 'psk' value '' Apr 12 20:44:47 foo NetworkManager[678]: Config: set interface ap_scan to 1 Apr 12 20:44:47 foo wpa_supplicant[776]: wlp58s0: SME: Trying to authenticate with e0:3f:49:9b:18:7a (SSID='eyrie' freq=2412 MHz) Apr 12 20:44:47 foo kernel: [125709.686920] wlp58s0: authenticate with e0:3f:49:9b:18:7a Apr 12 20:44:47 foo wpa_supplicant[776]: wlp58s0: Trying to associate with e0:3f:49:9b:18:7a (SSID='eyrie' freq=2412 MHz) Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: inactive -> associating Apr 12 20:44:47 foo kernel: [125709.689506] wlp58s0: send auth to e0:3f:49:9b:18:7a (try 1/3) Apr 12 20:44:47 foo kernel: [125709.691403] wlp58s0: authenticated Apr 12 20:44:47 foo kernel: [125709.693060] wlp58s0: associate with e0:3f:49:9b:18:7a (try 1/3) Apr 12 20:44:47 foo kernel: [125709.703607] wlp58s0: RX AssocResp from e0:3f:49:9b:18:7a (capab=0x411 status=0 aid=1) Apr 12 20:44:47 foo wpa_supplicant[776]: wlp58s0: Associated with e0:3f:49:9b:18:7a Apr 12 20:44:47 foo kernel: [125709.709838] wlp58s0: associated Apr 12 20:44:47 foo kernel: [125709.709934] IPv6: ADDRCONF(NETDEV_CHANGE): wlp58s0: link becomes ready Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associating -> associated Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: associated -> 4-way handshake Apr 12 20:44:47 foo wpa_supplicant[776]: wlp58s0: WPA: Key negotiation completed with e0:3f:49:9b:18:7a [PTK=CCMP GTK=CCMP] Apr 12 20:44:47 foo wpa_supplicant[776]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to e0:3f:49:9b:18:7a completed [id=0 id_str=] Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): supplicant interface state: 4-way handshake -> completed Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'eyrie'. Apr 12 20:44:47 foo NetworkManager[678]: (wlp58s0): device state change: config -> ip-config (reason 'none') [50 70 0] Apr 12 20:44:47 foo NetworkManager[678]: Activation (wlp58s0) Beginning DHCPv4 transaction (timeout in 45 seconds) Apr 12 20:44:47 foo NetworkManager[678]: dhclient started with pid 31121 Apr 12 20:44:47 foo dhclient[31121]: DHCPREQUEST of 192.168.1.103 on wlp58s0 to 255.255.255.255 port 67 Apr 12 20:44:48 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv6 with address fe80::de53:60ff:fecc:254a. Apr 12 20:44:48 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv6 for mDNS. Apr 12 20:44:48 foo avahi-daemon[635]: Registering new address record for fe80::de53:60ff:fecc:254a on wlp58s0.*. Apr 12 20:44:51 foo dhclient[31121]: DHCPREQUEST of 192.168.1.103 on wlp58s0 to 255.255.255.255 port 67 Apr 12 20:44:51 foo dhclient[31121]: DHCPACK of 192.168.1.103 from 192.168.1.1 Apr 12 20:44:51 foo NetworkManager[678]: address 192.168.1.103 Apr 12 20:44:51 foo NetworkManager[678]: plen 24 (255.255.255.0) Apr 12 20:44:51 foo NetworkManager[678]: gateway 192.168.1.1 Apr 12 20:44:51 foo NetworkManager[678]: server identifier 192.168.1.1 Apr 12 20:44:51 foo avahi-daemon[635]: Joining mDNS multicast group on interface wlp58s0.IPv4 with address 192.168.1.103. Apr 12 20:44:51 foo NetworkManager[678]: lease time 86400 Apr 12 20:44:51 foo NetworkManager[678]: hostname 'foo' Apr 12 20:44:51 foo NetworkManager[678]: nameserver '192.168.1.1' Apr 12 20:44:51 foo avahi-daemon[635]: New relevant interface wlp58s0.IPv4 for mDNS. Apr 12 20:44:51 foo NetworkManager[678]: domain name 'columbia.edu' Apr 12 20:44:51 foo avahi-daemon[635]: Registering new address record for 192.168.1.103 on wlp58s0.IPv4. Apr 12 20:44:51 foo NetworkManager[678]: (wlp58s0): DHCPv4 state changed unknown -> bound Apr 12 20:44:51 foo NetworkManager[678]: (wlp58s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Apr 12 20:44:51 foo dhclient[31121]: bound to 192.168.1.103 -- renewal in 36000 seconds. Apr 12 20:44:51 foo NetworkManager[678]: (wlp58s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Apr 12 20:44:51 foo NetworkManager[678]: (wlp58s0): device state change: secondaries -> activated (reason 'none') [90 100 0] Apr 12 20:44:51 foo NetworkManager[678]: NetworkManager state is now CONNECTED_LOCAL Apr 12 20:44:51 foo NetworkManager[678]: NetworkManager state is now CONNECTED_GLOBAL Apr 12 20:44:51 foo NetworkManager[678]: Policy set 'eyrie 1' (wlp58s0) as default for IPv4 routing and DNS. Apr 12 20:44:51 foo dnsmasq[930]: reading /etc/resolv.conf Apr 12 20:44:51 foo dnsmasq[930]: using nameserver 192.168.1.1#53 Apr 12 20:44:51 foo NetworkManager[678]: (wlp58s0): Activation: successful, device activated. Apr 12 20:44:51 foo dbus[645]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Apr 12 20:44:51 foo systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 12 20:44:52 foo dbus[645]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Apr 12 20:44:52 foo systemd[1]: Started Network Manager Script Dispatcher Service. Apr 12 20:44:52 foo nm-dispatcher: #1 'up' [wlp58s0]: new request (1 scripts) Apr 12 20:44:52 foo nm-dispatcher: #1 'up' [wlp58s0]: start running ordered scripts... Apr 12 20:44:52 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 20:44:52 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 20:44:52 foo systemd[1]: Started CUPS Scheduler. Apr 12 20:44:52 foo systemd[1]: Reloading OpenBSD Secure Shell server. Apr 12 20:44:52 foo systemd[1]: Reloaded OpenBSD Secure Shell server. Apr 12 20:45:13 foo systemd[1067]: Time has been changed Apr 12 20:45:13 foo systemd[860]: Time has been changed Apr 12 20:45:13 foo systemd[1]: Time has been changed Apr 12 20:45:13 foo systemd-timesyncd[562]: Synchronized to time server 173.230.144.178:123 (3.debian.pool.ntp.org). Apr 12 21:17:01 foo CRON[31743]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Apr 12 21:30:58 foo wpa_supplicant[776]: wlp58s0: WPA: Group rekeying completed with e0:3f:49:9b:18:7a [GTK=CCMP] Apr 12 22:17:01 foo CRON[32391]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Apr 12 22:24:08 foo kernel: [131671.230552] usb 1-1: USB disconnect, device number 20 Apr 12 22:24:08 foo kernel: [131671.230555] usb 1-1.1: USB disconnect, device number 21 Apr 12 22:24:08 foo kernel: [131671.230557] usb 1-1.1.3: USB disconnect, device number 23 Apr 12 22:24:08 foo kernel: [131671.315333] usb 2-1: USB disconnect, device number 6 Apr 12 22:24:08 foo kernel: [131671.315336] usb 2-1.1: USB disconnect, device number 7 Apr 12 22:24:08 foo kernel: [131671.347773] usb 1-1.2: USB disconnect, device number 22 Apr 12 22:24:09 foo kernel: [131672.551476] usb 1-1: new high-speed USB device number 24 using xhci_hcd Apr 12 22:24:09 foo kernel: [131672.603492] usb 2-1: new SuperSpeed USB device number 8 using xhci_hcd Apr 12 22:24:09 foo kernel: [131672.686612] usb 1-1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 22:24:09 foo kernel: [131672.686615] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:09 foo kernel: [131672.686616] usb 1-1: Product: USB2.0 Hub Apr 12 22:24:09 foo kernel: [131672.686618] usb 1-1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:09 foo kernel: [131672.687333] hub 1-1:1.0: USB hub found Apr 12 22:24:09 foo kernel: [131672.687627] hub 1-1:1.0: 4 ports detected Apr 12 22:24:09 foo kernel: [131672.858620] usb 2-1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 22:24:09 foo kernel: [131672.858624] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:09 foo kernel: [131672.858627] usb 2-1: Product: USB3.0 Hub Apr 12 22:24:09 foo kernel: [131672.858628] usb 2-1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:09 foo kernel: [131672.860467] hub 2-1:1.0: USB hub found Apr 12 22:24:09 foo kernel: [131672.860630] hub 2-1:1.0: 4 ports detected Apr 12 22:24:09 foo kernel: [131672.975311] usb 1-1.1: new high-speed USB device number 25 using xhci_hcd Apr 12 22:24:09 foo kernel: [131673.080816] usb 1-1.1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 22:24:09 foo kernel: [131673.080819] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:09 foo kernel: [131673.080820] usb 1-1.1: Product: USB2.0 Hub Apr 12 22:24:09 foo kernel: [131673.080821] usb 1-1.1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:09 foo kernel: [131673.081830] hub 1-1.1:1.0: USB hub found Apr 12 22:24:09 foo kernel: [131673.082183] hub 1-1.1:1.0: 4 ports detected Apr 12 22:24:10 foo kernel: [131673.215402] usb 1-1.2: new low-speed USB device number 26 using xhci_hcd Apr 12 22:24:10 foo kernel: [131673.235471] usb 2-1.1: new SuperSpeed USB device number 9 using xhci_hcd Apr 12 22:24:10 foo kernel: [131673.363576] usb 1-1.2: New USB device found, idVendor=047d, idProduct=2048 Apr 12 22:24:10 foo kernel: [131673.363580] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:10 foo kernel: [131673.363582] usb 1-1.2: Product: Kensington Eagle Trackball Apr 12 22:24:10 foo kernel: [131673.363584] usb 1-1.2: Manufacturer: Primax Apr 12 22:24:10 foo kernel: [131673.370755] input: Primax Kensington Eagle Trackball as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:047D:2048.0015/input/input62 Apr 12 22:24:10 foo kernel: [131673.372505] hid-generic 0003:047D:2048.0015: input,hidraw0: USB HID v1.11 Mouse [Primax Kensington Eagle Trackball] on usb-0000:00:14.0-1.2/input0 Apr 12 22:24:10 foo mtp-probe: checking bus 1, device 26: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2" Apr 12 22:24:10 foo mtp-probe: bus: 1, device: 26 was not an MTP device Apr 12 22:24:10 foo kernel: [131673.479393] usb 1-1.1.3: new low-speed USB device number 27 using xhci_hcd Apr 12 22:24:10 foo kernel: [131673.490896] usb 2-1.1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 22:24:10 foo kernel: [131673.490899] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:10 foo kernel: [131673.490901] usb 2-1.1: Product: USB3.0 Hub Apr 12 22:24:10 foo kernel: [131673.490902] usb 2-1.1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:10 foo kernel: [131673.493723] hub 2-1.1:1.0: USB hub found Apr 12 22:24:10 foo kernel: [131673.493882] hub 2-1.1:1.0: 4 ports detected Apr 12 22:24:10 foo kernel: [131673.627875] usb 1-1.1.3: New USB device found, idVendor=04ca, idProduct=005d Apr 12 22:24:10 foo kernel: [131673.627879] usb 1-1.1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:10 foo kernel: [131673.627881] usb 1-1.1.3: Product: Goldtouch USB Keyboard Apr 12 22:24:10 foo kernel: [131673.627883] usb 1-1.1.3: Manufacturer: Lite-On Apr 12 22:24:10 foo kernel: [131673.632205] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.0/0003:04CA:005D.0016/input/input63 Apr 12 22:24:10 foo kernel: [131673.687736] hid-generic 0003:04CA:005D.0016: input,hidraw1: USB HID v1.10 Keyboard [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input0 Apr 12 22:24:10 foo kernel: [131673.691817] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.1/0003:04CA:005D.0017/input/input64 Apr 12 22:24:10 foo kernel: [131673.747671] hid-generic 0003:04CA:005D.0017: input,hidraw2: USB HID v1.10 Device [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input1 Apr 12 22:24:10 foo mtp-probe: checking bus 1, device 27: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3" Apr 12 22:24:10 foo mtp-probe: bus: 1, device: 27 was not an MTP device Apr 12 22:24:19 foo kernel: [131682.175342] usb 1-1: USB disconnect, device number 24 Apr 12 22:24:19 foo kernel: [131682.175345] usb 1-1.1: USB disconnect, device number 25 Apr 12 22:24:19 foo kernel: [131682.175347] usb 1-1.1.3: USB disconnect, device number 27 Apr 12 22:24:19 foo kernel: [131682.364233] usb 1-1.2: USB disconnect, device number 26 Apr 12 22:24:19 foo kernel: [131682.441747] usb 2-1: USB disconnect, device number 8 Apr 12 22:24:19 foo kernel: [131682.441750] usb 2-1.1: USB disconnect, device number 9 Apr 12 22:24:20 foo kernel: [131683.795847] usb 1-1: new high-speed USB device number 28 using xhci_hcd Apr 12 22:24:20 foo kernel: [131683.826873] usb 2-1: new SuperSpeed USB device number 10 using xhci_hcd Apr 12 22:24:20 foo kernel: [131683.944061] usb 1-1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 22:24:20 foo kernel: [131683.944064] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:20 foo kernel: [131683.944065] usb 1-1: Product: USB2.0 Hub Apr 12 22:24:20 foo kernel: [131683.944067] usb 1-1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:20 foo kernel: [131683.944756] hub 1-1:1.0: USB hub found Apr 12 22:24:20 foo kernel: [131683.945149] hub 1-1:1.0: 4 ports detected Apr 12 22:24:20 foo kernel: [131684.082742] usb 2-1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 22:24:20 foo kernel: [131684.082745] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:20 foo kernel: [131684.082746] usb 2-1: Product: USB3.0 Hub Apr 12 22:24:20 foo kernel: [131684.082747] usb 2-1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:20 foo kernel: [131684.094177] hub 2-1:1.0: USB hub found Apr 12 22:24:20 foo kernel: [131684.094401] hub 2-1:1.0: 4 ports detected Apr 12 22:24:21 foo kernel: [131684.247719] usb 1-1.1: new high-speed USB device number 29 using xhci_hcd Apr 12 22:24:21 foo kernel: [131684.360812] usb 1-1.1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 22:24:21 foo kernel: [131684.360815] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:21 foo kernel: [131684.360817] usb 1-1.1: Product: USB2.0 Hub Apr 12 22:24:21 foo kernel: [131684.360818] usb 1-1.1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:21 foo kernel: [131684.361623] hub 1-1.1:1.0: USB hub found Apr 12 22:24:21 foo kernel: [131684.361960] hub 1-1.1:1.0: 4 ports detected Apr 12 22:24:21 foo kernel: [131684.467907] usb 2-1.1: new SuperSpeed USB device number 11 using xhci_hcd Apr 12 22:24:21 foo kernel: [131684.510806] usb 1-1.2: new low-speed USB device number 30 using xhci_hcd Apr 12 22:24:21 foo kernel: [131684.660111] usb 1-1.2: New USB device found, idVendor=047d, idProduct=2048 Apr 12 22:24:21 foo kernel: [131684.660116] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:21 foo kernel: [131684.660132] usb 1-1.2: Product: Kensington Eagle Trackball Apr 12 22:24:21 foo kernel: [131684.660133] usb 1-1.2: Manufacturer: Primax Apr 12 22:24:21 foo kernel: [131684.665820] input: Primax Kensington Eagle Trackball as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:047D:2048.0018/input/input65 Apr 12 22:24:21 foo kernel: [131684.665993] hid-generic 0003:047D:2048.0018: input,hidraw0: USB HID v1.11 Mouse [Primax Kensington Eagle Trackball] on usb-0000:00:14.0-1.2/input0 Apr 12 22:24:21 foo mtp-probe: checking bus 1, device 30: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2" Apr 12 22:24:21 foo mtp-probe: bus: 1, device: 30 was not an MTP device Apr 12 22:24:21 foo kernel: [131684.723139] usb 2-1.1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 22:24:21 foo kernel: [131684.723143] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:21 foo kernel: [131684.723145] usb 2-1.1: Product: USB3.0 Hub Apr 12 22:24:21 foo kernel: [131684.723147] usb 2-1.1: Manufacturer: VIA Labs, Inc. Apr 12 22:24:21 foo kernel: [131684.725645] hub 2-1.1:1.0: USB hub found Apr 12 22:24:21 foo kernel: [131684.725804] hub 2-1.1:1.0: 4 ports detected Apr 12 22:24:21 foo kernel: [131684.775675] usb 1-1.1.3: new low-speed USB device number 31 using xhci_hcd Apr 12 22:24:21 foo kernel: [131684.944523] usb 1-1.1.3: New USB device found, idVendor=04ca, idProduct=005d Apr 12 22:24:21 foo kernel: [131684.944527] usb 1-1.1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:24:21 foo kernel: [131684.944529] usb 1-1.1.3: Product: Goldtouch USB Keyboard Apr 12 22:24:21 foo kernel: [131684.944531] usb 1-1.1.3: Manufacturer: Lite-On Apr 12 22:24:21 foo kernel: [131684.949199] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.0/0003:04CA:005D.0019/input/input66 Apr 12 22:24:21 foo kernel: [131685.011808] hid-generic 0003:04CA:005D.0019: input,hidraw1: USB HID v1.10 Keyboard [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input0 Apr 12 22:24:21 foo kernel: [131685.015889] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.1/0003:04CA:005D.001A/input/input67 Apr 12 22:24:21 foo kernel: [131685.078287] hid-generic 0003:04CA:005D.001A: input,hidraw2: USB HID v1.10 Device [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input1 Apr 12 22:24:21 foo mtp-probe: checking bus 1, device 31: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3" Apr 12 22:24:21 foo mtp-probe: bus: 1, device: 31 was not an MTP device Apr 12 22:27:14 foo kernel: [131857.688694] usb 1-1: USB disconnect, device number 28 Apr 12 22:27:14 foo kernel: [131857.688697] usb 1-1.1: USB disconnect, device number 29 Apr 12 22:27:14 foo kernel: [131857.688698] usb 1-1.1.3: USB disconnect, device number 31 Apr 12 22:27:14 foo kernel: [131857.824437] usb 2-1: USB disconnect, device number 10 Apr 12 22:27:14 foo kernel: [131857.824440] usb 2-1.1: USB disconnect, device number 11 Apr 12 22:27:14 foo kernel: [131857.837263] usb 1-1.2: USB disconnect, device number 30 Apr 12 22:27:15 foo kernel: [131858.808465] usb 1-1: new high-speed USB device number 32 using xhci_hcd Apr 12 22:27:15 foo kernel: [131858.808649] usb 2-1: new SuperSpeed USB device number 12 using xhci_hcd Apr 12 22:27:15 foo kernel: [131858.995604] usb 1-1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 22:27:15 foo kernel: [131858.995607] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:27:15 foo kernel: [131858.995609] usb 1-1: Product: USB2.0 Hub Apr 12 22:27:15 foo kernel: [131858.995610] usb 1-1: Manufacturer: VIA Labs, Inc. Apr 12 22:27:15 foo kernel: [131858.996346] hub 1-1:1.0: USB hub found Apr 12 22:27:15 foo kernel: [131858.996646] hub 1-1:1.0: 4 ports detected Apr 12 22:27:15 foo kernel: [131859.064407] usb 2-1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 22:27:15 foo kernel: [131859.064410] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:27:15 foo kernel: [131859.064411] usb 2-1: Product: USB3.0 Hub Apr 12 22:27:15 foo kernel: [131859.064412] usb 2-1: Manufacturer: VIA Labs, Inc. Apr 12 22:27:15 foo kernel: [131859.073554] hub 2-1:1.0: USB hub found Apr 12 22:27:15 foo kernel: [131859.073740] hub 2-1:1.0: 4 ports detected Apr 12 22:27:16 foo kernel: [131859.292445] usb 1-1.1: new high-speed USB device number 33 using xhci_hcd Apr 12 22:27:16 foo kernel: [131859.394916] usb 1-1.1: New USB device found, idVendor=2109, idProduct=2812 Apr 12 22:27:16 foo kernel: [131859.394934] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:27:16 foo kernel: [131859.394936] usb 1-1.1: Product: USB2.0 Hub Apr 12 22:27:16 foo kernel: [131859.394937] usb 1-1.1: Manufacturer: VIA Labs, Inc. Apr 12 22:27:16 foo kernel: [131859.395569] hub 1-1.1:1.0: USB hub found Apr 12 22:27:16 foo kernel: [131859.395970] hub 1-1.1:1.0: 4 ports detected Apr 12 22:27:16 foo kernel: [131859.444671] usb 2-1.1: new SuperSpeed USB device number 13 using xhci_hcd Apr 12 22:27:16 foo kernel: [131859.528534] usb 1-1.2: new low-speed USB device number 34 using xhci_hcd Apr 12 22:27:16 foo kernel: [131859.691347] usb 1-1.2: New USB device found, idVendor=047d, idProduct=2048 Apr 12 22:27:16 foo kernel: [131859.691350] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:27:16 foo kernel: [131859.691352] usb 1-1.2: Product: Kensington Eagle Trackball Apr 12 22:27:16 foo kernel: [131859.691353] usb 1-1.2: Manufacturer: Primax Apr 12 22:27:16 foo mtp-probe: checking bus 1, device 34: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2" Apr 12 22:27:16 foo mtp-probe: bus: 1, device: 34 was not an MTP device Apr 12 22:27:16 foo kernel: [131859.696703] input: Primax Kensington Eagle Trackball as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:047D:2048.001B/input/input68 Apr 12 22:27:16 foo kernel: [131859.696827] hid-generic 0003:047D:2048.001B: input,hidraw0: USB HID v1.11 Mouse [Primax Kensington Eagle Trackball] on usb-0000:00:14.0-1.2/input0 Apr 12 22:27:16 foo kernel: [131859.700927] usb 2-1.1: New USB device found, idVendor=2109, idProduct=0812 Apr 12 22:27:16 foo kernel: [131859.700930] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:27:16 foo kernel: [131859.700931] usb 2-1.1: Product: USB3.0 Hub Apr 12 22:27:16 foo kernel: [131859.700932] usb 2-1.1: Manufacturer: VIA Labs, Inc. Apr 12 22:27:16 foo kernel: [131859.706147] hub 2-1.1:1.0: USB hub found Apr 12 22:27:16 foo kernel: [131859.706240] hub 2-1.1:1.0: 4 ports detected Apr 12 22:27:16 foo kernel: [131859.800357] usb 1-1.1.3: new low-speed USB device number 35 using xhci_hcd Apr 12 22:27:16 foo kernel: [131859.957356] usb 1-1.1.3: New USB device found, idVendor=04ca, idProduct=005d Apr 12 22:27:16 foo kernel: [131859.957360] usb 1-1.1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 12 22:27:16 foo kernel: [131859.957362] usb 1-1.1.3: Product: Goldtouch USB Keyboard Apr 12 22:27:16 foo kernel: [131859.957364] usb 1-1.1.3: Manufacturer: Lite-On Apr 12 22:27:16 foo kernel: [131859.962410] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.0/0003:04CA:005D.001C/input/input69 Apr 12 22:27:16 foo kernel: [131860.024552] hid-generic 0003:04CA:005D.001C: input,hidraw1: USB HID v1.10 Keyboard [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input0 Apr 12 22:27:16 foo kernel: [131860.028922] input: Lite-On Goldtouch USB Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3/1-1.1.3:1.1/0003:04CA:005D.001D/input/input70 Apr 12 22:27:16 foo kernel: [131860.091116] hid-generic 0003:04CA:005D.001D: input,hidraw2: USB HID v1.10 Device [Lite-On Goldtouch USB Keyboard] on usb-0000:00:14.0-1.1.3/input1 Apr 12 22:27:16 foo mtp-probe: checking bus 1, device 35: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1.3" Apr 12 22:27:16 foo mtp-probe: bus: 1, device: 35 was not an MTP device Apr 12 22:27:54 foo systemd[1]: Stopping User Manager for UID 115... Apr 12 22:27:54 foo systemd[1]: Stopping User Manager for UID 1000... Apr 12 22:27:54 foo systemd[1]: Stopping RealtimeKit Scheduling Policy Service... Apr 12 22:27:54 foo systemd[1]: Stopping Authenticate and Authorize Users to Run Privileged Tasks... Apr 12 22:27:54 foo systemd[1]: Stopped target Sound Card. Apr 12 22:27:54 foo rsyslogd: [origin software="rsyslogd" swVersion="8.16.0" x-pid="665" x-info="http://www.rsyslog.com"] exiting on signal 15.