0

I was running a spring web server in ubuntu on aws ec2. The server unexpectedly encountered a status check error during off-duty hours and forced a restart.

From the monitoring tool, it seems that the server did not work normally after a few minutes after the CPU increased rapidly.

After the forced restart, it worked normally, and when I checked the system log, it was as follows.

Oct  6 17:48:49 ip-12-0-10-30 systemd[1]: Starting Daily apt download activities...
Oct  6 17:48:54 ip-12-0-10-30 dbus-daemon[531]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.327' (uid=0 pid=98303 comm="/usr/bin/gdbus call --system --dest org.freedeskto" label="unconfined")
Oct  6 17:48:54 ip-12-0-10-30 PackageKit: daemon start
Oct  6 17:48:54 ip-12-0-10-30 systemd[1]: Starting PackageKit Daemon...
Oct  6 17:48:54 ip-12-0-10-30 dbus-daemon[531]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Oct  6 17:48:54 ip-12-0-10-30 systemd[1]: Started PackageKit Daemon.
Oct  6 17:54:00 ip-12-0-10-30 PackageKit: daemon quit
Oct  6 17:54:00 ip-12-0-10-30 systemd[1]: packagekit.service: Succeeded.
Oct  6 18:17:03 ip-12-0-10-30 CRON[98618]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Oct  6 18:29:05 ip-12-0-10-30 systemd[1]: snapd.service: Watchdog timeout (limit 5min)!
Oct  6 18:29:05 ip-12-0-10-30 systemd[1]: snapd.service: Killing process 62550 (snapd) with signal SIGABRT.
Oct  6 18:29:10 ip-12-0-10-30 snapd[62550]: SIGABRT: abort
Oct  6 18:29:10 ip-12-0-10-30 snapd[62550]: PC=0x55568c42a791 m=0 sigcode=0
Oct  6 18:29:10 ip-12-0-10-30 snapd[62550]: goroutine 0 [idle]:
Oct  6 18:29:11 ip-12-0-10-30 snapd[62550]: runtime.futex(0x55568def64e8, 0x80, 0x0, 0x0, 0xc000000000, 0x7ffc63c1fd50, 0x55568c3fe065, 0xc000055648, 0x7ffc63c1fd70, 0x55568c3d3b83, ...)
Oct  6 18:29:11 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/sys_linux_amd64.s:535 +0x21
Oct  6 18:29:11 ip-12-0-10-30 snapd[62550]: runtime.futexsleep(0x55568def64e8, 0x7ffc00000000, 0xffffffffffffffff)
Oct  6 18:29:11 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/os_linux.go:44 +0x46
Oct  6 18:29:11 ip-12-0-10-30 snapd[62550]: runtime.notesleep(0x55568def64e8)
Oct  6 18:29:11 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/lock_futex.go:151 +0xa3
Oct  6 18:29:12 ip-12-0-10-30 snapd[62550]: runtime.stoplockedm()
Oct  6 18:29:12 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/proc.go:2068 +0x8c
Oct  6 18:29:13 ip-12-0-10-30 snapd[62550]: runtime.schedule()
Oct  6 18:29:13 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/proc.go:2469 +0x489
Oct  6 18:29:13 ip-12-0-10-30 snapd[62550]: runtime.park_m(0xc000302d80)
Oct  6 18:29:13 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/proc.go:2610 +0xa3
Oct  6 18:29:14 ip-12-0-10-30 snapd[62550]: runtime.mcall(0x0)
Oct  6 18:29:14 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/asm_amd64.s:318 +0x53
Oct  6 18:29:15 ip-12-0-10-30 snapd[62550]: goroutine 1 [select, 13464 minutes]:
Oct  6 18:29:15 ip-12-0-10-30 snapd[62550]: main.run(0xc00033c6c0, 0x0, 0x0)
Oct  6 18:29:16 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/cmd/snapd/main.go:153 +0x4e5
Oct  6 18:29:17 ip-12-0-10-30 snapd[62550]: main.main()
Oct  6 18:29:17 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/cmd/snapd/main.go:64 +0x10e
Oct  6 18:29:18 ip-12-0-10-30 snapd[62550]: goroutine 19 [syscall, 13464 minutes]:
Oct  6 18:29:19 ip-12-0-10-30 snapd[62550]: os/signal.signal_recv(0x0)
Oct  6 18:29:19 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/sigqueue.go:147 +0x9e
Oct  6 18:29:20 ip-12-0-10-30 snapd[62550]: os/signal.loop()
Oct  6 18:29:20 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/os/signal/signal_unix.go:23 +0x24
Oct  6 18:29:20 ip-12-0-10-30 snapd[62550]: created by os/signal.init.0
Oct  6 18:29:20 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/os/signal/signal_unix.go:29 +0x43
Oct  6 18:29:21 ip-12-0-10-30 snapd[62550]: goroutine 40 [semacquire]:
Oct  6 18:29:21 ip-12-0-10-30 snapd[62550]: sync.runtime_SemacquireMutex(0xc0000ea074, 0x55568c3d1e01, 0x1)
Oct  6 18:29:22 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/sema.go:71 +0x49
Oct  6 18:29:22 ip-12-0-10-30 snapd[62550]: sync.(*Mutex).lockSlow(0xc0000ea070)
Oct  6 18:29:22 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/sync/mutex.go:138 +0xfe
Oct  6 18:29:22 ip-12-0-10-30 snapd[62550]: sync.(*Mutex).Lock(...)
Oct  6 18:29:22 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/sync/mutex.go:81
Oct  6 18:29:23 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/state.(*State).Lock(0xc0000ea070)
Oct  6 18:29:23 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/state/state.go:122 +0x4e
Oct  6 18:29:23 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/snapstate.(*SnapManager).localInstallCleanup(0xc0002ce9c0, 0x0, 0x0)
Oct  6 18:29:24 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/snapstate/snapmgr.go:1027 +0x53
Oct  6 18:29:24 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/snapstate.(*SnapManager).Ensure(0xc0002ce9c0, 0x0, 0x0)
Oct  6 18:29:24 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/snapstate/snapmgr.go:1087 +0x192
Oct  6 18:29:24 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord.(*StateEngine).Ensure(0xc000444e10, 0x0, 0x0)
Oct  6 18:29:25 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/stateengine.go:147 +0x11e
Oct  6 18:29:25 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord.(*Overlord).Loop.func1(0x55568c3cda75, 0xc00052dc80)
Oct  6 18:29:25 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/overlord.go:454 +0x64
Oct  6 18:29:25 ip-12-0-10-30 snapd[62550]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc0000b6550, 0xc0006f8e80)
Oct  6 18:29:25 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d
Oct  6 18:29:26 ip-12-0-10-30 snapd[62550]: created by gopkg.in/tomb%2ev2.(*Tomb).Go
Oct  6 18:29:26 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9
Oct  6 18:29:26 ip-12-0-10-30 snapd[62550]: goroutine 42 [runnable]:
Oct  6 18:29:26 ip-12-0-10-30 snapd[62550]: net.(*sysDialer).dialUnix(0xc000064dd0, 0x55568d7b3e80, 0xc0000ac058, 0x0, 0xc000568160, 0xc000568160, 0x7f58bc0031f1, 0xc000064d08)
Oct  6 18:29:27 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:153 +0x137
Oct  6 18:29:27 ip-12-0-10-30 snapd[62550]: net.DialUnix(0x55568ce66870, 0x8, 0x0, 0xc000568160, 0x0, 0x0, 0x0)
Oct  6 18:29:27 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock.go:210 +0x106
Oct  6 18:29:27 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/systemd.SdNotify(0x55568ce687d7, 0xa, 0x0, 0x0)
Oct  6 18:29:28 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/systemd/sdnotify.go:51 +0x136
Oct  6 18:29:28 ip-12-0-10-30 snapd[62550]: main.runWatchdog.func1(0xc0000b65f0, 0xc00001e000)
Oct  6 18:29:28 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/cmd/snapd/main.go:98 +0x4c
Oct  6 18:29:28 ip-12-0-10-30 snapd[62550]: created by main.runWatchdog
Oct  6 18:29:29 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/cmd/snapd/main.go:91 +0x1e2
Oct  6 18:29:29 ip-12-0-10-30 snapd[62550]: goroutine 43 [IO wait, 13464 minutes]:
Oct  6 18:29:29 ip-12-0-10-30 snapd[62550]: internal/poll.runtime_pollWait(0x7f58bc20ff08, 0x72, 0x0)
Oct  6 18:29:29 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/netpoll.go:184 +0x57
Oct  6 18:29:30 ip-12-0-10-30 snapd[62550]: internal/poll.(*pollDesc).wait(0xc0000f9618, 0x72, 0x0, 0x0, 0x55568ce64611)
Oct  6 18:29:30 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:87 +0x47
Oct  6 18:29:30 ip-12-0-10-30 snapd[62550]: internal/poll.(*pollDesc).waitRead(...)
Oct  6 18:29:30 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:92
Oct  6 18:29:31 ip-12-0-10-30 snapd[62550]: internal/poll.(*FD).Accept(0xc0000f9600, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
Oct  6 18:29:31 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_unix.go:384 +0x1fa
Oct  6 18:29:32 ip-12-0-10-30 snapd[62550]: net.(*netFD).accept(0xc0000f9600, 0x203000, 0x0, 0x0)
Oct  6 18:29:32 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/fd_unix.go:238 +0x44
Oct  6 18:29:33 ip-12-0-10-30 snapd[62550]: net.(*UnixListener).accept(0xc000456120, 0xc000466090, 0x30, 0x30)
Oct  6 18:29:33 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:162 +0x34
Oct  6 18:29:33 ip-12-0-10-30 snapd[62550]: net.(*UnixListener).Accept(0xc000456120, 0xc000466090, 0x55568d7723f0, 0xc000307d28, 0xc000171c00)
Oct  6 18:29:33 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock.go:260 +0x49
Oct  6 18:29:33 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/daemon.(*ucrednetListener).Accept(0xc000456180, 0x55568d6d5440, 0xc000466090, 0x55568d605dc0, 0x55568de93030)
Oct  6 18:29:34 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/daemon/ucrednet.go:112 +0x4a
Oct  6 18:29:34 ip-12-0-10-30 snapd[62550]: net/http.(*Server).Serve(0xc00027c000, 0x55568d7ad480, 0xc000456180, 0x0, 0x0)
Oct  6 18:29:34 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/http/server.go:2896 +0x282
Oct  6 18:29:34 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/daemon.(*Daemon).Start.func1.1(0x0, 0x0)
Oct  6 18:29:34 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/daemon/daemon.go:370 +0x4b
Oct  6 18:29:35 ip-12-0-10-30 snapd[62550]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc00001e050, 0xc000464b00)
Oct  6 18:29:35 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d
Oct  6 18:29:36 ip-12-0-10-30 snapd[62550]: created by gopkg.in/tomb%2ev2.(*Tomb).Go
Oct  6 18:29:36 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9
Oct  6 18:29:36 ip-12-0-10-30 snapd[62550]: goroutine 48 [syscall, 13464 minutes]:
Oct  6 18:29:37 ip-12-0-10-30 snapd[62550]: syscall.Syscall6(0x17, 0xa, 0xc00030b628, 0x0, 0x0, 0x0, 0x0, 0xc000302300, 0x200000003, 0xc000302300)
Oct  6 18:29:37 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/syscall/asm_linux_amd64.s:44 +0x5
Oct  6 18:29:37 ip-12-0-10-30 snapd[62550]: syscall.Select(0xa, 0xc00030b628, 0x0, 0x0, 0x0, 0x55568c3f78f3, 0x55568d771910, 0xc00030b648)
Oct  6 18:29:37 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/syscall/zsyscall_linux_amd64.go:1320 +0xa2
Oct  6 18:29:38 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/osutil/udev/netlink.stopperSelectReadable(0x4, 0x9, 0x0, 0xc00030b758, 0x55568c3cdf3d)
Oct  6 18:29:38 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/osutil/udev/netlink/rawsockstop.go:57 +0x16c
Oct  6 18:29:38 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/osutil/udev/netlink.RawSockStopper.func1(0x0, 0x0, 0xc00030b790)
Oct  6 18:29:38 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/osutil/udev/netlink/rawsockstop.go:31 +0x4e
Oct  6 18:29:39 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/osutil/udev/netlink.(*UEventConn).Monitor.func4(0xc0003cc280, 0xc000264c60, 0xc000264cc0, 0xc000264d20, 0xc0003d9300, 0x55568d7b6780, 0xc0003cc260, 0xc000264c00)
Oct  6 18:29:39 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/osutil/udev/netlink/conn.go:139 +0x46
Oct  6 18:29:39 ip-12-0-10-30 snapd[62550]: created by github.com/snapcore/snapd/osutil/udev/netlink.(*UEventConn).Monitor
Oct  6 18:29:39 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/osutil/udev/netlink/conn.go:136 +0x247
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: goroutine 41 [IO wait, 13464 minutes]:
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: internal/poll.runtime_pollWait(0x7f58bc20fe38, 0x72, 0x0)
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/netpoll.go:184 +0x57
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: internal/poll.(*pollDesc).wait(0xc0000f9518, 0x72, 0x0, 0x0, 0x55568ce64611)
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:87 +0x47
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: internal/poll.(*pollDesc).waitRead(...)
Oct  6 18:29:40 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:92
Oct  6 18:29:41 ip-12-0-10-30 snapd[62550]: internal/poll.(*FD).Accept(0xc0000f9500, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
Oct  6 18:29:41 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_unix.go:384 +0x1fa
Oct  6 18:29:41 ip-12-0-10-30 snapd[62550]: net.(*netFD).accept(0xc0000f9500, 0x7f58bc1cddf8, 0x0, 0x30)
Oct  6 18:29:41 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/fd_unix.go:238 +0x44
Oct  6 18:29:42 ip-12-0-10-30 snapd[62550]: net.(*UnixListener).accept(0xc0004560f0, 0xc000466000, 0x30, 0x30)
Oct  6 18:29:42 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:162 +0x34
Oct  6 18:29:42 ip-12-0-10-30 snapd[62550]: net.(*UnixListener).Accept(0xc0004560f0, 0xc000466000, 0x55568d7723f0, 0xc000193d28, 0xc000171c00)
Oct  6 18:29:43 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock.go:260 +0x49
Oct  6 18:29:43 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/daemon.(*ucrednetListener).Accept(0xc000456150, 0x55568d6d5440, 0xc000466000, 0x55568d605dc0, 0x55568de93030)
Oct  6 18:29:43 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/daemon/ucrednet.go:112 +0x4a
Oct  6 18:29:43 ip-12-0-10-30 snapd[62550]: net/http.(*Server).Serve(0xc00027c000, 0x55568d7ad480, 0xc000456150, 0x0, 0x0)
Oct  6 18:29:44 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/http/server.go:2896 +0x282
Oct  6 18:29:44 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/daemon.(*Daemon).Start.func1(0x55568c3cda75, 0xc00052dc80)
Oct  6 18:29:45 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/daemon/daemon.go:378 +0x56
Oct  6 18:29:45 ip-12-0-10-30 snapd[62550]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc00001e050, 0xc000464af0)
Oct  6 18:29:46 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d
Oct  6 18:29:46 ip-12-0-10-30 snapd[62550]: created by gopkg.in/tomb%2ev2.(*Tomb).Go
Oct  6 18:29:47 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9
Oct  6 18:29:47 ip-12-0-10-30 snapd[62550]: goroutine 39 [runnable]:
Oct  6 18:29:48 ip-12-0-10-30 snapd[62550]: encoding/json.(*scanner).pushParseState(...)
Oct  6 18:29:49 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/encoding/json/scanner.go:144
Oct  6 18:29:50 ip-12-0-10-30 snapd[62550]: encoding/json.stateBeginValue(0xc00001c028, 0x55568d6fa37b, 0x55568ce62201)
Oct  6 18:29:51 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/encoding/json/scanner.go:183 +0x4f4
Oct  6 18:29:52 ip-12-0-10-30 snapd[62550]: encoding/json.checkValid(0xc000225000, 0xac1, 0xc00, 0xc00001c028, 0xc0000864b8, 0x8)
Oct  6 18:29:52 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/encoding/json/scanner.go:29 +0xa9
Oct  6 18:29:53 ip-12-0-10-30 snapd[62550]: encoding/json.Unmarshal(0xc000225000, 0xac1, 0xc00, 0x55568d591d40, 0xc0000ae048, 0x55568c8ebd2c, 0x55568d5f3de0)
Oct  6 18:29:53 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/encoding/json/decode.go:100 +0x68
Oct  6 18:29:54 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/state.customData.get(0xc000096ed0, 0x55568ce622e6, 0x5, 0x55568d591d40, 0xc0000ae048, 0xc000190e20, 0xc000190e60)
Oct  6 18:29:54 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/state/state.go:51 +0xa0
Oct  6 18:29:54 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/state.(*State).Get(...)
Oct  6 18:29:54 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/state/state.go:271
Oct  6 18:30:35 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/snapstate.NumSnaps(0xc0000ea070, 0x0, 0xc000190ec8, 0xc000464ab0)
Oct  6 18:31:31 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/snapstate/snapstate.go:3445 +0x82
Oct  6 18:31:32 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/snapstate.(*SnapManager).CanStandby(0xc0002ce9c0, 0x55568df12201)
Oct  6 18:31:33 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/snapstate/snapmgr.go:569 +0x30
Oct  6 18:32:09 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/standby.(*StandbyOpinions).CanStandby(0xc0000b6460, 0x4a817c8000)
Oct  6 18:32:19 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/standby/standby.go:69 +0x254
Oct  6 18:32:20 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/standby.(*StandbyOpinions).Start.func1(0xc0000b6460)
Oct  6 18:32:20 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/standby/standby.go:100 +0xab
Oct  6 18:32:20 ip-12-0-10-30 snapd[62550]: created by github.com/snapcore/snapd/overlord/standby.(*StandbyOpinions).Start
Oct  6 18:32:21 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/standby/standby.go:96 +0xaa
Oct  6 18:32:21 ip-12-0-10-30 snapd[62550]: goroutine 33 [IO wait, 13464 minutes]:
Oct  6 18:32:22 ip-12-0-10-30 snapd[62550]: internal/poll.runtime_pollWait(0x7f58bc20fd68, 0x72, 0x1000)
Oct  6 18:32:23 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/runtime/netpoll.go:184 +0x57
Oct  6 18:32:24 ip-12-0-10-30 snapd[62550]: internal/poll.(*pollDesc).wait(0xc0000f8218, 0x72, 0x0, 0x10, 0xc000162c20)
Oct  6 18:32:25 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:87 +0x47
Oct  6 18:32:25 ip-12-0-10-30 systemd[1]: snapd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Oct  6 18:32:26 ip-12-0-10-30 snapd[62550]: internal/poll.(*pollDesc).waitRead(...)
Oct  6 18:32:27 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:92
Oct  6 18:32:27 ip-12-0-10-30 snapd[62550]: internal/poll.(*FD).ReadMsg(0xc0000f8200, 0xc00077eb50, 0x10, 0x10, 0xc000162c20, 0x1000, 0x1000, 0x0, 0x0, 0x0, ...)
Oct  6 18:32:28 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/internal/poll/fd_unix.go:243 +0x230
Oct  6 18:32:29 ip-12-0-10-30 snapd[62550]: net.(*netFD).readMsg(0xc0000f8200, 0xc00077eb50, 0x10, 0x10, 0xc000162c20, 0x1000, 0x1000, 0xc000147d50, 0x55568deb95d6, 0x1, ...)
Oct  6 18:32:29 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/fd_unix.go:214 +0x92
Oct  6 18:32:30 ip-12-0-10-30 snapd[62550]: net.(*UnixConn).readMsg(0xc00048ca18, 0xc00077eb50, 0x10, 0x10, 0xc000162c20, 0x1000, 0x1000, 0xc00077ea20, 0xc00077ea1c, 0xc000212660, ...)
Oct  6 18:32:31 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:115 +0x93
Oct  6 18:32:31 ip-12-0-10-30 snapd[62550]: net.(*UnixConn).ReadMsgUnix(0xc00048ca18, 0xc00077eb50, 0x10, 0x10, 0xc000162c20, 0x1000, 0x1000, 0xc000212a60, 0x20, 0x18, ...)
Oct  6 18:32:31 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/net/unixsock.go:143 +0x9a
Oct  6 18:32:32 ip-12-0-10-30 snapd[62550]: github.com/godbus/dbus.(*oobReader).Read(0xc000162c00, 0xc00077eb50, 0x10, 0x10, 0xc000147df0, 0x55568c3d590a, 0x20)
Oct  6 18:32:32 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/github.com/godbus/dbus/transport_unix.go:21 +0x8f
Oct  6 18:32:33 ip-12-0-10-30 snapd[62550]: io.ReadAtLeast(0x55568d793220, 0xc000162c00, 0xc00077eb50, 0x10, 0x10, 0x10, 0xc000200090, 0x0, 0x0)
Oct  6 18:32:33 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/io/io.go:310 +0x89
Oct  6 18:32:42 ip-12-0-10-30 snapd[62550]: io.ReadFull(...)
Oct  6 18:32:42 ip-12-0-10-30 snapd[62550]: #011/usr/lib/go-1.13/src/io/io.go:329
Oct  6 18:32:42 ip-12-0-10-30 snapd[62550]: github.com/godbus/dbus.(*unixTransport).ReadMessage(0xc00047a800, 0xc000000002, 0x2, 0xc00014f401)
Oct  6 18:32:43 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/github.com/godbus/dbus/transport_unix.go:91 +0x11a
Oct  6 18:32:43 ip-12-0-10-30 snapd[62550]: github.com/godbus/dbus.(*Conn).inWorker(0xc0003d01b0)
Oct  6 18:32:43 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/github.com/godbus/dbus/conn.go:294 +0x42
Oct  6 18:32:44 ip-12-0-10-30 snapd[62550]: created by github.com/godbus/dbus.(*Conn).Auth
Oct  6 18:32:44 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/github.com/godbus/dbus/auth.go:118 +0x623
Oct  6 18:32:44 ip-12-0-10-30 snapd[62550]: goroutine 49 [select, 13465 minutes]:
Oct  6 18:32:45 ip-12-0-10-30 snapd[62550]: github.com/snapcore/snapd/overlord/ifacestate/udevmonitor.(*Monitor).Run.func1(0xc00004cfc8, 0x55568c85dad2)
Oct  6 18:32:45 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/overlord/ifacestate/udevmonitor/udevmon.go:147 +0x329
Oct  6 18:32:45 ip-12-0-10-30 snapd[62550]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc000152c60, 0xc000076b40)
Oct  6 18:32:46 ip-12-0-10-30 systemd[1]: snapd.service: Failed with result 'watchdog'.
Oct  6 18:32:46 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d
Oct  6 18:32:47 ip-12-0-10-30 snapd[62550]: created by gopkg.in/tomb%2ev2.(*Tomb).Go
Oct  6 18:32:47 ip-12-0-10-30 snapd[62550]: #011/build/snapd/parts/snapd-deb/build/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9
Oct  6 18:32:48 ip-12-0-10-30 snapd[62550]: rax    0xca
Oct  6 18:32:49 ip-12-0-10-30 snapd[62550]: rbx    0x55568def63a0
Oct  6 18:32:49 ip-12-0-10-30 snapd[62550]: rcx    0x55568c42a793
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rdx    0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rdi    0x55568def64e8
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rsi    0x80
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rbp    0x7ffc63c1fd38
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rsp    0x7ffc63c1fcf0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r8     0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r9     0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r10    0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r11    0x286
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r12    0xff
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r13    0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r14    0x55568d089af2
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: r15    0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rip    0x55568c42a791
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: rflags 0x286
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: cs     0x33
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: fs     0x0
Oct  6 18:32:50 ip-12-0-10-30 snapd[62550]: gs     0x0
Oct  6 18:32:50 ip-12-0-10-30 systemd[1]: snapd.service: Scheduled restart job, restart counter is at 3.
Oct  6 18:32:51 ip-12-0-10-30 snapd[98728]: AppArmor status: apparmor is enabled and all features are available
Oct  6 18:32:51 ip-12-0-10-30 systemd[1]: Stopped Snap Daemon.
Oct  6 18:32:52 ip-12-0-10-30 systemd[1]: Starting Snap Daemon...
Oct  6 18:32:52 ip-12-0-10-30 systemd[1]: snapd.service: start operation timed out. Terminating.
Oct  6 18:32:53 ip-12-0-10-30 systemd[1]: snapd.service: Failed with result 'timeout'.

