SIP Trunk not making nor receiving calls 1

[j_redhead]

I have a sip trunk configured, however neither incoming nor outgoing calls are going through. When making outgoing calls the number is dialed nothing happens. The system status shows the extension selecting the ARS route but there is nothing after that. On incoming calls it just rings and doesn't hit the auto attendant.

SIP trunk line IDs: incoming 0, outgoing 11

ARS: Code: XXXXXXXXXXN
Telephone number : N
Line ID: 11

Incoming route is set to auto attendant short code *88

Short Code programed:
Code: 8
Feature: Dial
Tel #: N@"192.168.44.242" ("N" was also used, got error saying call rejected)
Line group ID: 51: SIP

 

[AACon]

the @ sign is required to be in quotes.
how is your sip uri setup?

-Austin
I used to be an ACE. Now I'm just an Arse.

 

[derfloh]

You remove the first 10 digits with your ARS short code. Try XXXXXXXXXX/Dial/N

And in your short code 8N/Dial/N/51 (Or N"@192.16..."

IP Office remote service
IP Office certificate check
CLI based call blocking
SCN fallback over PSTN

 

[critchey]

Have you run a monitor trace on both inbound and outbound calls? It is possible the inbound calls aren't even hitting the system, and if so, nothing you can do to fix it except report it to the provider. If it does hit the system you should get some kind of error like unallocated/unassigned number. Same with outbound you should get some kind of error when the call gets rejected. The information you can gather the easier time you will have resolving the issue.

The truth is just an excuse for lack of imagination.

 

[j_redhead]

Hi all,

Sorry about the lengthy delay in response. Turns out there was an issue on the provider side. Where the incorrect digits were being directed to the sip. Incoming calls are now able to hit the auto attendant. However when attempting to make calls I am getting waiting for line.

@AACon that was an error on my part it was corrected.

 

[j_redhead]

 

[j_redhead]

@critchey Monitor trace below

09:39:00 1292661995mS RES2: IP 500 V2 10.1.0.4.0 build 7 Tasks=60 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=15+75 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=25(TLS=6 OFF=0) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
09:39:00 1292661995mS RES4: XML MemObjs=8 PoolMem=4748404(2) FreeMem=4736284(0) HeapUsed=0
09:39:00 1292661995mS RES5: CLog MemObjs=2027 FreePoolMem(Objs)=3796(73) TotalMem=109200 StringsTotalMem=183750
09:39:04 1292665920mS CMExtnEvt: Extn1706:1706: No user activity
09:39:25 1292686544mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 8
09:39:25 1292686546mS CMCallEvt: 0000000000000000 0.44788.0 -1 BaseEP: NEW CMEndpoint f1726330 TOTAL NOW=1 CALL_LIST=0
09:39:25 1292686546mS CMCallEvt: 0000000000000000 0.44788.0 -1 Extn2041.-1: NEW CMExtnEndpoint f1726330, Name=Extn2041, Extn=2041, Phys Extn=2041
09:39:25 1292686547mS CMCallEvt: CREATE CALL:10372 (f167641c)
09:39:25 1292686547mS CMCallEvt: 0000000000000000 0.44789.0 -1 BaseEP: NEW CMEndpoint f169a840 TOTAL NOW=2 CALL_LIST=0
09:39:25 1292686549mS CMExtnEvt: Extn2041: CMExtnHandler::SetCurrent( id: 0->44788 )
09:39:25 1292686550mS CMExtnRx: v=2041, p1=0
CMSetup
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[2041] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=???????) name=Extn2041
09:39:25 1292686550mS CMCallEvt: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
09:39:25 1292686550mS CMExtnEvt: v=28 State, new=Dialling old=Idle,0,0,Extn2041
09:39:25 1292686551mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=2041 calling_sub= dir=out complete=0 ses=0
09:39:25 1292686551mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
09:39:25 1292686552mS CMCallEvt: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
09:39:25 1292686552mS CMExtnTx: v=2041, p1=0
CMSetupAck
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
BChan: slot=10 chan=30
Timed: 27/10/21 09:39
09:39:25 1292686552mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
09:39:25 1292686553mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: Setting Hard Timer 4000
09:39:25 1292686554mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=8 sub= calling=2041 calling_sub= dir=out complete=0 ses=0
09:39:25 1292686554mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: ADD TARGET (N): number=8 type=100 depth=1 nobar=1 setorig=1 ses=0
09:39:25 1292686554mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: SYS SC: 8 2 sc=type=Dial code=8N, num=N"@192.168.44.242" callinfop->sending_complete=0 secondary_dialtone=
09:39:25 1292686555mS CMARS: FindActiveARSByGroupID GroupID=51 - Found
09:39:25 1292686555mS CMARS: MakeCallTarget - Called Number: @192.168.44.242
09:39:25 1292686555mS CMCallEvt: 0000000000000000 0.44790.0 -1 BaseEP: NEW CMEndpoint f15b7c5c TOTAL NOW=3 CALL_LIST=1
09:39:25 1292686556mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: CancelTimer CMTCDelayedProcessing
09:39:25 1292686556mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: INITIAL TARGETING SUCCEEDED
09:39:25 1292686556mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: GetNoAnswerTimer:25
09:39:25 1292686557mS CMCallEvt: 0000000000000000 0.44789.0 10372 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
09:39:25 1292686558mS CMCallEvt: 0000000000000000 0.44790.0 10372 ARS for SIP: StateChange: END=T CMCSIdle->CMCSOffering
09:39:25 1292686558mS CMCallEvt: 0000000000000000 0.44789.0 10372 TargetingEP: RequestEnd 0000000000000000 0.44790.0 10372 ARS for SIP
09:39:25 1292686558mS CMTARGET: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: CancelTimer CMTCNoAnswerTimeout
09:39:25 1292686559mS CMCallEvt: 0000000000000000 0.44790.0 10372 ARS for SIP: StateChange: END=B CMCSOffering->CMCSOverlapRecv
09:39:25 1292686559mS CMARS: FORM: SIP - Received Number: @192.168.44.242
09:39:25 1292686560mS CMARS: CMARSTargetingPending
09:39:25 1292686560mS CMCallEvt: 0000000000000000 0.44789.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
09:39:25 1292686560mS CMCallEvt: 0000000000000000 0.44789.0 -1 BaseEP: DELETE CMEndpoint f169a840 TOTAL NOW=2 CALL_LIST=1
09:39:26 1292687002mS RES: Wed 27/10/2021 09:39:25 FreeMem=53469824 Heap=52901404(2) Cache=568420 MemObjs=16071(Max 17264) CMMsg=5(7) ASN=0 Buff=5200 1354 1000 7443 5 Links=70772(71005) BTree=1553(3306) CB=6064 CPU=14.26% CPUStats=17.08%/16/24/1671/13676
/16839/00.25%/1/02.60% MCR=0
09:39:26 1292687003mS RES2: IP 500 V2 10.1.0.4.0 build 7 Tasks=60 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=15+76 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=25(TLS=6 OFF=0) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
09:39:26 1292687003mS RES4: XML MemObjs=8 PoolMem=4748404(2) FreeMem=4736284(0) HeapUsed=0
09:39:26 1292687003mS RES5: CLog MemObjs=2027 FreePoolMem(Objs)=3796(73) TotalMem=109200 StringsTotalMem=183750
09:39:26 1292687015mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 3
09:39:26 1292687015mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
09:39:26 1292687016mS CMARS: FORM: SIP - Received Number: @192.168.44.2423
09:39:26 1292687016mS CMARS: CMARSTargetingPending
09:39:26 1292687330mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 5
09:39:26 1292687330mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5]
09:39:26 1292687331mS CMARS: FORM: SIP - Received Number: @192.168.44.24235
09:39:26 1292687331mS CMARS: CMARSTargetingPending
09:39:26 1292687496mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 5
09:39:26 1292687496mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5]
09:39:26 1292687497mS CMARS: FORM: SIP - Received Number: @192.168.44.242355
09:39:26 1292687497mS CMARS: CMARSTargetingPending
09:39:26 1292687958mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 5
09:39:26 1292687959mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5]
09:39:26 1292687959mS CMARS: FORM: SIP - Received Number: @192.168.44.2423555
09:39:26 1292687959mS CMARS: CMARSTargetingPending
09:39:27 1292688124mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 3
09:39:27 1292688124mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
09:39:27 1292688125mS CMARS: FORM: SIP - Received Number: @192.168.44.24235553
09:39:27 1292688125mS CMARS: CMARSTargetingPending
09:39:27 1292688587mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 1
09:39:27 1292688587mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
09:39:27 1292688588mS CMARS: FORM: SIP - Received Number: @192.168.44.242355531
09:39:27 1292688588mS CMARS: CMARSTargetingPending
09:39:27 1292688753mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Digit Key Pressed 5
09:39:27 1292688754mS CMExtnRx: v=2041, p1=0
CMInformation
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5]
09:39:27 1292688754mS CMARS: FORM: SIP - Received Number: @192.168.44.2423555315
09:39:27 1292688755mS CMARS: CMARSTargetingPending
09:39:32 1292693555mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: @192.168.44.2423555315 Addr: f15b7c5c
09:39:32 1292693555mS CMARS: FORM: SIP - Received Number: @192.168.44.2423555315
09:39:32 1292693555mS CMARS: FOUND A SHORT CODE - short_code: XN; - Tel: N - Called_Party: @192.168.44.2423555315 - Line Group Id: 11
09:39:32 1292693556mS CMARS: SetCurrentTarget: Short_Code: XN; - Line_Group_ID: 11
09:39:32 1292693556mS CMARS: FindActiveARSByGroupID GroupID=11 - Not Found
09:39:32 1292693556mS CMLRQ: FindActiveLRQByGroupID GroupID=11 - Not Found
09:39:32 1292693556mS CMMap: a=2.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f52d2194) resource busy 1, total 84
09:39:32 1292693557mS CMCallEvt: 0000000000000000 0.44791.0 -1 BaseEP: NEW CMEndpoint f166bfc8 TOTAL NOW=3 CALL_LIST=1
09:39:32 1292693558mS Stun: Info: Line 17: Not using STUN for media in this case.
09:39:32 1292693560mS CMARS: ModifyCMARSTarget: Short_Code: XN; - Line_Group_ID: 11 set line status to CMARS_TRYING
09:39:32 1292693560mS CMARS: FOUND LINE - Line Id: 17 - using line group id: 11 (code XN;, line 11) - Called Number: @192.168.44.2423555315 - Calling Number: 2041
09:39:32 1292693560mS CMARS: SEND Setup TO LINE
09:39:32 1292693560mS CMCallEvt: c0a864f00000aef7 17.44791.0 10372 SIPTrunk Endpoint: StateChange: END=child CMCSIdle->CMCSOffering
09:39:32 1292693562mS CMLineTx: v=0
CMSetup
Line: type=SIPLine 17 Call: lid=17 id=44791 in=0
Called[@192.168.44.2423555315] Type=Default (100) Reason=CMDRdirect SndComp Calling[2041] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 18029
user 'Extn2041' presentation Allowed
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=???????) name=Extn2041
IE CMIERespondingPartyName (228)(Type=???????) name=Extn2041
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2041
IE CMIEDeviceDetail (231) c0a864f00000aef4 LOCALE=enu HW=15 VER=10 class=CMDeviceStdPhone type=99 number=328 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=44788 ipaddr=192.168.100.240 apps=0 loc=0 em_loc=1 features2=0x20 is_spc
all=0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 5)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 5)
}
Locale: enu
09:39:32 1292693565mS SIP Tx: UDP 192.168.44.1:5060 -> 192.168.40.25:5060
INVITE sip192.168.44.2423555315 SIP/2.0
Via: SIP/2.0/UDP 192.168.44.1:5060;rport;branch=z9hG4bKabaf9019fe09ede1706cf2d0519d4c6e
From: "6124224" <sip:6124224@192.168.44.242>;tag=2cca89851976636d
To: <sip192.168.44.2423555315>
Call-ID: b78eaddc89e86d071432b1617bfc7d3f
CSeq: 1170828815 INVITE
Contact: "6124224" <sip:6124224@192.168.44.1:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 10.1.0.4.0 build 7
P-Asserted-Identity: <sip:6124224@192.168.44.1:5060>
Content-Type: application/sdp
Content-Length: 298

