unofficial mirror of bug-guix@gnu.org 
 help / color / mirror / code / Atom feed
* bug#58732: installer: finalizers & device destroy segfault
@ 2022-10-23  9:07 Mathieu Othacehe
  2022-11-02 10:55 ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Mathieu Othacehe @ 2022-10-23  9:07 UTC (permalink / raw)
  To: 58732


Hello,

I found a segfault in the installer by running those steps:

- Run an automatic partitioning with separate home and no encryption
- In the final configuration page, come back to partitioning
- Remove all partitions but the ESP one, create a new btrfs root
- partition
- Repeat until the crash occurs

Using Josselin's instructions here: https://issues.guix.gnu.org/57513, I
was able to get the following backtrace:

--8<---------------cut here---------------start------------->8---
Reading symbols from /gnu/store/b0ymz7vjfkcvhbci49q5yk1fi0l9lq49-parted-3.5/lib/libparted.so...
(gdb) bt
#0  linux_destroy (dev=0x1dc89e0) at arch/linux.c:1615
#1  0x00007f8941aecd37 in ?? () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#2  0x00007f8941a45e3f in GC_invoke_finalizers () from /gnu/store/2lczkxbdbzh4gk7wh91bzrqrk7h5g1dl-libgc-8.0.4/lib/libgc.so.1
#3  0x00007f8941aed429 in scm_run_finalizers () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#4  0x00007f8941af4482 in ?? () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#5  0x00007f8941ae085a in ?? () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#6  0x00007f8941b6d336 in ?? () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#7  0x00007f8941b7a5e9 in scm_call_n () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#8  0x00007f8941ae209a in scm_call_2 () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#9  0x00007f8941b98752 in ?? () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#10 0x00007f8941b6a88f in scm_c_catch () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#11 0x00007f8941ae2e66 in scm_c_with_continuation_barrier () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#12 0x00007f8941b69b39 in ?? () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#13 0x00007f8941a400ba in GC_call_with_stack_base () from /gnu/store/2lczkxbdbzh4gk7wh91bzrqrk7h5g1dl-libgc-8.0.4/lib/libgc.so.1
#14 0x00007f8941b628b8 in scm_with_guile () from /gnu/store/1jgcbdzx2ss6xv59w55g3kr3x4935dfb-guile-3.0.8/lib/libguile-3.0.so.1
#15 0x00007f8941a16d7e in ?? () from /gnu/store/5h2w4qi9hk1qzzgi1w83220ydslinr4s-glibc-2.33/lib/libpthread.so.0
#16 0x00007f8941614eff in clone () from /gnu/store/5h2w4qi9hk1qzzgi1w83220ydslinr4s-glibc-2.33/lib/libc.so.6
--8<---------------cut here---------------end--------------->8---

linux_destroy is the PedDevice destruction function. The crash occurs
when dereferencing the arch_specific pointer which is ...

--8<---------------cut here---------------start------------->8---
(gdb) p dev
$1 = (PedDevice *) 0x1dc89e0
(gdb) p *dev
$2 = {next = 0x1, model = 0x1645d50 "", path = 0x0, type = PED_DEVICE_UNKNOWN, sector_size = 0, phys_sector_size = 1, length = 23272720, open_count = 0, read_only = 1, external_mode = 0, dirty = 0, boot_dirty = 0, hw_geom = {
    cylinders = 0, heads = 2, sectors = 0}, bios_geom = {cylinders = 23259184, heads = 0, sectors = 0}, host = 1, did = 0, arch_specific = 0x0}
(gdb) p dev->arch_specific 
$3 = (void *) 0x0
--8<---------------cut here---------------end--------------->8---

null! I guess this has to deal with device pointer finalizers. I'm a bit
disappointed because I thought we had overcome those mistakes.

Thanks,

Mathieu




^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-10-23  9:07 bug#58732: installer: finalizers & device destroy segfault Mathieu Othacehe
@ 2022-11-02 10:55 ` Ludovic Courtès
  2022-11-03 11:09   ` Mathieu Othacehe
  0 siblings, 1 reply; 10+ messages in thread
From: Ludovic Courtès @ 2022-11-02 10:55 UTC (permalink / raw)
  To: Mathieu Othacehe; +Cc: 58732

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

> null! I guess this has to deal with device pointer finalizers. I'm a bit
> disappointed because I thought we had overcome those mistakes.

There are several things we should audit in Guile-Parted regarding
object lifecycles.

Common issues when writing bindings that could cause problems like what
you report:

  1. Bindings create wrappers for C pointers—e.g., with
     ‘pointer->device’.  If several C functions return a pointer P, you
     must make sure to return always the same wrapper and not create a
     new one.

     ‘pointer->device!’ attempts to do that but I think it’s bogus: it
     uses a weak-value hash table, where the value is the wrapper.  So
     if the wrapper disappears before the underlying C object, then the
     pointer is called and bad things ensue.

     ‘define-wrapped-pointer-type’ in Guile is meant to help with these
     things (info "(guile) Void Pointers and Byte Access").  We can’t
     use it directly here because we’re using bytestructures and all
     that.

  2. Scheme wrappers must mirror the aggregation relations of the C
     objects they wrap.

     For instance, let’s say a PedDisk aggregates PedPartition
     objects—i.e., that PedDisk “owns” them and outlives them.  Then the
     Scheme <disk> wrappers must outlive the Scheme <partition> wrappers
     too, so that we don’t end up calling partition finalizers while the
     disk that owns them is still alive.  This is done using a weak-key
     hash table keyed by <disk> objects in this case and populated
     anytime a <disk> getter returns a <partition>.  (See for example
     ‘%commit-owners’ in Guile-Git.)

I think we should audit Guile-Parted with these issues in mind.

WDYT?

Ludo’.




^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-02 10:55 ` Ludovic Courtès
@ 2022-11-03 11:09   ` Mathieu Othacehe
  2022-11-03 11:25     ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Mathieu Othacehe @ 2022-11-03 11:09 UTC (permalink / raw)
  To: Ludovic Courtès; +Cc: 58732


Hey,

Thanks for your help :)

>   1. Bindings create wrappers for C pointers—e.g., with
>      ‘pointer->device’.  If several C functions return a pointer P, you
>      must make sure to return always the same wrapper and not create a
>      new one.

Agreed.

>
>      ‘pointer->device!’ attempts to do that but I think it’s bogus: it
>      uses a weak-value hash table, where the value is the wrapper.  So
>      if the wrapper disappears before the underlying C object, then the
>      pointer is called and bad things ensue.

I'm not sure to understand how could the wrapper disappear before the
underlying C object? We are only exposing <device> records to the
Guile-Parted users so my assumption is that when <device> goes out of
scope, the pointer it wraps can be freed, but I'm maybe missing
something?

>      ‘define-wrapped-pointer-type’ in Guile is meant to help with these
>      things (info "(guile) Void Pointers and Byte Access").  We can’t
>      use it directly here because we’re using bytestructures and all
>      that.

Turns out, the "wrap" procedure defined in define-wrapped-pointer-type
is a clone of pointer->device! except that it doesn't set a
finalizer.

Regarding object lifetime, I wrote a small memo in 2019 here:
https://issues.guix.gnu.org/36402#11.

We have three weak hash tables in Guile-Parted:

%devices: To make sure that we do not set multiple finalizers on the
same pointers.

%disk-devices: So that a device always outlives its disks.

%partition-disks: So that a disk always outlives its partitions.

This means that as far as I can tell we are OK regarding your second
point about "aggregation relations".

Mathieu




