Support
Community

Anonymous · ‎01-27-2016

I have a TA908e 3rd generation in role:user for 2 PRI's from carrier: Cablevision Lightpath (New York, Long Island).

I have an IP PBX connecting to make calls on the LAN interface...outbound caller-id given by the IP-PBX shows for ALL CARRIERS except AT&T cellular phones.

If the PRI is removed from the TA908E 3rd Generation and placed directly into the PBX, caller-id to AT&T and all carriers works fine. What could the TA908E be changing to cause this on only 1 carrier?

Config is as follows, PBX with issue is voice trunk T03:

<SNIP>

!

interface gigabit-eth 0/1

ip address 10.100.0.10 255.255.255.0

media-gateway ip primary

no shutdown

!

interface t1 0/1

tdm-group 1 timeslots 1-24 speed 64

no shutdown

!

interface t1 0/2

tdm-group 2 timeslots 1-24 speed 64

no shutdown

!

interface t1 0/3

shutdown

!

interface t1 0/4

shutdown

!

interface pri 1

description pri 1

role user

isdn name-delivery setup

connect t1 0/1 tdm-group 1

no shutdown

!

interface pri 2

description pri 2

role user

isdn name-delivery setup

connect t1 0/2 tdm-group 2

no shutdown

!

interface fxs 0/1

no shutdown

!

interface fxs 0/2

no shutdown

!

interface fxs 0/3

no shutdown

!

interface fxs 0/4

no shutdown

!

interface fxs 0/5

no shutdown

!

interface fxs 0/6

no shutdown

!

interface fxs 0/7

no shutdown

!

interface fxs 0/8

no shutdown

!

interface fxo 0/0

no shutdown

!

isdn-group 1

connect pri 1

!

isdn-group 2

connect pri 2

!

timing-source t1 0/1

!

ip route 0.0.0.0 0.0.0.0 10.100.0.1

!

no tftp server

no tftp server overwrite

http server

http secure-server

no snmp agent

no ip ftp server

no ip scp server

no ip sntp server

!

sip

sip udp 5060

no sip tcp

no sip tls

!

voice feature-mode network

voice forward-mode network

!

voice dial-plan 1 local NXX-NXX-XXXX

voice dial-plan 2 local XXXX

!

voice codec-list Trunk

codec g711ulaw

codec g729

!

voice trunk T01 type isdn

resource-selection linear descending

connect isdn-group 1

rtp delay-mode adaptive

!

voice trunk T02 type sip

description "PBX-1"

sip-server primary 10.100.0.101

!

voice trunk T03 type sip

description "PBX-2"

sip-server primary 10.0.0.254

transfer-mode network

!

voice trunk T04 type isdn

resource-selection linear descending

connect isdn-group 2

rtp delay-mode adaptive

!

voice trunk T05 type sip

description "PBX-3"

sip-server primary 10.1.1.40

transfer-mode network

!

voice grouped-trunk PRI

description "PRI to PBX"

trunk T01

accept 1-NXX-NXX-XXXX cost 0

accept 1-800-NXX-XXXX cost 0

accept 1-888-NXX-XXXX cost 0

accept 1-877-NXX-XXXX cost 0

accept 1-866-NXX-XXXX cost 0

accept 1-855-NXX-XXXX cost 0

accept 011-$ cost 0

accept 411 cost 0

accept 611 cost 0

accept 911 cost 0

accept NXX-XXXX cost 0

reject NXX-976-XXXX

reject 1-900-NXX-XXXX

reject 1-976-NXX-XXXX

!

voice grouped-trunk CTNY-PRI-1

trunk T03

accept ...........<7 digit numbers sanitized>

!

voice grouped-trunk PBX-2

trunk T05

accept ...........<7 digit numbers sanitized>

!

ip rtp symmetric-filter

!

End

Version Info:

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

ADTRAN, Inc. OS version R11.9.0.E

Mainline Version: ENM.15.130

P4 Changelist: 221342

Checksum: ece8ce396e1455b4fdf86be65ff5f69e686afbfc3ae9ec7f3f9c9268c120001e

Built on: Tue Sep 29 16:45:48 CDT 2015

Hardware version L.1.5.0.0-0

Boot ROM version R10.9.3.B1

Built on: Fri Apr 11 09:42:09 CDT 2014

Compatibility Version: 1

Platform: Total Access 908e (3rd Gen), part number 4243908F2SCTL

Serial number CFG1337655

Flash: 97120256 bytes DRAM: 509648896 bytes

TA908e uptime is 6 weeks, 6 days, 23 hours, 6 minutes, 10 seconds

slot 0, DSP 1

DSP software version: G3.R1.3..0-R

DSP hardware version: Freescale BSC9131

Total channels: 60

System returned to ROM by Soft Reset

Current system image file is "T900E3A-R11-9-0-E.biz"

Primary boot system image file is "T900E3A-R11-9-0-E.biz"

Backup boot system image file is "T900E3A-R10-9-4-E.biz"

Primary system configuration file is "startup-config"

jayh · ‎01-27-2016

It sounds like there's something about the formatting of the ISDN setup message that isn't quite standard and all carriers other than AT&T are fixing it up at the terminating end. What does an AT&T cell phone display instead of the CLID?

Perhaps it's the format of the outgoing number that makes a difference.

Debug isdn l2-formatted and look at the calling party number on the outbound message.

Try it as NPA-NXX-XXXX, 1-NPA-NXX-XXXX and e.164 +1-NPA-NXX-XXXX

Also look at the outgoing ISDN call rype, national vs. local vs. unknown.

Lastly, make sure that your switch type matches the carrier's. These days most are NI-2.

Anonymous · ‎01-28-2016

We also have had these symptoms but just for AT&T Iphone 6 phones. (google it) For us, it was really a bad ANI issue that causes no CNAM database dip on the far end.

We were sending ANI from a digital Panasonic PBX over a classic NI-2 PRI to a Lucent 5E switch. You can get more vanilla than that. Our carrier "broke" the outbound CNAM when they started to use "NeutralTandem.com" to transit the traffic to the AT&T network.

The bottom line was we the carrier asked us to change the ANI format an/or the numbering plan. I can't recall. THEN the carrier fixed it.

Anonymous · ‎02-01-2016

Thanks for the input guys. I've done a capture using "DEBUG ISDN L2-FORMATTED" and "DEBUG VOICE VERBOSE" for calls to VERIZON SUBSCRIBER (CALLER-ID OK) and ATT SUBSCRIBER (CALLER-ID NOT OK) below. Could you tell me if you see anything indicating bad ANI?

How would I spot BAD-ANI in these debug outputs?

Thanks!

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

<SNIP>

VERIZON SUBSCRIBER (CALLER-ID OK) - number called 15169716561

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

TA908e#debug voice ver

TA908e#debug voice verbose

04:22:53.582 ISDN.L2_MSG PRI 1 T 00 01 01 77

04:22:53.586 ISDN.L2_MSG PRI 1 R 00 01 01 83TA908e#

TA908e#

04:23:01.997 TM.T03 01 SipTM_Idle rcvd SIP call-leg request: INVITE

04:23:01.997 TM.T03 01 SipTM_Idle call-leg -> Offering

04:23:01.997 TM.T03 01 SipTM_Idle State change >> SipTM_Idle->SipTM_Trying

04:23:01.998 TM.T03 01 SipTM_Trying SDP offer is not loopback request

04:23:01.999 TM.T03 01 SipTM_Trying Processing From for Caller-ID.

04:23:01.999 TM.T03 01 SipTM_Trying Caller ID Name = "Constructure Technologies"

04:23:01.999 TM.T03 01 SipTM_Trying Caller ID Number = "6313967777"

04:23:01.999 TM.T03 01 SipTM_Trying info: unable to set redirect number(s) from INVITE

04:23:01.999 TM.T03 01 SipTM_Trying sent: TA->InboundCall

04:23:02.000 TM.T03 01 Looking up source address for destination 10.0.0.254

04:23:02.000 TM.T03 01 call-leg (0x0x4d169970) -> src: 10.100.0.10 : 5060 dst: 10.0.0.254 : 5060

04:23:02.001 TM.T03 01 SipTM_Trying sent: 100 Trying

04:23:02.002 TA.T03 01 TAIdle rcvd: inboundCall from TM

04:23:02.002 TA.T03 01 State change >> TAIdle->TAInboundCall (TAS_Calling)

04:23:02.002 TA.T03 01 Failed - DID translation: no match for 15169716561, using 15169716561

04:23:02.002 TA.T03 01 TAIdle sent: call to SB

04:23:02.002 TM.T03 01 SipTM_Trying tachg -> TAInboundCall

04:23:02.003 TM.T03 01 SipTM_Trying State change >> SipTM_Trying->SipTM_Pending

04:23:02.003 SB.CALL 9792 Idle Called the call routine with 15169716561

04:23:02 SB.TGMgr For dialed number 15169716561, against template 1-NXX-NXX-XXXX, on TrunkGroup PRI, the score is 2000

04:23:02.004 SB.CCM isMappable:

04:23:02.004 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:02.004 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:02.004 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = unknown 0/0

04:23:02.005 SB.CCM : SDP Transaction = CallID: 9792

04:23:02.005 SB.CCM : SDP Offer = 0x5220a910, (10.0.0.103:16430)

04:23:02.005 SB.CCM isMappable: Call Connection Type is RTP_TO_TDM

04:23:02.005 SB.CCM isMappable: Reserving RTP Channel 0/1.1

04:23:02.006 SB.CCM translateOffer: offer codec list: PCMU G729

04:23:02.006 SB.CCM translateOffer: revised offer codec list: PCMU G729

04:23:02.007 SB.CCM translateOffer: codec list after answerer: PCMU G729

04:23:02.008 SB.CCM translateOffer: DTMF signaling: answerer has no restrictions configured, passing offer(NTE 96) through

04:23:02.008 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP before offer filter

04:23:02.008 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:02.008 SRTP.SDES NEGOTIATION invoked pass-through SRTP filter

04:23:02.009 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP after offer filter

04:23:02.009 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:02.009 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP after offer translator

04:23:02.009 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:02.009 SB.CCM translateOffer: success

04:23:02.010 MEDIA.MANAGER Allocating media port.

04:23:02.010 MEDIA.MANAGER getSubstitutePort: No matching callIdMap entry found for call 9792

04:23:02.010 MEDIA.MANAGER Call ID map : Added new entry : call ID 9792 : session -1454371118INIP410.0.0.103 : version 1454371119 : index 2622

04:23:02.010 MEDIA.MANAGER New media entry : type(0), callID(9792), sessionID(-1454371118INIP410.0.0.103), original IP(10.0.0.103) ports(16430-16431), substitute IP(::) ports(12622-12623), RtpChannel(0/1.1), connection(0x0x52206010), sdpOverride(0), me(0x0x520cc710). RtpChannel 0/1.1

04:23:02.010 SB.CALL 9792 Idle Call sent from T03 to T01 (15169716561)

04:23:02.011 SB.CALL 9792 State change >> Idle->Delivering

04:23:02.011 RTP.MANAGER Isdn(Group) 0/ - empty - RTP: Reserve resource

04:23:02.011 RTP.MANAGER Isdn(Group) 0/ - Dsp 0/1.1 - RTP:

04:23:02.011 RTP.PROVIDER unknown - Dsp 0/1.1 - RTP: reserving already allocated RTP channel

04:23:02.011 TA.T03 01 TAInboundCall CallResp event accepted

04:23:02.012 TA.T03 01 State change >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

04:23:02.012 TA.T01 23 State change >> TAIdle->TAOutGoing (TAS_Delivering)

04:23:02.012 TM.T01 23 tachg_Delivering

04:23:02.012 TM.T01 23 IsdnTmStateIdle->IsdnTmStateOutboundDeliver

04:23:02.012 TM.T01 23 IsdnTmStateOutboundDeliver::enter()

04:23:02.013 ISDN.L2_MSG PRI 1 T 00 01 82 76 08 02 17 34 05 04 03 80 90 A2

04:23:02.013 ISDN.L2_MSG PRI 1 18 03 A1 83 97 1C 1D 9F 8B 01 00 A1 17 02

04:23:02.013 ISDN.L2_MSG PRI 1 01 01 02 01 00 80 0F 43 6F 6E 73 74 72 75

04:23:02.013 ISDN.L2_MSG PRI 1 63 74 75 72 65 20 54 65 6C 0C 00 80 36 33

04:23:02.013 ISDN.L2_MSG PRI 1 31 33 39 36 37 37 37 37 70 0C 80 31 35 31

04:23:02.013 ISDN.L2_MSG PRI 1 36 39 37 31 36 35 36 31

04:23:02.014 SB.CALL 9792 Delivering Called the deliverResponse routine from Delivering

04:23:02.014 SB.CALL 9792 Delivering DeliverResponse(accept) sent from T01 to T03

04:23:02.014 TA.T03 01 TAConnectWaitIn deliverResponse event accepted

04:23:02.014 TA.T03 01 TAConnectWaitIn ERROR! deliverResponse ignored

04:23:02.028 ISDN.L2_MSG PRI 1 R 00 01 01 84

04:23:02.204 ISDN.L2_MSG PRI 1 R 02 01 76 84 08 02 97 34 02 18 03 A9 83 97

04:23:02.204 ISDN.L2_MSG PRI 1 T 02 01 01 78

04:23:02.598 ISDN.L2_MSG PRI 1 R 02 01 78 84 08 02 97 34 01 1E 02 84 88

04:23:02.598 ISDN.L2_MSG PRI 1 T 02 01 01 7A

04:23:02.598 TM.T01 23 IsdnTmStateOutboundDeliver->IsdnTmStateOutboundPreconnect

04:23:02.598 TM.T01 23 IsdnTmStateOutboundPreconnect::enter()

04:23:02.599 TA.T01 23 TAOutGoing rcvd: preConnect from TM

04:23:02.599 SB.CCM isResponseMappable:

04:23:02.599 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:02.599 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:02.599 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:02.599 SB.CCM : SDP Transaction = CallID: 9792

04:23:02.600 SB.CCM : SDP Offer = 0x5220a910, (10.0.0.103:16430)

04:23:02.600 SB.CCM : Offer side SRTP session details

04:23:02.600 SB.CCM : None

04:23:02.600 SB.CCM : Answer side SRTP session details

04:23:02.600 SB.CCM : None

04:23:02.600 SB.CCM : RTP Channel = 0/1.1

04:23:02.600 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

04:23:02.600 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

04:23:02.601 SB.CCM isResponseMappable: Creating SDP Answer based on SDP Offer

04:23:02.601 SB.CCM createAnswer: creating SDP answer using RTP channel 0/1.1

04:23:02.601 SB.CCM createAnswer : offer codec list: PCMU G729

04:23:02.602 SB.CCM : answer codec list: PCMU G729

04:23:02.603 SB.CCM createAnswer : result codec list: PCMU G729

04:23:02.603 SB.CCM createAnswer : final DTMF signaling(NTE 96)

04:23:02.604 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9792 sessionId -1454371118INIP410.0.0.103 remote port 16430

04:23:02.604 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:02.604 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12622)

04:23:02.604 SB.CCM updateMediaEntryForReinviteWithSameSdp : no associated port found for port (12622)

04:23:02.605 SB.CCM translateAnswer: offer codec list: PCMU G729

04:23:02.605 SB.CCM : answer codec list: PCMU G729

04:23:02.605 SB.CCM translateAnswer: CODEC transcoding is not required

04:23:02.606 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

04:23:02.606 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - offer

04:23:02.606 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:02.606 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedOffer

04:23:02.606 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:02.607 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer

04:23:02.607 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:23:02.607 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after validator

04:23:02.607 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:23:02.607 SRTP.SDES NEGOTIATION invoked pass-through answer translation

04:23:02.607 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after translation

04:23:02.608 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:23:02.608 SB.CCM translateAnswer: success

04:23:02.608 MEDIA.MANAGER Allocating media port.

04:23:02.608 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9792 sessionId -1422332582INIP4127.0.0.3 remote port 0

04:23:02.608 MEDIA.MANAGER Call ID map : Added new session ID : call ID 9792 : session -1422332582INIP4127.0.0.3 : version 2 : index 2624

04:23:02.609 MEDIA.MANAGER New media entry : type(0), callID(9792), sessionID(-1422332582INIP4127.0.0.3), original IP(127.0.0.3) ports(12624-12625), substitute IP(::) ports(12624-12625), RtpChannel(0/1.1), connection(0x0x5204d510), sdpOverride(0), me(0x0x520b5410). RtpChannel 0/1.1

04:23:02.609 SB.CALL 9792 Delivering Sent preConnect from T01 to T03

04:23:02.609 SB.CALL 9792 State change >> Delivering->PreConnecting

04:23:02.609 TA.T03 01 TAConnectWaitIn preConnect event accepted

04:23:02.609 TM.T03 01 SipTM_Pending tachg -> TAConnectWaitIn

04:23:02.610 TM.T03 01 SipTM_Pending sent: TA->PreConnect Response

