3 way fronter/closer can't hear each other from time to time

[manos]

Hello folks!
I have made a fresh install of vicibox9.0.1, cluster installation in two bare metal servers
In one of them we installed vmware and the installation/specification are as below

The first bare metal server unvirtualized has this specs:

DB/Web/Asterisk - express install

CPU: Intel(R) Xeon(R) D-2141I CPU @ 2.20GHz / 16 cores
RAM: 32GB
Storage: SSD nvme 500GB

--------------------------------------------------------------------------------------

The other parts of cluster installation Dialers/Web are installed on the virtualized server

Dialer1 - express install:
-----------

CPU: Intel(R) Xeon(R) CPU E5-2630 v3 @ 2.40GHz / 4core
RAM: 16GB
Storage: SSD nvme (shared storage from virtual server 65GB)

Dialer2 - express install:
-----------

CPU: Intel(R) Xeon(R) CPU E5-2630 v3 @ 2.40GHz / 4 core
RAM: 8GB
Storage: SSD nvme (shared storage from virtual server 16GB)

Dialer3 / Web - express install:
--------------------

CPU: Intel(R) Xeon(R) CPU E5-2630 v3 @ 2.40GHz / 4 core
RAM: 8GB
Storage: SSD nvme (shared storage from virtual server 75GB)



-----------------------------------------------------------------------------------------------------------------------------
Asterisk version: Asterisk 13.27.1-vici
Vicibox:
VERSION: 2.14-794a
BUILD: 210309-2207



Problem explanation:
------------------------------

We have two campaigns configured one for fronters and one for closers.
Fronters make only outbound calls, Closers take inbound calls from Fronters and make outbound calls too with blended enable

Fronters pass the call using the 3way call method. From time to time when the fronter passes the call to the closer the closer can't hear neither the fronter or the customer, and the fronter can't hear the closer.
At these specific cases the closer always receives the call as hanged up.


What i saw at asterisk logs is this. When the call is successfully passed there is always a log like this one:

Code: Select all

pbx.c: Executing [xxx*xxx*xxx*xxx*8600057@default:1] Dial("IAX2/ASTloop-15485", "IAX2/Dialer5:password@xxx.xxx.xxx.xxx:4569/8600057,55,oT") in new stack
app_dial.c: Called IAX2/Dialer5:password@xxx.xxx.xxx.xxx:4569/8600057
app_dial.c: IAX2/salesWeb-1560 answered IAX2/ASTloop-15485


Dialer5 is the hostname of the first dialer where some of the fronters sips are,
salesWeb is the hostname of the Dialer/Web server where the closers sips are.

Meanwhile when the call isn't passed successfully in the asterisk logs those lines above are missing.
I can see only these type of lines:

Code: Select all

pbx.c: Executing [90009*sales*CXFER*515728**phone_number*user**58*@default:2] Dial("Local/90009*sales*CXFER*515728**phone_number*user**58*@default-0000abf9;2", "IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*515728**phone_number*user**58*,,to") in new stack
app_dial.c: Called IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*515728**phone_number*user**58*
app_dial.c: IAX2/127.0.0.1:40569-8534 answered Local/90009*sales*CXFER*515728**phone_number*user**58*@default-0000abf9;2


On the server there are stored both record_audio files.
On the fronter audio file you can hear only the fronter and the client, no sounds of the closer
On the closer audio file you can hear nothing cause only the ambient noise of the room where the closers are.

From this kind of logs it seems that the closer receives the call but for whatever reasons it arrives like hanged up and both parts can't hear each other.


Hope that I was clear with my explanation, thank you so much in advanced!
P.S: I desperately need some guides as soon as possible.

[carpenox]

do you have ip_relay running correctly and try running your keepalives with --cu3way flag next to it in crontab

[manos]

Hello and thanks for the reply!
I did a netstat -antup | grep ip_relay and it outputs this

Code: Select all

tcp         0      0 0.0.0.0:41569             0.0.0.0:*               LISTEN               2323/ip_relay       
tcp         0      0 0.0.0.0:42569             0.0.0.0:*               LISTEN               2324/ip_relay       
tcp         0      0 0.0.0.0:40569             0.0.0.0:*               LISTEN               2322/ip_relay       
udp        0      0 0.0.0.0:40569             0.0.0.0:*                                          2322/ip_relay       
udp        0      0 0.0.0.0:41569             0.0.0.0:*                                          2323/ip_relay       
udp        0      0 0.0.0.0:42569             0.0.0.0:*                                          2324/ip_relay       
udp        0      0 127.0.0.1:61160         127.0.0.1:4569    ESTABLISHED   2322/ip_relay       
udp        0      0 127.0.0.1:1202           127.0.0.1:4569    ESTABLISHED   2323/ip_relay       
udp        0      0 127.0.0.1:17604         127.0.0.1:4569    ESTABLISHED   2324/ip_relay


