Unattended Ubuntu Core device not booting

I recently came from a 4 weeks of being away from my devices and when I got back I noticed I couldn’t talk to my nextcloud box anymore. Today I finally had time to hook up a monitor to check what was going on and this is what I see

Any ideas on how to solve this?

this looks like your core snap vaanished quietly … very weird

if you check the SD’s writable partition, what does:

ls -l /writable/system-data/var/lib/snapd/snaps/core*

show ?

r1518 of core was a core release from 2017-03-17 to stable. We had another stable r1580 on 2017-03-29 and then a stable 1690 on 2017-04-11 and 2314 to stable on 2017-07-03. I would love to get hold of /var/lib/snapd/state.json from the writable partition (private please, it may contain a macaroon).

Two core snaps, 1443 and 1267 with octal permissions 644.

definitely not the version the bootloader thinks it should be…

can you also capture the content of /proc/cmdline in this state ?

The last few lines of the /var/log/syslog from writable would also be nice, maybe that gives us some clues. Its also puzzling that this revision is so old and yet the error has only happend recently(?).

Indeed it isn’t

dma.dmachans=0x7f35 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2709.boardrev=0xa01041 bcm2709.serial=0x9308dcec smsc95xx.macaddr=B8:27:EB:08:DC:EC bcm2708_fb.fbswap=1 bcm2709_uart_clock=3000000 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 vm_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000 dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty0 elevator=deadline root=/dev/disk/by-label/writable net.ifnames=0 init=/lib/systemd ro panic=-1 fixrtc snap_core=core_1516.snap snap_kernel=pi2-kernel_22.snap

All hand typed, but I certainly do not have core_1516

The error might be really old. I am just noticing this now though as I got home with a bucket load of photos to backup :slight_smile:

Seems to be out since March 31 (last log lines with messages about cron checks and no spas to auto-refresh found)

did you by chance run out of diskspace ? so the download broke but the bootloader did get updated or some such ?

writable is only 42% used.

yeah, not that then …
the state file that @mvo initially asked for has probably more data …

i’d also like to know if resetting power makes it at least roll back to some sane state.

Free space

$ df -h|grep sda
/dev/sda1       127M   17M  110M  14% /media/sergiusens/system-boot
/dev/sda2       3,5G  1,4G  2,0G  42% /media/sergiusens/writable

Redacted state.json

