clearlinux / distribution

Placeholder repository to allow filing of general bugs/issues/etc against the Clear Linux OS for Intel Architecture linux distribution
521 stars 29 forks source link

Clear GUI/text installers failing in VM due to qemu cache=writeback #2728

Closed marioroy closed 2 years ago

marioroy commented 2 years ago

The issue has been failing for a while and took time to track the actual cause. The installer immediately fails around "Setting boot partition", "Rescanning media". Perhaps, requires syncing to disk after "Updating partition table".

Passing: cache=none

-drive if=none,id=disk0,cache=none,format="$FORMAT",aio=threads,file="$IMAGE",discard=on \

Failing: cache=writeback

-drive if=none,id=disk0,cache=writeback,format="$FORMAT",aio=threads,file="$IMAGE",discard=on \

Error:

$ sudo grep -i error /root/clr-installer.log
... [WRN] getPartitionTable() had an error reading partition table "Error: /dev/loop0: unrecognized disk label\nBYT;\n/dev/loop0:3975557120B:loopback:512:512:unknown:Loopback device:;\n"
marioroy commented 2 years ago

image

Extract from log:

...
2022/09/07 02:41:32 [DBG] cmd.Env: []
2022/09/07 02:41:44 [DBG] lsblk --exclude 1,2,11 -J -b -O /dev/vda
2022/09/07 02:41:44 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:44 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:44 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:44 [DBG] cmd.Env: []
2022/09/07 02:41:44 [INF] Cleaning disk(dryrun): /dev/vda with ForceDestructive: false
2022/09/07 02:41:44 [DBG] lsblk --exclude 1,2,11 -J -b -O /dev/vda
2022/09/07 02:41:44 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:44 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:44 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:44 [DBG] cmd.Env: []
2022/09/07 02:41:44 [DBG] lsblk --exclude 1,2,11 -J -b -O /dev/vda
2022/09/07 02:41:44 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:44 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:44 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:44 [DBG] cmd.Env: []
2022/09/07 02:41:44 [DBG] Partitions before sorting:
2022/09/07 02:41:44 [DBG] vda1: fsType=vfat, mount=/boot, size=157286400, type=part
2022/09/07 02:41:44 [DBG] vda2: fsType=ext4, mount=/, size=20823629312, type=part
2022/09/07 02:41:44 [DBG] Partitions after sorting:
2022/09/07 02:41:44 [DBG] vda1: fsType=vfat, mount=/boot, size=157286400, type=part
2022/09/07 02:41:44 [DBG] vda2: fsType=ext4, mount=/, size=20823629312, type=part
2022/09/07 02:41:44 [DBG] parted --machine --script -- /dev/vda unit B print
2022/09/07 02:41:44 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:44 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:44 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:44 [DBG] cmd.Env: []
2022/09/07 02:41:44 [DBG] MediaChange: vda: WARNING: Selected media will be erased.
2022/09/07 02:41:44 [DBG] MediaChange: vda: WARNING: New Partition table will be created.
2022/09/07 02:41:44 [DBG] MediaChange: vda: Add new partition. [150MiB]
2022/09/07 02:41:44 [DBG] MediaChange: vda: Add new partition. [19.4GiB]
2022/09/07 02:41:44 [DBG] MediaChange: vda1: Format partition as vfat. [/boot]
2022/09/07 02:41:44 [DBG] MediaChange: vda2: Format partition as ext4. [/]
2022/09/07 02:41:44 [DBG] MediaChange: /var/swapfile (64MiB)
2022/09/07 02:41:49 [DBG] timeout --kill-after=30s 30s curl --no-sessionid -o /tmp/clr-installer-yaml-309892248 -s -f https://cdn.download.clearlinux.org/releases/37060/clear/config/image/.data/pre-gui-install-msg.yaml
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [INF] Running pre-install hooks
2022/09/07 02:41:49 [DBG] Clear Linux OS version: latest
2022/09/07 02:41:49 [DBG] lsblk --exclude 1,2,11 -J -b -O /dev/vda
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 6 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 2 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [INF] Cleaning disk(action): /dev/vda with ForceDestructive: false
2022/09/07 02:41:49 [DBG] lsblk --exclude 1,2,11 -J -b -O /dev/vda
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] removePart: Found parent: /dev/vda for child: /dev/vda1
2022/09/07 02:41:49 [WRN] Deleting part: vda1 from disk: vda
2022/09/07 02:41:49 [DBG] parted /dev/vda --script -- rm 1
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] lsblk --exclude 1,2,11 -J -b -O /dev/vda
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] removePart: Found parent: /dev/vda for child: /dev/vda2
2022/09/07 02:41:49 [WRN] Deleting part: vda2 from disk: vda
2022/09/07 02:41:49 [DBG] parted /dev/vda --script -- rm 2
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] Pre-Installation has no message content
2022/09/07 02:41:49 [INF] Writing partition table to: vda
2022/09/07 02:41:49 [DBG] parted -s /dev/vda mklabel gpt
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [INF] Updating partition table for: vda
2022/09/07 02:41:49 [DBG] Partitions before sorting:
2022/09/07 02:41:49 [DBG] vda1: fsType=vfat, mount=/boot, size=157286400, type=part
2022/09/07 02:41:49 [DBG] vda2: fsType=ext4, mount=/, size=20823629312, type=part
2022/09/07 02:41:49 [DBG] Partitions after sorting:
2022/09/07 02:41:49 [DBG] vda1: fsType=vfat, mount=/boot, size=157286400, type=part
2022/09/07 02:41:49 [DBG] vda2: fsType=ext4, mount=/, size=20823629312, type=part
2022/09/07 02:41:49 [DBG] parted --machine --script -- /dev/vda unit B print
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] WritePartitionTable: processing child: &{vda1      vfat   /boot boot  157286400 part  false false [] true true true false  false 1 []}
2022/09/07 02:41:49 [DBG] WritePartitionTable: WholeDisk mode
2022/09/07 02:41:49 [DBG] WritePartitionTable: start: 0, end: 157286400
2022/09/07 02:41:49 [DBG] WritePartitionTable: mkPartCmd: mkpart EFI fat32 0% 157M
2022/09/07 02:41:49 [DBG] parted -a optimal /dev/vda unit MB --script -- mkpart EFI fat32 0% 157M
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] parted --machine --script -- /dev/vda unit B print
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] WritePartitionTable: processing child: &{vda2      ext4   / root  20823629312 part  false false [] true true true false  false 2 []}
2022/09/07 02:41:49 [DBG] WritePartitionTable: WholeDisk mode
2022/09/07 02:41:49 [DBG] WritePartitionTable: start: 157286400, end: 20980915712
2022/09/07 02:41:49 [DBG] WritePartitionTable: mkPartCmd: mkpart / 157M 20980M
2022/09/07 02:41:49 [DBG] parted -a optimal /dev/vda unit MB --script -- mkpart / 157M 20980M
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [DBG] parted --machine --script -- /dev/vda unit B print
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:49 [INF] Setting GUIDs for device: /dev/vda
2022/09/07 02:41:49 [DBG] sgdisk /dev/vda --typecode=1:C12A7328-F81F-11D2-BA4B-00A0C93EC93B
2022/09/07 02:41:49 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:49 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:49 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:49 [DBG] cmd.Env: []
2022/09/07 02:41:50 [DBG] The operation has completed successfully.
2022/09/07 02:41:50 [DBG] sgdisk /dev/vda --typecode=2:4F68BCE3-E8CD-4DB1-96E7-FBCAF984B709
2022/09/07 02:41:50 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:50 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:50 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:50 [DBG] cmd.Env: []
2022/09/07 02:41:51 [DBG] The operation has completed successfully.
2022/09/07 02:41:51 [INF] Setting boot partition: vda1 [boot]
2022/09/07 02:41:51 [DBG] parted /dev/vda set 1 boot on
2022/09/07 02:41:51 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:51 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:51 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:51 [DBG] cmd.Env: []
2022/09/07 02:41:51 [DBG] Information: You may need to update /etc/fstab.

