Screen blank, audio choppy, system locked

Bug #1742867 reported by clickwir
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
Expired
Medium
Unassigned

Bug Description

While watching a YouTube video, screen went blank. Audio cut out, after a few seconds the audio started playing normally for a few more seconds then kept repeating the last half a second of audio for a few more seconds. Then it stopped and nothing responded.

It did this a few times over the course of an hour. Had to power off the PC to get a reboot. Last time it did this I ssh'd from another PC to get dmesg and syslog info as it happened. Attaching those captures.

clickwir@mach:~$ uname -a
Linux mach 4.13.0-25-generic #29-Ubuntu SMP Mon Jan 8 21:14:41 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

clickwir@mach:~$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 17.10
Release: 17.10
Codename: artful

#### dmesg ####

[ 10.136445] bond0: Enslaving enp7s0f1 as an active interface with an up link
[ 10.136497] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready
[ 10.144317] e1000e 0000:07:00.0 enp7s0f0: changing MTU from 1500 to 9000
[ 10.310070] e1000e 0000:07:00.1 enp7s0f1: changing MTU from 1500 to 9000
[ 10.625965] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 10.730200] r8169 0000:02:00.0 eth0: link down
[ 10.730246] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 12.573052] e1000e: enp7s0f0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[ 12.633055] e1000e: enp7s0f1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[ 16.875586] FS-Cache: Loaded
[ 16.896010] FS-Cache: Netfs 'nfs' registered for caching
[ 16.914353] NFS: Registering the id_resolver key type
[ 16.914364] Key type id_resolver registered
[ 16.914364] Key type id_legacy registered
[ 17.485539] ip6_tables: (C) 2000-2006 Netfilter Core Team
[ 17.513074] Ebtables v2.0 registered
[ 17.564084] radeon_dp_aux_transfer_native: 74 callbacks suppressed
[ 17.863232] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[ 17.864899] virbr0: port 1(virbr0-nic) entered blocking state
[ 17.864903] virbr0: port 1(virbr0-nic) entered disabled state
[ 17.864995] device virbr0-nic entered promiscuous mode
[ 17.960322] nf_conntrack version 0.5.0 (65536 buckets, 262144 max)
[ 18.038385] virbr0: port 1(virbr0-nic) entered blocking state
[ 18.038388] virbr0: port 1(virbr0-nic) entered listening state
[ 18.095412] virbr0: port 1(virbr0-nic) entered disabled state
[ 89.815180] radeon_dp_aux_transfer_native: 74 callbacks suppressed
[ 92.062606] show_signal_msg: 27 callbacks suppressed
[ 92.062608] xembedsniproxy[2507]: segfault at 2 ip 000055ea4a6890d7 sp 00007fff6c7a7c30 error 4 in xembedsniproxy[55ea4a67d000+13000]
[ 95.955166] radeon_dp_aux_transfer_native: 74 callbacks suppressed

### abnormal begins here ###

