SIP trunk and Wait()

Hi,

I have a SIP trunk between an old Asterisk 1.4 and a new Asterisk 16.
I noticed that if a UDP SIP client registered on Asterisk 16 tries to call an IVR in Asterisk 1.4 then the call hangs up if the IVR triggers the Wait() function with a parameter > 1.
For instance, Wait(3) gives this error and hangs up (h):

    -- Executing [s@custom-ivr1_init:2] Wait("SIP/meetbox-0003f556", "3") in new stack
  == Spawn extension (custom-ivr1_init, s, 2) exited non-zero on 'SIP/meetbox-0003f556'

On the other hand, Wait(1) works fine. I also noticed that for webrtc clients doing the same call, any value for Wait() works fine too.

So, why am I seeing this premature/forced hangup when using Wait( n > 1 ) and only for UDP SIP clients?
I’m guessing there must be a SIP trunk setting responsible for this.

Vieri

There is no error in that log. Please increase the logging level until you see something that isn’t a normal call hangup.

Best guess at the moment is that you have a short RTP timeout hat is being triggered.

Well, I thought I already had increased logging level.
I ran debug level 99 or core set debug 20 (in Asterisk 1.4) but I’m still only getting this in the console:

    -- Executing [s@custom-ivr1_init:2] Wait("SIP/meetbox-0003f728", "1") in new stack
  == Spawn extension (custom-ivr1_init, s, 2) exited non-zero on 'SIP/meetbox-0003f728'
    -- Executing [h@custom-ivr1_init:1] Macro("SIP/meetbox-0003f728", "hangupcall") in new stack

Setting core set verbose 20 doesn’t give me more information here either.

Setting both verbose and debug to 99 on the Asterisk 16 system doesn’t show much either:

Console verbose was 13 and is now 99.
  == Setting global variable 'SIPDOMAIN' to 'sip.mydomain.org'
    -- Executing [7000@default:1] NoOp("PJSIP/4053-0000004c", "4053 is dialing 7000 through trunk") in new stack
    -- Executing [7000@default:2] Dial("PJSIP/4053-0000004c", "PJSIP/meetbox/sip:7000@10.215.147.115,300,tTWg") in new stack
    -- Called PJSIP/meetbox/sip:7000@10.215.147.115
    -- PJSIP/meetbox-0000004d answered PJSIP/4053-0000004c
       > 0x7f04900a30a0 -- Strict RTP learning after remote address set to: 10.215.147.115:12392
       > 0x7f0490099870 -- Strict RTP learning after remote address set to: 10.215.147.115:18946
       > 0x7f0490045560 -- Strict RTP learning after remote address set to: 10.215.144.48:5093
       > 0x7f04900804f0 -- Strict RTP learning after remote address set to: 10.215.144.48:5095
    -- Channel PJSIP/meetbox-0000004d joined 'simple_bridge' basic-bridge <c7aa674a-0ccf-4434-925a-1f6d0e8d7f5d>
    -- Channel PJSIP/4053-0000004c joined 'simple_bridge' basic-bridge <c7aa674a-0ccf-4434-925a-1f6d0e8d7f5d>
    -- Channel PJSIP/4053-0000004c left 'simple_bridge' basic-bridge <c7aa674a-0ccf-4434-925a-1f6d0e8d7f5d>
    -- Channel PJSIP/meetbox-0000004d left 'simple_bridge' basic-bridge <c7aa674a-0ccf-4434-925a-1f6d0e8d7f5d>
  == Spawn extension (default, 7000, 2) exited non-zero on 'PJSIP/4053-0000004c'

RTP… I haven’t set anything explicitly as far as I know.

You are looking at the console, which doesn’t carry the debugging log by default and also doesn’t have time stamp information. You need to enable the full log in logger.conf and use /var/log/asterisk/full.

Also the lack of any problems reported on the debug log, suggests that it is the peer that is clearing the call, possibly due to not getting media. As such you will need the pjsip protocol logging, as well. Google “asterisk wiki debug” for more details.

I don’t know how I missed that, but now I have a “full” log on Ast 16 (Ast 1.4 doesn’t seem to tell me much about this hangup).

In the Ast 16 log I can see something about a capability mismatch. but I’m not sure which one it is. I’ll try to enable SIP debugging for that.
Strange thing though is that the call IS established but almost immediately hung up. It “shouldn’t” be a a codec issue.
I coudl also try with another SIP UA.

This is the log when SIP UA 4053 in Ast 16 calls IVR 7000 in Ast 1.4:

[Oct 12 08:34:46] VERBOSE[318][C-00000002] app_dial.c: Called PJSIP/meetbox/sip:7000@10.215.147.115
[...]
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Method is INVITE
[...]
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Response is 100 Trying

