Hi, I have the following config in radiusd.conf: log { destination = file file = ${logdir}/radius.log } When configured with destination = file, it's taking 1 second to write to the file exactly for any linelog configured output. If I change it to syslog instead of file, it's instant. This results in a one-second delay in the reply back to the client. Here is the verbose log output: 2026-04-02T21:31:26.150850Z: (0) [4] unlang_module - linelog (log_auth_access_accept) 2026-04-02T21:31:26.150900Z: (0) ** [5] frame_eval << pushed-child (noop not-set) 2026-04-02T21:31:26.150942Z: (0) ** [5] unlang_interpret - frame action next 2026-04-02T21:31:26.151011Z: (0) ** [5] frame_eval >> function 2026-04-02T21:31:26.151055Z: (0) Calling function 0x7f65be0b9924 (call_env_expand_start) 2026-04-02T21:31:26.151154Z: (0) Calling repeat function 0x7f65be0ba182 (call_env_expand_repeat) 2026-04-02T21:31:26.151239Z: (0) ** [5] frame_eval << calculate-result (... not-set) 2026-04-02T21:31:26.151255Z: (0) ** [5] result_calculate - skipping frame, no result set 2026-04-02T21:31:26.151323Z: (0) ** [5] frame_eval - done current subsection with (noop not-set), will NOT set higher frame rcode (p_result) 2026-04-02T21:31:26.151379Z: (0) ** [5] unlang_interpret - frame action pop 2026-04-02T21:31:26.151393Z: (0) ** [5] unlang_interpret - frame popped 2026-04-02T21:31:26.151441Z: (0) ** [4] unlang_interpret - frame action next 2026-04-02T21:31:26.151486Z: (0) ** [4] frame_eval >> module 2026-04-02T21:31:26.151559Z: (0) [4] unlang_module - linelog (log_auth_access_accept) 2026-04-02T21:31:26.151581Z: (0) log_auth_access_accept - Using default message 2026-04-02T21:31:26.151656Z: (0) log_auth_access_accept - ** [5] frame_eval << pushed-child (noop not-set) 2026-04-02T21:31:26.151867Z: (0) log_auth_access_accept - ** [5] unlang_interpret - frame action next 2026-04-02T21:31:26.151915Z: (0) log_auth_access_accept - ** [5] frame_eval >> tmpl 2026-04-02T21:31:26.151964Z: (0) log_auth_access_accept - ** [5] frame_eval << calculate-result (ok not-set) 2026-04-02T21:31:26.152036Z: (0) log_auth_access_accept - ** [5] result_calculate - have (... not-set) frame or module returned (ok not-set) 2026-04-02T21:31:26.152082Z: (0) log_auth_access_accept - ** [5] result_calculate - using default instruction priority for ok, not-set 2026-04-02T21:31:26.152156Z: (0) log_auth_access_accept - ** [5] result_calculate - overwriting existing result (... not-set) with higher priority (ok not-set) 2026-04-02T21:31:26.152174Z: (0) log_auth_access_accept - ** [5] frame_eval - done current subsection with (ok not-set), will set higher frame rcode 2026-04-02T21:31:26.152271Z: (0) log_auth_access_accept - ** [5] unlang_interpret - frame action pop 2026-04-02T21:31:26.152289Z: (0) log_auth_access_accept - ** [5] unlang_interpret - frame popped 2026-04-02T21:31:26.152325Z: (0) log_auth_access_accept - ** [4] result_pop - using instruction priority for higher frame (ok, 3) 2026-04-02T21:31:26.152399Z: (0) log_auth_access_accept - ** [4] result_calculate - have (ok 3) frame or module returned (ok 3) 2026-04-02T21:31:26.152444Z: (0) log_auth_access_accept - Setting request->rcode to 'ok' 2026-04-02T21:31:26.152459Z: (0) log_auth_access_accept - ** [4] result_calculate - overwriting existing result (ok 3) with higher priority (ok 3) 2026-04-02T21:31:26.152534Z: (0) log_auth_access_accept - ** [4] unlang_interpret - frame action next 2026-04-02T21:31:26.152553Z: (0) log_auth_access_accept - ** [4] frame_eval