which i think that its running okay..

Sorry for the stupid question maybe but what exactly does the --cu3way flag at keepalive script?
Thanks in advance!

[carpenox]

im not sure what the functionality for it triggers, i never looked at the code for that, but it helps fix issues with 3way calling and transfers for some reason

[manos]

Question...

I saw somewhere else that said that it may be a good practice to put this flag on this script too.

Code: Select all

### updater for conference validator
* * * * * /usr/share/astguiclient/AST_conf_update.pl --no-vc-3way-check


Does it make sense, what things do this flag fix or makes work smoother.
Also now the closers are complaining that when the call from 3way is closed by the client they hear the voice, "You have been kicked from this conference"
Is this a normal behavior caused by one of these flags..

Thanks again!

[manos]

Also something else that i always have doubts.
The options Balance DIaling is Y on all servers, immediately below is the option for Balance Rank.

I have 4 servers.. and lets say that i put them in this rank order
Server One: Balance Rank 1
Server Two: Balance Rank 2
Server Three: Balance Rank 3
Server Four: Balance Rank 4

Now which one takes more precedence, the one with Rank 1 or Rank 4?

[carpenox]

higher ranks take precedence and the kicked from 3 way IS normal, its telling them that they are no lnoger in the meetme conference, because it got transfered to the closer.....

[manos]

Look, i know it may sound stupid but.. lets say in a race the highest rank is 1, and then goes the 2nd etc.
But in here the system of ranking in vicidial is the same as in sports where the highest is 1 and so on or is 4,3,2,1.

As for the Voice "You have been kicked from this conference" this notification from the system didn't happen before..
As far as i now, correct me if i'm wrong..
Lets say that in channel with this conference number: 8600001 is a fronter in call with a client and wants to pass this call to the closer.
The closer enters in this conference right? Now there are three persons in the conference 8600001. After the fronter makes his work, he clicks the leave three way button and enters in an another conference number lets say 8600002 waiting for other autodial leads.
Now in the conference 8600001 is only the customer and the closer.. is it normal that when the customer closes the call for whatever reason cause he is bored from the closer or he got disconnected or whatever.. the closer at that specific time getting the message "You have been kicked from this conference" is normal.
I'm trying to understand because it is hard to distinguish if the customer really hanged up or it was just the system that for whatever reason kicks out from the channel the closer, even for the closers themself is hard to understand which of the scenarios was.

May this issue be caused by overloading, just a thought?

[mjohn425]

@Manos, rank 4 takes precedence, calls will be placed out of it first.

It appears that issues are only occurring when transferring to another agent using the same dialer as the request was initially passed out of. Have you configured your own firewall, if so, make sure loopback interfaces are allowed, i.e localhost, 127.0.0.1 and ::1/128, also NAT loopback just in case if you have a separate public IP for the server. IAX2 transmission occurs on different ports to the voice (RTP) (which is negotiated by the IAX2 interaction), hopefully your firewall considers further voice packets as RELATED if that is the way your firewall is configured. You can go into asterisk and confirm that you are getting the IAX2 packets (iax2 set debug on) within asterisk, if you are, please confirm that you are sending and receiving the voice packets using a tool such as tcpdump

From there you should be able to see what the firewall is blocking and be able to remedy it.

I don't think overload is the issue in this case as you have mentioned in your asterisk logs that you only receive the issue when you are doing Same Server > Same Server transfer.

[manos]

@mjohn425, thank you so much for the reply, i appreciate it!
Well, first of all i'm not good at asterisk and i just know some basic stuff about it.

You mentioned that you think the issue rises only when the fronter call is initialized on the same server as the sip closer receiver is right. (If i understood correctly)
But i'm gonne show you the entire log that i grabbed at the server that the fronter sip exists.
The phone call was initialized from Dialer1 and was send by vicidial through iax protocol to the main server where the fronter sip exists.

The fronter tried 3 or 4 times to connect with the closers, each time that was a failed connection he didn't hear nothing although that the two different closers opened the call and they didn't hear nothing neither.
The third time another closer picked up the phone and finally the connection was made with success. Here is the detailed log, at least I hope so..

Code: Select all


/* Receive the call from dialer1 where the call was originated to this main server Web/DB/Dialer where the fronter sip is */

