cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1716
Views
0
Helpful
1
Replies

FXO issues- call outbound fails on analog line, works with analog phone

STEPHEN LISLE
Level 1
Level 1

Here is the config, line is in port 0/1/0- ignore 0/1/1. Debugs after config. Call fails to 14043940384. Any thoughts?

 


MADRAS-2811#sh run
Building configuration...


Current configuration : 10579 bytes
!
version 15.0

!
hostname MADRAS-2811
!
boot-start-marker
boot-end-marker
!
! card type command needed for slot/vwic-slot 0/0
security authentication failure rate 3 log
security passwords min-length 6

!
aaa new-model
!
!
aaa authentication login local_authen local
aaa authorization exec local_author local
!
!
!
!
!
aaa session-id common
!
!
!
clock timezone PDT -8
clock summer-time PDT recurring
!
dot11 syslog
ip source-route
!
!
ip cef
no ip dhcp use vrf connected
ip dhcp excluded-address 172.24.5.1 172.24.5.49
!
ip dhcp pool PHONES
   network 172.24.5.0 255.255.255.0
   default-router 172.24.5.254
   option 150 ip 172.24.1.10
   dns-server 10.1.1.17 10.1.1.18
   option 42 ip 10.1.1.17
   option 160 ascii "http://cicprovision.midoregon.com:8088"
!
!
no ip domain lookup
ip domain name midoregon.com
ip inspect name mid-oregon esmtp
ip inspect name mid-oregon fragment maximum 256 timeout 1
ip inspect name mid-oregon ftp
ip inspect name mid-oregon h323
ip inspect name mid-oregon http
ip inspect name mid-oregon icmp
ip inspect name mid-oregon rtsp
ip inspect name mid-oregon sip
ip inspect name mid-oregon skinny
ip inspect name mid-oregon tcp
ip inspect name mid-oregon udp
no ipv6 cef
!
multilink bundle-name authenticated
!
!
!
!
!
!
voice call convert-discpi-to-prog
!
voice service voip
 fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
 sip
  bind control source-interface FastEthernet0/0.3
  bind media source-interface FastEthernet0/0.3
!
voice class codec 100
 codec preference 1 g711ulaw
 codec preference 2 g729r8
!
!
!
!
voice-card 0
!
!
application
 global
  service alternate DEFAULT
 !
!
!
crypto pki trustpoint TP-self-signed-4225746905
 enrollment selfsigned
 subject-name cn=IOS-Self-Signed-Certificate-4225746905
 revocation-check none
 rsakeypair TP-self-signed-4225746905
!
!
crypto pki certificate chain TP-self-signed-4225746905
 certificate self-signed 01
  30820251 308201BA A0030201 02020101 300D0609 2A864886 F70D0101 04050030
  31312F30 2D060355 04031326 494F532D 53656C66 2D536967 6E65642D 43657274
  69666963 6174652D 34323235 37343639 3035301E 170D3039 30353237 31373339
  35365A17 0D323030 31303130 30303030 305A3031 312F302D 06035504 03132649
  4F532D53 656C662D 5369676E 65642D43 65727469 66696361 74652D34 32323537
  34363930 3530819F 300D0609 2A864886 F70D0101 01050003 818D0030 81890281
  8100B5D6 7F1B1543 908FCDBD 9893BA92 164A6E39 BBF080A2 D6892750 93849F05
  F8F8981F E581B862 05F24E19 D211A145 DBA08775 A148C568 D47EC46C 09D278E9
  234E757A CA771A37 3F846AC9 8C0D062D 293B1AFA 911F327F B5A704B5 04169DAD
  E1D828F5 B7ED21B1 7F1F98D7 9EE443C1 E3ED85F3 F3E93C8D 117011E6 D4C1A5ED
  FCB90203 010001A3 79307730 0F060355 1D130101 FF040530 030101FF 30240603
  551D1104 1D301B82 194D4144 5241532D 32383131 2E6D6964 6F726567 6F6E2E63
  6F6D301F 0603551D 23041830 16801494 979C52C2 79023B1A 06B405A9 783DC08D
  FE7A7430 1D060355 1D0E0416 04149497 9C52C279 023B1A06 B405A978 3DC08DFE
  7A74300D 06092A86 4886F70D 01010405 00038181 004D7FEC 8DC90435 EDD081EA
  CFFE0F45 88DB02BA D88258C4 CB9593E5 7F575F9D 7B976992 3E3108CE C70D7033
  1B411BA1 C9E85B40 9426E4D4 B5788C38 274E20FB 7DEB5385 4586D342 BE7279AB
  B35137B3 D37626E9 F067D18E 999D6E3C 6D45B245 75E7993F 474B8186 A27932C5
  46A47EF0 002A0C0D BE0325CD 58EF1BF2 A4B46456 FF
      quit