2022/09/07 02:41:51 [DBG] partprobe /dev/vda
2022/09/07 02:41:51 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:51 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:51 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:51 [DBG] cmd.Env: []
2022/09/07 02:41:55 [INF] Writing vfat file system to vda1 '/boot'
2022/09/07 02:41:55 [DBG] mkfs.vfat -n boot -F32 /dev/vda1
2022/09/07 02:41:55 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:55 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:55 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:55 [DBG] cmd.Env: []
2022/09/07 02:41:55 [DBG] mkfs.fat: Warning: lowercase labels might not work properly on some systems
2022/09/07 02:41:55 [DBG] mkfs.fat 4.2 (2021-01-31)
2022/09/07 02:41:55 [DBG] blkid --probe /dev/vda1 --output export
2022/09/07 02:41:55 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:55 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:55 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:55 [DBG] cmd.Env: []
2022/09/07 02:41:55 [DBG] updatePartitionInfo: Updated /dev/vda1 LABEL: boot
2022/09/07 02:41:55 [DBG] updatePartitionInfo: Updated /dev/vda1 UUID: 4F3E-3E71
2022/09/07 02:41:55 [DBG] updatePartitionInfo: Ignoring unknown line: 
2022/09/07 02:41:56 [INF] Writing ext4 file system to vda2 '/'
2022/09/07 02:41:56 [DBG] mkfs.ext4 -L root -v -F -b 4096 /dev/vda2
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] mke2fs 1.46.5 (30-Dec-2021)
2022/09/07 02:41:56 [DBG] fs_types for mke2fs.conf resolution: 'ext4'
2022/09/07 02:41:56 [DBG] Discarding device blocks:       0/5083648
2022/09/07 02:41:56 [DBG] done                            
2022/09/07 02:41:56 [DBG] Filesystem label=root
2022/09/07 02:41:56 [DBG] OS type: Linux
2022/09/07 02:41:56 [DBG] Block size=4096 (log=2)
2022/09/07 02:41:56 [DBG] Fragment size=4096 (log=2)
2022/09/07 02:41:56 [DBG] Stride=0 blocks, Stripe width=256 blocks
2022/09/07 02:41:56 [DBG] 1272960 inodes, 5083648 blocks
2022/09/07 02:41:56 [DBG] 254182 blocks (5.00%) reserved for the super user
2022/09/07 02:41:56 [DBG] First data block=0
2022/09/07 02:41:56 [DBG] Maximum filesystem blocks=2153775104
2022/09/07 02:41:56 [DBG] 156 block groups
2022/09/07 02:41:56 [DBG] 32768 blocks per group, 32768 fragments per group
2022/09/07 02:41:56 [DBG] 8160 inodes per group
2022/09/07 02:41:56 [DBG] Filesystem UUID: 6903925f-abb1-4a3c-9199-caef7f39512a
2022/09/07 02:41:56 [DBG] Superblock backups stored on blocks: 
2022/09/07 02:41:56 [DBG]   32768
2022/09/07 02:41:56 [DBG] , 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208, 
2022/09/07 02:41:56 [DBG]   4096000
2022/09/07 02:41:56 [DBG] Allocating group tables:   0/156
2022/09/07 02:41:56 [DBG] done                            
2022/09/07 02:41:56 [DBG] Writing inode tables:   0/156
2022/09/07 02:41:56 [DBG] done                            
2022/09/07 02:41:56 [DBG] Creating journal (32768 blocks): 
2022/09/07 02:41:56 [DBG] done
2022/09/07 02:41:56 [DBG] Writing superblocks and filesystem accounting information: 
2022/09/07 02:41:56 [DBG]   0/156
2022/09/07 02:41:56 [DBG]        
2022/09/07 02:41:56 [DBG] done
2022/09/07 02:41:56 [DBG] blkid --probe /dev/vda2 --output export
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] updatePartitionInfo: Updated /dev/vda2 LABEL: root
2022/09/07 02:41:56 [DBG] updatePartitionInfo: Updated /dev/vda2 UUID: 6903925f-abb1-4a3c-9199-caef7f39512a
2022/09/07 02:41:56 [DBG] updatePartitionInfo: Ignoring unknown line: 
2022/09/07 02:41:56 [DBG] partprobe -s
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] Warning: Unable to open /dev/sr0 read-write (Read-only file system).  /dev/sr0 has been opened read-only.
2022/09/07 02:41:56 [DBG] /dev/sr0: msdos partitions 2
2022/09/07 02:41:56 [DBG] /dev/vda: gpt partitions 1 2
2022/09/07 02:41:56 [DBG] udevadm settle --timeout 10
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] lsblk --exclude 1,2,11 -J -b -O
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] parted --machine --script -- /dev/loop0 unit B print free
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [WRN] getPartitionTable() had an error reading partition table "Error: /dev/loop0: unrecognised disk label\nBYT;\n/dev/loop0:3975557120B:loopback:512:512:unknown:Loopback device:;\n"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is ""
2022/09/07 02:41:56 [DBG] parted --machine --script -- /dev/vda unit B print free
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] setPartitionTable() line is "BYT"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is "/dev/vda:20980915712B:virtblk:512:512:gpt:Virtio Block Device:"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is "1:17408B:1048575B:1031168B:free"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is "1:1048576B:157286399B:156237824B:fat32:EFI:boot, esp"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is "2:157286400B:20979908607B:20822622208B:ext4:/:"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is "1:20979908608B:20980898815B:990208B:free"
2022/09/07 02:41:56 [DBG] setPartitionTable() line is ""
2022/09/07 02:41:56 [INF] Mounting: /
2022/09/07 02:41:56 [INF] Running post-image hooks
2022/09/07 02:41:56 [INF] Installation Steps Complete
2022/09/07 02:41:56 [DBG] timeout --kill-after=30s 30s curl --no-sessionid -o /tmp/clr-installer-yaml-699747158 -s -f https://cdn.download.clearlinux.org/releases/37060/clear/config/image/.data/post-gui-install-msg.yaml
2022/09/07 02:41:56 [DBG] sync user is PKEXEC_UID=#1000
2022/09/07 02:41:56 [DBG] Gnome Proxy Mode: none
2022/09/07 02:41:56 [DBG] [Previous line repeated 4 times]
2022/09/07 02:41:56 [DBG] cmd.Env: []
2022/09/07 02:41:56 [DBG] Post-Installation has no message content
marioroy commented 2 years ago

Also failing randomly is aio=threads. I changed it to native. Running aio=threads is fine after the Clear Linux installation.

-object iothread,id=io0 \
-drive if=none,id=disk0,cache=none,format="$FORMAT",aio=native,file="$IMAGE",discard=on \
-device virtio-blk-pci,drive=disk0,scsi=off,iothread=io0 \
marioroy commented 2 years ago

Good luck with the GUI/text-based Clear installers. I'm not sure if pin-pointing to the actual issue. Sometimes, it takes several attempts installing the OS inside a VM.

bryteise commented 2 years ago

I've seen this occasionally usually it is kernel not getting notifications on partition changes for loopback devices. I haven't found a root cause.

marioroy commented 2 years ago

Setting cache=none and aio=native is helpful.

bryteise commented 2 years ago

Interesting finding for sure.

marioroy commented 2 years ago

The issue is resolved in Clear Linux 37110. I tested my VM using cache=writeback and aio=threads. No issues.