[Mar 19 15:58:46] VERBOSE[11420][C-0001cccf] pbx.c: Executing [8309@default:1] Answer("Local/58600056@default-0001697c;1", "") in new stack
[Mar 19 15:58:46] VERBOSE[11420][C-0001cccf] pbx.c: Executing [8309@default:2] Monitor("Local/58600056@default-0001697c;1", "wav,4444_fronter_20210319-155845_phonenr") in new stack
[Mar 19 15:58:46] VERBOSE[11420][C-0001cccf] pbx.c: Executing [8309@default:3] Wait("Local/58600056@default-0001697c;1", "3600") in new stack

/* The first attempt he makes to pass the call */

[Mar 19 15:59:41] VERBOSE[13115][C-0001cdf4] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**57*@default:1] Answer("Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2", "") in new stack
[Mar 19 15:59:41] VERBOSE[13114][C-0001cdf5] pbx.c: Executing [8600056@default:1] MeetMe("Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;1", "8600056,F") in new stack
[Mar 19 15:59:41] VERBOSE[13115][C-0001cdf4] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**57*@default:2] Dial("Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2", "IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**57*,,to") in new stack
[Mar 19 15:59:41] VERBOSE[13115][C-0001cdf4] app_dial.c: Called IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**57*
[Mar 19 15:59:41] VERBOSE[2393][C-0001cdf4] chan_iax2.c: Call accepted by 127.0.0.1:40569 (format ulaw)
[Mar 19 15:59:41] VERBOSE[2393][C-0001cdf4] chan_iax2.c: Format for call is (ulaw)
[Mar 19 15:59:41] VERBOSE[13116][C-0001cdf6] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**57*@default:1] Answer("IAX2/ASTloop-403", "") in new stack
[Mar 19 15:59:41] VERBOSE[13115][C-0001cdf4] app_dial.c: IAX2/127.0.0.1:40569-12391 answered Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2
[Mar 19 15:59:41] VERBOSE[13117][C-0001cdf4] bridge_channel.c: Channel IAX2/127.0.0.1:40569-12391 joined 'simple_bridge' basic-bridge <6f2f636d-c466-482b-8d4e-519464c13a41>
[Mar 19 15:59:41] VERBOSE[13115][C-0001cdf4] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2 joined 'simple_bridge' basic-bridge <6f2f636d-c466-482b-8d4e-519464c13a41>
[Mar 19 15:59:41] VERBOSE[13116][C-0001cdf6] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**57*@default:2] AGI("IAX2/ASTloop-403", "agi-VDAD_ALL_inbound.agi,CLOSER-----LB-----CL_TESTCAMP-----7275551212-----Closer-----park----------999-----1") in new stack
[Mar 19 15:59:41] VERBOSE[13116][C-0001cdf6] res_agi.c: Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[Mar 19 15:59:42] VERBOSE[13116][C-0001cdf6] res_agi.c: <IAX2/ASTloop-403> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 15:59:42] VERBOSE[13116][C-0001cdf6] res_agi.c: <IAX2/ASTloop-403> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 15:59:44] WARNING[13116][C-0001cdf6] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.
[Mar 19 15:59:48] WARNING[13116][C-0001cdf6] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.
[Mar 19 15:59:50] VERBOSE[13117][C-0001cdf4] bridge_channel.c: Channel IAX2/127.0.0.1:40569-12391 left 'simple_bridge' basic-bridge <6f2f636d-c466-482b-8d4e-519464c13a41>
[Mar 19 15:59:50] VERBOSE[13115][C-0001cdf4] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2 left 'simple_bridge' basic-bridge <6f2f636d-c466-482b-8d4e-519464c13a41>
[Mar 19 15:59:50] VERBOSE[13117][C-0001cdf4] chan_iax2.c: Hungup 'IAX2/127.0.0.1:40569-12391'
[Mar 19 15:59:50] VERBOSE[13115][C-0001cdf4] pbx.c: Spawn extension (default, 90009*sales*CXFER*559995**phonenr*fronter**57*, 2) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2'
[Mar 19 15:59:50] WARNING[13115][C-0001cdf4] func_hangupcause.c: Unable to find information for channel
[Mar 19 15:59:50] VERBOSE[13115][C-0001cdf4] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----8-----8-----)") in new stack
[Mar 19 15:59:50] VERBOSE[13116][C-0001cdf6] res_agi.c: <IAX2/ASTloop-403>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 4
[Mar 19 15:59:50] VERBOSE[13115][C-0001cdf4] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----8-----8-----) completed, returning 0
[Mar 19 15:59:50] VERBOSE[13116][C-0001cdf6] pbx.c: Spawn extension (default, 990009*sales*CXFER*559995**phonenr*fronter**57*, 2) exited non-zero on 'IAX2/ASTloop-403'
[Mar 19 15:59:50] VERBOSE[13116][C-0001cdf6] pbx.c: Executing [h@default:1] AGI("IAX2/ASTloop-403", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------IAX2 HANGUP (16))") in new stack
[Mar 19 15:59:50] VERBOSE[13114][C-0001cdf5] pbx.c: Spawn extension (default, 8600056, 1) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;1'
[Mar 19 15:59:50] WARNING[13114][C-0001cdf5] func_hangupcause.c: Unable to find information for channel
[Mar 19 15:59:50] VERBOSE[13114][C-0001cdf5] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------)") in new stack
[Mar 19 15:59:50] VERBOSE[13114][C-0001cdf5] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**57*@default-00016a6c;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------) completed, returning 0
[Mar 19 15:59:50] VERBOSE[13116][C-0001cdf6] res_agi.c: <IAX2/ASTloop-403>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------IAX2 HANGUP (16)) completed, returning 0
[Mar 19 15:59:50] VERBOSE[13116][C-0001cdf6] chan_iax2.c: Hungup 'IAX2/ASTloop-403'
/* The closer opened, both sides can't hear each other */


