nixcloud / ip2unix

Turn IP sockets into Unix domain sockets
GNU Lesser General Public License v3.0
361 stars 10 forks source link

Multiple systemd-activated sockets are attached to wrong rules #27

Closed noc0lour closed 3 years ago

noc0lour commented 3 years ago

I'm currently observing with a commandline like:

/usr/local/bin/ip2unix -v -p -r in,tcp,port=8090,systemd=service1 -r in,tcp,port=1113,systemd=service2 -r out,ignore

That the systemd named filedescriptor "service1" is attached to the socket matching on the second rule and the second named filedescriptor is then not matched anymore. It seems to me there might be an off-by-one indexing error in the logic handling systemd named filedescriptors. I'll provide some additional logs once I reproduce on a separate test system.

With only one named systemd filedescriptor things work out fine.

aszlig commented 3 years ago

I'll provide some additional logs once I reproduce on a separate test system.

No need to, I was able to reproduce your issue in a small test, but so far it doesn't look like an indexing error:

NixOS VM test ```nix import { name = "ip2unix-systemd-multi"; machine = { pkgs, lib, ... }: let ip2unix = import ../.. { inherit pkgs lib; }; testServer = pkgs.writeScript "test-server.py" '' #!${pkgs.python3.interpreter} from functools import partial from selectors import DefaultSelector, EVENT_READ from http.server import BaseHTTPRequestHandler, HTTPServer class TestHandler(BaseHTTPRequestHandler): def __init__(self, *args, reply, **kwargs): self.reply = reply super().__init__(*args, **kwargs) def do_GET(self): self.send_response(200) self.send_header('Content-Type', 'text/plain') self.send_header('X-Reply', self.reply) self.end_headers() self.wfile.write(self.reply.encode()) selector = DefaultSelector() for port in [1113, 8090]: handler = partial(TestHandler, reply=f'port{port}') server = HTTPServer(('127.0.0.1', port), handler) selector.register(server, EVENT_READ, server.handle_request) while True: for event in selector.select(): event[0].data() ''; in { systemd.sockets.testsock1 = { description = "Test Socket 1 for Multiple Socket Test"; wantedBy = [ "sockets.target" ]; requiredBy = [ "socktest.service" ]; socketConfig.ListenStream = "/run/test1.sock"; socketConfig.FileDescriptorName = "socket1"; socketConfig.Service = "socktest.service"; }; systemd.sockets.testsock2 = { description = "Test Socket 2 for Multiple Socket Test"; wantedBy = [ "sockets.target" ]; requiredBy = [ "socktest.service" ]; socketConfig.ListenStream = "/run/test2.sock"; socketConfig.FileDescriptorName = "socket2"; socketConfig.Service = "socktest.service"; }; systemd.services.canary = { description = "Canary Service to verify implementation"; after = [ "network.target" ]; requiredBy = [ "multi-user.target" ]; serviceConfig.User = "testuser"; serviceConfig.Group = "testgroup"; serviceConfig.ExecStart = testServer; }; systemd.services.socktest = { description = "Test Service for Multiple Socket Test"; serviceConfig.User = "testuser"; serviceConfig.Group = "testgroup"; serviceConfig.ExecStart = lib.escapeShellArgs [ "${ip2unix}/bin/ip2unix" "-r" "in,tcp,port=8090,systemd=socket1" "-r" "in,tcp,port=1113,systemd=socket2" "-r" "out,ignore" testServer ]; }; users.users.testuser.isSystemUser = true; users.users.testuser.group = "testgroup"; users.groups.testgroup = {}; }; testScript = { nodes, ... }: '' machine.wait_for_unit('multi-user.target') for n, port in enumerate([8090, 1113], start=1): for args in [f'http://127.0.0.1:{port}/', f'--unix-socket /run/test{n}.sock http://test/']: cmd = f'test "$(curl --no-progress-meter -v {args})" = port{port}' machine.succeed(cmd) ''; } ```

When adding -vvvvv to the ip2unix call, we get:

ip2unix:systemd.cc:223:init Matched systemd unix file descriptor name 'socket1' (fd 3) with rule #0.
ip2unix:systemd.cc:223:init Matched systemd unix file descriptor name 'socket2' (fd 4) with rule #1.

Rule #0 maps to port 8090, which in turn has a FileDescriptorName of socket1, so this part looks correct.

However, where things go bonkers is a bit later:

