vm-test-run-horae-e2e-oidc
checks.x86_64-linux.e2e-oidc
· build #804
· raw
1bld1: building 3h7xqbaxybkypbmq66dq9mdl1xbksycq-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 # Formatting '/build/vm-state-server/tmp.4rGqI1OdxP', fmt=raw size=107374182414server: QEMU running (pid 12)15server # 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: eb114976-bf0c-4eac-90c3-7f5c59d00f8b19server # 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)... o[ 0.000000] Linux version 6.18.38 (nixbld@localhost) (gcc (GCC) 15.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT_DYNAMIC Sat Jul 4 11:44:22 UTC 202645server # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/b5v9y74ac1i25h4ijb18iqakhmwkg2k9-nixos-system-server-test/init regInfo=/nix/store/r1lc66bxjahhm212jf0f2izbavl85896-closure-info/registration console=ttyS0,115200n8 console=tty046server # [ 0.000000] x86/split lock detection: #DB: warning on user-space bus_locks47server # [ 0.000000] BIOS-provided physical RAM map:48server # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable49server # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved50server # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved51server # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffd7fff] usable52server # [ 0.000000] BIOS-e820: [mem 0x000000003ffd8000-0x000000003fffffff] reserved53server # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved54server # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved55server # [ 0.000000] NX (Execute Disable) protection: active56server # [ 0.000000] APIC: Static calls initialized57server # [ 0.000000] SMBIOS 2.8 present.58server # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/201459server # [ 0.000000] DMI: Memory slots populated: 1/160server # [ 0.000000] Hypervisor detected: KVM61server # [ 0.000000] last_pfn = 0x3ffd8 max_arch_pfn = 0x1000000000062server # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d0063server # [ 0.000000] kvm-clock: using sched offset of 399029447 cycles64server # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns65server # [ 0.000006] tsc: Detected 2100.000 MHz processor66server # [ 0.001076] last_pfn = 0x3ffd8 max_arch_pfn = 0x1000000000067server # [ 0.001112] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs68server # [ 0.001115] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT69server # [ 0.010488] found SMP MP-table at [mem 0x000f5470-0x000f547f]70server # [ 0.010512] Using GB pages for direct mapping71server # [ 0.010593] RAMDISK: [mem 0x3e4dd000-0x3ffcffff]72server # [ 0.010607] ACPI: Early table checksum verification disabled73server # [ 0.010611] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )74server # [ 0.010627] ACPI: RSDT 0x000000003FFE23CC 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)75server # [ 0.010637] ACPI: FACP 0x000000003FFE2280 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)76server # [ 0.010659] ACPI: DSDT 0x000000003FFE0040 002240 (v01 BOCHS BXPC 00000001 BXPC 00000001)77server # [ 0.010663] ACPI: FACS 0x000000003FFE0000 00004078server # [ 0.010666] ACPI: APIC 0x000000003FFE22F4 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)79server # [ 0.010670] ACPI: HPET 0x000000003FFE236C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)80server # [ 0.010673] ACPI: WAET 0x000000003FFE23A4 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)81server # [ 0.010683] ACPI: Reserving FACP table memory at [mem 0x3ffe2280-0x3ffe22f3]82server # [ 0.010686] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe227f]83server # [ 0.010687] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]84server # [ 0.010687] ACPI: Reserving APIC table memory at [mem 0x3ffe22f4-0x3ffe236b]85server # [ 0.010688] ACPI: Reserving HPET table memory at [mem 0x3ffe236c-0x3ffe23a3]86server # [ 0.010688] ACPI: Reserving WAET table memory at [mem 0x3ffe23a4-0x3ffe23cb]87server # [ 0.010973] No NUMA configuration found88server # [ 0.010973] Faking a node at [mem 0x0000000000000000-0x000000003ffd7fff]89server # [ 0.010976] NODE_DATA(0) allocated [mem 0x3ffd2780-0x3ffd7cff]90server # [ 0.012539] Zone ranges:91server # [ 0.012542] DMA [mem 0x0000000000001000-0x0000000000ffffff]92server # [ 0.012544] DMA32 [mem 0x0000000001000000-0x000000003ffd7fff]93server # [ 0.012545] Normal empty94server # [ 0.012546] Device empty95server # [ 0.012546] Movable zone start for each node96server # [ 0.012547] Early memory node ranges97server # [ 0.012548] node 0: [mem 0x0000000000001000-0x000000000009efff]98server # [ 0.012549] node 0: [mem 0x0000000000100000-0x000000003ffd7fff]99server # [ 0.012550] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffd7fff]100server # [ 0.012590] On node 0, zone DMA: 1 pages in unavailable ranges101server # [ 0.012809] On node 0, zone DMA: 97 pages in unavailable ranges102server # [ 0.025127] On node 0, zone DMA32: 40 pages in unavailable ranges103server # [ 0.025664] ACPI: PM-Timer IO Port: 0x608104server # [ 0.025681] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])105server # [ 0.025719] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23106server # [ 0.025723] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)107server # [ 0.025725] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)108server # [ 0.025726] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)109server # [ 0.025727] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)110server # [ 0.025728] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)111server # [ 0.025732] ACPI: Using ACPI (MADT) for SMP configuration information112server # [ 0.025734] ACPI: HPET id: 0x8086a201 base: 0xfed00000113server # [ 0.025738] TSC deadline timer available114server # [ 0.025742] CPU topo: Max. logical packages: 1115server # [ 0.025743] CPU topo: Max. logical dies: 1116server # [ 0.025744] CPU topo: Max. dies per package: 1117server # [ 0.025747] CPU topo: Max. threads per core: 1118server # [ 0.025750] CPU topo: Num. cores per package: 1119server # [ 0.025750] CPU topo: Num. threads per package: 1120server # [ 0.025751] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs121server # [ 0.025775] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()122server # [ 0.025807] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]123server # [ 0.025809] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]124server # [ 0.025811] [mem 0x40000000-0xfeffbfff] available for PCI devices125server # [ 0.025812] Booting paravirtualized kernel on KVM126server # [ 0.025815] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns127server # [ 0.032374] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1128server # [ 0.034158] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u2097152129server # [ 0.034217] kvm-guest: PV spinlocks disabled, single CPU130server # [ 0.034219] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/b5v9y74ac1i25h4ijb18iqakhmwkg2k9-nixos-system-server-test/init regInfo=/nix/store/r1lc66bxjahhm212jf0f2izbavl85896-closure-info/registration console=ttyS0,115200n8 console=tty0131server # [ 0.034394] Unknown kernel command line parameters "regInfo=/nix/store/r1lc66bxjahhm212jf0f2izbavl85896-closure-info/registration", will be passed to user space.132server # [ 0.034426] random: crng init done133server # [ 0.034427] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes134server # [ 0.034471] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)135server # [ 0.034865] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)136server # [ 0.034945] Fallback order for Node 0: 0137server # [ 0.034948] Built 1 zonelists, mobility grouping on. Total pages: 262006138server # [ 0.034949] Policy zone: DMA32139server # [ 0.036830] mem auto-init: stack:all(zero), heap alloc:on, heap free:off140server # [ 0.040510] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1141server # [ 0.042122] allocated 2097152 bytes of page_ext142server # [ 0.053794] ftrace: allocating 48598 entries in 192 pages143server # [ 0.053796] ftrace: allocated 192 pages with 2 groups144server # [ 0.054543] Dynamic Preempt: lazy145server # [ 0.054659] rcu: Preemptible hierarchical RCU implementation.146server # [ 0.054660] rcu: RCU event tracing is enabled.147server # [ 0.054660] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.148server # [ 0.054662] Trampoline variant of Tasks RCU enabled.149server # [ 0.054662] Rude variant of Tasks RCU enabled.150server # [ 0.054663] Tracing variant of Tasks RCU enabled.151server # [ 0.054663] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.152server # [ 0.054664] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1153server # [ 0.054707] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.154server # [ 0.054709] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.155server # [ 0.054710] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.156server # [ 0.060847] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16157server # [ 0.061145] rcu: srcu_init: Setting srcu_struct sizes based on contention.158server # [ 0.061328] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)159server # [ 0.066024] Console: colour VGA+ 80x25160server # [ 0.066027] printk: legacy console [tty0] enabled161server # [ 0.097560] printk: legacy console [ttyS0] enabled162server # [ 0.187392] ACPI: Core revision 20250807163server # [ 0.188399] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns164server # [ 0.189954] APIC: Switch to symmetric I/O mode setup165server # [ 0.190981] x2apic enabled166server # [ 0.191756] APIC: Switched APIC routing to: physical x2apic167server # [ 0.193771] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1168server # [ 0.194706] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1e4530a99b6, max_idle_ns: 440795257976 ns169server # [ 0.196287] Calibrating delay loop (skipped) preset value.. 4200.00 BogoMIPS (lpj=2100000)170server # [ 0.197440] x86/cpu: User Mode Instruction Prevention (UMIP) activated171server # [ 0.199307] CET detected: Indirect Branch Tracking enabled172server # [ 0.200161] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0173server # [ 0.200877] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0174server # [ 0.201931] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto175server # [ 0.203273] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl176server # [ 0.204277] Spectre V2 : Mitigation: Enhanced / Automatic IBRS177server # [ 0.205273] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization178server # [ 0.206275] Spectre V2 : Spectre v2 / PBRSB-eIBRS: Retire a single CALL on VMEXIT179server # [ 0.208274] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier180server # [ 0.209327] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'181server # [ 0.210273] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'182server # [ 0.211273] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'183server # [ 0.212956] x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask'184server # [ 0.213956] x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256'185server # [ 0.214950] x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256'186server # [ 0.215976] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'187server # [ 0.217115] x86/fpu: Supporting XSAVE feature 0x800: 'Control-flow User registers'188server # [ 0.218278] x86/fpu: Supporting XSAVE feature 0x1000: 'Control-flow Kernel registers (KVM only)'189server # [ 0.219273] x86/fpu: Supporting XSAVE feature 0x20000: 'AMX Tile config'190server # [ 0.220273] x86/fpu: Supporting XSAVE feature 0x40000: 'AMX Tile data'191server # [ 0.221273] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256192server # [ 0.222273] x86/fpu: xstate_offset[5]: 832, xstate_sizes[5]: 64193server # [ 0.223275] x86/fpu: xstate_offset[6]: 896, xstate_sizes[6]: 512194server # [ 0.224277] x86/fpu: xstate_offset[7]: 1408, xstate_sizes[7]: 1024195server # [ 0.225275] x86/fpu: xstate_offset[9]: 2432, xstate_sizes[9]: 8196server # [ 0.226276] x86/fpu: xstate_offset[11]: 2440, xstate_sizes[11]: 16197server # [ 0.227273] x86/fpu: xstate_offset[12]: 2456, xstate_sizes[12]: 24198server # [ 0.228273] x86/fpu: xstate_offset[17]: 2496, xstate_sizes[17]: 64199server # [ 0.229273] x86/fpu: xstate_offset[18]: 2560, xstate_sizes[18]: 8192200server # [ 0.230120] x86/fpu: Enabled xstate features 0x61ae7, context size is 10752 bytes, using 'compacted' format.201server # [ 0.261991] Freeing SMP alternatives memory: 44K202server # [ 0.262275] pid_max: default: 32768 minimum: 301203server # [ 0.263347] LSM: initializing lsm=capability,landlock,yama,bpf,ima204server # [ 0.264378] landlock: Up and running.205server # [ 0.264915] Yama: becoming mindful.206server # [ 0.265449] LSM support for eBPF active207server # [ 0.266275] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)208server # [ 0.267283] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)209server # [ 0.268867] smpboot: CPU0: Intel(R) Xeon(R) Gold 5412U (family: 0x6, model: 0x8f, stepping: 0x8)210server # [ 0.269633] Performance Events: PEBS fmt0-, Sapphire Rapids events, full-width counters, Intel PMU driver.211server # [ 0.270277] ... version: 2212server # [ 0.270883] ... bit width: 48213server # [ 0.271273] ... generic counters: 8214server # [ 0.271882] ... generic bitmap: 00000000000000ff215server # [ 0.272273] ... fixed-purpose counters: 3216server # [ 0.272859] ... fixed-purpose bitmap: 0000000000000007217server # [ 0.273275] ... value mask: 0000ffffffffffff218server # [ 0.274215] ... max period: 00007fffffffffff219server # [ 0.274966] ... global_ctrl mask: 00000007000000ff220server # [ 0.275454] signal: max sigframe size: 11952221server # [ 0.276389] rcu: Hierarchical SRCU implementation.222server # [ 0.277245] rcu: Max phase no-delay instances is 400.223server # [ 0.278740] smp: Bringing up secondary CPUs ...224server # [ 0.279291] smp: Brought up 1 node, 1 CPU225server # [ 0.279856] smpboot: Total of 1 processors activated (4200.00 BogoMIPS)226server # [ 0.280442] Memory: 942540K/1048024K available (17159K kernel code, 2721K rwdata, 13560K rodata, 3636K init, 3020K bss, 98120K reserved, 0K cma-reserved)227server # [ 0.281713] devtmpfs: initialized228server # [ 0.282321] x86/mm: Memory block size: 128MB229server # [ 0.283527] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns230server # [ 0.284288] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)231server # [ 0.285264] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).232server # [ 0.286177] pinctrl core: initialized pinctrl subsystem233server # [ 0.287063] PM: RTC time: 09:30:09, date: 2026-11-07234server # [ 0.289042] NET: Registered PF_NETLINK/PF_ROUTE protocol family235server # [ 0.289499] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations236server # [ 0.290315] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations237server # [ 0.291361] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations238server # [ 0.292281] audit: initializing netlink subsys (disabled)239server # [ 0.293216] thermal_sys: Registered thermal governor 'fair_share'240server # [ 0.293219] thermal_sys: Registered thermal governor 'bang_bang'241server # [ 0.293882] thermal_sys: Registered thermal governor 'step_wise'242server # [ 0.294273] thermal_sys: Registered thermal governor 'user_space'243server # [ 0.295093] thermal_sys: Registered thermal governor 'power_allocator'244server # [ 0.295855] audit: type=2000 audit(1794043810.136:1): state=initialized audit_enabled=0 res=1245server # [ 0.297284] cpuidle: using governor menu246server # [ 0.297960] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5247server # [ 0.298443] PCI: Using configuration type 1 for base access248server # [ 0.299340] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.249server # [ 0.304365] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages250server # [ 0.305274] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page251server # [ 0.306161] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages252server # [ 0.311273] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page253server # [ 0.316854] ACPI: Added _OSI(Module Device)254server # [ 0.317274] ACPI: Added _OSI(Processor Device)255server # [ 0.317886] ACPI: Added _OSI(Processor Aggregator Device)256server # [ 0.319124] ACPI: 1 ACPI AML tables successfully acquired and loaded257server # [ 0.328498] ACPI: Interpreter enabled258server # [ 0.329050] ACPI: PM: (supports S0 S3 S4 S5)259server # [ 0.329274] ACPI: Using IOAPIC for interrupt routing260server # [ 0.329961] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug261server # [ 0.334274] PCI: Using E820 reservations for host bridge windows262server # [ 0.335143] ACPI: Enabled 2 GPEs in block 00 to 0F263server # [ 0.339673] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])264server # [ 0.342278] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]265server # [ 0.343274] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI]266server # [ 0.346282] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended configuration space under this bridge267server # [ 0.347415] acpiphp: Slot [3] registered268server # [ 0.347980] acpiphp: Slot [4] registered269server # [ 0.350308] acpiphp: Slot [5] registered270server # [ 0.350880] acpiphp: Slot [6] registered271server # [ 0.351286] acpiphp: Slot [7] registered272server # [ 0.351881] acpiphp: Slot [8] registered273server # [ 0.354290] acpiphp: Slot [9] registered274server # [ 0.354867] acpiphp: Slot [10] registered275server # [ 0.355286] acpiphp: Slot [11] registered276server # [ 0.355875] acpiphp: Slot [12] registered277server # [ 0.358288] acpiphp: Slot [13] registered278server # [ 0.358860] acpiphp: Slot [14] registered279server # [ 0.359286] acpiphp: Slot [15] registered280server # [ 0.359859] acpiphp: Slot [16] registered281server # [ 0.362288] acpiphp: Slot [17] registered282server # [ 0.362861] acpiphp: Slot [18] registered283server # [ 0.363294] acpiphp: Slot [19] registered284server # [ 0.363881] acpiphp: Slot [20] registered285server # [ 0.365667] acpiphp: Slot [21] registered286server # [ 0.366281] acpiphp: Slot [22] registered287server # [ 0.366877] acpiphp: Slot [23] registered288server # [ 0.367286] acpiphp: Slot [24] registered289server # [ 0.367872] acpiphp: Slot [25] registered290server # [ 0.368287] acpiphp: Slot [26] registered291server # [ 0.368866] acpiphp: Slot [27] registered292server # [ 0.369285] acpiphp: Slot [28] registered293server # [ 0.369855] acpiphp: Slot [29] registered294server # [ 0.370286] acpiphp: Slot [30] registered295server # [ 0.370862] acpiphp: Slot [31] registered296server # [ 0.371286] PCI host bridge to bus 0000:00297server # [ 0.371860] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]298server # [ 0.372274] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]299server # [ 0.373148] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]300server # [ 0.373983] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]301server # [ 0.374273] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]302server # [ 0.375282] pci_bus 0000:00: root bus resource [bus 00-ff]303server # [ 0.376094] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint304server # [ 0.377621] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint305server # [ 0.378668] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint306server # [ 0.380223] pci 0000:00:01.1: BAR 4 [io 0xc220-0xc22f]307server # [ 0.380816] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk308server # [ 0.381274] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk309server # [ 0.382091] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk310server # [ 0.382935] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk311server # [ 0.383447] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint312server # [ 0.385173] pci 0000:00:01.2: BAR 4 [io 0xc140-0xc15f]313server # [ 0.386371] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint314server # [ 0.387575] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI315server # [ 0.388280] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB316server # [ 0.389413] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint317server # [ 0.392172] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]318server # [ 0.392929] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]319server # [ 0.393312] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]320server # [ 0.394312] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]321server # [ 0.396293] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint322server # [ 0.398289] pci 0000:00:03.0: BAR 0 [io 0xc160-0xc17f]323server # [ 0.399001] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]324server # [ 0.399296] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]325server # [ 0.400206] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]326server # [ 0.401970] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint327server # [ 0.404306] pci 0000:00:04.0: BAR 0 [io 0xc180-0xc19f]328server # [ 0.405789] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]329server # [ 0.406296] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]330server # [ 0.409072] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint331server # [ 0.412307] pci 0000:00:05.0: BAR 0 [io 0xc1a0-0xc1bf]332server # [ 0.413034] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]333server # [ 0.413296] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]334server # [ 0.415143] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint335server # [ 0.417302] pci 0000:00:06.0: BAR 0 [io 0xc1c0-0xc1df]336server # [ 0.418040] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]337server # [ 0.418296] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]338server # [ 0.420179] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint339server # [ 0.422261] pci 0000:00:07.0: BAR 0 [io 0xc000-0xc07f]340server # [ 0.422784] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]341server # [ 0.423296] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]342server # [ 0.425080] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint343server # [ 0.427580] pci 0000:00:08.0: BAR 0 [io 0xc080-0xc0ff]344server # [ 0.428782] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]345server # [ 0.429296] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]346server # [ 0.431101] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint347server # [ 0.433100] pci 0000:00:09.0: BAR 0 [io 0xc1e0-0xc1ff]348server # [ 0.433798] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]349server # [ 0.434296] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]350server # [ 0.435200] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]351server # [ 0.436746] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint352server # [ 0.438878] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]353server # [ 0.439297] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]354server # [ 0.441082] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint355server # [ 0.443088] pci 0000:00:0b.0: BAR 0 [io 0xc100-0xc13f]356server # [ 0.443798] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]357server # [ 0.444310] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]358server # [ 0.446720] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint359server # [ 0.448296] pci 0000:00:0c.0: BAR 0 [io 0xc200-0xc21f]360server # [ 0.449015] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]361server # [ 0.449297] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]362server # [ 0.453462] ACPI: PCI: Interrupt link LNKA configured for IRQ 10363server # [ 0.454361] ACPI: PCI: Interrupt link LNKB configured for IRQ 10364server # [ 0.455368] ACPI: PCI: Interrupt link LNKC configured for IRQ 11365server # [ 0.456221] ACPI: PCI: Interrupt link LNKD configured for IRQ 11366server # [ 0.456885] ACPI: PCI: Interrupt link LNKS configured for IRQ 9367server # [ 0.458120] iommu: Default domain type: Translated368server # [ 0.458768] iommu: DMA domain TLB invalidation policy: lazy mode369server # [ 0.459484] ACPI: bus type USB registered370server # [ 0.460081] usbcore: registered new interface driver usbfs371server # [ 0.460842] usbcore: registered new interface driver hub372server # [ 0.461279] usbcore: registered new device driver usb373server # [ 0.462710] NetLabel: Initializing374server # [ 0.463244] NetLabel: domain hash size = 128375server # [ 0.463755] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO376server # [ 0.464311] NetLabel: unlabeled traffic allowed by default377server # [ 0.465061] PCI: Using ACPI for IRQ routing378server # [ 0.465630] pci 0000:00:02.0: vgaarb: setting as boot VGA device379server # [ 0.466271] pci 0000:00:02.0: vgaarb: bridge control possible380server # [ 0.466271] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none381server # [ 0.466274] vgaarb: loaded382server # [ 0.466886] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0383server # [ 0.467274] hpet0: 3 comparators, 64-bit 100.000000 MHz counter384server # [ 0.471332] clocksource: Switched to clocksource kvm-clock385server # [ 0.473743] VFS: Disk quotas dquot_6.6.0386server # [ 0.474331] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)387server # [ 0.475438] pnp: PnP ACPI init388server # [ 0.476251] pnp: PnP ACPI: found 6 devices389server # [ 0.482664] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns390server # [ 0.483868] clocksource: Switched to clocksource acpi_pm391server # [ 0.484796] NET: Registered PF_INET protocol family392server # [ 0.485609] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)393server # [ 0.500313] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)394server # [ 0.501661] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)395server # [ 0.502789] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)396server # [ 0.503876] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)397server # [ 0.504893] TCP: Hash tables configured (established 8192 bind 8192)398server # [ 0.505855] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)399server # [ 0.507004] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)400server # [ 0.508044] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)401server # [ 0.509099] NET: Registered PF_UNIX/PF_LOCAL protocol family402server # [ 0.510020] NET: Registered PF_XDP protocol family403server # [ 0.510723] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]404server # [ 0.511574] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]405server # [ 0.512533] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]406server # [ 0.513548] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]407server # [ 0.514663] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]408server # [ 0.515664] pci 0000:00:01.0: PIIX3: Enabling Passive Release409server # [ 0.516646] pci 0000:00:00.0: Limiting direct PCI/PCI transfers410server # [ 0.518234] ACPI: \_SB_.LNKD: Enabled at IRQ 11411server # [ 0.520241] PCI: CLS 0 bytes, default 64412server # [ 0.521068] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e4530a99b6, max_idle_ns: 440795257976 ns413server # [ 0.522550] Trying to unpack rootfs image as initramfs...414server # [ 0.560499] Initialise system trusted keyrings415server # [ 0.563184] workingset: timestamp_bits=40 max_order=18 bucket_order=0416server # [ 0.583429] Key type asymmetric registered417server # [ 0.584036] Asymmetric key parser 'x509' registered418server # [ 0.586196] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)419server # [ 0.589175] io scheduler mq-deadline registered420server # [ 0.589880] io scheduler kyber registered421server # [ 0.591057] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled422server # [ 0.594157] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A423server # [ 0.597627] Linux agpgart interface v0.103424server # [ 0.598452] ACPI: bus type drm_connector registered425server # [ 0.601489] usbcore: registered new interface driver usbserial_generic426server # [ 0.602394] usbserial: USB Serial support registered for generic427server # [ 0.605152] intel_pstate: CPU model not supported428server # [ 0.605921] drop_monitor: Initializing network drop monitor service429server # [ 0.606915] NET: Registered PF_INET6 protocol family430server # [ 0.610540] Segment Routing with IPv6431server # [ 0.611078] In-situ OAM (IOAM) with IPv6432server # [ 0.614415] IPI shorthand broadcast: enabled433server # [ 0.619324] sched_clock: Marking stable (489014701, 130119157)->(668539485, -49405627)434server # [ 0.624311] registered taskstats version 1435server # [ 0.625158] Loading compiled-in X.509 certificates436server # [ 0.636693] Demotion targets for Node 0: null437server # [ 0.637614] Key type .fscrypt registered438server # [ 0.640181] Key type fscrypt-provisioning registered439server # [ 0.640980] ima: No TPM chip found, activating TPM-bypass!440server # [ 0.641875] ima: Allocated hash algorithm: sha1441server # [ 0.644202] ima: No architecture policies found442server # [ 0.646154] PM: Magic number: 2:986:524443server # [ 0.647677] RAS: Correctable Errors collector initialized.444server # [ 0.659200] clk: Disabling unused clocks445server # [ 0.659859] PM: genpd: Disabling unused power domains446server # [ 0.800924] Freeing initrd memory: 27596K447server # [ 0.816908] Freeing unused decrypted memory: 2028K448server # [ 0.819291] Freeing unused kernel image (initmem) memory: 3636K449server # [ 0.820227] Write protecting the kernel read-only data: 32768k450server # [ 0.821831] Freeing unused kernel image (text/rodata gap) memory: 1272K451server # [ 0.823196] Freeing unused kernel image (rodata/data gap) memory: 776K452server # [ 0.832842] x86/mm: Checked W+X mappings: passed, no W+X pages found.453server # [ 0.833738] Run /init as init process454server # [ 0.842182] systemd[1]: Inserted module 'autofs4'455server # [ 0.858202] fuse: init (API version 7.45)456server # [ 0.864334] ACPI: \_SB_.LNKC: Enabled at IRQ 10457server # [ 0.870220] ACPI: \_SB_.LNKA: Enabled at IRQ 10458server # [ 0.872403] ACPI: \_SB_.LNKB: Enabled at IRQ 11459server # [ 0.892469] systemd[1]: Successfully made /usr/ read-only.460server # [ 1.229540] systemd[1]: systemd 260.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)461server # [ 1.234039] systemd[1]: Detected virtualization kvm.462server # [ 1.234811] systemd[1]: Detected architecture x86-64.463server # [ 1.235548] systemd[1]: Running in initrd.464server # [ 1.236383] systemd[1]: Initializing machine ID from random generator.465server # [ 1.237400] systemd[1]: Hostname set to <server>.466server # [ 1.276258] systemd[1]: Queued start job for default target Initrd Default Target.467server # [ 1.278990] systemd[1]: Created slice Slice /system/modprobe.468server # [ 1.280015] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.469server # [ 1.281201] systemd[1]: Expecting device /dev/disk/by-label/nix-store...470server # [ 1.282204] systemd[1]: Expecting device /dev/disk/by-label/nixos...471server # [ 1.283116] systemd[1]: Reached target Path Units.472server # [ 1.283858] systemd[1]: Reached target Slice Units.473server # [ 1.284607] systemd[1]: Reached target Swaps.474server # [ 1.285265] systemd[1]: Reached target Timer Units.475server # [ 1.286074] systemd[1]: Listening on D-Bus System Message Bus Socket.476server # [ 1.287052] systemd[1]: Listening on Journal Socket (/dev/log).477server # [ 1.287987] systemd[1]: Listening on Journal Sockets.478server # [ 1.288827] systemd[1]: Listening on udev Control Socket.479server # [ 1.289673] systemd[1]: Listening on udev Kernel Socket.480server # [ 1.290439] systemd[1]: Reached target Socket Units.481server # [ 1.291784] systemd[1]: Starting Create List of Static Device Nodes...482server # [ 1.294796] systemd[1]: Starting Load Kernel Module 9pnet_virtio...483server # [ 1.299111] systemd[1]: Starting Load Kernel Module configfs...484server # [ 1.317607] systemd[1]: Starting Journal Service...485server # [ 1.324201] systemd[1]: Starting Load Kernel Modules...486server # [ 1.325020] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki487server # [ 1.342262] systemd[1]: Starting Coldplug All udev Devices...488server # [ 1.347852] netfs: FS-Cache loaded489server # [ 1.354853] systemd[1]: Finished Create List of Static Device Nodes.490server # [ 1.360587] systemd[1]: modprobe@configfs.service: Deactivated successfully.491server # [ 1.369471] systemd[1]: Finished Load Kernel Module configfs.492server # [ 1.372021] 9pnet: Installing 9P2000 support493server # [ 1.375559] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config494server # [ 1.377147] systemd-journald[67]: Collecting audit messages is disabled.495server # [ 1.386764] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...496server # [ 1.395287] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.497server # [ 1.400431] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.498server # [ 1.404243] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev499server # [ 1.408253] systemd[1]: Finished Load Kernel Module 9pnet_virtio.500server # [ 1.426193] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.501server # [ 1.434571] systemd[1]: Starting Create Static Device Nodes in /dev...502server # [ 1.444211] systemd[1]: Finished Load Kernel Modules.503server # [ 1.452676] systemd[1]: Starting Apply Kernel Variables...504server # [ 1.466223] systemd[1]: Finished Create Static Device Nodes in /dev.505server # [ 1.470368] systemd[1]: Reached target Preparation for Local File Systems.506server # [ 1.475234] systemd[1]: Reached target Local File Systems.507server # [ 1.481200] systemd[1]: Starting Rule-based Manager for Device Events and Files...508server # [ 1.354720] systemd-modules-load[68]: Inserted module 'dm_mod'509server # [ 1.358277] systemd-modules-load[68]: Inserted module 'virtio_balloon'510server # [ 1.359135] systemd-modules-load[68]: Inserted module 'virtio_gpu'511server # [ 1.491047] systemd[1]: Started Journal Service.512server # [ 1.368174] systemd[1]: Finished Apply Kernel Variables.513server # [ 1.377467] systemd[1]: Starting Create System Files and Directories...514server # [ 1.401693] systemd[1]: Finished Create System Files and Directories.515server # [ 1.410240] systemd-udevd[75]: Using default interface naming scheme 'v260'.516server # [ 1.424424] systemd[1]: Finished Coldplug All udev Devices.517server # [ 1.432109] systemd[1]: Started Rule-based Manager for Device Events and Files.518server # [ 1.433112] systemd[1]: Reached target System Initialization.519server # [ 1.433912] systemd[1]: Reached target Basic System.520server # [ 1.720313] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12521server # [ 1.737324] serio: i8042 KBD port at 0x60,0x64 irq 1522server # [ 1.737915] serio: i8042 AUX port at 0x60,0x64 irq 12523server # [ 1.749775] virtio_blk virtio4: 1/0/0 default/read/poll queues524server # [ 1.751084] virtio_blk virtio4: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)525server # [ 1.764753] uhci_hcd 0000:00:01.2: UHCI Host Controller526server # [ 1.778222] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1527server # [ 1.779082] uhci_hcd 0000:00:01.2: detected 2 ports528server # [ 1.786014] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c140529server # [ 1.791923] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18530server # [ 1.792858] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1531server # [ 1.801345] usb usb1: Product: UHCI Host Controller532server # [ 1.801909] usb usb1: Manufacturer: Linux 6.18.38 uhci_hcd533server # [ 1.803603] SCSI subsystem initialized534server # [ 1.806516] virtio_blk virtio5: 1/0/0 default/read/poll queues535server # [ 1.812504] usb usb1: SerialNumber: 0000:00:01.2536server # [ 1.814784] virtio_blk virtio5: [vdb] 2558480 512-byte logical blocks (1.31 GB/1.22 GiB)537server # [ 1.817631] hub 1-0:1.0: USB hub found538server # [ 1.820696] hub 1-0:1.0: 2 ports detected539server # [ 1.703109] (udev-worker)[96]: Network interface NamePolicy= disabled on kernel command line.540server # [ 1.709758] systemd[1]: Starting Virtual Console Setup...541server # [ 1.717664] (udev-worker)[92]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.542server # [ 1.720440] (udev-worker)[92]: Network interface NamePolicy= disabled on kernel command line.543server # [ 1.859646] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0544server # [ 1.740522] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.545server # [ 1.743063] systemd[1]: Finished Virtual Console Setup.546server # [ 1.772054] systemd[1]: Found device /dev/disk/by-label/nixos.547server # [ 1.778061] systemd[1]: Found device /dev/disk/by-label/nix-store.548server # [ 1.779570] systemd[1]: Reached target Initrd Root Device.549server # [ 1.781062] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...550server # [ 1.927222] scsi host0: ata_piix551server # [ 1.929080] scsi host1: ata_piix552server # [ 1.929898] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc220 irq 14 lpm-pol 0553server # [ 1.931900] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc228 irq 15 lpm-pol 0554server # [ 1.814194] systemd-fsck[111]: nixos: clean, 12/65536 files, 13019/262144 blocks555server # [ 1.820567] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.556server # [ 2.048208] usb 1-1: new full-speed USB device number 2 using uhci_hcd557server # [ 2.088346] ata2: found unknown device (class 0)558server # [ 2.089743] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100559server # [ 2.092228] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5560server # [ 2.121681] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray561server # [ 2.130415] cdrom: Uniform CD-ROM driver Revision: 3.20562server # [ 2.215507] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00563server # [ 2.216731] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10564server # [ 2.218105] usb 1-1: Product: QEMU USB Tablet565server # [ 2.218895] usb 1-1: Manufacturer: QEMU566server # [ 2.219654] usb 1-1: SerialNumber: 28754-0000:00:01.2-1567server # [ 2.238481] hid: raw HID events driver (C) Jiri Kosina568server # [ 2.248992] usbcore: registered new interface driver usbhid569server # [ 2.250821] usbhid: USB HID core driver570server # [ 2.255324] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2571server # [ 2.257244] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0572server # [ 2.224404] systemd[1]: Mounting /sysroot...573server # [ 2.451528] EXT4-fs (vda): mounted filesystem eb114976-bf0c-4eac-90c3-7f5c59d00f8b r/w with ordered data mode. Quota mode: none.574server # [ 2.325352] systemd[1]: Mounted /sysroot.575server # [ 2.326723] systemd[1]: Reached target Initrd Root File System.576server # [ 2.329146] systemd[1]: Starting Mountpoints Configured in the Real Root...577server # [ 2.339915] systemd-sysroot-fstab-check[126]: /sysroot should be mounted in the initrd, will request daemon-reload.578server # [ 2.343505] systemd[1]: Reload requested from client PID 126 ('systemd-sysroot') (unit initrd-parse-etc.service)...579server # [ 2.345051] systemd[1]: Reloading...580server # [ 2.450862] systemd[1]: Reloading finished in 104 ms.581server # [ 2.457825] systemd-sysroot-fstab-check[126]: Requesting initrd-fs.target/start/replace...582server # [ 2.461105] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio583server # [ 2.462420] systemd-sysroot-fstab-check[126]: Requesting swap.target/start/replace...584server # [ 2.465491] systemd[1]: initrd-parse-etc.service: Deactivated successfully.585server # [ 2.466625] systemd[1]: Finished Mountpoints Configured in the Real Root.586server # [ 2.468063] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.587server # [ 3.227119] systemd[1]: Mounting /sysroot/nix/.ro-store...588server # [ 3.230090] systemd[1]: Mounting /sysroot/nix/.rw-store...589server # [ 3.233367] systemd[1]: Mounting /sysroot/run...590server # [ 3.239875] systemd[1]: Mounting /sysroot/tmp/shared...591server # [ 3.246345] systemd[1]: Mounting /sysroot/tmp/xchg...592server # [ 3.282871] systemd[1]: Mounted /sysroot/nix/.rw-store.593server # [ 3.283770] systemd[1]: Mounted /sysroot/run.594server # [ 3.293089] systemd[1]: Starting rw-sysroot-nix-store.service...595server # [ 3.432554] 9p: Installing v9fs 9p2000 file system support596server # [ 3.313060] systemd[1]: Mounted /sysroot/tmp/shared.597server # [ 3.444026] erofs (device vdb): mounted with root inode @ nid 36.598server # [ 3.315340] systemd[1]: Mounted /sysroot/tmp/xchg.599server # [ 3.318862] systemd[1]: Mounted /sysroot/nix/.ro-store.600server # [ 3.324869] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.601server # [ 3.326602] systemd[1]: Finished rw-sysroot-nix-store.service.602server # [ 3.328896] systemd[1]: Mounting /sysroot/nix/store...603server # [ 3.353188] systemd[1]: Mounted /sysroot/nix/store.604server # [ 3.354421] systemd[1]: Reached target Initrd File Systems.605server # [ 3.356166] systemd[1]: Starting Find NixOS closure...606server # [ 3.360194] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...607server # [ 3.384780] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.608server # [ 3.393310] systemd[1]: Finished Find NixOS closure.609server # [ 3.395263] systemd[1]: Reached target Initrd Default Target.610server # [ 3.396689] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...611server # [ 3.415316] systemd[1]: Stopped target Initrd Default Target.612server # [ 3.416253] systemd[1]: Stopped target Basic System.613server # [ 3.417050] systemd[1]: Stopped target Initrd Root Device.614server # [ 3.417983] systemd[1]: Stopped target Path Units.615server # [ 3.419102] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.616server # [ 3.420932] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.617server # [ 3.423126] systemd[1]: Stopped target Slice Units.618server # [ 3.424314] systemd[1]: Stopped target Socket Units.619server # [ 3.426224] systemd[1]: Stopped target System Initialization.620server # [ 3.427568] systemd[1]: Stopped target Swaps.621server # [ 3.428928] systemd[1]: Stopped target Timer Units.622server # [ 3.429901] systemd[1]: dbus.socket: Deactivated successfully.623server # [ 3.431165] systemd[1]: Closed D-Bus System Message Bus Socket.624server # [ 3.432873] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.625server # [ 3.433942] systemd[1]: Stopped Find NixOS closure.626server # [ 3.434676] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio627server # [ 3.438071] systemd[1]: Starting rw-sysroot-nix-store.service...628server # [ 3.438944] systemd[1]: systemd-sysctl.service: Deactivated successfully.629server # [ 3.439911] systemd[1]: Stopped Apply Kernel Variables.630server # [ 3.440823] systemd[1]: systemd-modules-load.service: Deactivated successfully.631server # [ 3.442052] systemd[1]: Stopped Load Kernel Modules.632server # [ 3.444247] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.633server # [ 3.445567] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.634server # [ 3.446738] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.635server # [ 3.447743] systemd[1]: Stopped Create System Files and Directories.636server # [ 3.449341] systemd[1]: Stopped target Local File Systems.637server # [ 3.450429] systemd[1]: Stopped target Preparation for Local File Systems.638server # [ 3.451841] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.639server # [ 3.453440] systemd[1]: Stopped Coldplug All udev Devices.640server # [ 3.457221] systemd[1]: Stopping Rule-based Manager for Device Events and Files...641server # [ 3.458969] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.642server # [ 3.460115] systemd[1]: Stopped Virtual Console Setup.643server # [ 3.473056] systemd[1]: systemd-udevd.service: Deactivated successfully.644server # [ 3.475953] systemd[1]: Stopped Rule-based Manager for Device Events and Files.645server # [ 3.477176] systemd[1]: initrd-cleanup.service: Deactivated successfully.646server # [ 3.478758] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.647server # [ 3.480580] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.648server # [ 3.481646] systemd[1]: Finished rw-sysroot-nix-store.service.649server # [ 3.485289] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.650server # [ 3.486472] systemd[1]: Closed udev Control Socket.651server # [ 3.488154] systemd[1]: Starting Cleanup udev Database...652server # [ 3.489179] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.653server # [ 3.491155] systemd[1]: Stopped Create Static Device Nodes in /dev.654server # [ 3.492644] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.655server # [ 3.493783] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.656server # [ 3.494786] systemd[1]: kmod-static-nodes.service: Deactivated successfully.657server # [ 3.495754] systemd[1]: Stopped Create List of Static Device Nodes.658server # [ 3.511799] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.659server # [ 3.513484] systemd[1]: Finished Cleanup udev Database.660server # [ 3.515200] systemd[1]: Reached target Switch Root.661server # [ 3.516638] systemd[1]: Starting NixOS Activation...662server # [ 3.588380] initrd-nixos-activation-start[177]: booting system configuration /nix/store/b5v9y74ac1i25h4ijb18iqakhmwkg2k9-nixos-system-server-test663server # [ 3.613895] initrd-nixos-activation-start[177]: running activation script...664server # [ 3.798980] initrd-nixos-activation-start[200]: setting up /etc...665server # [ 3.884279] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.666server # [ 3.885769] systemd[1]: Finished NixOS Activation.667server # [ 3.888100] systemd[1]: Starting Switch Root...668server # [ 3.906844] systemd[1]: Switching root.669server # [ 4.050292] systemd-journald[67]: Received SIGTERM from PID 1 (systemd).670server # [ 4.123210] NET: Registered PF_VSOCK protocol family671server # [ 4.480635] systemd[1]: systemd 260.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)672server # [ 4.484970] systemd[1]: Detected virtualization kvm.673server # [ 4.485791] systemd[1]: Detected architecture x86-64.674server # [ 4.486638] systemd[1]: Detected first boot.675server # [ 4.487681] systemd[1]: Initializing machine ID from random generator.676server # [ 4.696046] systemd[1]: bpf-restrict-fs: LSM BPF program attached677server # [ 4.777873] systemd[1]: Applying preset policy.678server # [ 4.866657] systemd[1]: Populated /etc with preset unit settings.679server # [ 4.967622] systemd[1]: initrd-switch-root.service: Deactivated successfully.680server # [ 4.969117] systemd[1]: Stopped initrd-switch-root.service.681server # [ 4.971566] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.682server # [ 4.973725] systemd[1]: Created slice Slice /system/getty.683server # [ 4.975314] systemd[1]: Created slice User and Session Slice.684server # [ 4.976343] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.685server # [ 4.977602] systemd[1]: Started Forward Password Requests to Wall Directory Watch.686server # [ 4.978868] systemd[1]: Expecting device /dev/hvc0...687server # [ 4.979961] systemd[1]: Expecting device /dev/ttyS0...688server # [ 4.980996] systemd[1]: Reached target Local Encrypted Volumes.689server # [ 4.982015] systemd[1]: Stopped target initrd-fs.target.690server # [ 4.982942] systemd[1]: Stopped target initrd-root-fs.target.691server # [ 4.983966] systemd[1]: Stopped target initrd-switch-root.target.692server # [ 4.985308] systemd[1]: Reached target Virtual Machines and Containers.693server # [ 4.986667] systemd[1]: Reached target Path Units.694server # [ 4.987833] systemd[1]: Reached target Remote File Systems.695server # [ 4.988931] systemd[1]: Reached target Slice Units.696server # [ 4.990179] systemd[1]: Reached target Swaps.697server # [ 4.993193] systemd[1]: Listening on Query the User Interactively for a Password.698server # [ 4.996718] systemd[1]: Listening on Process Core Dump Socket.699server # [ 4.998945] systemd[1]: Listening on Credential Encryption/Decryption.700server # [ 5.001423] systemd[1]: Listening on Factory Reset Management.701server # [ 5.004077] systemd[1]: Starting Journal Log Access Socket...702server # [ 5.005722] systemd[1]: Listening on Journal Audit Socket.703server # [ 5.008446] systemd[1]: Listening on Console Output Muting Service Socket.704server # [ 5.009715] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.705server # [ 5.010885] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-uki706server # [ 5.012307] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki707server # [ 5.015239] systemd[1]: Listening on Disk Repartitioning Service Socket.708server # [ 5.016331] systemd[1]: Listening on udev Control Socket.709server # [ 5.017296] systemd[1]: Listening on udev Varlink Socket.710server # [ 5.023098] systemd[1]: Mounting Huge Pages File System...711server # [ 5.028249] systemd[1]: Mounting POSIX Message Queue File System...712server # [ 5.033659] systemd[1]: Mounting Kernel Debug File System...713server # [ 5.040074] systemd[1]: Mounting Kernel Trace File System...714server # [ 5.052481] systemd[1]: Starting Create List of Static Device Nodes...715server # [ 5.059290] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio716server # [ 5.071263] systemd[1]: Starting Load Kernel Module configfs...717server # [ 5.074239] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm718server # [ 5.080169] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore719server # [ 5.082900] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse720server # [ 5.089548] systemd[1]: Mounting FUSE Control File System...721server # [ 5.092601] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67722server # [ 5.104597] systemd[1]: Starting Journal Service...723server # [ 5.110088] systemd[1]: Starting Load Kernel Modules...724server # [ 5.118220] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...725server # [ 5.132520] systemd[1]: Starting Remount Root and Kernel File Systems...726server # [ 5.142039] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki727server # [ 5.159449] loop: module loaded728server # [ 5.164262] systemd[1]: Starting Coldplug All udev Devices...729server # [ 5.173995] systemd-journald[269]: Collecting audit messages is enabled.730server # [ 5.186687] systemd[1]: Listening on Journal Log Access Socket.731server # [ 5.191167] EXT4-fs (vda): re-mounted eb114976-bf0c-4eac-90c3-7f5c59d00f8b.732server # [ 5.201549] systemd[1]: Mounted Huge Pages File System.733server # [ 5.205384] systemd[1]: Mounted POSIX Message Queue File System.734server # [ 5.209504] systemd[1]: Mounted Kernel Debug File System.735server # [ 5.082261] systemd[1]: Queued start job for default target Multi-User System.736server # [ 5.084548] systemd[1]: Unnecessary job was removed for /dev/vdb.737server # [ 5.216346] systemd[1]: Started Journal Service.738server # [ 5.089543] systemd[1]: systemd-journald.service: Deactivated successfully.739server # [ 5.090959] systemd-modules-load[270]: Inserted module 'loop'740server # [ 5.095225] systemd[1]: Mounted Kernel Trace File System.741server # [ 5.097393] systemd[1]: Finished Create List of Static Device Nodes.742server # [ 5.100388] systemd[1]: modprobe@configfs.service: Deactivated successfully.743server # [ 5.101639] systemd[1]: Finished Load Kernel Module configfs.744server # [ 5.105472] systemd[1]: Mounted FUSE Control File System.745server # [ 5.109705] systemd[1]: Finished Load Kernel Modules.746server # [ 5.110676] systemd[1]: Finished Remount Root and Kernel File Systems.747server # [ 5.127083] systemd[1]: Listening on Disk Image Download Service Socket.748server # [ 5.132625] systemd[1]: Mounting Kernel Configuration File System...749server # [ 5.144090] systemd[1]: Starting Firewall...750server # [ 5.153314] systemd-oomd[271]: No swap; memory pressure usage will be degraded751server # [ 5.157236] systemd[1]: Starting Flush Journal to Persistent Storage...752server # [ 5.158328] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore753server # [ 5.170090] systemd[1]: Starting Load/Save OS Random Seed...754server # [ 5.182108] systemd[1]: Starting Apply Kernel Variables...755server # [ 5.208892] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...756server # [ 5.210257] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki757server # [ 5.211738] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.758server # [ 5.399193] systemd-journald[269]: Received client request to flush runtime journal.759server # [ 5.438369] systemd[1]: Mounted Kernel Configuration File System.760server # [ 5.441967] systemd[1]: Finished Load/Save OS Random Seed.761server # [ 5.445442] systemd[1]: Finished Apply Kernel Variables.762server # [ 5.447361] systemd[1]: Reached target First Boot Complete.763server # [ 5.450174] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.764server # [ 5.452185] systemd[1]: Starting Create Static Device Nodes in /dev...765server # [ 5.454169] systemd[1]: Finished Create Static Device Nodes in /dev.766server # [ 5.455364] systemd[1]: Reached target Preparation for Local File Systems.767server # [ 5.459348] systemd[1]: Starting Rule-based Manager for Device Events and Files...768server # [ 5.460455] systemd[1]: Finished Flush Journal to Persistent Storage.769server # [ 5.476763] systemd[1]: Finished Coldplug All udev Devices.770server # [ 5.517066] systemd-udevd[304]: Using default interface naming scheme 'v260'.771server # [ 5.568353] systemd[1]: Started Rule-based Manager for Device Events and Files.772server # [ 5.788921] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse773server # [ 5.840579] systemd[1]: Finished Firewall.774server # [ 5.847440] systemd[1]: Mounting /run/wrappers...775server # [ 5.867909] systemd[1]: Mounted /run/wrappers.776server # [ 5.870534] systemd[1]: Reached target Local File Systems.777server # [ 5.873797] systemd[1]: Listening on Boot Loader Control Service Socket.778server # [ 5.877181] systemd[1]: Starting register-nix-paths.service...779server # [ 5.886090] systemd[1]: Starting Create SUID/SGID Wrappers...780server # [ 5.887027] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.781server # [ 5.897222] systemd[1]: Starting Save Transient machine-id to Disk...782server # [ 5.912082] systemd[1]: Starting Create System Files and Directories...783server # [ 5.951134] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.784server # [ 5.996920] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.785server # [ 6.002961] systemd[1]: Finished Save Transient machine-id to Disk.786server # [ 6.021914] systemd[1]: Finished Create System Files and Directories.787server # [ 6.028091] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.788server # [ 6.038097] systemd[1]: Starting Rebuild Journal Catalog...789server # [ 6.049159] systemd[1]: Starting Record System Boot/Shutdown in UTMP...790server # [ 6.081062] (udev-worker)[369]: Network interface NamePolicy= disabled on kernel command line.791server # [ 6.133945] systemd[1]: Finished Record System Boot/Shutdown in UTMP.792server # [ 6.140325] (udev-worker)[365]: eth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.793server # [ 6.142983] (udev-worker)[365]: Network interface NamePolicy= disabled on kernel command line.794server # [ 6.175072] systemd[1]: Finished Rebuild Journal Catalog.795server # [ 6.186104] systemd[1]: Starting Update is Completed...796server # [ 6.239337] systemd[1]: Finished Update is Completed.797server # [ 6.335257] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.798server # [ 6.336521] systemd[1]: Finished Create SUID/SGID Wrappers.799server # [ 6.348378] systemd[1]: Condition check resulted in Virtio network device being skipped.800server # [ 6.353772] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore801server # [ 6.359081] systemd[1]: Starting Create SUID/SGID Wrappers...802server # [ 6.359969] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.803server # [ 6.361686] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67804server # [ 6.364620] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore805server # [ 6.368224] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki806server # [ 6.369467] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-uki807server # [ 6.775906] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3808server # [ 6.679495] systemd[1]: Finished register-nix-paths.service.809server # [ 6.690671] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.810server # [ 6.692638] systemd[1]: Finished Create SUID/SGID Wrappers.811server # [ 6.696118] systemd[1]: Reached target System Initialization.812server # [ 6.697071] systemd[1]: Started Discard unused filesystem blocks once a week.813server # [ 6.699145] systemd[1]: Started postgresqlBackup-horae.timer.814server # [ 6.701093] systemd[1]: Started Daily Cleanup of Temporary Directories.815server # [ 6.702813] systemd[1]: Reached target Timer Units.816server # [ 6.703627] systemd[1]: Listening on D-Bus System Message Bus Socket.817server # [ 6.704542] systemd[1]: Listening on Nix Daemon Socket.818server # [ 6.706187] systemd[1]: Listening on Hostname Service Socket.819server # [ 6.707073] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.820server # [ 6.709037] systemd[1]: Reached target Socket Units.821server # [ 6.709787] systemd[1]: Reached target Basic System.822server # [ 6.713128] systemd[1]: Started backdoor.service.823server # [ 6.720827] systemd[1]: Starting Import lastlog data into lastlog2 database...824server # [ 6.730133] systemd[1]: Starting Name Service Cache Daemon (nsncd)...825server # [ 6.740076] systemd[1]: Starting Post-Boot Actions...826server # [ 6.758317] systemd[1]: Started Reset console on configuration changes.827server # [ 6.891599] rtc_cmos 00:05: RTC can wake from S4828server # [ 6.773185] systemd[1]: Starting resolvconf update...829server # connecting to host...830server # [ 6.798531] systemd[1]: Started test-console-diagnostics.service.831server # [ 6.846885] systemd[1]: Finished Post-Boot Actions.832server # [ 6.989295] rtc_cmos 00:05: registered as rtc0833server # [ 6.990074] rtc_cmos 00:05: setting system clock to 2026-11-07T09:30:16 UTC (1794043816)834server # [ 6.991576] systemd-journald[269]: Time jumped backwards, rotating.835server # [ 7.015212] parport_pc 00:03: reported by Plug and Play ACPI836server # [ 6.915929] systemd[1]: Starting D-Bus System Message Bus...837server # [ 7.051648] Floppy drive(s): fd0 is 2.88M AMI BIOS838server # [ 6.927695] nsncd[551]: Nov 07 09:30:16.514 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"839server # [ 6.936513] systemd[1]: Started Name Service Cache Daemon (nsncd).840server # [ 6.944248] systemd[1]: Reached target Host and Network Name Lookups.841server # [ 6.949175] systemd[1]: Reached target User and Group Name Lookups.842server # [ 6.951298] systemd[1]: Starting User Login Management...843server # [ 7.084305] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs844server # [ 6.956255] systemd[1]: Finished Import lastlog data into lastlog2 database.845server # [ 7.093312] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]846server # [ 7.113187] mousedev: PS/2 mouse device common for all mice847server # [ 6.985797] systemd[1]: test-console-diagnostics.service: Deactivated successfully.848server # [ 7.117284] ACPI: button: Power Button [PWRF]849server # [ 6.991221] systemd[1]: test-console-diagnostics.service: Consumed 18ms CPU time over 190ms wall clock time, 8.3M memory peak, 6.3M read from disk.850server # [ 7.025748] dbus-broker-launch[576]: Looking up NSS user entry for 'systemd-timesync'...851server # [ 7.030481] dbus-broker-launch[576]: NSS returned no entry for 'systemd-timesync'852server # [ 7.031596] dbus-broker-launch[576]: Invalid user-name in /nix/store/arpzvyccsp34rkxvaj85i50fy233z5lr-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"853server # [ 7.043096] systemd[1]: Started D-Bus System Message Bus.854server # [ 7.175559] FDC 0 is a S82078B855server # [ 7.077636] dbus-broker-launch[576]: Ready856server # [ 7.104294] systemd[1]: Stopped target Host and Network Name Lookups.857server # [ 7.105445] systemd[1]: Stopping Host and Network Name Lookups...858server # [ 7.108340] systemd[1]: Stopped target User and Group Name Lookups.859server # [ 7.112354] systemd[1]: Stopping User and Group Name Lookups...860server # [ 7.113254] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...861server # [ 7.114362] systemd[1]: nscd.service: Deactivated successfully.862server # [ 7.117149] systemd[1]: Stopped Name Service Cache Daemon (nsncd).863server # [ 7.121083] systemd[1]: nscd.service: Consumed 19ms CPU time over 382ms wall clock time, 7.6M memory peak, 5.7M read from disk.864server # [ 7.138241] systemd-logind[579]: New seat seat0.865server # [ 7.143684] systemd[1]: Starting Name Service Cache Daemon (nsncd)...866server # [ 7.149288] systemd[1]: Started User Login Management.867server # [ 7.287249] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console868server # [ 7.165103] systemd[1]: Starting linger-users.service...869server # [ 7.313521] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0870server # [ 7.201224] systemd[1]: Finished resolvconf update.871server # [ 7.201841] systemd[1]: Reached target Preparation for Network.872server # [ 7.207764] nsncd[623]: Nov 07 09:30:16.846 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"873server # [ 7.213073] systemd[1]: Starting DHCP Client...874server # [ 7.218421] systemd[1]: Starting Address configuration of eth1...875server # [ 7.229574] systemd[1]: Starting Extra networking commands....876server # [ 7.230334] systemd[1]: Started Name Service Cache Daemon (nsncd).877server # [ 7.231026] systemd[1]: linger-users.service: Deactivated successfully.878server # [ 7.336579] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4879server # [ 7.349827] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD880server # [ 7.413770] Console: switching to colour dummy device 80x25881server # [ 7.242945] systemd[1]: Finished linger-users.service.882server # [ 7.316710] systemd[1]: Reached target Host and Network Name Lookups.883server # [ 7.317457] systemd[1]: Reached target User and Group Name Lookups.884server # [ 7.484489] [drm] Found bochs VGA, ID 0xb0c5.885server # [ 7.484878] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.886server # [ 7.371535] dhcpcd[655]: dhcpcd-10.3.2 starting887server # [ 7.378250] network-addresses-eth1-start[650]: adding address 192.168.1.1/24... done888server # [ 7.380269] dhcpcd[668]: dev: loaded udev889server # [ 7.518908] 8021q: 802.1Q VLAN Support v1.8890server # [ 7.519258] 8021q: adding VLAN 0 to HW filter on device eth1891server # [ 7.389646] network-addresses-eth1-start[650]: adding address 2001:db8:1::1/64... done892server # [ 7.400944] systemd[1]: Finished Address configuration of eth1.893server # [ 7.537869] bochs-drm 0000:00:02.0: [drm] Registered 1 planes with drm panic894server # [ 7.538401] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0895server: waiting for unit register-nix-paths.service896server: waiting for the VM to finish booting897server: Guest shell says: b'Spawning backdoor root shell...\n'898server: connected to guest root shell899server: (connecting took 0.00 seconds)900server: (finished: waiting for the VM to finish booting, in 0.00 seconds)901server # [ 7.564884] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6902server # [ 7.565660] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5903server # [ 7.469868] systemd[1]: Starting Virtual Console Setup...904server # [ 7.475214] systemd[1]: Finished Extra networking commands..905server # [ 7.516101] systemd[1]: Reached target Network.906server: (finished: waiting for unit register-nix-paths.service, in 0.09 seconds)907server: waiting for unit postgresql.service908server # [ 7.626183] fbcon: bochs-drmdrmfb (fb0) is primary device909server # [ 7.697116] RAPL PMU: API unit is 2^-32 Joules, 1 fixed counters, 10737418240 ms ovfl timer910server # [ 7.697145] RAPL PMU: hw unit of domain psys 2^-0 Joules911server # [ 7.808830] cfg80211: Loading compiled-in X.509 certificates for regulatory database912server # [ 7.820162] ppdev: user-space parallel port driver913server # [ 7.820780] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'914server # [ 7.820901] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'915server # [ 7.821332] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2916server # [ 7.821338] cfg80211: failed to load regulatory.db917server # [ 7.877516] 8021q: adding VLAN 0 to HW filter on device eth0918server # [ 7.895108] Console: switching to colour frame buffer device 160x50919server # [ 7.994203] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device920server # [ 7.523107] systemd[1]: Starting dex identity provider...921server # [ 7.867266] dhcpcd[668]: eth0: waiting for carrier922server # [ 7.867794] systemd-logind[579]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)923server # [ 7.868809] dhcpcd[668]: eth0: carrier acquired924server # [ 7.869297] systemd[1]: Starting PostgreSQL Server...925server # [ 7.870325] dhcpcd[668]: DUID 00:01:00:01:32:81:ac:29:52:54:00:12:34:56926server # [ 7.870981] systemd[1]: Starting Permit User Sessions...927server # [ 7.874456] postgresql-pre-start[742]: The files belonging to this database system will be owned by user "postgres".928server # [ 7.875466] postgresql-pre-start[742]: This user must also own the server process.929server # [ 7.877915] postgresql-pre-start[742]: The database cluster will be initialized with locale "en_US.UTF-8".930server # [ 7.880208] postgresql-pre-start[742]: The default database encoding has accordingly been set to "UTF8".931server # [ 7.881086] postgresql-pre-start[742]: The default text search configuration will be set to "english".932server # [ 7.881963] postgresql-pre-start[742]: Data page checksums are disabled.933server # [ 7.882655] postgresql-pre-start[742]: fixing permissions on existing directory /var/lib/postgresql/17 ... ok934server # [ 7.883608] postgresql-pre-start[742]: creating subdirectories ... ok935server # [ 7.884297] postgresql-pre-start[742]: selecting dynamic shared memory implementation ... posix936server # [ 7.885256] dhcpcd[668]: eth0: IAID 00:12:34:56937server # [ 7.885905] systemd-logind[579]: Watching system buttons on /dev/input/event2 (Power Button)938server # [ 7.893279] dhcpcd[668]: eth0: adding address fe80::5054:ff:fe12:3456939server # [ 7.897162] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.940server # [ 7.901439] systemd[1]: Started dex identity provider.941server # [ 7.902316] systemd-logind[579]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)942server # [ 7.903211] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.943server # [ 7.903997] systemd[1]: Stopped Virtual Console Setup.944server # [ 7.917756] systemd[1]: Starting Virtual Console Setup...945server # [ 7.919256] postgresql-pre-start[742]: selecting default "max_connections" ... 100946server # [ 7.928402] systemd[1]: Finished Permit User Sessions.947server # [ 7.946076] systemd[1]: Started Getty on tty1.948server # [ 7.946657] systemd[1]: Reached target Login Prompts.949server # [ 8.016739] systemd-vconsole-setup[758]: Configuration of first virtual console was skipped, ignoring remaining ones.950server # [ 8.022505] systemd[1]: Finished Virtual Console Setup.951server # [ 8.030248] postgresql-pre-start[742]: selecting default "shared_buffers" ... 128MB952server # [ 8.067492] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="Version info" dex_version=v2.45.1 go.version=go1.26.4 go.os=linux go.arch=amd64953server # [ 8.068978] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config issuer" issuer=http://127.0.0.1:5556/dex954server # [ 8.070486] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config storage" storage_type=memory955server # [ 8.072155] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config static client" client_name=Horae956server # [ 8.073161] dex[750]: time=2026-11-07T09:30:17.706Z level=INFO msg="config static client" client_name="Horae without email_verified"957server # [ 8.074568] dex[750]: time=2026-11-07T09:30:17.707Z level=INFO msg="config connector" connector_id=mock958server # [ 8.076535] dex[750]: time=2026-11-07T09:30:17.707Z level=INFO msg="config skipping approval screen"959server # [ 8.077332] dex[750]: time=2026-11-07T09:30:17.707Z level=INFO msg="continue on connector failure feature flag enabled"960server # [ 8.078314] dex[750]: time=2026-11-07T09:30:17.711Z level=INFO msg="signer configured" type=local keys_rotation_period=6h961server # [ 8.079276] dex[750]: time=2026-11-07T09:30:17.711Z level=INFO msg="config refresh tokens rotation" enabled=true962server # [ 8.080157] dex[750]: time=2026-11-07T09:30:17.711Z level=ERROR msg="failed to get signing algorithm" err="no signing key found"963server # [ 8.083151] dex[750]: time=2026-11-07T09:30:17.721Z level=INFO msg="keys expired, rotating"964server # [ 8.251346] dex[750]: time=2026-11-07T09:30:17.891Z level=INFO msg="keys rotated" next_rotation=2026-11-07T15:30:17.891Z965server # [ 8.253650] dex[750]: time=2026-11-07T09:30:17.893Z level=INFO msg="listening on" server=http address=127.0.0.1:5556966server # [ 8.392146] Key type encrypted registered967server # [ 8.421477] EDAC MC: Ver: 3.0.0968server # [ 8.439671] postgresql-pre-start[742]: selecting default time zone ... UTC969server # [ 8.441624] postgresql-pre-start[742]: creating configuration files ... ok970server # [ 8.560580] postgresql-pre-start[742]: running bootstrap script ... ok971server # [ 8.960765] postgresql-pre-start[742]: performing post-bootstrap initialization ... ok972server # [ 9.052541] dhcpcd[668]: eth0: soliciting a DHCP lease973server # [ 9.191382] NET: Registered PF_PACKET protocol family974server # [ 9.067759] dhcpcd[668]: eth0: offered 10.0.2.15 from 10.0.2.2975server # [ 9.070288] dhcpcd[668]: eth0: probing address 10.0.2.15/24976server # [ 9.085511] postgresql-pre-start[742]: syncing data to disk ... ok977server # [ 9.087617] postgresql-pre-start[742]: initdb: warning: enabling "trust" authentication for local connections978server # [ 9.089262] postgresql-pre-start[742]: initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.979server # [ 9.091688] postgresql-pre-start[742]: Success. You can now start the database server using:980server # [ 9.093202] postgresql-pre-start[742]: pg_ctl -D /var/lib/postgresql/17 -l logfile start981server # [ 9.156414] postgres[783]: [783] LOG: starting PostgreSQL 17.10 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit982server # [ 9.158520] postgres[783]: [783] LOG: listening on IPv6 address "::1", port 5432983server # [ 9.159655] postgres[783]: [783] LOG: listening on IPv4 address "127.0.0.1", port 5432984server # [ 9.162365] postgres[783]: [783] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"985server # [ 9.169453] postgres[790]: [790] LOG: database system was shut down at 2026-11-07 09:30:18 GMT986server # [ 9.176732] postgres[783]: [783] LOG: database system is ready to accept connections987server # [ 9.178985] systemd[1]: Started PostgreSQL Server.988server # [ 9.182470] systemd[1]: Starting PostgreSQL Setup Scripts...989server # [ 9.284139] postgresql-setup-start[801]: CREATE DATABASE990server # [ 9.309522] postgresql-setup-start[806]: CREATE ROLE991server # [ 9.319156] postgresql-setup-start[808]: ALTER ROLE992server # [ 9.330113] postgresql-setup-start[810]: ALTER DATABASE993server # [ 9.332473] systemd[1]: Finished PostgreSQL Setup Scripts.994server # [ 9.335318] systemd[1]: Reached target PostgreSQL.995server # [ 9.337695] systemd[1]: Starting Horae time tracking server...996server # [ 9.603418] horae[813]: 2026-11-07T09:30:19.243046Z INFO horae: Running migrations...997server: (finished: waiting for unit postgresql.service, in 2.16 seconds)998server: waiting for unit dex.service999server: (finished: waiting for unit dex.service, in 0.05 seconds)1000server: waiting for unit horae.service1001server # [ 9.972626] horae[813]: 2026-11-07T09:30:19.612467Z INFO horae: Migrations complete.1002server # [ 9.978559] systemd[1]: Started Horae time tracking server.1003server # [ 9.997052] horae[832]: 2026-11-07T09:30:19.636848Z INFO horae: Starting Horae on 127.0.0.1:30001004server # [ 10.003438] horae[832]: 2026-11-07T09:30:19.643448Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1005server # [ 10.011063] horae[832]: 2026-11-07T09:30:19.651038Z INFO horae::plugin::registry: plugins directory does not exist: plugins1006server # [ 10.024830] horae[832]: 2026-11-07T09:30:19.664265Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541007server # [ 10.026204] horae[832]: 2026-11-07T09:30:19.664296Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541008server # [ 10.027457] horae[832]: 2026-11-07T09:30:19.664308Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541009server # [ 10.028726] horae[832]: 2026-11-07T09:30:19.664323Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541010server # [ 10.029961] horae[832]: 2026-11-07T09:30:19.664340Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541011server # [ 10.031175] horae[832]: 2026-11-07T09:30:19.664349Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721012server # [ 10.032447] horae[832]: 2026-11-07T09:30:19.664361Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961013server # [ 10.033721] horae[832]: 2026-11-07T09:30:19.664372Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961014server # [ 10.035766] horae[832]: 2026-11-07T09:30:19.664392Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961015server # [ 10.037056] horae[832]: 2026-11-07T09:30:19.664404Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961016server # [ 10.038283] horae[832]: 2026-11-07T09:30:19.664414Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961017server # [ 10.039513] horae[832]: 2026-11-07T09:30:19.664424Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961018server # [ 10.040722] horae[832]: 2026-11-07T09:30:19.664433Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341019server # [ 10.042045] horae[832]: 2026-11-07T09:30:19.664442Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341020server # [ 10.043311] horae[832]: 2026-11-07T09:30:19.664454Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191021server # [ 10.044617] horae[832]: 2026-11-07T09:30:19.664477Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191022server # [ 10.045955] horae[832]: 2026-11-07T09:30:19.664487Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191023server # [ 10.047315] horae[832]: 2026-11-07T09:30:19.664498Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191024server # [ 10.048695] horae[832]: 2026-11-07T09:30:19.664508Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191025server # [ 10.050017] horae[832]: 2026-11-07T09:30:19.664517Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191026server # [ 10.051282] horae[832]: 2026-11-07T09:30:19.664527Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191027server # [ 10.052549] horae[832]: 2026-11-07T09:30:19.664536Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191028server # [ 10.053804] horae[832]: 2026-11-07T09:30:19.664546Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191029server # [ 10.055069] horae[832]: 2026-11-07T09:30:19.664554Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191030server # [ 10.056309] horae[832]: 2026-11-07T09:30:19.664563Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191031server # [ 10.057573] horae[832]: 2026-11-07T09:30:19.664575Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111032server # [ 10.059102] horae[832]: 2026-11-07T09:30:19.664590Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001033server # [ 10.060432] horae[832]: 2026-11-07T09:30:19.664601Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551034server # [ 10.061817] horae[832]: 2026-11-07T09:30:19.664613Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551035server # [ 10.064079] horae[832]: 2026-11-07T09:30:19.664653Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551036server # [ 10.065389] horae[832]: 2026-11-07T09:30:19.664663Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551037server # [ 10.066673] horae[832]: 2026-11-07T09:30:19.664672Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551038server # [ 10.067969] horae[832]: 2026-11-07T09:30:19.664682Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551039server # [ 10.069242] horae[832]: 2026-11-07T09:30:19.664694Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551040server # [ 10.070512] horae[832]: 2026-11-07T09:30:19.664703Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551041server # [ 10.071755] horae[832]: 2026-11-07T09:30:19.664712Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551042server # [ 10.072953] horae[832]: 2026-11-07T09:30:19.664722Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview1043server # [ 10.074250] horae[832]: 2026-11-07T09:30:19.664731Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary1044server # [ 10.075441] horae[832]: 2026-11-07T09:30:19.664741Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1045server # [ 10.076641] horae[832]: 2026-11-07T09:30:19.664750Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1046server # [ 10.077788] horae[832]: 2026-11-07T09:30:19.664760Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1047server # [ 10.079331] horae[832]: 2026-11-07T09:30:19.674988Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1048server # [ 10.080462] horae[832]: 2026-11-07T09:30:19.675002Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1049server # [ 10.081602] horae[832]: 2026-11-07T09:30:19.675011Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1050server # [ 10.082755] horae[832]: 2026-11-07T09:30:19.675021Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1051server # [ 10.083911] horae[832]: 2026-11-07T09:30:19.675030Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931052server # [ 10.085176] horae[832]: 2026-11-07T09:30:19.675040Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1053server # [ 10.086348] horae[832]: 2026-11-07T09:30:19.675050Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1054server # [ 10.087557] horae[832]: 2026-11-07T09:30:19.675077Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931055server # [ 10.088842] horae[832]: 2026-11-07T09:30:19.675090Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1056server # [ 10.091837] horae[832]: 2026-11-07T09:30:19.675100Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931057server # [ 10.096142] horae[832]: 2026-11-07T09:30:19.675110Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061058server # [ 10.098075] horae[832]: 2026-11-07T09:30:19.675120Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061059server # [ 10.099952] horae[832]: 2026-11-07T09:30:19.675131Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061060server # [ 10.101741] horae[832]: 2026-11-07T09:30:19.675150Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061061server # [ 10.104104] horae[832]: 2026-11-07T09:30:19.675161Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061062server # [ 10.105897] horae[832]: 2026-11-07T09:30:19.675178Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061063server # [ 10.107690] horae[832]: 2026-11-07T09:30:19.675235Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061064server # [ 10.109477] horae[832]: 2026-11-07T09:30:19.675246Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061065server # [ 10.111223] horae[832]: 2026-11-07T09:30:19.675256Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061066server # [ 10.112997] horae[832]: 2026-11-07T09:30:19.675266Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061067server # [ 10.117634] horae[832]: 2026-11-07T09:30:19.675277Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061068server # [ 10.119335] horae[832]: 2026-11-07T09:30:19.675288Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061069server # [ 10.121076] horae[832]: 2026-11-07T09:30:19.675299Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061070server # [ 10.122792] horae[832]: 2026-11-07T09:30:19.675309Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061071server # [ 10.124489] horae[832]: 2026-11-07T09:30:19.675318Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061072server # [ 10.129139] dhcpcd[668]: eth0: soliciting an IPv6 router1073server # [ 10.129988] horae[832]: 2026-11-07T09:30:19.675328Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711074server # [ 10.133204] horae[832]: 2026-11-07T09:30:19.675338Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711075server # [ 10.134551] horae[832]: 2026-11-07T09:30:19.675348Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711076server # [ 10.135866] horae[832]: 2026-11-07T09:30:19.675358Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711077server # [ 10.137136] horae[832]: 2026-11-07T09:30:19.675368Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711078server # [ 10.138486] horae[832]: 2026-11-07T09:30:19.675378Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711079server # [ 10.139735] horae[832]: 2026-11-07T09:30:19.675388Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711080server # [ 10.140977] horae[832]: 2026-11-07T09:30:19.675397Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711081server # [ 10.142192] horae[832]: 2026-11-07T09:30:19.675406Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711082server # [ 10.143613] horae[832]: 2026-11-07T09:30:19.675418Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261083server # [ 10.144864] horae[832]: 2026-11-07T09:30:19.675427Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261084server # [ 10.146106] horae[832]: 2026-11-07T09:30:19.675437Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261085server # [ 10.147334] horae[832]: 2026-11-07T09:30:19.675446Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261086server # [ 10.148585] dhcpcd[668]: eth0: Router Advertisement from fe80::21087server # [ 10.149183] horae[832]: 2026-11-07T09:30:19.675456Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071088server # [ 10.150359] horae[832]: 2026-11-07T09:30:19.675466Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071089server # [ 10.153195] horae[832]: 2026-11-07T09:30:19.675476Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071090server # [ 10.154527] horae[832]: 2026-11-07T09:30:19.675486Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071091server # [ 10.155783] horae[832]: 2026-11-07T09:30:19.675497Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851092server # [ 10.157128] horae[832]: 2026-11-07T09:30:19.675506Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851093server # [ 10.158488] horae[832]: 2026-11-07T09:30:19.675516Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851094server # [ 10.159764] horae[832]: 2026-11-07T09:30:19.675527Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851095server # [ 10.161120] horae[832]: 2026-11-07T09:30:19.675536Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851096server # [ 10.162394] horae[832]: 2026-11-07T09:30:19.675546Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851097server # [ 10.164280] horae[832]: 2026-11-07T09:30:19.675556Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031098server # [ 10.165719] horae[832]: 2026-11-07T09:30:19.675568Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031099server # [ 10.167265] horae[832]: 2026-11-07T09:30:19.675578Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031100server # [ 10.168673] dhcpcd[668]: eth0: adding address fec0::5054:ff:fe12:3456/641101server # [ 10.169384] horae[832]: 2026-11-07T09:30:19.675588Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031102server # [ 10.170691] horae[832]: 2026-11-07T09:30:19.675603Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031103server # [ 10.173058] horae[832]: 2026-11-07T09:30:19.675615Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031104server # [ 10.174379] horae[832]: 2026-11-07T09:30:19.675625Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181105server # [ 10.175657] horae[832]: 2026-11-07T09:30:19.675635Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181106server # [ 10.176948] horae[832]: 2026-11-07T09:30:19.675644Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181107server # [ 10.178240] horae[832]: 2026-11-07T09:30:19.675654Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181108server # [ 10.179544] horae[832]: 2026-11-07T09:30:19.675663Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181109server # [ 10.180801] horae[832]: 2026-11-07T09:30:19.675687Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181110server # [ 10.182172] horae[832]: 2026-11-07T09:30:19.675697Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181111server # [ 10.183399] horae[832]: 2026-11-07T09:30:19.675707Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181112server # [ 10.184627] horae[832]: 2026-11-07T09:30:19.719313Z INFO horae: Listening on 127.0.0.1:30001113server # [ 10.186312] dhcpcd[668]: eth0: adding route to fec0::/641114server # [ 10.186921] dhcpcd[668]: eth0: adding default route via fe80::21115server: (finished: waiting for unit horae.service, in 1.07 seconds)1116server: waiting for TCP port 5556 on localhost1117server # Connection to localhost (127.0.0.1) 5556 port [tcp/freeciv] succeeded!1118server: (finished: waiting for TCP port 5556 on localhost, in 0.03 seconds)1119server: waiting for TCP port 3000 on localhost1120server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1121server: (finished: waiting for TCP port 3000 on localhost, in 0.01 seconds)1122server: must succeed: curl -sf http://127.0.0.1:3000/health | grep -q ok1123server: (finished: must succeed: curl -sf http://127.0.0.1:3000/health | grep -q ok, in 0.02 seconds)1124server: must succeed: curl -sf http://127.0.0.1:5556/dex/.well-known/openid-configuration >/dev/null1125server: (finished: must succeed: curl -sf http://127.0.0.1:5556/dex/.well-known/openid-configuration >/dev/null, in 0.02 seconds)1126server: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae seed1127server # [ 10.900712] sudo[863]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; ENV=DATABASE_URL=postgres:///horae ; COMMAND=/run/current-system/sw/bin/horae seed1128server # [ 10.920868] sudo[863]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1129server # [ 10.993971] sudo[863]: pam_unix(sudo:session): session closed for user horae1130server: (finished: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae seed, in 0.12 seconds)1131server: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member1132server # [ 11.009430] sudo[872]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; ENV=DATABASE_URL=postgres:///horae ; COMMAND=/run/current-system/sw/bin/horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member1133server # [ 11.028232] sudo[872]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1134server # [ 11.049798] postgres[879]: [879] LOG: could not send data to client: Broken pipe1135server # [ 11.050669] postgres[879]: [879] FATAL: connection to client lost1136server # [ 11.052604] sudo[872]: pam_unix(sudo:session): session closed for user horae1137server: (finished: must succeed: sudo -u horae DATABASE_URL=postgres:///horae horae user create --email kilgore@kilgore.trout --name 'Kilgore Trout' --role member, in 0.06 seconds)1138server: must succeed: curl -s -c /tmp/jar.txt -b /tmp/jar.txt -L http://127.0.0.1:3000/auth/oidc/start -o /dev/null1139server # [ 11.076873] dex[750]: time=2026-11-07T09:30:20.716Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=3c334cb6-67cc-49b9-bac5-dac28c7784a61140server: (finished: must succeed: curl -s -c /tmp/jar.txt -b /tmp/jar.txt -L http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.09 seconds)1141server: must succeed: curl -s -b /tmp/jar.txt http://127.0.0.1:3000/harvest/v2/time_entries1142server: (finished: must succeed: curl -s -b /tmp/jar.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.06 seconds)1143server: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''1144server # [ 11.224885] sudo[886]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT id FROM users WHERE email = \'kilgore@kilgore.trout\''1145server # [ 11.239370] sudo[886]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1146server # [ 11.249381] sudo[886]: pam_unix(sudo:session): session closed for user horae1147server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1148server: must succeed: dex-id-token horae horae-e2e-secret1149server # [ 11.624160] dex[750]: time=2026-11-07T09:30:21.264Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=0acfa9e1-91d6-4686-b774-88ff6146f55c1150server: (finished: must succeed: dex-id-token horae horae-e2e-secret, in 0.41 seconds)1151server # [ 11.682525] sudo[900]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-3a8c-7731-a5f3-7a4948d3aa41 --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1152server # [ 11.703152] sudo[900]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1153server # [ 11.725377] sudo[900]: pam_unix(sudo:session): session closed for user horae1154server: must succeed: sudo -u horae psql horae -c "UPDATE users SET active = false WHERE email = 'kilgore@kilgore.trout'"1155server # [ 11.742295] sudo[906]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -c 'UPDATE users SET active = false WHERE email = \'kilgore@kilgore.trout\''1156server # [ 11.778252] sudo[906]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1157server # [ 11.793962] sudo[906]: pam_unix(sudo:session): session closed for user horae1158server: (finished: must succeed: sudo -u horae psql horae -c "UPDATE users SET active = false WHERE email = 'kilgore@kilgore.trout'", in 0.07 seconds)1159server # [ 11.819705] dex[750]: time=2026-11-07T09:30:21.459Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=389f3be1-7a44-4982-a429-b2285263b5ca1160server # [ 11.831728] horae[832]: 2026-11-07T09:30:21.471373Z WARN call: horae::auth::oidc: OIDC login denied: account is deactivated1161server: must succeed: curl -s -o /dev/null -w '%{http_code}' -b /tmp/jar2.txt http://127.0.0.1:3000/harvest/v2/time_entries1162server: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' -b /tmp/jar2.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.02 seconds)1163server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"''1164server # [ 11.870545] sudo[925]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = \'kilgore@kilgore.trout\''1165server # [ 11.890620] sudo[925]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1166server # [ 11.904164] sudo[925]: pam_unix(sudo:session): session closed for user horae1167server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = true, oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1168server: 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.conf1169server: (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)1170server: must succeed: systemctl daemon-reload && systemctl restart horae.service1171server # [ 11.928331] systemd[1]: Reload requested from client PID 939 ('systemctl') (unit backdoor.service)...1172server # [ 11.930168] systemd[1]: Reloading...1173server # [ 12.130686] systemd[1]: Reloading finished in 199 ms.1174server # [ 12.173936] systemd[1]: Stopping Horae time tracking server...1175server # [ 12.178172] systemd[1]: horae.service: Deactivated successfully.1176server # [ 12.185035] systemd[1]: Stopped Horae time tracking server.1177server # [ 12.185902] systemd[1]: horae.service: Consumed 215ms CPU time over 2.842s wall clock time, 99.5M memory peak, 93.3M read from disk, 16.8K incoming IP traffic, 24.4K outgoing IP traffic.1178server # [ 12.193334] systemd[1]: Starting Horae time tracking server...1179server # [ 12.224573] horae[978]: 2026-11-07T09:30:21.864335Z INFO horae: Running migrations...1180server # [ 12.227302] horae[978]: 2026-11-07T09:30:21.867303Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1181server # [ 12.240209] horae[978]: 2026-11-07T09:30:21.877240Z INFO horae: Migrations complete.1182server # [ 12.241784] postgres[983]: [983] LOG: could not receive data from client: Connection reset by peer1183server # [ 12.245261] systemd[1]: Started Horae time tracking server.1184server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.33 seconds)1185server: waiting for TCP port 3000 on localhost1186server # [ 12.281984] horae[985]: 2026-11-07T09:30:21.921723Z INFO horae: Starting Horae on 127.0.0.1:30001187server # [ 12.290216] horae[985]: 2026-11-07T09:30:21.930166Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1188server # [ 12.300306] horae[985]: 2026-11-07T09:30:21.940261Z INFO horae::plugin::registry: plugins directory does not exist: plugins1189server # [ 12.302663] horae[985]: 2026-11-07T09:30:21.942645Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1190server # [ 12.304707] horae[985]: 2026-11-07T09:30:21.944721Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1191server # [ 12.309065] horae[985]: 2026-11-07T09:30:21.947568Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541192server # [ 12.310889] horae[985]: 2026-11-07T09:30:21.947595Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541193server # [ 12.312635] horae[985]: 2026-11-07T09:30:21.947610Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541194server # [ 12.314348] horae[985]: 2026-11-07T09:30:21.947625Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541195server # [ 12.316069] horae[985]: 2026-11-07T09:30:21.947641Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541196server # [ 12.317758] horae[985]: 2026-11-07T09:30:21.947653Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721197server # [ 12.319531] horae[985]: 2026-11-07T09:30:21.947668Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961198server # [ 12.322104] horae[985]: 2026-11-07T09:30:21.947682Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961199server # [ 12.323856] horae[985]: 2026-11-07T09:30:21.947702Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961200server # [ 12.325613] horae[985]: 2026-11-07T09:30:21.947716Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961201server # [ 12.327295] horae[985]: 2026-11-07T09:30:21.947729Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961202server # [ 12.328997] horae[985]: 2026-11-07T09:30:21.947742Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961203server # [ 12.330716] horae[985]: 2026-11-07T09:30:21.947755Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341204server # [ 12.332528] horae[985]: 2026-11-07T09:30:21.947768Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341205server # [ 12.336815] horae[985]: 2026-11-07T09:30:21.947782Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191206server # [ 12.338646] horae[985]: 2026-11-07T09:30:21.947804Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191207server # [ 12.340444] horae[985]: 2026-11-07T09:30:21.947817Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191208server # [ 12.342180] horae[985]: 2026-11-07T09:30:21.947831Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191209server # [ 12.343913] horae[985]: 2026-11-07T09:30:21.947844Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191210server # [ 12.345649] horae[985]: 2026-11-07T09:30:21.947856Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191211server # [ 12.348823] horae[985]: 2026-11-07T09:30:21.947869Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191212server # [ 12.350590] horae[985]: 2026-11-07T09:30:21.947882Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191213server # [ 12.352305] horae[985]: 2026-11-07T09:30:21.947902Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191214server # [ 12.354058] horae[985]: 2026-11-07T09:30:21.947915Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191215server # [ 12.355782] horae[985]: 2026-11-07T09:30:21.947927Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191216server # [ 12.357470] horae[985]: 2026-11-07T09:30:21.947941Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111217server # [ 12.359252] horae[985]: 2026-11-07T09:30:21.947956Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001218server # [ 12.364086] horae[985]: 2026-11-07T09:30:21.947970Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551219server # [ 12.365921] horae[985]: 2026-11-07T09:30:21.947985Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551220server # [ 12.367695] horae[985]: 2026-11-07T09:30:21.948014Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551221server # [ 12.369449] horae[985]: 2026-11-07T09:30:21.948027Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551222server # [ 12.371173] horae[985]: 2026-11-07T09:30:21.948041Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551223server # [ 12.372938] horae[985]: 2026-11-07T09:30:21.948080Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551224server # [ 12.377575] horae[985]: 2026-11-07T09:30:21.948094Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551225server # [ 12.379346] horae[985]: 2026-11-07T09:30:21.948108Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551226server # [ 12.381053] horae[985]: 2026-11-07T09:30:21.948120Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551227server # [ 12.384512] horae[985]: 2026-11-07T09:30:21.948134Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview1228server # [ 12.386197] horae[985]: 2026-11-07T09:30:21.948146Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary1229server # [ 12.387868] horae[985]: 2026-11-07T09:30:21.948160Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1230server # [ 12.391636] horae[985]: 2026-11-07T09:30:21.948174Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1231server # [ 12.393258] horae[985]: 2026-11-07T09:30:21.948190Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1232server # [ 12.394940] horae[985]: 2026-11-07T09:30:21.948207Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1233server # [ 12.396532] horae[985]: 2026-11-07T09:30:21.948219Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1234server # [ 12.401204] horae[985]: 2026-11-07T09:30:21.948231Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1235server # [ 12.402884] horae[985]: 2026-11-07T09:30:21.948244Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1236server # [ 12.404493] horae[985]: 2026-11-07T09:30:21.948257Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931237server # [ 12.406241] horae[985]: 2026-11-07T09:30:21.948269Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1238server # [ 12.407854] horae[985]: 2026-11-07T09:30:21.948282Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1239server # [ 12.409499] horae[985]: 2026-11-07T09:30:21.948297Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931240server # [ 12.412203] horae[985]: 2026-11-07T09:30:21.948312Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1241server # [ 12.413879] horae[985]: 2026-11-07T09:30:21.948326Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931242server # [ 12.415644] horae[985]: 2026-11-07T09:30:21.948339Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061243server # [ 12.417474] horae[985]: 2026-11-07T09:30:21.948351Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061244server # [ 12.419307] horae[985]: 2026-11-07T09:30:21.948364Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061245server # [ 12.421096] horae[985]: 2026-11-07T09:30:21.948377Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061246server # [ 12.423937] horae[985]: 2026-11-07T09:30:21.948392Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061247server # [ 12.425736] horae[985]: 2026-11-07T09:30:21.948412Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061248server # [ 12.427487] horae[985]: 2026-11-07T09:30:21.948453Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061249server # [ 12.429204] horae[985]: 2026-11-07T09:30:21.948467Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061250server # [ 12.430962] horae[985]: 2026-11-07T09:30:21.948480Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061251server # [ 12.432701] horae[985]: 2026-11-07T09:30:21.948494Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061252server # [ 12.436096] horae[985]: 2026-11-07T09:30:21.948507Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061253server # [ 12.437861] horae[985]: 2026-11-07T09:30:21.948519Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061254server # [ 12.439555] horae[985]: 2026-11-07T09:30:21.948532Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061255server # [ 12.441203] horae[985]: 2026-11-07T09:30:21.948545Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061256server # [ 12.442886] horae[985]: 2026-11-07T09:30:21.948558Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061257server # [ 12.444773] horae[985]: 2026-11-07T09:30:21.948570Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711258server # [ 12.447822] horae[985]: 2026-11-07T09:30:21.948584Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711259server # [ 12.449605] horae[985]: 2026-11-07T09:30:21.948596Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711260server # [ 12.451332] horae[985]: 2026-11-07T09:30:21.948609Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711261server # [ 12.453119] horae[985]: 2026-11-07T09:30:21.948621Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711262server # [ 12.455024] horae[985]: 2026-11-07T09:30:21.948634Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711263server # [ 12.456746] horae[985]: 2026-11-07T09:30:21.948648Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711264server # [ 12.458464] horae[985]: 2026-11-07T09:30:21.948660Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711265server # [ 12.460152] horae[985]: 2026-11-07T09:30:21.948673Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711266server # [ 12.461839] horae[985]: 2026-11-07T09:30:21.948687Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261267server # [ 12.463571] horae[985]: 2026-11-07T09:30:21.948699Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261268server # [ 12.465262] horae[985]: 2026-11-07T09:30:21.948712Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261269server # [ 12.466962] horae[985]: 2026-11-07T09:30:21.948726Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261270server # [ 12.468700] horae[985]: 2026-11-07T09:30:21.948739Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071271server # [ 12.470498] horae[985]: 2026-11-07T09:30:21.948753Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071272server # [ 12.472254] horae[985]: 2026-11-07T09:30:21.948766Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071273server # [ 12.474042] horae[985]: 2026-11-07T09:30:21.948779Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071274server # [ 12.475826] horae[985]: 2026-11-07T09:30:21.948793Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851275server # [ 12.477670] horae[985]: 2026-11-07T09:30:21.948806Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851276server # [ 12.479512] horae[985]: 2026-11-07T09:30:21.948820Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851277server # [ 12.481237] horae[985]: 2026-11-07T09:30:21.948832Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851278server # [ 12.482964] horae[985]: 2026-11-07T09:30:21.948844Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851279server # [ 12.484675] horae[985]: 2026-11-07T09:30:21.948858Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851280server # [ 12.486314] horae[985]: 2026-11-07T09:30:21.948871Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031281server # [ 12.488217] horae[985]: 2026-11-07T09:30:21.948893Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031282server # [ 12.490042] horae[985]: 2026-11-07T09:30:21.948907Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031283server # [ 12.491889] horae[985]: 2026-11-07T09:30:21.948920Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031284server # [ 12.493671] horae[985]: 2026-11-07T09:30:21.948934Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031285server # [ 12.495520] horae[985]: 2026-11-07T09:30:21.948951Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031286server # [ 12.497270] horae[985]: 2026-11-07T09:30:21.948964Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181287server # [ 12.499062] horae[985]: 2026-11-07T09:30:21.948979Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181288server # [ 12.500802] horae[985]: 2026-11-07T09:30:21.948991Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181289server # [ 12.502542] horae[985]: 2026-11-07T09:30:21.949005Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181290server # [ 12.504252] horae[985]: 2026-11-07T09:30:21.949017Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181291server # [ 12.505953] horae[985]: 2026-11-07T09:30:21.949036Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181292server # [ 12.507664] horae[985]: 2026-11-07T09:30:21.949050Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181293server # [ 12.509320] horae[985]: 2026-11-07T09:30:21.975393Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181294server # [ 12.511032] horae[985]: 2026-11-07T09:30:22.015325Z INFO horae: Listening on 127.0.0.1:30001295server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1296server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)1297server: must succeed: dex-id-token horae-omit-email-verified horae-omit-e2e-secret1298server # [ 13.487560] dex[750]: time=2026-11-07T09:30:23.127Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=1c8910a6-27e1-45a8-a00a-4097407664ad1299server: (finished: must succeed: dex-id-token horae-omit-email-verified horae-omit-e2e-secret, in 0.23 seconds)1300server: 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/null1301server # [ 13.549977] dex[750]: time=2026-11-07T09:30:23.189Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=a3f26467-fb85-45d9-a14a-234fdca614441302server # [ 13.565178] horae[985]: 2026-11-07T09:30:23.204689Z WARN call: horae::auth::oidc: OIDC login denied: no account for subject/email1303server: (finished: must succeed: curl -sS -c /tmp/jar3.txt -b /tmp/jar3.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.05 seconds)1304server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar3.txt http://127.0.0.1:3000/harvest/v2/time_entries1305server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar3.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.02 seconds)1306server: 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'"'"''1307server # [ 13.607620] sudo[1012]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT oidc_issuer IS NULL AND oidc_subject IS NULL FROM users WHERE email = \'kilgore@kilgore.trout\''1308server # [ 13.627754] sudo[1012]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1309server # [ 13.640391] sudo[1012]: pam_unix(sudo:session): session closed for user horae1310server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT oidc_issuer IS NULL AND oidc_subject IS NULL FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1311server # [ 13.660592] sudo[1023]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-3a8c-7731-a5f3-7a4948d3aa41 --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1312server # [ 13.681875] sudo[1023]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1313server # [ 13.701870] postgres[1028]: [1028] LOG: could not receive data from client: Connection reset by peer1314server # [ 13.705089] sudo[1023]: pam_unix(sudo:session): session closed for user horae1315server # [ 13.716754] dhcpcd[668]: eth0: leased 10.0.2.15 for 86400 seconds1316server # [ 13.718206] dhcpcd[668]: eth0: adding route to 10.0.2.0/241317server # [ 13.718982] dhcpcd[668]: eth0: adding default route via 10.0.2.21318server # [ 13.735075] sudo[1034]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-3a8c-7731-a5f3-7a4948d3aa41 --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1319server # [ 13.770937] sudo[1034]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1320server # [ 13.801978] postgres[1059]: [1059] LOG: could not send data to client: Broken pipe1321server # [ 13.803277] postgres[1059]: [1059] FATAL: connection to client lost1322server # [ 13.804994] sudo[1034]: pam_unix(sudo:session): session closed for user horae1323server # [ 13.839627] sudo[1079]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user create --email other@kilgore.trout --name Other --role member1324server # [ 13.857985] systemd[1]: Started DHCP Client.1325server # [ 13.861400] systemd[1]: Reached target Multi-User System.1326server # [ 13.862562] systemd[1]: Startup finished in 706ms (kernel) + 3.264s (initrd) + 9.890s (userspace) = 13.862s.1327server # [ 13.874450] sudo[1079]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1328server # [ 13.898158] postgres[1094]: [1094] LOG: could not receive data from client: Connection reset by peer1329server # [ 13.900100] sudo[1079]: pam_unix(sudo:session): session closed for user horae1330server: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'other@kilgore.trout'"'"''1331server # [ 13.918488] sudo[1095]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT id FROM users WHERE email = \'other@kilgore.trout\''1332server # [ 13.938126] sudo[1095]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1333server # [ 13.950571] sudo[1095]: pam_unix(sudo:session): session closed for user horae1334server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT id FROM users WHERE email = '"'"'other@kilgore.trout'"'"'', in 0.05 seconds)1335server # [ 13.971263] sudo[1106]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/env DATABASE_URL=postgres:///horae HORAE_OIDC_ISSUER=http://127.0.0.1:5556/dex horae user link-oidc --user-id 01a1b558-45ab-7761-b704-8a147e4f12ba --issuer http://127.0.0.1:5556/dex --subject Cg0wLTM4NS0yODA4OS0wEgRtb2Nr1336server # [ 13.992385] sudo[1106]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1337server # [ 14.010268] sudo[1106]: pam_unix(sudo:session): session closed for user horae1338server # [ 14.011566] postgres[1111]: [1111] LOG: unexpected EOF on client connection with an open transaction1339server: 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/null1340server # [ 14.042392] dex[750]: time=2026-11-07T09:30:23.682Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=a30de919-2c03-48aa-b99a-ad56eba2d70d1341server: (finished: must succeed: curl -sS -c /tmp/jar4.txt -b /tmp/jar4.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.11 seconds)1342server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar4.txt http://127.0.0.1:3000/harvest/v2/time_entries1343server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar4.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.05 seconds)1344server: 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'"'"''1345server # [ 14.188508] sudo[1119]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET email = \'kilgore-linked@kilgore.trout\', oidc_issuer = NULL, oidc_subject = NULL WHERE email = \'kilgore@kilgore.trout\''1346server # [ 14.208684] sudo[1119]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1347server # [ 14.226981] sudo[1119]: pam_unix(sudo:session): session closed for user horae1348server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET email = '"'"'kilgore-linked@kilgore.trout'"'"', oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)1349server: 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.conf1350server: (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)1351server: must succeed: systemctl daemon-reload && systemctl restart horae.service1352server # [ 14.251083] systemd[1]: Reload requested from client PID 1133 ('systemctl') (unit backdoor.service)...1353server # [ 14.253070] systemd[1]: Reloading...1354server # [ 14.468036] systemd[1]: Reloading finished in 214 ms.1355server # [ 14.507406] systemd[1]: Stopping Horae time tracking server...1356server # [ 14.511879] systemd[1]: horae.service: Deactivated successfully.1357server # [ 14.519782] systemd[1]: Stopped Horae time tracking server.1358server # [ 14.520675] systemd[1]: horae.service: Consumed 73ms CPU time over 2.318s wall clock time, 5.8M memory peak, 16.4K incoming IP traffic, 24.2K outgoing IP traffic.1359server # [ 14.527350] systemd[1]: Starting Horae time tracking server...1360server # [ 14.559619] horae[1171]: 2026-11-07T09:30:24.199354Z INFO horae: Running migrations...1361server # [ 14.562334] horae[1171]: 2026-11-07T09:30:24.202319Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1362server # [ 14.573623] horae[1171]: 2026-11-07T09:30:24.212271Z INFO horae: Migrations complete.1363server # [ 14.579202] systemd[1]: Started Horae time tracking server.1364server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.35 seconds)1365server: waiting for TCP port 3000 on localhost1366server # [ 14.618099] horae[1178]: 2026-11-07T09:30:24.257581Z INFO horae: Starting Horae on 127.0.0.1:30001367server # [ 14.626738] horae[1178]: 2026-11-07T09:30:24.266731Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1368server # [ 14.637657] horae[1178]: 2026-11-07T09:30:24.277544Z INFO horae::plugin::registry: plugins directory does not exist: plugins1369server # [ 14.646650] horae[1178]: 2026-11-07T09:30:24.286621Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1370server # [ 14.651066] horae[1178]: 2026-11-07T09:30:24.289425Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1371server # [ 14.652714] horae[1178]: 2026-11-07T09:30:24.289719Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541372server # [ 14.654508] horae[1178]: 2026-11-07T09:30:24.289743Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541373server # [ 14.656239] horae[1178]: 2026-11-07T09:30:24.289759Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541374server # [ 14.658159] horae[1178]: 2026-11-07T09:30:24.289776Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541375server # [ 14.659890] horae[1178]: 2026-11-07T09:30:24.289792Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541376server # [ 14.661834] horae[1178]: 2026-11-07T09:30:24.289805Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721377server # [ 14.663725] horae[1178]: 2026-11-07T09:30:24.289819Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961378server # [ 14.665606] horae[1178]: 2026-11-07T09:30:24.289834Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961379server # [ 14.667532] horae[1178]: 2026-11-07T09:30:24.289853Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961380server # [ 14.669255] horae[1178]: 2026-11-07T09:30:24.289866Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961381server # [ 14.672102] horae[1178]: 2026-11-07T09:30:24.289879Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961382server # [ 14.673846] horae[1178]: 2026-11-07T09:30:24.289901Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961383server # [ 14.675593] horae[1178]: 2026-11-07T09:30:24.289915Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341384server # [ 14.677411] horae[1178]: 2026-11-07T09:30:24.289928Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341385server # [ 14.679156] horae[1178]: 2026-11-07T09:30:24.289942Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191386server # [ 14.680967] horae[1178]: 2026-11-07T09:30:24.289964Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191387server # [ 14.682882] horae[1178]: 2026-11-07T09:30:24.289978Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191388server # [ 14.684711] horae[1178]: 2026-11-07T09:30:24.289992Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191389server # [ 14.686485] horae[1178]: 2026-11-07T09:30:24.290005Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191390server # [ 14.688256] horae[1178]: 2026-11-07T09:30:24.290017Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191391server # [ 14.690074] horae[1178]: 2026-11-07T09:30:24.290029Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191392server # [ 14.692944] horae[1178]: 2026-11-07T09:30:24.290043Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191393server # [ 14.694821] horae[1178]: 2026-11-07T09:30:24.290081Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191394server # [ 14.696908] horae[1178]: 2026-11-07T09:30:24.290094Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191395server # [ 14.698915] horae[1178]: 2026-11-07T09:30:24.290106Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191396server # [ 14.700690] horae[1178]: 2026-11-07T09:30:24.290119Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111397server # [ 14.704988] horae[1178]: 2026-11-07T09:30:24.290134Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001398server # [ 14.706835] horae[1178]: 2026-11-07T09:30:24.290148Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551399server # [ 14.708691] horae[1178]: 2026-11-07T09:30:24.290163Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551400server # [ 14.711105] horae[1178]: 2026-11-07T09:30:24.290195Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551401server # [ 14.712943] horae[1178]: 2026-11-07T09:30:24.290208Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551402server # [ 14.714785] horae[1178]: 2026-11-07T09:30:24.290221Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551403server # [ 14.718309] horae[1178]: 2026-11-07T09:30:24.290234Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551404server # [ 14.720144] horae[1178]: 2026-11-07T09:30:24.290248Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551405server # [ 14.721905] horae[1178]: 2026-11-07T09:30:24.290261Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551406server # [ 14.723607] horae[1178]: 2026-11-07T09:30:24.290273Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551407server # [ 14.725281] horae[1178]: 2026-11-07T09:30:24.290287Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview1408server # [ 14.726956] horae[1178]: 2026-11-07T09:30:24.290304Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary1409server # [ 14.731304] horae[1178]: 2026-11-07T09:30:24.290317Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1410server # [ 14.732985] horae[1178]: 2026-11-07T09:30:24.290330Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1411server # [ 14.734772] horae[1178]: 2026-11-07T09:30:24.290343Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1412server # [ 14.736464] horae[1178]: 2026-11-07T09:30:24.290357Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1413server # [ 14.738094] horae[1178]: 2026-11-07T09:30:24.290370Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1414server # [ 14.741255] horae[1178]: 2026-11-07T09:30:24.290381Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1415server # [ 14.742982] horae[1178]: 2026-11-07T09:30:24.290394Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1416server # [ 14.744645] horae[1178]: 2026-11-07T09:30:24.290406Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931417server # [ 14.746420] horae[1178]: 2026-11-07T09:30:24.290419Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1418server # [ 14.748050] horae[1178]: 2026-11-07T09:30:24.290432Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1419server # [ 14.749715] horae[1178]: 2026-11-07T09:30:24.290447Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931420server # [ 14.752413] horae[1178]: 2026-11-07T09:30:24.290463Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1421server # [ 14.754090] horae[1178]: 2026-11-07T09:30:24.290477Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931422server # [ 14.755894] horae[1178]: 2026-11-07T09:30:24.290489Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061423server # [ 14.757809] horae[1178]: 2026-11-07T09:30:24.290502Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061424server # [ 14.759622] horae[1178]: 2026-11-07T09:30:24.290515Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061425server # [ 14.761392] horae[1178]: 2026-11-07T09:30:24.290528Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061426server # [ 14.763154] horae[1178]: 2026-11-07T09:30:24.290544Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061427server # [ 14.764928] horae[1178]: 2026-11-07T09:30:24.290562Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061428server # [ 14.766707] horae[1178]: 2026-11-07T09:30:24.290607Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061429server # [ 14.768543] horae[1178]: 2026-11-07T09:30:24.290621Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061430server # [ 14.770380] horae[1178]: 2026-11-07T09:30:24.290634Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061431server # [ 14.772209] horae[1178]: 2026-11-07T09:30:24.290647Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061432server # [ 14.774128] horae[1178]: 2026-11-07T09:30:24.290659Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061433server # [ 14.775977] horae[1178]: 2026-11-07T09:30:24.290673Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061434server # [ 14.777756] horae[1178]: 2026-11-07T09:30:24.290687Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061435server # [ 14.779474] horae[1178]: 2026-11-07T09:30:24.290699Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061436server # [ 14.781332] horae[1178]: 2026-11-07T09:30:24.290711Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061437server # [ 14.783172] horae[1178]: 2026-11-07T09:30:24.290723Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711438server # [ 14.784980] horae[1178]: 2026-11-07T09:30:24.290736Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711439server # [ 14.786812] horae[1178]: 2026-11-07T09:30:24.290752Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711440server # [ 14.788594] horae[1178]: 2026-11-07T09:30:24.290765Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711441server # [ 14.790371] horae[1178]: 2026-11-07T09:30:24.290777Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711442server # [ 14.792138] horae[1178]: 2026-11-07T09:30:24.290790Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711443server # [ 14.793895] horae[1178]: 2026-11-07T09:30:24.290803Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711444server # [ 14.795709] horae[1178]: 2026-11-07T09:30:24.290814Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711445server # [ 14.797444] horae[1178]: 2026-11-07T09:30:24.290827Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711446server # [ 14.799155] horae[1178]: 2026-11-07T09:30:24.290840Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261447server # [ 14.800947] horae[1178]: 2026-11-07T09:30:24.290854Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261448server # [ 14.802797] horae[1178]: 2026-11-07T09:30:24.290866Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261449server # [ 14.804822] horae[1178]: 2026-11-07T09:30:24.290879Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261450server # [ 14.806644] horae[1178]: 2026-11-07T09:30:24.290897Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071451server # [ 14.808393] horae[1178]: 2026-11-07T09:30:24.290911Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071452server # [ 14.810415] horae[1178]: 2026-11-07T09:30:24.290924Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071453server # [ 14.812408] horae[1178]: 2026-11-07T09:30:24.290937Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071454server # [ 14.814351] horae[1178]: 2026-11-07T09:30:24.290950Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851455server # [ 14.816297] horae[1178]: 2026-11-07T09:30:24.290964Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851456server # [ 14.818151] horae[1178]: 2026-11-07T09:30:24.290978Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851457server # [ 14.819908] horae[1178]: 2026-11-07T09:30:24.290990Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851458server # [ 14.821624] horae[1178]: 2026-11-07T09:30:24.291002Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851459server # [ 14.823295] horae[1178]: 2026-11-07T09:30:24.291015Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851460server # [ 14.824947] horae[1178]: 2026-11-07T09:30:24.291028Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031461server # [ 14.826864] horae[1178]: 2026-11-07T09:30:24.291044Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031462server # [ 14.828753] horae[1178]: 2026-11-07T09:30:24.311380Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031463server # [ 14.830534] horae[1178]: 2026-11-07T09:30:24.311402Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031464server # [ 14.832318] horae[1178]: 2026-11-07T09:30:24.311417Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031465server # [ 14.834153] horae[1178]: 2026-11-07T09:30:24.311437Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031466server # [ 14.835935] horae[1178]: 2026-11-07T09:30:24.311450Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181467server # [ 14.837714] horae[1178]: 2026-11-07T09:30:24.311464Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181468server # [ 14.839703] horae[1178]: 2026-11-07T09:30:24.311476Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181469server # [ 14.841562] horae[1178]: 2026-11-07T09:30:24.311490Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181470server # [ 14.843259] horae[1178]: 2026-11-07T09:30:24.311502Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181471server # [ 14.845138] horae[1178]: 2026-11-07T09:30:24.311515Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181472server # [ 14.846881] horae[1178]: 2026-11-07T09:30:24.311530Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181473server # [ 14.848574] horae[1178]: 2026-11-07T09:30:24.311542Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181474server # [ 14.850272] horae[1178]: 2026-11-07T09:30:24.343725Z INFO horae: Listening on 127.0.0.1:30001475server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1476server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)1477server: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1478server # [ 15.654560] dex[750]: time=2026-11-07T09:30:25.294Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=f939edd5-fbe9-4b69-917a-1f170104ce781479server # [ 15.671324] horae[1178]: 2026-11-07T09:30:25.310933Z WARN call: horae::auth::oidc: OIDC login denied: no account for subject/email1480server: (finished: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.05 seconds)1481server: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt http://127.0.0.1:3000/auth/login1482server: (finished: must succeed: curl -sS -c /tmp/jar5.txt -b /tmp/jar5.txt http://127.0.0.1:3000/auth/login, in 0.02 seconds)1483server: 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'1484server # [ 15.720202] sudo[1201]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'1485server # [ 15.740125] sudo[1201]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1486server # [ 15.751340] sudo[1201]: pam_unix(sudo:session): session closed for user horae1487server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.05 seconds)1488server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1489server # [ 15.769608] sudo[1208]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''1490server # [ 15.789356] sudo[1208]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1491server # [ 15.803987] sudo[1208]: pam_unix(sudo:session): session closed for user horae1492server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1493server: 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.conf1494server: (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)1495server: must succeed: systemctl daemon-reload && systemctl restart horae.service1496server # [ 15.830322] systemd[1]: Reload requested from client PID 1222 ('systemctl') (unit backdoor.service)...1497server # [ 15.831882] systemd[1]: Reloading...1498server # [ 16.059502] systemd[1]: Reloading finished in 229 ms.1499server # [ 16.097311] systemd[1]: Stopping Horae time tracking server...1500server # [ 16.104411] systemd[1]: horae.service: Deactivated successfully.1501server # [ 16.105442] systemd[1]: Stopped Horae time tracking server.1502server # [ 16.108667] systemd[1]: horae.service: Consumed 61ms CPU time over 1.576s wall clock time, 5.5M memory peak, 8.2K incoming IP traffic, 18K outgoing IP traffic.1503server # [ 16.116384] systemd[1]: Starting Horae time tracking server...1504server # [ 16.150191] horae[1260]: 2026-11-07T09:30:25.789711Z INFO horae: Running migrations...1505server # [ 16.154322] horae[1260]: 2026-11-07T09:30:25.794268Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1506server # [ 16.169492] horae[1260]: 2026-11-07T09:30:25.805727Z INFO horae: Migrations complete.1507server # [ 16.172605] systemd[1]: Started Horae time tracking server.1508server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.36 seconds)1509server: waiting for TCP port 3000 on localhost1510server # [ 16.211914] horae[1267]: 2026-11-07T09:30:25.851644Z INFO horae: Starting Horae on 127.0.0.1:30001511server # [ 16.220755] horae[1267]: 2026-11-07T09:30:25.860743Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1512server # [ 16.231424] horae[1267]: 2026-11-07T09:30:25.871401Z INFO horae::plugin::registry: plugins directory does not exist: plugins1513server # [ 16.233996] horae[1267]: 2026-11-07T09:30:25.873980Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1514server # [ 16.238184] horae[1267]: 2026-11-07T09:30:25.877104Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1515server # [ 16.239817] horae[1267]: 2026-11-07T09:30:25.877402Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541516server # [ 16.241653] horae[1267]: 2026-11-07T09:30:25.877426Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541517server # [ 16.243417] horae[1267]: 2026-11-07T09:30:25.877441Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541518server # [ 16.245163] horae[1267]: 2026-11-07T09:30:25.877456Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541519server # [ 16.246915] horae[1267]: 2026-11-07T09:30:25.877473Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541520server # [ 16.251111] horae[1267]: 2026-11-07T09:30:25.877486Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721521server # [ 16.252943] horae[1267]: 2026-11-07T09:30:25.877500Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961522server # [ 16.254758] horae[1267]: 2026-11-07T09:30:25.877514Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961523server # [ 16.256574] horae[1267]: 2026-11-07T09:30:25.877533Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961524server # [ 16.258303] horae[1267]: 2026-11-07T09:30:25.877547Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961525server # [ 16.260095] horae[1267]: 2026-11-07T09:30:25.877561Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961526server # [ 16.261843] horae[1267]: 2026-11-07T09:30:25.877574Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961527server # [ 16.263611] horae[1267]: 2026-11-07T09:30:25.877588Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341528server # [ 16.265416] horae[1267]: 2026-11-07T09:30:25.877601Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341529server # [ 16.267219] horae[1267]: 2026-11-07T09:30:25.877616Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191530server # [ 16.269099] horae[1267]: 2026-11-07T09:30:25.877638Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191531server # [ 16.273125] horae[1267]: 2026-11-07T09:30:25.877652Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191532server # [ 16.275391] horae[1267]: 2026-11-07T09:30:25.877666Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191533server # [ 16.277203] horae[1267]: 2026-11-07T09:30:25.877679Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191534server # [ 16.279079] horae[1267]: 2026-11-07T09:30:25.877691Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191535server # [ 16.280873] horae[1267]: 2026-11-07T09:30:25.877704Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191536server # [ 16.282662] horae[1267]: 2026-11-07T09:30:25.877718Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191537server # [ 16.284466] horae[1267]: 2026-11-07T09:30:25.877732Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191538server # [ 16.287630] horae[1267]: 2026-11-07T09:30:25.877745Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191539server # [ 16.289479] horae[1267]: 2026-11-07T09:30:25.877757Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191540server # [ 16.291262] horae[1267]: 2026-11-07T09:30:25.877770Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111541server # [ 16.293138] horae[1267]: 2026-11-07T09:30:25.877786Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001542server # [ 16.294909] horae[1267]: 2026-11-07T09:30:25.877799Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551543server # [ 16.296770] horae[1267]: 2026-11-07T09:30:25.877818Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551544server # [ 16.304605] horae[1267]: 2026-11-07T09:30:25.877847Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551545server # [ 16.306502] horae[1267]: 2026-11-07T09:30:25.877860Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551546server # [ 16.308345] horae[1267]: 2026-11-07T09:30:25.877874Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551547server # [ 16.310205] horae[1267]: 2026-11-07T09:30:25.877894Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551548server # [ 16.312082] horae[1267]: 2026-11-07T09:30:25.877908Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551549server # [ 16.313879] horae[1267]: 2026-11-07T09:30:25.877921Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551550server # [ 16.318499] horae[1267]: 2026-11-07T09:30:25.877933Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551551server # [ 16.320258] horae[1267]: 2026-11-07T09:30:25.877947Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview1552server # [ 16.321994] horae[1267]: 2026-11-07T09:30:25.877966Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary1553server # [ 16.323819] horae[1267]: 2026-11-07T09:30:25.877980Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1554server # [ 16.325544] horae[1267]: 2026-11-07T09:30:25.877994Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1555server # [ 16.330757] horae[1267]: 2026-11-07T09:30:25.878008Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1556server # [ 16.332625] horae[1267]: 2026-11-07T09:30:25.878024Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1557server # [ 16.334336] horae[1267]: 2026-11-07T09:30:25.878036Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1558server # [ 16.336043] horae[1267]: 2026-11-07T09:30:25.878048Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1559server # [ 16.337731] horae[1267]: 2026-11-07T09:30:25.890197Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1560server # [ 16.339394] horae[1267]: 2026-11-07T09:30:25.890214Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931561server # [ 16.342673] horae[1267]: 2026-11-07T09:30:25.890228Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1562server # [ 16.344396] horae[1267]: 2026-11-07T09:30:25.890242Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1563server # [ 16.346555] horae[1267]: 2026-11-07T09:30:25.890259Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931564server # [ 16.348428] horae[1267]: 2026-11-07T09:30:25.890274Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1565server # [ 16.350211] horae[1267]: 2026-11-07T09:30:25.890288Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931566server # [ 16.352153] horae[1267]: 2026-11-07T09:30:25.890302Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061567server # [ 16.357420] horae[1267]: 2026-11-07T09:30:25.890315Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061568server # [ 16.359421] horae[1267]: 2026-11-07T09:30:25.890329Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061569server # [ 16.361926] horae[1267]: 2026-11-07T09:30:25.890345Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061570server # [ 16.363781] horae[1267]: 2026-11-07T09:30:25.890358Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061571server # [ 16.365668] horae[1267]: 2026-11-07T09:30:25.890381Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061572server # [ 16.368261] horae[1267]: 2026-11-07T09:30:25.890422Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061573server # [ 16.370153] horae[1267]: 2026-11-07T09:30:25.890437Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061574server # [ 16.371975] horae[1267]: 2026-11-07T09:30:25.890451Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061575server # [ 16.373799] horae[1267]: 2026-11-07T09:30:25.890465Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061576server # [ 16.377025] horae[1267]: 2026-11-07T09:30:25.890478Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061577server # [ 16.378882] horae[1267]: 2026-11-07T09:30:25.890491Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061578server # [ 16.382086] horae[1267]: 2026-11-07T09:30:25.890504Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061579server # [ 16.383892] horae[1267]: 2026-11-07T09:30:25.890517Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061580server # [ 16.385722] horae[1267]: 2026-11-07T09:30:25.890529Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061581server # [ 16.387480] horae[1267]: 2026-11-07T09:30:25.890542Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711582server # [ 16.389342] horae[1267]: 2026-11-07T09:30:25.890556Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711583server # [ 16.393162] horae[1267]: 2026-11-07T09:30:25.890569Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711584server # [ 16.395064] horae[1267]: 2026-11-07T09:30:25.890582Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711585server # [ 16.396932] horae[1267]: 2026-11-07T09:30:25.890596Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711586server # [ 16.398775] horae[1267]: 2026-11-07T09:30:25.890609Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711587server # [ 16.400623] horae[1267]: 2026-11-07T09:30:25.890623Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711588server # [ 16.402452] horae[1267]: 2026-11-07T09:30:25.890635Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711589server # [ 16.406571] horae[1267]: 2026-11-07T09:30:25.890647Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711590server # [ 16.408399] horae[1267]: 2026-11-07T09:30:25.890662Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261591server # [ 16.410283] horae[1267]: 2026-11-07T09:30:25.890675Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261592server # [ 16.412159] horae[1267]: 2026-11-07T09:30:25.890687Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261593server # [ 16.414905] horae[1267]: 2026-11-07T09:30:25.890700Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261594server # [ 16.416864] horae[1267]: 2026-11-07T09:30:25.890713Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071595server # [ 16.418607] horae[1267]: 2026-11-07T09:30:25.890726Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071596server # [ 16.420576] horae[1267]: 2026-11-07T09:30:25.890739Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071597server # [ 16.422419] horae[1267]: 2026-11-07T09:30:25.890753Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071598server # [ 16.424244] horae[1267]: 2026-11-07T09:30:25.890767Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851599server # [ 16.426240] horae[1267]: 2026-11-07T09:30:25.890780Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851600server # [ 16.428297] horae[1267]: 2026-11-07T09:30:25.890794Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851601server # [ 16.430197] horae[1267]: 2026-11-07T09:30:25.890807Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851602server # [ 16.432487] horae[1267]: 2026-11-07T09:30:25.890819Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851603server # [ 16.434384] horae[1267]: 2026-11-07T09:30:25.890832Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851604server # [ 16.436301] horae[1267]: 2026-11-07T09:30:25.890845Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031605server # [ 16.438520] horae[1267]: 2026-11-07T09:30:25.890860Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031606server # [ 16.440555] horae[1267]: 2026-11-07T09:30:25.890873Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031607server # [ 16.443158] horae[1267]: 2026-11-07T09:30:25.890897Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031608server # [ 16.446508] horae[1267]: 2026-11-07T09:30:25.890914Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031609server # [ 16.448721] horae[1267]: 2026-11-07T09:30:25.890928Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031610server # [ 16.450733] horae[1267]: 2026-11-07T09:30:25.890942Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181611server # [ 16.452671] horae[1267]: 2026-11-07T09:30:25.890956Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181612server # [ 16.454514] horae[1267]: 2026-11-07T09:30:25.890969Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181613server # [ 16.456344] horae[1267]: 2026-11-07T09:30:25.890982Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181614server # [ 16.458190] horae[1267]: 2026-11-07T09:30:25.890995Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181615server # [ 16.460079] horae[1267]: 2026-11-07T09:30:25.891017Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181616server # [ 16.461921] horae[1267]: 2026-11-07T09:30:25.891031Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181617server # [ 16.463747] horae[1267]: 2026-11-07T09:30:25.891044Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181618server # [ 16.465511] horae[1267]: 2026-11-07T09:30:25.943258Z INFO horae: Listening on 127.0.0.1:30001619server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1620server: (finished: waiting for TCP port 3000 on localhost, in 1.06 seconds)1621server: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1622server # [ 17.290459] dex[750]: time=2026-11-07T09:30:26.929Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=b576b4cf-d064-4d19-b385-ee39c11572751623server # [ 17.316913] horae[1267]: 2026-11-07T09:30:26.956502Z WARN call: horae::auth::oidc: OIDC login denied: no account, and the email's domain is not listed1624server: (finished: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.09 seconds)1625server: must succeed: curl -sS -c /tmp/jar6.txt -b /tmp/jar6.txt http://127.0.0.1:3000/auth/login1626server: (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)1627server: 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'1628server # [ 17.362652] sudo[1293]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'1629server # [ 17.383154] sudo[1293]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1630server # [ 17.396320] sudo[1293]: pam_unix(sudo:session): session closed for user horae1631server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.05 seconds)1632server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1633server # [ 17.413385] sudo[1300]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''1634server # [ 17.433307] sudo[1300]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1635server # [ 17.449100] sudo[1300]: pam_unix(sudo:session): session closed for user horae1636server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1637server: 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.conf1638server: (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)1639server: must succeed: systemctl daemon-reload && systemctl restart horae.service1640server # [ 17.472970] systemd[1]: Reload requested from client PID 1314 ('systemctl') (unit backdoor.service)...1641server # [ 17.475172] systemd[1]: Reloading...1642server # [ 17.678489] systemd[1]: Reloading finished in 203 ms.1643server # [ 17.717101] systemd[1]: Stopping Horae time tracking server...1644server # [ 17.727519] systemd[1]: horae.service: Deactivated successfully.1645server # [ 17.731116] systemd[1]: Stopped Horae time tracking server.1646server # [ 17.731986] systemd[1]: horae.service: Consumed 67ms CPU time over 1.606s wall clock time, 5.4M memory peak, 8.2K incoming IP traffic, 18.1K outgoing IP traffic.1647server # [ 17.739348] systemd[1]: Starting Horae time tracking server...1648server # [ 17.771997] horae[1352]: 2026-11-07T09:30:27.411715Z INFO horae: Running migrations...1649server # [ 17.775338] horae[1352]: 2026-11-07T09:30:27.414800Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1650server # [ 17.785285] horae[1352]: 2026-11-07T09:30:27.425283Z INFO horae: Migrations complete.1651server # [ 17.787400] postgres[1356]: [1356] LOG: could not receive data from client: Connection reset by peer1652server # [ 17.794288] systemd[1]: Started Horae time tracking server.1653server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.34 seconds)1654server: waiting for TCP port 3000 on localhost1655server # [ 17.834268] horae[1359]: 2026-11-07T09:30:27.473725Z INFO horae: Starting Horae on 127.0.0.1:30001656server # [ 17.842733] horae[1359]: 2026-11-07T09:30:27.482716Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1657server # [ 17.854216] horae[1359]: 2026-11-07T09:30:27.493463Z INFO horae::plugin::registry: plugins directory does not exist: plugins1658server # [ 17.863155] horae[1359]: 2026-11-07T09:30:27.503124Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1659server # [ 17.866058] horae[1359]: 2026-11-07T09:30:27.505271Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1660server # [ 17.869062] horae[1359]: 2026-11-07T09:30:27.508249Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541661server # [ 17.870882] horae[1359]: 2026-11-07T09:30:27.508281Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541662server # [ 17.872679] horae[1359]: 2026-11-07T09:30:27.508297Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541663server # [ 17.874469] horae[1359]: 2026-11-07T09:30:27.508311Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541664server # [ 17.876190] horae[1359]: 2026-11-07T09:30:27.508327Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541665server # [ 17.877906] horae[1359]: 2026-11-07T09:30:27.508340Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721666server # [ 17.879698] horae[1359]: 2026-11-07T09:30:27.508354Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961667server # [ 17.883097] horae[1359]: 2026-11-07T09:30:27.508369Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961668server # [ 17.884875] horae[1359]: 2026-11-07T09:30:27.508389Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961669server # [ 17.886645] horae[1359]: 2026-11-07T09:30:27.508403Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961670server # [ 17.888353] horae[1359]: 2026-11-07T09:30:27.508416Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961671server # [ 17.890627] horae[1359]: 2026-11-07T09:30:27.508429Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961672server # [ 17.893266] horae[1359]: 2026-11-07T09:30:27.508442Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341673server # [ 17.895271] horae[1359]: 2026-11-07T09:30:27.508455Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341674server # [ 17.897236] horae[1359]: 2026-11-07T09:30:27.508472Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191675server # [ 17.898931] horae[1359]: 2026-11-07T09:30:27.508494Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191676server # [ 17.900611] horae[1359]: 2026-11-07T09:30:27.508508Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191677server # [ 17.903121] horae[1359]: 2026-11-07T09:30:27.508521Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191678server # [ 17.904602] horae[1359]: 2026-11-07T09:30:27.508534Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191679server # [ 17.905983] horae[1359]: 2026-11-07T09:30:27.508546Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191680server # [ 17.907408] horae[1359]: 2026-11-07T09:30:27.508558Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191681server # [ 17.908788] horae[1359]: 2026-11-07T09:30:27.508571Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191682server # [ 17.910174] horae[1359]: 2026-11-07T09:30:27.508585Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191683server # [ 17.912198] horae[1359]: 2026-11-07T09:30:27.508598Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191684server # [ 17.913842] horae[1359]: 2026-11-07T09:30:27.508610Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191685server # [ 17.915290] horae[1359]: 2026-11-07T09:30:27.508623Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111686server # [ 17.917283] horae[1359]: 2026-11-07T09:30:27.508643Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001687server # [ 17.921989] horae[1359]: 2026-11-07T09:30:27.508656Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551688server # [ 17.924679] horae[1359]: 2026-11-07T09:30:27.508672Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551689server # [ 17.927269] horae[1359]: 2026-11-07T09:30:27.508701Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551690server # [ 17.929923] horae[1359]: 2026-11-07T09:30:27.508715Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551691server # [ 17.936318] horae[1359]: 2026-11-07T09:30:27.508729Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551692server # [ 17.939091] horae[1359]: 2026-11-07T09:30:27.508743Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551693server # [ 17.941928] horae[1359]: 2026-11-07T09:30:27.508756Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551694server # [ 17.945592] horae[1359]: 2026-11-07T09:30:27.508769Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551695server # [ 17.947803] horae[1359]: 2026-11-07T09:30:27.508781Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551696server # [ 17.951139] horae[1359]: 2026-11-07T09:30:27.508795Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview1697server # [ 17.953417] horae[1359]: 2026-11-07T09:30:27.508808Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary1698server # [ 17.957179] horae[1359]: 2026-11-07T09:30:27.508821Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1699server # [ 17.958982] horae[1359]: 2026-11-07T09:30:27.508834Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1700server # [ 17.960613] horae[1359]: 2026-11-07T09:30:27.508847Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1701server # [ 17.962244] horae[1359]: 2026-11-07T09:30:27.508862Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1702server # [ 17.963823] horae[1359]: 2026-11-07T09:30:27.508874Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1703server # [ 17.966099] horae[1359]: 2026-11-07T09:30:27.508892Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1704server # [ 17.968410] horae[1359]: 2026-11-07T09:30:27.508908Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1705server # [ 17.970081] horae[1359]: 2026-11-07T09:30:27.508921Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931706server # [ 17.971864] horae[1359]: 2026-11-07T09:30:27.508934Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1707server # [ 17.973478] horae[1359]: 2026-11-07T09:30:27.508948Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1708server # [ 17.975147] horae[1359]: 2026-11-07T09:30:27.508960Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931709server # [ 17.978134] horae[1359]: 2026-11-07T09:30:27.508977Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1710server # [ 17.979844] horae[1359]: 2026-11-07T09:30:27.508991Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931711server # [ 17.981592] horae[1359]: 2026-11-07T09:30:27.509004Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061712server # [ 17.983398] horae[1359]: 2026-11-07T09:30:27.509017Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061713server # [ 17.985204] horae[1359]: 2026-11-07T09:30:27.509030Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061714server # [ 17.986966] horae[1359]: 2026-11-07T09:30:27.509043Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061715server # [ 17.989565] horae[1359]: 2026-11-07T09:30:27.521834Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061716server # [ 17.991334] horae[1359]: 2026-11-07T09:30:27.521860Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061717server # [ 17.993127] horae[1359]: 2026-11-07T09:30:27.521918Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061718server # [ 17.994898] horae[1359]: 2026-11-07T09:30:27.521932Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061719server # [ 17.996670] horae[1359]: 2026-11-07T09:30:27.521945Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061720server # [ 17.998436] horae[1359]: 2026-11-07T09:30:27.521959Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061721server # [ 18.001059] horae[1359]: 2026-11-07T09:30:27.521972Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061722server # [ 18.002795] horae[1359]: 2026-11-07T09:30:27.521985Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061723server # [ 18.004512] horae[1359]: 2026-11-07T09:30:27.521998Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061724server # [ 18.006190] horae[1359]: 2026-11-07T09:30:27.522011Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061725server # [ 18.008827] horae[1359]: 2026-11-07T09:30:27.522023Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061726server # [ 18.010590] horae[1359]: 2026-11-07T09:30:27.522036Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711727server # [ 18.014341] horae[1359]: 2026-11-07T09:30:27.522049Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711728server # [ 18.016166] horae[1359]: 2026-11-07T09:30:27.522086Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711729server # [ 18.017998] horae[1359]: 2026-11-07T09:30:27.522098Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711730server # [ 18.019800] horae[1359]: 2026-11-07T09:30:27.522111Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711731server # [ 18.021597] horae[1359]: 2026-11-07T09:30:27.522124Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711732server # [ 18.023339] horae[1359]: 2026-11-07T09:30:27.522138Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711733server # [ 18.026171] horae[1359]: 2026-11-07T09:30:27.522150Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711734server # [ 18.027927] horae[1359]: 2026-11-07T09:30:27.522163Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711735server # [ 18.029614] horae[1359]: 2026-11-07T09:30:27.522177Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261736server # [ 18.031314] horae[1359]: 2026-11-07T09:30:27.522190Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261737server # [ 18.033068] horae[1359]: 2026-11-07T09:30:27.522202Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261738server # [ 18.034770] horae[1359]: 2026-11-07T09:30:27.522215Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261739server # [ 18.036507] horae[1359]: 2026-11-07T09:30:27.522228Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071740server # [ 18.038195] horae[1359]: 2026-11-07T09:30:27.522241Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071741server # [ 18.040023] horae[1359]: 2026-11-07T09:30:27.522255Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071742server # [ 18.041798] horae[1359]: 2026-11-07T09:30:27.522269Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071743server # [ 18.043567] horae[1359]: 2026-11-07T09:30:27.522283Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851744server # [ 18.045387] horae[1359]: 2026-11-07T09:30:27.522297Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851745server # [ 18.047269] horae[1359]: 2026-11-07T09:30:27.522312Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851746server # [ 18.049072] horae[1359]: 2026-11-07T09:30:27.522324Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851747server # [ 18.050819] horae[1359]: 2026-11-07T09:30:27.522337Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851748server # [ 18.052552] horae[1359]: 2026-11-07T09:30:27.522350Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851749server # [ 18.054207] horae[1359]: 2026-11-07T09:30:27.522364Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031750server # [ 18.056152] horae[1359]: 2026-11-07T09:30:27.522382Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031751server # [ 18.058043] horae[1359]: 2026-11-07T09:30:27.522396Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031752server # [ 18.059905] horae[1359]: 2026-11-07T09:30:27.522410Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031753server # [ 18.061705] horae[1359]: 2026-11-07T09:30:27.522423Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031754server # [ 18.063507] horae[1359]: 2026-11-07T09:30:27.522439Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031755server # [ 18.065280] horae[1359]: 2026-11-07T09:30:27.522452Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181756server # [ 18.067104] horae[1359]: 2026-11-07T09:30:27.522465Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181757server # [ 18.068863] horae[1359]: 2026-11-07T09:30:27.522477Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181758server # [ 18.070595] horae[1359]: 2026-11-07T09:30:27.522491Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181759server # [ 18.072325] horae[1359]: 2026-11-07T09:30:27.522504Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181760server # [ 18.074059] horae[1359]: 2026-11-07T09:30:27.522517Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181761server # [ 18.075763] horae[1359]: 2026-11-07T09:30:27.522533Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181762server # [ 18.077468] horae[1359]: 2026-11-07T09:30:27.522549Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181763server # [ 18.079141] horae[1359]: 2026-11-07T09:30:27.561275Z INFO horae: Listening on 127.0.0.1:30001764server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1765server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)1766server: 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/null1767server # [ 18.871680] dex[750]: time=2026-11-07T09:30:28.510Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=7348ddbc-1dfd-4680-b76e-09719455b1361768server # [ 18.895564] horae[1359]: 2026-11-07T09:30:28.535179Z INFO call: horae::auth::oidc: OIDC sign-in created an account user_id=01a1b558-5933-7170-94e3-efaa625c84931769server: (finished: must succeed: curl -sS -c /tmp/jar7.txt -b /tmp/jar7.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.06 seconds)1770server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar7.txt http://127.0.0.1:3000/harvest/v2/time_entries1771server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar7.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.07 seconds)1772server: 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'"'"''1773server # [ 18.993641] sudo[1383]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT org_role, active, cost_rate_cents IS NULL AND billable_rate_cents IS NULL, oidc_issuer, oidc_subject FROM users WHERE email = \'kilgore@kilgore.trout\''1774server # [ 19.014760] sudo[1383]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1775server # [ 19.028813] sudo[1383]: pam_unix(sudo:session): session closed for user horae1776server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT org_role, active, cost_rate_cents IS NULL AND billable_rate_cents IS NULL, oidc_issuer, oidc_subject FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)1777server: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = false WHERE email = '"'"'kilgore@kilgore.trout'"'"''1778server # [ 19.046457] sudo[1390]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET active = false WHERE email = \'kilgore@kilgore.trout\''1779server # [ 19.065873] sudo[1390]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1780server # [ 19.081592] sudo[1390]: pam_unix(sudo:session): session closed for user horae1781server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET active = false WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1782server: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1783server # [ 19.105347] dex[750]: time=2026-11-07T09:30:28.745Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=1f041b40-9b35-419d-b1b2-e359fd1ada131784server # [ 19.117355] horae[1359]: 2026-11-07T09:30:28.757253Z WARN call: horae::auth::oidc: OIDC login denied: account is deactivated1785server: (finished: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.04 seconds)1786server: must succeed: curl -sS -c /tmp/jar8.txt -b /tmp/jar8.txt http://127.0.0.1:3000/auth/login1787server: (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)1788server: 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'1789server # [ 19.160393] sudo[1403]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'1790server # [ 19.180490] sudo[1403]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1791server # [ 19.193971] sudo[1403]: pam_unix(sudo:session): session closed for user horae1792server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.05 seconds)1793server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1794server # [ 19.210553] sudo[1410]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''1795server # [ 19.229773] sudo[1410]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1796server # [ 19.244853] sudo[1410]: pam_unix(sudo:session): session closed for user horae1797server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.05 seconds)1798server: must succeed: sudo -u horae psql horae -tAc 'SELECT active FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"''1799server # [ 19.262485] sudo[1417]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT active FROM users WHERE email = \'kilgore@kilgore.trout\''1800server # [ 19.281740] sudo[1417]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1801server # [ 19.301059] sudo[1417]: pam_unix(sudo:session): session closed for user horae1802server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT active FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)1803server: 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'"'"''1804server # [ 19.323944] sudo[1424]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'UPDATE users SET email = \'kilgore-provisioned@kilgore.trout\', oidc_issuer = NULL, oidc_subject = NULL WHERE email = \'kilgore@kilgore.trout\''1805server # [ 19.353805] sudo[1424]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1806server # [ 19.375610] sudo[1424]: pam_unix(sudo:session): session closed for user horae1807server: (finished: must succeed: sudo -u horae psql horae -tAc 'UPDATE users SET email = '"'"'kilgore-provisioned@kilgore.trout'"'"', oidc_issuer = NULL, oidc_subject = NULL WHERE email = '"'"'kilgore@kilgore.trout'"'"'', in 0.07 seconds)1808server: 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.conf1809server: (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)1810server: must succeed: systemctl daemon-reload && systemctl restart horae.service1811server # [ 19.399805] systemd[1]: Reload requested from client PID 1438 ('systemctl') (unit backdoor.service)...1812server # [ 19.402067] systemd[1]: Reloading...1813server # [ 19.599586] systemd[1]: Reloading finished in 197 ms.1814server # [ 19.639145] systemd[1]: Stopping Horae time tracking server...1815server # [ 19.646988] systemd[1]: horae.service: Deactivated successfully.1816server # [ 19.651769] systemd[1]: Stopped Horae time tracking server.1817server # [ 19.652650] systemd[1]: horae.service: Consumed 76ms CPU time over 1.907s wall clock time, 5.9M memory peak, 16.3K incoming IP traffic, 30.9K outgoing IP traffic.1818server # [ 19.660442] systemd[1]: Starting Horae time tracking server...1819server # [ 19.691857] horae[1476]: 2026-11-07T09:30:29.331605Z INFO horae: Running migrations...1820server # [ 19.694619] horae[1476]: 2026-11-07T09:30:29.334581Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1821server # [ 19.707138] horae[1476]: 2026-11-07T09:30:29.344723Z INFO horae: Migrations complete.1822server # [ 19.708774] postgres[1481]: [1481] LOG: could not send data to client: Broken pipe1823server # [ 19.709786] postgres[1481]: [1481] FATAL: connection to client lost1824server # [ 19.714088] systemd[1]: Started Horae time tracking server.1825server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.33 seconds)1826server: waiting for TCP port 3000 on localhost1827server # [ 19.767249] horae[1483]: 2026-11-07T09:30:29.406798Z INFO horae: Starting Horae on 127.0.0.1:30001828server # [ 19.780514] horae[1483]: 2026-11-07T09:30:29.420454Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1829server # [ 19.794281] horae[1483]: 2026-11-07T09:30:29.434243Z INFO horae::plugin::registry: plugins directory does not exist: plugins1830server # [ 19.797563] horae[1483]: 2026-11-07T09:30:29.437423Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1831server # [ 19.802070] horae[1483]: 2026-11-07T09:30:29.440651Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1832server # [ 19.803729] horae[1483]: 2026-11-07T09:30:29.440986Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541833server # [ 19.805484] horae[1483]: 2026-11-07T09:30:29.441010Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541834server # [ 19.807467] horae[1483]: 2026-11-07T09:30:29.441026Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541835server # [ 19.809192] horae[1483]: 2026-11-07T09:30:29.441041Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541836server # [ 19.810888] horae[1483]: 2026-11-07T09:30:29.441083Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541837server # [ 19.813723] horae[1483]: 2026-11-07T09:30:29.441096Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721838server # [ 19.815751] horae[1483]: 2026-11-07T09:30:29.441110Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961839server # [ 19.817505] horae[1483]: 2026-11-07T09:30:29.441125Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961840server # [ 19.819234] horae[1483]: 2026-11-07T09:30:29.441147Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961841server # [ 19.820963] horae[1483]: 2026-11-07T09:30:29.441162Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961842server # [ 19.822662] horae[1483]: 2026-11-07T09:30:29.441174Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961843server # [ 19.826891] horae[1483]: 2026-11-07T09:30:29.441188Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961844server # [ 19.828680] horae[1483]: 2026-11-07T09:30:29.441200Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341845server # [ 19.830491] horae[1483]: 2026-11-07T09:30:29.441213Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341846server # [ 19.832251] horae[1483]: 2026-11-07T09:30:29.441231Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191847server # [ 19.834111] horae[1483]: 2026-11-07T09:30:29.441252Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191848server # [ 19.835918] horae[1483]: 2026-11-07T09:30:29.441265Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191849server # [ 19.839878] horae[1483]: 2026-11-07T09:30:29.441278Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191850server # [ 19.841721] horae[1483]: 2026-11-07T09:30:29.441291Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191851server # [ 19.843526] horae[1483]: 2026-11-07T09:30:29.441303Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191852server # [ 19.845290] horae[1483]: 2026-11-07T09:30:29.441315Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191853server # [ 19.847087] horae[1483]: 2026-11-07T09:30:29.441328Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191854server # [ 19.848853] horae[1483]: 2026-11-07T09:30:29.441340Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191855server # [ 19.850613] horae[1483]: 2026-11-07T09:30:29.441353Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829191856server # [ 19.852345] horae[1483]: 2026-11-07T09:30:29.441365Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829191857server # [ 19.854660] horae[1483]: 2026-11-07T09:30:29.441380Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985111858server # [ 19.856466] horae[1483]: 2026-11-07T09:30:29.441395Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218001859server # [ 19.858148] horae[1483]: 2026-11-07T09:30:29.441408Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339551860server # [ 19.859978] horae[1483]: 2026-11-07T09:30:29.441423Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339551861server # [ 19.865415] horae[1483]: 2026-11-07T09:30:29.441452Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339551862server # [ 19.867226] horae[1483]: 2026-11-07T09:30:29.441465Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339551863server # [ 19.869059] horae[1483]: 2026-11-07T09:30:29.441478Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339551864server # [ 19.870866] horae[1483]: 2026-11-07T09:30:29.441492Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339551865server # [ 19.872631] horae[1483]: 2026-11-07T09:30:29.441505Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339551866server # [ 19.874354] horae[1483]: 2026-11-07T09:30:29.441518Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339551867server # [ 19.878090] horae[1483]: 2026-11-07T09:30:29.441531Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339551868server # [ 19.879790] horae[1483]: 2026-11-07T09:30:29.441548Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview1869server # [ 19.881475] horae[1483]: 2026-11-07T09:30:29.441564Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary1870server # [ 19.883198] horae[1483]: 2026-11-07T09:30:29.441577Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection1871server # [ 19.884843] horae[1483]: 2026-11-07T09:30:29.441590Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel1872server # [ 19.886460] horae[1483]: 2026-11-07T09:30:29.441604Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}1873server # [ 19.891611] horae[1483]: 2026-11-07T09:30:29.441618Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start1874server # [ 19.893249] horae[1483]: 2026-11-07T09:30:29.441631Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry1875server # [ 19.894848] horae[1483]: 2026-11-07T09:30:29.441642Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history1876server # [ 19.896439] horae[1483]: 2026-11-07T09:30:29.441655Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client1877server # [ 19.898032] horae[1483]: 2026-11-07T09:30:29.441667Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993931878server # [ 19.899790] horae[1483]: 2026-11-07T09:30:29.441680Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status1879server # [ 19.905113] horae[1483]: 2026-11-07T09:30:29.441693Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove1880server # [ 19.906856] horae[1483]: 2026-11-07T09:30:29.441708Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993931881server # [ 19.908653] horae[1483]: 2026-11-07T09:30:29.441721Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save1882server # [ 19.910514] horae[1483]: 2026-11-07T09:30:29.441735Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993931883server # [ 19.912252] horae[1483]: 2026-11-07T09:30:29.441748Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732061884server # [ 19.914177] horae[1483]: 2026-11-07T09:30:29.441761Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732061885server # [ 19.918965] horae[1483]: 2026-11-07T09:30:29.441773Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732061886server # [ 19.920835] horae[1483]: 2026-11-07T09:30:29.441788Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732061887server # [ 19.922621] horae[1483]: 2026-11-07T09:30:29.441801Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732061888server # [ 19.924372] horae[1483]: 2026-11-07T09:30:29.441820Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732061889server # [ 19.926143] horae[1483]: 2026-11-07T09:30:29.441858Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732061890server # [ 19.927939] horae[1483]: 2026-11-07T09:30:29.441872Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732061891server # [ 19.929838] horae[1483]: 2026-11-07T09:30:29.441890Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732061892server # [ 19.931604] horae[1483]: 2026-11-07T09:30:29.441903Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732061893server # [ 19.933328] horae[1483]: 2026-11-07T09:30:29.441916Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732061894server # [ 19.936502] horae[1483]: 2026-11-07T09:30:29.441928Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732061895server # [ 19.938210] horae[1483]: 2026-11-07T09:30:29.441941Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732061896server # [ 19.939920] horae[1483]: 2026-11-07T09:30:29.441956Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732061897server # [ 19.942891] horae[1483]: 2026-11-07T09:30:29.441968Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732061898server # [ 19.944623] horae[1483]: 2026-11-07T09:30:29.441981Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915711899server # [ 19.946382] horae[1483]: 2026-11-07T09:30:29.441993Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915711900server # [ 19.948147] horae[1483]: 2026-11-07T09:30:29.442006Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915711901server # [ 19.949919] horae[1483]: 2026-11-07T09:30:29.442018Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915711902server # [ 19.951671] horae[1483]: 2026-11-07T09:30:29.442030Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915711903server # [ 19.954931] horae[1483]: 2026-11-07T09:30:29.442042Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915711904server # [ 19.956697] horae[1483]: 2026-11-07T09:30:29.465186Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915711905server # [ 19.958443] horae[1483]: 2026-11-07T09:30:29.465212Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915711906server # [ 19.960153] horae[1483]: 2026-11-07T09:30:29.465227Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915711907server # [ 19.961930] horae[1483]: 2026-11-07T09:30:29.465241Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770261908server # [ 19.963692] horae[1483]: 2026-11-07T09:30:29.465254Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770261909server # [ 19.965422] horae[1483]: 2026-11-07T09:30:29.465267Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770261910server # [ 19.968801] horae[1483]: 2026-11-07T09:30:29.465280Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770261911server # [ 19.970498] horae[1483]: 2026-11-07T09:30:29.465292Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243071912server # [ 19.972170] horae[1483]: 2026-11-07T09:30:29.465306Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243071913server # [ 19.974027] horae[1483]: 2026-11-07T09:30:29.465320Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243071914server # [ 19.976269] horae[1483]: 2026-11-07T09:30:29.465333Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243071915server # [ 19.980179] horae[1483]: 2026-11-07T09:30:29.465346Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861851916server # [ 19.982955] horae[1483]: 2026-11-07T09:30:29.465359Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861851917server # [ 19.985374] horae[1483]: 2026-11-07T09:30:29.465373Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861851918server # [ 19.987733] horae[1483]: 2026-11-07T09:30:29.465385Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861851919server # [ 19.990756] horae[1483]: 2026-11-07T09:30:29.465397Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861851920server # [ 19.993200] horae[1483]: 2026-11-07T09:30:29.465410Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861851921server # [ 19.995391] horae[1483]: 2026-11-07T09:30:29.465424Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273031922server # [ 19.997974] horae[1483]: 2026-11-07T09:30:29.465443Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273031923server # [ 20.000656] horae[1483]: 2026-11-07T09:30:29.465455Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273031924server # [ 20.003195] horae[1483]: 2026-11-07T09:30:29.465472Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273031925server # [ 20.005727] horae[1483]: 2026-11-07T09:30:29.465488Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273031926server # [ 20.008250] horae[1483]: 2026-11-07T09:30:29.465501Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273031927server # [ 20.010158] horae[1483]: 2026-11-07T09:30:29.465514Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648181928server # [ 20.011942] horae[1483]: 2026-11-07T09:30:29.465527Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648181929server # [ 20.013793] horae[1483]: 2026-11-07T09:30:29.465539Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648181930server # [ 20.015560] horae[1483]: 2026-11-07T09:30:29.465552Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648181931server # [ 20.017279] horae[1483]: 2026-11-07T09:30:29.465564Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648181932server # [ 20.018973] horae[1483]: 2026-11-07T09:30:29.465584Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648181933server # [ 20.020707] horae[1483]: 2026-11-07T09:30:29.465597Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648181934server # [ 20.022390] horae[1483]: 2026-11-07T09:30:29.465610Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648181935server # [ 20.024049] horae[1483]: 2026-11-07T09:30:29.504128Z INFO horae: Listening on 127.0.0.1:30001936server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!1937server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)1938server: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start1939server # [ 20.815252] dex[750]: time=2026-11-07T09:30:30.454Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=00fd080c-8b42-4d97-9905-f45d8ceb19651940server # [ 20.832670] horae[1483]: 2026-11-07T09:30:30.471829Z WARN call: horae::auth::oidc: OIDC login denied: no account, and the email is not verified1941server: (finished: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start, in 0.07 seconds)1942server: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt http://127.0.0.1:3000/auth/login1943server: (finished: must succeed: curl -sS -c /tmp/jar9.txt -b /tmp/jar9.txt http://127.0.0.1:3000/auth/login, in 0.02 seconds)1944server: 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'1945server # [ 20.883707] sudo[1509]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to(\'kilgore@kilgore.trout\', \'UTF8\') in data) > 0'1946server # [ 20.904305] sudo[1509]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1947server # [ 20.919300] sudo[1509]: pam_unix(sudo:session): session closed for user horae1948server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM tower_sessions.session WHERE position(convert_to('"'"'kilgore@kilgore.trout'"'"', '"'"'UTF8'"'"') in data) > 0', in 0.06 seconds)1949server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"''1950server # [ 20.939626] sudo[1516]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = \'kilgore@kilgore.trout\''1951server # [ 20.960545] sudo[1516]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)1952server # [ 20.977266] sudo[1516]: pam_unix(sudo:session): session closed for user horae1953server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE lower(email) = '"'"'kilgore@kilgore.trout'"'"'', in 0.06 seconds)1954server: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=kilgore.trout Environment=HORAE_OIDC_TRUST_UNVERIFIED_EMAIL=1 > /run/systemd/system/horae.service.d/omit-email-verified.conf1955server: (finished: must succeed: mkdir -p /run/systemd/system/horae.service.d && printf '%s\n' '[Service]' Environment=HORAE_OIDC_CLIENT_ID=horae-omit-email-verified Environment=HORAE_OIDC_CLIENT_SECRET=horae-omit-e2e-secret Environment=HORAE_OIDC_AUTO_PROVISION_DOMAINS=kilgore.trout Environment=HORAE_OIDC_TRUST_UNVERIFIED_EMAIL=1 > /run/systemd/system/horae.service.d/omit-email-verified.conf, in 0.01 seconds)1956server: must succeed: systemctl daemon-reload && systemctl restart horae.service1957server # [ 21.004483] systemd[1]: Reload requested from client PID 1530 ('systemctl') (unit backdoor.service)...1958server # [ 21.007191] systemd[1]: Reloading...1959server # [ 21.196856] systemd[1]: Reloading finished in 190 ms.1960server # [ 21.227415] systemd[1]: Stopping Horae time tracking server...1961server # [ 21.232757] systemd[1]: horae.service: Deactivated successfully.1962server # [ 21.237823] systemd[1]: Stopped Horae time tracking server.1963server # [ 21.238588] systemd[1]: horae.service: Consumed 72ms CPU time over 1.572s wall clock time, 5.5M memory peak, 8.2K incoming IP traffic, 18.2K outgoing IP traffic.1964server # [ 21.245237] systemd[1]: Starting Horae time tracking server...1965server # [ 21.269606] horae[1568]: 2026-11-07T09:30:30.909386Z INFO horae: Running migrations...1966server # [ 21.271797] horae[1568]: 2026-11-07T09:30:30.911814Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1967server # [ 21.280087] horae[1568]: 2026-11-07T09:30:30.919813Z INFO horae: Migrations complete.1968server # [ 21.285077] systemd[1]: Started Horae time tracking server.1969server: (finished: must succeed: systemctl daemon-reload && systemctl restart horae.service, in 0.30 seconds)1970server: waiting for TCP port 3000 on localhost1971server # [ 21.314569] horae[1575]: 2026-11-07T09:30:30.954392Z INFO horae: Starting Horae on 127.0.0.1:30001972server # [ 21.321058] horae[1575]: 2026-11-07T09:30:30.961037Z INFO sqlx::postgres::notice: relation "_sqlx_migrations" already exists, skipping1973server # [ 21.329624] horae[1575]: 2026-11-07T09:30:30.969015Z INFO horae::plugin::registry: plugins directory does not exist: plugins1974server # [ 21.336421] horae[1575]: 2026-11-07T09:30:30.976399Z INFO sqlx::postgres::notice: schema "tower_sessions" already exists, skipping1975server # [ 21.339993] horae[1575]: 2026-11-07T09:30:30.978305Z INFO sqlx::postgres::notice: relation "session" already exists, skipping1976server # [ 21.341269] horae[1575]: 2026-11-07T09:30:30.978530Z INFO dioxus_server::server: Registering: POST /api/approve_submissions135900591888008486541977server # [ 21.342713] horae[1575]: 2026-11-07T09:30:30.978549Z INFO dioxus_server::server: Registering: POST /api/approve_submission135900591888008486541978server # [ 21.344052] horae[1575]: 2026-11-07T09:30:30.978561Z INFO dioxus_server::server: Registering: POST /api/reject_submission135900591888008486541979server # [ 21.345407] horae[1575]: 2026-11-07T09:30:30.978571Z INFO dioxus_server::server: Registering: POST /api/list_approvals135900591888008486541980server # [ 21.346689] horae[1575]: 2026-11-07T09:30:30.978584Z INFO dioxus_server::server: Registering: POST /api/submit_week135900591888008486541981server # [ 21.347942] horae[1575]: 2026-11-07T09:30:30.978593Z INFO dioxus_server::server: Registering: POST /api/load_task_catalog122563778109868174721982server # [ 21.349509] horae[1575]: 2026-11-07T09:30:30.978604Z INFO dioxus_server::server: Registering: POST /api/add_harvest_people137396755887194634961983server # [ 21.350791] horae[1575]: 2026-11-07T09:30:30.978614Z INFO dioxus_server::server: Registering: POST /api/set_user_active137396755887194634961984server # [ 21.352075] horae[1575]: 2026-11-07T09:30:30.978631Z INFO dioxus_server::server: Registering: POST /api/set_user_role137396755887194634961985server # [ 21.353344] horae[1575]: 2026-11-07T09:30:30.978641Z INFO dioxus_server::server: Registering: POST /api/list_people137396755887194634961986server # [ 21.354608] horae[1575]: 2026-11-07T09:30:30.978650Z INFO dioxus_server::server: Registering: POST /api/create_user137396755887194634961987server # [ 21.355850] horae[1575]: 2026-11-07T09:30:30.978659Z INFO dioxus_server::server: Registering: POST /api/list_users137396755887194634961988server # [ 21.357142] horae[1575]: 2026-11-07T09:30:30.978669Z INFO dioxus_server::server: Registering: POST /api/save_project_managers114747469634461219341989server # [ 21.358474] horae[1575]: 2026-11-07T09:30:30.978678Z INFO dioxus_server::server: Registering: POST /api/load_project_managers114747469634461219341990server # [ 21.359782] horae[1575]: 2026-11-07T09:30:30.978689Z INFO dioxus_server::server: Registering: POST /api/project_creation_selection16044791136740829191991server # [ 21.361124] horae[1575]: 2026-11-07T09:30:30.978706Z INFO dioxus_server::server: Registering: POST /api/project_creation_options16044791136740829191992server # [ 21.363692] horae[1575]: 2026-11-07T09:30:30.978715Z INFO dioxus_server::server: Registering: POST /api/project_creation_client16044791136740829191993server # [ 21.368142] horae[1575]: 2026-11-07T09:30:30.978725Z INFO dioxus_server::server: Registering: POST /api/project_editor_catalog16044791136740829191994server # [ 21.370111] horae[1575]: 2026-11-07T09:30:30.978735Z INFO dioxus_server::server: Registering: POST /api/finalize_project_draft16044791136740829191995server # [ 21.372091] horae[1575]: 2026-11-07T09:30:30.978744Z INFO dioxus_server::server: Registering: POST /api/discard_project_draft16044791136740829191996server # [ 21.373999] horae[1575]: 2026-11-07T09:30:30.978753Z INFO dioxus_server::server: Registering: POST /api/save_project_editor16044791136740829191997server # [ 21.375780] horae[1575]: 2026-11-07T09:30:30.978762Z INFO dioxus_server::server: Registering: POST /api/load_project_editor16044791136740829191998server # [ 21.377589] horae[1575]: 2026-11-07T09:30:30.978772Z INFO dioxus_server::server: Registering: POST /api/save_project_draft16044791136740829191999server # [ 21.379857] horae[1575]: 2026-11-07T09:30:30.978781Z INFO dioxus_server::server: Registering: POST /api/load_project_draft16044791136740829192000server # [ 21.381195] horae[1575]: 2026-11-07T09:30:30.978790Z INFO dioxus_server::server: Registering: POST /api/project_people16044791136740829192001server # [ 21.382590] horae[1575]: 2026-11-07T09:30:30.978799Z INFO dioxus_server::server: Registering: POST /api/get_project_detail_view79311481232659985112002server # [ 21.383975] horae[1575]: 2026-11-07T09:30:30.978810Z INFO dioxus_server::server: Registering: POST /api/list_plugins152655463789645218002003server # [ 21.385287] horae[1575]: 2026-11-07T09:30:30.978820Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_entries163860635615838339552004server # [ 21.386714] horae[1575]: 2026-11-07T09:30:30.978832Z INFO dioxus_server::server: Registering: POST /api/list_time_entry_contexts163860635615838339552005server # [ 21.391658] horae[1575]: 2026-11-07T09:30:30.978853Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_tracking163860635615838339552006server # [ 21.393055] horae[1575]: 2026-11-07T09:30:30.978864Z INFO dioxus_server::server: Registering: POST /api/apply_timesheet_command163860635615838339552007server # [ 21.394417] horae[1575]: 2026-11-07T09:30:30.978874Z INFO dioxus_server::server: Registering: POST /api/list_timesheet_people163860635615838339552008server # [ 21.395717] horae[1575]: 2026-11-07T09:30:30.978889Z INFO dioxus_server::server: Registering: POST /api/load_timesheet_page163860635615838339552009server # [ 21.397040] horae[1575]: 2026-11-07T09:30:30.978899Z INFO dioxus_server::server: Registering: POST /api/get_current_timer163860635615838339552010server # [ 21.398300] horae[1575]: 2026-11-07T09:30:30.978908Z INFO dioxus_server::server: Registering: POST /api/start_timer163860635615838339552011server # [ 21.399607] horae[1575]: 2026-11-07T09:30:30.978917Z INFO dioxus_server::server: Registering: POST /api/stop_timer163860635615838339552012server # [ 21.403162] horae[1575]: 2026-11-07T09:30:30.978927Z INFO dioxus_server::server: Registering: POST /api/import/harvest/commit-preview2013server # [ 21.404508] horae[1575]: 2026-11-07T09:30:30.978940Z INFO dioxus_server::server: Registering: POST /api/import/harvest/error-summary2014server # [ 21.405825] horae[1575]: 2026-11-07T09:30:30.978950Z INFO dioxus_server::server: Registering: POST /api/import/harvest/connection2015server # [ 21.407179] horae[1575]: 2026-11-07T09:30:30.978959Z INFO dioxus_server::server: Registering: POST /api/import/harvest/cancel2016server # [ 21.408489] horae[1575]: 2026-11-07T09:30:30.978969Z INFO dioxus_server::server: Registering: POST /api/import/harvest/csv-job/{mode}2017server # [ 21.409815] horae[1575]: 2026-11-07T09:30:30.978980Z INFO dioxus_server::server: Registering: POST /api/import/harvest/start2018server # [ 21.412888] horae[1575]: 2026-11-07T09:30:30.978989Z INFO dioxus_server::server: Registering: POST /api/import/harvest/retry2019server # [ 21.414151] horae[1575]: 2026-11-07T09:30:30.978998Z INFO dioxus_server::server: Registering: POST /api/import/harvest/history2020server # [ 21.415378] horae[1575]: 2026-11-07T09:30:30.979008Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client2021server # [ 21.416581] horae[1575]: 2026-11-07T09:30:30.979017Z INFO dioxus_server::server: Registering: POST /api/harvest_change_account14792234983801993932022server # [ 21.417939] horae[1575]: 2026-11-07T09:30:30.979026Z INFO dioxus_server::server: Registering: POST /api/import/harvest/status2023server # [ 21.419217] horae[1575]: 2026-11-07T09:30:30.979041Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/remove2024server # [ 21.420453] horae[1575]: 2026-11-07T09:30:30.979089Z INFO dioxus_server::server: Registering: POST /api/harvest_connect_start14792234983801993932025server # [ 21.421810] horae[1575]: 2026-11-07T09:30:30.979109Z INFO dioxus_server::server: Registering: POST /api/import/harvest/client/save2026server # [ 21.423935] horae[1575]: 2026-11-07T09:30:30.979126Z INFO dioxus_server::server: Registering: POST /api/harvest_disconnect14792234983801993932027server # [ 21.425376] horae[1575]: 2026-11-07T09:30:30.979141Z INFO dioxus_server::server: Registering: POST /api/list_project_budget_progress139632003752584732062028server # [ 21.426810] horae[1575]: 2026-11-07T09:30:30.979155Z INFO dioxus_server::server: Registering: POST /api/list_tracking_projects139632003752584732062029server # [ 21.428153] horae[1575]: 2026-11-07T09:30:30.979167Z INFO dioxus_server::server: Registering: POST /api/get_project_overview139632003752584732062030server # [ 21.429475] horae[1575]: 2026-11-07T09:30:30.979179Z INFO dioxus_server::server: Registering: POST /api/set_projects_active139632003752584732062031server # [ 21.430796] horae[1575]: 2026-11-07T09:30:30.979191Z INFO dioxus_server::server: Registering: POST /api/list_tracking_tasks139632003752584732062032server # [ 21.432104] horae[1575]: 2026-11-07T09:30:30.979205Z INFO dioxus_server::server: Registering: POST /api/set_project_active139632003752584732062033server # [ 21.433414] horae[1575]: 2026-11-07T09:30:30.979240Z INFO dioxus_server::server: Registering: POST /api/list_project_spend139632003752584732062034server # [ 21.434704] horae[1575]: 2026-11-07T09:30:30.979250Z INFO dioxus_server::server: Registering: POST /api/list_project_tags139632003752584732062035server # [ 21.435979] horae[1575]: 2026-11-07T09:30:30.979260Z INFO dioxus_server::server: Registering: POST /api/delete_assignment139632003752584732062036server # [ 21.437295] horae[1575]: 2026-11-07T09:30:30.979270Z INFO dioxus_server::server: Registering: POST /api/create_assignment139632003752584732062037server # [ 21.438710] horae[1575]: 2026-11-07T09:30:30.979279Z INFO dioxus_server::server: Registering: POST /api/set_task_active139632003752584732062038server # [ 21.439984] horae[1575]: 2026-11-07T09:30:30.979288Z INFO dioxus_server::server: Registering: POST /api/list_projects139632003752584732062039server # [ 21.441234] horae[1575]: 2026-11-07T09:30:30.979298Z INFO dioxus_server::server: Registering: POST /api/update_task139632003752584732062040server # [ 21.442469] horae[1575]: 2026-11-07T09:30:30.979307Z INFO dioxus_server::server: Registering: POST /api/create_task139632003752584732062041server # [ 21.443734] horae[1575]: 2026-11-07T09:30:30.979317Z INFO dioxus_server::server: Registering: POST /api/list_tasks139632003752584732062042server # [ 21.444958] horae[1575]: 2026-11-07T09:30:30.979326Z INFO dioxus_server::server: Registering: POST /api/update_client_profile104851358257774915712043server # [ 21.446320] horae[1575]: 2026-11-07T09:30:30.979335Z INFO dioxus_server::server: Registering: POST /api/create_project_client104851358257774915712044server # [ 21.447799] horae[1575]: 2026-11-07T09:30:30.979344Z INFO dioxus_server::server: Registering: POST /api/create_client_profile104851358257774915712045server # [ 21.449206] horae[1575]: 2026-11-07T09:30:30.979354Z INFO dioxus_server::server: Registering: POST /api/list_client_invoices104851358257774915712046server # [ 21.450545] horae[1575]: 2026-11-07T09:30:30.979363Z INFO dioxus_server::server: Registering: POST /api/get_client_details104851358257774915712047server # [ 21.451858] horae[1575]: 2026-11-07T09:30:30.979372Z INFO dioxus_server::server: Registering: POST /api/client_detail_view104851358257774915712048server # [ 21.453135] horae[1575]: 2026-11-07T09:30:30.979385Z INFO dioxus_server::server: Registering: POST /api/set_client_active104851358257774915712049server # [ 21.454402] horae[1575]: 2026-11-07T09:30:30.979394Z INFO dioxus_server::server: Registering: POST /api/client_overview104851358257774915712050server # [ 21.455650] horae[1575]: 2026-11-07T09:30:30.979403Z INFO dioxus_server::server: Registering: POST /api/list_clients104851358257774915712051server # [ 21.456879] horae[1575]: 2026-11-07T09:30:30.979412Z INFO dioxus_server::server: Registering: POST /api/update_org_branding130471720523972770262052server # [ 21.458161] horae[1575]: 2026-11-07T09:30:30.979422Z INFO dioxus_server::server: Registering: POST /api/get_org_branding130471720523972770262053server # [ 21.459839] horae[1575]: 2026-11-07T09:30:30.979430Z INFO dioxus_server::server: Registering: POST /api/get_week_start130471720523972770262054server # [ 21.461659] horae[1575]: 2026-11-07T09:30:30.979439Z INFO dioxus_server::server: Registering: POST /api/get_org_name130471720523972770262055server # [ 21.463299] horae[1575]: 2026-11-07T09:30:30.979450Z INFO dioxus_server::server: Registering: POST /api/get_me161443592707961243072056server # [ 21.464825] horae[1575]: 2026-11-07T09:30:30.979460Z INFO dioxus_server::server: Registering: POST /api/list_permission_audit161443592707961243072057server # [ 21.466160] horae[1575]: 2026-11-07T09:30:30.979469Z INFO dioxus_server::server: Registering: POST /api/get_permission_audit161443592707961243072058server # [ 21.467465] horae[1575]: 2026-11-07T09:30:30.979479Z INFO dioxus_server::server: Registering: POST /api/get_my_permissions161443592707961243072059server # [ 21.468742] horae[1575]: 2026-11-07T09:30:30.979489Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_entries76905535698631861852060server # [ 21.470174] horae[1575]: 2026-11-07T09:30:30.979498Z INFO dioxus_server::server: Registering: POST /api/list_visible_time_report_groups76905535698631861852061server # [ 21.471545] horae[1575]: 2026-11-07T09:30:30.979508Z INFO dioxus_server::server: Registering: POST /api/get_time_report_access76905535698631861852062server # [ 21.472857] horae[1575]: 2026-11-07T09:30:30.979517Z INFO dioxus_server::server: Registering: POST /api/get_plugin_widgets76905535698631861852063server # [ 21.474137] horae[1575]: 2026-11-07T09:30:30.979526Z INFO dioxus_server::server: Registering: POST /api/report_detailed76905535698631861852064server # [ 21.475378] horae[1575]: 2026-11-07T09:30:30.979536Z INFO dioxus_server::server: Registering: POST /api/report_time76905535698631861852065server # [ 21.476637] horae[1575]: 2026-11-07T09:30:30.979546Z INFO dioxus_server::server: Registering: POST /api/preview_permission_template_deletion115797103093460273032066server # [ 21.478051] horae[1575]: 2026-11-07T09:30:30.979556Z INFO dioxus_server::server: Registering: POST /api/preview_person_permissions115797103093460273032067server # [ 21.479442] horae[1575]: 2026-11-07T09:30:30.979565Z INFO dioxus_server::server: Registering: POST /api/save_permission_template115797103093460273032068server # [ 21.480772] horae[1575]: 2026-11-07T09:30:30.979575Z INFO dioxus_server::server: Registering: POST /api/list_permission_subjects115797103093460273032069server # [ 21.483095] horae[1575]: 2026-11-07T09:30:30.979585Z INFO dioxus_server::server: Registering: POST /api/save_person_permissions115797103093460273032070server # [ 21.485707] horae[1575]: 2026-11-07T09:30:30.979597Z INFO dioxus_server::server: Registering: POST /api/load_permission_editor115797103093460273032071server # [ 21.487659] horae[1575]: 2026-11-07T09:30:30.979606Z INFO dioxus_server::server: Registering: POST /api/update_invoice_status20640419902238648182072server # [ 21.489446] horae[1575]: 2026-11-07T09:30:30.979616Z INFO dioxus_server::server: Registering: POST /api/review_invoice_edit20640419902238648182073server # [ 21.491199] horae[1575]: 2026-11-07T09:30:30.979626Z INFO dioxus_server::server: Registering: POST /api/save_invoice_draft20640419902238648182074server # [ 21.492935] horae[1575]: 2026-11-07T09:30:30.979635Z INFO dioxus_server::server: Registering: POST /api/get_invoice_editor20640419902238648182075server # [ 21.494722] horae[1575]: 2026-11-07T09:30:30.979644Z INFO dioxus_server::server: Registering: POST /api/generate_invoice20640419902238648182076server # [ 21.496422] horae[1575]: 2026-11-07T09:30:30.979653Z INFO dioxus_server::server: Registering: POST /api/prepare_invoice20640419902238648182077server # [ 21.498128] horae[1575]: 2026-11-07T09:30:30.979665Z INFO dioxus_server::server: Registering: POST /api/list_invoices20640419902238648182078server # [ 21.499951] horae[1575]: 2026-11-07T09:30:30.979673Z INFO dioxus_server::server: Registering: POST /api/get_invoice20640419902238648182079server # [ 21.501673] horae[1575]: 2026-11-07T09:30:31.029892Z INFO horae: Listening on 127.0.0.1:30002080server # Connection to localhost (127.0.0.1) 3000 port [tcp/hbci] succeeded!2081server: (finished: waiting for TCP port 3000 on localhost, in 1.05 seconds)2082server: must succeed: curl -sS -c /tmp/jar10.txt -b /tmp/jar10.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null2083server # [ 22.393189] dex[750]: time=2026-11-07T09:30:32.032Z level=INFO msg="login successful" connector_id=mock username="Kilgore Trout" preferred_username="" email=kilgore@kilgore.trout groups=[authors] request_id=410bb42f-fd0f-448e-9417-b955960754042084server # [ 22.426751] horae[1575]: 2026-11-07T09:30:32.066261Z INFO call: horae::auth::oidc: OIDC sign-in created an account user_id=01a1b558-66fb-7622-b6d7-49e1bdfe37942085server: (finished: must succeed: curl -sS -c /tmp/jar10.txt -b /tmp/jar10.txt -L --max-redirs 8 http://127.0.0.1:3000/auth/oidc/start -o /dev/null, in 0.15 seconds)2086server: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar10.txt http://127.0.0.1:3000/harvest/v2/time_entries2087server: (finished: must succeed: curl -sS -o /dev/null -w '%{http_code}' -b /tmp/jar10.txt http://127.0.0.1:3000/harvest/v2/time_entries, in 0.05 seconds)2088server: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"' AND active AND org_role = '"'"'member'"'"''2089server # [ 22.542970] sudo[1598]: root : TTY=hvc0 ; PWD=/tmp ; USER=horae ; COMMAND=/run/current-system/sw/bin/psql horae -tAc 'SELECT count(*) FROM users WHERE email = \'kilgore@kilgore.trout\' AND active AND org_role = \'member\''2090server # [ 22.564722] sudo[1598]: pam_unix(sudo:session): session opened for user horae(uid=63319) by (uid=0)2091server # [ 22.579450] sudo[1598]: pam_unix(sudo:session): session closed for user horae2092server: (finished: must succeed: sudo -u horae psql horae -tAc 'SELECT count(*) FROM users WHERE email = '"'"'kilgore@kilgore.trout'"'"' AND active AND org_role = '"'"'member'"'"'', in 0.05 seconds)2093server # [ 22.598129] systemd[1]: Reload requested from client PID 1609 ('systemctl') (unit backdoor.service)...2094server # [ 22.601072] systemd[1]: Reloading...2095server # [ 22.819667] systemd[1]: Reloading finished in 218 ms.2096server # [ 22.861621] systemd[1]: Stopping Horae time tracking server...2097server # [ 22.869165] systemd[1]: horae.service: Deactivated successfully.2098server # [ 22.873964] systemd[1]: Stopped Horae time tracking server.2099server # [ 22.875293] systemd[1]: horae.service: Consumed 57ms CPU time over 1.623s wall clock time, 5.7M memory peak, 8.3K incoming IP traffic, 13K outgoing IP traffic.2100server # [ 22.882319] systemd[1]: Starting Horae time tracking server...2101server # [ 22.913572] horae[1647]: Error: HORAE_OIDC_AUTO_PROVISION_DOMAINS must be a comma-separated list of email domains (e.g. example.com,example.org); "*" is not a domain2102server # [ 22.917105] systemd[1]: horae.service: Control process exited, code=exited, status=1/FAILURE2103server # [ 22.918870] systemd[1]: horae.service: Failed with result 'exit-code'.2104server # [ 22.921228] systemd[1]: Failed to start Horae time tracking server.2105server # Job for horae.service failed because the control process exited with error code.2106server # See "systemctl status horae.service" and "journalctl -xeu horae.service" for details.2107server: waiting for failure: systemctl is-active --quiet horae.service2108server: (finished: waiting for failure: systemctl is-active --quiet horae.service, in 0.02 seconds)2109server: must succeed: journalctl -u horae.service --no-pager -n 502110server: (finished: must succeed: journalctl -u horae.service --no-pager -n 50, in 0.01 seconds)2111(finished: run the VM test script, in 30.36 seconds)2112test script finished in 30.40s2113cleanup2114kill QemuMachine (pid 12)2115server # qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/l9k0anq0z7zz81zcwy035jfwap9ga6rl-python3-3.13.13/bin/python3.13)2116(finished: cleanup, in 0.14 seconds)