[...]
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fad40071400'
[Oct 12 08:34:46] DEBUG[2600] netsock2.c: Splitting '10.215.147.115' into...
[Oct 12 08:34:46] DEBUG[2600] netsock2.c: ...host '10.215.147.115' and port ''.
[Oct 12 08:34:46] DEBUG[2600] acl.c: For destination '10.215.147.115', our source address is '172.16.0.2'.
[Oct 12 08:34:46] DEBUG[2585] devicestate.c: No provider found, checking channel drivers for PJSIP - meetbox
[Oct 12 08:34:46] VERBOSE[318][C-00000002] app_dial.c: PJSIP/meetbox-00000003 answered PJSIP/4053-00000002
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fad40071400'
[Oct 12 08:34:46] VERBOSE[2600] res_rtp_asterisk.c: 0x7fad4008de80 -- Strict RTP learning after remote address set to: 10.215.147.115:18054
[Oct 12 08:34:46] DEBUG[2585] devicestate.c: Changing state for PJSIP/meetbox - state 2 (In use)
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fad6eee4da0
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7fad6eee4da0
[Oct 12 08:34:46] DEBUG[2639] app_queue.c: Device 'PJSIP/meetbox' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Setting tx payload type 3 based on m type on 0x7fad6eee4da0
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Copying tx payload mapping 0 (0x7fad40084478) from 0x7fad6eee4da0 to 0x7fad400715d8
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Copying tx payload mapping 3 (0x7fad400844c8) from 0x7fad6eee4da0 to 0x7fad400715d8
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Copying tx payload mapping 8 (0x7fad40084388) from 0x7fad6eee4da0 to 0x7fad400715d8
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Copying tx payload mapping 101 (0x7fad40084628) from 0x7fad6eee4da0 to 0x7fad400715d8
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/meetbox-00000003 setting read format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/4053-00000002 setting write format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[2600] channel.c: Channel PJSIP/meetbox-00000003 setting read format path: alaw -> ulaw
[Oct 12 08:34:46] DEBUG[2600] channel.c: Channel PJSIP/meetbox-00000003 setting write format path: ulaw -> alaw
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: ast_rtp_activate (0x7fad4008de80) - setup and perform DTLS'
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/4053-00000002 setting read format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad4008de80) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad4008de80) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Applying negotiated SDP media stream 'video' using video SDP handler
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fad400735c0'
[Oct 12 08:34:46] DEBUG[2600] netsock2.c: Splitting '10.215.147.115' into...
[Oct 12 08:34:46] DEBUG[2600] netsock2.c: ...host '10.215.147.115' and port ''.
[Oct 12 08:34:46] DEBUG[2600] acl.c: For destination '10.215.147.115', our source address is '172.16.0.2'.
[Oct 12 08:34:46] DEBUG[2585] devicestate.c: No provider found, checking channel drivers for PJSIP - 4053
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fad400735c0'
[Oct 12 08:34:46] VERBOSE[2600] res_rtp_asterisk.c: 0x7fad40081230 -- Strict RTP learning after remote address set to: 10.215.147.115:18678
[Oct 12 08:34:46] DEBUG[2585] devicestate.c: Changing state for PJSIP/4053 - state 3 (Busy)
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fad400c0750'
[Oct 12 08:34:46] DEBUG[319] netsock2.c: Splitting '10.215.144.48' into...
[Oct 12 08:34:46] DEBUG[319] netsock2.c: ...host '10.215.144.48' and port ''.
[Oct 12 08:34:46] DEBUG[2600] rtp_engine.c: Copying tx payload mapping 99 (0x7fad400843f8) from 0x7fad6eee4da0 to 0x7fad40073798
[Oct 12 08:34:46] DEBUG[2639] app_queue.c: Removed testuser. from pending_members
[Oct 12 08:34:46] DEBUG[319] acl.c: For destination '10.215.144.48', our source address is '172.16.0.2'.
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: ast_rtp_activate (0x7fad40081230) - setup and perform DTLS'
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fad400c0750'
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad40081230) - ssl = (nil), setup = 0
[Oct 12 08:34:46] VERBOSE[319] res_rtp_asterisk.c: 0x7fad400bc910 -- Strict RTP learning after remote address set to: 10.215.144.48:5105
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad40081230) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[2639] app_queue.c: Device 'PJSIP/4053' changed to state '3' (Busy)
[Oct 12 08:34:46] DEBUG[319] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7fad6ed6dfb0
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Applied negotiated SDP media stream 'video' using video SDP handler
[Oct 12 08:34:46] DEBUG[319] rtp_engine.c: Copying tx payload mapping 0 (0x7fad3c008d38) from 0x7fad6ed6dfb0 to 0x7fad400c0928
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.215.147.115'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Transport type for target '10.215.147.115' is 'UDP transport'
[Oct 12 08:34:46] DEBUG[319] channel.c: Channel PJSIP/4053-00000002 setting read format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[319] channel.c: Channel PJSIP/4053-00000002 setting write format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Target '10.215.147.115' is an IP address, skipping resolution
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: ast_rtp_activate (0x7fad400bc910) - setup and perform DTLS'
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad400bc910) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad400bc910) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Applying negotiated SDP media stream 'video' using video SDP handler
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fad400c13a0'
[Oct 12 08:34:46] DEBUG[319] netsock2.c: Splitting '10.215.144.48' into...
[Oct 12 08:34:46] DEBUG[319] netsock2.c: ...host '10.215.144.48' and port ''.
[Oct 12 08:34:46] DEBUG[319] acl.c: For destination '10.215.144.48', our source address is '172.16.0.2'.
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fad400c13a0'
[Oct 12 08:34:46] VERBOSE[319] res_rtp_asterisk.c: 0x7fad40094f00 -- Strict RTP learning after remote address set to: 10.215.144.48:5107
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The state change pertains to the endpoint 'meetbox(PJSIP/meetbox-00000003)'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fad4005f268)
[Oct 12 08:34:46] DEBUG[319] rtp_engine.c: Copying tx payload mapping 96 (0x7fad3c008be8) from 0x7fad6ed6dfb0 to 0x7fad400c1578
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: There is no transaction involved in this state change
[Oct 12 08:34:46] DEBUG[319] rtp_engine.c: Copying tx payload mapping 97 (0x7fad3c008cd8) from 0x7fad6ed6dfb0 to 0x7fad400c1578
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current inv state is CONFIRMED
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: ast_rtp_activate (0x7fad40094f00) - setup and perform DTLS'
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad40094f00) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The state change pertains to the endpoint 'meetbox(PJSIP/meetbox-00000003)'
[Oct 12 08:34:46] DEBUG[319] res_rtp_asterisk.c: dtls_perform_handshake (0x7fad40094f00) - ssl = (nil), setup = 0
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Applied negotiated SDP media stream 'video' using video SDP handler
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fad4005f268
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current transaction state is Terminated
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The transaction state change event is RX_MSG
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current inv state is CONFIRMED
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Received response
[Oct 12 08:34:46] DEBUG[319] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 172.16.0.2:5060 (this may be re-written again later)
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Response is 200 OK
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The state change pertains to the endpoint '4053(PJSIP/4053-00000002)'
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fad4004d578)
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: There is no transaction involved in this state change
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The current inv state is CONNECTING
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The state change pertains to the endpoint '4053(PJSIP/4053-00000002)'
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fad4004d578)
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7fad4004d578
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The current transaction state is Completed
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The transaction state change event is TX_MSG
[Oct 12 08:34:46] DEBUG[319] res_pjsip_session.c: The current inv state is CONNECTING
[Oct 12 08:34:46] DEBUG[318][C-00000002] stasis.c: Creating topic. name: bridge:b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6, detail:
[Oct 12 08:34:46] DEBUG[318][C-00000002] stasis.c: Topic 'bridge:b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6': 0x7fad3800e070 created
[Oct 12 08:34:46] DEBUG[318][C-00000002] stasis.c: Creating topic. name: cache:85/bridge:b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6, detail:
[Oct 12 08:34:46] DEBUG[318][C-00000002] stasis.c: Topic 'cache:85/bridge:b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6': 0x7fad38012060 created
[Oct 12 08:34:46] DEBUG[2599] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fad40061a28 for Request msg ACK/cseq=2 (rdata0x7facc400e4b8)
[Oct 12 08:34:46] DEBUG[2599] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000005a associated with dialog dlg0x7fad40061a28
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_native_rtp.c: Bridge 'b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6' can not use native RTP bridge as two channels are required
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Oct 12 08:34:46] DEBUG[318][C-00000002] dahdi/bridge_native_dahdi.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: Cannot use native DAHDI.  Must have two channels.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping.
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The state change pertains to the endpoint '4053(PJSIP/4053-00000002)'
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Chose bridge technology simple_bridge
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7fad4004d578
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: calling simple_bridge technology constructor
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current transaction state is Terminated
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: calling simple_bridge technology start
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The transaction state change event is USER
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current inv state is CONNECTING
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The state change pertains to the endpoint '4053(PJSIP/4053-00000002)'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: There is no transaction involved in this state change
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current inv state is CONFIRMED
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Received request
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: 0x7fad3800bec0(PJSIP/meetbox-00000003) is joining
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Method is ACK
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: pushing 0x7fad3800bec0(PJSIP/meetbox-00000003)
[Oct 12 08:34:46] VERBOSE[324][C-00000002] bridge_channel.c: Channel PJSIP/meetbox-00000003 joined 'simple_bridge' basic-bridge <b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6>
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge_native_rtp.c: Bridge 'b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6' can not use native RTP bridge as two channels are required
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Oct 12 08:34:46] DEBUG[324][C-00000002] dahdi/bridge_native_dahdi.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: Cannot use native DAHDI.  Must have two channels.
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Chose bridge technology simple_bridge
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6 is already using the new technology.
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: 0x7fad3800bec0(PJSIP/meetbox-00000003) is joining simple_bridge technology
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: 0x7fad38001da0(PJSIP/4053-00000002) is joining
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: pushing 0x7fad38001da0(PJSIP/4053-00000002)
[Oct 12 08:34:46] VERBOSE[318][C-00000002] bridge_channel.c: Channel PJSIP/4053-00000002 joined 'simple_bridge' basic-bridge <b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6>
[Oct 12 08:34:46] DEBUG[2593] cdr.c: Finalized CDR for PJSIP/meetbox-00000003 - start 1602484486.415525 answer 1602484486.889081 end 1602484486.951218 dur 0.535 bill 0.062 dispo ANSWERED
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_native_rtp.c: Bridge 'b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6'.  Checking compatability for channels 'PJSIP/meetbox-00000003' and 'PJSIP/4053-00000002'
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_native_rtp.c: Bridge 'b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6' can not use native RTP bridge as it was forbidden while getting details
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Oct 12 08:34:46] DEBUG[318][C-00000002] dahdi/bridge_native_dahdi.c: Channel 'PJSIP/meetbox-00000003' has DTMF hooks.
[Oct 12 08:34:46] DEBUG[318][C-00000002] dahdi/bridge_native_dahdi.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: Cannot use native DAHDI.  Channel 'PJSIP/meetbox-00000003' not compatible.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Chose bridge technology simple_bridge
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6 is already using the new technology.
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: 0x7fad38001da0(PJSIP/4053-00000002) is joining simple_bridge technology
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/4053-00000002 setting read format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/meetbox-00000003 setting read format path: alaw -> alaw
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/4053-00000002 setting write format path: alaw -> ulaw
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fad400c0750'
[Oct 12 08:34:46] DEBUG[2600] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fad400c13a0'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Sending session refresh SDP via re-INVITE to 4053
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Method is INVITE
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.215.144.48'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Transport type for target '10.215.144.48' is 'UDP transport'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Target '10.215.144.48' is an IP address, skipping resolution
[Oct 12 08:34:46] DEBUG[324][C-00000002] channel.c: Dropping duplicate answer!
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 172.16.0.2:5060 (this may be re-written again later)
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The state change pertains to the endpoint '4053(PJSIP/4053-00000002)'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fad4004d578)
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fad4004d578
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current transaction state is Calling
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The transaction state change event is TX_MSG
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current inv state is CONFIRMED
[Oct 12 08:34:46] DEBUG[2599] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fad40061a28 for Response msg 200/INVITE/cseq=16487 (rdata0x7facc400e4b8)
[Oct 12 08:34:46] DEBUG[2599] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000005a associated with dialog dlg0x7fad40061a28
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.215.144.48'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Transport type for target '10.215.144.48' is 'UDP transport'
[Oct 12 08:34:46] DEBUG[2600] res_pjsip/pjsip_resolver.c: Target '10.215.144.48' is an IP address, skipping resolution
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Setting 0x7fad38001da0(PJSIP/4053-00000002) state from:0 to:1
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: pulling 0x7fad38001da0(PJSIP/4053-00000002)
[Oct 12 08:34:46] VERBOSE[318][C-00000002] bridge_channel.c: Channel PJSIP/4053-00000002 left 'simple_bridge' basic-bridge <b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6>
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: 0x7fad38001da0(PJSIP/4053-00000002) is leaving simple_bridge technology
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The state change pertains to the endpoint '4053(PJSIP/4053-00000002)'
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: dissolving bridge with cause 58(Bearer capability not available)
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Setting 0x7fad3800bec0(PJSIP/meetbox-00000003) state from:0 to:2
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fad4004d578
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current transaction state is Terminated
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The transaction state change event is RX_MSG
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: The current inv state is CONFIRMED
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Received response
[Oct 12 08:34:46] DEBUG[2600] res_pjsip_session.c: Response is 200 OK
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: queueing action type:13 sub:1001
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6 is dissolved, not performing smart bridge operation.
[Oct 12 08:34:46] DEBUG[2593] cdr.c: Finalized CDR for PJSIP/4053-00000002 - start 1602484486.411620 answer 1602484486.907884 end 1602484486.985112 dur 0.573 bill 0.077 dispo ANSWERED
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: pulling 0x7fad3800bec0(PJSIP/meetbox-00000003)
[Oct 12 08:34:46] VERBOSE[324][C-00000002] bridge_channel.c: Channel PJSIP/meetbox-00000003 left 'simple_bridge' basic-bridge <b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6>
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge_channel.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: 0x7fad3800bec0(PJSIP/meetbox-00000003) is leaving simple_bridge technology
[Oct 12 08:34:46] DEBUG[318][C-00000002] bridge_channel.c: Bridge is returning 0x7fad38001da0(PJSIP/4053-00000002) to write format ulaw
[Oct 12 08:34:46] DEBUG[318][C-00000002] channel.c: Channel PJSIP/4053-00000002 setting write format path: ulaw -> ulaw
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6 is dissolved, not performing smart bridge operation.
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge_channel.c: Bridge is returning 0x7fad3800bec0(PJSIP/meetbox-00000003) to read format ulaw
[Oct 12 08:34:46] DEBUG[324][C-00000002] channel.c: Channel PJSIP/meetbox-00000003 setting read format path: alaw -> ulaw
[Oct 12 08:34:46] DEBUG[324][C-00000002] bridge.c: Bridge b1deaf6f-4cfa-4232-b51f-ff2f2f92aca6: actually destroying basic bridge, nobody wants it anymore