^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-03 11:09   ` Mathieu Othacehe
@ 2022-11-03 11:25     ` Ludovic Courtès
  2022-11-06 17:17       ` Mathieu Othacehe
  0 siblings, 1 reply; 10+ messages in thread
From: Ludovic Courtès @ 2022-11-03 11:25 UTC (permalink / raw)
  To: Mathieu Othacehe; +Cc: 58732

Hi!

Mathieu Othacehe <othacehe@gnu.org> skribis:

>>      ‘pointer->device!’ attempts to do that but I think it’s bogus: it
>>      uses a weak-value hash table, where the value is the wrapper.  So
>>      if the wrapper disappears before the underlying C object, then the
>>      pointer is called and bad things ensue.
>
> I'm not sure to understand how could the wrapper disappear before the
> underlying C object? We are only exposing <device> records to the
> Guile-Parted users so my assumption is that when <device> goes out of
> scope, the pointer it wraps can be freed, but I'm maybe missing
> something?

Hmm you’re right (and yes it’s the same as ‘define-wrapped-pointer-type’
does).  So that should be fine.

> Regarding object lifetime, I wrote a small memo in 2019 here:
> https://issues.guix.gnu.org/36402#11.

Nice, though it does feel like we’re running in circles.  :-)

> We have three weak hash tables in Guile-Parted:
>
> %devices: To make sure that we do not set multiple finalizers on the
> same pointers.
>
> %disk-devices: So that a device always outlives its disks.
>
> %partition-disks: So that a disk always outlives its partitions.
>
> This means that as far as I can tell we are OK regarding your second
> point about "aggregation relations".

OK.

Another thing to keep in mind: finalizers run in a separate thread, so
finalization can happen concurrently.  That can be problematic is there
is shared global state in the library that’s being access when an
benign-looking free function is called.

Could you show the backtrace of the other threads as well, preferably
with debugging info?

Thanks,
Ludo’.




^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-03 11:25     ` Ludovic Courtès
@ 2022-11-06 17:17       ` Mathieu Othacehe
  2022-11-07 13:29         ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Mathieu Othacehe @ 2022-11-06 17:17 UTC (permalink / raw)
  To: Ludovic Courtès; +Cc: 58732

[-- Attachment #1: Type: text/plain, Size: 1447 bytes --]


Hey,

I made some progress on that one. I think, this is what's going on:

1. Two new PedDevice A and B are malloc'ed by the libparted when opening
the installer partitioning page.

2. They are added to the %devices weak hash table by pointer->device!
and their respective finalizers are registered.

3. The partitioning ends and A goes out of scope. It is eventually
removed from %devices but it does not mean its finalizer will be run
immediately.

4. The partitioning is restarted using the installer menu. B is still in
the %devices hash table. However, A is now gone and is added again to
the %devices hash table by the pointer->device! procedure. Another
finalizer is registered for A.

That's because set-pointer-finalizer! does not *set* a finalizer it
*adds* one.

5. The partitioning ends and both A and B goes out of scope. They are
removed from %devices and their finalizers are called. The A finalizer
is called twice resulting in a double free.

This race condition is created by the fact that there is a time window
where the device is removed from the %devices hash table but its
finalizer is not immediately called.

If set-pointer-finalizer! actually called scm_i_set_finalizer instead of
scm_i_add_finalizer the A finalizer would be set twice but called only
once. Do you think it would be an option?

I attached the instrumentation patches (good old printf's) as well as
the syslog I based my analysis upon.

Thanks,

Mathieu

[-- Attachment #2: diff_guix.txt --]
[-- Type: text/plain, Size: 501 bytes --]

diff --git a/gnu/installer/parted.scm b/gnu/installer/parted.scm
index 82375d29e3..381e1b3ce7 100644
--- a/gnu/installer/parted.scm
+++ b/gnu/installer/parted.scm
@@ -1502,6 +1502,7 @@ (define (user-partitions->configuration user-partitions)
 
 (define (init-parted)
   "Initialize libparted support."
+  (%parted-syslog-port (syslog-port))
   (probe-all-devices!)
   ;; Remove all logical devices, otherwise "device-is-busy?" will report true
   ;; on all devices containaing active logical volumes.

[-- Attachment #3: diff_parted.txt --]
[-- Type: text/plain, Size: 1319 bytes --]

diff -aur parted/libparted/arch/linux.c tmp/parted-3.5/libparted/arch/linux.c
--- parted/libparted/arch/linux.c	2022-11-04 10:14:33.551737324 +0100
+++ tmp/parted-3.5/libparted/arch/linux.c	2022-04-18 20:38:45.000000000 +0200
@@ -17,7 +17,6 @@
 
 #define PROC_DEVICES_BUFSIZ 16384
 
-#include <syslog.h>
 #include <config.h>
 #include <arch/linux.h>
 #include <linux/blkpg.h>
@@ -44,7 +43,6 @@
 #include <assert.h>
 #include <sys/sysmacros.h>
 #ifdef ENABLE_DEVICE_MAPPER
-
 #include <libdevmapper.h>
 #endif
 
@@ -89,8 +87,6 @@
 #define WR_MODE (O_WRONLY)
 #define RW_MODE (O_RDWR)
 
-int syslog_init;
-
 struct hd_geometry {
         unsigned char heads;
         unsigned char sectors;
@@ -1600,11 +1596,6 @@
                                 _("ped_device_new()  Unsupported device type"));
                 goto error_free_arch_specific;
         }
-        if (!syslog_init) {
-                openlog("parted", LOG_PID, LOG_USER);
-                syslog_init = 1;
-        }
-        syslog(LOG_INFO, "parted: new: %p\n", dev);
         return dev;
 
 error_free_arch_specific:
@@ -1620,8 +1611,6 @@
 static void
 linux_destroy (PedDevice* dev)
 {
-        syslog(LOG_INFO, "parted: destroy: %p\n", dev);
-
         LinuxSpecific *arch_specific = LINUX_SPECIFIC(dev);
         void *p = arch_specific->dmtype;
 

[-- Attachment #4: diff_guile_parted.txt --]
[-- Type: text/plain, Size: 1830 bytes --]

diff --git a/parted/device.scm b/parted/device.scm
index 9f688dd..36d83f4 100644
--- a/parted/device.scm
+++ b/parted/device.scm
@@ -23,7 +23,7 @@
   #:use-module (parted geom)
   #:use-module (parted natmath)
   #:use-module (parted structs)
-  #:export (parted-syslog-port
+  #:export (%parted-syslog-port
             probe-all-devices!
             get-device
             get-device-next
@@ -44,8 +44,8 @@
             device-get-minimum-alignment
             device-get-optimum-alignment))
 
-(define parted-syslog-port
-  (make-parameter #f))
+(define %parted-syslog-port
+  (make-parameter #t))
 
 ;; Record all devices, so that pointer finalizers are only set once,
 ;; even if get-device returns an already known pointer.  Use the
@@ -58,22 +58,22 @@
 (define (pointer->device! pointer)
   ;; Check if a finalizer is already registered for this pointer.
   (format (%parted-syslog-port)
-          "guile-parted: pointer->device!: ~a" pointer)
+          "guile-parted: pointer->device!: ~a~%" pointer)
 
   (format (%parted-syslog-port)
-          "guile-parted: hash begin")
+          "guile-parted: hash begin~%")
   (hash-for-each (lambda (k v)
                    (format (%parted-syslog-port)
-                           "guile-parted: hash: ~a -> ~a" k v))
+                           "guile-parted: hash: ~a -> ~a~%" k v))
                  %devices)
   (format (%parted-syslog-port)
-          "guile-parted: hash end")
+          "guile-parted: hash end~%")
 
   (or (hash-ref %devices pointer)
       (let ((device (pointer->device pointer)))
 
         (format (%parted-syslog-port)
-          "guile-parted: finalizer!: ~a" pointer)
+          "guile-parted: finalizer!: ~a~%" pointer)
 
         ;; Contrary to its name, this "adds" a finalizer.
         (set-pointer-finalizer! pointer %device-destroy)

[-- Attachment #5: messages --]
[-- Type: application/octet-stream, Size: 89238 bytes --]

Nov  6 13:01:22 localhost syslogd (GNU inetutils 2.0): restart
Nov  6 13:01:22 localhost vmunix: [    0.000000] Linux version 5.19.17-gnu (guix@guix) (gcc (GCC) 10.3.0, GNU ld (GNU Binutils) 2.37) #1 SMP PREEMPT_DYNAMIC 1
Nov  6 13:01:22 localhost vmunix: [    0.000000] Command line: BOOT_IMAGE=/gnu/store/z2fcr22r752g2smwhy677bqfqmr8vjk0-linux-libre-5.19.17/bzImage root=31393730-3031-3031-3139-333333313833 gnu.system=/gnu/store/pngj02ak7gfa56qnjvbj9hm7vdmw6yca-system gnu.load=/gnu/store/pngj02ak7gfa56qnjvbj9hm7vdmw6yca-system/boot quiet modprobe.blacklist=radeon,amdgpu
Nov  6 13:01:22 localhost vmunix: [    0.000000] KERNEL supported cpus:
Nov  6 13:01:22 localhost vmunix: [    0.000000]   Intel GenuineIntel
Nov  6 13:01:22 localhost vmunix: [    0.000000]   AMD AuthenticAMD
Nov  6 13:01:22 localhost vmunix: [    0.000000]   Hygon HygonGenuine
Nov  6 13:01:22 localhost vmunix: [    0.000000]   Centaur CentaurHauls
Nov  6 13:01:22 localhost vmunix: [    0.000000]   zhaoxin   Shanghai  
Nov  6 13:01:22 localhost vmunix: [    0.000000] x86/fpu: x87 FPU will use FXSAVE
Nov  6 13:01:22 localhost vmunix: [    0.000000] signal: max sigframe size: 1440
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-provided physical RAM map:
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000007fffff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000800000-0x0000000000807fff] ACPI NVS
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000808000-0x000000000080ffff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000810000-0x0000000000817fff] ACPI NVS
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000818000-0x000000000081ffff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000820000-0x00000000008fffff] ACPI NVS
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x0000000000900000-0x000000007ecc0fff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ecc1000-0x000000007ecc1fff] ACPI data
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ecc2000-0x000000007ed69fff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ed6a000-0x000000007ed76fff] ACPI NVS
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ed77000-0x000000007ed8dfff] reserved
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ed8e000-0x000000007eda7fff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007eda8000-0x000000007edc7fff] reserved
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007edc8000-0x000000007fe47fff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007fe48000-0x000000007fe77fff] type 20
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007fe78000-0x000000007fe9ffff] reserved
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007fea0000-0x000000007fea7fff] ACPI data
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007fea8000-0x000000007feabfff] ACPI NVS
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007feac000-0x000000007ff4ffff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ff50000-0x000000007ff6ffff] reserved
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ff70000-0x000000007ff77fff] usable
Nov  6 13:01:22 localhost vmunix: [    0.000000] BIOS-e820: [mem 0x000000007ff78000-0x000000007fffffff] ACPI NVS
Nov  6 13:01:22 localhost vmunix: [    0.000000] NX (Execute Disable) protection: active
Nov  6 13:01:22 localhost vmunix: [    0.000000] efi: EFI v2.60 by EDK II
Nov  6 13:01:22 localhost vmunix: [    0.000000] efi: SMBIOS=0x7fe79000 ACPI=0x7fea7000 ACPI 2.0=0x7fea7014 MEMATTR=0x7f050018 
Nov  6 13:01:22 localhost vmunix: [    0.000000] SMBIOS 2.8 present.
Nov  6 13:01:22 localhost vmunix: [    0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 0.0.0 02/06/2015
Nov  6 13:01:22 localhost vmunix: [    0.000000] Hypervisor detected: KVM
Nov  6 13:01:22 localhost vmunix: [    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
Nov  6 13:01:22 localhost vmunix: [    0.000001] kvm-clock: using sched offset of 18812543689 cycles
Nov  6 13:01:22 localhost vmunix: [    0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
Nov  6 13:01:22 localhost vmunix: [    0.000005] tsc: Detected 1804.800 MHz processor
Nov  6 13:01:22 localhost vmunix: [    0.000096] last_pfn = 0x7ff78 max_arch_pfn = 0x400000000
Nov  6 13:01:22 localhost vmunix: [    0.000141] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
Nov  6 13:01:22 localhost vmunix: [    0.009606] Secure boot disabled
Nov  6 13:01:22 localhost vmunix: [    0.009608] RAMDISK: [mem 0x36685000-0x37339fff]
Nov  6 13:01:22 localhost vmunix: [    0.009615] ACPI: Early table checksum verification disabled
Nov  6 13:01:22 localhost vmunix: [    0.009620] ACPI: RSDP 0x000000007FEA7014 000024 (v02 BOCHS )
Nov  6 13:01:22 localhost vmunix: [    0.009623] ACPI: XSDT 0x000000007FEA60E8 00004C (v01 BOCHS  BXPC     00000001      01000013)
Nov  6 13:01:22 localhost vmunix: [    0.009627] ACPI: FACP 0x000000007FEA3000 000074 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
Nov  6 13:01:22 localhost vmunix: [    0.009632] ACPI: DSDT 0x000000007FEA4000 00176A (v01 BOCHS  BXPC     00000001 BXPC 00000001)
Nov  6 13:01:22 localhost vmunix: [    0.009634] ACPI: FACS 0x000000007FEAA000 000040
Nov  6 13:01:22 localhost vmunix: [    0.009636] ACPI: APIC 0x000000007FEA2000 000078 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
Nov  6 13:01:22 localhost vmunix: [    0.009639] ACPI: HPET 0x000000007FEA1000 000038 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
Nov  6 13:01:22 localhost vmunix: [    0.009641] ACPI: WAET 0x000000007FEA0000 000028 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
Nov  6 13:01:22 localhost vmunix: [    0.009645] ACPI: BGRT 0x000000007ECC1000 000038 (v01 INTEL  EDK2     00000002      01000013)
Nov  6 13:01:22 localhost vmunix: [    0.009646] ACPI: Reserving FACP table memory at [mem 0x7fea3000-0x7fea3073]
Nov  6 13:01:22 localhost vmunix: [    0.009647] ACPI: Reserving DSDT table memory at [mem 0x7fea4000-0x7fea5769]
Nov  6 13:01:22 localhost vmunix: [    0.009648] ACPI: Reserving FACS table memory at [mem 0x7feaa000-0x7feaa03f]
Nov  6 13:01:22 localhost vmunix: [    0.009649] ACPI: Reserving APIC table memory at [mem 0x7fea2000-0x7fea2077]
Nov  6 13:01:22 localhost vmunix: [    0.009649] ACPI: Reserving HPET table memory at [mem 0x7fea1000-0x7fea1037]
Nov  6 13:01:22 localhost vmunix: [    0.009650] ACPI: Reserving WAET table memory at [mem 0x7fea0000-0x7fea0027]
Nov  6 13:01:22 localhost vmunix: [    0.009650] ACPI: Reserving BGRT table memory at [mem 0x7ecc1000-0x7ecc1037]
Nov  6 13:01:22 localhost vmunix: [    0.009819] No NUMA configuration found
Nov  6 13:01:22 localhost vmunix: [    0.009819] Faking a node at [mem 0x0000000000000000-0x000000007ff77fff]
Nov  6 13:01:22 localhost vmunix: [    0.009823] NODE_DATA(0) allocated [mem 0x7ff73000-0x7ff77fff]
Nov  6 13:01:22 localhost vmunix: [    0.009838] Zone ranges:
Nov  6 13:01:22 localhost vmunix: [    0.009838]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
Nov  6 13:01:22 localhost vmunix: [    0.009840]   DMA32    [mem 0x0000000001000000-0x000000007ff77fff]
Nov  6 13:01:22 localhost vmunix: [    0.009841]   Normal   empty
Nov  6 13:01:22 localhost vmunix: [    0.009841]   Device   empty
Nov  6 13:01:22 localhost vmunix: [    0.009842] Movable zone start for each node
Nov  6 13:01:22 localhost vmunix: [    0.009843] Early memory node ranges
Nov  6 13:01:22 localhost vmunix: [    0.009843]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
Nov  6 13:01:22 localhost vmunix: [    0.009844]   node   0: [mem 0x0000000000100000-0x00000000007fffff]
Nov  6 13:01:22 localhost vmunix: [    0.009844]   node   0: [mem 0x0000000000808000-0x000000000080ffff]
Nov  6 13:01:22 localhost vmunix: [    0.009845]   node   0: [mem 0x0000000000818000-0x000000000081ffff]
Nov  6 13:01:22 localhost vmunix: [    0.009845]   node   0: [mem 0x0000000000900000-0x000000007ecc0fff]
Nov  6 13:01:22 localhost vmunix: [    0.009846]   node   0: [mem 0x000000007ecc2000-0x000000007ed69fff]
Nov  6 13:01:22 localhost vmunix: [    0.009846]   node   0: [mem 0x000000007ed8e000-0x000000007eda7fff]
Nov  6 13:01:22 localhost vmunix: [    0.009847]   node   0: [mem 0x000000007edc8000-0x000000007fe47fff]
Nov  6 13:01:22 localhost vmunix: [    0.009847]   node   0: [mem 0x000000007feac000-0x000000007ff4ffff]
Nov  6 13:01:22 localhost vmunix: [    0.009848]   node   0: [mem 0x000000007ff70000-0x000000007ff77fff]
Nov  6 13:01:22 localhost vmunix: [    0.009849] Initmem setup node 0 [mem 0x0000000000001000-0x000000007ff77fff]
Nov  6 13:01:22 localhost vmunix: [    0.010102] On node 0, zone DMA: 1 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.010110] On node 0, zone DMA: 96 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.010110] On node 0, zone DMA: 8 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.010111] On node 0, zone DMA: 8 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.010117] On node 0, zone DMA: 224 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015007] On node 0, zone DMA32: 1 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015009] On node 0, zone DMA32: 36 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015027] On node 0, zone DMA32: 32 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015028] On node 0, zone DMA32: 100 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015029] On node 0, zone DMA32: 32 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015030] On node 0, zone DMA32: 136 pages in unavailable ranges
Nov  6 13:01:22 localhost vmunix: [    0.015251] ACPI: PM-Timer IO Port: 0xb008
Nov  6 13:01:22 localhost vmunix: [    0.015261] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
Nov  6 13:01:22 localhost vmunix: [    0.015290] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
Nov  6 13:01:22 localhost vmunix: [    0.015293] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
Nov  6 13:01:22 localhost vmunix: [    0.015294] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
Nov  6 13:01:22 localhost vmunix: [    0.015295] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
Nov  6 13:01:22 localhost vmunix: [    0.015295] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
Nov  6 13:01:22 localhost vmunix: [    0.015296] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
Nov  6 13:01:22 localhost vmunix: [    0.015299] ACPI: Using ACPI (MADT) for SMP configuration information
Nov  6 13:01:22 localhost vmunix: [    0.015300] ACPI: HPET id: 0x8086a201 base: 0xfed00000
Nov  6 13:01:22 localhost vmunix: [    0.015324] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
Nov  6 13:01:22 localhost vmunix: [    0.015352] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
Nov  6 13:01:22 localhost vmunix: [    0.015354] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000fffff]
Nov  6 13:01:22 localhost vmunix: [    0.015355] PM: hibernation: Registered nosave memory: [mem 0x00800000-0x00807fff]
Nov  6 13:01:22 localhost vmunix: [    0.015356] PM: hibernation: Registered nosave memory: [mem 0x00810000-0x00817fff]
Nov  6 13:01:22 localhost vmunix: [    0.015358] PM: hibernation: Registered nosave memory: [mem 0x00820000-0x008fffff]
Nov  6 13:01:22 localhost vmunix: [    0.015359] PM: hibernation: Registered nosave memory: [mem 0x7ecc1000-0x7ecc1fff]
Nov  6 13:01:22 localhost vmunix: [    0.015360] PM: hibernation: Registered nosave memory: [mem 0x7ed6a000-0x7ed76fff]
Nov  6 13:01:22 localhost vmunix: [    0.015361] PM: hibernation: Registered nosave memory: [mem 0x7ed77000-0x7ed8dfff]
Nov  6 13:01:22 localhost vmunix: [    0.015362] PM: hibernation: Registered nosave memory: [mem 0x7eda8000-0x7edc7fff]
Nov  6 13:01:22 localhost vmunix: [    0.015363] PM: hibernation: Registered nosave memory: [mem 0x7ee33000-0x7ee3bfff]
Nov  6 13:01:22 localhost vmunix: [    0.015365] PM: hibernation: Registered nosave memory: [mem 0x7fe48000-0x7fe77fff]
Nov  6 13:01:22 localhost vmunix: [    0.015365] PM: hibernation: Registered nosave memory: [mem 0x7fe78000-0x7fe9ffff]
Nov  6 13:01:22 localhost vmunix: [    0.015366] PM: hibernation: Registered nosave memory: [mem 0x7fea0000-0x7fea7fff]
Nov  6 13:01:22 localhost vmunix: [    0.015366] PM: hibernation: Registered nosave memory: [mem 0x7fea8000-0x7feabfff]
Nov  6 13:01:22 localhost vmunix: [    0.015367] PM: hibernation: Registered nosave memory: [mem 0x7ff50000-0x7ff6ffff]
Nov  6 13:01:22 localhost vmunix: [    0.015368] [mem 0x80000000-0xffffffff] available for PCI devices
Nov  6 13:01:22 localhost vmunix: [    0.015369] Booting paravirtualized kernel on KVM
Nov  6 13:01:22 localhost vmunix: [    0.015371] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
Nov  6 13:01:22 localhost vmunix: [    0.015379] setup_percpu: NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:1 nr_node_ids:1
Nov  6 13:01:22 localhost vmunix: [    0.015459] percpu: Embedded 57 pages/cpu s193576 r8192 d31704 u2097152
Nov  6 13:01:22 localhost vmunix: [    0.015491] kvm-guest: PV spinlocks disabled, no host support
Nov  6 13:01:22 localhost vmunix: [    0.015493] Fallback order for Node 0: 0 
Nov  6 13:01:22 localhost vmunix: [    0.015495] Built 1 zonelists, mobility grouping on.  Total pages: 513478
Nov  6 13:01:22 localhost vmunix: [    0.015496] Policy zone: DMA32
Nov  6 13:01:22 localhost vmunix: [    0.015496] Kernel command line: BOOT_IMAGE=/gnu/store/z2fcr22r752g2smwhy677bqfqmr8vjk0-linux-libre-5.19.17/bzImage root=31393730-3031-3031-3139-333333313833 gnu.system=/gnu/store/pngj02ak7gfa56qnjvbj9hm7vdmw6yca-system gnu.load=/gnu/store/pngj02ak7gfa56qnjvbj9hm7vdmw6yca-system/boot quiet modprobe.blacklist=radeon,amdgpu
Nov  6 13:01:22 localhost vmunix: [    0.015554] Unknown kernel command line parameters "BOOT_IMAGE=/gnu/store/z2fcr22r752g2smwhy677bqfqmr8vjk0-linux-libre-5.19.17/bzImage", will be passed to user space.
Nov  6 13:01:22 localhost vmunix: [    0.015611] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.015645] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.015673] mem auto-init: stack:byref_all(zero), heap alloc:on, heap free:off
Nov  6 13:01:22 localhost vmunix: [    0.018291] Memory: 1996128K/2094456K available (16392K kernel code, 2733K rwdata, 5224K rodata, 2716K init, 2588K bss, 98068K reserved, 0K cma-reserved)
Nov  6 13:01:22 localhost vmunix: [    0.018452] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Nov  6 13:01:22 localhost vmunix: [    0.018461] Kernel/User page tables isolation: enabled
Nov  6 13:01:22 localhost vmunix: [    0.018469] ftrace: allocating 46629 entries in 183 pages
Nov  6 13:01:22 localhost vmunix: [    0.024612] ftrace: allocated 183 pages with 6 groups
Nov  6 13:01:22 localhost vmunix: [    0.025220] Dynamic Preempt: voluntary
Nov  6 13:01:22 localhost vmunix: [    0.025445] rcu: Preemptible hierarchical RCU implementation.
Nov  6 13:01:22 localhost vmunix: [    0.025446] rcu: 	RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=1.
Nov  6 13:01:22 localhost vmunix: [    0.025447] 	Trampoline variant of Tasks RCU enabled.
Nov  6 13:01:22 localhost vmunix: [    0.025447] 	Rude variant of Tasks RCU enabled.
Nov  6 13:01:22 localhost vmunix: [    0.025447] 	Tracing variant of Tasks RCU enabled.
Nov  6 13:01:22 localhost vmunix: [    0.025448] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
Nov  6 13:01:22 localhost vmunix: [    0.025448] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
Nov  6 13:01:22 localhost vmunix: [    0.028556] NR_IRQS: 16640, nr_irqs: 256, preallocated irqs: 16
Nov  6 13:01:22 localhost vmunix: [    0.028718] rcu: srcu_init: Setting srcu_struct sizes based on contention.
Nov  6 13:01:22 localhost vmunix: [    0.028747] Console: colour dummy device 80x25
Nov  6 13:01:22 localhost vmunix: [    0.028758] printk: console [tty0] enabled
Nov  6 13:01:22 localhost vmunix: [    0.028771] ACPI: Core revision 20220331
Nov  6 13:01:22 localhost vmunix: [    0.028880] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
Nov  6 13:01:22 localhost vmunix: [    0.028948] APIC: Switch to symmetric I/O mode setup
Nov  6 13:01:22 localhost vmunix: [    0.029088] x2apic enabled
Nov  6 13:01:22 localhost vmunix: [    0.029245] Switched APIC routing to physical x2apic.
Nov  6 13:01:22 localhost vmunix: [    0.030218] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
Nov  6 13:01:22 localhost vmunix: [    0.030234] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1a03dfe73b3, max_idle_ns: 440795256845 ns
Nov  6 13:01:22 localhost vmunix: [    0.030239] Calibrating delay loop (skipped) preset value.. 3609.60 BogoMIPS (lpj=7219200)
Nov  6 13:01:22 localhost vmunix: [    0.030241] pid_max: default: 32768 minimum: 301
Nov  6 13:01:22 localhost vmunix: [    0.030881] LSM: Security Framework initializing
Nov  6 13:01:22 localhost vmunix: [    0.030889] Yama: becoming mindful.
Nov  6 13:01:22 localhost vmunix: [    0.030910] AppArmor: AppArmor initialized
Nov  6 13:01:22 localhost vmunix: [    0.030912] TOMOYO Linux initialized
Nov  6 13:01:22 localhost vmunix: [    0.030946] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.030949] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.031227] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
Nov  6 13:01:22 localhost vmunix: [    0.031228] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
Nov  6 13:01:22 localhost vmunix: [    0.031231] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
Nov  6 13:01:22 localhost vmunix: [    0.031232] Spectre V2 : Mitigation: Retpolines
Nov  6 13:01:22 localhost vmunix: [    0.031233] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
Nov  6 13:01:22 localhost vmunix: [    0.031233] Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT
Nov  6 13:01:22 localhost vmunix: [    0.031234] Speculative Store Bypass: Vulnerable
Nov  6 13:01:22 localhost vmunix: [    0.031236] MDS: Vulnerable: Clear CPU buffers attempted, no microcode
Nov  6 13:01:22 localhost vmunix: [    0.031237] MMIO Stale Data: Unknown: No mitigations
Nov  6 13:01:22 localhost vmunix: [    0.051688] Freeing SMP alternatives memory: 40K
Nov  6 13:01:22 localhost vmunix: [    0.159837] smpboot: CPU0: Intel QEMU Virtual CPU version 2.5+ (family: 0xf, model: 0x6b, stepping: 0x1)
Nov  6 13:01:22 localhost vmunix: [    0.159942] cblist_init_generic: Setting adjustable number of callback queues.
Nov  6 13:01:22 localhost vmunix: [    0.159943] cblist_init_generic: Setting shift to 0 and lim to 1.
Nov  6 13:01:22 localhost vmunix: [    0.159952] cblist_init_generic: Setting shift to 0 and lim to 1.
Nov  6 13:01:22 localhost vmunix: [    0.159961] cblist_init_generic: Setting shift to 0 and lim to 1.
Nov  6 13:01:22 localhost vmunix: [    0.159972] Performance Events: unsupported Netburst CPU model 107 no PMU driver, software events only.
Nov  6 13:01:22 localhost vmunix: [    0.160016] rcu: Hierarchical SRCU implementation.
Nov  6 13:01:22 localhost vmunix: [    0.160016] rcu: 	Max phase no-delay instances is 1000.
Nov  6 13:01:22 localhost vmunix: [    0.160320] NMI watchdog: Perf NMI watchdog permanently disabled
Nov  6 13:01:22 localhost vmunix: [    0.160354] smp: Bringing up secondary CPUs ...
Nov  6 13:01:22 localhost vmunix: [    0.160355] smp: Brought up 1 node, 1 CPU
Nov  6 13:01:22 localhost vmunix: [    0.160356] smpboot: Max logical packages: 1
Nov  6 13:01:22 localhost vmunix: [    0.160357] smpboot: Total of 1 processors activated (3609.60 BogoMIPS)
Nov  6 13:01:22 localhost vmunix: [    0.160555] devtmpfs: initialized
Nov  6 13:01:22 localhost vmunix: [    0.160592] x86/mm: Memory block size: 128MB
Nov  6 13:01:22 localhost vmunix: [    0.160796] ACPI: PM: Registering ACPI NVS region [mem 0x00800000-0x00807fff] (32768 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.160797] ACPI: PM: Registering ACPI NVS region [mem 0x00810000-0x00817fff] (32768 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.160798] ACPI: PM: Registering ACPI NVS region [mem 0x00820000-0x008fffff] (917504 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.160807] ACPI: PM: Registering ACPI NVS region [mem 0x7ed6a000-0x7ed76fff] (53248 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.160809] ACPI: PM: Registering ACPI NVS region [mem 0x7fea8000-0x7feabfff] (16384 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.160810] ACPI: PM: Registering ACPI NVS region [mem 0x7ff78000-0x7fffffff] (557056 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.160841] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Nov  6 13:01:22 localhost vmunix: [    0.160846] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.160876] pinctrl core: initialized pinctrl subsystem
Nov  6 13:01:22 localhost vmunix: [    0.160973] PM: RTC time: 12:01:15, date: 2022-11-06
Nov  6 13:01:22 localhost vmunix: [    0.161067] NET: Registered PF_NETLINK/PF_ROUTE protocol family
Nov  6 13:01:22 localhost vmunix: [    0.161120] audit: initializing netlink subsys (disabled)
Nov  6 13:01:22 localhost vmunix: [    0.161200] thermal_sys: Registered thermal governor 'fair_share'
Nov  6 13:01:22 localhost vmunix: [    0.161200] thermal_sys: Registered thermal governor 'bang_bang'
Nov  6 13:01:22 localhost vmunix: [    0.161201] thermal_sys: Registered thermal governor 'step_wise'
Nov  6 13:01:22 localhost vmunix: [    0.161201] thermal_sys: Registered thermal governor 'user_space'
Nov  6 13:01:22 localhost vmunix: [    0.161203] cpuidle: using governor ladder
Nov  6 13:01:22 localhost vmunix: [    0.161204] cpuidle: using governor menu
Nov  6 13:01:22 localhost vmunix: [    0.161240] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
Nov  6 13:01:22 localhost vmunix: [    0.161313] PCI: Using configuration type 1 for base access
Nov  6 13:01:22 localhost vmunix: [    0.162128] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
Nov  6 13:01:22 localhost vmunix: [    0.162141] audit: type=2000 audit(1667736076.143:1): state=initialized audit_enabled=0 res=1
Nov  6 13:01:22 localhost vmunix: [    0.180489] HugeTLB: can optimize 7 vmemmap pages for hugepages-2048kB
Nov  6 13:01:22 localhost vmunix: [    0.180492] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
Nov  6 13:01:22 localhost vmunix: [    0.180700] ACPI: Added _OSI(Module Device)
Nov  6 13:01:22 localhost vmunix: [    0.180700] ACPI: Added _OSI(Processor Device)
Nov  6 13:01:22 localhost vmunix: [    0.180701] ACPI: Added _OSI(3.0 _SCP Extensions)
Nov  6 13:01:22 localhost vmunix: [    0.180702] ACPI: Added _OSI(Processor Aggregator Device)
Nov  6 13:01:22 localhost vmunix: [    0.180702] ACPI: Added _OSI(Linux-Dell-Video)
Nov  6 13:01:22 localhost vmunix: [    0.180703] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
Nov  6 13:01:22 localhost vmunix: [    0.180704] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
Nov  6 13:01:22 localhost vmunix: [    0.181028] ACPI: 1 ACPI AML tables successfully acquired and loaded
Nov  6 13:01:22 localhost vmunix: [    0.181565] ACPI: Interpreter enabled
Nov  6 13:01:22 localhost vmunix: [    0.181575] ACPI: PM: (supports S0 S3 S4 S5)
Nov  6 13:01:22 localhost vmunix: [    0.181576] ACPI: Using IOAPIC for interrupt routing
Nov  6 13:01:22 localhost vmunix: [    0.181585] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
Nov  6 13:01:22 localhost vmunix: [    0.181585] PCI: Using E820 reservations for host bridge windows
Nov  6 13:01:22 localhost vmunix: [    0.181638] ACPI: Enabled 2 GPEs in block 00 to 0F
Nov  6 13:01:22 localhost vmunix: [    0.182985] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
Nov  6 13:01:22 localhost vmunix: [    0.182989] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
Nov  6 13:01:22 localhost vmunix: [    0.182991] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI]
Nov  6 13:01:22 localhost vmunix: [    0.182996] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
Nov  6 13:01:22 localhost vmunix: [    0.183131] acpiphp: Slot [3] registered
Nov  6 13:01:22 localhost vmunix: [    0.183141] acpiphp: Slot [4] registered
Nov  6 13:01:22 localhost vmunix: [    0.183149] acpiphp: Slot [5] registered
Nov  6 13:01:22 localhost vmunix: [    0.183157] acpiphp: Slot [6] registered
Nov  6 13:01:22 localhost vmunix: [    0.183165] acpiphp: Slot [7] registered
Nov  6 13:01:22 localhost vmunix: [    0.183173] acpiphp: Slot [8] registered
Nov  6 13:01:22 localhost vmunix: [    0.183181] acpiphp: Slot [9] registered
Nov  6 13:01:22 localhost vmunix: [    0.183191] acpiphp: Slot [10] registered
Nov  6 13:01:22 localhost vmunix: [    0.183199] acpiphp: Slot [11] registered
Nov  6 13:01:22 localhost vmunix: [    0.183207] acpiphp: Slot [12] registered
Nov  6 13:01:22 localhost vmunix: [    0.183215] acpiphp: Slot [13] registered
Nov  6 13:01:22 localhost vmunix: [    0.183223] acpiphp: Slot [14] registered
Nov  6 13:01:22 localhost vmunix: [    0.183231] acpiphp: Slot [15] registered
Nov  6 13:01:22 localhost vmunix: [    0.183239] acpiphp: Slot [16] registered
Nov  6 13:01:22 localhost vmunix: [    0.183248] acpiphp: Slot [17] registered
Nov  6 13:01:22 localhost vmunix: [    0.183256] acpiphp: Slot [18] registered
Nov  6 13:01:22 localhost vmunix: [    0.183264] acpiphp: Slot [19] registered
Nov  6 13:01:22 localhost vmunix: [    0.183272] acpiphp: Slot [20] registered
Nov  6 13:01:22 localhost vmunix: [    0.183280] acpiphp: Slot [21] registered
Nov  6 13:01:22 localhost vmunix: [    0.183288] acpiphp: Slot [22] registered
Nov  6 13:01:22 localhost vmunix: [    0.183297] acpiphp: Slot [23] registered
Nov  6 13:01:22 localhost vmunix: [    0.183305] acpiphp: Slot [24] registered
Nov  6 13:01:22 localhost vmunix: [    0.183315] acpiphp: Slot [25] registered
Nov  6 13:01:22 localhost vmunix: [    0.183323] acpiphp: Slot [26] registered
Nov  6 13:01:22 localhost vmunix: [    0.183331] acpiphp: Slot [27] registered
Nov  6 13:01:22 localhost vmunix: [    0.183339] acpiphp: Slot [28] registered
Nov  6 13:01:22 localhost vmunix: [    0.183347] acpiphp: Slot [29] registered
Nov  6 13:01:22 localhost vmunix: [    0.183356] acpiphp: Slot [30] registered
Nov  6 13:01:22 localhost vmunix: [    0.183364] acpiphp: Slot [31] registered
Nov  6 13:01:22 localhost vmunix: [    0.183370] PCI host bridge to bus 0000:00
Nov  6 13:01:22 localhost vmunix: [    0.183371] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
Nov  6 13:01:22 localhost vmunix: [    0.183373] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
Nov  6 13:01:22 localhost vmunix: [    0.183373] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
Nov  6 13:01:22 localhost vmunix: [    0.183374] pci_bus 0000:00: root bus resource [mem 0x80000000-0xfebfffff window]
Nov  6 13:01:22 localhost vmunix: [    0.183375] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
Nov  6 13:01:22 localhost vmunix: [    0.183376] pci_bus 0000:00: root bus resource [bus 00-ff]
Nov  6 13:01:22 localhost vmunix: [    0.183399] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
Nov  6 13:01:22 localhost vmunix: [    0.184030] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
Nov  6 13:01:22 localhost vmunix: [    0.184343] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
Nov  6 13:01:22 localhost vmunix: [    0.185266] pci 0000:00:01.1: reg 0x20: [io  0xc040-0xc04f]
Nov  6 13:01:22 localhost vmunix: [    0.185634] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
Nov  6 13:01:22 localhost vmunix: [    0.185635] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
Nov  6 13:01:22 localhost vmunix: [    0.185636] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
Nov  6 13:01:22 localhost vmunix: [    0.185637] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
Nov  6 13:01:22 localhost vmunix: [    0.185731] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
Nov  6 13:01:22 localhost vmunix: [    0.185979] pci 0000:00:01.3: quirk: [io  0xb000-0xb03f] claimed by PIIX4 ACPI
Nov  6 13:01:22 localhost vmunix: [    0.185985] pci 0000:00:01.3: quirk: [io  0xb100-0xb10f] claimed by PIIX4 SMB
Nov  6 13:01:22 localhost vmunix: [    0.186335] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000
Nov  6 13:01:22 localhost vmunix: [    0.187474] pci 0000:00:02.0: reg 0x10: [mem 0x80000000-0x80ffffff pref]
Nov  6 13:01:22 localhost vmunix: [    0.189019] pci 0000:00:02.0: reg 0x18: [mem 0x81020000-0x81020fff]
Nov  6 13:01:22 localhost vmunix: [    0.190989] pci 0000:00:02.0: reg 0x30: [mem 0xffff0000-0xffffffff pref]
Nov  6 13:01:22 localhost vmunix: [    0.191017] pci 0000:00:02.0: BAR 0: assigned to efifb
Nov  6 13:01:22 localhost vmunix: [    0.191031] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
Nov  6 13:01:22 localhost vmunix: [    0.191723] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000
Nov  6 13:01:22 localhost vmunix: [    0.192188] pci 0000:00:03.0: reg 0x10: [mem 0x81000000-0x8101ffff]
Nov  6 13:01:22 localhost vmunix: [    0.192523] pci 0000:00:03.0: reg 0x14: [io  0xc000-0xc03f]
Nov  6 13:01:22 localhost vmunix: [    0.194572] pci 0000:00:03.0: reg 0x30: [mem 0xfffc0000-0xffffffff pref]
Nov  6 13:01:22 localhost vmunix: [    0.202513] ACPI: PCI: Interrupt link LNKA configured for IRQ 11
Nov  6 13:01:22 localhost vmunix: [    0.204333] ACPI: PCI: Interrupt link LNKB configured for IRQ 11
Nov  6 13:01:22 localhost vmunix: [    0.204449] ACPI: PCI: Interrupt link LNKC configured for IRQ 10
Nov  6 13:01:22 localhost vmunix: [    0.204537] ACPI: PCI: Interrupt link LNKD configured for IRQ 10
Nov  6 13:01:22 localhost vmunix: [    0.204588] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
Nov  6 13:01:22 localhost vmunix: [    0.204785] iommu: Default domain type: Translated 
Nov  6 13:01:22 localhost vmunix: [    0.204787] iommu: DMA domain TLB invalidation policy: lazy mode 
Nov  6 13:01:22 localhost vmunix: [    0.204948] SCSI subsystem initialized
Nov  6 13:01:22 localhost vmunix: [    0.204999] ACPI: bus type USB registered
Nov  6 13:01:22 localhost vmunix: [    0.205013] usbcore: registered new interface driver usbfs
Nov  6 13:01:22 localhost vmunix: [    0.205019] usbcore: registered new interface driver hub
Nov  6 13:01:22 localhost vmunix: [    0.205023] usbcore: registered new device driver usb
Nov  6 13:01:22 localhost vmunix: [    0.205074] EDAC MC: Ver: 3.0.0
Nov  6 13:01:22 localhost vmunix: [    0.205231] Registered efivars operations
Nov  6 13:01:22 localhost vmunix: [    0.205446] NetLabel: Initializing
Nov  6 13:01:22 localhost vmunix: [    0.205447] NetLabel:  domain hash size = 128
Nov  6 13:01:22 localhost vmunix: [    0.205448] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
Nov  6 13:01:22 localhost vmunix: [    0.205457] NetLabel:  unlabeled traffic allowed by default
Nov  6 13:01:22 localhost vmunix: [    0.205485] mctp: management component transport protocol core
Nov  6 13:01:22 localhost vmunix: [    0.205485] NET: Registered PF_MCTP protocol family
Nov  6 13:01:22 localhost vmunix: [    0.205491] PCI: Using ACPI for IRQ routing
Nov  6 13:01:22 localhost vmunix: [    0.205627] pci 0000:00:02.0: vgaarb: setting as boot VGA device
Nov  6 13:01:22 localhost vmunix: [    0.205629] pci 0000:00:02.0: vgaarb: bridge control possible
Nov  6 13:01:22 localhost vmunix: [    0.205630] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
Nov  6 13:01:22 localhost vmunix: [    0.205632] vgaarb: loaded
Nov  6 13:01:22 localhost vmunix: [    0.205702] hpet: 3 channels of 0 reserved for per-cpu timers
Nov  6 13:01:22 localhost vmunix: [    0.205716] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
Nov  6 13:01:22 localhost vmunix: [    0.205719] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
Nov  6 13:01:22 localhost vmunix: [    0.209307] clocksource: Switched to clocksource kvm-clock
Nov  6 13:01:22 localhost vmunix: [    0.212309] VFS: Disk quotas dquot_6.6.0
Nov  6 13:01:22 localhost vmunix: [    0.212319] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
Nov  6 13:01:22 localhost vmunix: [    0.212401] AppArmor: AppArmor Filesystem Enabled
Nov  6 13:01:22 localhost vmunix: [    0.212415] pnp: PnP ACPI init
Nov  6 13:01:22 localhost vmunix: [    0.212622] pnp: PnP ACPI: found 6 devices
Nov  6 13:01:22 localhost vmunix: [    0.218059] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
Nov  6 13:01:22 localhost vmunix: [    0.218108] NET: Registered PF_INET protocol family
Nov  6 13:01:22 localhost vmunix: [    0.218154] IP idents hash table entries: 32768 (order: 6, 262144 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219091] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219294] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219300] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219318] TCP bind hash table entries: 16384 (order: 6, 262144 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219329] TCP: Hash tables configured (established 16384 bind 16384)
Nov  6 13:01:22 localhost vmunix: [    0.219360] MPTCP token hash table entries: 2048 (order: 3, 49152 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219373] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219378] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
Nov  6 13:01:22 localhost vmunix: [    0.219400] NET: Registered PF_UNIX/PF_LOCAL protocol family
Nov  6 13:01:22 localhost vmunix: [    0.219403] NET: Registered PF_XDP protocol family
Nov  6 13:01:22 localhost vmunix: [    0.219407] pci 0000:00:03.0: can't claim BAR 6 [mem 0xfffc0000-0xffffffff pref]: no compatible bridge window
Nov  6 13:01:22 localhost vmunix: [    0.219413] pci 0000:00:03.0: BAR 6: assigned [mem 0x81040000-0x8107ffff pref]
Nov  6 13:01:22 localhost vmunix: [    0.219416] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
Nov  6 13:01:22 localhost vmunix: [    0.219417] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
Nov  6 13:01:22 localhost vmunix: [    0.219418] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
Nov  6 13:01:22 localhost vmunix: [    0.219419] pci_bus 0000:00: resource 7 [mem 0x80000000-0xfebfffff window]
Nov  6 13:01:22 localhost vmunix: [    0.219419] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
Nov  6 13:01:22 localhost vmunix: [    0.219453] pci 0000:00:01.0: PIIX3: Enabling Passive Release
Nov  6 13:01:22 localhost vmunix: [    0.219460] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
Nov  6 13:01:22 localhost vmunix: [    0.219467] pci 0000:00:01.0: Activating ISA DMA hang workarounds
Nov  6 13:01:22 localhost vmunix: [    0.219494] PCI: CLS 0 bytes, default 64
Nov  6 13:01:22 localhost vmunix: [    0.219526] Trying to unpack rootfs image as initramfs...
Nov  6 13:01:22 localhost vmunix: [    0.222302] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1a03dfe73b3, max_idle_ns: 440795256845 ns
Nov  6 13:01:22 localhost vmunix: [    0.226452] Initialise system trusted keyrings
Nov  6 13:01:22 localhost vmunix: [    0.226494] workingset: timestamp_bits=40 max_order=19 bucket_order=0
Nov  6 13:01:22 localhost vmunix: [    0.227190] zbud: loaded
Nov  6 13:01:22 localhost vmunix: [    0.227519] Allocating IMA blacklist keyring.
Nov  6 13:01:22 localhost vmunix: [    0.242302] Key type asymmetric registered
Nov  6 13:01:22 localhost vmunix: [    0.242304] Asymmetric key parser 'x509' registered
Nov  6 13:01:22 localhost vmunix: [    0.372389] Freeing initrd memory: 13012K
Nov  6 13:01:22 localhost vmunix: [    0.372555] alg: self-tests for CTR-KDF (hmac(sha256)) passed
Nov  6 13:01:22 localhost vmunix: [    0.372572] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
Nov  6 13:01:22 localhost vmunix: [    0.372588] io scheduler mq-deadline registered
Nov  6 13:01:22 localhost vmunix: [    0.372700] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
Nov  6 13:01:22 localhost vmunix: [    0.372752] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
Nov  6 13:01:22 localhost vmunix: [    0.372774] ACPI: button: Power Button [PWRF]
Nov  6 13:01:22 localhost vmunix: [    0.372922] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
Nov  6 13:01:22 localhost vmunix: [    0.373003] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
Nov  6 13:01:22 localhost vmunix: [    0.373771] Linux agpgart interface v0.103
Nov  6 13:01:22 localhost vmunix: [    0.375002] brd: module loaded
Nov  6 13:01:22 localhost vmunix: [    0.375578] loop: module loaded
Nov  6 13:01:22 localhost vmunix: [    0.375940] scsi host0: ata_piix
Nov  6 13:01:22 localhost vmunix: [    0.375993] scsi host1: ata_piix
Nov  6 13:01:22 localhost vmunix: [    0.376009] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc040 irq 14
Nov  6 13:01:22 localhost vmunix: [    0.376010] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc048 irq 15
Nov  6 13:01:22 localhost vmunix: [    0.376084] tun: Universal TUN/TAP device driver, 1.6
Nov  6 13:01:22 localhost vmunix: [    0.376654] PPP generic driver version 2.4.2
Nov  6 13:01:22 localhost vmunix: [    0.376678] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Nov  6 13:01:22 localhost vmunix: [    0.376681] ehci-pci: EHCI PCI platform driver
Nov  6 13:01:22 localhost vmunix: [    0.376687] ehci-platform: EHCI generic platform driver
Nov  6 13:01:22 localhost vmunix: [    0.376690] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
Nov  6 13:01:22 localhost vmunix: [    0.376691] ohci-pci: OHCI PCI platform driver
Nov  6 13:01:22 localhost vmunix: [    0.376694] ohci-platform: OHCI generic platform driver
Nov  6 13:01:22 localhost vmunix: [    0.376696] uhci_hcd: USB Universal Host Controller Interface driver
Nov  6 13:01:22 localhost vmunix: [    0.376723] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
Nov  6 13:01:22 localhost vmunix: [    0.377173] serio: i8042 KBD port at 0x60,0x64 irq 1
Nov  6 13:01:22 localhost vmunix: [    0.377175] serio: i8042 AUX port at 0x60,0x64 irq 12
Nov  6 13:01:22 localhost vmunix: [    0.377228] mousedev: PS/2 mouse device common for all mice
Nov  6 13:01:22 localhost vmunix: [    0.377376] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
Nov  6 13:01:22 localhost vmunix: [    0.377522] rtc_cmos 00:05: RTC can wake from S4
Nov  6 13:01:22 localhost vmunix: [    0.377781] rtc_cmos 00:05: registered as rtc0
Nov  6 13:01:22 localhost vmunix: [    0.377817] rtc_cmos 00:05: setting system clock to 2022-11-06T12:01:16 UTC (1667736076)
Nov  6 13:01:22 localhost vmunix: [    0.377826] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
Nov  6 13:01:22 localhost vmunix: [    0.377830] i2c_dev: i2c /dev entries driver
Nov  6 13:01:22 localhost vmunix: [    0.377857] device-mapper: uevent: version 1.0.3
Nov  6 13:01:22 localhost vmunix: [    0.378040] device-mapper: ioctl: 4.47.0-ioctl (2022-07-28) initialised: dm-devel@redhat.com
Nov  6 13:01:22 localhost vmunix: [    0.378043] intel_pstate: CPU model not supported
Nov  6 13:01:22 localhost vmunix: [    0.378049] ledtrig-cpu: registered to indicate activity on CPUs
Nov  6 13:01:22 localhost vmunix: [    0.378064] efifb: probing for efifb
Nov  6 13:01:22 localhost vmunix: [    0.378071] efifb: framebuffer at 0x80000000, using 1408k, total 1408k
Nov  6 13:01:22 localhost vmunix: [    0.378073] efifb: mode is 800x600x24, linelength=2400, pages=1
Nov  6 13:01:22 localhost vmunix: [    0.378073] efifb: scrolling: redraw
Nov  6 13:01:22 localhost vmunix: [    0.378074] efifb: Truecolor: size=0:8:8:8, shift=0:16:8:0
Nov  6 13:01:22 localhost vmunix: [    0.378122] Console: switching to colour frame buffer device 100x37
Nov  6 13:01:22 localhost vmunix: [    0.379351] fb0: EFI VGA frame buffer device
Nov  6 13:01:22 localhost vmunix: [    0.379357] EFI Variables Facility v0.08 2004-May-17
Nov  6 13:01:22 localhost vmunix: [    0.379686] NET: Registered PF_INET6 protocol family
Nov  6 13:01:22 localhost vmunix: [    0.380051] Segment Routing with IPv6
Nov  6 13:01:22 localhost vmunix: [    0.380056] In-situ OAM (IOAM) with IPv6
Nov  6 13:01:22 localhost vmunix: [    0.380067] NET: Registered PF_PACKET protocol family
Nov  6 13:01:22 localhost vmunix: [    0.380084] Key type dns_resolver registered
Nov  6 13:01:22 localhost vmunix: [    0.380162] IPI shorthand broadcast: enabled
Nov  6 13:01:22 localhost vmunix: [    0.380174] sched_clock: Marking stable (380729376, -2487706)->(382223866, -3982196)
Nov  6 13:01:22 localhost vmunix: [    0.380234] registered taskstats version 1
Nov  6 13:01:22 localhost vmunix: [    0.380241] Loading compiled-in X.509 certificates
Nov  6 13:01:22 localhost vmunix: [    0.380287] zswap: loaded using pool lzo/zbud
Nov  6 13:01:22 localhost vmunix: [    0.380474] Key type encrypted registered
Nov  6 13:01:22 localhost vmunix: [    0.380476] AppArmor: AppArmor sha1 policy hashing enabled
Nov  6 13:01:22 localhost vmunix: [    0.380479] ima: No TPM chip found, activating TPM-bypass!
Nov  6 13:01:22 localhost vmunix: [    0.380482] ima: Allocated hash algorithm: sha1
Nov  6 13:01:22 localhost vmunix: [    0.380486] ima: No architecture policies found
Nov  6 13:01:22 localhost vmunix: [    0.380492] evm: Initialising EVM extended attributes:
Nov  6 13:01:22 localhost vmunix: [    0.380492] evm: security.selinux
Nov  6 13:01:22 localhost vmunix: [    0.380493] evm: security.SMACK64
Nov  6 13:01:22 localhost vmunix: [    0.380493] evm: security.SMACK64EXEC
Nov  6 13:01:22 localhost vmunix: [    0.380494] evm: security.SMACK64TRANSMUTE
Nov  6 13:01:22 localhost vmunix: [    0.380494] evm: security.SMACK64MMAP
Nov  6 13:01:22 localhost vmunix: [    0.380494] evm: security.apparmor
Nov  6 13:01:22 localhost vmunix: [    0.380495] evm: security.ima
Nov  6 13:01:22 localhost vmunix: [    0.380495] evm: security.capability
Nov  6 13:01:22 localhost vmunix: [    0.380495] evm: HMAC attrs: 0x1
Nov  6 13:01:22 localhost vmunix: [    0.380991] PM:   Magic number: 14:713:25
Nov  6 13:01:22 localhost vmunix: [    0.534680] ata2: found unknown device (class 0)
Nov  6 13:01:22 localhost vmunix: [    0.535228] ata1: found unknown device (class 0)
Nov  6 13:01:22 localhost vmunix: [    0.536608] ata1.00: ATA-7: QEMU HARDDISK, 2.5+, max UDMA/100
Nov  6 13:01:22 localhost vmunix: [    0.536613] ata1.00: 6291456 sectors, multi 16: LBA48 
Nov  6 13:01:22 localhost vmunix: [    0.536967] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
Nov  6 13:01:22 localhost vmunix: [    0.538187] scsi 0:0:0:0: Direct-Access     ATA      QEMU HARDDISK    2.5+ PQ: 0 ANSI: 5
Nov  6 13:01:22 localhost vmunix: [    0.538696] sd 0:0:0:0: [sda] 6291456 512-byte logical blocks: (3.22 GB/3.00 GiB)
Nov  6 13:01:22 localhost vmunix: [    0.538712] sd 0:0:0:0: [sda] Write Protect is off
Nov  6 13:01:22 localhost vmunix: [    0.538736] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov  6 13:01:22 localhost vmunix: [    0.538765] sd 0:0:0:0: [sda] Preferred minimum I/O size 512 bytes
Nov  6 13:01:22 localhost vmunix: [    0.539080] sd 0:0:0:0: Attached scsi generic sg0 type 0
Nov  6 13:01:22 localhost vmunix: [    0.539943] scsi 1:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     2.5+ PQ: 0 ANSI: 5
Nov  6 13:01:22 localhost vmunix: [    0.555650]  sda: sda1 sda2 sda3
Nov  6 13:01:22 localhost vmunix: [    0.555888] sd 0:0:0:0: [sda] Attached SCSI disk
Nov  6 13:01:22 localhost vmunix: [    0.563472] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
Nov  6 13:01:22 localhost vmunix: [    0.563479] cdrom: Uniform CD-ROM driver Revision: 3.20
Nov  6 13:01:22 localhost vmunix: [    0.588295] sr 1:0:0:0: Attached scsi generic sg1 type 5
Nov  6 13:01:22 localhost vmunix: [    0.590320] Freeing unused kernel image (initmem) memory: 2716K
Nov  6 13:01:22 localhost vmunix: [    0.590362] Write protecting the kernel read-only data: 24576k
Nov  6 13:01:22 localhost vmunix: [    0.590858] Freeing unused kernel image (text/rodata gap) memory: 2036K
Nov  6 13:01:22 localhost vmunix: [    0.591062] Freeing unused kernel image (rodata/data gap) memory: 920K
Nov  6 13:01:22 localhost vmunix: [    0.591092] Run /init as init process
Nov  6 13:01:22 localhost vmunix: [    0.640078] usbcore: registered new interface driver usb-storage
Nov  6 13:01:22 localhost vmunix: [    0.641903] usbcore: registered new interface driver uas
Nov  6 13:01:22 localhost vmunix: [    0.643262] hid: raw HID events driver (C) Jiri Kosina
Nov  6 13:01:22 localhost vmunix: [    0.643678] usbcore: registered new interface driver usbhid
Nov  6 13:01:22 localhost vmunix: [    0.643679] usbhid: USB HID core driver
Nov  6 13:01:22 localhost vmunix: [    0.653382] isci: Intel(R) C600 SAS Controller Driver - version 1.2.0
Nov  6 13:01:22 localhost vmunix: [    1.766244] random: crng init done
Nov  6 13:01:22 localhost vmunix: [    2.348621] shepherd[1]: Service root has been started.
Nov  6 13:01:22 localhost vmunix: [    2.437218] shepherd[1]: starting services...
Nov  6 13:01:22 localhost vmunix: [    2.437627] shepherd[1]: Service root-file-system has been started.
Nov  6 13:01:22 localhost vmunix: [    2.438528] shepherd[1]: Service user-file-systems has been started.
Nov  6 13:01:22 localhost vmunix: [    2.442830] shepherd[1]: waiting for udevd...
Nov  6 13:01:22 localhost vmunix: [    2.450930] udevd[126]: starting version 3.2.11
Nov  6 13:01:22 localhost vmunix: [    2.463131] udevd[126]: starting eudev-3.2.11
Nov  6 13:01:22 localhost vmunix: [    2.944941] udevd[126]: no sender credentials received, message ignored
Nov  6 13:01:22 localhost vmunix: [    3.007002] parport_pc 00:03: reported by Plug and Play ACPI
Nov  6 13:01:22 localhost vmunix: [    3.007092] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE]
Nov  6 13:01:22 localhost vmunix: [    3.007323] Floppy drive(s): fd0 is 2.88M AMI BIOS
Nov  6 13:01:22 localhost vmunix: [    3.026484] FDC 0 is a S82078B
Nov  6 13:01:22 localhost vmunix: [    3.028525] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0xb100, revision 0
Nov  6 13:01:22 localhost vmunix: [    3.030916] e1000: Intel(R) PRO/1000 Network Driver
Nov  6 13:01:22 localhost vmunix: [    3.030917] e1000: Copyright (c) 1999-2006 Intel Corporation.
Nov  6 13:01:22 localhost vmunix: [    3.051642] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4
Nov  6 13:01:22 localhost vmunix: [    3.051768] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3
Nov  6 13:01:22 localhost vmunix: [    3.094791] input: PC Speaker as /devices/platform/pcspkr/input/input5
Nov  6 13:01:22 localhost vmunix: [    3.130117] pstore: Using crash dump compression: deflate
Nov  6 13:01:22 localhost vmunix: [    3.130120] pstore: Registered efi as persistent store backend
Nov  6 13:01:22 localhost vmunix: [    3.132207] ACPI: bus type drm_connector registered
Nov  6 13:01:22 localhost vmunix: [    3.142598] Error: Driver 'pcspkr' is already registered, aborting...
Nov  6 13:01:22 localhost vmunix: [    3.150118] ACPI: \_SB_.LNKC: Enabled at IRQ 10
Nov  6 13:01:22 localhost vmunix: [    3.168084] Console: switching to colour dummy device 80x25
Nov  6 13:01:22 localhost vmunix: [    3.168108] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
Nov  6 13:01:22 localhost vmunix: [    3.168169] [drm] Found bochs VGA, ID 0xb0c5.
Nov  6 13:01:22 localhost vmunix: [    3.168170] [drm] Framebuffer size 16384 kB @ 0x80000000, mmio @ 0x81020000.
Nov  6 13:01:22 localhost vmunix: [    3.168826] [drm] Found EDID data blob.
Nov  6 13:01:22 localhost vmunix: [    3.170719] [drm] Initialized bochs-drm 1.0.0 20130925 for 0000:00:02.0 on minor 0
Nov  6 13:01:22 localhost vmunix: [    3.172669] fbcon: bochs-drmdrmfb (fb0) is primary device
Nov  6 13:01:22 localhost vmunix: [    3.175418] Console: switching to colour frame buffer device 160x50
Nov  6 13:01:22 localhost vmunix: [    3.182506] ppdev: user-space parallel port driver
Nov  6 13:01:22 localhost vmunix: [    3.185472] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
Nov  6 13:01:22 localhost vmunix: [    3.492410] e1000 0000:00:03.0 eth0: (PCI:33MHz:32-bit) 52:54:00:12:34:56
Nov  6 13:01:22 localhost vmunix: [    3.492418] e1000 0000:00:03.0 eth0: Intel(R) PRO/1000 Network Connection
Nov  6 13:01:22 localhost vmunix: [    3.493897] e1000 0000:00:03.0 ens3: renamed from eth0
Nov  6 13:01:22 localhost vmunix: [    6.079910] shepherd[1]: Service udev has been started.
Nov  6 13:01:22 localhost vmunix: [    6.081147] shepherd[1]: Service file-system-/tmp has been started.
Nov  6 13:01:22 localhost vmunix: [    6.082057] shepherd[1]: Service file-system-/dev/pts has been started.
Nov  6 13:01:22 localhost vmunix: [    6.083157] shepherd[1]: Service file-system-/dev/shm has been started.
Nov  6 13:01:22 localhost vmunix: [    6.084769] shepherd[1]: Service file-system-/sys/firmware/efi/efivars has been started.
Nov  6 13:01:22 localhost vmunix: [    6.085868] shepherd[1]: Service file-system-/gnu/store has been started.
Nov  6 13:01:22 localhost vmunix: [    6.086460] shepherd[1]: Service file-systems has been started.
Nov  6 13:01:22 localhost vmunix: [    6.095356] shepherd[1]: Service user-homes has been started.
Nov  6 13:01:22 localhost vmunix: [    6.095521] shepherd[1]: Service user-processes has been started.
Nov  6 13:01:22 localhost vmunix: [    6.095713] shepherd[1]: Service host-name has been started.
Nov  6 13:01:22 localhost vmunix: [    6.095911] shepherd[1]: Service user-homes has been started.
Nov  6 13:01:22 localhost vmunix: [    6.096112] shepherd[1]: Service maybe-uvesafb has been started.
Nov  6 13:01:23 localhost shepherd[1]: Service syslogd has been started. 
Nov  6 13:01:24 localhost shepherd[1]: Service dbus-system has been started. 
Nov  6 13:01:24 localhost shepherd[1]: Service loopback has been started. 
Nov  6 13:01:24 localhost wpa_supplicant[164]: Successfully initialized wpa_supplicant
Nov  6 13:01:25 localhost shepherd[1]: Service wpa-supplicant has been started. 
Nov  6 13:01:25 localhost shepherd[1]: Service networking has been started. 
Nov  6 13:01:25 localhost nscd: 167 monitoring file `/etc/hosts` (1)
Nov  6 13:01:25 localhost nscd: 167 monitoring directory `/etc` (2)
Nov  6 13:01:25 localhost nscd: 167 monitoring file `/etc/resolv.conf` (3)
Nov  6 13:01:25 localhost nscd: 167 monitoring directory `/etc` (2)
Nov  6 13:01:25 localhost nscd: 167 monitoring file `/etc/nsswitch.conf` (4)
Nov  6 13:01:25 localhost nscd: 167 monitoring directory `/etc` (2)
Nov  6 13:01:25 localhost connmand[166]: Connection Manager version 1.41
Nov  6 13:01:25 localhost connmand[166]: Excluding VPN plugin
Nov  6 13:01:25 localhost connmand[166]: Checking loopback interface settings
Nov  6 13:01:25 localhost connmand[166]: System hostname is gnu
Nov  6 13:01:25 localhost connmand[166]: lo {newlink} index 1 address 00:00:00:00:00:00 mtu 65536
Nov  6 13:01:25 localhost connmand[166]: lo {newlink} index 1 operstate 0 <UNKNOWN>
Nov  6 13:01:25 localhost connmand[166]: ens3 {create} index 2 type 1 <ETHER>
Nov  6 13:01:25 localhost connmand[166]: ens3 {update} flags 4098 <DOWN>
Nov  6 13:01:25 localhost connmand[166]: ens3 {newlink} index 2 address 52:54:00:12:34:56 mtu 1500
Nov  6 13:01:25 localhost connmand[166]: ens3 {newlink} index 2 operstate 2 <DOWN>
Nov  6 13:01:25 localhost connmand[166]: Adding interface ens3 [ ethernet ]
Nov  6 13:01:25 localhost connmand[166]: ens3 {update} flags 36867 <UP>
Nov  6 13:01:25 localhost connmand[166]: ens3 {newlink} index 2 address 52:54:00:12:34:56 mtu 1500
Nov  6 13:01:25 localhost connmand[166]: ens3 {newlink} index 2 operstate 2 <DOWN>
Nov  6 13:01:25 localhost vmunix: [    9.186660] e1000: ens3 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
Nov  6 13:01:25 localhost vmunix: [    9.186938] IPv6: ADDRCONF(NETDEV_CHANGE): ens3: link becomes ready
Nov  6 13:01:25 localhost connmand[166]: ens3 {add} route fe80:: gw :: scope 0 <UNIVERSE>
Nov  6 13:01:25 localhost connmand[166]: ens3 {update} flags 102467 <UP,RUNNING,LOWER_UP>
Nov  6 13:01:25 localhost connmand[166]: ens3 {newlink} index 2 address 52:54:00:12:34:56 mtu 1500
Nov  6 13:01:25 localhost connmand[166]: ens3 {newlink} index 2 operstate 6 <UP>
Nov  6 13:01:25 localhost vmunix: [    9.207954] 8021q: 802.1Q VLAN Support v1.8
Nov  6 13:01:25 localhost vmunix: [    9.207963] 8021q: adding VLAN 0 to HW filter on device ens3
Nov  6 13:01:26 localhost shepherd[1]: Service nscd has been started. 
Nov  6 13:01:26 localhost /gnu/store/5ipd04ydr6zi27bksp31di77vhq863b1-gpm-1.20.7/sbin/gpm[177]: *** info [daemon/startup.c(136)]: 
Nov  6 13:01:26 localhost /gnu/store/5ipd04ydr6zi27bksp31di77vhq863b1-gpm-1.20.7/sbin/gpm[177]: Started gpm successfully. Entered daemon mode.
Nov  6 13:01:26 localhost connmand[166]: Cannot create /var/run/connman/resolv.conf falling back to /etc/resolv.conf
Nov  6 13:01:26 localhost nscd: 167 monitored file `/etc/resolv.conf` was written to
Nov  6 13:01:26 localhost connmand[166]: ens3 {add} address 10.0.2.15/24 label ens3 family 2
Nov  6 13:01:26 localhost nscd: 167 monitored file `/etc/resolv.conf` was written to
Nov  6 13:01:26 localhost nscd: 167 monitored file `/etc/resolv.conf` was written to
Nov  6 13:01:26 localhost connmand[166]: ens3 {add} route 10.0.2.0 gw 0.0.0.0 scope 253 <LINK>
Nov  6 13:01:26 localhost connmand[166]: ens3 {add} route 10.0.2.2 gw 0.0.0.0 scope 253 <LINK>
Nov  6 13:01:26 localhost connmand[166]: ens3 {add} route 0.0.0.0 gw 10.0.2.2 scope 0 <UNIVERSE>
Nov  6 13:01:27 localhost connmand[166]: ens3 {add} route fec0:: gw :: scope 0 <UNIVERSE>
Nov  6 13:01:27 localhost nscd: 167 monitored file `/etc/resolv.conf` was written to
Nov  6 13:01:27 localhost shepherd[1]: Service gpm has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service term-tty1 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service console-font-tty1 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service host-name has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service virtual-terminal has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service term-tty2 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service console-font-tty2 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service host-name has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service term-tty3 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service console-font-tty3 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service host-name has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service term-tty4 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service console-font-tty4 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service host-name has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service term-tty5 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service console-font-tty5 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service host-name has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service term-tty6 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service console-font-tty6 has been started. 
Nov  6 13:01:27 localhost shepherd[1]: Service guix-daemon has been started. 
Nov  6 13:01:27 localhost shepherd[1]: [kmscon] [0000.000000] NOTICE: kmscon Revision UnknownRevision Jan  1 1970 00:00:01 (log_print_init() in src/shl_log.c:509) 
Nov  6 13:01:27 localhost shepherd[1]: [kmscon] [0000.075066] NOTICE: vt: using tty /dev/tty1 (open_tty() in src/uterm_vt.c:285) 
Nov  6 13:01:27 localhost avahi-daemon[204]: Found user 'avahi' (UID 987) and group 'avahi' (GID 981).
Nov  6 13:01:27 localhost avahi-daemon[204]: Successfully dropped root privileges.
Nov  6 13:01:27 localhost avahi-daemon[204]: avahi-daemon 0.8 starting up.
Nov  6 13:01:27 localhost avahi-daemon[204]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
Nov  6 13:01:27 localhost avahi-daemon[204]: Successfully called chroot().
Nov  6 13:01:27 localhost avahi-daemon[204]: Successfully dropped remaining capabilities.
Nov  6 13:01:27 localhost avahi-daemon[204]: Loading service file /services/sftp-ssh.service.
Nov  6 13:01:27 localhost avahi-daemon[204]: Loading service file /services/ssh.service.
Nov  6 13:01:27 localhost avahi-daemon[204]: Joining mDNS multicast group on interface ens3.IPv6 with address fec0::5054:ff:fe12:3456.
Nov  6 13:01:27 localhost avahi-daemon[204]: New relevant interface ens3.IPv6 for mDNS.
Nov  6 13:01:27 localhost avahi-daemon[204]: Joining mDNS multicast group on interface ens3.IPv4 with address 10.0.2.15.
Nov  6 13:01:27 localhost avahi-daemon[204]: New relevant interface ens3.IPv4 for mDNS.
Nov  6 13:01:27 localhost avahi-daemon[204]: Joining mDNS multicast group on interface lo.IPv6 with address ::1.
Nov  6 13:01:27 localhost avahi-daemon[204]: New relevant interface lo.IPv6 for mDNS.
Nov  6 13:01:27 localhost avahi-daemon[204]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1.
Nov  6 13:01:27 localhost avahi-daemon[204]: New relevant interface lo.IPv4 for mDNS.
Nov  6 13:01:27 localhost avahi-daemon[204]: Network interface enumeration completed.
Nov  6 13:01:27 localhost avahi-daemon[204]: Registering new address record for fec0::5054:ff:fe12:3456 on ens3.*.
Nov  6 13:01:27 localhost avahi-daemon[204]: Registering new address record for 10.0.2.15 on ens3.IPv4.
Nov  6 13:01:27 localhost avahi-daemon[204]: Registering new address record for ::1 on lo.*.
Nov  6 13:01:27 localhost avahi-daemon[204]: Registering new address record for 127.0.0.1 on lo.IPv4.
Nov  6 13:01:28 localhost avahi-daemon[204]: Server startup complete. Host name is gnu.local. Local service cookie is 980222873.
Nov  6 13:01:28 localhost shepherd[1]: Service avahi-daemon has been started. 
Nov  6 13:01:28 localhost shepherd[1]: Service mcron has been started. 
Nov  6 13:01:28 localhost installer[214]: Display is 128x42. 
Nov  6 13:01:28 localhost installer[214]: running step 'locale' 
Nov  6 13:01:28 localhost installer[214]: running step 'language' 
Nov  6 13:01:28 localhost connmand[166]: ens3 {add} address fec0::5054:ff:fe12:3456/64 label (null) family 10
Nov  6 13:01:28 localhost installer[214]: running form #<newt-form 2362ef0> ("Locale language") with 0 clients 
Nov  6 13:01:29 localhost avahi-daemon[204]: Service "gnu" (/services/ssh.service) successfully established.
Nov  6 13:01:29 localhost avahi-daemon[204]: Service "gnu" (/services/sftp-ssh.service) successfully established.
Nov  6 13:01:31 localhost installer[214]: running step 'territory' 
Nov  6 13:01:31 localhost installer[214]: running form #<newt-form 2362f90> ("Locale location") with 0 clients 
Nov  6 13:01:31 localhost installer[214]: running step 'codeset' 
Nov  6 13:01:31 localhost shepherd[1]: Service console-font-tty2 has been stopped. 
Nov  6 13:01:31 localhost shepherd[1]: Service term-tty2 has been stopped. 
Nov  6 13:01:31 localhost shepherd[1]: Service host-name has been started. 
Nov  6 13:01:31 localhost shepherd[1]: Service term-tty2 has been started. 
Nov  6 13:01:31 localhost installer[214]: running step 'welcome' 
Nov  6 13:01:31 localhost installer[214]: running form #<newt-form 237dfc0> ("GNU Guix install") with 0 clients 
Nov  6 13:01:31 localhost installer[214]: running step 'timezone' 
Nov  6 13:01:31 localhost installer[214]: running form #<newt-form 237e120> ("Timezone") with 0 clients 
Nov  6 13:01:31 localhost installer[214]: running form #<newt-form 2377dc0> ("Timezone") with 0 clients 
Nov  6 13:01:31 localhost installer[214]: running step 'keymap' 
Nov  6 13:01:32 localhost installer[214]: running step 'layout' 
Nov  6 13:01:32 localhost installer[214]: running form #<newt-form 2376c60> ("Layout") with 0 clients 
Nov  6 13:01:32 localhost installer[214]: running step 'variant' 
Nov  6 13:01:32 localhost installer[214]: running step 'hostname' 
Nov  6 13:01:32 localhost installer[214]: running form #<newt-form 2379cb0> ("Hostname") with 0 clients 
Nov  6 13:01:37 localhost installer[214]: running step 'network' 
Nov  6 13:01:37 localhost installer[214]: running step 'select-technology' 
Nov  6 13:01:37 localhost installer[214]: running step 'power-technology' 
Nov  6 13:01:38 localhost installer[214]: running step 'connect-service' 
Nov  6 13:01:38 localhost installer[214]: running step 'wait-online' 
Nov  6 13:01:41 localhost installer[214]: running step 'substitutes' 
Nov  6 13:01:41 localhost shepherd[1]: enable substitute servers discovery 
Nov  6 13:01:41 localhost shepherd[1]: Service guix-daemon has been stopped. 
Nov  6 13:01:41 localhost shepherd[1]: Service guix-daemon has been started. 
Nov  6 13:01:41 localhost installer[214]: running step 'user' 
Nov  6 13:01:41 localhost installer[214]: running form #<newt-form 2ac6810> ("System administrator password") with 0 clients 
Nov  6 13:01:43 localhost installer[214]: running form #<newt-form 2adc580> ("Password confirmation required") with 0 clients 
Nov  6 13:01:45 localhost installer[214]: running form #<newt-form 2adc8b0> (add-users) with 0 clients 
Nov  6 13:01:50 localhost installer[214]: running form #<newt-form 2ad2960> ("Password confirmation required") with 0 clients 
Nov  6 13:01:51 localhost installer[214]: running form #<newt-form 2ad5870> (add-users) with 0 clients 
Nov  6 13:01:52 localhost installer[214]: running step 'services' 
Nov  6 13:01:52 localhost installer[214]: running form #<newt-form 2ac68e0> ("Desktop environment") with 0 clients 
Nov  6 13:01:53 localhost installer[214]: running form #<newt-form 2ad2b50> ("Network service") with 0 clients 
Nov  6 13:01:53 localhost installer[214]: running form #<newt-form 2ac68e0> ("Network management") with 0 clients 
Nov  6 13:01:54 localhost installer[214]: running form #<newt-form 2ad3640> ("Console services") with 0 clients 
Nov  6 13:01:55 localhost installer[214]: running form #<newt-form 2ad3740> ("Printing and document services") with 0 clients 
Nov  6 13:01:56 localhost installer[214]: running step 'partition' 
Nov  6 13:01:56 localhost parted[214]: parted: new: 0x2ac6860 
Nov  6 13:01:56 localhost parted[214]: parted: new: 0x2ac5390 
Nov  6 13:01:56 localhost guile-parted: pointer->device!: #<pointer 0x2ac6860> 
Nov  6 13:01:56 localhost guile-parted: hash begin 
Nov  6 13:01:56 localhost guile-parted: hash end 
Nov  6 13:01:56 localhost guile-parted: finalizer!: #<pointer 0x2ac6860> 
Nov  6 13:01:56 localhost guile-parted: pointer->device!: #<pointer 0x2ac5390> 
Nov  6 13:01:56 localhost guile-parted: hash begin 
Nov  6 13:01:56 localhost guile-parted: hash: #<pointer 0x2ac6860> -> #<<device> bytestructure: #<bytestructure 0x7fab01c0a3e0>> 
Nov  6 13:01:56 localhost guile-parted: hash end 
Nov  6 13:01:56 localhost guile-parted: finalizer!: #<pointer 0x2ac5390> 
Nov  6 13:01:56 localhost installer[214]: /dev/sr0 is not eligible because it is the installation device. 
Nov  6 13:01:56 localhost installer[214]: running form #<newt-form 2ab3470> ("Partitioning method") with 0 clients 
Nov  6 13:01:57 localhost installer[214]: running form #<newt-form 2ad3740> ("Disk") with 0 clients 
Nov  6 13:01:57 localhost installer[214]: running form #<newt-form 2ab3470> ("Partition scheme") with 0 clients 
Nov  6 13:01:59 localhost installer[214]: Creating partition: 
Nov  6 13:01:59 localhost installer[214]: 	type: 0 
Nov  6 13:01:59 localhost installer[214]: 	filesystem-type: ext4 
Nov  6 13:01:59 localhost installer[214]: 	flags: () 
Nov  6 13:01:59 localhost installer[214]: 	start: 1126399 
Nov  6 13:01:59 localhost installer[214]: 	end: 2830869 
Nov  6 13:01:59 localhost installer[214]: 	start-range: [1126399, 1128447] 
Nov  6 13:01:59 localhost installer[214]: 	end-range: [2828821, 2830869] 
Nov  6 13:01:59 localhost installer[214]: 	constraint: #t 
Nov  6 13:01:59 localhost installer[214]: 	no-constraint: #t 
Nov  6 13:01:59 localhost installer[214]: Creating partition: 
Nov  6 13:01:59 localhost installer[214]: 	type: 0 
Nov  6 13:01:59 localhost installer[214]: 	filesystem-type: linux-swap(v1) 
Nov  6 13:01:59 localhost installer[214]: 	flags: () 
Nov  6 13:01:59 localhost installer[214]: 	start: 2830336 
Nov  6 13:01:59 localhost installer[214]: 	end: 3144910 
Nov  6 13:01:59 localhost installer[214]: 	start-range: [2830336, 2832384] 
Nov  6 13:01:59 localhost installer[214]: 	end-range: [3142862, 3144910] 
Nov  6 13:01:59 localhost installer[214]: 	constraint: #t 
Nov  6 13:01:59 localhost installer[214]: 	no-constraint: #t 
Nov  6 13:01:59 localhost installer[214]: Creating partition: 
Nov  6 13:01:59 localhost installer[214]: 	type: 0 
Nov  6 13:01:59 localhost installer[214]: 	filesystem-type: ext4 
Nov  6 13:01:59 localhost installer[214]: 	flags: () 
Nov  6 13:01:59 localhost installer[214]: 	start: 3143680 
Nov  6 13:01:59 localhost installer[214]: 	end: 6291455 
Nov  6 13:01:59 localhost installer[214]: 	start-range: [3143680, 3145728] 
Nov  6 13:01:59 localhost installer[214]: 	end-range: [6289407, 6291455] 
Nov  6 13:01:59 localhost installer[214]: 	constraint: #t 
Nov  6 13:01:59 localhost installer[214]: 	no-constraint: #t 
Nov  6 13:01:59 localhost installer[214]: running form #<newt-form 2ad68e0> ("Guided partitioning") with 0 clients 
Nov  6 13:02:01 localhost installer[214]: running form #<newt-form 2ad6570> ("Format disk?") with 0 clients 
Nov  6 13:02:01 localhost vmunix: [   45.230240] raid6: sse2x4   gen() 26968 MB/s
Nov  6 13:02:01 localhost vmunix: [   45.298240] raid6: sse2x2   gen() 27572 MB/s
Nov  6 13:02:01 localhost vmunix: [   45.366239] raid6: sse2x1   gen() 21956 MB/s
Nov  6 13:02:01 localhost vmunix: [   45.366240] raid6: using algorithm sse2x2 gen() 27572 MB/s
Nov  6 13:02:01 localhost vmunix: [   45.434240] raid6: .... xor() 15822 MB/s, rmw enabled
Nov  6 13:02:01 localhost vmunix: [   45.434241] raid6: using intx1 recovery algorithm
Nov  6 13:02:01 localhost vmunix: [   45.435279] xor: measuring software checksum speed
Nov  6 13:02:01 localhost vmunix: [   45.435601]    prefetch64-sse  : 33091 MB/sec
Nov  6 13:02:01 localhost vmunix: [   45.435981]    generic_sse     : 25952 MB/sec
Nov  6 13:02:01 localhost vmunix: [   45.435982] xor: using function: prefetch64-sse (33091 MB/sec)
Nov  6 13:02:01 localhost vmunix: [   45.477253] Btrfs loaded, crc32c=crc32c-generic, zoned=yes, fsverity=yes
Nov  6 13:02:01 localhost vmunix: [   45.478038] BTRFS: device fsid 52dd0ad0-246f-459f-a05f-059d7c99d09b devid 1 transid 8 /dev/sda4 scanned by udevd (251)
Nov  6 13:02:02 localhost vmunix: [   46.208603]  sda: sda1 sda2 sda3 sda4
Nov  6 13:02:02 localhost installer[214]: Syncing /dev/sda took 0 seconds. 
Nov  6 13:02:02 localhost installer[214]: mke2fs 1.46.4 (18-Aug-2021) 
Nov  6 13:02:02 localhost installer[214]: Discarding device blocks:      0/212992^H^H^H^H^H^H^H^H^H^H^H^H^H             ^H^H^H^H^H^H^H^H^H^H^H^H^Hdone                             
Nov  6 13:02:02 localhost installer[214]: Creating filesystem with 212992 4k blocks and 53312 inodes 
Nov  6 13:02:02 localhost installer[214]: Filesystem UUID: a8054a8d-7070-44a9-b9df-7f6b9d394574 
Nov  6 13:02:02 localhost installer[214]: Superblock backups stored on blocks:  
Nov  6 13:02:02 localhost installer[214]: 	32768, 98304, 163840 
Nov  6 13:02:02 localhost installer[214]:  
Nov  6 13:02:02 localhost installer[214]: Allocating group tables: 0/7^H^H^H   ^H^H^Hdone                             
Nov  6 13:02:02 localhost installer[214]: Writing inode tables: 0/7^H^H^H   ^H^H^Hdone                             
Nov  6 13:02:02 localhost installer[214]: Creating journal (4096 blocks): done 
Nov  6 13:02:02 localhost installer[214]: Writing superblocks and filesystem accounting information: 0/7^H^H^H   ^H^H^Hdone 
Nov  6 13:02:02 localhost installer[214]:  
Nov  6 13:02:02 localhost installer[214]: Setting up swapspace version 1, size = 153 MiB (160428032 bytes) 
Nov  6 13:02:02 localhost installer[214]: no label, UUID=b7375440-267a-4dc4-8c6b-bd35121c2a2a 
Nov  6 13:02:02 localhost installer[214]: mke2fs 1.46.4 (18-Aug-2021) 
Nov  6 13:02:02 localhost installer[214]: Discarding device blocks:      0/393216^H^H^H^H^H^H^H^H^H^H^H^H^H             ^H^H^H^H^H^H^H^H^H^H^H^H^Hdone                             
Nov  6 13:02:02 localhost installer[214]: Creating filesystem with 393216 4k blocks and 98304 inodes 
Nov  6 13:02:02 localhost installer[214]: Filesystem UUID: 8d9b521e-6be7-49cd-a2ac-0d6c6e0ad51c 
Nov  6 13:02:02 localhost installer[214]: Superblock backups stored on blocks:  
Nov  6 13:02:02 localhost installer[214]: 	32768, 98304, 163840, 229376, 294912 
Nov  6 13:02:02 localhost installer[214]:  
Nov  6 13:02:02 localhost installer[214]: Allocating group tables:  0/12^H^H^H^H^H     ^H^H^H^H^Hdone                             
Nov  6 13:02:02 localhost installer[214]: Writing inode tables:  0/12^H^H^H^H^H     ^H^H^H^H^Hdone                             
Nov  6 13:02:02 localhost installer[214]: Creating journal (8192 blocks): done 
Nov  6 13:02:02 localhost installer[214]: Writing superblocks and filesystem accounting information:  0/12^H^H^H^H^H     ^H^H^H^H^Hdone 
Nov  6 13:02:02 localhost installer[214]:  
Nov  6 13:02:02 localhost installer[214]: formatted 4 user partitions 
Nov  6 13:02:02 localhost installer[214]: user-partitions: (#<<user-partition> name: #f type: normal file-name: "/dev/sda1" disk-file-name: "/dev/sda" crypt-label: #f crypt-password: #f fs-type: fat32 bootable?: #t esp?: #t bios-grub?: #f size: #f start: #f end: #f mount-point: "/boot/efi" need-formatting?: #f parted-object: #<<partition> bytestructure: #<bytestructure 0x7fab01c90b20>>> #<<user-partition> name: #f type: normal file-name: "/dev/sda2" disk-file-name: "/dev/sda" crypt-label: #f crypt-password: #f fs-type: ext4 bootable?: #f esp?: #f bios-grub?: #f size: "33%" start: "1126399s" end: "2830869s" mount-point: "/" need-formatting?: #t parted-object: #<<partition> bytestructure: #<bytestructure 0x7fab01c97920>>> #<<user-partition> name: #f type: normal file-name: "/dev/sda3" disk-file-name: "/dev/sda" crypt-label: #f crypt-password: #f fs-type: swap bootable?: #f esp?: #f bios-grub?: #f size: 314573 start: "2830336s" end: "3144910s" mount-point: #f need-formatting?: #t parted-object: #<<partition> bytestructure: #<bytestructur
Nov  6 13:02:02 localhost installer[214]: running step 'final' 
Nov  6 13:02:02 localhost installer[214]: proceeding with final step 
Nov  6 13:02:02 localhost installer[214]: mounting "/dev/sda2" on "/mnt/" 
Nov  6 13:02:02 localhost vmunix: [   46.738948] EXT4-fs (sda2): mounted filesystem with ordered data mode. Quota mode: none.
Nov  6 13:02:02 localhost installer[214]: mounting "/dev/sda1" on "/mnt/boot/efi" 
Nov  6 13:02:02 localhost vmunix: [   46.741132] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Nov  6 13:02:02 localhost installer[214]: mounting "/dev/sda4" on "/mnt/home" 
Nov  6 13:02:02 localhost vmunix: [   46.743462] EXT4-fs (sda4): mounted filesystem with ordered data mode. Quota mode: none.
Nov  6 13:02:02 localhost vmunix: [   46.743831] Adding 156668k swap on /dev/sda3.  Priority:-2 extents:1 across:156668k FS
Nov  6 13:02:02 localhost installer[214]: running form #<newt-form 2aefc20> ("Configuration file") with 0 clients 
Nov  6 13:02:04 localhost installer[214]: unmounting "/mnt/home" 
Nov  6 13:02:04 localhost vmunix: [   48.148992] EXT4-fs (sda4): unmounting filesystem.
Nov  6 13:02:04 localhost installer[214]: unmounting "/mnt/boot/efi" 
Nov  6 13:02:04 localhost installer[214]: unmounting "/mnt/" 
Nov  6 13:02:04 localhost vmunix: [   48.171684] EXT4-fs (sda2): unmounting filesystem.
Nov  6 13:02:04 localhost installer[214]: running form #<newt-form 23725f0> ("Installation menu") with 0 clients 
Nov  6 13:02:05 localhost installer[214]: running step 'partition' 
Nov  6 13:02:05 localhost guile-parted: pointer->device!: #<pointer 0x2ac6860> 
Nov  6 13:02:05 localhost guile-parted: hash begin 
Nov  6 13:02:05 localhost guile-parted: hash: #<pointer 0x2ac6860> -> #<<device> bytestructure: #<bytestructure 0x7fab01c0a3e0>> 
Nov  6 13:02:05 localhost guile-parted: hash end 
Nov  6 13:02:05 localhost guile-parted: pointer->device!: #<pointer 0x2ac5390> 
Nov  6 13:02:05 localhost guile-parted: hash begin 
Nov  6 13:02:05 localhost guile-parted: hash: #<pointer 0x2ac6860> -> #<<device> bytestructure: #<bytestructure 0x7fab01c0a3e0>> 
Nov  6 13:02:05 localhost guile-parted: hash end 
Nov  6 13:02:05 localhost guile-parted: finalizer!: #<pointer 0x2ac5390> 
Nov  6 13:02:05 localhost installer[214]: /dev/sr0 is not eligible because it is the installation device. 
Nov  6 13:02:05 localhost installer[214]: running form #<newt-form 2af2e10> ("Partitioning method") with 0 clients 
Nov  6 13:02:07 localhost installer[214]: running form #<newt-form 2372290> ("Disk") with 0 clients 
Nov  6 13:02:07 localhost installer[214]: running form #<newt-form 2371bb0> ("Partition scheme") with 0 clients 
Nov  6 13:02:09 localhost installer[214]: Creating partition: 
Nov  6 13:02:09 localhost installer[214]: 	type: 0 
Nov  6 13:02:09 localhost installer[214]: 	filesystem-type: ext4 
Nov  6 13:02:09 localhost installer[214]: 	flags: () 
Nov  6 13:02:09 localhost installer[214]: 	start: 1126399 
Nov  6 13:02:09 localhost installer[214]: 	end: 2830869 
Nov  6 13:02:09 localhost installer[214]: 	start-range: [1126399, 1128447] 
Nov  6 13:02:09 localhost installer[214]: 	end-range: [2828821, 2830869] 
Nov  6 13:02:09 localhost installer[214]: 	constraint: #t 
Nov  6 13:02:09 localhost installer[214]: 	no-constraint: #t 
Nov  6 13:02:09 localhost installer[214]: Creating partition: 
Nov  6 13:02:09 localhost installer[214]: 	type: 0 
Nov  6 13:02:09 localhost installer[214]: 	filesystem-type: ext4 
Nov  6 13:02:09 localhost installer[214]: 	flags: () 
Nov  6 13:02:09 localhost installer[214]: 	start: 2830336 
Nov  6 13:02:09 localhost installer[214]: 	end: 6291455 
Nov  6 13:02:09 localhost installer[214]: 	start-range: [2830336, 2832384] 
Nov  6 13:02:09 localhost installer[214]: 	end-range: [6289407, 6291455] 
Nov  6 13:02:09 localhost installer[214]: 	constraint: #t 
Nov  6 13:02:09 localhost installer[214]: 	no-constraint: #t 
Nov  6 13:02:09 localhost installer[214]: running form #<newt-form 2373510> ("Guided partitioning") with 0 clients 
Nov  6 13:02:10 localhost installer[214]: running form #<newt-form 2365600> ("Password required") with 0 clients 
Nov  6 13:02:12 localhost installer[214]: running form #<newt-form 237a190> ("Password confirmation required") with 0 clients 
Nov  6 13:02:13 localhost installer[214]: running form #<newt-form 2376dc0> ("Password required") with 0 clients 
Nov  6 13:02:14 localhost installer[214]: running form #<newt-form 2370aa0> ("Password confirmation required") with 0 clients 
Nov  6 13:02:15 localhost installer[214]: running form #<newt-form 2379b50> ("Format disk?") with 0 clients 
Nov  6 13:02:16 localhost vmunix: [   60.768366]  sda: sda1 sda2 sda3
Nov  6 13:02:16 localhost installer[214]: Syncing /dev/sda took 0 seconds. 
Nov  6 13:02:16 localhost installer[214]: formatting and opening LUKS entry "cryptroot" at "/dev/sda2" 
Nov  6 13:02:22 localhost vmunix: [   66.619555] cryptd: max_cpu_qlen set to 1000
Nov  6 13:02:22 localhost installer[214]: mke2fs 1.46.4 (18-Aug-2021) 
Nov  6 13:02:22 localhost installer[214]: Creating filesystem with 212480 4k blocks and 53200 inodes 
Nov  6 13:02:22 localhost installer[214]: Filesystem UUID: 75b677f5-9b64-47a1-8134-918bd21ac919 
Nov  6 13:02:22 localhost installer[214]: Superblock backups stored on blocks:  
Nov  6 13:02:22 localhost installer[214]: 	32768, 98304, 163840 
Nov  6 13:02:22 localhost installer[214]:  
Nov  6 13:02:22 localhost installer[214]: Allocating group tables: 0/7^H^H^H   ^H^H^Hdone                             
Nov  6 13:02:22 localhost installer[214]: Writing inode tables: 0/7^H^H^H   ^H^H^Hdone                             
Nov  6 13:02:22 localhost installer[214]: Creating journal (4096 blocks): done 
Nov  6 13:02:22 localhost installer[214]: Writing superblocks and filesystem accounting information: 0/7^H^H^H   ^H^H^Hdone 
Nov  6 13:02:22 localhost installer[214]:  
Nov  6 13:02:22 localhost installer[214]: formatting and opening LUKS entry "crypthome" at "/dev/sda3" 
Nov  6 13:02:28 localhost installer[214]: mke2fs 1.46.4 (18-Aug-2021) 
Nov  6 13:02:28 localhost installer[214]: Creating filesystem with 431872 4k blocks and 107968 inodes 
Nov  6 13:02:28 localhost installer[214]: Filesystem UUID: c9c11eee-3459-48e3-bafd-39fc72478c96 
Nov  6 13:02:28 localhost installer[214]: Superblock backups stored on blocks:  
Nov  6 13:02:28 localhost installer[214]: 	32768, 98304, 163840, 229376, 294912 
Nov  6 13:02:28 localhost installer[214]:  
Nov  6 13:02:28 localhost installer[214]: Allocating group tables:  0/14^H^H^H^H^H     ^H^H^H^H^Hdone                             
Nov  6 13:02:28 localhost installer[214]: Writing inode tables:  0/14^H^H^H^H^H     ^H^H^H^H^Hdone                             
Nov  6 13:02:28 localhost installer[214]: Creating journal (8192 blocks): done 
Nov  6 13:02:29 localhost installer[214]: Writing superblocks and filesystem accounting information:  0/14^H^H^H^H^H 2/14^H^H^H^H^H     ^H^H^H^H^Hdone 
Nov  6 13:02:29 localhost installer[214]:  
Nov  6 13:02:29 localhost installer[214]: formatted 3 user partitions 
Nov  6 13:02:29 localhost installer[214]: user-partitions: (#<<user-partition> name: #f type: normal file-name: "/dev/sda1" disk-file-name: "/dev/sda" crypt-label: #f crypt-password: #f fs-type: fat32 bootable?: #t esp?: #t bios-grub?: #f size: #f start: #f end: #f mount-point: "/boot/efi" need-formatting?: #f parted-object: #<<partition> bytestructure: #<bytestructure 0x7faaffb13a00>>> #<<user-partition> name: #f type: normal file-name: "/dev/sda2" disk-file-name: "/dev/sda" crypt-label: "cryptroot" crypt-password: <secret> fs-type: ext4 bootable?: #f esp?: #f bios-grub?: #f size: "33%" start: "1126399s" end: "2830869s" mount-point: "/" need-formatting?: #t parted-object: #<<partition> bytestructure: #<bytestructure 0x7faaffb19120>>> #<<user-partition> name: #f type: normal file-name: "/dev/sda3" disk-file-name: "/dev/sda" crypt-label: "crypthome" crypt-password: <secret> fs-type: ext4 bootable?: #f esp?: #f bios-grub?: #f size: "100%" start: "2830336s" end: "6291455s" mount-point: "/home" need-formatting?: #t parted-object: #<<parti
Nov  6 13:02:29 localhost installer[214]: running step 'final' 
Nov  6 13:02:29 localhost installer[214]: proceeding with final step 
Nov  6 13:02:29 localhost parted[214]: parted: destroy: 0x2ac5390 
Nov  6 13:02:29 localhost installer[214]: mounting "/dev/mapper/cryptroot" on "/mnt/" 
Nov  6 13:02:29 localhost vmunix: [   73.440748] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Quota mode: none.
Nov  6 13:02:29 localhost installer[214]: mounting "/dev/sda1" on "/mnt/boot/efi" 
Nov  6 13:02:29 localhost vmunix: [   73.443772] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Nov  6 13:02:29 localhost installer[214]: mounting "/dev/mapper/crypthome" on "/mnt/home" 
Nov  6 13:02:29 localhost vmunix: [   73.446155] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Quota mode: none.
Nov  6 13:02:29 localhost installer[214]: running form #<newt-form 23762b0> ("Configuration file") with 0 clients 
Nov  6 13:02:31 localhost installer[214]: unmounting "/mnt/home" 
Nov  6 13:02:31 localhost vmunix: [   75.063631] EXT4-fs (dm-1): unmounting filesystem.
Nov  6 13:02:31 localhost installer[214]: closing LUKS entry "crypthome" 
Nov  6 13:02:31 localhost installer[214]: unmounting "/mnt/boot/efi" 
Nov  6 13:02:31 localhost installer[214]: unmounting "/mnt/" 
Nov  6 13:02:31 localhost vmunix: [   75.130823] EXT4-fs (dm-0): unmounting filesystem.
Nov  6 13:02:31 localhost installer[214]: closing LUKS entry "cryptroot" 
Nov  6 13:02:31 localhost installer[214]: running form #<newt-form 237d2d0> ("Installation menu") with 0 clients 
Nov  6 13:02:33 localhost installer[214]: running step 'partition' 
Nov  6 13:02:33 localhost parted[214]: parted: new: 0x2a05ff0 
Nov  6 13:02:33 localhost guile-parted: pointer->device!: #<pointer 0x2ac6860> 
Nov  6 13:02:33 localhost guile-parted: hash begin 
Nov  6 13:02:33 localhost guile-parted: hash: #<pointer 0x2ac6860> -> #<<device> bytestructure: #<bytestructure 0x7fab01c0a3e0>> 
Nov  6 13:02:33 localhost guile-parted: hash end 
Nov  6 13:02:33 localhost guile-parted: pointer->device!: #<pointer 0x2a05ff0> 
Nov  6 13:02:33 localhost guile-parted: hash begin 
Nov  6 13:02:33 localhost guile-parted: hash: #<pointer 0x2ac6860> -> #<<device> bytestructure: #<bytestructure 0x7fab01c0a3e0>> 
Nov  6 13:02:33 localhost guile-parted: hash end 
Nov  6 13:02:33 localhost guile-parted: finalizer!: #<pointer 0x2a05ff0> 
Nov  6 13:02:33 localhost installer[214]: /dev/sr0 is not eligible because it is the installation device. 
Nov  6 13:02:33 localhost installer[214]: running form #<newt-form 2ab7d10> ("Partitioning method") with 0 clients 
Nov  6 13:02:34 localhost vmunix: [   78.697023]  sda: sda1 sda2 sda3
Nov  6 13:02:34 localhost installer[214]: running form #<newt-form 237c580> ("Manual partitioning") with 0 clients 
Nov  6 13:02:36 localhost installer[214]: running form #<newt-form 2377dc0> ("Partition edit") with 0 clients 
Nov  6 13:02:37 localhost installer[214]: running form #<newt-form 23769a0> ("File-system type") with 0 clients 
Nov  6 13:02:38 localhost installer[214]: running form #<newt-form 2364f30> ("Partition edit") with 0 clients 
Nov  6 13:02:40 localhost installer[214]: running form #<newt-form 2375590> ("Encryption label") with 0 clients 
Nov  6 13:02:42 localhost installer[214]: running form #<newt-form 237a9d0> ("Partition edit") with 0 clients 
Nov  6 13:02:42 localhost installer[214]: running form #<newt-form 2380c30> ("Partition edit") with 0 clients 
Nov  6 13:02:43 localhost installer[214]: running form #<newt-form 2370130> ("Mounting point") with 0 clients 
Nov  6 13:02:44 localhost installer[214]: running form #<newt-form 2369a90> ("Partition edit") with 0 clients 
Nov  6 13:02:45 localhost installer[214]: running form #<newt-form 2365030> ("Manual partitioning") with 0 clients 
Nov  6 13:02:46 localhost installer[214]: running form #<newt-form 2368a90> ("Wrong partition format") with 0 clients 
Nov  6 13:02:47 localhost installer[214]: running form #<newt-form 2725430> ("Manual partitioning") with 0 clients 
Nov  6 13:02:49 localhost installer[214]: running form #<newt-form 237f8b0> ("Partition edit") with 0 clients 
Nov  6 13:02:50 localhost installer[214]: running form #<newt-form 2376c60> ("Partition edit") with 0 clients 
Nov  6 13:02:51 localhost installer[214]: running form #<newt-form 2375ef0> ("Manual partitioning") with 0 clients 
Nov  6 13:02:52 localhost installer[214]: running form #<newt-form 237a870> ("Password required") with 0 clients 
Nov  6 13:02:54 localhost installer[214]: running form #<newt-form 2ad65e0> ("Password confirmation required") with 0 clients 
Nov  6 13:02:54 localhost installer[214]: running form #<newt-form 2363050> ("Format disk?") with 0 clients 
Nov  6 13:02:56 localhost vmunix: [   99.965187]  sda: sda1 sda2 sda3
Nov  6 13:02:56 localhost installer[214]: Syncing /dev/sda took 0 seconds. 
Nov  6 13:02:56 localhost installer[214]: formatting and opening LUKS entry "e" at "/dev/sda3" 
Nov  6 13:03:02 localhost vmunix: [  105.915851] BTRFS: device fsid c4d0f5df-7e4f-414d-b4cb-4d638817d88b devid 1 transid 6 /dev/mapper/e scanned by mkfs.btrfs (374)
Nov  6 13:03:02 localhost installer[214]: btrfs-progs v5.18.1 
Nov  6 13:03:02 localhost installer[214]: See http://btrfs.wiki.kernel.org for more information. 
Nov  6 13:03:02 localhost installer[214]:  
Nov  6 13:03:02 localhost installer[214]: NOTE: several default settings have changed in version 5.15, please make sure 
Nov  6 13:03:02 localhost installer[214]:       this does not affect your deployments: 
Nov  6 13:03:02 localhost installer[214]:       - DUP for metadata (-m dup) 
Nov  6 13:03:02 localhost installer[214]:       - enabled no-holes (-O no-holes) 
Nov  6 13:03:02 localhost installer[214]:       - enabled free-space-tree (-R free-space-tree) 
Nov  6 13:03:02 localhost installer[214]:  
Nov  6 13:03:02 localhost installer[214]: Label:              (null) 
Nov  6 13:03:02 localhost installer[214]: UUID:               c4d0f5df-7e4f-414d-b4cb-4d638817d88b 
Nov  6 13:03:02 localhost installer[214]: Node size:          16384 
Nov  6 13:03:02 localhost installer[214]: Sector size:        4096 
Nov  6 13:03:02 localhost installer[214]: Filesystem size:    1.65GiB 
Nov  6 13:03:02 localhost installer[214]: Block group profiles: 
Nov  6 13:03:02 localhost installer[214]:   Data:             single            8.00MiB 
Nov  6 13:03:02 localhost installer[214]:   Metadata:         DUP              84.31MiB 
Nov  6 13:03:02 localhost installer[214]:   System:           DUP               8.00MiB 
Nov  6 13:03:02 localhost installer[214]: SSD detected:       no 
Nov  6 13:03:02 localhost installer[214]: Zoned device:       no 
Nov  6 13:03:02 localhost installer[214]: Incompat features:  extref, skinny-metadata, no-holes 
Nov  6 13:03:02 localhost installer[214]: Runtime features:   free-space-tree 
Nov  6 13:03:02 localhost installer[214]: Checksum:           crc32c 
Nov  6 13:03:02 localhost installer[214]: Number of devices:  1 
Nov  6 13:03:02 localhost installer[214]: Devices: 
Nov  6 13:03:02 localhost installer[214]:    ID        SIZE  PATH 
Nov  6 13:03:02 localhost installer[214]:     1     1.65GiB  /dev/mapper/e 
Nov  6 13:03:02 localhost installer[214]:  
Nov  6 13:03:02 localhost installer[214]: formatted 2 user partitions 
Nov  6 13:03:02 localhost installer[214]: user-partitions: (#<<user-partition> name: #f type: normal file-name: "/dev/sda3" disk-file-name: "/dev/sda" crypt-label: "e" crypt-password: <secret> fs-type: btrfs bootable?: #f esp?: #f bios-grub?: #f size: #f start: "2830336s" end: "6289407s" mount-point: "/" need-formatting?: #t parted-object: #<<partition> bytestructure: #<bytestructure 0x7fab0207a0a0>>> #<<user-partition> name: #f type: normal file-name: "/dev/sda1" disk-file-name: "/dev/sda" crypt-label: #f crypt-password: #f fs-type: fat32 bootable?: #t esp?: #t bios-grub?: #f size: #f start: #f end: #f mount-point: "/boot/efi" need-formatting?: #f parted-object: #<<partition> bytestructure: #<bytestructure 0x7fab020658a0>>>) 
Nov  6 13:03:02 localhost installer[214]: running step 'final' 
Nov  6 13:03:02 localhost installer[214]: proceeding with final step 
Nov  6 13:03:02 localhost vmunix: [  106.036661] traps: yhh15yy4yzmzgs3[215] trap invalid opcode ip:7fab1747d3c8 sp:7fab16ff9728 error:0
Nov  6 13:03:02 localhost installer[376]: Display is 128x42. 
Nov  6 13:03:02 localhost installer[376]: running step 'locale' 
Nov  6 13:03:02 localhost installer[376]: running step 'language' 
Nov  6 13:03:02 localhost installer[376]: running form #<newt-form ceeef0> ("Locale language") with 0 clients 
Nov  6 13:21:22 localhost -- MARK --
Nov  6 13:41:22 localhost -- MARK --
Nov  6 14:01:22 localhost -- MARK --
Nov  6 14:21:22 localhost -- MARK --
Nov  6 14:41:22 localhost -- MARK --
Nov  6 15:01:22 localhost -- MARK --
Nov  6 15:21:22 localhost -- MARK --
Nov  6 15:41:22 localhost -- MARK --
Nov  6 17:57:15 localhost -- MARK --

^ permalink raw reply related	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-06 17:17       ` Mathieu Othacehe
@ 2022-11-07 13:29         ` Ludovic Courtès
  2022-11-07 16:37           ` Mathieu Othacehe
  0 siblings, 1 reply; 10+ messages in thread