!
!
license udi pid CISCO2811 sn FTX1433A1U2
archive
 log config
  hidekeys
!
redundancy
!
!
ip tcp selective-ack
ip tcp timestamp
ip tcp synwait-time 10
ip tcp path-mtu-discovery
ip ssh time-out 60
!
!
crypto isakmp policy 1
 encr aes 256
 authentication pre-share
 group 2
!
crypto isakmp policy 20
 encr 3des
 authentication pre-share
 group 2
crypto isakmp key $mid0-cu-DATA! address 172.24.199.2
crypto isakmp key $mid0-cu-DATA! address 172.24.199.3
crypto isakmp key $mid0-cu-DATA! address 172.24.199.1
crypto isakmp key $mid0-cu-DATA! address 172.24.199.4
crypto isakmp key $mid0-cu-DATA! address 172.24.199.6
crypto isakmp key $mid0-cu-DATA! address 172.24.199.7
crypto isakmp key TSML0056YTTSOO11thselsss address 216.228.182.49 no-xauth
!
!
crypto ipsec transform-set tset esp-3des esp-sha-hmac
crypto ipsec transform-set ESP-AES256-SHA-HMAC esp-aes 256 esp-sha-hmac
 mode transport
!
crypto map mid-or 11 ipsec-isakmp
 set peer 172.24.199.1
 set transform-set tset
 match address 111
crypto map mid-or 21 ipsec-isakmp
 set peer 172.24.199.2
 set transform-set tset
 match address 112
crypto map mid-or 31 ipsec-isakmp
 set peer 172.24.199.3
 set transform-set tset
 match address 113
crypto map mid-or 41 ipsec-isakmp
 set peer 172.24.199.4
 set transform-set tset
 match address 114
crypto map mid-or 61 ipsec-isakmp
 set peer 172.24.199.6
 set transform-set tset
 match address 116
crypto map mid-or 71 ipsec-isakmp
 set peer 172.24.199.7
 set transform-set tset
 match address 117
!
crypto map mid-or-outside 10 ipsec-isakmp
 description IPSEC INTERNET TUNNEL TO EAST BEND
 set peer 216.228.182.49
 set transform-set ESP-AES256-SHA-HMAC
 match address 126
!
!
!
!
!
!
interface Loopback1
 description GRE LOOPBACK
 ip address 10.222.222.14 255.255.255.255
 ip access-group gre-in in
 ip access-group gre-out out
 !
!
interface Tunnel0
 description GRE TUNNEL TO EAST BEND
 ip address 10.222.0.14 255.255.255.252
 ip access-group gre-in in
 ip access-group gre-out out
 ip mtu 1400
 ip tcp adjust-mss 1360
 ip ospf cost 100
 ip ospf mtu-ignore
 tunnel source 10.222.222.14
 tunnel destination 10.222.222.1
 !
!
interface Null0
 no ip unreachables
!
interface FastEthernet0/0
 no ip address
 duplex full
 speed 100
 !
!
interface FastEthernet0/0.2
 description LAN - DATA
 encapsulation dot1Q 2 native
 ip address 10.5.1.231 255.255.0.0 secondary
 ip address 10.5.2.254 255.255.0.0
 ip helper-address 10.1.1.17
 ip nat inside
 ip virtual-reassembly
!
interface FastEthernet0/0.3
 description LAN - VOIP
 encapsulation dot1Q 3
 ip address 172.24.5.254 255.255.255.0
!
interface FastEthernet0/0.199
 description QUANTUM WAN - DATA - ENCRYPTED
 encapsulation dot1Q 199
 ip address 172.24.199.5 255.255.255.0
 crypto map mid-or
!
interface FastEthernet0/0.200
 description QUANTUM WAN - VOIP
 encapsulation dot1Q 200
 ip address 172.24.200.5 255.255.255.0
!
interface FastEthernet0/1
 description INTERNET - CRESTVIEW CABLE
 ip address dhcp
 ip access-group firewall in
 ip nat outside
 ip inspect mid-oregon in
 ip inspect mid-oregon out
 ip virtual-reassembly
 duplex auto
 speed auto
 crypto map mid-or-outside
 !
!
router ospf 99
 log-adjacency-changes
 network 10.5.0.0 0.0.255.255 area 2
 network 172.24.5.0 0.0.0.255 area 1
 network 172.24.199.0 0.0.0.255 area 2
 network 172.24.200.0 0.0.0.255 area 1
!
ip default-gateway 192.168.252.1
ip forward-protocol nd
no ip http server
ip http secure-server
!
!
ip nat inside source list 169 interface FastEthernet0/1 overload
ip route 0.0.0.0 0.0.0.0 64.77.196.1 200
ip route 10.222.222.1 255.255.255.255 64.77.196.1
ip route 216.228.182.49 255.255.255.255 64.77.196.1
!
ip access-list extended firewall
 permit udp any eq bootps any eq bootpc
 permit udp host 216.228.182.49 host 64.77.196.114
 permit esp host 216.228.182.49 host 64.77.196.114
 deny   ip any any