I get the same behavior even if I change the codec list priority in the SIP client.

In the pjsip wizard conf on Ast 16 I have:

endpoint/allow = !all,alaw,ulaw,opus,gsm,vp8,h264

which matches what the SIP client is also supporting and offering.

I hope the SIP trace will shed some more light on this.

Thanks,

Vieri

OK, so this is the SIP trace right before the hangup.

    -- Channel PJSIP/meetbox-0000000e joined 'simple_bridge' basic-bridge <f4ac96f7-1d0b-4793-b534-5ed9ae768f5d>
    -- Channel PJSIP/4053-0000000d joined 'simple_bridge' basic-bridge <f4ac96f7-1d0b-4793-b534-5ed9ae768f5d>
<--- Transmitting SIP request (1221 bytes) to UDP:10.215.144.48:5060 --->
INVITE sip:4053@10.215.144.48:5060;registering_acc=sip_mydomain_org SIP/2.0
Via: SIP/2.0/UDP 172.16.0.2:5060;rport;branch=z9hG4bKPj1d31345f-3508-4bcd-b8a4-809c40f332ff
From: <sip:7000@sip.mydomain.org>;tag=63047e9e-cd8d-4fa1-84dc-965a67fa84e7
To: "4053" <sip:4053@sip.mydomain.org>;tag=ccc143a5
Contact: <sip:172.16.0.2:5060>
Call-ID: d30eea8ba5ddfc24febd07729d30ac27@0:0:0:0:0:0:0:0
CSeq: 14561 INVITE
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub, path
Session-Expires: 1800
Min-SE: 90
P-Asserted-Identity: <sip:7000@sip.mydomain.org>
Remote-Party-ID: <sip:7000@sip.mydomain.org>;party=called;privacy=off;screen=no
Max-Forwards: 70
User-Agent: Asterisk PBX 16.11.1
Content-Type: application/sdp
Content-Length:   372