[ 1429.496584] sched: RT throttling activated
[ 1429.706303] clocksource: timekeeping watchdog on CPU3: Marking clocksource 'tsc' as unstable because the skew is too large:
[ 1429.706305] clocksource: 'hpet' wd_now: c4741f2e wd_last: c3bcdb60 mask: ffffffff
[ 1429.706306] clocksource: 'tsc' cs_now: 4acf553cc2d cs_last: 4ac71a54967 mask: ffffffffffffffff
[ 1429.706309] tsc: Marking TSC unstable due to clocksource watchdog
[ 1434.739539] nfs: server 10.1.0.4 not responding, still trying
[ 1437.469449] nfs: server 10.1.0.4 OK
[ 1439.143494] TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
[ 1439.143498] sched_clock: Marking unstable (1439092126811, 50992985)<-(1439477690212, -334199655)
[ 1440.403916] clocksource: Switched to clocksource hpet
[ 1443.553969] hrtimer: interrupt took 629117003 ns
[ 1454.039245] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 209.684 msecs
[ 1454.454671] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 44.646 msecs
[ 1454.454673] perf: interrupt took too long (349007 > 2500), lowering kernel.perf_event_max_sample_rate to 500
[ 1455.293492] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 61.329 msecs
[ 1455.293494] perf: interrupt took too long (479410 > 436258), lowering kernel.perf_event_max_sample_rate to 250
[ 1463.284343] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 172.103 msecs
[ 1463.284345] perf: interrupt took too long (1344829 > 599262), lowering kernel.perf_event_max_sample_rate to 250
[ 1465.175694] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 209.709 msecs
[ 1479.788229] perf: interrupt took too long (1849954 > 1681036), lowering kernel.perf_event_max_sample_rate to 250
[ 1481.889284] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 209.761 msecs
[ 1481.889284] perf: interrupt took too long (3252104 > 2312442), lowering kernel.perf_event_max_sample_rate to 250
[ 1491.745472] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 401.897 msecs
[ 1491.745472] perf: interrupt took too long (4443157 > 4065130), lowering kernel.perf_event_max_sample_rate to 250
[ 1500.339407] watchdog: BUG: soft lockup - CPU#7 stuck for 23s! [kworker/u16:5:228]
[ 1500.339410] Modules linked in: 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 libcrc32c ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter nfsv3 nfs_acl cfg80211 rpcsec_gss_krb5 auth_rpcgss nfsv4 nfs lockd grace fscache zram binfmt_misc nls_iso8859_1 snd_hda_codec_hdmi edac_mce_amd kvm_amd kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 input_leds snd_hda_intel snd_hda_codec crypto_simd glue_helper snd_hda_core cryptd snd_hwdep snd_seq_midi snd_seq_midi_event fam15h_power eeepc_wmi asus_wmi snd_rawmidi sparse_keymap video wmi_bmof k10temp snd_ctxfi snd_pcm snd_seq i2c_piix4 snd_seq_device
[ 1500.339445] snd_timer snd soundcore shpchp mac_hid bonding parport_pc ppdev lp parport sunrpc ip_tables x_tables autofs4 btrfs xor raid6_pq hid_generic usbhid hid amdkfd amd_iommu_v2 radeon i2c_algo_bit ttm e1000e drm_kms_helper syscopyarea firewire_ohci ptp sysfillrect firewire_core sysimgblt crc_itu_t fb_sys_fops pps_core ahci drm r8169 libahci mii wmi
[ 1500.339465] CPU: 7 PID: 228 Comm: kworker/u16:5 Not tainted 4.13.0-25-generic #29-Ubuntu
[ 1500.339465] Hardware name: To be filled by O.E.M. To be filled by O.E.M./M5A97 EVO, BIOS 1604 10/16/2012
[ 1500.339492] Workqueue: events_power_efficient radeon_fence_check_lockup [radeon]
[ 1500.339493] task: ffff99df17762e80 task.stack: ffffb91f43de4000
[ 1500.339512] RIP: 0010:evergreen_is_display_hung+0x125/0x1b0 [radeon]
[ 1500.339513] RSP: 0018:ffffb91f43de7d80 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff10
[ 1500.339515] RAX: 00000000ffffffff RBX: 0000000000000008 RCX: 0000000000000003
[ 1500.339515] RDX: 0000000000000003 RSI: 00000000000112a0 RDI: 00000000000550a7
[ 1500.339516] RBP: ffffb91f43de7dd8 R08: 0000000000000001 R09: 0000000000000000
[ 1500.339517] R10: ffff99df173f4000 R11: 0000000000000000 R12: ffff99df173f4000
[ 1500.339517] R13: 0000000000000002 R14: 000000000000003f R15: 0000000000000001
[ 1500.339518] FS: 0000000000000000(0000) GS:ffff99df3edc0000(0000) knlGS:0000000000000000
[ 1500.339519] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1500.339520] CR2: 00007f048862b000 CR3: 0000000560b5e000 CR4: 00000000000406e0
[ 1500.339520] Call Trace:
[ 1500.339542] evergreen_gpu_check_soft_reset+0xc5/0x120 [radeon]
[ 1500.339560] evergreen_gfx_is_lockup+0x17/0x40 [radeon]
[ 1500.339574] radeon_fence_check_lockup+0x93/0x180 [radeon]
[ 1500.339577] ? __schedule+0x293/0x880
[ 1500.339580] process_one_work+0x1e7/0x410
[ 1500.339581] worker_thread+0x4b/0x420
[ 1500.339583] kthread+0x125/0x140
[ 1500.339585] ? process_one_work+0x410/0x410
[ 1500.339586] ? kthread_create_on_node+0x70/0x70
[ 1500.339588] ret_from_fork+0x1f/0x30
[ 1500.339589] Code: ca 8b 04 95 40 90 70 c0 05 a0 6e 00 00 49 3b 84 24 b0 01 00 00 48 89 c6 72 07 3d ff ff 00 00 77 41 49 03 84 24 e8 01 00 00 8b 00 <39> 44 95 b8 74 05 f7 d3 41 21 de 83 c1 01 41 39 8c 24 98 26 00
[ 1504.114131] radeon 0000:01:00.0: ring 0 stalled for more than 30404msec
[ 1504.114139] radeon 0000:01:00.0: GPU lockup (current fence id 0x000000000001c40a last fence id 0x000000000001c40b on ring 0)

