[asterisk-users] async agi question

Wed Apr 15 10:52:32 CDT 2009

Hi Moy,
You are right. I failed applying the patch. In fact, I applied it but I didn't "make install" so I started a wrong asterisk. I apologize, it was my mistake. This time I made sure twice before getting the logs and this time the log message you said appears, but it doesn't work either as you can see:
I'm copying the whole log from the originate action to the hangup:

=====================================================================
[Apr 15 13:01:22] DEBUG[25752]: manager.c:2108 process_message: Manager received command 'originate'
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:15874 sip_request_call: Asked to create a SIP channel with formats: 0x40 (slin)
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:4508 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:2740 do_setnat: Setting NAT on RTP to Off
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:2745 do_setnat: Setting NAT on VRTP to Off
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:2998 sip_call: Outgoing Call for 501
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:3013 sip_call: Our T38 capability (0), joint T38 capability (0)
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:6423 add_sdp: ** Our capability: 0x38000e (gsm|ulaw|alaw|h263|h263p|h264) Video flag: False
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:6424 add_sdp: ** Our prefcodec: 0x40 (slin)
[Apr 15 13:01:22] DEBUG[26933]: chan_sip.c:6439 add_sdp: This call needs video offers!
[Apr 15 13:01:22] DEBUG[30207]: chan_sip.c:2215 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5c2607ce7cda26537726b6a4323a3049 at 10.0.5.20' Request 102: Found
[Apr 15 13:01:22] DEBUG[30207]: chan_sip.c:2215 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5c2607ce7cda26537726b6a4323a3049 at 10.0.5.20' Request 102: Found
[Apr 15 13:01:22] DEBUG[30207]: chan_sip.c:2157 __sip_ack: Acked pending invite 102
[Apr 15 13:01:22] DEBUG[30207]: chan_sip.c:2174 __sip_ack: Stopping retransmission on '5c2607ce7cda26537726b6a4323a3049 at 10.0.5.20' of Request 102: Match Not Found
[Apr 15 13:01:22] DEBUG[30207]: chan_sip.c:5470 process_sdp: We're settling with these formats: 0x100008 (alaw|h263p)
[Apr 15 13:01:22] DEBUG[30207]: chan_sip.c:8236 build_route: build_route: Contact hop: <sip:501 at 10.0.2.151:5060;user=phone>
[Apr 15 13:01:22]        > Channel SIP/501-0828df48 was answered.
[Apr 15 13:01:22] DEBUG[26934]: pbx.c:1831 pbx_extension_helper: Launching 'NoOp'
[Apr 15 13:01:22]     -- Executing [801 at sip_sercom:1] NoOp("SIP/501-0828df48", "entrada numeracion del 8 801") in new stack
[Apr 15 13:01:22] DEBUG[26934]: pbx.c:1831 pbx_extension_helper: Launching 'AGI'
[Apr 15 13:01:22]     -- Executing [801 at sip_sercom:2] AGI("SIP/501-0828df48", "agi:async") in new stack
[Apr 15 13:01:51] DEBUG[25752]: manager.c:2108 process_message: Manager received command 'AGI'
[Apr 15 13:01:51]     -- Playing 'es/demo-congrats' (escape_digits=1) (sample_offset 0)
[Apr 15 13:01:51] DEBUG[26934]: rtp.c:2753 ast_rtp_write: Ooh, format changed from unknown to alaw
[Apr 15 13:01:51] DEBUG[26934]: rtp.c:2770 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Apr 15 13:01:51] DEBUG[26934]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals
[Apr 15 13:02:00] DEBUG[25752]: manager.c:2108 process_message: Manager received command 'Redirect'
[Apr 15 13:02:00] DEBUG[25752]: channel.c:1378 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/501-0828df48'
[Apr 15 13:02:00] DEBUG[26934]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals
[Apr 15 13:02:00] DEBUG[26934]: res_agi.c:488 launch_asyncagi: launch_asyncagi returned (0x2) for chan SIP/501-0828df48
[Apr 15 13:02:00] DEBUG[26934]: pbx.c:2448 __ast_pbx_run: Extension 801, priority 0 returned normally even though call was hung up
[Apr 15 13:02:00] DEBUG[26934]: channel.c:1378 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/501-0828df48'
[Apr 15 13:02:00] DEBUG[26934]: channel.c:1477 ast_hangup: Hanging up channel 'SIP/501-0828df48'
[Apr 15 13:02:00] DEBUG[26934]: chan_sip.c:3485 sip_hangup: Hangup call SIP/501-0828df48, SIP callid 5c2607ce7cda26537726b6a4323a3049 at 10.0.5.20)
=====================================================================

As it seemed the execution was exiting by a line of code without a log, I did a bit modification to res_agi.c (some additional log line) and I was able to find out the execution was exiting in the line 437 with the res variable containing a -1:

		if (cmd) {
			res = agi_handle_command(chan, &async_agi, cmd->cmd_buffer);
			if ((res < 0) || (res == AST_PBX_KEEPALIVE)) {
				free_agi_cmd(cmd);
				break;

In order to discard any version issues, I installed a new one from scratch and then applied the async-agi patch only, getting the same results. By the way, I was also able to install an asterisk 1.6.0.9 with the same configuration and dial plan like the 1.4.18 one and it worked fine.

I hope this can be useful.

Regards
Jose

-- Moises Silva wrote : 

I really think you did not recompile and reinstall after applying the
new patch. I don't see any code path where the message

[Apr 13 12:03:57] DEBUG[2755]: res_agi.c:464 launch_asyncagi: No frame
read on channel SIP/501-08279028, going out ...

Is displayed but then

ast_log(LOG_DEBUG, "launch_asyncagi returned (0x%X) for chan %s\n",
returnstatus, chan->name);

is NOT displayed. In fact, there is no way you can get out of
launch_asyncagi without displaying that message. I tested this with
1.4.18 version exactly.

The fact that works for some people and not for others may be due to
different asterisk versions and/or dial plan specific issues.

Please make sure the patch was correctly applied, once that is done we
can try some other things.

--
This message was sent on behalf of cyr2242 at gmail.com at openSubscriber.com
http://www.opensubscriber.com/message/asterisk-users@lists.digium.com/11929418.html