v=0
o=- 0 3 IN IP4 172.16.0.2
s=Asterisk
c=IN IP4 172.16.0.2
t=0 0
m=audio 21022 RTP/AVP 8 0 96 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 opus/48000/2
a=fmtp:96 usedtx=1
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:20
a=sendrecv
m=video 33492 RTP/AVP 97
a=rtpmap:97 H264/90000
a=recvonly

<--- Received SIP response (1061 bytes) from UDP:10.215.144.48:5060 --->
SIP/2.0 200 OK
CSeq: 14561 INVITE
Call-ID: d30eea8ba5ddfc24febd07729d30ac27@0:0:0:0:0:0:0:0
From: <sip:7000@sip.mydomain.org>;tag=63047e9e-cd8d-4fa1-84dc-965a67fa84e7
To: "4053" <sip:4053@sip.mydomain.org>;tag=ccc143a5
Via: SIP/2.0/UDP 172.16.0.2:5060;rport=5060;branch=z9hG4bKPj1d31345f-3508-4bcd-b8a4-809c40f332ff;received=172.16.0.2
Contact: "4053" <sip:4053@10.215.144.48:5060;transport=udp;registering_acc=sip_mydomain_org>
User-Agent: Jitsi2.9.65535.12Windows 8.1
Content-Type: application/sdp
Content-Length: 521

