Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Revert gpg version bump and unify key to card code to properly create bug upstream #1677

Merged
merged 1 commit into from
May 17, 2024

Conversation

tlaurion
Copy link
Collaborator

@tlaurion tlaurion commented May 14, 2024

There is a spotted regression with gpg toolstack 2.4.2+ as merged per #1661. This reverts the gpg tool stack (gnupg and deps) back to what it was before #1661, and adds proper calls for future debugging (enabled by default under qemu boards with canokey virt smartcard usable and provisioned at make run call).

This is BUGFIX and should be merged fast. (gnupg toolstack version bump 2.4.0 -> 2.4.2 broken key to card ops required to enable Authenticated Heads optional feature on re-ownership).


  • Unified p256 algo calls with RSA ones for key in memory and key to card.
  • switched to flake.nix to qemu_full instead of qemu_kvm and qemu with canokey support
    • required to bump flake.lock otherwise was not building (will bump again since Nix decided to include canokey support by default in their qemu_full derivative so nix develop won't have to build it in the future, it's gonna be cached)
  • added gpg requirement in flake.nix to be able to fully use qemu to test this PR. Thsi is awesome, without need of USB Security dongle but to sign commits.
  • Updated README.md with better instructions as I went along.

@tlaurion tlaurion self-assigned this May 14, 2024
@tlaurion tlaurion added the bug label May 14, 2024
@tlaurion tlaurion marked this pull request as draft May 14, 2024 17:06
@tlaurion
Copy link
Collaborator Author

tlaurion commented May 14, 2024

It's going to take more time then I thought, since this is the first full development cycle over nix and calling qemu targets requires qemu-img tools and other stuff that are not availble under nix as current v0.1.6/latest docker image. Building the whole qemu-full requires rebuilding python and a lot of other stuff, just like I tried to build diffoscope and stopped in the middle of it. since we rebuild qemu to have canokey enabled. For diffoscope, no clue why the image was so big so I'll try diffoscopeMinimal derivative here. That will probably be continued tomorrow once the image is ready to jump in, the building will take at least an hour if not more.

Rebuilding docker image 0.1.7 with qemu-full instead of qemu and qemu_kvm as I thought would be needed but didn't want to bake the docker image too big, but it is needed otherwise the docker image is not self-contained

heads/flake.nix

