14181 2021-01-11 11:44:32 +0000 Failure to unpickle during testimage 2021-02-09 11:20:03 +0000 1 1 7 Build System, Metadata & Runtime BitBake bitbake 3.3 x86 Multiple RESOLVED FIXED https://autobuilder.yoctoproject.org/typhoon/#/builders/101/builds/1800 AB-INT Medium+ normal 3.3 M3 1 ross.burton richard.purdie alexandre.belloni jon.mason poky.bs.watcher poky.watcher randy.macleod --- --- No (bug/feature does not impact docs) oldest_to_newest 88902 0 ross.burton 2021-01-11 11:44:32 +0000 During testimage, an unpickle fails: ERROR: failed load pickle ''utf-8' codec can't decode byte 0x80 in position 570: invalid start byte': 'b'\x80\x03clogging\nLogRecord\nq\x00)\x81q\x01}q\x02(X\x04\x00\x00\x00nameq\x03X\x07\x00\x00\x00BitBakeq\x04X\x03\x00\x00\x00msgq\x05X\x1c\x10\x00\x00Partial data from SSH call: ted\n[ 2.979538] hdc: host max PIO4 wanted PIO255(auto-tune) selected PIO0\n[ 2.329926] hdc: QEMU DVD-ROM, ATAPI CD/DVD-ROM drive\n[ 1.642474] Probing IDE interface ide1...\n[ 1.103041] Probing IDE interface ide0...\n[ 1.103041] ide1: BM-DMA at 0xc0e8-0xc0ef\n[ 1.102581] ide0: BM-DMA at 0xc0e0-0xc0e7\n[ 1.098314] Report any missing HW support to linux-ide@vger.kernel.org\n[ 1.098314] legacy IDE will be removed in 2021, please switch to libata\nStarting Connection service...\n[ 1.098314] piix 0000:00:01.1:<event>\x80\x03clogging\nLogRecord\nq\x00)\x81q\x01}q\x02(X\x04\x00\x00\x00nameq\x03X\x07\x00\x00\x00BitBakeq\x04X\x03\x00\x00\x00msgq\x05X4\x00\x00\x00time: 1610164805.497182, endtime: 1610165105.4971802q\x06X\x04\x00\x00\x00argsq\x07)X\t\x00\x00\x00levelnameq\x08X\x05\x00\x00\x00DEBUGq\tX\x07\x00\x00\x00levelnoq\nK\nX\x08\x00\x00\x00pathnameq\x0bXN\x00\x00\x00/home/pokybuild/yocto-worker/qemux86-alt/build/meta/lib/oeqa/utils/__init__.pyq\x0cX\x08\x00\x00\x00filenameq\rX\x0b\x00\x00\x00__init__.pyq\x0eX\x06\x00\x00\x00moduleq\x0fX\x08\x00\x00\x00__init__q\x10X\x08\x00\x00\x00exc_infoq\x11NX\x08\x00\x00\x00exc_textq\x12NX\n\x00\x00\x00stack_infoq\x13NX\x06\x00\x00\x00linenoq\x14K>X\x08\x00\x00\x00funcNameq\x15X\x12\x00\x00\x00_bitbake_log_debugq\x16X\x07\x00\x00\x00createdq\x17GA\xd7\xfeJ\x91_\xd2?X\x05\x00\x00\x00msecsq\x18G@\x7f\x13Q\x86\x00\x00\x00X\x0f\x00\x00\x00relativeCreatedq\x19G@\xfe\xcd~\xd4 \x00\x00X\x06\x00\x00\x00threadq\x1a\x8a\x06\x80\xdb\x08\xf1"\x7fX\n\x00\x00\x00threadNameq\x1bX\n\x00\x00\x00MainThreadq\x1cX\x0b\x00\x00\x00processNameq\x1dX\x0b\x00\x00\x00MainProcessq\x1eX\x07\x00\x00\x00processq\x1fMv\xb8X\x07\x00\x00\x00taskpidq Mv\xb8ub.</event><event>\x80\x03clogging\nLogRecord\nq\x00)\x81q\x01}q\x02(X\x04\x00\x00\x00nameq\x03X\x07\x00\x00\x00BitBakeq\x04X\x03\x00\x00\x00msgq\x05X\x1c\x10\x00\x00Partial data from SSH call: cheduler mq-deadline registered\n[ 0.831482] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)\n[ 0.830446] Asymmetric key parser \'x509\' registered\n[ 0.829490] Key type asymmetric registered\n[ 0.823596] Key type cifs.idmap registered\n[ 0.822608] Key type id_legacy registered\n[ 0.821258] Key type id_resolver registered\n[ 0.820189] NFS: Registering the id_resolver key type\n[ 0.812456] workingset: timestamp_bits=14 max_order=17 bucket_order=3\n[ 0.812456] Initialise system trusted keyrings\n[ 0.812456] check: Scanning for low memory corruption every 60 seconds\n[ 0.812456] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x257a34a6eea, max_idle_ns: 440795264358 ns\n[ 0.811501] PCI: CLS 0 bytes, default 64\n[ 0.809879] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]\n[ 0.797548] pci 0000:00:01.2: quirk_usb_early_handoff+0x0/0x661 took 53224 usecs\n[ 0.770849] PCI: setting IRQ 11 as level-triggered\n[ 0.769040] PCI Interrupt Link [LNKD] enabled at IRQ 11\n[ 0.741380] pci 0000:00:01.0: Activating ISA DMA hang workarounds\n[ 0.740407] pci 0000:00:00.0: Limiting direct PCI/PCI transfers\n[ 0.739173] pci 0000:00:01.0: PIIX3: Enabling Passive Release\n[ 0.737773] RPC: Registered tcp NFSv4.1 backchannel transport module.\n[ 0.734905] RPC: Registered tcp transport module.\n[ 0.729980] RPC: Registered udp transport module.\n[ 0.729980] RPC: Registered named UNIX socket transport module.\n[ 0.729980] NET: Registered protocol family 1\n[ 0.729980] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)\n[ 0.729040] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)\n[ 0.727756] TCP: Hash tables configured (established 4096 bind 4096)\n[ 0.726382] TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear)\n[ 0.724801] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)\n[ 0.719021] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)\n[ 0.719021] NET: Registered protocol family 2\n[ 0.719021] pci_bus 0000:00: resource 7 [mem 0x20000000-0xfebfffff window]\n[ 0.719021] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]\n[ 0.718032] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]\n[ 0.716811] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]\n[ 0.713726] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns\n[ 0.677062] thermal_sys: Registered thermal governor \'user_space\'\n[ 0.677062] thermal_sys: Registered thermal governor \'step_wise\'\n[ 0.670743] pnp: PnP ACPI: found 7 devices\n[ 0.670519] pnp 00:06: Plug and Play ACPI device, IDs PNP0b00 (active)\n[ 0.670501] pnp 00:05: Plug and Play ACPI device, IDs PNP0501 (active)\n[ 0.670485] pnp 00:04: Plug and Play ACPI device, IDs PNP0501 (active)\n[ 0.670465] pnp 00:03: Plug and Play ACPI device, IDs PNP0400 (active)\n[ 0.670445] pnp 00:02: Plug and Play ACPI device, IDs PNP0700 (active)\n[ 0.670428] pnp 00:02: [dma 2]\n[ 0.670416] pnp 00:01: Plug and Play ACPI device, IDs PNP0f13 (active)\n[ 0.670389] pnp 00:00: Plug and Play ACPI device, IDs PNP0303 (active)\n[ 0.657130] pnp: PnP ACPI init\n[ 0.565762] random: fast init done\n[ 0.528728] clocksource: Switched to clocksource kvm-clock\n[ 0.528728] Bluetooth: SCO socket layer initialized\n[ 0.528728] Bluetooth: L2CAP socket layer initialized\n[ 0.527747] Bluetooth: HCI socket layer initialized\n[ 0.525733] Bluetooth: HCI device and connection manager initialized\n[ 0.525544] NET: Registered protocol family 31\n[ 0.524750] Bluetooth: Core ver 2.22\n[ 0.523909] e820: reserve RAM buffer [mem 0x1ffdb000-0x1fffffff]\n[ 0.523903] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]\n[ 0.523741] PCI: pci_cache_line_size set to 64 bytes\n[ 0.522925] PCI: Using ACPI for IRQ routing\n[ 0.521728] PTP clock support registered\n[ 0.521728] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>\n[ 0.521728] pps_coq\x06X\x04\x00\x00\x00argsq\x07)X\t\x00\x00\x00levelnameq\x08X\x05\x00\x00\x00DEBUGq\tX\x07\x00\x00\x00levelnoq\nK\nX\x08\x00\x00\x00pathnameq\x0bXN\x00\x00\x00/home/pokybuild/yocto-worker/qemux86-alt/build/meta/lib/oeqa/utils/__init__.pyq\x0cX\x08\x00\x00\x00filenameq\rX\x0b\x00\x00\x00__init__.pyq\x0eX\x06\x00\x00\x00moduleq\x0fX\x08\x00\x00\x00__init__q\x10X\x08\x00\x00\x00exc_infoq\x11NX\x08\x00\x00\x00exc_textq\x12NX\n\x00\x00\x00stack_infoq\x13NX\x06\x00\x00\x00linenoq\x14K>X\x08\x00\x00\x00funcNameq\x15X\x12\x00\x00\x00_bitbake_log_debugq\x16X\x07\x00\x00\x00createdq\x17GA\xd7\xfeJ\x91_\xd4\xefX\x05\x00\x00\x00msecsq\x18G@\x7f\x15\xf1f\x00\x00\x00X\x0f\x00\x00\x00relativeCreatedq\x19G@\xfe\xcd\x81t\x00\x00\x00X\x06\x00\x00\x00threadq\x1a\x8a\x06\x80\xdb\x08\xf1"\x7fX\n\x00\x00\x00threadNameq\x1bX\n\x00\x00\x00MainThreadq\x1cX\x0b\x00\x00\x00processNameq\x1dX\x0b\x00\x00\x00MainProcessq\x1eX\x07\x00\x00\x00processq\x1fMv\xb8X\x07\x00\x00\x00taskpidq Mv\xb8ub.'' 88919 1 richard.purdie 2021-01-13 23:49:37 +0000 It looks like kernel dmesg logs containing "<event>" which is a magic string in the event piping within bitbake might be corrupting the IPC. 89087 2 alexandre.belloni 2021-01-29 16:47:18 +0000 Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/101/builds/1882/steps/13 89095 3 jon.mason 2021-01-30 18:02:44 +0000 Seeing the issue in https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1574 89181 4 richard.purdie 2021-02-09 11:20:03 +0000 http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=2ffbb020fe1d9f332fdc58cd93d7a41885850771