04:23:02.610 TM.T03 01 SipTM_Pending State change >> SipTM_Pending->SipTM_Preconnect

04:23:02.610 TM.T03 01 SDP DPI call ID 9792 : No media bin.

04:23:02.610 TM.T03 01 Processing new SDP entries.

04:23:02.610 TM.T03 01 Checking for internal Media Gateway IP Address

04:23:02.611 TM.T03 01 Using RTP Channel 0/1.1

04:23:02.611 TM.T03 01 Inserting 10.100.0.10 into SDP for Media Gateway

04:23:02.611 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9792 sessionId -1422332582INIP4127.0.0.3 remote port 12624

04:23:02.611 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:02.611 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12624)

04:23:02.611 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12624 and sub port 12624.

04:23:02.612 MEDIA.MANAGER Call ID map : Received stale SDP - will ignore : call ID 9792 : session -1422332582INIP4127.0.0.3 : version 1

04:23:02.612 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9792 : session -1422332582INIP4127.0.0.3 : IP 10.100.0.10 ports 12624 - 12625 : remote IP 127.0.0.3 ports 12624 - 12625.

04:23:02.612 TM.T03 01 Adding RTP Media Gateway Entry: 127.0.0.3:12624 -> 10.100.0.10:12624

04:23:02.612 TM.T03 01 Allocating anchor ports 12624 and 12625 for interface 10.100.0.10

04:23:02.614 TM.T03 01 SipTM_Preconnect sent: 183 Session Progress

04:23:02.614 TA.T03 01 TAConnectWaitIn rcvd: preConnectResponse from TM

04:23:02.614 SB.CCM connect:

04:23:02.614 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:02.614 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:02.615 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:02.615 SB.CCM : SDP Transaction = CallID: 9792

04:23:02.615 SB.CCM : SDP Offer = 0x5220a910, (10.0.0.103:16430)

04:23:02.615 SB.CCM : SDP Answer = 0x521aef10, (127.0.0.3:12624)

04:23:02.615 SB.CCM : Offer side SRTP session details

04:23:02.616 SB.CCM : None

04:23:02.616 SB.CCM : Answer side SRTP session details

04:23:02.616 SB.CCM : None

04:23:02.616 SB.CCM : RTP Channel = 0/1.1

04:23:02.616 SB.CCM connect: Call Connection Type is RTP_TO_TDM

04:23:02.616 SB.CCM call rtpChannel->allocateForInterface

04:23:02.617 SB.CCM SDP offer is 10.0.0.103:16430, SDP answer is 127.0.0.3:12624

04:23:02.617 MEDIA.MANAGER Trying to connect call ID 9792 : SDP sessions -1454371118INIP410.0.0.103 and -1422332582INIP4127.0.0.3

04:23:02.617 MEDIA.MANAGER Found 1 ports for session -1454371118INIP410.0.0.103

04:23:02.617 MEDIA.MANAGER Found 1 ports for session -1422332582INIP4127.0.0.3

04:23:02.617 MEDIA.MANAGER Connecting Disconnected Local [::]:12622 : Remote 10.0.0.103:16430

04:23:02.617 MEDIA.MANAGER and Disconnected Local 10.100.0.10:12624 : Remote 127.0.0.3:12624

04:23:02.618 MEDIA.MANAGER Setting up DSP Media Connection 9792 for entry(type(0), callID(9792), sessionID(-1454371118INIP410.0.0.103), original IP(10.0.0.103) ports(16430-16431), substitute IP(::) ports(12622-12623), RtpChannel(0/1.1), connection(0x0x52206010), sdpOverride(0), me(0x0x520cc710))

04:23:02.618 MEDIA.MANAGER Setting up DSP Media Connection 9792 for entry(type(0), callID(9792), sessionID(-1422332582INIP4127.0.0.3), original IP(127.0.0.3) ports(12624-12625), substitute IP(10.100.0.10) ports(12624-12625), RtpChannel(0/1.1), connection(0x0x5204d510), sdpOverride(0), me(0x0x520b5410))

04:23:02.618 MEDIA.MANAGER Connection Fixup 1 DSP Port 12622

04:23:02.618 MEDIA.MANAGER Local [::]:12622 : Remote 10.0.0.103:16430

04:23:02.618 MEDIA.MANAGER Connection Fixup 2 DSP Port 12624

04:23:02.618 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 127.0.0.3:12624

04:23:02.619 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12622 sub [::]:12622 remote 10.0.0.103:16430

04:23:02.619 MEDIA.MANAGER : Other side : entry 12624 sub 10.100.0.10:12624 remote 127.0.0.3:12624

04:23:02.619 MEDIA.MANAGER Connection Fixup 1 DSP Port 12624

04:23:02.619 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 127.0.0.3:12624

04:23:02.619 MEDIA.MANAGER Connection Fixup 2 DSP Port 12622

04:23:02.619 MEDIA.MANAGER Local [::]:12622 : Remote 10.0.0.103:16430

04:23:02.619 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12624 remote from 127.0.0.3:12624 to 10.0.0.103:16430

04:23:02.620 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:02.620 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:02.620 MEDIA.MANAGER Connection Result 1 DSP Port 12624

04:23:02.620 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 10.0.0.103:16430

04:23:02.620 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:02.620 MEDIA.MANAGER connectionFixup success for port 12624 and 12622

04:23:02.620 MEDIA.MANAGER Marking setup complete for port 12624

04:23:02.620 MEDIA.MANAGER Marking setup complete for port 12622

04:23:02.621 MEDIA.MANAGER Connection Fixup 1 DSP Port 12623

04:23:02.621 MEDIA.MANAGER Local [::]:12623 : Remote 10.0.0.103:16431

04:23:02.621 MEDIA.MANAGER Connection Fixup 2 DSP Port 12625

04:23:02.621 MEDIA.MANAGER Local 10.100.0.10:12625 : Remote 127.0.0.3:12625

04:23:02.621 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12623 sub [::]:12623 remote 10.0.0.103:16431

04:23:02.621 MEDIA.MANAGER : Other side : entry 12625 sub 10.100.0.10:12625 remote 127.0.0.3:12625

04:23:02.621 MEDIA.MANAGER Connection Fixup 1 DSP Port 12625

04:23:02.622 MEDIA.MANAGER Local 10.100.0.10:12625 : Remote 127.0.0.3:12625

04:23:02.622 MEDIA.MANAGER Connection Fixup 2 DSP Port 12623

04:23:02.622 MEDIA.MANAGER Local [::]:12623 : Remote 10.0.0.103:16431

04:23:02.622 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12625 remote from 127.0.0.3:12625 to 10.0.0.103:16431

04:23:02.622 MEDIA.MANAGER Connection Result 1 DSP Port 12625

04:23:02.622 MEDIA.MANAGER Local 10.100.0.10:12625 : Remote 10.0.0.103:16431

04:23:02.622 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:02.622 MEDIA.MANAGER connectionFixup success for port 12625 and 12623

04:23:02.622 MEDIA.MANAGER Marking setup complete for port 12625

04:23:02.623 MEDIA.MANAGER Marking setup complete for port 12623

04:23:02.623 MEDIA.MANAGER Connected DSP Port 12624

04:23:02.623 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 10.0.0.103:16430

04:23:02.623 MEDIA.MANAGER Connected associations Entry not activated

04:23:02.623 SB.CCM connect: Connected RTP/TDM via MCM

04:23:02.623 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:02.623 SB.CCM setupRtpChannel, source 1, silence 0

04:23:02.624 SB.CCM setupRtpChannel: setup using media connection

04:23:02.624 SB.CCM Looking up source address for destination 10.0.0.103

04:23:02.624 SB.CCM setupRtpChannel: Source IP addr = 10.100.0.10, port = 12624

04:23:02.624 SB.CCM setupRtpChannel: Target IP addr = 10.0.0.103, port = 16430

04:23:02.624 SB.CCM setupRtpChannel: Undo of previous operation not required

04:23:02.625 SB.CCM getFinalCodec: PCMU

04:23:02.625 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.100.0.10:12624 Trg 10.0.0.103:16430 via PCMU Rx PCMU G729

04:23:02.625 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=96/96 dscp=46 vad=off isOffer no

04:23:02.626 SB.CCM setupRtpChannel: Starting RTP Channel

04:23:02.626 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

04:23:02.626 RTP.CHANNEL Channel 0/1.1 started successfully.

04:23:02.626 SB.CCM firewallConnectCall: Set up firewall from media connections

04:23:02.626 SB.CCM sdpFirewall: invoked with offer - 10.0.0.103:16430, answer - 10.100.0.10:12624

04:23:02.627 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

04:23:02.627 SB.CCM connect: TDM streams: port(SipTrunk 0/1.1) to port(Isdn(Ds1Ds0Trunk) 0/1.23)

04:23:02.628 SB.CALL 9792 State change >> PreConnecting->PreConnected

04:23:02.628 SB.CALL 9792 PreConnected Call PreConnecting from T03 to T01

04:23:02.628 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: starting

04:23:02.628 TA.T01 ERROR! preConnectResponse ignored

04:23:12.891 ISDN.L2_MSG PRI 1 T 00 01 01 7B

04:23:12.896 ISDN.L2_MSG PRI 1 R 00 01 01 85

04:23:13.158 ISDN.L2_MSG PRI 1 R 02 01 7A 84 08 02 97 34 07 1E 02 84 82

04:23:13.158 ISDN.L2_MSG PRI 1 T 02 01 01 7C

04:23:13.158 ISDN.L2_MSG PRI 1 T 00 01 84 7C 08 02 17 34 0F

04:23:13.158 TM.T01 23 IsdnTmStateOutboundPreconnect->IsdnTmStateOutboundConnecting

04:23:13.158 TM.T01 23 IsdnTmStateOutboundConnecting::enter()

04:23:13.159 TA.T01 23 TAOutGoing rcvd: connect from TM

04:23:13.159 TA.T01 23 State change >> TAOutGoing->TAConnectWaitOut (TAS_Delivering)

04:23:13.159 SB.CALL 9792 PreConnected Called the connect routine

04:23:13.159 SB.CCM isResponseMappable:

04:23:13.159 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:13.159 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:13.160 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:13.160 SB.CCM : SDP Transaction = CallID: 9792

04:23:13.160 SB.CCM : SDP Offer = 0x5220a910, (10.0.0.103:16430)

04:23:13.160 SB.CCM : SDP Answer = 0x521aef10, (127.0.0.3:12624)

04:23:13.160 SB.CCM : Offer side SRTP session details

04:23:13.160 SB.CCM : None

04:23:13.161 SB.CCM : Answer side SRTP session details

04:23:13.161 SB.CCM : None

04:23:13.161 SB.CCM : RTP Channel = 0/1.1

04:23:13.161 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

04:23:13.161 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

04:23:13.161 SB.CCM isResponseMappable: Modifying SDP Answer

04:23:13.162 SB.CCM translateAnswer: offer codec list: PCMU G729

04:23:13.162 SB.CCM : answer codec list: PCMU G729

04:23:13.163 SB.CCM translateAnswer: CODEC transcoding is not required

04:23:13.163 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

04:23:13.164 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - offer

04:23:13.164 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:13.164 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedOffer

04:23:13.164 SRTP.SDES NEGOTIATION m=audio 16430 RTP/AVP 0 18 96

04:23:13.164 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer

04:23:13.164 SRTP.SDES NEGOTIATION m=audio 12624 RTP/AVP 0 96

04:23:13.165 ISDN.L2_MSG PRI 1 R 00 01 01 86

04:23:13.165 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after validator

04:23:13.165 SRTP.SDES NEGOTIATION m=audio 12624 RTP/AVP 0 96

04:23:13.165 SRTP.SDES NEGOTIATION invoked pass-through answer translation

04:23:13.165 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after translation

04:23:13.165 SRTP.SDES NEGOTIATION m=audio 12624 RTP/AVP 0 96

04:23:13.166 SB.CCM translateAnswer: success

04:23:13.166 MEDIA.MANAGER Allocating media port.

04:23:13.166 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9792 sessionId -1422332582INIP4127.0.0.3 remote port 12624

04:23:13.166 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:13.166 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12624)

04:23:13.166 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12624 and sub port 12624.

04:23:13.167 MEDIA.MANAGER Call ID map : Replacing with newer version : call ID 9792 : session -1422332582INIP4127.0.0.3 : version 3 : index 2624

04:23:13.167 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9792 : session -1422332582INIP4127.0.0.3 : IP 10.100.0.10 ports 12624 - 12625 : remote IP 127.0.0.3 ports 12624 - 12625.

04:23:13.167 SB.CALL 9792 PreConnected Connect sent from T01 to T03

04:23:13.167 SB.CALL 9792 State change >> PreConnected->Connecting

04:23:13.167 TA.T03 01 TAConnectWaitIn connect event accepted

04:23:13.168 TA.T03 01 State change >> TAConnectWaitIn->TAConnectPending (TAS_Connected)

04:23:13.168 TM.T03 01 SipTM_Preconnect tachg -> TAConnectPending

04:23:13.168 TM.T03 01 SipTM_Preconnect State change >> SipTM_Preconnect->SipTM_Accept

04:23:13.168 TM.T03 01 SDP DPI call ID 9792 : Media bin present.

04:23:13.168 TM.T03 01 Processing new SDP entries.

04:23:13.169 TM.T03 01 Checking for internal Media Gateway IP Address

04:23:13.169 TM.T03 01 Using RTP Channel 0/1.1

04:23:13.169 TM.T03 01 Inserting 10.100.0.10 into SDP for Media Gateway

04:23:13.169 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9792 sessionId -1422332582INIP4127.0.0.3 remote port 12624

04:23:13.169 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:13.169 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12624)

04:23:13.169 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12624 and sub port 12624.

04:23:13.170 MEDIA.MANAGER Call ID map : Received stale SDP - will ignore : call ID 9792 : session -1422332582INIP4127.0.0.3 : version 2

04:23:13.170 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9792 : session -1422332582INIP4127.0.0.3 : IP 10.100.0.10 ports 12624 - 12625 : remote IP 127.0.0.3 ports 12624 - 12625.

04:23:13.170 TM.T03 01 Adding RTP Media Gateway Entry: 127.0.0.3:12624 -> 10.100.0.10:12624

04:23:13.170 TM.T03 01 Allocating anchor ports 12624 and 12625 for interface 10.100.0.10

04:23:13.172 TM.T03 01 SipTM_Accept call-leg -> Accepted

04:23:13.173 TM.T03 01 SipTM_Accept sent: 200 with SDP

04:23:13.175 TM.T03 01 SipTM_Accept rcvd SIP call-leg request: ACK

04:23:13.176 TM.T03 01 SipTM_Accept call-leg -> Connected

04:23:13.176 TM.T03 01 SipTM_Accept No body in message when trying to get SDP

04:23:13.176 TM.T03 01 SipTM_Accept info: unable to save SDP

04:23:13.176 TM.T03 01 SipTM_Accept sent: TA->Connect

04:23:13.176 TM.T03 01 SipTM_Accept State change >> SipTM_Accept->SipTM_Connected

04:23:13.176 TM.T03 01 SipTM_Connected call-leg-mod -> Modify Idle

04:23:13.177 TA.T03 01 TAConnectPending rcvd: connect from TM

04:23:13.177 TA.T03 01 State change >> TAConnectPending->TAConnected (TAS_Connected)

04:23:13.177 SB.CALL 9792 Connecting Called the connectResponse routine

04:23:13.177 SB.CCM connect:

04:23:13.177 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:13.177 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:13.178 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:13.178 SB.CCM : SDP Transaction = CallID: 9792

04:23:13.178 SB.CCM : SDP Offer = 0x5220a910, (10.0.0.103:16430)

04:23:13.178 SB.CCM : SDP Answer = 0x521aef10, (127.0.0.3:12624)

04:23:13.178 SB.CCM : Offer side SRTP session details

04:23:13.179 SB.CCM : None

04:23:13.179 SB.CCM : Answer side SRTP session details

04:23:13.179 SB.CCM : None

04:23:13.179 SB.CCM : RTP Channel = 0/1.1

04:23:13.179 SB.CCM connect: Call Connection Type is RTP_TO_TDM

04:23:13.179 SB.CCM SDP offer is 10.0.0.103:16430, SDP answer is 127.0.0.3:12624

04:23:13.180 MEDIA.MANAGER Trying to connect call ID 9792 : SDP sessions -1454371118INIP410.0.0.103 and -1422332582INIP4127.0.0.3

04:23:13.180 MEDIA.MANAGER Found 1 ports for session -1454371118INIP410.0.0.103

04:23:13.180 MEDIA.MANAGER Found 1 ports for session -1422332582INIP4127.0.0.3

04:23:13.180 MEDIA.MANAGER Connecting DSP Local [::]:12622 : Remote 10.0.0.103:16430

04:23:13.180 MEDIA.MANAGER and DSP Local 10.100.0.10:12624 : Remote 127.0.0.3:12624