v=0
o=4053-jitsi.org 0 1 IN IP4 0.0.0.0
s=-
c=IN IP4 0.0.0.0
t=0 0
m=audio 0 RTP/AVP 8 0 96 3
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 opus/48000/2
a=fmtp:96 usedtx=1
a=rtpmap:3 GSM/8000
a=zrtp-hash:1.10 5c6565107182d263c35c28599376d5c962918f6dc8736bd92976d9d7da550de0
m=video 0 RTP/AVP 99
a=inactive
a=rtpmap:99 H264/90000
a=fmtp:99 profile-level-id=4DE01f
a=imageattr:99 send * recv [x=[0-1596],y=[0-910]]
a=zrtp-hash:1.10 949a1270de36efca4ef92c7cadffa1cc26f38216952c0f01d28b0f6b6c457e5f

    -- Channel PJSIP/4053-0000000d left 'simple_bridge' basic-bridge <f4ac96f7-1d0b-4793-b534-5ed9ae768f5d>
<--- Transmitting SIP request (446 bytes) to UDP:10.215.144.48:5060 --->
ACK sip:4053@10.215.144.48:5060;registering_acc=sip_mydomain_org SIP/2.0
Via: SIP/2.0/UDP 172.16.0.2:5060;rport;branch=z9hG4bKPjff6fe460-fbe3-4141-ae1c-8ef27c5b67da
From: <sip:7000@sip.mydomain.org>;tag=63047e9e-cd8d-4fa1-84dc-965a67fa84e7
To: "4053" <sip:4053@sip.mydomain.org>;tag=ccc143a5
Call-ID: d30eea8ba5ddfc24febd07729d30ac27@0:0:0:0:0:0:0:0
CSeq: 14561 ACK
Max-Forwards: 70
User-Agent: Asterisk PBX 16.11.1
Content-Length:  0


    -- Channel PJSIP/meetbox-0000000e left 'simple_bridge' basic-bridge <f4ac96f7-1d0b-4793-b534-5ed9ae768f5d>
  == Spawn extension (default, 7000, 2) exited non-zero on 'PJSIP/4053-0000000d'