Lines 71 to 80 in c91731c

] ++ [
# Below are overrides to make canokey-qemu library available to qemu built derivative through a qemu override, which qemu is used for other derivatives
canokey-qemu # Canokey lib for qemu build-time compilation.
(qemu.override {
canokeySupport = true; # This override enables Canokey support in QEMU, resulting in -device canokey being available.
})
# Packages for qemu support with Canokey integration from previous override
#qemu_full #Heavier but contains qemu-img, kvm and everything else needed to do development cycles under docker
qemu # To test make BOARD=qemu-coreboot-* boards and then call make BOARD=qemu-coreboot-* with inject_gpg statement, and then run statement.
qemu_kvm # kvm additional support for qemu without all the qemu-img and everything else under qemu_full

I will use qemu to troubleshoot this because testing on real hardware this sort of thing is really messy, where qemu over two consoles is ideal and I will use this pull request and issue to detail how to resolve such things where debug traces are available, useful and easy to share properly.

Bonus, troubleshooting those OpenPGP card and dev cycles requires to test gpg toolstack will be able to use canokey under qemu, which I will use because doing those over qemu on top of qubesos is really a pain with usb device pass-through not being totally exclusive and host and qemu competing for exclusive access.

@tlaurion
Copy link
Collaborator Author

tlaurion commented May 14, 2024

ceph> [  6%] Linking CXX static library ../../lib/libcls_lock_client.a
ceph> [  6%] Built target cls_lock_client
ceph> [  6%] Building CXX object src/erasure-code/shec/CMakeFiles/shec_utils.dir/ErasureCodePluginShec.cc.o
ceph> [  6%] Building C object src/erasure-code/jerasure/CMakeFiles/gf-complete_objs.dir/gf-complete/src/gf_rand.c.o
ceph> [  6%] Building C object src/erasure-code/jerasure/CMakeFiles/gf-complete_objs.dir/gf-complete/src/gf_w8.c.o
ceph> In function 'gf_w8_table_init',
ceph>     inlined from 'gf_w8_init' at /build/ceph-18.2.1/src/erasure-code/jerasure/gf-complete/src/gf_w8.c:2321:36:
ceph> /build/ceph-18.2.1/src/erasure-code/jerasure/gf-complete/src/gf_w8.c:1176:7: warning: 'scase' may be used uninitialized [8;;https://gcc.gnu.org/onlinedocs/gcc/Warning-Options.html#index-Wmaybe-uninitialized-Wmaybe-uninitialized8;;]
ceph>  1176 |       switch (scase) {
ceph>       |       ^~~~~~
ceph> /build/ceph-18.2.1/src/erasure-code/jerasure/gf-complete/src/gf_w8.c: In function 'gf_w8_init':
ceph> /build/ceph-18.2.1/src/erasure-code/jerasure/gf-complete/src/gf_w8.c:1140:22: note: 'scase' was declared here
ceph>  1140 |   int a, b, c, prod, scase;
ceph>       |                      ^~~~~
ceph> [  6%] Built target gf-complete_objs
ceph> [  6%] Building CXX object src/global/CMakeFiles/libglobal_objs.dir/global_init.cc.o
ceph> [  6%] Built target erasure_code_objs
ceph> [  6%] Building CXX object src/common/options/CMakeFiles/common-options-objs.dir/ceph-exporter_options.cc.o
ceph> [  6%] Building CXX object src/common/options/CMakeFiles/common-options-objs.dir/rgw_options.cc.o
ceph> [  6%] Built target jerasure_objs
ceph> [  6%] Building CXX object src/perfglue/CMakeFiles/heap_profiler.dir/disabled_heap_profiler.cc.o
ceph> [  6%] Building CXX object src/common/CMakeFiles/common_prioritycache_obj.dir/PriorityCache.cc.o
ceph> [  6%] Built target jerasure_utils
ceph> [  6%] Building CXX object src/global/CMakeFiles/libglobal_objs.dir/pidfile.cc.o
ceph> [  7%] Building CXX object src/global/CMakeFiles/libglobal_objs.dir/signal_handler.cc.o
ceph> [  8%] Building CXX object src/mgr/CMakeFiles/mgr_cap_obj.dir/MgrCap.cc.o
ceph> [  8%] Building CXX object src/erasure-code/shec/CMakeFiles/shec_utils.dir/ErasureCodeShec.cc.o
ceph> [  8%] Building CXX object src/erasure-code/shec/CMakeFiles/shec_utils.dir/ErasureCodeShecTableCache.cc.o
ceph> [  8%] Building C object src/erasure-code/shec/CMakeFiles/shec_utils.dir/determinant.c.o
ceph> [  8%] Linking CXX static library ../../lib/libheap_profiler.a
ceph> [  8%] Built target heap_profiler
ceph> [  8%] Building CXX object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isal_crypto_accel.cc.o
ceph> [  8%] Building CXX object src/crypto/openssl/CMakeFiles/ceph_crypto_openssl.dir/openssl_crypto_accel.cc.o
ceph> [  8%] generating /build/ceph-18.2.1/build/include/tracing/bluestore.h
ceph> [  8%] Built target bluestore-tp
ceph> [  8%] Building CXX object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isal_crypto_plugin.cc.o
ceph> [  8%] Building C object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_pre.c.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_multibinary.asm.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/keyexp_128.asm.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/keyexp_192.asm.o
ceph> [  8%] generating /build/ceph-18.2.1/build/include/tracing/objectstore.h
ceph> [  8%] Built target objectstore-tp
ceph> [  8%] Building CXX object src/crypto/openssl/CMakeFiles/ceph_crypto_openssl.dir/openssl_crypto_plugin.cc.o
ceph> g++: fatal error: Killed signal terminated program cc1plus
ceph> compilation terminated.
ceph> make[2]: *** [src/msg/CMakeFiles/common-msg-objs.dir/build.make:90: src/msg/CMakeFiles/common-msg-objs.dir/Message.cc.o] Error 1
ceph> make[1]: *** [CMakeFiles/Makefile2:2910: src/msg/CMakeFiles/common-msg-objs.dir/all] Error 2
ceph> make[1]: *** Waiting for unfinished jobs....
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/keyexp_256.asm.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/keyexp_multibinary.asm.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_dec_128_x4_sse.asm.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_dec_128_x8_avx.asm.o
ceph> [  8%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_dec_192_x4_sse.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_dec_192_x8_avx.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_dec_256_x4_sse.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_dec_256_x8_avx.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_enc_128_x4_sb.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_enc_128_x8_sb.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_enc_192_x4_sb.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_enc_192_x8_sb.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_enc_256_x4_sb.asm.o
ceph> [  9%] Building ASM object src/crypto/isa-l/CMakeFiles/ceph_crypto_isal.dir/isa-l_crypto/aes/cbc_enc_256_x8_sb.asm.o
ceph> [  9%] Built target common_prioritycache_obj
ceph> [  9%] Built target libglobal_objs
ceph> [  9%] Built target common-options-objs
ceph> [  9%] Built target shec_utils
ceph> [  9%] Linking CXX shared library ../../../lib/libceph_crypto_isal.so
ceph> [  9%] Built target ceph_crypto_isal
ceph> [  9%] Linking CXX shared library ../../../lib/libceph_crypto_openssl.so
ceph> [  9%] Built target ceph_crypto_openssl
ceph> [  9%] Built target mgr_cap_obj
ceph> make: *** [Makefile:146: all] Error 2
error: builder for '/nix/store/gxpjmqm57sqlfgzx2nrlkwbb5bbyxahb-ceph-18.2.1.drv' failed with exit code 2
error: 1 dependencies of derivation '/nix/store/8hgd99r54la7hbwzqlflw5i3xnprc1iy-qemu-8.2.2.drv' failed to build
error: 1 dependencies of derivation '/nix/store/757id018h7mlvv6iqjlxdmqpihlsbph4-nix-shell-env.drv' failed to build

Updating flake.lock pkg pinned with
nix update flakes
and redoing.

@tlaurion
Copy link
Collaborator Author

tlaurion commented May 14, 2024

Don't try to use this yet, no updated docker image was created successfully yet, this is what i'm trying to do, push the docker image and then switch circleci config to use it and if successfull, push docker image to docker hub with latest tag when successful and docker image fully usable to do proper dev cycles.

I won't use my debian-11, debian-12 dev environements from now on and I want to have a working dev env for everyone to test in qemu/kvm, including myself first.

@tlaurion
Copy link
Collaborator Author

tlaurion commented May 14, 2024

Build successful. Creating docker image and pushing

Nix team considering having canokey support by default under qemu_full (Discussion at https://matrix.to/#/!pAlHOfxQNPXOgFGTmo:matrix.org/$jWIgolUhkWfkvKxZPXLn_humw1qkesaqkZl5oX2Uufs?via=matrix.org&via=nitro.chat&via=fairydust.space)

@tlaurion tlaurion force-pushed the fix_key_to_card branch 2 times, most recently from ec9a3cb to a2f9bb2 Compare May 15, 2024 16:02
@tlaurion
Copy link
Collaborator Author

Bon.

We have reproducible environment. I use whiptail for testing debugging and just saw discrepencies that fell out of my checks because of that between fbwhiptail HEIGHT 0 being respected by whiptail (dynamic) vs fbwhiptail. Outside of that fact

docker run -e DISPLAY=$DISPLAY --network host --rm -ti -v $(pwd):$(pwd) -w $(pwd) tlaurion/heads-dev-env:v0.1.8 -- make BOARD=qemu-coreboot-whiptail-tpm2 PUBKEY_ASC=A64D3AC489E7F6B6A907AA15239755A5458CBD47.asc run
----------------------------------------------------------------------
!!!!!! BUILD SYSTEM INFO !!!!!!
System CPUS: 12
System Available Memory: 10246 GB
System Load Average: 3.60
----------------------------------------------------------------------
Used **CPUS**: 12
Used **LOADAVG**: 18
Used **AVAILABLE_MEM_GB**: 10245 GB
----------------------------------------------------------------------
**MAKE_JOBS**: -j12 --load-average=18 

Variables available for override (use 'make VAR_NAME=value'):
**CPUS** (default: number of processors, e.g., 'make CPUS=4')
**LOADAVG** (default: 1.5 times CPUS, e.g., 'make LOADAVG=54')
**AVAILABLE_MEM_GB** (default: memory available on the system in GB, e.g., 'make AVAILABLE_MEM_GB=4')
**MEM_PER_JOB_GB** (default: 1GB per job, e.g., 'make MEM_PER_JOB_GB=2')
----------------------------------------------------------------------
!!!!!! Build starts !!!!!!
swtpm socket \
	--tpm2 \
	--tpmstate dir="/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/vtpm" \
	--flags "startup-clear" \
	--terminate \
	--ctrl type=unixio,path="/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/vtpm/sock" &
sleep 0.5
qemu-system-x86_64 -drive file="/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/root.qcow2",if=virtio \
	--machine q35,accel=kvm:tcg \
	-rtc base=utc \
	-smp 1 \
	-vga std \
	-m "$(cat "/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/memory")" \
	-serial stdio \
	--bios "/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/heads-qemu-coreboot-whiptail-tpm2-v0.2.0-2154-ga2f9bb2-gpg-injected.rom" \
	-object rng-random,filename=/dev/urandom,id=rng0 \
	-device virtio-rng-pci,rng=rng0 \
	-netdev user,id=u1 -device e1000,netdev=u1 \
	-chardev socket,id=chrtpm,path="/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/vtpm/sock" \
	-tpmdev emulator,id=tpm0,chardev=chrtpm \
	-device tpm-tis,tpmdev=tpm0 \
	-device qemu-xhci,id=usb \
	-device usb-tablet \
	-drive file="/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/usb_fd.raw",if=none,id=usb-fd-drive,format=raw \
	-device usb-storage,bus=usb.0,drive=usb-fd-drive \
	-usb -device canokey,file=/home/user/heads/build/x86/qemu-coreboot-whiptail-tpm2/.canokey-file \

qemu-system-x86_64: Gdk: gdk_atom_intern: assertion 'atom_name != NULL' failed
qemu-system-x86_64: Gdk: gdk_atom_intern: assertion 'atom_name != NULL' failed
qemu-system-x86_64: warning: dbind: Couldn't connect to accessibility bus: Failed to connect to socket /run/user/1000/at-spi/bus_0: No such file or directory
Could not access KVM kernel module: No such file or directory
qemu-system-x86_64: failed to initialize kvm: No such file or directory
qemu-system-x86_64: falling back to tcg
Fontconfig error: Cannot load default config file: No such file: (null)
Fontconfig error: No writable cache directories
Fontconfig error: No writable cache directories
Fontconfig error: No writable cache directories
Fontconfig error: No writable cache directories
[    0.000000] Linux version 5.10.5-Heads (linux-qemu.config@linuxboot) (x86_64-linux-musl-gcc (GCC) 8.3.0, GNU ld (GNU Binutils) 2.32) #0 SMP 1970-00-00
[    0.000000] Command line: debug console=ttyS0,115200 console=tty
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000] x86/fpu: x87 FPU will use FXSAVE
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x0000000000000fff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000001000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000000a0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007ff41fff] usable
[    0.000000] BIOS-e820: [mem 0x000000007ff42000-0x000000007fffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fed40000-0x00000000fed44fff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000027fffffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 3.0 present.
[    0.000000] DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS Heads-v0.2.0-2154-gec9a3cb-dirty 01/01/1970
[    0.000000] tsc: Fast TSC calibration using PIT
[    0.000000] tsc: Detected 2495.963 MHz processor
[    0.001000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.001151] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.001422] last_pfn = 0x280000 max_arch_pfn = 0x400000000
[    0.002285] MTRR default type: uncachable
[    0.002384] MTRR fixed ranges disabled:
[    0.002614]   00000-FFFFF uncachable
[    0.002653] MTRR variable ranges enabled:
[    0.002794]   0 base 00FF000000 mask FFFF000000 write-protect
[    0.002825]   1 disabled
[    0.002839]   2 disabled
[    0.002845]   3 disabled
[    0.002851]   4 disabled
[    0.002856]   5 disabled
[    0.002862]   6 disabled
[    0.002867]   7 disabled
[    0.003214] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
[    0.003696] CPU MTRRs all blank - virtualized system.
[    0.003783] last_pfn = 0x7ff42 max_arch_pfn = 0x400000000
[    0.010471] RAMDISK: [mem 0x04000000-0x045defff]
[    0.011441] ACPI: Early table checksum verification disabled
[    0.011848] ACPI: RSDP 0x000000007FF4A000 000024 (v02       )
[    0.012113] ACPI: XSDT 0x000000007FF7A040 00005C (v01 COREv4 COREBOOT 00000000 CORE 20230628)
[    0.012787] ACPI: FACP 0x000000007FF5C423 0000F4 (v03 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.013752] ACPI: DSDT 0x000000007FF5A080 0023A3 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.013920] ACPI: FACS 0x000000007FF5A040 000040
[    0.014007] ACPI: APIC 0x000000007FF5C517 000078 (v03 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.014046] ACPI: HPET 0x000000007FF5C58F 000038 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.014081] ACPI: TPM2 0x000000007FF5C5C7 00004C (v04 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.014114] ACPI: MCFG 0x000000007FF5C613 00003C (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.014146] ACPI: WAET 0x000000007FF5C64F 000028 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.014177] ACPI: SSDT 0x000000007FF7A170 00038D (v02 COREv4 COREBOOT 0000002A CORE 20230628)
[    0.014886] ACPI: Local APIC address 0xfee00000
[    0.017262] Zone ranges:
[    0.017362]   DMA32    [mem 0x0000000000001000-0x00000000ffffffff]
[    0.017445]   Normal   [mem 0x0000000100000000-0x000000027fffffff]
[    0.017477] Movable zone start for each node
[    0.017537] Early memory node ranges
[    0.017592]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.017640]   node   0: [mem 0x0000000000100000-0x000000007ff41fff]
[    0.017656]   node   0: [mem 0x0000000100000000-0x000000027fffffff]
[    0.018412] Zeroed struct page in unavailable ranges: 287 pages
[    0.018550] Initmem setup node 0 [mem 0x0000000000001000-0x000000027fffffff]
[    0.018817] On node 0 totalpages: 2096865
[    0.018924]   DMA32 zone: 8188 pages used for memmap
[    0.018951]   DMA32 zone: 22 pages reserved
[    0.019014]   DMA32 zone: 524001 pages, LIFO batch:63
[    0.050894]   Normal zone: 24576 pages used for memmap
[    0.050927]   Normal zone: 1572864 pages, LIFO batch:63
[    0.137474] ACPI: PM-Timer IO Port: 0x608
[    0.137525] ACPI: Local APIC address 0xfee00000
[    0.138007] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.138758] IOAPIC[0]: apic_id 0, version 32, address 0xfec00000, GSI 0-23
[    0.138982] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.139451] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.139502] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.139597] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.139609] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.139724] ACPI: IRQ0 used by override.
[    0.139787] ACPI: IRQ5 used by override.
[    0.139796] ACPI: IRQ9 used by override.
[    0.139802] ACPI: IRQ10 used by override.
[    0.139808] ACPI: IRQ11 used by override.
[    0.139866] Using ACPI (MADT) for SMP configuration information
[    0.139913] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.140195] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.140949] [mem 0xc0000000-0xfed3ffff] available for PCI devices
[    0.141459] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
[    0.149255] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:1 nr_node_ids:1
[    0.155639] percpu: Embedded 43 pages/cpu s137368 r8192 d30568 u2097152
[    0.156180] pcpu-alloc: s137368 r8192 d30568 u2097152 alloc=1*2097152
[    0.156352] pcpu-alloc: [0] 0 
[    0.158615] Built 1 zonelists, mobility grouping on.  Total pages: 2064079
[    0.158849] Kernel command line: debug console=ttyS0,115200 console=tty
[    0.174289] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[    0.180701] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.181875] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.432362] Memory: 8153132K/8387460K available (8194K kernel code, 1465K rwdata, 1948K rodata, 932K init, 2084K bss, 234072K reserved, 0K cma-reserved)
[    0.436369] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.442436] rcu: Hierarchical RCU implementation.
[    0.442501] rcu: 	RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=1.
[    0.442759] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.442801] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.443530] NR_IRQS: 4352, nr_irqs: 256, preallocated irqs: 16
[    0.454534] random: get_random_bytes called from start_kernel+0x301/0x4e3 with crng_init=0
[    0.457723] Console: colour dummy device 80x25
[    0.460410] printk: console [tty0] enabled
[    0.485777] printk: console [ttyS0] enabled
[    0.486498] ACPI: Core revision 20200925
[    0.490007] ACPI BIOS Warning (bug): Incorrect checksum in table [SSDT] - 0x05, should be 0xE7 (20200925/tbprint-177)
[    0.495513] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.500157] APIC: Switch to symmetric I/O mode setup
[    0.505378] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=0 pin2=0
[    0.525645] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x23fa5418e03, max_idle_ns: 440795269834 ns
[    0.528090] Calibrating delay loop (skipped), value calculated using timer frequency.. 4991.92 BogoMIPS (lpj=9983852)
[    0.532006] pid_max: default: 4096 minimum: 301
[    0.533693] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.534230] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.555235] process: using AMD E400 aware idle routine
[    0.555639] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
[    0.555909] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
[    0.556490] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.557295] Spectre V2 : Mitigation: Full AMD retpoline
[    0.557598] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.602613] Freeing SMP alternatives memory: 12K
[    0.722065] smpboot: CPU0: AMD QEMU Virtual CPU version 2.5+ (family: 0xf, model: 0x6b, stepping: 0x1)
[    0.725106] Performance Events: PMU not available due to virtualization, using software events only.
[    0.726995] rcu: Hierarchical SRCU implementation.
[    0.729989] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.733662] smp: Bringing up secondary CPUs ...
[    0.733952] smp: Brought up 1 node, 1 CPU
[    0.734269] smpboot: Max logical packages: 1
[    0.734622] smpboot: Total of 1 processors activated (4991.92 BogoMIPS)
[    0.746739] devtmpfs: initialized
[    0.752145] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.753562] futex hash table entries: 16 (order: -2, 1024 bytes, linear)
[    0.761202] NET: Registered protocol family 16
[    0.769334] thermal_sys: Registered thermal governor 'step_wise'
[    0.769380] thermal_sys: Registered thermal governor 'user_space'
[    0.769663] cpuidle: using governor menu
[    0.770592] ACPI: bus type PCI registered
[    0.771955] PCI: Using configuration type 1 for base access
[    0.798016] cryptd: max_cpu_qlen set to 1000
[    0.801851] ACPI: Added _OSI(Module Device)
[    0.802135] ACPI: Added _OSI(Processor Device)
[    0.802835] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.803556] ACPI: Added _OSI(Processor Aggregator Device)
[    0.804163] ACPI: Added _OSI(Linux-Dell-Video)
[    0.804901] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.805182] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.845998] ACPI BIOS Error (bug): Failure creating named object [\_SB.PCI0._PRT], AE_ALREADY_EXISTS (20200925/dswload2-327)
[    0.847719] ACPI Error: AE_ALREADY_EXISTS, During name lookup/catalog (20200925/psobject-221)
[    0.848103] ACPI: Skipping parse of AML opcode: Method (0x0014)
[    0.849401] ACPI: 2 ACPI AML tables successfully acquired and loaded
[    0.868773] ACPI: Interpreter enabled
[    0.869785] ACPI: (supports S0 S5)
[    0.870021] ACPI: Using IOAPIC for interrupt routing
[    0.871760] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.874687] ACPI: Enabled 2 GPEs in block 00 to 3F
[    0.922273] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.923215] acpi PNP0A08:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
[    0.925569] acpi PNP0A08:00: PCIe port services disabled; not requesting _OSC control
[    0.929073] PCI host bridge to bus 0000:00
[    0.929487] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.929827] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.930170] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.930518] pci_bus 0000:00: root bus resource [mem 0x80000000-0xafffffff window]
[    0.930862] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window]
[    0.931299] pci_bus 0000:00: root bus resource [mem 0x280000000-0xa7fffffff window]
[    0.931673] pci_bus 0000:00: root bus resource [mem 0xfed40000-0xfed44fff]
[    0.931988] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.933355] pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000
[    0.936701] pci 0000:00:01.0: [1234:1111] type 00 class 0x030000
[    0.938174] pci 0000:00:01.0: reg 0x10: [mem 0xc0000000-0xc0ffffff pref]
[    0.940620] pci 0000:00:01.0: reg 0x18: [mem 0xc107c000-0xc107cfff]
[    0.945284] pci 0000:00:01.0: reg 0x30: [mem 0xc1060000-0xc106ffff pref]
[    0.946010] pci 0000:00:01.0: BAR 0: assigned to efifb
[    0.947398] pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00
[    0.949001] pci 0000:00:02.0: reg 0x10: [io  0x10c0-0x10df]
[    0.951919] pci 0000:00:02.0: reg 0x14: [mem 0xc107d000-0xc107dfff]
[    0.954528] pci 0000:00:02.0: reg 0x20: [mem 0xc1070000-0xc1073fff 64bit pref]
[    0.957675] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000
[    0.958981] pci 0000:00:03.0: reg 0x10: [mem 0xc1040000-0xc105ffff]
[    0.960492] pci 0000:00:03.0: reg 0x14: [io  0x1080-0x10bf]
[    0.965100] pci 0000:00:03.0: reg 0x30: [mem 0xc1000000-0xc103ffff pref]
[    0.966245] pci 0000:00:04.0: [1b36:000d] type 00 class 0x0c0330
[    0.966892] pci 0000:00:04.0: reg 0x10: [mem 0xc1074000-0xc1077fff 64bit]
[    0.969752] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000
[    0.971962] pci 0000:00:05.0: reg 0x10: [io  0x1000-0x107f]
[    0.973763] pci 0000:00:05.0: reg 0x14: [mem 0xc107e000-0xc107efff]
[    0.977132] pci 0000:00:05.0: reg 0x20: [mem 0xc1078000-0xc107bfff 64bit pref]
[    0.980036] pci 0000:00:1d.0: [8086:2934] type 00 class 0x0c0300
[    0.984225] pci 0000:00:1d.0: reg 0x20: [io  0x10e0-0x10ff]
[    0.987308] pci 0000:00:1d.1: [8086:2935] type 00 class 0x0c0300
[    0.989125] pci 0000:00:1d.1: reg 0x20: [io  0x1100-0x111f]
[    0.990885] pci 0000:00:1d.2: [8086:2936] type 00 class 0x0c0300
[    0.994722] pci 0000:00:1d.2: reg 0x20: [io  0x1120-0x113f]
[    0.996687] pci 0000:00:1d.7: [8086:293a] type 00 class 0x0c0320
[    0.997342] pci 0000:00:1d.7: reg 0x10: [mem 0xc107f000-0xc107ffff]
[    0.999581] pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100
[    1.000337] pci 0000:00:1f.0: quirk: [io  0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO
[    1.000797] pci 0000:00:1f.0: quirk: [io  0x0580-0x05bf] claimed by ICH6 GPIO
[    1.001715] pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601
[    1.006478] pci 0000:00:1f.2: reg 0x20: [io  0x1140-0x115f]
[    1.007515] pci 0000:00:1f.2: reg 0x24: [mem 0xc1080000-0xc1080fff]
[    1.009471] pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500
[    1.010982] pci 0000:00:1f.3: reg 0x20: [io  0x0400-0x043f]
[    1.013188] pci_bus 0000:00: on NUMA node 0
[    1.020203] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 10 11) *0
[    1.022003] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 10 11) *0
[    1.024568] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 11) *0
[    1.026138] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 11) *0
[    1.027061] ACPI: PCI Interrupt Link [LNKE] (IRQs 5 10 11) *0
[    1.028317] ACPI: PCI Interrupt Link [LNKF] (IRQs 5 10 11) *0
[    1.029457] ACPI: PCI Interrupt Link [LNKG] (IRQs 5 10 11) *0
[    1.030639] ACPI: PCI Interrupt Link [LNKH] (IRQs 5 10 11) *0
[    1.031034] ACPI: PCI Interrupt Link [GSIA] (IRQs *16)
[    1.031785] ACPI: PCI Interrupt Link [GSIB] (IRQs *17)
[    1.032033] ACPI: PCI Interrupt Link [GSIC] (IRQs *18)
[    1.032281] ACPI: PCI Interrupt Link [GSID] (IRQs *19)
[    1.032491] ACPI: PCI Interrupt Link [GSIE] (IRQs *20)
[    1.032695] ACPI: PCI Interrupt Link [GSIF] (IRQs *21)
[    1.032910] ACPI: PCI Interrupt Link [GSIG] (IRQs *22)
[    1.033239] ACPI: PCI Interrupt Link [GSIH] (IRQs *23)
[    1.039071] iommu: Default domain type: Translated 
[    1.041895] SCSI subsystem initialized
[    1.042814] libata version 3.00 loaded.
[    1.043158] ACPI: bus type USB registered
[    1.043778] usbcore: registered new interface driver usbfs
[    1.044153] usbcore: registered new interface driver hub
[    1.044583] usbcore: registered new device driver usb
[    1.054070] PCI: Using ACPI for IRQ routing
[    1.055032] PCI: pci_cache_line_size set to 64 bytes
[    1.055952] e820: reserve RAM buffer [mem 0x7ff42000-0x7fffffff]
[    1.056888] hpet: 3 channels of 0 reserved for per-cpu timers
[    1.059297] clocksource: Switched to clocksource tsc-early
[    1.059753] pnp: PnP ACPI init
[    1.060475] pnp 00:00: Plug and Play ACPI device, IDs PNP0303 (active)
[    1.061320] pnp 00:01: Plug and Play ACPI device, IDs PNP0f13 (active)
[    1.062026] pnp 00:02: Plug and Play ACPI device, IDs PNP0400 (active)
[    1.062512] pnp 00:03: Plug and Play ACPI device, IDs PNP0501 (active)
[    1.063174] pnp 00:04: Plug and Play ACPI device, IDs PNP0b00 (active)
[    1.064767] system 00:05: [mem 0xb0000000-0xbfffffff window] has been reserved
[    1.066625] system 00:05: Plug and Play ACPI device, IDs PNP0c01 (active)
[    1.071487] pnp: PnP ACPI: found 6 devices
[    1.088239] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    1.089337] NET: Registered protocol family 2
[    1.094498] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear)
[    1.095855] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    1.096875] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[    1.098274] TCP: Hash tables configured (established 65536 bind 65536)
[    1.100269] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    1.100978] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    1.104465] NET: Registered protocol family 1
[    1.106229] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    1.106600] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
[    1.107013] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[    1.107374] pci_bus 0000:00: resource 7 [mem 0x80000000-0xafffffff window]
[    1.107709] pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window]
[    1.107898] pci_bus 0000:00: resource 9 [mem 0x280000000-0xa7fffffff window]
[    1.108011] pci_bus 0000:00: resource 10 [mem 0xfed40000-0xfed44fff]
[    1.108774] pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    1.116488] PCI Interrupt Link [GSIE] enabled at IRQ 20
[    1.123706] pci 0000:00:04.0: quirk_usb_early_handoff+0x0/0x628 took 14321 usecs
[    1.126582] PCI Interrupt Link [GSIA] enabled at IRQ 16
[    1.132172] PCI Interrupt Link [GSIB] enabled at IRQ 17
[    1.137954] PCI Interrupt Link [GSIC] enabled at IRQ 18
[    1.143375] PCI Interrupt Link [GSID] enabled at IRQ 19
[    1.147042] PCI: CLS 64 bytes, default 64
[    1.159947] Trying to unpack rootfs image as initramfs...
[    3.643506] Freeing initrd memory: 6012K
[    3.644156] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    3.644758] software IO TLB: mapped [mem 0x000000007bf42000-0x000000007ff42000] (64MB)
[    3.650745] workingset: timestamp_bits=46 max_order=21 bucket_order=0
[    3.657240] SGI XFS with security attributes, no debug enabled
[    3.660264] NET: Registered protocol family 38
[    3.660870] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    3.661432] io scheduler mq-deadline registered
[    3.663066] efifb: probing for efifb
[    3.663712] efifb: framebuffer at 0xc0000000, using 3072k, total 3072k
[    3.664257] efifb: mode is 1024x768x32, linelength=4096, pages=1
[    3.664646] efifb: scrolling: redraw
[    3.664927] efifb: Truecolor: size=8:8:8:8, shift=24:16:8:0
[    3.679374] Console: switching to colour frame buffer device 128x48
[    3.687239] fb0: EFI VGA frame buffer device
[    3.691037] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    3.692150] ACPI: Power Button [PWRF]
[    3.698794] PCI Interrupt Link [GSIG] enabled at IRQ 22
[    3.703964] PCI Interrupt Link [GSIF] enabled at IRQ 21
[    3.715415] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    3.717288] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    3.720047] Non-volatile memory driver v1.3
[    3.731652] random: fast init done
[    3.732919] tpm_tis MSFT0101:00: 2.0 TPM (device-id 0x1, rev-id 1)
[    3.734119] random: crng init done
[    3.800809] tpm_tis MSFT0101:01: can't request region for resource [mem 0xfed40000-0xfed44fff]
[    3.803209] tpm_tis: probe of MSFT0101:01 failed with error -16
[    3.806644] AMD-Vi: AMD IOMMUv2 driver by Joerg Roedel <jroedel@suse.de>
[    3.807659] AMD-Vi: AMD IOMMUv2 functionality not available on this system
[    3.831965] brd: module loaded
[    3.858480] loop: module loaded
[    3.875553] virtio_blk virtio1: [vda] 41943040 512-byte logical blocks (21.5 GB/20.0 GiB)
[    3.877673] vda: detected capacity change from 0 to 21474836480
[    3.900568]  vda: vda1 vda2 < vda5 >
[    3.905858] Loading iSCSI transport class v2.0-870.
[    3.907653] iscsi: registered transport (tcp)
[    3.910047] ahci 0000:00:1f.2: version 3.0
[    3.926223] ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode
[    3.929964] ahci 0000:00:1f.2: flags: 64bit ncq only 
[    3.946596] scsi host0: ahci
[    3.954840] scsi host1: ahci
[    3.962598] scsi host2: ahci
[    3.970363] scsi host3: ahci
[    3.979365] scsi host4: ahci
[    3.986464] scsi host5: ahci
[    3.993626] ata1: SATA max UDMA/133 abar m4096@0xc1080000 port 0xc1080100 irq 28
[    3.999747] ata2: SATA max UDMA/133 abar m4096@0xc1080000 port 0xc1080180 irq 28
[    4.003695] ata3: SATA max UDMA/133 abar m4096@0xc1080000 port 0xc1080200 irq 28
[    4.006793] ata4: SATA max UDMA/133 abar m4096@0xc1080000 port 0xc1080280 irq 28
[    4.009943] ata5: SATA max UDMA/133 abar m4096@0xc1080000 port 0xc1080300 irq 28
[    4.013210] ata6: SATA max UDMA/133 abar m4096@0xc1080000 port 0xc1080380 irq 28
[    4.018960] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    4.027840] serio: i8042 KBD port at 0x60,0x64 irq 1
[    4.031328] serio: i8042 AUX port at 0x60,0x64 irq 12
[    4.034963] rtc_cmos 00:04: RTC can wake from S4
[    4.046508] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    4.057172] rtc_cmos 00:04: registered as rtc0
[    4.063400] rtc_cmos 00:04: setting system clock to 2024-05-15T16:25:11 UTC (1715790311)
[    4.067457] rtc_cmos 00:04: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
[    4.074454] i801_smbus 0000:00:1f.3: SMBus using PCI interrupt
[    4.079663] i2c i2c-0: 1/1 memory slots populated (from DMI)
[    4.094496] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
[    4.105442] device-mapper: ioctl: 4.43.0-ioctl (2020-10-01) initialised: dm-devel@redhat.com
[    4.119558] NET: Registered protocol family 17
[    4.124996] IPI shorthand broadcast: enabled
[    4.129229] sched_clock: Marking stable (4080001125, 48914183)->(4130503880, -1588572)
[    4.370084] ata1: SATA link down (SStatus 0 SControl 300)
[    4.417271] ata4: SATA link down (SStatus 0 SControl 300)
[    4.422592] ata5: SATA link down (SStatus 0 SControl 300)
[    4.427388] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[    4.432938] ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[    4.436890] ata3.00: applying bridge limits
[    4.446393] ata3.00: configured for UDMA/100
[    4.450414] ata6: SATA link down (SStatus 0 SControl 300)
[    4.453912] ata2: SATA link down (SStatus 0 SControl 300)
[    4.464495] scsi 2:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     2.5+ PQ: 0 ANSI: 5
[    4.498631] sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
[    4.510108] cdrom: Uniform CD-ROM driver Revision: 3.20
[    4.538988] sr 2:0:0:0: Attached scsi CD-ROM sr0
[    4.548438] sr 2:0:0:0: Attached scsi generic sg0 type 5
[    4.839232] Freeing unused kernel image (initmem) memory: 932K
[    4.842860] tsc: Refined TSC clocksource calibration: 2495.991 MHz
[    4.846084] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x23fa6ea494a, max_idle_ns: 440795222040 ns
[    4.850511] clocksource: Switched to clocksource tsc
[    4.854074] Write protecting the kernel read-only data: 12288k
[    4.869481] Freeing unused kernel image (text/rodata gap) memory: 2044K
[    4.876998] Freeing unused kernel image (rodata/data gap) memory: 100K
[    4.888021] Run /init as init process
[    4.891612]   with arguments:
[    4.894400]     /init
[    4.897233]   with environment:
[    4.913582]     HOME=/
[    4.916671]     TERM=linux
[    4.992965] [U] hello world
[    5.233087] DEBUG: Debug output enabled from board CONFIG_DEBUG_OUTPUT=y option (/etc/config)
[    5.250972] TRACE: Under init
[    5.290788] DEBUG: Applying panic_on_oom setting to sysctl
[    5.430383] TRACE: /bin/tpmr(32): main
[    5.477394] TRACE: /bin/tpmr(336): tpm2_startsession
[    6.150675] TRACE: /bin/cbfs-init(5): main
[    6.294512] DEBUG: Extending TPM PCR 7 with /.gnupg/pubring.kbx
[    6.374151] TRACE: /bin/tpmr(32): main
[    6.420908] TRACE: /bin/tpmr(232): tpm2_extend
[    6.530971] DEBUG: tpm2 pcrread sha256:7
[    6.746176] DEBUG: Extending TPM PCR 7 with /.gnupg/trustdb.gpg
[    6.825733] TRACE: /bin/tpmr(32): main
[    6.858434] TRACE: /bin/tpmr(232): tpm2_extend
[    6.992334] DEBUG: tpm2 pcrread sha256:7
[    7.196932] TRACE: /bin/key-init(5): main
[    8.370159] TRACE: Under /etc/ash_functions:combine_configs
[    8.441474] TRACE: Under /etc/ash_functions:pause_recovery
!!! Hit enter to proceed to recovery shell !!!
[    8.652782] TRACE: /bin/setconsolefont.sh(6): main
[    8.694249] DEBUG: Board does not ship setfont, not checking console font
[    8.895257] TRACE: /bin/gui-init(643): main
[    8.919099] TRACE: /etc/functions(715): detect_boot_device
[    8.965732] TRACE: /etc/functions(682): mount_possible_boot_device
[    9.002842] TRACE: /etc/functions(642): is_gpt_bios_grub
[    9.073054] TRACE: /dev/vda1 is partition 1 of vda
[    9.171219] TRACE: /etc/functions(619): find_lvm_vg_name
[    9.302841] TRACE: Try mounting /dev/vda1 as /boot
[    9.328535] EXT4-fs (vda1): mounting ext2 file system using the ext4 subsystem
[    9.348211] EXT4-fs (vda1): mounted filesystem without journal. Opts: (null)
[    9.391280] TRACE: /bin/gui-init(317): clean_boot_check
[    9.484600] TRACE: /bin/gui-init(346): check_gpg_key
[    9.567329] TRACE: /bin/gui-init(183): update_totp
[    9.680896] TRACE: /bin/unseal-totp(8): main
[    9.767028] TRACE: /bin/tpmr(32): main
[    9.801461] TRACE: /bin/tpmr(554): tpm2_unseal
[    9.864278] DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
[   10.303402] DEBUG: Running at_exit handlers
[   10.329433] TRACE: /bin/tpmr(361): cleanup_session
[   10.365529] DEBUG: Clean up session: /tmp/secret/unsealfile_policy.session
[   10.466168]  !!! ERROR: Unable to unseal TOTP secret !!!
[   13.051493] TRACE: /bin/unseal-totp(8): main
[   13.136114] TRACE: /bin/tpmr(32): main
[   13.172434] TRACE: /bin/tpmr(554): tpm2_unseal
[   13.233786] DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
[   13.737065] DEBUG: Running at_exit handlers
[   13.761720] TRACE: /bin/tpmr(361): cleanup_session
[   13.808761] DEBUG: Clean up session: /tmp/secret/unsealfile_policy.session
[   13.924480]  !!! ERROR: Unable to unseal TOTP secret !!!
[   16.519408] TRACE: /bin/unseal-totp(8): main
[   16.593320] TRACE: /bin/tpmr(32): main
[   16.643153] TRACE: /bin/tpmr(554): tpm2_unseal
[   16.702430] DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
[   17.116506] DEBUG: Running at_exit handlers
[   17.139218] TRACE: /bin/tpmr(361): cleanup_session
[   17.177092] DEBUG: Clean up session: /tmp/secret/unsealfile_policy.session
[   17.285946]  !!! ERROR: Unable to unseal TOTP secret !!!
[   19.335162] DEBUG: CONFIG_TPM: y
[   19.369041] DEBUG: CONFIG_TPM2_TOOLS: y
[   19.414565] DEBUG: Show PCRs
[   19.551476] DEBUG:   sha256:
[   19.576280] 0 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.601598] 1 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.621973] 2 : 0x609E91CA638B27E28DBC5E346174B08D5500D92E9A3BB8F06B776CA20834A2BB
[   19.655889] 3 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.686936] 4 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.707444] 5 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.737940] 6 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.763082] 7 : 0x205992251DC2B7D4D20E939850B277EB68B50D8E1B09155AE063483167EC1240
[   19.793537] 8 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.820224] 9 : 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.843955] 10: 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.869235] 11: 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.897633] 12: 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.915777] 13: 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.942640] 14: 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.961383] 15: 0x0000000000000000000000000000000000000000000000000000000000000000
[   19.984413] 16: 0x0000000000000000000000000000000000000000000000000000000000000000
[   20.011612] 17: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
[   20.038217] 18: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
[   20.069995] 19: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
[   20.096617] 20: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
[   20.123537] 21: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
[   20.146498] 22: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
[   20.178638] 23: 0x0000000000000000000000000000000000000000000000000000000000000000
[   99.725599] TRACE: /bin/gui-init(252): update_hotp
[   99.747225] TRACE: /bin/gui-init(677): main
[   99.773297] TRACE: /bin/gui-init(393): show_main_menu