04:23:13.180 MEDIA.MANAGER Setting up DSP Media Connection 9792 for entry(type(3), callID(9792), sessionID(-1454371118INIP410.0.0.103), original IP(10.0.0.103) ports(16430-16431), substitute IP(::) ports(12622-12623), RtpChannel(0/1.1), connection(0x0x520cc210), sdpOverride(0), me(0x0x520cc710))

04:23:13.181 MEDIA.MANAGER Setting up DSP Media Connection 9792 for entry(type(3), callID(9792), sessionID(-1422332582INIP4127.0.0.3), original IP(127.0.0.3) ports(12624-12625), substitute IP(10.100.0.10) ports(12624-12625), RtpChannel(0/1.1), connection(0x0x52206510), sdpOverride(0), me(0x0x520b5410))

04:23:13.181 MEDIA.MANAGER Connection Fixup 1 DSP Port 12622

04:23:13.181 MEDIA.MANAGER Local [::]:12622 : Remote 10.0.0.103:16430

04:23:13.181 MEDIA.MANAGER Connection Fixup 2 DSP Port 12624

04:23:13.181 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 127.0.0.3:12624

04:23:13.182 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12622 sub [::]:12622 remote 10.0.0.103:16430

04:23:13.182 MEDIA.MANAGER : Other side : entry 12624 sub 10.100.0.10:12624 remote 127.0.0.3:12624

04:23:13.182 MEDIA.MANAGER Connection Fixup 1 DSP Port 12624

04:23:13.182 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 127.0.0.3:12624

04:23:13.182 MEDIA.MANAGER Connection Fixup 2 DSP Port 12622

04:23:13.182 MEDIA.MANAGER Local [::]:12622 : Remote 10.0.0.103:16430

04:23:13.182 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12624 remote from 127.0.0.3:12624 to 10.0.0.103:16430

04:23:13.183 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:13.183 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:13.183 MEDIA.MANAGER Connection Result 1 DSP Port 12624

04:23:13.183 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 10.0.0.103:16430

04:23:13.183 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:13.183 MEDIA.MANAGER connectionFixup success for port 12624 and 12622

04:23:13.183 MEDIA.MANAGER Marking setup complete for port 12624

04:23:13.183 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:13.184 MEDIA.MANAGER Marking setup complete for port 12622

04:23:13.184 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:13.184 MEDIA.MANAGER Connection Fixup 1 DSP Port 12623

04:23:13.184 MEDIA.MANAGER Local [::]:12623 : Remote 10.0.0.103:16431

04:23:13.184 MEDIA.MANAGER Connection Fixup 2 DSP Port 12625

04:23:13.184 MEDIA.MANAGER Local 10.100.0.10:12625 : Remote 127.0.0.3:12625

04:23:13.184 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12623 sub [::]:12623 remote 10.0.0.103:16431

04:23:13.184 MEDIA.MANAGER : Other side : entry 12625 sub 10.100.0.10:12625 remote 127.0.0.3:12625

04:23:13.185 MEDIA.MANAGER Connection Fixup 1 DSP Port 12625

04:23:13.185 MEDIA.MANAGER Local 10.100.0.10:12625 : Remote 127.0.0.3:12625

04:23:13.185 MEDIA.MANAGER Connection Fixup 2 DSP Port 12623

04:23:13.185 MEDIA.MANAGER Local [::]:12623 : Remote 10.0.0.103:16431

04:23:13.185 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12625 remote from 127.0.0.3:12625 to 10.0.0.103:16431

04:23:13.185 MEDIA.MANAGER Connection Result 1 DSP Port 12625

04:23:13.185 MEDIA.MANAGER Local 10.100.0.10:12625 : Remote 10.0.0.103:16431

04:23:13.185 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:13.186 MEDIA.MANAGER connectionFixup success for port 12625 and 12623

04:23:13.186 MEDIA.MANAGER Marking setup complete for port 12625

04:23:13.186 MEDIA.MANAGER Marking setup complete for port 12623

04:23:13.186 MEDIA.MANAGER Connected DSP Port 12624

04:23:13.186 MEDIA.MANAGER Local 10.100.0.10:12624 : Remote 10.0.0.103:16430

04:23:13.186 MEDIA.MANAGER Connected associations Entry not activated

04:23:13.186 SB.CCM connect: Connected RTP/TDM via MCM

04:23:13.187 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:13.187 SB.CCM setupRtpChannel, source 2, silence 0

04:23:13.187 SB.CCM setupRtpChannel: setup using media connection

04:23:13.187 SB.CCM Looking up source address for destination 10.0.0.103

04:23:13.187 SB.CCM setupRtpChannel: Source IP addr = 10.100.0.10, port = 12624

04:23:13.187 SB.CCM setupRtpChannel: Target IP addr = 10.0.0.103, port = 16430

04:23:13.188 SB.CCM setupRtpChannel: Undo of previous operation not required

04:23:13.188 SB.CCM getFinalCodec: PCMU

04:23:13.189 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.100.0.10:12624 Trg 10.0.0.103:16430 via PCMU Rx PCMU G729

04:23:13.189 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=96/96 dscp=46 vad=off isOffer no

04:23:13.189 SB.CCM setupRtpChannel: No changes needed to RTP Channel

04:23:13.189 SB.CCM firewallConnectCall: Set up firewall from media connections

04:23:13.189 SB.CCM sdpFirewall: invoked with offer - 10.0.0.103:16430, answer - 10.100.0.10:12624

04:23:13.190 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

04:23:13.190 SB.CCM connect: TDM streams: port(SipTrunk 0/1.1) to port(Isdn(Ds1Ds0Trunk) 0/1.23)

04:23:13.191 SB.CALL 9792 Connecting ConnectResponse sent from T03 to T01

04:23:13.191 TA.T01 23 TAConnectWaitOut connectResponse event accepted

04:23:13.191 TA.T01 23 State change >> TAConnectWaitOut->TAConnected (TAS_Connected)

04:23:13.191 TM.T01 23 IsdnTmStateOutboundConnecting->IsdnTmStateOutboundConnected

04:23:13.191 TM.T01 23 IsdnTmStateOutboundConnected::enter()

04:23:13.191 TM.T01 23 sent: finalizeConnect to TA

04:23:13.192 TA.T01 23 TAConnected rcvd: finalizeConnect from TM

04:23:13.192 TA.T01 23 TAConnected forwarding finalizeConnect from TM

04:23:13.192 TA.T01 23 TAConnected sent finalizeConnect to SB

04:23:13.192 SB.CALL 9792 Connecting Called the finalizeConnect routine

04:23:13.192 SB.CCM finalizeConnect: connection already finalized(3)

04:23:13.192 SB.CALL 9792 State change >> Connecting->Connected

04:23:15.653 TM.T03 01 SipTM_Connected rcvd SIP call-leg request: BYE

04:23:15.653 TM.T03 01 SipTM_Connected call-leg -> Disconnected

04:23:15.653 TM.T03 01 SipTM_Connected CallLegStateChanged to Disconnected - TM change to closing state.

04:23:15.653 TM.T03 01 SipTM_Connected State change >> SipTM_Connected->SipTM_Closing

04:23:15.653 TM.T03 01 SipTM_Closing sent: TA->Clear

04:23:15.655 TM.T03 01 SipTM_Closing call-leg -> Terminated

04:23:15.655 TA.T03 01 TAConnected rcvd: clear from TM

04:23:15.655 TA.T03 01 State change >> TAConnected->TATrunkClearing (TAS_Clearing)

04:23:15.655 TM.T03 01 SipTM_Closing tachg -> TATrunkClearing

04:23:15.656 TM.T03 01 SipTM_Closing State change >> SipTM_Closing->SipTM_Terminated

04:23:15.656 TM.T03 01 SipTM_Terminated sent: TA->AppearanceOff

04:23:15.656 TM.T03 01 SipTM_Terminated State change >> SipTM_Terminated->SipTM_Idle

04:23:15.656 SB.CALL 9792 Connected Called the clearCall routine

04:23:15.656 SB.CALL 9792 Connected ClearCall sent from T03 to T01

04:23:15.656 SB.CALL 9792 State change >> Connected->Clearing

04:23:15.657 TA.T03 01 TATrunkClearing rcvd: appearance off from TM

04:23:15.657 TA.T03 01 State change >> TATrunkClearing->TAClearingComplete (TAS_Clearing)

04:23:15.657 TA.T03 01 TATrunkClearing Processing an appearance OFF

04:23:15.657 TA.T01 23 TAConnected ClearCall event accepted

04:23:15.657 TA.T01 23 State change >> TAConnected->TAClearingComplete (TAS_Clearing)

04:23:15.657 TM.T01 23 IsdnTmStateOutboundConnected->IsdnTmStateUserClearing

04:23:15.657 TM.T01 23 IsdnTmStateUserClearing::enter()

04:23:15.658 ISDN.L2_MSG PRI 1 T 00 01 86 7C 08 02 17 34 45 08 02 80 90

04:23:15.658 SB.CALL 9792 Clearing Called the clearResponse routine

04:23:15.659 SB.CALL 9792 State change >> Clearing->CallIdlePending

04:23:15.659 SB.CCM disconnect:

04:23:15.659 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:15.659 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:15.659 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:15.660 SB.CCM : Offer side SRTP session details

04:23:15.660 SB.CCM : None

04:23:15.660 SB.CCM : Answer side SRTP session details

04:23:15.660 SB.CCM : None

04:23:15.660 SB.CCM : RTP Channel = 0/1.1

04:23:15.660 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

04:23:15.660 SB.CCM disconnect: Stopping RTP Channel 0/1.1

04:23:15.661 RTP.CHANNEL Channel 0/1.1 stopped successfully.

04:23:15.661 SB.CCM disconnect: Disconnecting TDM streams

04:23:15.661 SB.CCM release:

04:23:15.662 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9792

04:23:15.662 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:15.662 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:15.662 SB.CCM : Offer side SRTP session details

04:23:15.662 SB.CCM : None

04:23:15.662 SB.CCM : Answer side SRTP session details

04:23:15.662 SB.CCM : None

04:23:15.663 SB.CCM : RTP Channel = 0/1.1

04:23:15.663 SB.CCM release: Call Connection Type is RTP_TO_TDM

04:23:15.663 SB.CCM release: Releasing RTP Channel 0/1.1

04:23:15.663 RTP.CHANNEL Channel 0/1.1 released successfully.

04:23:15.664 SB.CALL 9792 CallIdlePending ClearResponse sent from T01 to T03

04:23:15.664 TONESERVICES.EVENTS t1 0/1.23 - empty - FastBusy Generation: Request resource

04:23:15.664 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: DSP channel allocated for the resource

04:23:15.664 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: constructed

04:23:15.664 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: starting

04:23:15.665 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: TDM map

04:23:15.665 ISDN.L2_MSG PRI 1 R 00 01 01 88

04:23:15.665 TA.T03 01 TAClearingComplete clearResponse event accepted

04:23:15.665 TA.T03 01 TAClearingComplete Clear Local Variables

04:23:15.665 TA.T03 01 State change >> TAClearingComplete->TAIdle (TAS_Idle)

04:23:15.666 TM.T03 01 SipTM_Idle tachg -> TAIdle

04:23:15.666 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: stopping

04:23:15.666 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: releasing RTP resource

04:23:15.666 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: releasing

04:23:15.680 ISDN.L2_MSG PRI 1 R 02 01 7C 88 08 02 97 34 4D

04:23:15.680 ISDN.L2_MSG PRI 1 T 02 01 01 7E

04:23:15.681 ISDN.L2_MSG PRI 1 T 00 01 88 7E 08 02 17 34 5A

04:23:15.681 TM.T01 23 IsdnTmStateUserClearing->IsdnTmStateIdling

04:23:15.681 TM.T01 23 IsdnTmStateIdling::enter()

04:23:15.681 TM.T01 23 IsdnTmStateIdling - send appearance off

04:23:15.682 TM.T01 23 IsdnTmStateIdling->IsdnTmStateIdle

04:23:15.682 TM.T01 23 IsdnAppearanceChannel::releaseChannel

04:23:15.682 TM.T01 23 IsdnTmStateIdle::enter()

04:23:15.682 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: stopping

04:23:15.682 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: TDM unmap

04:23:15.683 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: releasing RTP resource

04:23:15.683 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: release

04:23:15.683 TA.T01 23 TAClearingComplete rcvd: appearance off from TM

04:23:15.683 TA.T01 23 TAClearingComplete Clear Local Variables

04:23:15.683 TA.T01 23 State change >> TAClearingComplete->TAIdle (TAS_Idle)

04:23:15.687 ISDN.L2_MSG PRI 1 R 00 01 01 8A

2015.01.27 04:23:16 SMDR 9792 01/27/2015 04:23:02 0.2 0 E 00/01 Constructure Te 6313967777 00/01 T01 15169716561 0 N

04:23:17.727 MEDIA.MANAGER Remove Call ID map entry for call 9792

04:23:24.418 TM.T03 01 SipTM_Idle rcvd SIP call-leg request: INVITE

04:23:24.418 TM.T03 01 SipTM_Idle call-leg -> Offering

04:23:24.418 TM.T03 01 SipTM_Idle State change >> SipTM_Idle->SipTM_Trying

04:23:24.419 TM.T03 01 SipTM_Trying SDP offer is not loopback request

04:23:24.419 TM.T03 01 SipTM_Trying Processing From for Caller-ID.

04:23:24.420 TM.T03 01 SipTM_Trying Caller ID Name = "Constructure Technologies"

04:23:24.420 TM.T03 01 SipTM_Trying Caller ID Number = "6313967777"

04:23:24.420 TM.T03 01 SipTM_Trying info: unable to set redirect number(s) from INVITE

04:23:24.420 TM.T03 01 SipTM_Trying sent: TA->InboundCall

04:23:24.421 TM.T03 01 Looking up source address for destination 10.0.0.254

04:23:24.421 TM.T03 01 call-leg (0x0x4d16afc8) -> src: 10.100.0.10 : 5060 dst: 10.0.0.254 : 5060

04:23:24.422 TM.T03 01 SipTM_Trying sent: 100 Trying

04:23:24.422 TA.T03 01 TAIdle rcvd: inboundCall from TM

04:23:24.423 TA.T03 01 State change >> TAIdle->TAInboundCall (TAS_Calling)

04:23:24.423 TA.T03 01 Failed - DID translation: no match for 15169716561, using 15169716561

04:23:24.423 TA.T03 01 TAIdle sent: call to SB

04:23:24.423 TM.T03 01 SipTM_Trying tachg -> TAInboundCall

04:23:24.424 TM.T03 01 SipTM_Trying State change >> SipTM_Trying->SipTM_Pending

04:23:24.424 SB.CALL 9793 Idle Called the call routine with 15169716561

04:23:24 SB.TGMgr For dialed number 15169716561, against template 1-NXX-NXX-XXXX, on TrunkGroup PRI, the score is 2000

04:23:24.425 SB.CCM isMappable:

04:23:24.425 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:24.425 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:24.425 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = unknown 0/0

04:23:24.426 SB.CCM : SDP Transaction = CallID: 9793

04:23:24.426 SB.CCM : SDP Offer = 0x521eec10, (10.0.0.103:16434)

04:23:24.426 SB.CCM isMappable: Call Connection Type is RTP_TO_TDM

04:23:24.426 SB.CCM isMappable: Reserving RTP Channel 0/1.1

04:23:24.427 SB.CCM translateOffer: offer codec list: PCMU G729

04:23:24.427 SB.CCM translateOffer: revised offer codec list: PCMU G729

04:23:24.428 SB.CCM translateOffer: codec list after answerer: PCMU G729

04:23:24.429 SB.CCM translateOffer: DTMF signaling: answerer has no restrictions configured, passing offer(NTE 96) through

04:23:24.429 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP before offer filter

04:23:24.429 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:24.429 SRTP.SDES NEGOTIATION invoked pass-through SRTP filter

04:23:24.430 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP after offer filter

04:23:24.430 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:24.430 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP after offer translator

04:23:24.430 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:24.430 SB.CCM translateOffer: success

04:23:24.431 MEDIA.MANAGER Allocating media port.

04:23:24.431 MEDIA.MANAGER getSubstitutePort: No matching callIdMap entry found for call 9793

04:23:24.431 MEDIA.MANAGER Call ID map : Added new entry : call ID 9793 : session -1454371140INIP410.0.0.103 : version 1454371141 : index 2626

04:23:24.431 MEDIA.MANAGER New media entry : type(0), callID(9793), sessionID(-1454371140INIP410.0.0.103), original IP(10.0.0.103) ports(16434-16435), substitute IP(::) ports(12626-12627), RtpChannel(0/1.1), connection(0x0x52051c10), sdpOverride(0), me(0x0x521ef810). RtpChannel 0/1.1

04:23:24.431 SB.CALL 9793 Idle Call sent from T03 to T01 (15169716561)

04:23:24.432 SB.CALL 9793 State change >> Idle->Delivering

04:23:24.432 RTP.MANAGER Isdn(Group) 0/ - empty - RTP: Reserve resource

04:23:24.432 RTP.MANAGER Isdn(Group) 0/ - Dsp 0/1.1 - RTP:

