Netvanta 7100 Paging

[Anonymous]

Have a question about overhead paging:  We are trying to setup overhead paging and I used as an example  with the following modifications:

interface fxo 1/4

  no shutdown

voice trunk T06 type analog supervision loop-start

  description "Paging System"

  blind-dial

  connect fxo 1/4

  match dnis "444" substitute "1"

  rtp delay-mode adaptive

  rtp qos dscp 0

  codec-group g711_first

voice grouped-trunk ANALOG_PAGING

  trunk T06

  accept 444 cost 0

But nothing come out of the speakers when we dial 444.  If I plug my tone generator into the RJ11 paging port of the paging system, the tone come over the speakers. 

A debug voice verbose produces:

Nettech_NV7100#debug voice verbose

Nettech_NV7100#

10:45:22.911 PM.208 Ca:0 SipPM_Idle           call-leg (P:0x50f5e38 S:0x0) -> Offering (Remote Inviting)

10:45:22.911 PM.208 Ca:0 SipPM_Idle           rcvd: INVITE

10:45:22.911 PM.208 Ca:0 State change      >> SipPM_Idle->SipPM_Authenticating

10:45:22.911 PM.208 Ca:0 SipPM_Authenticating sent: 401 Unauthorized

10:45:22.913 PM.208 Ca:0 SipPM_Authenticating call-leg (P:0x50f5e38 S:0x0) -> Disconnected (Local Reject)

10:45:22.913 PM.208 Ca:0 State change      >> SipPM_Authenticating->SipPM_Terminated

10:45:22.913 PM.208 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

10:45:23.004 PM.208 Ca:0 SipPM_Idle           call-leg (P:0x50f0ea8 S:0x0) -> Offering (Remote Inviting)

10:45:23.005 PM.208 Ca:0 SipPM_Idle           rcvd: INVITE

10:45:23.005 PM.208 Ca:0 State change      >> SipPM_Idle->SipPM_Authenticating

10:45:23.005 PM.208 Ca:0 SipPM_Authenticating sent: 401 Unauthorized

10:45:23.006 PM.208 Ca:0 State change      >> SipPM_Authenticating->SipPM_Trying

10:45:23.006 PM.208 Ca:0 call-leg (0x50f0ea8) -> src: 192.168.108.2:5060  dst: 192.168.108.13:5060

10:45:23.007 PM.208 Ca:0 SipPM_Trying         sent: 100 Trying

10:45:23.008 PM.208 Ca:0 SipPM_Trying         sent: SA->Appearance On

10:45:23.008 SA.208 Ca:0 Idle                 rcvd: AcctPhoneMgr_appearance(ON) from PM

10:45:23.009 SA.208 Ca:0 Idle                 State change      >> Idle->DigitGathering (CAS_ReqDigits)

10:45:23.017 SA.208 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_ReqDigits) to PM

10:45:23.017 PM.208 Ca:0 State change      >> SipPM_Trying->SipPM_Pending

10:45:23.017 PM.208 Ca:0 SipPM_Pending        sent: SA->Dial Digit

10:45:23.018 SA.208 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(444#) from PM

10:45:23.018 SA.208 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

10:45:23.018 SA.208 Ca:0 DigitGathering       State change      >> DigitGathering->DigitGathering (CAS_Active)

10:45:23.019 SA.208 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_Active) to PM

10:45:23.020 SA.208 Ca:0 DigitGathering       sent: call to SB

10:45:23.020 SA.208 Ca:0 DigitGathering       State change      >> DigitGathering->CallPending (CAS_Active)

10:45:23.021 SB.CALL 3065 Idle                 Called the call routine with 444

10:45:23.021 SB.CCM isMappable:

10:45:23.021 SB.CCM  :  Call Struct 0x64f2610 :   Call-ID = 3065

10:45:23.021 SB.CCM  :  Org Acct = 208    Dst Acct = 444

10:45:23.021 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

10:45:23.022 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

10:45:23.022 SB.CCM  :  SDP Transaction = CallID: 3065

10:45:23.022 SB.CCM  :  SDP Offer = 0x05a3aa10, (192.168.108.13:3000)

10:45:23.022 SB.CCM isMappable: Call Connection Type is RTP_TO_RTP

10:45:23.022 SB.CCM handleRtpToRtp: Modifying SDP Offer

10:45:23.023 SB.CCM getBestMatchCodecList: PCMU G729

10:45:23.025 SB.CALL 3065 Idle                 Call sent from 208 to 444 (444)

10:45:23.025 SB.CALL 3065 State change      >> Idle->Delivering

10:45:23.025 SA.208 Ca:0 CallPending          rcvd: callResponse from SB

10:45:23.025 SA.208 Ca:0 CallPending          State change      >> CallPending->Calling (CAS_Active)

10:45:23.026 HPG.444 rcvd: deliver from SB

10:45:23.026 REPLICATION.M Reserving 1 of 50 replications results in session ID: 0

10:45:23.026 REPLICATION.M Replication reservations now greater than 801f max resources. Total reservations: 50, Max replications:

98, Percentage reserved

10:45:23.028 HPG.444 sdpDeepPacketInspection call id 3065 : No media bin.

10:45:23.028 HPG.444 Processing new SDP entries.

10:45:23.028 HPG.444 Undo of previous operation not required (RTP NAT Entry for 192.168.108.13:3000 not found)

10:45:23.028 HPG.444 Checking for internal Media Gateway IP Address

10:45:23.028 HPG.444 Given RTP Channel is null, checking for hairpinned RTP Channel

10:45:23.029 HPG.444 Unable to find hairpinned RTP Channel

10:45:23.029 HPG.444 RTP Channel is NULL, Media Gateway must not be involved in call

10:45:23.029 HPG.444 Checking need for firewall traversal

10:45:23.029 HPG.444 Testing firewall policies

10:45:23.029 HPG.444 NAT not required, no need for firewall traversal here

10:45:23.030 HPG.444 sent: deliverResponse to SB

10:45:23.031 HPG.444 In - State change >> Idle -> Ringing

10:45:23.031 HPG.444 Out.OP.Idle recvd: callMember

10:45:23.032 HPG.444 sent: call to SB

10:45:23.032 HPG.444 Out.OP - State change >> Idle -> Calling

10:45:23.032 SB.CALL 3065 Delivering           Called the deliverResponse routine from Delivering

10:45:23.032 SB.CALL 3065 Delivering           DeliverResponse(accept) sent from 444 to 208

10:45:23.032 SB.CALL 3066 Idle                 Called the call routine with 800

10:45:23.033 SB.CCM isMappable:

10:45:23.033 SB.CCM  :  Call Struct 0x3c39e10 :   Call-ID = 3066

10:45:23.033 SB.CCM  :  Org Acct = 444    Dst Acct = 800