I noticed that if I disable the video codec offering on the SIP client then the call succeeds without hangups on the Wait() function.
So it seems that Asterisk and the SIP client do not agree on the video codec capabilities.
Why?
Also, why isn’t the call rejected right away then?
Why is it answered and why does it even reach the second instruction in the custom IVR context where Wait() is run?
Also, why does the call fully succeed and does not hang up if I either remove the call to “Wait()” in the IVR or I pass it a very low value such as “1”?
If there’s a codec disagreement shouldn’t the call never “reach the context” and exit immediately?

Have you mangled the c= line on the peer’s SDP? If seems to be putting both audio and video streams on hold in different ways.

In any case it is definitely putting the video stream on hold. Maybe Asterisk can’t cope with held video?

I didn’t mangle anything in the SDP.

Could it be a bug in Asterisk 16?

What is the actual SIP traffic for the calling endpoint? What is the full SIP traffic (not just re-INVITE) for the called party? Does this issue occur with the latest version of Asterisk? Do you need video flowing (if not you could just remove the video codecs).

From what is given I can only say that the remote side, Jitsi, has essentially declined all of the re-INVITE. The audio was declined, and the video was declined. The SDP that we sent appears to be perfectly fine.

But why does the call proceed fine (audio) if I remove Wait() or lower the seconds to Wait() (eg. Wait(1)) even with the video codec offerings enabled?

I will have to dump the SIP trace to a file and share it here as I cannot post all that data in-line.

I am running Ast 16 (not the very latest sub-release) on the Jitsi client side and Asterisk 1.4.31 on the IVR side. I am unable to test with the latest Asterisk 16 right now. Will try…

Yes, I need video.

Thanks. Will get back to you with a full trace.

You’re providing bits and pieces of information and logs, so it is extremely hard to help because it’s hard to put it all together to see what is going on. For example in your latest information, I don’t see Wait() at all.

You need to provide complete information of failing and passing cases with the debug and SIP traces of all sides involved. That will allow a comparison to see the difference, otherwise we can only guess and state what is happening based on what we see.

Wait() was referred to in my first post:

In my last posts Wait() was not there because those logs are taken on the Asterisk 16 side. The Wait() call is in an IVR on the Asterisk 1.4 side.

I can understand the confusion, and I will post asap a full log + trace of both sides for both working and failing scenarios.
Thanks

I was referring to the incoming SDP. It has 0.0.0.0 ha the media address, and I was wondering whether that was the result of your redacting the log, or whether it really was declining to receive.

I did not mangle that. It really is 0.0.0.0.

Technically, the 0.0.0.0 is a deprecated way of putting the media on hold, but the peer is also using the modern way of doing this for the video stream, and both streams have port 0, which is a permanent rejection of the stream, and probably why Asterisk is dropping the connection as missing a required bearer capability.

Also, according to https://tools.ietf.org/html/rfc3264 page 17, one mustn’t combine port 0 with address 0.0.0.0 conventions, so it looks like the peer is in violation.

Given the reference to zrtp, it might be trying to enforce and unsupported encryption mode, but that doesn’t explain why the call doesn’t fail on the initial exchange, but only on the re-invite.

OK, I think the source of my woes is the SIP trunk itself and how it’s configured. It came up in another thread, and I thought I had properly set it up.
I’m almost sure it actually was working, but I must have screwed it up somewhere at some point…

So let’s first see if I can get the sneaky SIP trunk up and running properly now (I find IAX2 to work out of the box, except video support seems to be an issue – but that’s another topic).