ip2unix:preload.cc:252:operator() Systemd file descriptor queue empty, blackholing socket with fd 3.
ip2unix:socket.cc:97:blackhole Socket with fd 3 blackholed.
Full log output ``` starting VDE switch for network 1 running the VM test script machine: waiting for the VM to finish booting machine: starting vm machine # Formatting '/build/vm-state-machine/machine.qcow2', fmt=qcow2 cluster_size=65536 extended_l2=off compression_type=zlib size=536870912 lazy_refcounts=off refcount_bits=16 machine: QEMU running (pid 10) machine # SeaBIOS (version rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org) machine # machine # machine # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+17F8EE30+17EEEE30 CA00 machine # Press Ctrl-B to configure iPXE (PCI 00:03.0)... machine # machine # machine # machine # machine # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 17F8EE30 17EEEE30 CB00 machine # Press Ctrl-B to configure iPXE (PCI 00:09.0)... machine # machine # machine # Booting from ROM... machine # Probing EDD (edd=off to disable)... oP Fri Jun 18 08:00:06 UTC 2021 machine # [ 0.000000] Command line: console=ttyS0 panic=1 boot.panic_on_fail loglevel=7 net.ifnames=0 init=/nix/store/2f3vd830c5cg657q78xc3akbdyg2dzpn-nixos-system-machine-21.11pre299942.09c38c29f2c-vuizvui/init regInfo=/nix/store/zl6fvd3pmq8b5naybnb8y4wn16rqywi9-closure-info/registration console=ttyS0 machine # [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' machine # [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' machine # [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' machine # [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 machine # [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format. machine # [ 0.000000] BIOS-provided physical RAM map: machine # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable machine # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved machine # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved machine # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x0000000017fdafff] usable machine # [ 0.000000] BIOS-e820: [mem 0x0000000017fdb000-0x0000000017ffffff] reserved machine # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved machine # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved machine # [ 0.000000] NX (Execute Disable) protection: active machine # [ 0.000000] SMBIOS 2.8 present. machine # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014 machine # [ 0.000000] Hypervisor detected: KVM machine # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 machine # [ 0.000000] kvm-clock: cpu 0, msr 7b1f001, primary cpu clock machine # [ 0.000000] kvm-clock: using sched offset of 211280728 cycles machine # [ 0.000001] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns machine # [ 0.000002] tsc: Detected 3992.496 MHz processor machine # [ 0.000637] last_pfn = 0x17fdb max_arch_pfn = 0x400000000 machine # [ 0.000668] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT machine # [ 0.002513] found SMP MP-table at [mem 0x000f5a60-0x000f5a6f] machine # [ 0.002609] check: Scanning 1 areas for low memory corruption machine # [ 0.002621] Using GB pages for direct mapping machine # [ 0.002688] RAMDISK: [mem 0x1777d000-0x17fcffff] machine # [ 0.002691] ACPI: Early table checksum verification disabled machine # [ 0.002693] ACPI: RSDP 0x00000000000F5880 000014 (v00 BOCHS ) machine # [ 0.002696] ACPI: RSDT 0x0000000017FE18FE 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) machine # [ 0.002699] ACPI: FACP 0x0000000017FE17B2 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) machine # [ 0.002702] ACPI: DSDT 0x0000000017FE0040 001772 (v01 BOCHS BXPC 00000001 BXPC 00000001) machine # [ 0.002704] ACPI: FACS 0x0000000017FE0000 000040 machine # [ 0.002706] ACPI: APIC 0x0000000017FE1826 000078 (v01 BOCHS BXPC 00000001 BXPC 00000001) machine # [ 0.002707] ACPI: HPET 0x0000000017FE189E 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) machine # [ 0.002709] ACPI: WAET 0x0000000017FE18D6 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) machine # [ 0.002711] ACPI: Reserving FACP table memory at [mem 0x17fe17b2-0x17fe1825] machine # [ 0.002712] ACPI: Reserving DSDT table memory at [mem 0x17fe0040-0x17fe17b1] machine # [ 0.002713] ACPI: Reserving FACS table memory at [mem 0x17fe0000-0x17fe003f] machine # [ 0.002713] ACPI: Reserving APIC table memory at [mem 0x17fe1826-0x17fe189d] machine # [ 0.002714] ACPI: Reserving HPET table memory at [mem 0x17fe189e-0x17fe18d5] machine # [ 0.002715] ACPI: Reserving WAET table memory at [mem 0x17fe18d6-0x17fe18fd] machine # [ 0.002826] No NUMA configuration found machine # [ 0.002826] Faking a node at [mem 0x0000000000000000-0x0000000017fdafff] machine # [ 0.002828] NODE_DATA(0) allocated [mem 0x17fd6000-0x17fdafff] machine # [ 0.002841] Zone ranges: machine # [ 0.002841] DMA [mem 0x0000000000001000-0x0000000000ffffff] machine # [ 0.002842] DMA32 [mem 0x0000000001000000-0x0000000017fdafff] machine # [ 0.002843] Normal empty machine # [ 0.002844] Device empty machine # [ 0.002845] Movable zone start for each node machine # [ 0.002845] Early memory node ranges machine # [ 0.002846] node 0: [mem 0x0000000000001000-0x000000000009efff] machine # [ 0.002847] node 0: [mem 0x0000000000100000-0x0000000017fdafff] machine # [ 0.002848] Initmem setup node 0 [mem 0x0000000000001000-0x0000000017fdafff] machine # [ 0.003175] DMA zone: 28770 pages in unavailable ranges machine # [ 0.003753] DMA32 zone: 37 pages in unavailable ranges machine # [ 0.003952] ACPI: PM-Timer IO Port: 0x608 machine # [ 0.003957] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) machine # [ 0.003969] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 machine # [ 0.003970] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) machine # [ 0.003972] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) machine # [ 0.003972] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) machine # [ 0.003973] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) machine # [ 0.003974] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) machine # [ 0.003977] Using ACPI (MADT) for SMP configuration information machine # [ 0.003978] ACPI: HPET id: 0x8086a201 base: 0xfed00000 machine # [ 0.003979] TSC deadline timer available machine # [ 0.003981] smpboot: Allowing 1 CPUs, 0 hotplug CPUs machine # [ 0.003985] kvm-guest: KVM setup pv remote TLB flush machine # [ 0.003989] kvm-guest: setup PV sched yield machine # [ 0.003994] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff] machine # [ 0.003995] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x0009ffff] machine # [ 0.003995] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000effff] machine # [ 0.003996] PM: hibernation: Registered nosave memory: [mem 0x000f0000-0x000fffff] machine # [ 0.003997] [mem 0x18000000-0xfeffbfff] available for PCI devices machine # [ 0.003997] Booting paravirtualized kernel on KVM machine # [ 0.003999] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns machine # [ 0.006744] setup_percpu: NR_CPUS:384 nr_cpumask_bits:384 nr_cpu_ids:1 nr_node_ids:1 machine # [ 0.006933] percpu: Embedded 54 pages/cpu s183384 r8192 d29608 u2097152 machine # [ 0.006953] kvm-guest: KVM setup async PF for cpu 0 machine # [ 0.006956] kvm-guest: stealtime: cpu 0, msr 16e18540 machine # [ 0.006958] kvm-guest: PV spinlocks disabled, single CPU machine # [ 0.006960] Built 1 zonelists, mobility grouping on. Total pages: 96612 machine # [ 0.006960] Policy zone: DMA32 machine # [ 0.006961] Kernel command line: console=ttyS0 panic=1 boot.panic_on_fail loglevel=7 net.ifnames=0 init=/nix/store/2f3vd830c5cg657q78xc3akbdyg2dzpn-nixos-system-machine-21.11pre299942.09c38c29f2c-vuizvui/init regInfo=/nix/store/zl6fvd3pmq8b5naybnb8y4wn16rqywi9-closure-info/registration console=ttyS0 machine # [ 0.007020] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes, linear) machine # [ 0.007038] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes, linear) machine # [ 0.007049] mem auto-init: stack:off, heap alloc:off, heap free:off machine # [ 0.007482] Memory: 349936K/392676K available (12295K kernel code, 2200K rwdata, 2400K rodata, 1556K init, 1032K bss, 42480K reserved, 0K cma-reserved) machine # [ 0.007503] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 machine # [ 0.007509] ftrace: allocating 33669 entries in 132 pages machine # [ 0.015402] ftrace: allocated 132 pages with 2 groups machine # [ 0.015586] rcu: Hierarchical RCU implementation. machine # [ 0.015587] rcu: RCU event tracing is enabled. machine # [ 0.015588] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1. machine # [ 0.015589] Trampoline variant of Tasks RCU enabled. machine # [ 0.015589] Rude variant of Tasks RCU enabled. machine # [ 0.015590] Tracing variant of Tasks RCU enabled. machine # [ 0.015590] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. machine # [ 0.015591] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1 machine # [ 0.017844] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16 machine # [ 0.018113] random: crng done (trusting CPU's manufacturer) machine # [ 0.019956] Console: colour VGA+ 80x25 machine # [ 0.057958] printk: console [ttyS0] enabled machine # [ 0.058189] ACPI: Core revision 20200925 machine # [ 0.058460] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns machine # [ 0.058997] APIC: Switch to symmetric I/O mode setup machine # [ 0.059360] x2apic enabled machine # [ 0.059603] Switched APIC routing to physical x2apic. machine # [ 0.059880] kvm-guest: setup PV IPIs machine # [ 0.060611] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 machine # [ 0.060942] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x731956d9b7a, max_idle_ns: 881590693066 ns machine # [ 0.061503] Calibrating delay loop (skipped) preset value.. 7984.99 BogoMIPS (lpj=3992496) machine # [ 0.061936] pid_max: default: 32768 minimum: 301 machine # [ 0.062512] LSM: Security Framework initializing machine # [ 0.062758] Yama: becoming mindful. machine # [ 0.062945] SELinux: Initializing. machine # [ 0.063143] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes, linear) machine # [ 0.063504] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes, linear) machine # [ 0.064060] x86/cpu: User Mode Instruction Prevention (UMIP) activated machine # [ 0.064558] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127 machine # [ 0.064861] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0 machine # [ 0.065200] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization machine # [ 0.065504] Spectre V2 : Mitigation: Full AMD retpoline machine # [ 0.065778] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch machine # [ 0.066504] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier machine # [ 0.066944] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp machine # [ 0.069401] Freeing SMP alternatives memory: 32K machine # [ 0.070648] smpboot: CPU0: AMD Ryzen Threadripper PRO 3945WX 12-Cores (family: 0x17, model: 0x31, stepping: 0x0) machine # [ 0.071272] Performance Events: Fam17h+ core perfctr, AMD PMU driver. machine # [ 0.071502] ... version: 0 machine # [ 0.071505] ... bit width: 48 machine # [ 0.071721] ... generic registers: 6 machine # [ 0.071931] ... value mask: 0000ffffffffffff machine # [ 0.072214] ... max period: 00007fffffffffff machine # [ 0.072495] ... fixed-purpose events: 0 machine # [ 0.072504] ... event mask: 000000000000003f machine # [ 0.072823] rcu: Hierarchical SRCU implementation. machine # [ 0.073407] smp: Bringing up secondary CPUs ... machine # [ 0.073505] smp: Brought up 1 node, 1 CPU machine # [ 0.073720] smpboot: Max logical packages: 1 machine # [ 0.073943] smpboot: Total of 1 processors activated (7984.99 BogoMIPS) machine # [ 0.074359] devtmpfs: initialized machine # [ 0.074526] x86/mm: Memory block size: 128MB machine # [ 0.074848] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns machine # [ 0.075362] futex hash table entries: 256 (order: 2, 16384 bytes, linear) machine # [ 0.075524] pinctrl core: initialized pinctrl subsystem machine # [ 0.075903] NET: Registered protocol family 16 machine # [ 0.076174] audit: initializing netlink subsys (disabled) machine # [ 0.076521] thermal_sys: Registered thermal governor 'bang_bang' machine # [ 0.076521] thermal_sys: Registered thermal governor 'step_wise' machine # [ 0.076841] thermal_sys: Registered thermal governor 'user_space' machine # [ 0.077157] cpuidle: using governor menu machine # [ 0.077737] ACPI: bus type PCI registered machine # [ 0.077951] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 machine # [ 0.078340] PCI: Using configuration type 1 for base access machine # [ 0.078504] PCI: Using configuration type 1 for extended access machine # [ 0.079175] Kprobes globally optimized machine # [ 0.079387] audit: type=2000 audit(1625661423.158:1): state=initialized audit_enabled=0 res=1 machine # [ 0.079540] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages machine # [ 0.079900] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages machine # [ 0.080423] ACPI: Added _OSI(Module Device) machine # [ 0.080506] ACPI: Added _OSI(Processor Device) machine # [ 0.080746] ACPI: Added _OSI(3.0 _SCP Extensions) machine # [ 0.080993] ACPI: Added _OSI(Processor Aggregator Device) machine # [ 0.081277] ACPI: Added _OSI(Linux-Dell-Video) machine # [ 0.081504] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio) machine # [ 0.081787] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics) machine # [ 0.082380] ACPI: 1 ACPI AML tables successfully acquired and loaded machine # [ 0.083153] ACPI: Interpreter enabled machine # [ 0.083364] ACPI: (supports S0 S3 S4 S5) machine # [ 0.083516] ACPI: Using IOAPIC for interrupt routing machine # [ 0.083785] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug machine # [ 0.084311] ACPI: Enabled 2 GPEs in block 00 to 0F machine # [ 0.085479] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) machine # [ 0.085513] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] machine # [ 0.086035] acpiphp: Slot [3] registered machine # [ 0.086254] acpiphp: Slot [4] registered machine # [ 0.086472] acpiphp: Slot [5] registered machine # [ 0.086514] acpiphp: Slot [6] registered machine # [ 0.086736] acpiphp: Slot [7] registered machine # [ 0.086953] acpiphp: Slot [8] registered machine # [ 0.087173] acpiphp: Slot [9] registered machine # [ 0.087389] acpiphp: Slot [10] registered machine # [ 0.087513] acpiphp: Slot [11] registered machine # [ 0.087740] acpiphp: Slot [12] registered machine # [ 0.087960] acpiphp: Slot [13] registered machine # [ 0.088182] acpiphp: Slot [14] registered machine # [ 0.088402] acpiphp: Slot [15] registered machine # [ 0.088513] acpiphp: Slot [16] registered machine # [ 0.088735] acpiphp: Slot [17] registered machine # [ 0.088961] acpiphp: Slot [18] registered machine # [ 0.089182] acpiphp: Slot [19] registered machine # [ 0.089403] acpiphp: Slot [20] registered machine # [ 0.089512] acpiphp: Slot [21] registered machine # [ 0.089739] acpiphp: Slot [22] registered machine # [ 0.089962] acpiphp: Slot [23] registered machine # [ 0.090183] acpiphp: Slot [24] registered machine # [ 0.090410] acpiphp: Slot [25] registered machine # [ 0.090512] acpiphp: Slot [26] registered machine # [ 0.090735] acpiphp: Slot [27] registered machine # [ 0.090956] acpiphp: Slot [28] registered machine # [ 0.091183] acpiphp: Slot [29] registered machine # [ 0.091410] acpiphp: Slot [30] registered machine # [ 0.091513] acpiphp: Slot [31] registered machine # [ 0.091731] PCI host bridge to bus 0000:00 machine # [ 0.091949] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] machine # [ 0.092309] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] machine # [ 0.092505] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] machine # [ 0.092895] pci_bus 0000:00: root bus resource [mem 0x18000000-0xfebfffff window] machine # [ 0.093288] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window] machine # [ 0.093504] pci_bus 0000:00: root bus resource [bus 00-ff] machine # [ 0.093859] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 machine # [ 0.094401] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 machine # [ 0.094742] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 machine # [ 0.096659] pci 0000:00:01.1: reg 0x20: [io 0xc1c0-0xc1cf] machine # [ 0.097514] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] machine # [ 0.097895] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] machine # [ 0.098236] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] machine # [ 0.098505] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] machine # [ 0.098920] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 machine # [ 0.100851] pci 0000:00:01.2: reg 0x20: [io 0xc0c0-0xc0df] machine # [ 0.102173] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 machine # [ 0.102661] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI machine # [ 0.103048] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB machine # [ 0.103517] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 machine # [ 0.104505] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref] machine # [ 0.105829] pci 0000:00:02.0: reg 0x18: [mem 0xfebd0000-0xfebd0fff] machine # [ 0.108867] pci 0000:00:02.0: reg 0x30: [mem 0xfebc0000-0xfebcffff pref] machine # [ 0.109417] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 machine # [ 0.110505] pci 0000:00:03.0: reg 0x10: [io 0xc0e0-0xc0ff] machine # [ 0.112309] pci 0000:00:03.0: reg 0x14: [mem 0xfebd1000-0xfebd1fff] machine # [ 0.114505] pci 0000:00:03.0: reg 0x20: [mem 0xfe000000-0xfe003fff 64bit pref] machine # [ 0.115505] pci 0000:00:03.0: reg 0x30: [mem 0xfeb40000-0xfeb7ffff pref] machine # [ 0.116172] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 machine # [ 0.117047] pci 0000:00:04.0: reg 0x10: [io 0xc100-0xc11f] machine # [ 0.119347] pci 0000:00:04.0: reg 0x20: [mem 0xfe004000-0xfe007fff 64bit pref] machine # [ 0.121297] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 machine # [ 0.122332] pci 0000:00:05.0: reg 0x10: [io 0xc120-0xc13f] machine # [ 0.123252] pci 0000:00:05.0: reg 0x14: [mem 0xfebd2000-0xfebd2fff] machine # [ 0.125505] pci 0000:00:05.0: reg 0x20: [mem 0xfe008000-0xfe00bfff 64bit pref] machine # [ 0.126821] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 machine # [ 0.127904] pci 0000:00:06.0: reg 0x10: [io 0xc140-0xc15f] machine # [ 0.128883] pci 0000:00:06.0: reg 0x14: [mem 0xfebd3000-0xfebd3fff] machine # [ 0.132305] pci 0000:00:06.0: reg 0x20: [mem 0xfe00c000-0xfe00ffff 64bit pref] machine # [ 0.133581] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 machine # [ 0.134505] pci 0000:00:07.0: reg 0x10: [io 0xc160-0xc17f] machine # [ 0.135505] pci 0000:00:07.0: reg 0x14: [mem 0xfebd4000-0xfebd4fff] machine # [ 0.137906] pci 0000:00:07.0: reg 0x20: [mem 0xfe010000-0xfe013fff 64bit pref] machine # [ 0.139219] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 machine # [ 0.140383] pci 0000:00:08.0: reg 0x10: [io 0xc000-0xc07f] machine # [ 0.141337] pci 0000:00:08.0: reg 0x14: [mem 0xfebd5000-0xfebd5fff] machine # [ 0.143505] pci 0000:00:08.0: reg 0x20: [mem 0xfe014000-0xfe017fff 64bit pref] machine # [ 0.144821] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 machine # [ 0.145886] pci 0000:00:09.0: reg 0x10: [io 0xc180-0xc19f] machine # [ 0.146884] pci 0000:00:09.0: reg 0x14: [mem 0xfebd6000-0xfebd6fff] machine # [ 0.149393] pci 0000:00:09.0: reg 0x20: [mem 0xfe018000-0xfe01bfff 64bit pref] machine # [ 0.150329] pci 0000:00:09.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] machine # [ 0.150820] pci 0000:00:0a.0: [1af4:1003] type 00 class 0x078000 machine # [ 0.151888] pci 0000:00:0a.0: reg 0x10: [io 0xc080-0xc0bf] machine # [ 0.152891] pci 0000:00:0a.0: reg 0x14: [mem 0xfebd7000-0xfebd7fff] machine # [ 0.155303] pci 0000:00:0a.0: reg 0x20: [mem 0xfe01c000-0xfe01ffff 64bit pref] machine # [ 0.156594] pci 0000:00:0b.0: [1af4:1005] type 00 class 0x00ff00 machine # [ 0.157460] pci 0000:00:0b.0: reg 0x10: [io 0xc1a0-0xc1bf] machine # [ 0.160297] pci 0000:00:0b.0: reg 0x20: [mem 0xfe020000-0xfe023fff 64bit pref] machine # [ 0.161474] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) machine # [ 0.161555] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11) machine # [ 0.161892] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11) machine # [ 0.162230] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11) machine # [ 0.162529] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) machine # [ 0.162885] iommu: Default domain type: Translated machine # [ 0.163177] pci 0000:00:02.0: vgaarb: setting as boot VGA device machine # [ 0.163495] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none machine # [ 0.163505] pci 0000:00:02.0: vgaarb: bridge control possible machine # [ 0.163811] vgaarb: loaded machine # [ 0.164102] NetLabel: Initializing machine # [ 0.164289] NetLabel: domain hash size = 128 machine # [ 0.164504] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO machine # [ 0.164814] NetLabel: unlabeled traffic allowed by default machine # [ 0.165111] PCI: Using ACPI for IRQ routing machine # [ 0.165444] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 machine # [ 0.165505] hpet0: 3 comparators, 64-bit 100.000000 MHz counter machine # [ 0.167514] clocksource: Switched to clocksource kvm-clock machine # [ 0.173902] VFS: Disk quotas dquot_6.6.0 machine # [ 0.174128] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) machine # [ 0.174522] pnp: PnP ACPI init machine # [ 0.174847] pnp: PnP ACPI: found 6 devices machine # [ 0.180127] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns machine # [ 0.180629] NET: Registered protocol family 2 machine # [ 0.180879] IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear) machine # [ 0.181367] tcp_listen_portaddr_hash hash table entries: 256 (order: 0, 4096 bytes, linear) machine # [ 0.181811] TCP established hash table entries: 4096 (order: 3, 32768 bytes, linear) machine # [ 0.182222] TCP bind hash table entries: 4096 (order: 4, 65536 bytes, linear) machine # [ 0.182616] TCP: Hash tables configured (established 4096 bind 4096) machine # [ 0.182962] MPTCP token hash table entries: 512 (order: 1, 12288 bytes, linear) machine # [ 0.183347] UDP hash table entries: 256 (order: 1, 8192 bytes, linear) machine # [ 0.183696] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear) machine # [ 0.184081] NET: Registered protocol family 1 machine # [ 0.184316] NET: Registered protocol family 44 machine # [ 0.184574] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] machine # [ 0.184903] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] machine # [ 0.185231] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] machine # [ 0.185595] pci_bus 0000:00: resource 7 [mem 0x18000000-0xfebfffff window] machine # [ 0.185957] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window] machine # [ 0.186342] pci 0000:00:01.0: PIIX3: Enabling Passive Release machine # [ 0.186657] pci 0000:00:00.0: Limiting direct PCI/PCI transfers machine # [ 0.186976] pci 0000:00:01.0: Activating ISA DMA hang workarounds machine # [ 0.196815] PCI Interrupt Link [LNKD] enabled at IRQ 11 machine # [ 0.206859] pci 0000:00:01.2: quirk_usb_early_handoff+0x0/0x700 took 19093 usecs machine # [ 0.207273] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] machine # [ 0.207750] PCI: CLS 0 bytes, default 64 machine # [ 0.207981] Trying to unpack rootfs image as initramfs... machine # [ 0.246094] Freeing initrd memory: 8524K machine # [ 0.246358] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x731956d9b7a, max_idle_ns: 881590693066 ns machine # [ 0.246925] check: Scanning for low memory corruption every 60 seconds machine # [ 0.247749] Initialise system trusted keyrings machine # [ 0.248025] workingset: timestamp_bits=40 max_order=17 bucket_order=0 machine # [ 0.248968] zbud: loaded machine # [ 0.249222] Key type asymmetric registered machine # [ 0.249447] Asymmetric key parser 'x509' registered machine # [ 0.249718] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251) machine # [ 0.250133] io scheduler mq-deadline registered machine # [ 0.250375] io scheduler kyber registered machine # [ 0.250686] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled machine # [ 0.251081] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A machine # [ 0.251653] drop_monitor: Initializing network drop monitor service machine # [ 0.252067] NET: Registered protocol family 10 machine # [ 0.252546] Segment Routing with IPv6 machine # [ 0.252815] IPI shorthand broadcast: enabled machine # [ 0.253051] sched_clock: Marking stable (212004391, 40501117)->(272486377, -19980869) machine # [ 0.253496] registered taskstats version 1 machine # [ 0.253724] Loading compiled-in X.509 certificates machine # [ 0.253989] zswap: loaded using pool lzo/zbud machine # [ 0.254265] Key type ._fscrypt registered machine # [ 0.254481] Key type .fscrypt registered machine # [ 0.254700] Key type fscrypt-provisioning registered machine # [ 0.256204] Freeing unused kernel image (initmem) memory: 1556K machine # [ 0.257508] Write protecting the kernel read-only data: 18432k machine # [ 0.258071] Freeing unused kernel image (text/rodata gap) memory: 2040K machine # [ 0.258592] Freeing unused kernel image (rodata/data gap) memory: 1696K machine # [ 0.258957] Run /init as init process machine # machine # <<< NixOS Stage 1 >>> machine # machine # loading module virtio_balloon... machine # loading module virtio_console... machine # loading module virtio_rng... machine # loading module dm_mod... machine # [ 0.284104] device-mapper: ioctl: 4.43.0-ioctl (2020-10-01) initialised: dm-devel@redhat.com machine # running udev... machine # Starting version 247 machine # [ 0.307743] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 machine # [ 0.313209] rtc_cmos 00:05: RTC can wake from S4 machine # [ 0.313571] serio: i8042 KBD port at 0x60,0x64 irq 1 machine # [ 0.313844] serio: i8042 AUX port at 0x60,0x64 irq 12 machine # [ 0.315872] rtc_cmos 00:05: registered as rtc0 machine # [ 0.316129] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs machine # [ 0.354619] SCSI subsystem initialized machine # [ 0.365566] PCI Interrupt Link [LNKC] enabled at IRQ 10 machine # [ 0.366734] ACPI: bus type USB registered machine # [ 0.366967] usbcore: registered new interface driver usbfs machine # [ 0.367263] usbcore: registered new interface driver hub machine # [ 0.367555] usbcore: registered new device driver usb machine # [ 0.381556] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver machine # [ 0.388086] uhci_hcd: USB Universal Host Controller Interface driver machine # [ 0.399519] scsi host0: ata_piix machine # [ 0.403516] scsi host1: ata_piix machine # [ 0.403714] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1c0 irq 14 machine # [ 0.404078] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1c8 irq 15 machine # [ 0.437251] uhci_hcd 0000:00:01.2: UHCI Host Controller machine # [ 0.437540] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1 machine # [ 0.437939] uhci_hcd 0000:00:01.2: detected 2 ports machine # [ 0.438229] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c0c0 machine # [ 0.438574] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.10 machine # [ 0.439035] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 machine # [ 0.439417] usb usb1: Product: UHCI Host Controller machine # [ 0.439695] usb usb1: Manufacturer: Linux 5.10.45 uhci_hcd machine # [ 0.439991] usb usb1: SerialNumber: 0000:00:01.2 machine # [ 0.440367] PCI Interrupt Link [LNKA] enabled at IRQ 10 machine # [ 0.440688] hub 1-0:1.0: USB hub found machine # [ 0.441415] hub 1-0:1.0: 2 ports detected machine # [ 0.457387] PCI Interrupt Link [LNKB] enabled at IRQ 11 machine # [ 0.562956] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 machine # [ 0.563851] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 machine # [ 0.571492] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0 machine # [ 0.589312] virtio_blk virtio5: [vda] 1048576 512-byte logical blocks (537 MB/512 MiB) machine # [ 0.589781] vda: detected capacity change from 0 to 536870912 machine # [ 0.592634] 9pnet: Installing 9P2000 support machine # [ 0.611767] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray machine # [ 0.612170] cdrom: Uniform CD-ROM driver Revision: 3.20 machine # [ 0.660508] usb 1-1: new full-speed USB device number 2 using uhci_hcd machine # kbd_mode: KDSKBMODE: Inappropriate ioctl for device machine # apper and LVM... machine # [ 0.823185] clocksource: Switched to clocksource acpi_pm machine # mke2fs 1.46.2 (28-Feb-2021) machine # Discarding device blocks: 4096/131072 done machine # Creating filesystem with 131072 4k blocks and 32768 inodes machine # Filesystem UUID: 1e27c197-beb1-4b0e-afbc-16c684e9006c[ 0.828481] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 machine # [ 0.828970] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10 machine # [ 0.829406] usb 1-1: Product: QEMU USB Tablet machine # [ 0.829666] usb 1-1: Manufacturer: QEMU machine # [ 0.829889] usb 1-1: SerialNumber: 28754-0000:00:01.2-1 machine # machine # Superblock backups stored on blocks: machine # 32768, 98304 machine # machine # Allocating group tables: 0/4 done machine # [ 0.838882] hid: raw HID events driver (C) Jiri Kosina machine # [ 0.844845] usbcore: registered new interface driver usbhid machine # [ 0.845171] usbhid: USB HID core driver machine # [ 0.846143] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2 machine # [ 0.846938] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0 machine # Writing inode tables: 0/4 done machine # Creating journal (4096 blocks): done machine # Writing superblocks and filesystem accounting information: 0/4 done machine # machine # checking /dev/vda... machine # fsck (busybox 1.33.1) machine # [fsck.ext4 (1) -- /mnt-root/] fsck.ext4 -a /dev/vda machine # /dev/vda: clean, 11/32768 files, 6353/131072 blocks machine # mounting /dev/vda on /... machine # [ 0.968693] EXT4-fs (vda): mounted filesystem with ordered data mode. Opts: (null) machine # mounting store on /nix/.ro-store... machine # [ 0.980670] FS-Cache: Loaded machine # [ 0.983298] 9p: Installing v9fs 9p2000 file system support machine # [ 0.983643] FS-Cache: Netfs '9p' registered for caching machine # qemu-system-x86_64: warning: 9p: degraded performance: a reasonable high msize should be chosen on client/guest side (chosen msize is <= 8192). See https://wiki.qemu.org/Documentation/9psetup#msize for details. machine # mounting tmpfs on /nix/.rw-store... machine # mounting shared on /tmp/shared... machine # mounting xchg on /tmp/xchg... machine # mounting overlay filesystem on /nix/store... machine # machine # <<< NixOS Stage 2 >>> machine # machine # [ 1.080699] EXT4-fs (vda): re-mounted. Opts: (null) machine # [ 1.081346] booting system configuration /nix/store/2f3vd830c5cg657q78xc3akbdyg2dzpn-nixos-system-machine-21.11pre299942.09c38c29f2c-vuizvui machine # running activation script... machine # setting up /etc... machine # starting systemd... machine # [ 2.130016] systemd[1]: Inserted module 'autofs4' machine # [ 2.148981] systemd[1]: systemd 247 running in system mode. (+PAM +AUDIT -SELINUX +IMA +APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS +ACL +XZ +LZ4 -ZSTD +SECCOMP +BLKID -ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified) machine # [ 2.150315] systemd[1]: Detected virtualization kvm. machine # [ 2.150624] systemd[1]: Detected architecture x86-64. machine # [ 2.151440] systemd[1]: Set hostname to . machine # [ 2.152913] systemd[1]: Initializing machine ID from random generator. machine # [ 2.223699] systemd-fstab-generator[442]: Checking was requested for "store", but it is not a device. machine # [ 2.225343] systemd-fstab-generator[442]: Checking was requested for "shared", but it is not a device. machine # [ 2.226393] systemd-fstab-generator[442]: Checking was requested for "xchg", but it is not a device. machine # [ 2.454619] systemd[1]: Queued start job for default target Multi-User System. machine # [ 2.456346] systemd[1]: Created slice system-getty.slice. machine # [ 2.456956] systemd[1]: Created slice system-modprobe.slice. machine # [ 2.457537] systemd[1]: Created slice User and Session Slice. machine # [ 2.457951] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. machine # [ 2.458460] systemd[1]: Started Forward Password Requests to Wall Directory Watch. machine # [ 2.459019] systemd[1]: Reached target Local Encrypted Volumes. machine # [ 2.459407] systemd[1]: Reached target Containers. machine # [ 2.459748] systemd[1]: Reached target Paths. machine # [ 2.460037] systemd[1]: Reached target Remote File Systems. machine # [ 2.460395] systemd[1]: Reached target Slices. machine # [ 2.460718] systemd[1]: Reached target Swap. machine # [ 2.462643] systemd[1]: Listening on Process Core Dump Socket. machine # [ 2.463353] systemd[1]: Listening on Journal Audit Socket. machine # [ 2.463780] systemd[1]: Listening on Journal Socket (/dev/log). machine # [ 2.464213] systemd[1]: Listening on Journal Socket. machine # [ 2.465328] systemd[1]: Listening on udev Control Socket. machine # [ 2.465819] systemd[1]: Listening on udev Kernel Socket. machine # [ 2.466643] systemd[1]: Mounting Huge Pages File System... machine # [ 2.467467] systemd[1]: Mounting POSIX Message Queue File System... machine # [ 2.468368] systemd[1]: Mounting Kernel Debug File System... machine # [ 2.469871] systemd[1]: Starting Create list of static device nodes for the current kernel... machine # [ 2.471010] systemd[1]: Starting Load Kernel Module configfs... machine # [ 2.472755] systemd[1]: Starting Load Kernel Module drm... machine # [ 2.478286] systemd[1]: Starting Load Kernel Module fuse... machine # [ 2.480783] systemd[1]: Starting Load Kernel Module pstore... machine # [ 2.481843] systemd[1]: Condition check resulted in File System Check on Root Device being skipped. machine # [ 2.487963] systemd[1]: Starting Journal Service... machine # [ 2.489945] systemd[1]: Starting Load Kernel Modules... machine # [ 2.491598] systemd[1]: Starting Remount Root and Kernel File Systems... machine # [ 2.505080] systemd[1]: Starting Coldplug All udev Devices... machine # [ 2.520418] Linux agpgart interface v0.103 machine # [ 2.521677] fuse: init (API version 7.32) machine # [ 2.533693] systemd[1]: Mounted Huge Pages File System. machine # [ 2.536697] systemd[1]: Mounted POSIX Message Queue File System. machine # [ 2.537924] EXT4-fs (vda): re-mounted. Opts: (null) machine # [ 2.542758] systemd[1]: Mounted Kernel Debug File System. machine # [ 2.545575] systemd[1]: Finished Create list of static device nodes for the current kernel. machine # [ 2.546236] systemd[1]: modprobe@configfs.service: Succeeded. machine # [ 2.549804] systemd[1]: Finished Load Kernel Module configfs. machine # [ 2.553575] systemd[1]: modprobe@fuse.service: Succeeded. machine # [ 2.556559] systemd[1]: Finished Load Kernel Module fuse. machine # [ 2.557063] systemd[1]: modprobe@pstore.service: Succeeded. machine # [ 2.560603] systemd[1]: Finished Load Kernel Module pstore. machine # [ 2.561738] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. machine # [ 2.563557] systemd[1]: Finished Remount Root and Kernel File Systems. machine # [ 2.567090] systemd[1]: Mounting FUSE Control File System... machine # [ 2.583613] systemd[1]: Mounting Kernel Configuration File System... machine # [ 2.592828] systemd[1]: Starting mount-pstore.service... machine # [ 2.593996] tun: Universal TUN/TAP device driver, 1.6 machine # [ 2.595823] audit: type=1334 audit(1625661424.772:2): prog-id=48 op=LOAD machine # [ 2.598783] audit: type=1334 audit(1625661424.775:3): prog-id=49 op=LOAD machine # [ 2.599830] systemd[1]: Starting Load/Save Random Seed... machine # [ 2.606119] audit: type=1334 audit(1625661424.782:4): prog-id=50 op=LOAD machine # [ 2.608488] audit: type=1334 audit(1625661424.784:5): prog-id=51 op=LOAD machine # [ 2.613479] loop: module loaded machine # [ 2.615255] systemd[1]: Starting Create Static Device Nodes in /dev... machine # [ 2.623823] systemd[1]: Mounted FUSE Control File System. machine # [ 2.628765] systemd[1]: Finished Load Kernel Modules. machine # [ 2.631353] audit: type=1130 audit(1625661424.807:6): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-modules-load comm="systemd" exe="/nix/store/m82y9l76ygpnfjaqshrqh1l4xyfjdan2-systemd-247.6/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' machine # [ 2.634236] systemd[1]: modprobe@drm.service: Succeeded. machine # [ 2.637775] systemd[1]: Finished Load Kernel Module drm. machine # [ 2.639012] audit: type=1130 audit(1625661424.815:7): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=modprobe@drm comm="systemd" exe="/nix/store/m82y9l76ygpnfjaqshrqh1l4xyfjdan2-systemd-247.6/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' machine # [ 2.640806] audit: type=1131 audit(1625661424.817:8): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=modprobe@drm comm="systemd" exe="/nix/store/m82y9l76ygpnfjaqshrqh1l4xyfjdan2-systemd-247.6/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' machine # [ 2.643186] systemd[1]: Mounted Kernel Configuration File System. machine # [ 2.651612] audit: type=1334 audit(1625661424.828:9): prog-id=52 op=LOAD machine # [ 2.652708] audit: type=1334 audit(1625661424.829:10): prog-id=53 op=LOAD machine # [ 2.654813] systemd[1]: Starting Firewall... machine # [ 2.660015] systemd[1]: Starting Apply Kernel Variables... machine # [ 2.669182] systemd[1]: Finished Coldplug All udev Devices. machine # [ 2.674660] systemd[1]: Finished Load/Save Random Seed. machine # [ 2.678755] systemd[1]: Finished Create Static Device Nodes in /dev. machine # [ 2.681624] systemd[1]: Reached target Local File Systems (Pre). machine # [ 2.682021] systemd[1]: Reached target Local File Systems. machine # [ 2.685943] systemd[1]: Starting Rule-based Manager for Device Events and Files... machine # [ 2.697462] systemd[1]: Finished Apply Kernel Variables. machine # [ 2.784721] systemd[1]: Started Journal Service. machine # [ 2.807578] systemd-journald[458]: Received client request to flush runtime journal. machine # [ 2.880772] systemd-modules-load[459]: Inserted module 'bridge' machine # [ 2.893778] systemd-modules-load[459]: Inserted module 'macvlan' machine # [ 2.898301] systemd-modules-load[459]: Inserted module 'tap' machine # [ 2.900090] systemd-modules-load[459]: Inserted module 'tun' machine # [ 2.900630] systemd-modules-load[459]: Inserted module 'loop' machine # [ 2.902594] systemd-sysctl[472]: Not setting net/ipv4/conf/all/rp_filter (explicit setting exists). machine # [ 2.904684] systemd-sysctl[472]: Not setting net/ipv4/conf/default/rp_filter (explicit setting exists). machine # [ 2.907688] systemd-sysctl[472]: Not setting net/ipv4/conf/all/accept_source_route (explicit setting exists). machine # [ 2.910631] systemd-sysctl[472]: Not setting net/ipv4/conf/default/accept_source_route (explicit setting exists). machine # [ 2.914754] systemd-sysctl[472]: Not setting net/ipv4/conf/all/promote_secondaries (explicit setting exists). machine # [ 2.919468] systemd-sysctl[472]: Not setting net/ipv4/conf/default/promote_secondaries (explicit setting exists). machine # [ 2.923880] systemd-udevd[478]: Network interface NamePolicy= disabled on kernel command line, ignoring. machine # [ 2.929090] systemd[1]: Starting Flush Journal to Persistent Storage... machine # [ 2.933855] systemd[1]: Started Rule-based Manager for Device Events and Files. machine # [ 2.938786] systemd[1]: Finished Flush Journal to Persistent Storage. machine # [ 2.941242] systemd[1]: Starting Create Volatile Files and Directories... machine # [ 2.942299] systemd[1]: Finished Create Volatile Files and Directories. machine # [ 2.944272] systemd[1]: Starting Rebuild Journal Catalog... machine # [ 2.945068] systemd[1]: Starting Update UTMP about System Boot/Shutdown... machine # [ 2.946483] systemd[1]: Finished Update UTMP about System Boot/Shutdown. machine # [ 2.951161] systemd[1]: Finished Rebuild Journal Catalog. machine # [ 2.956657] systemd[1]: Starting Update is Completed... machine # [ 2.960078] systemd[1]: Finished Update is Completed. machine # [ 3.052124] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3 machine # [ 3.056844] ACPI: Power Button [PWRF] machine # [ 3.081404] parport_pc 00:03: reported by Plug and Play ACPI machine # [ 3.087767] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)] machine # [ 3.096531] Floppy drive(s): fd0 is 2.88M AMI BIOS machine # [ 3.108757] FDC 0 is a S82078B machine # [ 3.149274] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 machine # [ 3.140517] systemd-udevd[506]: Using default interface naming scheme 'v247'. machine # [ 3.146980] systemd-udevd[506]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable. machine # [ 3.199800] mousedev: PS/2 mouse device common for all mice machine # [ 3.180221] systemd-udevd[508]: Using default interface naming scheme 'v247'. machine # [ 3.182591] systemd-udevd[508]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable. machine # [ 3.263157] systemd[1]: Finished Firewall. machine # [ 3.265367] systemd[1]: Found device /dev/ttyS0. machine # [ 3.274666] systemd[1]: Found device Virtio network device. machine # [ 3.335105] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console machine # [ 3.338087] cryptd: max_cpu_qlen set to 1000 machine # [ 3.340623] Console: switching to colour dummy device 80x25 machine # [ 3.346996] AVX2 version of gcm_enc/dec engaged. machine # [ 3.347272] AES CTR mode by8 optimization enabled machine # [ 3.348192] [drm] Found bochs VGA, ID 0xb0c0. machine # [ 3.348461] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000. machine # [ 3.356528] [TTM] Zone kernel: Available graphics memory: 182022 KiB machine # [ 3.356912] [TTM] Initializing pool allocator machine # [ 3.357178] [TTM] Initializing DMA pool allocator machine # [ 3.359556] [drm] Found EDID data blob. machine # [ 3.321757] systemd-udevd[505]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable. machine # [ 3.363204] [drm] Initialized bochs-drm 1.0.0 20130925 for 0000:00:02.0 on minor 0 machine # [ 3.324267] systemd[1]: Found device /dev/hvc0. machine # [ 3.369380] fbcon: bochs-drmdrmfb (fb0) is primary device machine # [ 3.462113] ppdev: user-space parallel port driver machine # [ 3.504954] Console: switching to colour frame buffer device 128x48 machine # [ 3.589143] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device machine # [ 3.605172] kvm: Nested Virtualization enabled machine # [ 3.605573] SVM: kvm: Nested Paging enabled machine # [ 3.606637] blk_update_request: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0 machine # [ 3.607225] floppy: error 10 while reading block 0 machine # [ 3.620084] EDAC MC: Ver: 3.0.0 machine # [ 3.624015] Decoding supported only on Scalable MCA processors. machine # [ 4.026954] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input4 machine # [ 4.848917] systemd[1]: Finished mount-pstore.service. machine # [ 4.849320] systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped. machine # [ 4.849866] systemd[1]: Reached target System Initialization. machine # [ 4.850610] systemd[1]: Started Daily Cleanup of Temporary Directories. machine # [ 4.851770] systemd[1]: Reached target Timers. machine # [ 4.852653] systemd[1]: Listening on D-Bus System Message Bus Socket. machine # connecting to host... machine # [ 4.941251] 8021q: 802.1Q VLAN Support v1.8 machine # [ 4.906679] systemd[1]: Listening on Nix Daemon Socket. machine # [ 4.912349] nscd[682]: 682 monitoring file `/etc/passwd` (1) machine # [ 4.917333] systemd[1]: Listening on Test Socket 1 for Multiple Socket Test. machine # [ 4.929905] nscd[682]: 682 monitoring directory `/etc` (2) machine: connected to guest root shell machine: (connecting took 5.22 seconds) machine # [ 4.933520] systemd[1]: Listening on Test Socket 2 for Multiple Socket Test. (5.30 seconds) machine # [ 4.937689] pfwm25n6ijljvqldf4apjmhax7biqqxs-audit-disable[680]: No rules machine # sh: cannot set terminal process group (-1): Inappropriate ioctl for device machine # sh: no job control in this shell machine # [ 4.945611] nscd[682]: 682 monitoring file `/etc/group` (3) machine # [ 4.947734] systemd[1]: Reached target Sockets. machine # [ 4.950765] nscd[682]: 682 monitoring directory `/etc` (2) machine # [ 4.956741] systemd[1]: Reached target Basic System. machine # [ 4.964862] nscd[682]: 682 monitoring file `/etc/hosts` (4) machine # [ 4.969176] systemd[1]: Starting Kernel Auditing... machine # [ 4.976043] nscd[682]: 682 monitoring directory `/etc` (2) machine # [ 4.980740] systemd[1]: Started backdoor.service. machine # [ 4.987148] nscd[682]: 682 disabled inotify-based monitoring for file `/etc/resolv.conf': No such file or directory machine # [ 4.992620] systemd[1]: Starting DHCP Client... machine # [ 4.995649] nscd[682]: 682 stat failed for file `/etc/resolv.conf'; will try again later: No such file or directory machine # [ 4.998955] systemd[1]: Starting Name Service Cache Daemon... machine # [ 5.007352] nscd[682]: 682 monitoring file `/etc/services` (5) machine # [ 5.014033] systemd[1]: Started Reset console on configuration changes. machine # [ 5.021724] nscd[682]: 682 monitoring directory `/etc` (2) machine # [ 5.023156] systemd[1]: Starting resolvconf update... machine # [ 5.023515] nscd[682]: 682 monitoring file `/etc/netgroup` (6) machine # [ 5.023885] systemd[1]: Finished Kernel Auditing. machine # [ 5.030347] nscd[682]: 682 monitoring directory `/etc` (2) machine # [ 5.033148] systemd[1]: Started Name Service Cache Daemon. machine # [ 5.035049] dhcpcd[678]: dev: loaded udev machine # [ 5.035367] systemd[1]: Reached target Host and Network Name Lookups. machine # [ 5.035800] systemd[1]: Reached target User and Group Name Lookups. machine # [ 5.045819] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. machine # [ 5.056437] nscd[745]: 745 monitoring file `/etc/passwd` (1) machine # [ 5.058423] systemd[1]: Starting User Login Management... machine # [ 5.059613] nscd[745]: 745 monitoring directory `/etc` (2) machine # [ 5.064047] systemd[1]: Stopping Name Service Cache Daemon... machine # [ 5.066261] nscd[745]: 745 monitoring file `/etc/group` (3) machine # [ 5.109048] cfg80211: Loading compiled-in X.509 certificates for regulatory database machine # [ 5.070809] systemd[1]: nscd.service: Succeeded. machine # [ 5.072157] nscd[745]: 745 monitoring directory `/etc` (2) machine # [ 5.073297] systemd[1]: Stopped Name Service Cache Daemon. machine # [ 5.075793] nscd[745]: 745 monitoring file `/etc/hosts` (4) machine # [ 5.078110] systemd[1]: Starting Name Service Cache Daemon... machine # [ 5.079414] nscd[745]: 745 monitoring directory `/etc` (2) machine # [ 5.081403] systemd[1]: Finished resolvconf update. machine # [ 5.131856] 8021q: adding VLAN 0 to HW filter on device eth1 machine # [ 5.092389] nscd[745]: 745 monitoring file `/etc/resolv.conf` (5) machine # [ 5.097984] systemd[1]: Reached target Network (Pre). machine # [ 5.102930] network-addresses-eth1-start[744]: adding address 192.168.1.1/24... done machine # [ 5.108909] nscd[745]: 745 monitoring directory `/etc` (2) machine # [ 5.114435] systemd[1]: Reached target All Network Interfaces (deprecated). machine # [ 5.159210] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' machine # [ 5.161090] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 machine # [ 5.161635] cfg80211: failed to load regulatory.db machine # [ 5.130925] nscd[745]: 745 monitoring file `/etc/services` (6) machine # [ 5.136252] systemd[1]: Starting Address configuration of eth1... machine # [ 5.142363] nscd[745]: 745 monitoring directory `/etc` (2) machine # [ 5.143883] systemd[1]: Started Name Service Cache Daemon. machine # [ 5.146318] nscd[745]: 745 monitoring file `/etc/netgroup` (7) machine # [ 5.148980] systemd-logind[719]: New seat seat0. machine # [ 5.152127] nscd[745]: 745 monitoring directory `/etc` (2) machine # [ 5.154429] systemd[1]: Started D-Bus System Message Bus. machine # [ 5.157273] systemd-logind[719]: Watching system buttons on /dev/input/event2 (Power Button) machine # [ 5.160885] systemd-logind[719]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) machine # [ 5.164427] systemd[1]: Finished Address configuration of eth1. machine # [ 5.166187] systemd[1]: Starting Networking Setup... machine # [ 5.170175] dbus-daemon[760]: dbus[760]: Unknown username "systemd-timesync" in message bus configuration file machine # [ 5.200240] dbus-daemon[760]: [system] Successfully activated service 'org.freedesktop.systemd1' machine # [ 5.201191] systemd[1]: Started User Login Management. machine # [ 5.205302] systemd[1]: Finished Networking Setup. machine # [ 5.206355] systemd[1]: Starting Extra networking commands.... machine # [ 5.211641] systemd[1]: Finished Extra networking commands.. machine # [ 5.213071] systemd[1]: Reached target Network. machine # [ 5.213844] systemd[1]: Started Canary Service to verify implementation. machine # [ 5.215476] systemd[1]: Starting Permit User Sessions... machine # [ 5.231934] systemd[1]: Finished Permit User Sessions. machine # [ 5.235285] systemd[1]: Started Getty on tty1. machine # [ 5.237088] systemd[1]: Reached target Login Prompts. machine # [ 6.228434] 8021q: adding VLAN 0 to HW filter on device eth0 machine # [ 6.188519] dhcpcd[678]: eth0: waiting for carrier machine # [ 6.189041] dhcpcd[678]: eth0: carrier acquired machine # [ 6.195625] dhcpcd[678]: DUID 00:01:00:01:28:78:5c:74:52:54:00:12:34:56 machine # [ 6.196083] dhcpcd[678]: eth0: IAID 00:12:34:56 machine # [ 6.196445] dhcpcd[678]: eth0: adding address fe80::5054:ff:fe12:3456 machine # [ 6.639608] dhcpcd[678]: eth0: soliciting a DHCP lease machine # [ 6.688549] NET: Registered protocol family 17 machine # [ 6.650091] dhcpcd[678]: eth0: offered 10.0.2.15 from 10.0.2.2 machine # [ 6.650479] dhcpcd[678]: eth0: leased 10.0.2.15 for 86400 seconds machine # [ 6.650869] dhcpcd[678]: eth0: adding route to 10.0.2.0/24 machine # [ 6.651245] dhcpcd[678]: eth0: adding default route via 10.0.2.2 machine # [ 6.686993] nscd[745]: 745 monitored file `/etc/resolv.conf` was written to machine # [ 6.696884] systemd[1]: Stopping Name Service Cache Daemon... machine # [ 6.699552] systemd[1]: nscd.service: Succeeded. machine # [ 6.700149] systemd[1]: Stopped Name Service Cache Daemon. machine # [ 6.702088] systemd[1]: Starting Name Service Cache Daemon... machine # [ 6.710256] nscd[872]: 872 monitoring file `/etc/passwd` (1) machine # [ 6.710637] nscd[872]: 872 monitoring directory `/etc` (2) machine # [ 6.711021] nscd[872]: 872 monitoring file `/etc/group` (3) machine # [ 6.711393] nscd[872]: 872 monitoring directory `/etc` (2) machine # [ 6.711813] nscd[872]: 872 monitoring file `/etc/hosts` (4) machine # [ 6.712671] nscd[872]: 872 monitoring directory `/etc` (2) machine # [ 6.713282] nscd[872]: 872 monitoring file `/etc/resolv.conf` (5) machine # [ 6.714514] nscd[872]: 872 monitoring directory `/etc` (2) machine # [ 6.715546] nscd[872]: 872 monitoring file `/etc/services` (6) machine # [ 6.718659] nscd[872]: 872 monitoring directory `/etc` (2) machine # [ 6.719105] systemd[1]: Started Name Service Cache Daemon. machine # [ 6.720468] nscd[872]: 872 monitoring file `/etc/netgroup` (7) machine # [ 6.721318] nscd[872]: 872 monitoring directory `/etc` (2) machine # [ 6.735594] dhcpcd[889]: Failed to reload-or-try-restart ntpd.service: Unit ntpd.service not found. machine # [ 6.736465] dhcpcd[889]: Failed to reload-or-try-restart openntpd.service: Unit openntpd.service not found. machine # [ 6.737695] dhcpcd[889]: Failed to reload-or-try-restart chronyd.service: Unit chronyd.service not found. machine # [ 6.740782] dhcpcd[678]: forked to background, child pid 890 machine # [ 6.798665] systemd[1]: Started DHCP Client. machine # [ 6.799363] systemd[1]: Reached target Network is Online. machine # [ 6.800483] systemd[1]: Reached target Multi-User System. machine # [ 6.801563] systemd[1]: Startup finished in 2.058s (kernel) + 4.742s (userspace) = 6.801s. machine # [ 7.022426] dhcpcd[890]: eth0: soliciting an IPv6 router machine: must succeed: test "$(curl --no-progress-meter -v http://127.0.0.1:8090/)" = port8090 machine # * Trying 127.0.0.1:8090... machine # * Connected to 127.0.0.1 (127.0.0.1) port 8090 (#0) machine # > GET / HTTP/1.1 machine # > Host: 127.0.0.1:8090 machine # > User-Agent: curl/7.76.1 machine # > Accept: */* machine # > machine # * Mark bundle as not supporting multiuse machine # * HTTP 1.0, assume close after body machine # < HTTP/1.0 200 OK machine # < Server: BaseHTTP/0.6 Python/3.8.9 machine # < Date: Wed, 07 Jul 2021 12:37:09 GMT machine # < Content-Type: text/plain machine # < X-Reply: port8090 machine # < machine # { [8 bytes data] machine # * Closing connection 0 (0.04 seconds) machine: must succeed: test "$(curl --no-progress-meter -v --unix-socket /run/test1.sock http://test/)" = port8090 machine # * Trying /run/test1.sock:0... machine # [ 7.120219] systemd[1]: Started Test Service for Multiple Socket Test. machine # * Connected to test (/run/test1.sock) port 80 (#0) machine # > GET / HTTP/1.1 machine # > Host: test machine # > User-Agent: curl/7.76.1 machine # > Accept: */* machine # > machine # [ 7.154532] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.154979] ip2unix[897]: ip2unix:systemd.cc:190:init Number of systemd file descriptors found in LISTEN_FDS: 2 machine # [ 7.155608] ip2unix[897]: ip2unix:systemd.cc:32:get_env_vector Splitting value of LISTEN_FDNAMES: socket1:socket2 machine # [ 7.156229] ip2unix[897]: ip2unix:systemd.cc:38:get_env_vector Got element 'socket1' from LISTEN_FDNAMES. machine # [ 7.156864] ip2unix[897]: ip2unix:systemd.cc:43:get_env_vector Got last element 'socket2' from LISTEN_FDNAMES. machine # [ 7.157437] ip2unix[897]: ip2unix:systemd.cc:223:init Matched systemd unix file descriptor name 'socket1' (fd 3) with rule #0. machine # [ 7.159095] ip2unix[897]: ip2unix:systemd.cc:223:init Matched systemd unix file descriptor name 'socket2' (fd 4) with rule #1. machine # [ 7.159699] ip2unix[897]: ip2unix:systemd.cc:95:update_env Setting __IP2UNIX_SYSTEMD_FDS to ''. machine # [ 7.161110] ip2unix[897]: ip2unix:systemd.cc:106:update_env Setting __IP2UNIX_SYSTEMD_FDMAP to '1&=4&#f$;0&=3&#f$;'. machine # [ 7.161677] ip2unix[897]: ip2unix:systemd.cc:261:init Finished getting systemd file descriptors. machine # [ 7.162775] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.167541] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.169377] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.170690] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.171985] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.173205] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.174489] ip2unix[897]: ip2unix:preload.cc:506:dup dup(0) machine # [ 7.174860] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.175316] ip2unix[897]: ip2unix:preload.cc:506:dup dup(1) machine # [ 7.175695] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.176139] ip2unix[897]: ip2unix:preload.cc:506:dup dup(2) machine # [ 7.176527] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.177376] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.180136] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.184677] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.186305] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.191118] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.193865] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.195621] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.198677] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.199797] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.204442] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.211162] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.213832] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.214874] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.217692] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.220117] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.223268] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.226656] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.228647] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.230081] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.234630] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.238342] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.243084] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.245066] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.248445] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.250568] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.252335] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.263776] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.265451] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.267619] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.269641] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.274036] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.279450] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.281811] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.285211] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.288234] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.290581] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.296607] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.298073] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.303657] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.306594] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.310880] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.316542] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.318437] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.319690] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.322673] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.324714] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.326433] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.329077] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.330702] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.331872] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.334190] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.336122] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.343592] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.348808] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.350167] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.352737] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.354635] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.358664] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.363837] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.365566] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.367399] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.369079] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.379054] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.381693] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.387659] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.389483] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.391418] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.392969] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.398312] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.401468] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.404637] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.410984] ip2unix[897]: ip2unix:preload.cc:541:close close(5) machine # [ 7.411621] ip2unix[897]: ip2unix:preload.cc:81:socket socket(2, 524289, 0) machine # [ 7.412091] ip2unix[897]: ip2unix:socket.cc:33:create Registered socket with fd 6, domain 2, type 524289 and protocol 0. machine # [ 7.412724] ip2unix[897]: ip2unix:preload.cc:96:setsockopt setsockopt(6, 1, 2, 0x7ffcb29f0a50, 4) machine # [ 7.413302] ip2unix[897]: ip2unix:preload.cc:269:bind bind(6, 0x7ffcb29f0a40, 16) machine # [ 7.413981] ip2unix[897]: ip2unix:systemd.cc:270:remove_fd Disassociating systemd file descriptor 3. machine # [ 7.414526] ip2unix[897]: ip2unix:systemd.cc:95:update_env Setting __IP2UNIX_SYSTEMD_FDS to ''. machine # [ 7.415099] ip2unix[897]: ip2unix:systemd.cc:106:update_env Setting __IP2UNIX_SYSTEMD_FDMAP to '1&=4&#f$;'. machine # [ 7.415668] ip2unix[897]: ip2unix:systemd.cc:288:remove_fd Setting new flags 1 on fd 3, previos flags were 0. machine # [ 7.417468] ip2unix[897]: ip2unix:socket.cc:219:make_unix Re-using socket with fd 3. machine # [ 7.417912] ip2unix[897]: ip2unix:socket.cc:249:make_unix Replaced socket fd 6 by socket with fd 3. machine # [ 7.418724] ip2unix[897]: ip2unix:socket.cc:302:activate Socket fd 6 marked for systemd socket activation. machine # [ 7.421249] ip2unix[897]: ip2unix:preload.cc:332:getsockname getsockname(6, 0x7ffcb29f0a30, 0x7ffcb29f0a2c) machine # [ 7.421784] ip2unix[897]: ip2unix:preload.cc:541:close close(3) machine # [ 7.422419] ip2unix[897]: ip2unix:preload.cc:541:close close(3) machine # * Mark bundle as not supporting multiuse machine # * HTTP 1.0, assume close after body machine # < HTTP/1.0 200 OK machine # < Server: BaseHTTP/0.6 Python/3.8.9 machine # < Date: Wed, 07 Jul 2021 12:37:09 GMT machine # < Content-Type: text/plain machine # < X-Reply: port1113 machine # < machine # { [8 bytes data] machine # * Closing connection 0 machine # [ 7.428180] ip2unix[897]: ip2unix:preload.cc:146:listen listen(6, 5) machine # [ 7.428559] ip2unix[897]: ip2unix:preload.cc:126:epoll_ctl epoll(5, 1, 6, 0x7ffcb29f0f84) machine # [ 7.429034] ip2unix[897]: ip2unix:preload.cc:81:socket socket(2, 524289, 0) machine # [ 7.429653] ip2unix[897]: ip2unix:socket.cc:33:create Registered socket with fd 3, domain 2, type 524289 and protocol 0. machine # [ 7.430436] ip2unix[897]: ip2unix:preload.cc:96:setsockopt setsockopt(3, 1, 2, 0x7ffcb29f0a50, 4) machine # [ 7.431185] ip2unix[897]: ip2unix:preload.cc:269:bind bind(3, 0x7ffcb29f0a40, 16) machine # [ 7.431740] ip2unix[897]: ip2unix:preload.cc:252:operator() Systemd file descriptor queue empty, blackholing socket with fd 3. machine # [ 7.432584] ip2unix[897]: ip2unix:socket.cc:97:blackhole Socket with fd 3 blackholed. machine: output: error: machine # [ 7.433258] ip2unix[897]: ip2unix:socket.cc:227:make_unix Created new Unix socket with fd 7. machine # [ 7.433971] ip2unix[897]: ip2unix:socket.cc:249:make_unix Replaced socket fd 3 by socket with fd 7. machine # [ 7.434476] ip2unix[897]: ip2unix:preload.cc:332:getsockname getsockname(3, 0x7ffcb29f0a30, 0x7ffcb29f0a2c) machine # [ 7.434924] ip2unix[897]: ip2unix:preload.cc:146:listen listen(3, 5) machine # [ 7.435268] ip2unix[897]: ip2unix:preload.cc:126:epoll_ctl epoll(5, 1, 3, 0x7ffcb29f0f84) machine # [ 7.435656] ip2unix[897]: ip2unix:preload.cc:310:accept4 accept4(6, 0x7ffcb29f0a40, 0x7ffcb29f0a34, 524288) machine # [ 7.436117] ip2unix[897]: ip2unix:socket.cc:485:accept Accepted socket fd 7 registered as a children of socket fd 6. machine # [ 7.436601] ip2unix[897]: ip2unix:preload.cc:332:getsockname getsockname(7, 0x7ffcb29f05b0, 0x7ffcb29f059c) machine # [ 7.437060] ip2unix[897]: ip2unix:preload.cc:541:close close(7) machine # [ 7.437369] ip2unix[897]: ip2unix:socket.cc:642:close Closing socket fd 7. Traceback (most recent call last): machine # [ 7.437703] ip2unix[897]: ip2unix:socket.cc:657:close Socket fd 7 unregistered. File "/nix/store/xhz7gfxlpy0r19qqcsyay0n8n2shcahh-nixos-test-driver/bin/.nixos-test-driver-wrapped", line 938, in run_tests exec(tests, globals()) File "", line 1, in File "", line 7, in File "/nix/store/xhz7gfxlpy0r19qqcsyay0n8n2shcahh-nixos-test-driver/bin/.nixos-test-driver-wrapped", line 478, in succeed raise Exception( Exception: command `test "$(curl --no-progress-meter -v --unix-socket /run/test1.sock http://test/)" = port8090` failed (exit code 1) cleaning up killing machine (pid 10) (0.00 seconds) ```
aszlig commented 3 years ago

Okay, turns out this actually is a regression and I've bisected the issue to commit 1a8a9b6ca73865a10452eb10c93dd751d0ba6af7.

aszlig commented 3 years ago

@noc0lour: Commit 5ead045bffe781e1133d3881d70a4b5bdc66021d should fix the issue. Can you please test the commit in question and check whether it's working for you?

aszlig commented 3 years ago

Closing this since the proposed fix is part of version 2.1.4. If the problem persist, please reopen or create a new issue. Thanks :-)