#### end dmesg ####

#### syslog ####

Jan 11 21:50:55 mach PackageKit: refresh-cache transaction /1263_aaaabccc from uid 1000 finished with success after 2337ms
Jan 11 21:50:58 mach PackageKit: get-updates transaction /1264_aaabeebe from uid 1000 finished with success after 2528ms
Jan 11 21:50:58 mach PackageKit: get-updates transaction /1265_cadbcaec from uid 1000 finished with success after 655ms
Jan 11 21:50:59 mach PackageKit: get-updates transaction /1266_abecebda from uid 1000 finished with success after 606ms
Jan 11 21:53:07 mach systemd[1]: Started Session 6 of user clickwir.
Jan 11 21:53:07 mach udev-acl.ck[4215]: g_slice_set_config: assertion 'sys_page_size == 0' failed
Jan 11 21:53:07 mach console-kit-daemon[2348]: missing action
Jan 11 21:53:17 mach systemd[1]: Started Session 7 of user clickwir.
Jan 11 21:53:17 mach udev-acl.ck[4309]: g_slice_set_config: assertion 'sys_page_size == 0' failed
Jan 11 21:53:17 mach console-kit-daemon[2348]: missing action
Jan 11 21:57:45 mach dbus[1073]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service'
Jan 11 21:59:36 mach systemd[1]: Starting Cleanup of Temporary Directories...
Jan 11 21:59:36 mach systemd-tmpfiles[4804]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring.
Jan 11 21:59:36 mach systemd[1]: Started Cleanup of Temporary Directories.
Jan 11 22:04:15 mach systemd[1]: Starting Message of the Day...
Jan 11 22:04:15 mach systemd[1]: Started Run anacron jobs.
Jan 11 22:04:15 mach anacron[4897]: Anacron 2.3 started on 2018-01-11
Jan 11 22:04:15 mach anacron[4897]: Normal exit (0 jobs run)
Jan 11 22:04:16 mach 50-motd-news[4896]: * Ubuntu Updates for the Meltdown / Spectre Vulnerabilities
Jan 11 22:04:16 mach 50-motd-news[4896]: - https://ubu.one/uMelt
Jan 11 22:04:16 mach systemd[1]: Started Message of the Day.

### abnormal begins here ###