10:45:23.033 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

10:45:23.033 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

10:45:23.034 SB.CCM  :  SDP Transaction = CallID: 3066

10:45:23.034 SB.CCM  :  SDP Offer = 0x05a39410, (127.0.0.1:11596)

10:45:23.034 SB.CCM isMappable: Call Connection Type is RTP_TO_TDM

10:45:23.035 SB.CCM isMappable: Reserving RTP Channel 0/1.1

10:45:23.035 SB.CCM isMappable: Creating SDP Answer based on SDP Offer

10:45:23.036 SB.CCM getBestMatchCodec: G729

10:45:23.037 SB.CALL 3066 Idle                 Call sent from 444 to 800 (800)

10:45:23.037 SB.CALL 3066 State change      >> Idle->Delivering

10:45:23.037 SA.208 Ca:0 Calling              rcvd: deliverResponse from SB

10:45:23.037 SA.208 Ca:0 Calling              sent: AcctPhoneMgr_info to PM

10:45:23.038 PM.208 Ca:0 SipPM_Pending        warn: AcctPhoneMgr_info

10:45:23.038 RTP.MANAGER ? - 12292 0/1. - empty - RTP: Request resource

10:45:23.038 RTP.MANAGER ? - 12292 0/1. - dsp 0/1.1 - RTP: DSP channel allocated for the resource

10:45:23.038 RTP.PROVIDER ? - 12292 0/1. - dsp 0/1.1 - RTP: providing already allocated RTP channel

10:45:23.038 HPG.444 Out.OP.Calling rcvd: callResponse from SB

10:45:23.039 SA.800 rcvd: deliver from SB

10:45:23.039 SA.800 Ca:0 Idle                 sent: deliverResponse(accept) to SB

10:45:23.040 SA.800 Ca:0 Idle                 Set my destination sessionCookie to my call Appearance

10:45:23.040 SA.800 Ca:0 Idle                 State change      >> Idle->Ringing (CAS_Ringing)

10:45:23.040 SA.800 Ca:0 Ringing              sent: AcctPhoneMgr_cachg(CAS_Ringing) to PM

10:45:23.040 PM.PAGING Idle                 Processed CACHG:Ring

10:45:23.041 PM.PAGING State change      >> Idle->Connected

10:45:23.041 SB.CALL 3066 Delivering           Called the deliverResponse routine from Delivering

10:45:23.041 SB.CALL 3066 Delivering           DeliverResponse(accept) sent from 800 to 444

10:45:23.041 SA.800 Ca:0 Ringing              rcvd: AcctPhoneMgr_connect from PM

10:45:23.042 SA.800 Ca:0 Ringing              sent: connect to SB

10:45:23.042 SA.800 Ca:0 Ringing              State change      >> Ringing->Connecting (CAS_Active)

10:45:23.042 HPG.444 Ignoring deliverResponse

10:45:23.042 SB.CALL 3066 Delivering           Called the connect routine from Delivering

10:45:23.043 SB.CALL 3066 State change      >> Delivering->Connecting

10:45:23.043 SB.CALL 3066 Connecting           Connect sent from 800 to 444

10:45:23.043 HPG.444 Out.OP.Calling rcvd: connect from SB

10:45:23.044 HPG.444 sdpDeepPacketInspection call id 3066 : No media bin.

10:45:23.044 HPG.444 Processing new SDP entries.

10:45:23.044 HPG.444 Undo of previous operation not required (RTP NAT Entry for 127.0.0.3:10000 not found)

10:45:23.044 HPG.444 Checking for internal Media Gateway IP Address

10:45:23.044 HPG.444 Using RTP Channel 0/1.1

10:45:23.045 HPG.444 Inserting 127.0.0.3 into SDP for Media Gateway on interface Loopback

10:45:23.045 HPG.444 Adding RTP Media Gateway Entry: 127.0.0.3:10000 -> 127.0.0.3:10000

10:45:23.045 HPG.444 Checking need for firewall traversal

10:45:23.045 HPG.444 Testing firewall policies

10:45:23.046 HPG.444 NAT not required, no need for firewall traversal here

10:45:23.046 HPG.444 sent: connectResponse to SB

10:45:23.046 HPG.444 In.Ringing processConnectedMember

10:45:23.046 HPG.444 sent: connect to SB

10:45:23.046 HPG.444 In - State change >> Ringing -> Connecting

10:45:23.047 HPG.444 Out.OP - State change >> Calling -> Connected

10:45:23.047 SB.CALL 3066 Connecting           Called the connectResponse routine

10:45:23.047 SB.CCM connect:

10:45:23.047 SB.CCM  :  Call Struct 0x3c39e10 :   Call-ID = 3066

10:45:23.047 SB.CCM  :  Org Acct = 444    Dst Acct = 800

10:45:23.047 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/1.0

10:45:23.048 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

10:45:23.048 SB.CCM  :  SDP Transaction = CallID: 3066

10:45:23.048 SB.CCM  :  SDP Offer = 0x05a39410, (127.0.0.1:11596)

10:45:23.048 SB.CCM  :  SDP Answer = 0x05821b10, (127.0.0.3:10000)

10:45:23.048 SB.CCM  :  RTP Channel = 0/1.1

10:45:23.049 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

10:45:23.049 SB.CCM connect: Call Connection Type is RTP_TO_TDM

10:45:23.049 SB.CCM offer ip 127.0.0.1, 11596, answer ip 127.0.0.3, 10000

10:45:23.050 SB.CCM Looking up outbound interface to 127.0.0.1

10:45:23.050 SB.CCM connect: TDM streams: Table SipPhoneManager 0/1.1 to Table 12292 0/1.0

10:45:23.050 SB.CCM not tdm only, call setupRtpChannel

10:45:23.051 SB.CCM setupRtpChannel, type 2, source 2, silence 0

10:45:23.051 SB.CCM TheCallConnectionManager::setupRtpChannel, IP addr = 127.0.0.1, port = 11596

10:45:23.051 SB.CCM connect: Received SDP contains sendonly SDP; disabling RTP transmission

10:45:23.051 SB.CCM connect: Undo of previous operation not required

10:45:23.052 SB.CCM getFinalCodec: G729

10:45:23.052 SB.CCM connect: Configuring RTP Channel 0/1.1 to 127.0.0.1:11596 via G729

10:45:23.052 SB.CCM connect:     fpp=2 echo=on dtmf=0/0 dscp=46 vad=off

10:45:23.053 SB.CCM connect: Starting RTP Channel

10:45:23.053 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

10:45:23.053 RTP.CHANNEL Channel 0/1.1 started sucessfully.

10:45:23.053 SB.CCM firewallConnectCall: Checking need for firewall traversal

10:45:23.054 SB.CALL 3066 State change      >> Connecting->Connected

