vm-test-run-horae-e2e-oidc
checks.x86_64-linux.e2e-oidc
· build #790
· raw
1bld1: building sf7ddzjm7xq9q8vn72yl0fa5jcswapcm-vm-test-run-horae-e2e-oidc.drv2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)5Test will time out and terminate in 3600 seconds6run the VM test script7additionally exposed symbols:8 server,9 vlan1,10 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_ssh11server: starting vm12server # Disk image does not exist, creating the virtualisation disk image...13server: QEMU running (pid 12)14server # Formatting '/build/vm-state-server/tmp.pfszA1iIZM', fmt=raw size=107374182415server # mke2fs 1.47.4 (6-Mar-2025)16server # Discarding device blocks: 0/262144 done17server # Creating filesystem with 262144 4k blocks and 65536 inodes18server # Filesystem UUID: 5565c9e2-47f9-4acc-a6c6-6269a84de8e019server # Superblock backups stored on blocks:20server # 32768, 98304, 163840, 22937621server # 22server # Allocating group tables: 0/8 done23server # Writing inode tables: 0/8 done24server # Creating journal (8192 blocks): done25server # Writing superblocks and filesystem accounting information: 0/8 done26server # 27server # Virtualisation disk image created.28server # Creating Nix store image...29server # Created Nix store image.30server # SeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)31server # 32server # 33server # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1830+3EF31830 CA0034server # Press Ctrl-B to configure iPXE (PCI 00:03.0)...35server # 36server # 37server # 38server # 39server # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1830 3EF31830 CB0040server # Press Ctrl-B to configure iPXE (PCI 00:09.0)...41server # 42server # 43server # Booting from ROM...44server # Probing EDD (edd=off to disable)... ok45server # [ 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 202646server # [ 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/xh8v1463jmwk3rvaiz3wlmx6i8n3vgj3-nixos-system-server-test/init regInfo=/nix/store/40mz0awy86w2n1p5khwb1ra5094cm76a-closure-info/registration console=ttyS0,115200n8 console=tty047server # [ 0.000000] x86/split lock detection: #DB: warning on user-space bus_locks48server # [ 0.000000] BIOS-provided physical RAM map:49server # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable50server # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved51server # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved52server # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffd7fff] usable53server # [ 0.000000] BIOS-e820: [mem 0x000000003ffd8000-0x000000003fffffff] reserved54server # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved55server # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved56server # [ 0.000000] NX (Execute Disable) protection: active57server # [ 0.000000] APIC: Static calls initialized58server # [ 0.000000] SMBIOS 2.8 present.59server # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/201460server # [ 0.000000] DMI: Memory slots populated: 1/161server # [ 0.000000] Hypervisor detected: KVM62server # [ 0.000000] last_pfn = 0x3ffd8 max_arch_pfn = 0x1000000000063server # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d0064server # [ 0.000001] kvm-clock: using sched offset of 395738761 cycles65server # [ 0.000003] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns66server # [ 0.000007] tsc: Detected 2100.000 MHz processor67server # [ 0.001024] last_pfn = 0x3ffd8 max_arch_pfn = 0x1000000000068server # [ 0.001059] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs69server # [ 0.001062] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT70server # [ 0.009658] found SMP MP-table at [mem 0x000f5470-0x000f547f]71server # [ 0.009677] Using GB pages for direct mapping72server # [ 0.009810] RAMDISK: [mem 0x3e4dd000-0x3ffcffff]73server # [ 0.009817] ACPI: Early table checksum verification disabled74server # [ 0.009821] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )75server # [ 0.009826] ACPI: RSDT 0x000000003FFE23CC 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)76server # [ 0.009833] ACPI: FACP 0x000000003FFE2280 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)77server # [ 0.009842] ACPI: DSDT 0x000000003FFE0040 002240 (v01 BOCHS BXPC 00000001 BXPC 00000001)78server # [ 0.009846] ACPI: FACS 0x000000003FFE0000 00004079server # [ 0.009850] ACPI: APIC 0x000000003FFE22F4 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)80server # [ 0.009853] ACPI: HPET 0x000000003FFE236C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)81server # [ 0.009857] ACPI: WAET 0x000000003FFE23A4 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)82server # [ 0.009859] ACPI: Reserving FACP table memory at [mem 0x3ffe2280-0x3ffe22f3]83server # [ 0.009861] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe227f]84server # [ 0.009861] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]85server # [ 0.009862] ACPI: Reserving APIC table memory at [mem 0x3ffe22f4-0x3ffe236b]86server # [ 0.009863] ACPI: Reserving HPET table memory at [mem 0x3ffe236c-0x3ffe23a3]87server # [ 0.009863] ACPI: Reserving WAET table memory at [mem 0x3ffe23a4-0x3ffe23cb]88server # [ 0.010144] No NUMA configuration found89server # [ 0.010145] Faking a node at [mem 0x0000000000000000-0x000000003ffd7fff]90server # [ 0.010148] NODE_DATA(0) allocated [mem 0x3ffd2780-0x3ffd7cff]91server # [ 0.011603] Zone ranges:92server # [ 0.011604] DMA [mem 0x0000000000001000-0x0000000000ffffff]93server # [ 0.011606] DMA32 [mem 0x0000000001000000-0x000000003ffd7fff]94server # [ 0.011608] Normal empty95server # [ 0.011609] Device empty96server # [ 0.011609] Movable zone start for each node97server # [ 0.011610] Early memory node ranges98server # [ 0.011611] node 0: [mem 0x0000000000001000-0x000000000009efff]99server # [ 0.011612] node 0: [mem 0x0000000000100000-0x000000003ffd7fff]100server # [ 0.011613] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffd7fff]101server # [ 0.011658] On node 0, zone DMA: 1 pages in unavailable ranges102server # [ 0.011831] On node 0, zone DMA: 97 pages in unavailable ranges103server # [ 0.023481] On node 0, zone DMA32: 40 pages in unavailable ranges104server # [ 0.024019] ACPI: PM-Timer IO Port: 0x608105server # [ 0.024038] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])106server # [ 0.024077] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23107server # [ 0.024081] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)108server # [ 0.024083] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)109server # [ 0.024084] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)110server # [ 0.024085] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)111server # [ 0.024086] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)112server # [ 0.024091] ACPI: Using ACPI (MADT) for SMP configuration information113server # [ 0.024092] ACPI: HPET id: 0x8086a201 base: 0xfed00000114server # [ 0.024097] TSC deadline timer available115server # [ 0.024101] CPU topo: Max. logical packages: 1116server # [ 0.024103] CPU topo: Max. logical dies: 1117server # [ 0.024103] CPU topo: Max. dies per package: 1118server # [ 0.024106] CPU topo: Max. threads per core: 1119server # [ 0.024107] CPU topo: Num. cores per package: 1120server # [ 0.024108] CPU topo: Num. threads per package: 1121server # [ 0.024108] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs122server # [ 0.024131] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()123server # [ 0.024162] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]124server # [ 0.024164] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]125server # [ 0.024166] [mem 0x40000000-0xfeffbfff] available for PCI devices126server # [ 0.024167] Booting paravirtualized kernel on KVM127server # [ 0.024171] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns128server # [ 0.030239] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1129server # [ 0.031729] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u2097152130server # [ 0.031782] kvm-guest: PV spinlocks disabled, single CPU131server # [ 0.031785] 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/xh8v1463jmwk3rvaiz3wlmx6i8n3vgj3-nixos-system-server-test/init regInfo=/nix/store/40mz0awy86w2n1p5khwb1ra5094cm76a-closure-info/registration console=ttyS0,115200n8 console=tty0132server # [ 0.031902] Unknown kernel command line parameters "regInfo=/nix/store/40mz0awy86w2n1p5khwb1ra5094cm76a-closure-info/registration", will be passed to user space.133server # [ 0.031913] random: crng init done134server # [ 0.031914] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes135server # [ 0.031958] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)136server # [ 0.032318] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)137server # [ 0.032373] Fallback order for Node 0: 0138server # [ 0.032377] Built 1 zonelists, mobility grouping on. Total pages: 262006139server # [ 0.032378] Policy zone: DMA32140server # [ 0.034120] mem auto-init: stack:all(zero), heap alloc:on, heap free:off141server # [ 0.037476] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1142server # [ 0.039639] allocated 2097152 bytes of page_ext143server # [ 0.050000] ftrace: allocating 48598 entries in 192 pages144server # [ 0.050003] ftrace: allocated 192 pages with 2 groups145server # [ 0.050741] Dynamic Preempt: lazy146server # [ 0.050896] rcu: Preemptible hierarchical RCU implementation.147server # [ 0.050897] rcu: RCU event tracing is enabled.148server # [ 0.050898] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.149server # [ 0.050899] Trampoline variant of Tasks RCU enabled.150server # [ 0.050900] Rude variant of Tasks RCU enabled.151server # [ 0.050900] Tracing variant of Tasks RCU enabled.152server # [ 0.050901] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.153server # [ 0.050901] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1154server # [ 0.050922] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.155server # [ 0.050924] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.156server # [ 0.050925] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.157server # [ 0.056022] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16158server # [ 0.056306] rcu: srcu_init: Setting srcu_struct sizes based on contention.159server # [ 0.056452] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)160server # [ 0.060829] Console: colour VGA+ 80x25161server # [ 0.060833] printk: legacy console [tty0] enabled162server # [ 0.090970] printk: legacy console [ttyS0] enabled163server # [ 0.175145] ACPI: Core revision 20250807164server # [ 0.175948] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns165server # [ 0.177378] APIC: Switch to symmetric I/O mode setup166server # [ 0.178308] x2apic enabled167server # [ 0.179034] APIC: Switched APIC routing to: physical x2apic168server # [ 0.180820] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1169server # [ 0.181720] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1e4530a99b6, max_idle_ns: 440795257976 ns170server # [ 0.183269] Calibrating delay loop (skipped) preset value.. 4200.00 BogoMIPS (lpj=2100000)171server # [ 0.185406] x86/cpu: User Mode Instruction Prevention (UMIP) activated172server # [ 0.186377] CET detected: Indirect Branch Tracking enabled173server # [ 0.187266] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0174server # [ 0.188039] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0175server # [ 0.188895] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto176server # [ 0.190265] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl177server # [ 0.191266] Spectre V2 : Mitigation: Enhanced / Automatic IBRS178server # [ 0.192265] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization179server # [ 0.193267] Spectre V2 : Spectre v2 / PBRSB-eIBRS: Retire a single CALL on VMEXIT180server # [ 0.195069] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier181server # [ 0.196305] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'182server # [ 0.197265] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'183server # [ 0.198265] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'184server # [ 0.199892] x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask'185server # [ 0.200899] x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256'186server # [ 0.201892] x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256'187server # [ 0.202265] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'188server # [ 0.203265] x86/fpu: Supporting XSAVE feature 0x800: 'Control-flow User registers'189server # [ 0.204265] x86/fpu: Supporting XSAVE feature 0x1000: 'Control-flow Kernel registers (KVM only)'190server # [ 0.206125] x86/fpu: Supporting XSAVE feature 0x20000: 'AMX Tile config'191server # [ 0.206926] x86/fpu: Supporting XSAVE feature 0x40000: 'AMX Tile data'192server # [ 0.207912] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256193server # [ 0.208265] x86/fpu: xstate_offset[5]: 832, xstate_sizes[5]: 64194server # [ 0.209265] x86/fpu: xstate_offset[6]: 896, xstate_sizes[6]: 512195server # [ 0.210265] x86/fpu: xstate_offset[7]: 1408, xstate_sizes[7]: 1024196server # [ 0.211058] x86/fpu: xstate_offset[9]: 2432, xstate_sizes[9]: 8197server # [ 0.212268] x86/fpu: xstate_offset[11]: 2440, xstate_sizes[11]: 16198server # [ 0.213160] x86/fpu: xstate_offset[12]: 2456, xstate_sizes[12]: 24199server # [ 0.213871] x86/fpu: xstate_offset[17]: 2496, xstate_sizes[17]: 64200server # [ 0.214880] x86/fpu: xstate_offset[18]: 2560, xstate_sizes[18]: 8192201server # [ 0.215267] x86/fpu: Enabled xstate features 0x61ae7, context size is 10752 bytes, using 'compacted' format.202server # [ 0.248663] Freeing SMP alternatives memory: 44K203server # [ 0.249273] pid_max: default: 32768 minimum: 301204server # [ 0.250384] LSM: initializing lsm=capability,landlock,yama,bpf,ima205server # [ 0.251393] landlock: Up and running.206server # [ 0.252797] Yama: becoming mindful.207server # [ 0.253508] LSM support for eBPF active208server # [ 0.254442] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)209server # [ 0.256291] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)210server # [ 0.258658] smpboot: CPU0: Intel(R) Xeon(R) Gold 5412U (family: 0x6, model: 0x8f, stepping: 0x8)211server # [ 0.259874] Performance Events: PEBS fmt0-, Sapphire Rapids events, full-width counters, Intel PMU driver.212server # [ 0.261274] ... version: 2213server # [ 0.262160] ... bit width: 48214server # [ 0.262858] ... generic counters: 8215server # [ 0.263268] ... generic bitmap: 00000000000000ff216server # [ 0.264256] ... fixed-purpose counters: 3217server # [ 0.264792] ... fixed-purpose bitmap: 0000000000000007218server # [ 0.265268] ... value mask: 0000ffffffffffff219server # [ 0.266267] ... max period: 00007fffffffffff220server # [ 0.267267] ... global_ctrl mask: 00000007000000ff221server # [ 0.268457] signal: max sigframe size: 11952222server # [ 0.269176] rcu: Hierarchical SRCU implementation.223server # [ 0.269731] rcu: Max phase no-delay instances is 400.224server # [ 0.270869] smp: Bringing up secondary CPUs ...225server # [ 0.271281] smp: Brought up 1 node, 1 CPU226server # [ 0.271895] smpboot: Total of 1 processors activated (4200.00 BogoMIPS)227server # [ 0.272436] Memory: 942512K/1048024K available (17159K kernel code, 2721K rwdata, 13560K rodata, 3636K init, 3020K bss, 98120K reserved, 0K cma-reserved)228server # [ 0.273480] devtmpfs: initialized229server # [ 0.274131] x86/mm: Memory block size: 128MB230server # [ 0.275253] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns231server # [ 0.276255] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)232server # [ 0.276986] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).233server # [ 0.278177] pinctrl core: initialized pinctrl subsystem234server # [ 0.279031] PM: RTC time: 19:26:52, date: 2026-11-06235server # [ 0.281121] NET: Registered PF_NETLINK/PF_ROUTE protocol family236server # [ 0.282081] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations237server # [ 0.282982] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations238server # [ 0.284185] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations239server # [ 0.285193] audit: initializing netlink subsys (disabled)240server # [ 0.286063] thermal_sys: Registered thermal governor 'fair_share'241server # [ 0.286065] thermal_sys: Registered thermal governor 'bang_bang'242server # [ 0.286978] audit: type=2000 audit(1793993212.722:1): state=initialized audit_enabled=0 res=1243server # [ 0.289097] thermal_sys: Registered thermal governor 'step_wise'244server # [ 0.289098] thermal_sys: Registered thermal governor 'user_space'245server # [ 0.289851] thermal_sys: Registered thermal governor 'power_allocator'246server # [ 0.290297] cpuidle: using governor menu247server # [ 0.291773] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5248server # [ 0.292453] PCI: Using configuration type 1 for base access249server # [ 0.293317] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.250server # [ 0.300365] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages251server # [ 0.301266] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page252server # [ 0.302150] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages253server # [ 0.307272] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page254server # [ 0.312907] ACPI: Added _OSI(Module Device)255server # [ 0.313267] ACPI: Added _OSI(Processor Device)256server # [ 0.313887] ACPI: Added _OSI(Processor Aggregator Device)257server # [ 0.315113] ACPI: 1 ACPI AML tables successfully acquired and loaded258server # [ 0.324541] ACPI: Interpreter enabled259server # [ 0.325087] ACPI: PM: (supports S0 S3 S4 S5)260server # [ 0.325713] ACPI: Using IOAPIC for interrupt routing261server # [ 0.330288] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug262server # [ 0.331266] PCI: Using E820 reservations for host bridge windows263server # [ 0.332145] ACPI: Enabled 2 GPEs in block 00 to 0F264server # [ 0.339356] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])265server # [ 0.340261] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]266server # [ 0.341117] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI]267server # [ 0.344283] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended configuration space under this bridge268server # [ 0.345466] acpiphp: Slot [3] registered269server # [ 0.346047] acpiphp: Slot [4] registered270server # [ 0.348314] acpiphp: Slot [5] registered271server # [ 0.348976] acpiphp: Slot [6] registered272server # [ 0.349279] acpiphp: Slot [7] registered273server # [ 0.349880] acpiphp: Slot [8] registered274server # [ 0.352281] acpiphp: Slot [9] registered275server # [ 0.352845] acpiphp: Slot [10] registered276server # [ 0.353280] acpiphp: Slot [11] registered277server # [ 0.353852] acpiphp: Slot [12] registered278server # [ 0.356280] acpiphp: Slot [13] registered279server # [ 0.356868] acpiphp: Slot [14] registered280server # [ 0.357278] acpiphp: Slot [15] registered281server # [ 0.357871] acpiphp: Slot [16] registered282server # [ 0.360284] acpiphp: Slot [17] registered283server # [ 0.360873] acpiphp: Slot [18] registered284server # [ 0.361284] acpiphp: Slot [19] registered285server # [ 0.361891] acpiphp: Slot [20] registered286server # [ 0.362654] acpiphp: Slot [21] registered287server # [ 0.363240] acpiphp: Slot [22] registered288server # [ 0.363672] acpiphp: Slot [23] registered289server # [ 0.364251] acpiphp: Slot [24] registered290server # [ 0.364690] acpiphp: Slot [25] registered291server # [ 0.365260] acpiphp: Slot [26] registered292server # [ 0.365685] acpiphp: Slot [27] registered293server # [ 0.366255] acpiphp: Slot [28] registered294server # [ 0.366705] acpiphp: Slot [29] registered295server # [ 0.367271] acpiphp: Slot [30] registered296server # [ 0.367878] acpiphp: Slot [31] registered297server # [ 0.368291] PCI host bridge to bus 0000:00298server # [ 0.368863] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]299server # [ 0.369266] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]300server # [ 0.370157] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]301server # [ 0.370982] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]302server # [ 0.371266] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]303server # [ 0.372266] pci_bus 0000:00: root bus resource [bus 00-ff]304server # [ 0.373183] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint305server # [ 0.374489] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint306server # [ 0.375665] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint307server # [ 0.377296] pci 0000:00:01.1: BAR 4 [io 0xc220-0xc22f]308server # [ 0.378041] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk309server # [ 0.379034] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk310server # [ 0.379859] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk311server # [ 0.380266] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk312server # [ 0.381317] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint313server # [ 0.383204] pci 0000:00:01.2: BAR 4 [io 0xc140-0xc15f]314server # [ 0.384327] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint315server # [ 0.385560] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI316server # [ 0.386272] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB317server # [ 0.387388] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint318server # [ 0.390364] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]319server # [ 0.391287] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]320server # [ 0.392141] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]321server # [ 0.393059] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]322server # [ 0.395051] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint323server # [ 0.397275] pci 0000:00:03.0: BAR 0 [io 0xc160-0xc17f]324server # [ 0.397998] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]325server # [ 0.398290] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]326server # [ 0.399246] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]327server # [ 0.401000] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint328server # [ 0.403285] pci 0000:00:04.0: BAR 0 [io 0xc180-0xc19f]329server # [ 0.404054] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]330server # [ 0.404948] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]331server # [ 0.407034] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint332server # [ 0.409116] pci 0000:00:05.0: BAR 0 [io 0xc1a0-0xc1bf]333server # [ 0.409798] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]334server # [ 0.410293] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]335server # [ 0.412122] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint336server # [ 0.414291] pci 0000:00:06.0: BAR 0 [io 0xc1c0-0xc1df]337server # [ 0.415000] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]338server # [ 0.415292] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]339server # [ 0.417192] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint340server # [ 0.419066] pci 0000:00:07.0: BAR 0 [io 0xc000-0xc07f]341server # [ 0.419787] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]342server # [ 0.420289] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]343server # [ 0.422176] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint344server # [ 0.424275] pci 0000:00:08.0: BAR 0 [io 0xc080-0xc0ff]345server # [ 0.424981] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]346server # [ 0.425294] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]347server # [ 0.427240] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint348server # [ 0.429188] pci 0000:00:09.0: BAR 0 [io 0xc1e0-0xc1ff]349server # [ 0.429791] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]350server # [ 0.430288] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]351server # [ 0.431173] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]352server # [ 0.433194] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint353server # [ 0.434967] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]354server # [ 0.435293] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]355server # [ 0.437144] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint356server # [ 0.439054] pci 0000:00:0b.0: BAR 0 [io 0xc100-0xc13f]357server # [ 0.439273] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]358server # [ 0.440289] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]359server # [ 0.442167] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint360server # [ 0.443999] pci 0000:00:0c.0: BAR 0 [io 0xc200-0xc21f]361server # [ 0.444273] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]362server # [ 0.445082] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]363server # [ 0.449325] ACPI: PCI: Interrupt link LNKA configured for IRQ 10364server # [ 0.450221] ACPI: PCI: Interrupt link LNKB configured for IRQ 10365server # [ 0.450929] ACPI: PCI: Interrupt link LNKC configured for IRQ 11366server # [ 0.451344] ACPI: PCI: Interrupt link LNKD configured for IRQ 11367server # [ 0.452208] ACPI: PCI: Interrupt link LNKS configured for IRQ 9368server # [ 0.453749] iommu: Default domain type: Translated369server # [ 0.454277] iommu: DMA domain TLB invalidation policy: lazy mode370server # [ 0.455338] ACPI: bus type USB registered371server # [ 0.455951] usbcore: registered new interface driver usbfs372server # [ 0.456279] usbcore: registered new interface driver hub373server # [ 0.456984] usbcore: registered new device driver usb374server # [ 0.458166] NetLabel: Initializing375server # [ 0.458621] NetLabel: domain hash size = 128376server # [ 0.459234] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO377server # [ 0.459870] NetLabel: unlabeled traffic allowed by default378server # [ 0.460274] PCI: Using ACPI for IRQ routing379server # [ 0.461209] pci 0000:00:02.0: vgaarb: setting as boot VGA device380server # [ 0.461264] pci 0000:00:02.0: vgaarb: bridge control possible381server # [ 0.461264] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none382server # [ 0.461267] vgaarb: loaded383server # [ 0.461837] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0384server # [ 0.462266] hpet0: 3 comparators, 64-bit 100.000000 MHz counter385server # [ 0.465318] clocksource: Switched to clocksource kvm-clock386server # [ 0.467931] VFS: Disk quotas dquot_6.6.0387server # [ 0.468516] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)388server # [ 0.469621] pnp: PnP ACPI init389server # [ 0.470446] pnp: PnP ACPI: found 6 devices390server # [ 0.476869] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns391server # [ 0.478055] clocksource: Switched to clocksource acpi_pm392server # [ 0.478854] NET: Registered PF_INET protocol family393server # [ 0.479657] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)394server # [ 0.494421] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)395server # [ 0.495700] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)396server # [ 0.496808] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)397server # [ 0.497907] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)398server # [ 0.498923] TCP: Hash tables configured (established 8192 bind 8192)399server # [ 0.499833] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)400server # [ 0.500859] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)401server # [ 0.501766] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)402server # [ 0.502750] NET: Registered PF_UNIX/PF_LOCAL protocol family403server # [ 0.503519] NET: Registered PF_XDP protocol family404server # [ 0.504211] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]405server # [ 0.505475] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]406server # [ 0.506763] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]407server # [ 0.508151] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]408server # [ 0.509506] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]409server # [ 0.511033] pci 0000:00:01.0: PIIX3: Enabling Passive Release410server # [ 0.512257] pci 0000:00:00.0: Limiting direct PCI/PCI transfers411server # [ 0.514712] ACPI: \_SB_.LNKD: Enabled at IRQ 11412server # [ 0.517289] PCI: CLS 0 bytes, default 64413server # [ 0.518323] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e4530a99b6, max_idle_ns: 440795257976 ns414server # [ 0.520600] Trying to unpack rootfs image as initramfs...415server # [ 0.573346] Initialise system trusted keyrings416server # [ 0.576050] workingset: timestamp_bits=40 max_order=18 bucket_order=0417server # [ 0.604640] Key type asymmetric registered418server # [ 0.605511] Asymmetric key parser 'x509' registered419server # [ 0.609049] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)420server # [ 0.610998] io scheduler mq-deadline registered421server # [ 0.611841] io scheduler kyber registered422server # [ 0.615603] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled423server # [ 0.619108] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A424server # [ 0.624480] Linux agpgart interface v0.103425server # [ 0.625428] ACPI: bus type drm_connector registered426server # [ 0.628491] usbcore: registered new interface driver usbserial_generic427server # [ 0.629769] usbserial: USB Serial support registered for generic428server # [ 0.633015] intel_pstate: CPU model not supported429server # [ 0.634129] drop_monitor: Initializing network drop monitor service430server # [ 0.637193] NET: Registered PF_INET6 protocol family431server # [ 0.641617] Segment Routing with IPv6432server # [ 0.642423] In-situ OAM (IOAM) with IPv6433server # [ 0.645368] IPI shorthand broadcast: enabled434server # [ 0.653397] sched_clock: Marking stable (530021864, 122950522)->(699760429, -46788043)435server # [ 0.657128] registered taskstats version 1436server # [ 0.658183] Loading compiled-in X.509 certificates437server # [ 0.675000] Demotion targets for Node 0: null438server # [ 0.676134] Key type .fscrypt registered439server # [ 0.676905] Key type fscrypt-provisioning registered440server # [ 0.680141] ima: No TPM chip found, activating TPM-bypass!441server # [ 0.681242] ima: Allocated hash algorithm: sha1442server # [ 0.686038] ima: No architecture policies found443server # [ 0.687161] PM: Magic number: 2:871:444444server # [ 0.691297] RAS: Correctable Errors collector initialized.445server # [ 0.703771] clk: Disabling unused clocks446server # [ 0.706021] PM: genpd: Disabling unused power domains447server # [ 0.892219] Freeing initrd memory: 27596K448server # [ 0.908365] Freeing unused decrypted memory: 2028K449server # [ 0.910640] Freeing unused kernel image (initmem) memory: 3636K450server # [ 0.911567] Write protecting the kernel read-only data: 32768k451server # [ 0.913183] Freeing unused kernel image (text/rodata gap) memory: 1272K452server # [ 0.914546] Freeing unused kernel image (rodata/data gap) memory: 776K453server # [ 0.924555] x86/mm: Checked W+X mappings: passed, no W+X pages found.454server # [ 0.925494] Run /init as init process455server # [ 0.934597] systemd[1]: Inserted module 'autofs4'456server # [ 0.951389] fuse: init (API version 7.45)457server # [ 0.957845] ACPI: \_SB_.LNKC: Enabled at IRQ 10458server # [ 0.962378] ACPI: \_SB_.LNKA: Enabled at IRQ 10459server # [ 0.964583] ACPI: \_SB_.LNKB: Enabled at IRQ 11460server # [ 0.986332] systemd[1]: Successfully made /usr/ read-only.461server # [ 1.322204] 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)462server # [ 1.326565] systemd[1]: Detected virtualization kvm.463server # [ 1.327299] systemd[1]: Detected architecture x86-64.464server # [ 1.328059] systemd[1]: Running in initrd.465server # [ 1.329167] systemd[1]: Initializing machine ID from random generator.466server # [ 1.330209] systemd[1]: Hostname set to <server>.467server # [ 1.388571] systemd[1]: Queued start job for default target Initrd Default Target.468server # [ 1.392924] systemd[1]: Created slice Slice /system/modprobe.469server # [ 1.394583] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.470server # [ 1.396099] systemd[1]: Expecting device /dev/disk/by-label/nix-store...471server # [ 1.397257] systemd[1]: Expecting device /dev/disk/by-label/nixos...472server # [ 1.398258] systemd[1]: Reached target Path Units.473server # [ 1.399126] systemd[1]: Reached target Slice Units.474server # [ 1.400212] systemd[1]: Reached target Swaps.475server # [ 1.401270] systemd[1]: Reached target Timer Units.476server # [ 1.402255] systemd[1]: Listening on D-Bus System Message Bus Socket.477server # [ 1.403411] systemd[1]: Listening on Journal Socket (/dev/log).478server # [ 1.404395] systemd[1]: Listening on Journal Sockets.479server # [ 1.405280] systemd[1]: Listening on udev Control Socket.480server # [ 1.406176] systemd[1]: Listening on udev Kernel Socket.481server # [ 1.407275] systemd[1]: Reached target Socket Units.482server # [ 1.409811] systemd[1]: Starting Create List of Static Device Nodes...483server # [ 1.415786] systemd[1]: Starting Load Kernel Module 9pnet_virtio...484server # [ 1.424109] systemd[1]: Starting Load Kernel Module configfs...485server # [ 1.452096] systemd[1]: Starting Journal Service...486server # [ 1.462134] systemd[1]: Starting Load Kernel Modules...487server # [ 1.468110] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki488server # [ 1.492815] systemd[1]: Starting Coldplug All udev Devices...489server # [ 1.495456] netfs: FS-Cache loaded490server # [ 1.510153] systemd[1]: Finished Create List of Static Device Nodes.491server # [ 1.524840] 9pnet: Installing 9P2000 support492server # [ 1.527437] systemd[1]: modprobe@configfs.service: Deactivated successfully.493server # [ 1.538512] systemd[1]: Finished Load Kernel Module configfs.494server # [ 1.546701] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.495server # [ 1.557465] systemd[1]: Finished Load Kernel Module 9pnet_virtio.496server # [ 1.558543] systemd-journald[67]: Collecting audit messages is disabled.497server # [ 1.561542] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config498server # [ 1.565581] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.499server # [ 1.573052] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...500server # [ 1.575212] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev501server # [ 1.611760] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.502server # [ 1.617047] systemd[1]: Finished Load Kernel Modules.503server # [ 1.624111] systemd[1]: Starting Apply Kernel Variables...504server # [ 1.638177] systemd[1]: Starting Create Static Device Nodes in /dev...505server # [ 1.675113] systemd[1]: Finished Apply Kernel Variables.506server # [ 1.680068] systemd[1]: Finished Create Static Device Nodes in /dev.507server # [ 1.558795] systemd-modules-load[68]: Inserted module 'dm_mod'508server # [ 1.560874] systemd-modules-load[68]: Inserted module 'virtio_balloon'509server # [ 1.684717] systemd[1]: Started Journal Service.510server # [ 1.562667] systemd-modules-load[68]: Inserted module 'virtio_gpu'511server # [ 1.571080] systemd[1]: Reached target Preparation for Local File Systems.512server # [ 1.573946] systemd[1]: Reached target Local File Systems.513server # [ 1.575190] systemd[1]: Starting Create System Files and Directories...514server # [ 1.579959] systemd[1]: Starting Rule-based Manager for Device Events and Files...515server # [ 1.607457] systemd[1]: Finished Create System Files and Directories.516server # [ 1.635246] systemd-udevd[83]: Using default interface naming scheme 'v260'.517server # [ 1.637696] systemd[1]: Finished Coldplug All udev Devices.518server # [ 1.651121] systemd[1]: Started Rule-based Manager for Device Events and Files.519server # [ 1.652420] systemd[1]: Reached target System Initialization.520server # [ 1.653504] systemd[1]: Reached target Basic System.521server # [ 1.991919] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12522server # [ 2.004459] serio: i8042 KBD port at 0x60,0x64 irq 1523server # [ 2.007189] virtio_blk virtio4: 1/0/0 default/read/poll queues524server # [ 2.018995] serio: i8042 AUX port at 0x60,0x64 irq 12525server # [ 2.023612] virtio_blk virtio4: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)526server # [ 2.028913] uhci_hcd 0000:00:01.2: UHCI Host Controller527server # [ 2.029526] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1528server # [ 2.044445] uhci_hcd 0000:00:01.2: detected 2 ports529server # [ 2.045459] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c140530server # [ 2.055155] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18531server # [ 2.056081] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1532server # [ 2.069352] virtio_blk virtio5: 1/0/0 default/read/poll queues533server # [ 2.070095] usb usb1: Product: UHCI Host Controller534server # [ 2.070635] usb usb1: Manufacturer: Linux 6.18.38 uhci_hcd535server # [ 2.073134] SCSI subsystem initialized536server # [ 2.076821] virtio_blk virtio5: [vdb] 2556032 512-byte logical blocks (1.31 GB/1.22 GiB)537server # [ 2.079268] usb usb1: SerialNumber: 0000:00:01.2538server # [ 2.087127] hub 1-0:1.0: USB hub found539server # [ 2.091055] hub 1-0:1.0: 2 ports detected540server # [ 1.984435] (udev-worker)[89]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.541server # [ 1.995213] (udev-worker)[90]: Network interface NamePolicy= disabled on kernel command line.542server # [ 1.997795] (udev-worker)[89]: Network interface NamePolicy= disabled on kernel command line.543server # [ 2.002074] systemd[1]: Starting Virtual Console Setup...544server # [ 2.130470] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0545server # [ 2.031344] systemd-vconsole-setup[101]: Configuration of first virtual console was skipped, ignoring remaining ones.546server # [ 2.034880] systemd[1]: Finished Virtual Console Setup.547server # [ 2.062086] systemd[1]: Found device /dev/disk/by-label/nixos.548server # [ 2.063684] systemd[1]: Reached target Initrd Root Device.549server # [ 2.065060] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...550server # [ 2.076305] systemd[1]: Found device /dev/disk/by-label/nix-store.551server # [ 2.213227] scsi host0: ata_piix552server # [ 2.216435] scsi host1: ata_piix553server # [ 2.219558] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc220 irq 14 lpm-pol 0554server # [ 2.220795] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc228 irq 15 lpm-pol 0555server # [ 2.099793] systemd-fsck[110]: nixos: clean, 12/65536 files, 13019/262144 blocks556server # [ 2.105975] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.557server # [ 2.316043] usb 1-1: new full-speed USB device number 2 using uhci_hcd558server # [ 2.380369] ata2: found unknown device (class 0)559server # [ 2.381503] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100560server # [ 2.383837] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5561server # [ 2.407407] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray562server # [ 2.416281] cdrom: Uniform CD-ROM driver Revision: 3.20563server # [ 2.480737] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00564server # [ 2.481694] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10565server # [ 2.482950] usb 1-1: Product: QEMU USB Tablet566server # [ 2.483624] usb 1-1: Manufacturer: QEMU567server # [ 2.484386] usb 1-1: SerialNumber: 28754-0000:00:01.2-1568server # [ 2.387091] systemd[1]: Mounting /sysroot...569server # [ 2.510731] hid: raw HID events driver (C) Jiri Kosina570server # [ 2.525449] usbcore: registered new interface driver usbhid571server # [ 2.526308] usbhid: USB HID core driver572server # [ 2.536550] 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/input2573server # [ 2.542666] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0574server # [ 2.617106] EXT4-fs (vda): mounted filesystem 5565c9e2-47f9-4acc-a6c6-6269a84de8e0 r/w with ordered data mode. Quota mode: none.575server # [ 2.498135] systemd[1]: Mounted /sysroot.576server # [ 2.499588] systemd[1]: Reached target Initrd Root File System.577server # [ 2.502064] systemd[1]: Starting Mountpoints Configured in the Real Root...578server # [ 2.511144] systemd-sysroot-fstab-check[126]: /sysroot should be mounted in the initrd, will request daemon-reload.579server # [ 2.513760] systemd[1]: Reload requested from client PID 126 ('systemd-sysroot') (unit initrd-parse-etc.service)...580server # [ 2.515114] systemd[1]: Reloading...581server # [ 2.579973] systemd[1]: Reloading finished in 64 ms.582server # [ 2.585348] systemd-sysroot-fstab-check[126]: Requesting initrd-fs.target/start/replace...583server # [ 2.587576] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio584server # [ 2.588667] systemd-sysroot-fstab-check[126]: Requesting swap.target/start/replace...585server # [ 2.590918] systemd[1]: initrd-parse-etc.service: Deactivated successfully.586server # [ 2.591705] systemd[1]: Finished Mountpoints Configured in the Real Root.587server # [ 2.592472] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.588server # [ 3.382443] systemd[1]: Mounting /sysroot/nix/.ro-store...589server # [ 3.385748] systemd[1]: Mounting /sysroot/nix/.rw-store...590server # [ 3.389722] systemd[1]: Mounting /sysroot/run...591server # [ 3.394705] systemd[1]: Mounting /sysroot/tmp/shared...592server # [ 3.397154] systemd[1]: Mounting /sysroot/tmp/xchg...593server # [ 3.421936] systemd[1]: Mounted /sysroot/nix/.rw-store.594server # [ 3.432755] systemd[1]: Mounted /sysroot/run.595server # [ 3.557039] erofs (device vdb): mounted with root inode @ nid 36.596server # [ 3.564681] 9p: Installing v9fs 9p2000 file system support597server # [ 3.445642] systemd[1]: Starting rw-sysroot-nix-store.service...598server # [ 3.446593] systemd[1]: Mounted /sysroot/nix/.ro-store.599server # [ 3.453086] systemd[1]: Mounted /sysroot/tmp/shared.600server # [ 3.455819] systemd[1]: Mounted /sysroot/tmp/xchg.601server # [ 3.464235] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.602server # [ 3.465247] systemd[1]: Finished rw-sysroot-nix-store.service.603server # [ 4.382987] systemd[1]: Mounting /sysroot/nix/store...604server # [ 4.407856] systemd[1]: Mounted /sysroot/nix/store.605server # [ 4.409802] systemd[1]: Reached target Initrd File Systems.606server # [ 4.410729] systemd[1]: Starting Find NixOS closure...607server # [ 4.414176] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...608server # [ 4.433071] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.609server # [ 4.433958] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.610server # [ 4.440751] systemd[1]: Finished Find NixOS closure.611server # [ 4.442325] systemd[1]: Reached target Initrd Default Target.612server # [ 4.443784] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...613server # [ 4.457859] systemd[1]: Stopped target Initrd Default Target.614server # [ 4.458969] systemd[1]: Stopped target Basic System.615server # [ 4.460140] systemd[1]: Stopped target Initrd Root Device.616server # [ 4.460764] systemd[1]: Stopped target Path Units.617server # [ 4.461354] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.618server # [ 4.462179] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.619server # [ 4.463352] systemd[1]: Stopped target Slice Units.620server # [ 4.464276] systemd[1]: Stopped target Socket Units.621server # [ 4.465053] systemd[1]: Stopped target System Initialization.622server # [ 4.466116] systemd[1]: Stopped target Swaps.623server # [ 4.466674] systemd[1]: Stopped target Timer Units.624server # [ 4.467255] systemd[1]: dbus.socket: Deactivated successfully.625server # [ 4.468179] systemd[1]: Closed D-Bus System Message Bus Socket.626server # [ 4.468832] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.627server # [ 4.469799] systemd[1]: Stopped Find NixOS closure.628server # [ 4.471105] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio629server # [ 4.472539] systemd[1]: Starting rw-sysroot-nix-store.service...630server # [ 4.474119] systemd[1]: systemd-sysctl.service: Deactivated successfully.631server # [ 4.475135] systemd[1]: Stopped Apply Kernel Variables.632server # [ 4.476129] systemd[1]: systemd-modules-load.service: Deactivated successfully.633server # [ 4.476991] systemd[1]: Stopped Load Kernel Modules.634server # [ 4.477641] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.635server # [ 4.479123] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.636server # [ 4.480071] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.637server # [ 4.482136] systemd[1]: Stopped Create System Files and Directories.638server # [ 4.482958] systemd[1]: Stopped target Local File Systems.639server # [ 4.483765] systemd[1]: Stopped target Preparation for Local File Systems.640server # [ 4.484607] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.641server # [ 4.485518] systemd[1]: Stopped Coldplug All udev Devices.642server # [ 4.487612] systemd[1]: Stopping Rule-based Manager for Device Events and Files...643server # [ 4.489165] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.644server # [ 4.489977] systemd[1]: Stopped Virtual Console Setup.645server # [ 4.497909] systemd[1]: initrd-cleanup.service: Deactivated successfully.646server # [ 4.500961] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.647server # [ 4.504037] systemd[1]: systemd-udevd.service: Deactivated successfully.648server # [ 4.506128] systemd[1]: Stopped Rule-based Manager for Device Events and Files.649server # [ 4.507634] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.650server # [ 4.508820] systemd[1]: Finished rw-sysroot-nix-store.service.651server # [ 4.510146] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.652server # [ 4.510886] systemd[1]: Closed udev Control Socket.653server # [ 4.512329] systemd[1]: Starting Cleanup udev Database...654server # [ 4.512979] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.655server # [ 4.514138] systemd[1]: Stopped Create Static Device Nodes in /dev.656server # [ 4.514802] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.657server # [ 4.516172] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.658server # [ 4.516901] systemd[1]: kmod-static-nodes.service: Deactivated successfully.659server # [ 4.517604] systemd[1]: Stopped Create List of Static Device Nodes.660server # [ 4.529157] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.661server # [ 4.530566] systemd[1]: Finished Cleanup udev Database.662server # [ 4.532144] systemd[1]: Reached target Switch Root.663server # [ 4.533371] systemd[1]: Starting NixOS Activation...664server # [ 4.599190] initrd-nixos-activation-start[177]: booting system configuration /nix/store/xh8v1463jmwk3rvaiz3wlmx6i8n3vgj3-nixos-system-server-test665server # [ 4.617377] initrd-nixos-activation-start[177]: running activation script...666server # [ 4.758807] initrd-nixos-activation-start[200]: setting up /etc...667server # [ 4.835813] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.668server # [ 4.836682] systemd[1]: Finished NixOS Activation.669server # [ 4.838763] systemd[1]: Starting Switch Root...670server # [ 4.850648] systemd[1]: Switching root.671server # [ 4.987326] systemd-journald[67]: Received SIGTERM from PID 1 (systemd).672server # [ 5.051190] NET: Registered PF_VSOCK protocol family673server # [ 5.402158] 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)674server # [ 5.405243] systemd[1]: Detected virtualization kvm.675server # [ 5.405887] systemd[1]: Detected architecture x86-64.676server # [ 5.406564] systemd[1]: Detected first boot.677server # [ 5.407402] systemd[1]: Initializing machine ID from random generator.678server # [ 5.582459] systemd[1]: bpf-restrict-fs: LSM BPF program attached679server # [ 5.650236] systemd[1]: Applying preset policy.680server # [ 5.735777] systemd[1]: Populated /etc with preset unit settings.681server # [ 5.814692] systemd[1]: initrd-switch-root.service: Deactivated successfully.682server # [ 5.815753] systemd[1]: Stopped initrd-switch-root.service.683server # [ 5.817480] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.684server # [ 5.819136] systemd[1]: Created slice Slice /system/getty.685server # [ 5.820204] systemd[1]: Created slice User and Session Slice.686server # [ 5.821085] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.687server # [ 5.822058] systemd[1]: Started Forward Password Requests to Wall Directory Watch.688server # [ 5.822895] systemd[1]: Expecting device /dev/hvc0...689server # [ 5.823477] systemd[1]: Expecting device /dev/ttyS0...690server # [ 5.824102] systemd[1]: Reached target Local Encrypted Volumes.691server # [ 5.824779] systemd[1]: Stopped target initrd-fs.target.692server # [ 5.825395] systemd[1]: Stopped target initrd-root-fs.target.693server # [ 5.826067] systemd[1]: Stopped target initrd-switch-root.target.694server # [ 5.826753] systemd[1]: Reached target Virtual Machines and Containers.695server # [ 5.827485] systemd[1]: Reached target Path Units.696server # [ 5.828124] systemd[1]: Reached target Remote File Systems.697server # [ 5.828829] systemd[1]: Reached target Slice Units.698server # [ 5.829444] systemd[1]: Reached target Swaps.699server # [ 5.830860] systemd[1]: Listening on Query the User Interactively for a Password.700server # [ 5.832665] systemd[1]: Listening on Process Core Dump Socket.701server # [ 5.833858] systemd[1]: Listening on Credential Encryption/Decryption.702server # [ 5.835264] systemd[1]: Listening on Factory Reset Management.703server # [ 5.837313] systemd[1]: Starting Journal Log Access Socket...704server # [ 5.838548] systemd[1]: Listening on Journal Audit Socket.705server # [ 5.840690] systemd[1]: Listening on Console Output Muting Service Socket.706server # [ 5.841651] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.707server # [ 5.842542] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-uki708server # [ 5.843577] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki709server # [ 5.845795] systemd[1]: Listening on Disk Repartitioning Service Socket.710server # [ 5.846611] systemd[1]: Listening on udev Control Socket.711server # [ 5.847316] systemd[1]: Listening on udev Varlink Socket.712server # [ 5.851184] systemd[1]: Mounting Huge Pages File System...713server # [ 5.856075] systemd[1]: Mounting POSIX Message Queue File System...714server # [ 5.859410] systemd[1]: Mounting Kernel Debug File System...715server # [ 5.865052] systemd[1]: Mounting Kernel Trace File System...716server # [ 5.872092] systemd[1]: Starting Create List of Static Device Nodes...717server # [ 5.876146] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio718server # [ 5.886150] systemd[1]: Starting Load Kernel Module configfs...719server # [ 5.892407] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm720server # [ 5.898704] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore721server # [ 5.900548] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse722server # [ 5.906136] systemd[1]: Mounting FUSE Control File System...723server # [ 5.906874] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67724server # [ 5.918637] systemd[1]: Starting Journal Service...725server # [ 5.924062] systemd[1]: Starting Load Kernel Modules...726server # [ 5.931754] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...727server # [ 5.942531] systemd[1]: Starting Remount Root and Kernel File Systems...728server # [ 5.950076] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki729server # [ 5.965322] loop: module loaded730server # [ 5.969520] systemd[1]: Starting Coldplug All udev Devices...731server # [ 5.977659] systemd-journald[269]: Collecting audit messages is enabled.732server # [ 5.986671] systemd[1]: Listening on Journal Log Access Socket.733server # [ 5.992496] systemd[1]: Mounted Huge Pages File System.734server # [ 5.998183] systemd[1]: Mounted POSIX Message Queue File System.735server # [ 6.001060] systemd[1]: Mounted Kernel Debug File System.736server # [ 6.001835] systemd[1]: Mounted Kernel Trace File System.737server # [ 5.881705] systemd[1]: Queued start job for default target Multi-User System.[ 6.005464] EXT4-fs (vda): re-mounted 5565c9e2-47f9-4acc-a6c6-6269a84de8e0.738server # [ 6.009588] systemd[1]: Started Journal Service.739server # 740server # [ 5.887668] systemd[1]: Unnecessary job was removed for /dev/vdb.741server # [ 5.888583] systemd[1]: systemd-journald.service: Deactivated successfully.742server # [ 5.892486] systemd-modules-load[270]: Inserted module 'loop'743server # [ 5.898065] systemd[1]: Finished Create List of Static Device Nodes.744server # [ 5.900211] systemd[1]: modprobe@configfs.service: Deactivated successfully.745server # [ 5.900934] systemd[1]: Finished Load Kernel Module configfs.746server # [ 5.901611] systemd[1]: Mounted FUSE Control File System.747server # [ 5.903822] systemd[1]: Finished Load Kernel Modules.748server # [ 5.907603] systemd[1]: Finished Remount Root and Kernel File Systems.749server # [ 5.918266] systemd-oomd[271]: No swap; memory pressure usage will be degraded750server # [ 5.919319] systemd[1]: Listening on Disk Image Download Service Socket.751server # [ 5.925077] systemd[1]: Mounting Kernel Configuration File System...752server # [ 5.931966] systemd[1]: Starting Firewall...753server # [ 5.939190] systemd[1]: Starting Flush Journal to Persistent Storage...754server # [ 5.940910] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore755server # [ 5.951997] systemd[1]: Starting Load/Save OS Random Seed...756server # [ 5.965095] systemd[1]: Starting Apply Kernel Variables...757server # [ 5.974074] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...758server # [ 5.974905] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki759server # [ 5.982065] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.760server # [ 6.132236] systemd-journald[269]: Received client request to flush runtime journal.761server # [ 6.156514] systemd[1]: Mounted Kernel Configuration File System.762server # [ 6.158088] systemd[1]: Finished Load/Save OS Random Seed.763server # [ 6.158835] systemd[1]: Reached target First Boot Complete.764server # [ 6.163426] systemd[1]: Finished Apply Kernel Variables.765server # [ 6.164193] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.766server # [ 6.166152] systemd[1]: Starting Create Static Device Nodes in /dev...767server # [ 6.166822] systemd[1]: Finished Create Static Device Nodes in /dev.768server # [ 6.167633] systemd[1]: Reached target Preparation for Local File Systems.769server # [ 6.169261] systemd[1]: Starting Rule-based Manager for Device Events and Files...770server # [ 6.171806] systemd[1]: Finished Flush Journal to Persistent Storage.771server # [ 6.173707] systemd[1]: Finished Coldplug All udev Devices.772server # [ 6.217296] systemd-udevd[302]: Using default interface naming scheme 'v260'.773server # [ 6.258392] systemd[1]: Started Rule-based Manager for Device Events and Files.774server # [ 6.418219] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse775server # [ 6.460093] systemd[1]: Finished Firewall.776server # [ 6.515242] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.777server # [ 6.521075] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.778server # [ 6.523238] (udev-worker)[369]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.779server # [ 6.525320] (udev-worker)[369]: Network interface NamePolicy= disabled on kernel command line.780server # [ 6.536234] (udev-worker)[365]: Network interface NamePolicy= disabled on kernel command line.781server # [ 6.592621] systemd[1]: Condition check resulted in Virtio network device being skipped.782server # [ 6.594219] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore783server # [ 6.596486] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67784server # [ 6.597987] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore785server # [ 6.599274] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki786server # [ 6.600676] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki787server # [ 6.783934] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3788server # [ 6.800338] mousedev: PS/2 mouse device common for all mice789server # [ 6.802776] ACPI: button: Power Button [PWRF]790server # [ 6.816212] rtc_cmos 00:05: RTC can wake from S4791server # [ 6.695685] systemd[1]: Mounting /run/wrappers...792server # [ 6.713458] systemd[1]: Mounted /run/wrappers.793server # [ 6.716057] systemd[1]: Reached target Local File Systems.794server # [ 6.717560] systemd[1]: Listening on Boot Loader Control Service Socket.795server # [ 6.721124] systemd[1]: Starting register-nix-paths.service...796server # [ 6.850429] parport_pc 00:03: reported by Plug and Play ACPI797server # [ 6.729432] systemd[1]: Starting Create SUID/SGID Wrappers...798server # [ 6.730105] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.799server # [ 6.857277] rtc_cmos 00:05: registered as rtc0800server # [ 6.857867] rtc_cmos 00:05: setting system clock to 2026-11-06T19:26:59 UTC (1793993219)801server # [ 6.738672] systemd[1]: Starting Save Transient machine-id to Disk...802server # [ 6.866237] Floppy drive(s): fd0 is 2.88M AMI BIOS803server # [ 6.748177] systemd[1]: Starting Create System Files and Directories...804server # [ 6.878673] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs805server # [ 6.887102] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]806server # [ 6.891337] FDC 0 is a S82078B807server # [ 6.850768] systemd[1]: Finished Create System Files and Directories.808server # [ 6.870404] systemd[1]: Starting Rebuild Journal Catalog...809server # [ 6.883607] systemd[1]: Starting Record System Boot/Shutdown in UTMP...810server # [ 6.885978] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.811server # [ 6.907708] systemd[1]: Finished Save Transient machine-id to Disk.812server # [ 7.041759] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console813server # [ 7.066083] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0814server # [ 7.066141] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD815server # [ 7.128734] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4816server # [ 7.188448] Console: switching to colour dummy device 80x25817server # [ 7.218604] [drm] Found bochs VGA, ID 0xb0c5.818server # [ 7.218606] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.819server # [ 6.976592] systemd[1]: Finished Rebuild Journal Catalog.820server # [ 7.099116] systemd[1]: Starting Update is Completed...821server # [ 7.100513] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.822server # [ 7.103355] systemd[1]: Finished Create SUID/SGID Wrappers.823server # [ 7.141775] systemd[1]: Finished Update is Completed.824server # [ 7.272682] bochs-drm 0000:00:02.0: [drm] Registered 1 planes with drm panic825server # [ 7.273421] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0826server # [ 7.153617] systemd[1]: Finished Record System Boot/Shutdown in UTMP.827server # [ 7.318646] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6828server # [ 7.319490] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5829server # [ 7.242240] systemd[1]: Starting Virtual Console Setup...830server # [ 7.367055] fbcon: bochs-drmdrmfb (fb0) is primary device831server # [ 7.429562] RAPL PMU: API unit is 2^-32 Joules, 1 fixed counters, 10737418240 ms ovfl timer832server # [ 7.429566] RAPL PMU: hw unit of domain psys 2^-0 Joules833server # [ 7.452574] ppdev: user-space parallel port driver834server # [ 7.495460] Console: switching to colour frame buffer device 160x50835server # [ 7.501979] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device836server # [ 7.307762] systemd[1]: Finished register-nix-paths.service.837server # [ 7.383649] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.838server # [ 7.384523] systemd[1]: Stopped Virtual Console Setup.839server # [ 7.387713] systemd[1]: Starting Virtual Console Setup...840server # [ 7.430389] systemd-vconsole-setup[496]: Configuration of first virtual console was skipped, ignoring remaining ones.841server # [ 7.434070] systemd[1]: Finished Virtual Console Setup.842server # [ 7.437296] systemd[1]: Reached target System Initialization.843server # [ 7.437971] systemd[1]: Started Discard unused filesystem blocks once a week.844server # [ 7.438688] systemd[1]: Started postgresqlBackup-horae.timer.845server # [ 7.439315] systemd[1]: Started Daily Cleanup of Temporary Directories.846server # [ 7.439976] systemd[1]: Reached target Timer Units.847server # [ 7.441226] systemd[1]: Listening on D-Bus System Message Bus Socket.848server # [ 7.442123] systemd[1]: Listening on Nix Daemon Socket.849server # [ 7.442682] systemd[1]: Listening on Hostname Service Socket.850server # [ 7.443356] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.851server # [ 7.447061] systemd[1]: Reached target Socket Units.852server # [ 7.447713] systemd[1]: Reached target Basic System.853server # [ 7.449142] systemd[1]: Started backdoor.service.854server # [ 7.453790] systemd[1]: Starting Import lastlog data into lastlog2 database...855server # [ 7.463616] systemd[1]: Starting Name Service Cache Daemon (nsncd)...856server # connecting to host...857server # [ 7.519097] systemd[1]: Starting Post-Boot Actions...858server # [ 7.525234] systemd[1]: Started Reset console on configuration changes.859server # [ 7.539073] systemd[1]: Starting resolvconf update...860server # [ 7.542250] nsncd[501]: Nov 06 19:27:00.306 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"861server # [ 7.551069] systemd[1]: Started test-console-diagnostics.service.862server # [ 7.551743] systemd[1]: Started Name Service Cache Daemon (nsncd).863server # [ 7.591644] systemd[1]: Finished Post-Boot Actions.864server # [ 7.609962] systemd[1]: Reached target Host and Network Name Lookups.865server # [ 7.618230] systemd[1]: Reached target User and Group Name Lookups.866server # [ 7.631172] systemd[1]: Starting D-Bus System Message Bus...867server # [ 7.664435] systemd[1]: Starting User Login Management...868server # [ 7.675079] systemd[1]: Finished Import lastlog data into lastlog2 database.869server # [ 7.822487] Key type encrypted registered870server # [ 7.711437] systemd[1]: test-console-diagnostics.service: Deactivated successfully.871server # [ 7.715227] systemd[1]: test-console-diagnostics.service: Consumed 19ms CPU time over 163ms wall clock time, 8.2M memory peak, 6.3M read from disk.872server # [ 7.738967] dbus-broker-launch[526]: Looking up NSS user entry for 'systemd-timesync'...873server # [ 7.744070] dbus-broker-launch[526]: NSS returned no entry for 'systemd-timesync'874server # [ 7.744825] dbus-broker-launch[526]: Invalid user-name in /nix/store/r3ijqam52cfmgx9xqgykq7n6d25wgmps-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"875server # [ 7.753082] systemd[1]: Started D-Bus System Message Bus.876server # [ 7.894717] EDAC MC: Ver: 3.0.0877server # [ 7.785854] dbus-broker-launch[526]: Ready878server # [ 7.807799] systemd[1]: Stopped target Host and Network Name Lookups.879server # [ 7.808892] systemd[1]: Stopping Host and Network Name Lookups...880server # [ 7.809824] systemd[1]: Stopped target User and Group Name Lookups.881server # [ 7.810755] systemd[1]: Stopping User and Group Name Lookups...882server # [ 7.814253] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...883server # [ 7.816447] systemd[1]: nscd.service: Deactivated successfully.884server # [ 7.819771] systemd[1]: Stopped Name Service Cache Daemon (nsncd).885server # [ 7.820740] systemd[1]: nscd.service: Consumed 17ms CPU time over 352ms wall clock time, 7.6M memory peak, 5.7M read from disk.886server # [ 7.843332] systemd-logind[530]: New seat seat0.887server # [ 7.850103] systemd-logind[530]: Watching system buttons on /dev/input/event2 (Power Button)888server # [ 7.851420] systemd[1]: Starting Name Service Cache Daemon (nsncd)...889server # [ 7.855352] systemd-logind[530]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)890server # [ 7.856642] systemd-logind[530]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)891server # [ 7.859583] systemd[1]: Started User Login Management.892server # [ 7.875553] systemd[1]: Starting linger-users.service...893server # [ 7.912277] systemd[1]: Finished resolvconf update.894server # [ 7.919068] systemd[1]: Reached target Preparation for Network.895server # [ 7.924289] nsncd[573]: Nov 06 19:27:00.688 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"896server # [ 7.926112] systemd[1]: Starting DHCP Client...897server # [ 7.930069] systemd[1]: Starting Address configuration of eth1...898server # [ 7.933333] systemd[1]: Starting Extra networking commands....899server # [ 7.934795] systemd[1]: Started Name Service Cache Daemon (nsncd).900server # [ 7.938975] systemd[1]: linger-users.service: Deactivated successfully.901server # [ 7.940064] systemd[1]: Finished linger-users.service.902server # [ 7.945946] systemd[1]: Reached target Host and Network Name Lookups.903server # [ 7.949148] systemd[1]: Reached target User and Group Name Lookups.904server # [ 7.985260] network-addresses-eth1-start[600]: adding address 192.168.1.1/24... done905server # [ 7.990856] network-addresses-eth1-start[600]: adding address 2001:db8:1::1/64... done906server # [ 8.002449] systemd[1]: Finished Address configuration of eth1.907server # [ 8.046791] systemd[1]: Finished Extra networking commands..908server # [ 8.051172] systemd[1]: Reached target Network.909server # [ 8.052116] dhcpcd[612]: dhcpcd-10.3.2 starting910server # [ 8.055226] dhcpcd[659]: dev: loaded udev911server # [ 8.056068] systemd[1]: Starting dex identity provider...912server # [ 8.184401] 8021q: 802.1Q VLAN Support v1.8913server # [ 8.184750] 8021q: adding VLAN 0 to HW filter on device eth1914server # [ 8.063181] systemd[1]: Starting PostgreSQL Server...915server # [ 8.071414] systemd[1]: Starting Permit User Sessions...916server # [ 8.095463] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.917server # [ 8.125167] systemd[1]: Finished Permit User Sessions.918server # [ 8.134178] systemd[1]: Started Getty on tty1.919server # [ 8.134728] systemd[1]: Reached target Login Prompts.920server # [ 8.240806] systemd[1]: Started dex identity provider.921server # [ 8.387119] cfg80211: Loading compiled-in X.509 certificates for regulatory database922server # [ 8.397655] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'923server # [ 8.275656] postgresql-pre-start[673]: The files belonging to this database system will be owned by user "postgres".924server # [ 8.399940] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'925server # [ 8.277746] postgresql-pre-start[673]: This user must also own the server process.926server # [ 8.402340] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2927server # [ 8.402979] cfg80211: failed to load regulatory.db928server # [ 8.289810] postgresql-pre-start[673]: The database cluster will be initialized with locale "en_US.UTF-8".929server # [ 8.291171] postgresql-pre-start[673]: The default database encoding has accordingly been set to "UTF8".930server # [ 8.292349] postgresql-pre-start[673]: The default text search configuration will be set to "english".931server # [ 8.293549] postgresql-pre-start[673]: Data page checksums are disabled.932server # [ 8.294463] postgresql-pre-start[673]: fixing permissions on existing directory /var/lib/postgresql/17 ... ok933server # [ 8.299154] postgresql-pre-start[673]: creating subdirectories ... ok934server # [ 8.300108] postgresql-pre-start[673]: selecting dynamic shared memory implementation ... posix935server # [ 8.489394] 8021q: adding VLAN 0 to HW filter on device eth0936server # [ 8.370313] dhcpcd[659]: eth0: waiting for carrier937server # [ 8.371142] dhcpcd[659]: eth0: carrier acquired938server # [ 8.383373] postgresql-pre-start[673]: selecting default "max_connections" ... 100939server # [ 8.384350] dhcpcd[659]: DUID 00:01:00:01:32:80:e6:85:52:54:00:12:34:56940server # [ 8.385164] dhcpcd[659]: eth0: IAID 00:12:34:56941server # [ 8.385725] dhcpcd[659]: eth0: adding address fe80::5054:ff:fe12:3456942server # [ 8.435162] postgresql-pre-start[673]: selecting default "shared_buffers" ... 128MB943server: waiting for unit register-nix-paths.service944server: waiting for the VM to finish booting945server: Guest shell says: b'Spawning backdoor root shell...\n'946server: connected to guest root shell947server: (connecting took 0.00 seconds)948server: (finished: waiting for the VM to finish booting, in 0.00 seconds)949server # [ 8.508860] dex[679]: time=2026-11-06T19:27:01.272Z level=INFO msg="Version info" dex_version=v2.45.1 go.version=go1.26.4 go.os=linux go.arch=amd64950server # [ 8.511392] dex[679]: time=2026-11-06T19:27:01.272Z level=INFO msg="config issuer" issuer=http://127.0.0.1:5556/dex951server: (finished: waiting for unit register-nix-paths.service, in 0.07 seconds)952server: waiting for unit postgresql.service953server # [ 8.513504] dex[679]: time=2026-11-06T19:27:01.273Z level=INFO msg="config storage" storage_type=memory954server # [ 8.515175] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="config static client" client_name=Horae955server # [ 8.517740] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="config static client" client_name="Horae without email_verified"956server # [ 8.518822] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="config connector" connector_id=mock957server # [ 8.519773] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="config skipping approval screen"958server # [ 8.522076] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="continue on connector failure feature flag enabled"959server # [ 8.523134] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="signer configured" type=local keys_rotation_period=6h960server # [ 8.524171] dex[679]: time=2026-11-06T19:27:01.277Z level=INFO msg="config refresh tokens rotation" enabled=true961server # [ 8.525159] dex[679]: time=2026-11-06T19:27:01.278Z level=ERROR msg="failed to get signing algorithm" err="no signing key found"962server # [ 8.526216] dex[679]: time=2026-11-06T19:27:01.285Z level=INFO msg="keys expired, rotating"963server # [ 8.625968] dex[679]: time=2026-11-06T19:27:01.390Z level=INFO msg="keys rotated" next_rotation=2026-11-07T01:27:01.390Z964server # [ 8.627753] dex[679]: time=2026-11-06T19:27:01.392Z level=INFO msg="listening on" server=http address=127.0.0.1:5556965server # [ 8.801022] dhcpcd[659]: eth0: soliciting a DHCP lease966server # [ 8.932882] NET: Registered PF_PACKET protocol family967server # [ 8.815439] dhcpcd[659]: eth0: offered 10.0.2.15 from 10.0.2.2968server # [ 8.817133] dhcpcd[659]: eth0: probing address 10.0.2.15/24969server # [ 8.824918] postgresql-pre-start[673]: selecting default time zone ... UTC970server # [ 8.826801] postgresql-pre-start[673]: creating configuration files ... ok971server # [ 9.021416] postgresql-pre-start[673]: running bootstrap script ... ok972server # [ 9.451791] postgresql-pre-start[673]: performing post-bootstrap initialization ... ok973server # [ 9.531407] postgresql-pre-start[673]: syncing data to disk ... ok974server # [ 9.532757] postgresql-pre-start[673]: initdb: warning: enabling "trust" authentication for local connections975server # [ 9.533605] postgresql-pre-start[673]: 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.976server # [ 9.534931] postgresql-pre-start[673]: Success. You can now start the database server using:977server # [ 9.535673] postgresql-pre-start[673]: pg_ctl -D /var/lib/postgresql/17 -l logfile start978server # [ 9.597377] postgres[718]: [718] LOG: starting PostgreSQL 17.10 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit979server # [ 9.602329] postgres[718]: [718] LOG: listening on IPv6 address "::1", port 5432980server # [ 9.603475] postgres[718]: [718] LOG: listening on IPv4 address "127.0.0.1", port 5432981server # [ 9.606922] postgres[718]: [718] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"982server # [ 9.613524] postgres[728]: [728] LOG: database system was shut down at 2026-11-06 19:27:02 GMT983server # [ 9.620743] postgres[718]: [718] LOG: database system is ready to accept connections984server # [ 9.622957] systemd[1]: Started PostgreSQL Server.985server # [ 9.626955] systemd[1]: Starting PostgreSQL Setup Scripts...986server # [ 9.715635] postgresql-setup-start[739]: CREATE DATABASE987server # [ 9.738637] postgresql-setup-start[744]: CREATE ROLE988server # [ 9.741877] dhcpcd[659]: eth0: soliciting an IPv6 router989server # [ 9.743095] dhcpcd[659]: eth0: Router Advertisement from fe80::2990server # [ 9.743726] dhcpcd[659]: eth0: adding address fec0::5054:ff:fe12:3456/64991server # [ 9.745159] dhcpcd[659]: eth0: adding route to fec0::/64992server # [ 9.745791] dhcpcd[659]: eth0: adding default route via fe80::2993server # [ 9.751822] postgresql-setup-start[746]: ALTER ROLE994server # [ 9.760392] postgresql-setup-start[748]: ALTER DATABASE995server # [ 9.763101] systemd[1]: Finished PostgreSQL Setup Scripts.996server # [ 9.764918] systemd[1]: Reached target PostgreSQL.997server # [ 9.768124] systemd[1]: Starting Horae time tracking server...998server # [ 9.963991] horae[751]: 2026-11-06T19:27:02.728778Z INFO horae: Running migrations...999server # [ 10.184726] horae[751]: 2026-11-06T19:27:02.949694Z INFO horae: Migrations complete.1000server # [ 10.190758] systemd[1]: Started Horae time tracking server.1001server # [ 10.210662] horae[758]: 2026-11-06T19:27:02.975488Z INFO horae: Starting Horae on 127.0.0.1:30001002server # [ 10.217339] horae[758]: 2026-11-06T19:27:02.982357Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1003server # [ 10.226490] horae[758]: 2026-11-06T19:27:02.991488Z INFO horae::plugin::registry: plugins directory does not exist: plugins1004server # [ 10.239072] horae[758]: 2026-11-06T19:27:03.003452Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061005server # [ 10.240694] horae[758]: 2026-11-06T19:27:03.003483Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061006server # [ 10.242113] horae[758]: 2026-11-06T19:27:03.003496Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061007server # [ 10.243489] horae[758]: 2026-11-06T19:27:03.003507Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061008server # [ 10.244778] horae[758]: 2026-11-06T19:27:03.003526Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061009server # [ 10.246050] horae[758]: 2026-11-06T19:27:03.003537Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061010server # [ 10.249515] horae[758]: 2026-11-06T19:27:03.003547Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061011server # [ 10.250866] horae[758]: 2026-11-06T19:27:03.003557Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061012server # [ 10.252126] horae[758]: 2026-11-06T19:27:03.003576Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061013server # [ 10.253423] horae[758]: 2026-11-06T19:27:03.003585Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061014server # [ 10.254687] horae[758]: 2026-11-06T19:27:03.003594Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061015server # [ 10.255926] horae[758]: 2026-11-06T19:27:03.003605Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061016server # [ 10.257158] horae[758]: 2026-11-06T19:27:03.003617Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061017server # [ 10.258447] horae[758]: 2026-11-06T19:27:03.003626Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061018server # [ 10.259974] horae[758]: 2026-11-06T19:27:03.003637Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061019server # [ 10.261259] horae[758]: 2026-11-06T19:27:03.003661Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181020server # [ 10.262566] horae[758]: 2026-11-06T19:27:03.003672Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181021server # [ 10.263906] horae[758]: 2026-11-06T19:27:03.003681Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181022server # [ 10.266687] horae[758]: 2026-11-06T19:27:03.003691Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181023server # [ 10.268282] horae[758]: 2026-11-06T19:27:03.003700Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181024server # [ 10.269561] horae[758]: 2026-11-06T19:27:03.003713Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181025server # [ 10.270810] horae[758]: 2026-11-06T19:27:03.003722Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181026server # [ 10.272036] horae[758]: 2026-11-06T19:27:03.003731Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181027server # [ 10.273240] horae[758]: 2026-11-06T19:27:03.003742Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851028server # [ 10.274597] horae[758]: 2026-11-06T19:27:03.003752Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851029server # [ 10.275944] horae[758]: 2026-11-06T19:27:03.003766Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851030server # [ 10.277291] horae[758]: 2026-11-06T19:27:03.003776Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851031server # [ 10.278794] horae[758]: 2026-11-06T19:27:03.003786Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851032server # [ 10.281094] horae[758]: 2026-11-06T19:27:03.003804Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851033server # [ 10.282375] horae[758]: 2026-11-06T19:27:03.003850Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001034server # [ 10.283618] horae[758]: 2026-11-06T19:27:03.003859Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961035server # [ 10.284909] horae[758]: 2026-11-06T19:27:03.003869Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961036server # [ 10.286163] horae[758]: 2026-11-06T19:27:03.003878Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961037server # [ 10.287387] horae[758]: 2026-11-06T19:27:03.003887Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961038server # [ 10.288610] horae[758]: 2026-11-06T19:27:03.003896Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961039server # [ 10.290511] horae[758]: 2026-11-06T19:27:03.003905Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071040server # [ 10.291812] horae[758]: 2026-11-06T19:27:03.003917Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071041server # [ 10.293118] horae[758]: 2026-11-06T19:27:03.003927Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071042server # [ 10.294385] horae[758]: 2026-11-06T19:27:03.003936Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071043server # [ 10.295697] horae[758]: 2026-11-06T19:27:03.003948Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111044server # [ 10.296973] horae[758]: 2026-11-06T19:27:03.003960Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261045server # [ 10.298240] horae[758]: 2026-11-06T19:27:03.003970Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261046server # [ 10.299488] horae[758]: 2026-11-06T19:27:03.003979Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261047server # [ 10.303571] horae[758]: 2026-11-06T19:27:03.003992Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261048server # [ 10.304882] horae[758]: 2026-11-06T19:27:03.004007Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721049server # [ 10.306153] horae[758]: 2026-11-06T19:27:03.004020Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711050server # [ 10.307446] horae[758]: 2026-11-06T19:27:03.004029Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711051server # [ 10.308764] horae[758]: 2026-11-06T19:27:03.004038Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711052server # [ 10.310070] horae[758]: 2026-11-06T19:27:03.004048Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711053server # [ 10.311337] horae[758]: 2026-11-06T19:27:03.004057Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711054server # [ 10.312594] horae[758]: 2026-11-06T19:27:03.004066Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711055server # [ 10.315145] horae[758]: 2026-11-06T19:27:03.004080Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711056server # [ 10.316447] horae[758]: 2026-11-06T19:27:03.013744Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711057server # [ 10.317700] horae[758]: 2026-11-06T19:27:03.013770Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711058server # [ 10.318941] horae[758]: 2026-11-06T19:27:03.013782Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341059server # [ 10.320213] horae[758]: 2026-11-06T19:27:03.013792Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341060server # [ 10.322760] horae[758]: 2026-11-06T19:27:03.013818Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191061server # [ 10.324106] horae[758]: 2026-11-06T19:27:03.013894Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191062server # [ 10.325860] horae[758]: 2026-11-06T19:27:03.013906Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191063server # [ 10.327167] horae[758]: 2026-11-06T19:27:03.013916Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191064server # [ 10.328465] horae[758]: 2026-11-06T19:27:03.013926Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191065server # [ 10.329778] horae[758]: 2026-11-06T19:27:03.013937Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191066server # [ 10.331087] horae[758]: 2026-11-06T19:27:03.013947Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191067server # [ 10.332343] horae[758]: 2026-11-06T19:27:03.013957Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191068server # [ 10.333599] horae[758]: 2026-11-06T19:27:03.013966Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191069server # [ 10.334897] horae[758]: 2026-11-06T19:27:03.013976Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191070server # [ 10.336958] horae[758]: 2026-11-06T19:27:03.013985Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191071server # [ 10.338203] horae[758]: 2026-11-06T19:27:03.013996Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031072server # [ 10.339591] horae[758]: 2026-11-06T19:27:03.014006Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031073server # [ 10.340919] horae[758]: 2026-11-06T19:27:03.014017Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031074server # [ 10.342225] horae[758]: 2026-11-06T19:27:03.014026Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031075server # [ 10.343535] horae[758]: 2026-11-06T19:27:03.014037Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031076server # [ 10.344871] horae[758]: 2026-11-06T19:27:03.014052Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031077server # [ 10.346144] horae[758]: 2026-11-06T19:27:03.014062Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551078server # [ 10.347434] horae[758]: 2026-11-06T19:27:03.014072Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551079server # [ 10.348721] horae[758]: 2026-11-06T19:27:03.014081Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551080server # [ 10.350023] horae[758]: 2026-11-06T19:27:03.014109Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551081server # [ 10.351303] horae[758]: 2026-11-06T19:27:03.014118Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551082server # [ 10.352634] horae[758]: 2026-11-06T19:27:03.014131Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551083server # [ 10.353922] horae[758]: 2026-11-06T19:27:03.014144Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551084server # [ 10.355189] horae[758]: 2026-11-06T19:27:03.014160Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551085server # [ 10.356418] horae[758]: 2026-11-06T19:27:03.014169Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551086server # [ 10.357624] horae[758]: 2026-11-06T19:27:03.014179Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541087server # [ 10.358898] horae[758]: 2026-11-06T19:27:03.014189Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541088server # [ 10.360183] horae[758]: 2026-11-06T19:27:03.014199Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541089server # [ 10.361821] horae[758]: 2026-11-06T19:27:03.014208Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541090server # [ 10.363154] horae[758]: 2026-11-06T19:27:03.014217Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541091server # [ 10.364419] horae[758]: 2026-11-06T19:27:03.014229Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1092server # [ 10.365590] horae[758]: 2026-11-06T19:27:03.014242Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1093server # [ 10.366771] horae[758]: 2026-11-06T19:27:03.014251Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1094server # [ 10.367955] horae[758]: 2026-11-06T19:27:03.014263Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1095server # [ 10.369097] horae[758]: 2026-11-06T19:27:03.014273Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1096server # [ 10.370260] horae[758]: 2026-11-06T19:27:03.014282Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1097server # [ 10.371406] horae[758]: 2026-11-06T19:27:03.014292Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1098server # [ 10.372555] horae[758]: 2026-11-06T19:27:03.014301Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931099server # [ 10.373880] horae[758]: 2026-11-06T19:27:03.014310Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1100server # [ 10.375072] horae[758]: 2026-11-06T19:27:03.014328Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1101server # [ 10.376485] horae[758]: 2026-11-06T19:27:03.014338Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931102server # [ 10.377800] horae[758]: 2026-11-06T19:27:03.014348Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1103server # [ 10.378981] horae[758]: 2026-11-06T19:27:03.014358Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931104server # [ 10.380289] horae[758]: 2026-11-06T19:27:03.066678Z INFO horae: Listening on 127.0.0.1:30001105server: (finished: waiting for unit postgresql.service, in 2.12 seconds)1106server: waiting for unit dex.service1107server: (finished: waiting for unit dex.service, in 0.01 seconds)1108server: waiting for unit horae.service1109server: (finished: waiting for unit horae.service, in 0.01 seconds)1110server: waiting for TCP port 5556 on localhost1111server # Connection to localhost (127.0.0.1) 5556 port [tcp/freeciv] succeeded!1112server: (finished: waiting for TCP port 5556 on localhost, in 0.02 seconds)1113server: waiting for TCP port 3000 on localhost1114server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1115server: (finished: waiting for TCP port 3000 on localhost, in 0.01 seconds)1116server: must succeed: curl -sf http://127.0.0.1:3000/health | grep -q ok1117server: (finished: must succeed: curl -sf http://127.0.0.1:3000/health | grep -q ok, in 0.02 seconds)1118server: must succeed: curl -sf http://127.0.0.1:5556/dex/.well-known/openid-configuration >/dev/null1119server: (finished: must succeed: curl -sf http://127.0.0.1:5556/dex/.well-known/openid-configuration >/dev/null, in 0.01 seconds)1120server: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae seed1121server # [ 10.739990] sudo[796]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; ENV=DATABASE_URL=postgres:///horae ; COMMAND=/run/current-system/sw/bin/horae seed1122server # [ 10.755698] sudo[796]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1123server # [ 10.800302] sudo[796]: pam_unix(sudo:session): session closed for user horae1124server: (finished: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae seed, in 0.08 seconds)1125server: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member1126server # [ 10.813467] sudo[805]: 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 member1127server # [ 10.828188] sudo[805]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1128server # [ 10.848293] postgres[812]: [812] LOG: could not send data to client: Broken pipe1129server # [ 10.850599] postgres[812]: [812] FATAL: connection to client lost1130server # [ 10.851475] sudo[805]: pam_unix(sudo:session): session closed for user horae1131server: (finished: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member, in 0.05 seconds)1132server: must succeed: curl -s -c /tmp/jar.txt -b /tmp/jar.txt -L http://127.0.0.1:3000/auth/oidc/start -o /dev/null1133server # [ 10.886412] dex[679]: time=2026-11-06T19:27:03.650Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=4f85227a-23dd-4891-bda3-e970fb2865861134server: (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.11 seconds)1135server: must succeed: curl -s -b /tmp/jar.txt http://127.0.0.1:3000/harvest/v2/time_entries1136server: (finished: must succeed: curl -s -b /tmp/jar.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.03 seconds)1137server: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''1138server # [ 11.008347] sudo[824]: 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\''1139server # [ 11.023720] sudo[824]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1140server # [ 11.034809] sudo[824]: pam_unix(sudo:session): session closed for user horae1141server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.04 seconds)1142server: must succeed: dex-id-token horae horae-e2e-secret1143server # [ 11.305609] dex[679]: time=2026-11-06T19:27:04.070Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=7c56450a-1da7-4396-bd97-23813f5a34511144server: (finished: must succeed: dex-id-token horae horae-e2e-secret, in 0.30 seconds)1145server # [ 11.346697] sudo[838]: 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 01a1b254-2db5-7c43-9516-830b9f9507fd --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1146server # [ 11.362036] sudo[838]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1147server # [ 11.376872] postgres[843]: [843] LOG: could not receive data from client: Connection reset by peer1148server # [ 11.378515] sudo[838]: pam_unix(sudo:session): session closed for user horae1149server: must succeed: sudo -u horae psql horae -c "UPDATE users SET active = false WHERE email = 'kilgore@kilgore.trout'"1150server # [ 11.391452] sudo[844]: 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\''1151server # [ 11.405825] sudo[844]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1152server # [ 11.422869] sudo[844]: pam_unix(sudo:session): session closed for user horae1153server: (finished: must succeed: sudo -u horae psql horae -c "UPDATE users SET active = false WHERE email = 'kilgore@kilgore.trout'", in 0.04 seconds)1154server # [ 11.447042] dex[679]: time=2026-11-06T19:27:04.211Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=78583012-cd85-4be2-8d46-b7c1fe69cb561155server # [ 11.456648] horae[758]: 2026-11-06T19:27:04.221453Z WARN call: horae::auth::oidc: OIDC login denied: account is deactivated1156server: must succeed: curl -s -o /dev/null -w '%{http_code}' -b /tmp/jar2.txt http://127.0.0.1:3000/harvest/v2/time_entries1157server: (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.01 seconds)1158server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"''1159server # [ 11.491574] sudo[858]: 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\''1160server # [ 11.506374] sudo[858]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1161server # [ 11.519023] sudo[858]: pam_unix(sudo:session): session closed for user horae1162server: (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.04 seconds)1163server: 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.conf1164server: (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)1165server: must succeed: systemctl daemon-reload && systemctl restart horae.service1166server # [ 11.538221] systemd[1]: Reload requested from client PID 872 ('systemctl') (unit backdoor.service)...1167server # [ 11.539236] systemd[1]: Reloading...1168server # [ 11.695792] systemd[1]: Reloading finished in 155 ms.1169server # [ 11.723931] systemd[1]: Stopping Horae time tracking server...1170server # [ 11.730098] systemd[1]: horae.service: Deactivated successfully.1171server # [ 11.731194] systemd[1]: Stopped Horae time tracking server.1172server # [ 11.731798] systemd[1]: horae.service: Consumed 159ms CPU time over 1.962s wall clock time, 98.8M memory peak, 92.7M read from disk, 16.8K incoming IP traffic, 23.9K outgoing IP traffic.1173server # [ 11.738241] systemd[1]: Starting Horae time tracking server...1174server # [ 11.762412] horae[911]: 2026-11-06T19:27:04.527252Z INFO horae: Running migrations...1175server # [ 11.764602] horae[911]: 2026-11-06T19:27:04.529651Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1176server # [ 11.774205] horae[911]: 2026-11-06T19:27:04.537309Z INFO horae: Migrations complete.1177server # [ 11.775385] postgres[916]: [916] LOG: could not send data to client: Broken pipe1178server # [ 11.776106] postgres[916]: [916] FATAL: connection to client lost1179server # [ 11.778786] systemd[1]: Started Horae time tracking server.1180server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.25 seconds)1181server: waiting for TCP port 3000 on localhost1182server # [ 11.807220] horae[917]: 2026-11-06T19:27:04.572054Z INFO horae: Starting Horae on 127.0.0.1:30001183server # [ 11.813453] horae[917]: 2026-11-06T19:27:04.578497Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1184server # [ 11.821196] horae[917]: 2026-11-06T19:27:04.586236Z INFO horae::plugin::registry: plugins directory does not exist: plugins1185server # [ 11.822875] horae[917]: 2026-11-06T19:27:04.587913Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1186server # [ 11.827069] horae[917]: 2026-11-06T19:27:04.590296Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1187server # [ 11.828275] horae[917]: 2026-11-06T19:27:04.590524Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061188server # [ 11.829598] horae[917]: 2026-11-06T19:27:04.590542Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061189server # [ 11.830905] horae[917]: 2026-11-06T19:27:04.590554Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061190server # [ 11.832223] horae[917]: 2026-11-06T19:27:04.590565Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061191server # [ 11.833490] horae[917]: 2026-11-06T19:27:04.590577Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061192server # [ 11.834796] horae[917]: 2026-11-06T19:27:04.590588Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061193server # [ 11.836100] horae[917]: 2026-11-06T19:27:04.590599Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061194server # [ 11.838965] horae[917]: 2026-11-06T19:27:04.590609Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061195server # [ 11.840300] horae[917]: 2026-11-06T19:27:04.590622Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061196server # [ 11.841567] horae[917]: 2026-11-06T19:27:04.590631Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061197server # [ 11.842837] horae[917]: 2026-11-06T19:27:04.590640Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061198server # [ 11.844076] horae[917]: 2026-11-06T19:27:04.590650Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061199server # [ 11.845344] horae[917]: 2026-11-06T19:27:04.590660Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061200server # [ 11.846550] horae[917]: 2026-11-06T19:27:04.590670Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061201server # [ 11.847774] horae[917]: 2026-11-06T19:27:04.590680Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061202server # [ 11.849030] horae[917]: 2026-11-06T19:27:04.590696Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181203server # [ 11.850304] horae[917]: 2026-11-06T19:27:04.590708Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181204server # [ 11.851567] horae[917]: 2026-11-06T19:27:04.590718Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181205server # [ 11.852857] horae[917]: 2026-11-06T19:27:04.590728Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181206server # [ 11.854121] horae[917]: 2026-11-06T19:27:04.590738Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181207server # [ 11.855372] horae[917]: 2026-11-06T19:27:04.590747Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181208server # [ 11.856607] horae[917]: 2026-11-06T19:27:04.590757Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181209server # [ 11.857870] horae[917]: 2026-11-06T19:27:04.590766Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181210server # [ 11.859111] horae[917]: 2026-11-06T19:27:04.590776Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851211server # [ 11.860729] horae[917]: 2026-11-06T19:27:04.590786Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851212server # [ 11.862114] horae[917]: 2026-11-06T19:27:04.590798Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851213server # [ 11.863393] horae[917]: 2026-11-06T19:27:04.590807Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851214server # [ 11.864647] horae[917]: 2026-11-06T19:27:04.590817Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851215server # [ 11.865894] horae[917]: 2026-11-06T19:27:04.590837Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851216server # [ 11.867129] horae[917]: 2026-11-06T19:27:04.590858Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001217server # [ 11.868344] horae[917]: 2026-11-06T19:27:04.590868Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961218server # [ 11.869576] horae[917]: 2026-11-06T19:27:04.590877Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961219server # [ 11.870815] horae[917]: 2026-11-06T19:27:04.590886Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961220server # [ 11.876074] horae[917]: 2026-11-06T19:27:04.590895Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961221server # [ 11.877354] horae[917]: 2026-11-06T19:27:04.590904Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961222server # [ 11.878589] horae[917]: 2026-11-06T19:27:04.590914Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071223server # [ 11.879799] horae[917]: 2026-11-06T19:27:04.590922Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071224server # [ 11.882252] horae[917]: 2026-11-06T19:27:04.590932Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071225server # [ 11.884338] horae[917]: 2026-11-06T19:27:04.590943Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071226server # [ 11.885635] horae[917]: 2026-11-06T19:27:04.590955Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111227server # [ 11.889095] horae[917]: 2026-11-06T19:27:04.590967Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261228server # [ 11.890410] horae[917]: 2026-11-06T19:27:04.590976Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261229server # [ 11.891644] horae[917]: 2026-11-06T19:27:04.590985Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261230server # [ 11.892867] horae[917]: 2026-11-06T19:27:04.590994Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261231server # [ 11.894108] horae[917]: 2026-11-06T19:27:04.591006Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721232server # [ 11.895358] horae[917]: 2026-11-06T19:27:04.591021Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711233server # [ 11.896624] horae[917]: 2026-11-06T19:27:04.591031Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711234server # [ 11.898420] horae[917]: 2026-11-06T19:27:04.591040Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711235server # [ 11.899722] horae[917]: 2026-11-06T19:27:04.591049Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711236server # [ 11.901941] horae[917]: 2026-11-06T19:27:04.591058Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711237server # [ 11.903211] horae[917]: 2026-11-06T19:27:04.591066Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711238server # [ 11.904505] horae[917]: 2026-11-06T19:27:04.591077Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711239server # [ 11.905809] horae[917]: 2026-11-06T19:27:04.591086Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711240server # [ 11.907068] horae[917]: 2026-11-06T19:27:04.602608Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711241server # [ 11.908288] horae[917]: 2026-11-06T19:27:04.602621Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341242server # [ 11.909581] horae[917]: 2026-11-06T19:27:04.602631Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341243server # [ 11.910958] horae[917]: 2026-11-06T19:27:04.602652Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191244server # [ 11.912249] horae[917]: 2026-11-06T19:27:04.602686Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191245server # [ 11.913530] horae[917]: 2026-11-06T19:27:04.602696Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191246server # [ 11.914821] horae[917]: 2026-11-06T19:27:04.602706Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191247server # [ 11.916108] horae[917]: 2026-11-06T19:27:04.602716Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191248server # [ 11.917384] horae[917]: 2026-11-06T19:27:04.602725Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191249server # [ 11.918739] horae[917]: 2026-11-06T19:27:04.602735Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191250server # [ 11.920020] horae[917]: 2026-11-06T19:27:04.602745Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191251server # [ 11.921324] horae[917]: 2026-11-06T19:27:04.602754Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191252server # [ 11.923589] horae[917]: 2026-11-06T19:27:04.602763Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191253server # [ 11.924922] horae[917]: 2026-11-06T19:27:04.602772Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191254server # [ 11.926175] horae[917]: 2026-11-06T19:27:04.602784Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031255server # [ 11.927550] horae[917]: 2026-11-06T19:27:04.602793Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031256server # [ 11.928859] horae[917]: 2026-11-06T19:27:04.602803Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031257server # [ 11.930225] horae[917]: 2026-11-06T19:27:04.602813Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031258server # [ 11.931509] horae[917]: 2026-11-06T19:27:04.602826Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031259server # [ 11.932807] horae[917]: 2026-11-06T19:27:04.602836Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031260server # [ 11.934110] horae[917]: 2026-11-06T19:27:04.602846Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551261server # [ 11.935404] horae[917]: 2026-11-06T19:27:04.602856Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551262server # [ 11.936694] horae[917]: 2026-11-06T19:27:04.602865Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551263server # [ 11.937984] horae[917]: 2026-11-06T19:27:04.602875Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551264server # [ 11.939291] horae[917]: 2026-11-06T19:27:04.602883Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551265server # [ 11.940570] horae[917]: 2026-11-06T19:27:04.602892Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551266server # [ 11.941838] horae[917]: 2026-11-06T19:27:04.602902Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551267server # [ 11.943102] horae[917]: 2026-11-06T19:27:04.602912Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551268server # [ 11.944300] horae[917]: 2026-11-06T19:27:04.602921Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551269server # [ 11.945492] horae[917]: 2026-11-06T19:27:04.602931Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541270server # [ 11.946757] horae[917]: 2026-11-06T19:27:04.602941Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541271server # [ 11.948031] horae[917]: 2026-11-06T19:27:04.602951Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541272server # [ 11.949278] horae[917]: 2026-11-06T19:27:04.602960Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541273server # [ 11.950513] horae[917]: 2026-11-06T19:27:04.602969Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541274server # [ 11.951744] horae[917]: 2026-11-06T19:27:04.602977Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1275server # [ 11.952918] horae[917]: 2026-11-06T19:27:04.602986Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1276server # [ 11.954083] horae[917]: 2026-11-06T19:27:04.602995Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1277server # [ 11.955270] horae[917]: 2026-11-06T19:27:04.603006Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1278server # [ 11.956470] horae[917]: 2026-11-06T19:27:04.603017Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1279server # [ 11.957602] horae[917]: 2026-11-06T19:27:04.603025Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1280server # [ 11.958757] horae[917]: 2026-11-06T19:27:04.603034Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1281server # [ 11.959914] horae[917]: 2026-11-06T19:27:04.603042Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931282server # [ 11.961186] horae[917]: 2026-11-06T19:27:04.603052Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1283server # [ 11.962339] horae[917]: 2026-11-06T19:27:04.603063Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1284server # [ 11.963544] horae[917]: 2026-11-06T19:27:04.603072Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931285server # [ 11.964866] horae[917]: 2026-11-06T19:27:04.603082Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1286server # [ 11.966069] horae[917]: 2026-11-06T19:27:04.603111Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931287server # [ 11.967319] horae[917]: 2026-11-06T19:27:04.639611Z INFO horae: Listening on 127.0.0.1:30001288server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1289server: (finished: waiting for TCP port 3000 on localhost, in 1.03 seconds)1290server: must succeed: dex-id-token horae-omit-email-verified horae-omit-e2e-secret1291server # [ 12.973693] dex[679]: time=2026-11-06T19:27:05.738Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=16caf387-d9b6-4e73-ae1c-db72fb2709e41292server: (finished: must succeed: dex-id-token horae-omit-email-verified horae-omit-e2e-secret, in 0.19 seconds)1293server: 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/null1294server # [ 13.022079] dex[679]: time=2026-11-06T19:27:05.787Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=9b00c1f3-f771-49d4-9586-1d9c37e39a231295server # [ 13.034811] horae[917]: 2026-11-06T19:27:05.799221Z WARN call: horae::auth::oidc: OIDC login denied: no account for subject/email1296server: (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.04 seconds)1297server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar3.txt http://127.0.0.1:3000/harvest/v2/time_entries1298server: (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.01 seconds)1299server: 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'"'"''1300server # [ 13.065478] sudo[944]: 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\''1301server # [ 13.080597] sudo[944]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1302server # [ 13.092095] sudo[944]: pam_unix(sudo:session): session closed for user horae1303server: (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.04 seconds)1304server # [ 13.106683] sudo[955]: 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 01a1b254-2db5-7c43-9516-830b9f9507fd --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1305server # [ 13.124373] sudo[955]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1306server # [ 13.142978] sudo[955]: pam_unix(sudo:session): session closed for user horae1307server # [ 13.162443] sudo[965]: 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 01a1b254-2db5-7c43-9516-830b9f9507fd --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1308server # [ 13.188308] sudo[965]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1309server # [ 13.203757] postgres[970]: [970] LOG: could not receive data from client: Connection reset by peer1310server # [ 13.205218] sudo[965]: pam_unix(sudo:session): session closed for user horae1311server # [ 13.219245] sudo[975]: 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 member1312server # [ 13.233273] sudo[975]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1313server # [ 13.249319] postgres[980]: [980] LOG: could not receive data from client: Connection reset by peer1314server # [ 13.251425] sudo[975]: pam_unix(sudo:session): session closed for user horae1315server: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'other@kilgore.trout'"'"''1316server # [ 13.265249] sudo[981]: 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\''1317server # [ 13.278982] sudo[981]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1318server # [ 13.289103] sudo[981]: pam_unix(sudo:session): session closed for user horae1319server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'other@kilgore.trout'"'"'', in 0.04 seconds)1320server # [ 13.302763] sudo[992]: 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 01a1b254-371b-7843-b665-460979c704af --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1321server # [ 13.317680] sudo[992]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1322server # [ 13.330255] postgres[997]: [997] LOG: could not receive data from client: Connection reset by peer1323server # [ 13.333428] sudo[992]: pam_unix(sudo:session): session closed for user horae1324server: 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/null1325server # [ 13.353354] dex[679]: time=2026-11-06T19:27:06.118Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=11e2671e-48e7-4fbe-8044-fd39c8ff1a841326server: (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.04 seconds)1327server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar4.txt http://127.0.0.1:3000/harvest/v2/time_entries1328server: (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.03 seconds)1329server: 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'"'"''1330server # [ 13.414468] sudo[1004]: 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\''1331server # [ 13.429180] sudo[1004]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1332server # [ 13.440535] sudo[1004]: pam_unix(sudo:session): session closed for user horae1333server: (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.04 seconds)1334server: 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.conf1335server: (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)1336server: must succeed: systemctl daemon-reload && systemctl restart horae.service1337server # [ 13.459231] systemd[1]: Reload requested from client PID 1018 ('systemctl') (unit backdoor.service)...1338server # [ 13.460194] systemd[1]: Reloading...1339server # [ 13.603877] systemd[1]: Reloading finished in 145 ms.1340server # [ 13.635355] systemd[1]: Stopping Horae time tracking server...1341server # [ 13.638765] systemd[1]: horae.service: Deactivated successfully.1342server # [ 13.643635] systemd[1]: Stopped Horae time tracking server.1343server # [ 13.644306] systemd[1]: horae.service: Consumed 53ms CPU time over 1.900s wall clock time, 5.7M memory peak, 16.3K incoming IP traffic, 23.6K outgoing IP traffic.1344server # [ 13.651345] systemd[1]: Starting Horae time tracking server...1345server # [ 13.676955] horae[1057]: 2026-11-06T19:27:06.441715Z INFO horae: Running migrations...1346server # [ 13.679621] horae[1057]: 2026-11-06T19:27:06.444627Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1347server # [ 13.687743] horae[1057]: 2026-11-06T19:27:06.452725Z INFO horae: Migrations complete.1348server # [ 13.692881] systemd[1]: Started Horae time tracking server.1349server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.25 seconds)1350server: waiting for TCP port 3000 on localhost1351server # [ 13.726899] horae[1063]: 2026-11-06T19:27:06.491660Z INFO horae: Starting Horae on 127.0.0.1:30001352server # [ 13.733751] horae[1063]: 2026-11-06T19:27:06.498759Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1353server # [ 13.741679] horae[1063]: 2026-11-06T19:27:06.506612Z INFO horae::plugin::registry: plugins directory does not exist: plugins1354server # [ 13.743438] horae[1063]: 2026-11-06T19:27:06.508350Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1355server # [ 13.748088] horae[1063]: 2026-11-06T19:27:06.510666Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1356server # [ 13.749409] horae[1063]: 2026-11-06T19:27:06.510883Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061357server # [ 13.750912] horae[1063]: 2026-11-06T19:27:06.510906Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061358server # [ 13.752245] horae[1063]: 2026-11-06T19:27:06.510917Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061359server # [ 13.753551] horae[1063]: 2026-11-06T19:27:06.510928Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061360server # [ 13.754843] horae[1063]: 2026-11-06T19:27:06.510940Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061361server # [ 13.756112] horae[1063]: 2026-11-06T19:27:06.510954Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061362server # [ 13.757481] horae[1063]: 2026-11-06T19:27:06.510968Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061363server # [ 13.758836] horae[1063]: 2026-11-06T19:27:06.510980Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061364server # [ 13.760100] horae[1063]: 2026-11-06T19:27:06.510994Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061365server # [ 13.761350] horae[1063]: 2026-11-06T19:27:06.511003Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061366server # [ 13.762591] horae[1063]: 2026-11-06T19:27:06.511012Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061367server # [ 13.764097] horae[1063]: 2026-11-06T19:27:06.511022Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061368server # [ 13.765357] horae[1063]: 2026-11-06T19:27:06.511031Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061369server # [ 13.766573] horae[1063]: 2026-11-06T19:27:06.511041Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061370server # [ 13.767789] horae[1063]: 2026-11-06T19:27:06.511051Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061371server # [ 13.770272] horae[1063]: 2026-11-06T19:27:06.511067Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181372server # [ 13.771570] horae[1063]: 2026-11-06T19:27:06.511077Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181373server # [ 13.773019] horae[1063]: 2026-11-06T19:27:06.511110Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181374server # [ 13.774396] horae[1063]: 2026-11-06T19:27:06.511119Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181375server # [ 13.775820] horae[1063]: 2026-11-06T19:27:06.511128Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181376server # [ 13.777210] horae[1063]: 2026-11-06T19:27:06.511138Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181377server # [ 13.778794] horae[1063]: 2026-11-06T19:27:06.511147Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181378server # [ 13.780161] horae[1063]: 2026-11-06T19:27:06.511156Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181379server # [ 13.781461] horae[1063]: 2026-11-06T19:27:06.511166Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851380server # [ 13.782908] horae[1063]: 2026-11-06T19:27:06.511175Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851381server # [ 13.784376] horae[1063]: 2026-11-06T19:27:06.511186Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851382server # [ 13.788119] horae[1063]: 2026-11-06T19:27:06.511195Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851383server # [ 13.790692] horae[1063]: 2026-11-06T19:27:06.511205Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851384server # [ 13.792116] horae[1063]: 2026-11-06T19:27:06.511220Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851385server # [ 13.793429] horae[1063]: 2026-11-06T19:27:06.511241Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001386server # [ 13.794771] horae[1063]: 2026-11-06T19:27:06.511251Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961387server # [ 13.796114] horae[1063]: 2026-11-06T19:27:06.511260Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961388server # [ 13.797455] horae[1063]: 2026-11-06T19:27:06.511269Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961389server # [ 13.798780] horae[1063]: 2026-11-06T19:27:06.511278Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961390server # [ 13.801691] horae[1063]: 2026-11-06T19:27:06.511286Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961391server # [ 13.803756] horae[1063]: 2026-11-06T19:27:06.511297Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071392server # [ 13.806090] horae[1063]: 2026-11-06T19:27:06.511306Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071393server # [ 13.807508] horae[1063]: 2026-11-06T19:27:06.511315Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071394server # [ 13.808925] horae[1063]: 2026-11-06T19:27:06.511324Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071395server # [ 13.810285] horae[1063]: 2026-11-06T19:27:06.511333Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111396server # [ 13.811792] horae[1063]: 2026-11-06T19:27:06.511343Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261397server # [ 13.813145] horae[1063]: 2026-11-06T19:27:06.511353Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261398server # [ 13.814468] horae[1063]: 2026-11-06T19:27:06.511362Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261399server # [ 13.815784] horae[1063]: 2026-11-06T19:27:06.511370Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261400server # [ 13.817121] horae[1063]: 2026-11-06T19:27:06.511383Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721401server # [ 13.818445] horae[1063]: 2026-11-06T19:27:06.511393Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711402server # [ 13.819823] horae[1063]: 2026-11-06T19:27:06.511402Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711403server # [ 13.821189] horae[1063]: 2026-11-06T19:27:06.511411Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711404server # [ 13.823466] horae[1063]: 2026-11-06T19:27:06.511420Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711405server # [ 13.824880] horae[1063]: 2026-11-06T19:27:06.511429Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711406server # [ 13.826916] horae[1063]: 2026-11-06T19:27:06.511439Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711407server # [ 13.828366] horae[1063]: 2026-11-06T19:27:06.511450Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711408server # [ 13.831102] horae[1063]: 2026-11-06T19:27:06.511459Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711409server # [ 13.832477] horae[1063]: 2026-11-06T19:27:06.511468Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711410server # [ 13.833973] horae[1063]: 2026-11-06T19:27:06.511477Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341411server # [ 13.835328] horae[1063]: 2026-11-06T19:27:06.511487Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341412server # [ 13.836701] horae[1063]: 2026-11-06T19:27:06.511501Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191413server # [ 13.838095] horae[1063]: 2026-11-06T19:27:06.511532Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191414server # [ 13.839448] horae[1063]: 2026-11-06T19:27:06.511542Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191415server # [ 13.842307] horae[1063]: 2026-11-06T19:27:06.511551Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191416server # [ 13.843926] horae[1063]: 2026-11-06T19:27:06.511560Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191417server # [ 13.848355] horae[1063]: 2026-11-06T19:27:06.511570Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191418server # [ 13.850135] horae[1063]: 2026-11-06T19:27:06.511579Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191419server # [ 13.853134] horae[1063]: 2026-11-06T19:27:06.511588Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191420server # [ 13.855280] dhcpcd[659]: eth0: leased 10.0.2.15 for 86400 seconds1421server # [ 13.858212] horae[1063]: 2026-11-06T19:27:06.511598Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191422server # [ 13.861221] horae[1063]: 2026-11-06T19:27:06.511606Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191423server # [ 13.863074] horae[1063]: 2026-11-06T19:27:06.511618Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191424server # [ 13.864790] horae[1063]: 2026-11-06T19:27:06.511627Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031425server # [ 13.867255] horae[1063]: 2026-11-06T19:27:06.511636Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031426server # [ 13.868792] horae[1063]: 2026-11-06T19:27:06.511646Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031427server # [ 13.870403] horae[1063]: 2026-11-06T19:27:06.511655Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031428server # [ 13.872294] horae[1063]: 2026-11-06T19:27:06.511665Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031429server # [ 13.874968] horae[1063]: 2026-11-06T19:27:06.511674Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031430server # [ 13.876900] horae[1063]: 2026-11-06T19:27:06.511683Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551431server # [ 13.880164] horae[1063]: 2026-11-06T19:27:06.511693Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551432server # [ 13.882123] horae[1063]: 2026-11-06T19:27:06.511704Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551433server # [ 13.883957] horae[1063]: 2026-11-06T19:27:06.511712Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551434server # [ 13.885899] dhcpcd[659]: eth0: adding route to 10.0.2.0/241435server # [ 13.888184] horae[1063]: 2026-11-06T19:27:06.511721Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551436server # [ 13.890476] horae[1063]: 2026-11-06T19:27:06.511730Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551437server # [ 13.892793] horae[1063]: 2026-11-06T19:27:06.511740Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551438server # [ 13.894650] horae[1063]: 2026-11-06T19:27:06.511749Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551439server # [ 13.897242] horae[1063]: 2026-11-06T19:27:06.511757Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551440server # [ 13.899069] horae[1063]: 2026-11-06T19:27:06.511767Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541441server # [ 13.900935] horae[1063]: 2026-11-06T19:27:06.511777Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541442server # [ 13.902846] horae[1063]: 2026-11-06T19:27:06.511786Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541443server # [ 13.904647] horae[1063]: 2026-11-06T19:27:06.511795Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541444server # [ 13.908910] horae[1063]: 2026-11-06T19:27:06.511804Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541445server # [ 13.910737] horae[1063]: 2026-11-06T19:27:06.511814Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1446server # [ 13.912320] horae[1063]: 2026-11-06T19:27:06.511827Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1447server # [ 13.914090] horae[1063]: 2026-11-06T19:27:06.511837Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1448server # [ 13.915951] horae[1063]: 2026-11-06T19:27:06.511848Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1449server # [ 13.918165] dhcpcd[659]: eth0: adding default route via 10.0.2.21450server # [ 13.920123] horae[1063]: 2026-11-06T19:27:06.511859Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1451server # [ 13.921887] horae[1063]: 2026-11-06T19:27:06.511868Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1452server # [ 13.923603] horae[1063]: 2026-11-06T19:27:06.511877Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1453server # [ 13.925338] horae[1063]: 2026-11-06T19:27:06.511885Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931454server # [ 13.927168] horae[1063]: 2026-11-06T19:27:06.511894Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1455server # [ 13.928884] horae[1063]: 2026-11-06T19:27:06.511905Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1456server # [ 13.930941] horae[1063]: 2026-11-06T19:27:06.511914Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931457server # [ 13.932856] horae[1063]: 2026-11-06T19:27:06.511924Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1458server # [ 13.935118] horae[1063]: 2026-11-06T19:27:06.511934Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931459server # [ 13.937057] horae[1063]: 2026-11-06T19:27:06.555621Z INFO horae: Listening on 127.0.0.1:30001460server # [ 13.985929] systemd[1]: Started DHCP Client.1461server # [ 13.988996] systemd[1]: Reached target Multi-User System.1462server # [ 13.990385] systemd[1]: Startup finished in 805ms (kernel) + 4.100s (initrd) + 9.083s (userspace) = 13.990s.1463server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1464server: (finished: waiting for TCP port 3000 on localhost, in 1.04 seconds)1465server: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1466server # [ 14.753781] dex[679]: time=2026-11-06T19:27:07.518Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=6204734a-4acf-4376-9466-7d3a633846981467server # [ 14.767711] horae[1063]: 2026-11-06T19:27:07.532292Z WARN call: horae::auth::oidc: OIDC login denied: no account for subject/email1468server: (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.04 seconds)1469server: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt http://127.0.0.1:3000/auth/login1470server: (finished: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt http://127.0.0.1:3000/auth/login, in 0.01 seconds)1471server: 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'1472server # [ 14.800295] sudo[1135]: 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'1473server # [ 14.815599] sudo[1135]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1474server # [ 14.826502] sudo[1135]: pam_unix(sudo:session): session closed for user horae1475server: (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.04 seconds)1476server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1477server # [ 14.838965] sudo[1142]: 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\''1478server # [ 14.853772] sudo[1142]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1479server # [ 14.865910] sudo[1142]: pam_unix(sudo:session): session closed for user horae1480server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.04 seconds)1481server: 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.conf1482server: (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)1483server: must succeed: systemctl daemon-reload && systemctl restart horae.service1484server # [ 14.884165] systemd[1]: Reload requested from client PID 1156 ('systemctl') (unit backdoor.service)...1485server # [ 14.885205] systemd[1]: Reloading...1486server # [ 15.038654] systemd[1]: Reloading finished in 152 ms.1487server # [ 15.068729] systemd[1]: Stopping Horae time tracking server...1488server # [ 15.075439] systemd[1]: horae.service: Deactivated successfully.1489server # [ 15.078069] systemd[1]: Stopped Horae time tracking server.1490server # [ 15.078658] systemd[1]: horae.service: Consumed 50ms CPU time over 1.422s wall clock time, 5.4M memory peak, 8.2K incoming IP traffic, 17.6K outgoing IP traffic.1491server # [ 15.084171] systemd[1]: Starting Horae time tracking server...1492server # [ 15.109224] horae[1194]: 2026-11-06T19:27:07.874005Z INFO horae: Running migrations...1493server # [ 15.111717] horae[1194]: 2026-11-06T19:27:07.876374Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1494server # [ 15.121217] horae[1194]: 2026-11-06T19:27:07.884119Z INFO horae: Migrations complete.1495server # [ 15.122460] postgres[1199]: [1199] LOG: could not send data to client: Broken pipe1496server # [ 15.123178] postgres[1199]: [1199] FATAL: connection to client lost1497server # [ 15.126065] systemd[1]: Started Horae time tracking server.1498server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.25 seconds)1499server: waiting for TCP port 3000 on localhost1500server # [ 15.156217] horae[1200]: 2026-11-06T19:27:07.921026Z INFO horae: Starting Horae on 127.0.0.1:30001501server # [ 15.162749] horae[1200]: 2026-11-06T19:27:07.927774Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1502server # [ 15.170731] horae[1200]: 2026-11-06T19:27:07.935762Z INFO horae::plugin::registry: plugins directory does not exist: plugins1503server # [ 15.172576] horae[1200]: 2026-11-06T19:27:07.937629Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1504server # [ 15.177073] horae[1200]: 2026-11-06T19:27:07.939940Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1505server # [ 15.178310] horae[1200]: 2026-11-06T19:27:07.940180Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061506server # [ 15.179674] horae[1200]: 2026-11-06T19:27:07.940203Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061507server # [ 15.180991] horae[1200]: 2026-11-06T19:27:07.940216Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061508server # [ 15.182304] horae[1200]: 2026-11-06T19:27:07.940227Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061509server # [ 15.183494] horae[1200]: 2026-11-06T19:27:07.940240Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061510server # [ 15.184779] horae[1200]: 2026-11-06T19:27:07.940251Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061511server # [ 15.186073] horae[1200]: 2026-11-06T19:27:07.940262Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061512server # [ 15.187337] horae[1200]: 2026-11-06T19:27:07.940275Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061513server # [ 15.188601] horae[1200]: 2026-11-06T19:27:07.940292Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061514server # [ 15.189901] horae[1200]: 2026-11-06T19:27:07.940302Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061515server # [ 15.191181] horae[1200]: 2026-11-06T19:27:07.940311Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061516server # [ 15.193080] horae[1200]: 2026-11-06T19:27:07.940323Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061517server # [ 15.194414] horae[1200]: 2026-11-06T19:27:07.940335Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061518server # [ 15.195619] horae[1200]: 2026-11-06T19:27:07.940344Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061519server # [ 15.196911] horae[1200]: 2026-11-06T19:27:07.940354Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061520server # [ 15.198390] horae[1200]: 2026-11-06T19:27:07.940371Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181521server # [ 15.199656] horae[1200]: 2026-11-06T19:27:07.940381Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181522server # [ 15.200980] horae[1200]: 2026-11-06T19:27:07.940391Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181523server # [ 15.202262] horae[1200]: 2026-11-06T19:27:07.940400Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181524server # [ 15.203509] horae[1200]: 2026-11-06T19:27:07.940411Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181525server # [ 15.204755] horae[1200]: 2026-11-06T19:27:07.940423Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181526server # [ 15.205978] horae[1200]: 2026-11-06T19:27:07.940432Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181527server # [ 15.207179] horae[1200]: 2026-11-06T19:27:07.940440Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181528server # [ 15.210119] horae[1200]: 2026-11-06T19:27:07.940450Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851529server # [ 15.211505] horae[1200]: 2026-11-06T19:27:07.940460Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851530server # [ 15.212922] horae[1200]: 2026-11-06T19:27:07.940472Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851531server # [ 15.214201] horae[1200]: 2026-11-06T19:27:07.940482Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851532server # [ 15.215450] horae[1200]: 2026-11-06T19:27:07.940491Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851533server # [ 15.216685] horae[1200]: 2026-11-06T19:27:07.940507Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851534server # [ 15.217900] horae[1200]: 2026-11-06T19:27:07.940528Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001535server # [ 15.219119] horae[1200]: 2026-11-06T19:27:07.940537Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961536server # [ 15.224022] horae[1200]: 2026-11-06T19:27:07.940547Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961537server # [ 15.225324] horae[1200]: 2026-11-06T19:27:07.940558Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961538server # [ 15.226895] horae[1200]: 2026-11-06T19:27:07.940570Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961539server # [ 15.228834] horae[1200]: 2026-11-06T19:27:07.940581Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961540server # [ 15.230113] horae[1200]: 2026-11-06T19:27:07.940591Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071541server # [ 15.231307] horae[1200]: 2026-11-06T19:27:07.940601Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071542server # [ 15.232577] horae[1200]: 2026-11-06T19:27:07.940610Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071543server # [ 15.235879] horae[1200]: 2026-11-06T19:27:07.940619Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071544server # [ 15.237198] horae[1200]: 2026-11-06T19:27:07.940631Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111545server # [ 15.238498] horae[1200]: 2026-11-06T19:27:07.940644Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261546server # [ 15.239803] horae[1200]: 2026-11-06T19:27:07.940654Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261547server # [ 15.241087] horae[1200]: 2026-11-06T19:27:07.940663Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261548server # [ 15.242348] horae[1200]: 2026-11-06T19:27:07.940673Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261549server # [ 15.243590] horae[1200]: 2026-11-06T19:27:07.940686Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721550server # [ 15.244917] horae[1200]: 2026-11-06T19:27:07.940697Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711551server # [ 15.249040] horae[1200]: 2026-11-06T19:27:07.940707Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711552server # [ 15.250348] horae[1200]: 2026-11-06T19:27:07.940716Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711553server # [ 15.251626] horae[1200]: 2026-11-06T19:27:07.940725Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711554server # [ 15.252913] horae[1200]: 2026-11-06T19:27:07.940734Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711555server # [ 15.254164] horae[1200]: 2026-11-06T19:27:07.940746Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711556server # [ 15.255477] horae[1200]: 2026-11-06T19:27:07.940757Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711557server # [ 15.256759] horae[1200]: 2026-11-06T19:27:07.940766Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711558server # [ 15.257991] horae[1200]: 2026-11-06T19:27:07.940775Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711559server # [ 15.259995] horae[1200]: 2026-11-06T19:27:07.940786Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341560server # [ 15.261318] horae[1200]: 2026-11-06T19:27:07.940795Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341561server # [ 15.262614] horae[1200]: 2026-11-06T19:27:07.940810Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191562server # [ 15.263917] horae[1200]: 2026-11-06T19:27:07.940849Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191563server # [ 15.265205] horae[1200]: 2026-11-06T19:27:07.940859Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191564server # [ 15.266507] horae[1200]: 2026-11-06T19:27:07.940869Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191565server # [ 15.267794] horae[1200]: 2026-11-06T19:27:07.940879Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191566server # [ 15.269075] horae[1200]: 2026-11-06T19:27:07.940889Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191567server # [ 15.272154] horae[1200]: 2026-11-06T19:27:07.940899Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191568server # [ 15.273440] horae[1200]: 2026-11-06T19:27:07.940908Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191569server # [ 15.274829] horae[1200]: 2026-11-06T19:27:07.940918Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191570server # [ 15.276127] horae[1200]: 2026-11-06T19:27:07.940927Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191571server # [ 15.277439] horae[1200]: 2026-11-06T19:27:07.940936Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191572server # [ 15.278746] horae[1200]: 2026-11-06T19:27:07.940946Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031573server # [ 15.280122] horae[1200]: 2026-11-06T19:27:07.940956Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031574server # [ 15.283195] horae[1200]: 2026-11-06T19:27:07.940966Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031575server # [ 15.285063] horae[1200]: 2026-11-06T19:27:07.940976Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031576server # [ 15.286377] horae[1200]: 2026-11-06T19:27:07.940986Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031577server # [ 15.287679] horae[1200]: 2026-11-06T19:27:07.940995Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031578server # [ 15.289027] horae[1200]: 2026-11-06T19:27:07.941005Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551579server # [ 15.290329] horae[1200]: 2026-11-06T19:27:07.941015Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551580server # [ 15.291621] horae[1200]: 2026-11-06T19:27:07.941025Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551581server # [ 15.292911] horae[1200]: 2026-11-06T19:27:07.941034Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551582server # [ 15.294474] horae[1200]: 2026-11-06T19:27:07.941043Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551583server # [ 15.296237] horae[1200]: 2026-11-06T19:27:07.941053Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551584server # [ 15.297976] horae[1200]: 2026-11-06T19:27:07.941063Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551585server # [ 15.299351] horae[1200]: 2026-11-06T19:27:07.941073Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551586server # [ 15.300575] horae[1200]: 2026-11-06T19:27:07.941082Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551587server # [ 15.301833] horae[1200]: 2026-11-06T19:27:07.957591Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541588server # [ 15.303111] horae[1200]: 2026-11-06T19:27:07.957620Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541589server # [ 15.304380] horae[1200]: 2026-11-06T19:27:07.957630Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541590server # [ 15.305644] horae[1200]: 2026-11-06T19:27:07.957640Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541591server # [ 15.306876] horae[1200]: 2026-11-06T19:27:07.957650Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541592server # [ 15.308144] horae[1200]: 2026-11-06T19:27:07.957665Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1593server # [ 15.309327] horae[1200]: 2026-11-06T19:27:07.957674Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1594server # [ 15.310500] horae[1200]: 2026-11-06T19:27:07.957684Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1595server # [ 15.311730] horae[1200]: 2026-11-06T19:27:07.957695Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1596server # [ 15.312953] horae[1200]: 2026-11-06T19:27:07.957705Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1597server # [ 15.314115] horae[1200]: 2026-11-06T19:27:07.957714Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1598server # [ 15.315287] horae[1200]: 2026-11-06T19:27:07.957724Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1599server # [ 15.316464] horae[1200]: 2026-11-06T19:27:07.957733Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931600server # [ 15.317770] horae[1200]: 2026-11-06T19:27:07.957746Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1601server # [ 15.318932] horae[1200]: 2026-11-06T19:27:07.957755Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1602server # [ 15.320135] horae[1200]: 2026-11-06T19:27:07.957765Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931603server # [ 15.321441] horae[1200]: 2026-11-06T19:27:07.957775Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1604server # [ 15.322693] horae[1200]: 2026-11-06T19:27:07.957785Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931605server # [ 15.323952] horae[1200]: 2026-11-06T19:27:07.993256Z INFO horae: Listening on 127.0.0.1:30001606server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1607server: (finished: waiting for TCP port 3000 on localhost, in 1.04 seconds)1608server: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1609server # [ 16.184573] dex[679]: time=2026-11-06T19:27:08.948Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=414ca6c3-3714-4e24-ba3d-95a2f8aebd631610server # [ 16.201358] horae[1200]: 2026-11-06T19:27:08.966025Z WARN call: horae::auth::oidc: OIDC login denied: no account, and the email's domain is not listed1611server: (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.04 seconds)1612server: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt http://127.0.0.1:3000/auth/login1613server: (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)1614server: 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'1615server # [ 16.237404] sudo[1225]: 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'1616server # [ 16.252136] sudo[1225]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1617server # [ 16.262073] sudo[1225]: pam_unix(sudo:session): session closed for user horae1618server: (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.04 seconds)1619server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1620server # [ 16.275805] sudo[1232]: 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\''1621server # [ 16.290870] sudo[1232]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1622server # [ 16.303284] sudo[1232]: pam_unix(sudo:session): session closed for user horae1623server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.04 seconds)1624server: 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.conf1625server: (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)1626server: must succeed: systemctl daemon-reload && systemctl restart horae.service1627server # [ 16.321322] systemd[1]: Reload requested from client PID 1246 ('systemctl') (unit backdoor.service)...1628server # [ 16.323138] systemd[1]: Reloading...1629server # [ 16.470934] systemd[1]: Reloading finished in 148 ms.1630server # [ 16.502274] systemd[1]: Stopping Horae time tracking server...1631server # [ 16.507503] systemd[1]: horae.service: Deactivated successfully.1632server # [ 16.511100] systemd[1]: Stopped Horae time tracking server.1633server # [ 16.511691] systemd[1]: horae.service: Consumed 48ms CPU time over 1.421s wall clock time, 5.4M memory peak, 8.2K incoming IP traffic, 17.7K outgoing IP traffic.1634server # [ 16.519500] systemd[1]: Starting Horae time tracking server...1635server # [ 16.545405] horae[1284]: 2026-11-06T19:27:09.310212Z INFO horae: Running migrations...1636server # [ 16.547553] horae[1284]: 2026-11-06T19:27:09.312594Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1637server # [ 16.558929] horae[1284]: 2026-11-06T19:27:09.321073Z INFO horae: Migrations complete.1638server # [ 16.561746] systemd[1]: Started Horae time tracking server.1639server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.25 seconds)1640server: waiting for TCP port 3000 on localhost1641server # [ 16.593375] horae[1290]: 2026-11-06T19:27:09.358197Z INFO horae: Starting Horae on 127.0.0.1:30001642server # [ 16.599897] horae[1290]: 2026-11-06T19:27:09.364940Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1643server # [ 16.607962] horae[1290]: 2026-11-06T19:27:09.372993Z INFO horae::plugin::registry: plugins directory does not exist: plugins1644server # [ 16.610917] horae[1290]: 2026-11-06T19:27:09.375708Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1645server # [ 16.612197] horae[1290]: 2026-11-06T19:27:09.375901Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1646server # [ 16.616067] horae[1290]: 2026-11-06T19:27:09.378757Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061647server # [ 16.617469] horae[1290]: 2026-11-06T19:27:09.378779Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061648server # [ 16.618773] horae[1290]: 2026-11-06T19:27:09.378791Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061649server # [ 16.620163] horae[1290]: 2026-11-06T19:27:09.378804Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061650server # [ 16.621644] horae[1290]: 2026-11-06T19:27:09.378818Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061651server # [ 16.622983] horae[1290]: 2026-11-06T19:27:09.378834Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061652server # [ 16.624324] horae[1290]: 2026-11-06T19:27:09.378845Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061653server # [ 16.625637] horae[1290]: 2026-11-06T19:27:09.378857Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061654server # [ 16.626918] horae[1290]: 2026-11-06T19:27:09.378873Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061655server # [ 16.628244] horae[1290]: 2026-11-06T19:27:09.378882Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061656server # [ 16.629818] horae[1290]: 2026-11-06T19:27:09.378892Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061657server # [ 16.631072] horae[1290]: 2026-11-06T19:27:09.378902Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061658server # [ 16.632506] horae[1290]: 2026-11-06T19:27:09.378913Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061659server # [ 16.633788] horae[1290]: 2026-11-06T19:27:09.378922Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061660server # [ 16.634995] horae[1290]: 2026-11-06T19:27:09.378932Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061661server # [ 16.636258] horae[1290]: 2026-11-06T19:27:09.378950Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181662server # [ 16.637728] horae[1290]: 2026-11-06T19:27:09.378963Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181663server # [ 16.639029] horae[1290]: 2026-11-06T19:27:09.378975Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181664server # [ 16.640289] horae[1290]: 2026-11-06T19:27:09.378988Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181665server # [ 16.641586] horae[1290]: 2026-11-06T19:27:09.379001Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181666server # [ 16.645125] horae[1290]: 2026-11-06T19:27:09.379013Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181667server # [ 16.646429] horae[1290]: 2026-11-06T19:27:09.379022Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181668server # [ 16.647693] horae[1290]: 2026-11-06T19:27:09.379032Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181669server # [ 16.648924] horae[1290]: 2026-11-06T19:27:09.379043Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851670server # [ 16.650253] horae[1290]: 2026-11-06T19:27:09.379052Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851671server # [ 16.651608] horae[1290]: 2026-11-06T19:27:09.379064Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851672server # [ 16.652962] horae[1290]: 2026-11-06T19:27:09.379074Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851673server # [ 16.657053] horae[1290]: 2026-11-06T19:27:09.379083Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851674server # [ 16.658312] horae[1290]: 2026-11-06T19:27:09.379117Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851675server # [ 16.659550] horae[1290]: 2026-11-06T19:27:09.379144Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001676server # [ 16.660831] horae[1290]: 2026-11-06T19:27:09.379154Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961677server # [ 16.662076] horae[1290]: 2026-11-06T19:27:09.379164Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961678server # [ 16.663293] horae[1290]: 2026-11-06T19:27:09.379175Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961679server # [ 16.664491] horae[1290]: 2026-11-06T19:27:09.379187Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961680server # [ 16.665700] horae[1290]: 2026-11-06T19:27:09.379198Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961681server # [ 16.669289] horae[1290]: 2026-11-06T19:27:09.379211Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071682server # [ 16.670499] horae[1290]: 2026-11-06T19:27:09.379222Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071683server # [ 16.672531] horae[1290]: 2026-11-06T19:27:09.379233Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071684server # [ 16.673839] horae[1290]: 2026-11-06T19:27:09.379242Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071685server # [ 16.675155] horae[1290]: 2026-11-06T19:27:09.379255Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111686server # [ 16.676438] horae[1290]: 2026-11-06T19:27:09.379267Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261687server # [ 16.677731] horae[1290]: 2026-11-06T19:27:09.379277Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261688server # [ 16.680307] horae[1290]: 2026-11-06T19:27:09.379286Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261689server # [ 16.681598] horae[1290]: 2026-11-06T19:27:09.379295Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261690server # [ 16.682840] horae[1290]: 2026-11-06T19:27:09.379308Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721691server # [ 16.684203] horae[1290]: 2026-11-06T19:27:09.379321Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711692server # [ 16.685515] horae[1290]: 2026-11-06T19:27:09.379330Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711693server # [ 16.686804] horae[1290]: 2026-11-06T19:27:09.379340Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711694server # [ 16.688117] horae[1290]: 2026-11-06T19:27:09.379350Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711695server # [ 16.691099] horae[1290]: 2026-11-06T19:27:09.379359Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711696server # [ 16.692409] horae[1290]: 2026-11-06T19:27:09.379370Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711697server # [ 16.693790] horae[1290]: 2026-11-06T19:27:09.379380Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711698server # [ 16.695105] horae[1290]: 2026-11-06T19:27:09.379389Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711699server # [ 16.696376] horae[1290]: 2026-11-06T19:27:09.379399Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711700server # [ 16.697601] horae[1290]: 2026-11-06T19:27:09.379409Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341701server # [ 16.698888] horae[1290]: 2026-11-06T19:27:09.379419Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341702server # [ 16.700167] horae[1290]: 2026-11-06T19:27:09.379435Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191703server # [ 16.703192] horae[1290]: 2026-11-06T19:27:09.379466Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191704server # [ 16.704518] horae[1290]: 2026-11-06T19:27:09.379477Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191705server # [ 16.705839] horae[1290]: 2026-11-06T19:27:09.379486Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191706server # [ 16.707103] horae[1290]: 2026-11-06T19:27:09.379496Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191707server # [ 16.708398] horae[1290]: 2026-11-06T19:27:09.379505Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191708server # [ 16.709658] horae[1290]: 2026-11-06T19:27:09.379515Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191709server # [ 16.711059] horae[1290]: 2026-11-06T19:27:09.379525Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191710server # [ 16.712334] horae[1290]: 2026-11-06T19:27:09.379535Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191711server # [ 16.714567] horae[1290]: 2026-11-06T19:27:09.379544Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191712server # [ 16.715848] horae[1290]: 2026-11-06T19:27:09.379553Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191713server # [ 16.717098] horae[1290]: 2026-11-06T19:27:09.379562Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031714server # [ 16.718466] horae[1290]: 2026-11-06T19:27:09.379572Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031715server # [ 16.719811] horae[1290]: 2026-11-06T19:27:09.379583Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031716server # [ 16.721110] horae[1290]: 2026-11-06T19:27:09.379593Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031717server # [ 16.722414] horae[1290]: 2026-11-06T19:27:09.379602Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031718server # [ 16.723719] horae[1290]: 2026-11-06T19:27:09.379614Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031719server # [ 16.727080] horae[1290]: 2026-11-06T19:27:09.379624Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551720server # [ 16.728400] horae[1290]: 2026-11-06T19:27:09.379633Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551721server # [ 16.730492] horae[1290]: 2026-11-06T19:27:09.379643Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551722server # [ 16.731825] horae[1290]: 2026-11-06T19:27:09.379652Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551723server # [ 16.733127] horae[1290]: 2026-11-06T19:27:09.379661Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551724server # [ 16.734493] horae[1290]: 2026-11-06T19:27:09.379671Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551725server # [ 16.735776] horae[1290]: 2026-11-06T19:27:09.379681Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551726server # [ 16.737159] horae[1290]: 2026-11-06T19:27:09.379691Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551727server # [ 16.738409] horae[1290]: 2026-11-06T19:27:09.379700Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551728server # [ 16.739640] horae[1290]: 2026-11-06T19:27:09.379710Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541729server # [ 16.740926] horae[1290]: 2026-11-06T19:27:09.379720Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541730server # [ 16.742202] horae[1290]: 2026-11-06T19:27:09.379730Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541731server # [ 16.743473] horae[1290]: 2026-11-06T19:27:09.379740Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541732server # [ 16.744757] horae[1290]: 2026-11-06T19:27:09.379749Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541733server # [ 16.746267] horae[1290]: 2026-11-06T19:27:09.379758Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1734server # [ 16.747635] horae[1290]: 2026-11-06T19:27:09.379768Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1735server # [ 16.748819] horae[1290]: 2026-11-06T19:27:09.379777Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1736server # [ 16.750054] horae[1290]: 2026-11-06T19:27:09.379788Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1737server # [ 16.751228] horae[1290]: 2026-11-06T19:27:09.379798Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1738server # [ 16.752419] horae[1290]: 2026-11-06T19:27:09.379807Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1739server # [ 16.753633] horae[1290]: 2026-11-06T19:27:09.379816Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1740server # [ 16.754868] horae[1290]: 2026-11-06T19:27:09.379831Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931741server # [ 16.756261] horae[1290]: 2026-11-06T19:27:09.379841Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1742server # [ 16.757425] horae[1290]: 2026-11-06T19:27:09.379854Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1743server # [ 16.758748] horae[1290]: 2026-11-06T19:27:09.379864Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931744server # [ 16.760117] horae[1290]: 2026-11-06T19:27:09.379873Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1745server # [ 16.761332] horae[1290]: 2026-11-06T19:27:09.379884Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931746server # [ 16.762667] horae[1290]: 2026-11-06T19:27:09.422018Z INFO horae: Listening on 127.0.0.1:30001747server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1748server: (finished: waiting for TCP port 3000 on localhost, in 1.03 seconds)1749server: 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/null1750server # [ 17.618870] dex[679]: time=2026-11-06T19:27:10.383Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=4868c19e-4333-4497-ad4e-9f2b40e3c8dc1751server # [ 17.637714] horae[1290]: 2026-11-06T19:27:10.402435Z INFO call: horae::auth::oidc: OIDC sign-in created an account user_id=01a1b254-483f-7b83-9320-46aa884837aa1752server: (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.09 seconds)1753server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar7.txt http://127.0.0.1:3000/harvest/v2/time_entries1754server: (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.03 seconds)1755server: 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'"'"''1756server # [ 17.734314] sudo[1315]: 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\''1757server # [ 17.750368] sudo[1315]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1758server # [ 17.760927] sudo[1315]: pam_unix(sudo:session): session closed for user horae1759server: (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.04 seconds)1760server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = false WHERE email = '"'"'kilgore@kilgore.trout'"'"''1761server # [ 17.775304] sudo[1322]: 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\''1762server # [ 17.790272] sudo[1322]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1763server # [ 17.802096] sudo[1322]: pam_unix(sudo:session): session closed for user horae1764server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = false WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.04 seconds)1765server: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1766server # [ 17.822213] dex[679]: time=2026-11-06T19:27:10.587Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=56b030df-6080-4fc7-bf9e-fadf626875401767server # [ 17.832160] horae[1290]: 2026-11-06T19:27:10.597088Z WARN call: horae::auth::oidc: OIDC login denied: account is deactivated1768server: (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.03 seconds)1769server: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt http://127.0.0.1:3000/auth/login1770server: (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)1771server: 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'1772server # [ 17.865896] sudo[1335]: 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'1773server # [ 17.880848] sudo[1335]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1774server # [ 17.895885] sudo[1335]: pam_unix(sudo:session): session closed for user horae1775server: (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.04 seconds)1776server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1777server # [ 17.909943] sudo[1343]: 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\''1778server # [ 17.924973] sudo[1343]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1779server # [ 17.937760] sudo[1343]: pam_unix(sudo:session): session closed for user horae1780server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.04 seconds)1781server: must succeed: sudo -u horae psql horae -tAc 'SELECT active FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''1782server # [ 17.950753] sudo[1350]: 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\''1783server # [ 17.967281] sudo[1350]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1784server # [ 17.978198] sudo[1350]: pam_unix(sudo:session): session closed for user horae1785server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT active FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.04 seconds)1786server: 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'"'"''1787server # [ 17.990439] sudo[1357]: 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\''1788server # [ 18.005684] sudo[1357]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1789server # [ 18.018086] sudo[1357]: pam_unix(sudo:session): session closed for user horae1790server: (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.04 seconds)1791server: 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.conf1792server: (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)1793server: must succeed: systemctl daemon-reload && systemctl restart horae.service1794server # [ 18.035818] systemd[1]: Reload requested from client PID 1371 ('systemctl') (unit backdoor.service)...1795server # [ 18.037128] systemd[1]: Reloading...1796server # [ 18.187228] systemd[1]: Reloading finished in 149 ms.1797server # [ 18.217284] systemd[1]: Stopping Horae time tracking server...1798server # [ 18.224258] systemd[1]: horae.service: Deactivated successfully.1799server # [ 18.224942] systemd[1]: Stopped Horae time tracking server.1800server # [ 18.225538] systemd[1]: horae.service: Consumed 58ms CPU time over 1.703s wall clock time, 5.7M memory peak, 16.4K incoming IP traffic, 30.2K outgoing IP traffic.1801server # [ 18.231055] systemd[1]: horae.service: Start request repeated too quickly.1802server # [ 18.231947] systemd[1]: horae.service: Failed with result 'start-limit-hit'.1803server # [ 18.233462] systemd[1]: Failed to start Horae time tracking server.1804server # Job for horae.service failed because start of the service was attempted too often.1805server # See "systemctl status horae.service" and "journalctl -xeu horae.service" for details.1806server # To force a start use "systemctl reset-failed horae.service"1807server # followed by "systemctl start horae.service" again.1808server: output: 1809!!! Traceback (most recent call last):1810!!! File "<string>", line 234, in <module>1811!!! restart_with({**omit_client, domains: "kilgore.trout"})1812!!! File "<string>", line 166, in restart_with1813!!! server.succeed("systemctl daemon-reload && systemctl restart horae.service")1814!!! 1815!!! RequestedAssertionFailed: command `systemctl daemon-reload && systemctl restart horae.service` failed (exit code 1)1816cleanup1817kill QemuMachine (pid 12)1818server # qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/l9k0anq0z7zz81zcwy035jfwap9ga6rl-python3-3.13.13/bin/python3.13)1819(finished: cleanup, in 0.12 seconds)