ip access-list extended gre-acl-in
 permit ip any any
ip access-list extended gre-acl-out
 permit ip any any
!
logging trap debugging
logging facility local2
logging 10.1.1.5
logging 10.1.1.20
access-list 111 permit ip 10.5.0.0 0.0.255.255 10.1.0.0 0.0.255.255
access-list 112 permit ip 10.5.0.0 0.0.255.255 10.2.0.0 0.0.255.255
access-list 113 permit ip 10.5.0.0 0.0.255.255 10.3.0.0 0.0.255.255
access-list 114 permit ip 10.5.0.0 0.0.255.255 10.4.0.0 0.0.255.255
access-list 116 permit ip 10.5.0.0 0.0.255.255 10.6.0.0 0.0.255.255
access-list 117 permit ip 10.5.0.0 0.0.255.255 10.7.0.0 0.0.255.255
access-list 126 permit ip host 10.222.222.14 host 10.222.222.1
access-list 169 deny   ip 172.24.5.0 0.0.0.255 any
access-list 169 permit ip 10.5.0.0 0.0.255.255 any
!
!
!
!
snmp-server community $ucfom$ RO
snmp-server community OBSID-RO RO
!
!
control-plane
 !
!
!
voice-port 0/1/0
 timing hookflash-out 500
 connection plar 6209
!
voice-port 0/1/1
 timing hookflash-out 500
 connection plar 6209
!
no ccm-manager fax protocol cisco
!
no mgcp package-capability res-package
no mgcp package-capability fxr-package
no mgcp timer receive-rtcp
!
!
dial-peer cor custom
 name outbound
 name inbound
!
!
dial-peer cor list Outbound
 member outbound
!
dial-peer cor list Inbound
 member inbound
!
!
dial-peer voice 100 pots
 preference 1
 destination-pattern 911
 incoming called-number .
 no digit-strip
 direct-inward-dial
 port 0/1/0
!
dial-peer voice 101 pots
 preference 2
 destination-pattern 911
 incoming called-number .
 no digit-strip
 direct-inward-dial
 port 0/1/1
!
dial-peer voice 102 pots
 preference 1
 destination-pattern 14043940384
 incoming called-number .
 no digit-strip
 direct-inward-dial
 port 0/1/0
!
dial-peer voice 103 pots
 preference 2
 shutdown
 destination-pattern 4043940384
 incoming called-number .
 no digit-strip
 direct-inward-dial
 port 0/1/1
!
dial-peer voice 200 voip
 preference 1
 destination-pattern .T
 session protocol sipv2
 session target ipv4:10.3.1.80:5060
 voice-class codec 100
 dtmf-relay rtp-nte digit-drop
 fax-relay ecm disable
 no vad
!
dial-peer voice 201 voip
 preference 2
 destination-pattern .T
 session protocol sipv2
 session target ipv4:10.1.1.81:5060
 voice-class codec 100
 dtmf-relay rtp-nte digit-drop
 fax-relay ecm disable
 no vad
!
!
no dial-peer outbound status-check pots
sip-ua
 disable-early-media 180
 retry invite 2
 timers connect 100
 timers buffer-invite 1000
!
!
!
line con 0
 login authentication local_authen
 transport output telnet ssh
line aux 0
 login authentication local_authen
 transport output telnet
line vty 0 4
 authorization exec local_author
 login authentication local_authen
 transport input ssh
 transport output telnet ssh
!
scheduler allocate 20000 1000
ntp update-calendar
ntp server 172.24.199.1 prefer
ntp server 192.43.244.18 source FastEthernet0/1
end

MADRAS-2811#
001166: Jun 23 09:34:24.854 PDT: //19/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
   Call Entry Is Not Found
001167: Jun 23 09:34:24.858 PDT: //-1/8B0B3F9C8038/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=5413821795
   ----- ccCallInfo IE subfields -----
   cisco-ani=5413821795
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=14043940384
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-lastrdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

001168: Jun 23 09:34:24.858 PDT: //-1/8B0B3F9C8038/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x495DC480, Call Info(
   Calling Number=5413821795,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=200, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=19
001169: Jun 23 09:34:24.858 PDT: //-1/8B0B3F9C8038/CCAPI/ccCheckClipClir:
   In: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001170: Jun 23 09:34:24.858 PDT: //-1/8B0B3F9C8038/CCAPI/ccCheckClipClir:
   Out: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001171: Jun 23 09:34:24.858 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001172: Jun 23 09:34:24.858 PDT: :cc_get_feature_vsa malloc success