skip

Oct  6 19:01:27 ip-12-0-10-30 systemd[1]: Stopped Snap Daemon.
Oct  6 19:02:54 ip-12-0-10-30 systemd[1]: Starting Snap Daemon...
Oct  6 19:05:14 ip-12-0-10-30 systemd[1]: snapd.service: start operation timed out. Terminating.
Oct  6 19:07:10 ip-12-0-10-30 systemd[1]: snapd.service: Failed with result 'timeout'.
Oct  6 19:08:57 ip-12-0-10-30 systemd[1]: Failed to start Snap Daemon.
Oct  6 19:14:41 ip-12-0-10-30 systemd[1]: snapd.service: Scheduled restart job, restart counter is at 20.
Oct  6 19:16:14 ip-12-0-10-30 systemd[1]: Stopped Snap Daemon.
Oct  6 19:18:46 ip-12-0-10-30 systemd[1]: Starting Snap Daemon...
Oct  6 19:22:44 ip-12-0-10-30 CRON[99169]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Oct  6 19:31:10 ip-12-0-10-30 systemd-networkd[425]: ens5: Could not set DHCPv4 address: Connection timed out
Oct  6 19:33:19 ip-12-0-10-30 systemd-networkd[425]: ens5: Failed
Oct  6 20:41:15 ip-12-0-10-30 CRON[99214]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Oct  6 20:50:55 ip-12-0-10-30 systemd-timesyncd[352]: Network configuration changed, trying to establish connection.