10:45:23.054 SB.CALL 3066 Connected            ConnectResponse sent from 444 to 800

10:45:23.054 SB.CALL 3065 Delivering           Called the connect routine from Delivering

10:45:23.055 SB.CALL 3065 State change      >> Delivering->Connecting

10:45:23.055 SB.CALL 3065 Connecting           Connect sent from 444 to 208

10:45:23.055 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: starting

10:45:23.055 SA.800 Ca:0 Connecting           rcvd: connectResponse from SB

10:45:23.055 SA.800 Ca:0 Connecting           State change      >> Connecting->Connected (CAS_Connected)

10:45:23.055 SA.800 Ca:0 Connected            sent: AcctPhoneMgr_cachg(CAS_Connected) to PM

10:45:23.056 SA.800 Ca:0 Connected            sent: AcctPhoneMgr_info to PM

10:45:23.056 SA.208 Ca:0 Calling              rcvd: connect from SB

10:45:23.056 SA.208 Ca:0 Calling              State change      >> Calling->ConnectPending (CAS_Connected)

10:45:23.057 SA.208 Ca:0 ConnectPending       sent: AcctPhoneMgr_cachg(CAS_Connected) to PM

10:45:23.057 PM.208 Ca:0 State change      >> SipPM_Pending->SipPM_Accepting

10:45:23.058 PM.208 Ca:0 sdpDeepPacketInspection call id 3065 : No media bin.

10:45:23.058 PM.208 Ca:0 Processing new SDP entries.

10:45:23.058 PM.208 Ca:0 Undo of previous operation not required (RTP NAT Entry for 127.0.0.1:11414 not found)

10:45:23.058 PM.208 Ca:0 Checking for internal Media Gateway IP Address

10:45:23.058 PM.208 Ca:0 Given RTP Channel is null, checking for hairpinned RTP Channel

10:45:23.059 PM.208 Ca:0 Unable to find hairpinned RTP Channel

10:45:23.059 PM.208 Ca:0 SDP Subsystem == VOICEMAIL

10:45:23.059 PM.208 Ca:0 Inserting 192.168.108.2 into SDP for Media Gateway on interface vlan 108

10:45:23.060 PM.208 Ca:0 Adding RTP Media Gateway Entry: 127.0.0.1:11414 -> 192.168.108.2:11414

10:45:23.060 PM.208 Ca:0 Checking need for firewall traversal

10:45:23.061 PM.208 Ca:0 Testing firewall policies

10:45:23.061 PM.208 Ca:0 NAT not required, no need for firewall traversal here

10:45:23.064 PM.208 Ca:0 SipPM_Accepting      call-leg (P:0x50f0ea8 S:0x0) -> Accepted (Local Accepted)

10:45:23.064 PM.208 Ca:0 SipPM_Accepting      sent: 200 with SDP

10:45:23 SB.CallStructObserver 3065 Created

10:45:23 SB.CallStructObserver 3065 <-> 9f9b6053fe9228671ae61d0eb3cf9a87@192.168.108.13

10:45:23 SB.CallStructObserver 3066 Created

10:45:23.235 PM.208 Warning: updateUserLocation failed for call-leg msg

10:45:23.236 PM.208 Ca:0 SipPM_Accepting      rcvd SIP call-leg request: ACK

10:45:23.236 PM.208 Ca:0 SipPM_Accepting      call-leg (P:0x50f0ea8 S:0x0) -> Connected (Remote Ack)

10:45:23.236 PM.208 Ca:0 SipPM_Accepting      rcvd: ACK

10:45:23.236 PM.208 Ca:0 SipPM_Accepting      No body in message when trying to get SDP

10:45:23.237 PM.208 Ca:0 SipPM_Accepting      info: unable to save SDP

10:45:23.237 PM.208 Ca:0 SipPM_Accepting      sent: SA->Connect

10:45:23.237 PM.208 Ca:0 State change      >> SipPM_Accepting->SipPM_Connected

10:45:23.237 PM.208 Ca:0 SipPM_Connected      call-leg-mod (P:0x50f0ea8 S:0x0) -> Modify Idle

10:45:23.237 PM.208 Ca:0 SipPM_Connected      Default: SipCallLegModifyStateChanged to Idle ignored

10:45:23.238 SA.208 Ca:0 ConnectPending       rcvd: AcctPhoneMgr_connect from PM

10:45:23.238 SA.208 Ca:0 ConnectPending       sent: connectResponse(pass) to SB

10:45:23.238 SA.208 Ca:0 ConnectPending       State change      >> ConnectPending->Connected (CAS_Connected)

10:45:23.239 SB.CALL 3065 Connecting           Called the connectResponse routine

10:45:23.239 SB.CCM connect:

10:45:23.240 SB.CCM  :  Call Struct 0x64f2610 :   Call-ID = 3065

10:45:23.240 SB.CCM  :  Org Acct = 208    Dst Acct = 444

10:45:23.240 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

10:45:23.240 SB.CCM  :  Org TID = SipPhoneManager   Dst TID = SipPhoneManager

10:45:23.241 SB.CCM  :  SDP Transaction = CallID: 3065

10:45:23.241 SB.CCM  :  SDP Offer = 0x05a3aa10, (192.168.108.13:3000)

10:45:23.241 SB.CCM  :  SDP Answer = 0x05a39510, (127.0.0.1:11414)

10:45:23.241 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

10:45:23.241 SB.CCM connect: Call Connection Type is RTP_TO_RTP

10:45:23.242 SB.CCM firewallConnectCall: Checking need for firewall traversal

10:45:23.242 SB.CCM firewallConnectCall: Create firewall event to connect 192.168.108.13:3000 and 192.168.108.2:11414

10:45:23.242 SB.CCM firewallConnectCall: Testing firewall policies

10:45:23.243 SB.CCM firewallConnectCall: Releasing NAT Ports for VQM, current firewall configuration allows RTP traffic flow

10:45:23.243 SB.CCM firewallConnectCall: Creating firewall associations to connect 192.168.108.13:3000 to 192.168.108.2:11414

10:45:23.243 SB.CCM Call matches VQM user, access list, or sampling criteria.

10:45:23.243 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.13:3000 for RTP

10:45:23.243 SB.CCM firewallConnectCall: The association does not need NAT

10:45:23.244 SB.CCM Delete criteria: Src: 192.168.108.2:0 Dst: 192.168.108.13:3000 Vrf: 0 Proto: 17 Dir: SELF

10:45:23.244 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.13:3001 for RTCP

10:45:23.244 SB.CCM firewallConnectCall: The association does not need NAT

10:45:23.245 SB.CCM Delete criteria: Src: 192.168.108.2:0 Dst: 192.168.108.13:3001 Vrf: 0 Proto: 17 Dir: SELF

