bld1: building 3h7xqbaxybkypbmq66dq9mdl1xbksycq-vm-test-run-horae-e2e-oidc.drv
Machine state will be reset. To keep it, pass --keep-machine-state
start all VLans
(finished: start all VLans, in 0.00 seconds)
Test will time out and terminate in 3600 seconds
run the VM test script
additionally exposed symbols:
    server,
    vlan1,
    start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh
server: starting vm
server # Disk image does not exist, creating the virtualisation disk image...
server # Formatting '/build/vm-state-server/tmp.4rGqI1OdxP', fmt=raw size=1073741824
server: QEMU running (pid 12)
server # mke2fs 1.47.4 (6-Mar-2025)
server # Discarding device blocks:      0/262144             done
server # Creating filesystem with 262144 4k blocks and 65536 inodes
server # Filesystem UUID: eb114976-bf0c-4eac-90c3-7f5c59d00f8b
server # Superblock backups stored on blocks:
server # 	32768, 98304, 163840, 229376
server # 
server # Allocating group tables: 0/8   done
server # Writing inode tables: 0/8   done
server # Creating journal (8192 blocks): done
server # Writing superblocks and filesystem accounting information: 0/8   done
server # 
server # Virtualisation disk image created.
server # Creating Nix store image...
server # Created Nix store image.
server # SeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
server # 
server # 
server # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1830+3EF31830 CA00
server # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
server # 
server # 
server # 
server # 
server # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1830 3EF31830 CB00
server # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
server # 
server # 
server # Booting from ROM...
server # Probing EDD (edd=off to disable)... o[    0.000000] Linux version 6.18.38 (nixbld@localhost) (gcc (GCC) 15.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT_DYNAMIC Sat Jul  4 11:44:22 UTC 2026
server # [    0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/b5v9y74ac1i25h4ijb18iqakhmwkg2k9-nixos-system-server-test/init regInfo=/nix/store/r1lc66bxjahhm212jf0f2izbavl85896-closure-info/registration console=ttyS0,115200n8 console=tty0
server # [    0.000000] x86/split lock detection: #DB: warning on user-space bus_locks
server # [    0.000000] BIOS-provided physical RAM map:
server # [    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
server # [    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
server # [    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
server # [    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffd7fff] usable
server # [    0.000000] BIOS-e820: [mem 0x000000003ffd8000-0x000000003fffffff] reserved
server # [    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
server # [    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
server # [    0.000000] NX (Execute Disable) protection: active
server # [    0.000000] APIC: Static calls initialized
server # [    0.000000] SMBIOS 2.8 present.
server # [    0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
server # [    0.000000] DMI: Memory slots populated: 1/1
server # [    0.000000] Hypervisor detected: KVM
server # [    0.000000] last_pfn = 0x3ffd8 max_arch_pfn = 0x10000000000
server # [    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
server # [    0.000000] kvm-clock: using sched offset of 399029447 cycles
server # [    0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
server # [    0.000006] tsc: Detected 2100.000 MHz processor
server # [    0.001076] last_pfn = 0x3ffd8 max_arch_pfn = 0x10000000000
server # [    0.001112] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
server # [    0.001115] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT
server # [    0.010488] found SMP MP-table at [mem 0x000f5470-0x000f547f]
server # [    0.010512] Using GB pages for direct mapping
server # [    0.010593] RAMDISK: [mem 0x3e4dd000-0x3ffcffff]
server # [    0.010607] ACPI: Early table checksum verification disabled
server # [    0.010611] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
server # [    0.010627] ACPI: RSDT 0x000000003FFE23CC 000034 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
server # [    0.010637] ACPI: FACP 0x000000003FFE2280 000074 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
server # [    0.010659] ACPI: DSDT 0x000000003FFE0040 002240 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
server # [    0.010663] ACPI: FACS 0x000000003FFE0000 000040
server # [    0.010666] ACPI: APIC 0x000000003FFE22F4 000078 (v03 BOCHS  BXPC     00000001 BXPC 00000001)
server # [    0.010670] ACPI: HPET 0x000000003FFE236C 000038 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
server # [    0.010673] ACPI: WAET 0x000000003FFE23A4 000028 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
server # [    0.010683] ACPI: Reserving FACP table memory at [mem 0x3ffe2280-0x3ffe22f3]
server # [    0.010686] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe227f]
server # [    0.010687] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
server # [    0.010687] ACPI: Reserving APIC table memory at [mem 0x3ffe22f4-0x3ffe236b]
server # [    0.010688] ACPI: Reserving HPET table memory at [mem 0x3ffe236c-0x3ffe23a3]
server # [    0.010688] ACPI: Reserving WAET table memory at [mem 0x3ffe23a4-0x3ffe23cb]
server # [    0.010973] No NUMA configuration found
server # [    0.010973] Faking a node at [mem 0x0000000000000000-0x000000003ffd7fff]
server # [    0.010976] NODE_DATA(0) allocated [mem 0x3ffd2780-0x3ffd7cff]
server # [    0.012539] Zone ranges:
server # [    0.012542]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
server # [    0.012544]   DMA32    [mem 0x0000000001000000-0x000000003ffd7fff]
server # [    0.012545]   Normal   empty
server # [    0.012546]   Device   empty
server # [    0.012546] Movable zone start for each node
server # [    0.012547] Early memory node ranges
server # [    0.012548]   node   0: [mem 0x0000000000001000-0x000000000009efff]
server # [    0.012549]   node   0: [mem 0x0000000000100000-0x000000003ffd7fff]
server # [    0.012550] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffd7fff]
server # [    0.012590] On node 0, zone DMA: 1 pages in unavailable ranges
server # [    0.012809] On node 0, zone DMA: 97 pages in unavailable ranges
server # [    0.025127] On node 0, zone DMA32: 40 pages in unavailable ranges
server # [    0.025664] ACPI: PM-Timer IO Port: 0x608
server # [    0.025681] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
server # [    0.025719] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
server # [    0.025723] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
server # [    0.025725] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
server # [    0.025726] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
server # [    0.025727] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
server # [    0.025728] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
server # [    0.025732] ACPI: Using ACPI (MADT) for SMP configuration information
server # [    0.025734] ACPI: HPET id: 0x8086a201 base: 0xfed00000
server # [    0.025738] TSC deadline timer available
server # [    0.025742] CPU topo: Max. logical packages:   1
server # [    0.025743] CPU topo: Max. logical dies:       1
server # [    0.025744] CPU topo: Max. dies per package:   1
server # [    0.025747] CPU topo: Max. threads per core:   1
server # [    0.025750] CPU topo: Num. cores per package:     1
server # [    0.025750] CPU topo: Num. threads per package:   1
server # [    0.025751] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
server # [    0.025775] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
server # [    0.025807] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
server # [    0.025809] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
server # [    0.025811] [mem 0x40000000-0xfeffbfff] available for PCI devices
server # [    0.025812] Booting paravirtualized kernel on KVM
server # [    0.025815] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
server # [    0.032374] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
server # [    0.034158] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u2097152
server # [    0.034217] kvm-guest: PV spinlocks disabled, single CPU
server # [    0.034219] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/b5v9y74ac1i25h4ijb18iqakhmwkg2k9-nixos-system-server-test/init regInfo=/nix/store/r1lc66bxjahhm212jf0f2izbavl85896-closure-info/registration console=ttyS0,115200n8 console=tty0
server # [    0.034394] Unknown kernel command line parameters "regInfo=/nix/store/r1lc66bxjahhm212jf0f2izbavl85896-closure-info/registration", will be passed to user space.
server # [    0.034426] random: crng init done
server # [    0.034427] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes
server # [    0.034471] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
server # [    0.034865] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
server # [    0.034945] Fallback order for Node 0: 0
server # [    0.034948] Built 1 zonelists, mobility grouping on.  Total pages: 262006
server # [    0.034949] Policy zone: DMA32
server # [    0.036830] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
server # [    0.040510] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
server # [    0.042122] allocated 2097152 bytes of page_ext
server # [    0.053794] ftrace: allocating 48598 entries in 192 pages
server # [    0.053796] ftrace: allocated 192 pages with 2 groups
server # [    0.054543] Dynamic Preempt: lazy
server # [    0.054659] rcu: Preemptible hierarchical RCU implementation.
server # [    0.054660] rcu: 	RCU event tracing is enabled.
server # [    0.054660] rcu: 	RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
server # [    0.054662] 	Trampoline variant of Tasks RCU enabled.
server # [    0.054662] 	Rude variant of Tasks RCU enabled.
server # [    0.054663] 	Tracing variant of Tasks RCU enabled.
server # [    0.054663] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
server # [    0.054664] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
server # [    0.054707] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
server # [    0.054709] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
server # [    0.054710] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
server # [    0.060847] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
server # [    0.061145] rcu: srcu_init: Setting srcu_struct sizes based on contention.
server # [    0.061328] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
server # [    0.066024] Console: colour VGA+ 80x25
server # [    0.066027] printk: legacy console [tty0] enabled
server # [    0.097560] printk: legacy console [ttyS0] enabled
server # [    0.187392] ACPI: Core revision 20250807
server # [    0.188399] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
server # [    0.189954] APIC: Switch to symmetric I/O mode setup
server # [    0.190981] x2apic enabled
server # [    0.191756] APIC: Switched APIC routing to: physical x2apic
server # [    0.193771] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
server # [    0.194706] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1e4530a99b6, max_idle_ns: 440795257976 ns
server # [    0.196287] Calibrating delay loop (skipped) preset value.. 4200.00 BogoMIPS (lpj=2100000)
server # [    0.197440] x86/cpu: User Mode Instruction Prevention (UMIP) activated
server # [    0.199307] CET detected: Indirect Branch Tracking enabled
server # [    0.200161] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
server # [    0.200877] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
server # [    0.201931] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto
server # [    0.203273] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
server # [    0.204277] Spectre V2 : Mitigation: Enhanced / Automatic IBRS
server # [    0.205273] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
server # [    0.206275] Spectre V2 : Spectre v2 / PBRSB-eIBRS: Retire a single CALL on VMEXIT
server # [    0.208274] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
server # [    0.209327] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
server # [    0.210273] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
server # [    0.211273] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
server # [    0.212956] x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask'
server # [    0.213956] x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256'
server # [    0.214950] x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256'
server # [    0.215976] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
server # [    0.217115] x86/fpu: Supporting XSAVE feature 0x800: 'Control-flow User registers'
server # [    0.218278] x86/fpu: Supporting XSAVE feature 0x1000: 'Control-flow Kernel registers (KVM only)'
server # [    0.219273] x86/fpu: Supporting XSAVE feature 0x20000: 'AMX Tile config'
server # [    0.220273] x86/fpu: Supporting XSAVE feature 0x40000: 'AMX Tile data'
server # [    0.221273] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
server # [    0.222273] x86/fpu: xstate_offset[5]:  832, xstate_sizes[5]:   64
server # [    0.223275] x86/fpu: xstate_offset[6]:  896, xstate_sizes[6]:  512
server # [    0.224277] x86/fpu: xstate_offset[7]: 1408, xstate_sizes[7]: 1024
server # [    0.225275] x86/fpu: xstate_offset[9]: 2432, xstate_sizes[9]:    8
server # [    0.226276] x86/fpu: xstate_offset[11]: 2440, xstate_sizes[11]:   16
server # [    0.227273] x86/fpu: xstate_offset[12]: 2456, xstate_sizes[12]:   24
server # [    0.228273] x86/fpu: xstate_offset[17]: 2496, xstate_sizes[17]:   64
server # [    0.229273] x86/fpu: xstate_offset[18]: 2560, xstate_sizes[18]: 8192
server # [    0.230120] x86/fpu: Enabled xstate features 0x61ae7, context size is 10752 bytes, using 'compacted' format.
server # [    0.261991] Freeing SMP alternatives memory: 44K
server # [    0.262275] pid_max: default: 32768 minimum: 301
server # [    0.263347] LSM: initializing lsm=capability,landlock,yama,bpf,ima
server # [    0.264378] landlock: Up and running.
server # [    0.264915] Yama: becoming mindful.
server # [    0.265449] LSM support for eBPF active
server # [    0.266275] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
server # [    0.267283] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
server # [    0.268867] smpboot: CPU0: Intel(R) Xeon(R) Gold 5412U (family: 0x6, model: 0x8f, stepping: 0x8)
server # [    0.269633] Performance Events: PEBS fmt0-, Sapphire Rapids events, full-width counters, Intel PMU driver.
server # [    0.270277] ... version:                   2
server # [    0.270883] ... bit width:                 48
server # [    0.271273] ... generic counters:          8
server # [    0.271882] ... generic bitmap:            00000000000000ff
server # [    0.272273] ... fixed-purpose counters:    3
server # [    0.272859] ... fixed-purpose bitmap:      0000000000000007
server # [    0.273275] ... value mask:                0000ffffffffffff
server # [    0.274215] ... max period:                00007fffffffffff
server # [    0.274966] ... global_ctrl mask:          00000007000000ff
server # [    0.275454] signal: max sigframe size: 11952
server # [    0.276389] rcu: Hierarchical SRCU implementation.
server # [    0.277245] rcu: 	Max phase no-delay instances is 400.
server # [    0.278740] smp: Bringing up secondary CPUs ...
server # [    0.279291] smp: Brought up 1 node, 1 CPU
server # [    0.279856] smpboot: Total of 1 processors activated (4200.00 BogoMIPS)
server # [    0.280442] Memory: 942540K/1048024K available (17159K kernel code, 2721K rwdata, 13560K rodata, 3636K init, 3020K bss, 98120K reserved, 0K cma-reserved)
server # [    0.281713] devtmpfs: initialized
server # [    0.282321] x86/mm: Memory block size: 128MB
server # [    0.283527] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
server # [    0.284288] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)
server # [    0.285264] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).
server # [    0.286177] pinctrl core: initialized pinctrl subsystem
server # [    0.287063] PM: RTC time: 09:30:09, date: 2026-11-07
server # [    0.289042] NET: Registered PF_NETLINK/PF_ROUTE protocol family
server # [    0.289499] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
server # [    0.290315] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
server # [    0.291361] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
server # [    0.292281] audit: initializing netlink subsys (disabled)
server # [    0.293216] thermal_sys: Registered thermal governor 'fair_share'
server # [    0.293219] thermal_sys: Registered thermal governor 'bang_bang'
server # [    0.293882] thermal_sys: Registered thermal governor 'step_wise'
server # [    0.294273] thermal_sys: Registered thermal governor 'user_space'
server # [    0.295093] thermal_sys: Registered thermal governor 'power_allocator'
server # [    0.295855] audit: type=2000 audit(1794043810.136:1): state=initialized audit_enabled=0 res=1
server # [    0.297284] cpuidle: using governor menu
server # [    0.297960] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
server # [    0.298443] PCI: Using configuration type 1 for base access
server # [    0.299340] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
server # [    0.304365] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
server # [    0.305274] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
server # [    0.306161] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
server # [    0.311273] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
server # [    0.316854] ACPI: Added _OSI(Module Device)
server # [    0.317274] ACPI: Added _OSI(Processor Device)
server # [    0.317886] ACPI: Added _OSI(Processor Aggregator Device)
server # [    0.319124] ACPI: 1 ACPI AML tables successfully acquired and loaded
server # [    0.328498] ACPI: Interpreter enabled
server # [    0.329050] ACPI: PM: (supports S0 S3 S4 S5)
server # [    0.329274] ACPI: Using IOAPIC for interrupt routing
server # [    0.329961] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
server # [    0.334274] PCI: Using E820 reservations for host bridge windows
server # [    0.335143] ACPI: Enabled 2 GPEs in block 00 to 0F
server # [    0.339673] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
server # [    0.342278] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
server # [    0.343274] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI]
server # [    0.346282] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended configuration space under this bridge
server # [    0.347415] acpiphp: Slot [3] registered
server # [    0.347980] acpiphp: Slot [4] registered
server # [    0.350308] acpiphp: Slot [5] registered
server # [    0.350880] acpiphp: Slot [6] registered
server # [    0.351286] acpiphp: Slot [7] registered
server # [    0.351881] acpiphp: Slot [8] registered
server # [    0.354290] acpiphp: Slot [9] registered
server # [    0.354867] acpiphp: Slot [10] registered
server # [    0.355286] acpiphp: Slot [11] registered
server # [    0.355875] acpiphp: Slot [12] registered
server # [    0.358288] acpiphp: Slot [13] registered
server # [    0.358860] acpiphp: Slot [14] registered
server # [    0.359286] acpiphp: Slot [15] registered
server # [    0.359859] acpiphp: Slot [16] registered
server # [    0.362288] acpiphp: Slot [17] registered
server # [    0.362861] acpiphp: Slot [18] registered
server # [    0.363294] acpiphp: Slot [19] registered
server # [    0.363881] acpiphp: Slot [20] registered
server # [    0.365667] acpiphp: Slot [21] registered
server # [    0.366281] acpiphp: Slot [22] registered
server # [    0.366877] acpiphp: Slot [23] registered
server # [    0.367286] acpiphp: Slot [24] registered
server # [    0.367872] acpiphp: Slot [25] registered
server # [    0.368287] acpiphp: Slot [26] registered
server # [    0.368866] acpiphp: Slot [27] registered
server # [    0.369285] acpiphp: Slot [28] registered
server # [    0.369855] acpiphp: Slot [29] registered
server # [    0.370286] acpiphp: Slot [30] registered
server # [    0.370862] acpiphp: Slot [31] registered
server # [    0.371286] PCI host bridge to bus 0000:00
server # [    0.371860] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
server # [    0.372274] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
server # [    0.373148] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
server # [    0.373983] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
server # [    0.374273] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
server # [    0.375282] pci_bus 0000:00: root bus resource [bus 00-ff]
server # [    0.376094] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
server # [    0.377621] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
server # [    0.378668] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
server # [    0.380223] pci 0000:00:01.1: BAR 4 [io  0xc220-0xc22f]
server # [    0.380816] pci 0000:00:01.1: BAR 0 [io  0x01f0-0x01f7]: legacy IDE quirk
server # [    0.381274] pci 0000:00:01.1: BAR 1 [io  0x03f6]: legacy IDE quirk
server # [    0.382091] pci 0000:00:01.1: BAR 2 [io  0x0170-0x0177]: legacy IDE quirk
server # [    0.382935] pci 0000:00:01.1: BAR 3 [io  0x0376]: legacy IDE quirk
server # [    0.383447] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
server # [    0.385173] pci 0000:00:01.2: BAR 4 [io  0xc140-0xc15f]
server # [    0.386371] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
server # [    0.387575] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
server # [    0.388280] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
server # [    0.389413] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
server # [    0.392172] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
server # [    0.392929] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
server # [    0.393312] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
server # [    0.394312] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
server # [    0.396293] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
server # [    0.398289] pci 0000:00:03.0: BAR 0 [io  0xc160-0xc17f]
server # [    0.399001] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
server # [    0.399296] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
server # [    0.400206] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
server # [    0.401970] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
server # [    0.404306] pci 0000:00:04.0: BAR 0 [io  0xc180-0xc19f]
server # [    0.405789] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
server # [    0.406296] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
server # [    0.409072] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.412307] pci 0000:00:05.0: BAR 0 [io  0xc1a0-0xc1bf]
server # [    0.413034] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
server # [    0.413296] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
server # [    0.415143] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
server # [    0.417302] pci 0000:00:06.0: BAR 0 [io  0xc1c0-0xc1df]
server # [    0.418040] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
server # [    0.418296] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
server # [    0.420179] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
server # [    0.422261] pci 0000:00:07.0: BAR 0 [io  0xc000-0xc07f]
server # [    0.422784] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
server # [    0.423296] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
server # [    0.425080] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
server # [    0.427580] pci 0000:00:08.0: BAR 0 [io  0xc080-0xc0ff]
server # [    0.428782] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
server # [    0.429296] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
server # [    0.431101] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
server # [    0.433100] pci 0000:00:09.0: BAR 0 [io  0xc1e0-0xc1ff]
server # [    0.433798] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
server # [    0.434296] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
server # [    0.435200] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
server # [    0.436746] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
server # [    0.438878] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
server # [    0.439297] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
server # [    0.441082] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
server # [    0.443088] pci 0000:00:0b.0: BAR 0 [io  0xc100-0xc13f]
server # [    0.443798] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
server # [    0.444310] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
server # [    0.446720] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
server # [    0.448296] pci 0000:00:0c.0: BAR 0 [io  0xc200-0xc21f]
server # [    0.449015] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
server # [    0.449297] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
server # [    0.453462] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
server # [    0.454361] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
server # [    0.455368] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
server # [    0.456221] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
server # [    0.456885] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
server # [    0.458120] iommu: Default domain type: Translated
server # [    0.458768] iommu: DMA domain TLB invalidation policy: lazy mode
server # [    0.459484] ACPI: bus type USB registered
server # [    0.460081] usbcore: registered new interface driver usbfs
server # [    0.460842] usbcore: registered new interface driver hub
server # [    0.461279] usbcore: registered new device driver usb
server # [    0.462710] NetLabel: Initializing
server # [    0.463244] NetLabel:  domain hash size = 128
server # [    0.463755] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
server # [    0.464311] NetLabel:  unlabeled traffic allowed by default
server # [    0.465061] PCI: Using ACPI for IRQ routing
server # [    0.465630] pci 0000:00:02.0: vgaarb: setting as boot VGA device
server # [    0.466271] pci 0000:00:02.0: vgaarb: bridge control possible
server # [    0.466271] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
server # [    0.466274] vgaarb: loaded
server # [    0.466886] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
server # [    0.467274] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
server # [    0.471332] clocksource: Switched to clocksource kvm-clock
server # [    0.473743] VFS: Disk quotas dquot_6.6.0
server # [    0.474331] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
server # [    0.475438] pnp: PnP ACPI init
server # [    0.476251] pnp: PnP ACPI: found 6 devices
server # [    0.482664] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
server # [    0.483868] clocksource: Switched to clocksource acpi_pm
server # [    0.484796] NET: Registered PF_INET protocol family
server # [    0.485609] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
server # [    0.500313] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
server # [    0.501661] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
server # [    0.502789] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
server # [    0.503876] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
server # [    0.504893] TCP: Hash tables configured (established 8192 bind 8192)
server # [    0.505855] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
server # [    0.507004] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)
server # [    0.508044] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)
server # [    0.509099] NET: Registered PF_UNIX/PF_LOCAL protocol family
server # [    0.510020] NET: Registered PF_XDP protocol family
server # [    0.510723] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
server # [    0.511574] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
server # [    0.512533] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
server # [    0.513548] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
server # [    0.514663] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
server # [    0.515664] pci 0000:00:01.0: PIIX3: Enabling Passive Release
server # [    0.516646] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
server # [    0.518234] ACPI: \_SB_.LNKD: Enabled at IRQ 11
server # [    0.520241] PCI: CLS 0 bytes, default 64
server # [    0.521068] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e4530a99b6, max_idle_ns: 440795257976 ns
server # [    0.522550] Trying to unpack rootfs image as initramfs...
server # [    0.560499] Initialise system trusted keyrings
server # [    0.563184] workingset: timestamp_bits=40 max_order=18 bucket_order=0
server # [    0.583429] Key type asymmetric registered
server # [    0.584036] Asymmetric key parser 'x509' registered
server # [    0.586196] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
server # [    0.589175] io scheduler mq-deadline registered
server # [    0.589880] io scheduler kyber registered
server # [    0.591057] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
server # [    0.594157] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
server # [    0.597627] Linux agpgart interface v0.103
server # [    0.598452] ACPI: bus type drm_connector registered
server # [    0.601489] usbcore: registered new interface driver usbserial_generic
server # [    0.602394] usbserial: USB Serial support registered for generic
server # [    0.605152] intel_pstate: CPU model not supported
server # [    0.605921] drop_monitor: Initializing network drop monitor service
server # [    0.606915] NET: Registered PF_INET6 protocol family
server # [    0.610540] Segment Routing with IPv6
server # [    0.611078] In-situ OAM (IOAM) with IPv6
server # [    0.614415] IPI shorthand broadcast: enabled
server # [    0.619324] sched_clock: Marking stable (489014701, 130119157)->(668539485, -49405627)
server # [    0.624311] registered taskstats version 1
server # [    0.625158] Loading compiled-in X.509 certificates
server # [    0.636693] Demotion targets for Node 0: null
server # [    0.637614] Key type .fscrypt registered
server # [    0.640181] Key type fscrypt-provisioning registered
server # [    0.640980] ima: No TPM chip found, activating TPM-bypass!
server # [    0.641875] ima: Allocated hash algorithm: sha1
server # [    0.644202] ima: No architecture policies found
server # [    0.646154] PM:   Magic number: 2:986:524
server # [    0.647677] RAS: Correctable Errors collector initialized.
server # [    0.659200] clk: Disabling unused clocks
server # [    0.659859] PM: genpd: Disabling unused power domains
server # [    0.800924] Freeing initrd memory: 27596K
server # [    0.816908] Freeing unused decrypted memory: 2028K
server # [    0.819291] Freeing unused kernel image (initmem) memory: 3636K
server # [    0.820227] Write protecting the kernel read-only data: 32768k
server # [    0.821831] Freeing unused kernel image (text/rodata gap) memory: 1272K
server # [    0.823196] Freeing unused kernel image (rodata/data gap) memory: 776K
server # [    0.832842] x86/mm: Checked W+X mappings: passed, no W+X pages found.
server # [    0.833738] Run /init as init process
server # [    0.842182] systemd[1]: Inserted module 'autofs4'
server # [    0.858202] fuse: init (API version 7.45)
server # [    0.864334] ACPI: \_SB_.LNKC: Enabled at IRQ 10
server # [    0.870220] ACPI: \_SB_.LNKA: Enabled at IRQ 10
server # [    0.872403] ACPI: \_SB_.LNKB: Enabled at IRQ 11
server # [    0.892469] systemd[1]: Successfully made /usr/ read-only.
server # [    1.229540] systemd[1]: systemd 260.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)
server # [    1.234039] systemd[1]: Detected virtualization kvm.
server # [    1.234811] systemd[1]: Detected architecture x86-64.
server # [    1.235548] systemd[1]: Running in initrd.
server # [    1.236383] systemd[1]: Initializing machine ID from random generator.
server # [    1.237400] systemd[1]: Hostname set to <server>.
server # [    1.276258] systemd[1]: Queued start job for default target Initrd Default Target.
server # [    1.278990] systemd[1]: Created slice Slice /system/modprobe.
server # [    1.280015] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
server # [    1.281201] systemd[1]: Expecting device /dev/disk/by-label/nix-store...
server # [    1.282204] systemd[1]: Expecting device /dev/disk/by-label/nixos...
server # [    1.283116] systemd[1]: Reached target Path Units.
server # [    1.283858] systemd[1]: Reached target Slice Units.
server # [    1.284607] systemd[1]: Reached target Swaps.
server # [    1.285265] systemd[1]: Reached target Timer Units.
server # [    1.286074] systemd[1]: Listening on D-Bus System Message Bus Socket.
server # [    1.287052] systemd[1]: Listening on Journal Socket (/dev/log).
server # [    1.287987] systemd[1]: Listening on Journal Sockets.
server # [    1.288827] systemd[1]: Listening on udev Control Socket.
server # [    1.289673] systemd[1]: Listening on udev Kernel Socket.
server # [    1.290439] systemd[1]: Reached target Socket Units.
server # [    1.291784] systemd[1]: Starting Create List of Static Device Nodes...
server # [    1.294796] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
server # [    1.299111] systemd[1]: Starting Load Kernel Module configfs...
server # [    1.317607] systemd[1]: Starting Journal Service...
server # [    1.324201] systemd[1]: Starting Load Kernel Modules...
server # [    1.325020] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
server # [    1.342262] systemd[1]: Starting Coldplug All udev Devices...
server # [    1.347852] netfs: FS-Cache loaded
server # [    1.354853] systemd[1]: Finished Create List of Static Device Nodes.
server # [    1.360587] systemd[1]: modprobe@configfs.service: Deactivated successfully.
server # [    1.369471] systemd[1]: Finished Load Kernel Module configfs.
server # [    1.372021] 9pnet: Installing 9P2000 support
server # [    1.375559] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config
server # [    1.377147] systemd-journald[67]: Collecting audit messages is disabled.
server # [    1.386764] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
server # [    1.395287] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
server # [    1.400431] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
server # [    1.404243] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev
server # [    1.408253] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
server # [    1.426193] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
server # [    1.434571] systemd[1]: Starting Create Static Device Nodes in /dev...
server # [    1.444211] systemd[1]: Finished Load Kernel Modules.
server # [    1.452676] systemd[1]: Starting Apply Kernel Variables...
server # [    1.466223] systemd[1]: Finished Create Static Device Nodes in /dev.
server # [    1.470368] systemd[1]: Reached target Preparation for Local File Systems.
server # [    1.475234] systemd[1]: Reached target Local File Systems.
server # [    1.481200] systemd[1]: Starting Rule-based Manager for Device Events and Files...
server # [    1.354720] systemd-modules-load[68]: Inserted module 'dm_mod'
server # [    1.358277] systemd-modules-load[68]: Inserted module 'virtio_balloon'
server # [    1.359135] systemd-modules-load[68]: Inserted module 'virtio_gpu'
server # [    1.491047] systemd[1]: Started Journal Service.
server # [    1.368174] systemd[1]: Finished Apply Kernel Variables.
server # [    1.377467] systemd[1]: Starting Create System Files and Directories...
server # [    1.401693] systemd[1]: Finished Create System Files and Directories.
server # [    1.410240] systemd-udevd[75]: Using default interface naming scheme 'v260'.
server # [    1.424424] systemd[1]: Finished Coldplug All udev Devices.
server # [    1.432109] systemd[1]: Started Rule-based Manager for Device Events and Files.
server # [    1.433112] systemd[1]: Reached target System Initialization.
server # [    1.433912] systemd[1]: Reached target Basic System.
server # [    1.720313] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
server # [    1.737324] serio: i8042 KBD port at 0x60,0x64 irq 1
server # [    1.737915] serio: i8042 AUX port at 0x60,0x64 irq 12
server # [    1.749775] virtio_blk virtio4: 1/0/0 default/read/poll queues
server # [    1.751084] virtio_blk virtio4: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
server # [    1.764753] uhci_hcd 0000:00:01.2: UHCI Host Controller
server # [    1.778222] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
server # [    1.779082] uhci_hcd 0000:00:01.2: detected 2 ports
server # [    1.786014] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c140
server # [    1.791923] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18
server # [    1.792858] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
server # [    1.801345] usb usb1: Product: UHCI Host Controller
server # [    1.801909] usb usb1: Manufacturer: Linux 6.18.38 uhci_hcd
server # [    1.803603] SCSI subsystem initialized
server # [    1.806516] virtio_blk virtio5: 1/0/0 default/read/poll queues
server # [    1.812504] usb usb1: SerialNumber: 0000:00:01.2
server # [    1.814784] virtio_blk virtio5: [vdb] 2558480 512-byte logical blocks (1.31 GB/1.22 GiB)
server # [    1.817631] hub 1-0:1.0: USB hub found
server # [    1.820696] hub 1-0:1.0: 2 ports detected
server # [    1.703109] (udev-worker)[96]: Network interface NamePolicy= disabled on kernel command line.
server # [    1.709758] systemd[1]: Starting Virtual Console Setup...
server # [    1.717664] (udev-worker)[92]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
server # [    1.720440] (udev-worker)[92]: Network interface NamePolicy= disabled on kernel command line.
server # [    1.859646] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
server # [    1.740522] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.
server # [    1.743063] systemd[1]: Finished Virtual Console Setup.
server # [    1.772054] systemd[1]: Found device /dev/disk/by-label/nixos.
server # [    1.778061] systemd[1]: Found device /dev/disk/by-label/nix-store.
server # [    1.779570] systemd[1]: Reached target Initrd Root Device.
server # [    1.781062] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...
server # [    1.927222] scsi host0: ata_piix
server # [    1.929080] scsi host1: ata_piix
server # [    1.929898] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc220 irq 14 lpm-pol 0
server # [    1.931900] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc228 irq 15 lpm-pol 0
server # [    1.814194] systemd-fsck[111]: nixos: clean, 12/65536 files, 13019/262144 blocks
server # [    1.820567] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.
server # [    2.048208] usb 1-1: new full-speed USB device number 2 using uhci_hcd
server # [    2.088346] ata2: found unknown device (class 0)
server # [    2.089743] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
server # [    2.092228] scsi 1:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     2.5+ PQ: 0 ANSI: 5
server # [    2.121681] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
server # [    2.130415] cdrom: Uniform CD-ROM driver Revision: 3.20
server # [    2.215507] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
server # [    2.216731] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
server # [    2.218105] usb 1-1: Product: QEMU USB Tablet
server # [    2.218895] usb 1-1: Manufacturer: QEMU
server # [    2.219654] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
server # [    2.238481] hid: raw HID events driver (C) Jiri Kosina
server # [    2.248992] usbcore: registered new interface driver usbhid
server # [    2.250821] usbhid: USB HID core driver
server # [    2.255324] 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
server # [    2.257244] 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
server # [    2.224404] systemd[1]: Mounting /sysroot...
server # [    2.451528] EXT4-fs (vda): mounted filesystem eb114976-bf0c-4eac-90c3-7f5c59d00f8b r/w with ordered data mode. Quota mode: none.
server # [    2.325352] systemd[1]: Mounted /sysroot.
server # [    2.326723] systemd[1]: Reached target Initrd Root File System.
server # [    2.329146] systemd[1]: Starting Mountpoints Configured in the Real Root...
server # [    2.339915] systemd-sysroot-fstab-check[126]: /sysroot should be mounted in the initrd, will request daemon-reload.
server # [    2.343505] systemd[1]: Reload requested from client PID 126 ('systemd-sysroot') (unit initrd-parse-etc.service)...
server # [    2.345051] systemd[1]: Reloading...
server # [    2.450862] systemd[1]: Reloading finished in 104 ms.
server # [    2.457825] systemd-sysroot-fstab-check[126]: Requesting initrd-fs.target/start/replace...
server # [    2.461105] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
server # [    2.462420] systemd-sysroot-fstab-check[126]: Requesting swap.target/start/replace...
server # [    2.465491] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
server # [    2.466625] systemd[1]: Finished Mountpoints Configured in the Real Root.
server # [    2.468063] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.
server # [    3.227119] systemd[1]: Mounting /sysroot/nix/.ro-store...
server # [    3.230090] systemd[1]: Mounting /sysroot/nix/.rw-store...
server # [    3.233367] systemd[1]: Mounting /sysroot/run...
server # [    3.239875] systemd[1]: Mounting /sysroot/tmp/shared...
server # [    3.246345] systemd[1]: Mounting /sysroot/tmp/xchg...
server # [    3.282871] systemd[1]: Mounted /sysroot/nix/.rw-store.
server # [    3.283770] systemd[1]: Mounted /sysroot/run.
server # [    3.293089] systemd[1]: Starting rw-sysroot-nix-store.service...
server # [    3.432554] 9p: Installing v9fs 9p2000 file system support
server # [    3.313060] systemd[1]: Mounted /sysroot/tmp/shared.
server # [    3.444026] erofs (device vdb): mounted with root inode @ nid 36.
server # [    3.315340] systemd[1]: Mounted /sysroot/tmp/xchg.
server # [    3.318862] systemd[1]: Mounted /sysroot/nix/.ro-store.
server # [    3.324869] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
server # [    3.326602] systemd[1]: Finished rw-sysroot-nix-store.service.
server # [    3.328896] systemd[1]: Mounting /sysroot/nix/store...
server # [    3.353188] systemd[1]: Mounted /sysroot/nix/store.
server # [    3.354421] systemd[1]: Reached target Initrd File Systems.
server # [    3.356166] systemd[1]: Starting Find NixOS closure...
server # [    3.360194] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...
server # [    3.384780] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.
server # [    3.393310] systemd[1]: Finished Find NixOS closure.
server # [    3.395263] systemd[1]: Reached target Initrd Default Target.
server # [    3.396689] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
server # [    3.415316] systemd[1]: Stopped target Initrd Default Target.
server # [    3.416253] systemd[1]: Stopped target Basic System.
server # [    3.417050] systemd[1]: Stopped target Initrd Root Device.
server # [    3.417983] systemd[1]: Stopped target Path Units.
server # [    3.419102] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
server # [    3.420932] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
server # [    3.423126] systemd[1]: Stopped target Slice Units.
server # [    3.424314] systemd[1]: Stopped target Socket Units.
server # [    3.426224] systemd[1]: Stopped target System Initialization.
server # [    3.427568] systemd[1]: Stopped target Swaps.
server # [    3.428928] systemd[1]: Stopped target Timer Units.
server # [    3.429901] systemd[1]: dbus.socket: Deactivated successfully.
server # [    3.431165] systemd[1]: Closed D-Bus System Message Bus Socket.
server # [    3.432873] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.
server # [    3.433942] systemd[1]: Stopped Find NixOS closure.
server # [    3.434676] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
server # [    3.438071] systemd[1]: Starting rw-sysroot-nix-store.service...
server # [    3.438944] systemd[1]: systemd-sysctl.service: Deactivated successfully.
server # [    3.439911] systemd[1]: Stopped Apply Kernel Variables.
server # [    3.440823] systemd[1]: systemd-modules-load.service: Deactivated successfully.
server # [    3.442052] systemd[1]: Stopped Load Kernel Modules.
server # [    3.444247] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.
server # [    3.445567] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.
server # [    3.446738] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
server # [    3.447743] systemd[1]: Stopped Create System Files and Directories.
server # [    3.449341] systemd[1]: Stopped target Local File Systems.
server # [    3.450429] systemd[1]: Stopped target Preparation for Local File Systems.
server # [    3.451841] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
server # [    3.453440] systemd[1]: Stopped Coldplug All udev Devices.
server # [    3.457221] systemd[1]: Stopping Rule-based Manager for Device Events and Files...
server # [    3.458969] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
server # [    3.460115] systemd[1]: Stopped Virtual Console Setup.
server # [    3.473056] systemd[1]: systemd-udevd.service: Deactivated successfully.
server # [    3.475953] systemd[1]: Stopped Rule-based Manager for Device Events and Files.
server # [    3.477176] systemd[1]: initrd-cleanup.service: Deactivated successfully.
server # [    3.478758] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
server # [    3.480580] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
server # [    3.481646] systemd[1]: Finished rw-sysroot-nix-store.service.
server # [    3.485289] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
server # [    3.486472] systemd[1]: Closed udev Control Socket.
server # [    3.488154] systemd[1]: Starting Cleanup udev Database...
server # [    3.489179] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
server # [    3.491155] systemd[1]: Stopped Create Static Device Nodes in /dev.
server # [    3.492644] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.
server # [    3.493783] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.
server # [    3.494786] systemd[1]: kmod-static-nodes.service: Deactivated successfully.
server # [    3.495754] systemd[1]: Stopped Create List of Static Device Nodes.
server # [    3.511799] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
server # [    3.513484] systemd[1]: Finished Cleanup udev Database.
server # [    3.515200] systemd[1]: Reached target Switch Root.
server # [    3.516638] systemd[1]: Starting NixOS Activation...
server # [    3.588380] initrd-nixos-activation-start[177]: booting system configuration /nix/store/b5v9y74ac1i25h4ijb18iqakhmwkg2k9-nixos-system-server-test
server # [    3.613895] initrd-nixos-activation-start[177]: running activation script...
server # [    3.798980] initrd-nixos-activation-start[200]: setting up /etc...
server # [    3.884279] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.
server # [    3.885769] systemd[1]: Finished NixOS Activation.
server # [    3.888100] systemd[1]: Starting Switch Root...
server # [    3.906844] systemd[1]: Switching root.
server # [    4.050292] systemd-journald[67]: Received SIGTERM from PID 1 (systemd).
server # [    4.123210] NET: Registered PF_VSOCK protocol family
server # [    4.480635] systemd[1]: systemd 260.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)
server # [    4.484970] systemd[1]: Detected virtualization kvm.
server # [    4.485791] systemd[1]: Detected architecture x86-64.
server # [    4.486638] systemd[1]: Detected first boot.
server # [    4.487681] systemd[1]: Initializing machine ID from random generator.
server # [    4.696046] systemd[1]: bpf-restrict-fs: LSM BPF program attached
server # [    4.777873] systemd[1]: Applying preset policy.
server # [    4.866657] systemd[1]: Populated /etc with preset unit settings.
server # [    4.967622] systemd[1]: initrd-switch-root.service: Deactivated successfully.
server # [    4.969117] systemd[1]: Stopped initrd-switch-root.service.
server # [    4.971566] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
server # [    4.973725] systemd[1]: Created slice Slice /system/getty.
server # [    4.975314] systemd[1]: Created slice User and Session Slice.
server # [    4.976343] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
server # [    4.977602] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
server # [    4.978868] systemd[1]: Expecting device /dev/hvc0...
server # [    4.979961] systemd[1]: Expecting device /dev/ttyS0...
server # [    4.980996] systemd[1]: Reached target Local Encrypted Volumes.
server # [    4.982015] systemd[1]: Stopped target initrd-fs.target.
server # [    4.982942] systemd[1]: Stopped target initrd-root-fs.target.
server # [    4.983966] systemd[1]: Stopped target initrd-switch-root.target.
server # [    4.985308] systemd[1]: Reached target Virtual Machines and Containers.
server # [    4.986667] systemd[1]: Reached target Path Units.
server # [    4.987833] systemd[1]: Reached target Remote File Systems.
server # [    4.988931] systemd[1]: Reached target Slice Units.
server # [    4.990179] systemd[1]: Reached target Swaps.
server # [    4.993193] systemd[1]: Listening on Query the User Interactively for a Password.
server # [    4.996718] systemd[1]: Listening on Process Core Dump Socket.
server # [    4.998945] systemd[1]: Listening on Credential Encryption/Decryption.
server # [    5.001423] systemd[1]: Listening on Factory Reset Management.
server # [    5.004077] systemd[1]: Starting Journal Log Access Socket...
server # [    5.005722] systemd[1]: Listening on Journal Audit Socket.
server # [    5.008446] systemd[1]: Listening on Console Output Muting Service Socket.
server # [    5.009715] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
server # [    5.010885] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-uki
server # [    5.012307] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki
server # [    5.015239] systemd[1]: Listening on Disk Repartitioning Service Socket.
server # [    5.016331] systemd[1]: Listening on udev Control Socket.
server # [    5.017296] systemd[1]: Listening on udev Varlink Socket.
server # [    5.023098] systemd[1]: Mounting Huge Pages File System...
server # [    5.028249] systemd[1]: Mounting POSIX Message Queue File System...
server # [    5.033659] systemd[1]: Mounting Kernel Debug File System...
server # [    5.040074] systemd[1]: Mounting Kernel Trace File System...
server # [    5.052481] systemd[1]: Starting Create List of Static Device Nodes...
server # [    5.059290] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
server # [    5.071263] systemd[1]: Starting Load Kernel Module configfs...
server # [    5.074239] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm
server # [    5.080169] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
server # [    5.082900] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
server # [    5.089548] systemd[1]: Mounting FUSE Control File System...
server # [    5.092601] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
server # [    5.104597] systemd[1]: Starting Journal Service...
server # [    5.110088] systemd[1]: Starting Load Kernel Modules...
server # [    5.118220] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
server # [    5.132520] systemd[1]: Starting Remount Root and Kernel File Systems...
server # [    5.142039] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
server # [    5.159449] loop: module loaded
server # [    5.164262] systemd[1]: Starting Coldplug All udev Devices...
server # [    5.173995] systemd-journald[269]: Collecting audit messages is enabled.
server # [    5.186687] systemd[1]: Listening on Journal Log Access Socket.
server # [    5.191167] EXT4-fs (vda): re-mounted eb114976-bf0c-4eac-90c3-7f5c59d00f8b.
server # [    5.201549] systemd[1]: Mounted Huge Pages File System.
server # [    5.205384] systemd[1]: Mounted POSIX Message Queue File System.
server # [    5.209504] systemd[1]: Mounted Kernel Debug File System.
server # [    5.082261] systemd[1]: Queued start job for default target Multi-User System.
server # [    5.084548] systemd[1]: Unnecessary job was removed for /dev/vdb.
server # [    5.216346] systemd[1]: Started Journal Service.
server # [    5.089543] systemd[1]: systemd-journald.service: Deactivated successfully.
server # [    5.090959] systemd-modules-load[270]: Inserted module 'loop'
server # [    5.095225] systemd[1]: Mounted Kernel Trace File System.
server # [    5.097393] systemd[1]: Finished Create List of Static Device Nodes.
server # [    5.100388] systemd[1]: modprobe@configfs.service: Deactivated successfully.
server # [    5.101639] systemd[1]: Finished Load Kernel Module configfs.
server # [    5.105472] systemd[1]: Mounted FUSE Control File System.
server # [    5.109705] systemd[1]: Finished Load Kernel Modules.
server # [    5.110676] systemd[1]: Finished Remount Root and Kernel File Systems.
server # [    5.127083] systemd[1]: Listening on Disk Image Download Service Socket.
server # [    5.132625] systemd[1]: Mounting Kernel Configuration File System...
server # [    5.144090] systemd[1]: Starting Firewall...
server # [    5.153314] systemd-oomd[271]: No swap; memory pressure usage will be degraded
server # [    5.157236] systemd[1]: Starting Flush Journal to Persistent Storage...
server # [    5.158328] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
server # [    5.170090] systemd[1]: Starting Load/Save OS Random Seed...
server # [    5.182108] systemd[1]: Starting Apply Kernel Variables...
server # [    5.208892] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
server # [    5.210257] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
server # [    5.211738] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
server # [    5.399193] systemd-journald[269]: Received client request to flush runtime journal.
server # [    5.438369] systemd[1]: Mounted Kernel Configuration File System.
server # [    5.441967] systemd[1]: Finished Load/Save OS Random Seed.
server # [    5.445442] systemd[1]: Finished Apply Kernel Variables.
server # [    5.447361] systemd[1]: Reached target First Boot Complete.
server # [    5.450174] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
server # [    5.452185] systemd[1]: Starting Create Static Device Nodes in /dev...
server # [    5.454169] systemd[1]: Finished Create Static Device Nodes in /dev.
server # [    5.455364] systemd[1]: Reached target Preparation for Local File Systems.
server # [    5.459348] systemd[1]: Starting Rule-based Manager for Device Events and Files...
server # [    5.460455] systemd[1]: Finished Flush Journal to Persistent Storage.
server # [    5.476763] systemd[1]: Finished Coldplug All udev Devices.
server # [    5.517066] systemd-udevd[304]: Using default interface naming scheme 'v260'.
server # [    5.568353] systemd[1]: Started Rule-based Manager for Device Events and Files.
server # [    5.788921] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
server # [    5.840579] systemd[1]: Finished Firewall.
server # [    5.847440] systemd[1]: Mounting /run/wrappers...
server # [    5.867909] systemd[1]: Mounted /run/wrappers.
server # [    5.870534] systemd[1]: Reached target Local File Systems.
server # [    5.873797] systemd[1]: Listening on Boot Loader Control Service Socket.
server # [    5.877181] systemd[1]: Starting register-nix-paths.service...
server # [    5.886090] systemd[1]: Starting Create SUID/SGID Wrappers...
server # [    5.887027] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
server # [    5.897222] systemd[1]: Starting Save Transient machine-id to Disk...
server # [    5.912082] systemd[1]: Starting Create System Files and Directories...
server # [    5.951134] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.
server # [    5.996920] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
server # [    6.002961] systemd[1]: Finished Save Transient machine-id to Disk.
server # [    6.021914] systemd[1]: Finished Create System Files and Directories.
server # [    6.028091] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.
server # [    6.038097] systemd[1]: Starting Rebuild Journal Catalog...
server # [    6.049159] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
server # [    6.081062] (udev-worker)[369]: Network interface NamePolicy= disabled on kernel command line.
server # [    6.133945] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
server # [    6.140325] (udev-worker)[365]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
server # [    6.142983] (udev-worker)[365]: Network interface NamePolicy= disabled on kernel command line.
server # [    6.175072] systemd[1]: Finished Rebuild Journal Catalog.
server # [    6.186104] systemd[1]: Starting Update is Completed...
server # [    6.239337] systemd[1]: Finished Update is Completed.
server # [    6.335257] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
server # [    6.336521] systemd[1]: Finished Create SUID/SGID Wrappers.
server # [    6.348378] systemd[1]: Condition check resulted in Virtio network device being skipped.
server # [    6.353772] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
server # [    6.359081] systemd[1]: Starting Create SUID/SGID Wrappers...
server # [    6.359969] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
server # [    6.361686] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
server # [    6.364620] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
server # [    6.368224] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
server # [    6.369467] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki
server # [    6.775906] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
server # [    6.679495] systemd[1]: Finished register-nix-paths.service.
server # [    6.690671] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
server # [    6.692638] systemd[1]: Finished Create SUID/SGID Wrappers.
server # [    6.696118] systemd[1]: Reached target System Initialization.
server # [    6.697071] systemd[1]: Started Discard unused filesystem blocks once a week.
server # [    6.699145] systemd[1]: Started postgresqlBackup-horae.timer.
server # [    6.701093] systemd[1]: Started Daily Cleanup of Temporary Directories.
server # [    6.702813] systemd[1]: Reached target Timer Units.
server # [    6.703627] systemd[1]: Listening on D-Bus System Message Bus Socket.
server # [    6.704542] systemd[1]: Listening on Nix Daemon Socket.
server # [    6.706187] systemd[1]: Listening on Hostname Service Socket.
server # [    6.707073] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
server # [    6.709037] systemd[1]: Reached target Socket Units.
server # [    6.709787] systemd[1]: Reached target Basic System.
server # [    6.713128] systemd[1]: Started backdoor.service.
server # [    6.720827] systemd[1]: Starting Import lastlog data into lastlog2 database...
server # [    6.730133] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
server # [    6.740076] systemd[1]: Starting Post-Boot Actions...
server # [    6.758317] systemd[1]: Started Reset console on configuration changes.
server # [    6.891599] rtc_cmos 00:05: RTC can wake from S4
server # [    6.773185] systemd[1]: Starting resolvconf update...
server # connecting to host...
server # [    6.798531] systemd[1]: Started test-console-diagnostics.service.
server # [    6.846885] systemd[1]: Finished Post-Boot Actions.
server # [    6.989295] rtc_cmos 00:05: registered as rtc0
server # [    6.990074] rtc_cmos 00:05: setting system clock to 2026-11-07T09:30:16 UTC (1794043816)
server # [    6.991576] systemd-journald[269]: Time jumped backwards, rotating.
server # [    7.015212] parport_pc 00:03: reported by Plug and Play ACPI
server # [    6.915929] systemd[1]: Starting D-Bus System Message Bus...
server # [    7.051648] Floppy drive(s): fd0 is 2.88M AMI BIOS
server # [    6.927695] nsncd[551]: Nov 07 09:30:16.514 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
server # [    6.936513] systemd[1]: Started Name Service Cache Daemon (nsncd).
server # [    6.944248] systemd[1]: Reached target Host and Network Name Lookups.
server # [    6.949175] systemd[1]: Reached target User and Group Name Lookups.
server # [    6.951298] systemd[1]: Starting User Login Management...
server # [    7.084305] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
server # [    6.956255] systemd[1]: Finished Import lastlog data into lastlog2 database.
server # [    7.093312] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
server # [    7.113187] mousedev: PS/2 mouse device common for all mice
server # [    6.985797] systemd[1]: test-console-diagnostics.service: Deactivated successfully.
server # [    7.117284] ACPI: button: Power Button [PWRF]
server # [    6.991221] systemd[1]: test-console-diagnostics.service: Consumed 18ms CPU time over 190ms wall clock time, 8.3M memory peak, 6.3M read from disk.
server # [    7.025748] dbus-broker-launch[576]: Looking up NSS user entry for 'systemd-timesync'...
server # [    7.030481] dbus-broker-launch[576]: NSS returned no entry for 'systemd-timesync'
server # [    7.031596] dbus-broker-launch[576]: Invalid user-name in /nix/store/arpzvyccsp34rkxvaj85i50fy233z5lr-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
server # [    7.043096] systemd[1]: Started D-Bus System Message Bus.
server # [    7.175559] FDC 0 is a S82078B
server # [    7.077636] dbus-broker-launch[576]: Ready
server # [    7.104294] systemd[1]: Stopped target Host and Network Name Lookups.
server # [    7.105445] systemd[1]: Stopping Host and Network Name Lookups...
server # [    7.108340] systemd[1]: Stopped target User and Group Name Lookups.
server # [    7.112354] systemd[1]: Stopping User and Group Name Lookups...
server # [    7.113254] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
server # [    7.114362] systemd[1]: nscd.service: Deactivated successfully.
server # [    7.117149] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
server # [    7.121083] systemd[1]: nscd.service: Consumed 19ms CPU time over 382ms wall clock time, 7.6M memory peak, 5.7M read from disk.
server # [    7.138241] systemd-logind[579]: New seat seat0.
server # [    7.143684] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
server # [    7.149288] systemd[1]: Started User Login Management.
server # [    7.287249] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
server # [    7.165103] systemd[1]: Starting linger-users.service...
server # [    7.313521] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
server # [    7.201224] systemd[1]: Finished resolvconf update.
server # [    7.201841] systemd[1]: Reached target Preparation for Network.
server # [    7.207764] nsncd[623]: Nov 07 09:30:16.846 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
server # [    7.213073] systemd[1]: Starting DHCP Client...
server # [    7.218421] systemd[1]: Starting Address configuration of eth1...
server # [    7.229574] systemd[1]: Starting Extra networking commands....
server # [    7.230334] systemd[1]: Started Name Service Cache Daemon (nsncd).
server # [    7.231026] systemd[1]: linger-users.service: Deactivated successfully.
server # [    7.336579] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
server # [    7.349827] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
server # [    7.413770] Console: switching to colour dummy device 80x25
server # [    7.242945] systemd[1]: Finished linger-users.service.
server # [    7.316710] systemd[1]: Reached target Host and Network Name Lookups.
server # [    7.317457] systemd[1]: Reached target User and Group Name Lookups.
server # [    7.484489] [drm] Found bochs VGA, ID 0xb0c5.
server # [    7.484878] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
server # [    7.371535] dhcpcd[655]: dhcpcd-10.3.2 starting
server # [    7.378250] network-addresses-eth1-start[650]: adding address 192.168.1.1/24... done
server # [    7.380269] dhcpcd[668]: dev: loaded udev
server # [    7.518908] 8021q: 802.1Q VLAN Support v1.8
server # [    7.519258] 8021q: adding VLAN 0 to HW filter on device eth1
server # [    7.389646] network-addresses-eth1-start[650]: adding address 2001:db8:1::1/64... done
server # [    7.400944] systemd[1]: Finished Address configuration of eth1.
server # [    7.537869] bochs-drm 0000:00:02.0: [drm] Registered 1 planes with drm panic
server # [    7.538401] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
server: waiting for unit register-nix-paths.service
server: waiting for the VM to finish booting
server: Guest shell says: b'Spawning backdoor root shell...\n'
server: connected to guest root shell
server: (connecting took 0.00 seconds)
server: (finished: waiting for the VM to finish booting, in 0.00 seconds)
server # [    7.564884] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
server # [    7.565660] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
server # [    7.469868] systemd[1]: Starting Virtual Console Setup...
server # [    7.475214] systemd[1]: Finished Extra networking commands..
server # [    7.516101] systemd[1]: Reached target Network.
server: (finished: waiting for unit register-nix-paths.service, in 0.09 seconds)
server: waiting for unit postgresql.service
server # [    7.626183] fbcon: bochs-drmdrmfb (fb0) is primary device
server # [    7.697116] RAPL PMU: API unit is 2^-32 Joules, 1 fixed counters, 10737418240 ms ovfl timer
server # [    7.697145] RAPL PMU: hw unit of domain psys 2^-0 Joules
server # [    7.808830] cfg80211: Loading compiled-in X.509 certificates for regulatory database
server # [    7.820162] ppdev: user-space parallel port driver
server # [    7.820780] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
server # [    7.820901] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
server # [    7.821332] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2
server # [    7.821338] cfg80211: failed to load regulatory.db
server # [    7.877516] 8021q: adding VLAN 0 to HW filter on device eth0
server # [    7.895108] Console: switching to colour frame buffer device 160x50
server # [    7.994203] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
server # [    7.523107] systemd[1]: Starting dex identity provider...
server # [    7.867266] dhcpcd[668]: eth0: waiting for carrier
server # [    7.867794] systemd-logind[579]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
server # [    7.868809] dhcpcd[668]: eth0: carrier acquired
server # [    7.869297] systemd[1]: Starting PostgreSQL Server...
server # [    7.870325] dhcpcd[668]: DUID 00:01:00:01:32:81:ac:29:52:54:00:12:34:56
server # [    7.870981] systemd[1]: Starting Permit User Sessions...
server # [    7.874456] postgresql-pre-start[742]: The files belonging to this database system will be owned by user "postgres".
server # [    7.875466] postgresql-pre-start[742]: This user must also own the server process.
server # [    7.877915] postgresql-pre-start[742]: The database cluster will be initialized with locale "en_US.UTF-8".
server # [    7.880208] postgresql-pre-start[742]: The default database encoding has accordingly been set to "UTF8".
server # [    7.881086] postgresql-pre-start[742]: The default text search configuration will be set to "english".
server # [    7.881963] postgresql-pre-start[742]: Data page checksums are disabled.
server # [    7.882655] postgresql-pre-start[742]: fixing permissions on existing directory /var/lib/postgresql/17 ... ok
server # [    7.883608] postgresql-pre-start[742]: creating subdirectories ... ok
server # [    7.884297] postgresql-pre-start[742]: selecting dynamic shared memory implementation ... posix
server # [    7.885256] dhcpcd[668]: eth0: IAID 00:12:34:56
server # [    7.885905] systemd-logind[579]: Watching system buttons on /dev/input/event2 (Power Button)
server # [    7.893279] dhcpcd[668]: eth0: adding address fe80::5054:ff:fe12:3456
server # [    7.897162] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
server # [    7.901439] systemd[1]: Started dex identity provider.
server # [    7.902316] systemd-logind[579]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
server # [    7.903211] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
server # [    7.903997] systemd[1]: Stopped Virtual Console Setup.
server # [    7.917756] systemd[1]: Starting Virtual Console Setup...
server # [    7.919256] postgresql-pre-start[742]: selecting default "max_connections" ... 100
server # [    7.928402] systemd[1]: Finished Permit User Sessions.
server # [    7.946076] systemd[1]: Started Getty on tty1.
server # [    7.946657] systemd[1]: Reached target Login Prompts.
server # [    8.016739] systemd-vconsole-setup[758]: Configuration of first virtual console was skipped, ignoring remaining ones.
server # [    8.022505] systemd[1]: Finished Virtual Console Setup.
server # [    8.030248] postgresql-pre-start[742]: selecting default "shared_buffers" ... 128MB
server # [    8.067492] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="Version info" dex_version=v2.45.1 go.version=go1.26.4 go.os=linux go.arch=amd64
server # [    8.068978] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config issuer" issuer=http://127.0.0.1:5556/dex
server # [    8.070486] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config storage" storage_type=memory
server # [    8.072155] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config static client" client_name=Horae
server # [    8.073161] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config static client" client_name="Horae without email_verified"
server # [    8.074568] dex[750]: time=2026-11-07T09:30:17.707Z level=INFO msg="config connector" connector_id=mock
server # [    8.076535] dex[750]: time=2026-11-07T09:30:17.707Z level=INFO msg="config skipping approval screen"
server # [    8.077332] dex[750]: time=2026-11-07T09:30:17.707Z level=INFO msg="continue on connector failure feature flag enabled"
server # [    8.078314] dex[750]: time=2026-11-07T09:30:17.711Z level=INFO msg="signer configured" type=local keys_rotation_period=6h
server # [    8.079276] dex[750]: time=2026-11-07T09:30:17.711Z level=INFO msg="config refresh tokens rotation" enabled=true
server # [    8.080157] dex[750]: time=2026-11-07T09:30:17.711Z level=ERROR msg="failed to get signing algorithm" err="no signing key found"
server # [    8.083151] dex[750]: time=2026-11-07T09:30:17.721Z level=INFO msg="keys expired, rotating"
server # [    8.251346] dex[750]: time=2026-11-07T09:30:17.891Z level=INFO msg="keys rotated" next_rotation=2026-11-07T15:30:17.891Z
server # [    8.253650] dex[750]: time=2026-11-07T09:30:17.893Z level=INFO msg="listening on" server=http address=127.0.0.1:5556
server # [    8.392146] Key type encrypted registered
server # [    8.421477] EDAC MC: Ver: 3.0.0
server # [    8.439671] postgresql-pre-start[742]: selecting default time zone ... UTC
server # [    8.441624] postgresql-pre-start[742]: creating configuration files ... ok
server # [    8.560580] postgresql-pre-start[742]: running bootstrap script ... ok
server # [    8.960765] postgresql-pre-start[742]: performing post-bootstrap initialization ... ok
server # [    9.052541] dhcpcd[668]: eth0: soliciting a DHCP lease
server # [    9.191382] NET: Registered PF_PACKET protocol family
server # [    9.067759] dhcpcd[668]: eth0: offered 10.0.2.15 from 10.0.2.2
server # [    9.070288] dhcpcd[668]: eth0: probing address 10.0.2.15/24
server # [    9.085511] postgresql-pre-start[742]: syncing data to disk ... ok
server # [    9.087617] postgresql-pre-start[742]: initdb: warning: enabling "trust" authentication for local connections
server # [    9.089262] postgresql-pre-start[742]: initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.
server # [    9.091688] postgresql-pre-start[742]: Success. You can now start the database server using:
server # [    9.093202] postgresql-pre-start[742]:     pg_ctl -D /var/lib/postgresql/17 -l logfile start
server # [    9.156414] postgres[783]: [783] LOG:  starting PostgreSQL 17.10 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit
server # [    9.158520] postgres[783]: [783] LOG:  listening on IPv6 address "::1", port 5432
server # [    9.159655] postgres[783]: [783] LOG:  listening on IPv4 address "127.0.0.1", port 5432
server # [    9.162365] postgres[783]: [783] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
server # [    9.169453] postgres[790]: [790] LOG:  database system was shut down at 2026-11-07 09:30:18 GMT
server # [    9.176732] postgres[783]: [783] LOG:  database system is ready to accept connections
server # [    9.178985] systemd[1]: Started PostgreSQL Server.
server # [    9.182470] systemd[1]: Starting PostgreSQL Setup Scripts...
server # [    9.284139] postgresql-setup-start[801]: CREATE DATABASE
server # [    9.309522] postgresql-setup-start[806]: CREATE ROLE
server # [    9.319156] postgresql-setup-start[808]: ALTER ROLE
server # [    9.330113] postgresql-setup-start[810]: ALTER DATABASE
server # [    9.332473] systemd[1]: Finished PostgreSQL Setup Scripts.
server # [    9.335318] systemd[1]: Reached target PostgreSQL.
server # [    9.337695] systemd[1]: Starting Horae time tracking server...
server # [    9.603418] horae[813]: 2026-11-07T09:30:19.243046Z  INFO horae: Running migrations...
server: (finished: waiting for unit postgresql.service, in 2.16 seconds)
server: waiting for unit dex.service
server: (finished: waiting for unit dex.service, in 0.05 seconds)
server: waiting for unit horae.service
server # [    9.972626] horae[813]: 2026-11-07T09:30:19.612467Z  INFO horae: Migrations complete.
server # [    9.978559] systemd[1]: Started Horae time tracking server.
server # [    9.997052] horae[832]: 2026-11-07T09:30:19.636848Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   10.003438] horae[832]: 2026-11-07T09:30:19.643448Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   10.011063] horae[832]: 2026-11-07T09:30:19.651038Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   10.024830] horae[832]: 2026-11-07T09:30:19.664265Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   10.026204] horae[832]: 2026-11-07T09:30:19.664296Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   10.027457] horae[832]: 2026-11-07T09:30:19.664308Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   10.028726] horae[832]: 2026-11-07T09:30:19.664323Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   10.029961] horae[832]: 2026-11-07T09:30:19.664340Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   10.031175] horae[832]: 2026-11-07T09:30:19.664349Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   10.032447] horae[832]: 2026-11-07T09:30:19.664361Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   10.033721] horae[832]: 2026-11-07T09:30:19.664372Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   10.035766] horae[832]: 2026-11-07T09:30:19.664392Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   10.037056] horae[832]: 2026-11-07T09:30:19.664404Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   10.038283] horae[832]: 2026-11-07T09:30:19.664414Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   10.039513] horae[832]: 2026-11-07T09:30:19.664424Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   10.040722] horae[832]: 2026-11-07T09:30:19.664433Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   10.042045] horae[832]: 2026-11-07T09:30:19.664442Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   10.043311] horae[832]: 2026-11-07T09:30:19.664454Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   10.044617] horae[832]: 2026-11-07T09:30:19.664477Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   10.045955] horae[832]: 2026-11-07T09:30:19.664487Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   10.047315] horae[832]: 2026-11-07T09:30:19.664498Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   10.048695] horae[832]: 2026-11-07T09:30:19.664508Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   10.050017] horae[832]: 2026-11-07T09:30:19.664517Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   10.051282] horae[832]: 2026-11-07T09:30:19.664527Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   10.052549] horae[832]: 2026-11-07T09:30:19.664536Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   10.053804] horae[832]: 2026-11-07T09:30:19.664546Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   10.055069] horae[832]: 2026-11-07T09:30:19.664554Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   10.056309] horae[832]: 2026-11-07T09:30:19.664563Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   10.057573] horae[832]: 2026-11-07T09:30:19.664575Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   10.059102] horae[832]: 2026-11-07T09:30:19.664590Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   10.060432] horae[832]: 2026-11-07T09:30:19.664601Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   10.061817] horae[832]: 2026-11-07T09:30:19.664613Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   10.064079] horae[832]: 2026-11-07T09:30:19.664653Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   10.065389] horae[832]: 2026-11-07T09:30:19.664663Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   10.066673] horae[832]: 2026-11-07T09:30:19.664672Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   10.067969] horae[832]: 2026-11-07T09:30:19.664682Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   10.069242] horae[832]: 2026-11-07T09:30:19.664694Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   10.070512] horae[832]: 2026-11-07T09:30:19.664703Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   10.071755] horae[832]: 2026-11-07T09:30:19.664712Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   10.072953] horae[832]: 2026-11-07T09:30:19.664722Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   10.074250] horae[832]: 2026-11-07T09:30:19.664731Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   10.075441] horae[832]: 2026-11-07T09:30:19.664741Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   10.076641] horae[832]: 2026-11-07T09:30:19.664750Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   10.077788] horae[832]: 2026-11-07T09:30:19.664760Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   10.079331] horae[832]: 2026-11-07T09:30:19.674988Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   10.080462] horae[832]: 2026-11-07T09:30:19.675002Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   10.081602] horae[832]: 2026-11-07T09:30:19.675011Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   10.082755] horae[832]: 2026-11-07T09:30:19.675021Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   10.083911] horae[832]: 2026-11-07T09:30:19.675030Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   10.085176] horae[832]: 2026-11-07T09:30:19.675040Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   10.086348] horae[832]: 2026-11-07T09:30:19.675050Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   10.087557] horae[832]: 2026-11-07T09:30:19.675077Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   10.088842] horae[832]: 2026-11-07T09:30:19.675090Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   10.091837] horae[832]: 2026-11-07T09:30:19.675100Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   10.096142] horae[832]: 2026-11-07T09:30:19.675110Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   10.098075] horae[832]: 2026-11-07T09:30:19.675120Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   10.099952] horae[832]: 2026-11-07T09:30:19.675131Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   10.101741] horae[832]: 2026-11-07T09:30:19.675150Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   10.104104] horae[832]: 2026-11-07T09:30:19.675161Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   10.105897] horae[832]: 2026-11-07T09:30:19.675178Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   10.107690] horae[832]: 2026-11-07T09:30:19.675235Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   10.109477] horae[832]: 2026-11-07T09:30:19.675246Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   10.111223] horae[832]: 2026-11-07T09:30:19.675256Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   10.112997] horae[832]: 2026-11-07T09:30:19.675266Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   10.117634] horae[832]: 2026-11-07T09:30:19.675277Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   10.119335] horae[832]: 2026-11-07T09:30:19.675288Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   10.121076] horae[832]: 2026-11-07T09:30:19.675299Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   10.122792] horae[832]: 2026-11-07T09:30:19.675309Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   10.124489] horae[832]: 2026-11-07T09:30:19.675318Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   10.129139] dhcpcd[668]: eth0: soliciting an IPv6 router
server # [   10.129988] horae[832]: 2026-11-07T09:30:19.675328Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   10.133204] horae[832]: 2026-11-07T09:30:19.675338Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   10.134551] horae[832]: 2026-11-07T09:30:19.675348Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   10.135866] horae[832]: 2026-11-07T09:30:19.675358Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   10.137136] horae[832]: 2026-11-07T09:30:19.675368Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   10.138486] horae[832]: 2026-11-07T09:30:19.675378Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   10.139735] horae[832]: 2026-11-07T09:30:19.675388Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   10.140977] horae[832]: 2026-11-07T09:30:19.675397Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   10.142192] horae[832]: 2026-11-07T09:30:19.675406Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   10.143613] horae[832]: 2026-11-07T09:30:19.675418Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   10.144864] horae[832]: 2026-11-07T09:30:19.675427Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   10.146106] horae[832]: 2026-11-07T09:30:19.675437Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   10.147334] horae[832]: 2026-11-07T09:30:19.675446Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   10.148585] dhcpcd[668]: eth0: Router Advertisement from fe80::2
server # [   10.149183] horae[832]: 2026-11-07T09:30:19.675456Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   10.150359] horae[832]: 2026-11-07T09:30:19.675466Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   10.153195] horae[832]: 2026-11-07T09:30:19.675476Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   10.154527] horae[832]: 2026-11-07T09:30:19.675486Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   10.155783] horae[832]: 2026-11-07T09:30:19.675497Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   10.157128] horae[832]: 2026-11-07T09:30:19.675506Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   10.158488] horae[832]: 2026-11-07T09:30:19.675516Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   10.159764] horae[832]: 2026-11-07T09:30:19.675527Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   10.161120] horae[832]: 2026-11-07T09:30:19.675536Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   10.162394] horae[832]: 2026-11-07T09:30:19.675546Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   10.164280] horae[832]: 2026-11-07T09:30:19.675556Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   10.165719] horae[832]: 2026-11-07T09:30:19.675568Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   10.167265] horae[832]: 2026-11-07T09:30:19.675578Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   10.168673] dhcpcd[668]: eth0: adding address fec0::5054:ff:fe12:3456/64
server # [   10.169384] horae[832]: 2026-11-07T09:30:19.675588Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   10.170691] horae[832]: 2026-11-07T09:30:19.675603Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   10.173058] horae[832]: 2026-11-07T09:30:19.675615Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   10.174379] horae[832]: 2026-11-07T09:30:19.675625Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   10.175657] horae[832]: 2026-11-07T09:30:19.675635Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   10.176948] horae[832]: 2026-11-07T09:30:19.675644Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   10.178240] horae[832]: 2026-11-07T09:30:19.675654Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   10.179544] horae[832]: 2026-11-07T09:30:19.675663Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   10.180801] horae[832]: 2026-11-07T09:30:19.675687Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   10.182172] horae[832]: 2026-11-07T09:30:19.675697Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   10.183399] horae[832]: 2026-11-07T09:30:19.675707Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   10.184627] horae[832]: 2026-11-07T09:30:19.719313Z  INFO horae: Listening on 127.0.0.1:3000
server # [   10.186312] dhcpcd[668]: eth0: adding route to fec0::/64
server # [   10.186921] dhcpcd[668]: eth0: adding default route via fe80::2
server: (finished: waiting for unit horae.service, in 1.07 seconds)
server: waiting for TCP port 5556 on localhost
server # Connection to localhost (127.0.0.1) 5556 port [tcp/freeciv] succeeded!
server: (finished: waiting for TCP port 5556 on localhost, in 0.03 seconds)
server: waiting for TCP port 3000 on localhost
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 0.01 seconds)
server: must succeed: curl -sf http://127.0.0.1:3000/health | grep -q ok
server: (finished: must succeed: curl -sf http://127.0.0.1:3000/health | grep -q ok, in 0.02 seconds)
server: must succeed: curl -sf http://127.0.0.1:5556/dex/.well-known/openid-configuration >/dev/null
server: (finished: must succeed: curl -sf http://127.0.0.1:5556/dex/.well-known/openid-configuration >/dev/null, in 0.02 seconds)
server: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae seed
server # [   10.900712] sudo[863]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; ENV=DATABASE_URL=postgres:///horae ; COMMAND=/run/current-system/sw/bin/horae seed
server # [   10.920868] sudo[863]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   10.993971] sudo[863]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae seed, in 0.12 seconds)
server: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member
server # [   11.009430] sudo[872]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; ENV=DATABASE_URL=postgres:///horae ; COMMAND=/run/current-system/sw/bin/horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member
server # [   11.028232] sudo[872]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   11.049798] postgres[879]: [879] LOG:  could not send data to client: Broken pipe
server # [   11.050669] postgres[879]: [879] FATAL:  connection to client lost
server # [   11.052604] sudo[872]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member, in 0.06 seconds)
server: must succeed: curl -s -c /tmp/jar.txt -b /tmp/jar.txt -L http://127.0.0.1:3000/auth/oidc/start -o /dev/null
server # [   11.076873] dex[750]: time=2026-11-07T09:30:20.716Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=3c334cb6-67cc-49b9-bac5-dac28c7784a6
server: (finished: must succeed: curl -s -c /tmp/jar.txt -b /tmp/jar.txt -L http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.09 seconds)
server: must succeed: curl -s -b /tmp/jar.txt http://127.0.0.1:3000/harvest/v2/time_entries
server: (finished: must succeed: curl -s -b /tmp/jar.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.06 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   11.224885] sudo[886]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT id FROM users WHERE email = \'kilgore@kilgore.trout\''
server # [   11.239370] sudo[886]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   11.249381] sudo[886]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server: must succeed: dex-id-token horae horae-e2e-secret
server # [   11.624160] dex[750]: time=2026-11-07T09:30:21.264Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=0acfa9e1-91d6-4686-b774-88ff6146f55c
server: (finished: must succeed: dex-id-token horae horae-e2e-secret, in 0.41 seconds)
server # [   11.682525] sudo[900]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-3a8c-7731-a5f3-7a4948d3aa41 --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr
server # [   11.703152] sudo[900]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   11.725377] sudo[900]: pam_unix(sudo:session): session closed for user horae
server: must succeed: sudo -u horae psql horae -c "UPDATE users SET active = false WHERE email = 'kilgore@kilgore.trout'"
server # [   11.742295] sudo[906]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -c 'UPDATE users SET active = false WHERE email = \'kilgore@kilgore.trout\''
server # [   11.778252] sudo[906]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   11.793962] sudo[906]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -c "UPDATE users SET active = false WHERE email = 'kilgore@kilgore.trout'", in 0.07 seconds)
server # [   11.819705] dex[750]: time=2026-11-07T09:30:21.459Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=389f3be1-7a44-4982-a429-b2285263b5ca
server # [   11.831728] horae[832]: 2026-11-07T09:30:21.471373Z  WARN call: horae::auth::oidc: OIDC login denied: account is deactivated
server: must succeed: curl -s -o /dev/null -w '%{http_code}' -b /tmp/jar2.txt http://127.0.0.1:3000/harvest/v2/time_entries
server: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' -b /tmp/jar2.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.02 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   11.870545] sudo[925]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = \'kilgore@kilgore.trout\''
server # [   11.890620] sudo[925]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   11.904164] sudo[925]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' 'Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified' 'Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret' > /run/systemd/system/horae.service.d/omit-email-verified.conf
server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' 'Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified' 'Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret' > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)
server: must succeed: systemctl daemon-reload && systemctl restart horae.service
server # [   11.928331] systemd[1]: Reload requested from client PID 939 ('systemctl') (unit backdoor.service)...
server # [   11.930168] systemd[1]: Reloading...
server # [   12.130686] systemd[1]: Reloading finished in 199 ms.
server # [   12.173936] systemd[1]: Stopping Horae time tracking server...
server # [   12.178172] systemd[1]: horae.service: Deactivated successfully.
server # [   12.185035] systemd[1]: Stopped Horae time tracking server.
server # [   12.185902] systemd[1]: horae.service: Consumed 215ms CPU time over 2.842s wall clock time, 99.5M memory peak, 93.3M read from disk, 16.8K incoming IP traffic, 24.4K outgoing IP traffic.
server # [   12.193334] systemd[1]: Starting Horae time tracking server...
server # [   12.224573] horae[978]: 2026-11-07T09:30:21.864335Z  INFO horae: Running migrations...
server # [   12.227302] horae[978]: 2026-11-07T09:30:21.867303Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   12.240209] horae[978]: 2026-11-07T09:30:21.877240Z  INFO horae: Migrations complete.
server # [   12.241784] postgres[983]: [983] LOG:  could not receive data from client: Connection reset by peer
server # [   12.245261] systemd[1]: Started Horae time tracking server.
server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.33 seconds)
server: waiting for TCP port 3000 on localhost
server # [   12.281984] horae[985]: 2026-11-07T09:30:21.921723Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   12.290216] horae[985]: 2026-11-07T09:30:21.930166Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   12.300306] horae[985]: 2026-11-07T09:30:21.940261Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   12.302663] horae[985]: 2026-11-07T09:30:21.942645Z  INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping
server # [   12.304707] horae[985]: 2026-11-07T09:30:21.944721Z  INFO sqlx::postgres::notice: relation "session" already exists, skipping
server # [   12.309065] horae[985]: 2026-11-07T09:30:21.947568Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   12.310889] horae[985]: 2026-11-07T09:30:21.947595Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   12.312635] horae[985]: 2026-11-07T09:30:21.947610Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   12.314348] horae[985]: 2026-11-07T09:30:21.947625Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   12.316069] horae[985]: 2026-11-07T09:30:21.947641Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   12.317758] horae[985]: 2026-11-07T09:30:21.947653Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   12.319531] horae[985]: 2026-11-07T09:30:21.947668Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   12.322104] horae[985]: 2026-11-07T09:30:21.947682Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   12.323856] horae[985]: 2026-11-07T09:30:21.947702Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   12.325613] horae[985]: 2026-11-07T09:30:21.947716Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   12.327295] horae[985]: 2026-11-07T09:30:21.947729Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   12.328997] horae[985]: 2026-11-07T09:30:21.947742Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   12.330716] horae[985]: 2026-11-07T09:30:21.947755Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   12.332528] horae[985]: 2026-11-07T09:30:21.947768Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   12.336815] horae[985]: 2026-11-07T09:30:21.947782Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   12.338646] horae[985]: 2026-11-07T09:30:21.947804Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   12.340444] horae[985]: 2026-11-07T09:30:21.947817Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   12.342180] horae[985]: 2026-11-07T09:30:21.947831Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   12.343913] horae[985]: 2026-11-07T09:30:21.947844Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   12.345649] horae[985]: 2026-11-07T09:30:21.947856Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   12.348823] horae[985]: 2026-11-07T09:30:21.947869Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   12.350590] horae[985]: 2026-11-07T09:30:21.947882Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   12.352305] horae[985]: 2026-11-07T09:30:21.947902Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   12.354058] horae[985]: 2026-11-07T09:30:21.947915Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   12.355782] horae[985]: 2026-11-07T09:30:21.947927Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   12.357470] horae[985]: 2026-11-07T09:30:21.947941Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   12.359252] horae[985]: 2026-11-07T09:30:21.947956Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   12.364086] horae[985]: 2026-11-07T09:30:21.947970Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   12.365921] horae[985]: 2026-11-07T09:30:21.947985Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   12.367695] horae[985]: 2026-11-07T09:30:21.948014Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   12.369449] horae[985]: 2026-11-07T09:30:21.948027Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   12.371173] horae[985]: 2026-11-07T09:30:21.948041Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   12.372938] horae[985]: 2026-11-07T09:30:21.948080Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   12.377575] horae[985]: 2026-11-07T09:30:21.948094Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   12.379346] horae[985]: 2026-11-07T09:30:21.948108Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   12.381053] horae[985]: 2026-11-07T09:30:21.948120Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   12.384512] horae[985]: 2026-11-07T09:30:21.948134Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   12.386197] horae[985]: 2026-11-07T09:30:21.948146Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   12.387868] horae[985]: 2026-11-07T09:30:21.948160Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   12.391636] horae[985]: 2026-11-07T09:30:21.948174Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   12.393258] horae[985]: 2026-11-07T09:30:21.948190Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   12.394940] horae[985]: 2026-11-07T09:30:21.948207Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   12.396532] horae[985]: 2026-11-07T09:30:21.948219Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   12.401204] horae[985]: 2026-11-07T09:30:21.948231Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   12.402884] horae[985]: 2026-11-07T09:30:21.948244Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   12.404493] horae[985]: 2026-11-07T09:30:21.948257Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   12.406241] horae[985]: 2026-11-07T09:30:21.948269Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   12.407854] horae[985]: 2026-11-07T09:30:21.948282Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   12.409499] horae[985]: 2026-11-07T09:30:21.948297Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   12.412203] horae[985]: 2026-11-07T09:30:21.948312Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   12.413879] horae[985]: 2026-11-07T09:30:21.948326Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   12.415644] horae[985]: 2026-11-07T09:30:21.948339Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   12.417474] horae[985]: 2026-11-07T09:30:21.948351Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   12.419307] horae[985]: 2026-11-07T09:30:21.948364Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   12.421096] horae[985]: 2026-11-07T09:30:21.948377Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   12.423937] horae[985]: 2026-11-07T09:30:21.948392Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   12.425736] horae[985]: 2026-11-07T09:30:21.948412Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   12.427487] horae[985]: 2026-11-07T09:30:21.948453Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   12.429204] horae[985]: 2026-11-07T09:30:21.948467Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   12.430962] horae[985]: 2026-11-07T09:30:21.948480Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   12.432701] horae[985]: 2026-11-07T09:30:21.948494Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   12.436096] horae[985]: 2026-11-07T09:30:21.948507Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   12.437861] horae[985]: 2026-11-07T09:30:21.948519Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   12.439555] horae[985]: 2026-11-07T09:30:21.948532Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   12.441203] horae[985]: 2026-11-07T09:30:21.948545Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   12.442886] horae[985]: 2026-11-07T09:30:21.948558Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   12.444773] horae[985]: 2026-11-07T09:30:21.948570Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   12.447822] horae[985]: 2026-11-07T09:30:21.948584Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   12.449605] horae[985]: 2026-11-07T09:30:21.948596Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   12.451332] horae[985]: 2026-11-07T09:30:21.948609Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   12.453119] horae[985]: 2026-11-07T09:30:21.948621Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   12.455024] horae[985]: 2026-11-07T09:30:21.948634Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   12.456746] horae[985]: 2026-11-07T09:30:21.948648Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   12.458464] horae[985]: 2026-11-07T09:30:21.948660Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   12.460152] horae[985]: 2026-11-07T09:30:21.948673Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   12.461839] horae[985]: 2026-11-07T09:30:21.948687Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   12.463571] horae[985]: 2026-11-07T09:30:21.948699Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   12.465262] horae[985]: 2026-11-07T09:30:21.948712Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   12.466962] horae[985]: 2026-11-07T09:30:21.948726Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   12.468700] horae[985]: 2026-11-07T09:30:21.948739Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   12.470498] horae[985]: 2026-11-07T09:30:21.948753Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   12.472254] horae[985]: 2026-11-07T09:30:21.948766Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   12.474042] horae[985]: 2026-11-07T09:30:21.948779Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   12.475826] horae[985]: 2026-11-07T09:30:21.948793Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   12.477670] horae[985]: 2026-11-07T09:30:21.948806Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   12.479512] horae[985]: 2026-11-07T09:30:21.948820Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   12.481237] horae[985]: 2026-11-07T09:30:21.948832Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   12.482964] horae[985]: 2026-11-07T09:30:21.948844Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   12.484675] horae[985]: 2026-11-07T09:30:21.948858Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   12.486314] horae[985]: 2026-11-07T09:30:21.948871Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   12.488217] horae[985]: 2026-11-07T09:30:21.948893Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   12.490042] horae[985]: 2026-11-07T09:30:21.948907Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   12.491889] horae[985]: 2026-11-07T09:30:21.948920Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   12.493671] horae[985]: 2026-11-07T09:30:21.948934Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   12.495520] horae[985]: 2026-11-07T09:30:21.948951Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   12.497270] horae[985]: 2026-11-07T09:30:21.948964Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   12.499062] horae[985]: 2026-11-07T09:30:21.948979Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   12.500802] horae[985]: 2026-11-07T09:30:21.948991Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   12.502542] horae[985]: 2026-11-07T09:30:21.949005Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   12.504252] horae[985]: 2026-11-07T09:30:21.949017Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   12.505953] horae[985]: 2026-11-07T09:30:21.949036Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   12.507664] horae[985]: 2026-11-07T09:30:21.949050Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   12.509320] horae[985]: 2026-11-07T09:30:21.975393Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   12.511032] horae[985]: 2026-11-07T09:30:22.015325Z  INFO horae: Listening on 127.0.0.1:3000
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)
server: must succeed: dex-id-token horae-omit-email-verified horae-omit-e2e-secret
server # [   13.487560] dex[750]: time=2026-11-07T09:30:23.127Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=1c8910a6-27e1-45a8-a00a-4097407664ad
server: (finished: must succeed: dex-id-token horae-omit-email-verified horae-omit-e2e-secret, in 0.23 seconds)
server: must succeed: curl -sS -c /tmp/jar3.txt -b /tmp/jar3.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null
server # [   13.549977] dex[750]: time=2026-11-07T09:30:23.189Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=a3f26467-fb85-45d9-a14a-234fdca61444
server # [   13.565178] horae[985]: 2026-11-07T09:30:23.204689Z  WARN call: horae::auth::oidc: OIDC login denied: no account for subject/email
server: (finished: must succeed: curl -sS -c /tmp/jar3.txt -b /tmp/jar3.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.05 seconds)
server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar3.txt http://127.0.0.1:3000/harvest/v2/time_entries
server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar3.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.02 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT oidc_issuer IS NULL AND oidc_subject IS NULL FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   13.607620] sudo[1012]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT oidc_issuer IS NULL AND oidc_subject IS NULL FROM users WHERE email = \'kilgore@kilgore.trout\''
server # [   13.627754] sudo[1012]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   13.640391] sudo[1012]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT oidc_issuer IS NULL AND oidc_subject IS NULL FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server # [   13.660592] sudo[1023]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-3a8c-7731-a5f3-7a4948d3aa41 --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr
server # [   13.681875] sudo[1023]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   13.701870] postgres[1028]: [1028] LOG:  could not receive data from client: Connection reset by peer
server # [   13.705089] sudo[1023]: pam_unix(sudo:session): session closed for user horae
server # [   13.716754] dhcpcd[668]: eth0: leased 10.0.2.15 for 86400 seconds
server # [   13.718206] dhcpcd[668]: eth0: adding route to 10.0.2.0/24
server # [   13.718982] dhcpcd[668]: eth0: adding default route via 10.0.2.2
server # [   13.735075] sudo[1034]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-3a8c-7731-a5f3-7a4948d3aa41 --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr
server # [   13.770937] sudo[1034]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   13.801978] postgres[1059]: [1059] LOG:  could not send data to client: Broken pipe
server # [   13.803277] postgres[1059]: [1059] FATAL:  connection to client lost
server # [   13.804994] sudo[1034]: pam_unix(sudo:session): session closed for user horae
server # [   13.839627] sudo[1079]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user create --email other@kilgore.trout --name Other --role member
server # [   13.857985] systemd[1]: Started DHCP Client.
server # [   13.861400] systemd[1]: Reached target Multi-User System.
server # [   13.862562] systemd[1]: Startup finished in 706ms (kernel) + 3.264s (initrd) + 9.890s (userspace) = 13.862s.
server # [   13.874450] sudo[1079]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   13.898158] postgres[1094]: [1094] LOG:  could not receive data from client: Connection reset by peer
server # [   13.900100] sudo[1079]: pam_unix(sudo:session): session closed for user horae
server: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'other@kilgore.trout'"'"''
server # [   13.918488] sudo[1095]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT id FROM users WHERE email = \'other@kilgore.trout\''
server # [   13.938126] sudo[1095]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   13.950571] sudo[1095]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'other@kilgore.trout'"'"'', in 0.05 seconds)
server # [   13.971263] sudo[1106]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-45ab-7761-b704-8a147e4f12ba --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr
server # [   13.992385] sudo[1106]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   14.010268] sudo[1106]: pam_unix(sudo:session): session closed for user horae
server # [   14.011566] postgres[1111]: [1111] LOG:  unexpected EOF on client connection with an open transaction
server: must succeed: curl -sS -c /tmp/jar4.txt -b /tmp/jar4.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null
server # [   14.042392] dex[750]: time=2026-11-07T09:30:23.682Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=a30de919-2c03-48aa-b99a-ad56eba2d70d
server: (finished: must succeed: curl -sS -c /tmp/jar4.txt -b /tmp/jar4.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.11 seconds)
server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar4.txt http://127.0.0.1:3000/harvest/v2/time_entries
server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar4.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.05 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET email = '"'"'kilgore-linked@kilgore.trout'"'"', oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   14.188508] sudo[1119]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET email = \'kilgore-linked@kilgore.trout\', oidc_issuer = NULL, oidc_subject = NULL WHERE email = \'kilgore@kilgore.trout\''
server # [   14.208684] sudo[1119]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   14.226981] sudo[1119]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET email = '"'"'kilgore-linked@kilgore.trout'"'"', oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)
server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae Environment=HORAE_OIDC_CLIENT_SECRET=horae-e2e-secret > /run/systemd/system/horae.service.d/omit-email-verified.conf
server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae Environment=HORAE_OIDC_CLIENT_SECRET=horae-e2e-secret > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)
server: must succeed: systemctl daemon-reload && systemctl restart horae.service
server # [   14.251083] systemd[1]: Reload requested from client PID 1133 ('systemctl') (unit backdoor.service)...
server # [   14.253070] systemd[1]: Reloading...
server # [   14.468036] systemd[1]: Reloading finished in 214 ms.
server # [   14.507406] systemd[1]: Stopping Horae time tracking server...
server # [   14.511879] systemd[1]: horae.service: Deactivated successfully.
server # [   14.519782] systemd[1]: Stopped Horae time tracking server.
server # [   14.520675] systemd[1]: horae.service: Consumed 73ms CPU time over 2.318s wall clock time, 5.8M memory peak, 16.4K incoming IP traffic, 24.2K outgoing IP traffic.
server # [   14.527350] systemd[1]: Starting Horae time tracking server...
server # [   14.559619] horae[1171]: 2026-11-07T09:30:24.199354Z  INFO horae: Running migrations...
server # [   14.562334] horae[1171]: 2026-11-07T09:30:24.202319Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   14.573623] horae[1171]: 2026-11-07T09:30:24.212271Z  INFO horae: Migrations complete.
server # [   14.579202] systemd[1]: Started Horae time tracking server.
server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.35 seconds)
server: waiting for TCP port 3000 on localhost
server # [   14.618099] horae[1178]: 2026-11-07T09:30:24.257581Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   14.626738] horae[1178]: 2026-11-07T09:30:24.266731Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   14.637657] horae[1178]: 2026-11-07T09:30:24.277544Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   14.646650] horae[1178]: 2026-11-07T09:30:24.286621Z  INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping
server # [   14.651066] horae[1178]: 2026-11-07T09:30:24.289425Z  INFO sqlx::postgres::notice: relation "session" already exists, skipping
server # [   14.652714] horae[1178]: 2026-11-07T09:30:24.289719Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   14.654508] horae[1178]: 2026-11-07T09:30:24.289743Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   14.656239] horae[1178]: 2026-11-07T09:30:24.289759Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   14.658159] horae[1178]: 2026-11-07T09:30:24.289776Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   14.659890] horae[1178]: 2026-11-07T09:30:24.289792Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   14.661834] horae[1178]: 2026-11-07T09:30:24.289805Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   14.663725] horae[1178]: 2026-11-07T09:30:24.289819Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   14.665606] horae[1178]: 2026-11-07T09:30:24.289834Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   14.667532] horae[1178]: 2026-11-07T09:30:24.289853Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   14.669255] horae[1178]: 2026-11-07T09:30:24.289866Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   14.672102] horae[1178]: 2026-11-07T09:30:24.289879Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   14.673846] horae[1178]: 2026-11-07T09:30:24.289901Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   14.675593] horae[1178]: 2026-11-07T09:30:24.289915Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   14.677411] horae[1178]: 2026-11-07T09:30:24.289928Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   14.679156] horae[1178]: 2026-11-07T09:30:24.289942Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   14.680967] horae[1178]: 2026-11-07T09:30:24.289964Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   14.682882] horae[1178]: 2026-11-07T09:30:24.289978Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   14.684711] horae[1178]: 2026-11-07T09:30:24.289992Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   14.686485] horae[1178]: 2026-11-07T09:30:24.290005Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   14.688256] horae[1178]: 2026-11-07T09:30:24.290017Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   14.690074] horae[1178]: 2026-11-07T09:30:24.290029Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   14.692944] horae[1178]: 2026-11-07T09:30:24.290043Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   14.694821] horae[1178]: 2026-11-07T09:30:24.290081Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   14.696908] horae[1178]: 2026-11-07T09:30:24.290094Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   14.698915] horae[1178]: 2026-11-07T09:30:24.290106Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   14.700690] horae[1178]: 2026-11-07T09:30:24.290119Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   14.704988] horae[1178]: 2026-11-07T09:30:24.290134Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   14.706835] horae[1178]: 2026-11-07T09:30:24.290148Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   14.708691] horae[1178]: 2026-11-07T09:30:24.290163Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   14.711105] horae[1178]: 2026-11-07T09:30:24.290195Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   14.712943] horae[1178]: 2026-11-07T09:30:24.290208Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   14.714785] horae[1178]: 2026-11-07T09:30:24.290221Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   14.718309] horae[1178]: 2026-11-07T09:30:24.290234Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   14.720144] horae[1178]: 2026-11-07T09:30:24.290248Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   14.721905] horae[1178]: 2026-11-07T09:30:24.290261Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   14.723607] horae[1178]: 2026-11-07T09:30:24.290273Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   14.725281] horae[1178]: 2026-11-07T09:30:24.290287Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   14.726956] horae[1178]: 2026-11-07T09:30:24.290304Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   14.731304] horae[1178]: 2026-11-07T09:30:24.290317Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   14.732985] horae[1178]: 2026-11-07T09:30:24.290330Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   14.734772] horae[1178]: 2026-11-07T09:30:24.290343Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   14.736464] horae[1178]: 2026-11-07T09:30:24.290357Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   14.738094] horae[1178]: 2026-11-07T09:30:24.290370Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   14.741255] horae[1178]: 2026-11-07T09:30:24.290381Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   14.742982] horae[1178]: 2026-11-07T09:30:24.290394Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   14.744645] horae[1178]: 2026-11-07T09:30:24.290406Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   14.746420] horae[1178]: 2026-11-07T09:30:24.290419Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   14.748050] horae[1178]: 2026-11-07T09:30:24.290432Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   14.749715] horae[1178]: 2026-11-07T09:30:24.290447Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   14.752413] horae[1178]: 2026-11-07T09:30:24.290463Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   14.754090] horae[1178]: 2026-11-07T09:30:24.290477Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   14.755894] horae[1178]: 2026-11-07T09:30:24.290489Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   14.757809] horae[1178]: 2026-11-07T09:30:24.290502Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   14.759622] horae[1178]: 2026-11-07T09:30:24.290515Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   14.761392] horae[1178]: 2026-11-07T09:30:24.290528Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   14.763154] horae[1178]: 2026-11-07T09:30:24.290544Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   14.764928] horae[1178]: 2026-11-07T09:30:24.290562Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   14.766707] horae[1178]: 2026-11-07T09:30:24.290607Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   14.768543] horae[1178]: 2026-11-07T09:30:24.290621Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   14.770380] horae[1178]: 2026-11-07T09:30:24.290634Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   14.772209] horae[1178]: 2026-11-07T09:30:24.290647Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   14.774128] horae[1178]: 2026-11-07T09:30:24.290659Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   14.775977] horae[1178]: 2026-11-07T09:30:24.290673Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   14.777756] horae[1178]: 2026-11-07T09:30:24.290687Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   14.779474] horae[1178]: 2026-11-07T09:30:24.290699Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   14.781332] horae[1178]: 2026-11-07T09:30:24.290711Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   14.783172] horae[1178]: 2026-11-07T09:30:24.290723Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   14.784980] horae[1178]: 2026-11-07T09:30:24.290736Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   14.786812] horae[1178]: 2026-11-07T09:30:24.290752Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   14.788594] horae[1178]: 2026-11-07T09:30:24.290765Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   14.790371] horae[1178]: 2026-11-07T09:30:24.290777Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   14.792138] horae[1178]: 2026-11-07T09:30:24.290790Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   14.793895] horae[1178]: 2026-11-07T09:30:24.290803Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   14.795709] horae[1178]: 2026-11-07T09:30:24.290814Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   14.797444] horae[1178]: 2026-11-07T09:30:24.290827Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   14.799155] horae[1178]: 2026-11-07T09:30:24.290840Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   14.800947] horae[1178]: 2026-11-07T09:30:24.290854Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   14.802797] horae[1178]: 2026-11-07T09:30:24.290866Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   14.804822] horae[1178]: 2026-11-07T09:30:24.290879Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   14.806644] horae[1178]: 2026-11-07T09:30:24.290897Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   14.808393] horae[1178]: 2026-11-07T09:30:24.290911Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   14.810415] horae[1178]: 2026-11-07T09:30:24.290924Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   14.812408] horae[1178]: 2026-11-07T09:30:24.290937Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   14.814351] horae[1178]: 2026-11-07T09:30:24.290950Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   14.816297] horae[1178]: 2026-11-07T09:30:24.290964Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   14.818151] horae[1178]: 2026-11-07T09:30:24.290978Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   14.819908] horae[1178]: 2026-11-07T09:30:24.290990Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   14.821624] horae[1178]: 2026-11-07T09:30:24.291002Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   14.823295] horae[1178]: 2026-11-07T09:30:24.291015Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   14.824947] horae[1178]: 2026-11-07T09:30:24.291028Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   14.826864] horae[1178]: 2026-11-07T09:30:24.291044Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   14.828753] horae[1178]: 2026-11-07T09:30:24.311380Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   14.830534] horae[1178]: 2026-11-07T09:30:24.311402Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   14.832318] horae[1178]: 2026-11-07T09:30:24.311417Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   14.834153] horae[1178]: 2026-11-07T09:30:24.311437Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   14.835935] horae[1178]: 2026-11-07T09:30:24.311450Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   14.837714] horae[1178]: 2026-11-07T09:30:24.311464Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   14.839703] horae[1178]: 2026-11-07T09:30:24.311476Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   14.841562] horae[1178]: 2026-11-07T09:30:24.311490Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   14.843259] horae[1178]: 2026-11-07T09:30:24.311502Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   14.845138] horae[1178]: 2026-11-07T09:30:24.311515Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   14.846881] horae[1178]: 2026-11-07T09:30:24.311530Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   14.848574] horae[1178]: 2026-11-07T09:30:24.311542Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   14.850272] horae[1178]: 2026-11-07T09:30:24.343725Z  INFO horae: Listening on 127.0.0.1:3000
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)
server: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start
server # [   15.654560] dex[750]: time=2026-11-07T09:30:25.294Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=f939edd5-fbe9-4b69-917a-1f170104ce78
server # [   15.671324] horae[1178]: 2026-11-07T09:30:25.310933Z  WARN call: horae::auth::oidc: OIDC login denied: no account for subject/email
server: (finished: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.05 seconds)
server: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt http://127.0.0.1:3000/auth/login
server: (finished: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt http://127.0.0.1:3000/auth/login, in 0.02 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0'
server # [   15.720202] sudo[1201]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'
server # [   15.740125] sudo[1201]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   15.751340] sudo[1201]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.05 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''
server # [   15.769608] sudo[1208]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''
server # [   15.789356] sudo[1208]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   15.803987] sudo[1208]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae Environment=HORAE_OIDC_CLIENT_SECRET=horae-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=example.com > /run/systemd/system/horae.service.d/omit-email-verified.conf
server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae Environment=HORAE_OIDC_CLIENT_SECRET=horae-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=example.com > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)
server: must succeed: systemctl daemon-reload && systemctl restart horae.service
server # [   15.830322] systemd[1]: Reload requested from client PID 1222 ('systemctl') (unit backdoor.service)...
server # [   15.831882] systemd[1]: Reloading...
server # [   16.059502] systemd[1]: Reloading finished in 229 ms.
server # [   16.097311] systemd[1]: Stopping Horae time tracking server...
server # [   16.104411] systemd[1]: horae.service: Deactivated successfully.
server # [   16.105442] systemd[1]: Stopped Horae time tracking server.
server # [   16.108667] systemd[1]: horae.service: Consumed 61ms CPU time over 1.576s wall clock time, 5.5M memory peak, 8.2K incoming IP traffic, 18K outgoing IP traffic.
server # [   16.116384] systemd[1]: Starting Horae time tracking server...
server # [   16.150191] horae[1260]: 2026-11-07T09:30:25.789711Z  INFO horae: Running migrations...
server # [   16.154322] horae[1260]: 2026-11-07T09:30:25.794268Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   16.169492] horae[1260]: 2026-11-07T09:30:25.805727Z  INFO horae: Migrations complete.
server # [   16.172605] systemd[1]: Started Horae time tracking server.
server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.36 seconds)
server: waiting for TCP port 3000 on localhost
server # [   16.211914] horae[1267]: 2026-11-07T09:30:25.851644Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   16.220755] horae[1267]: 2026-11-07T09:30:25.860743Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   16.231424] horae[1267]: 2026-11-07T09:30:25.871401Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   16.233996] horae[1267]: 2026-11-07T09:30:25.873980Z  INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping
server # [   16.238184] horae[1267]: 2026-11-07T09:30:25.877104Z  INFO sqlx::postgres::notice: relation "session" already exists, skipping
server # [   16.239817] horae[1267]: 2026-11-07T09:30:25.877402Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   16.241653] horae[1267]: 2026-11-07T09:30:25.877426Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   16.243417] horae[1267]: 2026-11-07T09:30:25.877441Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   16.245163] horae[1267]: 2026-11-07T09:30:25.877456Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   16.246915] horae[1267]: 2026-11-07T09:30:25.877473Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   16.251111] horae[1267]: 2026-11-07T09:30:25.877486Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   16.252943] horae[1267]: 2026-11-07T09:30:25.877500Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   16.254758] horae[1267]: 2026-11-07T09:30:25.877514Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   16.256574] horae[1267]: 2026-11-07T09:30:25.877533Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   16.258303] horae[1267]: 2026-11-07T09:30:25.877547Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   16.260095] horae[1267]: 2026-11-07T09:30:25.877561Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   16.261843] horae[1267]: 2026-11-07T09:30:25.877574Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   16.263611] horae[1267]: 2026-11-07T09:30:25.877588Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   16.265416] horae[1267]: 2026-11-07T09:30:25.877601Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   16.267219] horae[1267]: 2026-11-07T09:30:25.877616Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   16.269099] horae[1267]: 2026-11-07T09:30:25.877638Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   16.273125] horae[1267]: 2026-11-07T09:30:25.877652Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   16.275391] horae[1267]: 2026-11-07T09:30:25.877666Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   16.277203] horae[1267]: 2026-11-07T09:30:25.877679Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   16.279079] horae[1267]: 2026-11-07T09:30:25.877691Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   16.280873] horae[1267]: 2026-11-07T09:30:25.877704Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   16.282662] horae[1267]: 2026-11-07T09:30:25.877718Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   16.284466] horae[1267]: 2026-11-07T09:30:25.877732Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   16.287630] horae[1267]: 2026-11-07T09:30:25.877745Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   16.289479] horae[1267]: 2026-11-07T09:30:25.877757Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   16.291262] horae[1267]: 2026-11-07T09:30:25.877770Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   16.293138] horae[1267]: 2026-11-07T09:30:25.877786Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   16.294909] horae[1267]: 2026-11-07T09:30:25.877799Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   16.296770] horae[1267]: 2026-11-07T09:30:25.877818Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   16.304605] horae[1267]: 2026-11-07T09:30:25.877847Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   16.306502] horae[1267]: 2026-11-07T09:30:25.877860Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   16.308345] horae[1267]: 2026-11-07T09:30:25.877874Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   16.310205] horae[1267]: 2026-11-07T09:30:25.877894Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   16.312082] horae[1267]: 2026-11-07T09:30:25.877908Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   16.313879] horae[1267]: 2026-11-07T09:30:25.877921Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   16.318499] horae[1267]: 2026-11-07T09:30:25.877933Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   16.320258] horae[1267]: 2026-11-07T09:30:25.877947Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   16.321994] horae[1267]: 2026-11-07T09:30:25.877966Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   16.323819] horae[1267]: 2026-11-07T09:30:25.877980Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   16.325544] horae[1267]: 2026-11-07T09:30:25.877994Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   16.330757] horae[1267]: 2026-11-07T09:30:25.878008Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   16.332625] horae[1267]: 2026-11-07T09:30:25.878024Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   16.334336] horae[1267]: 2026-11-07T09:30:25.878036Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   16.336043] horae[1267]: 2026-11-07T09:30:25.878048Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   16.337731] horae[1267]: 2026-11-07T09:30:25.890197Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   16.339394] horae[1267]: 2026-11-07T09:30:25.890214Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   16.342673] horae[1267]: 2026-11-07T09:30:25.890228Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   16.344396] horae[1267]: 2026-11-07T09:30:25.890242Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   16.346555] horae[1267]: 2026-11-07T09:30:25.890259Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   16.348428] horae[1267]: 2026-11-07T09:30:25.890274Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   16.350211] horae[1267]: 2026-11-07T09:30:25.890288Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   16.352153] horae[1267]: 2026-11-07T09:30:25.890302Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   16.357420] horae[1267]: 2026-11-07T09:30:25.890315Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   16.359421] horae[1267]: 2026-11-07T09:30:25.890329Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   16.361926] horae[1267]: 2026-11-07T09:30:25.890345Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   16.363781] horae[1267]: 2026-11-07T09:30:25.890358Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   16.365668] horae[1267]: 2026-11-07T09:30:25.890381Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   16.368261] horae[1267]: 2026-11-07T09:30:25.890422Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   16.370153] horae[1267]: 2026-11-07T09:30:25.890437Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   16.371975] horae[1267]: 2026-11-07T09:30:25.890451Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   16.373799] horae[1267]: 2026-11-07T09:30:25.890465Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   16.377025] horae[1267]: 2026-11-07T09:30:25.890478Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   16.378882] horae[1267]: 2026-11-07T09:30:25.890491Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   16.382086] horae[1267]: 2026-11-07T09:30:25.890504Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   16.383892] horae[1267]: 2026-11-07T09:30:25.890517Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   16.385722] horae[1267]: 2026-11-07T09:30:25.890529Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   16.387480] horae[1267]: 2026-11-07T09:30:25.890542Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   16.389342] horae[1267]: 2026-11-07T09:30:25.890556Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   16.393162] horae[1267]: 2026-11-07T09:30:25.890569Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   16.395064] horae[1267]: 2026-11-07T09:30:25.890582Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   16.396932] horae[1267]: 2026-11-07T09:30:25.890596Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   16.398775] horae[1267]: 2026-11-07T09:30:25.890609Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   16.400623] horae[1267]: 2026-11-07T09:30:25.890623Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   16.402452] horae[1267]: 2026-11-07T09:30:25.890635Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   16.406571] horae[1267]: 2026-11-07T09:30:25.890647Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   16.408399] horae[1267]: 2026-11-07T09:30:25.890662Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   16.410283] horae[1267]: 2026-11-07T09:30:25.890675Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   16.412159] horae[1267]: 2026-11-07T09:30:25.890687Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   16.414905] horae[1267]: 2026-11-07T09:30:25.890700Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   16.416864] horae[1267]: 2026-11-07T09:30:25.890713Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   16.418607] horae[1267]: 2026-11-07T09:30:25.890726Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   16.420576] horae[1267]: 2026-11-07T09:30:25.890739Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   16.422419] horae[1267]: 2026-11-07T09:30:25.890753Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   16.424244] horae[1267]: 2026-11-07T09:30:25.890767Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   16.426240] horae[1267]: 2026-11-07T09:30:25.890780Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   16.428297] horae[1267]: 2026-11-07T09:30:25.890794Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   16.430197] horae[1267]: 2026-11-07T09:30:25.890807Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   16.432487] horae[1267]: 2026-11-07T09:30:25.890819Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   16.434384] horae[1267]: 2026-11-07T09:30:25.890832Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   16.436301] horae[1267]: 2026-11-07T09:30:25.890845Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   16.438520] horae[1267]: 2026-11-07T09:30:25.890860Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   16.440555] horae[1267]: 2026-11-07T09:30:25.890873Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   16.443158] horae[1267]: 2026-11-07T09:30:25.890897Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   16.446508] horae[1267]: 2026-11-07T09:30:25.890914Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   16.448721] horae[1267]: 2026-11-07T09:30:25.890928Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   16.450733] horae[1267]: 2026-11-07T09:30:25.890942Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   16.452671] horae[1267]: 2026-11-07T09:30:25.890956Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   16.454514] horae[1267]: 2026-11-07T09:30:25.890969Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   16.456344] horae[1267]: 2026-11-07T09:30:25.890982Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   16.458190] horae[1267]: 2026-11-07T09:30:25.890995Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   16.460079] horae[1267]: 2026-11-07T09:30:25.891017Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   16.461921] horae[1267]: 2026-11-07T09:30:25.891031Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   16.463747] horae[1267]: 2026-11-07T09:30:25.891044Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   16.465511] horae[1267]: 2026-11-07T09:30:25.943258Z  INFO horae: Listening on 127.0.0.1:3000
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 1.06 seconds)
server: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start
server # [   17.290459] dex[750]: time=2026-11-07T09:30:26.929Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=b576b4cf-d064-4d19-b385-ee39c1157275
server # [   17.316913] horae[1267]: 2026-11-07T09:30:26.956502Z  WARN call: horae::auth::oidc: OIDC login denied: no account, and the email's domain is not listed
server: (finished: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.09 seconds)
server: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt http://127.0.0.1:3000/auth/login
server: (finished: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt http://127.0.0.1:3000/auth/login, in 0.02 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0'
server # [   17.362652] sudo[1293]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'
server # [   17.383154] sudo[1293]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   17.396320] sudo[1293]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.05 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''
server # [   17.413385] sudo[1300]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''
server # [   17.433307] sudo[1300]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   17.449100] sudo[1300]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae Environment=HORAE_OIDC_CLIENT_SECRET=horae-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=Kilgore.Trout > /run/systemd/system/horae.service.d/omit-email-verified.conf
server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae Environment=HORAE_OIDC_CLIENT_SECRET=horae-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=Kilgore.Trout > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)
server: must succeed: systemctl daemon-reload && systemctl restart horae.service
server # [   17.472970] systemd[1]: Reload requested from client PID 1314 ('systemctl') (unit backdoor.service)...
server # [   17.475172] systemd[1]: Reloading...
server # [   17.678489] systemd[1]: Reloading finished in 203 ms.
server # [   17.717101] systemd[1]: Stopping Horae time tracking server...
server # [   17.727519] systemd[1]: horae.service: Deactivated successfully.
server # [   17.731116] systemd[1]: Stopped Horae time tracking server.
server # [   17.731986] systemd[1]: horae.service: Consumed 67ms CPU time over 1.606s wall clock time, 5.4M memory peak, 8.2K incoming IP traffic, 18.1K outgoing IP traffic.
server # [   17.739348] systemd[1]: Starting Horae time tracking server...
server # [   17.771997] horae[1352]: 2026-11-07T09:30:27.411715Z  INFO horae: Running migrations...
server # [   17.775338] horae[1352]: 2026-11-07T09:30:27.414800Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   17.785285] horae[1352]: 2026-11-07T09:30:27.425283Z  INFO horae: Migrations complete.
server # [   17.787400] postgres[1356]: [1356] LOG:  could not receive data from client: Connection reset by peer
server # [   17.794288] systemd[1]: Started Horae time tracking server.
server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.34 seconds)
server: waiting for TCP port 3000 on localhost
server # [   17.834268] horae[1359]: 2026-11-07T09:30:27.473725Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   17.842733] horae[1359]: 2026-11-07T09:30:27.482716Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   17.854216] horae[1359]: 2026-11-07T09:30:27.493463Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   17.863155] horae[1359]: 2026-11-07T09:30:27.503124Z  INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping
server # [   17.866058] horae[1359]: 2026-11-07T09:30:27.505271Z  INFO sqlx::postgres::notice: relation "session" already exists, skipping
server # [   17.869062] horae[1359]: 2026-11-07T09:30:27.508249Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   17.870882] horae[1359]: 2026-11-07T09:30:27.508281Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   17.872679] horae[1359]: 2026-11-07T09:30:27.508297Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   17.874469] horae[1359]: 2026-11-07T09:30:27.508311Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   17.876190] horae[1359]: 2026-11-07T09:30:27.508327Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   17.877906] horae[1359]: 2026-11-07T09:30:27.508340Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   17.879698] horae[1359]: 2026-11-07T09:30:27.508354Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   17.883097] horae[1359]: 2026-11-07T09:30:27.508369Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   17.884875] horae[1359]: 2026-11-07T09:30:27.508389Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   17.886645] horae[1359]: 2026-11-07T09:30:27.508403Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   17.888353] horae[1359]: 2026-11-07T09:30:27.508416Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   17.890627] horae[1359]: 2026-11-07T09:30:27.508429Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   17.893266] horae[1359]: 2026-11-07T09:30:27.508442Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   17.895271] horae[1359]: 2026-11-07T09:30:27.508455Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   17.897236] horae[1359]: 2026-11-07T09:30:27.508472Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   17.898931] horae[1359]: 2026-11-07T09:30:27.508494Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   17.900611] horae[1359]: 2026-11-07T09:30:27.508508Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   17.903121] horae[1359]: 2026-11-07T09:30:27.508521Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   17.904602] horae[1359]: 2026-11-07T09:30:27.508534Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   17.905983] horae[1359]: 2026-11-07T09:30:27.508546Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   17.907408] horae[1359]: 2026-11-07T09:30:27.508558Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   17.908788] horae[1359]: 2026-11-07T09:30:27.508571Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   17.910174] horae[1359]: 2026-11-07T09:30:27.508585Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   17.912198] horae[1359]: 2026-11-07T09:30:27.508598Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   17.913842] horae[1359]: 2026-11-07T09:30:27.508610Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   17.915290] horae[1359]: 2026-11-07T09:30:27.508623Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   17.917283] horae[1359]: 2026-11-07T09:30:27.508643Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   17.921989] horae[1359]: 2026-11-07T09:30:27.508656Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   17.924679] horae[1359]: 2026-11-07T09:30:27.508672Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   17.927269] horae[1359]: 2026-11-07T09:30:27.508701Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   17.929923] horae[1359]: 2026-11-07T09:30:27.508715Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   17.936318] horae[1359]: 2026-11-07T09:30:27.508729Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   17.939091] horae[1359]: 2026-11-07T09:30:27.508743Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   17.941928] horae[1359]: 2026-11-07T09:30:27.508756Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   17.945592] horae[1359]: 2026-11-07T09:30:27.508769Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   17.947803] horae[1359]: 2026-11-07T09:30:27.508781Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   17.951139] horae[1359]: 2026-11-07T09:30:27.508795Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   17.953417] horae[1359]: 2026-11-07T09:30:27.508808Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   17.957179] horae[1359]: 2026-11-07T09:30:27.508821Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   17.958982] horae[1359]: 2026-11-07T09:30:27.508834Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   17.960613] horae[1359]: 2026-11-07T09:30:27.508847Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   17.962244] horae[1359]: 2026-11-07T09:30:27.508862Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   17.963823] horae[1359]: 2026-11-07T09:30:27.508874Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   17.966099] horae[1359]: 2026-11-07T09:30:27.508892Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   17.968410] horae[1359]: 2026-11-07T09:30:27.508908Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   17.970081] horae[1359]: 2026-11-07T09:30:27.508921Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   17.971864] horae[1359]: 2026-11-07T09:30:27.508934Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   17.973478] horae[1359]: 2026-11-07T09:30:27.508948Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   17.975147] horae[1359]: 2026-11-07T09:30:27.508960Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   17.978134] horae[1359]: 2026-11-07T09:30:27.508977Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   17.979844] horae[1359]: 2026-11-07T09:30:27.508991Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   17.981592] horae[1359]: 2026-11-07T09:30:27.509004Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   17.983398] horae[1359]: 2026-11-07T09:30:27.509017Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   17.985204] horae[1359]: 2026-11-07T09:30:27.509030Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   17.986966] horae[1359]: 2026-11-07T09:30:27.509043Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   17.989565] horae[1359]: 2026-11-07T09:30:27.521834Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   17.991334] horae[1359]: 2026-11-07T09:30:27.521860Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   17.993127] horae[1359]: 2026-11-07T09:30:27.521918Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   17.994898] horae[1359]: 2026-11-07T09:30:27.521932Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   17.996670] horae[1359]: 2026-11-07T09:30:27.521945Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   17.998436] horae[1359]: 2026-11-07T09:30:27.521959Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   18.001059] horae[1359]: 2026-11-07T09:30:27.521972Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   18.002795] horae[1359]: 2026-11-07T09:30:27.521985Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   18.004512] horae[1359]: 2026-11-07T09:30:27.521998Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   18.006190] horae[1359]: 2026-11-07T09:30:27.522011Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   18.008827] horae[1359]: 2026-11-07T09:30:27.522023Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   18.010590] horae[1359]: 2026-11-07T09:30:27.522036Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   18.014341] horae[1359]: 2026-11-07T09:30:27.522049Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   18.016166] horae[1359]: 2026-11-07T09:30:27.522086Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   18.017998] horae[1359]: 2026-11-07T09:30:27.522098Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   18.019800] horae[1359]: 2026-11-07T09:30:27.522111Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   18.021597] horae[1359]: 2026-11-07T09:30:27.522124Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   18.023339] horae[1359]: 2026-11-07T09:30:27.522138Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   18.026171] horae[1359]: 2026-11-07T09:30:27.522150Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   18.027927] horae[1359]: 2026-11-07T09:30:27.522163Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   18.029614] horae[1359]: 2026-11-07T09:30:27.522177Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   18.031314] horae[1359]: 2026-11-07T09:30:27.522190Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   18.033068] horae[1359]: 2026-11-07T09:30:27.522202Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   18.034770] horae[1359]: 2026-11-07T09:30:27.522215Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   18.036507] horae[1359]: 2026-11-07T09:30:27.522228Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   18.038195] horae[1359]: 2026-11-07T09:30:27.522241Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   18.040023] horae[1359]: 2026-11-07T09:30:27.522255Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   18.041798] horae[1359]: 2026-11-07T09:30:27.522269Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   18.043567] horae[1359]: 2026-11-07T09:30:27.522283Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   18.045387] horae[1359]: 2026-11-07T09:30:27.522297Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   18.047269] horae[1359]: 2026-11-07T09:30:27.522312Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   18.049072] horae[1359]: 2026-11-07T09:30:27.522324Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   18.050819] horae[1359]: 2026-11-07T09:30:27.522337Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   18.052552] horae[1359]: 2026-11-07T09:30:27.522350Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   18.054207] horae[1359]: 2026-11-07T09:30:27.522364Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   18.056152] horae[1359]: 2026-11-07T09:30:27.522382Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   18.058043] horae[1359]: 2026-11-07T09:30:27.522396Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   18.059905] horae[1359]: 2026-11-07T09:30:27.522410Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   18.061705] horae[1359]: 2026-11-07T09:30:27.522423Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   18.063507] horae[1359]: 2026-11-07T09:30:27.522439Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   18.065280] horae[1359]: 2026-11-07T09:30:27.522452Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   18.067104] horae[1359]: 2026-11-07T09:30:27.522465Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   18.068863] horae[1359]: 2026-11-07T09:30:27.522477Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   18.070595] horae[1359]: 2026-11-07T09:30:27.522491Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   18.072325] horae[1359]: 2026-11-07T09:30:27.522504Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   18.074059] horae[1359]: 2026-11-07T09:30:27.522517Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   18.075763] horae[1359]: 2026-11-07T09:30:27.522533Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   18.077468] horae[1359]: 2026-11-07T09:30:27.522549Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   18.079141] horae[1359]: 2026-11-07T09:30:27.561275Z  INFO horae: Listening on 127.0.0.1:3000
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)
server: must succeed: curl -sS -c /tmp/jar7.txt -b /tmp/jar7.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null
server # [   18.871680] dex[750]: time=2026-11-07T09:30:28.510Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=7348ddbc-1dfd-4680-b76e-09719455b136
server # [   18.895564] horae[1359]: 2026-11-07T09:30:28.535179Z  INFO call: horae::auth::oidc: OIDC sign-in created an account user_id=01a1b558-5933-7170-94e3-efaa625c8493
server: (finished: must succeed: curl -sS -c /tmp/jar7.txt -b /tmp/jar7.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.06 seconds)
server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar7.txt http://127.0.0.1:3000/harvest/v2/time_entries
server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar7.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.07 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT org_role, active, cost_rate_cents IS NULL AND billable_rate_cents IS NULL, oidc_issuer, oidc_subject FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   18.993641] sudo[1383]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT org_role, active, cost_rate_cents IS NULL AND billable_rate_cents IS NULL, oidc_issuer, oidc_subject FROM users WHERE email = \'kilgore@kilgore.trout\''
server # [   19.014760] sudo[1383]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   19.028813] sudo[1383]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT org_role, active, cost_rate_cents IS NULL AND billable_rate_cents IS NULL, oidc_issuer, oidc_subject FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = false WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   19.046457] sudo[1390]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET active = false WHERE email = \'kilgore@kilgore.trout\''
server # [   19.065873] sudo[1390]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   19.081592] sudo[1390]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = false WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start
server # [   19.105347] dex[750]: time=2026-11-07T09:30:28.745Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=1f041b40-9b35-419d-b1b2-e359fd1ada13
server # [   19.117355] horae[1359]: 2026-11-07T09:30:28.757253Z  WARN call: horae::auth::oidc: OIDC login denied: account is deactivated
server: (finished: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.04 seconds)
server: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt http://127.0.0.1:3000/auth/login
server: (finished: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt http://127.0.0.1:3000/auth/login, in 0.02 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0'
server # [   19.160393] sudo[1403]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'
server # [   19.180490] sudo[1403]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   19.193971] sudo[1403]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.05 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''
server # [   19.210553] sudo[1410]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''
server # [   19.229773] sudo[1410]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   19.244853] sudo[1410]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT active FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   19.262485] sudo[1417]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT active FROM users WHERE email = \'kilgore@kilgore.trout\''
server # [   19.281740] sudo[1417]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   19.301059] sudo[1417]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT active FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET email = '"'"'kilgore-provisioned@kilgore.trout'"'"', oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"''
server # [   19.323944] sudo[1424]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET email = \'kilgore-provisioned@kilgore.trout\', oidc_issuer = NULL, oidc_subject = NULL WHERE email = \'kilgore@kilgore.trout\''
server # [   19.353805] sudo[1424]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   19.375610] sudo[1424]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET email = '"'"'kilgore-provisioned@kilgore.trout'"'"', oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.07 seconds)
server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=kilgore.trout > /run/systemd/system/horae.service.d/omit-email-verified.conf
server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=kilgore.trout > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)
server: must succeed: systemctl daemon-reload && systemctl restart horae.service
server # [   19.399805] systemd[1]: Reload requested from client PID 1438 ('systemctl') (unit backdoor.service)...
server # [   19.402067] systemd[1]: Reloading...
server # [   19.599586] systemd[1]: Reloading finished in 197 ms.
server # [   19.639145] systemd[1]: Stopping Horae time tracking server...
server # [   19.646988] systemd[1]: horae.service: Deactivated successfully.
server # [   19.651769] systemd[1]: Stopped Horae time tracking server.
server # [   19.652650] systemd[1]: horae.service: Consumed 76ms CPU time over 1.907s wall clock time, 5.9M memory peak, 16.3K incoming IP traffic, 30.9K outgoing IP traffic.
server # [   19.660442] systemd[1]: Starting Horae time tracking server...
server # [   19.691857] horae[1476]: 2026-11-07T09:30:29.331605Z  INFO horae: Running migrations...
server # [   19.694619] horae[1476]: 2026-11-07T09:30:29.334581Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   19.707138] horae[1476]: 2026-11-07T09:30:29.344723Z  INFO horae: Migrations complete.
server # [   19.708774] postgres[1481]: [1481] LOG:  could not send data to client: Broken pipe
server # [   19.709786] postgres[1481]: [1481] FATAL:  connection to client lost
server # [   19.714088] systemd[1]: Started Horae time tracking server.
server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.33 seconds)
server: waiting for TCP port 3000 on localhost
server # [   19.767249] horae[1483]: 2026-11-07T09:30:29.406798Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   19.780514] horae[1483]: 2026-11-07T09:30:29.420454Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   19.794281] horae[1483]: 2026-11-07T09:30:29.434243Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   19.797563] horae[1483]: 2026-11-07T09:30:29.437423Z  INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping
server # [   19.802070] horae[1483]: 2026-11-07T09:30:29.440651Z  INFO sqlx::postgres::notice: relation "session" already exists, skipping
server # [   19.803729] horae[1483]: 2026-11-07T09:30:29.440986Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   19.805484] horae[1483]: 2026-11-07T09:30:29.441010Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   19.807467] horae[1483]: 2026-11-07T09:30:29.441026Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   19.809192] horae[1483]: 2026-11-07T09:30:29.441041Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   19.810888] horae[1483]: 2026-11-07T09:30:29.441083Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   19.813723] horae[1483]: 2026-11-07T09:30:29.441096Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   19.815751] horae[1483]: 2026-11-07T09:30:29.441110Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   19.817505] horae[1483]: 2026-11-07T09:30:29.441125Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   19.819234] horae[1483]: 2026-11-07T09:30:29.441147Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   19.820963] horae[1483]: 2026-11-07T09:30:29.441162Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   19.822662] horae[1483]: 2026-11-07T09:30:29.441174Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   19.826891] horae[1483]: 2026-11-07T09:30:29.441188Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   19.828680] horae[1483]: 2026-11-07T09:30:29.441200Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   19.830491] horae[1483]: 2026-11-07T09:30:29.441213Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   19.832251] horae[1483]: 2026-11-07T09:30:29.441231Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   19.834111] horae[1483]: 2026-11-07T09:30:29.441252Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   19.835918] horae[1483]: 2026-11-07T09:30:29.441265Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   19.839878] horae[1483]: 2026-11-07T09:30:29.441278Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   19.841721] horae[1483]: 2026-11-07T09:30:29.441291Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   19.843526] horae[1483]: 2026-11-07T09:30:29.441303Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   19.845290] horae[1483]: 2026-11-07T09:30:29.441315Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   19.847087] horae[1483]: 2026-11-07T09:30:29.441328Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   19.848853] horae[1483]: 2026-11-07T09:30:29.441340Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   19.850613] horae[1483]: 2026-11-07T09:30:29.441353Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   19.852345] horae[1483]: 2026-11-07T09:30:29.441365Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   19.854660] horae[1483]: 2026-11-07T09:30:29.441380Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   19.856466] horae[1483]: 2026-11-07T09:30:29.441395Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   19.858148] horae[1483]: 2026-11-07T09:30:29.441408Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   19.859978] horae[1483]: 2026-11-07T09:30:29.441423Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   19.865415] horae[1483]: 2026-11-07T09:30:29.441452Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   19.867226] horae[1483]: 2026-11-07T09:30:29.441465Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   19.869059] horae[1483]: 2026-11-07T09:30:29.441478Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   19.870866] horae[1483]: 2026-11-07T09:30:29.441492Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   19.872631] horae[1483]: 2026-11-07T09:30:29.441505Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   19.874354] horae[1483]: 2026-11-07T09:30:29.441518Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   19.878090] horae[1483]: 2026-11-07T09:30:29.441531Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   19.879790] horae[1483]: 2026-11-07T09:30:29.441548Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   19.881475] horae[1483]: 2026-11-07T09:30:29.441564Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   19.883198] horae[1483]: 2026-11-07T09:30:29.441577Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   19.884843] horae[1483]: 2026-11-07T09:30:29.441590Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   19.886460] horae[1483]: 2026-11-07T09:30:29.441604Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   19.891611] horae[1483]: 2026-11-07T09:30:29.441618Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   19.893249] horae[1483]: 2026-11-07T09:30:29.441631Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   19.894848] horae[1483]: 2026-11-07T09:30:29.441642Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   19.896439] horae[1483]: 2026-11-07T09:30:29.441655Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   19.898032] horae[1483]: 2026-11-07T09:30:29.441667Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   19.899790] horae[1483]: 2026-11-07T09:30:29.441680Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   19.905113] horae[1483]: 2026-11-07T09:30:29.441693Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   19.906856] horae[1483]: 2026-11-07T09:30:29.441708Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   19.908653] horae[1483]: 2026-11-07T09:30:29.441721Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   19.910514] horae[1483]: 2026-11-07T09:30:29.441735Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   19.912252] horae[1483]: 2026-11-07T09:30:29.441748Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   19.914177] horae[1483]: 2026-11-07T09:30:29.441761Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   19.918965] horae[1483]: 2026-11-07T09:30:29.441773Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   19.920835] horae[1483]: 2026-11-07T09:30:29.441788Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   19.922621] horae[1483]: 2026-11-07T09:30:29.441801Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   19.924372] horae[1483]: 2026-11-07T09:30:29.441820Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   19.926143] horae[1483]: 2026-11-07T09:30:29.441858Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   19.927939] horae[1483]: 2026-11-07T09:30:29.441872Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   19.929838] horae[1483]: 2026-11-07T09:30:29.441890Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   19.931604] horae[1483]: 2026-11-07T09:30:29.441903Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   19.933328] horae[1483]: 2026-11-07T09:30:29.441916Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   19.936502] horae[1483]: 2026-11-07T09:30:29.441928Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   19.938210] horae[1483]: 2026-11-07T09:30:29.441941Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   19.939920] horae[1483]: 2026-11-07T09:30:29.441956Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   19.942891] horae[1483]: 2026-11-07T09:30:29.441968Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   19.944623] horae[1483]: 2026-11-07T09:30:29.441981Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   19.946382] horae[1483]: 2026-11-07T09:30:29.441993Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   19.948147] horae[1483]: 2026-11-07T09:30:29.442006Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   19.949919] horae[1483]: 2026-11-07T09:30:29.442018Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   19.951671] horae[1483]: 2026-11-07T09:30:29.442030Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   19.954931] horae[1483]: 2026-11-07T09:30:29.442042Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   19.956697] horae[1483]: 2026-11-07T09:30:29.465186Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   19.958443] horae[1483]: 2026-11-07T09:30:29.465212Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   19.960153] horae[1483]: 2026-11-07T09:30:29.465227Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   19.961930] horae[1483]: 2026-11-07T09:30:29.465241Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   19.963692] horae[1483]: 2026-11-07T09:30:29.465254Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   19.965422] horae[1483]: 2026-11-07T09:30:29.465267Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   19.968801] horae[1483]: 2026-11-07T09:30:29.465280Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   19.970498] horae[1483]: 2026-11-07T09:30:29.465292Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   19.972170] horae[1483]: 2026-11-07T09:30:29.465306Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   19.974027] horae[1483]: 2026-11-07T09:30:29.465320Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   19.976269] horae[1483]: 2026-11-07T09:30:29.465333Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   19.980179] horae[1483]: 2026-11-07T09:30:29.465346Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   19.982955] horae[1483]: 2026-11-07T09:30:29.465359Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   19.985374] horae[1483]: 2026-11-07T09:30:29.465373Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   19.987733] horae[1483]: 2026-11-07T09:30:29.465385Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   19.990756] horae[1483]: 2026-11-07T09:30:29.465397Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   19.993200] horae[1483]: 2026-11-07T09:30:29.465410Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   19.995391] horae[1483]: 2026-11-07T09:30:29.465424Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   19.997974] horae[1483]: 2026-11-07T09:30:29.465443Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   20.000656] horae[1483]: 2026-11-07T09:30:29.465455Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   20.003195] horae[1483]: 2026-11-07T09:30:29.465472Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   20.005727] horae[1483]: 2026-11-07T09:30:29.465488Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   20.008250] horae[1483]: 2026-11-07T09:30:29.465501Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   20.010158] horae[1483]: 2026-11-07T09:30:29.465514Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   20.011942] horae[1483]: 2026-11-07T09:30:29.465527Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   20.013793] horae[1483]: 2026-11-07T09:30:29.465539Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   20.015560] horae[1483]: 2026-11-07T09:30:29.465552Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   20.017279] horae[1483]: 2026-11-07T09:30:29.465564Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   20.018973] horae[1483]: 2026-11-07T09:30:29.465584Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   20.020707] horae[1483]: 2026-11-07T09:30:29.465597Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   20.022390] horae[1483]: 2026-11-07T09:30:29.465610Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   20.024049] horae[1483]: 2026-11-07T09:30:29.504128Z  INFO horae: Listening on 127.0.0.1:3000
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)
server: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start
server # [   20.815252] dex[750]: time=2026-11-07T09:30:30.454Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=00fd080c-8b42-4d97-9905-f45d8ceb1965
server # [   20.832670] horae[1483]: 2026-11-07T09:30:30.471829Z  WARN call: horae::auth::oidc: OIDC login denied: no account, and the email is not verified
server: (finished: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.07 seconds)
server: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt http://127.0.0.1:3000/auth/login
server: (finished: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt http://127.0.0.1:3000/auth/login, in 0.02 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0'
server # [   20.883707] sudo[1509]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'
server # [   20.904305] sudo[1509]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   20.919300] sudo[1509]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.06 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''
server # [   20.939626] sudo[1516]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''
server # [   20.960545] sudo[1516]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   20.977266] sudo[1516]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)
server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=kilgore.trout Environment=HORAE_OIDC_TRUST_UNVERIFIED_EMAIL=1 > /run/systemd/system/horae.service.d/omit-email-verified.conf
server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=kilgore.trout Environment=HORAE_OIDC_TRUST_UNVERIFIED_EMAIL=1 > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)
server: must succeed: systemctl daemon-reload && systemctl restart horae.service
server # [   21.004483] systemd[1]: Reload requested from client PID 1530 ('systemctl') (unit backdoor.service)...
server # [   21.007191] systemd[1]: Reloading...
server # [   21.196856] systemd[1]: Reloading finished in 190 ms.
server # [   21.227415] systemd[1]: Stopping Horae time tracking server...
server # [   21.232757] systemd[1]: horae.service: Deactivated successfully.
server # [   21.237823] systemd[1]: Stopped Horae time tracking server.
server # [   21.238588] systemd[1]: horae.service: Consumed 72ms CPU time over 1.572s wall clock time, 5.5M memory peak, 8.2K incoming IP traffic, 18.2K outgoing IP traffic.
server # [   21.245237] systemd[1]: Starting Horae time tracking server...
server # [   21.269606] horae[1568]: 2026-11-07T09:30:30.909386Z  INFO horae: Running migrations...
server # [   21.271797] horae[1568]: 2026-11-07T09:30:30.911814Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   21.280087] horae[1568]: 2026-11-07T09:30:30.919813Z  INFO horae: Migrations complete.
server # [   21.285077] systemd[1]: Started Horae time tracking server.
server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.30 seconds)
server: waiting for TCP port 3000 on localhost
server # [   21.314569] horae[1575]: 2026-11-07T09:30:30.954392Z  INFO horae: Starting Horae on 127.0.0.1:3000
server # [   21.321058] horae[1575]: 2026-11-07T09:30:30.961037Z  INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping
server # [   21.329624] horae[1575]: 2026-11-07T09:30:30.969015Z  INFO horae::plugin::registry: plugins directory does not exist: plugins
server # [   21.336421] horae[1575]: 2026-11-07T09:30:30.976399Z  INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping
server # [   21.339993] horae[1575]: 2026-11-07T09:30:30.978305Z  INFO sqlx::postgres::notice: relation "session" already exists, skipping
server # [   21.341269] horae[1575]: 2026-11-07T09:30:30.978530Z  INFO dioxus_server::server: Registering: POST /api/approve_submissions13590059188800848654
server # [   21.342713] horae[1575]: 2026-11-07T09:30:30.978549Z  INFO dioxus_server::server: Registering: POST /api/approve_submission13590059188800848654
server # [   21.344052] horae[1575]: 2026-11-07T09:30:30.978561Z  INFO dioxus_server::server: Registering: POST /api/reject_submission13590059188800848654
server # [   21.345407] horae[1575]: 2026-11-07T09:30:30.978571Z  INFO dioxus_server::server: Registering: POST /api/list_approvals13590059188800848654
server # [   21.346689] horae[1575]: 2026-11-07T09:30:30.978584Z  INFO dioxus_server::server: Registering: POST /api/submit_week13590059188800848654
server # [   21.347942] horae[1575]: 2026-11-07T09:30:30.978593Z  INFO dioxus_server::server: Registering: POST /api/load_task_catalog12256377810986817472
server # [   21.349509] horae[1575]: 2026-11-07T09:30:30.978604Z  INFO dioxus_server::server: Registering: POST /api/add_harvest_people13739675588719463496
server # [   21.350791] horae[1575]: 2026-11-07T09:30:30.978614Z  INFO dioxus_server::server: Registering: POST /api/set_user_active13739675588719463496
server # [   21.352075] horae[1575]: 2026-11-07T09:30:30.978631Z  INFO dioxus_server::server: Registering: POST /api/set_user_role13739675588719463496
server # [   21.353344] horae[1575]: 2026-11-07T09:30:30.978641Z  INFO dioxus_server::server: Registering: POST /api/list_people13739675588719463496
server # [   21.354608] horae[1575]: 2026-11-07T09:30:30.978650Z  INFO dioxus_server::server: Registering: POST /api/create_user13739675588719463496
server # [   21.355850] horae[1575]: 2026-11-07T09:30:30.978659Z  INFO dioxus_server::server: Registering: POST /api/list_users13739675588719463496
server # [   21.357142] horae[1575]: 2026-11-07T09:30:30.978669Z  INFO dioxus_server::server: Registering: POST /api/save_project_managers11474746963446121934
server # [   21.358474] horae[1575]: 2026-11-07T09:30:30.978678Z  INFO dioxus_server::server: Registering: POST /api/load_project_managers11474746963446121934
server # [   21.359782] horae[1575]: 2026-11-07T09:30:30.978689Z  INFO dioxus_server::server: Registering: POST /api/project_creation_selection1604479113674082919
server # [   21.361124] horae[1575]: 2026-11-07T09:30:30.978706Z  INFO dioxus_server::server: Registering: POST /api/project_creation_options1604479113674082919
server # [   21.363692] horae[1575]: 2026-11-07T09:30:30.978715Z  INFO dioxus_server::server: Registering: POST /api/project_creation_client1604479113674082919
server # [   21.368142] horae[1575]: 2026-11-07T09:30:30.978725Z  INFO dioxus_server::server: Registering: POST /api/project_editor_catalog1604479113674082919
server # [   21.370111] horae[1575]: 2026-11-07T09:30:30.978735Z  INFO dioxus_server::server: Registering: POST /api/finalize_project_draft1604479113674082919
server # [   21.372091] horae[1575]: 2026-11-07T09:30:30.978744Z  INFO dioxus_server::server: Registering: POST /api/discard_project_draft1604479113674082919
server # [   21.373999] horae[1575]: 2026-11-07T09:30:30.978753Z  INFO dioxus_server::server: Registering: POST /api/save_project_editor1604479113674082919
server # [   21.375780] horae[1575]: 2026-11-07T09:30:30.978762Z  INFO dioxus_server::server: Registering: POST /api/load_project_editor1604479113674082919
server # [   21.377589] horae[1575]: 2026-11-07T09:30:30.978772Z  INFO dioxus_server::server: Registering: POST /api/save_project_draft1604479113674082919
server # [   21.379857] horae[1575]: 2026-11-07T09:30:30.978781Z  INFO dioxus_server::server: Registering: POST /api/load_project_draft1604479113674082919
server # [   21.381195] horae[1575]: 2026-11-07T09:30:30.978790Z  INFO dioxus_server::server: Registering: POST /api/project_people1604479113674082919
server # [   21.382590] horae[1575]: 2026-11-07T09:30:30.978799Z  INFO dioxus_server::server: Registering: POST /api/get_project_detail_view7931148123265998511
server # [   21.383975] horae[1575]: 2026-11-07T09:30:30.978810Z  INFO dioxus_server::server: Registering: POST /api/list_plugins15265546378964521800
server # [   21.385287] horae[1575]: 2026-11-07T09:30:30.978820Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries16386063561583833955
server # [   21.386714] horae[1575]: 2026-11-07T09:30:30.978832Z  INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts16386063561583833955
server # [   21.391658] horae[1575]: 2026-11-07T09:30:30.978853Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking16386063561583833955
server # [   21.393055] horae[1575]: 2026-11-07T09:30:30.978864Z  INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command16386063561583833955
server # [   21.394417] horae[1575]: 2026-11-07T09:30:30.978874Z  INFO dioxus_server::server: Registering: POST /api/list_timesheet_people16386063561583833955
server # [   21.395717] horae[1575]: 2026-11-07T09:30:30.978889Z  INFO dioxus_server::server: Registering: POST /api/load_timesheet_page16386063561583833955
server # [   21.397040] horae[1575]: 2026-11-07T09:30:30.978899Z  INFO dioxus_server::server: Registering: POST /api/get_current_timer16386063561583833955
server # [   21.398300] horae[1575]: 2026-11-07T09:30:30.978908Z  INFO dioxus_server::server: Registering: POST /api/start_timer16386063561583833955
server # [   21.399607] horae[1575]: 2026-11-07T09:30:30.978917Z  INFO dioxus_server::server: Registering: POST /api/stop_timer16386063561583833955
server # [   21.403162] horae[1575]: 2026-11-07T09:30:30.978927Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview
server # [   21.404508] horae[1575]: 2026-11-07T09:30:30.978940Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary
server # [   21.405825] horae[1575]: 2026-11-07T09:30:30.978950Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/connection
server # [   21.407179] horae[1575]: 2026-11-07T09:30:30.978959Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel
server # [   21.408489] horae[1575]: 2026-11-07T09:30:30.978969Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}
server # [   21.409815] horae[1575]: 2026-11-07T09:30:30.978980Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/start
server # [   21.412888] horae[1575]: 2026-11-07T09:30:30.978989Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/retry
server # [   21.414151] horae[1575]: 2026-11-07T09:30:30.978998Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/history
server # [   21.415378] horae[1575]: 2026-11-07T09:30:30.979008Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client
server # [   21.416581] horae[1575]: 2026-11-07T09:30:30.979017Z  INFO dioxus_server::server: Registering: POST /api/harvest_change_account1479223498380199393
server # [   21.417939] horae[1575]: 2026-11-07T09:30:30.979026Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/status
server # [   21.419217] horae[1575]: 2026-11-07T09:30:30.979041Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove
server # [   21.420453] horae[1575]: 2026-11-07T09:30:30.979089Z  INFO dioxus_server::server: Registering: POST /api/harvest_connect_start1479223498380199393
server # [   21.421810] horae[1575]: 2026-11-07T09:30:30.979109Z  INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save
server # [   21.423935] horae[1575]: 2026-11-07T09:30:30.979126Z  INFO dioxus_server::server: Registering: POST /api/harvest_disconnect1479223498380199393
server # [   21.425376] horae[1575]: 2026-11-07T09:30:30.979141Z  INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress13963200375258473206
server # [   21.426810] horae[1575]: 2026-11-07T09:30:30.979155Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_projects13963200375258473206
server # [   21.428153] horae[1575]: 2026-11-07T09:30:30.979167Z  INFO dioxus_server::server: Registering: POST /api/get_project_overview13963200375258473206
server # [   21.429475] horae[1575]: 2026-11-07T09:30:30.979179Z  INFO dioxus_server::server: Registering: POST /api/set_projects_active13963200375258473206
server # [   21.430796] horae[1575]: 2026-11-07T09:30:30.979191Z  INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks13963200375258473206
server # [   21.432104] horae[1575]: 2026-11-07T09:30:30.979205Z  INFO dioxus_server::server: Registering: POST /api/set_project_active13963200375258473206
server # [   21.433414] horae[1575]: 2026-11-07T09:30:30.979240Z  INFO dioxus_server::server: Registering: POST /api/list_project_spend13963200375258473206
server # [   21.434704] horae[1575]: 2026-11-07T09:30:30.979250Z  INFO dioxus_server::server: Registering: POST /api/list_project_tags13963200375258473206
server # [   21.435979] horae[1575]: 2026-11-07T09:30:30.979260Z  INFO dioxus_server::server: Registering: POST /api/delete_assignment13963200375258473206
server # [   21.437295] horae[1575]: 2026-11-07T09:30:30.979270Z  INFO dioxus_server::server: Registering: POST /api/create_assignment13963200375258473206
server # [   21.438710] horae[1575]: 2026-11-07T09:30:30.979279Z  INFO dioxus_server::server: Registering: POST /api/set_task_active13963200375258473206
server # [   21.439984] horae[1575]: 2026-11-07T09:30:30.979288Z  INFO dioxus_server::server: Registering: POST /api/list_projects13963200375258473206
server # [   21.441234] horae[1575]: 2026-11-07T09:30:30.979298Z  INFO dioxus_server::server: Registering: POST /api/update_task13963200375258473206
server # [   21.442469] horae[1575]: 2026-11-07T09:30:30.979307Z  INFO dioxus_server::server: Registering: POST /api/create_task13963200375258473206
server # [   21.443734] horae[1575]: 2026-11-07T09:30:30.979317Z  INFO dioxus_server::server: Registering: POST /api/list_tasks13963200375258473206
server # [   21.444958] horae[1575]: 2026-11-07T09:30:30.979326Z  INFO dioxus_server::server: Registering: POST /api/update_client_profile10485135825777491571
server # [   21.446320] horae[1575]: 2026-11-07T09:30:30.979335Z  INFO dioxus_server::server: Registering: POST /api/create_project_client10485135825777491571
server # [   21.447799] horae[1575]: 2026-11-07T09:30:30.979344Z  INFO dioxus_server::server: Registering: POST /api/create_client_profile10485135825777491571
server # [   21.449206] horae[1575]: 2026-11-07T09:30:30.979354Z  INFO dioxus_server::server: Registering: POST /api/list_client_invoices10485135825777491571
server # [   21.450545] horae[1575]: 2026-11-07T09:30:30.979363Z  INFO dioxus_server::server: Registering: POST /api/get_client_details10485135825777491571
server # [   21.451858] horae[1575]: 2026-11-07T09:30:30.979372Z  INFO dioxus_server::server: Registering: POST /api/client_detail_view10485135825777491571
server # [   21.453135] horae[1575]: 2026-11-07T09:30:30.979385Z  INFO dioxus_server::server: Registering: POST /api/set_client_active10485135825777491571
server # [   21.454402] horae[1575]: 2026-11-07T09:30:30.979394Z  INFO dioxus_server::server: Registering: POST /api/client_overview10485135825777491571
server # [   21.455650] horae[1575]: 2026-11-07T09:30:30.979403Z  INFO dioxus_server::server: Registering: POST /api/list_clients10485135825777491571
server # [   21.456879] horae[1575]: 2026-11-07T09:30:30.979412Z  INFO dioxus_server::server: Registering: POST /api/update_org_branding13047172052397277026
server # [   21.458161] horae[1575]: 2026-11-07T09:30:30.979422Z  INFO dioxus_server::server: Registering: POST /api/get_org_branding13047172052397277026
server # [   21.459839] horae[1575]: 2026-11-07T09:30:30.979430Z  INFO dioxus_server::server: Registering: POST /api/get_week_start13047172052397277026
server # [   21.461659] horae[1575]: 2026-11-07T09:30:30.979439Z  INFO dioxus_server::server: Registering: POST /api/get_org_name13047172052397277026
server # [   21.463299] horae[1575]: 2026-11-07T09:30:30.979450Z  INFO dioxus_server::server: Registering: POST /api/get_me16144359270796124307
server # [   21.464825] horae[1575]: 2026-11-07T09:30:30.979460Z  INFO dioxus_server::server: Registering: POST /api/list_permission_audit16144359270796124307
server # [   21.466160] horae[1575]: 2026-11-07T09:30:30.979469Z  INFO dioxus_server::server: Registering: POST /api/get_permission_audit16144359270796124307
server # [   21.467465] horae[1575]: 2026-11-07T09:30:30.979479Z  INFO dioxus_server::server: Registering: POST /api/get_my_permissions16144359270796124307
server # [   21.468742] horae[1575]: 2026-11-07T09:30:30.979489Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries7690553569863186185
server # [   21.470174] horae[1575]: 2026-11-07T09:30:30.979498Z  INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups7690553569863186185
server # [   21.471545] horae[1575]: 2026-11-07T09:30:30.979508Z  INFO dioxus_server::server: Registering: POST /api/get_time_report_access7690553569863186185
server # [   21.472857] horae[1575]: 2026-11-07T09:30:30.979517Z  INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets7690553569863186185
server # [   21.474137] horae[1575]: 2026-11-07T09:30:30.979526Z  INFO dioxus_server::server: Registering: POST /api/report_detailed7690553569863186185
server # [   21.475378] horae[1575]: 2026-11-07T09:30:30.979536Z  INFO dioxus_server::server: Registering: POST /api/report_time7690553569863186185
server # [   21.476637] horae[1575]: 2026-11-07T09:30:30.979546Z  INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion11579710309346027303
server # [   21.478051] horae[1575]: 2026-11-07T09:30:30.979556Z  INFO dioxus_server::server: Registering: POST /api/preview_person_permissions11579710309346027303
server # [   21.479442] horae[1575]: 2026-11-07T09:30:30.979565Z  INFO dioxus_server::server: Registering: POST /api/save_permission_template11579710309346027303
server # [   21.480772] horae[1575]: 2026-11-07T09:30:30.979575Z  INFO dioxus_server::server: Registering: POST /api/list_permission_subjects11579710309346027303
server # [   21.483095] horae[1575]: 2026-11-07T09:30:30.979585Z  INFO dioxus_server::server: Registering: POST /api/save_person_permissions11579710309346027303
server # [   21.485707] horae[1575]: 2026-11-07T09:30:30.979597Z  INFO dioxus_server::server: Registering: POST /api/load_permission_editor11579710309346027303
server # [   21.487659] horae[1575]: 2026-11-07T09:30:30.979606Z  INFO dioxus_server::server: Registering: POST /api/update_invoice_status2064041990223864818
server # [   21.489446] horae[1575]: 2026-11-07T09:30:30.979616Z  INFO dioxus_server::server: Registering: POST /api/review_invoice_edit2064041990223864818
server # [   21.491199] horae[1575]: 2026-11-07T09:30:30.979626Z  INFO dioxus_server::server: Registering: POST /api/save_invoice_draft2064041990223864818
server # [   21.492935] horae[1575]: 2026-11-07T09:30:30.979635Z  INFO dioxus_server::server: Registering: POST /api/get_invoice_editor2064041990223864818
server # [   21.494722] horae[1575]: 2026-11-07T09:30:30.979644Z  INFO dioxus_server::server: Registering: POST /api/generate_invoice2064041990223864818
server # [   21.496422] horae[1575]: 2026-11-07T09:30:30.979653Z  INFO dioxus_server::server: Registering: POST /api/prepare_invoice2064041990223864818
server # [   21.498128] horae[1575]: 2026-11-07T09:30:30.979665Z  INFO dioxus_server::server: Registering: POST /api/list_invoices2064041990223864818
server # [   21.499951] horae[1575]: 2026-11-07T09:30:30.979673Z  INFO dioxus_server::server: Registering: POST /api/get_invoice2064041990223864818
server # [   21.501673] horae[1575]: 2026-11-07T09:30:31.029892Z  INFO horae: Listening on 127.0.0.1:3000
server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!
server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)
server: must succeed: curl -sS -c /tmp/jar10.txt -b /tmp/jar10.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null
server # [   22.393189] dex[750]: time=2026-11-07T09:30:32.032Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=410bb42f-fd0f-448e-9417-b95596075404
server # [   22.426751] horae[1575]: 2026-11-07T09:30:32.066261Z  INFO call: horae::auth::oidc: OIDC sign-in created an account user_id=01a1b558-66fb-7622-b6d7-49e1bdfe3794
server: (finished: must succeed: curl -sS -c /tmp/jar10.txt -b /tmp/jar10.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.15 seconds)
server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar10.txt http://127.0.0.1:3000/harvest/v2/time_entries
server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar10.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.05 seconds)
server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"' AND active AND org_role = '"'"'member'"'"''
server # [   22.542970] sudo[1598]:     root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE email = \'kilgore@kilgore.trout\' AND active AND org_role = \'member\''
server # [   22.564722] sudo[1598]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)
server # [   22.579450] sudo[1598]: pam_unix(sudo:session): session closed for user horae
server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"' AND active AND org_role = '"'"'member'"'"'', in 0.05 seconds)
server # [   22.598129] systemd[1]: Reload requested from client PID 1609 ('systemctl') (unit backdoor.service)...
server # [   22.601072] systemd[1]: Reloading...
server # [   22.819667] systemd[1]: Reloading finished in 218 ms.
server # [   22.861621] systemd[1]: Stopping Horae time tracking server...
server # [   22.869165] systemd[1]: horae.service: Deactivated successfully.
server # [   22.873964] systemd[1]: Stopped Horae time tracking server.
server # [   22.875293] systemd[1]: horae.service: Consumed 57ms CPU time over 1.623s wall clock time, 5.7M memory peak, 8.3K incoming IP traffic, 13K outgoing IP traffic.
server # [   22.882319] systemd[1]: Starting Horae time tracking server...
server # [   22.913572] horae[1647]: Error: HORAE_OIDC_AUTO_PROVISION_DOMAINS must be a comma-separated list of email domains (e.g. example.com,example.org); "*" is not a domain
server # [   22.917105] systemd[1]: horae.service: Control process exited, code=exited, status=1/FAILURE
server # [   22.918870] systemd[1]: horae.service: Failed with result 'exit-code'.
server # [   22.921228] systemd[1]: Failed to start Horae time tracking server.
server # Job for horae.service failed because the control process exited with error code.
server # See "systemctl status horae.service" and "journalctl -xeu horae.service" for details.
server: waiting for failure: systemctl is-active --quiet horae.service
server: (finished: waiting for failure: systemctl is-active --quiet horae.service, in 0.02 seconds)
server: must succeed: journalctl -u horae.service --no-pager -n 50
server: (finished: must succeed: journalctl -u horae.service --no-pager -n 50, in 0.01 seconds)
(finished: run the VM test script, in 30.36 seconds)
test script finished in 30.40s
cleanup
kill QemuMachine (pid 12)
server # qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/l9k0anq0z7zz81zcwy035jfwap9ga6rl-python3-3.13.13/bin/python3.13)
(finished: cleanup, in 0.14 seconds)