v=0
o=UserA 3897003339 525680797 IN IP4 192.168.44.1
s=Session SDP
c=IN IP4 192.168.44.1
t=0 0
m=audio 46750 RTP/AVP 4 18 8 0 101
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
09:39:32 1292693571mS SIP Rx: UDP 192.168.40.25:5060 -> 192.168.44.1:5060
SIP/2.0 400 Bad Request-URI
Via: SIP/2.0/UDP 192.168.44.1:5060;received=192.168.44.1;branch=z9hG4bKabaf9019fe09ede1706cf2d0519d4c6e;rport=5060
From: "6124224" <sip:6124224@192.168.44.242>;tag=2cca89851976636d
To: <sip:>;tag=aprqngfrt-godip3k89mru0
Call-ID: b78eaddc89e86d071432b1617bfc7d3f
CSeq: 1170828815 INVITE

09:39:33 1292694006mS RES: Wed 27/10/2021 09:39:32 FreeMem=53402024 Heap=52868056(2) Cache=533968 MemObjs=16476(Max 17264) CMMsg=5(7) ASN=0 Buff=5200 1354 1000 7443 5 Links=70838(71005) BTree=1558(3306) CB=6061 CPU=14.57% CPUStats=15.48%/11/16/1671/13864
/16839/00.22%/1/02.61% MCR=0
09:39:33 1292694007mS RES2: IP 500 V2 10.1.0.4.0 build 7 Tasks=60 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=15+78 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=25(TLS=6 OFF=0) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
09:39:33 1292694007mS RES4: XML MemObjs=8 PoolMem=4748404(2) FreeMem=4736284(0) HeapUsed=0
09:39:33 1292694007mS RES5: CLog MemObjs=2027 FreePoolMem(Objs)=3796(73) TotalMem=109200 StringsTotalMem=183750
09:39:34 1292695565mS SIP Tx: UDP 192.168.44.1:5060 -> 192.168.40.25:5060
INVITE sip192.168.44.2423555315 SIP/2.0
Via: SIP/2.0/UDP 192.168.44.1:5060;rport;branch=z9hG4bKabaf9019fe09ede1706cf2d0519d4c6e
From: "6124224" <sip:6124224@192.168.44.242>;tag=2cca89851976636d
To: <sip192.168.44.2423555315>
Call-ID: b78eaddc89e86d071432b1617bfc7d3f
CSeq: 1170828815 INVITE
Contact: "6124224" <sip:6124224@192.168.44.1:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 10.1.0.4.0 build 7
P-Asserted-Identity: <sip:6124224@192.168.44.1:5060>
Content-Type: application/sdp
Content-Length: 298