10:45:23.245 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.2:11414 for RTP

10:45:23.245 SB.CCM firewallConnectCall: The association does not need NAT

10:45:23.245 SB.CCM Delete criteria: Src: 192.168.108.13:0 Dst: 192.168.108.2:11414 Vrf: 0 Proto: 17 Dir: Private

10:45:23.246 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.2:11415 for RTCP

10:45:23.246 SB.CCM firewallConnectCall: The association does not need NAT

10:45:23.246 SB.CCM Delete criteria: Src: 192.168.108.13:0 Dst: 192.168.108.2:11415 Vrf: 0 Proto: 17 Dir: Private

10:45:23.247 SB.CALL 3065 State change      >> Connecting->Connected

10:45:23.247 SB.CALL 3065 Connected            ConnectResponse sent from 208 to 444

10:45:23.247 HPG.444 In.Connecting rcvd: connectResponse from SB

10:45:23.251 HPG.444 In - State change >> Connecting -> Connected

10:45:23.251 REPLICATION.M Opening receiver using external socket 112 expecting packets from 192.168.108.13

10:45:23.252 REPLICATION.M Opening target for 127.0.0.3 : 10000 on media gateway 127.0.0.1 : 11596

10:45:23.252 REPLICATION.M Opened socket for 127.0.0.1 : 11596 has status 113,0

10:45:23.931 HPG.444 In.Connected stopAudioResource

10:45:27.321 PM.208 Warning: updateUserLocation failed for call-leg msg

10:45:27.321 PM.208 Ca:0 SipPM_Connected      rcvd SIP call-leg request: BYE

10:45:27.322 PM.208 Ca:0 SipPM_Connected      call-leg (P:0x50f0ea8 S:0x0) -> Disconnected (Remote Disconnected)

10:45:27.322 PM.208 Ca:0 SipPM_Connected      rcvd: BYE

10:45:27.322 PM.208 Ca:0 State change      >> SipPM_Connected->SipPM_Closing

10:45:27.323 PM.208 Ca:0 SipPM_Closing        sent: SA->Appearance Off

10:45:27.325 PM.208 UISM                      call-leg (0x50f0ea8) -> Terminated

10:45:27.325 SA.208 Ca:0 Connected            rcvd: AcctPhoneMgr_appearance(OFF) from PM

10:45:27.325 SA.208 Ca:0 Connected            sent: clearCall to SB

10:45:27.326 SA.208 Ca:0 Connected            State change      >> Connected->Clearing (CAS_Active)

10:45:27.326 SB.CALL 3065 Connected            Called the clearCall routine

10:45:27.326 SB.CALL 3065 Connected            ClearCall sent from 208 to 444

10:45:27.327 SB.CALL 3065 State change      >> Connected->Clearing

10:45:27.327 HPG.444 In.Connected rcvd: clearCall from SB

10:45:27.327 HPG.444 sent: clearResponse to SB

10:45:27.327 HPG.444 Out.OP.Connected recvd: disconnectMember

10:45:27.327 HPG.444 sent: clearCall to SB

10:45:27.328 HPG.444 Out.OP - State change >> Connected -> Idle

10:45:27.328 HPG.444 In - State change >> Connected -> Idle

10:45:27.328 REPLICATION.M Stopping 1 replications for session ID: 0, total replications now 50

10:45:27.328 HPG.444 In.Idle stopAudioResource

10:45:27.329 SB.CALL 3065 Clearing             Called the clearResponse routine

10:45:27.329 SB.CALL 3065 State change      >> Clearing->CallIdlePending

10:45:27.329 SB.CCM disconnect:

10:45:27.329 SB.CCM  :  Call Struct 0x64f2610 :   Call-ID = 3065

10:45:27.330 SB.CCM  :  Org Acct = 208    Dst Acct = 444

10:45:27.330 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

10:45:27.330 SB.CCM  :  Org TID = SipPhoneManager   Dst TID = SipPhoneManager

10:45:27.330 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

10:45:27.330 SB.CCM disconnect: Call Connection Type is RTP_TO_RTP

10:45:27.330 SB.CCM firewallDisconnectCall: No action taken, call has already been cleaned up

10:45:27.331 SB.CCM release:

10:45:27.331 SB.CCM  :  Call Struct 0x64f2610 :   Call-ID = 3065

10:45:27.331 SB.CCM  :  Org Acct = 208    Dst Acct = 444

10:45:27.331 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

10:45:27.331 SB.CCM  :  Org TID = SipPhoneManager   Dst TID = SipPhoneManager

10:45:27.331 SB.CCM release: Call Connection Type is RTP_TO_RTP

10:45:27.332 SB.CALL 3065 CallIdlePending      ClearResponse sent from 444 to 208

10:45:27.332 SB.CALL 3066 Connected            Called the clearCall routine

10:45:27.332 SB.CALL 3066 Connected            ClearCall sent from 444 to 800

10:45:27.333 SB.CALL 3066 State change      >> Connected->Clearing

10:45:27.333 SA.208 Ca:0 Clearing             rcvd: clearResponse from SB

10:45:27.333 SA.208 Ca:0 Clearing             State change      >> Clearing->Idle (CAS_Idle)

10:45:27.341 SA.208 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

10:45:27.342 PM.208 Ca:0 State change      >> SipPM_Closing->SipPM_Terminated

10:45:27.342 PM.208 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

10:45:27.342 SA.800 Ca:0 Connected            rcvd: clearCall from SB

10:45:27.343 SA.800 Ca:0 Connected            sent: clearResponse(pass) to SB

10:45:27.343 SA.800 Ca:0 Connected            State change      >> Connected->Idle (CAS_Idle)

10:45:27.343 SA.800 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

10:45:27.344 PM.PAGING Connected            Processed CACHG:IDLE on Primary CA

10:45:27.344 PM.PAGING State change      >> Connected->Idle

10:45:27.344 SB.CALL 3066 Clearing             Called the clearResponse routine

10:45:27.344 SB.CALL 3066 State change      >> Clearing->CallIdlePending

10:45:27.344 SB.CCM disconnect:

10:45:27.345 SB.CCM  :  Call Struct 0x3c39e10 :   Call-ID = 3066

10:45:27.345 SB.CCM  :  Org Acct = 444    Dst Acct = 800

10:45:27.345 SB.CCM  :  Org Port ID = 0/1.1   Dst Port ID = 0/1.0

10:45:27.345 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

10:45:27.345 SB.CCM  :  RTP Channel = 0/1.1

10:45:27.345 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

10:45:27.346 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

10:45:27.346 SB.CCM disconnect: Stopping RTP Channel 0/1.1

10:45:27.346 RTP.CHANNEL Channel 0/1.1 stopped sucessfully.