On an Asterisk 16 box, I have this pjsip configuration:

================
ASTERISK 16.11.1
================

/etc/asterisk/pjsip_wizard.conf contains:

[trunk_defaults](!)
type = wizard
transport = transport-udp
endpoint/allow_subscribe = no
endpoint/allow = !all,alaw,ulaw,opus,gsm,vp8,h264
aor/qualify_frequency = 30
registration/expiration = 1800
; aor/max_contacts = 1000

[meetbox](trunk_defaults)
sends_auth = no
accepts_auth = no
sends_registrations = no
accepts_registrations = no
remote_hosts = 10.215.147.115
endpoint/context = custom-newsystem

# asterisk -rx "pjsip show endpoint meetbox"

 Endpoint:  <Endpoint/CID.....................................>  <State.....>  <Channels.>
    I/OAuth:  <AuthId/UserName...........................................................>
        Aor:  <Aor............................................>  <MaxContact>
      Contact:  <Aor/ContactUri..........................> <Hash....> <Status> <RTT(ms)..>
  Transport:  <TransportId........>  <Type>  <cos>  <tos>  <BindAddress..................>
   Identify:  <Identify/Endpoint.........................................................>
        Match:  <criteria.........................>
    Channel:  <ChannelId......................................>  <State.....>  <Time.....>
        Exten: <DialedExten...........>  CLCID: <ConnectedLineCID.......>
==========================================================================================

 Endpoint:  meetbox                                              Not in use    0 of inf
        Aor:  meetbox                                            0
      Contact:  meetbox/sip:10.215.147.115                 92e3d71c31 Avail         2.498
  Transport:  transport-udp             udp      0      0  0.0.0.0:5060
   Identify:  meetbox-identify/meetbox
        Match: 10.215.147.115/32


 ParameterName                      : ParameterValue
 ==================================================================
 100rel                             : yes
 @pjsip_wizard                      : meetbox
 accept_multiple_sdp_answers        : false
 accountcode                        :
 acl                                :
 aggregate_mwi                      : true
 allow                              : (alaw|ulaw|opus|gsm|vp8|h264)
 allow_overlap                      : true
 allow_subscribe                    : false
 allow_transfer                     : true
 aors                               : meetbox
 asymmetric_rtp_codec               : false
 auth                               :
 bind_rtp_to_media_address          : false
 bundle                             : false
 call_group                         :
 callerid                           : <unknown>
 callerid_privacy                   : allowed_not_screened
 callerid_tag                       :
 connected_line_method              : invite
 contact_acl                        :
 context                            : custom-newsystem
 cos_audio                          : 0
 cos_video                          : 0
 device_state_busy_at               : 0
 direct_media                       : true
 direct_media_glare_mitigation      : none
 direct_media_method                : invite
 disable_direct_media_on_nat        : false
 dtls_auto_generate_cert            : No
 dtls_ca_file                       :
 dtls_ca_path                       :
 dtls_cert_file                     :
 dtls_cipher                        :
 dtls_fingerprint                   : SHA-256
 dtls_private_key                   :
 dtls_rekey                         : 0
 dtls_setup                         : active
 dtls_verify                        : No
 dtmf_mode                          : rfc4733
 fax_detect                         : false
 fax_detect_timeout                 : 0
 follow_early_media_fork            : true
 force_avp                          : false
 force_rport                        : true
 from_domain                        :
 from_user                          :
 g726_non_standard                  : false
 ice_support                        : false
 identify_by                        : username,ip
 ignore_183_without_sdp             : false
 inband_progress                    : false
 incoming_mwi_mailbox               :
 language                           :
 mailboxes                          :
 max_audio_streams                  : 1
 max_video_streams                  : 1
 media_address                      :
 media_encryption                   : no
 media_encryption_optimistic        : false
 media_use_received_transport       : false
 message_context                    :
 moh_passthrough                    : false
 moh_suggest                        : default
 mwi_from_user                      :
 mwi_subscribe_replaces_unsolicited : no
 named_call_group                   :
 named_pickup_group                 :
 notify_early_inuse_ringing         : false
 one_touch_recording                : false
 outbound_auth                      :
 outbound_proxy                     :
 pickup_group                       :
 preferred_codec_only               : false
 record_off_feature                 : automixmon
 record_on_feature                  : automixmon
 refer_blind_progress               : true
 rewrite_contact                    : false
 rpid_immediate                     : false
 rtcp_mux                           : false
 rtp_engine                         : asterisk
 rtp_ipv6                           : false
 rtp_keepalive                      : 0
 rtp_symmetric                      : false
 rtp_timeout                        : 0
 rtp_timeout_hold                   : 0
 sdp_owner                          : -
 sdp_session                        : Asterisk
 send_connected_line                : yes
 send_diversion                     : true
 send_pai                           : false
 send_rpid                          : false
 set_var                            :
 srtp_tag_32                        : false
 sub_min_expiry                     : 0
 subscribe_context                  :
 suppress_q850_reason_headers       : false
 t38_udptl                          : false
 t38_udptl_ec                       : none
 t38_udptl_ipv6                     : false
 t38_udptl_maxdatagram              : 0
 t38_udptl_nat                      : false
 timers                             : yes
 timers_min_se                      : 90
 timers_sess_expires                : 1800
 tone_zone                          :
 tos_audio                          : 0
 tos_video                          : 0
 transport                          : transport-udp
 trust_connected_line               : yes
 trust_id_inbound                   : false
 trust_id_outbound                  : false
 use_avpf                           : false
 use_ptime                          : false
 user_eq_phone                      : false
 voicemail_extension                :
 webrtc                             : no

