[asterisk-bugs] [Asterisk 0016671]: callee chanel overwrites the caller cdr
Asterisk Bug Tracker
noreply at bugs.digium.com
Fri Jan 29 05:46:00 CST 2010
A NOTE has been added to this issue.
======================================================================
https://issues.asterisk.org/view.php?id=16671
======================================================================
Reported By: eagvoz
Assigned To:
======================================================================
Project: Asterisk
Issue ID: 16671
Category: Channels/chan_local
Reproducibility: have not tried
Severity: minor
Priority: normal
Status: feedback
Asterisk Version: 1.6.2.1
JIRA: SWP-778
Regression: No
Reviewboard Link:
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Request Review:
======================================================================
Date Submitted: 2010-01-22 09:16 CST
Last Modified: 2010-01-29 05:45 CST
======================================================================
Summary: callee chanel overwrites the caller cdr
Description:
When
1) contextA answers the call
2) contextA dials contextB (with local /n of course)
3) contextB answers the call
we expect (as like asterisk 1.2 and asterisk 1.4):
- That CDR of contextA has its own billsec (cdrA) and contextB its own
billsec (cdrB).
But in asterisk 1.6 we see:
- when contextB answers the call it sets the billsec of cdrA equals to the
billsec of cdrB.
======================================================================
----------------------------------------------------------------------
(0117365) eagvoz (reporter) - 2010-01-29 05:45
https://issues.asterisk.org/view.php?id=16671#c117365
----------------------------------------------------------------------
--- Reproducibility ---
Always
--- RESULTING CDRs ON ASTERISK 1.6.2.1 (BAD CDRs) ---
uniqueid userfield accountcode src dst dcontext clid
channel dstchannel lastapp lastdata
calldate duration billsec disposition amaflags
1264760350.12 B_SHORTCDR 100 s contextB \User Name\" <100>"
Local/s at contextB-fdc9;2 Hangup
2010-01-29 11:19:10 4 1 ANSWERED 3
1264760348.10 A_LARGECDR 100 s contextA \User Name\" <100>"
IAX2/remoteHost-6426 Local/s at contextB-fdc9;1 Dial Local/s at contextB/n
2010-01-29 11:19:08 5 1 ANSWERED 3
For the "A_LARGECDR" CDR asterisk stores:
The duration is OK because: ~1s (sound contextA) + 3s (wait on context B)
+ ~1s (sound on context B) = 5 seconds
but the billsec on "A_LARGECDR" is NOT ok because: ~1s (sound contextA) +
3s (wait on context B) + ~1s (sound on context B) != 1 seconds !!!
--- EXPECTED CDRs . RESULTS TAKEN FROM ASTERISK 1.4.21.1 (GOOD CDRs) ---
(Same contexts, clid, etc.)
uniqueid userfield accountcode src dst dcontext clid
channel dstchannel lastapp lastdata
calldate duration billsec disposition amaflags
1264762373.726 B_SHORTCDR 100 s contextB \User Name\" <100>"
Local/s at contextB-0407,2 Hangup
2010-01-29 11:52:53 4 1 ANSWERED 3
1264762373.724 A_LARGECDR 100 s contextA \User Name\" <100>"
IAX2/remoteHost-2547 Local/s at contextB-0407,1 Dial Local/s at contextB/n
2010-01-29 11:52:53 5 5 ANSWERED 3
For the "A_LARGECDR" CDR asterisk stores:
The duration is correct because: ~1s (sound contextA) + 3s (wait on
context B) + ~1s (sound on context B) = 5 seconds
the billsec on "A_LARGECDR" OK because: ~1s (sound contextA) + 3s (wait on
context B) + ~1s (sound on context B) = 5 seconds
As you can see on asterisk 1.6 the billsec of first channel is equals to
billsec of last channel. That is not true, because first CDR may be
answered before last CDR.
If you have more local channels between the first and last channel, all of
those billsecs will be changed by the last created channel.
--- Contexts used ----
[contextA]
exten => s,1,NoOp(I'm contextA)
exten => s,n,Set(CDR(accountcode)=A_LARGECDR)
exten => s,n,Answer()
exten => s,n,PlayBack(thanks-for-calling-today)
exten => s,n,Dial(Local/s at contextB/n)
exten => h,1,NoOp(Putting some global vars into userfield)
[contextB]
exten => s,1,NoOp(I'm contextB)
exten => s,n,Set(CDR(accountcode)=B_SHORTCDR)
exten => s,n,Wait(3)
exten => s,n,NoOp(Setting some global vars)
exten => s,n,Answer()
exten => s,n,PlayBack(goodbye)
exten => s,n,Hangup
exten => h,1,NoOp(Cleaning B)
--- Asterisk console (debug=999,verbose=999,iax.debug=on) ----
As expected we see:
Connected to Asterisk 1.6.2.1 currently running on myhost (pid = 4243)
Verbosity is at least 999
Core debug is at least 999
myhost*CLI>iax2 set debug on
IAX2 Debugging Enabled
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW
Timestamp: 00014ms SCall: 00005 DCall: 00000 [remoteIP:4569]
VERSION : 2
CALLED NUMBER : s
CODEC_PREFS : (gsm)
CALLING NUMBER : 102
CALLING PRESNTN : 0
CALLING TYPEOFN : 0
CALLING TRANSIT : 0
CALLING NAME : User Name
LANGUAGE : es
CALLED CONTEXT : contextA
USERNAME : user001
FORMAT : 2
CAPABILITY : 57346
ADSICPE : 2
DATE TIME : 2010-01-29 11:18:50
Tx-Frame Retry[-01] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00014ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass:
AUTHREQ
Timestamp: 00002ms SCall: 06426 DCall: 00005 [remoteIP:4569]
AUTHMETHODS : 2
CHALLENGE : \x31\x39\x32\x36\x38\x34\x30\x38\x39
USERNAME : user001
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass:
AUTHREP
Timestamp: 00076ms SCall: 00005 DCall: 06426 [remoteIP:4569]
MD5 RESULT : xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 00076ms SCall: 06426 DCall: 00005 [remoteIP:4569]
-- Accepting AUTHENTICATED call from remoteIP:
> requested format = gsm,
> requested prefs = (gsm),
> actual format = gsm,
> host prefs = (gsm),
> priority = mine
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass:
ACCEPT
Timestamp: 00061ms SCall: 06426 DCall: 00005 [remoteIP:4569]
FORMAT : 2
-- Executing [s at contextA:1] NoOp("IAX2/user001-6426", "I'm contextA")
in new stack
-- Executing [s at contextA:2] Set("IAX2/user001-6426",
"CDR(accountcode)=A_LARGECDR") in new stack
-- Executing [s at contextA:3] Answer("IAX2/user001-6426", "") in new
stack
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass:
ANSWER
Timestamp: 00064ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass:
(255?)
Timestamp: 00067ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 00061ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK
Timestamp: 00064ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 00079ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 003 Type: IAX Subclass: ACK
Timestamp: 00079ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK
Timestamp: 00067ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 00082ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 004 Type: IAX Subclass: ACK
Timestamp: 00082ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 00085ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 005 Type: IAX Subclass: ACK
Timestamp: 00085ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: VOICE Subclass: 2
Timestamp: 00140ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX Subclass: ACK
Timestamp: 00140ms SCall: 06426 DCall: 00005 [remoteIP:4569]
-- Executing [s at contextA:4] Playback("IAX2/user001-6426",
"thanks-for-calling-today") in new stack
-- <IAX2/user001-6426> Playing 'thanks-for-calling-today.gsm'
(language 'es')
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 006 Type: VOICE Subclass: 2
Timestamp: 00160ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 005 Type: IAX Subclass: ACK
Timestamp: 00160ms SCall: 00005 DCall: 06426 [remoteIP:4569]
-- Executing [s at contextA:5] Dial("IAX2/user001-6426",
"Local/s at contextB/n") in new stack
-- Called s at contextB/n
-- Executing [s at contextB:1] NoOp("Local/s at contextB-fdc9;2", "I'm
contextB") in new stack
-- Executing [s at contextB:2] Set("Local/s at contextB-fdc9;2",
"CDR(accountcode)=B_SHORTCDR") in new stack
-- Executing [s at contextB:3] Wait("Local/s at contextB-fdc9;2", "3") in
new stack
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass:
POKE
Timestamp: 00009ms SCall: 00021 DCall: 00000 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00009ms SCall: 00021 DCall: 00001 [remoteIP:4569]
-- Executing [s at contextB:4] NoOp("Local/s at contextB-fdc9;2", "Setting
some global vars") in new stack
-- Executing [s at contextB:5] Answer("Local/s at contextB-fdc9;2", "") in
new stack
-- Local/s at contextB-fdc9;1 answered IAX2/user001-6426
Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 006 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 04749ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 006 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 04752ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 006 Type: CONTROL Subclass:
(255?)
Timestamp: 04755ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 006 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 04758ms SCall: 06426 DCall: 00005 [remoteIP:4569]
-- Executing [s at contextB:6] Playback("Local/s at contextB-fdc9;2",
"goodbye") in new stack
-- <Local/s at contextB-fdc9;2> Playing 'goodbye.gsm' (language 'en')
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 006 Type: IAX Subclass: ACK
Timestamp: 04749ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 007 Type: IAX Subclass: ACK
Timestamp: 04752ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 008 Type: IAX Subclass: ACK
Timestamp: 04755ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 008 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 04803ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Tx-Frame Retry[-01] -- OSeqno: 008 ISeqno: 007 Type: IAX Subclass: ACK
Timestamp: 04803ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 008 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 04806ms SCall: 00005 DCall: 06426 [remoteIP:4569]
Tx-Frame Retry[-01] -- OSeqno: 008 ISeqno: 008 Type: IAX Subclass: ACK
Timestamp: 04806ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 009 Type: IAX Subclass: ACK
Timestamp: 04758ms SCall: 00005 DCall: 06426 [remoteIP:4569]
-- Executing [s at contextB:7] Hangup("Local/s at contextB-fdc9;2", "") in
new stack
== Spawn extension (contextB, s, 7) exited non-zero on
'Local/s at contextB-fdc9;2'
-- Executing [h at contextB:1] NoOp("Local/s at contextB-fdc9;2", "Cleaning
B") in new stack
-- Executing [h at contextA:1] NoOp("IAX2/user001-6426", "Putting some
global vars into userfield") in new stack
Tx-Frame Retry[000] -- OSeqno: 009 ISeqno: 008 Type: CONTROL Subclass:
SRCUPDT
Timestamp: 05663ms SCall: 06426 DCall: 00005 [remoteIP:4569]
Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 010 Type: IAX Subclass: ACK
Timestamp: 05663ms SCall: 00005 DCall: 06426 [remoteIP:4569]
== Spawn extension (contextA, s, 5) exited non-zero on
'IAX2/user001-6426'
-- Hungup 'IAX2/user001-6426'
Tx-Frame Retry[000] -- OSeqno: 010 ISeqno: 008 Type: IAX Subclass:
HANGUP
Timestamp: 05796ms SCall: 06426 DCall: 00005 [remoteIP:4569]
CAUSE CODE : 16
Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 011 Type: IAX Subclass: ACK
Timestamp: 05796ms SCall: 00005 DCall: 06426 [remoteIP:4569]
myhost*CLI>
Issue History
Date Modified Username Field Change
======================================================================
2010-01-29 05:45 eagvoz Note Added: 0117365
======================================================================
More information about the asterisk-bugs
mailing list