10:45:27.346 SB.CCM firewallDisconnectCall: No action taken, call has already been cleaned up

10:45:27.346 SB.CCM disconnect: Disconnecting TDM streams

10:45:27.347 SB.CCM release:

10:45:27.347 SB.CCM  :  Call Struct 0x3c39e10 :   Call-ID = 3066

10:45:27.347 SB.CCM  :  Org Acct = 444    Dst Acct = 800

10:45:27.347 SB.CCM  :  Org Port ID = 0/1.1   Dst Port ID = 0/1.0

10:45:27.347 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

10:45:27.347 SB.CCM  :  RTP Channel = 0/1.1

10:45:27.348 SB.CCM release: Call Connection Type is RTP_TO_TDM

10:45:27.348 SB.CCM release: Releasing RTP Channel 0/1.1

10:45:27.348 RTP.CHANNEL Channel 0/1.1 released sucessfully.

10:45:27.348 SB.CALL 3066 CallIdlePending      ClearResponse sent from 800 to 444

10:45:27.348 HPG.444 Ignoring clearResponse

10:45:27.349 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: stopping

10:45:27.349 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: releasing RTP resource

10:45:27.349 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: releasing

10:45:27 SB.CallStructObserver 3065 Finalized

10:45:27 SB.CallStructObserver 3066 Finalized

2013.08.15 10:45:28 SMDR 3065       08/15/2013 10:45:23      0.0 0    I  00/00 Jim Segal       208             00/00 HPG_444

  444             0 N

2013.08.15 10:45:28 SMDR 3066       08/15/2013 10:45:23      0.0 0    I  00/01 HPG_Jim Segal   208             00/01 Paging

  800             0 N

10:45:28.925 PM.304 Ca:0 Sending Keep-alive: INFO

10:45:28.927 PM.304 Ca:0 call-leg transaction -> Request Sent

10:45:29.034 PM.304 Ca:0 SipPM_Connected      rcvd SIP call-leg response: 200 OK

10:45:29.035 PM.304 Ca:0 call-leg transaction -> Final Response Rcvd

10:45:29.035 PM.304 Ca:0 SipPM_Connected      Received keep-alive response: 200

10:45:29.035 PM.304 Ca:0 call-leg transaction -> Terminated

10:45:34.335 PM.200 Ca:0 Sending Keep-alive: INFO

10:45:34.338 PM.200 Ca:0 call-leg transaction -> Request Sent

10:45:34.417 PM.200 Ca:0 SipPM_Connected      rcvd SIP call-leg response: 200 OK

10:45:34.417 PM.200 Ca:0 call-leg transaction -> Final Response Rcvd

10:45:34.417 PM.200 Ca:0 SipPM_Connected      Received keep-alive response: 200

10:45:34.417 PM.200 Ca:0 call-leg transaction -> Terminated

2013.08.15 10:46:09 VQM.EVENTS Monitoring session ended for 208 to 444, RTP=192.168.108.13:3000->192.168.108.2:11414, MOS (LQ/PQ)=3

.95/3.83, loss=0 pkts, out-of-order=0 pkts, jitter=0 ms

What further debugging should I do?

[valoremtech]

What kind of paging system are you using?

If the tone generator produces a tone when connected I think you have the paging system setup as a station port or page port.  In order for the paging to work on the FXO of the Adtran you must have the paging system setup to provide the "dial tone".  Paging systems often have settings to allow for connecting to a dry page port, an analog station port or a trunk port.  If you do not have an option for changing the type of connection, try using a FXS port on the Adtran to connect to the paging system.  Hope this helps.

[Anonymous]

The paging system is a VIKING CPA-7B General Purpose Telecom Paging System.  It has several configurations possible, but I am using it in its "Paging from an Unused Phone System Trunk Input".  In this configuration, you connect an unused trunk port on the PBX to the CPA-7B.  It does not specify if that port should be an FXO or an FXS.  I will change it to an FXS and see what happens.

[Anonymous]

Cannot connect a Voice Trunk to an FXS port.  When I move the CPA-7B to an FXS port, I get dial-tone over the speakers

[Anonymous]

The CPA-7B can also be setup to Page from a Phone System's 600 Ohm paging port.  If I try to use the paging port on the Adtran, I still get nothing over the speakers.

Debug Voice Verbose:

Nettech_NV7100#

14:19:53.822 PM.208 Ca:0 SipPM_Idle           call-leg (P:0x50bf950 S:0x0) -> Offering (Remote Inviting)

14:19:53.822 PM.208 Ca:0 SipPM_Idle           rcvd: INVITE

14:19:53.822 PM.208 Ca:0 State change      >> SipPM_Idle->SipPM_Authenticating

14:19:53.822 PM.208 Ca:0 SipPM_Authenticating sent: 401 Unauthorized

14:19:53.824 PM.208 Ca:0 SipPM_Authenticating call-leg (P:0x50bf950 S:0x0) -> Disconnected (Local Reject)

14:19:53.824 PM.208 Ca:0 State change      >> SipPM_Authenticating->SipPM_Terminated

14:19:53.824 PM.208 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

14:19:54.006 PM.208 Ca:0 SipPM_Idle           call-leg (P:0x50bfb68 S:0x0) -> Offering (Remote Inviting)

14:19:54.006 PM.208 Ca:0 SipPM_Idle           rcvd: INVITE

14:19:54.006 PM.208 Ca:0 State change      >> SipPM_Idle->SipPM_Authenticating

14:19:54.007 PM.208 Ca:0 SipPM_Authenticating sent: 401 Unauthorized

14:19:54.007 PM.208 Ca:0 State change      >> SipPM_Authenticating->SipPM_Trying

14:19:54.008 PM.208 Ca:0 call-leg (0x50bfb68) -> src: 192.168.108.2:5060  dst: 192.168.108.13:5060

14:19:54.009 PM.208 Ca:0 SipPM_Trying         sent: 100 Trying

14:19:54.010 PM.208 Ca:0 SipPM_Trying         sent: SA->Appearance On

14:19:54.010 SA.208 Ca:0 Idle                 rcvd: AcctPhoneMgr_appearance(ON) from PM

14:19:54.010 SA.208 Ca:0 Idle                 State change      >> Idle->DigitGathering (CAS_ReqDigits)

14:19:54.018 SA.208 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_ReqDigits) to PM

14:19:54.018 PM.208 Ca:0 State change      >> SipPM_Trying->SipPM_SPREProcessing

14:19:54.019 PM.208 SPRE:dialOverheadPage

14:19:54.019 PM.208 Ca:0 SipPM_SPREProcessing Processed SPRE code *30 successfully (Q).

14:19:54.019 PM.208 Ca:0 State change      >> SipPM_SPREProcessing->SipPM_Pending

14:19:54.019 PM.208 Ca:0 SipPM_Pending        sent: SA->Dial Digit