001173: Jun 23 09:34:24.858 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001174: Jun 23 09:34:24.858 PDT:  cc_get_feature_vsa count is 1
001175: Jun 23 09:34:24.858 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001176: Jun 23 09:34:24.858 PDT: :FEATURE_VSA attributes are: feature_name:0,feature_time:1252279848,feature_id:19
001177: Jun 23 09:34:24.858 PDT: //19/8B0B3F9C8038/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown))
001178: Jun 23 09:34:24.862 PDT: //19/8B0B3F9C8038/CCAPI/cc_process_call_setup_ind:
   Event=0x49DC4F60
001179: Jun 23 09:34:24.862 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 14043940384
001180: Jun 23 09:34:24.862 PDT: //19/8B0B3F9C8038/CCAPI/ccCallSetContext:
   Context=0x48D98914
001181: Jun 23 09:34:24.862 PDT: //19/8B0B3F9C8038/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 19 with tag 200 to app "_ManagedAppProcess_Default"
001182: Jun 23 09:34:24.866 PDT: //19/8B0B3F9C8038/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
001183: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=102, Params=0x48D99C6C, Progress Indication=NULL(0)
001184: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/ccCheckClipClir:
   In: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001185: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/ccCheckClipClir:
   Out: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001186: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/ccCallSetupRequest:
   Destination Pattern=14043940384, Called Number=14043940384, Digit Strip=FALSE
001187: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/ccCallSetupRequest:
   Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=5413821795, Final Destination Flag=TRUE,
   Guid=8B0B3F9C-18FC-11E5-8038-9DD770812C35, Outgoing Dial-peer=102
001188: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=5413821795
   ----- ccCallInfo IE subfields -----
   cisco-ani=5413821795
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=14043940384
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-lastrdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

001189: Jun 23 09:34:24.870 PDT: //19/8B0B3F9C8038/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x49E0A754, Interface Type=6, Destination=, Mode=0x0,
   Call Params(Calling Number=5413821795,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=102, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
001190: Jun 23 09:34:24.870 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001191: Jun 23 09:34:24.870 PDT: :cc_get_feature_vsa malloc success
001192: Jun 23 09:34:24.870 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001193: Jun 23 09:34:24.870 PDT:  cc_get_feature_vsa count is 2
001194: Jun 23 09:34:24.870 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001195: Jun 23 09:34:24.870 PDT: :FEATURE_VSA attributes are: feature_name:0,feature_time:1252279624,feature_id:20
001196: Jun 23 09:34:24.874 PDT: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb:  
   CDB=0x4ACA61B8
001197: Jun 23 09:34:24.874 PDT: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
001198: Jun 23 09:34:24.874 PDT: //20/8B0B3F9C8038/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
001199: Jun 23 09:34:24.874 PDT: //20/8B0B3F9C8038/CCAPI/ccCallSetContext:
   Context=0x48D99C1C
001200: Jun 23 09:34:24.874 PDT: //19/8B0B3F9C8038/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=102
001201: Jun 23 09:34:24.874 PDT: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:  
   [state:INVALID STATE MACHINE, event:E_CC_SETUP_REQ]
001202: Jun 23 09:34:24.874 PDT: htsp_timer_stop3
001203: Jun 23 09:34:24.874 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/vtsp_og_call_req:  
   Echo Cancel=TRUE, Gain Control=0
   Auto Gain Control=FALSE, Dual Tone Detect Mask=0x0, Seq Tone Detect=FALSE
001204: Jun 23 09:34:24.874 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_req:
001205: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
001206: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_SETUP_REQ_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
001207: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_setup_req_pend_succ:
001208: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_request_call:  
   Mode=0, Peer=102
001209: Jun 23 09:34:24.878 PDT: digit_strip:0, pcn:14043940384, poa:14043940384
001210: Jun 23 09:34:24.878 PDT: Final pcn:14043940384, poa:14043940384, dial_string:14043940384
001211: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req:  
   Target Carrier ID=
001212: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req:  
   Source Carrier ID=htsp_setup_req
001213: Jun 23 09:34:24.878 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_request_call:  
   Progress Indication=0, Info Trans Capability=0
   Calling Number=5413821795, TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed
   Called Number=14043940384, TON=Unknown, NPI=Unknown
001214: Jun 23 09:34:24.878 PDT: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
001215: Jun 23 09:34:24.878 PDT: [0/1/0] set signal state = 0xC timestamp = 0
001216: Jun 23 09:34:24.878 PDT: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0xC timestamp=0x0
001217: Jun 23 09:34:24.882 PDT: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
001218: Jun 23 09:34:24.882 PDT: htsp_timer - 1300 msec
001219: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_SETUP_REQUEST, event:E_TSP_PROCEEDING]
001220: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding:
001221: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_timer:  
   Timer Start Time=113182230, Timer Value=25000(ms)
001222: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/CCAPI/cc_api_call_proceeding:
   Interface=0x49E0A754, Progress Indication=NULL(0)
001223: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding:  
   Peer=102, Progress Indication=0, Return Code=2
