[Bug 1900693] Re: snapd cannot refresh on some SD cards due to uboot bug

Łukasz Zemczak 1900693 at bugs.launchpad.net
Wed Nov 18 16:42:31 UTC 2020 

Hello Zygmunt, or anyone else affected,

Accepted u-boot into bionic-proposed. The package will build now and be
available at https://launchpad.net/ubuntu/+source/u-boot/2020.10+dfsg-
1ubuntu0~18.04.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package.  See
https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how
to enable and use -proposed.  Your feedback will aid us getting this
update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug,
mentioning the version of the package you tested, what testing has been
performed on the package and change the tag from verification-needed-
bionic to verification-done-bionic. If it does not fix the bug for you,
please add a comment stating that, and change the tag to verification-
failed-bionic. In either case, without details of your testing we will
not be able to proceed.

Further information regarding the verification process can be found at
https://wiki.ubuntu.com/QATeam/PerformingSRUVerification .  Thank you in
advance for helping!

N.B. The updated package will be released to -updates after the bug(s)
fixed by this package have been verified and the package has been in
-proposed for a minimum of 7 days.

** Changed in: u-boot (Ubuntu Bionic)
       Status: New => Fix Committed

** Tags added: verification-needed verification-needed-bionic

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to u-boot in Ubuntu.
https://bugs.launchpad.net/bugs/1900693

Title:
  snapd cannot refresh on some SD cards due to uboot bug

Status in snapd:
  New
Status in u-boot package in Ubuntu:
  Fix Released
Status in u-boot source package in Bionic:
  Fix Committed
Status in u-boot source package in Focal:
  New