04:23:24.432 RTP.PROVIDER unknown - Dsp 0/1.1 - RTP: reserving already allocated RTP channel

04:23:24.432 TA.T03 01 TAInboundCall CallResp event accepted

04:23:24.432 TA.T03 01 State change >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

04:23:24.433 TA.T01 23 State change >> TAIdle->TAOutGoing (TAS_Delivering)

04:23:24.433 TM.T01 23 tachg_Delivering

04:23:24.433 TM.T01 23 IsdnTmStateIdle->IsdnTmStateOutboundDeliver

04:23:24.433 TM.T01 23 IsdnTmStateOutboundDeliver::enter()

04:23:24.434 ISDN.L2_MSG PRI 1 T 00 01 8A 7E 08 02 17 35 05 04 03 80 90 A2

04:23:24.434 ISDN.L2_MSG PRI 1 18 03 A1 83 97 1C 1D 9F 8B 01 00 A1 17 02

04:23:24.434 ISDN.L2_MSG PRI 1 01 01 02 01 00 80 0F 43 6F 6E 73 74 72 75

04:23:24.434 ISDN.L2_MSG PRI 1 63 74 75 72 65 20 54 65 6C 0C 00 80 36 33

04:23:24.434 ISDN.L2_MSG PRI 1 31 33 39 36 37 37 37 37 70 0C 80 31 35 31

04:23:24.434 ISDN.L2_MSG PRI 1 36 39 37 31 36 35 36 31

04:23:24.434 SB.CALL 9793 Delivering Called the deliverResponse routine from Delivering

04:23:24.435 SB.CALL 9793 Delivering DeliverResponse(accept) sent from T01 to T03

04:23:24.435 TA.T03 01 TAConnectWaitIn deliverResponse event accepted

04:23:24.435 TA.T03 01 TAConnectWaitIn ERROR! deliverResponse ignored

04:23:24.449 ISDN.L2_MSG PRI 1 R 00 01 01 8C

04:23:24.609 ISDN.L2_MSG PRI 1 R 02 01 7E 8C 08 02 97 35 02 18 03 A9 83 97

04:23:24.609 ISDN.L2_MSG PRI 1 T 02 01 01 80

04:23:25.027 ISDN.L2_MSG PRI 1 R 02 01 80 8C 08 02 97 35 01 1E 02 84 88

04:23:25.028 ISDN.L2_MSG PRI 1 T 02 01 01 82

04:23:25.028 TM.T01 23 IsdnTmStateOutboundDeliver->IsdnTmStateOutboundPreconnect

04:23:25.028 TM.T01 23 IsdnTmStateOutboundPreconnect::enter()

04:23:25.028 TA.T01 23 TAOutGoing rcvd: preConnect from TM

04:23:25.028 SB.CCM isResponseMappable:

04:23:25.029 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:25.029 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:25.029 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:25.029 SB.CCM : SDP Transaction = CallID: 9793

04:23:25.029 SB.CCM : SDP Offer = 0x521eec10, (10.0.0.103:16434)

04:23:25.029 SB.CCM : Offer side SRTP session details

04:23:25.030 SB.CCM : None

04:23:25.030 SB.CCM : Answer side SRTP session details

04:23:25.030 SB.CCM : None

04:23:25.030 SB.CCM : RTP Channel = 0/1.1

04:23:25.030 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

04:23:25.030 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

04:23:25.030 SB.CCM isResponseMappable: Creating SDP Answer based on SDP Offer

04:23:25.031 SB.CCM createAnswer: creating SDP answer using RTP channel 0/1.1

04:23:25.031 SB.CCM createAnswer : offer codec list: PCMU G729

04:23:25.031 SB.CCM : answer codec list: PCMU G729

04:23:25.033 SB.CCM createAnswer : result codec list: PCMU G729

04:23:25.033 SB.CCM createAnswer : final DTMF signaling(NTE 96)

04:23:25.033 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9793 sessionId -1454371140INIP410.0.0.103 remote port 16434

04:23:25.033 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:25.033 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12626)

04:23:25.034 SB.CCM updateMediaEntryForReinviteWithSameSdp : no associated port found for port (12626)

04:23:25.034 SB.CCM translateAnswer: offer codec list: PCMU G729

04:23:25.035 SB.CCM : answer codec list: PCMU G729

04:23:25.035 SB.CCM translateAnswer: CODEC transcoding is not required

04:23:25.035 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

04:23:25.036 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - offer

04:23:25.036 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:25.036 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedOffer

04:23:25.036 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:25.036 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer

04:23:25.036 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:23:25.037 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after validator

04:23:25.037 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:23:25.037 SRTP.SDES NEGOTIATION invoked pass-through answer translation

04:23:25.037 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after translation

04:23:25.037 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:23:25.037 SB.CCM translateAnswer: success

04:23:25.038 MEDIA.MANAGER Allocating media port.

04:23:25.038 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9793 sessionId -1422332605INIP4127.0.0.3 remote port 0

04:23:25.038 MEDIA.MANAGER Call ID map : Added new session ID : call ID 9793 : session -1422332605INIP4127.0.0.3 : version 2 : index 2628

04:23:25.038 MEDIA.MANAGER New media entry : type(0), callID(9793), sessionID(-1422332605INIP4127.0.0.3), original IP(127.0.0.3) ports(12628-12629), substitute IP(::) ports(12628-12629), RtpChannel(0/1.1), connection(0x0x521d3e10), sdpOverride(0), me(0x0x521c2510). RtpChannel 0/1.1

04:23:25.039 SB.CALL 9793 Delivering Sent preConnect from T01 to T03

04:23:25.039 SB.CALL 9793 State change >> Delivering->PreConnecting

04:23:25.039 TA.T03 01 TAConnectWaitIn preConnect event accepted

04:23:25.039 TM.T03 01 SipTM_Pending tachg -> TAConnectWaitIn

04:23:25.039 TM.T03 01 SipTM_Pending sent: TA->PreConnect Response

04:23:25.039 TM.T03 01 SipTM_Pending State change >> SipTM_Pending->SipTM_Preconnect

04:23:25.040 TM.T03 01 SDP DPI call ID 9793 : No media bin.

04:23:25.040 TM.T03 01 Processing new SDP entries.

04:23:25.040 TM.T03 01 Checking for internal Media Gateway IP Address

04:23:25.040 TM.T03 01 Using RTP Channel 0/1.1

04:23:25.040 TM.T03 01 Inserting 10.100.0.10 into SDP for Media Gateway

04:23:25.041 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9793 sessionId -1422332605INIP4127.0.0.3 remote port 12628

04:23:25.041 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:25.041 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12628)

04:23:25.041 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12628 and sub port 12628.

04:23:25.041 MEDIA.MANAGER Call ID map : Received stale SDP - will ignore : call ID 9793 : session -1422332605INIP4127.0.0.3 : version 1

04:23:25.041 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9793 : session -1422332605INIP4127.0.0.3 : IP 10.100.0.10 ports 12628 - 12629 : remote IP 127.0.0.3 ports 12628 - 12629.

04:23:25.041 TM.T03 01 Adding RTP Media Gateway Entry: 127.0.0.3:12628 -> 10.100.0.10:12628

04:23:25.042 TM.T03 01 Allocating anchor ports 12628 and 12629 for interface 10.100.0.10

04:23:25.043 TM.T03 01 SipTM_Preconnect sent: 183 Session Progress

04:23:25.044 TA.T03 01 TAConnectWaitIn rcvd: preConnectResponse from TM

04:23:25.044 SB.CCM connect:

04:23:25.044 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:25.044 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:25.044 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:25.045 SB.CCM : SDP Transaction = CallID: 9793

04:23:25.045 SB.CCM : SDP Offer = 0x521eec10, (10.0.0.103:16434)

04:23:25.045 SB.CCM : SDP Answer = 0x521ef510, (127.0.0.3:12628)

04:23:25.045 SB.CCM : Offer side SRTP session details

04:23:25.045 SB.CCM : None

04:23:25.045 SB.CCM : Answer side SRTP session details

04:23:25.046 SB.CCM : None

04:23:25.046 SB.CCM : RTP Channel = 0/1.1

04:23:25.046 SB.CCM connect: Call Connection Type is RTP_TO_TDM

04:23:25.046 SB.CCM call rtpChannel->allocateForInterface

04:23:25.046 SB.CCM SDP offer is 10.0.0.103:16434, SDP answer is 127.0.0.3:12628

04:23:25.047 MEDIA.MANAGER Trying to connect call ID 9793 : SDP sessions -1454371140INIP410.0.0.103 and -1422332605INIP4127.0.0.3

04:23:25.047 MEDIA.MANAGER Found 1 ports for session -1454371140INIP410.0.0.103

04:23:25.047 MEDIA.MANAGER Found 1 ports for session -1422332605INIP4127.0.0.3

04:23:25.047 MEDIA.MANAGER Connecting Disconnected Local [::]:12626 : Remote 10.0.0.103:16434

04:23:25.047 MEDIA.MANAGER and Disconnected Local 10.100.0.10:12628 : Remote 127.0.0.3:12628

04:23:25.047 MEDIA.MANAGER Setting up DSP Media Connection 9793 for entry(type(0), callID(9793), sessionID(-1454371140INIP410.0.0.103), original IP(10.0.0.103) ports(16434-16435), substitute IP(::) ports(12626-12627), RtpChannel(0/1.1), connection(0x0x52051c10), sdpOverride(0), me(0x0x521ef810))

04:23:25.048 MEDIA.MANAGER Setting up DSP Media Connection 9793 for entry(type(0), callID(9793), sessionID(-1422332605INIP4127.0.0.3), original IP(127.0.0.3) ports(12628-12629), substitute IP(10.100.0.10) ports(12628-12629), RtpChannel(0/1.1), connection(0x0x521d3e10), sdpOverride(0), me(0x0x521c2510))

04:23:25.048 MEDIA.MANAGER Connection Fixup 1 DSP Port 12626

04:23:25.048 MEDIA.MANAGER Local [::]:12626 : Remote 10.0.0.103:16434

04:23:25.048 MEDIA.MANAGER Connection Fixup 2 DSP Port 12628

04:23:25.048 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 127.0.0.3:12628

04:23:25.048 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12626 sub [::]:12626 remote 10.0.0.103:16434

04:23:25.048 MEDIA.MANAGER : Other side : entry 12628 sub 10.100.0.10:12628 remote 127.0.0.3:12628

04:23:25.048 MEDIA.MANAGER Connection Fixup 1 DSP Port 12628

04:23:25.049 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 127.0.0.3:12628

04:23:25.049 MEDIA.MANAGER Connection Fixup 2 DSP Port 12626

04:23:25.049 MEDIA.MANAGER Local [::]:12626 : Remote 10.0.0.103:16434

04:23:25.049 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12628 remote from 127.0.0.3:12628 to 10.0.0.103:16434

04:23:25.049 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:25.049 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:25.050 MEDIA.MANAGER Connection Result 1 DSP Port 12628

04:23:25.050 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 10.0.0.103:16434

04:23:25.050 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:25.050 MEDIA.MANAGER connectionFixup success for port 12628 and 12626

04:23:25.050 MEDIA.MANAGER Marking setup complete for port 12628

04:23:25.050 MEDIA.MANAGER Marking setup complete for port 12626

04:23:25.050 MEDIA.MANAGER Connection Fixup 1 DSP Port 12627

04:23:25.051 MEDIA.MANAGER Local [::]:12627 : Remote 10.0.0.103:16435

04:23:25.051 MEDIA.MANAGER Connection Fixup 2 DSP Port 12629

04:23:25.051 MEDIA.MANAGER Local 10.100.0.10:12629 : Remote 127.0.0.3:12629

04:23:25.051 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12627 sub [::]:12627 remote 10.0.0.103:16435

04:23:25.051 MEDIA.MANAGER : Other side : entry 12629 sub 10.100.0.10:12629 remote 127.0.0.3:12629

04:23:25.051 MEDIA.MANAGER Connection Fixup 1 DSP Port 12629

04:23:25.051 MEDIA.MANAGER Local 10.100.0.10:12629 : Remote 127.0.0.3:12629

04:23:25.051 MEDIA.MANAGER Connection Fixup 2 DSP Port 12627

04:23:25.052 MEDIA.MANAGER Local [::]:12627 : Remote 10.0.0.103:16435

04:23:25.052 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12629 remote from 127.0.0.3:12629 to 10.0.0.103:16435

04:23:25.052 MEDIA.MANAGER Connection Result 1 DSP Port 12629

04:23:25.052 MEDIA.MANAGER Local 10.100.0.10:12629 : Remote 10.0.0.103:16435

04:23:25.052 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:25.052 MEDIA.MANAGER connectionFixup success for port 12629 and 12627

04:23:25.052 MEDIA.MANAGER Marking setup complete for port 12629

04:23:25.052 MEDIA.MANAGER Marking setup complete for port 12627

04:23:25.053 MEDIA.MANAGER Connected DSP Port 12628

04:23:25.053 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 10.0.0.103:16434

04:23:25.053 MEDIA.MANAGER Connected associations Entry not activated

04:23:25.053 SB.CCM connect: Connected RTP/TDM via MCM

04:23:25.053 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:25.053 SB.CCM setupRtpChannel, source 1, silence 0

04:23:25.054 SB.CCM setupRtpChannel: setup using media connection

04:23:25.054 SB.CCM Looking up source address for destination 10.0.0.103

04:23:25.054 SB.CCM setupRtpChannel: Source IP addr = 10.100.0.10, port = 12628

04:23:25.054 SB.CCM setupRtpChannel: Target IP addr = 10.0.0.103, port = 16434

04:23:25.054 SB.CCM setupRtpChannel: Undo of previous operation not required

04:23:25.055 SB.CCM getFinalCodec: PCMU

04:23:25.056 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.100.0.10:12628 Trg 10.0.0.103:16434 via PCMU Rx PCMU G729

04:23:25.056 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=96/96 dscp=46 vad=off isOffer no

04:23:25.056 SB.CCM setupRtpChannel: Starting RTP Channel

04:23:25.056 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

04:23:25.056 RTP.CHANNEL Channel 0/1.1 started successfully.

04:23:25.056 SB.CCM firewallConnectCall: Set up firewall from media connections

04:23:25.057 SB.CCM sdpFirewall: invoked with offer - 10.0.0.103:16434, answer - 10.100.0.10:12628

04:23:25.057 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

04:23:25.057 SB.CCM connect: TDM streams: port(SipTrunk 0/1.1) to port(Isdn(Ds1Ds0Trunk) 0/1.23)

04:23:25.058 SB.CALL 9793 State change >> PreConnecting->PreConnected

04:23:25.058 SB.CALL 9793 PreConnected Call PreConnecting from T03 to T01

04:23:25.058 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: starting

04:23:25.058 TA.T01 ERROR! preConnectResponse ignored

04:23:31.959 ISDN.L2_MSG PRI 1 R 02 01 82 8C 08 02 97 35 07 1E 02 84 82

04:23:31.960 ISDN.L2_MSG PRI 1 T 02 01 01 84

04:23:31.960 ISDN.L2_MSG PRI 1 T 00 01 8C 84 08 02 17 35 0F

04:23:31.960 TM.T01 23 IsdnTmStateOutboundPreconnect->IsdnTmStateOutboundConnecting

04:23:31.960 TM.T01 23 IsdnTmStateOutboundConnecting::enter()

04:23:31.960 TA.T01 23 TAOutGoing rcvd: connect from TM

04:23:31.961 TA.T01 23 State change >> TAOutGoing->TAConnectWaitOut (TAS_Delivering)

04:23:31.961 SB.CALL 9793 PreConnected Called the connect routine

04:23:31.961 SB.CCM isResponseMappable:

04:23:31.961 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:31.961 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:31.961 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:31.962 SB.CCM : SDP Transaction = CallID: 9793

04:23:31.962 SB.CCM : SDP Offer = 0x521eec10, (10.0.0.103:16434)

04:23:31.962 SB.CCM : SDP Answer = 0x521ef510, (127.0.0.3:12628)

04:23:31.962 SB.CCM : Offer side SRTP session details

04:23:31.962 SB.CCM : None

04:23:31.962 SB.CCM : Answer side SRTP session details

04:23:31.963 SB.CCM : None

04:23:31.963 SB.CCM : RTP Channel = 0/1.1

04:23:31.963 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

04:23:31.963 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

04:23:31.963 SB.CCM isResponseMappable: Modifying SDP Answer

04:23:31.964 SB.CCM translateAnswer: offer codec list: PCMU G729

04:23:31.964 SB.CCM : answer codec list: PCMU G729

04:23:31.964 SB.CCM translateAnswer: CODEC transcoding is not required

04:23:31.965 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

04:23:31.965 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - offer

04:23:31.965 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:31.966 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedOffer

04:23:31.966 SRTP.SDES NEGOTIATION m=audio 16434 RTP/AVP 0 18 96

04:23:31.966 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer

04:23:31.966 SRTP.SDES NEGOTIATION m=audio 12628 RTP/AVP 0 96

04:23:31.966 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after validator

