Getting another call while stil bein in communication/SOLVED

[sofcall]

Hi all.
I ve been running vicidial server () for about 8 months now with no problem; in fact working just great.until two days now. The agents start to get a second call while been in communication with a client or again hearing another call ringing.

It happens 4 to 5 times a day for every agent and in every compaigns.
I m running at least 6 compaigns for 5 agents in the same time.with 2 to 3 different trunks.

When this happens the server load is under 2.5(4 core xeon server)
(it s working great even with a load of 4.00)
Stable Adsl connexion with 3 Mega upload and download
No load on the agents workstations (running just the necessary applications)
Vicidial ;eyebeam;gmail)

The hard drive never reach its 50% Capacity (deleting records every 24h)
The asterisk –r output
[Apr 24 17:49:17] -- Executing [8309@default:3] Wait("Local/58600058@default-57fe,1", "2400") in new stack
[Apr 24 17:49:19] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 24 17:49:22] -- SIP/siptrunk-00000533 answered Local/8600051@default-b1ac,1
[Apr 24 17:49:23] == Parsing '/etc/asterisk/manager.conf': [Apr 24 17:49:23] Found
[Apr 24 17:49:23] == Manager 'sendcron' logged on from 127.0.0.1
[Apr 24 17:49:23] -- Executing [58600056@default:1] MeetMe("Local/58600056@default-fb77,2", "8600056|Fmq") in new stack
[Apr 24 17:49:23] > Channel Local/58600056@default-fb77,1 was answered.
[Apr 24 17:49:23] -- Executing [8309@default:1] Answer("Local/58600056@default-fb77,1", "") in new stack
[Apr 24 17:49:23] -- Executing [8309@default:2] Monitor("Local/58600056@default-fb77,1", "wav|LENGOSKI_120424174922_0321498279") in new stack
[Apr 24 17:49:23] -- Executing [8309@default:3] Wait("Local/58600056@default-fb77,1", "2400") in new stack
[Apr 24 17:49:25] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 24 17:49:28] == Parsing '/etc/asterisk/manager.conf': [Apr 24 17:49:28] Found
[Apr 24 17:49:28] == Manager 'sendcron' logged on from 127.0.0.1
[Apr 24 17:49:28] -- Executing [58600051@default:1] MeetMe("Local/58600051@default-71e1,2", "8600051|Fmq") in new stack
[Apr 24 17:49:28] > Channel Local/58600051@default-71e1,1 was answered.
[Apr 24 17:49:28] -- Executing [8309@default:1] Answer("Local/58600051@default-71e1,1", "") in new stack
[Apr 24 17:49:28] -- Executing [8309@default:2] Monitor("Local/58600051@default-71e1,1", "wav|CALASANT_120424174927_0953071985") in new stack
[Apr 24 17:49:28] -- Executing [8309@default:3] Wait("Local/58600051@default-71e1,1", "2400") in new stack
[Apr 24 17:49:30] -- SIP/siptrunk-00000534 is making progress passing it to Local/8600055@default-6f16,1
[Apr 24 17:49:30] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 24 17:49:32] == Parsing '/etc/asterisk/manager.conf': [Apr 24 17:49:32] Found
[Apr 24 17:49:32] == Manager 'sendcron' logged on from 127.0.0.1
[Apr 24 17:49:32] -- Executing [58600055@default:1] MeetMe("Local/58600055@default-85f1,2", "8600055|Fmq") in new stack
[Apr 24 17:49:32] > Channel Local/58600055@default-85f1,1 was answered.
[Apr 24 17:49:32] -- Executing [8309@default:1] Answer("Local/58600055@default-85f1,1", "") in new stack
[Apr 24 17:49:32] -- Executing [8309@default:2] Monitor("Local/58600055@default-85f1,1", "wav|CALASANT_120424174931_0534399438") in new stack
[Apr 24 17:49:32] -- Executing [8309@default:3] Wait("Local/58600055@default-85f1,1", "2400") in new stack
[Apr 24 17:49:34] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 24 17:49:35] -- Executing [h@default:1] DeadAGI("Local/8600051@default-b1ac,1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----13") in new stack
[Apr 24 17:49:35] WARNING[17074]: res_agi.c:2212 deadagi_exec: Running DeadAGI on a live channel will cause problems, please use AGI
[Apr 24 17:49:35] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... -28-----13 completed, returning 0
[Apr 24 17:49:35] == Spawn extension (default, 70953071985, 2) exited non-zero on 'Local/8600051@default-b1ac,1'
[Apr 24 17:49:35] == Spawn extension (default, 8600051, 1) exited non-zero on 'Local/8600051@default-b1ac,2'
[Apr 24 17:49:35] -- Executing [h@default:1] DeadAGI("Local/8600051@default-b1ac,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Apr 24 17:49:35] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Apr 24 17:49:36] -- SIP/siptrunk-00000535 answered Local/8600057@default-9fed,1
go*CLI> quit

Below is the “show processlist”when this is happening

and the screen -ls

Have changed nothing from the first configuration.

Dial time out set to 35 sec
Drop call second set to 4
Recording allcalls delaying it to 35 sec
Max vicidial trunk set to 20
Most of the time disabling (system Performance ,server log and carrier logging ) to keep the server load down.

**********************************************************
[siptrunk]
disallow=all
allow=ulaw
allow=alaw
allow=gsm
type=friend
secret=mysecret
username=username
host=x.x.x.x
dtmfmode=rfc2833
context=from-trunk
qualify=yes
insecure=very
nat=yes

TRUNK=SIP/siptrunk

exten => _0ZXXXXXXX.,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _0ZXXXXXXX.,n,Dial(${TRUNK}/0033${EXTEN:1},,tToR)
exten => _0ZXXXXXXX.,n,Hangup

exten => _0033ZXXXX.,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _0033ZXXXX.,n,Dial(${TRUNK}/${EXTEN},,tToR)
exten => _0033ZXXXX.,n,Hangup
***
Waiting for your help .
Thank you

[williamconley]

Thanks for the rather thorough request. With installer version and vicidial build Excellent.

The situation you describe is ordinarily the result of server overload. When you are watching htop, do you notice "spikes" that push one or several of the CPUs to 100%? (Even temporarily ...). This situation can cause problems.

Also: 6 campaigns for 5 agents? I'm a wee bit confused why you would possibly need more campaigns that agents. So there may also be a configuration issue that contributes. Please explain this in a bit more detail. And when you say "2 to 3 different trunks" I presume you mean you have a dial ratio between 2-3. If that is not what you mean, please also explain this in a bit more detail.

Please post your actual server load (from "uptime" is simplest) from the moment when one of these problems happens.

Please check your logs for several of these intruding prospects and see if they have anything in common (such as a specific campaign/did/ingroup/remote agent/whatever).

[sofcall]

Thanks.

do you notice "spikes" that push one or several of the CPUs to 100%?

well it' does push one or several of the CPUs but not really up to 100% sometimes up to 70% But most of the time it stays under 30 % .Have to add a second server right?(Db/ webserver)

6 campaigns for 5 agents?

well just a mistake .in fact 15 agents for at least 7 compaigns.
and having other compaigns activated on the system (do i have to disactivate them while they are not in use?

2 to 3 different trunks" I presume you mean you have a dial ratio between 2-3

i mean 2-3 diffirent voip providers. each one with it's own dial prfix.(Also noticed that there are lots of canceled calls when showing Carrier Stats in Reports.for example for the last 24 hours it shows :ANSWER :2488 CANCEL :1326 CONGESTION :268.
Wondering what could cause all this number of canceled calls (almost always 50 % of the total calls.)

Please post your actual server load from the moment when one of these problems happens

well been running 5 hours now with no problem till now.
will keep an eye on the server load and logs.
Thank you so much.

[sofcall]

Happened 1 hour ago. for two agents then later for another agent.

server load :1.7 /1.7. / 1.6
I noticed a log in :var/log/asterguiclient(remoteagent) but only saying :2012-04-25 09:33:03|PROGRAM STARTED|

Thank you

[sofcall]

Did it again lots of times
loadaverage: 1.7 1.6 1.43
[Apr 27 11:33:58] -- Executing [h@default:1] [1;36;40mDeadAGI [0;37;40m(" [1;35;40mLocal/58600054@default-cb88,1 [0;37;40m", " [1;35;40magi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- [0;37;40m") in new stack
[Apr 27 11:33:58] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Apr 27 11:33:58] == Parsing '/etc/asterisk/manager.conf': [Apr 27 11:33:58] Found
[Apr 27 11:33:58] == Manager 'sendcron' logged on from 127.0.0.1
[Apr 27 11:33:58] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 27 11:33:59] == Parsing '/etc/asterisk/manager.conf': [Apr 27 11:33:59] Found
[Apr 27 11:33:59] == Manager 'sendcron' logged on from 127.0.0.1
[Apr 27 11:33:59] -- Executing [8600054@default:1] [1;36;40mMeetMe [0;37;40m(" [1;35;40mLocal/8600054@default-a3ab,2 [0;37;40m", " [1;35;40m8600054|F [0;37;40m") in new stack
[Apr 27 11:33:59] > Channel Local/8600054@default-a3ab,1 was answered.
[Apr 27 11:33:59] -- Executing [50977089996@default:1] [1;36;40mAGI [0;37;40m(" [1;35;40mLocal/8600054@default-a3ab,1 [0;37;40m", " [1;35;40magi://127.0.0.1:4577/call_log [0;37;40m") in new stack
[Apr 27 11:33:59] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Apr 27 11:33:59] -- Executing [50977089996@default:2] [1;36;40mDial [0;37;40m(" [1;35;40mLocal/8600054@default-a3ab,1 [0;37;40m", " [1;35;40mSIP/siptrunk/0033977089996||tToR [0;37;40m") in new stack
[Apr 27 11:33:59] -- Called siptrunk/0033977089996
[Apr 27 11:33:59] -- SIP/siptrunk-00000321 is making progress passing it to Local/8600057@default-c2d2,1
[Apr 27 11:33:59] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 27 11:34:00] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 27 11:34:00] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 27 11:34:00] == Manager 'sendcron' logged off from 127.0.0.1
[Apr 27 11:34:00] [1;33;40mNOTICE [0;37;40m[3182]: [1;37;40mchan_sip.c [0;37;40m: [1;37;40m8208 [0;37;40m [1;37;40msip_reg_timeout [0;37;40m: -- Registration for '80601@193.105.217.3' timed out, trying again (Attempt #18)
[Apr 27 11:34:00] == Parsing '/etc/asterisk/manager.conf': [Apr 27 11:34:00] Found
[Apr 27 11:34:00] == Manager 'sendcron' logged on from 127.0.0.1
[Apr 27 11:34:00] -- Executing [58600055@default:1] [1;36;40mMeetMe [0;37;40m(" [1;35;40mLocal/58600055@default-0dc7,2 [0;37;40m", " [1;35;40m8600055|Fmq [0;37;40m") in new stack
[Apr 27 11:34:00] > Channel Local/58600055@default-0dc7,1 was answered.
[Apr 27 11:34:00] -- Executing [8309@default:1] [1;36;40mAnswer [0;37;40m(" [1;35;40mLocal/58600055@default-0dc7,1 [0;37;40m", " [1;35;40m [0;37;40m") in new stack
[Apr 27 11:34:00] -- Executing [8309@default:2] [1;36;40
************
Please help

[cbsys]

This is happening to quite a few of our client's sites too!

It seems to clear after rebooting, but comes back again after a while
the load on the CPU is never over 10%

[sofcall]

It still happens here.maybe two to three times a day.
one thing i m sure of is that it's not because of the load on the server

[marmu]

Hi Guys,

I'd say, we are experiencing the same. In one shift, from 5 pm to 9 pm we have about 5 to 10 cases where 1 agent is talking to at least 2 people in one conference room. It seems like it has something to do with local calls. I will add a paste bin link asap, where calls joining and leaving the conference is clearly shown. And you can see that there are 3 people in one conference room. Which shouldn't be the case. And yes, it has nothin to do with the load an the server, our server is nearly sleeping handlich over 100 agents

Do I get it right, that no one has a solution for this?

UPDATE
here is a log for conference room 8600072. I guess line 208 (2012-05-08 19:37:52) shows that multiple calls are in one conference room. Correct me if I am wrong. My collegue is working hard on solving this, or at least getting to the root of all evil

pastebin: http://pastebin.com/8xffjUtS

Could someone please explain what the use of these local channels is. We do not get it. What are they for, what script is checking available rooms and putting outbound calls into them. Is it /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi ?

Thanks for any hints in advance. Has someone solved this already? We will tell you our solution as soon as we got one.

Talk to you soon,
Marcus

[sofcall]

Hi,

our server is nearly sleeping handlich over 100 agents

I saw you have a single server; can you please share with us your server specs as well as your Vici configuration.
Are you recording call; codec used:Max VICIDIAL Trunks;Max Calls per Second;etc

Thank you;

[marmu]

Here are our server specs:

Code: Select all

cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 44
model name      : Intel(R) Xeon(R) CPU           X5650  @ 2.67GHz
stepping        : 2
cpu MHz         : 1596.000
cache size      : 12288 KB
we got 12 cores (2x hexa core), 24 threads

RAM: 12032M total

HD: LSI Mega RAID 1, 2x SAS 15k

we are not recording any calls.

codecs during a test outbound call: alaw/ulaw:
ast*CLI> sip show channels
Peer                         User/ANR           Call ID                   Seq (Tx/Rx)        Format           Hold     Last Message
xxx.xxx.xxx.xxx       external line       122749370a0      00102/28208409    0x4 (ulaw)       No       Rx: INFO
xxx.xxx.xxx.xxx       internal phone     735854546-5      00101/00141         0x4 (ulaw)       No       Rx: ACK
2 active SIP channels

Max VICIDIAL Trunks: 180
Max Calls per Second: 15

If there is anything else you'd like to know, tell me. Then I will update this post.

[sofcall]

Thank you so much for your quick answer

[marmu]

It was our fautl, I am sorry! Our agents were set to ready at the wrong time and that caused vicidial to put another call through to them.

Have a nice weekend!

Cheers,
Marcus

[sofcall]

Hi

Our agents were set to ready at the wrong time

how is that? please explain

Thank you

[eze-voip]

listening!

[sofcall]

Our agents were set to ready at the wrong time

how is that? please explain.Cause it's still happening here .

Thank you

[cbsys]

yes please explain, we have everything set to 24 hours, but the dialler should only start working when agents are logged in.
It should never have multiple calls in the same conference, no matter what the agents' times are!

[mcargile]

The usual cause of this is networking problems. It can also be caused by JavaScript problems.

The code that determines which determines which state an agent is in runs in JavaScript in the agents web browser. So for instance when an agent dispositions a call, this state machine transitions from Dispo to Ready. When it does so it sends a message to the web server saying that the agent is ready for a call. Because this is processed using HTTP the web server sends back an ACK to the agent's browser. If the browser never gets this ACK due to packet loss or other network problems, it will resend the message. This happens within the browser, out side the control of Vicidial's JavaScript engine. What can end up happening is that the web server will put the agent in ready. The dialer will send the agent a call. The agent goes into the InCall state. The retransmitted Ready message hits the web server. It puts the agent back into Ready. The dialer sends the agent another call.

[DomeDan]

Cool, I haven't had this problem in a while (I think) but I'm running mtr to ping a agent now, will leave it there for a week or longer.

But I have also noticed that some agents use double-click everywhere when using vicidial *facepalm*, but I haven't been able to directly connect that to this issue.

[sofcall]

Hi;

It puts the agent back into Ready. The dialer sends the agent another call.

We are only doing a manual dial so i geuss even when the agent is ready he should not receive a call until he hits the Next call button.

Any suggestion how to solve that? how to check and detect if there is any networking issue.and JavaScript problems.

tried many network configuration .

will show you my actual network configuration tomorrow.

thank you.

[sofcall]

SOLVED
Well i have to tell you that all this trouble was due to our voip provider.we had three acount from the same voip provider.

we switched to a newone and everything is fine now.
the owner did not want to beleive that it was the provider fault and was saying that it was VICI side.

i m the master now .
thank you VICI

[franklinsj]

The usual cause of this is networking problems. It can also be caused by JavaScript problems.

The code that determines which determines which state an agent is in runs in JavaScript in the agents web browser. So for instance when an agent dispositions a call, this state machine transitions from Dispo to Ready. When it does so it sends a message to the web server saying that the agent is ready for a call. Because this is processed using HTTP the web server sends back an ACK to the agent's browser. If the browser never gets this ACK due to packet loss or other network problems, it will resend the message. This happens within the browser, out side the control of Vicidial's JavaScript engine. What can end up happening is that the web server will put the agent in ready. The dialer will send the agent a call. The agent goes into the InCall state. The retransmitted Ready message hits the web server. It puts the agent back into Ready. The dialer sends the agent another call.

Hi. How can those javascript problems be worked out? Is there a specific version of a web browser that has proven not to cause these issues?

[gers55]

I concur with mcargile.


Whenever i have had this issue it has been a faulty LAN Cable or an issue with the browser . Either changing the LAN cable or checking out browser settings / changing browser has helped.

Load on the agents pc has also been a factor on this in the past ..

[franklinsj]

But what about the case where servers are powerful, network is not congested, pings from the agent station get replies in 1ms, constant ping shows no packet loss, servers are located in the local network, server's load is never over 0.50 in a multi processor server, agent's computer is not over loaded either, the switch ports do not show any collisions, late collisions, giants, etc. the only thing left would be javascript, what can be done about that?

[williamconley]

Process of elimination works with Carburetors, but not so much with Vicidial. What I mean to say is that I don't believe you can narrow it down to "it's the javascript" in that fashion.

But you CAN troubleshoot it via the various logs available and find out why a call went the way that it went ... and then find out where the flaw in the logic was.

More to the point, each time someone has described what you just described it has turned out to be a custom installation with non-standard code or configuration which turns out to be the problem. Not due to inexperience, but due to a strange (read: unpredictable) interaction with some of the custom/nonstandard nature of the install.

So turn on all your logging methods and wait for it to occur. Then get out your reading glasses and trace the call that went awry and see where that flaw was.

IF you possibly can, see if you can duplicate/cause/predict the error. If you can reproduce it at will, we can find it much easier.

[jkidd]

Hey William,

Can you tell me exactly what logs I should look at to try and troubleshoot this? I know of asterisk -vvvvvvvvvvvvvvvvvvvvvvvr is there anything else to watch for?

[williamconley]

Logs are in /var/log/astguiclient and /var/log/asterisk

Controlling those logs is via "Admin->Servers" look for the log settings on this page ... and in /etc/asterisk/logger.conf.

Note that "screen -r asterisk" will show you an asterisk console which is NOT available anywhere else. It is the ONLY log that will contain certain types of perl AGI script exceptions. Exercise caution while in here, though, as this is the real console. You can not type "exit", you must exit by [ctrl-a][ctrl-d]. Do not leave text on the CLI, as there are commands issued through this console regularly and any extraneous cr@p you may leave in the cli will cause the command to fail. Under no circumstances should you enter [ctrl-c], as you'll stop asterisk. LOL

[jkidd]

One cause of this issue is having the alt dial checkbox ticked when ending a call. It's a bug in a go autodial version and will then connect the agent to 2 calls next.

[williamconley]

One cause of this issue is having the alt dial checkbox ticked when ending a call. It's a bug in a go autodial version and will then connect the agent to 2 calls next.

Of course, you're on a very old version ... but that's an interesting note that could suggest "upgrading fixes it" ...

[jkidd]

Yeah I know it's old. Honestly, I just like using it for the agent display on the lunch room screen.