[  102.275101] TRACE: Under /etc/ash_functions:recovery
!!!!! Console recovery shell
[  102.412963] DEBUG: Board qemu-coreboot-whiptail-tpm2 - version Heads-v0.2.0-2154-gec9a3cb-dirty
[  102.439087] DEBUG: Extending TPM PCR 4 for recovery shell access
[  102.504104] TRACE: /bin/tpmr(32): main
[  102.542741] TRACE: /bin/tpmr(232): tpm2_extend
[  102.651651] DEBUG: tpm2 pcrread sha256:4
  sha256:
    4 : 0x51737C77C481AA22095B38D38FC9FD494B0FFA4EAE7D3AC238082083D0AFD614
!!!!! Starting recovery shell
~ # oem-factory-reset 
[  108.711164] TRACE: /bin/oem-factory-reset(11): main
























[  109.955371] TRACE: /bin/oem-factory-reset(77): mount_boot
[  109.992412] TRACE: /bin/oem-factory-reset(769): report_integrity_measurements
[  110.150056] TRACE: /bin/unseal-totp(8): main
[  110.210131] TRACE: /bin/tpmr(32): main
[  110.252969] TRACE: /bin/tpmr(554): tpm2_unseal
[  110.313444] DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
[  110.345602] DEBUG: tpm2_unseal: No primary handle, cannot attempt to unseal
[  110.363185]  *** WARNING: No TPM primary handle. You must reset TPM to seal secret to TPM NVRAM ***
[  111.400553]  !!! ERROR: Unable to unseal TOTP secret !!!
[  113.430114] TRACE: /etc/functions(396): check_config
+++ Found verified kexec boot params
