04:23:31.967 ISDN.L2_MSG PRI 1 R 00 01 01 8E

04:23:31.966 SRTP.SDES NEGOTIATION m=audio 12628 RTP/AVP 0 96

04:23:31.967 SRTP.SDES NEGOTIATION invoked pass-through answer translation

04:23:31.967 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after translation

04:23:31.967 SRTP.SDES NEGOTIATION m=audio 12628 RTP/AVP 0 96

04:23:31.967 SB.CCM translateAnswer: success

04:23:31.967 MEDIA.MANAGER Allocating media port.

04:23:31.968 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9793 sessionId -1422332605INIP4127.0.0.3 remote port 12628

04:23:31.968 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:31.968 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12628)

04:23:31.968 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12628 and sub port 12628.

04:23:31.968 MEDIA.MANAGER Call ID map : Replacing with newer version : call ID 9793 : session -1422332605INIP4127.0.0.3 : version 3 : index 2628

04:23:31.968 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9793 : session -1422332605INIP4127.0.0.3 : IP 10.100.0.10 ports 12628 - 12629 : remote IP 127.0.0.3 ports 12628 - 12629.

04:23:31.968 SB.CALL 9793 PreConnected Connect sent from T01 to T03

04:23:31.969 SB.CALL 9793 State change >> PreConnected->Connecting

04:23:31.969 TA.T03 01 TAConnectWaitIn connect event accepted

04:23:31.969 TA.T03 01 State change >> TAConnectWaitIn->TAConnectPending (TAS_Connected)

04:23:31.969 TM.T03 01 SipTM_Preconnect tachg -> TAConnectPending

04:23:31.969 TM.T03 01 SipTM_Preconnect State change >> SipTM_Preconnect->SipTM_Accept

04:23:31.970 TM.T03 01 SDP DPI call ID 9793 : Media bin present.

04:23:31.970 TM.T03 01 Processing new SDP entries.

04:23:31.970 TM.T03 01 Checking for internal Media Gateway IP Address

04:23:31.970 TM.T03 01 Using RTP Channel 0/1.1

04:23:31.970 TM.T03 01 Inserting 10.100.0.10 into SDP for Media Gateway

04:23:31.971 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9793 sessionId -1422332605INIP4127.0.0.3 remote port 12628

04:23:31.971 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:23:31.971 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12628)

04:23:31.971 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12628 and sub port 12628.

04:23:31.971 MEDIA.MANAGER Call ID map : Received stale SDP - will ignore : call ID 9793 : session -1422332605INIP4127.0.0.3 : version 2

04:23:31.972 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9793 : session -1422332605INIP4127.0.0.3 : IP 10.100.0.10 ports 12628 - 12629 : remote IP 127.0.0.3 ports 12628 - 12629.

04:23:31.972 TM.T03 01 Adding RTP Media Gateway Entry: 127.0.0.3:12628 -> 10.100.0.10:12628

04:23:31.972 TM.T03 01 Allocating anchor ports 12628 and 12629 for interface 10.100.0.10

04:23:31.974 TM.T03 01 SipTM_Accept call-leg -> Accepted

04:23:31.974 TM.T03 01 SipTM_Accept sent: 200 with SDP

04:23:31.977 TM.T03 01 SipTM_Accept rcvd SIP call-leg request: ACK

04:23:31.977 TM.T03 01 SipTM_Accept call-leg -> Connected

04:23:31.977 TM.T03 01 SipTM_Accept No body in message when trying to get SDP

04:23:31.977 TM.T03 01 SipTM_Accept info: unable to save SDP

04:23:31.977 TM.T03 01 SipTM_Accept sent: TA->Connect

04:23:31.978 TM.T03 01 SipTM_Accept State change >> SipTM_Accept->SipTM_Connected

04:23:31.978 TM.T03 01 SipTM_Connected call-leg-mod -> Modify Idle

04:23:31.978 TA.T03 01 TAConnectPending rcvd: connect from TM

04:23:31.978 TA.T03 01 State change >> TAConnectPending->TAConnected (TAS_Connected)

04:23:31.978 SB.CALL 9793 Connecting Called the connectResponse routine

04:23:31.979 SB.CCM connect:

04:23:31.979 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:31.979 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:31.979 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:31.979 SB.CCM : SDP Transaction = CallID: 9793

04:23:31.980 SB.CCM : SDP Offer = 0x521eec10, (10.0.0.103:16434)

04:23:31.980 SB.CCM : SDP Answer = 0x521ef510, (127.0.0.3:12628)

04:23:31.980 SB.CCM : Offer side SRTP session details

04:23:31.980 SB.CCM : None

04:23:31.980 SB.CCM : Answer side SRTP session details

04:23:31.980 SB.CCM : None

04:23:31.981 SB.CCM : RTP Channel = 0/1.1

04:23:31.981 SB.CCM connect: Call Connection Type is RTP_TO_TDM

04:23:31.981 SB.CCM SDP offer is 10.0.0.103:16434, SDP answer is 127.0.0.3:12628

04:23:31.981 MEDIA.MANAGER Trying to connect call ID 9793 : SDP sessions -1454371140INIP410.0.0.103 and -1422332605INIP4127.0.0.3

04:23:31.981 MEDIA.MANAGER Found 1 ports for session -1454371140INIP410.0.0.103

04:23:31.981 MEDIA.MANAGER Found 1 ports for session -1422332605INIP4127.0.0.3

04:23:31.982 MEDIA.MANAGER Connecting DSP Local [::]:12626 : Remote 10.0.0.103:16434

04:23:31.982 MEDIA.MANAGER and DSP Local 10.100.0.10:12628 : Remote 127.0.0.3:12628

04:23:31.982 MEDIA.MANAGER Setting up DSP Media Connection 9793 for entry(type(3), callID(9793), sessionID(-1454371140INIP410.0.0.103), original IP(10.0.0.103) ports(16434-16435), substitute IP(::) ports(12626-12627), RtpChannel(0/1.1), connection(0x0x521ef910), sdpOverride(0), me(0x0x521ef810))

04:23:31.982 MEDIA.MANAGER Setting up DSP Media Connection 9793 for entry(type(3), callID(9793), sessionID(-1422332605INIP4127.0.0.3), original IP(127.0.0.3) ports(12628-12629), substitute IP(10.100.0.10) ports(12628-12629), RtpChannel(0/1.1), connection(0x0x521c6e10), sdpOverride(0), me(0x0x521c2510))

04:23:31.982 MEDIA.MANAGER Connection Fixup 1 DSP Port 12626

04:23:31.982 MEDIA.MANAGER Local [::]:12626 : Remote 10.0.0.103:16434

04:23:31.983 MEDIA.MANAGER Connection Fixup 2 DSP Port 12628

04:23:31.983 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 127.0.0.3:12628

04:23:31.983 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12626 sub [::]:12626 remote 10.0.0.103:16434

04:23:31.983 MEDIA.MANAGER : Other side : entry 12628 sub 10.100.0.10:12628 remote 127.0.0.3:12628

04:23:31.983 MEDIA.MANAGER Connection Fixup 1 DSP Port 12628

04:23:31.983 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 127.0.0.3:12628

04:23:31.983 MEDIA.MANAGER Connection Fixup 2 DSP Port 12626

04:23:31.984 MEDIA.MANAGER Local [::]:12626 : Remote 10.0.0.103:16434

04:23:31.984 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12628 remote from 127.0.0.3:12628 to 10.0.0.103:16434

04:23:31.984 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:31.984 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:31.984 MEDIA.MANAGER Connection Result 1 DSP Port 12628

04:23:31.984 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 10.0.0.103:16434

04:23:31.984 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:31.984 MEDIA.MANAGER connectionFixup success for port 12628 and 12626

04:23:31.985 MEDIA.MANAGER Marking setup complete for port 12628

04:23:31.985 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:31.985 MEDIA.MANAGER Marking setup complete for port 12626

04:23:31.985 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:23:31.985 MEDIA.MANAGER Connection Fixup 1 DSP Port 12627

04:23:31.985 MEDIA.MANAGER Local [::]:12627 : Remote 10.0.0.103:16435

04:23:31.986 MEDIA.MANAGER Connection Fixup 2 DSP Port 12629

04:23:31.986 MEDIA.MANAGER Local 10.100.0.10:12629 : Remote 127.0.0.3:12629

04:23:31.986 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12627 sub [::]:12627 remote 10.0.0.103:16435

04:23:31.986 MEDIA.MANAGER : Other side : entry 12629 sub 10.100.0.10:12629 remote 127.0.0.3:12629

04:23:31.986 MEDIA.MANAGER Connection Fixup 1 DSP Port 12629

04:23:31.986 MEDIA.MANAGER Local 10.100.0.10:12629 : Remote 127.0.0.3:12629

04:23:31.986 MEDIA.MANAGER Connection Fixup 2 DSP Port 12627

04:23:31.986 MEDIA.MANAGER Local [::]:12627 : Remote 10.0.0.103:16435

04:23:31.987 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12629 remote from 127.0.0.3:12629 to 10.0.0.103:16435

04:23:31.987 MEDIA.MANAGER Connection Result 1 DSP Port 12629

04:23:31.987 MEDIA.MANAGER Local 10.100.0.10:12629 : Remote 10.0.0.103:16435

04:23:31.987 MEDIA.MANAGER Connection Result 2 Entry not activated

04:23:31.987 MEDIA.MANAGER connectionFixup success for port 12629 and 12627

04:23:31.987 MEDIA.MANAGER Marking setup complete for port 12629

04:23:31.987 MEDIA.MANAGER Marking setup complete for port 12627

04:23:31.988 MEDIA.MANAGER Connected DSP Port 12628

04:23:31.988 MEDIA.MANAGER Local 10.100.0.10:12628 : Remote 10.0.0.103:16434

04:23:31.988 MEDIA.MANAGER Connected associations Entry not activated

04:23:31.988 SB.CCM connect: Connected RTP/TDM via MCM

04:23:31.988 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:23:31.988 SB.CCM setupRtpChannel, source 2, silence 0

04:23:31.989 SB.CCM setupRtpChannel: setup using media connection

04:23:31.989 SB.CCM Looking up source address for destination 10.0.0.103

04:23:31.989 SB.CCM setupRtpChannel: Source IP addr = 10.100.0.10, port = 12628

04:23:31.989 SB.CCM setupRtpChannel: Target IP addr = 10.0.0.103, port = 16434

04:23:31.989 SB.CCM setupRtpChannel: Undo of previous operation not required

04:23:31.990 SB.CCM getFinalCodec: PCMU

04:23:31.991 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.100.0.10:12628 Trg 10.0.0.103:16434 via PCMU Rx PCMU G729

04:23:31.991 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=96/96 dscp=46 vad=off isOffer no

04:23:31.991 SB.CCM setupRtpChannel: No changes needed to RTP Channel

04:23:31.991 SB.CCM firewallConnectCall: Set up firewall from media connections

04:23:31.992 SB.CCM sdpFirewall: invoked with offer - 10.0.0.103:16434, answer - 10.100.0.10:12628

04:23:31.992 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

04:23:31.992 SB.CCM connect: TDM streams: port(SipTrunk 0/1.1) to port(Isdn(Ds1Ds0Trunk) 0/1.23)

04:23:31.993 SB.CALL 9793 Connecting ConnectResponse sent from T03 to T01

04:23:31.993 TA.T01 23 TAConnectWaitOut connectResponse event accepted

04:23:31.993 TA.T01 23 State change >> TAConnectWaitOut->TAConnected (TAS_Connected)

04:23:31.993 TM.T01 23 IsdnTmStateOutboundConnecting->IsdnTmStateOutboundConnected

04:23:31.993 TM.T01 23 IsdnTmStateOutboundConnected::enter()

04:23:31.994 TM.T01 23 sent: finalizeConnect to TA

04:23:31.994 TA.T01 23 TAConnected rcvd: finalizeConnect from TM

04:23:31.994 TA.T01 23 TAConnected forwarding finalizeConnect from TM

04:23:31.994 TA.T01 23 TAConnected sent finalizeConnect to SB

04:23:31.994 SB.CALL 9793 Connecting Called the finalizeConnect routine

04:23:31.994 SB.CCM finalizeConnect: connection already finalized(3)

04:23:31.994 SB.CALL 9793 State change >> Connecting->Connected

04:23:37.924 TM.T03 01 SipTM_Connected rcvd SIP call-leg request: BYE

04:23:37.924 TM.T03 01 SipTM_Connected call-leg -> Disconnected

04:23:37.924 TM.T03 01 SipTM_Connected CallLegStateChanged to Disconnected - TM change to closing state.

04:23:37.924 TM.T03 01 SipTM_Connected State change >> SipTM_Connected->SipTM_Closing

04:23:37.924 TM.T03 01 SipTM_Closing sent: TA->Clear

04:23:37.926 TM.T03 01 SipTM_Closing call-leg -> Terminated

04:23:37.926 TA.T03 01 TAConnected rcvd: clear from TM

04:23:37.926 TA.T03 01 State change >> TAConnected->TATrunkClearing (TAS_Clearing)

04:23:37.926 TM.T03 01 SipTM_Closing tachg -> TATrunkClearing

04:23:37.926 TM.T03 01 SipTM_Closing State change >> SipTM_Closing->SipTM_Terminated

04:23:37.927 TM.T03 01 SipTM_Terminated sent: TA->AppearanceOff

04:23:37.927 TM.T03 01 SipTM_Terminated State change >> SipTM_Terminated->SipTM_Idle

04:23:37.927 SB.CALL 9793 Connected Called the clearCall routine

04:23:37.927 SB.CALL 9793 Connected ClearCall sent from T03 to T01

04:23:37.927 SB.CALL 9793 State change >> Connected->Clearing

04:23:37.927 TA.T03 01 TATrunkClearing rcvd: appearance off from TM

04:23:37.928 TA.T03 01 State change >> TATrunkClearing->TAClearingComplete (TAS_Clearing)

04:23:37.928 TA.T03 01 TATrunkClearing Processing an appearance OFF

04:23:37.928 TA.T01 23 TAConnected ClearCall event accepted

04:23:37.928 TA.T01 23 State change >> TAConnected->TAClearingComplete (TAS_Clearing)

04:23:37.928 TM.T01 23 IsdnTmStateOutboundConnected->IsdnTmStateUserClearing

04:23:37.928 TM.T01 23 IsdnTmStateUserClearing::enter()

04:23:37.929 ISDN.L2_MSG PRI 1 T 00 01 8E 84 08 02 17 35 45 08 02 80 90

04:23:37.929 SB.CALL 9793 Clearing Called the clearResponse routine

04:23:37.929 SB.CALL 9793 State change >> Clearing->CallIdlePending

04:23:37.930 SB.CCM disconnect:

04:23:37.930 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:37.930 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:37.930 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:37.930 SB.CCM : Offer side SRTP session details

04:23:37.931 SB.CCM : None

04:23:37.931 SB.CCM : Answer side SRTP session details

04:23:37.931 SB.CCM : None

04:23:37.931 SB.CCM : RTP Channel = 0/1.1

04:23:37.931 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

04:23:37.931 SB.CCM disconnect: Stopping RTP Channel 0/1.1

04:23:37.932 RTP.CHANNEL Channel 0/1.1 stopped successfully.

04:23:37.932 SB.CCM disconnect: Disconnecting TDM streams

04:23:37.932 SB.CCM release:

04:23:37.932 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9793

04:23:37.932 SB.CCM : Org Acct = T03 Dst Acct = T01

04:23:37.932 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:23:37.933 SB.CCM : Offer side SRTP session details

04:23:37.933 SB.CCM : None

04:23:37.933 SB.CCM : Answer side SRTP session details

04:23:37.933 SB.CCM : None

04:23:37.933 SB.CCM : RTP Channel = 0/1.1

04:23:37.934 SB.CCM release: Call Connection Type is RTP_TO_TDM

04:23:37.934 SB.CCM release: Releasing RTP Channel 0/1.1

04:23:37.934 RTP.CHANNEL Channel 0/1.1 released successfully.

04:23:37.934 SB.CALL 9793 CallIdlePending ClearResponse sent from T01 to T03

04:23:37.934 TONESERVICES.EVENTS t1 0/1.23 - empty - FastBusy Generation: Request resource

04:23:37.935 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: DSP channel allocated for the resource

04:23:37.935 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: constructed

04:23:37.935 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: starting

04:23:37.935 ISDN.L2_MSG PRI 1 R 00 01 01 90

04:23:37.935 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: TDM map

04:23:37.936 TA.T03 01 TAClearingComplete clearResponse event accepted

04:23:37.936 TA.T03 01 TAClearingComplete Clear Local Variables

04:23:37.936 TA.T03 01 State change >> TAClearingComplete->TAIdle (TAS_Idle)

04:23:37.936 TM.T03 01 SipTM_Idle tachg -> TAIdle

04:23:37.936 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: stopping

04:23:37.937 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: releasing RTP resource

04:23:37.937 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: releasing

04:23:37.962 ISDN.L2_MSG PRI 1 R 02 01 84 90 08 02 97 35 4D

