Peter Chant
2018-02-25 22:38:40 UTC
I've seen some odd stuff in the syslog. It may have been occurring for
a while as I've had no reason to check for a while. However, I've just
migrated from 4.15.4 - which was solid to 4.15.5 which has locked up a
couple of times. I've now moved back to 4.15.4.
Anyway, I could not see anything in /var/log/messages just before the
freeze. Looking in syslog I see the following, I'm not sure whether
they are relevant.
Any thoughts?
Feb 21 21:46:34 phoenix pulseaudio[2046]: [alsa-sink-VT1708S Analog]
alsa-sink.c: Error opening PCM device front:0: Device or reso
urce busy
Feb 21 22:02:46 phoenix pulseaudio[2046]: [alsa-sink-VT1708S Analog]
alsa-sink.c: Error opening PCM device front:0: Device or reso
urce busy
Feb 21 22:40:45 phoenix pulseaudio[2046]: [pulseaudio] sink-input.c:
Failed to create sink input: sink is suspended.
Feb 21 23:34:48 phoenix kernel: [291624.446220] hrtimer: interrupt took
3795105 ns
Feb 22 15:02:02 phoenix pulseaudio[2046]: [pulseaudio] sink-input.c:
Failed to create sink input: sink is suspended.
Feb 23 01:53:02 phoenix pulseaudio[2046]: [pulseaudio] sink-input.c:
Failed to create sink input: sink is suspended.
Feb 23 20:14:32 phoenix pulseaudio[9615]: [pulseaudio] server-lookup.c:
Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSup
ported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Feb 23 20:14:32 phoenix pulseaudio[9615]: [pulseaudio] main.c: Unable to
contact D-Bus: org.freedesktop.DBus.Error.NotSupported: U
nable to autolaunch a dbus-daemon without a $DISPLAY for X11
Feb 23 20:14:32 phoenix pulseaudio[9615]: [pulseaudio] bluez5-util.c:
GetManagedObjects() failed: org.freedesktop.DBus.Error.Servi
ceUnknown: The name org.bluez was not provided by any .service files
Feb 24 07:31:10 phoenix kernel: [493014.453748] CE: hpet increased
min_delta_ns to 1000000 nsec
Feb 24 07:32:32 phoenix kernel: [493096.971414] CE: Reprogramming
failure. Giving up
Feb 24 07:32:50 phoenix kernel: [493115.070901] CE: Reprogramming
failure. Giving up
Feb 24 07:33:17 phoenix kernel: [493141.885687] CE: Reprogramming
failure. Giving up
Also:
eb 25 18:12:18 phoenix pulseaudio[4690]: [pulseaudio] bluez5-util.c:
GetManagedObjects() failed: org.freedesktop.DBus.Error.ServiceUnknown:
The name org.bluez was not provided by any .service files
Feb 25 18:12:18 phoenix pulseaudio[4698]: [pulseaudio] pid.c: Daemon
already running.
Feb 25 18:13:21 phoenix kernel: [ 215.524953] NFSD: Unable to end grace
period: -110
Feb 25 18:16:55 phoenix kernel: [ 429.806736] CE: hpet increased
min_delta_ns to 20115 nsec
Feb 25 18:16:55 phoenix kernel: [ 430.123118] CE: hpet increased
min_delta_ns to 30172 nsec
Feb 25 18:16:55 phoenix kernel: [ 430.128894] CE: hpet increased
min_delta_ns to 45258 nsec
Feb 25 18:17:14 phoenix kernel: [ 448.174710] CE: hpet increased
min_delta_ns to 67887 nsec
Feb 25 18:19:35 phoenix kernel: [ 589.915288] CE: hpet increased
min_delta_ns to 101830 nsec
Feb 25 18:20:59 phoenix kernel: [ 674.143749] CE: hpet increased
min_delta_ns to 152745 nsec
Feb 25 18:21:02 phoenix kernel: [ 677.063819] CE: hpet increased
min_delta_ns to 229117 nsec
Feb 25 18:25:12 phoenix kernel: [ 926.973403] CE: hpet increased
min_delta_ns to 343675 nsec
Feb 25 18:25:14 phoenix kernel: [ 928.388881] CE: hpet increased
min_delta_ns to 515512 nsec
Feb 25 18:25:27 phoenix kernel: [ 941.272120] CE: hpet increased
min_delta_ns to 773268 nsec
Feb 25 20:12:04 phoenix kernel: [ 7339.004682] CE: hpet increased
min_delta_ns to 1000000 nsec
Feb 25 20:12:10 phoenix kernel: [ 7344.483663] CE: Reprogramming
failure. Giving up
Feb 25 20:12:10 phoenix kernel: [ 7345.338026] CE: Reprogramming
failure. Giving up
Feb 25 20:15:14 phoenix kernel: [ 7529.017725] CE: Reprogramming
failure. Giving up
Feb 25 20:16:08 phoenix kernel: [ 7582.752362] CE: Reprogramming
failure. Giving up
Feb 25 20:16:17 phoenix kernel: [ 7591.658957] CE: Reprogramming
failure. Giving up
Feb 25 20:16:30 phoenix kernel: [ 7605.160754] CE: Reprogramming
failure. Giving up
Feb 25 20:17:06 phoenix kernel: [ 7640.923962] CE: Reprogramming
failure. Giving up
Feb 25 20:29:56 phoenix kernel: [ 8411.100556] CE: Reprogramming
failure. Giving up
Feb 25 20:29:56 phoenix kernel: [ 8411.107076] CE: Reprogramming
failure. Giving up
And:
Feb 25 18:11:24 phoenix kernel: [ 98.620721] hwmon acpi_cpufreq ehci_hcd
Feb 25 18:11:24 phoenix kernel: [ 98.620730] CPU: 5 PID: 2119 Comm:
lxc-start Not tainted 4.15.4 #1
Feb 25 18:11:24 phoenix kernel: [ 98.620733] Hardware name: System
manufacturer System Product Name/M4A78 PRO, BIOS 1701 08/1
6/2010
Feb 25 18:11:24 phoenix kernel: [ 98.620739] RIP:
0010:ovl_getattr+0x132/0x1d0
Feb 25 18:11:24 phoenix kernel: [ 98.620742] RSP:
0018:ffffba7042987d78 EFLAGS: 00010297
Feb 25 18:11:24 phoenix kernel: [ 98.620746] RAX: 000000000000003c
RBX: ffffba7042987ea8 RCX: 0000000000001000
Feb 25 18:11:24 phoenix kernel: [ 98.620748] RDX: 0000000000000000
RSI: fffffffffffff000 RDI: ffff970af7fcdb58
Feb 25 18:11:24 phoenix kernel: [ 98.620751] RBP: 0000000000000000
R08: ffffba7042987d88 R09: ffff970af7fcdad0
Feb 25 18:11:24 phoenix kernel: [ 98.620753] R10: 0000000000000000
R11: 00007366746f6f72 R12: 0000000000004000
Feb 25 18:11:24 phoenix kernel: [ 98.620755] R13: 0000000000000000
R14: ffff970ae06830c0 R15: ffff970ae5c26300
Feb 25 18:11:24 phoenix kernel: [ 98.620759] FS:
00007f61c1a3b780(0000) GS:ffff970b2fd40000(0000) knlGS:0000000000000000
Feb 25 18:11:24 phoenix kernel: [ 98.620762] CS: 0010 DS: 0000 ES:
0000 CR0: 0000000080050033
Feb 25 18:11:24 phoenix kernel: [ 98.620764] CR2: 00007ffc82489db8
CR3: 00000001defa8000 CR4: 00000000000006e0
Feb 25 18:11:24 phoenix kernel: [ 98.620767] Call Trace:
Feb 25 18:11:24 phoenix kernel: [ 98.620781] vfs_statx+0x79/0xb0
Feb 25 18:11:24 phoenix kernel: [ 98.620788] SYSC_newlstat+0x26/0x40
Feb 25 18:11:24 phoenix kernel: [ 98.620795] do_syscall_64+0x71/0x130
Feb 25 18:11:24 phoenix kernel: [ 98.620801]
entry_SYSCALL_64_after_hwframe+0x21/0x86
Feb 25 18:11:24 phoenix kernel: [ 98.620806] RIP: 0033:0x7f61c0cde835
Feb 25 18:11:24 phoenix kernel: [ 98.620808] RSP:
002b:00007ffc82489ca8 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
Feb 25 18:11:24 phoenix kernel: [ 98.620812] RAX: ffffffffffffffda
RBX: 00007ffc8248ae50 RCX: 00007f61c0cde835
Feb 25 18:11:24 phoenix kernel: [ 98.620814] RDX: 00007ffc82489cf0
RSI: 00007ffc82489cf0 RDI: 00007ffc82489e50
Feb 25 18:11:24 phoenix kernel: [ 98.620816] RBP: 00007ffc82489db0
R08: 0000000000000000 R09: 00007f61c07c1900
Feb 25 18:11:24 phoenix kernel: [ 98.620818] R10: 0000000000000006
R11: 0000000000000246 R12: 00007ffc82489e50
Feb 25 18:11:24 phoenix kernel: [ 98.620821] R13: 00007ffc82489e6c
R14: 00000000018c3506 R15: 00000000018c350c
Feb 25 18:11:24 phoenix kernel: [ 98.620824] Code: 49 8b 77 30 bf 02
00 00 00 e8 4b fb ff ff 84 c0 74 09 48 8b 44 24 40 48 89 43
20 48 83 3c 24 00 74 4d 8b 44 24 48 39 43 28 74 02 <0f> ff 48 83 3c 24
00 74 49 49 8b 47 68 8b 40 10 89 43 28 66 41
Feb 25 18:11:24 phoenix kernel: [ 98.620893] ---[ end trace
260b2a52d2c84b4c ]---
a while as I've had no reason to check for a while. However, I've just
migrated from 4.15.4 - which was solid to 4.15.5 which has locked up a
couple of times. I've now moved back to 4.15.4.
Anyway, I could not see anything in /var/log/messages just before the
freeze. Looking in syslog I see the following, I'm not sure whether
they are relevant.
Any thoughts?
Feb 21 21:46:34 phoenix pulseaudio[2046]: [alsa-sink-VT1708S Analog]
alsa-sink.c: Error opening PCM device front:0: Device or reso
urce busy
Feb 21 22:02:46 phoenix pulseaudio[2046]: [alsa-sink-VT1708S Analog]
alsa-sink.c: Error opening PCM device front:0: Device or reso
urce busy
Feb 21 22:40:45 phoenix pulseaudio[2046]: [pulseaudio] sink-input.c:
Failed to create sink input: sink is suspended.
Feb 21 23:34:48 phoenix kernel: [291624.446220] hrtimer: interrupt took
3795105 ns
Feb 22 15:02:02 phoenix pulseaudio[2046]: [pulseaudio] sink-input.c:
Failed to create sink input: sink is suspended.
Feb 23 01:53:02 phoenix pulseaudio[2046]: [pulseaudio] sink-input.c:
Failed to create sink input: sink is suspended.
Feb 23 20:14:32 phoenix pulseaudio[9615]: [pulseaudio] server-lookup.c:
Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSup
ported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Feb 23 20:14:32 phoenix pulseaudio[9615]: [pulseaudio] main.c: Unable to
contact D-Bus: org.freedesktop.DBus.Error.NotSupported: U
nable to autolaunch a dbus-daemon without a $DISPLAY for X11
Feb 23 20:14:32 phoenix pulseaudio[9615]: [pulseaudio] bluez5-util.c:
GetManagedObjects() failed: org.freedesktop.DBus.Error.Servi
ceUnknown: The name org.bluez was not provided by any .service files
Feb 24 07:31:10 phoenix kernel: [493014.453748] CE: hpet increased
min_delta_ns to 1000000 nsec
Feb 24 07:32:32 phoenix kernel: [493096.971414] CE: Reprogramming
failure. Giving up
Feb 24 07:32:50 phoenix kernel: [493115.070901] CE: Reprogramming
failure. Giving up
Feb 24 07:33:17 phoenix kernel: [493141.885687] CE: Reprogramming
failure. Giving up
Also:
eb 25 18:12:18 phoenix pulseaudio[4690]: [pulseaudio] bluez5-util.c:
GetManagedObjects() failed: org.freedesktop.DBus.Error.ServiceUnknown:
The name org.bluez was not provided by any .service files
Feb 25 18:12:18 phoenix pulseaudio[4698]: [pulseaudio] pid.c: Daemon
already running.
Feb 25 18:13:21 phoenix kernel: [ 215.524953] NFSD: Unable to end grace
period: -110
Feb 25 18:16:55 phoenix kernel: [ 429.806736] CE: hpet increased
min_delta_ns to 20115 nsec
Feb 25 18:16:55 phoenix kernel: [ 430.123118] CE: hpet increased
min_delta_ns to 30172 nsec
Feb 25 18:16:55 phoenix kernel: [ 430.128894] CE: hpet increased
min_delta_ns to 45258 nsec
Feb 25 18:17:14 phoenix kernel: [ 448.174710] CE: hpet increased
min_delta_ns to 67887 nsec
Feb 25 18:19:35 phoenix kernel: [ 589.915288] CE: hpet increased
min_delta_ns to 101830 nsec
Feb 25 18:20:59 phoenix kernel: [ 674.143749] CE: hpet increased
min_delta_ns to 152745 nsec
Feb 25 18:21:02 phoenix kernel: [ 677.063819] CE: hpet increased
min_delta_ns to 229117 nsec
Feb 25 18:25:12 phoenix kernel: [ 926.973403] CE: hpet increased
min_delta_ns to 343675 nsec
Feb 25 18:25:14 phoenix kernel: [ 928.388881] CE: hpet increased
min_delta_ns to 515512 nsec
Feb 25 18:25:27 phoenix kernel: [ 941.272120] CE: hpet increased
min_delta_ns to 773268 nsec
Feb 25 20:12:04 phoenix kernel: [ 7339.004682] CE: hpet increased
min_delta_ns to 1000000 nsec
Feb 25 20:12:10 phoenix kernel: [ 7344.483663] CE: Reprogramming
failure. Giving up
Feb 25 20:12:10 phoenix kernel: [ 7345.338026] CE: Reprogramming
failure. Giving up
Feb 25 20:15:14 phoenix kernel: [ 7529.017725] CE: Reprogramming
failure. Giving up
Feb 25 20:16:08 phoenix kernel: [ 7582.752362] CE: Reprogramming
failure. Giving up
Feb 25 20:16:17 phoenix kernel: [ 7591.658957] CE: Reprogramming
failure. Giving up
Feb 25 20:16:30 phoenix kernel: [ 7605.160754] CE: Reprogramming
failure. Giving up
Feb 25 20:17:06 phoenix kernel: [ 7640.923962] CE: Reprogramming
failure. Giving up
Feb 25 20:29:56 phoenix kernel: [ 8411.100556] CE: Reprogramming
failure. Giving up
Feb 25 20:29:56 phoenix kernel: [ 8411.107076] CE: Reprogramming
failure. Giving up
And:
Feb 25 18:11:24 phoenix kernel: [ 98.620721] hwmon acpi_cpufreq ehci_hcd
Feb 25 18:11:24 phoenix kernel: [ 98.620730] CPU: 5 PID: 2119 Comm:
lxc-start Not tainted 4.15.4 #1
Feb 25 18:11:24 phoenix kernel: [ 98.620733] Hardware name: System
manufacturer System Product Name/M4A78 PRO, BIOS 1701 08/1
6/2010
Feb 25 18:11:24 phoenix kernel: [ 98.620739] RIP:
0010:ovl_getattr+0x132/0x1d0
Feb 25 18:11:24 phoenix kernel: [ 98.620742] RSP:
0018:ffffba7042987d78 EFLAGS: 00010297
Feb 25 18:11:24 phoenix kernel: [ 98.620746] RAX: 000000000000003c
RBX: ffffba7042987ea8 RCX: 0000000000001000
Feb 25 18:11:24 phoenix kernel: [ 98.620748] RDX: 0000000000000000
RSI: fffffffffffff000 RDI: ffff970af7fcdb58
Feb 25 18:11:24 phoenix kernel: [ 98.620751] RBP: 0000000000000000
R08: ffffba7042987d88 R09: ffff970af7fcdad0
Feb 25 18:11:24 phoenix kernel: [ 98.620753] R10: 0000000000000000
R11: 00007366746f6f72 R12: 0000000000004000
Feb 25 18:11:24 phoenix kernel: [ 98.620755] R13: 0000000000000000
R14: ffff970ae06830c0 R15: ffff970ae5c26300
Feb 25 18:11:24 phoenix kernel: [ 98.620759] FS:
00007f61c1a3b780(0000) GS:ffff970b2fd40000(0000) knlGS:0000000000000000
Feb 25 18:11:24 phoenix kernel: [ 98.620762] CS: 0010 DS: 0000 ES:
0000 CR0: 0000000080050033
Feb 25 18:11:24 phoenix kernel: [ 98.620764] CR2: 00007ffc82489db8
CR3: 00000001defa8000 CR4: 00000000000006e0
Feb 25 18:11:24 phoenix kernel: [ 98.620767] Call Trace:
Feb 25 18:11:24 phoenix kernel: [ 98.620781] vfs_statx+0x79/0xb0
Feb 25 18:11:24 phoenix kernel: [ 98.620788] SYSC_newlstat+0x26/0x40
Feb 25 18:11:24 phoenix kernel: [ 98.620795] do_syscall_64+0x71/0x130
Feb 25 18:11:24 phoenix kernel: [ 98.620801]
entry_SYSCALL_64_after_hwframe+0x21/0x86
Feb 25 18:11:24 phoenix kernel: [ 98.620806] RIP: 0033:0x7f61c0cde835
Feb 25 18:11:24 phoenix kernel: [ 98.620808] RSP:
002b:00007ffc82489ca8 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
Feb 25 18:11:24 phoenix kernel: [ 98.620812] RAX: ffffffffffffffda
RBX: 00007ffc8248ae50 RCX: 00007f61c0cde835
Feb 25 18:11:24 phoenix kernel: [ 98.620814] RDX: 00007ffc82489cf0
RSI: 00007ffc82489cf0 RDI: 00007ffc82489e50
Feb 25 18:11:24 phoenix kernel: [ 98.620816] RBP: 00007ffc82489db0
R08: 0000000000000000 R09: 00007f61c07c1900
Feb 25 18:11:24 phoenix kernel: [ 98.620818] R10: 0000000000000006
R11: 0000000000000246 R12: 00007ffc82489e50
Feb 25 18:11:24 phoenix kernel: [ 98.620821] R13: 00007ffc82489e6c
R14: 00000000018c3506 R15: 00000000018c350c
Feb 25 18:11:24 phoenix kernel: [ 98.620824] Code: 49 8b 77 30 bf 02
00 00 00 e8 4b fb ff ff 84 c0 74 09 48 8b 44 24 40 48 89 43
20 48 83 3c 24 00 74 4d 8b 44 24 48 39 43 28 74 02 <0f> ff 48 83 3c 24
00 74 49 49 8b 47 68 8b 40 10 89 43 28 66 41
Feb 25 18:11:24 phoenix kernel: [ 98.620893] ---[ end trace
260b2a52d2c84b4c ]---