Hi
I’m running freeradius 1.1.8 with rlm_exec. External program on ACCTOUNTING packets runs and my external program returns OK! And printout the following in its logfile: (PID 5036) 2011-09-15 18:24:28 Packet: updt UserName: hhsde0100413@tct9 187923@172.31.3.7 10320 Sec 3993228/61717432 Bytes FreeRADIUS Debugging shows log as the following and shows everything goes fine for that request. Thu Sep 15 18:24:28 2011 : Debug: Thread 1 handling request 175, (31 handled so far) User-Name = "hhsde0100413@tct9" NAS-Port = 136339956 NAS-IP-Address = 172.31.3.7 Framed-IP-Address = 2.179.17.211 Filter-Id = "tct9" Class = 0x68687364653031303034313340746374397c387c3137322e33312e332e377c316361666637623036653264 rad_recv: Accounting-Request packet from host 172.31.3.7:1813, id=92, length=530 NAS-Identifier = "KJ-RJ-ME60X16-01" Acct-Status-Type = Interim-Update Acct-Delay-Time = 0 Acct-Input-Octets = 3993228 Acct-Output-Octets = 61717432 Acct-Session-Id = "KJ-RJ-M08206050000000890a6e187923" Acct-Authentic = RADIUS Acct-Session-Time = 10320 Acct-Input-Packets = 45602 Acct-Output-Packets = 50322 Acct-Input-Gigawords = 0 Acct-Output-Gigawords = 0 Thu Sep 15 18:24:28 2011 : Debug: Thread 1 handling request 175, (31 handled so far) Thu Sep 15 18:24:28 2011 : Debug: modcall: entering group preacct for request 175 Thu Sep 15 18:24:28 2011 : Debug: modsingle[preacct]: calling preprocess (rlm_preprocess) for request 175 Acct-Session-Time = 10320Thu Sep 15 18:24:28 2011 : Debug: modsingle[preacct]: returned from preprocess (rlm_preprocess) for request 175 Thu Sep 15 18:24:28 2011 : Debug: modcall[preacct]: module "preprocess" returns noop for request 175 Thu Sep 15 18:24:28 2011 : Debug: modsingle[preacct]: calling acct_unique (rlm_acct_unique) for request 175 Thu Sep 15 18:24:28 2011 : Debug: modsingle[preacct]: returned from acct_unique (rlm_acct_unique) for request 175 Thu Sep 15 18:24:28 2011 : Debug: modcall[preacct]: module "acct_unique" returns ok for request 175 Thu Sep 15 18:24:28 2011 : Debug: modcall: leaving group preacct (returns ok) for request 175 Thu Sep 15 18:24:28 2011 : Debug: modcall: entering group accounting for request 175 Thu Sep 15 18:24:28 2011 : Debug: modsingle[accounting]: calling detail (rlm_detail) for request 175 Thu Sep 15 18:24:28 2011 : Debug: modsingle[accounting]: returned from detail (rlm_detail) for request 175 Thu Sep 15 18:24:28 2011 : Debug: modcall[accounting]: module "detail" returns ok for request 175 Thu Sep 15 18:24:28 2011 : Debug: modsingle[accounting]: calling netbill_acct (rlm_exec) for request 175 Tcpdump shows the accounting packet issued and returned back to the RAS: IP 172.31.3.7.radius-acct > 172.26.60.3.radius-acct: RADIUS, Accounting Request (4), id: 0xx length: 527 IP 172.26.60.3.radius-acct > 172.31.3.7.radius-acct: RADIUS, Accounting Response (5), id: 0xxx length: 20 But after about 30 secound, I got the following error in freeRADIUS’s log!!!! Thu Sep 15 18:24:59 2011 : Error: WARNING: Unresponsive child (id 3086457744) for request 175 (in component accounting module rlm_exec) hhsde0100413@tct9 Thu Sep 15 18:24:59 2011 : Debug: Server rejecting request 175. And then shows: Thu Sep 15 18:43:54 2011 : Error: Dropping conflicting packet from client 172.31.3.7:1646 - ID: 151 due to unfinished request 175 My external program returns 0 (means OK) and freeRADIUS getting it and returns back to the BRAS, so why freeradius gives such error?! Kind Regards, Ali Majdzadeh Kohbanani
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html