04:23:37.963 ISDN.L2_MSG PRI 1 T 02 01 01 86

04:23:37.963 ISDN.L2_MSG PRI 1 T 00 01 90 86 08 02 17 35 5A

04:23:37.963 TM.T01 23 IsdnTmStateUserClearing->IsdnTmStateIdling

04:23:37.964 TM.T01 23 IsdnTmStateIdling::enter()

04:23:37.964 TM.T01 23 IsdnTmStateIdling - send appearance off

04:23:37.964 TM.T01 23 IsdnTmStateIdling->IsdnTmStateIdle

04:23:37.964 TM.T01 23 IsdnAppearanceChannel::releaseChannel

04:23:37.964 TM.T01 23 IsdnTmStateIdle::enter()

04:23:37.965 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: stopping

04:23:37.965 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: TDM unmap

04:23:37.965 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: releasing RTP resource

04:23:37.965 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: release

04:23:37.965 TA.T01 23 TAClearingComplete rcvd: appearance off from TM

04:23:37.966 TA.T01 23 TAClearingComplete Clear Local Variables

04:23:37.966 TA.T01 23 State change >> TAClearingComplete->TAIdle (TAS_Idle)

04:23:37.970 ISDN.L2_MSG PRI 1 R 00 01 01 92

2015.01.27 04:23:38 SMDR 9793 01/27/2015 04:23:24 0.2 0 E 00/01 Constructure Te 6313967777 00/01 T01 15169716561 0 N

04:23:40.756 MEDIA.MANAGER Remove Call ID map entry for call 9793

Debug from call setup to ATT subscriber (CALLER-ID NOT WORKING)

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

<SNIP>

04:25:14.047 ISDN.L2_MSG PRI 1 T 00 01 01 8D

04:25:14.052 ISDN.L2_MSG PRI 1 R 00 01 01 99

04:25:15.953 TM.T03 01 SipTM_Idle rcvd SIP call-leg request: INVITE

04:25:15.954 TM.T03 01 SipTM_Idle call-leg -> Offering

04:25:15.954 TM.T03 01 SipTM_Idle State change >> SipTM_Idle->SipTM_Trying

04:25:15.955 TM.T03 01 SipTM_Trying SDP offer is not loopback request

04:25:15.955 TM.T03 01 SipTM_Trying Processing From for Caller-ID.

04:25:15.955 TM.T03 01 SipTM_Trying Caller ID Name = "Constructure Technologies"

04:25:15.955 TM.T03 01 SipTM_Trying Caller ID Number = "6313967777"

04:25:15.956 TM.T03 01 SipTM_Trying info: unable to set redirect number(s) from INVITE

04:25:15.956 TM.T03 01 SipTM_Trying sent: TA->InboundCall

04:25:15.956 TM.T03 01 Looking up source address for destination 10.0.0.254

04:25:15.956 TM.T03 01 call-leg (0x0x4d169150) -> src: 10.100.0.10 : 5060 dst: 10.0.0.254 : 5060

04:25:15.957 TM.T03 01 SipTM_Trying sent: 100 Trying

04:25:15.958 TA.T03 01 TAIdle rcvd: inboundCall from TM

04:25:15.958 TA.T03 01 State change >> TAIdle->TAInboundCall (TAS_Calling)

04:25:15.958 TA.T03 01 Failed - DID translation: no match for 15165325445, using 15165325445

04:25:15.958 TA.T03 01 TAIdle sent: call to SB

04:25:15.958 TM.T03 01 SipTM_Trying tachg -> TAInboundCall

04:25:15.959 TM.T03 01 SipTM_Trying State change >> SipTM_Trying->SipTM_Pending

04:25:15.959 SB.CALL 9795 Idle Called the call routine with 15165325445

04:25:15 SB.TGMgr For dialed number 15165325445, against template 1-NXX-NXX-XXXX, on TrunkGroup PRI, the score is 2000

04:25:15.960 SB.CCM isMappable:

04:25:15.960 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:25:15.960 SB.CCM : Org Acct = T03 Dst Acct = T01

04:25:15.961 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = unknown 0/0

04:25:15.961 SB.CCM : SDP Transaction = CallID: 9795

04:25:15.961 SB.CCM : SDP Offer = 0x521cc310, (10.0.0.103:16442)

04:25:15.961 SB.CCM isMappable: Call Connection Type is RTP_TO_TDM

04:25:15.962 SB.CCM isMappable: Reserving RTP Channel 0/1.1

04:25:15.962 SB.CCM translateOffer: offer codec list: PCMU G729

04:25:15.963 SB.CCM translateOffer: revised offer codec list: PCMU G729

04:25:15.963 SB.CCM translateOffer: codec list after answerer: PCMU G729

04:25:15.964 SB.CCM translateOffer: DTMF signaling: answerer has no restrictions configured, passing offer(NTE 96) through

04:25:15.964 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP before offer filter

04:25:15.964 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:15.964 SRTP.SDES NEGOTIATION invoked pass-through SRTP filter

04:25:15.965 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP after offer filter

04:25:15.965 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:15.965 SRTP.SDES NEGOTIATION SrtpNegotiation - SDP after offer translator

04:25:15.965 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:15.965 SB.CCM translateOffer: success

04:25:15.966 MEDIA.MANAGER Allocating media port.

04:25:15.966 MEDIA.MANAGER getSubstitutePort: No matching callIdMap entry found for call 9795

04:25:15.966 MEDIA.MANAGER Call ID map : Added new entry : call ID 9795 : session -1454371252INIP410.0.0.103 : version 1454371253 : index 2634

04:25:15.966 MEDIA.MANAGER New media entry : type(0), callID(9795), sessionID(-1454371252INIP410.0.0.103), original IP(10.0.0.103) ports(16442-16443), substitute IP(::) ports(12634-12635), RtpChannel(0/1.1), connection(0x0x521d8e10), sdpOverride(0), me(0x0x520c8110). RtpChannel 0/1.1

04:25:15.966 SB.CALL 9795 Idle Call sent from T03 to T01 (15165325445)

04:25:15.967 SB.CALL 9795 State change >> Idle->Delivering

04:25:15.967 RTP.MANAGER Isdn(Group) 0/ - empty - RTP: Reserve resource

04:25:15.967 RTP.MANAGER Isdn(Group) 0/ - Dsp 0/1.1 - RTP:

04:25:15.967 RTP.PROVIDER unknown - Dsp 0/1.1 - RTP: reserving already allocated RTP channel

04:25:15.967 TA.T03 01 TAInboundCall CallResp event accepted

04:25:15.968 TA.T03 01 State change >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

04:25:15.968 TA.T01 23 State change >> TAIdle->TAOutGoing (TAS_Delivering)

04:25:15.968 TM.T01 23 tachg_Delivering

04:25:15.968 TM.T01 23 IsdnTmStateIdle->IsdnTmStateOutboundDeliver

04:25:15.968 TM.T01 23 IsdnTmStateOutboundDeliver::enter()

04:25:15.969 ISDN.L2_MSG PRI 1 T 00 01 98 8C 08 02 17 37 05 04 03 80 90 A2

04:25:15.969 ISDN.L2_MSG PRI 1 18 03 A1 83 97 1C 1D 9F 8B 01 00 A1 17 02

04:25:15.969 ISDN.L2_MSG PRI 1 01 01 02 01 00 80 0F 43 6F 6E 73 74 72 75

04:25:15.969 ISDN.L2_MSG PRI 1 63 74 75 72 65 20 54 65 6C 0C 00 80 36 33

04:25:15.969 ISDN.L2_MSG PRI 1 31 33 39 36 37 37 37 37 70 0C 80 31 35 31

04:25:15.970 ISDN.L2_MSG PRI 1 36 35 33 32 35 34 34 35

04:25:15.970 SB.CALL 9795 Delivering Called the deliverResponse routine from Delivering

04:25:15.970 SB.CALL 9795 Delivering DeliverResponse(accept) sent from T01 to T03

04:25:15.970 TA.T03 01 TAConnectWaitIn deliverResponse event accepted

04:25:15.970 TA.T03 01 TAConnectWaitIn ERROR! deliverResponse ignored

04:25:15.984 ISDN.L2_MSG PRI 1 R 00 01 01 9A

04:25:16.259 ISDN.L2_MSG PRI 1 R 02 01 8C 9A 08 02 97 37 02 18 03 A9 83 97

04:25:16.259 ISDN.L2_MSG PRI 1 T 02 01 01 8E

04:25:18.088 ISDN.L2_MSG PRI 1 R 02 01 8E 9A 08 02 97 37 03 1E 02 84 88

04:25:18.088 ISDN.L2_MSG PRI 1 T 02 01 01 90

04:25:18.089 TM.T01 23 IsdnTmStateOutboundDeliver->IsdnTmStateOutboundPreconnect

04:25:18.089 TM.T01 23 IsdnTmStateOutboundPreconnect::enter()

04:25:18.089 TA.T01 23 TAOutGoing rcvd: preConnect from TM

04:25:18.089 SB.CCM isResponseMappable:

04:25:18.089 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:25:18.089 SB.CCM : Org Acct = T03 Dst Acct = T01

04:25:18.089 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:25:18.090 SB.CCM : SDP Transaction = CallID: 9795

04:25:18.090 SB.CCM : SDP Offer = 0x521cc310, (10.0.0.103:16442)

04:25:18.090 SB.CCM : Offer side SRTP session details

04:25:18.090 SB.CCM : None

04:25:18.091 SB.CCM : Answer side SRTP session details

04:25:18.091 SB.CCM : None

04:25:18.091 SB.CCM : RTP Channel = 0/1.1

04:25:18.091 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

04:25:18.091 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

04:25:18.091 SB.CCM isResponseMappable: Creating SDP Answer based on SDP Offer

04:25:18.091 SB.CCM createAnswer: creating SDP answer using RTP channel 0/1.1

04:25:18.092 SB.CCM createAnswer : offer codec list: PCMU G729

04:25:18.092 SB.CCM : answer codec list: PCMU G729

04:25:18.093 SB.CCM createAnswer : result codec list: PCMU G729

04:25:18.094 SB.CCM createAnswer : final DTMF signaling(NTE 96)

04:25:18.094 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9795 sessionId -1454371252INIP410.0.0.103 remote port 16442

04:25:18.094 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:25:18.094 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12634)

04:25:18.094 SB.CCM updateMediaEntryForReinviteWithSameSdp : no associated port found for port (12634)

04:25:18.095 SB.CCM translateAnswer: offer codec list: PCMU G729

04:25:18.095 SB.CCM : answer codec list: PCMU G729

04:25:18.096 SB.CCM translateAnswer: CODEC transcoding is not required

04:25:18.096 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

04:25:18.096 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - offer

04:25:18.096 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:18.097 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedOffer

04:25:18.097 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:18.097 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer

04:25:18.097 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:25:18.097 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after validator

04:25:18.098 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:25:18.098 SRTP.SDES NEGOTIATION invoked pass-through answer translation

04:25:18.098 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after translation

04:25:18.098 SRTP.SDES NEGOTIATION m=audio 0 RTP/AVP 0 96

04:25:18.098 SB.CCM translateAnswer: success

04:25:18.098 MEDIA.MANAGER Allocating media port.

04:25:18.098 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9795 sessionId -1422332718INIP4127.0.0.3 remote port 0

04:25:18.099 MEDIA.MANAGER Call ID map : Added new session ID : call ID 9795 : session -1422332718INIP4127.0.0.3 : version 2 : index 2636

04:25:18.099 MEDIA.MANAGER New media entry : type(0), callID(9795), sessionID(-1422332718INIP4127.0.0.3), original IP(127.0.0.3) ports(12636-12637), substitute IP(::) ports(12636-12637), RtpChannel(0/1.1), connection(0x0x5204cf10), sdpOverride(0), me(0x0x5203b810). RtpChannel 0/1.1

04:25:18.099 SB.CALL 9795 Delivering Sent preConnect from T01 to T03

04:25:18.099 SB.CALL 9795 State change >> Delivering->PreConnecting

04:25:18.100 TA.T03 01 TAConnectWaitIn preConnect event accepted

04:25:18.100 TM.T03 01 SipTM_Pending tachg -> TAConnectWaitIn

04:25:18.100 TM.T03 01 SipTM_Pending sent: TA->PreConnect Response

04:25:18.100 TM.T03 01 SipTM_Pending State change >> SipTM_Pending->SipTM_Preconnect

04:25:18.100 TM.T03 01 SDP DPI call ID 9795 : No media bin.

04:25:18.101 TM.T03 01 Processing new SDP entries.

04:25:18.101 TM.T03 01 Checking for internal Media Gateway IP Address

04:25:18.101 TM.T03 01 Using RTP Channel 0/1.1

04:25:18.101 TM.T03 01 Inserting 10.100.0.10 into SDP for Media Gateway

04:25:18.101 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9795 sessionId -1422332718INIP4127.0.0.3 remote port 12636

04:25:18.101 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:25:18.102 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12636)

04:25:18.102 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12636 and sub port 12636.

04:25:18.102 MEDIA.MANAGER Call ID map : Received stale SDP - will ignore : call ID 9795 : session -1422332718INIP4127.0.0.3 : version 1

04:25:18.102 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9795 : session -1422332718INIP4127.0.0.3 : IP 10.100.0.10 ports 12636 - 12637 : remote IP 127.0.0.3 ports 12636 - 12637.

04:25:18.102 TM.T03 01 Adding RTP Media Gateway Entry: 127.0.0.3:12636 -> 10.100.0.10:12636

04:25:18.102 TM.T03 01 Allocating anchor ports 12636 and 12637 for interface 10.100.0.10

04:25:18.104 TM.T03 01 SipTM_Preconnect sent: 183 Session Progress

04:25:18.104 TA.T03 01 TAConnectWaitIn rcvd: preConnectResponse from TM

04:25:18.104 SB.CCM connect:

04:25:18.105 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:25:18.105 SB.CCM : Org Acct = T03 Dst Acct = T01

04:25:18.105 SB.CCM : Org Port ID = SipTrunk 0/0.200 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:25:18.105 SB.CCM : SDP Transaction = CallID: 9795

04:25:18.105 SB.CCM : SDP Offer = 0x521cc310, (10.0.0.103:16442)

04:25:18.106 SB.CCM : SDP Answer = 0x520d6a10, (127.0.0.3:12636)

04:25:18.106 SB.CCM : Offer side SRTP session details

04:25:18.106 SB.CCM : None

04:25:18.106 SB.CCM : Answer side SRTP session details

04:25:18.106 SB.CCM : None

04:25:18.106 SB.CCM : RTP Channel = 0/1.1

04:25:18.106 SB.CCM connect: Call Connection Type is RTP_TO_TDM

04:25:18.106 SB.CCM call rtpChannel->allocateForInterface

04:25:18.107 SB.CCM SDP offer is 10.0.0.103:16442, SDP answer is 127.0.0.3:12636

04:25:18.107 MEDIA.MANAGER Trying to connect call ID 9795 : SDP sessions -1454371252INIP410.0.0.103 and -1422332718INIP4127.0.0.3

04:25:18.107 MEDIA.MANAGER Found 1 ports for session -1454371252INIP410.0.0.103

04:25:18.107 MEDIA.MANAGER Found 1 ports for session -1422332718INIP4127.0.0.3

04:25:18.107 MEDIA.MANAGER Connecting Disconnected Local [::]:12634 : Remote 10.0.0.103:16442

04:25:18.108 MEDIA.MANAGER and Disconnected Local 10.100.0.10:12636 : Remote 127.0.0.3:12636

04:25:18.108 MEDIA.MANAGER Setting up DSP Media Connection 9795 for entry(type(0), callID(9795), sessionID(-1454371252INIP410.0.0.103), original IP(10.0.0.103) ports(16442-16443), substitute IP(::) ports(12634-12635), RtpChannel(0/1.1), connection(0x0x521d8e10), sdpOverride(0), me(0x0x520c8110))

04:25:18.108 MEDIA.MANAGER Setting up DSP Media Connection 9795 for entry(type(0), callID(9795), sessionID(-1422332718INIP4127.0.0.3), original IP(127.0.0.3) ports(12636-12637), substitute IP(10.100.0.10) ports(12636-12637), RtpChannel(0/1.1), connection(0x0x5204cf10), sdpOverride(0), me(0x0x5203b810))

04:25:18.108 MEDIA.MANAGER Connection Fixup 1 DSP Port 12634

04:25:18.108 MEDIA.MANAGER Local [::]:12634 : Remote 10.0.0.103:16442

04:25:18.109 MEDIA.MANAGER Connection Fixup 2 DSP Port 12636

04:25:18.109 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 127.0.0.3:12636

04:25:18.109 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12634 sub [::]:12634 remote 10.0.0.103:16442

04:25:18.109 MEDIA.MANAGER : Other side : entry 12636 sub 10.100.0.10:12636 remote 127.0.0.3:12636

04:25:18.109 MEDIA.MANAGER Connection Fixup 1 DSP Port 12636

04:25:18.109 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 127.0.0.3:12636