Jan 11 22:08:10 mach kernel: [ 1429.496584] sched: RT throttling activated
Jan 11 22:08:10 mach kernel: [ 1429.706303] clocksource: timekeeping watchdog on CPU3: Marking clocksource 'tsc' as unstable because the skew is too large:
Jan 11 22:08:10 mach kernel: [ 1429.706305] clocksource: 'hpet' wd_now: c4741f2e wd_last: c3bcdb60 mask: ffffffff
Jan 11 22:08:10 mach kernel: [ 1429.706306] clocksource: 'tsc' cs_now: 4acf553cc2d cs_last: 4ac71a54967 mask: ffffffffffffffff
Jan 11 22:08:10 mach kernel: [ 1429.706309] tsc: Marking TSC unstable due to clocksource watchdog
Jan 11 22:08:15 mach kernel: [ 1434.739539] nfs: server 10.10.10.10 not responding, still trying
Jan 11 22:08:20 mach kernel: [ 1437.469449] nfs: server 10.10.10.10 OK
Jan 11 22:08:20 mach kernel: [ 1439.143494] TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
Jan 11 22:08:20 mach kernel: [ 1439.143498] sched_clock: Marking unstable (1439092126811, 50992985)<-(1439477690212, -334199655)
Jan 11 22:08:20 mach kernel: [ 1440.403916] clocksource: Switched to clocksource hpet
Jan 11 22:08:26 mach kernel: [ 1443.553969] hrtimer: interrupt took 629117003 ns
Jan 11 22:08:29 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 1196568 bytes (6232 ms).
Jan 11 22:08:35 mach kernel: [ 1454.039245] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 209.684 msecs
Jan 11 22:08:37 mach kernel: [ 1454.454671] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 44.646 msecs
Jan 11 22:08:37 mach kernel: [ 1454.454673] perf: interrupt took too long (349007 > 2500), lowering kernel.perf_event_max_sample_rate to 500
Jan 11 22:08:37 mach kernel: [ 1455.293492] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 61.329 msecs
Jan 11 22:08:38 mach kernel: [ 1455.293494] perf: interrupt took too long (479410 > 436258), lowering kernel.perf_event_max_sample_rate to 250
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_ctxfi'. Please report this issue to the ALSA developers.
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: snd_pcm_dump():
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: Hardware PCM card 0 'Creative X-Fi' device 0 subdevice 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: Its setup is:
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: stream : PLAYBACK
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: access : MMAP_INTERLEAVED
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: format : S16_LE
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: subformat : STD
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: channels : 2
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: rate : 48000
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: exact rate : 48000 (48000/1)
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: msbits : 16
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: buffer_size : 32768
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_size : 16384
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_time : 341333
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: tstamp_mode : ENABLE
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: tstamp_type : MONOTONIC
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_step : 1
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: avail_min : 31041
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_event : 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: start_threshold : -1
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: stop_threshold : 4611686018427387904
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: silence_threshold: 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: silence_size : 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: boundary : 4611686018427387904
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: appl_ptr : 5628650
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: hw_ptr : 5895024
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -2045036 bytes (-10651 ms).
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_ctxfi'. Please report this issue to the ALSA developers.
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: snd_pcm_dump():
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: Hardware PCM card 0 'Creative X-Fi' device 0 subdevice 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: Its setup is:
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: stream : PLAYBACK
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: access : MMAP_INTERLEAVED
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: format : S16_LE
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: subformat : STD
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: channels : 2
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: rate : 48000
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: exact rate : 48000 (48000/1)
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: msbits : 16
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: buffer_size : 32768
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_size : 16384
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_time : 341333
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: tstamp_mode : ENABLE
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: tstamp_type : MONOTONIC
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_step : 1
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: avail_min : 31041
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: period_event : 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: start_threshold : -1
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: stop_threshold : 4611686018427387904
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: silence_threshold: 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: silence_size : 0
Jan 11 22:08:38 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: boundary : 4611686018427387904
Jan 11 22:08:44 mach kernel: [ 1463.284343] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 172.103 msecs
Jan 11 22:08:44 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: appl_ptr : 5655530
Jan 11 22:08:45 mach kernel: [ 1463.284345] perf: interrupt took too long (1344829 > 599262), lowering kernel.perf_event_max_sample_rate to 250
Jan 11 22:08:48 mach kernel: [ 1465.175694] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 209.709 msecs
Jan 11 22:08:48 mach pulseaudio[2525]: [alsa-sink-ctxfi] alsa-util.c: hw_ptr : 6186922
Jan 11 22:08:49 mach sSMTP[5014]: Creating SSL connection to host
Jan 11 22:08:49 mach sSMTP[5014]: SSL connection using ECDHE_RSA_AES_256_GCM_SHA384
Jan 11 22:08:51 mach sSMTP[5014]: Sent mail for <email address hidden> (221 2.0.0 Bye) uid=999 username=netdata outbytes=9296
Jan 11 22:08:51 mach sSMTP[5028]: Creating SSL connection to host
Jan 11 22:08:51 mach sSMTP[5028]: SSL connection using ECDHE_RSA_AES_256_GCM_SHA384
Jan 11 22:08:53 mach sSMTP[5028]: Sent mail for <email address hidden> (221 2.0.0 Bye) uid=999 username=netdata outbytes=9326
Jan 11 22:09:00 mach kernel: [ 1479.788229] perf: interrupt took too long (1849954 > 1681036), lowering kernel.perf_event_max_sample_rate to 250

