CM3 fails to boot fsarchiver-backed system
Posted: Tue Dec 18, 2018 9:53 am
Hi,
I've got an issue while trying to restore a CM3 system backup. The backup and restoration process are executed without errors but the CM3 fails at booting. As I'm using several CM3 with embedded EMMC, I used usbboot/rpiboot utility to mount EMMC partitions to my ubuntu machine. I then used fsarchiver to create a backup of my running system using the following command :
This is supposed to create a backup of both partition, FAT32 boot partition and EXT4 rootfs one.
So far the process is runs properly. Using again rpiboot on a new CM3 with EMMC, I created the two required partitions (boot/rootfs) using gparted. For the backup restoration, the command used for fsarchiver was the following one :
Unfortunately, the CM3 doesn't boot as expected and is stuck. Here is the boot trace :
Thanks for your answers, have a good day !
Raphael
I've got an issue while trying to restore a CM3 system backup. The backup and restoration process are executed without errors but the CM3 fails at booting. As I'm using several CM3 with embedded EMMC, I used usbboot/rpiboot utility to mount EMMC partitions to my ubuntu machine. I then used fsarchiver to create a backup of my running system using the following command :
Code: Select all
sudo fsarchiver savefs cm3_backup_20181218.fsa /dev/sdb1 /dev/sdb2This is supposed to create a backup of both partition, FAT32 boot partition and EXT4 rootfs one.
So far the process is runs properly. Using again rpiboot on a new CM3 with EMMC, I created the two required partitions (boot/rootfs) using gparted. For the backup restoration, the command used for fsarchiver was the following one :
Code: Select all
sudo fsarchiver restfs cm3_backup_20181218.fsa id=0,dest=/dev/sdb1 id=1,dest=/dev/sdb2Unfortunately, the CM3 doesn't boot as expected and is stuck. Here is the boot trace :
Code: Select all
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.14.87-v7+ (pi@raspberrypi) (gcc version 6.3.0 20170516 (Raspbian 6.3.0-18+rpi1+deb9u1)) #1 SMP Wed Dec 12 10:37:34 GMT 2018
[ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi Compute Module 3 Rev 1.0
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] cma: Reserved 8 MiB at 0x3ac00000
[ 0.000000] percpu: Embedded 17 pages/cpu @ba349000 s38668 r8192 d22772 u69632
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 240555
[ 0.000000] Kernel command line: bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:C5:85:A5 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=PARTUUID=80fc31e3-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Memory: 940236K/970752K available (7168K kernel code, 576K rwdata, 2076K rodata, 1024K init, 697K bss, 22324K reserved, 8192K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xbb800000 - 0xff800000 (1088 MB)
[ 0.000000] lowmem : 0x80000000 - 0xbb400000 ( 948 MB)
[ 0.000000] modules : 0x7f000000 - 0x80000000 ( 16 MB)
[ 0.000000] .text : 0x80008000 - 0x80800000 (8160 kB)
[ 0.000000] .init : 0x80b00000 - 0x80c00000 (1024 kB)
[ 0.000000] .data : 0x80c00000 - 0x80c900fc ( 577 kB)
[ 0.000000] .bss : 0x80c980cc - 0x80d468a0 ( 698 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 25203 entries in 74 pages
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[ 0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[ 0.000021] Switching to timer-based delay loop, resolution 52ns
[ 0.000268] Console: colour dummy device 80x30
[ 0.000802] console [tty1] enabled
[ 0.000836] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[ 0.000876] pid_max: default: 32768 minimum: 301
[ 0.001192] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001224] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.002180] Disabling memory control group subsystem
[ 0.002270] CPU: Testing write buffer coherency: ok
[ 0.002686] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.003101] Setting up static identity map for 0x100000 - 0x10003c
[ 0.003236] Hierarchical SRCU implementation.
[ 0.003918] smp: Bringing up secondary CPUs ...
[ 0.004653] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.005431] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.006195] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.006298] smp: Brought up 1 node, 4 CPUs
[ 0.006371] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[ 0.006393] CPU: All CPU(s) started in HYP mode.
[ 0.006411] CPU: Virtualization extensions available.
[ 0.007349] devtmpfs: initialized
[ 0.016823] random: get_random_u32 called from bucket_table_alloc+0x100/0x254 with crng_init=0
[ 0.017488] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[ 0.017721] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.017765] futex hash table entries: 1024 (order: 4, 65536 bytes)
[ 0.018356] pinctrl core: initialized pinctrl subsystem
[ 0.019092] NET: Registered protocol family 16
[ 0.021684] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.026241] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.026274] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.026478] Serial: AMBA PL011 UART driver
[ 0.028103] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[ 0.058460] bcm2835-dma 3f007000.dma: DMA legacy API manager at bb813000, dmachans=0x1
[ 0.059872] SCSI subsystem initialized
[ 0.060217] usbcore: registered new interface driver usbfs
[ 0.060286] usbcore: registered new interface driver hub
[ 0.060384] usbcore: registered new device driver usb
[ 0.070084] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-11-04 16:31
[ 0.071378] clocksource: Switched to clocksource arch_sys_counter
[ 0.146972] VFS: Disk quotas dquot_6.6.0
[ 0.147082] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.147282] FS-Cache: Loaded
[ 0.147493] CacheFiles: Loaded
[ 0.156103] NET: Registered protocol family 2
[ 0.156830] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.156958] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[ 0.157160] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.157305] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 0.157366] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 0.157603] NET: Registered protocol family 1
[ 0.158077] RPC: Registered named UNIX socket transport module.
[ 0.158101] RPC: Registered udp transport module.
[ 0.158120] RPC: Registered tcp transport module.
[ 0.158139] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.159613] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[ 0.162307] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[ 0.169862] FS-Cache: Netfs 'nfs' registered for caching
[ 0.170466] NFS: Registering the id_resolver key type
[ 0.170510] Key type id_resolver registered
[ 0.170530] Key type id_legacy registered
[ 0.170559] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.172520] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.172677] io scheduler noop registered
[ 0.172699] io scheduler deadline registered (default)
[ 0.172880] io scheduler cfq registered
[ 0.172901] io scheduler mq-deadline registered
[ 0.172921] io scheduler kyber registered
[ 0.175557] BCM2708FB: allocated DMA memory fad10000
[ 0.175602] BCM2708FB: allocated DMA channel 0 @ bb813000
[ 0.183375] Console: switching to colour frame buffer device 82x26
[ 0.190592] bcm2835-rng 3f104000.rng: hwrng registered
[ 0.192704] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[ 0.197121] vc-sm: Videocore shared memory driver
[ 0.199349] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[ 0.212543] brd: module loaded
[ 0.222965] loop: module loaded
[ 0.224908] Loading iSCSI transport class v2.0-870.
[ 0.227486] libphy: Fixed MDIO Bus: probed
[ 0.229509] usbcore: registered new interface driver lan78xx
[ 0.231525] usbcore: registered new interface driver smsc95xx
[ 0.233358] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.263065] dwc_otg 3f980000.usb: base=0xf0980000
[ 0.465118] Core Release: 2.80a
[ 0.466964] Setting default values for core params
[ 0.468878] Finished setting default values for core params
[ 0.671061] Using Buffer DMA mode
[ 0.673001] Periodic Transfer Interrupt Enhancement - disabled
[ 0.675025] Multiprocessor Interrupt Enhancement - disabled
[ 0.677035] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 0.679007] Dedicated Tx FIFOs mode
[ 0.681267] WARN::dwc_otg_hcd_init:1046: FIQ DMA bounce buffers: virt = 0xbad04000 dma = 0xfad04000 len=9024
[ 0.685162] FIQ FSM acceleration enabled for :
[ 0.685162] Non-periodic Split Transactions
[ 0.685162] Periodic Split Transactions
[ 0.685162] High-Speed Isochronous Endpoints
[ 0.685162] Interrupt/Control Split Transaction hack enabled
[ 0.694428] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x805eece4
[ 0.696344] WARN::hcd_init_fiq:460: FIQ ASM at 0x805ef03c length 36
[ 0.698229] WARN::hcd_init_fiq:486: MPHI regs_base at 0xf0006000
[ 0.700188] dwc_otg 3f980000.usb: DWC OTG Controller
[ 0.702139] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[ 0.704119] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[ 0.706086] Init: Port Power? op_state=1
[ 0.707989] Init: Power Port (0)
[ 0.710025] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.711994] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.713939] usb usb1: Product: DWC OTG Controller
[ 0.715839] usb usb1: Manufacturer: Linux 4.14.87-v7+ dwc_otg_hcd
[ 0.717760] usb usb1: SerialNumber: 3f980000.usb
[ 0.720244] hub 1-0:1.0: USB hub found
[ 0.722146] hub 1-0:1.0: 1 port detected
[ 0.724635] usbcore: registered new interface driver usb-storage
[ 0.726589] mousedev: PS/2 mouse device common for all mice
[ 0.728470] IR NEC protocol handler initialized
[ 0.730301] IR RC5(x/sz) protocol handler initialized
[ 0.732183] IR RC6 protocol handler initialized
[ 0.734025] IR JVC protocol handler initialized
[ 0.735784] IR Sony protocol handler initialized
[ 0.737548] IR SANYO protocol handler initialized
[ 0.739313] IR Sharp protocol handler initialized
[ 0.740996] IR MCE Keyboard/mouse protocol handler initialized
[ 0.742725] IR XMP protocol handler initialized
[ 0.745071] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[ 0.747088] bcm2835-cpufreq: min=600000 max=1200000
[ 0.749216] sdhci: Secure Digital Host Controller Interface driver
[ 0.751014] sdhci: Copyright(c) Pierre Ossman
[ 0.753139] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[ 0.755064] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.757306] ledtrig-cpu: registered to indicate activity on CPUs
[ 0.759246] hidraw: raw HID events driver (C) Jiri Kosina
[ 0.761230] usbcore: registered new interface driver usbhid
[ 0.763177] usbhid: USB HID core driver
[ 0.765651] vchiq: vchiq_init_state: slot_zero = bad80000, is_master = 0
[ 0.769020] [vc_sm_connected_init]: start
[ 0.777868] [vc_sm_connected_init]: end - returning 0
[ 0.780337] Initializing XFRM netlink socket
[ 0.782282] NET: Registered protocol family 17
[ 0.784318] Key type dns_resolver registered
[ 0.786679] Registering SWP/SWPB emulation handler
[ 0.789221] registered taskstats version 1
[ 0.796961] uart-pl011 3f201000.serial: cts_event_workaround enabled
[ 0.799100] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[ 1.803015] console [ttyAMA0] enabled
[ 1.810642] sdhost: log_buf @ bad07000 (fad07000)
[ 1.891403] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 1.899887] of_cfs_init
[ 1.904431] of_cfs_init: OK
[ 1.909552] Waiting for root device PARTUUID=80fc31e3-02...
[ 1.977858] mmc0: new high speed MMC card at address 0001
[ 1.985642] mmcblk0: mmc0:0001 4FPD3R 3.64 GiB
[ 1.992193] mmcblk0boot0: mmc0:0001 4FPD3R partition 1 4.00 MiB
[ 2.000247] mmcblk0boot1: mmc0:0001 4FPD3R partition 2 4.00 MiB
[ 2.008221] mmcblk0rpmb: mmc0:0001 4FPD3R partition 3 512 KiB
[ 2.017292] mmcblk0: p1 p2Thanks for your answers, have a good day !
Raphael