04:25:18.109 MEDIA.MANAGER Connection Fixup 2 DSP Port 12634

04:25:18.109 MEDIA.MANAGER Local [::]:12634 : Remote 10.0.0.103:16442

04:25:18.110 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12636 remote from 127.0.0.3:12636 to 10.0.0.103:16442

04:25:18.110 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:25:18.110 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:25:18.110 MEDIA.MANAGER Connection Result 1 DSP Port 12636

04:25:18.110 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 10.0.0.103:16442

04:25:18.110 MEDIA.MANAGER Connection Result 2 Entry not activated

04:25:18.110 MEDIA.MANAGER connectionFixup success for port 12636 and 12634

04:25:18.110 MEDIA.MANAGER Marking setup complete for port 12636

04:25:18.111 MEDIA.MANAGER Marking setup complete for port 12634

04:25:18.111 MEDIA.MANAGER Connection Fixup 1 DSP Port 12635

04:25:18.111 MEDIA.MANAGER Local [::]:12635 : Remote 10.0.0.103:16443

04:25:18.111 MEDIA.MANAGER Connection Fixup 2 DSP Port 12637

04:25:18.111 MEDIA.MANAGER Local 10.100.0.10:12637 : Remote 127.0.0.3:12637

04:25:18.111 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12635 sub [::]:12635 remote 10.0.0.103:16443

04:25:18.111 MEDIA.MANAGER : Other side : entry 12637 sub 10.100.0.10:12637 remote 127.0.0.3:12637

04:25:18.112 MEDIA.MANAGER Connection Fixup 1 DSP Port 12637

04:25:18.112 MEDIA.MANAGER Local 10.100.0.10:12637 : Remote 127.0.0.3:12637

04:25:18.112 MEDIA.MANAGER Connection Fixup 2 DSP Port 12635

04:25:18.112 MEDIA.MANAGER Local [::]:12635 : Remote 10.0.0.103:16443

04:25:18.112 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12637 remote from 127.0.0.3:12637 to 10.0.0.103:16443

04:25:18.112 MEDIA.MANAGER Connection Result 1 DSP Port 12637

04:25:18.112 MEDIA.MANAGER Local 10.100.0.10:12637 : Remote 10.0.0.103:16443

04:25:18.112 MEDIA.MANAGER Connection Result 2 Entry not activated

04:25:18.112 MEDIA.MANAGER connectionFixup success for port 12637 and 12635

04:25:18.113 MEDIA.MANAGER Marking setup complete for port 12637

04:25:18.113 MEDIA.MANAGER Marking setup complete for port 12635

04:25:18.113 MEDIA.MANAGER Connected DSP Port 12636

04:25:18.113 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 10.0.0.103:16442

04:25:18.113 MEDIA.MANAGER Connected associations Entry not activated

04:25:18.113 SB.CCM connect: Connected RTP/TDM via MCM

04:25:18.113 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:25:18.114 SB.CCM setupRtpChannel, source 1, silence 0

04:25:18.114 SB.CCM setupRtpChannel: setup using media connection

04:25:18.114 SB.CCM Looking up source address for destination 10.0.0.103

04:25:18.114 SB.CCM setupRtpChannel: Source IP addr = 10.100.0.10, port = 12636

04:25:18.114 SB.CCM setupRtpChannel: Target IP addr = 10.0.0.103, port = 16442

04:25:18.114 SB.CCM setupRtpChannel: Undo of previous operation not required

04:25:18.115 SB.CCM getFinalCodec: PCMU

04:25:18.116 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.100.0.10:12636 Trg 10.0.0.103:16442 via PCMU Rx PCMU G729

04:25:18.116 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=96/96 dscp=46 vad=off isOffer no

04:25:18.116 SB.CCM setupRtpChannel: Starting RTP Channel

04:25:18.116 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

04:25:18.116 RTP.CHANNEL Channel 0/1.1 started successfully.

04:25:18.116 SB.CCM firewallConnectCall: Set up firewall from media connections

04:25:18.116 SB.CCM sdpFirewall: invoked with offer - 10.0.0.103:16442, answer - 10.100.0.10:12636

04:25:18.117 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

04:25:18.117 SB.CCM connect: TDM streams: port(SipTrunk 0/1.1) to port(Isdn(Ds1Ds0Trunk) 0/1.23)

04:25:18.118 SB.CALL 9795 State change >> PreConnecting->PreConnected

04:25:18.118 SB.CALL 9795 PreConnected Call PreConnecting from T03 to T01

04:25:18.118 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: starting

04:25:18.118 TA.T01 ERROR! preConnectResponse ignored

04:25:21.713 ISDN.L2_MSG PRI 1 R 02 01 90 9A 08 02 97 37 01

04:25:21.713 ISDN.L2_MSG PRI 1 T 02 01 01 92

04:25:21.714 TM.T01 23 IsdnTmStateOutboundPreconnect->IsdnTmStateOutboundAlerting

04:25:21.714 TM.T01 23 IsdnTmStateOutboundAlerting::enter()

04:25:21.714 TA.T01 23 TAOutGoing rcvd: alert from TM

04:25:21.714 SB.CALL 9795 PreConnected Called the deliverResponse routine

04:25:21.714 SB.CCM disconnect:

04:25:21.714 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:25:21.714 SB.CCM : Org Acct = T03 Dst Acct = T01

04:25:21.715 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:25:21.715 SB.CCM : SDP Transaction = CallID: 9795

04:25:21.715 SB.CCM : SDP Offer = 0x521cc310, (10.0.0.103:16442)

04:25:21.715 SB.CCM : SDP Answer = 0x520d6a10, (127.0.0.3:12636)

04:25:21.715 SB.CCM : Offer side SRTP session details

04:25:21.715 SB.CCM : None

04:25:21.716 SB.CCM : Answer side SRTP session details

04:25:21.716 SB.CCM : None

04:25:21.716 SB.CCM : RTP Channel = 0/1.1

04:25:21.716 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

04:25:21.716 SB.CCM disconnect: Stopping RTP Channel 0/1.1

04:25:21.717 RTP.CHANNEL Channel 0/1.1 stopped successfully.

04:25:21.717 SB.CCM disconnect: Disconnecting TDM streams

04:25:21.717 SB.CALL 9795 PreConnected Alert after PreConnect sent from T01 to T03

04:25:21.717 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: stopping

04:25:21.718 TA.T03 01 TAConnectWaitIn alert event accepted

04:25:21.718 TM.T03 01 SipTM_Preconnect tachg -> TAConnectWaitIn

04:25:21.718 TM.T03 01 SipTM_Preconnect State change >> SipTM_Preconnect->SipTM_Alerting

04:25:21.720 TM.T03 01 SipTM_Alerting Sent 180 Ringing

04:25:28.695 ISDN.L2_MSG PRI 1 R 02 01 92 9A 08 02 97 37 07

04:25:28.695 ISDN.L2_MSG PRI 1 T 02 01 01 94

04:25:28.695 ISDN.L2_MSG PRI 1 T 00 01 9A 94 08 02 17 37 0F

04:25:28.695 TM.T01 23 IsdnTmStateOutboundAlerting->IsdnTmStateOutboundConnecting

04:25:28.695 TM.T01 23 IsdnTmStateOutboundConnecting::enter()

04:25:28.696 TA.T01 23 TAOutGoing rcvd: connect from TM

04:25:28.696 TA.T01 23 State change >> TAOutGoing->TAConnectWaitOut (TAS_Delivering)

04:25:28.696 SB.CALL 9795 PreConnected Called the connect routine

04:25:28.696 SB.CCM isResponseMappable:

04:25:28.696 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:25:28.696 SB.CCM : Org Acct = T03 Dst Acct = T01

04:25:28.697 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:25:28.697 SB.CCM : SDP Transaction = CallID: 9795

04:25:28.697 SB.CCM : SDP Offer = 0x521cc310, (10.0.0.103:16442)

04:25:28.697 SB.CCM : SDP Answer = 0x520d6a10, (127.0.0.3:12636)

04:25:28.697 SB.CCM : Offer side SRTP session details

04:25:28.697 SB.CCM : None

04:25:28.698 SB.CCM : Answer side SRTP session details

04:25:28.698 SB.CCM : None

04:25:28.698 SB.CCM : RTP Channel = 0/1.1

04:25:28.698 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction

04:25:28.698 SB.CCM isResponseMappable: Call Connection Type is TDM_TO_RTP

04:25:28.698 SB.CCM isResponseMappable: Modifying SDP Answer

04:25:28.699 SB.CCM translateAnswer: offer codec list: PCMU G729

04:25:28.699 SB.CCM : answer codec list: PCMU G729

04:25:28.699 SB.CCM translateAnswer: CODEC transcoding is not required

04:25:28.700 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required

04:25:28.700 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - offer

04:25:28.700 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:28.700 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedOffer

04:25:28.701 SRTP.SDES NEGOTIATION m=audio 16442 RTP/AVP 0 18 96

04:25:28.701 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer

04:25:28.701 SRTP.SDES NEGOTIATION m=audio 12636 RTP/AVP 0 96

04:25:28.701 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after validator

04:25:28.701 SRTP.SDES NEGOTIATION m=audio 12636 RTP/AVP 0 96

04:25:28.701 ISDN.L2_MSG PRI 1 R 00 01 01 9C

04:25:28.702 SRTP.SDES NEGOTIATION invoked pass-through answer translation

04:25:28.702 SRTP.SDES NEGOTIATION SrtpNegotiation - translateAnswer - xlatedAnswer after translation

04:25:28.702 SRTP.SDES NEGOTIATION m=audio 12636 RTP/AVP 0 96

04:25:28.702 SB.CCM translateAnswer: success

04:25:28.703 MEDIA.MANAGER Allocating media port.

04:25:28.703 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9795 sessionId -1422332718INIP4127.0.0.3 remote port 12636

04:25:28.703 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:25:28.703 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12636)

04:25:28.703 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12636 and sub port 12636.

04:25:28.703 MEDIA.MANAGER Call ID map : Replacing with newer version : call ID 9795 : session -1422332718INIP4127.0.0.3 : version 3 : index 2636

04:25:28.703 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9795 : session -1422332718INIP4127.0.0.3 : IP 10.100.0.10 ports 12636 - 12637 : remote IP 127.0.0.3 ports 12636 - 12637.

04:25:28.704 SB.CALL 9795 PreConnected Connect sent from T01 to T03

04:25:28.704 SB.CALL 9795 State change >> PreConnected->Connecting

04:25:28.704 TA.T03 01 TAConnectWaitIn connect event accepted

04:25:28.704 TA.T03 01 State change >> TAConnectWaitIn->TAConnectPending (TAS_Connected)

04:25:28.704 TM.T03 01 SipTM_Alerting tachg -> TAConnectPending

04:25:28.704 TM.T03 01 SipTM_Alerting State change >> SipTM_Alerting->SipTM_Accept

04:25:28.705 TM.T03 01 SDP DPI call ID 9795 : Media bin present.

04:25:28.705 TM.T03 01 Processing new SDP entries.

04:25:28.705 TM.T03 01 Checking for internal Media Gateway IP Address

04:25:28.705 TM.T03 01 Using RTP Channel 0/1.1

04:25:28.705 TM.T03 01 Inserting 10.100.0.10 into SDP for Media Gateway

04:25:28.706 MEDIA.MANAGER getSubstitutePort: Matching callIdMap entry found for call 9795 sessionId -1422332718INIP4127.0.0.3 remote port 12636

04:25:28.706 MEDIA.MANAGER getSubstitutePort: Matching sessionPortMap entry found for session

04:25:28.706 MEDIA.MANAGER getSubstitutePort: Session port count (1) Returning port (12636)

04:25:28.706 MEDIA.MANAGER Existing entry found for port reuse of SDP port 12636 and sub port 12636.

04:25:28.706 MEDIA.MANAGER Call ID map : Received stale SDP - will ignore : call ID 9795 : session -1422332718INIP4127.0.0.3 : version 2

04:25:28.706 MEDIA.MANAGER Reuse anchor entry with same SDP : call 9795 : session -1422332718INIP4127.0.0.3 : IP 10.100.0.10 ports 12636 - 12637 : remote IP 127.0.0.3 ports 12636 - 12637.

04:25:28.706 TM.T03 01 Adding RTP Media Gateway Entry: 127.0.0.3:12636 -> 10.100.0.10:12636

04:25:28.707 TM.T03 01 Allocating anchor ports 12636 and 12637 for interface 10.100.0.10

04:25:28.709 TM.T03 01 SipTM_Accept call-leg -> Accepted

04:25:28.709 TM.T03 01 SipTM_Accept sent: 200 with SDP

04:25:28.712 TM.T03 01 SipTM_Accept rcvd SIP call-leg request: ACK

04:25:28.712 TM.T03 01 SipTM_Accept call-leg -> Connected

04:25:28.712 TM.T03 01 SipTM_Accept No body in message when trying to get SDP

04:25:28.712 TM.T03 01 SipTM_Accept info: unable to save SDP

04:25:28.712 TM.T03 01 SipTM_Accept sent: TA->Connect

04:25:28.713 TM.T03 01 SipTM_Accept State change >> SipTM_Accept->SipTM_Connected

04:25:28.713 TM.T03 01 SipTM_Connected call-leg-mod -> Modify Idle

04:25:28.713 TA.T03 01 TAConnectPending rcvd: connect from TM

04:25:28.713 TA.T03 01 State change >> TAConnectPending->TAConnected (TAS_Connected)

04:25:28.713 SB.CALL 9795 Connecting Called the connectResponse routine

04:25:28.714 SB.CCM connect:

04:25:28.714 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:25:28.714 SB.CCM : Org Acct = T03 Dst Acct = T01

04:25:28.714 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:25:28.714 SB.CCM : SDP Transaction = CallID: 9795

04:25:28.715 SB.CCM : SDP Offer = 0x521cc310, (10.0.0.103:16442)

04:25:28.715 SB.CCM : SDP Answer = 0x520d6a10, (127.0.0.3:12636)

04:25:28.715 SB.CCM : Offer side SRTP session details

04:25:28.715 SB.CCM : None

04:25:28.715 SB.CCM : Answer side SRTP session details

04:25:28.715 SB.CCM : None

04:25:28.715 SB.CCM : RTP Channel = 0/1.1

04:25:28.715 SB.CCM connect: Call Connection Type is RTP_TO_TDM

04:25:28.716 SB.CCM SDP offer is 10.0.0.103:16442, SDP answer is 127.0.0.3:12636

04:25:28.716 MEDIA.MANAGER Trying to connect call ID 9795 : SDP sessions -1454371252INIP410.0.0.103 and -1422332718INIP4127.0.0.3

04:25:28.716 MEDIA.MANAGER Found 1 ports for session -1454371252INIP410.0.0.103

04:25:28.716 MEDIA.MANAGER Found 1 ports for session -1422332718INIP4127.0.0.3

04:25:28.716 MEDIA.MANAGER Connecting DSP Local [::]:12634 : Remote 10.0.0.103:16442

04:25:28.717 MEDIA.MANAGER and DSP Local 10.100.0.10:12636 : Remote 127.0.0.3:12636

04:25:28.717 MEDIA.MANAGER Setting up DSP Media Connection 9795 for entry(type(3), callID(9795), sessionID(-1454371252INIP410.0.0.103), original IP(10.0.0.103) ports(16442-16443), substitute IP(::) ports(12634-12635), RtpChannel(0/1.1), connection(0x0x520c8a10), sdpOverride(0), me(0x0x520c8110))

04:25:28.717 MEDIA.MANAGER Setting up DSP Media Connection 9795 for entry(type(3), callID(9795), sessionID(-1422332718INIP4127.0.0.3), original IP(127.0.0.3) ports(12636-12637), substitute IP(10.100.0.10) ports(12636-12637), RtpChannel(0/1.1), connection(0x0x520c5a10), sdpOverride(0), me(0x0x5203b810))

04:25:28.717 MEDIA.MANAGER Connection Fixup 1 DSP Port 12634

04:25:28.717 MEDIA.MANAGER Local [::]:12634 : Remote 10.0.0.103:16442

04:25:28.718 MEDIA.MANAGER Connection Fixup 2 DSP Port 12636

04:25:28.718 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 127.0.0.3:12636

04:25:28.718 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12634 sub [::]:12634 remote 10.0.0.103:16442

04:25:28.718 MEDIA.MANAGER : Other side : entry 12636 sub 10.100.0.10:12636 remote 127.0.0.3:12636

04:25:28.718 MEDIA.MANAGER Connection Fixup 1 DSP Port 12636

04:25:28.718 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 127.0.0.3:12636

04:25:28.718 MEDIA.MANAGER Connection Fixup 2 DSP Port 12634

04:25:28.718 MEDIA.MANAGER Local [::]:12634 : Remote 10.0.0.103:16442

04:25:28.719 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12636 remote from 127.0.0.3:12636 to 10.0.0.103:16442

04:25:28.719 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:25:28.719 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:25:28.719 MEDIA.MANAGER Connection Result 1 DSP Port 12636

04:25:28.719 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 10.0.0.103:16442