#### end syslog ####

ProblemType: Bug
DistroRelease: Ubuntu 17.10
Package: xorg 1:7.7+19ubuntu3
ProcVersionSignature: Ubuntu 4.13.0-25.29-generic 4.13.13
Uname: Linux 4.13.0-25-generic x86_64
ApportVersion: 2.20.7-0ubuntu3.7
Architecture: amd64
CompizPlugins: No value set for `/apps/compiz-1/general/screen0/options/active_plugins'
CompositorRunning: None
Date: Thu Jan 11 22:46:24 2018
DistUpgraded: 2017-10-17 21:26:23,088 DEBUG icon theme changed, re-reading
DistroCodename: artful
DistroVariant: ubuntu
ExtraDebuggingInterest: I just need to know a workaround
GraphicsCard:
 Advanced Micro Devices, Inc. [AMD/ATI] Turks XT [Radeon HD 6670/7670] [1002:6758] (prog-if 00 [VGA controller])
   Subsystem: Dell Radeon HD 6670 [1028:0b0e]
InstallationDate: Installed on 2015-02-14 (1063 days ago)
InstallationMedia: Kubuntu 14.10 "Utopic Unicorn" - Release amd64 (20141022.1)
LightdmGreeterLogOld:
 QInotifyFileSystemWatcherEngine::addPaths: inotify_add_watch failed: No such file or directory
 QFileSystemWatcher: failed to add paths: /var/lib/lightdm/.config/ibus/bus
 Bus::open: Can not get ibus-daemon's address.
 IBusInputContext::createInputContext: no connection to ibus-daemon
MachineType: To be filled by O.E.M. To be filled by O.E.M.
ProcEnviron:
 LANGUAGE=
 TERM=xterm-256color
 PATH=(custom, no user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.13.0-25-generic.efi.signed root=UUID=d68d35a1-918f-429a-815c-49d116bac1b5 ro
SourcePackage: xorg
Symptom: display
UpgradeStatus: Upgraded to artful on 2017-10-18 (86 days ago)
dmi.bios.date: 10/16/2012
dmi.bios.vendor: American Megatrends Inc.
dmi.bios.version: 1604
dmi.board.asset.tag: To be filled by O.E.M.
dmi.board.name: M5A97 EVO
dmi.board.vendor: ASUSTeK COMPUTER INC.
dmi.board.version: Rev 1.xx
dmi.chassis.asset.tag: To Be Filled By O.E.M.
dmi.chassis.type: 3
dmi.chassis.vendor: To Be Filled By O.E.M.
dmi.chassis.version: To Be Filled By O.E.M.
dmi.modalias: dmi:bvnAmericanMegatrendsInc.:bvr1604:bd10/16/2012:svnTobefilledbyO.E.M.:pnTobefilledbyO.E.M.:pvrTobefilledbyO.E.M.:rvnASUSTeKCOMPUTERINC.:rnM5A97EVO:rvrRev1.xx:cvnToBeFilledByO.E.M.:ct3:cvrToBeFilledByO.E.M.:
dmi.product.family: To be filled by O.E.M.
dmi.product.name: To be filled by O.E.M.
dmi.product.version: To be filled by O.E.M.
dmi.sys.vendor: To be filled by O.E.M.
version.compiz: compiz N/A
version.libdrm2: libdrm2 2.4.83-1
version.libgl1-mesa-dri: libgl1-mesa-dri 17.2.2-0ubuntu1
version.libgl1-mesa-glx: libgl1-mesa-glx 17.2.2-0ubuntu1
version.xserver-xorg-core: xserver-xorg-core 2:1.19.5-0ubuntu2
version.xserver-xorg-input-evdev: xserver-xorg-input-evdev 1:2.10.5-1ubuntu1
version.xserver-xorg-video-ati: xserver-xorg-video-ati 1:7.10.0-1
version.xserver-xorg-video-intel: xserver-xorg-video-intel 2:2.99.917+git20170309-0ubuntu1
version.xserver-xorg-video-nouveau: xserver-xorg-video-nouveau 1:1.0.15-2

Revision history for this message
clickwir (clickwir) wrote :
Revision history for this message
clickwir (clickwir) wrote :

Quick comment, before today I've never seen this happen on this PC. Now it's happened 4 times in the past couple hours.

Revision history for this message
clickwir (clickwir) wrote :

I used "ubuntu-bug" to gather this info. I see it set "ExtraDebuggingInterest: I just need to know a workaround" but that's not what I selected when it asked. I chose the option that was something like "Yes, but not if too technical".

Revision history for this message
clickwir (clickwir) wrote :
Download full text (6.8 KiB)

Happened again after watching about 7-9 minutes of YouTube.

#### syslog ####

Jan 12 21:38:57 mach kernel: [ 569.724268] sched: RT throttling activated
Jan 12 21:38:59 mach kernel: [ 571.401961] clocksource: timekeeping watchdog on CPU2: Marking clocksource 'tsc' as unstable because the skew is too large:
Jan 12 21:38:59 mach kernel: [ 571.401981] clocksource: 'hpet' wd_now: e7f33546 wd_last: e543f369 mask: ffffffff
Jan 12 21:38:59 mach kernel: [ 571.401986] clocksource: 'tsc' cs_now: 1ea1fa20651 cs_last: 1e7e50167fd mask: ffffffffffffffff
Jan 12 21:38:59 mach kernel: [ 571.401991] tsc: Marking TSC unstable due to clocksource watchdog
Jan 12 21:38:59 mach kernel: [ 571.403034] TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
Jan 12 21:38:59 mach kernel: [ 571.403037] sched_clock: Marking unstable (571388047245, 14818071)<-(571736398266, -333366693)
Jan 12 21:39:06 mach kernel: [ 576.435061] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 209.713 msecs
Jan 12 21:39:06 mach kernel: [ 576.435064] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 1258.275 msecs
Jan 12 21:39:06 mach kernel: [ 576.435065] perf: interrupt took too long (9830397 > 2500), lowering kernel.perf_event_max_sample_rate to 250
Jan 12 21:39:06 mach rtkit-daemon[2525]: The canary thread is apparently starving. Taking action.
Jan 12 21:39:06 mach rtkit-daemon[2525]: Demoting known real-time threads.
Jan 12 21:39:06 mach rtkit-daemon[2525]: Successfully demoted thread 2555 of process 2523 (n/a).
Jan 12 21:39:06 mach rtkit-daemon[2525]: Successfully demoted thread 2554 of process 2523 (n/a).
Jan 12 21:39:06 mach rtkit-daemon[2525]: Successfully demoted thread 2523 of process 2523 (n/a).
Jan 12 21:39:06 mach rtkit-daemon[2525]: Demoted 3 threads.
Jan 12 21:39:43 mach kernel: [ 594.681033] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 419.422 msecs
Jan 12 21:39:43 mach kernel: [ 597.617006] hrtimer: interrupt took 1258213518 ns
Jan 12 21:39:43 mach kernel: [ 604.118141] watchdog: BUG: soft lockup - CPU#7 stuck for 21s! [ksoftirqd/7:52]
Jan 12 21:39:43 mach kernel: [ 604.118144]...

Read more...

Revision history for this message
clickwir (clickwir) wrote :
Download full text (59.9 KiB)

Happened again after just a few minutes of watching. Tried not watching YouTube for a while and it was fine for about 20 mins.

#### dmesg ####

[ 2441.656816] clocksource: timekeeping watchdog on CPU2: Marking clocksource 'tsc' as unstable because the skew is too large:
[ 2441.656819] clocksource: 'hpet' wd_now: 23e5cdb2 wd_last: 2300b853 mask: ffffffff
[ 2441.656820] clocksource: 'tsc' cs_now: 7e4398e6b37 cs_last: 7e389faed6b mask: ffffffffffffffff
[ 2441.656822] tsc: Marking TSC unstable due to clocksource watchdog
[ 2446.689848] hrtimer: interrupt took 1048512639 ns
[ 2450.464784] nfs: server 10.1.0.4 not responding, still trying
[ 2461.579468] sched: RT throttling activated
[ 2462.627985] INFO: NMI handler (perf_ibs_nmi_handler) took too long to run: 419.422 msecs
[ 2462.627988] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 838.852 msecs
[ 2462.627990] perf: interrupt took too long (6553849 > 4096258), lowering kernel.perf_event_max_sample_rate to 250
[ 2464.305681] watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [kworker/u16:1:4770]
[ 2464.305684] Modules linked in: 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 libcrc32c ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter nfsv3 nfs_acl cfg80211 rpcsec_gss_krb5 auth_rpcgss nfsv4 nfs lockd grace fscache zram binfmt_misc nls_iso8859_1 snd_hda_codec_hdmi edac_mce_amd kvm_amd kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc input_leds aesni_intel aes_x86_64 crypto_simd glue_helper cryptd eeepc_wmi asus_wmi sparse_keymap video snd_hda_intel snd_ctxfi snd_hda_codec k10temp snd_hda_core wmi_bmof snd_hwdep fam15h_power snd_pcm snd_seq_midi snd_seq_midi_event i2c_piix4 snd_rawmidi snd_seq snd_seq_device
[ 2464.305717] snd_timer snd soundcore shpchp mac_hid bonding parport_pc ppdev sunrpc lp parport ip_tables x_tables autofs4 btrfs xor raid6_pq hid_generic usbhid hid amdkfd amd_iommu_v2 radeon i2c_algo_bit ttm drm_kms_helper e1000e syscopyarea sysfillrect firewire_ohci sysimgblt ptp fb_sys_fops pps_core firewire_core crc_itu_t drm ahci r8169 libahci mii wmi
[ 2464.305738] CPU: 2 PID: 4770 Comm: kworker/u16:1 Not tainted 4.13.0-25-generic #29-Ubuntu
[ 2464.305739] Hardware name: To be filled by O.E.M. To be filled by O.E.M./M5A97 EVO, BIOS 1604 10/16/2012
[ 2464.305765] Workqueue: events_power_efficient radeon_fence_check_lockup [radeon]
[ 2464.305766] task: ffff9a5eeb535d00 task.stack: ffffb3d203218000
[ 2464.305788] RIP: 0010:evergreen_is_display_hung+0x125/0x1b0 [radeon]
[ 2464.305789] RSP: 0018:ffffb3d20321bd80 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff10
[ 2464.305791] RAX: 00000000ffffffff RBX: 0000000000000001 RCX: 0000000000000000
[ 2464.305792] RDX: 0000000000000000 RSI: 0000000000006ea0 RDI: 00000000000550ba
[ 2464.305792] RBP: ffffb3d20321bdd8 R08: 0000000000000001 R09: 0000000000000000
[ 2464.305793] R10: ffff9a5f18678000 R11: 0000000000000000 R12: ffff9a5f18678000
[ 2464.305794] R13: 0000000000000004 R14: 000000000000003f R15: 00...

Revision history for this message
clickwir (clickwir) wrote :

xorg was chosen by the bug utility, I did not select xorg. Problem appears to be with latest kernel, did not happen prior.

affects: xorg (Ubuntu) → linux (Ubuntu)
Revision history for this message
Ubuntu Kernel Bot (ubuntu-kernel-bot) wrote : Status changed to Confirmed

This change was made by a bot.

Changed in linux (Ubuntu):
status: New → Confirmed
Revision history for this message
Joseph Salisbury (jsalisbury) wrote :

Does this bug go away if you boot back into the prior kernel?

Revision history for this message
Joseph Salisbury (jsalisbury) wrote :

Would it be possible for you to test the latest upstream kernel? Refer to https://wiki.ubuntu.com/KernelMainlineBuilds . Please test the latest v4.15 kernel[0].

If this bug is fixed in the mainline kernel, please add the following tag 'kernel-fixed-upstream'.

If the mainline kernel does not fix this bug, please add the tag: 'kernel-bug-exists-upstream'.

Once testing of the upstream kernel is complete, please mark this bug as "Confirmed".

Thanks in advance.

[0] http://kernel.ubuntu.com/~kernel-ppa/mainline/v4.15-rc8

Changed in linux (Ubuntu):
importance: Undecided → Medium
status: Confirmed → Incomplete
Revision history for this message
clickwir (clickwir) wrote :
Download full text (107.1 KiB)

Installed 4.15 rc8 and same issue.

#### dmesg ####

[ 1265.953008] sched: RT throttling activated
[ 1265.953018] clocksource: timekeeping watchdog on CPU4: Marking clocksource 'tsc' as unstable because the skew is too large:
[ 1265.953021] clocksource: 'hpet' wd_now: 38b37199 wd_last: 3829ff32 mask: ffffffff
[ 1265.953022] clocksource: 'tsc' cs_now: 4262fdbe767 cs_last: 425d7d7d680 mask: ffffffffffffffff
[ 1265.953023] tsc: Marking TSC unstable due to clocksource watchdog
[ 1265.953040] TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
[ 1265.953041] sched_clock: Marking unstable (1265908240846, 44771742)<-(1266267179035, -314139659)
[ 1275.809138] clocksource: Switched to clocksource hpet
[ 1299.951513] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 108.138 msecs
[ 1299.951516] perf: interrupt took too long (845222 > 2500), lowering kernel.perf_event_max_sample_rate to 250
[ 1300.790347] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 137.277 msecs
[ 1300.790351] perf: interrupt took too long (1072756 > 1056527), lowering kernel.perf_event_max_sample_rate to 250
[ 1306.558101] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 208.273 msecs
[ 1306.558101] perf: interrupt took too long (1627614 > 1340945), lowering kernel.perf_event_max_sample_rate to 250
[ 1307.396931] hrtimer: interrupt took 629121891 ns
[ 1310.123102] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 209.705 msecs
[ 1323.540307] radeon 0000:01:00.0: ring 0 stalled for more than 19176msec
[ 1323.540312] radeon 0000:01:00.0: GPU lockup (current fence id 0x0000000000022c50 last fence id 0x0000000000022c51 on ring 0)
[ 1323.540321] perf: interrupt took too long (2198839 > 2034517), lowering kernel.perf_event_max_sample_rate to 250
[ 1337.804353] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 209.718 msecs
[ 1337.804353] perf: interrupt took too long (3803000 > 2748548), lowering kernel.perf_event_max_sample_rate to 250
[ 1340.945936] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 209.758 msecs
[ 1342.623577] INFO: NMI handler (perf_event_nmi_handler) took too long to run: 393.159 msecs
[ 1352.270069] watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [kworker/u16:2:4609]
[ 1352.270071] Modules linked in: 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 libcrc32c ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter nfsv3 nfs_acl cfg80211 rpcsec_gss_krb5 auth_rpcgss nfsv4 nfs lockd grace fscache zram binfmt_misc nls_iso8859_1 edac_mce_amd kvm_amd kvm irqbypass crct10dif_pclmul crc32_pclmul snd_hda_codec_hdmi ghash_clmulni_intel pcbc snd_hda_intel input_leds snd_hda_codec snd_hda_core aesni_intel snd_hwdep snd_seq_midi aes_x86_64 snd_seq_midi_event crypto_simd glue_helper cryptd snd_rawmidi snd_ctxfi snd_seq snd_pcm wmi_bmof k10temp eeepc_wmi asus_wmi sparse_keymap video snd_seq_device fam15h_power snd_timer
[ 1352.270108] i2c_piix4 snd s...

tags: added: kernel-bug-exists-upstream
Revision history for this message
clickwir (clickwir) wrote :

Tested on 4.15 rc8

Changed in linux (Ubuntu):
status: Incomplete → Confirmed
Revision history for this message
clickwir (clickwir) wrote :

I tried 4.15 rc8, same result. Went back one rev from my GRUB to 4.13.0-21 and saw the same result. Looking at the dmesg and syslog output, there were a lot of references to the video system. Grabbed another video card, slightly older and put that in. The fan on the one that came out didn't feel like it was spinning as freely as I would assume.

Card may have simply been overheating when playing YouTube. New card has almost 1 hour of YouTube playback now with no problems on 4.13.0-25.

Odd that this issue happened right with the reboot to the newer kernel, but if that's all it was then job done. If I see any of the same behavior I will post again.

Changed in linux (Ubuntu):
status: Confirmed → Incomplete
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for linux (Ubuntu) because there has been no activity for 60 days.]

Changed in linux (Ubuntu):
status: Incomplete → Expired
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.