001224: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
001225: Jun 23 09:34:24.882 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_NULL, event:E_VTSP_DSM_OPEN_SUCCESS]
001226: Jun 23 09:34:24.886 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_setup_req_wait_pend_success:  
   Event=75
001227: Jun 23 09:34:24.886 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:  
   Timer Stop Time=113182230
001228: Jun 23 09:34:25.134 PDT: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_1100]fxols_power_denial_detected
001229: Jun 23 09:34:25.134 PDT: htsp_timer2 - 1000 msec
001230: Jun 23 09:34:25.134 PDT: htsp_timer_stop
001231: Jun 23 09:34:26.134 PDT: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER2]fxols_power_den_disc
001232: Jun 23 09:34:26.134 PDT: htsp_timer_stop
001233: Jun 23 09:34:26.134 PDT: htsp_timer_stop2
001234: Jun 23 09:34:26.134 PDT: [0/1/0] set signal state = 0x4 timestamp = 0
001235: Jun 23 09:34:26.134 PDT: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0x4 timestamp=0x0
001236: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_SETUP_REQ_PROC, event:E_TSP_DISCONNECT_IND]
001237: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_setup_pend_release_ind:  
   Cause Value=34
001238: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop:  
   Timer Stop Time=113182355
001239: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_cc_call_disconnected:
001240: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_cc_call_disconnected:  
   Cause Value=34
001241: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/CCAPI/cc_api_call_disconnected:
   Cause Value=34, Interface=0x49E0A754, Call Id=20
001242: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=34, Retry Count=0)
001243: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_set_release_source:  
   Release Direction=PSTN, Release Source=Called Party-PSTN
001244: Jun 23 09:34:26.134 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_setup_pend_release_ind:  
   Peer=102
001245: Jun 23 09:34:26.134 PDT: //19/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
001246: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/CCAPI/ccCallSetAAA_Accounting:
   Accounting=1, Call Id=20
001247: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/CCAPI/ccCallDisconnect:
   Cause Value=34, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=34)
001248: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/CCAPI/ccCallDisconnect:
   Cause Value=34, Call Entry(Responsed=TRUE, Cause Value=34)
001249: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_call_disconnect:  
   [Out Of Service]-Tone Played In Direction [Both]
001250: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_HOST_DISC, event:E_CC_DISCONNECT]
001251: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_host_disc_cleanup:  
   dsm_indicate_error=0, short_cleardown_timeout=0, Mode=0
001252: Jun 23 09:34:26.138 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_host_disc_cleanup:  
   Exit State=16
001253: Jun 23 09:34:26.138 PDT: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
001254: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
001255: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
001256: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_dsm_dsp_stats_complete: htsp_release_req: cause 34, no_onhook 0
001257: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_timer:  
   Timer Start Time=113182356, Timer Value=60000(ms)
001258: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_RELEASE, event:E_VTSP_DSM_STATS_COMPLETE]
001259: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   Unexpected EVENT [E_VTSP_DSM_STATS_COMPLETE] Received For STATE [S_WAIT_RELEASE];
   Previous STATE [0.16 ]
001260: Jun 23 09:34:26.142 PDT: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_HTSP_RELEASE_REQ]fxols_onhook_release
001261: Jun 23 09:34:26.142 PDT: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
001262: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
001263: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
001264: Jun 23 09:34:26.142 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop:  
   Timer Stop Time=113182356
001265: Jun 23 09:34:26.146 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:  
   Timer Stop Time=113182356
001266: Jun 23 09:34:26.146 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
001267: Jun 23 09:34:26.146 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:  
   Coder Rate=-1
001268: Jun 23 09:34:26.146 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:1:1/vtsp_is_valid_dsm_handle:  
   DMGR=0x4A787BF4, VTSP CDB=0x4ACA61B8