Would you like to use default configuration options?
If N, you will be prompted for each option [Y/n]: n
****************************************************
**** Factory Reset / Re-Ownership Questionnaire ****
****************************************************
The following questionnaire will help you configure the security components of your system.
Each prompt requires a single letter answer: eg. (Y/n).
If you don't know what to answer, pressing Enter will select the default answer for that prompt: eg. Y, above.



Would you like to change the current LUKS Disk Recovery Key passphrase?
 (Highly recommended if you didn't install the Operating System yourself, so that past configured passphrase would not permit to access content.
  Note that without re-encrypting disk, a backed up header could be restored to access encrypted content with old passphrase) [y/N]: n
Would you like to re-encrypt LUKS encrypted container and generate new LUKS Disk Recovery Key?
 (Highly recommended if you didn't install the operating system yourself: this would prevent any LUKS backed up header to be restored to access encrypted data) [y/N]: n
Would you like to format an encrypted USB Thumb drive to store GPG key material?
 (Required to enable GPG authentication) [y/N]: y
 ++++ Master key and subkeys will be generated in memory, backed up to dedicated LUKS container +++
Would you like in-memory generated subkeys to be copied to USB Security Dongle's smartcard?
 (Highly recommended so the smartcard is used on daily basis and backup is kept safe, but not required) [Y/n]: y
++++ Subkeys will be copied to USB Security Dongle's smartcard ++++
[  120.161001]  *** WARNING: Please keep your GPG key material backup thumb drive safe ***

The following Security Components will be configured with defaults or further chosen PINs/passwords:
	
TPM Owner Password
GPG Key material backup passphrase (Same as GPG Admin PIN)
GPG Admin PIN
GPG User PIN


Would you like to set a single custom password to all previously stated security components? [y/N]: n
Would you like to set distinct PINs/passwords to configure previously stated security components? [y/N]: n
Would you like to set custom user information for the GnuPG key? [y/N]: n
[  136.707571] TRACE: /bin/oem-factory-reset(412): select_thumb_drive_for_key_material
[  136.734054] TRACE: Under /etc/ash_functions:enable_usb
[  136.824409] TRACE: /sbin/insmod(9): main
[  136.979407] DEBUG: Extending TPM PCR 5 with /lib/modules/ehci-hcd.ko prior of usage
[  137.063392] TRACE: /bin/tpmr(32): main
[  137.094253] TRACE: /bin/tpmr(232): tpm2_extend
[  137.210612] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0xB4CE0466797D36BE2CC2526F7CA853179399A79E6F1D96B67317663A43E58027
[  137.384871] DEBUG: Loading /lib/modules/ehci-hcd.ko with busybox insmod
[  137.407503] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[  137.473479] TRACE: /sbin/insmod(9): main
[  137.605957] DEBUG: Extending TPM PCR 5 with /lib/modules/uhci-hcd.ko prior of usage
[  137.680258] TRACE: /bin/tpmr(32): main
[  137.714949] TRACE: /bin/tpmr(232): tpm2_extend
[  137.839827] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0x47CAB23B0BD95C0DA43DE546D5D2297E4B50F9870A075AAD940913FAE428F397
[  138.013541] DEBUG: Loading /lib/modules/uhci-hcd.ko with busybox insmod
[  138.035527] uhci_hcd: USB Universal Host Controller Interface driver
[  138.044531] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[  138.048901] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 1
[  138.053322] uhci_hcd 0000:00:1d.0: detected 2 ports
[  138.057363] uhci_hcd 0000:00:1d.0: irq 16, io base 0x000010e0
[  138.075562] hub 1-0:1.0: USB hub found
[  138.087643] hub 1-0:1.0: 2 ports detected
[  138.097171] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[  138.101003] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 2
[  138.105466] uhci_hcd 0000:00:1d.1: detected 2 ports
[  138.109768] uhci_hcd 0000:00:1d.1: irq 17, io base 0x00001100
[  138.115668] hub 2-0:1.0: USB hub found
[  138.121260] hub 2-0:1.0: 2 ports detected
[  138.137280] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[  138.155064] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 3
[  138.159696] uhci_hcd 0000:00:1d.2: detected 2 ports
[  138.164510] uhci_hcd 0000:00:1d.2: irq 18, io base 0x00001120
[  138.172257] hub 3-0:1.0: USB hub found
[  138.183405] hub 3-0:1.0: 2 ports detected
[  138.271153] TRACE: /sbin/insmod(9): main
[  138.402874] DEBUG: Extending TPM PCR 5 with /lib/modules/ohci-hcd.ko prior of usage
[  138.483048] TRACE: /bin/tpmr(32): main
[  138.525497] TRACE: /bin/tpmr(232): tpm2_extend
[  138.646232] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0x75260E66F3FB5D00BF72B187F7520A7D7CA6C5D08A0958402CB73758D0D8D9F4
[  138.829672] DEBUG: Loading /lib/modules/ohci-hcd.ko with busybox insmod
[  138.851392] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[  138.929388] TRACE: /sbin/insmod(9): main
[  139.055257] DEBUG: Extending TPM PCR 5 with /lib/modules/ohci-pci.ko prior of usage
[  139.133651] TRACE: /bin/tpmr(32): main
[  139.177449] TRACE: /bin/tpmr(232): tpm2_extend
[  139.284525] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0xFD89D4CB6B1E81A96F823166D2607A6B51321B80E747D4636BB1464CBE593B74
[  139.464242] DEBUG: Loading /lib/modules/ohci-pci.ko with busybox insmod
[  139.483535] ohci-pci: OHCI PCI platform driver
[  139.563109] TRACE: /sbin/insmod(9): main
[  139.694876] DEBUG: Extending TPM PCR 5 with /lib/modules/ehci-pci.ko prior of usage
[  139.796452] TRACE: /bin/tpmr(32): main
[  139.835916] TRACE: /bin/tpmr(232): tpm2_extend
[  139.963196] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0xD35840DA8FBB860549886B2555ED4F9FBC95B20EA9CB2EEF54F9BEE29F0C07CD
[  140.150802] DEBUG: Loading /lib/modules/ehci-pci.ko with busybox insmod
[  140.176801] ehci-pci: EHCI PCI platform driver
[  140.187674] ehci-pci 0000:00:1d.7: EHCI Host Controller
[  140.192317] ehci-pci 0000:00:1d.7: new USB bus registered, assigned bus number 4
[  140.197743] ehci-pci 0000:00:1d.7: irq 19, io mem 0xc107f000
[  140.216325] ehci-pci 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[  140.221271] hub 4-0:1.0: USB hub found
[  140.226715] hub 4-0:1.0: 6 ports detected
[  140.231354] hub 1-0:1.0: USB hub found
[  140.234674] hub 1-0:1.0: 2 ports detected
[  140.238095] hub 2-0:1.0: USB hub found
[  140.241077] hub 2-0:1.0: 2 ports detected
[  140.250913] hub 3-0:1.0: USB hub found
[  140.253762] hub 3-0:1.0: 2 ports detected
[  140.334365] TRACE: /sbin/insmod(9): main
[  140.475428] DEBUG: Extending TPM PCR 5 with /lib/modules/xhci-hcd.ko prior of usage
[  140.545489] TRACE: /bin/tpmr(32): main
[  140.598502] TRACE: /bin/tpmr(232): tpm2_extend
[  140.723290] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0x4E8B798C4B93C56C6BC453A87F8231D79BD37AD38A702EB8A37FA718DFB93DEF
[  140.898680] DEBUG: Loading /lib/modules/xhci-hcd.ko with busybox insmod
[  140.993445] TRACE: /sbin/insmod(9): main
[  141.122919] DEBUG: Extending TPM PCR 5 with /lib/modules/xhci-pci.ko prior of usage
[  141.221624] TRACE: /bin/tpmr(32): main
[  141.285938] TRACE: /bin/tpmr(232): tpm2_extend
[  141.439668] DEBUG: tpm2 pcrread sha256:5
  sha256:
    5 : 0xD76470232B7C3FD7D18D4DF3B77DACAFFDB876DBF3E84C996D74F7ECFA0FF60F
[  141.645945] DEBUG: Loading /lib/modules/xhci-pci.ko with busybox insmod
[  141.674333] xhci_hcd 0000:00:04.0: xHCI Host Controller
[  141.678258] xhci_hcd 0000:00:04.0: new USB bus registered, assigned bus number 5
[  141.684947] xhci_hcd 0000:00:04.0: hcc params 0x00087001 hci version 0x100 quirks 0x0000000000000010
[  141.694082] hub 5-0:1.0: USB hub found
[  141.698634] hub 5-0:1.0: 4 ports detected
[  141.703066] xhci_hcd 0000:00:04.0: xHCI Host Controller
[  141.706456] xhci_hcd 0000:00:04.0: new USB bus registered, assigned bus number 6
[  141.712737] xhci_hcd 0000:00:04.0: Host supports USB 3.0 SuperSpeed
[  141.719754] usb usb6: We don't know the algorithms for LPM for this host, disabling LPM.
[  141.725260] hub 6-0:1.0: USB hub found
[  141.729021] hub 6-0:1.0: 4 ports detected
[  142.040719] usb 5-1: new high-speed USB device number 2 using xhci_hcd
[  142.320672] usb 6-2: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[  142.472299] usb 5-3: new full-speed USB device number 3 using xhci_hcd
[  143.769885] TRACE: /etc/functions(224): enable_usb_storage
Scanning for USB storage devices...
[  143.874702] TRACE: /sbin/insmod(9): main
[  144.005140] DEBUG: Extending TPM PCR 5 with /lib/modules/usb-storage.ko prior of usage
[  144.082673] TRACE: /bin/tpmr(32): main
[  144.117716] TRACE: /bin/tpmr(232): tpm2_extend
[  144.235412] DEBUG: tpm2 pcrread sha256:5
[  144.423164] DEBUG: Loading /lib/modules/usb-storage.ko with busybox insmod
[  144.446579] usb-storage 6-2:1.0: USB Mass Storage device detected
[  144.452103] scsi host6: usb-storage 6-2:1.0
[  144.456330] usbcore: registered new interface driver usb-storage
[  144.494274] TRACE: /etc/functions(261): list_usb_storage
[  144.535484] DEBUG: Listing USB storage devices (including partitions)
[  145.463280] scsi 6:0:0:0: Direct-Access     QEMU     QEMU HARDDISK    2.5+ PQ: 0 ANSI: 5
[  145.471020] sd 6:0:0:0: Power-on or device reset occurred
[  145.478082] sd 6:0:0:0: [sda] 524288 512-byte logical blocks: (268 MB/256 MiB)
[  145.482641] sd 6:0:0:0: Attached scsi generic sg1 type 0
[  145.486305] sd 6:0:0:0: [sda] Write Protect is off
[  145.491402] sd 6:0:0:0: [sda] Mode Sense: 63 00 00 08
[  145.503640] sd 6:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[  145.510764]  sda: sda1 sda2
[  145.515688] sd 6:0:0:0: [sda] Attached SCSI disk
[  145.659221] TRACE: /etc/functions(261): list_usb_storage
[  145.698498] DEBUG: Listing USB storage devices (including partitions)
[  145.826425] DEBUG: USB storage device of size greater then 0: /sys/block/sda
[  145.943237] DEBUG: USB storage device with partition table: /dev/sda
[  146.008517] TRACE: /bin/oem-factory-reset(314): prompt_insert_to_be_wiped_thumb_drive






























┌────────────┤ WARNING: Please insert the thumb drive to be wiped ├────────────┐
│                                                                              │
│ The thumb drive will be WIPED next.                                          │
│                                                                              │
│ Please connect only the thumb drive to be wiped and disconnect others.       │
│                                                                              │
│                                    <Ok>                                      │
│                                                                              │
└──────────────────────────────────────────────────────────────────────────────┘







[  298.102256] TRACE: /etc/functions(261): list_usb_storage
[  298.150051] DEBUG: Listing USB storage devices (disks only) since list_usb_storage was called with 'disks' argument
[  298.274612] DEBUG: USB storage device of size greater then 0: /sys/block/sda
[  298.383577] DEBUG: USB storage device with partition table: /dev/sda
[  298.435692] DEBUG: We asked for disks only, so we don't want to list partitions
[  298.493708] TRACE: /etc/gui_functions(83): file_selector

























────────────────────┤ Select your File ├────────────────────────────────────────
to partition [1-1, a to abort]:

                              1 /dev/sda - 256 MB
                              a Abort












               <Ok>                                      <Cancel>

────────────────────────────────────────────────────────────────────────────────

[  299.507884] TRACE: /etc/luks-functions(19): select_luks_container_size_percent





























┌─────────────┤ Select LUKS container size percentage of device ├──────────────┐
│ Select LUKS container size percentage of device:                             │
│                                                                              │
│                                    10 10%                                    │
│                                    25 25%                                    │
│                                    50 50%                                    │
│                                    75 75%                                    │
│                                                                              │
│                                                                              │
│                     <Ok>                         <Cancel>                    │
│                                                                              │
└──────────────────────────────────────────────────────────────────────────────┘





[  300.427872] TRACE: /etc/luks-functions(191): confirm_thumb_drive_format





























┌───────────┤ WARNING: Wiping and repartitioning /dev/sda (256 MB) ├───────────┐
│                                                                              │
│ WARNING: Wiping and repartitioning /dev/sda (256 MB) with 25 MB              │
│  assigned to private LUKS ext4 partition,                                    │
│  rest assigned to exFAT public partition.                                    │
│                                                                              │
│ Are you sure you want to continue?                                           │
│                                                                              │
│                     <Yes>                        <No>                        │
│                                                                              │
└──────────────────────────────────────────────────────────────────────────────┘







Checking for USB Security Dongle...

[  301.345226] TRACE: Under /etc/ash_functions:enable_usb
[  301.407905] TRACE: /sbin/insmod(9): main
[  301.550928] DEBUG: /lib/modules/ehci-hcd.ko: already loaded
[  301.630985] TRACE: /sbin/insmod(9): main
[  301.753069] DEBUG: /lib/modules/uhci-hcd.ko: already loaded
[  301.822579] TRACE: /sbin/insmod(9): main
[  301.950906] DEBUG: /lib/modules/ohci-hcd.ko: already loaded
[  302.025633] TRACE: /sbin/insmod(9): main
[  302.168860] DEBUG: /lib/modules/ohci-pci.ko: already loaded
[  302.241132] TRACE: /sbin/insmod(9): main
[  302.376386] DEBUG: /lib/modules/ehci-pci.ko: already loaded
[  302.456253] TRACE: /sbin/insmod(9): main
[  302.595434] DEBUG: /lib/modules/xhci-hcd.ko: already loaded
[  302.686147] TRACE: /sbin/insmod(9): main
[  302.839328] DEBUG: /lib/modules/xhci-pci.ko: already loaded
[  305.085034] TRACE: /bin/oem-factory-reset(839): usb_security_token_capabilities_check
[  305.110396] TRACE: Under /etc/ash_functions:enable_usb
[  305.198903] TRACE: /sbin/insmod(9): main
[  305.338343] DEBUG: /lib/modules/ehci-hcd.ko: already loaded
[  305.417037] TRACE: /sbin/insmod(9): main
[  305.549081] DEBUG: /lib/modules/uhci-hcd.ko: already loaded
[  305.627135] TRACE: /sbin/insmod(9): main
[  305.777058] DEBUG: /lib/modules/ohci-hcd.ko: already loaded
[  305.859523] TRACE: /sbin/insmod(9): main
[  305.997172] DEBUG: /lib/modules/ohci-pci.ko: already loaded
[  306.077765] TRACE: /sbin/insmod(9): main
[  306.222138] DEBUG: /lib/modules/ehci-pci.ko: already loaded
[  306.301053] TRACE: /sbin/insmod(9): main
[  306.433496] DEBUG: /lib/modules/xhci-hcd.ko: already loaded
[  306.506002] TRACE: /sbin/insmod(9): main
[  306.647887] DEBUG: /lib/modules/xhci-pci.ko: already loaded
[  308.741283] TRACE: /etc/functions(568): assert_signable

Detecting and setting boot device...

[  308.901967] TRACE: /etc/functions(715): detect_boot_device
[  308.987029] TRACE: /etc/functions(682): mount_possible_boot_device
[  309.028577] TRACE: /etc/functions(642): is_gpt_bios_grub
[  309.110367] TRACE: /dev/vda1 is partition 1 of vda
[  309.206079] TRACE: /etc/functions(619): find_lvm_vg_name
[  309.362783] TRACE: Try mounting /dev/vda1 as /boot
[  309.385690] EXT4-fs (vda1): mounting ext2 file system using the ext4 subsystem
[  309.393251] EXT4-fs (vda1): mounted filesystem without journal. Opts: (null)
Boot device set to /dev/vda1

[  309.449477] TRACE: /etc/functions(437): replace_config
[  309.630188] TRACE: Under /etc/ash_functions:combine_configs

Resetting TPM...

[  309.722867] TRACE: /bin/tpmr(32): main
[  309.766919] TRACE: /bin/tpmr(634): tpm2_reset
[  309.817310] DEBUG: Caching TPM Owner Password to /tmp/secret/tpm_owner_password
[  311.043775] TRACE: /bin/tpmr(336): tpm2_startsession
[  312.177066] TRACE: /bin/oem-factory-reset(92): generate_inmemory_RSA_master_and_subkeys
Generating GPG key material in memory:
Generating GPG RSA 3072 bits master key...
Generating GPG RSA 3072 bits signing subkey...
Generating GPG RSA 3072 bits encryption subkey...
Generating GPG RSA 3072 bits authentication subkey...
[  341.728203] DEBUG: Setting public key to ultimate trust...
[  341.870407] TRACE: /bin/oem-factory-reset(464): wipe_thumb_drive_and_copy_gpg_key_material
[  341.898975] TRACE: /etc/luks-functions(233): prepare_thumb_drive
Preparing /dev/sda with 25 MB for private LUKS container while rest of device will be assigned to exFAT public partition...

Please wait...
[  341.963059] DEBUG: Creating empty DOS partition table on device through fdisk to start clean
[  343.011741]  sda:
[  343.059250] DEBUG: partition device with two partitions: first one being the percent applied and rest for second partition through fdisk
[  344.103363]  sda: sda1 sda2
[  344.144874] DEBUG: cryptsetup luksFormat  first partition with LUKS container aes-xts-plain64 cipher with sha256 hash and 512 bit key
[  344.199952] DEBUG: Creating 25MB LUKS container on /dev/sda1...
[  344.254081] DEBUG: cryptsetup --batch-mode -c aes-xts-plain64 -h sha256 -s 512 -y luksFormat /dev/sda1 --key-file /dev/fd/63
[  351.549947] DEBUG: Opening LUKS device and mapping under /dev/mapper/private...
[  351.604015] DEBUG: cryptsetup open /dev/sda1 private --key-file /dev/fd/63
[  354.559132] DEBUG: Formatting LUKS container mapped under /dev/mapper/private as an ext4 partition...
[  354.774629] DEBUG: Closing LUKS device /dev/mapper/private...
[  354.893291] DEBUG: Formatting second partition /dev/sda2 with exfat filesystem...
Done.
[  354.985834] TRACE: /bin/oem-factory-reset(323): export_master_key_subkeys_and_revocation_key_to_private_LUKS_container
[  355.131053] TRACE: /bin/mount-usb(6): main
[  355.178728] DEBUG: Parameters: --mode=rw, --device=/dev/sda1, --mountpoint=/media, --pass=provided
[  355.212633] TRACE: Under /etc/ash_functions:enable_usb
[  355.280141] TRACE: /sbin/insmod(9): main
[  355.413822] DEBUG: /lib/modules/ehci-hcd.ko: already loaded
[  355.483836] TRACE: /sbin/insmod(9): main
[  355.609210] DEBUG: /lib/modules/uhci-hcd.ko: already loaded
[  355.681621] TRACE: /sbin/insmod(9): main
[  355.819255] DEBUG: /lib/modules/ohci-hcd.ko: already loaded
[  355.893756] TRACE: /sbin/insmod(9): main
[  356.022803] DEBUG: /lib/modules/ohci-pci.ko: already loaded
[  356.092974] TRACE: /sbin/insmod(9): main
[  356.216768] DEBUG: /lib/modules/ehci-pci.ko: already loaded
[  356.296544] TRACE: /sbin/insmod(9): main
[  356.424770] DEBUG: /lib/modules/xhci-hcd.ko: already loaded
[  356.495685] TRACE: /sbin/insmod(9): main
[  356.632465] DEBUG: /lib/modules/xhci-pci.ko: already loaded
[  358.670563] TRACE: /etc/functions(224): enable_usb_storage
[  358.740488] DEBUG: Cleaning /media directory
[  358.783091] TRACE: /etc/functions(261): list_usb_storage
[  358.834696] DEBUG: Listing USB storage devices (including partitions)
[  358.980679] DEBUG: USB storage device of size greater then 0: /sys/block/sda
[  359.086357] DEBUG: USB storage device with partition table: /dev/sda
[  359.170948] DEBUG: Checking if /dev/sda1 is a USB detected block device
[  359.226328] DEBUG: Selected device is a USB block device
[  359.266243] DEBUG: Checking if /dev/sda1 is a LUKS device/partition
[  359.358427] DEBUG: Selected USB partition is a LUKS device
[  359.414201] DEBUG: Opening LUKS device /dev/sda1
[  362.372371]  *** WARNING: Note that you cannot boot from a mounted encrypted device ***
[  363.447268] DEBUG: Setting USB_MOUNT_DEVICE=/dev/mapper/usb_mount_sda1
[  363.505468] DEBUG: Mounting /dev/mapper/usb_mount_sda1 as read-write
[  363.565610] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)
[  363.618738] DEBUG: Exporting master key and subkeys to private LUKS container's partition...
[  365.832478] TRACE: /bin/oem-factory-reset(368): export_master_key_subkeys_and_revocation_key_to_private_LUKS_container
[  365.862499] TRACE: /bin/oem-factory-reset(373): export_public_key_to_thumbdrive_public_partition
[  366.014584] TRACE: /bin/mount-usb(6): main
[  366.068647] DEBUG: Parameters: --mode=rw, --device=/dev/sda2, --mountpoint=/media, --pass=
[  366.106514] TRACE: Under /etc/ash_functions:enable_usb
[  366.198399] TRACE: /sbin/insmod(9): main
[  366.347460] DEBUG: /lib/modules/ehci-hcd.ko: already loaded
[  366.418672] TRACE: /sbin/insmod(9): main
[  366.562888] DEBUG: /lib/modules/uhci-hcd.ko: already loaded
[  366.631420] TRACE: /sbin/insmod(9): main
[  366.775656] DEBUG: /lib/modules/ohci-hcd.ko: already loaded
[  366.854323] TRACE: /sbin/insmod(9): main
[  366.994322] DEBUG: /lib/modules/ohci-pci.ko: already loaded
[  367.070188] TRACE: /sbin/insmod(9): main
[  367.213897] DEBUG: /lib/modules/ehci-pci.ko: already loaded
[  367.290812] TRACE: /sbin/insmod(9): main
[  367.425397] DEBUG: /lib/modules/xhci-hcd.ko: already loaded
[  367.503006] TRACE: /sbin/insmod(9): main
[  367.647580] DEBUG: /lib/modules/xhci-pci.ko: already loaded
[  369.684337] TRACE: /etc/functions(224): enable_usb_storage
[  369.749220] DEBUG: Cleaning /media directory
[  369.797340] TRACE: /etc/functions(261): list_usb_storage
[  369.840739] DEBUG: Listing USB storage devices (including partitions)
[  369.982843] DEBUG: USB storage device of size greater then 0: /sys/block/sda
[  370.082911] DEBUG: USB storage device with partition table: /dev/sda
[  370.173790] DEBUG: Checking if /dev/sda2 is a USB detected block device
[  370.232218] DEBUG: Selected device is a USB block device
[  370.279072] DEBUG: Checking if /dev/sda2 is a LUKS device/partition
[  370.367314] DEBUG: Selected USB partition is not a LUKS device, continuing...
[  370.411522] DEBUG: Mounting /dev/sda2 as read-write
[  370.593058] TRACE: /bin/oem-factory-reset(404): export_public_key_to_thumbdrive_public_partition
[  370.617684] TRACE: /bin/oem-factory-reset(477): wipe_thumb_drive_and_copy_gpg_key_material
[  370.656817] TRACE: Under /etc/ash_functions:combine_configs
[  370.694283] TRACE: /bin/oem-factory-reset(269): keytocard_subkeys_to_smartcard
[  370.722587] TRACE: Under /etc/ash_functions:enable_usb
[  370.802304] TRACE: /sbin/insmod(9): main
[  370.933498] DEBUG: /lib/modules/ehci-hcd.ko: already loaded
[  371.012966] TRACE: /sbin/insmod(9): main
[  371.152218] DEBUG: /lib/modules/uhci-hcd.ko: already loaded
[  371.226082] TRACE: /sbin/insmod(9): main
[  371.387005] DEBUG: /lib/modules/ohci-hcd.ko: already loaded
[  371.464613] TRACE: /sbin/insmod(9): main
[  371.597403] DEBUG: /lib/modules/ohci-pci.ko: already loaded
[  371.682123] TRACE: /sbin/insmod(9): main
[  371.826150] DEBUG: /lib/modules/ehci-pci.ko: already loaded
[  371.909250] TRACE: /sbin/insmod(9): main
[  372.053481] DEBUG: /lib/modules/xhci-hcd.ko: already loaded
[  372.132980] TRACE: /sbin/insmod(9): main
[  372.279762] DEBUG: /lib/modules/xhci-pci.ko: already loaded
[  374.318151] TRACE: /etc/functions(224): enable_usb_storage
[  374.462699] TRACE: /bin/oem-factory-reset(481): gpg_key_factory_reset
[  374.489546] TRACE: Under /etc/ash_functions:enable_usb
[  374.555733] TRACE: /sbin/insmod(9): main
[  374.699078] DEBUG: /lib/modules/ehci-hcd.ko: already loaded
[  374.784179] TRACE: /sbin/insmod(9): main
[  374.916317] DEBUG: /lib/modules/uhci-hcd.ko: already loaded
[  374.992602] TRACE: /sbin/insmod(9): main
[  375.128419] DEBUG: /lib/modules/ohci-hcd.ko: already loaded
[  375.202926] TRACE: /sbin/insmod(9): main
[  375.336894] DEBUG: /lib/modules/ohci-pci.ko: already loaded
[  375.410495] TRACE: /sbin/insmod(9): main
[  375.551390] DEBUG: /lib/modules/ehci-pci.ko: already loaded
[  375.633402] TRACE: /sbin/insmod(9): main
[  375.789531] DEBUG: /lib/modules/xhci-hcd.ko: already loaded
[  375.861833] TRACE: /sbin/insmod(9): main
[  376.010066] DEBUG: /lib/modules/xhci-pci.ko: already loaded
GPG factory reset of USB Security Dongle's smartcard...
[  380.550581] DEBUG: GPG setting RSA key length to 3072 bits...
[  380.712240] TRACE: /bin/oem-factory-reset(567): gpg_key_factory_reset
[  380.772295] DEBUG: GPG_USER_MAIL: oem-20240515162655@example.com
Moving subkeys to smartcard...
[  380.834486] DEBUG: gpg --expert --command-fd=0 --status-fd=1 --pinentry-mode=loopback --edit-key oem-20240515162655@example.com
[  381.114823] DEBUG: gpg stderr:
[  381.227254] DEBUG: gpg stderr:
[  381.323346] DEBUG: gpg stderr:
[  381.405027] DEBUG: gpg stderr:
[  381.571383] DEBUG: gpg stderr:
[  381.659815] DEBUG: gpg stderr:
[  381.750615] DEBUG: gpg stderr:
[  381.835523] DEBUG: gpg stderr:
[  381.995430] DEBUG: gpg stderr:
[  382.067878] DEBUG: gpg stderr:
[  382.163798] DEBUG: gpg stderr:
[  382.257874] DEBUG: gpg stderr:
[  382.338815] DEBUG: gpg stderr:
[  382.387976] DEBUG: gpg stderr:
[  382.437416] DEBUG: gpg stderr:
[  382.480730] DEBUG: gpg stderr:
[  382.538025] DEBUG: gpg stderr:
[  382.578562] DEBUG: gpg stderr:
[  382.631468] DEBUG: gpg stderr:
[  382.683760] DEBUG: gpg stderr:
[  382.730543] DEBUG: gpg stderr:
[  382.798265] DEBUG: gpg stderr:
[  382.850381] DEBUG: gpg stderr:
[  382.908968] DEBUG: gpg: exited with status 2