/* The second attempt he makes to pass the call */

[Mar 19 15:59:52] VERBOSE[13480][C-0001ce38] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**67*@default:1] Answer("Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2", "") in new stack
[Mar 19 15:59:52] VERBOSE[13479][C-0001ce39] pbx.c: Executing [8600056@default:1] MeetMe("Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;1", "8600056,F") in new stack
[Mar 19 15:59:52] VERBOSE[13480][C-0001ce38] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**67*@default:2] Dial("Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2", "IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**67*,,to") in new stack
[Mar 19 15:59:52] VERBOSE[13480][C-0001ce38] app_dial.c: Called IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**67*
[Mar 19 15:59:52] VERBOSE[2420][C-0001ce38] chan_iax2.c: Call accepted by 127.0.0.1:40569 (format ulaw)
[Mar 19 15:59:52] VERBOSE[2420][C-0001ce38] chan_iax2.c: Format for call is (ulaw)
[Mar 19 15:59:52] VERBOSE[13484][C-0001ce3b] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**67*@default:1] Answer("IAX2/ASTloop-4882", "") in new stack
[Mar 19 15:59:52] VERBOSE[13480][C-0001ce38] app_dial.c: IAX2/127.0.0.1:40569-6113 answered Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2
[Mar 19 15:59:52] VERBOSE[13485][C-0001ce38] bridge_channel.c: Channel IAX2/127.0.0.1:40569-6113 joined 'simple_bridge' basic-bridge <cd974988-4115-4d5d-81df-b3bb163c8391>
[Mar 19 15:59:52] VERBOSE[13480][C-0001ce38] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2 joined 'simple_bridge' basic-bridge <cd974988-4115-4d5d-81df-b3bb163c8391>
[Mar 19 15:59:52] VERBOSE[13484][C-0001ce3b] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**67*@default:2] AGI("IAX2/ASTloop-4882", "agi-VDAD_ALL_inbound.agi,CLOSER-----LB-----CL_TESTCAMP-----7275551212-----Closer-----park----------999-----1") in new stack
[Mar 19 15:59:52] VERBOSE[13484][C-0001ce3b] res_agi.c: Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[Mar 19 15:59:52] VERBOSE[13484][C-0001ce3b] res_agi.c: <IAX2/ASTloop-4882> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 15:59:52] VERBOSE[13484][C-0001ce3b] res_agi.c: <IAX2/ASTloop-4882> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 15:59:54] WARNING[13484][C-0001ce3b] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.
[Mar 19 15:59:58] WARNING[13484][C-0001ce3b] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.
[Mar 19 16:00:02] VERBOSE[13485][C-0001ce38] bridge_channel.c: Channel IAX2/127.0.0.1:40569-6113 left 'simple_bridge' basic-bridge <cd974988-4115-4d5d-81df-b3bb163c8391>
[Mar 19 16:00:02] VERBOSE[13485][C-0001ce38] chan_iax2.c: Hungup 'IAX2/127.0.0.1:40569-6113'
[Mar 19 16:00:02] VERBOSE[13480][C-0001ce38] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2 left 'simple_bridge' basic-bridge <cd974988-4115-4d5d-81df-b3bb163c8391>
[Mar 19 16:00:02] VERBOSE[13480][C-0001ce38] pbx.c: Spawn extension (default, 90009*sales*CXFER*559995**phonenr*fronter**67*, 2) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2'
[Mar 19 16:00:02] WARNING[13480][C-0001ce38] func_hangupcause.c: Unable to find information for channel
[Mar 19 16:00:02] VERBOSE[13480][C-0001ce38] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----10-----)") in new stack
[Mar 19 16:00:02] VERBOSE[13484][C-0001ce3b] res_agi.c: <IAX2/ASTloop-4882>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 4
[Mar 19 16:00:02] VERBOSE[13484][C-0001ce3b] pbx.c: Spawn extension (default, 990009*sales*CXFER*559995**phonenr*fronter**67*, 2) exited non-zero on 'IAX2/ASTloop-4882'
[Mar 19 16:00:02] VERBOSE[13484][C-0001ce3b] pbx.c: Executing [h@default:1] AGI("IAX2/ASTloop-4882", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------IAX2 HANGUP (16))") in new stack
[Mar 19 16:00:02] VERBOSE[13480][C-0001ce38] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----10-----) completed, returning 0
[Mar 19 16:00:02] VERBOSE[13479][C-0001ce39] pbx.c: Spawn extension (default, 8600056, 1) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;1'
[Mar 19 16:00:02] WARNING[13479][C-0001ce39] func_hangupcause.c: Unable to find information for channel
[Mar 19 16:00:02] VERBOSE[13479][C-0001ce39] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------)") in new stack
[Mar 19 16:00:02] VERBOSE[13479][C-0001ce39] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**67*@default-00016aa3;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------) completed, returning 0
[Mar 19 16:00:03] VERBOSE[13484][C-0001ce3b] res_agi.c: <IAX2/ASTloop-4882>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------IAX2 HANGUP (16)) completed, returning 0
[Mar 19 16:00:03] VERBOSE[13484][C-0001ce3b] chan_iax2.c: Hungup 'IAX2/ASTloop-4882'
/* Another closer opened, both sides can't hear each other */