...

module 2026-04-02T21:31:26.152711Z: (0) log_auth_access_accept - ** [4] frame_eval << yield (noop not-set) 2026-04-02T21:31:26.152851Z: (0) log_auth_access_accept - ** [4] frame_eval - yielding with current (noop not-set) 2026-04-02T21:31:26.152983Z: (0) log_auth_access_accept - ** [4] unlang_interpret - frame action yield 2026-04-02T21:31:26.153089Z: (0) log_auth_access_accept - ** [4] unlang_interpret - interpret yielding 2026-04-02T21:31:26.153136Z: (0) log_auth_access_accept - _worker_request_yield - Request yielded 2026-04-02T21:31:27.155378Z: (0) log_auth_access_accept - Interpreter - Request marked as runnable 2026-04-02T21:31:27.155422Z: (0) log_auth_access_accept - _worker_request_runnable - Request marked as runnable 2026-04-02T21:31:27.155484Z: (0) log_auth_access_accept - ** [4] unlang_interpret - interpret entered 2026-04-02T21:31:27.155494Z: (0) log_auth_access_accept - _worker_request_resume - Request resuming 2026-04-02T21:31:27.155503Z: (0) log_auth_access_accept - ** [4] unlang_interpret - frame action next 2026-04-02T21:31:27.155514Z: (0) log_auth_access_accept - log_auth_access_accept - Resuming execution 2026-04-02T21:31:27.155523Z: (0) log_auth_access_accept - ** [4] frame_eval module 2026-04-02T21:31:27.155536Z: (0) log_auth_access_accept - log_auth_access_accept (noop) 2026-04-02T21:31:27.155544Z: (0) ** [4] frame_eval << next (noop not-set) 2026-04-02T21:31:27.155556Z: (0) ** [4] frame_eval - done current subsection with (ok 3), will set higher frame rcode 2026-04-02T21:31:27.155564Z: (0) ** [4] unlang_interpret - frame action pop 2026-04-02T21:31:27.155571Z: (0) ** [4] unlang_interpret - frame popped 2026-04-02T21:31:27.155580Z: (0) ** [3] result_pop - using instruction priority for higher frame (ok, not-set) 2026-04-02T21:31:27.155589Z: (0) ** [3] result_calculate - have (noop not-set) frame or module returned (ok not-set) 2026-04-02T21:31:27.155597Z: (0) ** [3] result_calculate - using default instruction priority for ok, not-set 2026-04-02T21:31:27.155606Z: (0) ** [3] result_calculate - overwriting existing result (noop not-set) with higher priority (ok not-set) 2026-04-02T21:31:27.155621Z: (0) } # send Access-Accept ((ok)) 2026-04-02T21:31:27.155629Z: (0) ** [3] unlang_interpret - done current subsection with (... not-set) 2026-04-02T21:31:27.155636Z: (0) ** [3] unlang_interpret - frame action pop 2026-04-02T21:31:27.155643Z: (0) ** [3] unlang_interpret - frame popped 2026-04-02T21:31:27.155650Z: (0) ** [2] unlang_interpret - frame action next 2026-04-02T21:31:27.155658Z: (0) ** [2] frame_eval >> module 2026-04-02T21:31:27.155674Z: (0) Entered state resume_access_accept 2026-04-02T21:31:27.155685Z: (0) request_data_reference: No request data found at 0x5608d64308d0:0 2026-04-02T21:31:27.155693Z: (0) Adding Proxy-State attributes from request 2026-04-02T21:31:27.155703Z: (0) default (noop) 2026-04-02T21:31:27.155710Z: (0) ** [2] frame_eval << calculate-result (noop not-set) 2026-04-02T21:31:27.155718Z: (0) ** [2] result_calculate - have (... not-set) frame or module returned (noop not-set) 2026-04-02T21:31:27.155727Z: (0) Setting request->rcode to 'noop' 2026-04-02T21:31:27.155734Z: (0) ** [2] result_calculate - using default instruction priority for noop, not-set 2026-04-02T21:31:27.155742Z: (0) ** [2] result_calculate - overwriting existing result (... not-set) with higher priority (noop not-set) 2026-04-02T21:31:27.155751Z: (0) ** [2] frame_eval - done current subsection with (noop not-set), will set higher frame rcode 2026-04-02T21:31:27.155759Z: (0) ** [2] unlang_interpret - frame action pop 2026-04-02T21:31:27.155766Z: (0) ** [2] unlang_interpret - frame popped 2026-04-02T21:31:27.155774Z: (0) ** [1] result_pop - using instruction priority for higher frame (noop, not-set) 2026-04-02T21:31:27.155782Z: (0) ** [1] result_calculate - have (... not-set) frame or module returned (noop not-set) 2026-04-02T21:31:27.155790Z: (0) ** [1] result_calculate - using default instruction priority for noop, not-set 2026-04-02T21:31:27.155798Z: (0) ** [1] result_calculate - overwriting existing result (... not-set) with higher priority (noop not-set) 2026-04-02T21:31:27.155806Z: (0) ** [1] unlang_interpret - frame action next 2026-04-02T21:31:27.155815Z: (0) ** [1] frame_eval >> call 2026-04-02T21:31:27.155822Z: (0) ** [1] frame_eval << calculate-result (... not-set) 2026-04-02T21:31:27.155830Z: (0) ** [1] result_calculate - skipping frame, no result set 2026-04-02T21:31:27.155837Z: (0) } # default (noop) 2026-04-02T21:31:27.155844Z: (0) ** [1] frame_eval - done current subsection with (noop not-set), will set higher frame rcode 2026-04-02T21:31:27.155852Z: (0) ** [1] unlang_interpret - frame action pop 2026-04-02T21:31:27.155859Z: (0) ** [1] unlang_interpret - frame popped 2026-04-02T21:31:27.155866Z: (0) ** [0] result_calculate - have (... not-set) frame or module returned (noop not-set) 2026-04-02T21:31:27.155874Z: (0) ** [0] result_calculate - using default instruction priority for noop, not-set 2026-04-02T21:31:27.155882Z: (0) ** [0] result_calculate - overwriting existing result (... not-set) with higher priority (noop not-set) 2026-04-02T21:31:27.155891Z: (0) ** [0] unlang_interpret - interpret exiting, returning (noop) 2026-04-02T21:31:27.155914Z: (0) Done request 2026-04-02T21:31:27.155920Z: (0) Time tracking ended 2026-04-02T21:31:27.155974Z: stk: Currently in fr_radius_encode_pair 2026-04-02T21:31:27.156041Z: stk: > [0] uint32: Acct-Interim-Interval, vendor: 0x0 (0), attr: 0x55 (85) 2026-04-02T21:31:27.156050Z: stk: 2026-04-02T21:31:27.156056Z: stk: Currently in encode_rfc 2026-04-02T21:31:27.156061Z: stk: > [0] uint32: Acct-Interim-Interval, vendor: 0x0 (0), attr: 0x55 (85) 2026-04-02T21:31:27.156069Z: stk: 2026-04-02T21:31:27.156074Z: stk: Currently in encode_child 2026-04-02T21:31:27.156079Z: stk: > [0] uint32: Acct-Interim-Interval, vendor: 0x0 (0), attr: 0x55 (85) 2026-04-02T21:31:27.156086Z: stk: 2026-04-02T21:31:27.156091Z: stk: Currently in encode_value 2026-04-02T21:31:27.156096Z: stk: > [0] uint32: Acct-Interim-Interval, vendor: 0x0 (0), attr: 0x55 (85) 2026-04-02T21:31:27.156104Z: stk: 2026-04-02T21:31:27.156115Z: hex: -- value uint32 -- 2026-04-02T21:31:27.156123Z: hex: 0000: 00 00 00 f0 2026-04-02T21:31:27.156131Z: hex: -- header rfc -- 2026-04-02T21:31:27.156137Z: hex: 0000: 55 06 2026-04-02T21:31:27.156143Z: stk: Currently in fr_radius_encode_pair 2026-04-02T21:31:27.156148Z: stk: > [0] string: User-Name, vendor: 0x0 (0), attr: 0x1 (1) 2026-04-02T21:31:27.156155Z: stk: 2026-04-02T21:31:27.156160Z: stk: Currently in encode_rfc 2026-04-02T21:31:27.156166Z: stk: > [0] string: User-Name, vendor: 0x0 (0), attr: 0x1 (1) 2026-04-02T21:31:27.156172Z: stk: 2026-04-02T21:31:27.156177Z: stk: Currently in encode_child 2026-04-02T21:31:27.156182Z: stk: > [0] string: User-Name, vendor: 0x0 (0), attr: 0x1 (1) 2026-04-02T21:31:27.156189Z: stk: 2026-04-02T21:31:27.156200Z: stk: Currently in encode_value 2026-04-02T21:31:27.156205Z: stk: > [0] string: User-Name, vendor: 0x0 (0), attr: 0x1 (1) 2026-04-02T21:31:27.156212Z: stk: 2026-04-02T21:31:27.156217Z: hex: -- value string -- 2026-04-02T21:31:27.156224Z: hex: 0000: 6d 61 63 61 75 74 68 40 34 41 2d 39 42 2d 44 42 2026-04-02T21:31:27.156231Z: hex: 0010: 2d 37 36 2d 44 36 2d 35 33 2026-04-02T21:31:27.156238Z: hex: -- header rfc -- 2026-04-02T21:31:27.156243Z: hex: 0000: 01 1b 2026-04-02T21:31:27.156249Z: hex: -- fr_radius_encode encoded packet -- 2026-04-02T21:31:27.156256Z: hex: 0000: 02 94 00 47 19 d6 f5 64 9e 8d 68 bf d1 e9 f5 3b 2026-04-02T21:31:27.156264Z: hex: 0010: b5 ed df 2c 50 12 00 00 00 00 00 00 00 00 00 00 2026-04-02T21:31:27.156272Z: hex: 0020: 00 00 00 00 00 00 55 06 00 00 00 f0 01 1b 6d 61 2026-04-02T21:31:27.156280Z: hex: 0030: 63 61 75 74 68 40 34 41 2d 39 42 2d 44 42 2d 37 2026-04-02T21:31:27.156286Z: hex: 0040: 36 2d 44 36 2d 35 33 2026-04-02T21:31:27.156477Z: (0) Sending Access-Accept ID 148 from 0.0.0.0/0:1812 to 127.0.0.1:33797 length 71 via socket radius_udp server * port 1812 2026-04-02T21:31:27.156509Z: (0) Acct-Interim-Interval = 240 2026-04-02T21:31:27.156499Z: (0) Packet-Type = Access-Accept 2026-04-02T21:31:27.156531Z: (0) Finished request 2026-04-02T21:31:27.156547Z: (0) Request deinitialising (0x5608d7a25220)

In particular, you can see the exact one-second gap: 2026-04-02T21:31:26.153136Z: (0) log_auth_access_accept - _worker_request_yield - Request yielded 2026-04-02T21:31:27.155378Z: (0) log_auth_access_accept - Interpreter - Request marked as runnable Any thoughts on why this would be the case? Thanks, James -- Visit purple.ai <https://purple.ai/> Purple on LinkedIn <https://uk.linkedin.com/company/purple-wifi> Email disclaimer <http://www.purple.ai/email-disclaimer/>