14:19:54.020 SA.208 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(800#) from PM

14:19:54.020 SA.208 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

14:19:54.020 SA.208 Ca:0 DigitGathering       State change      >> DigitGathering->DigitGathering (CAS_Active)

14:19:54.021 SA.208 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_Active) to PM

14:19:54.021 SA.208 Ca:0 DigitGathering       sent: call to SB

14:19:54.021 SA.208 Ca:0 DigitGathering       State change      >> DigitGathering->CallPending (CAS_Active)

14:19:54.022 SB.CALL 3239 Idle                 Called the call routine with 800

14:19:54.022 SB.CCM isMappable:

14:19:54.022 SB.CCM  :  Call Struct 0x650b210 :   Call-ID = 3239

14:19:54.022 SB.CCM  :  Org Acct = 208    Dst Acct = 800

14:19:54.022 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

14:19:54.023 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

14:19:54.023 SB.CCM  :  SDP Transaction = CallID: 3239

14:19:54.023 SB.CCM  :  SDP Offer = 0x05a3e010, (192.168.108.13:3000)

14:19:54.023 SB.CCM isMappable: Call Connection Type is RTP_TO_TDM

14:19:54.024 SB.CCM isMappable: Reserving RTP Channel 0/1.1

14:19:54.024 SB.CCM isMappable: Creating SDP Answer based on SDP Offer

14:19:54.025 SB.CCM getBestMatchCodec: PCMU

14:19:54.026 SB.CALL 3239 Idle                 Call sent from 208 to 800 (800)

14:19:54.026 SB.CALL 3239 State change      >> Idle->Delivering

14:19:54.027 RTP.MANAGER ? - 12292 0/1. - empty - RTP: Request resource

14:19:54.027 RTP.MANAGER ? - 12292 0/1. - dsp 0/1.1 - RTP: DSP channel allocated for the resource

14:19:54.027 RTP.PROVIDER ? - 12292 0/1. - dsp 0/1.1 - RTP: providing already allocated RTP channel

14:19:54.027 SA.208 Ca:0 CallPending          rcvd: callResponse from SB

14:19:54.027 SA.208 Ca:0 CallPending          State change      >> CallPending->Calling (CAS_Active)

14:19:54.028 SA.800 rcvd: deliver from SB

14:19:54.028 SA.800 Ca:0 Idle                 sent: deliverResponse(accept) to SB

14:19:54.028 SA.800 Ca:0 Idle                 Set my destination sessionCookie to my call Appearance

14:19:54.028 SA.800 Ca:0 Idle                 State change      >> Idle->Ringing (CAS_Ringing)

14:19:54.029 SA.800 Ca:0 Ringing              sent: AcctPhoneMgr_cachg(CAS_Ringing) to PM

14:19:54.029 PM.PAGING Idle                 Processed CACHG:Ring

14:19:54.029 PM.PAGING State change      >> Idle->Connected

14:19:54.029 SB.CALL 3239 Delivering           Called the deliverResponse routine from Delivering

14:19:54.030 SB.CALL 3239 Delivering           DeliverResponse(accept) sent from 800 to 208

14:19:54.030 SA.800 Ca:0 Ringing              rcvd: AcctPhoneMgr_connect from PM

14:19:54.030 SA.800 Ca:0 Ringing              sent: connect to SB

14:19:54.030 SA.800 Ca:0 Ringing              State change      >> Ringing->Connecting (CAS_Active)

14:19:54.030 SA.208 Ca:0 Calling              rcvd: deliverResponse from SB

14:19:54.031 SA.208 Ca:0 Calling              sent: AcctPhoneMgr_info to PM

14:19:54.031 PM.208 Ca:0 SipPM_Pending        warn: AcctPhoneMgr_info

14:19:54.031 SB.CALL 3239 Delivering           Called the connect routine from Delivering

14:19:54.031 SB.CALL 3239 State change      >> Delivering->Connecting

14:19:54.032 SB.CALL 3239 Connecting           Connect sent from 800 to 208

14:19:54.032 SA.208 Ca:0 Calling              rcvd: connect from SB

14:19:54.032 SA.208 Ca:0 Calling              State change      >> Calling->ConnectPending (CAS_Connected)

14:19:54.032 SA.208 Ca:0 ConnectPending       sent: AcctPhoneMgr_cachg(CAS_Connected) to PM

14:19:54.033 PM.208 Ca:0 State change      >> SipPM_Pending->SipPM_Accepting

14:19:54.033 PM.208 Ca:0 sdpDeepPacketInspection call id 3239 : No media bin.

14:19:54.033 PM.208 Ca:0 Processing new SDP entries.

14:19:54.034 PM.208 Ca:0 Undo of previous operation not required (RTP NAT Entry for 127.0.0.3:10000 not found)

14:19:54.034 PM.208 Ca:0 Checking for internal Media Gateway IP Address

14:19:54.034 PM.208 Ca:0 Using RTP Channel 0/1.1

14:19:54.034 PM.208 Ca:0 Inserting 192.168.108.2 into SDP for Media Gateway on interface vlan 108

14:19:54.034 PM.208 Ca:0 Adding RTP Media Gateway Entry: 127.0.0.3:10000 -> 192.168.108.2:10000

14:19:54.035 PM.208 Ca:0 Checking need for firewall traversal

14:19:54.035 PM.208 Ca:0 Testing firewall policies

14:19:54.036 PM.208 Ca:0 NAT not required, no need for firewall traversal here

14:19:54.038 PM.208 Ca:0 SipPM_Accepting      call-leg (P:0x50bfb68 S:0x0) -> Accepted (Local Accepted)

14:19:54.038 PM.208 Ca:0 SipPM_Accepting      sent: 200 with SDP

14:19:54 SB.CallStructObserver 3239 Created

14:19:54 SB.CallStructObserver 3239 <-> e3ea118698c0a168f2abc328727aa3de@192.168.108.13

14:19:54.165 PM.208 Warning: updateUserLocation failed for call-leg msg

14:19:54.165 PM.208 Ca:0 SipPM_Accepting      rcvd SIP call-leg request: CANCEL

14:19:54.174 PM.208 Warning: updateUserLocation failed for call-leg msg

14:19:54.174 PM.208 Ca:0 SipPM_Accepting      rcvd SIP call-leg request: ACK

14:19:54.175 PM.208 Ca:0 SipPM_Accepting      call-leg (P:0x50bfb68 S:0x0) -> Connected (Remote Ack)

14:19:54.175 PM.208 Ca:0 SipPM_Accepting      rcvd: ACK

14:19:54.175 PM.208 Ca:0 SipPM_Accepting      No body in message when trying to get SDP

14:19:54.176 PM.208 Ca:0 SipPM_Accepting      info: unable to save SDP