/* The third attempt he makes to pass the call */

[Mar 19 16:00:05] VERBOSE[13907][C-0001ce7b] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**81*@default:1] Answer("Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2", "") in new stack
[Mar 19 16:00:05] VERBOSE[13906][C-0001ce7c] pbx.c: Executing [8600056@default:1] MeetMe("Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;1", "8600056,F") in new stack
[Mar 19 16:00:05] VERBOSE[13907][C-0001ce7b] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**81*@default:2] Dial("Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2", "IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**81*,,to") in new stack
[Mar 19 16:00:05] VERBOSE[13907][C-0001ce7b] app_dial.c: Called IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**81*
[Mar 19 16:00:05] VERBOSE[2374][C-0001ce7b] chan_iax2.c: Call accepted by 127.0.0.1:40569 (format ulaw)
[Mar 19 16:00:05] VERBOSE[2374][C-0001ce7b] chan_iax2.c: Format for call is (ulaw)
[Mar 19 16:00:05] VERBOSE[13910][C-0001ce7d] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**81*@default:1] Answer("IAX2/ASTloop-10402", "") in new stack
[Mar 19 16:00:05] VERBOSE[13907][C-0001ce7b] app_dial.c: IAX2/127.0.0.1:40569-956 answered Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2
[Mar 19 16:00:05] VERBOSE[13914][C-0001ce7b] bridge_channel.c: Channel IAX2/127.0.0.1:40569-956 joined 'simple_bridge' basic-bridge <75a02139-787f-43bf-98e3-efb2bff55b9e>
[Mar 19 16:00:05] VERBOSE[13907][C-0001ce7b] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2 joined 'simple_bridge' basic-bridge <75a02139-787f-43bf-98e3-efb2bff55b9e>
[Mar 19 16:00:05] VERBOSE[13910][C-0001ce7d] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**81*@default:2] AGI("IAX2/ASTloop-10402", "agi-VDAD_ALL_inbound.agi,CLOSER-----LB-----CL_TESTCAMP-----7275551212-----Closer-----park----------999-----1") in new stack
[Mar 19 16:00:05] VERBOSE[13910][C-0001ce7d] res_agi.c: Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[Mar 19 16:00:06] VERBOSE[13910][C-0001ce7d] res_agi.c: <IAX2/ASTloop-10402> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:06] VERBOSE[13910][C-0001ce7d] res_agi.c: <IAX2/ASTloop-10402> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:08] WARNING[13910][C-0001ce7d] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.
[Mar 19 16:00:12] WARNING[13910][C-0001ce7d] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.
[Mar 19 16:00:20] VERBOSE[13914][C-0001ce7b] bridge_channel.c: Channel IAX2/127.0.0.1:40569-956 left 'simple_bridge' basic-bridge <75a02139-787f-43bf-98e3-efb2bff55b9e>
[Mar 19 16:00:20] VERBOSE[13907][C-0001ce7b] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2 left 'simple_bridge' basic-bridge <75a02139-787f-43bf-98e3-efb2bff55b9e>
[Mar 19 16:00:20] VERBOSE[13914][C-0001ce7b] chan_iax2.c: Hungup 'IAX2/127.0.0.1:40569-956'
[Mar 19 16:00:20] VERBOSE[13907][C-0001ce7b] pbx.c: Spawn extension (default, 90009*sales*CXFER*559995**phonenr*fronter**81*, 2) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2'
[Mar 19 16:00:20] WARNING[13907][C-0001ce7b] func_hangupcause.c: Unable to find information for channel
[Mar 19 16:00:20] VERBOSE[13907][C-0001ce7b] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----15-----15-----)") in new stack
[Mar 19 16:00:20] VERBOSE[13910][C-0001ce7d] res_agi.c: <IAX2/ASTloop-10402>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 4
[Mar 19 16:00:20] VERBOSE[13910][C-0001ce7d] pbx.c: Spawn extension (default, 990009*sales*CXFER*559995**phonenr*fronter**81*, 2) exited non-zero on 'IAX2/ASTloop-10402'
[Mar 19 16:00:20] VERBOSE[13910][C-0001ce7d] pbx.c: Executing [h@default:1] AGI("IAX2/ASTloop-10402", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------IAX2 HANGUP (16))") in new stack
[Mar 19 16:00:20] VERBOSE[13907][C-0001ce7b] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----15-----15-----) completed, returning 0
[Mar 19 16:00:20] VERBOSE[13906][C-0001ce7c] pbx.c: Spawn extension (default, 8600056, 1) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;1'
[Mar 19 16:00:20] WARNING[13906][C-0001ce7c] func_hangupcause.c: Unable to find information for channel
[Mar 19 16:00:20] VERBOSE[13906][C-0001ce7c] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------)") in new stack
[Mar 19 16:00:20] VERBOSE[13906][C-0001ce7c] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**81*@default-00016ace;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------) completed, returning 0
[Mar 19 16:00:20] VERBOSE[13910][C-0001ce7d] res_agi.c: <IAX2/ASTloop-10402>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------IAX2 HANGUP (16)) completed, returning 0
[Mar 19 16:00:20] VERBOSE[13910][C-0001ce7d] chan_iax2.c: Hungup 'IAX2/ASTloop-10402'