{
  "data": {
    "aliases": {},
    "auth": {
      "last-id": 1,
      "users": [
        {
          "id": 1,
          "username": "username",
          "email": "me@email.com",
          "macaroon": "my-macaroon"
        }
      ],
      "device": {
        "brand": "canonical",
        "model": "pi2",
        "serial": "my-serial",
        "key-id": "my-key",
        "session-macaroon": "my-session-macaroon"
      },
      "macaroon-key": "my-macaroon-key"
    },
    "config": {
      "core": {
        "refresh": {
          "last": "2017-03-31T18:30:32.994690046Z"
        }
      }
    },
    "conns": {
      "core:core-support core:core-support": {
        "auto": true,
        "interface": "core-support"
      },
      "core:network-bind core:network-bind": {
        "auto": true,
        "interface": "network-bind"
      },
      "nextcloud:network core:network": {
        "auto": true,
        "interface": "network"
      },
      "nextcloud:network-bind core:network-bind": {
        "auto": true,
        "interface": "network-bind"
      },
      "nextcloud:removable-media core:removable-media": {
        "interface": "removable-media"
      },
      "snapweb:network core:network": {
        "auto": true,
        "interface": "network"
      },
      "snapweb:network-bind core:network-bind": {
        "auto": true,
        "interface": "network-bind"
      },
      "snapweb:snapd-control core:snapd-control": {
        "auto": true,
        "interface": "snapd-control"
      },
      "snapweb:timeserver-control core:timeserver-control": {
        "auto": true,
        "interface": "timeserver-control"
      },
      "snapweb:timezone-control core:timezone-control": {
        "auto": true,
        "interface": "timezone-control"
      }
    },
    "patch-level": 6,
    "seeded": true,
    "snaps": {
      "core": {
        "type": "os",
        "sequence": [
          {
            "name": "core",
            "snap-id": "99T7MUlRhtI3U0QFgl5mXXESAiSwt776",
            "revision": "1267",
            "channel": "stable",
            "summary": "snapd runtime environment",
            "description": "The core runtime environment for snapd"
          },
          {
            "name": "core",
            "snap-id": "99T7MUlRhtI3U0QFgl5mXXESAiSwt776",
            "revision": "1443",
            "channel": "stable",
            "summary": "snapd runtime environment",
            "description": "The core runtime environment for snapd"
          }
        ],
        "active": true,
        "current": "1443",
        "channel": "stable"
      },
      "nextcloud": {
        "type": "app",
        "sequence": [
          {
            "name": "nextcloud",
            "snap-id": "njObIbGQEaVx1H4nyWxchk1i8opy4h54",
            "revision": "863",
            "channel": "stable",
            "summary": "Nextcloud Server",
            "description": "Access & share your files, calendars, contacts, mail & more from any device, on your terms."
          },
          {
            "name": "nextcloud",
            "snap-id": "njObIbGQEaVx1H4nyWxchk1i8opy4h54",
            "revision": "1161",
            "channel": "stable",
            "summary": "Nextcloud Server",
            "description": "Access & share your files, calendars, contacts, mail & more from any device, on your terms."
          },
          {
            "name": "nextcloud",
            "snap-id": "njObIbGQEaVx1H4nyWxchk1i8opy4h54",
            "revision": "1190",
            "channel": "stable",
            "summary": "Nextcloud Server",
            "description": "Access & share your files, calendars, contacts, mail & more from any device, on your terms."
          }
        ],
        "active": true,
        "current": "1190",
        "channel": "stable"
      },
      "pi2": {
        "type": "gadget",
        "sequence": [
          {
            "name": "pi2",
            "snap-id": "ZbHoNCV2YMyGLhAf1U9SLaOvuVD02Sqs",
            "revision": "29",
            "developer-id": "canonical",
            "developer": "canonical"
          }
        ],
        "active": true,
        "current": "29",
        "channel": "stable"
      },
      "pi2-kernel": {
        "type": "kernel",
        "sequence": [
          {
            "name": "pi2-kernel",
            "snap-id": "m0rvvnmRdDgexonz1XSP9a9U4K7vUbiy",
            "revision": "22",
            "developer-id": "canonical",
            "developer": "canonical"
          }
        ],
        "active": true,
        "current": "22",
        "channel": "stable"
      },
      "snapweb": {
        "type": "app",
        "sequence": [
          {
            "name": "snapweb",
            "snap-id": "cr5pkasGhR7N3M8wKfP9DJqGxbBGeET2",
            "revision": "25",
            "channel": "stable",
            "summary": "Beautiful and functional interface for snap management",
            "description": "This service allows you to manage your Ubuntu Core device from a web interface or REST API.\r\n\r\nFeatures include:\r\n\r\n- manage updates to the system.\r\n- control the state of other snappy packages.\r\n- browse the store to install new snappy packages.\r\n"
          },
          {
            "name": "snapweb",
            "snap-id": "cr5pkasGhR7N3M8wKfP9DJqGxbBGeET2",
            "revision": "209",
            "channel": "stable",
            "contact": "mailto:canonical-snapcraft@lists.canonical.com",
            "summary": "Beautiful and functional interface for snap management",
            "description": "This service allows you to manage your Ubuntu Core device from a web interface or REST API.\r\n\r\nFeatures include:\r\n\r\n- manage updates to the system.\r\n- control the state of other snappy packages.\r\n- browse the store to install new snappy packages.\r\n"
          },
          {
            "name": "snapweb",
            "snap-id": "cr5pkasGhR7N3M8wKfP9DJqGxbBGeET2",
            "revision": "201",
            "channel": "stable",
            "contact": "mailto:canonical-snapcraft@lists.canonical.com",
            "summary": "Beautiful and functional interface for snap management",
            "description": "This service allows you to manage your Ubuntu Core device from a web interface or REST API.\r\n\r\nFeatures include:\r\n\r\n- manage updates to the system.\r\n- control the state of other snappy packages.\r\n- browse the store to install new snappy packages.\r\n"
          }
        ],
        "active": true,
        "current": "201",
        "channel": "stable"
      }
    }
  },
  "changes": {},
  "tasks": {},
  "last-change-id": 121,
  "last-task-id": 219,
  "last-lane-id": 9
}