From: Ludovic Courtès @ 2022-11-07 13:29 UTC (permalink / raw)
  To: Mathieu Othacehe; +Cc: 58732

Hi Mathieu,

Mathieu Othacehe <othacehe@gnu.org> skribis:

> I made some progress on that one. I think, this is what's going on:
>
> 1. Two new PedDevice A and B are malloc'ed by the libparted when opening
> the installer partitioning page.
>
> 2. They are added to the %devices weak hash table by pointer->device!
> and their respective finalizers are registered.
>
> 3. The partitioning ends and A goes out of scope. It is eventually
> removed from %devices but it does not mean its finalizer will be run
> immediately.
>
> 4. The partitioning is restarted using the installer menu. B is still in
> the %devices hash table. However, A is now gone and is added again to
> the %devices hash table by the pointer->device! procedure. Another
> finalizer is registered for A.
>
> That's because set-pointer-finalizer! does not *set* a finalizer it
> *adds* one.

Oh, I think I see what you mean.  You’re right about
‘set-pointer-finalizer!’ adding a finalizer, but I don’t think that’s
what’s happening here.

Finalizers are set on pointer objects, so they’re invoked when the
pointer object goes out of scope.  But:

  (eq? (make-pointer 123) (make-pointer 123))
  => #f

So a possible mistake is to add one finalizer on each pointer object and
have several pointer objects aliasing the same C object; that’s how you
can get the same “free” function called several times on the same C
object.