14:19:54.176 PM.208 Ca:0 SipPM_Accepting      sent: SA->Connect

14:19:54.176 PM.208 Ca:0 State change      >> SipPM_Accepting->SipPM_Connected

14:19:54.176 PM.208 Ca:0 SipPM_Connected      call-leg-mod (P:0x50bfb68 S:0x0) -> Modify Idle

14:19:54.176 PM.208 Ca:0 SipPM_Connected      Default: SipCallLegModifyStateChanged to Idle ignored

14:19:54.177 SA.208 Ca:0 ConnectPending       rcvd: AcctPhoneMgr_connect from PM

14:19:54.177 SA.208 Ca:0 ConnectPending       sent: connectResponse(pass) to SB

14:19:54.177 SA.208 Ca:0 ConnectPending       State change      >> ConnectPending->Connected (CAS_Connected)

14:19:54.178 SB.CALL 3239 Connecting           Called the connectResponse routine

14:19:54.178 SB.CCM connect:

14:19:54.178 SB.CCM  :  Call Struct 0x650b210 :   Call-ID = 3239

14:19:54.178 SB.CCM  :  Org Acct = 208    Dst Acct = 800

14:19:54.178 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/1.0

14:19:54.179 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

14:19:54.179 SB.CCM  :  SDP Transaction = CallID: 3239

14:19:54.179 SB.CCM  :  SDP Offer = 0x05a3e010, (192.168.108.13:3000)

14:19:54.179 SB.CCM  :  SDP Answer = 0x05a3d510, (127.0.0.3:10000)

14:19:54.179 SB.CCM  :  RTP Channel = 0/1.1

14:19:54.180 MOH.APP printCSHoldStates, connect_: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:19:54.180 SB.CCM connect: Call Connection Type is RTP_TO_TDM

14:19:54.180 SB.CCM offer ip 192.168.108.13, 3000, answer ip 127.0.0.3, 10000

14:19:54.180 SB.CCM Looking up outbound interface to 192.168.108.13

14:19:54.181 SB.CCM Changing RTP Channel source IP Address to 192.168.108.2 for Media Gateway on interface vlan 108

14:19:54.181 SB.CCM connect: TDM streams: Table SipPhoneManager 0/1.1 to Table 12292 0/1.0

14:19:54.181 SB.CCM not tdm only, call setupRtpChannel

14:19:54.181 SB.CCM setupRtpChannel, type 2, source 2, silence 0

14:19:54.182 SB.CCM TheCallConnectionManager::setupRtpChannel, IP addr = 192.168.108.13, port = 3000

14:19:54.182 SB.CCM connect: Received SDP contains recvonly or sendrecv SDP

14:19:54.185 PM.208 Warning: updateUserLocation failed for call-leg msg

14:19:54.185 PM.208 Ca:0 SipPM_Connected      rcvd SIP call-leg request: BYE

14:19:54.185 PM.208 Ca:0 SipPM_Connected      call-leg (P:0x50bfb68 S:0x0) -> Disconnected (Remote Disconnected)

14:19:54.186 PM.208 Ca:0 SipPM_Connected      rcvd: BYE

14:19:54.186 PM.208 Ca:0 State change      >> SipPM_Connected->SipPM_Closing

14:19:54.186 PM.208 Ca:0 SipPM_Closing        sent: SA->Appearance Off

14:19:54.188 PM.208 UISM                      call-leg (0x50bfb68) -> Terminated

14:19:54.188 SB.CCM connect: Undo of previous operation not required

14:19:54.189 SB.CCM getFinalCodec: PCMU

14:19:54.189 SB.CCM connect: Configuring RTP Channel 0/1.1 to 192.168.108.13:3000 via PCMU

14:19:54.189 SB.CCM connect:     fpp=2 echo=on dtmf=101/101 dscp=46 vad=off

14:19:54.190 SB.CCM connect: Starting RTP Channel

14:19:54.190 RTP.CHANNEL Channel 0/1.1 session statistics cleared.

14:19:54.190 RTP.CHANNEL Channel 0/1.1 started sucessfully.

14:19:54.190 SB.CCM firewallConnectCall: Checking need for firewall traversal

14:19:54.191 SB.CCM firewallConnectCall: Create firewall event to connect 192.168.108.13:3000 and 192.168.108.2:10000

14:19:54.191 SB.CCM firewallConnectCall: Testing firewall policies

14:19:54.191 SB.CCM firewallConnectCall: Releasing NAT Ports for VQM, current firewall configuration allows RTP traffic flow

14:19:54.191 SB.CCM firewallConnectCall: Creating firewall associations to connect 192.168.108.13:3000 to 192.168.108.2:10000

14:19:54.192 SB.CCM Call matches VQM user, access list, or sampling criteria.

14:19:54.192 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.13:3000 for RTP

14:19:54.192 SB.CCM firewallConnectCall: The association does not need NAT

14:19:54.192 SB.CCM Delete criteria: Src: 192.168.108.2:0 Dst: 192.168.108.13:3000 Vrf: 0 Proto: 17 Dir: SELF

14:19:54.193 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.13:3001 for RTCP

14:19:54.193 SB.CCM firewallConnectCall: The association does not need NAT

14:19:54.193 SB.CCM Delete criteria: Src: 192.168.108.2:0 Dst: 192.168.108.13:3001 Vrf: 0 Proto: 17 Dir: SELF

14:19:54.193 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.2:10000 for RTP

14:19:54.194 SB.CCM firewallConnectCall: The association does not need NAT

14:19:54.194 SB.CCM Delete criteria: Src: 192.168.108.13:0 Dst: 192.168.108.2:10000 Vrf: 0 Proto: 17 Dir: Private

14:19:54.194 SB.CCM firewallConnectCall: Creating association for traffic destined to 192.168.108.2:10001 for RTCP

14:19:54.194 SB.CCM firewallConnectCall: The association does not need NAT

14:19:54.195 SB.CCM Delete criteria: Src: 192.168.108.13:0 Dst: 192.168.108.2:10001 Vrf: 0 Proto: 17 Dir: Private

14:19:54.196 SB.CALL 3239 State change      >> Connecting->Connected

14:19:54.196 SB.CALL 3239 Connected            ConnectResponse sent from 208 to 800

14:19:54.196 SA.208 Ca:0 Connected            rcvd: AcctPhoneMgr_appearance(OFF) from PM

14:19:54.196 SA.208 Ca:0 Connected            sent: clearCall to SB

14:19:54.197 SA.208 Ca:0 Connected            State change      >> Connected->Clearing (CAS_Active)

14:19:54.197 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: starting

14:19:54.199 SA.800 Ca:0 Connecting           rcvd: connectResponse from SB

14:19:54.199 SA.800 Ca:0 Connecting           State change      >> Connecting->Connected (CAS_Connected)