┌──────────────────────────────────┤ Error ├───────────────────────────────────┐
│                                                                              │
│                                                                              ↑
│ No user ID with index 12345678                                               ▒
│                                                                              ▒
│                                                                              ▒
│ sec  rsa3072/867F754A2B77BD79                                                ▒
│      created: 2024-05-15  expires: never       usage: SC                     ▒
│      trust: ultimate      validity: ultimate                                 ▒
│ ssb  rsa3072/B3AD5541B07B5CD7                                                ▒
│      created: 2024-05-15  expires: never       usage: S                      ▒
│ ssb  rsa3072/E52717F446E8D9B6                                                ▒
│      created: 2024-05-15  expires: never       usage: E                      ▒
│ ssb  rsa3072/EDE5BC25C42457BF                                                ▒
│      created: 2024-05-15  expires: never       usage: AR                     ▒
│ [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com> ▒
│                                                                              ▒
│ Key not changed so no update needed.                                         ▮
│                                                                              ↓
│
│                                    <Ok>
│                                                                              │
└──────────────────────────────────────────────────────────────────────────────┘
~ # cat /tmp/debug.log 
DEBUG: Debug output enabled from board CONFIG_DEBUG_OUTPUT=y option (/etc/config)
TRACE: Under init
DEBUG: Applying panic_on_oom setting to sysctl
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(336): tpm2_startsession
TRACE: /bin/cbfs-init(5): main
DEBUG: Extending TPM PCR 7 with /.gnupg/pubring.kbx
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:7
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     7 : 0x159E7C23810C023B6E0122FA1D309488EE4470FD9F6A7DABC575D5995551B41A
DEBUG: Extending TPM PCR 7 with /.gnupg/trustdb.gpg
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:7
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     7 : 0x205992251DC2B7D4D20E939850B277EB68B50D8E1B09155AE063483167EC1240
TRACE: /bin/key-init(5): main
TRACE: Under /etc/ash_functions:combine_configs
TRACE: Under /etc/ash_functions:pause_recovery
TRACE: /bin/setconsolefont.sh(6): main
DEBUG: Board does not ship setfont, not checking console font
TRACE: /bin/gui-init(643): main
TRACE: /etc/functions(715): detect_boot_device
TRACE: /etc/functions(682): mount_possible_boot_device
TRACE: /etc/functions(642): is_gpt_bios_grub
TRACE: /dev/vda1 is partition 1 of vda
TRACE: /etc/functions(619): find_lvm_vg_name
TRACE: Try mounting /dev/vda1 as /boot
TRACE: /bin/gui-init(317): clean_boot_check
TRACE: /bin/gui-init(346): check_gpg_key
TRACE: /bin/gui-init(183): update_totp
TRACE: /bin/unseal-totp(8): main
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(554): tpm2_unseal
DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
DEBUG: Running at_exit handlers
TRACE: /bin/tpmr(361): cleanup_session
DEBUG: Clean up session: /tmp/secret/unsealfile_policy.session
 !!! ERROR: Unable to unseal TOTP secret !!!
TRACE: /bin/unseal-totp(8): main
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(554): tpm2_unseal
DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
DEBUG: Running at_exit handlers
TRACE: /bin/tpmr(361): cleanup_session
DEBUG: Clean up session: /tmp/secret/unsealfile_policy.session
 !!! ERROR: Unable to unseal TOTP secret !!!
TRACE: /bin/unseal-totp(8): main
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(554): tpm2_unseal
DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
DEBUG: Running at_exit handlers
TRACE: /bin/tpmr(361): cleanup_session
DEBUG: Clean up session: /tmp/secret/unsealfile_policy.session
 !!! ERROR: Unable to unseal TOTP secret !!!
DEBUG: CONFIG_TPM: y
DEBUG: CONFIG_TPM2_TOOLS: y
DEBUG: Show PCRs
DEBUG:   sha256:
0 : 0x0000000000000000000000000000000000000000000000000000000000000000
1 : 0x0000000000000000000000000000000000000000000000000000000000000000
2 : 0x609E91CA638B27E28DBC5E346174B08D5500D92E9A3BB8F06B776CA20834A2BB
3 : 0x0000000000000000000000000000000000000000000000000000000000000000
4 : 0x0000000000000000000000000000000000000000000000000000000000000000
5 : 0x0000000000000000000000000000000000000000000000000000000000000000
6 : 0x0000000000000000000000000000000000000000000000000000000000000000
7 : 0x205992251DC2B7D4D20E939850B277EB68B50D8E1B09155AE063483167EC1240
8 : 0x0000000000000000000000000000000000000000000000000000000000000000
9 : 0x0000000000000000000000000000000000000000000000000000000000000000
10: 0x0000000000000000000000000000000000000000000000000000000000000000
11: 0x0000000000000000000000000000000000000000000000000000000000000000
12: 0x0000000000000000000000000000000000000000000000000000000000000000
13: 0x0000000000000000000000000000000000000000000000000000000000000000
14: 0x0000000000000000000000000000000000000000000000000000000000000000
15: 0x0000000000000000000000000000000000000000000000000000000000000000
16: 0x0000000000000000000000000000000000000000000000000000000000000000
17: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
18: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
19: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
20: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
21: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
22: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
23: 0x0000000000000000000000000000000000000000000000000000000000000000
TRACE: /bin/gui-init(252): update_hotp
TRACE: /bin/gui-init(677): main
TRACE: /bin/gui-init(393): show_main_menu
TRACE: Under /etc/ash_functions:recovery
DEBUG: Board qemu-coreboot-whiptail-tpm2 - version Heads-v0.2.0-2154-gec9a3cb-dirty
DEBUG: Extending TPM PCR 4 for recovery shell access
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:4
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     4 : 0x51737C77C481AA22095B38D38FC9FD494B0FFA4EAE7D3AC238082083D0AFD614
TRACE: /bin/oem-factory-reset(11): main
TRACE: /bin/oem-factory-reset(77): mount_boot
TRACE: /bin/oem-factory-reset(769): report_integrity_measurements
TRACE: /bin/unseal-totp(8): main
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(554): tpm2_unseal
DEBUG: tpm2_unseal: handle=0x81004d47 pcrl=0,1,2,3,4,7 file=/tmp/secret/totp.key pass=<empty>
DEBUG: tpm2_unseal: No primary handle, cannot attempt to unseal
 *** WARNING: No TPM primary handle. You must reset TPM to seal secret to TPM NVRAM ***
 !!! ERROR: Unable to unseal TOTP secret !!!
TRACE: /etc/functions(396): check_config
TRACE: /bin/oem-factory-reset(835): report_integrity_measurements
 *** WARNING: Please keep your GPG key material backup thumb drive safe ***
TRACE: /bin/oem-factory-reset(412): select_thumb_drive_for_key_material
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/ehci-hcd.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0xB4CE0466797D36BE2CC2526F7CA853179399A79E6F1D96B67317663A43E58027
DEBUG: Loading /lib/modules/ehci-hcd.ko with busybox insmod
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/uhci-hcd.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0x47CAB23B0BD95C0DA43DE546D5D2297E4B50F9870A075AAD940913FAE428F397
DEBUG: Loading /lib/modules/uhci-hcd.ko with busybox insmod
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/ohci-hcd.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0x75260E66F3FB5D00BF72B187F7520A7D7CA6C5D08A0958402CB73758D0D8D9F4
DEBUG: Loading /lib/modules/ohci-hcd.ko with busybox insmod
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/ohci-pci.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0xFD89D4CB6B1E81A96F823166D2607A6B51321B80E747D4636BB1464CBE593B74
DEBUG: Loading /lib/modules/ohci-pci.ko with busybox insmod
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/ehci-pci.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0xD35840DA8FBB860549886B2555ED4F9FBC95B20EA9CB2EEF54F9BEE29F0C07CD
DEBUG: Loading /lib/modules/ehci-pci.ko with busybox insmod
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/xhci-hcd.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0x4E8B798C4B93C56C6BC453A87F8231D79BD37AD38A702EB8A37FA718DFB93DEF
DEBUG: Loading /lib/modules/xhci-hcd.ko with busybox insmod
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/xhci-pci.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0xD76470232B7C3FD7D18D4DF3B77DACAFFDB876DBF3E84C996D74F7ECFA0FF60F
DEBUG: Loading /lib/modules/xhci-pci.ko with busybox insmod
TRACE: /etc/functions(224): enable_usb_storage
TRACE: /sbin/insmod(9): main
DEBUG: Extending TPM PCR 5 with /lib/modules/usb-storage.ko prior of usage
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(232): tpm2_extend
DEBUG: tpm2 pcrread sha256:5
LOG: tpm2 stdout:   sha256:
LOG: tpm2 stdout:     5 : 0x3ADA3C61A344EDF0109D45CEA85F1C53F0D8B893CDD0F7048E4DDB94424032B4
DEBUG: Loading /lib/modules/usb-storage.ko with busybox insmod
TRACE: /etc/functions(261): list_usb_storage
DEBUG: Listing USB storage devices (including partitions)
TRACE: /etc/functions(261): list_usb_storage
DEBUG: Listing USB storage devices (including partitions)
DEBUG: USB storage device of size greater then 0: /sys/block/sda
DEBUG: USB storage device with partition table: /dev/sda
TRACE: /bin/oem-factory-reset(314): prompt_insert_to_be_wiped_thumb_drive
TRACE: /etc/functions(261): list_usb_storage
DEBUG: Listing USB storage devices (disks only) since list_usb_storage was called with 'disks' argument
DEBUG: USB storage device of size greater then 0: /sys/block/sda
DEBUG: USB storage device with partition table: /dev/sda
DEBUG: We asked for disks only, so we don't want to list partitions
TRACE: /etc/gui_functions(83): file_selector
TRACE: /etc/luks-functions(19): select_luks_container_size_percent
TRACE: /etc/luks-functions(191): confirm_thumb_drive_format
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/uhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-pci.ko: already loaded
TRACE: /bin/oem-factory-reset(839): usb_security_token_capabilities_check
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/uhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-pci.ko: already loaded
TRACE: /etc/functions(568): assert_signable
TRACE: /etc/functions(715): detect_boot_device
TRACE: /etc/functions(682): mount_possible_boot_device
TRACE: /etc/functions(642): is_gpt_bios_grub
TRACE: /dev/vda1 is partition 1 of vda
TRACE: /etc/functions(619): find_lvm_vg_name
TRACE: Try mounting /dev/vda1 as /boot
TRACE: /etc/functions(437): replace_config
TRACE: Under /etc/ash_functions:combine_configs
TRACE: /bin/tpmr(32): main
TRACE: /bin/tpmr(634): tpm2_reset
DEBUG: Caching TPM Owner Password to /tmp/secret/tpm_owner_password
TRACE: /bin/tpmr(336): tpm2_startsession
TRACE: /bin/oem-factory-reset(92): generate_inmemory_RSA_master_and_subkeys
DEBUG: Setting public key to ultimate trust...
TRACE: /bin/oem-factory-reset(464): wipe_thumb_drive_and_copy_gpg_key_material
TRACE: /etc/luks-functions(233): prepare_thumb_drive
DEBUG: Creating empty DOS partition table on device through fdisk to start clean
DEBUG: partition device with two partitions: first one being the percent applied and rest for second partition through fdisk
DEBUG: cryptsetup luksFormat  first partition with LUKS container aes-xts-plain64 cipher with sha256 hash and 512 bit key
DEBUG: Creating 25MB LUKS container on /dev/sda1...
DEBUG: cryptsetup --batch-mode -c aes-xts-plain64 -h sha256 -s 512 -y luksFormat /dev/sda1 --key-file /dev/fd/63
DEBUG: Opening LUKS device and mapping under /dev/mapper/private...
DEBUG: cryptsetup open /dev/sda1 private --key-file /dev/fd/63
DEBUG: Formatting LUKS container mapped under /dev/mapper/private as an ext4 partition...
DEBUG: Closing LUKS device /dev/mapper/private...
DEBUG: Formatting second partition /dev/sda2 with exfat filesystem...
TRACE: /bin/oem-factory-reset(323): export_master_key_subkeys_and_revocation_key_to_private_LUKS_container
TRACE: /bin/mount-usb(6): main
DEBUG: Parameters: --mode=rw, --device=/dev/sda1, --mountpoint=/media, --pass=provided
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/uhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-pci.ko: already loaded
TRACE: /etc/functions(224): enable_usb_storage
DEBUG: Cleaning /media directory
TRACE: /etc/functions(261): list_usb_storage
DEBUG: Listing USB storage devices (including partitions)
DEBUG: USB storage device of size greater then 0: /sys/block/sda
DEBUG: USB storage device with partition table: /dev/sda
DEBUG: Checking if /dev/sda1 is a USB detected block device
DEBUG: Selected device is a USB block device
DEBUG: Checking if /dev/sda1 is a LUKS device/partition
DEBUG: Selected USB partition is a LUKS device
DEBUG: Opening LUKS device /dev/sda1
 *** WARNING: Note that you cannot boot from a mounted encrypted device ***
DEBUG: Setting USB_MOUNT_DEVICE=/dev/mapper/usb_mount_sda1
DEBUG: Mounting /dev/mapper/usb_mount_sda1 as read-write
DEBUG: Exporting master key and subkeys to private LUKS container's partition...
TRACE: /bin/oem-factory-reset(368): export_master_key_subkeys_and_revocation_key_to_private_LUKS_container
TRACE: /bin/oem-factory-reset(373): export_public_key_to_thumbdrive_public_partition
TRACE: /bin/mount-usb(6): main
DEBUG: Parameters: --mode=rw, --device=/dev/sda2, --mountpoint=/media, --pass=
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/uhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-pci.ko: already loaded
TRACE: /etc/functions(224): enable_usb_storage
DEBUG: Cleaning /media directory
TRACE: /etc/functions(261): list_usb_storage
DEBUG: Listing USB storage devices (including partitions)
DEBUG: USB storage device of size greater then 0: /sys/block/sda
DEBUG: USB storage device with partition table: /dev/sda
DEBUG: Checking if /dev/sda2 is a USB detected block device
DEBUG: Selected device is a USB block device
DEBUG: Checking if /dev/sda2 is a LUKS device/partition
DEBUG: Selected USB partition is not a LUKS device, continuing...
DEBUG: Mounting /dev/sda2 as read-write
TRACE: /bin/oem-factory-reset(404): export_public_key_to_thumbdrive_public_partition
TRACE: /bin/oem-factory-reset(477): wipe_thumb_drive_and_copy_gpg_key_material
TRACE: Under /etc/ash_functions:combine_configs
TRACE: /bin/oem-factory-reset(269): keytocard_subkeys_to_smartcard
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/uhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-pci.ko: already loaded
TRACE: /etc/functions(224): enable_usb_storage
TRACE: /bin/oem-factory-reset(481): gpg_key_factory_reset
TRACE: Under /etc/ash_functions:enable_usb
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/uhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ohci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/ehci-pci.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-hcd.ko: already loaded
TRACE: /sbin/insmod(9): main
DEBUG: /lib/modules/xhci-pci.ko: already loaded
DEBUG: GPG setting RSA key length to 3072 bits...
TRACE: /bin/oem-factory-reset(567): gpg_key_factory_reset
DEBUG: GPG_USER_MAIL: oem-20240515162655@example.com
DEBUG: gpg --expert --command-fd=0 --status-fd=1 --pinentry-mode=loopback --edit-key oem-20240515162655@example.com
LOG: gpg stderr: gpg (GnuPG) 2.4.2; Copyright (C) 2023 g10 Code GmbH
LOG: gpg stderr: This is free software: you are free to change and redistribute it.
LOG: gpg stderr: There is NO WARRANTY, to the extent permitted by law.
LOG: gpg stdout: [GNUPG:] KEY_CONSIDERED 04444B1DD79B70E7332B4E04867F754A2B77BD79 0
LOG: gpg stdout: [GNUPG:] KEY_CONSIDERED 04444B1DD79B70E7332B4E04867F754A2B77BD79 0
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
DEBUG: gpg stderr:
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] CARDCTRL 3 D276000124010304F1D0000000000000
LOG: gpg stdout: [GNUPG:] GET_LINE cardedit.genkeys.storekeytype
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] INQUIRE_MAXLEN 100
LOG: gpg stdout: [GNUPG:] GET_HIDDEN passphrase.enter
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stderr: Secret key is available.
DEBUG: gpg stderr:
LOG: gpg stderr: gpg: checking the trustdb
LOG: gpg stderr: gpg: marginals needed: 3  completes needed: 1  trust model: pgp
LOG: gpg stderr: gpg: depth: 0  valid:   1  signed:   0  trust: 0-, 0q, 0n, 0m, 0f, 1u
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb  rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
DEBUG: gpg stderr:
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb* rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stdout: [GNUPG:] SC_OP_FAILURE
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE cardedit.genkeys.storekeytype
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] INQUIRE_MAXLEN 100
LOG: gpg stdout: [GNUPG:] GET_HIDDEN passphrase.enter
LOG: gpg stdout: [GNUPG:] GOT_IT
DEBUG: gpg stderr:
LOG: gpg stderr: Please select where to store the key:
LOG: gpg stderr:    (1) Signature key
LOG: gpg stderr:    (3) Authentication key
LOG: gpg stderr: gpg: KEYTOCARD failed: Invalid time
DEBUG: gpg stderr:
LOG: gpg stderr: No user ID with index 12345678
DEBUG: gpg stderr:
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb* rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stdout: [GNUPG:] SC_OP_FAILURE
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE cardedit.genkeys.storekeytype
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] INQUIRE_MAXLEN 100
LOG: gpg stdout: [GNUPG:] GET_HIDDEN passphrase.enter
LOG: gpg stdout: [GNUPG:] GOT_IT
DEBUG: gpg stderr:
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb  rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
DEBUG: gpg stderr:
LOG: gpg stdout: [GNUPG:] SC_OP_FAILURE
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb  rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb* rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
DEBUG: gpg stderr:
LOG: gpg stderr: Please select where to store the key:
LOG: gpg stderr:    (2) Encryption key
LOG: gpg stderr: gpg: KEYTOCARD failed: Invalid time
DEBUG: gpg stderr:
LOG: gpg stderr: No user ID with index 12345678
DEBUG: gpg stderr:
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb  rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
DEBUG: gpg stderr:
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb  rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb* rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
DEBUG: gpg stderr:
LOG: gpg stderr: Please select where to store the key:
LOG: gpg stderr:    (3) Authentication key
LOG: gpg stderr: gpg: KEYTOCARD failed: Invalid time
DEBUG: gpg stderr:
LOG: gpg stderr: No user ID with index 12345678
DEBUG: gpg stderr:
DEBUG: gpg stderr:
LOG: gpg stderr: sec  rsa3072/867F754A2B77BD79
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: SC  
LOG: gpg stderr:      trust: ultimate      validity: ultimate
LOG: gpg stderr: ssb  rsa3072/B3AD5541B07B5CD7
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: S   
LOG: gpg stderr: ssb  rsa3072/E52717F446E8D9B6
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: E   
LOG: gpg stderr: ssb  rsa3072/EDE5BC25C42457BF
LOG: gpg stderr:      created: 2024-05-15  expires: never       usage: AR  
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
DEBUG: gpg stderr:
LOG: gpg stderr: Key not changed so no update needed.
DEBUG: gpg: exited with status 2
~ # qemu: terminating on signal 2
make: *** wait: No child processes.  Stop.

