Update on bbb from r33 to r35 fails

[Kick In]

The upgrade didn't succeed, tried two to three times, got two different output:

Last login: Thu Apr 23 14:23:05 2015 from 192.168.0.52
(BeagleBoneBlack)ubuntu@localhost:~$ snappy list
Name Date Version Developer
ubuntu-core 2015-04-23 33 ubuntu
docker 2015-04-23 1.6.0.002
owncloud 2015-04-23 8.0.2.002 sideload
beagleblack 2015-04-22 1.7
(BeagleBoneBlack)ubuntu@localhost:~$ sudo snappy update
Installing ubuntu-core (35)
Starting download of ubuntu-core
131.08 KB / 131.08 KB [==============================================================================================================================================] 100.00 % 11.82 KB/s
Done
Failed to run command '/bin/mount -obind /boot/uboot /writable/cache/system/boot/uboot': mount: mount point /writable/cache/system/boot/uboot does not exist
 (exit status 32)
(BeagleBoneBlack)ubuntu@localhost:~$

and then
(BeagleBoneBlack)ubuntu@localhost:~$ snappy list -v
Name Date Version Developer
ubuntu-core 2015-04-23 33 ubuntu*
ubuntu-core 2015-04-23 35 ubuntu
docker 2015-04-23 1.6.0.002 *
owncloud 2015-04-23 8.0.2.002 sideload*
beagleblack 2015-04-22 1.7 *
(BeagleBoneBlack)ubuntu@localhost:~$ sudo snappy update
Installing ubuntu-core (35)
Starting download of ubuntu-core
131.08 KB / 131.08 KB [==============================================================================================================================================] 100.00 % 12.83 KB/s
Done
Failed to run command '/bin/umount /writable/cache/system': umount: /writable/cache/system: target is busy
        (In some cases useful info about processes that
         use the device is found by lsof(8) or fuser(1).)
 (exit status 32)
(BeagleBoneBlack)ubuntu@localhost:~$

[Kick In (kick-d)]

Was an updated system from r29 to r30 to t33

[Kick In (kick-d)]

(BeagleBoneBlack)ubuntu@localhost:~$ ls -l /writable/cache/system
total 88
drwxr-xr-x 2 root root 4096 Apr 23 12:48 apps
drwxr-xr-x 2 root root 4096 Apr 23 13:12 bin
drwxr-xr-x 3 root root 4096 Apr 23 13:13 boot
drwxr-xr-x 15 root root 4100 Apr 23 14:25 dev
drwxr-xr-x 78 root root 4096 Apr 23 14:09 etc
drwxr-xr-x 3 root root 4096 Apr 23 13:09 home
drwxr-xr-x 15 root root 4096 Apr 23 13:13 lib
drwx------ 2 root root 16384 Apr 23 14:06 lost+found
drwxr-xr-x 2 root root 4096 Apr 23 13:01 media
drwxr-xr-x 2 root root 4096 Apr 17 21:35 mnt
drwxr-xr-x 2 root root 4096 Apr 23 12:48 oem
drwxr-xr-x 2 root root 4096 Apr 23 13:01 opt
dr-xr-xr-x 80 root root 0 Jan 1 1970 proc
drwx------ 2 root root 4096 Apr 23 13:12 root
drwxr-xr-x 5 root root 4096 Apr 23 13:09 run
drwxr-xr-x 2 root root 4096 Apr 23 13:12 sbin
drwxr-xr-x 2 root root 4096 Apr 23 13:01 srv
dr-xr-xr-x 12 root root 0 Apr 23 14:24 sys
drwxrwxrwt 2 root root 4096 Apr 23 13:13 tmp
drwxr-xr-x 10 root root 4096 Apr 23 13:01 usr
drwxr-xr-x 11 root root 4096 Apr 23 13:12 var
drwxr-xr-x 2 root root 4096 Apr 23 13:30 writa

[Kick In (kick-d)]

(BeagleBoneBlack)ubuntu@localhost:~$ ls -l /writable/cache/system/etc/system-image/
total 32
-rw-r--r-- 1 root root 1468 Feb 24 14:29 archive-master.tar.xz
-rw-r--r-- 1 root root 836 Feb 24 14:29 archive-master.tar.xz.asc
-rw-r--r-- 1 root root 208 Apr 23 13:53 channel.ini
-rw-r--r-- 1 root root 882 Apr 23 13:09 client.ini
-rw-r--r-- 1 root root 882 Feb 24 14:29 client.inie
drwxr-xr-x 2 root root 4096 Apr 23 13:08 config.d
-rw-r--r-- 1 root root 5437 Apr 23 11:35 writable-paths
(BeagleBoneBlack)ubuntu@localhost:~$

(BeagleBoneBlack)ubuntu@localhost:~$ ls -l /writable/cache/system/boot/
total 37184
-rw------- 1 root root 3195831 Apr 17 03:46 System.map-3.19.0-15-generic
-rw-r--r-- 1 root root 1189894 Apr 17 03:46 abi-3.19.0-15-generic
-rw-r--r-- 1 root root 182579 Apr 17 03:46 config-3.19.0-15-generic
drwxr-xr-x 2 root root 4096 Apr 23 11:38 efi
-rw-r--r-- 1 root root 13490027 Apr 23 13:11 initrd.img
-rw-r--r-- 1 root root 13490027 Apr 23 13:12 initrd.img-3.19.0-15-generic
lrwxrwxrwx 1 root root 25 Apr 23 14:07 vmlinuz -> vmlinuz-3.19.0-15-generic
-rw------- 1 root root 6508992 Apr 17 03:46 vmlinuz-3.19.0-15-generic
(BeagleBoneBlack)ubuntu@localhost:~$