001269: Jun 23 09:34:26.150 PDT: flex_dsprm_close_cleanup
001270: Jun 23 09:34:26.150 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/vtsp_dsm_closed_cb:
001271: Jun 23 09:34:26.150 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:  
   [state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
001272: Jun 23 09:34:26.150 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/act_terminate:
001273: Jun 23 09:34:26.150 PDT: //20/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/vtsp_timer_stop:  
   Timer Stop Time=113182357
001274: Jun 23 09:34:26.150 PDT: //20/8B0B3F9C8038/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x49E0A754, Tag=0x0, Call Id=20,
   Call Entry(Disconnect Cause=34, Voice Class Cause Code=0, Retry Count=0)
001275: Jun 23 09:34:26.150 PDT: //20/8B0B3F9C8038/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
001276: Jun 23 09:34:26.150 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001277: Jun 23 09:34:26.150 PDT: :cc_free_feature_vsa freeing 4AA44540
001278: Jun 23 09:34:26.150 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001279: Jun 23 09:34:26.154 PDT:  vsacount in free is 1
001280: Jun 23 09:34:26.154 PDT: //-1/8B0B3F9C8038/VTSP:(0/1/0):-1:-1:-1/vtsp_free_cdb:  
   CDB=0x4ACA61B8
001281: Jun 23 09:34:26.154 PDT: //19/8B0B3F9C8038/CCAPI/ccCallDisconnect:
   Cause Value=34, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
001282: Jun 23 09:34:26.154 PDT: //19/8B0B3F9C8038/CCAPI/ccCallDisconnect:
   Cause Value=34, Call Entry(Responsed=TRUE, Cause Value=34)
001283: Jun 23 09:34:26.194 PDT: //19/8B0B3F9C8038/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x495DC480, Tag=0x0, Call Id=19,
   Call Entry(Disconnect Cause=34, Voice Class Cause Code=0, Retry Count=0)
001284: Jun 23 09:34:26.194 PDT: //19/8B0B3F9C8038/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
001285: Jun 23 09:34:26.194 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001286: Jun 23 09:34:26.194 PDT: :cc_free_feature_vsa freeing 4AA44620
001287: Jun 23 09:34:26.194 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001288: Jun 23 09:34:26.194 PDT:  vsacount in free is 0
MADRAS-2811#
MADRAS-2811#
MADRAS-2811#
MADRAS-2811#
MADRAS-2811#
MADRAS-2811#
MADRAS-2811#
001289: Jun 23 09:36:31.175 PDT: //21/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
   Call Entry Is Not Found
001290: Jun 23 09:36:31.179 PDT: //-1/D6594EAD803E/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=5413821795
   ----- ccCallInfo IE subfields -----
   cisco-ani=5413821795
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=14043940384
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-lastrdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

001291: Jun 23 09:36:31.179 PDT: //-1/D6594EAD803E/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x495DC480, Call Info(
   Calling Number=5413821795,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=200, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=21
001292: Jun 23 09:36:31.179 PDT: //-1/D6594EAD803E/CCAPI/ccCheckClipClir:
   In: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001293: Jun 23 09:36:31.179 PDT: //-1/D6594EAD803E/CCAPI/ccCheckClipClir:
   Out: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001294: Jun 23 09:36:31.179 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001295: Jun 23 09:36:31.179 PDT: :cc_get_feature_vsa malloc success
001296: Jun 23 09:36:31.179 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001297: Jun 23 09:36:31.179 PDT:  cc_get_feature_vsa count is 1
001298: Jun 23 09:36:31.179 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001299: Jun 23 09:36:31.179 PDT: :FEATURE_VSA attributes are: feature_name:0,feature_time:1252279848,feature_id:21
001300: Jun 23 09:36:31.183 PDT: //21/D6594EAD803E/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown))
001301: Jun 23 09:36:31.183 PDT: //21/D6594EAD803E/CCAPI/cc_process_call_setup_ind:
   Event=0x49DC4F60
001302: Jun 23 09:36:31.183 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 14043940384
001303: Jun 23 09:36:31.183 PDT: //21/D6594EAD803E/CCAPI/ccCallSetContext:
   Context=0x48D83284
001304: Jun 23 09:36:31.183 PDT: //21/D6594EAD803E/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 21 with tag 200 to app "_ManagedAppProcess_Default"
001305: Jun 23 09:36:31.187 PDT: //21/D6594EAD803E/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
001306: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=102, Params=0x48D858E4, Progress Indication=NULL(0)
001307: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/ccCheckClipClir:
   In: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001308: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/ccCheckClipClir:
   Out: Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
001309: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/ccCallSetupRequest:
   Destination Pattern=14043940384, Called Number=14043940384, Digit Strip=FALSE
001310: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/ccCallSetupRequest:
   Calling Number=5413821795(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=5413821795, Final Destination Flag=TRUE,
   Guid=D6594EAD-18FC-11E5-803E-9DD770812C35, Outgoing Dial-peer=102
001311: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=5413821795
   ----- ccCallInfo IE subfields -----
   cisco-ani=5413821795
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=14043940384
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-lastrdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

001312: Jun 23 09:36:31.191 PDT: //21/D6594EAD803E/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x49E0A754, Interface Type=6, Destination=, Mode=0x0,
   Call Params(Calling Number=5413821795,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=14043940384(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=102, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
001313: Jun 23 09:36:31.191 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001314: Jun 23 09:36:31.191 PDT: :cc_get_feature_vsa malloc success
001315: Jun 23 09:36:31.191 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001316: Jun 23 09:36:31.191 PDT:  cc_get_feature_vsa count is 2
001317: Jun 23 09:36:31.191 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
001318: Jun 23 09:36:31.195 PDT: :FEATURE_VSA attributes are: feature_name:0,feature_time:1252279624,feature_id:22
001319: Jun 23 09:36:31.195 PDT: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb:  
   CDB=0x4ACA61B8
001320: Jun 23 09:36:31.195 PDT: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
001321: Jun 23 09:36:31.195 PDT: //22/D6594EAD803E/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
001322: Jun 23 09:36:31.195 PDT: //22/D6594EAD803E/CCAPI/ccCallSetContext:
   Context=0x48D85894
001323: Jun 23 09:36:31.195 PDT: //21/D6594EAD803E/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=102
001324: Jun 23 09:36:31.195 PDT: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:  
   [state:INVALID STATE MACHINE, event:E_CC_SETUP_REQ]
001325: Jun 23 09:36:31.195 PDT: htsp_timer_stop3
001326: Jun 23 09:36:31.195 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/vtsp_og_call_req:  
   Echo Cancel=TRUE, Gain Control=0
   Auto Gain Control=FALSE, Dual Tone Detect Mask=0x0, Seq Tone Detect=FALSE
001327: Jun 23 09:36:31.195 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_req:
001328: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
001329: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_SETUP_REQ_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
001330: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_setup_req_pend_succ:
001331: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_request_call:  
   Mode=0, Peer=102
001332: Jun 23 09:36:31.199 PDT: digit_strip:0, pcn:14043940384, poa:14043940384
001333: Jun 23 09:36:31.199 PDT: Final pcn:14043940384, poa:14043940384, dial_string:14043940384
001334: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req:  
   Target Carrier ID=
001335: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_create_call_active_on_setup_req:  
   Source Carrier ID=htsp_setup_req
001336: Jun 23 09:36:31.199 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_request_call:  
   Progress Indication=0, Info Trans Capability=0
   Calling Number=5413821795, TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed
   Called Number=14043940384, TON=Unknown, NPI=Unknown
001337: Jun 23 09:36:31.203 PDT: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
001338: Jun 23 09:36:31.203 PDT: [0/1/0] set signal state = 0xC timestamp = 0
001339: Jun 23 09:36:31.203 PDT: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0xC timestamp=0x0
001340: Jun 23 09:36:31.203 PDT: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
001341: Jun 23 09:36:31.203 PDT: htsp_timer - 1300 msec
001342: Jun 23 09:36:31.203 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_SETUP_REQUEST, event:E_TSP_PROCEEDING]
001343: Jun 23 09:36:31.203 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding:
001344: Jun 23 09:36:31.203 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_timer:  
   Timer Start Time=113194862, Timer Value=25000(ms)
001345: Jun 23 09:36:31.203 PDT: //22/D6594EAD803E/CCAPI/cc_api_call_proceeding:
   Interface=0x49E0A754, Progress Indication=NULL(0)
001346: Jun 23 09:36:31.203 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_setup_pend_proceeding:  
   Peer=102, Progress Indication=0, Return Code=2
001347: Jun 23 09:36:31.203 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_dsm_opened_cb:
001348: Jun 23 09:36:31.207 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_NULL, event:E_VTSP_DSM_OPEN_SUCCESS]
001349: Jun 23 09:36:31.207 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_setup_req_wait_pend_success:  
   Event=75
001350: Jun 23 09:36:31.207 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:  
   Timer Stop Time=113194862
001351: Jun 23 09:36:31.455 PDT: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_1100]fxols_power_denial_detected
001352: Jun 23 09:36:31.455 PDT: htsp_timer2 - 1000 msec
001353: Jun 23 09:36:31.455 PDT: htsp_timer_stop
001354: Jun 23 09:36:32.455 PDT: htsp_process_event: [0/1/0, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER2]fxols_power_den_disc
001355: Jun 23 09:36:32.455 PDT: htsp_timer_stop
001356: Jun 23 09:36:32.455 PDT: htsp_timer_stop2
001357: Jun 23 09:36:32.455 PDT: [0/1/0] set signal state = 0x4 timestamp = 0
001358: Jun 23 09:36:32.455 PDT: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0x4 timestamp=0x0
001359: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_SETUP_REQ_PROC, event:E_TSP_DISCONNECT_IND]
001360: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_setup_pend_release_ind:  
   Cause Value=34