v=0
o=UserA 3897003339 525680797 IN IP4 192.168.44.1
s=Session SDP
c=IN IP4 192.168.44.1
t=0 0
m=audio 46750 RTP/AVP 4 18 8 0 101
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
09:39:34 1292695571mS SIP Rx: UDP 192.168.40.25:5060 -> 192.168.44.1:5060
SIP/2.0 400 Bad Request-URI
Via: SIP/2.0/UDP 192.168.44.1:5060;received=192.168.44.1;branch=z9hG4bKabaf9019fe09ede1706cf2d0519d4c6e;rport=5060
From: "6124224" <sip:6124224@192.168.44.242>;tag=2cca89851976636d
To: <sip:>;tag=aprqngfrt-godip3k89mru0
Call-ID: b78eaddc89e86d071432b1617bfc7d3f
CSeq: 1170828815 INVITE

09:39:36 1292697167mS CMLineRx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=44791 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[2041] Type=Internal Plan=Default
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=83555315
IE CMIEDeviceDetail (231) c0a864f00000aef7 LOCALE=enu HW=15 VER=10 class=CMDeviceSIPTrunk type=0 number=17 channel=1 features=0x1 rx_gain=32 tx_gain=32 ep_callid=44791 ipaddr=192.168.100.240 apps=0 loc=999 em_loc=999 features2=0x0 is_spcall=1
Cause=38, Network out of order
09:39:36 1292697167mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
09:39:36 1292697168mS CMLineTx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=44791 in=0
Cause=16, Normal call clearing
09:39:36 1292697168mS CMCallEvt: c0a864f00000aef7 17.44791.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSOffering->CMCSDelete
09:39:36 1292697168mS CMARS: ModifyCMARSTarget: Short_Code: XN; - Line_Group_ID: 11 set line status to CMARS_OUTOFSERVICE
09:39:36 1292697169mS CMARS: Target: Short_Code: XN; - Line_Group_ID: 11 has been set to: CMARS_OUTOFSERVICE
09:39:36 1292697169mS CMCallEvt: c0a864f00000aef4 0.44790.0 10372 ARS for SIP: StateChange: END=B CMCSOverlapRecv->CMCSAccept
09:39:36 1292697170mS CMCallEvt: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: StateChange: END=A CMCSDialling->CMCSRingBack
09:39:36 1292697170mS CMExtnEvt: v=28 State, new=Alerting old=Dialling,0,0,Extn2041
09:39:36 1292697171mS CMExtnTx: v=2041, p1=0
CMProgress
Line: type=DigitalExtn 8 Call: lid=0 id=44788 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 27/10/21 09:39
09:39:36 1292697171mS CMCallEvt: c0a864f00000aef7 17.44791.0 -1 BaseEP: DELETE CMEndpoint f166bfc8 TOTAL NOW=2 CALL_LIST=1
09:39:36 1292697174mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f5267c40) resource busy -2358, total 45
09:39:36 1292697174mS CMMap: a=21.11 b=1.65535 T
09:39:36 1292697174mS CMMap: PCG::MapBChan pcp[225]b1r0 cp_b f51adaf0 other_cp_b f5267b28 type CGTypeDTMF
09:39:36 1292697174mS CMMap: a=21.11 b=10.30 M22
09:39:36 1292697174mS CMMap: DTMF:layTones g T[175] Tones ',EEEEE'
09:39:36 1292697175mS CMMap: Started playing tones, cp[225]b1r0 (from g null)
09:39:36 1292697175mS CMMap: cp[225]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE
09:39:37 1292698169mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: SIP
09:39:37 1292698996mS CMMap: PCG::UnmapBChan pcp[225]b1r0 cp_b f51adaf0 other_cp_b f5267b28
09:39:37 1292698996mS CMMap: a=21.11 b=10.30 M02
09:39:37 1292698996mS CMMap: a=21.11 b=0.0 T0
09:39:37 1292698997mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown(f5267c40) resource busy 1, total 45
09:39:37 1292698998mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f5267c40) resource busy -2358, total 45
09:39:37 1292698998mS CMMap: a=21.11 b=1.65535 T
09:39:37 1292698998mS CMMap: PCG::MapBChan pcp[225]b1r0 cp_b f51adaf0 other_cp_b f5267b28 type CGTypeDTMF
09:39:37 1292698998mS CMMap: a=21.11 b=10.30 M22
09:39:37 1292698998mS CMMap: DTMF:layTones g T[176] Tones ',EEEEE'
09:39:37 1292698999mS CMMap: Started playing tones, cp[225]b1r0 (from g null)
09:39:37 1292698999mS CMMap: cp[225]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE
09:39:38 1292699013mS RES: Wed 27/10/2021 09:39:37 FreeMem=53468324 Heap=52900532(2) Cache=567792 MemObjs=16084(Max 17264) CMMsg=5(7) ASN=0 Buff=5200 1353 1000 7441 5 Links=70782(71005) BTree=1558(3306) CB=6062 CPU=14.74% CPUStats=14.00%/3/8/1671/14071/1
6839/00.19%/1/02.57% MCR=0 MC
09:39:38 1292699014mS RES2: IP 500 V2 10.1.0.4.0 build 7 Tasks=60 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=15+78 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=25(TLS=6 OFF=0) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
09:39:38 1292699014mS RES4: XML MemObjs=8 PoolMem=4748404(2) FreeMem=4736284(0) HeapUsed=0
09:39:38 1292699015mS RES5: CLog MemObjs=2027 FreePoolMem(Objs)=3796(73) TotalMem=109200 StringsTotalMem=183750
09:39:39 1292700820mS CMMap: PCG::UnmapBChan pcp[225]b1r0 cp_b f51adaf0 other_cp_b f5267b28
09:39:39 1292700821mS CMMap: a=21.11 b=10.30 M02
09:39:39 1292700821mS CMMap: a=21.11 b=0.0 T0
09:39:39 1292700822mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown(f5267c40) resource busy 1, total 45
09:39:44 1292704169mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: SIP
09:39:44 1292704169mS CMARS: Target: Short_Code: XN; - Line_Group_ID: 11 - Telephone_Number: N - Line_Status: CMARS_OUTOFSERVICE
09:39:44 1292704170mS CMCallEvt: 0000000000000000 0.44792.0 -1 BaseEP: NEW CMEndpoint f166bfc8 TOTAL NOW=3 CALL_LIST=1
09:39:44 1292704171mS Stun: Info: Line 17: Not using STUN for media in this case.
09:39:44 1292704173mS CMARS: FOUND LINE - Line Id: 17 - using line group id: 11 - Short Code: XN; - Called Number: @192.168.44.2423555315 - Calling Number: 2041
09:39:44 1292704173mS CMARS: ModifyCMARSTarget: Short_Code: XN; - Line_Group_ID: 11 set line status to CMARS_TRYING
09:39:44 1292704173mS CMARS: SetCurrentTarget (TryTarget): Short_Code: XN; - Line_Group_ID: 11
09:39:44 1292704173mS CMARS: Retarget result=SEND Setup TO LINE
09:39:44 1292704174mS CMCallEvt: c0a864f00000aef8 17.44792.0 10372 SIPTrunk Endpoint: StateChange: END=child CMCSIdle->CMCSOffering
09:39:44 1292704175mS CMLineTx: v=0
CMSetup
Line: type=SIPLine 17 Call: lid=17 id=44792 in=0
Called[@192.168.44.2423555315] Type=Default (100) Reason=CMDRdirect SndComp Calling[2041] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 18030
user 'Extn2041' presentation Allowed
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=???????) name=Extn2041
IE CMIERespondingPartyName (228)(Type=???????) name=Extn2041
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=2041
IE CMIEDeviceDetail (231) c0a864f00000aef4 LOCALE=enu HW=15 VER=10 class=CMDeviceStdPhone type=99 number=328 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=44788 ipaddr=192.168.100.240 apps=0 loc=0 em_loc=1 features2=0x20 is_spc
all=0
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 5)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 5)
}
Locale: enu
09:39:44 1292704178mS SIP Tx: UDP 192.168.44.1:5060 -> 192.168.40.25:5060
INVITE sip192.168.44.2423555315 SIP/2.0
Via: SIP/2.0/UDP 192.168.44.1:5060;rport;branch=z9hG4bK6767992731174dcb6f4728d77ee851a4
From: "6124224" <sip:6124224@192.168.44.242>;tag=c60429a86f4d6f9d
To: <sip192.168.44.2423555315>
Call-ID: 058759020cddc0b68f543b299835c790
CSeq: 2033834785 INVITE
Contact: "6124224" <sip:6124224@192.168.44.1:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 10.1.0.4.0 build 7
P-Asserted-Identity: <sip:6124224@192.168.44.1:5060>
Content-Type: application/sdp
Content-Length: 299