Thanks @sergiusens - this all looks normal. Is there anything in /var/log/syslog that could give us any hints?

It is pretty bland:

Mar 31 06:25:01 moria CRON[4870]: (CRON) info (No MTA installed, discarding output)
Mar 31 07:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 07:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 07:17:01 moria CRON[8029]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 08:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 08:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 08:17:01 moria CRON[11615]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 09:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 09:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 09:17:01 moria CRON[15209]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 09:46:21 moria systemd-timesyncd[1076]: Network configuration changed, trying to establish connection.
Mar 31 09:46:21 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 09:47:51 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 09:46:21 moria systemd[1]: Starting Update resolvconf for networkd DNS...
Mar 31 09:46:21 moria systemd[1]: Started Update resolvconf for networkd DNS.
Mar 31 09:46:21 moria systemd-timesyncd[1076]: Synchronized to time server 91.189.94.4:123 (ntp.ubuntu.com).
Mar 31 09:50:30 moria /usr/lib/snapd/snapd[1225]: snapmgr.go:508: No snaps to auto-refresh found
Mar 31 09:50:30 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 09:52:00 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 09:50:30 moria snapd[1225]: 2017/03/31 09:50:30.907729 snapmgr.go:508: No snaps to auto-refresh found
Mar 31 10:17:02 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 10:18:32 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 10:17:02 moria CRON[18814]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 10:43:01 moria kernel: [950583.887743] audit: type=1400 audit(1490956981.457:204): apparmor="DENIED" operation="open" profile="snap.nextcloud.renew-certs" name="/proc/20366/mounts" pid=20366 comm="python2" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Mar 31 10:43:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 10:44:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 10:43:08 moria snap[1716]: Saving debug log to /var/snap/nextcloud/current/certs/certbot/logs/letsencrypt.log
Mar 31 10:43:08 moria snap[1716]: No renewals attempted, so not running post-hook
Mar 31 10:43:08 moria snap[1716]: No renewals were attempted.
Mar 31 11:01:23 moria systemd[1]: Starting Cleanup of Temporary Directories...
Mar 31 11:01:23 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 11:02:53 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 11:01:23 moria systemd-tmpfiles[21503]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring.
Mar 31 11:01:23 moria systemd[1]: Started Cleanup of Temporary Directories.
Mar 31 11:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 11:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 11:17:01 moria CRON[22446]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 12:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 12:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 12:17:01 moria CRON[26034]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 13:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 13:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 13:17:01 moria CRON[29631]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 14:10:30 moria /usr/lib/snapd/snapd[1225]: snapmgr.go:508: No snaps to auto-refresh found
Mar 31 14:10:30 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 14:12:00 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 14:10:30 moria snapd[1225]: 2017/03/31 14:10:30.859129 snapmgr.go:508: No snaps to auto-refresh found
Mar 31 14:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 14:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 14:17:01 moria CRON[771]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 15:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 15:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 15:17:01 moria CRON[4510]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 16:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 16:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 16:17:01 moria CRON[8097]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 17:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 17:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 17:17:01 moria CRON[11690]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 18:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 18:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 18:17:01 moria CRON[15285]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar 31 18:30:32 moria /usr/lib/snapd/snapd[1225]: snapmgr.go:508: No snaps to auto-refresh found
Mar 31 18:30:32 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 18:32:02 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 18:30:32 moria snapd[1225]: 2017/03/31 18:30:32.995641 snapmgr.go:508: No snaps to auto-refresh found
Mar 31 19:17:01 moria rsyslogd-2007: action 'action 11' suspended, next retry is Fri Mar 31 19:18:31 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Mar 31 19:17:01 moria CRON[18872]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)

All said and done, what are my options to avoid starting from scratch?