> 5. The partitioning ends and both A and B goes out of scope. They are
> removed from %devices and their finalizers are called. The A finalizer
> is called twice resulting in a double free.
>
> This race condition is created by the fact that there is a time window
> where the device is removed from the %devices hash table but its
> finalizer is not immediately called.

What if we create an extra hashv table that maps pointer values
(integers) to pointer objects?

  (define %pointers (make-hash-table))

  (define (canonical-pointer ptr)
    (or (hashv-ref %pointers (pointer-address ptr))
        (begin
          (hashv-set! %pointers (pointer-address ptr) ptr)
          ptr)))

This is kinda terrible but it would allow us to test the above
hypothesis.

Thanks,
Ludo’.




^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-07 13:29         ` Ludovic Courtès
@ 2022-11-07 16:37           ` Mathieu Othacehe
  2022-11-09 15:25             ` Mathieu Othacehe
  0 siblings, 1 reply; 10+ messages in thread
From: Mathieu Othacehe @ 2022-11-07 16:37 UTC (permalink / raw)
  To: Ludovic Courtès; +Cc: 58732

[-- Attachment #1: Type: text/plain, Size: 1882 bytes --]


Hola,

> Finalizers are set on pointer objects, so they’re invoked when the
> pointer object goes out of scope.  But:
>
>   (eq? (make-pointer 123) (make-pointer 123))
>   => #f

I agree, but somehow this works:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> ,use (parted)
scheme@(guile-user)> (eq? (get-device "/tmp/test.img") (get-device "/tmp/test.img"))
$3 = #t
--8<---------------cut here---------------end--------------->8---

denoting that the "pointer->device!" procedure is working correctly and
the underlying pointer object returned by pointer->procedure is the
same.

> So a possible mistake is to add one finalizer on each pointer object and
> have several pointer objects aliasing the same C object; that’s how you
> can get the same “free” function called several times on the same C
> object.

I don't think that what's happening. I have monitored closely the
%devices weak hash table and it never exceeds the total device count.

We have multiple finalizers registered for the same C pointer but that's
because the weak hash table may be cleaned by (gc) calls, leaving the
opportunity for multiple finalizers registration on the same C pointer.

I attached a reproducer that exposes the double free issue.

--8<---------------cut here---------------start------------->8---
sudo -E guile ~/tmp/parted-bug.scm
double free or corruption (!prev)
Aborted
--8<---------------cut here---------------end--------------->8---

We could save up somewhere which pointers have registered finalizers but
that would prevent the devices garbage collection, in the same way as if
%device was a plain hash table and not a weak one.

That could well be a solution, as I cannot see at the moment how we
could preserve this mechanism and avoid multiple finalization.

Thanks,

Mathieu

[-- Attachment #2: parted-bug.scm --]
[-- Type: application/octet-stream, Size: 310 bytes --]

(use-modules (parted))

(define (probe)
  (probe-all-devices!)
  (get-device "/tmp/test.img")
  (devices)
  1)

(define (a)
  (probe)
  (probe)
  (probe)

  (let loop ((i 0))
    (when (< i 5)
      (sleep 1)
      (gc)
      (gc)
      (probe)
      (gc)
      (loop (+ 1 i)))))

(a)
(sleep 4)
(gc)
(gc)
(gc)

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-07 16:37           ` Mathieu Othacehe
@ 2022-11-09 15:25             ` Mathieu Othacehe
  2022-11-10 11:42               ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Mathieu Othacehe @ 2022-11-09 15:25 UTC (permalink / raw)
  To: Ludovic Courtès; +Cc: 58732

[-- Attachment #1: Type: text/plain, Size: 934 bytes --]


Hey,

I ran further tests and my understanding is that the weak hash-table /
finalizer mechanism is not compatible with a C function that can return
multiple times the same allocated object.

Even if we were to introduce a set-pointer-unique-finalizer! procedure
that calls scm_i_set_finalizer instead of scm_i_add_finalizer we would
still have double free errors because the finalizers are registered on
SCM pointers and not on libparted C pointers when calling
GC_REGISTER_FINALIZER_NO_ORDER.

I tested it out and I had several SCM pointers encapsulating the same
libparted C pointer, thus multiple finalizers on the same underlying C
pointer.

Anyway, here is a patch that solves the issue by removing the device
finalizer. It also means that all devices are persisted until the end of
the program which doesn't feel right, but I cannot think of a better
solution.

Let me know if you agree with my reasoning :)

Thanks,

Mathieu

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: 0001-Remove-the-finalizer-on-device-pointers.patch --]
[-- Type: text/x-patch, Size: 2238 bytes --]

From 066220a75c020b818aab9c2f5c3a7db835fa871a Mon Sep 17 00:00:00 2001
From: Mathieu Othacehe <othacehe@gnu.org>
Date: Wed, 9 Nov 2022 16:12:52 +0100
Subject: [PATCH 1/1] Remove the finalizer on device pointers.

Fixes: <https://issues.guix.gnu.org/58732>

* parted/device.scm (%device-destroy): Remove it.
(pointer->device!): Do not set a finalizer.
---
 parted/device.scm | 25 ++++++++++++++-----------
 1 file changed, 14 insertions(+), 11 deletions(-)

diff --git a/parted/device.scm b/parted/device.scm
index 56a774b..be7f0ac 100644
--- a/parted/device.scm
+++ b/parted/device.scm
@@ -43,20 +43,23 @@
             device-get-minimum-alignment
             device-get-optimum-alignment))
 
-;; Record all devices, so that pointer finalizers are only set once,
-;; even if get-device returns an already known pointer.  Use the
-;; pointer as key and the associated <device> as value.
-(define %devices (make-weak-value-hash-table))
-
-(define %device-destroy
-  (libparted->pointer "ped_device_destroy"))
-
+;; Record all devices, so that we do not end up with different <device>
+;; objects aliasing the same underlying C pointer. Use the pointer as key and
+;; the associated <device> as value.
+(define %devices (make-hash-table))
+
+;; %DEVICES was a weak hash-table and we used to set a finalizer on POINTER.
+;; This is inevitably causing double free issues for the following reason:
+;;
+;; When <device> goes out of scope and is removed from the %DEVICES table, the
+;; finalizer that is set on the underlying C pointer is still registered but
+;; possibly not called as finalization happens is a separate thread.  If a
+;; subsequent call to ped_device_get returns the same C pointer, another
+;; finalizer will be registered.  This means that the finalization function
+;; can be called twice on the same pointer, causing a double free issue.
 (define (pointer->device! pointer)
-  ;; Check if a finalizer is already registered for this pointer.
   (or (hash-ref %devices pointer)
       (let ((device (pointer->device pointer)))
-        ;; Contrary to its name, this "adds" a finalizer.
-        (set-pointer-finalizer! pointer %device-destroy)
         (hash-set! %devices pointer device)
         device)))
 
-- 
2.38.0


^ permalink raw reply related	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-09 15:25             ` Mathieu Othacehe
@ 2022-11-10 11:42               ` Ludovic Courtès
  2022-11-10 12:29                 ` Mathieu Othacehe
  0 siblings, 1 reply; 10+ messages in thread
