[Home]

Summary:ASTERISK-11853: Local channel didn't get answered from answered child SIP channel
Reporter:Atis Lezdins (atis)Labels:
Date Opened:2008-04-15 06:31:45Date Closed:2011-06-07 14:02:59
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_local
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) callid_1208205583.11806.log
( 1) callid_1208211747.2312.log
Description:It seems that Local channel didn't get answer from Dial() to SIP device, which was answered. So, masquerade can't bridge call, and it remains in previous application (in my case - app_queue).

I'm not sure that I will be able to reproduce or confirm fix, as this seems to be only case for week since I switched to 1.4.19, and as I found another config issue with app_queue, this won't halt all call processing in our PBX. But maybe anyone have some ideas how this can happen.

I added two call logs, callid_1208205583.11806.log is where problem occurs, and callid_1208211747.2312.log is with normal masquerade. I have some additions to masquerade and channels.c that logs all channel changes into realtime table, so it's visible in logs what's going on with channels and masquerade. Both files are with Verbosity 3 and Debug 1.



****** ADDITIONAL INFORMATION ******

The affected part can be tracked by following queue_call_answer macro, which executes after SIP is answered. Normally after that masquerade should look as in callid_1208211747.2312.log

[Apr 14 15:28:31] VERBOSE[9239] logger.c:     -- Executing [s@macro-queue_call_answer:16] NoOp("SIP/90169-c407dc00", "--(E)--------------------------- queue_call_answer(28225)----
[Apr 14 15:28:31] DEBUG[9239] app_macro.c: Executed application: NoOp
[Apr 14 15:28:31] DEBUG[9239] app_dial.c: Macro exited with status 0
[Apr 14 15:28:31] DEBUG[5017] app_queue.c: Dunno what to do with control type -1
[Apr 14 15:28:31] DEBUG[9239] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Apr 14 15:28:31] DEBUG[9239] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE channels SET state = 'Up', accountcode = '1208211747.2312', context = 'local_dial', exten = '2
[Apr 14 15:28:31] DEBUG[9239] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: channels
[Apr 14 15:28:31] DEBUG[5017] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Apr 14 15:28:31] DEBUG[5017] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE channels SET state = 'Up', accountcode = '', context = 'default_queue', exten = '28901', prior
[Apr 14 15:28:31] DEBUG[5017] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: channels
[Apr 14 15:28:31] DEBUG[9239] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Apr 14 15:28:31] VERBOSE[5017] logger.c:     -- Local/28225@default_queue-3a18,1 answered SIP/204.11.200.152-ac162b50
[Apr 14 15:28:31] DEBUG[9239] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE channels SET bridgedto = '1208212110.2539', accountcode = '1208211747.2312', context = 'local_
[Apr 14 15:28:31] VERBOSE[5017] logger.c:     -- Stopped music on hold on SIP/204.11.200.152-ac162b50
[Apr 14 15:28:31] DEBUG[9239] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: channels
[Apr 14 15:28:31] DEBUG[5017] res_config_mysql.c: MySQL RealTime: Everything is fine.


However in problematic call, callid_1208205583.11806.log it looks like this:

[Apr 14 13:40:42] VERBOSE[2016] logger.c:     -- Executing [s@macro-queue_call_answer:16] NoOp("SIP/90259-ac0b0890", "--(E)--------------------------- queue_call_answer(28366)----
--------------------") in new stack
[Apr 14 13:40:42] DEBUG[2016] app_macro.c: Executed application: NoOp
[Apr 14 13:40:42] DEBUG[2016] app_dial.c: Macro exited with status 0
[Apr 14 13:40:46] DEBUG[1000] rtp.c: Got RTCP report of 88 bytes
[Apr 14 13:40:51] DEBUG[1000] rtp.c: Got RTCP report of 88 bytes
[Apr 14 13:40:56] DEBUG[1000] rtp.c: Got RTCP report of 88 bytes
[Apr 14 13:41:01] DEBUG[1000] rtp.c: Got RTCP report of 88 bytes
[Apr 14 13:41:06] DEBUG[1000] rtp.c: Got RTCP report of 88 bytes
Comments:By: jmls (jmls) 2008-07-04 14:53:05

atis, is this still a problem with .21 ?
By: Atis Lezdins (atis) 2008-07-17 12:18:28

Sorry, but I have no way how to check for this, as it doesn't causes lock-up of queue anymore (because of other queue settings).
By: Tilghman Lesher (tilghman) 2008-07-31 12:45:14

Fixed by configuration change