001361: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop:  
   Timer Stop Time=113194987
001362: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_cc_call_disconnected:
001363: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_cc_call_disconnected:  
   Cause Value=34
001364: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/CCAPI/cc_api_call_disconnected:
   Cause Value=34, Interface=0x49E0A754, Call Id=22
001365: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=34, Retry Count=0)
001366: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_set_release_source:  
   Release Direction=PSTN, Release Source=Called Party-PSTN
001367: Jun 23 09:36:32.455 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_setup_pend_release_ind:  
   Peer=102
001368: Jun 23 09:36:32.455 PDT: //21/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
001369: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/CCAPI/ccCallSetAAA_Accounting:
   Accounting=1, Call Id=22
001370: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/CCAPI/ccCallDisconnect:
   Cause Value=34, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=34)
001371: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/CCAPI/ccCallDisconnect:
   Cause Value=34, Call Entry(Responsed=TRUE, Cause Value=34)
001372: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_call_disconnect:  
   [Out Of Service]-Tone Played In Direction [Both]
001373: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_HOST_DISC, event:E_CC_DISCONNECT]
001374: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_host_disc_cleanup:  
   dsm_indicate_error=0, short_cleardown_timeout=0, Mode=0
001375: Jun 23 09:36:32.459 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_host_disc_cleanup:  
   Exit State=16