v=0
o=UserA 1807599132 1232908366 IN IP4 192.168.44.1
s=Session SDP
c=IN IP4 192.168.44.1
t=0 0
m=audio 46750 RTP/AVP 4 18 8 0 101
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
09:39:44 1292704181mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f5267c40) resource busy -2358, total 45
09:39:44 1292704182mS CMMap: a=21.11 b=1.65535 T
09:39:44 1292704182mS CMMap: PCG::MapBChan pcp[225]b1r0 cp_b f51adaf0 other_cp_b f5267b28 type CGTypeDTMF
09:39:44 1292704182mS CMMap: a=21.11 b=10.30 M22
09:39:44 1292704182mS CMMap: DTMF:layTones g T[177] Tones ',EEEEE'
09:39:44 1292704182mS CMMap: Started playing tones, cp[225]b1r0 (from g null)
09:39:44 1292704182mS CMMap: cp[225]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE
09:39:44 1292704184mS SIP Rx: UDP 192.168.40.25:5060 -> 192.168.44.1:5060
SIP/2.0 400 Bad Request-URI
Via: SIP/2.0/UDP 192.168.44.1:5060;received=192.168.44.1;branch=z9hG4bK6767992731174dcb6f4728d77ee851a4;rport=5060
From: "6124224" <sip:6124224@192.168.44.242>;tag=c60429a86f4d6f9d
To: <sip:>;tag=aprqngfrt-nlcfc07fppm32
Call-ID: 058759020cddc0b68f543b299835c790
CSeq: 2033834785 INVITE

