'snap install X' ends up with 'error: cannot communicate with server: Post http://localhost/v2/snaps/X EOF'


#1

(I’m new to this community so please move this to an appropriate category if needed).

Similar to Snap cannot communicate with server but doesn’t seem to be exactly the same.

Problem

$ sudo snap install openhab
error: cannot communicate with server: Post http://localhost/v2/snaps/openhab: EOF

Note that the command takes a few minutes to return.

Out of the set of outputs (detail below), the following might be the most concerning to me but I’m not yet sure.

PANIC cannot checkpoint even after 5m0s of retries every 3s: write /var/lib/snapd/state.json.srD9QjJDy5Td~: no space left on device

Environment

Thank you.

Commands output:

$ systemctl status snapd
● snapd.service - Snappy daemon
   Loaded: loaded (/lib/systemd/system/snapd.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2019-01-05 23:15:37 UTC; 2min 12s ago
 Main PID: 22219 (snapd)
   CGroup: /system.slice/snapd.service
           └─22219 /usr/lib/snapd/snapd
$ snap list
Name        Version         Rev   Tracking  Developer  Notes
core        16-2.33.1       4916  stable    canonical  core
pi2         16.04-0.17      29    stable    canonical  gadget
pi2-kernel  4.4.0-1092.100  56    stable    canonical  kernel

$ snap version
snap    2.33.1
snapd   unavailable
series  -
$ df -h
Filesystem      Size  Used Avail Use% Mounted on
udev            455M     0  455M   0% /dev
tmpfs            93M   14M   79M  15% /run
/dev/mmcblk0p2  296M  290M     0 100% /writable
/dev/loop0       74M   74M     0 100% /
/dev/loop1      129M  129M     0 100% /lib/modules
tmpfs           461M  4.0K  461M   1% /etc/fstab
tmpfs           461M     0  461M   0% /dev/shm
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs           461M     0  461M   0% /sys/fs/cgroup
tmpfs           461M     0  461M   0% /media
tmpfs           461M     0  461M   0% /mnt
tmpfs           461M     0  461M   0% /var/lib/sudo
tmpfs           461M     0  461M   0% /tmp
/dev/loop2       74M   74M     0 100% /snap/core/4916
/dev/loop3      3.8M  3.8M     0 100% /snap/pi2/29
/dev/loop4      129M  129M     0 100% /snap/pi2-kernel/56
/dev/mmcblk0p1  127M   16M  111M  13% /boot/uboot
cgmfs           100K     0  100K   0% /run/cgmanager/fs
tmpfs            93M     0   93M   0% /run/user/1000

$ sudo journalctl -f -u snapd
-- Logs begin at Fri 2019-01-04 15:09:48 UTC. --
Jan 05 23:20:40 localhost.localdomain systemd[1]: snapd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jan 05 23:20:40 localhost.localdomain systemd[1]: snapd.service: Unit entered failed state.
Jan 05 23:20:40 localhost.localdomain systemd[1]: snapd.service: Failed with result 'exit-code'.
Jan 05 23:20:40 localhost.localdomain systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Jan 05 23:20:40 localhost.localdomain systemd[1]: Stopped Snappy daemon.
Jan 05 23:20:40 localhost.localdomain systemd[1]: Starting Snappy daemon...
Jan 05 23:20:40 localhost.localdomain snapd[22316]: AppArmor status: apparmor is enabled and all features are available
Jan 05 23:20:40 localhost.localdomain snapd[22316]: 2019/01/05 23:20:40.875434 daemon.go:343: started snapd/2.33.1 (series 16) ubuntu-core/16 (armhf) linux/4.4.0-1092-raspi2.
Jan 05 23:20:40 localhost.localdomain systemd[1]: Started Snappy daemon.
Jan 05 23:20:42 localhost.localdomain snapd[22316]: 2019/01/05 23:20:42.924077 storehelpers.go:413: cannot refresh snap "pi2": snap has no updates available

Jan 05 23:25:43 localhost.localdomain snapd[22316]: 2019/01/05 23:25:43.143721 state.go:235: PANIC cannot checkpoint even after 5m0s of retries every 3s: write /var/lib/snapd/state.json.srD9QjJDy5Td~: no space left on device
Jan 05 23:25:43 localhost.localdomain snapd[22316]: panic: cannot checkpoint even after 5m0s of retries every 3s: write /var/lib/snapd/state.json.srD9QjJDy5Td~: no space left on device
Jan 05 23:25:43 localhost.localdomain snapd[22316]: goroutine 26 [running]:
Jan 05 23:25:43 localhost.localdomain snapd[22316]: panic(0xea8e00, 0x1198e0e8)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /usr/lib/go-1.6/src/runtime/panic.go:481 +0x370
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/logger.Panicf(0x10b93a8, 0x37, 0x1152fbc4, 0x3, 0x3)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/logger/logger.go:67 +0x14c
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/overlord/state.(*State).Unlock(0x116a3500)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/overlord/state/state.go:235 +0x310
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/overlord/snapstate.(*autoRefresh).Ensure(0x11721110, 0x0, 0x0)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/overlord/snapstate/autorefresh.go:299 +0xee0
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/overlord/snapstate.(*SnapManager).Ensure(0x11721140, 0x0, 0x0)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/overlord/snapstate/snapmgr.go:540 +0xa4
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/overlord.(*StateEngine).Ensure(0x11727540, 0x0, 0x0)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/overlord/stateengine.go:99 +0x194
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/overlord.(*Overlord).Loop.func1(0x0, 0x0)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/overlord/overlord.go:262 +0x48
Jan 05 23:25:43 localhost.localdomain snapd[22316]: github.com/snapcore/snapd/vendor/gopkg.in/tomb%2ev2.(*Tomb).run(0x116a6810, 0x1173b318)
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x1c
Jan 05 23:25:43 localhost.localdomain snapd[22316]: created by github.com/snapcore/snapd/vendor/gopkg.in/tomb%2ev2.(*Tomb).Go
Jan 05 23:25:43 localhost.localdomain snapd[22316]:         /build/snapd-22JIGV/snapd-2.33.1/_build/src/github.com/snapcore/snapd/vendor/gopkg.in/tomb.v2/tomb.go:159 +0x134
Jan 05 23:25:43 localhost.localdomain systemd[1]: snapd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jan 05 23:25:43 localhost.localdomain systemd[1]: snapd.service: Unit entered failed state.
Jan 05 23:25:43 localhost.localdomain systemd[1]: snapd.service: Failed with result 'exit-code'.
Jan 05 23:25:43 localhost.localdomain systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Jan 05 23:25:43 localhost.localdomain systemd[1]: Stopped Snappy daemon.
Jan 05 23:25:43 localhost.localdomain systemd[1]: Starting Snappy daemon...
Jan 05 23:25:43 localhost.localdomain snapd[22358]: AppArmor status: apparmor is enabled and all features are available
Jan 05 23:25:43 localhost.localdomain snapd[22358]: 2019/01/05 23:25:43.988432 daemon.go:343: started snapd/2.33.1 (series 16) ubuntu-core/16 (armhf) linux/4.4.0-1092-raspi2.
Jan 05 23:25:43 localhost.localdomain systemd[1]: Started Snappy daemon.
Jan 05 23:25:46 localhost.localdomain snapd[22358]: 2019/01/05 23:25:46.101986 storehelpers.go:413: cannot refresh snap "pi2": snap has no updates available

How the SD disk formatted:

$ sudo umount /dev/mmcblk0p1
$ sudo umount /dev/mmcblk0p2
$ lsblk
NAME        MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
sda           8:0    0 465.8G  0 disk
├─sda1        8:1    0     1K  0 part
├─sda2        8:2    0     4G  0 part [SWAP]
└─sda5        8:5    0 461.8G  0 part /
sr0          11:0    1  1024M  0 rom
mmcblk0     179:0    0  14.4G  0 disk
├─mmcblk0p1 179:1    0   128M  0 part
└─mmcblk0p2 179:2    0  14.3G  0 part
$ sudo fdisk /dev/mmcblk0

Welcome to fdisk (util-linux 2.27.1).
Changes will remain in memory only, until you decide to write them.
Be careful before using the write command.

Command (m for help): p
Disk /dev/mmcblk0: 14.4 GiB, 15489564672 bytes, 30253056 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x68c4443d

Device         Boot  Start      End  Sectors  Size Id Type
/dev/mmcblk0p1 *      2048   264191   262144  128M  c W95 FAT32 (LBA)
/dev/mmcblk0p2      264192 30253055 29988864 14.3G 83 Linux

Command (m for help): d
Partition number (1,2, default 2):

Partition 2 has been deleted.

Command (m for help): d
Selected partition 1
Partition 1 has been deleted.

Command (m for help):


Command (m for help): p

Disk /dev/mmcblk0: 14.4 GiB, 15489564672 bytes, 30253056 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x68c4443d

Command (m for help): n
Partition type
   p   primary (0 primary, 0 extended, 4 free)
      e   extended (container for logical partitions)
      Select (default p):

Using default response p.
Partition number (1-4, default 1):
First sector (2048-30253055, default 2048):
Last sector, +sectors or +size{K,M,G,T,P} (2048-30253055, default 30253055):

Created a new partition 1 of type 'Linux' and of size 14.4 GiB.

Command (m for help): t
Selected partition 1
Partition type (type L to list all types): b
Changed type of partition 'Linux' to 'W95 FAT32'.

Command (m for help): p
Disk /dev/mmcblk0: 14.4 GiB, 15489564672 bytes, 30253056 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x68c4443d

Device         Boot Start      End  Sectors  Size Id Type
/dev/mmcblk0p1       2048 30253055 30251008 14.4G  b W95 FAT32

Command (m for help): a
Selected partition 1
The bootable flag on partition 1 is enabled now.

Command (m for help): w
The partition table has been altered.
Calling ioctl() to re-read partition table.
Syncing disks.

$ sudo mkfs.vfat /dev/mmcblk0
mkfs.fat 3.0.28 (2015-05-16)

$ sudo ddrescue -D --force ubuntu-core-16-pi2.img /dev/mmcblk0

#2

this is your issue, i guess ddrescue messes something up here when writing the image, try using godd (from the godd snap) or plain dd as recommended in the image flashing instructions …

https://developer.ubuntu.com/core/get-started/installation-medias


#3

Thanks for the input. I tried dd as suggested but unfortunately it didn’t fix.

Then I used a branch new SD card (32GB, sandisk) then it went smoothly. I do admit the issue I reported above happened with an SD card with 16GB and has been in use for a few years. Not sure if anything wrong with that old SD card though
(If curious I’m keeping track of the work here).