001376: Jun 23 09:36:32.459 PDT: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
001377: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
001378: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
001379: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_dsm_dsp_stats_complete: htsp_release_req: cause 34, no_onhook 0
001380: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_timer:  
   Timer Start Time=113194988, Timer Value=60000(ms)
001381: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_RELEASE, event:E_VTSP_DSM_STATS_COMPLETE]
001382: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   Unexpected EVENT [E_VTSP_DSM_STATS_COMPLETE] Received For STATE [S_WAIT_RELEASE];
   Previous STATE [0.16 ]
001383: Jun 23 09:36:32.463 PDT: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_HTSP_RELEASE_REQ]fxols_onhook_release
001384: Jun 23 09:36:32.463 PDT: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
001385: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_process_event:  
   [state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
001386: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
001387: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop:  
   Timer Stop Time=113194988
001388: Jun 23 09:36:32.463 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:  
   Timer Stop Time=113194988
001389: Jun 23 09:36:32.467 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:
001390: Jun 23 09:36:32.467 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_do_call_history:  
   Coder Rate=-1
001391: Jun 23 09:36:32.467 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:1:1/vtsp_is_valid_dsm_handle:  
   DMGR=0x4A787BF4, VTSP CDB=0x4ACA61B8
001392: Jun 23 09:36:32.471 PDT: flex_dsprm_close_cleanup
001393: Jun 23 09:36:32.471 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/vtsp_dsm_closed_cb:
001394: Jun 23 09:36:32.471 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:  
   [state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
001395: Jun 23 09:36:32.471 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/act_terminate:
001396: Jun 23 09:36:32.471 PDT: //22/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/vtsp_timer_stop:  
   Timer Stop Time=113194989
001397: Jun 23 09:36:32.471 PDT: //22/D6594EAD803E/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x49E0A754, Tag=0x0, Call Id=22,
   Call Entry(Disconnect Cause=34, Voice Class Cause Code=0, Retry Count=0)
001398: Jun 23 09:36:32.475 PDT: //22/D6594EAD803E/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
001399: Jun 23 09:36:32.475 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001400: Jun 23 09:36:32.475 PDT: :cc_free_feature_vsa freeing 4AA44540
001401: Jun 23 09:36:32.475 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001402: Jun 23 09:36:32.475 PDT:  vsacount in free is 1
001403: Jun 23 09:36:32.475 PDT: //-1/D6594EAD803E/VTSP:(0/1/0):-1:-1:-1/vtsp_free_cdb:  
   CDB=0x4ACA61B8
001404: Jun 23 09:36:32.479 PDT: //21/D6594EAD803E/CCAPI/ccCallDisconnect:
   Cause Value=34, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
001405: Jun 23 09:36:32.479 PDT: //21/D6594EAD803E/CCAPI/ccCallDisconnect:
   Cause Value=34, Call Entry(Responsed=TRUE, Cause Value=34)
001406: Jun 23 09:36:32.515 PDT: //21/D6594EAD803E/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x495DC480, Tag=0x0, Call Id=21,
   Call Entry(Disconnect Cause=34, Voice Class Cause Code=0, Retry Count=0)
001407: Jun 23 09:36:32.515 PDT: //21/D6594EAD803E/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
001408: Jun 23 09:36:32.515 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001409: Jun 23 09:36:32.515 PDT: :cc_free_feature_vsa freeing 4AA44620
001410: Jun 23 09:36:32.519 PDT: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
001411: Jun 23 09:36:32.519 PDT:  vsacount in free is 0

 

 

 

 

1 Reply 1

Nadeem Ahmed
Cisco Employee
Cisco Employee

Can you pls eloborate the Problem  in bit more details from where to where the calls are failing, I am assuming you having an outbound call issue on certain ports which fails.

 

looking at the logs and cause value you are getting cause value 34 which

 

   Cause Value=34, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
001405: Jun 23 09:36:32.479 PDT: //21/D6594EAD803E/CCAPI/ccCallDisconnect:
   Cause Value=34, Call Entry(Responsed=TRUE, Cause Value=34)

 

Cause No. 34 - no circuit/channel available.
This cause indicates that there is no appropriate circuit/channel presently available to handle the call.

 

Regards

Nadeem Ahmed

Br, Nadeem Please rate all useful post.