From: Ludovic Courtès @ 2022-11-10 11:42 UTC (permalink / raw)
  To: Mathieu Othacehe; +Cc: 58732

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

> I tested it out and I had several SCM pointers encapsulating the same
> libparted C pointer, thus multiple finalizers on the same underlying C
> pointer.

Yes, that’s the idea I tried to convey.

> Anyway, here is a patch that solves the issue by removing the device
> finalizer. It also means that all devices are persisted until the end of
> the program which doesn't feel right, but I cannot think of a better
> solution.

Looking at device.c in Parted, that’s probably the right thing because
PedDevice objects are kept in a linked list whose head is stored in the
‘devices’ global variable of device.c.  So you cannot just free them
asynchronously from a finalizer thread because they might still be
accessed from other parts of the library.  This is the explanation that
should go in the comment, and it’s clearly a good reason not to free
those PedDevice objects.

Now, we could provide bindings for ‘ped_device_destroy’ that users could
explicitly call if they want to (this would be similar to explicit calls
to ‘close-port’).  We’d arrange to make it idempotent.

Thanks,
Ludo’.




^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#58732: installer: finalizers & device destroy segfault
  2022-11-10 11:42               ` Ludovic Courtès
@ 2022-11-10 12:29                 ` Mathieu Othacehe
  0 siblings, 0 replies; 10+ messages in thread
