What type of defect/bug is this?
Incorrect behaviour of the tacacs server
How can the issue be reproduced?
The error occurs in the current master branch:
root@freeradius:/usr/local/etc/raddb# radiusd -v
Info : radiusd - DEVELOPER BUILD - FreeRADIUS version 4.0.37128 (git #22704eac), for host x86_64-pc-linux-gnu, built on Nov 6 2025 at 14:33:57 [...]
In the tacacs config there are only this two clients. The second client "10.2.0.0/27" is within the first clients subnet 10.0.0.0/14.
client 10.0.0.0/14 {
ipaddr = 10.0.0.0/14
proto = tcp
secret = "1secret1"
}
client 10.2.0.0/27 {
ipaddr = 10.2.0.0/27
proto = tcp
secret = "2secret2"
}
The error can be produced with the tacacs_client by first using the client with the ip 10.0.0.2 and then the second client with the 10.2.0.2. When the seconds client sends the Authentication-Start packet it is decrypted with the wrong secret "1secret1" and the client runs into a timeout.
root@ubuntu:/home/ubuntu# tacacs_client -t pap -u test -H 10.0.0.1 -k 1secret1 -v authenticate
password for test:
status: FAIL
server_msg: b'Failed login!'
root@ubuntu:/home/ubuntu# tacacs_client -t pap -u test -H 10.2.0.1 -k 2secret2 -v authenticate
password for test:
error:
Traceback (most recent call last):
File "/usr/local/bin/tacacs_client", line 163, in main
sys.exit(authenticate(cli, args))
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/bin/tacacs_client", line 116, in authenticate
auth = cli.authenticate(args.username, args.password, priv_lvl=args.priv_lvl,
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/dist-packages/tacacs_plus/client.py", line 200, in authenticate
packet = self.send(
^^^^^^^^^^
File "/usr/local/lib/python3.12/dist-packages/tacacs_plus/client.py", line 153, in send
raise socket.timeout
TimeoutError
The error does not occur when the second client connects first after an restart of freeradius. Then both clients can send packets without any problem.
Log output from the FreeRADIUS daemon
[...]
2025-11-06T15:12:01.583344Z: proto_tacacs_tcp - starting connection tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49
2025-11-06T15:12:01.585884Z: Listening on tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49 bound to virtual server tacacs
2025-11-06T15:12:01.586690Z: Network - Using new socket tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49 with FD 18
2025-11-06T15:12:01.587269Z: Network - Reading data from FD 18
2025-11-06T15:12:01.587687Z: hex: -- tacacs_tcp_recv --
2025-11-06T15:12:01.587731Z: hex: 0000: c1 01 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa
2025-11-06T15:12:01.587762Z: hex: 0010: ba c3 de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30
2025-11-06T15:12:01.587876Z: hex: 0020: 1d 3f 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53
2025-11-06T15:12:01.588010Z: hex: 0030: 51 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.588095Z: proto_tacacs_tcp - Received Authentication seq_no 1 length 56 tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49
2025-11-06T15:12:01.588500Z: Network - Read 56 byte(s) from FD 18
2025-11-06T15:12:01.588595Z: Worker - Received request 1
2025-11-06T15:12:01.588999Z: (0) proto_tacacs decode packet
2025-11-06T15:12:01.589556Z: (0) 0000: c1 01 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa
2025-11-06T15:12:01.589845Z: (0) 0010: ba c3 de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30
2025-11-06T15:12:01.590119Z: (0) 0020: 1d 3f 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53
2025-11-06T15:12:01.590390Z: (0) 0030: 51 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.590469Z: msg: Decoding struct Packet
2025-11-06T15:12:01.590646Z: hex: -- fr_struct_from_network --
2025-11-06T15:12:01.590681Z: hex: 0000: c1 01 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa
2025-11-06T15:12:01.590710Z: hex: 0010: ba c3 de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30
2025-11-06T15:12:01.590807Z: hex: 0020: 1d 3f 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53
2025-11-06T15:12:01.590976Z: hex: 0030: 51 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.591057Z: msg: Decoding struct Packet child Version-Major (1)
2025-11-06T15:12:01.591156Z: hex: -- fr_struct_from_network - remaining 56 --
2025-11-06T15:12:01.591312Z: hex: 0000: c1 01 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa
2025-11-06T15:12:01.591344Z: hex: 0010: ba c3 de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30
2025-11-06T15:12:01.591416Z: hex: 0020: 1d 3f 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53
2025-11-06T15:12:01.591599Z: hex: 0030: 51 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.591746Z: msg: Decoding struct Packet child Version-Minor (2)
2025-11-06T15:12:01.591944Z: hex: -- fr_struct_from_network - remaining 56 --
2025-11-06T15:12:01.591978Z: hex: 0000: c1 01 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa
2025-11-06T15:12:01.592120Z: hex: 0010: ba c3 de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30
2025-11-06T15:12:01.592217Z: hex: 0020: 1d 3f 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53
2025-11-06T15:12:01.592247Z: hex: 0030: 51 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.592279Z: msg: Decoding struct Packet child Packet-Type (3)
2025-11-06T15:12:01.592462Z: hex: -- fr_struct_from_network - remaining 55 --
2025-11-06T15:12:01.592537Z: hex: 0000: 01 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa ba
2025-11-06T15:12:01.592676Z: hex: 0010: c3 de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30 1d
2025-11-06T15:12:01.592892Z: hex: 0020: 3f 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53 51
2025-11-06T15:12:01.592937Z: hex: 0030: 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.592963Z: msg: Decoding struct Packet child Sequence-Number (4)
2025-11-06T15:12:01.592987Z: hex: -- fr_struct_from_network - remaining 54 --
2025-11-06T15:12:01.593002Z: hex: 0000: 01 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa ba c3
2025-11-06T15:12:01.593015Z: hex: 0010: de 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30 1d 3f
2025-11-06T15:12:01.593030Z: hex: 0020: 18 43 60 a6 85 df ff a3 fa 34 77 69 77 53 51 20
2025-11-06T15:12:01.593042Z: hex: 0030: bd 72 61 39 58 f4
2025-11-06T15:12:01.593056Z: msg: Decoding struct Packet child Flags (5)
2025-11-06T15:12:01.593074Z: hex: -- fr_struct_from_network - remaining 53 --
2025-11-06T15:12:01.593088Z: hex: 0000: 00 bb ba 16 2b 00 00 00 2c fa b0 cf fa ba c3 de
2025-11-06T15:12:01.593102Z: hex: 0010: 89 cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30 1d 3f 18
2025-11-06T15:12:01.593116Z: hex: 0020: 43 60 a6 85 df ff a3 fa 34 77 69 77 53 51 20 bd
2025-11-06T15:12:01.593128Z: hex: 0030: 72 61 39 58 f4
2025-11-06T15:12:01.593142Z: msg: Decoding struct Packet child Session-Id (6)
2025-11-06T15:12:01.593160Z: hex: -- fr_struct_from_network - remaining 52 --
2025-11-06T15:12:01.593174Z: hex: 0000: bb ba 16 2b 00 00 00 2c fa b0 cf fa ba c3 de 89
2025-11-06T15:12:01.593188Z: hex: 0010: cd a3 e6 6b cd e5 a7 bc 2b 30 2f 30 1d 3f 18 43
2025-11-06T15:12:01.593202Z: hex: 0020: 60 a6 85 df ff a3 fa 34 77 69 77 53 51 20 bd 72
2025-11-06T15:12:01.593214Z: hex: 0030: 61 39 58 f4
2025-11-06T15:12:01.593229Z: msg: Decoding struct Packet child Length (7)
2025-11-06T15:12:01.593258Z: hex: -- fr_struct_from_network - remaining 48 --
2025-11-06T15:12:01.593273Z: hex: 0000: 00 00 00 2c fa b0 cf fa ba c3 de 89 cd a3 e6 6b
2025-11-06T15:12:01.593286Z: hex: 0010: cd e5 a7 bc 2b 30 2f 30 1d 3f 18 43 60 a6 85 df
2025-11-06T15:12:01.593300Z: hex: 0020: ff a3 fa 34 77 69 77 53 51 20 bd 72 61 39 58 f4
2025-11-06T15:12:01.593316Z: msg: used 56 bytes
2025-11-06T15:12:01.593490Z: hex: -- fr_tacacs_packet_t (unencrypted) --
2025-11-06T15:12:01.593512Z: hex: 0000: c1 01 01 01 bb ba 16 2b 00 00 00 2c 01 00 02 01
2025-11-06T15:12:01.593526Z: hex: 0010: 04 0b 0d 08 74 65 73 74 70 79 74 68 6f 6e 5f 74
2025-11-06T15:12:01.593540Z: hex: 0020: 74 79 30 70 79 74 68 6f 6e 5f 64 65 76 69 63 65
2025-11-06T15:12:01.593553Z: hex: 0030: 1b 5b 41 1b 5b 41 61 73
2025-11-06T15:12:01.593563Z: major 12
2025-11-06T15:12:01.593574Z: minor 1
2025-11-06T15:12:01.593583Z: type 01
2025-11-06T15:12:01.593593Z: seq_no 01
2025-11-06T15:12:01.593603Z: flags 01
2025-11-06T15:12:01.593613Z: sessid bbba162b
2025-11-06T15:12:01.593623Z: length 0000002c
2025-11-06T15:12:01.593633Z: body
2025-11-06T15:12:01.593642Z: authentication-start
2025-11-06T15:12:01.593653Z: action 01
2025-11-06T15:12:01.593663Z: priv_lvl 00
2025-11-06T15:12:01.593673Z: authen_type 02
2025-11-06T15:12:01.593683Z: authen_service 01
2025-11-06T15:12:01.593693Z: user_len 04
2025-11-06T15:12:01.593703Z: port_len 0b
2025-11-06T15:12:01.593713Z: rem_addr_len 0d
2025-11-06T15:12:01.593723Z: data_len 08
2025-11-06T15:12:01.593733Z: user test
2025-11-06T15:12:01.593745Z: port python_tty0
2025-11-06T15:12:01.593755Z: rem_addr python_device
2025-11-06T15:12:01.593770Z: data 0000: 1b 5b 41 1b 5b 41 61 73
2025-11-06T15:12:01.594648Z: (0) Received Authentication-Start ID 1 from 10.0.0.2:41888 to 10.0.0.1:49 length 56 via socket tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49
2025-11-06T15:12:01.595000Z: (0) Packet {
2025-11-06T15:12:01.595277Z: (0) Version-Major = Plus
2025-11-06T15:12:01.596338Z: (0) Version-Minor = 1
2025-11-06T15:12:01.596392Z: (0) Packet-Type = Authentication
2025-11-06T15:12:01.596430Z: (0) Sequence-Number = 1
2025-11-06T15:12:01.596464Z: (0) Flags = None
2025-11-06T15:12:01.596499Z: (0) Session-Id = 3149534763
2025-11-06T15:12:01.596533Z: (0) Length = 44
2025-11-06T15:12:01.596561Z: (0) }
2025-11-06T15:12:01.596615Z: (0) Packet-Body-Type = Start
2025-11-06T15:12:01.596651Z: (0) Action = LOGIN
2025-11-06T15:12:01.596686Z: (0) Privilege-Level = Minimum
2025-11-06T15:12:01.596721Z: (0) Authentication-Type = PAP
2025-11-06T15:12:01.596757Z: (0) Authentication-Service = LOGIN
2025-11-06T15:12:01.596818Z: (0) User-Name = "test"
2025-11-06T15:12:01.597143Z: (0) Client-Port = "python_tty0"
2025-11-06T15:12:01.597187Z: (0) Remote-Address = "python_device"
2025-11-06T15:12:01.597228Z: (0) User-Password = "\033[A\033[Aas"
2025-11-06T15:12:01.597326Z: (0) Time tracking started in yielded state
2025-11-06T15:12:01.597483Z: (0) ** [1] unlang_interpret - interpret entered
2025-11-06T15:12:01.598266Z: (0) _worker_request_resume - Request resuming
2025-11-06T15:12:01.598309Z: (0) ** [1] unlang_interpret - frame action next
2025-11-06T15:12:01.598346Z: (0) tacacs {
2025-11-06T15:12:01.598376Z: (0) ** [1] frame_eval >> call
2025-11-06T15:12:01.598434Z: (0) ** [2] frame_eval << pushed-child (... not-set)
2025-11-06T15:12:01.598470Z: (0) ** [2] unlang_interpret - frame action next
2025-11-06T15:12:01.598530Z: (0) ** [2] frame_eval >> module
2025-11-06T15:12:01.598618Z: (0) [2] unlang_module - tacacs (tacacs)
2025-11-06T15:12:01.598755Z: (0) tacacs - Entered state mod_process
2025-11-06T15:12:01.598906Z: (0) Entered state recv_generic
2025-11-06T15:12:01.598982Z: (0) Running 'recv Authentication-Start' from file /usr/local/etc/raddb/sites-enabled/tacacs
2025-11-06T15:12:01.599078Z: (0) Resetting request->rcode to noop
2025-11-06T15:12:01.599212Z: (0) ** [3] unlang_interpret_push_instruction - substack begins
2025-11-06T15:12:01.599339Z: (0) ** [3] frame_eval << pushed-child (noop not-set)
2025-11-06T15:12:01.599461Z: (0) ** [3] unlang_interpret - frame action next
2025-11-06T15:12:01.599539Z: (0) recv Authentication-Start {
2025-11-06T15:12:01.600103Z: (0) ** [3] frame_eval >> group
2025-11-06T15:12:01.600153Z: (0) ... ignoring empty subsection ...
2025-11-06T15:12:01.600186Z: (0) ** [3] frame_eval << next (... not-set)
2025-11-06T15:12:01.600215Z: (0) }
2025-11-06T15:12:01.600246Z: (0) ** [3] frame_eval - done current subsection with (noop not-set), will NOT set higher frame rcode (p_result)
2025-11-06T15:12:01.600279Z: (0) ** [3] unlang_interpret - frame action pop
2025-11-06T15:12:01.600309Z: (0) ** [3] unlang_interpret - frame popped
2025-11-06T15:12:01.600338Z: (0) ** [2] unlang_interpret - frame action next
2025-11-06T15:12:01.600372Z: (0) ** [2] frame_eval >> module
2025-11-06T15:12:01.600403Z: (0) Entered state resume_auth_start
2025-11-06T15:12:01.600483Z: (0) request_data_reference: No request data found at 0x60d664a68060:0
2025-11-06T15:12:01.600659Z: (0) Running 'authenticate PAP' from file /usr/local/etc/raddb/sites-enabled/tacacs
2025-11-06T15:12:01.600775Z: (0) Resetting request->rcode to noop
2025-11-06T15:12:01.601326Z: (0) ** [3] unlang_interpret_push_instruction - substack begins
2025-11-06T15:12:01.601366Z: (0) ** [3] frame_eval << pushed-child (noop not-set)
2025-11-06T15:12:01.601396Z: (0) ** [3] unlang_interpret - frame action next
2025-11-06T15:12:01.601430Z: (0) authenticate PAP {
2025-11-06T15:12:01.601552Z: (0) ** [3] frame_eval >> group
2025-11-06T15:12:01.601744Z: (0) ... ignoring empty subsection ...
2025-11-06T15:12:01.601857Z: (0) ** [3] frame_eval << next (... not-set)
2025-11-06T15:12:01.601976Z: (0) }
2025-11-06T15:12:01.602383Z: (0) ** [3] frame_eval - done current subsection with (noop not-set), will NOT set higher frame rcode (p_result)
2025-11-06T15:12:01.602422Z: (0) ** [3] unlang_interpret - frame action pop
2025-11-06T15:12:01.602451Z: (0) ** [3] unlang_interpret - frame popped
2025-11-06T15:12:01.602565Z: (0) ** [2] unlang_interpret - frame action next
2025-11-06T15:12:01.602632Z: (0) ** [2] frame_eval >> module
2025-11-06T15:12:01.602727Z: (0) Entered state resume_auth_type
2025-11-06T15:12:01.602829Z: (0) Failed to authenticate the user
2025-11-06T15:12:01.602847Z: (0) Entered state send_generic
2025-11-06T15:12:01.602865Z: (0) Running 'send Authentication-Fail' from file /usr/local/etc/raddb/sites-enabled/tacacs
2025-11-06T15:12:01.602880Z: (0) Resetting request->rcode to noop
2025-11-06T15:12:01.602904Z: (0) ** [3] unlang_interpret_push_instruction - substack begins
2025-11-06T15:12:01.602921Z: (0) ** [3] frame_eval << pushed-child (noop not-set)
2025-11-06T15:12:01.602936Z: (0) ** [3] unlang_interpret - frame action next
2025-11-06T15:12:01.602951Z: (0) send Authentication-Fail {
2025-11-06T15:12:01.602965Z: (0) ** [3] frame_eval >> group
2025-11-06T15:12:01.602980Z: (0) ** [4] frame_eval << pushed-child (... not-set)
2025-11-06T15:12:01.602994Z: (0) ** [4] unlang_interpret - frame action next
2025-11-06T15:12:01.603010Z: (0) ** [4] frame_eval >> edit
2025-11-06T15:12:01.603103Z: (0) reply.Server-Message := "Failed login!"
2025-11-06T15:12:01.603144Z: (0) ** [4] frame_eval << calculate-result (... not-set)
2025-11-06T15:12:01.603167Z: (0) ** [4] result_calculate - skipping frame, no result set
2025-11-06T15:12:01.603197Z: (0) ** [4] frame_eval - done current subsection with (... not-set), will set higher frame rcode
2025-11-06T15:12:01.603223Z: (0) ** [4] unlang_interpret - frame action pop
2025-11-06T15:12:01.603238Z: (0) ** [4] unlang_interpret - frame popped
2025-11-06T15:12:01.603253Z: (0) ** [3] result_pop - using instruction priority for higher frame (..., not-set)
2025-11-06T15:12:01.603267Z: (0) ** [3] result_calculate - skipping frame, no result set
2025-11-06T15:12:01.603284Z: (0) } # send Authentication-Fail ((noop))
2025-11-06T15:12:01.603298Z: (0) ** [3] unlang_interpret - frame action next
2025-11-06T15:12:01.603313Z: (0) ** [3] frame_eval - done current subsection with (noop not-set), will NOT set higher frame rcode (p_result)
2025-11-06T15:12:01.603328Z: (0) ** [3] unlang_interpret - frame action pop
2025-11-06T15:12:01.603342Z: (0) ** [3] unlang_interpret - frame popped
2025-11-06T15:12:01.603355Z: (0) ** [2] unlang_interpret - frame action next
2025-11-06T15:12:01.603375Z: (0) ** [2] frame_eval >> module
2025-11-06T15:12:01.603389Z: (0) Entered state resume_auth_fail
2025-11-06T15:12:01.603404Z: (0) tacacs (noop)
2025-11-06T15:12:01.603418Z: (0) ** [2] frame_eval << calculate-result (noop not-set)
2025-11-06T15:12:01.603433Z: (0) ** [2] result_calculate - have (... not-set) frame or module returned (noop not-set)
2025-11-06T15:12:01.603449Z: (0) ** [2] result_calculate - using default instruction priority for noop, not-set
2025-11-06T15:12:01.603466Z: (0) ** [2] result_calculate - overwriting existing result (... not-set) with higher priority (noop not-set)
2025-11-06T15:12:01.603482Z: (0) ** [2] frame_eval - done current subsection with (noop not-set), will set higher frame rcode
2025-11-06T15:12:01.603497Z: (0) ** [2] unlang_interpret - frame action pop
2025-11-06T15:12:01.603511Z: (0) ** [2] unlang_interpret - frame popped
2025-11-06T15:12:01.603526Z: (0) ** [1] result_pop - using instruction priority for higher frame (noop, not-set)
2025-11-06T15:12:01.603543Z: (0) ** [1] result_calculate - have (... not-set) frame or module returned (noop not-set)
2025-11-06T15:12:01.603572Z: (0) ** [1] result_calculate - using default instruction priority for noop, not-set
2025-11-06T15:12:01.603598Z: (0) ** [1] result_calculate - overwriting existing result (... not-set) with higher priority (noop not-set)
2025-11-06T15:12:01.603615Z: (0) ** [1] unlang_interpret - frame action next
2025-11-06T15:12:01.603632Z: (0) ** [1] frame_eval >> call
2025-11-06T15:12:01.603647Z: (0) ** [1] frame_eval << calculate-result (... not-set)
2025-11-06T15:12:01.603661Z: (0) ** [1] result_calculate - skipping frame, no result set
2025-11-06T15:12:01.603675Z: (0) } # tacacs (noop)
2025-11-06T15:12:01.603689Z: (0) ** [1] frame_eval - done current subsection with (noop not-set), will set higher frame rcode
2025-11-06T15:12:01.603704Z: (0) ** [1] unlang_interpret - frame action pop
2025-11-06T15:12:01.603717Z: (0) ** [1] unlang_interpret - frame popped
2025-11-06T15:12:01.603731Z: (0) ** [0] result_calculate - have (... not-set) frame or module returned (noop not-set)
2025-11-06T15:12:01.603747Z: (0) ** [0] result_calculate - using default instruction priority for noop, not-set
2025-11-06T15:12:01.603763Z: (0) ** [0] result_calculate - overwriting existing result (... not-set) with higher priority (noop not-set)
2025-11-06T15:12:01.605032Z: (0) ** [0] unlang_interpret - interpret exiting, returning (noop)
2025-11-06T15:12:01.605838Z: (0) Done request
2025-11-06T15:12:01.606650Z: (0) Time tracking ended
2025-11-06T15:12:01.606983Z: hex: -- Server-Message --
2025-11-06T15:12:01.607272Z: hex: 0000: 46 61 69 6c 65 64 20 6c 6f 67 69 6e 21
2025-11-06T15:12:01.607894Z: major 12
2025-11-06T15:12:01.607954Z: minor 1
2025-11-06T15:12:01.608507Z: type 01
2025-11-06T15:12:01.608545Z: seq_no 02
2025-11-06T15:12:01.608591Z: flags 01
2025-11-06T15:12:01.608638Z: sessid bbba162b
2025-11-06T15:12:01.608666Z: length 00000013
2025-11-06T15:12:01.608758Z: body
2025-11-06T15:12:01.608838Z: authentication-reply
2025-11-06T15:12:01.609355Z: status 02
2025-11-06T15:12:01.609457Z: flags 00
2025-11-06T15:12:01.609485Z: server_msg_len 000d
2025-11-06T15:12:01.609511Z: data_len 0000
2025-11-06T15:12:01.609537Z: server_msg Failed login!
2025-11-06T15:12:01.609585Z: hex: -- fr_tacacs_packet_t (unencrypted) --
2025-11-06T15:12:01.609631Z: hex: 0000: c1 01 02 00 bb ba 16 2b 00 00 00 13 02 00 00 0d
2025-11-06T15:12:01.609662Z: hex: 0010: 00 00 46 61 69 6c 65 64 20 6c 6f 67 69 6e 21
2025-11-06T15:12:01.609712Z: hex: -- fr_tacacs_packet_t (encoded) --
2025-11-06T15:12:01.609816Z: hex: 0000: c1 01 02 00 bb ba 16 2b 00 00 00 13 0e 3b d0 8b
2025-11-06T15:12:01.609954Z: hex: 0010: 5c 45 14 e9 f9 00 28 da 36 21 62 67 44 88 7e
2025-11-06T15:12:01.610081Z: (0) Sending Authentication-Fail ID 2 from 10.0.0.1:49 to 10.0.0.2:41888 length 31 via socket tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49
2025-11-06T15:12:01.610226Z: (0) Packet-Type = Authentication-Fail
2025-11-06T15:12:01.610406Z: (0) Server-Message = "Failed login!"
2025-11-06T15:12:01.610988Z: (0) proto_tacacs encode packet
2025-11-06T15:12:01.611028Z: (0) 0000: c1 01 02 00 bb ba 16 2b 00 00 00 13 0e 3b d0 8b
2025-11-06T15:12:01.611062Z: (0) 0010: 5c 45 14 e9 f9 00 28 da 36 21 62 67 44 88 7e
2025-11-06T15:12:01.611096Z: (0) Finished request
2025-11-06T15:12:01.611132Z: (0) Request deinitialising (0x60d6669915e0)
2025-11-06T15:12:01.611201Z: Processing reply for tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49
2025-11-06T15:12:01.611469Z: Not tracking duplicates - expiring the request
2025-11-06T15:12:01.612316Z: proto_tacacs_tcp - cleaning up
2025-11-06T15:12:01.612454Z: TIMER - setting idle timeout to 60s for connection from client 10.0.0.0/14
2025-11-06T15:12:01.612665Z: Network - Socket tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49 closed by peer
2025-11-06T15:12:01.613144Z: Closing connection tacacs_tcp from client 10.0.0.2 port 41888 to server * port 49
2025-11-06T15:12:01.614096Z: Freeing .tcp.0 (0x60d665c2bb10)
2025-11-06T15:12:03.974236Z: Network - Reading data from FD 17
2025-11-06T15:12:03.974385Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: ipaddr
2025-11-06T15:12:03.974404Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: ipv4addr
2025-11-06T15:12:03.974415Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: ipv6addr
2025-11-06T15:12:03.974426Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: interface
2025-11-06T15:12:03.974441Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: port_name
2025-11-06T15:12:03.974457Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: port
2025-11-06T15:12:03.974468Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: recv_buff
2025-11-06T15:12:03.974496Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: dynamic_clients
2025-11-06T15:12:03.974507Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: networks {}
2025-11-06T15:12:03.974518Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: max_packet_size
2025-11-06T15:12:03.974528Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: max_attributes
2025-11-06T15:12:03.974538Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: read_hexdump
2025-11-06T15:12:03.974548Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Pushed parse rule to tcp section: write_hexdump
2025-11-06T15:12:03.974559Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: tcp {
2025-11-06T15:12:03.974572Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: ipaddr = *
2025-11-06T15:12:03.974594Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: port = 49
2025-11-06T15:12:03.974856Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Evaluating rules for networks section. Output 0x60d66687b060
2025-11-06T15:12:03.974874Z: src/lib/server/cf_parse.c[863]: Pushed parse rule to networks section: allow
2025-11-06T15:12:03.974886Z: src/lib/server/cf_parse.c[863]: Pushed parse rule to networks section: deny
2025-11-06T15:12:03.974896Z: src/lib/server/cf_parse.c[863]: networks {
2025-11-06T15:12:03.974906Z: src/lib/server/cf_parse.c[863]: }
2025-11-06T15:12:03.974916Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: max_packet_size = 4096
2025-11-06T15:12:03.974929Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: max_attributes = 256
2025-11-06T15:12:03.974940Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: }
2025-11-06T15:12:03.974957Z: /usr/local/etc/raddb/sites-enabled/tacacs[115]: Instantiating proto_tacacs_tcp ".tcp.1"
2025-11-06T15:12:03.974989Z: proto_tacacs_tcp - starting connection tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49
2025-11-06T15:12:03.975239Z: Listening on tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49 bound to virtual server tacacs
2025-11-06T15:12:03.975262Z: Network - Using new socket tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49 with FD 18
2025-11-06T15:12:03.975310Z: Network - Reading data from FD 18
2025-11-06T15:12:03.975332Z: hex: -- tacacs_tcp_recv --
2025-11-06T15:12:03.975343Z: hex: 0000: c1 01 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a
2025-11-06T15:12:03.975360Z: hex: 0010: 46 34 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0
2025-11-06T15:12:03.975382Z: hex: 0020: 20 a0 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75
2025-11-06T15:12:03.975394Z: hex: 0030: 5f 5f ed c0
2025-11-06T15:12:03.975403Z: proto_tacacs_tcp - Received Authentication seq_no 1 length 52 tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49
2025-11-06T15:12:03.975421Z: Network - Read 52 byte(s) from FD 18
2025-11-06T15:12:03.975436Z: Worker - Received request 2
2025-11-06T15:12:03.975493Z: (1) proto_tacacs decode packet
2025-11-06T15:12:03.975513Z: (1) 0000: c1 01 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a
2025-11-06T15:12:03.975524Z: (1) 0010: 46 34 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0
2025-11-06T15:12:03.975532Z: (1) 0020: 20 a0 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75
2025-11-06T15:12:03.975540Z: (1) 0030: 5f 5f ed c0
2025-11-06T15:12:03.975549Z: msg: Decoding struct Packet
2025-11-06T15:12:03.975562Z: hex: -- fr_struct_from_network --
2025-11-06T15:12:03.975571Z: hex: 0000: c1 01 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a
2025-11-06T15:12:03.975578Z: hex: 0010: 46 34 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0
2025-11-06T15:12:03.975586Z: hex: 0020: 20 a0 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75
2025-11-06T15:12:03.975593Z: hex: 0030: 5f 5f ed c0
2025-11-06T15:12:03.975605Z: msg: Decoding struct Packet child Version-Major (1)
2025-11-06T15:12:03.975616Z: hex: -- fr_struct_from_network - remaining 52 --
2025-11-06T15:12:03.975624Z: hex: 0000: c1 01 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a
2025-11-06T15:12:03.975632Z: hex: 0010: 46 34 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0
2025-11-06T15:12:03.975640Z: hex: 0020: 20 a0 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75
2025-11-06T15:12:03.975646Z: hex: 0030: 5f 5f ed c0
2025-11-06T15:12:03.975654Z: msg: Decoding struct Packet child Version-Minor (2)
2025-11-06T15:12:03.975665Z: hex: -- fr_struct_from_network - remaining 52 --
2025-11-06T15:12:03.975673Z: hex: 0000: c1 01 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a
2025-11-06T15:12:03.975680Z: hex: 0010: 46 34 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0
2025-11-06T15:12:03.975688Z: hex: 0020: 20 a0 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75
2025-11-06T15:12:03.975694Z: hex: 0030: 5f 5f ed c0
2025-11-06T15:12:03.975702Z: msg: Decoding struct Packet child Packet-Type (3)
2025-11-06T15:12:03.975712Z: hex: -- fr_struct_from_network - remaining 51 --
2025-11-06T15:12:03.975720Z: hex: 0000: 01 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a 46
2025-11-06T15:12:03.975727Z: hex: 0010: 34 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0 20
2025-11-06T15:12:03.975735Z: hex: 0020: a0 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75 5f
2025-11-06T15:12:03.975741Z: hex: 0030: 5f ed c0
2025-11-06T15:12:03.975751Z: msg: Decoding struct Packet child Sequence-Number (4)
2025-11-06T15:12:03.975762Z: hex: -- fr_struct_from_network - remaining 50 --
2025-11-06T15:12:03.976646Z: hex: 0000: 01 00 85 1d bc f0 00 00 00 28 87 19 8a 7a 46 34
2025-11-06T15:12:03.976723Z: hex: 0010: 41 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0 20 a0
2025-11-06T15:12:03.976814Z: hex: 0020: 4a 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75 5f 5f
2025-11-06T15:12:03.976896Z: hex: 0030: ed c0
2025-11-06T15:12:03.976972Z: msg: Decoding struct Packet child Flags (5)
2025-11-06T15:12:03.977052Z: hex: -- fr_struct_from_network - remaining 49 --
2025-11-06T15:12:03.977119Z: hex: 0000: 00 85 1d bc f0 00 00 00 28 87 19 8a 7a 46 34 41
2025-11-06T15:12:03.977160Z: hex: 0010: 1c 28 fa b6 de 56 59 e7 95 70 4c f2 b0 20 a0 4a
2025-11-06T15:12:03.977221Z: hex: 0020: 3d 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75 5f 5f ed
2025-11-06T15:12:03.977260Z: hex: 0030: c0
2025-11-06T15:12:03.977301Z: msg: Decoding struct Packet child Session-Id (6)
2025-11-06T15:12:03.977372Z: hex: -- fr_struct_from_network - remaining 48 --
2025-11-06T15:12:03.977413Z: hex: 0000: 85 1d bc f0 00 00 00 28 87 19 8a 7a 46 34 41 1c
2025-11-06T15:12:03.977679Z: hex: 0010: 28 fa b6 de 56 59 e7 95 70 4c f2 b0 20 a0 4a 3d
2025-11-06T15:12:03.977700Z: hex: 0020: 1e 45 b0 cd d8 f1 7b a3 a6 9b 48 75 5f 5f ed c0
2025-11-06T15:12:03.977721Z: msg: Decoding struct Packet child Length (7)
2025-11-06T15:12:03.977742Z: hex: -- fr_struct_from_network - remaining 44 --
2025-11-06T15:12:03.977759Z: hex: 0000: 00 00 00 28 87 19 8a 7a 46 34 41 1c 28 fa b6 de
2025-11-06T15:12:03.977791Z: hex: 0010: 56 59 e7 95 70 4c f2 b0 20 a0 4a 3d 1e 45 b0 cd
2025-11-06T15:12:03.977808Z: hex: 0020: d8 f1 7b a3 a6 9b 48 75 5f 5f ed c0
2025-11-06T15:12:03.977825Z: msg: used 52 bytes
2025-11-06T15:12:03.977909Z: hex: -- fr_tacacs_packet_t (unencrypted) --
2025-11-06T15:12:03.977992Z: hex: 0000: c1 01 01 01 85 1d bc f0 00 00 00 28 a7 00 45 49
2025-11-06T15:12:03.978064Z: hex: 0010: ef 37 32 39 62 22 c9 22 94 63 95 0f af 0e 66 aa
2025-11-06T15:12:03.978335Z: hex: 0020: c0 45 8b c8 d6 d7 2f f2 5a 82 43 45 23 6d ca a4
2025-11-06T15:12:03.978355Z: hex: 0030: d9 e0 02 11
2025-11-06T15:12:03.978370Z: major 12
2025-11-06T15:12:03.978384Z: minor 1
2025-11-06T15:12:03.978397Z: type 01
2025-11-06T15:12:03.978411Z: seq_no 01
2025-11-06T15:12:03.978450Z: flags 01
2025-11-06T15:12:03.978508Z: sessid 851dbcf0
2025-11-06T15:12:03.978525Z: length 00000028
2025-11-06T15:12:03.978563Z: body
2025-11-06T15:12:03.978601Z: authentication-start
2025-11-06T15:12:03.978640Z: action a7
2025-11-06T15:12:03.978701Z: priv_lvl 00
2025-11-06T15:12:03.978953Z: authen_type 45
2025-11-06T15:12:03.978988Z: authen_service 49
2025-11-06T15:12:03.979016Z: user_len ef
2025-11-06T15:12:03.979042Z: port_len 37
2025-11-06T15:12:03.979066Z: rem_addr_len 32
2025-11-06T15:12:03.979088Z: data_len 39
2025-11-06T15:12:03.979160Z: TRUNCATED 0000: 62 22 c9 22 94 63 95 0f af 0e 66 aa c0 45 8b c8
2025-11-06T15:12:03.979226Z: TRUNCATED 0010: d6 d7 2f f2 5a 82 43 45 23 6d ca a4 d9 e0 02 11
2025-11-06T15:12:03.979277Z: ERROR : (1) Failed decoding packet: Data overflows the packet
2025-11-06T15:12:03.979369Z: (1) Request deinitialising (0x60d6669953a0)
2025-11-06T15:12:03.979632Z: Processing reply for tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49
2025-11-06T15:12:03.979683Z: Not sending response to request - it is marked as 'do not respond'
2025-11-06T15:12:03.979700Z: proto_tacacs_tcp - cleaning up
2025-11-06T15:12:03.979717Z: TIMER - setting idle timeout to 60s for connection from client 10.0.0.0/14
2025-11-06T15:12:13.988897Z: Network - Socket tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49 closed by peer
2025-11-06T15:12:13.996317Z: Closing connection tacacs_tcp from client 10.2.0.2 port 44568 to server * port 49
2025-11-06T15:12:13.996452Z: Freeing .tcp.1 (0x60d665c2bb10)
[...]
Relevant log output from client utilities
No response
Backtrace from LLDB or GDB
What type of defect/bug is this?
Incorrect behaviour of the tacacs server
How can the issue be reproduced?
The error occurs in the current master branch:
In the tacacs config there are only this two clients. The second client "10.2.0.0/27" is within the first clients subnet 10.0.0.0/14.
The error can be produced with the tacacs_client by first using the client with the ip 10.0.0.2 and then the second client with the 10.2.0.2. When the seconds client sends the Authentication-Start packet it is decrypted with the wrong secret "1secret1" and the client runs into a timeout.
The error does not occur when the second client connects first after an restart of freeradius. Then both clients can send packets without any problem.
Log output from the FreeRADIUS daemon
Relevant log output from client utilities
No response
Backtrace from LLDB or GDB