Unattended Ubuntu Core device not booting


#1

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?


#2

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 ?


#3

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).


#4

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


#5

definitely not the version the bootloader thinks it should be…

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


#6

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(?).


#7

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


#8

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:


#9

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


#10

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


#11

writable is only 42% used.


#12

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.


#13

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
}

#14

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


#15

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)

#16

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