@tlaurion
Copy link
Collaborator Author

The real error is

LOG: gpg stdout: [GNUPG:] SC_OP_FAILURE
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stderr: [ultimate] (1). OEM Key (OEM-generated key) <oem-20240515162655@example.com>
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE keyedit.prompt
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] GET_LINE cardedit.genkeys.storekeytype
LOG: gpg stdout: [GNUPG:] GOT_IT
LOG: gpg stdout: [GNUPG:] INQUIRE_MAXLEN 100
LOG: gpg stdout: [GNUPG:] GET_HIDDEN passphrase.enter
LOG: gpg stdout: [GNUPG:] GOT_IT
DEBUG: gpg stderr:
LOG: gpg stderr: Please select where to store the key:
LOG: gpg stderr:    (1) Signature key
LOG: gpg stderr:    (3) Authentication key
LOG: gpg stderr: gpg: KEYTOCARD failed: Invalid time
DEBUG: gpg stderr:
LOG: gpg stderr: No user ID with index 12345678
DEBUG: gpg stderr:

Have to context switch will come back to it in a bit

@tlaurion
Copy link
Collaborator Author

Issues are to track details of issues and PR is where fix are developed until merged to fix issue.

@headscontrib was able to reproduce. Seems like culprit is version bump of gpg toolstack that happened under #1661

