LIVE CALL detection delay

[b0l3k]

Hi everyone,

I have a problem with live call detection delay.
Once vicidial makes a call to my mobile and i answer it, i can talk to an agent stright away. The problem is that a green "LIVE CALL" message appears 21 seconds later.
I'm not sure how detection works, so if someone could light this up for me, I'll be much appreciated.

logs from my asterisk:
[May 4 13:38:20] == Manager 'sendcron' logged on from 127.0.0.1
[May 4 13:38:20] -- Executing [94907848074878408XXXX@default:1] AGI("Local/94907848074878408XXXX@default-00000011;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 4 13:38:20] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=FIN_MON))
[May 4 13:38:20] -- <Local/94907848074878408XXXX@default-00000011;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 4 13:38:20] -- Executing [94907848074878408XXXX@default:2] Dial("Local/94907848074878408XXXX@default-00000011;2", "SIP/4878408XXXX@ASTERISK,,tTo") in new stack
[May 4 13:38:20] == Using SIP RTP CoS mark 5
[May 4 13:38:20] -- Called SIP/4878408XXXX@ASTERISK
[May 4 13:38:21] -- SIP/ASTERISK-0000000b is making progress passing it to Local/94907848074878408XXXX@default-00000011;2
[May 4 13:38:25] -- SIP/ASTERISK-0000000b is ringing
[May 4 13:38:30] -- SIP/ASTERISK-0000000b answered Local/94907848074878408XXXX@default-00000011;2
[May 4 13:38:30] > Channel Local/94907848074878408XXXX@default-00000011;1 was answered.
[May 4 13:38:30] -- Executing [8368@default:1] Playback("Local/94907848074878408XXXX@default-00000011;1", "sip-silence") in new stack
[May 4 13:38:30] -- <Local/94907848074878408XXXX@default-00000011;1> Playing 'sip-silence.gsm' (language 'en')
[May 4 13:38:30] -- Executing [h@default:1] AGI("Local/94907848074878408XXXX@default-00000011;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----0") in new stack
[May 4 13:38:30] -- Executing [8368@default:2] AGI("SIP/ASTERISK-0000000b", "agi://127.0.0.1:4577/call_log") in new stack
[May 4 13:38:30] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=FIN_MON))
[May 4 13:38:30] -- <SIP/ASTERISK-0000000b>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 4 13:38:30] -- Executing [8368@default:3] AGI("SIP/ASTERISK-0000000b", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack
[May 4 13:38:30] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[May 4 13:38:30] -- <SIP/ASTERISK-0000000b>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[May 4 13:38:30] -- Executing [192*168*087*118*8600051@default:1] Goto("SIP/ASTERISK-0000000b", "default,8600051,1") in new stack
[May 4 13:38:30] -- Goto (default,8600051,1)
[May 4 13:38:30] -- Executing [8600051@default:1] MeetMe("SIP/ASTERISK-0000000b", "8600051,F") in new stack
[May 4 13:38:31] -- <Local/94907848074878408XXXX@default-00000011;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --10-----0 completed, returning 0
[May 4 13:38:31] == Spawn extension (default, 94907848074878408XXXX, 2) exited non-zero on 'Local/94907848074878408XXXX@default-00000011;2'
[May 4 13:38:32] == Manager 'sendcron' logged off from 127.0.0.1

... Here the call has been answered and sent to an agent ...
... no more logs for 21 seconds, and then "LIVE CALL" appeared on agent's screen:

[May 4 13:38:53] == Manager 'sendcron' logged on from 127.0.0.1
[May 4 13:38:53] -- Executing [58600051@default:1] MeetMe("Local/58600051@default-00000012;2", "8600051,Fmq") in new stack
[May 4 13:38:53] > Channel Local/58600051@default-00000012;1 was answered.
[May 4 13:38:53] -- Executing [8309@default:1] Answer("Local/58600051@default-00000012;1", "") in new stack
[May 4 13:38:53] -- Executing [8309@default:2] Monitor("Local/58600051@default-00000012;1", "wav,FIN-MON_2177_20150504-133851_784089202_dg") in new stack
[May 4 13:38:53] -- Executing [8309@default:3] Wait("Local/58600051@default-00000012;1", "3600") in new stack
[May 4 13:38:55] == Manager 'sendcron' logged off from 127.0.0.1

... Hangup works fine, once call is terminated, LIVE CALL disappears...

[May 4 13:39:01] == Manager 'sendcron' logged on from 127.0.0.1
[May 4 13:39:01] == Manager 'sendcron' logged on from 127.0.0.1
[May 4 13:39:01] == Manager 'sendcron' logged off from 127.0.0.1
[May 4 13:39:02] == Manager 'sendcron' logged off from 127.0.0.1
[May 4 13:39:02] == Spawn extension (default, 8600051, 1) exited non-zero on 'SIP/ASTERISK-0000000b'
[May 4 13:39:02] -- Executing [h@default:1] AGI("SIP/ASTERISK-0000000b", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 4 13:39:02] -- <SIP/ASTERISK-0000000b>AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0


PS.
Does it have to do with "Manager 'sendcron'" being logged off and back on all the time?

_____________________________________________
GoAutoDial CE 3.3
Vicidial VERSION: 2.9-441a, BUILD: 140612-1628
Asterisk 1.8.23.0-1
CentOS release 5.10 (Final)

[bobchaos]

Could be quite a few things. We'll need more info:

Is this a cluster? how many users? What's the specs on your machines? Is your DB or webserver showing any signs of strain? how about time sync, are the client station showing the exact same time as the server(s), down to the second?

[b0l3k]

Thanks for responce.

Its not a cluster, single vicidial server with mysql server running on the same machine. No time synchronisation issue. Server has 8 core CPU with 8GB of ram. Its not in production yet, still during tests, so server is not overloaded while this occures. It happens every single time,even when theres only one agent and one active call.

I wonder what makes vicidial client to know when is "Active Call", is it some mysql update query?

[bobchaos]

I dug into the code for active call detection some time back but I can't recall exactly how it works. It turned out to be an issue with the way canadian PRI carriers do thing and required the use of a special loopback interface. Are you using Canadian PRIs by any chance? It's the only similar issue i`ve encountered.

If not, have you looked into the apache logs and the AGI logs? Also are your client stations using Firefox? Vicidial is optimized for Firefox only. Are there any other symptoms that you've observed?

How exactly are you doing these tests? For example, are you dial in manual mode over PRIs, predictive over SIP, manual overide over IAX2? Does it work right if you test using different dialing methods? What about the live reports, what do they display in that 21 seconds of limbo?

Also, FYI, that sendcron thing is normal, it`s just Vicidial checking in for regular tasks. For example, if you edit a dialplan in the admin interface, submit and drop to asterisk console immediatly, you`ll see the sendcron trigger the dialplan reload.

[b0l3k]

Ok, I've located the problem.
I made a new campaign and attached the same list to it. Everything was fine, so i started comparing both campaigns.
Then i found out that there was a typo in my "Start Call URL" link

Basically, server was trying to open my link once it had a call. There must be some timeout around 20secs.
Ehhh, feel mad at myself

Once again, Thanks for your help.
Best Regards, Tom.

[bobchaos]

Glad you found it, I never would have guessed that o.O Thanks for the postback!