enter image description here

The graph above shows a sharp increase in cpu.

At 17:40, the cpu usage increased, and from 17:44, it increased sharply. It peaked at 93% usage at 17:55 and the CPU usage dropped at 18:55.

The status check failed from 20:25, and the server went down around 20:30.

My guess is snapd.service: Watchdog timeout (limit 5min)! It seems that snapd started and stopped after that.

What is the cause of this and what can be done to prevent it?

4
  • 1
    Which EC2 instance is being used and in what region is it running? Reason I ask is because there are some instance types in some regions that have awful I/O performance, which can result in failures such as this. Those charts and graphs in the dashboard consistently show no I/O problem ... because there is no I/O for the instance to use. I've encountered this a number of times in us-east and eu-central on t1.micro, t1.small, t2.micro, t2.small, t2.medium, and t3.small servers. The solution was to move the server to a different location or upgrade to a more expensive instance type.
    – matigo
    Commented Oct 14, 2022 at 1:59
  • I'm running into this issue. Did you find a solution?
    – Drew
    Commented Mar 12, 2023 at 20:15
  • @ matigo/ I also saw the solution mentioned by matigo for this problem. It is not in the us-east and eu-central region, but the instance is using a lower specification. However, in the case of some instances, it is continuously being used well, but only certain instances are experiencing errors. I'm not sure if this is a real solution.
    – Joker
    Commented Mar 30, 2023 at 2:32
  • I encountered the same problem. My instance is also low-spec (t2.micro with 1GB of memory), so I believe Rohjay's solution is effective. However, in the end, I decided to completely stop Ubuntu's daily tasks to avoid this problem altogether. Please refer to the link below for instructions on how to disable these tasks: superuser.com/questions/1327884/…
    – Filo
    Commented Jun 3, 2023 at 13:53

1 Answer 1

Reset to default
1

I was running into this issue as well. I did a few things, but I think the biggest effect was changing the threshold of "swappiness", since I have a pretty small VM that I'm running on.

Link to thread I used

Effectively, edit the /etc/sysctl.conf file and update/add the line vm.swappiness=10 to whatever threshold you want. I changed mine from like 60 to 10 (in other words: only leverage swap at when available mem is less than or equal to 10%). That pepped a bunch of stuff up.

Reboot and the effects should take place.

2
  • Now, since the error hasn't occurred since rebooting, I can't confirm if this is the solution. But thanks for the nice answer.
    – Joker
    Commented Mar 30, 2023 at 2:34
  • No problem, man! Keep us posted if that seemed to do the trick for you. Cheers!
    – Rohjay
    Commented Mar 31, 2023 at 13:09

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .