Big problem with Queue

Hi

When a person calls the standard, he is moving into a Queue.
The problem is that the responding agent is obliged to put the person on hold in order to be heard.

It is on a SIP phone, and the problem also persists on X-Lite, in reverse, with Zoiper there is no problem.

Do you have any idea where the problem may come from?

Define “the standard”.

Putting someone on hold normally cuts the audio in both directions.

Which SIP channel driver are you using?

Please provide the sip/pjsip debugging for the case both failing and working cases. Try to identify differences before posting, so that we don’t have to do so ourselves.

Sorry, i’m french

“The standard”, is my asterisk system

"Which SIP channel driver are you using?"
Where i can found this ?

"Please provide the sip/pjsip debugging for the case both failing and working cases. Try to identify differences before posting, so that we don’t have to do so ourselves."
Where i can found this too ?

Sorry, i’m not verry good :smiley:

The channel driver will be chan_sip, or chan_pjsip. You will have needed to know this in order to use the right configuration file.

For obtaining SIP debugging, see https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information#CollectingDebugInformation-Enablechanneltechorfeaturespecificdebug

In my “make menuselect”, chan_pjsip AND chan_sip are checked.

Please ask the person who configured the system to answer the question as it is not possible to configure it without knowing the answer.

I am the one who configured the system, and I did not select anything about it, I leave the default settings, I can see where it is active?

The logs with the problem : https://pastebin.com/QdwUniHu

Asterisk will not allow you to make any calls, except to the demo number and local services, if you don’t configure it. However, I see references to trunk_ovh, which I do not believe appears in the sample configuration. trunk_ovh appears to have been configured for the chan_sip channel driver.

The only calls in your log are incoming calls which have failed because you don’t recognize the called number, and they seem to be missing the actual SIP requests and response; s; you probably haven’t enabled verbose logging. What I want is the SIP re-INVITE or update transactions that are generated when the call is put on hold. For that, you need a call that is answered!

[Jun 13 18:03:22] Asterisk 14.5.0 built by root @ vps364285.ovh.net on a x86_64 running Linux on 2017-06-08 19:52:48 UTC
[Jun 13 18:03:22] DEBUG[3627] config.c: Parsing /etc/asterisk/logger.conf
[Jun 13 18:03:22] VERBOSE[3627] config.c: Parsing '/etc/asterisk/logger.conf': Found
[Jun 13 18:03:22] VERBOSE[3627] logger.c: Asterisk Queue Logger restarted
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: = Looking for  Call ID: ee52b2dc8fa52e35f66f3c7663103df0 (Checking From) --From tag 697f13dd65c7775aa1ea44b3cc832cf6 --To-tag   
[Jun 13 18:03:28] DEBUG[13205] acl.c: For destination '85.14.242.70', our source address is '137.74.198.197'.
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: Setting AST_TRANSPORT_UDP with address 137.74.198.197:5060
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:32782' into...
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '32782'.
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: Allocating new SIP dialog for ee52b2dc8fa52e35f66f3c7663103df0 - REGISTER (No RTP)
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:32782' into...
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '32782'.
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 85.14.242.70:32782
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: = Looking for  Call ID: ee52b2dc8fa52e35f66f3c7663103df0 (Checking From) --From tag 697f13dd65c7775aa1ea44b3cc832cf6 --To-tag   
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:32782' into...
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '32782'.
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:03:28] DEBUG[13205] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 85.14.242.70:32782
[Jun 13 18:03:28] NOTICE[13205] chan_sip.c: Registration from '210 <sip:210@137.74.198.197>' failed for '85.14.242.70:32782' - Wrong password
[Jun 13 18:03:28] DEBUG[13205] chan_sip.c: SIP message could not be handled, bad request: ee52b2dc8fa52e35f66f3c7663103df0                                      
[Jun 13 18:03:39] VERBOSE[13205] chan_sip.c: 
<--- SIP read from UDP:91.121.129.23:5060 --->
OPTIONS sip:s@137.74.198.197:5060 SIP/2.0
Call-ID: 06-03096-0c472da2-241369fc4@91.121.129.23
Contact: <sip:91.121.129.23:5060>
CSeq: 1 OPTIONS
From: <sip:keepalive@91.121.129.23:5060>;tag=06-03096-0c472da1-1ead73ab4
Max-Forwards: 70
To: <sip:00442034455325@siptrunk.ovh.co.uk>
Via: SIP/2.0/UDP 91.121.129.23:5060;rport;branch=z9hG4bK-MPMX-07052c57-18b09ca0
Content-Length: 0

<------------->
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  0 [ 41]: OPTIONS sip:s@137.74.198.197:5060 SIP/2.0
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  1 [ 50]: Call-ID: 06-03096-0c472da2-241369fc4@91.121.129.23
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  2 [ 33]: Contact: <sip:91.121.129.23:5060>
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  3 [ 15]: CSeq: 1 OPTIONS
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  4 [ 72]: From: <sip:keepalive@91.121.129.23:5060>;tag=06-03096-0c472da1-1ead73ab4
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  5 [ 16]: Max-Forwards: 70
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  6 [ 43]: To: <sip:00442034455325@siptrunk.ovh.co.uk>
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  7 [ 79]: Via: SIP/2.0/UDP 91.121.129.23:5060;rport;branch=z9hG4bK-MPMX-07052c57-18b09ca0
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c:  Header  8 [ 17]: Content-Length: 0
[Jun 13 18:03:39] VERBOSE[13205] chan_sip.c: --- (9 headers 0 lines) ---
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c: = Looking for  Call ID: 06-03096-0c472da2-241369fc4@91.121.129.23 (Checking From) --From tag 06-03096-0c472da1-1ead73ab4 --To-tag   
[Jun 13 18:03:39] DEBUG[13205] acl.c: For destination '91.121.129.23', our source address is '137.74.198.197'.
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c: Setting AST_TRANSPORT_UDP with address 137.74.198.197:5060
[Jun 13 18:03:39] DEBUG[13205] netsock2.c: Splitting '91.121.129.23:5060' into...
[Jun 13 18:03:39] DEBUG[13205] netsock2.c: ...host '91.121.129.23' and port '5060'.
[Jun 13 18:03:39] VERBOSE[13205] chan_sip.c: Sending to 91.121.129.23:5060 (no NAT)
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c: Allocating new SIP dialog for 06-03096-0c472da2-241369fc4@91.121.129.23 - OPTIONS (No RTP)
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS
[Jun 13 18:03:39] DEBUG[13205] netsock2.c: Splitting '137.74.198.197:5060' into...
[Jun 13 18:03:39] DEBUG[13205] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:03:39] DEBUG[13205] netsock2.c: Splitting '91.121.129.23:5060' into...
[Jun 13 18:03:39] DEBUG[13205] netsock2.c: ...host '91.121.129.23' and port ''.
[Jun 13 18:03:39] VERBOSE[13205] chan_sip.c: Looking for s in trunk-ovh (domain 137.74.198.197)
[Jun 13 18:03:39] VERBOSE[13205] chan_sip.c: 
<--- Transmitting (no NAT) to 91.121.129.23:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 91.121.129.23:5060;branch=z9hG4bK-MPMX-07052c57-18b09ca0;received=91.121.129.23;rport=5060
From: <sip:keepalive@91.121.129.23:5060>;tag=06-03096-0c472da1-1ead73ab4
To: <sip:00442034455325@siptrunk.ovh.co.uk>;tag=as63366f3a
Call-ID: 06-03096-0c472da2-241369fc4@91.121.129.23
CSeq: 1 OPTIONS
Server: Asterisk PBX 14.5.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Accept: application/sdp
Content-Length: 0


<------------>
[Jun 13 18:03:39] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 91.121.129.23:5060
[Jun 13 18:03:39] VERBOSE[13205] chan_sip.c: Scheduling destruction of SIP dialog '06-03096-0c472da2-241369fc4@91.121.129.23' in 32000 ms (Method: OPTIONS)
[Jun 13 18:03:40] DEBUG[13212] res_pjsip_registrar_expire.c: Woke up at 1497369820  Interval: 30
[Jun 13 18:03:40] DEBUG[13212] res_pjsip_registrar_expire.c: Expiring 0 contacts
[Jun 13 18:04:00] DEBUG[13205] chan_sip.c: Auto destroying SIP dialog 'ee52b2dc8fa52e35f66f3c7663103df0'
[Jun 13 18:04:00] DEBUG[13205] chan_sip.c: Destroying SIP dialog ee52b2dc8fa52e35f66f3c7663103df0
[Jun 13 18:04:00] VERBOSE[13205] chan_sip.c: Really destroying SIP dialog 'ee52b2dc8fa52e35f66f3c7663103df0' Method: REGISTER
[Jun 13 18:04:10] DEBUG[13212] res_pjsip_registrar_expire.c: Woke up at 1497369850  Interval: 30
[Jun 13 18:04:10] DEBUG[13212] res_pjsip_registrar_expire.c: Expiring 0 contacts
[Jun 13 18:04:11] DEBUG[13205] chan_sip.c: Auto destroying SIP dialog '06-03096-0c472da2-241369fc4@91.121.129.23'
[Jun 13 18:04:11] DEBUG[13205] chan_sip.c: Destroying SIP dialog 06-03096-0c472da2-241369fc4@91.121.129.23
[Jun 13 18:04:11] VERBOSE[13205] chan_sip.c: Really destroying SIP dialog '06-03096-0c472da2-241369fc4@91.121.129.23' Method: OPTIONS
[Jun 13 18:04:57] VERBOSE[13205][C-00009c89] netsock2.c: Using SIP RTP CoS mark 5
[Jun 13 18:04:57] NOTICE[13205][C-00009c89] chan_sip.c: Call from '' (163.182.171.212:5071) to extension '000264441743290091' rejected because extension not found in context 'trunk-ovh'.
[Jun 13 18:08:12] Asterisk 14.5.0 built by root @ vps364285.ovh.net on a x86_64 running Linux on 2017-06-08 19:52:48 UTC
[Jun 13 18:08:12] DEBUG[3635] config.c: Parsing /etc/asterisk/logger.conf
[Jun 13 18:08:12] VERBOSE[3635] config.c: Parsing '/etc/asterisk/logger.conf': Found
[Jun 13 18:08:12] VERBOSE[3635] logger.c: Asterisk Queue Logger restarted
[Jun 13 18:08:12] DEBUG[13205] chan_sip.c: = Looking for  Call ID: b9ace4506dfc4530c916593d46f88d45 (Checking From) --From tag c0c83287 --To-tag   
[Jun 13 18:08:12] DEBUG[13205] acl.c: For destination '93.115.26.147', our source address is '137.74.198.197'.
[Jun 13 18:08:12] DEBUG[13205] chan_sip.c: Setting AST_TRANSPORT_UDP with address 137.74.198.197:5060
[Jun 13 18:08:12] DEBUG[13205] netsock2.c: Splitting '93.115.26.147:5076' into...
[Jun 13 18:08:12] DEBUG[13205] netsock2.c: ...host '93.115.26.147' and port '5076'.
[Jun 13 18:08:12] DEBUG[13205] chan_sip.c: Allocating new SIP dialog for b9ace4506dfc4530c916593d46f88d45 - INVITE (No RTP)
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '93.115.26.147:5076' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '93.115.26.147' and port '5076'.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fe784d020f8'
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] res_rtp_asterisk.c: Allocated port 16548 for RTP instance '0x7fe784d020f8'
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:16548 (16548) for RTP instance '0x7fe784d020f8'
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: RTP instance '0x7fe784d020f8' is setup and ready to go
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting 'vps364285.ovh.net' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host 'vps364285.ovh.net' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fe784d020f8'
[Jun 13 18:08:12] VERBOSE[13205][C-00009c8d] netsock2.c: Using SIP RTP CoS mark 5
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Setting NAT on RTP to Off
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing session-level SDP o=sipcli-Session 1630346161 1817465356 IN IP4 93.115.26.147... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing session-level SDP s=sipcli... UNSUPPORTED OR FAILED.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '93.115.26.147' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '93.115.26.147' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing session-level SDP c=IN IP4 93.115.26.147... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7fe784325cc0) from 0x7fe724458440 to 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x7fe7862a21f0) from 0x7fe724458440 to 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x7fe784036060) from 0x7fe724458440 to 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Crossover copying tx to rx payload mapping 101 (0xe603e0) from 0x7fe724458440 to 0x7fe724458440
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] acl.c: For destination '93.115.26.147', our source address is '137.74.198.197'.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe784d020f8'
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying rx payload mapping 0 (0x7fe784325cc0) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying rx payload mapping 8 (0x7fe7862a21f0) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying rx payload mapping 18 (0x7fe784036060) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying rx payload mapping 101 (0xe603e0) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying tx payload mapping 0 (0x7fe784325cc0) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying tx payload mapping 8 (0x7fe7862a21f0) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying tx payload mapping 18 (0x7fe784036060) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] rtp_engine.c: Copying tx payload mapping 101 (0xe603e0) from 0x7fe724458440 to 0x7fe784d022c0
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fe784d020f8'
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: We're settling with these formats: (ulaw|alaw)
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Checking SIP call limits for device 
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Updating call counter for incoming call
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.147:5076
[Jun 13 18:08:12] NOTICE[13205][C-00009c8d] chan_sip.c: Call from '' (93.115.26.147:5076) to extension '5470048222043741' rejected because extension not found in context 'trunk-ovh'.
[Jun 13 18:08:12] DEBUG[13205][C-00009c8d] chan_sip.c: Updating call counter for incoming call
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: = Looking for  Call ID: 5c6204a5cb2eecdf4ca1cc9e68ef4fd1 (Checking From) --From tag e6203858f17515f878cba557cc73b7c0 --To-tag   
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jun 13 18:08:13] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:60123' into...
[Jun 13 18:08:13] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '60123'.
[Jun 13 18:08:13] DEBUG[13205] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:13] DEBUG[13205] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 85.14.242.70:60123
[Jun 13 18:08:13] NOTICE[13205] chan_sip.c: Registration from '400 <sip:400@137.74.198.197>' failed for '85.14.242.70:60123' - Wrong password
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: SIP message could not be handled, bad request: 5c6204a5cb2eecdf4ca1cc9e68ef4fd1                                      
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 500 ms (Retrans id #936)) 
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.145:5071
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #1554)) 
[Jun 13 18:08:13] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.147:5076
[Jun 13 18:08:14] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #1554)) 
[Jun 13 18:08:14] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.147:5076
[Jun 13 18:08:14] DEBUG[13205] chan_sip.c: Auto destroying SIP dialog '0062978acc7f06d895554623ccd9f6cb'
[Jun 13 18:08:14] DEBUG[13205] chan_sip.c: Destroying SIP dialog 0062978acc7f06d895554623ccd9f6cb
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: = Looking for  Call ID: 155bcf1bbe52e03758182c2d30d54403 (Checking From) --From tag 3de8af78c541885427682dd1b86f46cc --To-tag   
[Jun 13 18:08:15] DEBUG[13205] acl.c: For destination '85.14.242.70', our source address is '137.74.198.197'.
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: Setting AST_TRANSPORT_UDP with address 137.74.198.197:5060
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:52987' into...
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '52987'.
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: Allocating new SIP dialog for 155bcf1bbe52e03758182c2d30d54403 - REGISTER (No RTP)
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:52987' into...
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '52987'.
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 85.14.242.70:52987
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: = Looking for  Call ID: 155bcf1bbe52e03758182c2d30d54403 (Checking From) --From tag 3de8af78c541885427682dd1b86f46cc --To-tag   
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: Splitting '85.14.242.70:52987' into...
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: ...host '85.14.242.70' and port '52987'.
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: Splitting '137.74.198.197' into...
[Jun 13 18:08:15] DEBUG[13205] netsock2.c: ...host '137.74.198.197' and port ''.
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 85.14.242.70:52987
[Jun 13 18:08:15] NOTICE[13205] chan_sip.c: Registration from '400 <sip:400@137.74.198.197>' failed for '85.14.242.70:52987' - Wrong password
[Jun 13 18:08:15] DEBUG[13205] chan_sip.c: SIP message could not be handled, bad request: 155bcf1bbe52e03758182c2d30d54403                                      
[Jun 13 18:08:16] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #1554)) 
[Jun 13 18:08:16] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.147:5076
[Jun 13 18:08:17] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 8 to 4000 ms (t1 500 ms (Retrans id #936)) 
[Jun 13 18:08:17] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.145:5071
[Jun 13 18:08:18] DEBUG[13205] chan_sip.c: Auto destroying SIP dialog 'ce17218ad32c424f9e93edf4754a7488'
[Jun 13 18:08:18] DEBUG[13205] chan_sip.c: Destroying SIP dialog ce17218ad32c424f9e93edf4754a7488
[Jun 13 18:08:20] DEBUG[13205] chan_sip.c: Auto destroying SIP dialog '33c4d97f179bd508fd5c6abe30a4d888'
[Jun 13 18:08:20] DEBUG[13205] chan_sip.c: Destroying SIP dialog 33c4d97f179bd508fd5c6abe30a4d888
[Jun 13 18:08:20] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #1554)) 
[Jun 13 18:08:20] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.147:5076
[Jun 13 18:08:20] DEBUG[13205] chan_sip.c: Auto destroying SIP dialog '4de5cc737add6cc5f5e1349c92f14cb5'
[Jun 13 18:08:20] DEBUG[13205] chan_sip.c: Destroying SIP dialog 4de5cc737add6cc5f5e1349c92f14cb5
[Jun 13 18:08:21] DEBUG[13205] chan_sip.c: ** SIP timers: Rescheduling retransmission 9 to 4000 ms (t1 500 ms (Retrans id #936)) 
[Jun 13 18:08:21] DEBUG[13205] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 93.115.26.145:5071

The new logs with all activated :
https://pastebin.com/j0wmgxWy

In this log, A customer called, the agent responded, and because of the problem he does not hear, he was forced to put on hold.

[Jun 13 20:59:00] VERBOSE[6484][C-00000081] chan_sip.c: No matching peer for '0760486760' from '91.121.129.23:5060'

indicates bad practice or misconfiguration. You seem to be handling traffic from your ITSP as though it were from an unknown source. You will get a lot of such traffic, trying to make free calls through you.

[Jun 13 20:59:00] VERBOSE[6484][C-00000081] chan_sip.c: No matching peer for '0760486760' from '91.121.129.23:5060'

OVH has not sent any speech. One thing that can cause that is if both sides have the equivalent to Asterisk’s nat=comedia. They are both waiting for the other to send, to see what address to use. I can’t be sure that Asterisk is in this mode without your general section settings (as noted above, you are not matching a peer or user).

[Jun 13 20:59:04] VERBOSE[6484] chan_sip.c: Retransmitting #2 (NAT) to 90.104.106.66:36087:

You seem to have ringall agents,and one of them is down.

[Jun 13 20:59:04] DEBUG[6942][C-00000081] chan_sip.c: Sending reinvite on SIP '19149-DZ-00d2caef-7b36f64d0@siptrunk.ovh.co.uk' - It's audio soon redirected to IP 109.132.209.210:12282

You appear to have directmedia=yes, and no contraindications.

o=root 1434986479 1434986480 IN IP4 109.132.209.210
o=root 1197687716 1197687717 IN IP4 91.121.129.164

Unusually, both agent and ITSP seem to be on public IP addresses.

<--- SIP read from UDP:91.121.129.23:5060 --->
SIP/2.0 200 OK
Call-ID: 19149-DZ-00d2caef-7b36f64d0@siptrunk.ovh.co.uk

The ITSP has accepted the direct media re-invite.

<--- SIP read from UDP:91.121.129.23:5060 --->
SIP/2.0 200 OK
Call-ID: 19149-DZ-00d2caef-7b36f64d0@siptrunk.ovh.co.uk

The ITSP has started its own re-INVITE. I don’t know why.

<--- SIP read from UDP:109.132.209.210:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 137.74.198.197:5060;branch=z9hG4bK111fd3f0;rport=5060

The agent has accepted the direct media re-INVITE.

FROM NOW ON, THIS IS AN ISSUE BETWEEN THE AGENT PHONE AND THE ITSP. Asterisk is out of the media path!

<--- SIP read from UDP:109.132.209.210:5060 --->
INVITE sip:0760486760@137.74.198.197:5060 SIP/2.0
Via: SIP/2.0/UDP 109.132.209.210:5060;branch=z9hG4bK3689006006
From: <sip:112@109.132.209.210:5060>;tag=3837713256
To: "0760486760" <sip:0760486760@137.74.198.197>;tag=as3377adb4
Call-ID: 4a234c9135ba18e27bb795af7b0ca0fb@137.74.198.197:5060
CSeq: 2 INVITE
Contact: <sip:112@109.132.209.210:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.81.0.25
Allow-Events: talk,hold,conference,refer,check-sync
Content-Length: 312
 
v=0
o=- 20463 20465 IN IP4 109.132.209.210
s=SDP data
c=IN IP4 109.132.209.210
t=0 0
m=audio 12282 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendonly

The agent has put the call on hold.

[Jun 13 20:59:10] VERBOSE[6942][C-00000081] chan_sip.c: Reliably Transmitting (no NAT) to 91.121.129.23:5060:
INVITE sip:10.7.1.163:5060 SIP/2.0
Via: SIP/2.0/UDP 137.74.198.197:5060;branch=z9hG4bK7e34c3ef
Route: <sip:91.121.129.23:5060;lr>

Asterisk takes the ITSP out of directmeda.

[Jun 13 20:59:10] DEBUG[6945][C-00000081] res_rtp_asterisk.c: No remote address on RTP instance '0x7fa1d8017018' so dropping frame
[Jun 13 20:59:10] DEBUG[6945][C-00000081] res_rtp_asterisk.c: No remote address on RTP instance '0x7fa1d8017018' so dropping frame

Asterisk discards media because of the hold.

INVITE sip:0760486760@137.74.198.197:5060 SIP/2.0
Via: SIP/2.0/UDP 109.132.209.210:5060;branch=z9hG4bK16597691
From: <sip:112@109.132.209.210:5060>;tag=3837713256
To: "0760486760" <sip:0760486760@137.74.198.197>;tag=as3377adb4
Call-ID: 4a234c9135ba18e27bb795af7b0ca0fb@137.74.198.197:5060
CSeq: 3 INVITE
Contact: <sip:112@109.132.209.210:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.81.0.25
Allow-Events: talk,hold,conference,refer,check-sync
Content-Length: 312
 
v=0
o=- 20463 20466 IN IP4 109.132.209.210
s=SDP data
c=IN IP4 109.132.209.210
t=0 0
m=audio 12282 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

Agent cancels hold.

[Jun 13 20:59:12] VERBOSE[6942][C-00000081] chan_sip.c: Reliably Transmitting (no NAT) to 91.121.129.23:5060:
INVITE sip:10.7.1.163:5060 SIP/2.0
Via: SIP/2.0/UDP 137.74.198.197:5060;branch=z9hG4bK2f1906e5

Asterisk re-instates direct media to the ITSP.

<--- SIP read from UDP:91.121.129.23:5060 --->
BYE sip:0186954041@137.74.198.197:5060 SIP/2.0
Call-ID: 19149-DZ-00d2caef-7b36f64d0@siptrunk.ovh.co.uk
CSeq: 13500054 BYE

ITSP closes the call.

Conclusiion. Whilst there might be a comedia issue, that is not critical, as the symptom appears after Asterisk has taken itself out of the media path. The problem must lie with the phone, or network. As the second attempt at direct media works, I would say the problem has to be with the phone.

Suggested workround. Disable directmedia.

In the sip.conf in the [general] ?

directmedia=no

And i see in the doc, i must put NAT=yes ?

You appear to be using all real addresses, so there is no evidence that there is any NAT involved. If there is, I can’t tell it from what you have provided. nat=yes enables comedia, and if there is a comedia standoff will cause problems.

Okay, but

directmedia=no

In my sip.con, in [general] or in [trunk] ?

As you are failing to match trunk, it will need to go in general, until you have fixed the fail to match problem.

It works ! The agent no longer needs to put on hold to be heard.

Note that the use of Queues is almost certainly irrelevant, here.

Thanks you, and can i ask you an other question ?

In my features.conf, i have this :
[featuremap]
;blindxfer => #1 ; Blind transfer (default is #) – Make sure to$
;disconnect => *0 ; Disconnect (default is *) – Make sure to se$
;automon => *1 ; One Touch Record a.k.a. Touch Monitor – Make$
atxfer => ** ; Attended transfer – Make sure to set the T a$
;parkcall => #72 ; Park call (one step parking) – Make sure to$
;automixmon => *3

But when i press **, this not work.


And now, when i enter in asterisk with asterisk -rvvvv, i don’t have logs in my console

Please start a new thread.

Thanks you for this problem !

New thread : Problem with features