14:19:54.199 SA.800 Ca:0 Connected            sent: AcctPhoneMgr_cachg(CAS_Connected) to PM

14:19:54.199 SA.800 Ca:0 Connected            sent: AcctPhoneMgr_info to PM

14:19:54.199 SB.CALL 3239 Connected            Called the clearCall routine

14:19:54.200 SB.CALL 3239 Connected            ClearCall sent from 208 to 800

14:19:54.200 SB.CALL 3239 State change      >> Connected->Clearing

14:19:54.200 SA.800 Ca:0 Connected            rcvd: clearCall from SB

14:19:54.200 SA.800 Ca:0 Connected            sent: clearResponse(pass) to SB

14:19:54.200 SA.800 Ca:0 Connected            State change      >> Connected->Idle (CAS_Idle)

14:19:54.201 SA.800 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

14:19:54.201 PM.PAGING Connected            Processed CACHG:IDLE on Primary CA

14:19:54.201 PM.PAGING State change      >> Connected->Idle

14:19:54.201 SB.CALL 3239 Clearing             Called the clearResponse routine

14:19:54.202 SB.CALL 3239 State change      >> Clearing->CallIdlePending

14:19:54.202 SB.CCM disconnect:

14:19:54.202 SB.CCM  :  Call Struct 0x650b210 :   Call-ID = 3239

14:19:54.202 SB.CCM  :  Org Acct = 208    Dst Acct = 800

14:19:54.202 SB.CCM  :  Org Port ID = 0/1.1   Dst Port ID = 0/1.0

14:19:54.202 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

14:19:54.203 SB.CCM  :  RTP Channel = 0/1.1

14:19:54.203 MOH.APP printCSHoldStates, disconnect: towOrig 0, towDest 0 origHold 0 destHold 0 isHold 0

14:19:54.203 SB.CCM disconnect: Call Connection Type is RTP_TO_TDM

14:19:54.203 SB.CCM disconnect: Stopping RTP Channel 0/1.1

14:19:54.203 RTP.CHANNEL Channel 0/1.1 stopped sucessfully.

14:19:54.204 SB.CCM firewallDisconnectCall: No action taken, call has already been cleaned up

14:19:54.204 SB.CCM disconnect: Disconnecting TDM streams

14:19:54.204 SB.CCM release:

14:19:54.204 SB.CCM  :  Call Struct 0x650b210 :   Call-ID = 3239

14:19:54.204 SB.CCM  :  Org Acct = 208    Dst Acct = 800

14:19:54.204 SB.CCM  :  Org Port ID = 0/1.1   Dst Port ID = 0/1.0

14:19:54.205 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

14:19:54.205 SB.CCM  :  RTP Channel = 0/1.1

14:19:54.205 SB.CCM release: Call Connection Type is RTP_TO_TDM

14:19:54.206 SB.CCM release: Releasing RTP Channel 0/1.1

14:19:54.206 RTP.CHANNEL Channel 0/1.1 released sucessfully.

14:19:54.206 SB.CALL 3239 CallIdlePending      ClearResponse sent from 800 to 208

14:19:54.206 SA.208 Ca:0 Clearing             rcvd: clearResponse from SB

14:19:54.206 SA.208 Ca:0 Clearing             State change      >> Clearing->Idle (CAS_Idle)

14:19:54.207 SA.208 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

14:19:54.207 PM.208 Ca:0 State change      >> SipPM_Closing->SipPM_Terminated

14:19:54.207 PM.208 Ca:0 State change      >> SipPM_Terminated->SipPM_Idle

14:19:54.208 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: stopping

14:19:54.208 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: releasing RTP resource

14:19:54.208 RTP.CHANNEL ? - 12292 0/1. - dsp 0/1.1 - RTP: releasing

14:19:54 SB.CallStructObserver 3239 Finalized

2013.08.15 14:19:55 SMDR 3239       08/15/2013 14:19:54      0.0 0    I  00/01 Jim Segal       208             00/01 Paging

  800             0 N

[valoremtech]

Hi quazar66,

Can we test to see if you have the port on the amplifier setup to "Unused Trunk Port"?  If you are using the tone generator from Ideal or Tempo set the switch the middle position.  This is OFF/POLARITY.  When you connect it to the paging port on the amplifier it should turn green or red.  If it does not then we need to setup the page port on the amplifier.

If you do get the light then it is setup as Used Trunk Port.  Continue to connect the FXO port back up, and we will look at the configuration of the port.

[Anonymous]

Valoremtech,

If I connect my Progressive Electronics 77HP Tracer2 to the paging port, it does turn green.  When I looked at the port I got this:

Nettech_NV7100#sh int fxo 1/4

fxo 1/4 is UP

  Two-wire Status:    Onhook

  Test Status:        INACTIVE

    No Tests

  Impedance:         600 ohms +2.16uF

  Transmit Gain:      +0.0dB

  Receive Gain:       +0.0dB

  Measured ERL:       not available - run 'test erl'

  Last clearing of "show interface" counters: never

I ran the "test erl all auto-set" and the port was changed to:

Nettech_NV7100#sh int fxo 1/4

fxo 1/4 is UP

  Two-wire Status:    Onhook

  Test Status:        INACTIVE

    No Tests

  Impedance:         900 ohms real

  Transmit Gain:      +0.0dB

  Receive Gain:       +0.0dB

  Measured ERL:        3 dB

  Last clearing of "show interface" counters: never

Still nothing when we call 444, the phone beeps, and we try to talk.

[Anonymous · Accepted solution]

quazar66

The snippet of the debug below shows extension 208 initiating a call to 444.  The last line below shows that 444 is a paging-group that is configured on the NV7100.  The NV7100 will always prefer routing calls to a local extension before routing a call over a trunk.  You would need to delete this paging-group or change the extension number for this group before the call will route over the analog trunk to your paging system.

10:45:23.021 SB.CCM  :  Call Struct 0x64f2610 :   Call-ID = 3065

10:45:23.021 SB.CCM  :  Org Acct = 208    Dst Acct = 444

10:45:23.021 SB.CCM  :  Org Port ID = 0/0.0   Dst Port ID = 0/0.0

10:45:23.022 SB.CCM  :  Org TID = SipPhoneManager   Dst TID =

10:45:23.022 SB.CCM  :  SDP Transaction = CallID: 3065

10:45:23.022 SB.CCM  :  SDP Offer = 0x05a3aa10, (192.168.108.13:3000)

10:45:23.026 HPG.444 rcvd: deliver from SB

Thanks,

Charles

[Anonymous]

Charles,

That did the trick!  Forgot about that paging group even being setup.  That was from when we were trying to the the 1/8" paging port on the Adtran to work with the CPA-7B

Thanks.