09:39:44 1292704417mS RES: Wed 27/10/2021 09:39:43 FreeMem=53401132 Heap=52868004(2) Cache=533128 MemObjs=16483(Max 17264) CMMsg=5(7) ASN=0 Buff=5200 1353 1000 7444 5 Links=70843(71005) BTree=1562(3306) CB=6059 CPU=14.49% CPUStats=11.59%/1/5/1671/14528/1
6839/00.17%/0/02.57% MCR=0 MC
09:39:44 1292704418mS RES2: IP 500 V2 10.1.0.4.0 build 7 Tasks=60 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=15+79 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=25(TLS=6 OFF=0) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
09:39:44 1292704418mS RES4: XML MemObjs=8 PoolMem=4748404(2) FreeMem=4736284(0) HeapUsed=0
09:39:44 1292704418mS RES5: CLog MemObjs=2027 FreePoolMem(Objs)=3796(73) TotalMem=109200 StringsTotalMem=183750
09:39:46 1292706003mS CMMap: PCG::UnmapBChan pcp[225]b1r0 cp_b f51adaf0 other_cp_b f5267b28
09:39:46 1292706003mS CMMap: a=21.11 b=10.30 M02
09:39:46 1292706003mS CMMap: a=21.11 b=0.0 T0
09:39:46 1292706004mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown(f5267c40) resource busy 1, total 45
09:39:46 1292706178mS SIP Tx: UDP 192.168.44.1:5060 -> 192.168.40.25:5060
INVITE sip192.168.44.2423555315 SIP/2.0
Via: SIP/2.0/UDP 192.168.44.1:5060;rport;branch=z9hG4bK6767992731174dcb6f4728d77ee851a4
From: "6124224" <sip:6124224@192.168.44.242>;tag=c60429a86f4d6f9d
To: <sip192.168.44.2423555315>
Call-ID: 058759020cddc0b68f543b299835c790
CSeq: 2033834785 INVITE
Contact: "6124224" <sip:6124224@192.168.44.1:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 10.1.0.4.0 build 7
P-Asserted-Identity: <sip:6124224@192.168.44.1:5060>
Content-Type: application/sdp
Content-Length: 299