04:25:28.719 MEDIA.MANAGER Connection Result 2 Entry not activated

04:25:28.720 MEDIA.MANAGER connectionFixup success for port 12636 and 12634

04:25:28.720 MEDIA.MANAGER Marking setup complete for port 12636

04:25:28.720 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:25:28.720 MEDIA.MANAGER Marking setup complete for port 12634

04:25:28.720 MEDIA.MANAGER Setup RTP Channel false for 0/1.1

04:25:28.720 MEDIA.MANAGER Connection Fixup 1 DSP Port 12635

04:25:28.720 MEDIA.MANAGER Local [::]:12635 : Remote 10.0.0.103:16443

04:25:28.721 MEDIA.MANAGER Connection Fixup 2 DSP Port 12637

04:25:28.721 MEDIA.MANAGER Local 10.100.0.10:12637 : Remote 127.0.0.3:12637

04:25:28.721 MEDIA.MANAGER connectionFixup : Letting other side fixup connection : entry 12635 sub [::]:12635 remote 10.0.0.103:16443

04:25:28.721 MEDIA.MANAGER : Other side : entry 12637 sub 10.100.0.10:12637 remote 127.0.0.3:12637

04:25:28.721 MEDIA.MANAGER Connection Fixup 1 DSP Port 12637

04:25:28.721 MEDIA.MANAGER Local 10.100.0.10:12637 : Remote 127.0.0.3:12637

04:25:28.721 MEDIA.MANAGER Connection Fixup 2 DSP Port 12635

04:25:28.721 MEDIA.MANAGER Local [::]:12635 : Remote 10.0.0.103:16443

04:25:28.721 MEDIA.MANAGER connectionFixup : DSP media : Change entry 12637 remote from 127.0.0.3:12637 to 10.0.0.103:16443

04:25:28.722 MEDIA.MANAGER Connection Result 1 DSP Port 12637

04:25:28.722 MEDIA.MANAGER Local 10.100.0.10:12637 : Remote 10.0.0.103:16443

04:25:28.722 MEDIA.MANAGER Connection Result 2 Entry not activated

04:25:28.722 MEDIA.MANAGER connectionFixup success for port 12637 and 12635

04:25:28.722 MEDIA.MANAGER Marking setup complete for port 12637

04:25:28.722 MEDIA.MANAGER Marking setup complete for port 12635

04:25:28.722 MEDIA.MANAGER Connected DSP Port 12636

04:25:28.723 MEDIA.MANAGER Local 10.100.0.10:12636 : Remote 10.0.0.103:16442

04:25:28.723 MEDIA.MANAGER Connected associations Entry not activated

04:25:28.723 SB.CCM connect: Connected RTP/TDM via MCM

04:25:28.723 MEDIA.MANAGER Setup RTP Channel true for 0/1.1

04:25:28.723 SB.CCM setupRtpChannel, source 2, silence 0

04:25:28.723 SB.CCM setupRtpChannel: setup using media connection

04:25:28.724 SB.CCM Looking up source address for destination 10.0.0.103

04:25:28.724 SB.CCM setupRtpChannel: Source IP addr = 10.100.0.10, port = 12636

04:25:28.724 SB.CCM setupRtpChannel: Target IP addr = 10.0.0.103, port = 16442

04:25:28.724 SB.CCM setupRtpChannel: Undo of previous operation not required

04:25:28.724 SB.CCM getFinalCodec: PCMU

04:25:28.725 SB.CCM getFinalCodec: PCMU

04:25:28.725 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 10.100.0.10:12636 Trg 10.0.0.103:16442 via PCMU Rx PCMU G729

04:25:28.725 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=96/96 dscp=46 vad=off isOffer no

04:25:28.725 SB.CCM setupRtpChannel: Starting RTP Channel

04:25:28.726 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

04:25:28.726 RTP.CHANNEL Channel 0/1.1 started successfully.

04:25:28.726 SB.CCM firewallConnectCall: Set up firewall from media connections

04:25:28.726 SB.CCM sdpFirewall: invoked with offer - 10.0.0.103:16442, answer - 10.100.0.10:12636

04:25:28.726 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken

04:25:28.727 SB.CCM connect: TDM streams: port(SipTrunk 0/1.1) to port(Isdn(Ds1Ds0Trunk) 0/1.23)

04:25:28.727 SB.CALL 9795 Connecting ConnectResponse sent from T03 to T01

04:25:28.727 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: starting

04:25:28.728 TA.T01 23 TAConnectWaitOut connectResponse event accepted

04:25:28.728 TA.T01 23 State change >> TAConnectWaitOut->TAConnected (TAS_Connected)

04:25:28.728 TM.T01 23 IsdnTmStateOutboundConnecting->IsdnTmStateOutboundConnected

04:25:28.728 TM.T01 23 IsdnTmStateOutboundConnected::enter()

04:25:28.728 TM.T01 23 sent: finalizeConnect to TA

04:25:28.729 TA.T01 23 TAConnected rcvd: finalizeConnect from TM

04:25:28.729 TA.T01 23 TAConnected forwarding finalizeConnect from TM

04:25:28.729 TA.T01 23 TAConnected sent finalizeConnect to SB

04:25:28.729 SB.CALL 9795 Connecting Called the finalizeConnect routine

04:25:28.729 SB.CCM finalizeConnect: connection already finalized(3)

04:25:28.729 SB.CALL 9795 State change >> Connecting->Connected

04:25:38.995 ISDN.L2_MSG PRI 1 T 00 01 01 95

04:25:38.999 ISDN.L2_MSG PRI 1 R 00 01 01 9D

04:25:49.302 ISDN.L2_MSG PRI 1 T 00 01 01 95

04:25:49.306 ISDN.L2_MSG PRI 1 R 00 01 01 9D

04:25:59.608 ISDN.L2_MSG PRI 1 T 00 01 01 95

04:25:59.613 ISDN.L2_MSG PRI 1 R 00 01 01 9D

04:26:08.831 TM.T03 01 SipTM_Connected rcvd SIP call-leg request: BYE

04:26:08.832 TM.T03 01 SipTM_Connected call-leg -> Disconnected

04:26:08.832 TM.T03 01 SipTM_Connected CallLegStateChanged to Disconnected - TM change to closing state.

04:26:08.832 TM.T03 01 SipTM_Connected State change >> SipTM_Connected->SipTM_Closing

04:26:08.832 TM.T03 01 SipTM_Closing sent: TA->Clear

04:26:08.833 TM.T03 01 SipTM_Closing call-leg -> Terminated

04:26:08.834 TA.T03 01 TAConnected rcvd: clear from TM

04:26:08.834 TA.T03 01 State change >> TAConnected->TATrunkClearing (TAS_Clearing)

04:26:08.834 TM.T03 01 SipTM_Closing tachg -> TATrunkClearing

04:26:08.834 TM.T03 01 SipTM_Closing State change >> SipTM_Closing->SipTM_Terminated

04:26:08.834 TM.T03 01 SipTM_Terminated sent: TA->AppearanceOff

04:26:08.834 TM.T03 01 SipTM_Terminated State change >> SipTM_Terminated->SipTM_Idle

04:26:08.835 SB.CALL 9795 Connected Called the clearCall routine

04:26:08.835 SB.CALL 9795 Connected ClearCall sent from T03 to T01

04:26:08.835 SB.CALL 9795 State change >> Connected->Clearing

04:26:08.835 TA.T03 01 TATrunkClearing rcvd: appearance off from TM

04:26:08.835 TA.T03 01 State change >> TATrunkClearing->TAClearingComplete (TAS_Clearing)

04:26:08.835 TA.T03 01 TATrunkClearing Processing an appearance OFF

04:26:08.835 TA.T01 23 TAConnected ClearCall event accepted

04:26:08.836 TA.T01 23 State change >> TAConnected->TAClearingComplete (TAS_Clearing)

04:26:08.836 TM.T01 23 IsdnTmStateOutboundConnected->IsdnTmStateUserClearing

04:26:08.836 TM.T01 23 IsdnTmStateUserClearing::enter()

04:26:08.837 ISDN.L2_MSG PRI 1 T 00 01 9C 94 08 02 17 37 45 08 02 80 90

04:26:08.837 SB.CALL 9795 Clearing Called the clearResponse routine

04:26:08.837 SB.CALL 9795 State change >> Clearing->CallIdlePending

04:26:08.837 SB.CCM disconnect:

04:26:08.837 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:26:08.838 SB.CCM : Org Acct = T03 Dst Acct = T01

04:26:08.838 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:26:08.838 SB.CCM : Offer side SRTP session details

04:26:08.838 SB.CCM : None

04:26:08.838 SB.CCM : Answer side SRTP session details

04:26:08.838 SB.CCM : None

04:26:08.838 SB.CCM : RTP Channel = 0/1.1

04:26:08.838 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

04:26:08.839 SB.CCM disconnect: Stopping RTP Channel 0/1.1

04:26:08.839 RTP.CHANNEL Channel 0/1.1 stopped successfully.

04:26:08.839 SB.CCM disconnect: Disconnecting TDM streams

04:26:08.839 SB.CCM release:

04:26:08.840 SB.CCM : Call Struct 0x0x520bf610 : Call-ID = 9795

04:26:08.840 SB.CCM : Org Acct = T03 Dst Acct = T01

04:26:08.840 SB.CCM : Org Port ID = SipTrunk 0/1.1 Dst Port ID = Isdn(Ds1Ds0Trunk) 0/1.23

04:26:08.840 SB.CCM : Offer side SRTP session details

04:26:08.840 SB.CCM : None

04:26:08.840 SB.CCM : Answer side SRTP session details

04:26:08.840 SB.CCM : None

04:26:08.841 SB.CCM : RTP Channel = 0/1.1

04:26:08.841 SB.CCM release: Call Connection Type is RTP_TO_TDM

04:26:08.841 SB.CCM release: Releasing RTP Channel 0/1.1

04:26:08.841 RTP.CHANNEL Channel 0/1.1 released successfully.

04:26:08.841 SB.CALL 9795 CallIdlePending ClearResponse sent from T01 to T03

04:26:08.841 TONESERVICES.EVENTS t1 0/1.23 - empty - FastBusy Generation: Request resource

04:26:08.842 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: DSP channel allocated for the resource

04:26:08.842 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: constructed

04:26:08.842 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: starting

04:26:08.843 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: TDM map

04:26:08.843 ISDN.L2_MSG PRI 1 R 00 01 01 9E

04:26:08.843 TA.T03 01 TAClearingComplete clearResponse event accepted

04:26:08.843 TA.T03 01 TAClearingComplete Clear Local Variables

04:26:08.844 TA.T03 01 State change >> TAClearingComplete->TAIdle (TAS_Idle)

04:26:08.844 TM.T03 01 SipTM_Idle tachg -> TAIdle

04:26:08.844 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: stopping

04:26:08.844 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: releasing RTP resource

04:26:08.845 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - RTP: releasing

04:26:08.872 ISDN.L2_MSG PRI 1 R 02 01 94 9E 08 02 97 37 4D

04:26:08.872 ISDN.L2_MSG PRI 1 T 02 01 01 96

04:26:08.872 ISDN.L2_MSG PRI 1 T 00 01 9E 96 08 02 17 37 5A

04:26:08.872 TM.T01 23 IsdnTmStateUserClearing->IsdnTmStateIdling

04:26:08.873 TM.T01 23 IsdnTmStateIdling::enter()

04:26:08.873 TM.T01 23 IsdnTmStateIdling - send appearance off

04:26:08.873 TM.T01 23 IsdnTmStateIdling->IsdnTmStateIdle

04:26:08.873 TM.T01 23 IsdnAppearanceChannel::releaseChannel

04:26:08.874 TM.T01 23 IsdnTmStateIdle::enter()

04:26:08.874 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: stopping

04:26:08.874 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: TDM unmap

04:26:08.874 RTP.CHANNEL t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: releasing RTP resource

04:26:08.874 TONESERVICES.EVENTS t1 0/1.23 - Dsp 0/1.1 - FastBusy Generation: release

04:26:08.875 TA.T01 23 TAClearingComplete rcvd: appearance off from TM

04:26:08.875 TA.T01 23 TAClearingComplete Clear Local Variables

04:26:08.875 TA.T01 23 State change >> TAClearingComplete->TAIdle (TAS_Idle)

04:26:08.879 ISDN.L2_MSG PRI 1 R 00 01 01 A0

2015.01.27 04:26:09 SMDR 9795 01/27/2015 04:25:15 0.9 0 E 00/01 Constructure Te 6313967777 00/01 T01 15165325445 0 N

04:26:10.941 MEDIA.MANAGER Remove Call ID map entry for call 9795

04:26:19.170 ISDN.L2_MSG PRI 1 T 00 01 01 97

04:26:19.175 ISDN.L2_MSG PRI 1 R 00 01 01 A1

04:26:29.476 ISDN.L2_MSG PRI 1 T 00 01 01 97

04:26:29.481 ISDN.L2_MSG PRI 1 R 00 01 01 A1

04:26:39.783 ISDN.L2_MSG PRI 1 T 00 01 01 97

04:26:39.787 ISDN.L2_MSG PRI 1 R 00 01 01 A1

04:26:50.089 ISDN.L2_MSG PRI 1 T 00 01 01 97

04:26:50.094 ISDN.L2_MSG PRI 1 R 00 01 01 A1

04:27:00.396 ISDN.L2_MSG PRI 1 T 00 01 01 97

04:27:00.401 ISDN.L2_MSG PRI 1 R 00 01 01 A1

Anonymous · ‎02-02-2016

Hello Joseph,

It doesn't look like debug isdn l2-formatted was running. To get a clear look at both call legs, run these debugs and place another test call:

debug sip stack message

debug voice verbose

debug isdn l2-for

Thanks,

Geoff

Anonymous · ‎02-03-2016

You are correct, I was running "debug isdn l2-messages" not "debug isdn l2-formatted".

However, I have an update...

After some extensive investigation (with the assistance of Patrick from Adtran support), I found that my IP-PBX, when hosting the PRI directly with the internal PRI interface, all caller-id to AT&T subscribers worked without issue. So, since my PBX (Allworx) is able to capture PRI messages (equivalent to "debug isdn l2-formatted"), we captured a call from the TA-908E gateway as well as the PBX, and compared the results.

Allworx:

(seqNum[408] - 7:02/02/2016 01:20:11pm) tTslL3L2: PRI_CAPTURE: [6C 0B A1 36 33 31 33 39 36 37 37 37 37] Calling Party Number : National, ISDN, <Undefined>, <Undefined>, 6313967777

AdTran:

22:34:04.194 ISDN.L2_FMT PRI 1 Calling Name: Constructure Te

22:34:04.194 ISDN.L2_FMT PRI 1 IE - 6C CALLING PARTY # Len=12

22:34:04.194 ISDN.L2_FMT PRI 1 00 Numb. Type:UNKNOWN

22:34:04.195 ISDN.L2_FMT PRI 1 Numb. Plan:UNKNOWN

22:34:04.195 ISDN.L2_FMT PRI 1 80 Presentation:ALLOWED

22:34:04.195 ISDN.L2_FMT PRI 1 Screening:USER PROVIDED

22:34:04.195 ISDN.L2_FMT PRI 1 Ph.# 6313967777

The result that stood out was, the Allworx was sending caller-id in national format, and the AdTran was not (by default it sends caller-id in a different format, I'm not sure what that is, can someone help with this? In the debug it just shows up as number type: unknown). Patrick from AdTran support suggested that we setup an ANI map to have caller-id sent in national format when the pattern matched. We matched for ANY 10 digit number with the following command:

isdn-number-template 0 prefix "" national NXXNXXXXXX

Once we set this up, caller-id to AT&T finally worked! More importantly, it continued to work on all of the other carriers that did NOT have an issue as well. So, THANK YOU PATRICK FROM ADTRAN SUPPORT, you da man! I've been trying to get this resolved for quite a while, and AdTran and the PBX vendor all insisted that it was the carrier (AT&T or the PRI provider) and not the PBX or gateway because it worked on most other carriers. Does that make this an AT&T issue? Perhaps, I'd say PROBABLY...but knowing this and spreading it here on the forums will hopefully make this an issue that does not affect people anymore.

Anonymous · ‎02-15-2016

Joseph, I went ahead and flagged this post as "Assumed Answered". If any of the responses on this thread assisted you, please mark them as Correct or Helpful as the case may be with the applicable buttons. This will make them visible and help other members of the community find solutions more easily. If you still need assistance, we would be more than happy to continue working with you on this - just let us know in a reply.

Thanks,

Jay

Anonymous · ‎05-18-2016

Thanks so much for posting this fix. I just ran into the same issue with a Frontier PRI and the isdn-number-template did the trick!

Chris

Support
Community

TA908e 3rd generation outbound caller-id issues with AT&T cellphones

PRI

SIP

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

SupportCommunity

TA908e 3rd generation outbound caller-id issues with AT&T cellphones

PRI

SIP

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Re: TA908e 3rd generation outbound caller-id issues with AT&T cellphones

Support
Community