/* i dont know if he pressed somewhere Hangup CXFER Line just shooting in the dark thinking that again somebody opened and still silence
cause there exists only 4 audio_records on the server, The audio record of the fronter, the two silent with ambient noise of the first two closers
and the forth of the last closer that finally the call was passed successfully */

/* The forth and the successful attempt to pass the call */
/* The call is passed to Dialer3/Web where the closers sipis are */

[Mar 19 16:00:22] VERBOSE[14540][C-0001ced7] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**97*@default:1] Answer("Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2", "") in new stack
[Mar 19 16:00:22] VERBOSE[14539][C-0001ced8] pbx.c: Executing [8600056@default:1] MeetMe("Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;1", "8600056,F") in new stack
[Mar 19 16:00:22] VERBOSE[14540][C-0001ced7] pbx.c: Executing [90009*sales*CXFER*559995**phonenr*fronter**97*@default:2] Dial("Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2", "IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**97*,,to") in new stack
[Mar 19 16:00:22] VERBOSE[14540][C-0001ced7] app_dial.c: Called IAX2/ASTloop:test@127.0.0.1:40569/990009*sales*CXFER*559995**phonenr*fronter**97*
[Mar 19 16:00:22] VERBOSE[2420][C-0001ced7] chan_iax2.c: Call accepted by 127.0.0.1:40569 (format ulaw)
[Mar 19 16:00:22] VERBOSE[2420][C-0001ced7] chan_iax2.c: Format for call is (ulaw)
[Mar 19 16:00:22] VERBOSE[14546][C-0001ceda] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**97*@default:1] Answer("IAX2/ASTloop-6356", "") in new stack
[Mar 19 16:00:22] VERBOSE[14540][C-0001ced7] app_dial.c: IAX2/127.0.0.1:40569-4227 answered Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2
[Mar 19 16:00:22] VERBOSE[14549][C-0001ced7] bridge_channel.c: Channel IAX2/127.0.0.1:40569-4227 joined 'simple_bridge' basic-bridge <c4b6e1a6-dcad-4be3-872c-30703c5463aa>
[Mar 19 16:00:22] VERBOSE[14540][C-0001ced7] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2 joined 'simple_bridge' basic-bridge <c4b6e1a6-dcad-4be3-872c-30703c5463aa>
[Mar 19 16:00:22] VERBOSE[14546][C-0001ceda] pbx.c: Executing [990009*sales*CXFER*559995**phonenr*fronter**97*@default:2] AGI("IAX2/ASTloop-6356", "agi-VDAD_ALL_inbound.agi,CLOSER-----LB-----CL_TESTCAMP-----7275551212-----Closer-----park----------999-----1") in new stack
[Mar 19 16:00:22] VERBOSE[14546][C-0001ceda] res_agi.c: Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[Mar 19 16:00:22] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:22] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:23] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:23] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en')
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] pbx.c: Executing [xxx*xxx*xxx*xxx*8600065@default:1] Dial("IAX2/ASTloop-6356", "IAX2/main:aZEys2cG9triVFg@xxx.xxx.xxx.xxx:4569/8600065,55,oT") in new stack
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] app_dial.c: Called IAX2/main:aZEys2cG9triVFg@xxx.xxx.xxx.xxx:4569/8600065
[Mar 19 16:00:24] VERBOSE[2419][C-0001ceda] chan_iax2.c: Call accepted by xxx.xxx.xxx.xxx:4569 (format ulaw)
[Mar 19 16:00:24] VERBOSE[2419][C-0001ceda] chan_iax2.c: Format for call is (ulaw)
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] app_dial.c: IAX2/salesWeb-8735 answered IAX2/ASTloop-6356
[Mar 19 16:00:24] VERBOSE[14615][C-0001ceda] bridge_channel.c: Channel IAX2/salesWeb-8735 joined 'simple_bridge' basic-bridge <76dfd484-15cd-451b-82c1-596669582770>
[Mar 19 16:00:24] VERBOSE[14546][C-0001ceda] bridge_channel.c: Channel IAX2/ASTloop-6356 joined 'simple_bridge' basic-bridge <76dfd484-15cd-451b-82c1-596669582770>
[Mar 19 16:01:07] VERBOSE[11420][C-0001cccf] pbx.c: Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600056@default-0001697c;1'
[Mar 19 16:01:07] WARNING[11420][C-0001cccf] func_hangupcause.c: Unable to find information for channel
[Mar 19 16:01:07] VERBOSE[11420][C-0001cccf] pbx.c: Executing [h@default:1] AGI("Local/58600056@default-0001697c;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------------)") in new stack
[Mar 19 16:01:07] VERBOSE[11420][C-0001cccf] res_agi.c: <Local/58600056@default-0001697c;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------------) completed, returning 0
[Mar 19 16:02:02] VERBOSE[14615][C-0001ceda] bridge_channel.c: Channel IAX2/salesWeb-8735 left 'simple_bridge' basic-bridge <76dfd484-15cd-451b-82c1-596669582770>
[Mar 19 16:02:02] VERBOSE[14546][C-0001ceda] bridge_channel.c: Channel IAX2/ASTloop-6356 left 'simple_bridge' basic-bridge <76dfd484-15cd-451b-82c1-596669582770>
[Mar 19 16:02:02] VERBOSE[14615][C-0001ceda] chan_iax2.c: Hungup 'IAX2/salesWeb-8735'
[Mar 19 16:02:02] VERBOSE[14546][C-0001ceda] pbx.c: Spawn extension (default, xxx*xxx*xxx*xxx*8600065, 1) exited non-zero on 'IAX2/ASTloop-6356'
[Mar 19 16:02:02] VERBOSE[14546][C-0001ceda] pbx.c: Executing [h@default:1] AGI("IAX2/ASTloop-6356", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----100-----100-----IAX2 HANGUP (0))") in new stack
[Mar 19 16:02:02] VERBOSE[14546][C-0001ceda] res_agi.c: <IAX2/ASTloop-6356>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----100-----100-----IAX2 HANGUP (0)) completed, returning 0
[Mar 19 16:02:02] VERBOSE[14546][C-0001ceda] chan_iax2.c: Hungup 'IAX2/ASTloop-6356'
[Mar 19 16:02:02] VERBOSE[14549][C-0001ced7] bridge_channel.c: Channel IAX2/127.0.0.1:40569-4227 left 'simple_bridge' basic-bridge <c4b6e1a6-dcad-4be3-872c-30703c5463aa>
[Mar 19 16:02:02] VERBOSE[14540][C-0001ced7] bridge_channel.c: Channel Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2 left 'simple_bridge' basic-bridge <c4b6e1a6-dcad-4be3-872c-30703c5463aa>
[Mar 19 16:02:02] VERBOSE[14549][C-0001ced7] chan_iax2.c: Hungup 'IAX2/127.0.0.1:40569-4227'
[Mar 19 16:02:02] VERBOSE[14540][C-0001ced7] pbx.c: Spawn extension (default, 90009*sales*CXFER*559995**phonenr*fronter**97*, 2) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2'
[Mar 19 16:02:02] VERBOSE[14540][C-0001ced7] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----100-----100-----IAX2 HANGUP (16))") in new stack
[Mar 19 16:02:02] VERBOSE[14540][C-0001ced7] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----100-----100-----IAX2 HANGUP (16)) completed, returning 0
[Mar 19 16:02:02] VERBOSE[14539][C-0001ced8] pbx.c: Spawn extension (default, 8600056, 1) exited non-zero on 'Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;1'
[Mar 19 16:02:02] WARNING[14539][C-0001ced8] func_hangupcause.c: Unable to find information for channel
[Mar 19 16:02:02] VERBOSE[14539][C-0001ced8] pbx.c: Executing [h@default:1] AGI("Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------)") in new stack
[Mar 19 16:02:02] VERBOSE[14539][C-0001ced8] res_agi.c: <Local/90009*sales*CXFER*559995**phonenr*fronter**97*@default-00016b16;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------------) completed, returning 0