v=0
o=UserA 1807599132 1232908366 IN IP4 192.168.44.1
s=Session SDP
c=IN IP4 192.168.44.1
t=0 0
m=audio 46750 RTP/AVP 4 18 8 0 101
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
09:39:46 1292706184mS SIP Rx: UDP 192.168.40.25:5060 -> 192.168.44.1:5060
SIP/2.0 400 Bad Request-URI
Via: SIP/2.0/UDP 192.168.44.1:5060;received=192.168.44.1;branch=z9hG4bK6767992731174dcb6f4728d77ee851a4;rport=5060
From: "6124224" <sip:6124224@192.168.44.242>;tag=c60429a86f4d6f9d
To: <sip:>;tag=aprqngfrt-nlcfc07fppm32
Call-ID: 058759020cddc0b68f543b299835c790
CSeq: 2033834785 INVITE

09:39:47 1292707780mS CMLineRx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=44792 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[2041] Type=Internal Plan=Default
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=83555315
IE CMIEDeviceDetail (231) c0a864f00000aef8 LOCALE=enu HW=15 VER=10 class=CMDeviceSIPTrunk type=0 number=17 channel=1 features=0x1 rx_gain=32 tx_gain=32 ep_callid=44792 ipaddr=192.168.100.240 apps=0 loc=999 em_loc=999 features2=0x0 is_spcall=1
Cause=38, Network out of order
09:39:47 1292707780mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSAccept
09:39:47 1292707781mS CMLineTx: v=0
CMReleaseComp
Line: type=SIPLine 17 Call: lid=17 id=44792 in=0
Cause=16, Normal call clearing
09:39:47 1292707781mS CMCallEvt: c0a864f00000aef8 17.44792.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSOffering->CMCSDelete
09:39:47 1292707782mS CMARS: ModifyCMARSTarget: Short_Code: XN; - Line_Group_ID: 11 set line status to CMARS_OUTOFSERVICE
09:39:47 1292707782mS CMARS: Target: Short_Code: XN; - Line_Group_ID: 11 has been set to: CMARS_OUTOFSERVICE
09:39:47 1292707782mS CMCallEvt: c0a864f00000aef8 17.44792.0 -1 BaseEP: DELETE CMEndpoint f166bfc8 TOTAL NOW=2 CALL_LIST=1
09:39:48 1292708125mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,2041: Feature Key Pressed 6CPLFeatureDrop
09:39:48 1292708126mS CMCallEvt: c0a864f00000aef4 0.44788.0 10372 Extn2041.0: StateChange: END=A CMCSRingBack->CMCSCompleted
09:39:48 1292708126mS CMExtnEvt: v=28 State, new=PortRecoverDelay old=Alerting,0,0,Extn2041
09:39:48 1292708127mS CMLOGGING: CALL:2021/10/2709:39,00:00:00,000,2041,O,83555315,83555315,Extn2041,,,1,,"",0,n/a
09:39:48 1292708127mS CMExtnEvt: Extn2041: CALL LOST (CMCauseNormal)
09:39:48 1292708128mS CMExtnEvt: Extn2041: Extn(2041) Calling Party Number(2041) Type(CMNTypeInternal)
09:39:48 1292708128mS CMExtnEvt: Extn2041: CMExtnHandler::SetCurrent( id: 44788->0 )
09:39:48 1292708129mS CMCallEvt: c0a864f00000aef4 0.44788.0 -1 Extn2041.-1: StateChange: END=X CMCSCompleted->CMCSDelete
09:39:48 1292708129mS CMARS: CMARSEndpoint::CallLost(cause=16) - Address: c0a864f00000aef4 0.44790.0 10372 ARS for SIP - Call State: CMCSAccept
09:39:48 1292708130mS CMCallEvt: c0a864f00000aef4 0.44790.0 -1 ARS for SIP: StateChange: END=X CMCSAccept->CMCSDelete
09:39:48 1292708130mS CMCallEvt: c0a864f00000aef4 0.44790.0 -1 BaseEP: DELETE CMEndpoint f15b7c5c TOTAL NOW=1 CALL_LIST=0
09:39:48 1292708130mS CMCallEvt: END CALL:10372 (f167641c)
09:39:48 1292708131mS CMTARGET: c0a864f00000aef4 0.44788.0 -1 BaseEP: ~CMTargetHandler f4e48c44 ep f1726330
09:39:48 1292708131mS CMCallEvt: c0a864f00000aef4 0.44788.0 -1 BaseEP: DELETE CMEndpoint f1726330 TOTAL NOW=0 CALL_LIST=0
09:39:48 1292708134mS CMMap: a=2.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f52d2194) resource busy 0, total 84
09:39:50 1292710129mS CMExtnEvt: Extn2041: Recover Timer reason=CMTRWrapUp
09:39:50 1292710129mS CMExtnEvt: v=28 State, new=Idle old=PortRecoverDelay,0,0,Extn2041
09:39:50 1292710130mS CMExtnTx: v=2041, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 8 Call: lid=0 id=-1 in=0
Called[Extn2041 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Extn2041 Msgs=0]
Timed: 27/10/21 09:39

 