From: Mathieu Othacehe @ 2022-11-10 12:29 UTC (permalink / raw)
  To: Ludovic Courtès; +Cc: 58732-done


Hey,

> Looking at device.c in Parted, that’s probably the right thing because
> PedDevice objects are kept in a linked list whose head is stored in the
> ‘devices’ global variable of device.c.  So you cannot just free them
> asynchronously from a finalizer thread because they might still be
> accessed from other parts of the library.  This is the explanation that
> should go in the comment, and it’s clearly a good reason not to free
> those PedDevice objects.

If the finalizer was run synchronously when a device is removed from the
weak hash table then things would be OK. The device would be removed
from the global linked list by _device_register. get_device would malloc
a new structure and so on. However finalizers are not run synchronously
so here we are.

> Now, we could provide bindings for ‘ped_device_destroy’ that users could
> explicitly call if they want to (this would be similar to explicit calls
> to ‘close-port’).  We’d arrange to make it idempotent.

Sure.

Thanks for your help on that one. I pushed the proposed patch and updated
Guile-Parted to 0.0.7 in Guix.

Mathieu




^ permalink raw reply	[flat|nested] 10+ messages in thread

end of thread, other threads:[~2022-11-10 12:30 UTC | newest]

Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-10-23  9:07 bug#58732: installer: finalizers & device destroy segfault Mathieu Othacehe
2022-11-02 10:55 ` Ludovic Courtès
2022-11-03 11:09   ` Mathieu Othacehe
2022-11-03 11:25     ` Ludovic Courtès
2022-11-06 17:17       ` Mathieu Othacehe
2022-11-07 13:29         ` Ludovic Courtès
2022-11-07 16:37           ` Mathieu Othacehe
2022-11-09 15:25             ` Mathieu Othacehe
2022-11-10 11:42               ` Ludovic Courtès
2022-11-10 12:29                 ` Mathieu Othacehe

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/guix.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).