Originally posted by @tlaurion in #1674 (comment)

@tlaurion
Copy link
Collaborator Author

haaaa

.gnupg/configs get wiped and the error is known with pinentry

@tlaurion
Copy link
Collaborator Author

github-af/SmartPGP#15

@tlaurion
Copy link
Collaborator Author

tlaurion commented May 16, 2024

So something fishy is happening with newer version toolstack as opposed to pior of #1661 one.
At this point, p256 ALGO (instead of RSA) works as intended. Will use this commit as base to understand what is wrong with RSA key to card.

Notes under eae082d commit message.

@tlaurion
Copy link
Collaborator Author

tlaurion commented May 17, 2024

Well it will take more work to understand and probably do bug report upstream.

Poitn is that past used gpg toolstack worked for both p256 and RSA keys so strategy here is to revert unneeded changes for our use case for now and will check that without it breaking anything.

@tlaurion tlaurion marked this pull request as ready for review May 17, 2024 00:34
@tlaurion
Copy link
Collaborator Author

tlaurion commented May 17, 2024

  • Test if reproducible.
  • clean commit message
  • Open another issue to track issue upstream with gnupg, this error is not normal and haven't seen it reported upstream.
  • fix sleep when enable_usb is called when modules are already loaded. This is annoying in dev cycles. Open other issue for tracking.
  • update flake.lock, flake.nix and push newer docker image (v0.1.9?) when qemu: enable canokey by default NixOS/nixpkgs#311914 gets merged so that we don't have to build qemu_full with override, resulting in smaller docker image and reuse of cached derivative for qemu_full. Also bumps canokey to latest devel which now supports RSA4096, which now fails and requires testing with RSA 2048 key (needs to be switched in oem-factory-reset code in this PR)
  • Move RSA keysize to 4096 next after nk3 firmware 1.7.1 is mass deployed and keys are generated/handled in secure element instead of MCU? I remember there was pushback which made us default to set lower RSA keysize for key time generation, but is that decision still valid today with current oem-factory-reset unattended flow for OEMs and end users pushing for 4096? Change dongle detection code to check firmware version maybe?