Hope that i wasn't too verbose with all these logs but, lets hope that you can help me with finding what causes this problem
Thanks so much for the help!

[manos]

@mjohn425

Here is the iptables-save configuration output from the main server which is a full install DB/Web/Asterisk.
Take a look if you think that something is misconfigured in it for this specific scenario that you are talking about.

Code: Select all

:INPUT DROP [61055431:10550196229]
:FORWARD DROP [0:0]
:OUTPUT ACCEPT [628407517:176551767586]
-A INPUT -i lo -j ACCEPT
-A INPUT -m state --state RELATED,ESTABLISHED -j ACCEPT
-A INPUT -s xxx.xxx.xxx.xxx/32 -j ACCEPT # DIALER 1
-A INPUT -s xxx.xxx.xxx.xxx/32 -j ACCEPT # DIALER 2
-A INPUT -s xxx.xxx.xxx.xxx/32 -j ACCEPT # DIALER 3 / WEB  (where closers sips are)
-A INPUT -s xxx.xxx.xxx.xxx/32 -j ACCEPT # Our gateway public Ip Adress
COMMIT


This kind of configuration is also on the other Dialers. Nothing special.
Thank you again!

[manos]

Please, has somebody any idea, or can someone share their time to take a look at the logs that i posted..
I don't have the enough knowledge to troubleshoot this problem alone