On an Asterisk 1.4 box I this chan_sip configuration:

===============
ASTERISK 1.4.31
===============

/etc/asterisk/sip.conf contains:

[meetbox]
disallow=all
type=peer
host=10.215.144.92
insecure=invite
allow=alaw
allow=ulaw
allow=gsm
allow=opus
allow=vp8
allow=h264
context=custom-newsystem
videosupport=yes
qualify=yes

# asterisk -rx "sip show peer meetbox"


  * Name       : meetbox
  Secret       : <Not set>
  MD5Secret    : <Not set>
  Context      : custom-newsystem
  Subscr.Cont. : <Not set>
  Language     : es
  AMA flags    : Unknown
  Transfer mode: open
  CallingPres  : Presentation Allowed, Not Screened
  Callgroup    :
  Pickupgroup  :
  Mailbox      :
  VM Extension : *97
  LastMsgsSent : 32767/65535
  Call limit   : 0
  Dynamic      : No
  Callerid     : "" <>
  MaxCallBR    : 384 kbps
  Expire       : -1
  Insecure     : invite
  Nat          : RFC3581
  ACL          : No
  T38 pt UDPTL : Yes
  CanReinvite  : Yes
  PromiscRedir : No
  User=Phone   : No
  Video Support: Yes
  Trust RPID   : No
  Send RPID    : No
  Subscriptions: Yes
  Overlap dial : Yes
  DTMFmode     : rfc2833
  LastMsg      : 0
  ToHost       : 10.215.144.92
  Addr->IP     : 10.215.144.92 Port 5060
  Defaddr->IP  : 0.0.0.0 Port 0
  Reg. exten   :
  Def. Username: meetbox
  SIP Options  : (none)
  Codecs       : 0x20000e (gsm|ulaw|alaw|h264)
  Codec Order  : (alaw:20,ulaw:20,gsm:20)
  Auto-Framing:  No
  Status       : OK (1 ms)
  Useragent    :
  Reg. Contact :

The idea is for endpoints registered to both Asterisk servers to be able to place calls between them.
I assume the SIP trunk is in a “trusted” network and that its authentication is not necessary.

If I place a call from a webrtc client in Asterisk 16 to an extension in Asterisk 1.4, I get an “unknown peer” there.
In Asterisk 16 I run:

Dial(PJSIP/meetbox/sip:${EXTEN}@10.215.147.115,300,tTWg)

I check that the caller ID name and number are set.

On the other side I receive the call in Asterisk 1.4, but it is not properly sent to the right context (ie. custom-newsystem). Instead, it is sent to a context defined in the [general] section of sip.conf.
In the log I see custom messages such as:

NoOp("SIP/10.215.144.92-000014e0", "whatever")

So, why isn’t Asterisk (1.4) matching the [meetbox] SIP context and sending these calls to the [custom-newsystem] dialplan context?

Yes, I know this is quite different to the original post, but I’m sure if I fix this part then I probably will get to the “Wait()” issue again somehow. I can open a new thread though if you think it’s best.

Would a SIP trace be useful here (Ast 1.4)?

2010-05-03 Leif Madsen lmadsen@digium.com

  • Asterisk 1.4.31 Released

That’s more than a decade old.

That’s why I’ve set up a trunk between the old server and the new one, so I can slowly and peacefully migrate – or at least I thought I could.

There are later versions of 1.4, which should be compatible with the old configuration files.

Are you saying that Asterisk 1.4.31 is known to be unable to “match by IP address or hostname” and properly send the call to the right context ([meetbox]->[custom-newsystem] in my example)?

I mean, my setup can’t get any simpler than this.

After further testing it seems that the other way around works better. A SIP client on Asterisk 1.4 can call another SP client on Asterisk 16 through the SIP trunk (ie. Asterisk 16 can properly send the call to the right context). The only glitch is that if the caller (Ast 1.4) or the callee (Ast 16) hangs up, the channel stays up until the other party actually hangs up too.

I guess I’m going to have to keep using IAX2 instead as it’s a lot more reliable (maybe it hasn’t changed that much over the years) despite H264 video not working properly.

Thanks