No user name at acct start
"Kurt Tragant" <[email protected]> Wed, 8 Mar 2006 15:48:28 +0100 (MET)
| Newsgroups | gmane.comp.gnu.radius.general |
|---|---|
| Message-ID | <[email protected]> |
Hello list, I get a request from another radius (not under my control) to my radius. User is [email protected]. Strip-Names is on. The user is granted access by my radius. But then the acct start record is written without the user name. In the acct stop record the user name (test) is included, but I get an error, because the acct start record was written without user name. Is there a mistake on my side or doesn't send the NAS (not under my control) the user name in the acct start record? Thank you in advance. Best regards Kurt users: ------ test Auth-Type = Local, Password = password Service-Type = Login-User config: ------- [snip] auth { listen a.b.c.d; max-requests 127; request-cleanup-delay 2; detail yes; detail-file-name "=nas_name(request_source_ip()) + \"/detail.auth\""; strip-names yes; checkrad-assume-logged yes; }; acct { listen a.b.c.d; max-requests 127; request-cleanup-delay 2; detail-file-name "=nas_name(request_source_ip()) + \"/detail\""; }; [snip] realms: ------- testdomain.com LOCAL detail: ------- Wed Mar 8 13:24:39 2006 Acct-Status-Type = Start Acct-Session-Id = 1234 Timestamp = 1141820679 Request-Authenticator = Verified Wed Mar 8 13:24:46 2006 Acct-Status-Type = Stop Acct-Session-Id = 1234 User-Name = test Acct-Input-Octets = 0 Acct-Output-Gigawords = 0 Acct-Output-Octets = 5061119 Acct-Input-Gigawords = 0 Acct-Session-Time = 9 Framed-IP-Address = e.f.g.h Acct-Output-Packets = 0 Acct-Link-Count = 0 Timestamp = 1141820686 Request-Authenticator = Verified detail.auth: ------------ Wed Mar 8 13:24:39 2006 User-Name = [email protected] Timestamp = 1141820679 Request-Authenticator = None debug information: ------------------ Mär 08 13:24:39 Main.debug: input.c:251:input_select: select returned 1 Mär 08 13:24:39 Main.debug: input.c:136:channel_handle: handling method udp Mär 08 13:24:39 Auth.debug: files.c:943:client_lookup_ip: Found secret for w.x.y.z/255.255.255.255 (w.x.y.z): secret Mär 08 13:24:39 Auth.debug: request.c:392:request_handle: AUTH request 0 added to the list. 1 requests held. Mär 08 13:24:39 Auth.debug: rpp.c:562:rpp_forward_request: sending request to 15642 Mär 08 13:24:39 Auth.debug: rpp.c:221:rpp_fd_write: size=28 Mär 08 13:24:39 Auth.debug: rpp.c:121:pipe_write: n = 4 Mär 08 13:24:39 Auth.debug: rpp.c:200:rpp_fd_read: nbytes=28 Mär 08 13:24:39 Auth.debug: rpp.c:121:pipe_write: n = 28 Mär 08 13:24:39 Auth.debug: rpp.c:212:rpp_fd_read: return 28 Mär 08 13:24:39 Auth.debug: rpp.c:226:rpp_fd_write: return 28 Mär 08 13:24:39 Auth.debug: rpp.c:221:rpp_fd_write: size=62 Mär 08 13:24:39 Auth.debug: rpp.c:121:pipe_write: n = 4 Mär 08 13:24:39 Auth.debug: rpp.c:200:rpp_fd_read: nbytes=62 Mär 08 13:24:39 Auth.debug: rpp.c:121:pipe_write: n = 62 Mär 08 13:24:39 Auth.debug: rpp.c:212:rpp_fd_read: return 62 Mär 08 13:24:39 Auth.debug: rpp.c:226:rpp_fd_write: return 62 Mär 08 13:24:39 Auth.debug: input.c:258:input_select: exit Mär 08 13:24:39 Auth.debug: files.c:943:client_lookup_ip: Found secret for w.x.y.z/255.255.255.255 (w.x.y.z): secret Mär 08 13:24:39 Main.debug: input.c:224:input_select: enter Mär 08 13:24:39 Auth.debug: request.c:392:request_handle: AUTH request 0 added to the list. 1 requests held. Mär 08 13:24:39 Auth.debug: files.c:698:hints_setup: called for `[email protected]' Mär 08 13:24:39 Auth.debug: files.c:856:huntgroup_access: returning 1 Mär 08 13:24:39 Auth.debug: auth.c:761:rad_authenticate: auth: test Mär 08 13:24:39 Auth.debug: files.c:324:user_find_sym: looking for test Mär 08 13:24:39 Auth.debug: sql.c:733:attach_sql_connection: allocating new 0 sql connection Mär 08 13:24:39 Auth.debug: sql.c:747:attach_sql_connection: connection 0 timed out: reconnect Mär 08 13:24:39 Auth.debug: sql.c:752:attach_sql_connection: attaching 0x8086d98 [0] Mär 08 13:24:39 Auth.debug: sql.c:709:sql_cache_lookup: looking up SELECT attr,value,op FROM attrib WHERE user_name='test' AND op IS NOT NULL Mär 08 13:24:39 Auth.debug: sql.c:717:sql_cache_lookup: NOT FOUND Mär 08 13:24:39 Auth.debug: sql.c:664:sql_cache_retrieve: query: SELECT attr,value,op FROM attrib WHERE user_name='test' AND op IS NOT NULL Mär 08 13:24:39 Auth.debug: sql.c:645:sql_cache_insert: cache: 0,(0,0) Mär 08 13:24:39 Auth.debug: sql.c:651:sql_cache_insert: inserting at pos 0 Mär 08 13:24:39 Auth.debug: sql.c:654:sql_cache_insert: tail: 0,1 Mär 08 13:24:39 Auth.debug: files.c:1433:paircmp: returning 0 Mär 08 13:24:39 Auth.debug: sql.c:752:attach_sql_connection: attaching 0x8086d98 [0] Mär 08 13:24:39 Auth.debug: sql.c:709:sql_cache_lookup: looking up SELECT attr,value FROM attrib WHERE user_name='test' AND op IS NULL Mär 08 13:24:39 Auth.debug: sql.c:717:sql_cache_lookup: NOT FOUND Mär 08 13:24:39 Auth.debug: sql.c:664:sql_cache_retrieve: query: SELECT attr,value FROM attrib WHERE user_name='test' AND op IS NULL Mär 08 13:24:39 Auth.debug: sql.c:645:sql_cache_insert: cache: 1,(0,1) Mär 08 13:24:39 Auth.debug: sql.c:651:sql_cache_insert: inserting at pos 1 Mär 08 13:24:39 Auth.debug: sql.c:654:sql_cache_insert: tail: 0,2 Mär 08 13:24:39 Auth.debug: files.c:337:user_find_sym: returning 1 Mär 08 13:24:39 Auth.debug: auth.c:602:rad_check_password: auth_type=0, userpass=password, name=test, password=password Mär 08 13:24:39 Auth.debug: auth.c:648:rad_check_password: auth: Local Mär 08 13:24:39 Auth.debug: auth.c:1282:sfn_ack: ACK: test Mär 08 13:24:39 Auth.notice: (Access-Request HW3 0 "test"): Login OK [test] Mär 08 13:24:39 Auth.debug: sql.c:764:detach_sql_connection: detaching 0x8086d98 [0] Mär 08 13:24:39 Auth.debug: sql.c:767:detach_sql_connection: destructing sql connection 0x8086d98 Mär 08 13:24:39 Auth.debug: rpp.c:688:rpp_request_handler: notifying the master Mär 08 13:24:39 Auth.debug: rpp.c:221:rpp_fd_write: size=8 Mär 08 13:24:39 Auth.debug: rpp.c:226:rpp_fd_write: return 8 Mär 08 13:24:39 Main.debug: input.c:251:input_select: select returned 1 Mär 08 13:24:39 Main.debug: input.c:136:channel_handle: handling method rpp Mär 08 13:24:39 Main.debug: rpp.c:200:rpp_fd_read: nbytes=8 Mär 08 13:24:39 Main.debug: rpp.c:212:rpp_fd_read: return 8 Mär 08 13:24:39 Main.debug: rpp.c:731:rpp_input_handler: updating pid 15642 Mär 08 13:24:39 Main.debug: request.c:406:request_update: enter, pid=15642, ptr = (nil) Mär 08 13:24:39 Main.debug: request.c:418:request_update: exit Mär 08 13:24:39 Main.debug: input.c:258:input_select: exit Mär 08 13:24:39 Main.debug: input.c:224:input_select: enter Mär 08 13:24:39 Main.debug: input.c:251:input_select: select returned 1 Mär 08 13:24:39 Main.debug: input.c:136:channel_handle: handling method udp Mär 08 13:24:39 Acct.debug: files.c:943:client_lookup_ip: Found secret for w.x.y.z/255.255.255.255 (w.x.y.z): secret Mär 08 13:24:39 Acct.debug: request.c:392:request_handle: ACCT request 0 added to the list. 2 requests held. Mär 08 13:24:39 Acct.debug: rpp.c:562:rpp_forward_request: sending request to 15642 Mär 08 13:24:39 Acct.debug: rpp.c:221:rpp_fd_write: size=28 Mär 08 13:24:39 Acct.debug: rpp.c:121:pipe_write: n = 4 Mär 08 13:24:39 Auth.debug: rpp.c:200:rpp_fd_read: nbytes=28 Mär 08 13:24:39 Acct.debug: rpp.c:121:pipe_write: n = 28 Mär 08 13:24:39 Auth.debug: rpp.c:212:rpp_fd_read: return 28 Mär 08 13:24:39 Acct.debug: rpp.c:226:rpp_fd_write: return 28 Mär 08 13:24:39 Acct.debug: rpp.c:221:rpp_fd_write: size=69 Mär 08 13:24:39 Acct.debug: rpp.c:121:pipe_write: n = 4 Mär 08 13:24:39 Auth.debug: rpp.c:200:rpp_fd_read: nbytes=69 Mär 08 13:24:39 Acct.debug: rpp.c:121:pipe_write: n = 69 Mär 08 13:24:39 Auth.debug: rpp.c:212:rpp_fd_read: return 69 Mär 08 13:24:39 Acct.debug: rpp.c:226:rpp_fd_write: return 69 Mär 08 13:24:39 Acct.debug: files.c:943:client_lookup_ip: Found secret for w.x.y.z/255.255.255.255 (w.x.y.z): secret Mär 08 13:24:39 Acct.debug: input.c:258:input_select: exit Mär 08 13:24:39 Acct.debug: request.c:392:request_handle: ACCT request 0 added to the list. 2 requests held. Mär 08 13:24:39 Main.debug: input.c:224:input_select: enter Mär 08 13:24:39 Acct.debug: files.c:698:hints_setup: called for `' Mär 08 13:24:39 Acct.debug: files.c:856:huntgroup_access: returning 1 Mär 08 13:24:39 Acct.debug: acct.c:332:rad_acct_system: start: User at NAS HW3 port 0 session 1234 Mär 08 13:24:39 Acct.debug: sql.c:733:attach_sql_connection: allocating new 1 sql connection Mär 08 13:24:39 Acct.debug: sql.c:747:attach_sql_connection: connection 1 timed out: reconnect Mär 08 13:24:39 Acct.debug: sql.c:752:attach_sql_connection: attaching 0x80877e8 [1] Mär 08 13:24:39 Acct.debug: sql.c:764:detach_sql_connection: detaching 0x80877e8 [1] Mär 08 13:24:39 Acct.debug: sql.c:767:detach_sql_connection: destructing sql connection 0x80877e8 Mär 08 13:24:39 Acct.debug: rpp.c:688:rpp_request_handler: notifying the master Mär 08 13:24:39 Acct.debug: rpp.c:221:rpp_fd_write: size=8 Mär 08 13:24:39 Acct.debug: rpp.c:226:rpp_fd_write: return 8 Mär 08 13:24:39 Main.debug: input.c:251:input_select: select returned 1 Mär 08 13:24:39 Main.debug: input.c:136:channel_handle: handling method rpp Mär 08 13:24:39 Main.debug: rpp.c:200:rpp_fd_read: nbytes=8 Mär 08 13:24:39 Main.debug: rpp.c:212:rpp_fd_read: return 8 Mär 08 13:24:39 Main.debug: rpp.c:731:rpp_input_handler: updating pid 15642 Mär 08 13:24:39 Main.debug: request.c:406:request_update: enter, pid=15642, ptr = (nil) Mär 08 13:24:39 Main.debug: request.c:418:request_update: exit Mär 08 13:24:39 Main.debug: input.c:258:input_select: exit Mär 08 13:24:39 Main.debug: input.c:224:input_select: enter Mär 08 13:24:46 Main.debug: input.c:251:input_select: select returned 1 Mär 08 13:24:46 Main.debug: input.c:136:channel_handle: handling method udp Mär 08 13:24:46 Acct.debug: files.c:943:client_lookup_ip: Found secret for w.x.y.z/255.255.255.255 (w.x.y.z): secret Mär 08 13:24:46 Acct.debug: request.c:202:_request_iterator: deleting completed AUTH request Mär 08 13:24:46 Acct.debug: request.c:202:_request_iterator: deleting completed ACCT request Mär 08 13:24:46 Acct.debug: request.c:392:request_handle: ACCT request 0 added to the list. 1 requests held. Mär 08 13:24:46 Acct.debug: rpp.c:562:rpp_forward_request: sending request to 15642 Mär 08 13:24:46 Acct.debug: rpp.c:221:rpp_fd_write: size=28 Mär 08 13:24:46 Acct.debug: rpp.c:121:pipe_write: n = 4 Mär 08 13:24:46 Acct.debug: rpp.c:200:rpp_fd_read: nbytes=28 Mär 08 13:24:46 Acct.debug: rpp.c:121:pipe_write: n = 28 Mär 08 13:24:46 Acct.debug: rpp.c:212:rpp_fd_read: return 28 Mär 08 13:24:46 Acct.debug: rpp.c:226:rpp_fd_write: return 28 Mär 08 13:24:46 Acct.debug: rpp.c:221:rpp_fd_write: size=127 Mär 08 13:24:46 Acct.debug: rpp.c:121:pipe_write: n = 4 Mär 08 13:24:46 Acct.debug: rpp.c:200:rpp_fd_read: nbytes=127 Mär 08 13:24:46 Acct.debug: rpp.c:121:pipe_write: n = 127 Mär 08 13:24:46 Acct.debug: rpp.c:212:rpp_fd_read: return 127 Mär 08 13:24:46 Acct.debug: rpp.c:226:rpp_fd_write: return 127 Mär 08 13:24:46 Acct.debug: input.c:258:input_select: exit Mär 08 13:24:46 Acct.debug: files.c:943:client_lookup_ip: Found secret for w.x.y.z/255.255.255.255 (w.x.y.z): secret Mär 08 13:24:46 Main.debug: input.c:224:input_select: enter Mär 08 13:24:46 Acct.debug: request.c:202:_request_iterator: deleting completed AUTH request Mär 08 13:24:46 Acct.debug: request.c:202:_request_iterator: deleting completed ACCT request Mär 08 13:24:46 Acct.debug: request.c:392:request_handle: ACCT request 0 added to the list. 1 requests held. Mär 08 13:24:46 Acct.debug: files.c:698:hints_setup: called for `test' Mär 08 13:24:46 Acct.debug: files.c:856:huntgroup_access: returning 1 Mär 08 13:24:46 Acct.debug: acct.c:332:rad_acct_system: stop: User test at NAS HW3 port 0 session 1234 Mär 08 13:24:46 Acct.debug: sql.c:733:attach_sql_connection: allocating new 1 sql connection Mär 08 13:24:46 Acct.debug: sql.c:747:attach_sql_connection: connection 1 timed out: reconnect Mär 08 13:24:46 Acct.debug: sql.c:752:attach_sql_connection: attaching 0x8087ba0 [1] Mär 08 13:24:46 Acct.warning: (Accounting-Request HW3 0 "test"): acct_stop_query updated 0 records Mär 08 13:24:46 Acct.debug: sql.c:764:detach_sql_connection: detaching 0x8087ba0 [1] Mär 08 13:24:46 Acct.debug: sql.c:767:detach_sql_connection: destructing sql connection 0x8087ba0 Mär 08 13:24:46 Acct.debug: rpp.c:688:rpp_request_handler: notifying the master Mär 08 13:24:46 Acct.debug: rpp.c:221:rpp_fd_write: size=8 Mär 08 13:24:46 Acct.debug: rpp.c:226:rpp_fd_write: return 8 Mär 08 13:24:46 Main.debug: input.c:251:input_select: select returned 1 Mär 08 13:24:46 Main.debug: input.c:136:channel_handle: handling method rpp Mär 08 13:24:46 Main.debug: rpp.c:200:rpp_fd_read: nbytes=8 Mär 08 13:24:46 Main.debug: rpp.c:212:rpp_fd_read: return 8 Mär 08 13:24:46 Main.debug: rpp.c:731:rpp_input_handler: updating pid 15642 Mär 08 13:24:46 Main.debug: request.c:406:request_update: enter, pid=15642, ptr = (nil) Mär 08 13:24:46 Main.debug: request.c:418:request_update: exit Mär 08 13:24:46 Main.debug: input.c:258:input_select: exit Mär 08 13:24:46 Main.debug: input.c:224:input_select: enter -- "Feel free" mit GMX FreeMail! Monat für Monat 10 FreeSMS inklusive! http://www.gmx.net