Thanks!

[carpenox]

msg me on skype ill help you out

[mjohn425]

Please, has somebody any idea, or can someone share their time to take a look at the logs that i posted..
I don't have the enough knowledge to troubleshoot this problem alone

Thanks!

Apologies @manos, not sure if you've fixed it, if not read below. It doesn't seem the issue I initially thought (it always fails when transferring to the same server). One line does stick out to me though:

Code: Select all

[Mar 19 16:00:12] WARNING[13910][C-0001ce7d] res_musiconhold.c: Music on Hold class 'default' not found in memory. Verify your configuration.

Couple of things can cause this, run through these steps:
1) Check the /etc/asterisk/musiconhold.conf and /etc/asterisk/musiconhold-vicidial.conf for abnormalities
2) Check that your audio store is updating correctly. If you are using https, make sure your secondary dialers can curl https://mymaindialer.com/vicidial/admin.php. If it comes up with an issue, your server won't be able to update the audio files. You can either add the cert into the trusted root store or make your apache instance have a cert chain which is trusted. Also check that your system settings point to the correct location as the central audio store (note: don't copy files individually, upload them by the GUI and let the below script sync them. If an issue with the script, fix that first)
3) Try run perl /usr/share/astguiclient/ADMIN_audio_store_sync.pl --debugX manually and see if any issues.
4) Check for correct file/folder permissions for the folders listed in /etc/asterisk/musiconhold ....

If any issues, let me know.