@tlaurion tlaurion changed the title WiP key to card fails with invalid time when moving keys to smartcard Revert gpg version bump and unify key to card code to properly create bug upstream May 17, 2024
…rd on master (Opt: Authenticated Heads)

- Revert gnupg toolstack version bump to prior of linuxboot#1661 merge (2.4.2 -> 2.4.0). Version bump not needed for reproducibility.
  - Investigation and upstream discussions will take their time resolving invalid time issue introduced by between 2.4.0 and latest gnupg, fix regression first under master)

- oem-factory-reset
  - Adding DO_WITH_DEBUG to oem-factory-reset for all its gpg calls. If failing in debug mode, /tmp/debug.txt contains calls and errors
  - Wipe keyrings only (*.gpg, *.kbx)  not conf files under gpg homedir (keep initrd/.gnupg/*.conf)

- flake.nix
  - switch build derivative from qemu and qemu_kvm to qemu_full to have qemu-img tool which was missing to run qemu boards (v0.1.8 docker)
  - add gnupg so that qemu boards can call inject_gpg to inject public key in absence of flashrom+pflash support for internal flashing

- flake.lock: Updated nix pinned package list under flake.lock with 'nix flake update' so qemu_full builds

- README.md: have consistent docker testing + release (push) notes

- .circleci/config.yml: depend on docker v0.1.8 (qemu_full built with canokey-qemu lib support, diffoscopeMinimal and gnupg for proper qemu testing)

TODO:
- some fd2 instead of fd1?!
- oem-factory-resest has whiptail_or_die which sets whiptail box to HEIGHT 0. This doesn't show a scrolling window on gpg errors which is problematic with fbwhiptail, not whiptail

Signed-off-by: Thierry Laurion <insurgo@riseup.net>
Copy link
Collaborator

@JonathonHall-Purism JonathonHall-Purism left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks fine to me, thanks for the fixes. We discussed a few things separately:

  1. docker image for build env is ~1.4 GB, that's fine right now
  2. The removed steps relating to marking a new key as ultimately trusted were redundant, the steps removed only apply to in-mem generated RSA keys, a common path handles everything and covers those as well
  3. The change from rm -rf /.gnupg/* to rm -rf /.gnupg/*.kbx /.gnupg/*.gpg is because the former was deleting a GPG config file we create at startup telling it where to find the GPG agent, this functionally reverts that change from 2c55338

@tlaurion tlaurion merged commit 59df86f into linuxboot:master May 17, 2024
40 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

OEM Factory Reset GPG user authentication: key_to_card fails with « invalid time »
2 participants