rendered paste bodyHello,
I am using FreePBX for configuration (TrixBox 2.2).
Asterisk 1.2.18 is connected to a VoIP provider using a SIP trunk.
The provider is using Acmepaket /Metaswitch gear.
Inbound and outbound calling work, but only to provisioned extensions.
Inbound Routing (i.e. matching any/any CLID/DID) to a DISA/IVR or anything else for that matter does not work.
Traces show a 404 is being sent back to the network.
Here's example indicating the described behavior from Asterisk (sip debug enabled):
INVITE sip:4002602@10.70.0.196:5060 SIP/2.0
Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bK0ngjtd202g7gfbsd47s1.1
Allow-Events: message-summary
Allow-Events: refer
Allow-Events: dialog
Allow-Events: line-seize
Allow-Events: presence
Max-Forwards: 69
Call-ID: SD8fofa01-0dfaf46e328a203a4ec2d7691d8d4ea2-v3000i1
From: ;isup-oli=00;tag=SD8fofa01-xxx.xxxx.com+1+35ac30+891f56b0
To:
CSeq: 412230031 INVITE
Expires: 180
Organization:
Supported: 100rel
Content-Length: 162
Content-Type: application/sdp
Contact: ;isup-oli=00
P-Asserted-Identity:
v=0
o=- 3934957908 3934957908 IN IP4 10.70.0.193
s=-
c=IN IP4 10.70.0.193
t=0 0
m=audio 9434 RTP/AVP 2 0 101
a=rtpmap:101 telephone-event/8000
a=ptime:20
Jun 2 00:42:08 VERBOSE[3794] logger.c: --- (19 headers 8 lines) ---
Jun 2 00:42:08 VERBOSE[3794] logger.c: Using INVITE request as basis request - SD8fofa01-0dfaf46e328a203a4ec2d7691d8d4ea2-v3000i1
Jun 2 00:42:08 VERBOSE[3794] logger.c: Sending to 10.70.0.193 : 5060 (non-NAT)
Jun 2 00:42:08 VERBOSE[3794] logger.c: Found peer 'QT'
Jun 2 00:42:08 DEBUG[3794] chan_sip.c: Setting NAT on RTP to 524288
Jun 2 00:42:08 VERBOSE[3794] logger.c: Found RTP audio format 2
Jun 2 00:42:08 VERBOSE[3794] logger.c: Found RTP audio format 0
Jun 2 00:42:08 VERBOSE[3794] logger.c: Found RTP audio format 101
Jun 2 00:42:08 VERBOSE[3794] logger.c: Peer audio RTP is at port 10.70.0.193:9434
Jun 2 00:42:08 DEBUG[3794] chan_sip.c: Peer audio RTP is at port 10.70.0.193:9434
Jun 2 00:42:08 VERBOSE[3794] logger.c: Found description format telephone-event
Jun 2 00:42:08 VERBOSE[3794] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Jun 2 00:42:08 VERBOSE[3794] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Jun 2 00:42:08 DEBUG[3794] chan_sip.c: Checking SIP call limits for device 4414002600
Jun 2 00:42:08 VERBOSE[3794] logger.c: Looking for 4002602 in default (domain 10.70.0.196)
Jun 2 00:42:08 VERBOSE[3794] logger.c: Reliably Transmitting (NAT) to 10.70.0.193:5060:
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bK0ngjtd202g7gfbsd47s1.1;received=10.70.0.193
From: ;isup-oli=00;tag=SD8fofa01-xxx.xxxx.com+1+35ac30+891f56b0
To: ;tag=as54797227
Call-ID: SD8fofa01-0dfaf46e328a203a4ec2d7691d8d4ea2-v3000i1
CSeq: 412230031 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
---
Jun 2 00:42:08 VERBOSE[3794] logger.c:
<-- SIP read from 10.70.0.193:5060:
ACK sip:4002602@10.70.0.196:5060 SIP/2.0
Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bK0ngjtd202g7gfbsd47s1.1
CSeq: 412230031 ACK
Max-Forwards: 69
Call-ID: SD8fofa01-0dfaf46e328a203a4ec2d7691d8d4ea2-v3000i1
From: ;isup-oli=00;tag=SD8fofa01-xxx.xxxx.com+1+35ac30+891f56b0
To: ;tag=as54797227
Content-Length: 0
I have packet captures off the network and sip debug if anyone interested.
Grateful for any suggestions,
Cheers,
Mike
Mike Harris
ONXIS
26 Victoria Street,
Hamilton, HMCX,
Bermuda.
O: 441-400-4001
M: 441-505-7153
MORE DEBUG (As Requested by TheCompWiz)
<-- SIP read from 10.70.0.193:5060:
INVITE sip:4002602@10.70.0.196:5060 SIP/2.0
Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bKgebg893070k10b0pb3g1.1
Allow-Events: message-summary
Allow-Events: refer
Allow-Events: dialog
Allow-Events: line-seize
Allow-Events: presence
Max-Forwards: 69
Call-ID: SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1
From: ;isup-oli=00;tag=SD8vrba01-quantum1.quantum.bm+1+25053a+f171d803
To:
CSeq: 155893236 INVITE
Expires: 180
Organization:
Supported: 100rel
Content-Length: 162
Content-Type: application/sdp
Contact: ;isup-oli=00
P-Asserted-Identity:
v=0
o=- 4165324218 4165324218 IN IP4 10.70.0.193
s=-
c=IN IP4 10.70.0.193
t=0 0
m=audio 9550 RTP/AVP 2 0 101
a=rtpmap:101 telephone-event/8000
a=ptime:20
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 0: INVITE sip:4002602@10.70.0.196:5060 SIP/2.0 (43)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bKgebg893070k10b0pb3g1.1 (70)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 2: Allow-Events: message-summary (29)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 3: Allow-Events: refer (19)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 4: Allow-Events: dialog (20)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 5: Allow-Events: line-seize (24)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 6: Allow-Events: presence (22)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 7: Max-Forwards: 69 (16)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 8: Call-ID: SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1 (59)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 9: From: ;isup-oli=00;tag=SD8vrba01-quantum1.quantum.bm+1+25053a+f171d803 (117)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 10: To: (29)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 11: CSeq: 155893236 INVITE (22)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 12: Expires: 180 (12)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 13: Organization: (14)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 14: Supported: 100rel (17)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 15: Content-Length: 162 (19)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 16: Content-Type: application/sdp (29)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 17: Contact: ;isup-oli=00 (68)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 18: P-Asserted-Identity: (52)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 19: (0)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: v=0 (3)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: o=- 4165324218 4165324218 IN IP4 10.70.0.193 (44)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: s=- (3)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: c=IN IP4 10.70.0.193 (20)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: t=0 0 (5)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: m=audio 9550 RTP/AVP 2 0 101 (28)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Line: a=ptime:20 (10)
Jun 4 16:41:32 VERBOSE[3794] logger.c: --- (19 headers 8 lines) ---
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Allocating new SIP dialog for SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1 - INVITE (With RTP)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Begin: parsing SIP "Supported: 100rel"
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Found SIP option: -100rel-
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Matched SIP option: 100rel
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: * SIP extension value: 2 for call SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1
Jun 4 16:41:32 VERBOSE[3794] logger.c: Using INVITE request as basis request - SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1
Jun 4 16:41:32 VERBOSE[3794] logger.c: Sending to 10.70.0.193 : 5060 (non-NAT)
Jun 4 16:41:32 VERBOSE[3794] logger.c: Found peer 'Quantum'
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Setting NAT on RTP to 524288
Jun 4 16:41:32 VERBOSE[3794] logger.c: Found RTP audio format 2
Jun 4 16:41:32 VERBOSE[3794] logger.c: Found RTP audio format 0
Jun 4 16:41:32 VERBOSE[3794] logger.c: Found RTP audio format 101
Jun 4 16:41:32 VERBOSE[3794] logger.c: Peer audio RTP is at port 10.70.0.193:9550
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Peer audio RTP is at port 10.70.0.193:9550
Jun 4 16:41:32 VERBOSE[3794] logger.c: Found description format telephone-event
Jun 4 16:41:32 VERBOSE[3794] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Jun 4 16:41:32 VERBOSE[3794] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Checking SIP call limits for device 4414002600
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Updating call counter for incoming call
Jun 4 16:41:32 VERBOSE[3794] logger.c: Looking for 4002602 in default (domain 10.70.0.196)
Jun 4 16:41:32 VERBOSE[3794] logger.c: Reliably Transmitting (NAT) to 10.70.0.193:5060:
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bKgebg893070k10b0pb3g1.1;received=10.70.0.193
From: ;isup-oli=00;tag=SD8vrba01-quantum1.quantum.bm+1+25053a+f171d803
To: ;tag=as67a0e37e
Call-ID: SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1
CSeq: 155893236 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
---
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #58436
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Updating call counter for incoming call
Jun 4 16:41:32 VERBOSE[3794] logger.c:
<-- SIP read from 10.70.0.193:5060:
ACK sip:4002602@10.70.0.196:5060 SIP/2.0
Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bKgebg893070k10b0pb3g1.1
CSeq: 155893236 ACK
Max-Forwards: 69
Call-ID: SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1
From: ;isup-oli=00;tag=SD8vrba01-quantum1.quantum.bm+1+25053a+f171d803
To: ;tag=as67a0e37e
Content-Length: 0
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 0: ACK sip:4002602@10.70.0.196:5060 SIP/2.0 (40)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.70.0.193:5060;branch=z9hG4bKgebg893070k10b0pb3g1.1 (70)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 2: CSeq: 155893236 ACK (19)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 3: Max-Forwards: 69 (16)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 4: Call-ID: SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1 (59)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 5: From: ;isup-oli=00;tag=SD8vrba01-quantum1.quantum.bm+1+25053a+f171d803 (117)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 6: To: ;tag=as67a0e37e (44)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 7: Content-Length: 0 (17)
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Header 8: (0)
Jun 4 16:41:32 VERBOSE[3794] logger.c: --- (8 headers 0 lines) ---
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: = Found Their Call ID: SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1 Their Tag SD8vrba01-quantum1.quantum.bm+1+25053a+f171d803 Our tag: as67a0e37e
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #58436
Jun 4 16:41:32 DEBUG[3794] chan_sip.c: Stopping retransmission on 'SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1' of Response 155893236: Match Found
Jun 4 16:41:32 VERBOSE[3794] logger.c: Destroying call 'SD8vrba01-167f24b1e4eedc72e25858555aa759d4-v3000i1'
Jun 4 16:41:42 DEBUG[509] manager.c: Manager received command 'login'
Jun 4 16:41:42 VERBOSE[509] logger.c: == Parsing '/etc/asterisk/manager.conf': Jun 4 16:41:42 DEBUG[509] config.c: Parsing /etc/asterisk/manager.conf
Jun 4 16:41:42 VERBOSE[509] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Jun 4 16:41:42 VERBOSE[509] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Jun 4 16:41:42 DEBUG[509] config.c: Parsing /etc/asterisk/manager_custom.conf
Jun 4 16:41:42 VERBOSE[509] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Jun 4 16:41:42 DEBUG[509] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Jun 4 16:41:42 DEBUG[509] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Jun 4 16:41:42 DEBUG[509] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Jun 4 16:41:42 DEBUG[509] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Jun 4 16:41:42 VERBOSE[509] logger.c: == Manager 'admin' logged on from 127.0.0.1
Jun 4 16:41:42 VERBOSE[509] logger.c: == Manager 'admin' logged off from 127.0.0.1
Jun 4 16:41:42 VERBOSE[509] logger.c: == Manager 'admin' logged off from 127.0.0.1