[asterisk-bugs] [Asterisk 0014443]: cdr_radius duplicate accounting packets.
Asterisk Bug Tracker
noreply at bugs.digium.com
Fri Feb 13 12:07:52 CST 2009
A NOTE has been added to this issue.
======================================================================
http://bugs.digium.com/view.php?id=14443
======================================================================
Reported By: rmartinez
Assigned To:
======================================================================
Project: Asterisk
Issue ID: 14443
Category: CDR/cdr_radius
Reproducibility: always
Severity: minor
Priority: normal
Status: new
Asterisk Version: 1.4.23
Regression: No
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Request Review:
======================================================================
Date Submitted: 2009-02-09 14:29 CST
Last Modified: 2009-02-13 12:07 CST
======================================================================
Summary: cdr_radius duplicate accounting packets.
Description:
Hello.
I've been experimenting some weird behavior with my asterisk box. First
let me clarify that i'm not absolutely sure if this is a problem related
with the cdr_module or maybe the radiusclient. module Hope you understand
and would help me to track dow this issue.
I'm using the SVN-sruffell-asterisk-1.4-transcoder-r168696 version,
because Digium was helping me with a TC400B issue. Anyway the problem was
happening even with the BRANCH version 1.4.
I'm also using raduisclient-ng-0.5.6 and I have a radius server with
RADIATOR.
I'm sending calls to the asterisk box with sipp, as long as i stay below
the 100 simulateous calls i can see the radius accounting packets arriving
to my server without any problem, in the asterisk console i don't see any
trouble. But when i reach the 100 simultaneous calls i start to see three
duplicate radius accounting packets in my radius server. And the console
of asterisk shows :
[Feb 2 11:30:11] ERROR[409]: cdr_radius.c:227 radius_log: Failed to
record Radius CDR record!
[Feb 2 11:30:12] ERROR[410]: cdr_radius.c:227 radius_log: Failed to
record Radius CDR record!
[Feb 2 11:30:13] ERROR[411]: cdr_radius.c:227 radius_log: Failed to
record Radius CDR record!
[Feb 2 11:30:14] ERROR[412]: cdr_radius.c:227 radius_log: Failed to
record Radius CDR record!
The /var/log/messages file shows :
Feb 2 10:54:28 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:29 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:30 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:31 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:32 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:33 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:34 b2buang01 asterisk[13250]: rc_check_reply: received
invalid reply digest from RADIUS server
Feb 2 10:54:35 b2buang01 asterisk[13250]: rc_ip_hostname: couldn't look
up host by addr: MY.IP.ADDR.D7
Feb 2 10:54:35 b2buang01 asterisk[13250]: rc_send_server: no reply from
RADIUS server unknown:1646
Feb 2 10:54:36 b2buang01 asterisk[13250]: rc_ip_hostname: couldn't look
up host by addr: MY.IP.ADDR.D7
Feb 2 10:54:36 b2buang01 asterisk[13250]: rc_send_server: no reply from
RADIUS server unknown:1646
Feb 2 10:54:37 b2buang01 asterisk[13250]: rc_ip_hostname: couldn't look
up host by addr: MY.IP.ADDR.D7
Feb 2 10:54:37 b2buang01 asterisk[13250]: rc_send_server: no reply from
RADIUS server unknown:1646
Feb 2 10:54:38 b2buang01 asterisk[13250]: rc_ip_hostname: couldn't look
up host by addr: MY.IP.ADDR.D7
Feb 2 10:54:38 b2buang01 asterisk[13250]: rc_send_server: no reply from
RADIUS server unknown:1646
Feb 2 10:54:39 b2buang01 asterisk[13250]: rc_ip_hostname: couldn't look
up host by addr: MY.IP.ADDR.D7
Feb 2 10:54:39 b2buang01 asterisk[13250]: rc_send_server: no reply from
RADIUS server unknown:1646
Feb 2 10:54:40 b2buang01 asterisk[13250]: rc_ip_hostname: couldn't look
up host by addr: MY.IP.ADDR.D7
Finally in my radius server i see the next lines :
Fri Jan 30 23:34:08 1998: DEBUG: Packet dump:
*** Received from 10.10.149.211 port 56844 ....
Code: Accounting-Request
Identifier: 129
Authentic: <237>U<254>W<129><156><159>D<153>A$<209><233>`G<9>
Attributes:
Acct-Status-Type = Stop
Asterisk-Acc-Code = "TO_PROVIDER"
Asterisk-Src = "5502222272"
Asterisk-Dst = "0130005411234618"
Asterisk-Dst-Ctx = "INC_CALLS"
Asterisk-Clid = ""sipp" <5502222272>"
Asterisk-Chan = "SIP/5060-0972ae58"
Asterisk-Dst-Chan = "SIP/TO_ITSP1-0972f830"
Asterisk-Last-App = "Dial"
Asterisk-Last-Data = "SIP/005411234618 at TO_ITSP1"
Asterisk-Start-Time = "2009-01-30 14:51:23 +0000"
Asterisk-Answer-Time = "2009-01-30 14:51:28 +0000"
Asterisk-End-Time = "2009-01-30 14:52:50 +0000"
Asterisk-Duration = 87
Asterisk-Bill-Sec = 82
Asterisk-Disposition = "ANSWERED"
Asterisk-AMA-Flags = "DOCUMENTATION"
Asterisk-Unique-ID = "1233327083.102"
Asterisk-User-Field = "B2BUA-PROVIDER-PRUEBAS"
User-Name = "SIP/5060-0972ae58"
Acct-Session-Id = "1233327083.102"
NAS-Port = 0
Acct-Delay-Time = 0
NAS-IP-Address = 10.10.149.211
Fri Jan 30 23:34:08 1998: DEBUG: Handling request with Handler
'Request-Type = Accounting-Request'
Fri Jan 30 23:34:08 1998: DEBUG: Deleting session for SIP/5060-0972ae58,
10.10.149.211, 0
Fri Jan 30 23:34:08 1998: DEBUG: Handling with AuthINTERNAL:
Fri Jan 30 23:34:08 1998: DEBUG: AuthBy INTERNAL result: ACCEPT, Fixed by
DefaultResult
Fri Jan 30 23:34:08 1998: DEBUG: Accounting accepted Fri Jan 30 23:34:08
1998: DEBUG: Packet dump:
*** Sending to 10.10.149.211 port 56844 ....
Code: Accounting-Response
Identifier: 129
Authentic: <237>U<254>W<129><156><159>D<153>A$<209><233>`G<9>
Attributes:
Fri Jan 30 23:34:08 1998: DEBUG: Packet dump:
*** Received from 10.10.149.211 port 56844 ....
Code: Accounting-Request
Identifier: 129
Authentic: <237>U<254>W<129><156><159>D<153>A$<209><233>`G<9>
Attributes:
Acct-Status-Type = Stop
Asterisk-Acc-Code = "TO_PROVIDER"
Asterisk-Src = "5502222272"
Asterisk-Dst = "0130005411234618"
Asterisk-Dst-Ctx = "INC_CALLS"
Asterisk-Clid = ""sipp" <5502222272>"
Asterisk-Chan = "SIP/5060-0972ae58"
Asterisk-Dst-Chan = "SIP/TO_ITSP1-0972f830"
Asterisk-Last-App = "Dial"
Asterisk-Last-Data = "SIP/005411234618 at TO_ITSP1"
Asterisk-Start-Time = "2009-01-30 14:51:23 +0000"
Asterisk-Answer-Time = "2009-01-30 14:51:28 +0000"
Asterisk-End-Time = "2009-01-30 14:52:50 +0000"
Asterisk-Duration = 87
Asterisk-Bill-Sec = 82
Asterisk-Disposition = "ANSWERED"
Asterisk-AMA-Flags = "DOCUMENTATION"
Asterisk-Unique-ID = "1233327083.102"
Asterisk-User-Field = "B2BUA-PROVIDER-PRUEBAS"
User-Name = "SIP/5060-0972ae58"
Acct-Session-Id = "1233327083.102"
NAS-Port = 0
Acct-Delay-Time = 0
NAS-IP-Address = 10.10.149.211
Fri Jan 30 23:34:08 1998: INFO: Duplicate request id 129 received from
10.10.149.211(56844): ignored
Fri Jan 30 23:34:08 1998: DEBUG: Packet dump:
*** Received from 10.10.149.211 port 56844 ....
Code: Accounting-Request
Identifier: 129
Authentic: <237>U<254>W<129><156><159>D<153>A$<209><233>`G<9>
Attributes:
Acct-Status-Type = Stop
Asterisk-Acc-Code = "TO_PROVIDER"
Asterisk-Src = "5502222272"
Asterisk-Dst = "0130005411234618"
Asterisk-Dst-Ctx = "INC_CALLS"
Asterisk-Clid = ""sipp" <5502222272>"
Asterisk-Chan = "SIP/5060-0972ae58"
Asterisk-Dst-Chan = "SIP/TO_ITSP1-0972f830"
Asterisk-Last-App = "Dial"
Asterisk-Last-Data = "SIP/005411234618 at TO_ITSP1"
Asterisk-Start-Time = "2009-01-30 14:51:23 +0000"
Asterisk-Answer-Time = "2009-01-30 14:51:28 +0000"
Asterisk-End-Time = "2009-01-30 14:52:50 +0000"
Asterisk-Duration = 87
Asterisk-Bill-Sec = 82
Asterisk-Disposition = "ANSWERED"
Asterisk-AMA-Flags = "DOCUMENTATION"
Asterisk-Unique-ID = "1233327083.102"
Asterisk-User-Field = "B2BUA-PROVIDER-PRUEBAS"
User-Name = "SIP/5060-0972ae58"
Acct-Session-Id = "1233327083.102"
NAS-Port = 0
Acct-Delay-Time = 0
NAS-IP-Address = 10.10.149.211
Fri Jan 30 23:34:08 1998: INFO: Duplicate request id 129 received from
10.10.149.211(56844): ignored
As you can see the the first packet is OK, but for some reason i'm getting
two more packets after the first arrive.
Can someone explain to me what i'm doing wrong?
Thanks
Ricardo.-
======================================================================
----------------------------------------------------------------------
(0100115) rmartinez (reporter) - 2009-02-13 12:07
http://bugs.digium.com/view.php?id=14443#c100115
----------------------------------------------------------------------
I have done a few more test.
I changed the radiusclient-ng version from 0.5.6 to 0.5.2.... i still have
the problem.
I have removed the TC400B cards...i still have the problem.
Issue History
Date Modified Username Field Change
======================================================================
2009-02-13 12:07 rmartinez Note Added: 0100115
======================================================================
More information about the asterisk-bugs
mailing list