Hi Jan I did not see any other error in Ser or Radiusd Debuging, IŽve tested radiusclient with "radclient" and I think its working as I can see in the logs below:
sipser:/usr/local/etc/raddb# radclient -f digest localhost auth hola123 Received response ID 138, code 2, length = 45 Reply-Message = "Hello, test with digest"
on the other hand, freeradius in debug mode just show me authentication process from Ser and it is doing "accounting" for other NAS like gnugk and cisco as5350 (please look the radius log below)... About "radius-ing failed" message, I found this parameter in acc.c (line 674,2-16):
if (rc_acct(SIP_PORT, send)!=OK_RC) { LOG(L_ERR, "ERROR: acc_rad_request: radius-ing failed\n"); goto error; } rc_avpair_free(send); return 1;
please send some advice, thank you
Rafael
PS: FreeRadius is installed in the same host with ser (SuSE Linux 9.0)
Logs in radiusd -X: ###### from test tool "radclient": rad_recv: Access-Request packet from host 127.0.0.1:1295, id=59, length=140 User-Name = "test" Digest-Response = "631d6d73147add2f9e437f59bbc3aeb7" Digest-Attributes = "\001\013testrealm" Digest-Attributes = "\002\n1234abcd" Digest-Attributes = "\003\010INVITE" Digest-Attributes = "\004\034sip:5555551212@example.com" Digest-Attributes = "\006\005MD5" Digest-Attributes = "\n\006test" modcall: entering group authorize for request 95 modcall[authorize]: module "preprocess" returns ok for request 95 modcall[authorize]: module "chap" returns noop for request 95 modcall[authorize]: module "eap" returns noop for request 95 rlm_digest: Converting Digest-Attributes to something sane... Digest-Realm = "testrealm" Digest-Nonce = "1234abcd" Digest-Method = "INVITE" Digest-Uri = "sip:5555551212@example.com" Digest-Algorithm = "MD5" Digest-User-Name = "test" rlm_digest: Adding Auth-Type = DIGEST modcall[authorize]: module "digest" returns ok for request 95 rlm_realm: No '@' in User-Name = "test", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 95 users: Matched test at 309 modcall[authorize]: module "files" returns ok for request 95 modcall[authorize]: module "mschap" returns noop for request 95 modcall: group authorize returns ok for request 95 rad_check_password: Found Auth-Type Digest auth: type "digest" modcall: entering group authenticate for request 95 A1 = test:testrealm:test A2 = INVITE:sip:5555551212@example.com H(A1) = 1e00d6dbd30441265df6064b9d9b7da9 H(A2) = 675b8c827b388805aa252ea38bfb6804 KD = 1e00d6dbd30441265df6064b9d9b7da9:1234abcd:675b8c827b388805aa252ea38bfb6804 EXPECTED 631d6d73147add2f9e437f59bbc3aeb7 RECEIVED 631d6d73147add2f9e437f59bbc3aeb7 modcall[authenticate]: module "digest" returns ok for request 95 modcall: group authenticate returns ok for request 95 radius_xlat: 'Hello, test with digest' Sending Access-Accept of id 59 to 127.0.0.1:1295 Reply-Message = "Hello, test with digest" Finished request 95 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... --- Walking the entire request list --- Cleaning up request 95 ID 59 with timestamp 40fe8d1c Nothing to do. Sleeping until we see a request.
##### :this is from endpoint registration:
Waking up in 6 seconds... rad_recv: Access-Request packet from host 127.0.0.1:1295, id=41, length=209 User-Name = "660300X@200.110.2.132" Digest-Attributes = "\n\t660300X" Digest-Attributes = "\001\017200.110.2.132" Digest-Attributes = "\002*40fe8c883f9b07f4147001c9e11e49383af2cc20" Digest-Attributes = "\004\023sip:200.110.2.132" Digest-Attributes = "\003\nREGISTER" Digest-Response = "f5ceb840e2f11a0c4f83e39d2d61efeb" Service-Type = Sip-Session Sip-Uri-User = "6603000" NAS-IP-Address = 200.110.2.132 NAS-Port = 5060 modcall: entering group authorize for request 75 modcall[authorize]: module "preprocess" returns ok for request 75 modcall[authorize]: module "chap" returns noop for request 75 modcall[authorize]: module "eap" returns noop for request 75 rlm_digest: Converting Digest-Attributes to something sane... Digest-User-Name = "660300X" Digest-Realm = "200.110.2.132" Digest-Nonce = "40fe8c883f9b07f4147001c9e11e49383af2cc20" Digest-Uri = "sip:200.110.2.132" Digest-Method = "REGISTER" rlm_digest: Adding Auth-Type = DIGEST modcall[authorize]: module "digest" returns ok for request 75 rlm_realm: Looking up realm "200.110.2.132" for User-Name = "660300X@200.110.2.132" rlm_realm: No such realm "200.110.2.132" modcall[authorize]: module "suffix" returns noop for request 75 users: Matched 660300X@200.110.2.132 at 319 modcall[authorize]: module "files" returns ok for request 75 modcall[authorize]: module "mschap" returns noop for request 75 modcall: group authorize returns ok for request 75 rad_check_password: Found Auth-Type Digest auth: type "digest" modcall: entering group authenticate for request 75 A1 = 660300X:200.110.2.132:1234 A2 = REGISTER:sip:200.110.2.132 H(A1) = fa8f263b12c7457aeb25d91cdc6f0973 H(A2) = 84021d0e85c74628ca22606d4ef8ae80 KD = fa8f263b12c7457aeb25d91cdc6f0973:40fe8c883f9b07f4147001c9e11e49383af2cc20:84021d0e85c74628ca22606d4ef8ae80 EXPECTED f5ceb840e2f11a0c4f83e39d2d61efeb RECEIVED f5ceb840e2f11a0c4f83e39d2d61efeb modcall[authenticate]: module "digest" returns ok for request 75 modcall: group authenticate returns ok for request 75 radius_xlat: 'Welcome MILLICOM' Sending Access-Accept of id 41 to 127.0.0.1:1295 Reply-Message = "Welcome MILLICOM" Sip-Rpid = "6603000" Finished request 75 Going to the next request
####### this is an acc log from other NAS :
rad_recv: Accounting-Request packet from host 200.110.2.131:10227, id=186, length=351 Acct-Status-Type = Start NAS-IP-Address = 200.110.2.131 NAS-Identifier = "GKProxy01" NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = "1fc600b5" User-Name = "6603000" Framed-IP-Address = 200.110.2.130 Calling-Station-Id = "6603000" Called-Station-Id = "1411#13054224049" h323-gw-id = "h323-gw-id=GKProxy01" h323-conf-id = "h323-conf-id=729F7600 A770D8E2 801C0002 A40055B2" h323-call-origin = "h323-call-origin=proxy" h323-call-type = "h323-call-type=VoIP" h323-setup-time = "h323-setup-time=10:47:03.000 PET Wed Jul 21 2004" h323-remote-address = "h323-remote-address=65.211.214.21" Acct-Delay-Time = 0 modcall: entering group preacct for request 136 modcall[preacct]: module "preprocess" returns noop for request 136 rlm_realm: No '@' in User-Name = "6603000", looking up realm NULL rlm_realm: No such realm "NULL" modcall[preacct]: module "suffix" returns noop for request 136 modcall[preacct]: module "files" returns noop for request 136 modcall: group preacct returns noop for request 136 modcall: entering group accounting for request 136 rlm_acct_unique: WARNING: Attribute NAS-Port-Id was not found in request, unique ID MAY be inconsistent rlm_acct_unique: Hashing ',Client-IP-Address = 200.110.2.131,NAS-IP-Address = 200.110.2.131,Acct-Session-Id = "1fc600b5",User-Name = "6603000"' rlm_acct_unique: Acct-Unique-Session-ID = "299ec4b405cb6fb0". modcall[accounting]: module "acct_unique" returns ok for request 136 radius_xlat: '/usr/local/var/log/radius/radacct/200.110.2.131/detail-20040721' rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/200.110.2.131/detail-20040721 modcall[accounting]: module "detail" returns ok for request 136 modcall[accounting]: module "unix" returns noop for request 136 radius_xlat: '/usr/local/var/log/radius/radutmp' radius_xlat: '6603000' rlm_radutmp: No NAS-Port seen. Cannot do anything. rlm_radumtp: WARNING: checkrad will probably not work! modcall[accounting]: module "radutmp" returns noop for request 136 modcall: group accounting returns ok for request 136 Sending Accounting-Response of id 186 to 200.110.2.131:10227 Finished request 136 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Accounting-Request packet from host 200.110.2.131:10227, id=187, length=508 Acct-Status-Type = Stop NAS-IP-Address = 200.110.2.131 NAS-Identifier = "GKProxy01" NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = "1fc600b5" User-Name = "6603000" Framed-IP-Address = 200.110.2.130 Acct-Session-Time = 1 Calling-Station-Id = "6603000" Called-Station-Id = "1411#13054224049" h323-gw-id = "h323-gw-id=GKProxy01" h323-conf-id = "h323-conf-id=729F7600 A770D8E2 801C0002 A40055B2" h323-call-origin = "h323-call-origin=proxy" h323-call-type = "h323-call-type=VoIP" h323-setup-time = "h323-setup-time=10:47:03.000 PET Wed Jul 21 2004" h323-connect-time = "h323-connect-time=10:47:07.000 PET Wed Jul 21 2004" h323-disconnect-time = "h323-disconnect-time=10:47:08.000 PET Wed Jul 21 2004" h323-disconnect-cause = "h323-disconnect-cause=41" h323-remote-address = "h323-remote-address=65.211.214.21" Acct-Delay-Time = 0 modcall: entering group preacct for request 137 modcall[preacct]: module "preprocess" returns noop for request 137 rlm_realm: No '@' in User-Name = "6603000", looking up realm NULL rlm_realm: No such realm "NULL" modcall[preacct]: module "suffix" returns noop for request 137 modcall[preacct]: module "files" returns noop for request 137 modcall: group preacct returns noop for request 137 modcall: entering group accounting for request 137 rlm_acct_unique: WARNING: Attribute NAS-Port-Id was not found in request, unique ID MAY be inconsistent rlm_acct_unique: Hashing ',Client-IP-Address = 200.110.2.131,NAS-IP-Address = 200.110.2.131,Acct-Session-Id = "1fc600b5",User-Name = "6603000"' rlm_acct_unique: Acct-Unique-Session-ID = "299ec4b405cb6fb0". modcall[accounting]: module "acct_unique" returns ok for request 137 radius_xlat: '/usr/local/var/log/radius/radacct/200.110.2.131/detail-20040721' rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/200.110.2.131/detail-20040721 modcall[accounting]: module "detail" returns ok for request 137 modcall[accounting]: module "unix" returns noop for request 137 radius_xlat: '/usr/local/var/log/radius/radutmp' radius_xlat: '6603000' rlm_radutmp: No NAS-Port seen. Cannot do anything. rlm_radumtp: WARNING: checkrad will probably not work! modcall[accounting]: module "radutmp" returns noop for request 137 modcall: group accounting returns ok for request 137 Sending Accounting-Response of id 187 to 200.110.2.131:10227 Finished request 137 Going to the next request --- Walking the entire request list --- Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 136 ID 186 with timestamp 40fe8edd Waking up in 5 seconds... look the radius log below.--- Walking the entire request list --- Cleaning up request 137 ID 187 with timestamp 40fe8ee2 Nothing to do. Sleeping until we see a request.
Jan Janak jan@iptel.org escribió:
There is some problem with the radiusclient library -- this error comes from the library. Do you see any other error message (generated by the radiusclient library or freeradius server) in the logs ?
Jan.
On 20-07 11:18, Rafael J. Risco G.V. wrote:
Hi
please someone help me... I?m still having problems to obtain radius
accounting and I found this error in the debug file:
. . 7(7511) ERROR: acc_rad_request: radius-ing failed 7(7511) DEBUG: cleanup_uacs: RETR/FR timers reset 7(7511) DEBUG: add_to_tail_of_timer[2]: 0x402f59b8 7(7511) receive_msg: cleaning up 5(7509) ERROR: acc_rad_request: radius-ing failed 5(7509) SER: forwarding ACK statelessly 5(7509) DEBUG: mk_proxy: doing DNS lookup... 5(7509) check_via_address(200.110.6.58, 200.110.6.58, 0) 5(7509) Sending: ACK sip:6603000@10.0.0.236 SIP/2.0 Record-Route: sip:6603000@200.110.2.132;ftag=4040fe43a4;lr=on Via: SIP/2.0/UDP 200.110.2.132;branch=0 Via: SIP/2.0/UDP 200.110.6.58:5060;branch=z9hG4bK4040fe43a418 From: sip:6604000@200.110.2.132;tag=4040fe43a4 To: sip:6603000@200.110.2.132;tag=8e006a06a4 Call-ID: 40d9ba40-16dd-fe9c-8043-0002a4005564@200.110.6.58 CSeq: 18 ACK Route: sip:6603000@200.110.2.132;ftag=4040fe43a4;lr=on Content-Length: 0 Max-Forwards: 69
. . this error appears only when I try "setflag(1)" for the transactions I
want to account, also in this case the ACK message it comes too late (not when pick Up the phone...).
these are some details of my installation:
- SuSE Linux 9.0 (i586)
- ser-0.8.12
- I have followed "radius-how-to" very carefully.
- radiusclient-0.3.2
- freeradius-0.9.3 (installed in the same host with ser)
- I`m Not using mysql (do I have to use it??)
- my current ser.cfg and endpoints configuration are shown below
thanks.
Rafael Risco
PS: Config Files:
# # ----------- global configuration parameters
# debug=3 # debug level (cmd line: -dddddddddd) # fork=yes # log_stderror=no # (cmd line: -E)
#/* Uncomment these lines to enter debugging mode debug=6 fork=yes log_stderror=yes #*/
check_via=no # (cmd. line: -v) dns=no # (cmd. line: -r) rev_dns=no # (cmd. line: -R) port=5060 children=4 fifo="/tmp/ser_fifo"
# ------------------ module loading
# Uncomment this if you want to use SQL database #loadmodule "/usr/local/lib/ser/modules/mysql.so"
loadmodule "/usr/local/lib/ser/modules/sl.so" loadmodule "/usr/local/lib/ser/modules/tm.so" loadmodule "/usr/local/lib/ser/modules/rr.so" loadmodule "/usr/local/lib/ser/modules/maxfwd.so" loadmodule "/usr/local/lib/ser/modules/usrloc.so" loadmodule "/usr/local/lib/ser/modules/registrar.so" # loadmodule "/usr/local/lib/ser/modules/uri.so"
# Uncomment this if you want digest authentication # mysql.so must be loaded ! loadmodule "/usr/local/lib/ser/modules/auth.so" # loadmodule "/usr/local/lib/ser/modules/auth_db.so" loadmodule "/usr/local/lib/ser/modules/auth_radius.so" loadmodule "/usr/local/lib/ser/modules/group_radius.so" loadmodule "/usr/local/lib/ser/modules/acc.so"
# load the NAT Helper Module # loadmodule "/usr/local/lib/ser/modules/nathelper.so"
# ----------------- setting module-specific parameters
# -- usrloc params -- # modparam("usrloc", "db_mode", 0) # Uncomment this if you want to use SQL database # for persistent storage and comment the previous line # modparam("usrloc", "db_mode", 2) # -- auth params -- # Uncomment if you are using auth module # # modparam("auth_db", "calculate_ha1", yes) # # If you set "calculate_ha1" parameter to yes (which true in this
config),
# uncomment also the following parameter) # # modparam("auth_db", "password_column", "password") # -- rr params -- # add value to ;lr param to make some broken UAs happy modparam("rr", "enable_full_lr", 1) # modparam("acc","log_level",1)
modparam("auth_radius","radius_config","/usr/local/etc/radiusclient/radiusclient.conf")
modparam("auth_radius","service_type",15)
modparam("acc","radius_config","/usr/local/etc/radiusclient/radiusclient.conf")
modparam("acc", "service_type", 15) modparam("acc", "radius_flag", 1) modparam("acc", "radius_missed_flag", 3)
# ------------------------- request routing logic
# main routing logic
route{
# initial sanity checks -- messages with # max_forwards==0, or excessively long requests if (!mf_process_maxfwd_header("10")) { sl_send_reply("483","Too Many Hops"); break; }; if ( msg:len > max_len ) { sl_send_reply("513", "Message too big"); break; }; # we record-route all messages -- to make sure that # subsequent messages will go through our proxy; that's # particularly good if upstream and downstream entities # use different transport protocol record_route(); # loose-route processing# if (loose_route()) { # t_relay(); # break; # };
# if the request is for other domain use UsrLoc # (in case, it does not work, use the following command # with proper names and addresses in it) if (method=="REGISTER") { log(1, "REGISTER: Authenticating user\n"); if (!radius_www_authorize("")) { log(1, "REGISTER: challenginguser\n");
www_challenge("", "0"); break; }; save("location"); break; }; if (method=="INVITE") { log(1, "INVITE\n"); setflag(1); /* set for accounting (the same value asin log_flag!) */
}; if (method=="MESSAGE") { log(1, "MESSAGE\n"); setflag(1); /* set for accounting (the same value asin log_flag!) */
}; if (method=="BYE" || method=="CANCEL") { log (1, "BYE or CANCEL\n"); setflag(1); }; # native SIP destinations are handled using our USRLOCDB
if (!lookup("location")) { sl_send_reply("404", "Not Found"); break; }; # forward to current uri now; use stateful forwarding; that # works reliably even if we forward from TCP to UDP if (!t_relay()) { sl_reply_error(); break; };}