Summary: After building a ppc64el QEMU testbed, I met a similar symptom to
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=973038#40
From: Simon McVittie <s...@debian.org>
Subject: Re: autopkgtest-build-qemu support for ppc64el, arm64, armel, i386 UEFI
Date: Sun, 15 Nov 2020 18:49:36 +0000
> * #926945 (ppc64el UEFI)
> - needs a small PReP partition for the firmware
> - needs a special flag on that partition, with a vmdb2 patch that hasn't
> been reviewed or merged yet
As vmdb2 for ppc64el is not ready, I wrote a custom script to build a
QEMU autopkg testbed with GPT partitioning at
https://github.com/emojifreak/qemu-arm-image-builder/blob/main/README.md#build-gpt-autopkgtest-qemu-debiansh
The built testbed works fine for amd64 architecture, and for arm64 it reproduces
the same symptom as
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=973038#40
So I assume the script is OK... The built testbed for ppc64el is placed at
http://153.240.174.134:64193/tmp/autopkgtest-sid-ppc64el.qcow2
(300 MB qcow2 file with 25 GB disk image)
Since qemu-system-ppc64le does not have any serial port, we have to modify
autopkgtest-virt-qemu to give serial ports to VM, as the first attachment
(diff is against "apt-get source autopkgtest/sid"), which is similar to the one
required
for arm64 architecture.
Then I consistently got
autopkgtest-virt-qemu: DBG: execute-timeout:
/tmp/autopkgtest-qemu.z8ii9cut/runcmd true
autopkgtest-virt-qemu: DBG: can connect to autopkgtest sh in VM
autopkgtest-virt-qemu: DBG: determine_normal_user: no uid in [1000,59999]
available
which is strange as /etc/passwd in the testbed has
debci:x:106:65534::/home/debci:/bin/sh
user:x:1000:1000::/home/user:/bin/sh
The full log is attached as the second attachment.
I think I identified what are required for vmdb2 to handle ppc64el GPT
partition.
I will send my view to bts #973467
Best regards, Ryutaroh
--- autopkgtest-5.15/virt/autopkgtest-virt-qemu 2020-10-27 05:27:25.000000000
+0900
+++ /usr/bin/autopkgtest-virt-qemu 2020-11-20 12:20:54.356207762 +0900
@@ -577,12 +577,34 @@
'-net', 'user' + nic_opt,
'-object', 'rng-random,filename=/dev/urandom,id=rng0', '-device',
'virtio-rng-pci,rng=rng0,id=rng-device0',
'-monitor', 'unix:%s/monitor,server,nowait' % workdir,
- '-serial', 'unix:%s/ttyS0,server,nowait' % workdir,
- '-serial', 'unix:%s/ttyS1,server,nowait' % workdir,
'-virtfs',
'local,id=autopkgtest,path=%s,security_model=none,mount_tag=autopkgtest' %
shareddir,
'-drive', 'file=%s,cache=unsafe,if=virtio,index=0,format=qcow2' %
overlay]
+ if 'qemu-system-aarch64' in args.qemu_command or 'qemu-system-arm' in
args.qemu_command or "arm" in os.uname()[4] or "aarch64" == os.uname()[4]:
+ argv.append('-machine')
+ argv.append('virt')
+ argv.append('-cpu')
+ argv.append('max')
+ argv.append('-chardev')
+ argv.append('socket,id=ttyS0,path=%s/ttyS0,server,nowait' % workdir)
+ argv.append('-chardev')
+ argv.append('socket,id=ttyS1,path=%s/ttyS1,server,nowait' % workdir)
+ argv.append('-device')
+ argv.append('pci-serial-2x,chardev1=ttyS0,chardev2=ttyS1')
+ elif 'qemu-system-ppc64' in args.qemu_command:
+ argv.append('-chardev')
+ argv.append('socket,id=ttyS0,path=%s/ttyS0,server,nowait' % workdir)
+ argv.append('-chardev')
+ argv.append('socket,id=ttyS1,path=%s/ttyS1,server,nowait' % workdir)
+ argv.append('-device')
+ argv.append('pci-serial-2x,chardev1=ttyS0,chardev2=ttyS1')
+ else:
+ argv.append('-serial')
+ argv.append('unix:%s/ttyS0,server,nowait' % workdir)
+ argv.append('-serial')
+ argv.append('unix:%s/ttyS1,server,nowait' % workdir)
+
if args.efi:
code = None
data = None
@@ -597,14 +619,18 @@
elif 'qemu-system-arm' in args.qemu_command:
code = '/usr/share/AAVMF/AAVMF32_CODE.fd'
data = '/usr/share/AAVMF/AAVMF32_VARS.fd'
+ elif 'qemu-system-ppc64' in args.qemu_command:
+ code = '/dev/null'
+ data = '/dev/null'
else:
VirtSubproc.bomb('Unknown architecture for EFI boot')
- shutil.copy(data, '%s/efivars.fd' % workdir)
- argv.append('-drive')
- argv.append('if=pflash,format=raw,read-only,file=' + code)
- argv.append('-drive')
- argv.append('if=pflash,format=raw,file=%s/efivars.fd' % workdir)
+ if not 'qemu-system-ppc64' in args.qemu_command:
+ shutil.copy(data, '%s/efivars.fd' % workdir)
+ argv.append('-drive')
+ argv.append('if=pflash,format=raw,read-only,file=' + code)
+ argv.append('-drive')
+ argv.append('if=pflash,format=raw,file=%s/efivars.fd' % workdir)
for i, image in enumerate(args.image[1:]):
# TODO: Ideally we would specify format= for these rather than
autopkgtest [15:54:37]: starting date: 2020-11-20
autopkgtest [15:54:37]: version 5.15
autopkgtest [15:54:37]: host bullseye-gnome; command line: /bin/autopkgtest -B
-u debci bash -- qemu --debug --show-boot --efi -q qemu-system-ppc64le
--timeout-reboot 300 /var/tmp/autopkgtest-sid-ppc64el.qcow2
autopkgtest-virt-qemu: DBG: executing open
autopkgtest-virt-qemu: DBG: execute-timeout: qemu-img info --output=json
/var/tmp/autopkgtest-sid-ppc64el.qcow2
autopkgtest-virt-qemu: DBG: Creating temporary overlay image in
/tmp/autopkgtest-qemu.z8ii9cut/overlay.img
autopkgtest-virt-qemu: DBG: execute-timeout: qemu-img create -f qcow2 -F qcow2
-b /var/tmp/autopkgtest-sid-ppc64el.qcow2
/tmp/autopkgtest-qemu.z8ii9cut/overlay.img
autopkgtest-virt-qemu: DBG: find_free_port: trying 10022
autopkgtest-virt-qemu: DBG: find_free_port: 10022 is free
autopkgtest-virt-qemu: DBG: Forwarding local port 10022 to VM ssh port 22
autopkgtest-virt-qemu: DBG: expect: " login: "
qemu-system-ppc64le: warning: TCG doesn't support requested feature,
cap-cfpc=workaround
qemu-system-ppc64le: warning: TCG doesn't support requested feature,
cap-sbbc=workaround
qemu-system-ppc64le: warning: TCG doesn't support requested feature,
cap-ibs=workaround
qemu-system-ppc64le: warning: TCG doesn't support requested feature,
cap-ccf-assist=on
[ 0.000000] radix-mmu: Page sizes from device-tree:
[ 0.000000] radix-mmu: Page size shift = 12 AP=0x0
[ 0.000000] radix-mmu: Page size shift = 16 AP=0x5
[ 0.000000] radix-mmu: Page size shift = 21 AP=0x1
[ 0.000000] radix-mmu: Page size shift = 30 AP=0x2
[ 0.000000] radix-mmu: Activating Kernel Userspace Execution Prevention
[ 0.000000] radix-mmu: Activating Kernel Userspace Access Prevention
[ 0.000000] radix-mmu: Mapped 0x0000000000000000-0x0000000001400000 with
2.00 MiB pages (exec)
[ 0.000000] radix-mmu: Mapped 0x0000000001400000-0x0000000040000000 with
2.00 MiB pages
[ 0.000000] lpar: Using radix MMU under hypervisor
[ 0.000000] Linux version 5.9.0-3-powerpc64le
(debian-ker...@lists.debian.org) (gcc-10 (Debian 10.2.0-17) 10.2.0, GNU ld (GNU
Binutils for Debian) 2.35.1) #1 SMP Debian 5.9.9-1 (2020-11-19)
[ 0.000000] Found initrd at 0xc000000003800000:0xc0000000050b3ded
[ 0.000000] Using pSeries machine description
[ 0.000000] Partition configured for 1 cpus.
[ 0.000000] CPU maps initialized for 1 thread per core
[ 0.000000] -----------------------------------------------------
[ 0.000000] phys_mem_size = 0x40000000
[ 0.000000] dcache_bsize = 0x80
[ 0.000000] icache_bsize = 0x80
[ 0.000000] cpu_features = 0x0001c06b8f4f91a7
[ 0.000000] possible = 0x000ffbebcf5fb1a7
[ 0.000000] always = 0x00000003800081a1
[ 0.000000] cpu_user_features = 0xdc0065c2 0xaef00000
[ 0.000000] mmu_features = 0xbc007441
[ 0.000000] firmware_features = 0x00000085455a445f
[ 0.000000] vmalloc start = 0xc008000000000000
[ 0.000000] IO start = 0xc00a000000000000
[ 0.000000] vmemmap start = 0xc00c000000000000
[ 0.000000] -----------------------------------------------------
[ 0.000000] numa: NODE_DATA [mem 0x3ff9ef80-0x3ffa3fff]
[ 0.000000] rfi-flush: fallback displacement flush available
[ 0.000000] rfi-flush: ori type flush available
[ 0.000000] rfi-flush: mttrig type flush available
[ 0.000000] count-cache-flush: hardware flush enabled.
[ 0.000000] link-stack-flush: software flush enabled.
[ 0.000000] stf-barrier: eieio barrier available
[ 0.000000] PCI host bridge /pci@800000020000000 ranges:
[ 0.000000] IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000
[ 0.000000] MEM 0x0000200080000000..0x00002000ffffffff ->
0x0000000080000000
[ 0.000000] MEM 0x0000210000000000..0x000021ffffffffff ->
0x0000210000000000
[ 0.000000] PCI: OF: PROBE_ONLY disabled
[ 0.000000] PPC64 nvram contains 65536 bytes
[ 0.000000] barrier-nospec: using ORI speculation barrier
[ 0.000000] Zone ranges:
[ 0.000000] Normal [mem 0x0000000000000000-0x000000003fffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000003fffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000003fffffff]
[ 0.000000] percpu: Embedded 11 pages/cpu s629144 r0 d91752 u720896
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 16368
[ 0.000000] Policy zone: Normal
[ 0.000000] Kernel command line:
BOOT_IMAGE=/boot/vmlinux-5.9.0-3-powerpc64le
root=UUID=3015e31f-732f-43fb-b6d5-7ca5959e1130 ro net.ifnames=0 consoleblank=0
rw console=ttyS0 systemd.unified_cgroup_hierarchy=1
[ 0.000000] Dentry cache hash table entries: 131072 (order: 4, 1048576
bytes, linear)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 3, 524288 bytes,
linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:on, heap free:off
[ 0.000000] Memory: 0K/1048576K available (11968K kernel code, 1728K rwdata,
2688K rodata, 4736K init, 1347K bss, 136128K reserved, 0K cma-reserved)
[ 0.000000] random: get_random_u64 called from
__kmem_cache_create+0x40/0x740 with crng_init=0
[ 0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] ftrace: allocating 28672 entries in 11 pages
[ 0.000000] ftrace: allocated 11 pages with 3 groups
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=1.
[ 0.000000] Rude variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25
jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[ 0.000000] NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
[ 0.000000] xive: Using IRQ range [0-0]
[ 0.000000] xive: Interrupt handling initialized with spapr backend
[ 0.000000] xive: Using priority 6 for all interrupts
[ 0.000000] xive: Using 64kB queues
[ 0.000127] time_init: 56 bit decrementer (max: 7fffffffffffff)
[ 0.000490] clocksource: timebase: mask: 0xffffffffffffffff max_cycles:
0x761537d007, max_idle_ns: 440795202126 ns
[ 0.000717] clocksource: timebase mult[1f40000] shift[24] registered
[ 0.009044] Console: colour dummy device 80x25
[ 0.010994] pid_max: default: 32768 minimum: 301
[ 0.012179] LSM: Security Framework initializing
[ 0.013358] Yama: disabled by default; enable with sysctl kernel.yama.*
[ 0.015908] AppArmor: AppArmor initialized
[ 0.016002] TOMOYO Linux initialized
[ 0.017592] Mount-cache hash table entries: 8192 (order: 0, 65536 bytes,
linear)
[ 0.017683] Mountpoint-cache hash table entries: 8192 (order: 0, 65536
bytes, linear)
[ 0.071065] EEH: pSeries platform initialized
[ 0.071925] POWER9 performance monitor hardware support registered
[ 0.073430] rcu: Hierarchical SRCU implementation.
[ 0.085146] smp: Bringing up secondary CPUs ...
[ 0.085908] smp: Brought up 1 node, 1 CPU
[ 0.086432] numa: Node 0 CPUs: 0
[ 0.086782] Using standard scheduler topology
[ 0.098081] node 0 deferred pages initialised in 0ms
[ 0.118861] devtmpfs: initialized
[ 0.143019] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff,
max_idle_ns: 7645041785100000 ns
[ 0.143190] futex hash table entries: 256 (order: -1, 32768 bytes, linear)
[ 0.157308] NET: Registered protocol family 16
[ 0.163380] audit: initializing netlink subsys (disabled)
[ 0.169844] audit: type=2000 audit(1605855299.148:1): state=initialized
audit_enabled=0 res=1
[ 0.172655] thermal_sys: Registered thermal governor 'fair_share'
[ 0.172745] thermal_sys: Registered thermal governor 'step_wise'
[ 0.173553] cpuidle: using governor ladder
[ 0.173720] cpuidle: using governor menu
[ 0.192473] PCI: Probing PCI hardware
[ 0.196023] PCI host bridge to bus 0000:00
[ 0.196887] pci_bus 0000:00: root bus resource [io 0x10000-0x1ffff] (bus
address [0x0000-0xffff])
[ 0.197097] pci_bus 0000:00: root bus resource [mem
0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff])
[ 0.197138] pci_bus 0000:00: root bus resource [mem
0x210000000000-0x21ffffffffff]
[ 0.197503] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.200599] pci 0000:00:00.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.204783] pci 0000:00:01.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.205314] pci 0000:00:02.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.206096] pci 0000:00:03.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.206956] pci 0000:00:06.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.207672] pci 0000:00:04.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.208202] pci 0000:00:05.0: No hypervisor support for SR-IOV on this
device, IOV BARs disabled.
[ 0.215422] IOMMU table initialized, virtual merging enabled
[ 0.220109] pci 0000:00:04.0: BAR 4: assigned [mem
0x210000004000-0x210000007fff 64bit]
[ 0.220418] pci 0000:00:04.0: BAR 1: assigned [mem
0x200080001000-0x200080001fff]
[ 0.220484] pci 0000:00:04.0: BAR 0: assigned [io 0x10080-0x100bf]
[ 0.220525] pci 0000:00:05.0: BAR 0: assigned [io 0x10000-0x1000f]
[ 0.220780] pci_bus 0000:00: resource 4 [io 0x10000-0x1ffff]
[ 0.220799] pci_bus 0000:00: resource 5 [mem 0x200080000000-0x2000ffffffff]
[ 0.220811] pci_bus 0000:00: resource 6 [mem 0x210000000000-0x21ffffffffff]
[ 0.221236] pci 0000:00:00.0: Adding to iommu group 0
[ 0.223650] pci 0000:00:01.0: Adding to iommu group 0
[ 0.223833] pci 0000:00:02.0: Adding to iommu group 0
[ 0.224091] pci 0000:00:03.0: Adding to iommu group 0
[ 0.224319] pci 0000:00:06.0: Adding to iommu group 0
[ 0.224529] pci 0000:00:04.0: Adding to iommu group 0
[ 0.224680] pci 0000:00:05.0: Adding to iommu group 0
[ 0.224943] EEH: No capable adapters found: recovery disabled.
[ 0.249617] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.249669] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[ 0.953684] iommu: Default domain type: Translated
[ 0.958658] pci 0000:00:01.0: vgaarb: VGA device added:
decodes=io+mem,owns=mem,locks=none
[ 0.958798] pci 0000:00:01.0: vgaarb: bridge control possible
[ 0.958879] pci 0000:00:01.0: vgaarb: setting as boot device (VGA legacy
resources not available)
[ 0.958966] vgaarb: loaded
[ 0.962170] SCSI subsystem initialized
[ 0.973225] NetLabel: Initializing
[ 0.973247] NetLabel: domain hash size = 128
[ 0.973258] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
[ 0.974381] NetLabel: unlabeled traffic allowed by default
[ 0.976060] clocksource: Switched to clocksource timebase
[ 1.098960] VFS: Disk quotas dquot_6.6.0
[ 1.099213] VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes)
[ 1.104134] AppArmor: AppArmor Filesystem Enabled
[ 1.131030] NET: Registered protocol family 2
[ 1.140319] tcp_listen_portaddr_hash hash table entries: 4096 (order: 0,
65536 bytes, linear)
[ 1.140545] TCP established hash table entries: 8192 (order: 0, 65536 bytes,
linear)
[ 1.140823] TCP bind hash table entries: 8192 (order: 1, 131072 bytes,
linear)
[ 1.141048] TCP: Hash tables configured (established 8192 bind 8192)
[ 1.142127] UDP hash table entries: 2048 (order: 0, 65536 bytes, linear)
[ 1.142426] UDP-Lite hash table entries: 2048 (order: 0, 65536 bytes, linear)
[ 1.144587] NET: Registered protocol family 1
[ 1.144943] NET: Registered protocol family 44
[ 1.146439] PCI: CLS 0 bytes, default 128
[ 1.150908] Trying to unpack rootfs image as initramfs...
[ 3.459705] Freeing initrd memory: 25280K
[ 3.475327] Initialise system trusted keyrings
[ 3.477934] Key type blacklist registered
[ 3.479092] workingset: timestamp_bits=38 max_order=14 bucket_order=0
[ 3.490869] zbud: loaded
[ 3.494149] integrity: Platform Keyring initialized
[ 3.494217] Key type asymmetric registered
[ 3.494291] Asymmetric key parser 'x509' registered
[ 3.494490] Block layer SCSI generic (bsg) driver version 0.4 loaded (major
252)
[ 3.495160] io scheduler mq-deadline registered
[ 3.498389] Using unsupported 800x600 (null) at 200081000000, depth=32,
pitch=3200
[ 3.517404] Console: switching to colour frame buffer device 100x37
[ 3.524736] fb0: Open Firmware frame buffer device on
/pci@800000020000000/vga@1
[ 3.530365] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 3.536195] serial 0000:00:05.0: enabling device (0100 -> 0101)
[ 3.541491] printk: console [ttyS0] disabled
[ 3.565225] 0000:00:05.0: ttyS0 at I/O 0x10000 (irq = 20, base_baud =
115200) is a 16550A
[ 3.602101] printk: console [ttyS0] enabled
[ 3.626410] 0000:00:05.0: ttyS1 at I/O 0x10008 (irq = 20, base_baud =
115200) is a 16550A
[ 3.628825] Non-volatile memory driver v1.3
[ 3.629017] Linux agpgart interface v0.103
[ 3.633742] mousedev: PS/2 mouse device common for all mice
[ 3.636218] rtc-generic rtc-generic: registered as rtc0
[ 3.637559] rtc-generic rtc-generic: setting system clock to
2020-11-20T06:55:03 UTC (1605855303)
[ 3.640520] ledtrig-cpu: registered to indicate activity on CPUs
[ 3.642841] NET: Registered protocol family 10
[ 4.110995] Segment Routing with IPv6
[ 4.114479] mip6: Mobile IPv6
[ 4.114824] NET: Registered protocol family 17
[ 4.118580] mpls_gso: MPLS GSO support
[ 4.120600] drmem: No dynamic reconfiguration memory found
[ 4.149851] registered taskstats version 1
[ 4.150209] Loading compiled-in X.509 certificates
[ 4.323124] Loaded X.509 cert 'Debian Secure Boot CA:
6ccece7e4c6c0d1f6149f3dd27dfcc5cbb419ea1'
[ 4.324668] Loaded X.509 cert 'Debian Secure Boot Signer 2020: 00b55eb3b9'
[ 4.328325] zswap: loaded using pool lzo/zbud
[ 4.332420] Key type ._fscrypt registered
[ 4.332546] Key type .fscrypt registered
[ 4.332644] Key type fscrypt-provisioning registered
[ 4.334586] AppArmor: AppArmor sha1 policy hashing enabled
[ 4.421137] Freeing unused kernel memory: 4736K
[ 4.421329] This architecture does not have kernel memory protection.
[ 4.421850] Run /init as init process
Loading, please wait...
Starting version 246.6-4
[ 5.841103] virtio: module verification failed: signature and/or required
key missing - tainting kernel
[ 5.870583] synth uevent: /devices/vio: failed to send uevent
[ 5.871777] vio vio: uevent: failed to send synthetic uevent
[ 5.987080] virtio-pci 0000:00:00.0: enabling device (0100 -> 0103)
[ 6.020102] virtio-pci 0000:00:00.0: ibm,query-pe-dma-windows(2026) 0
8000000 20000000 returned 0
[ 6.021641] virtio-pci 0000:00:00.0: ibm,create-pe-dma-window(2027) 0
8000000 20000000 18 1e returned 0 (liobn = 0x80000001 starting addr = 8000000 0)
[ 6.077371] virtio-pci 0000:00:03.0: enabling device (0100 -> 0103)
[ 6.086674] usbcore: registered new interface driver usbfs
[ 6.087357] usbcore: registered new interface driver hub
[ 6.102341] virtio-pci 0000:00:06.0: enabling device (0100 -> 0103)
[ 6.121193] virtio-pci 0000:00:04.0: enabling device (0100 -> 0103)
[ 6.125430] usbcore: registered new device driver usb
[ 6.281732] xhci_hcd 0000:00:02.0: xHCI Host Controller
[ 6.282675] xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus
number 1
[ 6.326210] xhci_hcd 0000:00:02.0: hcc params 0x00087001 hci version 0x100
quirks 0x0000000000000014
[ 6.390003] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002,
bcdDevice= 5.09
[ 6.390293] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 6.390501] usb usb1: Product: xHCI Host Controller
[ 6.390652] usb usb1: Manufacturer: Linux 5.9.0-3-powerpc64le xhci-hcd
[ 6.390838] usb usb1: SerialNumber: 0000:00:02.0
[ 6.418604] hub 1-0:1.0: USB hub found
[ 6.438269] hub 1-0:1.0: 4 ports detected
[ 6.477602] xhci_hcd 0000:00:02.0: xHCI Host Controller
[ 6.477847] xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus
number 2
[ 6.478157] xhci_hcd 0000:00:02.0: Host supports USB 3.0 SuperSpeed
[ 6.496461] usb usb2: We don't know the algorithms for LPM for this host,
disabling LPM.
[ 6.508479] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003,
bcdDevice= 5.09
[ 6.508806] usb usb2: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 6.509036] usb usb2: Product: xHCI Host Controller
[ 6.509200] usb usb2: Manufacturer: Linux 5.9.0-3-powerpc64le xhci-hcd
[ 6.509402] usb usb2: SerialNumber: 0000:00:02.0
[ 6.523517] hub 2-0:1.0: USB hub found
[ 6.540864] hub 2-0:1.0: 4 ports detected
[ 6.550914] ibmvscsi 71000002: SRP_VERSION: 16.a
[ 6.552091] ibmvscsi 71000002: Maximum ID: 64 Maximum LUN: 32 Maximum
Channel: 3
[ 6.552407] scsi host0: IBM POWER Virtual SCSI Adapter 1.5.9
[ 6.601417] ibmvscsi 71000002: partner initialization complete
[ 6.602332] ibmvscsi 71000002: host srp version: 16.a, host partition qemu
(0), OS 2, max io 2097152
[ 6.602830] ibmvscsi 71000002: sent SRP login
[ 6.603193] ibmvscsi 71000002: SRP_LOGIN succeeded
[ 6.774191] scsi 0:0:2:0: CD-ROM QEMU QEMU CD-ROM 2.5+
PQ: 0 ANSI: 5
[ 6.816472] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 6.997550] usb 1-1: New USB device found, idVendor=0627, idProduct=0001,
bcdDevice= 0.00
[ 6.997851] usb 1-1: New USB device strings: Mfr=1, Product=4,
SerialNumber=11
[ 6.998058] usb 1-1: Product: QEMU USB Keyboard
[ 6.998191] usb 1-1: Manufacturer: QEMU
[ 6.998306] usb 1-1: SerialNumber: 68284-pci@800000020000000:02.0-1
[ 7.171888] usb 1-2: new high-speed USB device number 3 using xhci_hcd
[ 7.261544] virtio_blk virtio2: [vda] 52428800 512-byte logical blocks (26.8
GB/25.0 GiB)
[ 7.261893] vda: detected capacity change from 0 to 26843545600
[ 7.320763] usb 1-2: New USB device found, idVendor=0627, idProduct=0001,
bcdDevice= 0.00
[ 7.321069] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=9
[ 7.321281] usb 1-2: Product: QEMU USB Mouse
[ 7.321429] usb 1-2: Manufacturer: QEMU
[ 7.321545] usb 1-2: SerialNumber: 89126-pci@800000020000000:02.0-2
[ 7.343306] random: fast init done
[ 7.526759] vda: vda1 vda2
[ 7.765052] hid: raw HID events driver (C) Jiri Kosina
[ 7.836278] usbcore: registered new interface driver usbhid
[ 7.836715] usbhid: USB HID core driver
[ 7.992978] input: QEMU QEMU USB Keyboard as
/devices/pci0000:00/0000:00:02.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input0
[ 8.083857] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11
Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:02.0-1/input0
[ 8.086030] input: QEMU QEMU USB Mouse as
/devices/pci0000:00/0000:00:02.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input1
[ 8.097305] hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01
Mouse [QEMU QEMU USB Mouse] on usb-0000:00:02.0-2/input0
[ 8.871135] sr 0:0:2:0: Power-on or device reset occurred
[ 8.874055] sr 0:0:2:0: [sr0] scsi3-mmc drive: 16x/50x cd/rw xa/form2 cdda
tray
[ 8.874431] cdrom: Uniform CD-ROM driver Revision: 3.20
Begin: Loading essential drivers ... done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... [ 9.895819] raid6: vpermxor8
gen() 410 MB/s
[ 9.964406] raid6: vpermxor4 gen() 427 MB/s
[ 10.032140] raid6: vpermxor2 gen() 410 MB/s
[ 10.100152] raid6: vpermxor1 gen() 322 MB/s
[ 10.168184] raid6: altivecx8 gen() 638 MB/s
[ 10.235944] raid6: altivecx4 gen() 644 MB/s
[ 10.304162] raid6: altivecx2 gen() 515 MB/s
[ 10.372880] raid6: altivecx1 gen() 410 MB/s
[ 10.440215] raid6: int64x8 gen() 744 MB/s
[ 10.508052] raid6: int64x8 xor() 547 MB/s
[ 10.575774] raid6: int64x4 gen() 1201 MB/s
[ 10.643789] raid6: int64x4 xor() 624 MB/s
[ 10.711782] raid6: int64x2 gen() 1007 MB/s
[ 10.780045] raid6: int64x2 xor() 647 MB/s
[ 10.848230] raid6: int64x1 gen() 896 MB/s
[ 10.915981] raid6: int64x1 xor() 483 MB/s
[ 10.916221] raid6: using algorithm int64x4 gen() 1201 MB/s
[ 10.916416] raid6: .... xor() 624 MB/s, rmw enabled
[ 10.916674] raid6: using intx1 recovery algorithm
[ 10.931964] xor: measuring software checksum speed
[ 10.971793] 8regs : 1984.000 MB/sec
[ 11.011709] 8regs_prefetch: 1696.000 MB/sec
[ 11.051751] 32regs : 1520.000 MB/sec
[ 11.091764] 32regs_prefetch: 1600.000 MB/sec
[ 11.131804] altivec : 1760.000 MB/sec
[ 11.132078] xor: using function: 8regs (1984.000 MB/sec)
[ 11.330210] Btrfs loaded, crc32c=crc32c-generic
Scanning for Btrfs filesystems
done.
Warning: fsck not present, so skipping root file system
[ 11.946964] EXT4-fs (vda2): mounted filesystem with ordered data mode. Opts:
(null)
done.
Begin: Running /scripts/local-bottom ... done.
Begin: Running /scripts/init-bottom ... done.
[ 12.423311] Not activating Mandatory Access Control as /sbin/tomoyo-init
does not exist.
[ 12.865813] systemd[1]: Inserted module 'autofs4'
[ 12.937794] random: crng init done
[ 12.999505] systemd[1]: systemd 246.6-4 running in system mode. (+PAM +AUDIT
+SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS
+ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2
default-hierarchy=hybrid)
[ 13.003534] systemd[1]: Detected architecture ppc64-le.
Welcome to Debian GNU/Linux bullseye/sid!
[ 13.017297] systemd[1]: Set hostname to <host>.
[ 13.027549] systemd[1]: Initializing machine ID from D-Bus machine ID.
[ 16.997497] systemd[1]: Queued start job for default target Graphical
Interface.
[ 17.058628] systemd[1]: Created slice system-getty.slice.
[ OK ] Created slice system-getty.slice.
[ 17.069141] systemd[1]: Created slice system-modprobe.slice.
[ OK ] Created slice system-modprobe.slice.
[ 17.077110] systemd[1]: Created slice system-serial\x2dgetty.slice.
[ OK ] Created slice system-serial\x2dgetty.slice.
[ 17.083041] systemd[1]: Created slice User and Session Slice.
[ OK ] Created slice User and Session Slice.
[ 17.089826] systemd[1]: Started Dispatch Password Requests to Console
Directory Watch.
[ OK ] Started Dispatch Password …ts to Console Directory Watch.
[ 17.095357] systemd[1]: Started Forward Password Requests to Wall Directory
Watch.
[ OK ] Started Forward Password R…uests to Wall Directory Watch.
[ 17.104729] systemd[1]: Set up automount Arbitrary Executable File Formats
File System Automount Point.
[ OK ] Set up automount Arbitrary…s File System Automount Point.
[ 17.107245] systemd[1]: Reached target Local Encrypted Volumes.
[ OK ] Reached target Local Encrypted Volumes.
[ 17.109344] systemd[1]: Reached target Paths.
[ OK ] Reached target Paths.
[ 17.112155] systemd[1]: Reached target Remote File Systems.
[ OK ] Reached target Remote File Systems.
[ 17.119599] systemd[1]: Reached target Slices.
[ OK ] Reached target Slices.
[ 17.121903] systemd[1]: Reached target Swap.
[ OK ] Reached target Swap.
[ 17.129004] systemd[1]: Listening on fsck to fsckd communication Socket.
[ OK ] Listening on fsck to fsckd communication Socket.
[ 17.133638] systemd[1]: Listening on initctl Compatibility Named Pipe.
[ OK ] Listening on initctl Compatibility Named Pipe.
[ 17.143006] systemd[1]: Listening on Journal Audit Socket.
[ OK ] Listening on Journal Audit Socket.
[ 17.149386] systemd[1]: Listening on Journal Socket (/dev/log).
[ OK ] Listening on Journal Socket (/dev/log).
[ 17.153128] systemd[1]: Listening on Journal Socket.
[ OK ] Listening on Journal Socket.
[ 17.157361] systemd[1]: Listening on Network Service Netlink Socket.
[ OK ] Listening on Network Service Netlink Socket.
[ 17.164970] systemd[1]: Listening on udev Control Socket.
[ OK ] Listening on udev Control Socket.
[ 17.173822] systemd[1]: Listening on udev Kernel Socket.
[ OK ] Listening on udev Kernel Socket.
[ 17.213913] systemd[1]: Mounting Huge Pages File System...
Mounting Huge Pages File System...
[ 17.254165] systemd[1]: Mounting POSIX Message Queue File System...
Mounting POSIX Message Queue File System...
[ 17.317724] systemd[1]: Mounting Kernel Debug File System...
Mounting Kernel Debug File System...
[ 17.406296] systemd[1]: Mounting Kernel Trace File System...
Mounting Kernel Trace File System...
[ 17.512730] systemd[1]: Starting Set the console keyboard layout...
Starting Set the console keyboard layout...
[ 17.606172] systemd[1]: Starting Create list of static device nodes for the
current kernel...
Starting Create list of st…odes for the current kernel...
[ 17.733761] systemd[1]: Starting Load Kernel Module drm...
Starting Load Kernel Module drm...
[ 17.784634] systemd[1]: Condition check resulted in Set Up Additional Binary
Formats being skipped.
[ 17.785568] systemd[1]: Condition check resulted in File System Check on
Root Device being skipped.
[ 18.004660] systemd[1]: Starting Journal Service...
Starting Journal Service...
[ 18.102994] systemd[1]: Starting Load Kernel Modules...
Starting Load Kernel Modules...
[ 18.206929] systemd[1]: Starting Remount Root and Kernel File Systems...
Starting Remount Root and Kernel File Systems...
[ 18.319137] systemd[1]: Starting Coldplug All udev Devices...
Starting Coldplug All udev Devices...
[ 18.622139] systemd[1]: Mounted Huge Pages File System.
[ OK ] Mounted Huge Pages File System.
[ 18.681568] systemd[1]: Mounted POSIX Message Queue File System.
[ OK ] Mounted POSIX Message Queue File System.
[ 18.703549] systemd[1]: Mounted Kernel Debug File System.
[ OK ] Mounted Kernel Debug File System.
[ 18.734327] systemd[1]: Mounted Kernel Trace File System.
[ OK ] Mounted Kernel Trace File System.
[ 18.840911] systemd[1]: Finished Create list of static device nodes for the
current kernel.
[ OK ] Finished Create list of st… nodes for the current kernel.
[ 18.910237] systemd[1]: modprobe@drm.service: Succeeded.
[ 18.954373] systemd[1]: Finished Load Kernel Module drm.
[ OK ] Finished Load Kernel Module drm.
[ 19.257052] systemd[1]: Finished Load Kernel Modules.
[ OK ] Finished Load Kernel Modules.
[ 19.271021] systemd[1]: Condition check resulted in FUSE Control File System
being skipped.
[ 19.291059] systemd[1]: Condition check resulted in Kernel Configuration
File System being skipped.
[ 19.371450] systemd[1]: Starting Apply Kernel Variables...
Starting Apply Kernel Variables...
[ 19.832700] EXT4-fs (vda2): re-mounted. Opts: discard,nobarrier,commit=3600
[ 19.953774] systemd[1]: Finished Remount Root and Kernel File Systems.
[ OK ] Finished Remount Root and Kernel File Systems.
[ 20.016452] systemd[1]: Condition check resulted in Rebuild Hardware
Database being skipped.
[ 20.017619] systemd[1]: Condition check resulted in Platform Persistent
Storage Archival being skipped.
[ 20.091025] systemd[1]: Starting Load/Save Random Seed...
Starting Load/Save Random Seed...
[ 20.203154] systemd[1]: Starting Create System Users...
Starting Create System Users...
[ 20.576341] systemd[1]: Finished Apply Kernel Variables.
[ OK ] Finished Apply Kernel Variables.
[ 21.372558] systemd[1]: Finished Load/Save Random Seed.
[ OK ] Finished Load/Save Random Seed.
[ 22.364507] systemd[1]: Finished Create System Users.
[ OK ] Finished Create System Users.
[ 22.453346] systemd[1]: Starting Create Static Device Nodes in /dev...
Starting Create Static Device Nodes in /dev...
[ 22.890823] synth uevent: /devices/vio: failed to send uevent
[ 22.891044] vio vio: uevent: failed to send synthetic uevent
[ 23.048278] systemd[1]: Finished Coldplug All udev Devices.
[ OK ] Finished Coldplug All udev Devices.
[ 23.170718] systemd[1]: Started Journal Service.
[ OK ] Started Journal Service.
Starting Flush Journal to Persistent Storage...
[ OK ] Finished Create Static Device Nodes in /dev.
Starting Rule-based Manage…for Device Events and Files...
[ OK ] Finished Set the console keyboard layout.
[ OK ] Reached target Local File Systems (Pre).
[ OK ] Reached target Local File Systems.
Starting Set console font and keymap...
[ OK ] Finished Flush Journal to Persistent Storage.
Starting Create Volatile Files and Directories...
[ OK ] Started Rule-based Manager for Device Events and Files.
Starting Network Service...
[ 27.022010] 9pnet: Installing 9P2000 support
[ OK ] Finished Create Volatile Files and Directories.
Starting Network Time Synchronization...
[ 27.671248] fb0: switching to bochsdrmfb from OFfb vga
[ 27.802924] Console: switching to colour dummy device 80x25
[ 27.877213] bochs-drm 0000:00:01.0: vgaarb: deactivate vga console
[ 27.953981] [drm] Found bochs VGA, ID 0xb0c5.
[ 27.954205] [drm] Framebuffer size 16384 kB @ 0x200081000000, mmio @
0x200082000000.
Starting Update UTMP about System Boot/Shutdown...
[ 28.020505] [TTM] Zone kernel: Available graphics memory: 504192 KiB
[ 28.020733] [TTM] Initializing pool allocator
[ 28.021024] [TTM] Initializing DMA pool allocator
[ 28.084925] [drm] Found EDID data blob.
[ 28.186148] [drm] Initialized bochs-drm 1.0.0 20130925 for 0000:00:01.0 on
minor 0
[ OK ] Found device QEMU PCI Dual…dapter (QEMU Virtual Machine).
[ 28.884437] Console: switching to colour frame buffer device 128x48
[ 29.147873] bochs-drm 0000:00:01.0: [drm] fb0: bochs-drmdrmfb frame buffer
device
[ 30.168233] sr 0:0:2:0: Attached scsi generic sg0 type 5
[* ] (1 of 5) A start job is running for…e font and keymap (14s / no limit)
[** ] (1 of 5) A start job is running for…e font and keymap (15s / no limit)
[ OK ] Found device /dev/hvc0.
[ OK ] Finished Update UTMP about System Boot/Shutdown.
[ OK ] Started Network Service.
[ OK ] Reached target Network.
[ OK ] Started Network Time Synchronization.
[ OK ] Reached target System Initialization.
[ OK ] Started Daily Cleanup of Temporary Directories.
[ OK ] Reached target System Time Set.
[ OK ] Reached target System Time Synchronized.
[ OK ] Started Daily apt download activities.
[ OK ] Started Daily apt upgrade and clean activities.
[ OK ] Started Periodic ext4 Onli…ata Check for All Filesystems.
[ OK ] Started Discard unused blocks once a week.
[ OK ] Reached target Timers.
[ OK ] Listening on D-Bus System Message Bus Socket.
[ OK ] Reached target Sockets.
[ OK ] Reached target Basic System.
[ OK ] Started autopkgtest root shell on ttyS1.
[ OK ] Started D-Bus System Message Bus.
Starting Remove Stale Onli…t4 Metadata Check Snapshots...
Starting OpenBSD Secure Shell server...
Starting User Login Management...
Starting Permit User Sessions...
[ OK ] Finished Permit User Sessions.
[ OK ] Started Getty on tty1.
[ OK ] Started Serial Getty on hvc0.
[ OK ] Started Serial Getty on ttyS0.
[ OK ] Reached target Login Prompts.
[ OK ] Started OpenBSD Secure Shell server.
[ OK ] Started User Login Management.
[ OK ] Reached target Multi-User System.
Debian GNU/Linux bullseye/sid host ttyS0
host login: autopkgtest-virt-qemu: DBG: expect: found ""login prompt on ttyS0""
autopkgtest-virt-qemu: DBG: expect: "ok"
autopkgtest-virt-qemu: DBG: expect: found ""b'ok'""
autopkgtest-virt-qemu: DBG: setup_shell(): there already is a shell on ttyS1
autopkgtest-virt-qemu: DBG: expect: "#"
autopkgtest-virt-qemu: DBG: expect: found ""b'#'""
autopkgtest-virt-qemu: DBG: expect: "#"
autopkgtest-virt-qemu: DBG: expect: found ""b'#'""
autopkgtest-virt-qemu: DBG: expect: "# "
autopkgtest-virt-qemu: DBG: expect: found ""b'# '""
autopkgtest-virt-qemu: DBG: Copying host timezone Asia/Tokyo to VM
autopkgtest-virt-qemu: DBG: expect: "#"
autopkgtest-virt-qemu: DBG: expect: found ""b'#'""
autopkgtest-virt-qemu: DBG: expect: "/python"
autopkgtest-virt-qemu: DBG: expect: found ""b'/python'""
autopkgtest-virt-qemu: DBG: expect: "# "
autopkgtest-virt-qemu: DBG: expect: found ""b'# '""
autopkgtest-virt-qemu: DBG: execute-timeout:
/tmp/autopkgtest-qemu.z8ii9cut/runcmd true
autopkgtest-virt-qemu: DBG: can connect to autopkgtest sh in VM
autopkgtest-virt-qemu: DBG: determine_normal_user: no uid in [1000,59999]
available
autopkgtest-virt-qemu: DBG: auxverb =
['/tmp/autopkgtest-qemu.z8ii9cut/runcmd'], downtmp = None
autopkgtest-virt-qemu: DBG: execute-timeout:
/tmp/autopkgtest-qemu.z8ii9cut/runcmd mktemp --directory --tmpdir
autopkgtest.XXXXXX
autopkgtest-virt-qemu: DBG: execute-timeout:
/tmp/autopkgtest-qemu.z8ii9cut/runcmd chmod 1777 /tmp/autopkgtest.JMOBGB
autopkgtest-virt-qemu: DBG: cleanup...
qemu-system-ppc64le: terminating on signal 15 from pid 588219 (/usr/bin/python3)
autopkgtest [15:56:05]: ERROR: testbed failure: cannot send to testbed: I/O
operation on closed file.