Bug description:
  Analysis of a specific Pi device resulted in mystery of failure to
  upgrade core18 or other snaps that require writes to FAT bootable
  partition.

  This was finally reproduced with a fixed set of snaps:

  - core18 - revision 1076
  - pi - revision 17
  - pi-kernel - revision 44
  - snapd (current version may fail due to session.d bug) - revision 9731 (hard to seed without help)

  This combination seems to suffer from:
  - lack of fsck.vfat in core18 (fixed later)
  - possible malfunction of snapd-specific shutdown helper

  Refreshing core18 from this setup results in the following failure (as
  captured on the serial log), necessitating TWO power cycles to
  resolve:


  U-Boot 2019.04-dirty (Jul 10 2019 - 09:50:40 +0000)

  DRAM:  948 MiB
  RPI 3 Model B+ (0xa020d3)
  MMC:   mmc at 7e202000: 0, sdhci at 7e300000: 1
  Loading Environment from FAT... OK
  In:    serial
  Out:   serial
  Err:   serial
  Net:   No ethernet found.
  Hit any key to stop autoboot:  0 
  switch to partitions #0, OK
  mmc0 is current device
  LOADBOOTENV
  Running uenvcmd ...
  ENVCMD
  Saving Environment to FAT... wait_transfer_complete - still waiting after 100001 retries
  mmc write failed
  Error: writing directory entry
  OK
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  ** Can't read partition table on 0:0 **
  ** Invalid partition 1 **
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  ** Can't read partition table on 0:0 **
  ** Invalid partition 1 **
  previous command (24) not complete (EDM 00010807)
  WARNING at drivers/mmc/bcm2835_sdhost.c:376/bcm2835_prepare_data()!
  3314130 bytes read in 154 ms (20.5 MiB/s)
  42079 bytes read in 36 ms (1.1 MiB/s)
  Bad Linux ARM zImage magic!
  Scanning mmc 0:1...
  Scanning mmc 0:2...
  starting USB...
  USB0:   scanning bus 0 for devices... 4 USB Device(s) found
         scanning usb for storage devices... 0 Storage Device(s) found

  Device 0: unknown device
  lan78xx_eth Waiting for PHY auto negotiation to complete...... done
  BOOTP broadcast 1
  BOOTP broadcast 2
  BOOTP broadcast 3
  DHCP client bound to address 192.168.2.106 (757 ms)
  *** ERROR: `serverip' not set
  Cannot autoload with TFTPGET
  missing environment variable: pxeuuid
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/01-b8-27-eb-9f-89-d1
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A8026A
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A8026
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A802
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A80
  lan78xx_eth Waiting for PHY auto negotiation to complete...


  
  On the first power-cycle the logs say this:


  U-Boot 2019.04-dirty (Jul 10 2019 - 09:50:40 +0000)

  DRAM:  948 MiB
  RPI 3 Model B+ (0xa020d3)
  MMC:   mmc at 7e202000: 0, sdhci at 7e300000: 1
  Loading Environment from FAT... OK
  In:    serial
  Out:   serial
  Err:   serial
  Net:   No ethernet found.
  Hit any key to stop autoboot:  0 
  switch to partitions #0, OK
  mmc0 is current device
  LOADBOOTENV
  Running uenvcmd ...
  ENVCMD
  Saving Environment to FAT... wait_transfer_complete - still waiting after 100001 retries
  mmc write failed
  Error: writing directory entry
  OK
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  ** Can't read partition table on 0:0 **
  ** Invalid partition 1 **
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  ** Can't read partition table on 0:0 **
  ** Invalid partition 1 **
  previous command (24) not complete (EDM 00010807)
  WARNING at drivers/mmc/bcm2835_sdhost.c:376/bcm2835_prepare_data()!
  3314130 bytes read in 155 ms (20.4 MiB/s)
  42079 bytes read in 54 ms (760.7 KiB/s)
  Bad Linux ARM zImage magic!
  Scanning mmc 0:1...
  Scanning mmc 0:2...
  starting USB...
  USB0:   scanning bus 0 for devices... 4 USB Device(s) found
         scanning usb for storage devices... 0 Storage Device(s) found

  Device 0: unknown device
  lan78xx_eth Waiting for PHY auto negotiation to complete...... done
  BOOTP broadcast 1
  BOOTP broadcast 2
  BOOTP broadcast 3
  DHCP client bound to address 192.168.2.106 (758 ms)
  *** ERROR: `serverip' not set
  Cannot autoload with TFTPGET
  missing environment variable: pxeuuid
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/01-b8-27-eb-9f-89-d1
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A8026A
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A8026
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A802
  lan78xx_eth Waiting for PHY auto negotiation to complete...... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A80
  lan78xx_eth Waiting for PHY auto negotiation to complete..... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A8
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0A
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C0
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/C
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/default-arm-bcm283x
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/default-arm
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  missing environment variable: bootfile
  Retrieving file: pxelinux.cfg/default
  lan78xx_eth Waiting for PHY auto negotiation to complete....... done
  *** ERROR: `serverip' not set
  Config file not found
  lan78xx_eth Waiting for PHY auto negotiation to complete....

  
  Finally on the second power cycle the logs contain:

  
  U-Boot 2019.04-dirty (Jul 10 2019 - 09:50:40 +0000)

  DRAM:  948 MiB
  RPI 3 Model B+ (0xa020d3)
  MMC:   mmc at 7e202000: 0, sdhci at 7e300000: 1
  Loading Environment from FAT... OK
  In:    serial
  Out:   serial
  Err:   serial
  Net:   No ethernet found.
  Hit any key to stop autoboot:  0 
  switch to partitions #0, OK
  mmc0 is current device
  LOADBOOTENV
  Running uenvcmd ...
  ENVCMD
  Saving Environment to FAT... wait_transfer_complete - still waiting after 100001 retries
  mmc write failed
  Error: writing directory entry
  OK
  previous command (24) not complete (EDM 00010807)
  previous command (24) not complete (EDM 00010807)
  WARNING at drivers/mmc/bcm2835_sdhost.c:376/bcm2835_prepare_data()!
  6693376 bytes read in 304 ms (21 MiB/s)
  3314130 bytes read in 148 ms (21.4 MiB/s)
  42079 bytes read in 55 ms (747.1 KiB/s)
  Kernel image @ 0x200000 [ 0x000000 - 0x662200 ]
  ## Flattened Device Tree blob at 02000000
     Booting using the fdt blob at 0x2000000
     Loading Ramdisk to 3ac19000, end 3af4c631 ... OK
     Loading Device Tree to 3ac0f000, end 3ac18526 ... OK

  Starting kernel ...

  
  (boot proceeds normally)

  
  Searching the web seems to suggest that uboot is waiting insufficiently for the FAT write to complete: https://www.mail-archive.com/u-boot@lists.denx.de/msg330093.html

To manage notifications about this bug go to:
https://bugs.launchpad.net/snapd/+bug/1900693/+subscriptions

More information about the foundations-bugs mailing list