[derfloh]

To and/or Request URI are empty:

 INVITE sip:@192.168.44.2423555315 SIP/2.0
Via: SIP/2.0/UDP 192.168.44.1:5060;rport;branch=z9hG4bK6767992731174dcb6f4728d77ee851a4
From: "6124224" <sip:6124224@192.168.44.242>;tag=c60429a86f4d6f9d
To: <sip:@192.168.44.2423555315>
Call-ID: 058759020cddc0b68f543b299835c790
CSeq: 2033834785 INVITE
Contact: "6124224" <sip:6124224@192.168.44.1:5060;transport=udp>
Max-Forwards: 70

IP Office remote service
IP Office certificate check
CLI based call blocking
SCN fallback over PSTN

 

[Ekster]

I think the ARS or short codes are wrong somewhere, the number is going on the end of the "TO address"!

The dialled number looks like it is 3555315 and the invite has:

To: <sip192.168.44.242[highlight #FCE94F]3555315[/highlight]>

“Some humans would do anything to see if it was possible to do it.
If you put a large switch in some cave somewhere, with a sign on it saying 'End-of-the-World Switch. PLEASE DO NOT TOUCH'.
The paint wouldn't even have time to dry.”

Terry Pratchet

 

[critchey]

09:39:32 1292693555mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: @192.168.44.2423555315 Addr: f15b7c5c
09:39:32 1292693555mS CMARS: FORM: SIP - Received Number: @192.168.44.2423555315

Clearly something is wrong in your shortcodes. Can you post the 9N shortcode you use and if it points at an ARS table please post that ARS table as well.

The truth is just an excuse for lack of imagination.

 

[j_redhead]

 

[j_redhead]

 

[j_redhead]

@critchey attached are the short code and the ARS

 

[Ekster]

In the 8N short code, change the Telephone Number to just N (remove the "@192.168.44.242") and try it again

“Some humans would do anything to see if it was possible to do it.
If you put a large switch in some cave somewhere, with a sign on it saying 'End-of-the-World Switch. PLEASE DO NOT TOUCH'.
The paint wouldn't even have time to dry.”

Terry Pratchet

 

[j_redhead]

@Ekster now would you believe that was configured before and it was saying call rejected. Tried it again and it works now. However I am getting another issue now. I left the trunk able to receive calls but now that I just logged in to see that the trunk says out of service. If a change is made to the trunk under the SIP URI settings it comes up idle for about 2 mins then returns to out of service status.

 

[critchey]

How is the SIP provider registering the trunks? It appears by public IP because it does not appear you have any credentials setup. Is that correct?

The truth is just an excuse for lack of imagination.

 

[j_redhead]

Update. Got the trunk working. Turns out it was provider issue. The IP office was not receiving messages from provider side. Had to deselect the check oos setting in the sip settings. Sip stayed active and was able to make and recieve calls.