Summary:	ASTERISK-24943: Wrong ANSWEREDTIME from Dial app when the channel was answered earlier
Reporter:	Anton Korzun (roop)	Labels:
Date Opened:	2015-04-06 13:22:25	Date Closed:	2015-04-06 13:57:10
Priority:	Major	Regression?
Status:	Closed/Complete	Components:
Versions:	13.3.0	Frequency of Occurrence	Constant
Related Issues:
Environment:		Attachments:
Description:	https://wiki.asterisk.org/wiki/display/AST/Asterisk+13+Application_Dial {quote} ANSWEREDTIME - This is the amount of time for actual call. {quote} *Dialplan*: {quote} exten => _X.,1,NoOp exten => _X.,n,Answer exten => _X.,n,Wait(10) exten => _X.,n,Dial(SIP/13333333333/$\{EXTEN},45) exten => h,1,NoOp(DIALSTATUS is $\{DIALSTATUS}, ANSWEREDTIME is $\{ANSWEREDTIME}) {quote} *Log*: {quote} \[2015-04-06 21:00:04] VERBOSE\[4791]\[C-0000009c] pbx.c: Executing \[18888888888@externalvOffice-14:1] NoOp("SIP/1033-00000052", "") in new stack \[2015-04-06 21:00:04] VERBOSE\[4791]\[C-0000009c] pbx.c: Executing \[18888888888@externalvOffice-14:2] Answer("SIP/1033-00000052", "") in new stack \[2015-04-06 21:00:04] VERBOSE\[4791]\[C-0000009c] res_rtp_asterisk.c: 0x7f60340c1a80 -- Probation passed - setting RTP source address to 93.126.74.15:4002 \[2015-04-06 21:00:04] VERBOSE\[4791]\[C-0000009c] pbx.c: Executing \[18888888888@externalvOffice-14:3] Wait("SIP/1033-00000052", "10") in new stack \[2015-04-06 21:00:04] VERBOSE\[4791]\[C-0000009c] res_rtp_asterisk.c: 0x7f60340c1a80 -- Probation passed - setting RTP source address to 93.126.74.15:4002 \[2015-04-06 21:00:14] VERBOSE\[4791]\[C-0000009c] pbx.c: Executing \[18888888888@externalvOffice-14:4] Dial("SIP/1033-00000052", "SIP/13333333333/18888888888,45") in new stack \[2015-04-06 21:00:14] VERBOSE\[4791]\[C-0000009c] netsock2.c: Using SIP RTP TOS bits 184 \[2015-04-06 21:00:14] VERBOSE\[4791]\[C-0000009c] netsock2.c: Using SIP RTP CoS mark 5 \[2015-04-06 21:00:14] VERBOSE\[4791]\[C-0000009c] app_dial.c: Called SIP/13333333333/18888888888 \[2015-04-06 21:00:15] VERBOSE\[4791]\[C-0000009c] app_dial.c: SIP/13333333333-00000053 is ringing \[2015-04-06 21:00:15] VERBOSE\[4791]\[C-0000009c] app_dial.c: SIP/13333333333-00000053 is making progress passing it to SIP/1033-00000052 \[2015-04-06 21:00:15] VERBOSE\[4791]\[C-0000009c] res_rtp_asterisk.c: 0x7f6034117ab0 -- Probation passed - setting RTP source address to 193.28.184.30:18732 \[2015-04-06 21:00:25] VERBOSE\[4791]\[C-0000009c] app_dial.c: SIP/13333333333-00000053 answered SIP/1033-00000052 \[2015-04-06 21:00:25] VERBOSE\[4791]\[C-0000009c] bridge_channel.c: Channel SIP/1033-00000052 joined 'simple_bridge' basic-bridge <62ba449e-7dbf-463a-91e3-012ff80b445b> \[2015-04-06 21:00:25] VERBOSE\[4792]\[C-0000009c] bridge_channel.c: Channel SIP/13333333333-00000053 joined 'simple_bridge' basic-bridge <62ba449e-7dbf-463a-91e3-012ff80b445b> \[2015-04-06 21:00:25] VERBOSE\[4792]\[C-0000009c] bridge.c: Bridge 62ba449e-7dbf-463a-91e3-012ff80b445b: switching from simple_bridge technology to native_rtp \[2015-04-06 21:00:25] VERBOSE\[4792]\[C-0000009c] bridge_native_rtp.c: Locally RTP bridged 'SIP/13333333333-00000053' and 'SIP/1033-00000052' in stack \[2015-04-06 21:00:25] VERBOSE\[4792]\[C-0000009c] bridge_native_rtp.c: Locally RTP bridged 'SIP/13333333333-00000053' and 'SIP/1033-00000052' in stack \[2015-04-06 21:00:32] VERBOSE\[4792]\[C-0000009c] bridge_channel.c: Channel SIP/13333333333-00000053 left 'native_rtp' basic-bridge <62ba449e-7dbf-463a-91e3-012ff80b445b> \[2015-04-06 21:00:32] VERBOSE\[4791]\[C-0000009c] bridge_channel.c: Channel SIP/1033-00000052 left 'native_rtp' basic-bridge <62ba449e-7dbf-463a-91e3-012ff80b445b> \[2015-04-06 21:00:32] VERBOSE\[4791]\[C-0000009c] pbx.c: Spawn extension (externalvOffice-14, 18888888888, 4) exited non-zero on 'SIP/1033-00000052' \[2015-04-06 21:00:32] VERBOSE\[4791]\[C-0000009c] pbx.c: Executing \[h@externalvOffice-14:1] NoOp("SIP/1033-00000052", "DIALSTATUS is ANSWER, *ANSWEREDTIME is 27*") in new stack {quote} *Resume*: ANSWEREDTIME is *27* But should be *7* On my production asterisk 11.2 - ANSWEREDTIME works well.
Comments:	By: Matt Jordan (mjordan) 2015-04-06 13:57:10.673-0500 In Asterisk 13, the answered time is reflected by the state of the actual channel. Since you Answered the channel, that starts the time from when Asterisk calculates the answered time.