Web forms don't appear sometimes

[tukak]

Hello,
it happens sometimes on our computers, that web form window is not opened automatically when the call is connected, although it's defined in the campaign screen to do so. We're using Gentoo Linux with Firefox 1.5. The agents are able to open the web form using the appropriate button then.

It happens just sometimes (let's say in half of the cases) on the same machines/logins.

Can it have something to do with VICIDIAL or should I blame Firefox? Any idea where to check for problem?

Thanks

[gerski]

what do you mean the webform is it the information of the client?

maybe it is something to do with the connection.. can you check the ping from workstation to server?

[tukak]

I use web forms to connect it to my system which has some html form editing capability and stores aditional info for the customer

the web form system is running on the same server as the vicidial system and is on local network, so ping is fine

[mflorell]

I have seen this before on some systems, it is usually caused by the workstation. I would recommend turning off any popup blocking, and turn off the auto-updating and update checking within Firefox. All of those features can cause problems.

[tukak]

Thanks for the ideas, Matt.
So far I've tried upgrading to the latest version of FF, updated the extensions (noscript and adblock) and added our server to the exception list of adblock. The auto-update is turned off by default in Gentoo builds.

I will report later, whether it helped

[tukak]

It didn't help much, I will try something else.

But there's another thing worrying me about webforms, when we're on closer campaign and call comes in and the web form is opened automaticaly, it says in the url of the webform campaign=CLOSER&group=CRa (where CRa is name of the in-group). This is fine, because I'm saving these records in table according to the group variable. However, when the web form is opened by the web form button, in the url there is campaign=CLOSER&group=CLOSER.

AFAIK these calls also appear as DEAD in the AST_timeonVDAD.php

Is it possible that these calls don't have inboud group set somehow? And then it's understandable that the web forms don't appear automaticaly, because it's set just for the in-group.

In the vicidial_closer_log the group name is filled in the campaign_id collumn.

Any ideas what could be causing it and how to debug?

[mflorell]

Interesting issue, what version and build of vicidial.php are you using?

If you can post some more details like Asterisk CLI output and agiout.2007-06-XX output for transfer AGI it would be very helpful.

[tukak]

This is said on bottom of vicidial.php
VERSION: 2.0.129 BUILD: 70322-1545
We've installed the 2.0.3 VICIDIAL, afaik

this should be the CLI output for misbeheaving call :

Code: Select all

Jun 22 12:14:25 DEBUG[19132] pbx.c: Launching 'Ringing'
Jun 22 12:14:25 VERBOSE[19132] logger.c:     -- Executing Ringing("IAX2/draco-2", "") in new stack
Jun 22 12:14:25 DEBUG[19132] pbx.c: Launching 'Wait'
Jun 22 12:14:25 VERBOSE[19132] logger.c:     -- Executing Wait("IAX2/draco-2", "1") in new stack
Jun 22 12:14:26 DEBUG[19132] pbx.c: Launching 'Answer'
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Executing Answer("IAX2/draco-2", "") in new stack
Jun 22 12:14:26 DEBUG[19132] chan_iax2.c: Answering IAX2 call
Jun 22 12:14:26 DEBUG[19132] pbx.c: Launching 'Set'
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Executing Set("IAX2/draco-2", "menurep=1") in new stack
Jun 22 12:14:26 DEBUG[19132] pbx.c: Launching 'GotoIfTime'
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Executing GotoIfTime("IAX2/draco-2", "00:00-08:00|mon-sun|*|*?incoming|565554910|100") in new stack
Jun 22 12:14:26 DEBUG[19132] pbx.c: Launching 'GotoIfTime'
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Executing GotoIfTime("IAX2/draco-2", "08:01-12:00|mon-sun|*|*?incoming|565554910|110") in new stack
Jun 22 12:14:26 DEBUG[19132] pbx.c: Launching 'GotoIfTime'
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Executing GotoIfTime("IAX2/draco-2", "12:01-18:00|mon-sun|*|*?incoming|565554910|120") in new stack
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Goto (incoming,565554910,120)
Jun 22 12:14:26 DEBUG[19132] pbx.c: Launching 'Playback'
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Executing Playback("IAX2/draco-2", "draco/CZPLres03_dobre_odpoledne") in new stack
Jun 22 12:14:26 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:14:26 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:14:26 VERBOSE[19132] logger.c:     -- Playing 'draco/CZPLres03_dobre_odpoledne' (language 'en')
Jun 22 12:14:34 DEBUG[19132] channel.c: Scheduling timer at 102 sample intervals
Jun 22 12:14:34 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:34 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:34 DEBUG[19132] pbx.c: Launching 'Goto'
Jun 22 12:14:34 VERBOSE[19132] logger.c:     -- Executing Goto("IAX2/draco-2", "incoming|565554910|200") in new stack
Jun 22 12:14:34 VERBOSE[19132] logger.c:     -- Goto (incoming,565554910,200)
Jun 22 12:14:34 DEBUG[19132] pbx.c: Launching 'Read'
Jun 22 12:14:34 VERBOSE[19132] logger.c:     -- Executing Read("IAX2/draco-2", "digito|draco/CZPLres05_menu|1||1") in new stack
Jun 22 12:14:34 VERBOSE[19132] logger.c:     -- Accepting a maximum of 1 digits.
Jun 22 12:14:34 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:14:34 VERBOSE[19132] logger.c:     -- Playing 'draco/CZPLres05_menu' (language 'en')
Jun 22 12:14:43 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- User entered '1'
Jun 22 12:14:43 DEBUG[19132] pbx.c: Expression result is '1'
Jun 22 12:14:43 DEBUG[19132] pbx.c: Launching 'GotoIf'
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- Executing GotoIf("IAX2/draco-2", "1?300") in new stack
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- Goto (incoming,565554910,300)
Jun 22 12:14:43 DEBUG[19132] pbx.c: Launching 'GotoIfTime'
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- Executing GotoIfTime("IAX2/draco-2", "07:00-23:00|mon-sun|*|*?incoming|565554910|400") in new stack
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- Goto (incoming,565554910,400)
Jun 22 12:14:43 DEBUG[19132] pbx.c: Launching 'Playback'
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- Executing Playback("IAX2/draco-2", "draco/CZPLres10_monitoring") in new stack
Jun 22 12:14:43 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:14:43 VERBOSE[19132] logger.c:     -- Playing 'draco/CZPLres10_monitoring' (language 'en')
Jun 22 12:14:51 DEBUG[19132] channel.c: Scheduling timer at 128 sample intervals
Jun 22 12:14:51 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:51 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:51 DEBUG[19132] pbx.c: Launching 'AGI'
Jun 22 12:14:51 VERBOSE[19132] logger.c:     -- Executing AGI("IAX2/draco-2", "agi-VDADcloser_inboundCID_CRA.agi|CRa-----565554910-----974816111---------------999-----") in new stack
Jun 22 12:14:51 VERBOSE[19132] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADcloser_inboundCID_CRA.agi
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_request: agi-VDADcloser_inboundCID_CRA.agi
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_channel: IAX2/draco-2
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_language: en
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_type: IAX2
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_uniqueid: 1182507265.24124
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_callerid: 974816111
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_calleridname: unknown
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_callingpres: 0
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_callingani2: 0
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_callington: 0
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_callingtns: 0
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_dnid: unknown
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_rdnis: unknown
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_context: incoming
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_extension: 565554910
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_priority: 401
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_enhanced: 0.0
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >> agi_accountcode:
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Tx >>
Jun 22 12:14:51 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE beep ""
Jun 22 12:14:51 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:14:51 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:14:52 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:52 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:52 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3520
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Rx << SET CALLERID Y0622121451000198671
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Tx >> 200 result=1
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:52 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:14:53 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:14:53 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:14:53 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:14:53 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:14:53 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE draco/CZPLres11_fronta ""
Jun 22 12:14:53 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:15:56 DEBUG[19132] channel.c: Scheduling timer at 122 sample intervals
Jun 22 12:15:56 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:15:56 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=499802
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:15:56 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:15:56 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:15:56 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:15:57 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:15:57 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:15:57 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:15:57 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3680
Jun 22 12:15:57 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:57 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:15:57 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:57 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:15:58 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:58 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:15:59 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:15:59 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:00 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:00 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:00 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:16:00 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:16:00 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:16:00 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:00 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:00 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:16:00 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3680
Jun 22 12:16:01 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:01 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:02 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:02 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:03 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:03 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:04 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:04 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:05 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:05 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:05 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:16:05 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:16:05 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:16:05 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:05 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:05 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:16:05 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3680
Jun 22 12:16:06 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:06 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:07 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:07 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:08 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:08 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:09 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:09 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:10 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:10 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:10 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:16:10 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:16:10 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:16:11 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:11 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:11 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:16:11 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3680
Jun 22 12:16:12 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:12 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:13 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:13 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:14 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:14 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:15 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:15 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:16 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:16 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:16 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:16:16 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:16:16 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:16:16 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:16 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:16 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:16:16 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3680
Jun 22 12:16:17 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:17 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:18 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:18 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:19 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:19 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:20 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:20 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:21 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:21 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:21 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE hold_tone ""
Jun 22 12:16:21 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format gsm
Jun 22 12:16:21 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:16:22 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:22 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:16:22 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format alaw
Jun 22 12:16:22 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=3680
Jun 22 12:16:23 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:23 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:24 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:24 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:25 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:25 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:26 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:16:26 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:16:26 VERBOSE[19132] logger.c: AGI Rx << STREAM FILE draco/CZPLres11_fronta ""
Jun 22 12:16:26 DEBUG[19132] channel.c: Scheduling timer at 160 sample intervals
Jun 22 12:17:28 DEBUG[19132] channel.c: Scheduling timer at 122 sample intervals
Jun 22 12:17:28 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:17:28 DEBUG[19132] channel.c: Scheduling timer at 0 sample intervals
Jun 22 12:17:28 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0 endpos=499802
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Rx << CHANNEL STATUS IAX2/draco-2
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Tx >> 200 result=6
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Rx << SET CONTEXT default
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Rx << SET EXTENSION 8600052
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Rx << SET PRIORITY 1
Jun 22 12:17:29 VERBOSE[19132] logger.c: AGI Tx >> 200 result=0
Jun 22 12:17:29 VERBOSE[19132] logger.c:     -- AGI Script agi-VDADcloser_inboundCID_CRA.agi completed, returning 0
Jun 22 12:17:29 DEBUG[19132] pbx.c: Launching 'Goto'
Jun 22 12:17:29 VERBOSE[19132] logger.c:     -- Executing Goto("IAX2/draco-2", "route|8600052|1") in new stack
Jun 22 12:17:29 VERBOSE[19132] logger.c:     -- Goto (route,8600052,1)
Jun 22 12:17:29 DEBUG[19132] pbx.c: Launching 'MeetMe'
Jun 22 12:17:29 VERBOSE[19132] logger.c:     -- Executing MeetMe("IAX2/draco-2", "8600052") in new stack
Jun 22 12:17:29 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to write format slin
Jun 22 12:17:29 DEBUG[19132] channel.c: Set channel IAX2/draco-2 to read format slin
Jun 22 12:17:29 DEBUG[19132] app_meetme.c: Placed channel IAX2/draco-2 in ZAP conf 1023
Jun 22 12:23:23 DEBUG[19132] pbx.c: Spawn extension (route,8600052,1) exited non-zero on 'IAX2/draco-2'
Jun 22 12:23:23 VERBOSE[19132] logger.c:   == Spawn extension (route, 8600052, 1) exited non-zero on 'IAX2/draco-2'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Launching 'DeadAGI'
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- Executing DeadAGI("IAX2/draco-2", "call_log.agi|h") in new stack
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/call_log.agi
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_request: call_log.agi
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_channel: IAX2/draco-2
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_language: en
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_type: IAX2
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_uniqueid: 1182507265.24124
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callerid: unknown
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_calleridname: Y0622121451000198671
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callingpres: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callingani2: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callington: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callingtns: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_dnid: unknown
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_rdnis: unknown
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_context: route
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_extension: h
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_priority: 1
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_enhanced: 0.0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_accountcode:
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >>
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- AGI Script call_log.agi completed, returning 0
Jun 22 12:23:23 DEBUG[19132] pbx.c: Launching 'DeadAGI'
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- Executing DeadAGI("IAX2/draco-2", "VD_hangup.agi|h") in new stack
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_hangup.agi
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_request: VD_hangup.agi
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_channel: IAX2/draco-2
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_language: en
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_type: IAX2
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_uniqueid: 1182507265.24124
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callerid: unknown
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_calleridname: Y0622121451000198671
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callingpres: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callingani2: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callington: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_callingtns: 0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_dnid: unknown
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_rdnis: unknown
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_context: route
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_extension: h
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_priority: 2
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_enhanced: 0.0
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >> agi_accountcode:
Jun 22 12:23:23 VERBOSE[19132] logger.c: AGI Tx >>
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- AGI Script VD_hangup.agi completed, returning 0
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'Y0622121451000198671'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '(null)'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '8600052'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'route'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'IAX2/draco-2'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '(null)'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'DeadAGI'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'VD_hangup.agi|h'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '2007-06-22 12:14:25'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '2007-06-22 12:14:26'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '2007-06-22 12:23:23'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '538'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '537'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'ANSWERED'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is 'DOCUMENTATION'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '(null)'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '1182507265.24124'
Jun 22 12:23:23 DEBUG[19132] pbx.c: Function result is '(null)'
Jun 22 12:23:23 DEBUG[19132] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jun 22 12:23:23 DEBUG[19132] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2007-06-22 12:14:25','Y0622121451000198671','','8600052','route', 'IAX2/draco-2','','DeadAGI','VD_hangup.agi|h',538,537,'ANSWERED',3,'','')
Jun 22 12:23:23 DEBUG[19132] channel.c: Hanging up channel 'IAX2/draco-2'
Jun 22 12:23:23 DEBUG[19132] chan_iax2.c: We're hanging up IAX2/draco-2 now...
Jun 22 12:23:23 DEBUG[19132] chan_iax2.c: Really destroying IAX2/draco-2 now...
Jun 22 12:23:23 VERBOSE[19132] logger.c:     -- Hungup 'IAX2/draco-2'


I'm trying to get the agiout file, but I'm not sure, if it's written on our system (the agi_output collumn is empty in servers table), so I hope it's not taken as NONE

Thanks for the interest into this problem

[mflorell]

You need to enable agi output going to FILE on the servers section in admin.php, then the file will write to the logs directory.

[tukak]

Will try, but the person responsible for our server, which can send me the logs is on vacation right now, so I'll have to wait a week.

Is there anything to be read from the output I pasted recently?

And I found out, that this happens just for the calls, which enter the queue (the 'All agents are busy, please wait a moment' style message is played) (and only to them). What config/file can affect it?

[mflorell]

That is interesting, I have never had an issue of calls entering a queue not properly popping the web form up. There might be the issue in your case though.

Have you done any tests on this to confirm, can you reproduce it at will?

[tukak]

It seems that these calls are losing information about the in-group when handled at the queue somehow.

I haven't done the tests yet, but I am able to find out, on which call it happened (the web form is then saved in another way) and it's just and only the calls which entered the queue.

I will try to reproduce today, but I'm quite sure I will be able to do it at will.

[mflorell]

If you can reproduce it in a testing situation please send me all of the details of your setup including:
- section of extensions.conf for the transfer or closer AGI script is
- agiout logfile output
- Asterisk CLI output