[Kick In (kick-d)]

lsof output, but way later:

http://paste.ubuntu.com/10872169/

[James Hunt (jamesodhunt)]

A fresh r33 bbb install does correctly upgrade to r35 for me.

[James Hunt (jamesodhunt)]

Apparently the system was:

- installed as r29.
- upgraded to r30.
- upgraded to r33.

[Steve Langasek (vorlon)]

- installed as r29.
- upgraded to r30.
- upgraded to r33.

That would be consistent with there being an upgrader problem that eats the /boot/uboot directory on the opposite partition on each upgrade.

installed r29: both partitions are in working order. system-a booted.
upgraded to r30: system-b partition updated, /boot/uboot nuked from that partition. Still boots fine (/boot/uboot not mounted).
upgraded to r33: system-a partition updated, /boot/uboot nuked from that partition. Still boots fine (/boot/uboot not mounted).
attempt to upgrade to r35: fails because system-b partition now has no /boot/uboot directory.

[Jamie Strandboge (jdstrand)]

Not sure if this is related, but on a bbb with 4G microsd on r33, it cannot upgrade to r36:
error from system-image-cli: ('%s exited with %s:\n%s', ['ubuntu-core-upgrade'], 1, "failed to unmount (['umount', '/writable/cache/system']): umount: /writable/cache/system: target is busy\n (In some cases useful info about processes that\n use the device is found by lsof(8) or fuser(1).)\n\nfailed to mount (['m")

[Jamie Strandboge (jdstrand)]

I also found this in the logs:
Apr 23 19:05:40 localhost ubuntu-core-upgrade: failed to unmount (['umount', '/writable/cache/system']): umount: /writable/cache/system: target is busy#012 (In some cases useful info about processes that#012 use the device is found by lsof(8) or fuser(1).)
Apr 23 19:05:40 localhost ubuntu-core-upgrade: failed to mount (['mount', '-o', 'rw', '/dev/mmcblk0p2', '/writable/cache/system']): mount: /dev/mmcblk0p2 is already mounted or /writable/cache/system busy#012 /dev/mmcblk0p2 is already mounted on /writable/cache/system
Apr 23 19:05:41 localhost snappy[1887]: error from system-image-cli: ('%s exited with %s:\n%s', ['ubuntu-core-upgrade'], 1, "failed to unmount (['umount', '/writable/cache/system']): umount: /writable/cache/system: target is busy\n (In some cases useful info about processes that\n use the device is found by lsof(8) or fuser(1).)\n\nfailed to mou")
Apr 23 19:05:41 localhost systemd[1]: snappy-autopilot.service: main process exited, code=exited, status=1/FAILURE
Apr 23 19:05:41 localhost systemd[1]: Unit snappy-autopilot.service entered failed state.
Apr 23 19:05:41 localhost systemd[1]: snappy-autopilot.service failed.

[Michael Vogt (mvo)]

I also see what Steve sees in #7 - i.e. there "is an upgrader problem that eats the /boot/uboot directory on the opposite partition on each upgrade".

I tried to reproduce this with r31 and have:
$ ls -l /writable/cache/system/boot/
total 37196
-rw------- 1 root root 3195831 Apr 17 03:46 System.map-3.19.0-15-generic
-rw-r--r-- 1 root root 1189894 Apr 17 03:46 abi-3.19.0-15-generic
-rw-r--r-- 1 root root 182579 Apr 17 03:46 config-3.19.0-15-generic
drwxr-xr-x 2 root root 4096 Apr 19 14:58 efi
-rw-r--r-- 1 root root 13492457 Apr 23 04:41 initrd.img
-rw-r--r-- 1 root root 13492457 Apr 23 04:42 initrd.img-3.19.0-15-generic
d-wxr----x 2 root root 4096 Apr 23 07:25 uboot

Note the incorrect permissions on uboot that might trigger it (but if it is, why
is it triggering only recently and we haven't seen the failure before(?)).

With that I upgraded from r31 to r40 and got:
"""
120.12 MB / 120.12 MB [==================================] 100.00 % 185.63 KB/s
Done
Failed to run command '/bin/mount -obind /boot/uboot /writable/cache/system/boot/uboot': mount: mount point /writable/cache/system/boot/uboot does not exist
 (exit status 32)
"""

After that I get:
"""
Failed to run command '/bin/umount /writable/cache/system': umount: /writable/cache/system: target is busy
"""
(which makes me wonder if we could do the fsck of the other partiton on boot instead of on snappy upgrade time so that on snappy upgrade time we can do a remount instead of unmount/mount.)

[Michael Vogt (mvo)]

I think the root cause for this is that the "format" command in ubuntu_commands clears the other rootfs and then the tarfile is used to re-create it. However this rootfs does not include /boot/uboot anymore and the subsequent bind mount fails (which we actually do not need on uboot to update the botloader because its only needed to run update-grub).

[Michael Vogt (mvo)]

This is fixed with image r41+, the missing /boot/uboot is now available in the ubuntu-$hash tar.