CME to CME over internet behind NAT/PAT on both sides scenario

JeanMJeanM Member Posts: 1,117
Hi,

I have a couple CME running routers with FXS cards/analog phones, and I would like to understand how the following scenario would work if possible.

Imagine you plugging in a CME router to your soho internet router , and then I would do the same on my side. So, essentially both sides would be behind edge/NAT routers.

What am I missing here for this to work? I am thinking I would need to add ip/port forwarding on each Edge router for port 2000 to inside local lan IP address running CME on each side?

Is this doable w/o first establishing ipsec vpn tunnel over the internet or using a SIP trunk provider?

Take a look at the simulation in packet tracer (minus telephony-server config), how would you establish connectivity between two Call Managers when each side is behind a NAT?

Thanks :)
2015 goals - ccna voice / vmware vcp.
«1

Comments

  • JeanMJeanM Member Posts: 1,117
    Example . I also tried setting up a static route on each edge side as well, didn't make a difference. I understand this wouldn't be a good idea or design anyway....but tried it for kicks anyway.

    Sh access-list , does show that the access list is getting hits when you ping from one side to another.

    2015 goals - ccna voice / vmware vcp.
  • azaghulazaghul Member Posts: 569 ■■■■□□□□□□
    I run a UC520 at home behind my ADSL router (in bridged mode), CME via a SIP trunk...working fine (nowicon_lol.gif).

    Been a while since I tried your scenario, but maybe try forwarding port 2000 on the WAN side to the CME source address? Or it could be a quirk of PacketTracer...
  • JeanMJeanM Member Posts: 1,117
    Hmm, maybe it is a PT glitch? Did you have to enable port forwarding on your ADSL router for UC520?
    2015 goals - ccna voice / vmware vcp.
  • azaghulazaghul Member Posts: 569 ■■■■□□□□□□
    Been a while since I've tested it that way, as I forward port 5060 for SIP, so it should be the same for SCCP.
  • JeanMJeanM Member Posts: 1,117
    azaghul wrote: »
    Been a while since I've tested it that way, as I forward port 5060 for SIP, so it should be the same for SCCP.


    I think in this case example above with CME with FXS/Analog phones (not CUCM) it's just H323, not SCCP/SIP?
    2015 goals - ccna voice / vmware vcp.
  • azaghulazaghul Member Posts: 569 ■■■■□□□□□□
    I think we are getting into the limitations of PT...

    I'm digging deep here, so could be way off the mark icon_rolleyes.gif...shodown & pitviper are the go-to guys on all things Cisco voip.
    • the analogue phone appears as an eFXS to the router and then talks SCCP internally,
    • the Cisco native (default) signalling/media protocol over the WAN is H323, so should be no need to worry about port 2000 (SCCP internal only),
    • the voip dial-peer session target points to the WAN router loopback address(?) to which you bind H323 (h323-gateway voip bind srcaddr <ip-address>)
    • on the CME router you point the telephony-service source-address to the WAN loopback(?)
    As I said I'm probably way off, I don't do VoIP at work so the skills are rusty.

    I guess alot also depends if you are using a service provider VPN, a point-to-point tunnel, or just the internet as the WAN.
  • JeanMJeanM Member Posts: 1,117
    azaghul wrote: »
    I think we are getting into the limitations of PT...

    I'm digging deep here, so could be way off the mark icon_rolleyes.gif...shodown & pitviper are the go-to guys on all things Cisco voip.
    • the analogue phone appears as an eFXS to the router and then talks SCCP internally,
    • the Cisco native (default) signalling/media protocol over the WAN is H323, so should be no need to worry about port 2000 (SCCP internal only),
    • the voip dial-peer session target points to the WAN router loopback address(?) to which you bind H323 (h323-gateway voip bind srcaddr <ip-address>)
    • on the CME router you point the telephony-service source-address to the WAN loopback(?)
    As I said I'm probably way off, I don't do VoIP at work so the skills are rusty.

    I guess alot also depends if you are using a service provider VPN, a point-to-point tunnel, or just the internet as the WAN.

    For this specific example, just internet as the WAN, not utilizing VPN.

    I am going to spin this up on my physical lab tomorrow and see if I get the same results as in PT.
    2015 goals - ccna voice / vmware vcp.
  • JeanMJeanM Member Posts: 1,117
    Ok, so I spun this topology in my lab. When dialing the phone number from CME A router to the CME B router, it's matching a dial peer and sends the call to the 20.20.20.2 ip address, ip address of the outside nat interface on the EDGE B router facing the wan.


    dial-peer voice 1 voip
    description TO call other CME over WAN
    destination-pattern 2...
    session target ipv4:20.20.20.2
    dtmf-relay h245-alphanumeric

    I see that the voip dial peer is hitting the first NAT for the CME A router and also the second NAT router for the remote CME B is also incrementing.

    EDGE_NAT_A#sh ip nat translations
    Pro Inside global Inside local Outside local Outside global
    tcp 10.10.10.2:2 10.10.10.2:23 20.20.20.2:1026 20.20.20.2:1026
    tcp 10.10.10.2:6 10.10.10.2:23 20.20.20.2:1032 20.20.20.2:1032
    tcp 10.10.10.2:1024 10.10.10.2:43286 1.1.1.12:23 1.1.1.12:23
    tcp 10.10.10.2:1025 10.10.10.2:1024 1.1.1.12:23 1.1.1.12:23
    tcp 10.10.10.2:18636 192.168.1.200:18636 20.20.20.2:1720 20.20.20.2:1720


    before call

    EDGE_NAT_B#sh ip nat translations
    Pro Inside global Inside local Outside local Outside global
    udp 20.20.20.2:123 65.65.65.200:123 192.168.1.7:123 192.168.1.7:123
    tcp 20.20.20.2:1 20.20.20.2:23 10.10.10.2:29220 10.10.10.2:29220
    tcp 20.20.20.2:2 20.20.20.2:1 10.10.10.2:29220 10.10.10.2:29220
    EDGE_NAT_B#

    during making the call from CME A to CME B


    EDGE_NAT_B#
    EDGE_NAT_B#sh ip nat translations
    Pro Inside global Inside local Outside local Outside global
    tcp 20.20.20.2:1044 20.20.20.2:1720 10.10.10.2:16660 10.10.10.2:16660
    udp 20.20.20.2:123 65.65.65.200:123 192.168.1.7:123 192.168.1.7:123
    tcp 20.20.20.2:1 20.20.20.2:23 10.10.10.2:29220 10.10.10.2:29220
    tcp 20.20.20.2:2 20.20.20.2:1 10.10.10.2:29220 10.10.10.2:29220

    After a few seconds I get a fast busy.

    So, what else do I need to set up on the EDGE NAT routers to be able to translate the packets from CME_A to CME_B and the other way around?

    I am currently pointing the voip dial peer to the remote OUTSIDE NAT address, since I think pointing to the INSIDE NAT interface wouldn't be correct in this case? Since it can be a local LAN address anyway?

    Do I need to set up a static translation rule to go from 20.20.20.2 (edge/nat_B outside ip) to 65.65.65.200 (cme_b ip address) ? And the same 10.10.10.2 (edge/nat_A outside ip to 192.168.1.200 (cme_a ip) ?

    Something like this on each EDGE/NAT router https://supportforums.cisco.com/discussion/11786016/ios-port-forwarding-commands-port-forwarding ?
    2015 goals - ccna voice / vmware vcp.
  • JeanMJeanM Member Posts: 1,117
    Ok so made some progress, it's still not working 100% but here is the latest. I've changed the edge nat config to static to re-direct anything hitting 10.10.10.2 to 192.168.1.200(cme) and anything hitting 20.20.20.2 to 65.65.65.200 (cme). See below .

    Call signaling appears to be working, I can call from one side to the other over the wan cloud and through two edge/nat routers, but there is no audio either way.

    CME A dial peer

    dial-peer voice 1 voip
    description TO call other CME over WAN
    destination-pattern 7...
    session target ipv4:20.20.20.2
    dtmf-relay h245-alphanumeric

    telephony-service
    max-ephones 30
    max-dn 30
    ip source-address 192.168.1.200 port 2000
    auto assign 1 to 1
    create cnf-files version-stamp 7960 Jan 03 2015 18:33:06
    max-conferences 4 gain -6
    transfer-system full-consult
    !

    CME A ip config


    interface FastEthernet0/0
    description TO EDGE
    ip address 192.168.1.200 255.255.255.0
    duplex auto
    speed auto
    !
    !
    ip forward-protocol nd
    ip route 0.0.0.0 0.0.0.0 192.168.1.100
    !


    CME_A_#sh voip rtp connections
    VoIP RTP active connections :
    No. CallId dstCallId LocalRTP RmtRTP LocalIP RemoteIP
    1 17 16 19014 16964 192.168.1.200 65.65.65.200
    Found 1 active RTP connections
    CME_A_#



    CME B dial peer

    dial-peer voice 1 voip
    description to call OTHER CME over WAN
    destination-pattern 66..
    session target ipv4:10.10.10.2
    !
    !
    !
    telephony-service
    max-ephones 30
    max-dn 30
    ip source-address 65.65.65.200 port 2000
    auto assign 1 to 1
    max-conferences 4 gain -6
    transfer-system full-consult


    interface FastEthernet0/0
    description TO SP CLOUD
    ip address 65.65.65.200 255.255.255.0
    duplex auto
    speed auto
    !
    !
    ip forward-protocol nd
    ip route 0.0.0.0 0.0.0.0 65.65.65.100
    !


    CME_B#sh voip rtp connections
    VoIP RTP active connections :
    No. CallId dstCallId LocalRTP RmtRTP LocalIP RemoteIP
    1 2 3 16964 19014 65.65.65.200 192.168.1.200
    Found 1 active RTP connections
    CME_B#


    EDGE A NAT router



    interface FastEthernet0/0
    description INSIDE TO CME
    ip address 192.168.1.100 255.255.255.0
    ip nat inside
    duplex auto
    speed auto
    !
    !
    interface FastEthernet0/1
    description TO WAN CLOUD
    ip address 10.10.10.2 255.255.255.0
    ip nat outside
    duplex auto
    speed auto
    !
    !
    ip nat inside source static 192.168.1.200 10.10.10.2
    ip http server
    ip classless
    ip route 0.0.0.0 0.0.0.0 10.10.10.1



    EDGE_NAT_A#sh ip nat translations
    Pro Inside global Inside local Outside local Outside global
    --- 10.10.10.2 192.168.1.200 --- ---
    EDGE_NAT_A#

    EDGE B NAT router



    interface FastEthernet0/0
    description TO CME SIDE
    ip address 65.65.65.100 255.255.255.0
    ip nat inside
    duplex auto
    speed auto
    !
    !
    interface FastEthernet0/1
    description TO WAN SIDE
    ip address 20.20.20.2 255.255.255.0
    ip nat outside
    duplex auto
    speed auto
    !


    !
    ip nat inside source static 65.65.65.200 20.20.20.2
    ip http server
    ip classless
    ip route 0.0.0.0 0.0.0.0 20.20.20.1


    EDGE_NAT_B#sh ip nat translations
    Pro Inside global Inside local Outside local Outside global
    --- 20.20.20.2 65.65.65.200 --- ---
    EDGE_NAT_B#
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    JeanM wrote: »
    Ok so made some progress, it's still not working 100% but here is the latest. I've changed the edge nat config to static to re-direct anything hitting 10.10.10.2 to 192.168.1.200(cme) and anything hitting 20.20.20.2 to 65.65.65.200 (cme). See below .

    Call signaling appears to be working, I can call from one side to the other over the wan cloud and through two edge/nat routers, but there is no audio either way.


    !
    ip nat inside source static 65.65.65.200 20.20.20.2
    ip http server
    ip classless
    ip route 0.0.0.0 0.0.0.0 20.20.20.1


    EDGE_NAT_B#sh ip nat translations
    Pro Inside global Inside local Outside local Outside global
    --- 20.20.20.2 65.65.65.200 --- ---
    EDGE_NAT_B#

    Just taking a stab..... going off what Azaghul mentioned...

    voice service voip
    allow-connections H323 to H323
    {then}

    H323

    I dunno I'm still in the novice stage of Voice....
  • JeanMJeanM Member Posts: 1,117
    Tried that as well on both routers, didn't make a difference.

    And there is no ip address trusted authenticate in 12.4 ios
    Cisco Unified Communications Manager Express Command Reference - Cisco Unified CME Commands: I [Cisco Unified Communications Manager Express] - Cisco

    CME_B(config)#voice service voip
    CME_B(conf-voi-serv)#?
    VOICE SERVICE configuration commands:
    allow-connections Allow call connection types
    cause-code Sets the internal cause code for SIP and H323
    default Set a command to its defaults
    exit Exit from voice service configuration mode
    fax Global fax commands
    h323 Global H.323 configuration commands
    media Global media setting for voip calls
    modem Global modem commands
    no Negate a command or set its defaults
    redirect voip call redirect
    shutdown Stop VoIP services gracefully without dropping active
    calls
    signaling Global setting for signaling payload handling
    sip SIP configuration commands
    supplementary-service Config supplementary service features
    CME_B(conf-voi-serv)#
    CME_B(conf-voi-serv)#allow-connections ?
    h323 from-type h323
    sip from-type sip


    CME_B(conf-voi-serv)#allow-connections h3
    CME_B(conf-voi-serv)#allow-connections h323 to ?
    h323 to-type h323
    sip to-type sip


    CME_B(conf-voi-serv)#allow-connections h323 to h323
    CME_B(conf-voi-serv)#
    CME_B(conf-voi-serv)#
    CME_B(conf-voi-serv)#signaling ?
    forward Global setting for signaling forwarding
    update Global setting for updating signaling data


    CME_B(conf-voi-serv)#h
    CME_B(conf-voi-serv)#h323 ?
    <cr>


    CME_B(conf-voi-serv)#h323
    CME_B(conf-serv-h323)#?
    VOICE SERVICE VOIP H323 configuration commands:
    bearercap-ie Specify bearercap_ie coding
    billing B-channel info present
    call Global setting for H.323 Calls
    ccm-compatible For Cisco Call Manager connections, allow CCM-specific
    behavior
    default Set a command to its defaults
    emptycapability Empty Capability (TCS=0)
    encoding Global setting for H.323 ASN.1 encoding options
    exit Exit from voice service voip h323 configuration mode
    h225 TCP H225 call signalling channel
    h245 H245 Signalling
    h450 H450 parameter configuration
    ip Global H.323 IP related configurations
    no Negate a command or set its defaults
    ras Gateway RAS configuration
    session H323 Voice Protocol session config
    telephony-service For CCME H323 connections


    CME_B(conf-serv-h323)#


    Since call signaling is working both ways, next step would be to debug RTP or what is blocking it right?
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    dunno I'm still in the novice stage of Voice.... :)

    If you are making connections but no actual sound could be codec mismatch.... both Dial-Peers using G711?
  • JeanMJeanM Member Posts: 1,117
    Yep, same here, just trying to learn this stuff via the means of labbing what comes into my mind lol. Same codec on both, if I by-pass the edge routers, everything works fine.

    I am thinking it's either additional config is needed on the edge/nat routers or maybe additional config is needed on the CME routers for the rtp to work over nat?
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    another stab

    router A


    dial-peer voice 1 voip
    description TO call other CME over WAN
    destination-pattern 7...
    session target ipv4:20.20.20.2
    dtmf-relay h245-alphanumeric
    router B

    dial-peer voice 1 voip
    description to call OTHER CME over WAN
    destination-pattern 66..
    session target ipv4:10.10.10.2

    my dial-peers on both ends have : [except for the one that uses MGCP... I've got 3 branch over frame with dial peers and then 1 that uses MGCP]

    dtmf-relay H245-alphanumeric
    codec g711.ulaw
    no vad

    and all 3 on frame use H323 over frame relay with:
    voice service voip
    allow-connections h323 to h323
    supplementary-service h450.12
    [&]
    H323

    again I'm a really really, really novice on all this..... best to as Pitviper because he's the man on all this..maybe a PM to him?
  • JeanMJeanM Member Posts: 1,117
    No difference. Do you have NAT on both sides as well?


    I am not using SIP, but I though these posts were interesting:

    https://supportforums.cisco.com/discussion/10134906/cme-behind-nat
    https://supportforums.cisco.com/discussion/11826301/outgoing-calls-cme-sip-trunk-not-working

    http://www.h323.net/config/
    http://hive2.hive.packetizer.com/users/h323forum/specifications/h323_nat_fw_solution.pdf


    4 How are NAT different and why is that important?


    While NAT issues are not unique to H.323 and, in fact, are issues shared by every communication protocol on the Internet, H.323 presents special challenges, since it is often the case that both communicating devices are behind two different NAT devices. Further, it is ideal to allow those devices to communicate directly, or to at least allow media to flow point-to-point between the devices in order to allow the H.323 multimedia systems to scale.


    The basic premise of point-to-point media is to have the devices send media packets to each other directly, even if one or both communicating devices are behind a NAT. If only one device is behind a NAT and one knows which one that is, then one could instruct the device on the public Internet to wait for the media to be established from the device behind the NAT first. In so doing, the device behind the NAT creates pinholes in the NAT so the external device can send media to the internal device.

    The problem becomes more challenging when both devices are behind a NAT and is complicated even further by the fact that there are a variety of different “NAT types”. The key to solving the double NAT issue is to understand how different NAT devices work and to understand that the behaviour of some NAT devices is more accommodating to achieve direct media. By understanding NAT behaviour, it is then possible to exploit that behaviour in order to enable direct point-to-point media flows.



    https://supportforums.cisco.com/discussion/9956976/how-h323-video-between-overlapping-private-networks
    According to the above,

    "NAT with ALG can translate the embedded addresses in H225/H245."
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    Maybe use NAT overload?

    instead of NAT static mapping?

    I messed with NAT and CME for about 2 days and gave up and went with Frame Relay just to get the stuff working.....

    Magic Jack works...so does IP phone service from ISP providers such as cable and DSL. those routers do NAT so for all appearances, it does work...but.....
    .
  • JeanMJeanM Member Posts: 1,117
    Yeah, there is no issue if I am not adding the edge routers into the mix. But, that's not really a realistic scenario then :)

    These are not SIP phones either, there are just analog phones connected to FXS modules in the CME A and B routers, I wanted to keep this as simple as possible before making it more complex. The more I am reading on this, it seems to be related to NAT/H.323 side and NAT packet inspection?

    I am going to try switching the VoIP dial-peer to sipv2 next and see if it makes any difference for kicks.
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    I just remember something about SCCP phones and an issue with NAT somewhere a while ago.....

    As far as analog on FXS/FXO ports I did that on my system, it worked with a gateway router and MGCP across WAN.. can call the analog phone on CME from SCCP phones in CME.


    Pitviper had that on his system. His red phone!! :)

    so he may have some info on his sticky notes for CCNP voice
  • JeanMJeanM Member Posts: 1,117
    Yes, 2 CME routers have a voip dial peer (h.323 or sip) and pots dial peers for the analog phones on the fxs ports.
    Each CME router is behind Edge routers doing the nat/pat, form there each edge router connects to a couple routers simulating the wan / eigrp cloud.

    Calling remote phone extension over this scenario is currently working, but there is no audio. That's why I am thinking it's an RTP issue over the edge routers. If the edge routers are removed, then this works fine.
    2015 goals - ccna voice / vmware vcp.
  • JeanMJeanM Member Posts: 1,117
    So, I switched the voip dial-peer protocol to SIP and made some test calls, same as with h.323, signaling works but no audio.

    I ran a debug on CME B router. This is what happens when a call comes in from CME A router and I answer it, and then hang it up.


    CME_B#debug ccsip all
    This may severely impact system performance. Continue? [confirm]
    All SIP Call tracing is enabled
    CME_B#
    CME_B#
    CME_B#
    *Mar 1 11:18:19.267: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 10.10.10.2:63056
    *Mar 1 11:18:19.267: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Mar 1 11:18:19.267: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    INVITE sip:7701@65.65.65.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK72509
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>
    Date: Sun, 04 Jan 2015 03:41:55 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Supported: 100rel,timer,replaces
    Min-SE: 1800
    Cisco-Guid: 1912525453-2465862116-2150164069-1803217998
    User-Agent: Cisco-SIPGateway/IOS-12.x
    Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
    CSeq: 101 INVITE
    Max-Forwards: 70
    Remote-Party-ID: "Lenzman" <sip:6601@10.10.10.2>;party=calling;screen=no;privacy=off
    Timestamp: 1420342915
    Contact: <sip:6601@10.10.10.2:5060>
    Expires: 180
    Allow-Events: telephone-event
    Content-Type: application/sdp
    Content-Length: 191


    v=0
    o=CiscoSystemsSIP-GW-UserAgent 8276 1095 IN IP4 192.168.1.200
    s=SIP Call
    c=IN IP4 192.168.1.200
    t=0 0
    m=audio 16702 RTP/AVP 8
    c=IN IP4 10.10.10.2
    a=rtpmap:8 PCMA/8000
    a=ptime:20


    *Mar 1 11:18:19.271: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.10.2,Port 5060, Transport 1, SentBy Port 5060
    *Mar 1 11:18:19.275: //-1/71FED28D8028/SIP/State/sipSPIChangeState: 0x88606548 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
    *Mar 1 11:18:19.275: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.10.2,Port 63056, Transport 1, SentBy Port 5060
    *Mar 1 11:18:19.275: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Mar 1 11:18:19.275: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.10.2,Port 63056, Transport 1, SentBy Port 5060
    *Mar 1 11:18:19.283: //-1/71FED28D8028/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: Lenzman, current remote number: 6601
    *Mar 1 11:18:19.283: //-1/71FED28D8028/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=no ;privacy=off -> Setting Octet3A 0x80, extended_privacy 0x00
    *Mar 1 11:18:19.283: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetGtdBody: No valid GTD body found.
    *Mar 1 11:18:19.283: //-1/71FED28D8028/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
    *Mar 1 11:18:19.287: //-1/71FED28D8028/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88606548 key=7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.2007701
    *Mar 1 11:18:19.287: //-1/71FED28D8028/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
    *Mar 1 11:18:19.287: //-1/71FED28D8028/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 7701
    *Mar 1 11:18:19.287: //-1/71FED28D8028/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 6601
    *Mar 1 11:18:19.287: //-1/71FED28D8028/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Lenzman, number 6601, Calling oct3 0x00, oct_3a 0x80, Called number 7701
    *Mar 1 11:18:19.291: //-1/71FED28D8028/SIP/Info/sipSPIGetCallConfig: Peer tag 1 matched for incoming call
    *Mar 1 11:18:19.291: //-1/71FED28D8028/SIP/Info/sipSPIGetCallConfig: Not using Voice Class Codec
    *Mar 1 11:18:19.291: //-1/71FED28D8028/SIP/Info/sipSPIContinueNewMsgInvite: Calling name Lenzman, number 6601, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 7701, oct3 0x00
    *Mar 1 11:18:19.295: //-1/71FED28D8028/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
    *Mar 1 11:18:19.295: //-1/71FED28D8028/SIP/Info/sipSPIContinueNewMsgInvite: Requires reliable-provisional support
    *Mar 1 11:18:19.295: //-1/71FED28D8028/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
    *Mar 1 11:18:19.295: //6/71FED28D8028/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
    *Mar 1 11:18:19.295: //6/71FED28D8028/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
    *Mar 1 11:18:19.299: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160
    *Mar 1 11:18:19.299: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
    *Mar 1 11:18:19.299: //6/71FED28D8028/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw
    *Mar 1 11:18:19.299: //6/71FED28D8028/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
    *Mar 1 11:18:19.299: //6/71FED28D8028/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred DTMF-RELAY option list!
    *Mar 1 11:18:19.299: //6/71FED28D8028/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice
    *Mar 1 11:18:19.299: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
    *Mar 1 11:18:19.299: //6/71FED28D8028/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
    *Mar 1 11:18:19.303: //6/71FED28D8028/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
    *Mar 1 11:18:19.303: //6/71FED28D8028/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
    payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=inband-voice
    stream_type=voice-only (0), dest_ip_address=10.10.10.2, dest_port=16702
    *Mar 1 11:18:19.303: //6/71FED28D8028/SIP/Media/sipSPIUpdCallWithSdpInfo:
    Preferred Codec : g711alaw, bytes :160
    Preferred DTMF relay : inband-voice
    Preferred NTE payload : 101
    Early Media : No
    Delayed Media : No
    Bridge Done : No
    New Media : No
    DSP DNLD Reqd : No


    *Mar 1 11:18:19.303: //6/71FED28D8028/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 65.65.65.200
    *Mar 1 11:18:19.303: //6/71FED28D8028/SIP/Info/sipSPI_ipip_report_media_to_peer:
    callId 6 peer 0 flags 0x201
    *Mar 1 11:18:19.303: //6/71FED28D8028/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
    CallID 6, sdp 0x88195174 channels 0x886080F8
    *Mar 1 11:18:19.307: //6/71FED28D8028/SIP/Info/copy_channels:
    callId 6 size 0 ptr 0x88186D8icon_cool.gif
    *Mar 1 11:18:19.307: //6/71FED28D8028/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
    Hndl ptype 8 mline 1
    *Mar 1 11:18:19.307: //6/71FED28D8028/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw
    *Mar 1 11:18:19.307: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
    *Mar 1 11:18:19.307: //6/71FED28D8028/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
    *Mar 1 11:18:19.307: //6/71FED28D8028/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
    Adding codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 0 10.10.10.2:16702
    *Mar 1 11:18:19.307: //6/71FED28D8028/SIP/Info/sipSPI_ipip_report_media_to_peer:
    Report initial call media
    *Mar 1 11:18:19.311: //6/71FED28D8028/SIP/Info/copy_channels:
    callId 6 size 80 ptr 0x84561EF0)
    *Mar 1 11:18:19.311: //6/71FED28D8028/SIP/Info/sipSPI_ipip_report_media_to_peer:
    CCSIP: Unable to report channel ind
    *Mar 1 11:18:19.311: //6/71FED28D8028/SIP/Media/sipSPIUpdCallWithSdpInfo:
    Stream type : voice-only
    Media line : 1
    State : STREAM_ADDING (2)
    Callid : -1
    Negotiated Codec : g711alaw, bytes :160
    Negotiated DTMF relay : inband-voice
    Negotiated NTE payload : 0
    Negotiated CN payload : 0
    Media Srce Addr/Port : 65.65.65.200:0
    Media Dest Addr/Port : 10.10.10.2:16702


    *Mar 1 11:18:19.311: //6/71FED28D8028/SIP/Info/sipSPIHandleInviteMedia:
    Negotiated Codec : g711alaw, bytes :160
    Preferred Codec : g711alaw, bytes :160
    Preferred DTMF relay 1 : 0
    Preferred DTMF relay 2 : 0
    Negotiated DTMF relay : 0
    Preferred and Negotiated NTE payloads: 101 0
    Preferred and Negotiated NSE payloads: 100 0
    Preferred and Negotiated Modem Relay: 0 0
    Preferred and Negotiated Modem Relay GwXid: 1 0


    *Mar 1 11:18:19.311: //6/71FED28D8028/SIP/Info/sipSPIDoQoSNegotiation: SDP body with media description
    *Mar 1 11:18:19.315: //6/71FED28D8028/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
    *Mar 1 11:18:19.315: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16610 for stream 1
    *Mar 1 11:18:19.315: //6/71FED28D8028/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16610
    *Mar 1 11:18:19.315: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
    *Mar 1 11:18:19.315: //6/71FED28D8028/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16610
    *Mar 1 11:18:19.319: //6/71FED28D8028/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    *Mar 1 11:18:19.319: //6/71FED28D8028/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
    *Mar 1 11:18:19.319: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateRawMsg: No GTD passed.
    *Mar 1 11:18:19.319: //6/71FED28D8028/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
    *Mar 1 11:18:19.319: //6/71FED28D8028/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
    *Mar 1 11:18:19.319: //6/71FED28D8028/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88606548 key=7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200105B94-2315
    *Mar 1 11:18:19.323: //6/71FED28D8028/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 6 to table
    *Mar 1 11:18:19.327: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: msg=0x855545A8, addr=10.10.10.2, port=63056, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
    *Mar 1 11:18:19.327: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Mar 1 11:18:19.327: //6/71FED28D8028/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Mar 1 11:18:19.327: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x855545A8, addr=10.10.10.2, port=5060, connId=0 for UDP
    *Mar 1 11:18:19.327: //6/71FED28D8028/SIP/State/sipSPIChangeState: 0x88606548 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
    *Mar 1 11:18:19.327: //6/71FED28D8028/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.10.10.2:5060
    *Mar 1 11:18:19.343: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 100 Trying
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK72509
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>;tag=105B94-2315
    Date: Fri, 01 Mar 2002 11:18:19 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Timestamp: 1420342915
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Allow-Events: telephone-event
    Content-Length: 0






    *Mar 1 11:18:19.343: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
    *Mar 1 11:18:19.351: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:
    *Mar 1 11:18:19.351: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 13icon_cool.gif
    *Mar 1 11:18:19.351: //6/71FED28D8028/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: peer ID 7 chans 0x855C0160 event 138 flags 0x12020038 0x601 data 0x855C0160
    *Mar 1 11:18:19.351: //6/71FED28D8028/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 7 chans 0x855C0160 event 138 flags 0x12020038 0x601 data 0x855C0160
    *Mar 1 11:18:19.351: //6/71FED28D8028/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 7 chans 0x855C0160 event 138 flags 0x12020038 0x601 data 0x855C0160, type = 6
    *Mar 1 11:18:19.355: //6/71FED28D8028/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: !!!!!CC_EV_H245_SET_MODE: not clearing VTSP flag
    *Mar 1 11:18:19.355: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
    *Mar 1 11:18:19.367: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROGRESS
    *Mar 1 11:18:19.367: //6/71FED28D8028/SIP/Info/ccsip_bridge: confID = 3, srcCallID = 6, dstCallID = 7
    *Mar 1 11:18:19.367: //6/71FED28D8028/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 6/7
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=6
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice-only (callid 6) to the VOIP RTP library
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 65.65.65.200
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
    laddr = 65.65.65.200, lport = 16610, raddr = 10.10.10.2, rport=16702, do_rtcp=TRUE
    src_callid = 6, dest_callid = 7, stream type = voice-only, stream direction = SENDRECV
    media_ip_addr = 10.10.10.2
    *Mar 1 11:18:19.371: //6/71FED28D8028/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
    *Mar 1 11:18:19.375: //6/71FED28D8028/SIP/Media/sipSPIGetNewLocalMediaDirection:
    New Remote Media Direction = SENDRECV
    Present Local Media Direction = SENDRECV
    New Local Media Direction = SENDRECV
    retVal = 0


    *Mar 1 11:18:19.379: //6/71FED28D8028/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=6, current_seq_num=0x1750
    *Mar 1 11:18:19.379: //6/71FED28D8028/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=6, current_seq_num=0x5AF
    *Mar 1 11:18:19.379: //6/71FED28D8028/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g711alaw, Bytes=160
    *Mar 1 11:18:19.379: //6/71FED28D8028/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
    *Mar 1 11:18:19.383: //6/71FED28D8028/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Media/sipSPISetStreamInfo: 1 Active Streams
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice-only) from media line 1
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Media/sipSPISetStreamInfo:
    caps.stream_count=1,caps.stream[0].stream_type=0x1, caps.stream_list.xmitFunc=
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context=
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Media/sipSPISetStreamInfo: 0x855B1BA0 (gccb)
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Info/ccsip_caps_ind: Load DSP with codec : g711alaw, Bytes=160
    *Mar 1 11:18:19.387: //6/71FED28D8028/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->flags_ipip = 0x603
    *Mar 1 11:18:19.391: //6/71FED28D8028/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
    *Mar 1 11:18:19.391: //6/71FED28D8028/SIP/Info/sipSPIValidateGtd: No rawMsg from CCAPI
    *Mar 1 11:18:19.391: //6/71FED28D8028/SIP/Info/sipSPISendInviteResponse183: Session Type is Media/Qos/Security/RTR SDP body is attached
    *Mar 1 11:18:19.395: //6/71FED28D8028/SIP/Transport/sipSPISendInviteResponse: Sending 183 Response to the Transport Layer
    *Mar 1 11:18:19.395: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: msg=0x85554518, addr=10.10.10.2, port=63056, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x8105FF1C
    *Mar 1 11:18:19.399: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Mar 1 11:18:19.399: //6/71FED28D8028/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Mar 1 11:18:19.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x85554518, addr=10.10.10.2, port=5060, connId=0 for UDP
    *Mar 1 11:18:19.399: //6/71FED28D8028/SIP/Info/sentInviteResponse18x: Sent a 18x Response
    *Mar 1 11:18:19.399: //6/71FED28D8028/SIP/Info/setPrackLockIfNeeded: Transaction active. Facilities will be queued.
    *Mar 1 11:18:19.407: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 183 Session Progress
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK72509
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>;tag=105B94-2315
    Date: Fri, 01 Mar 2002 11:18:19 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Timestamp: 1420342915
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Require: 100rel
    RSeq: 9938
    Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
    Allow-Events: telephone-event
    Contact: <sip:7701@65.65.65.200:5060>
    Content-Disposition: session;handling=required
    Content-Type: application/sdp
    Content-Length: 191


    v=0
    o=CiscoSystemsSIP-GW-UserAgent 1365 6528 IN IP4 65.65.65.200
    s=SIP Call
    c=IN IP4 65.65.65.200
    t=0 0
    m=audio 16610 RTP/AVP 8
    c=IN IP4 65.65.65.200
    a=rtpmap:8 PCMA/8000
    a=ptime:20


    *Mar 1 11:18:19.455: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 10.10.10.2:63056
    *Mar 1 11:18:19.459: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Mar 1 11:18:19.459: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    PRACK sip:7701@65.65.65.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK8183E
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>;tag=105B94-2315
    Date: Sun, 04 Jan 2015 03:41:55 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    CSeq: 102 PRACK
    RAck: 9938 101 INVITE
    Max-Forwards: 70
    Content-Length: 0






    *Mar 1 11:18:19.459: //6/71FED28D8028/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x88606548
    *Mar 1 11:18:19.463: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.10.10.2,Port 63056, Transport 1, SentBy Port 5060
    *Mar 1 11:18:19.463: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Mar 1 11:18:19.467: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.10.10.2,Port 63056, Transport 1, SentBy Port 5060
    *Mar 1 11:18:19.467: //6/71FED28D8028/SIP/Info/act_recdinvite_new_message_request: Transaction Complete. Lock on Facilities released.
    *Mar 1 11:18:19.471: //6/71FED28D8028/SIP/Transport/sipSPISendPrackResponse: Sending PRACK Response to the transport layer
    *Mar 1 11:18:19.471: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: msg=0x85554998, addr=10.10.10.2, port=63056, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
    *Mar 1 11:18:19.471: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Mar 1 11:18:19.471: //6/71FED28D8028/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Mar 1 11:18:19.471: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x85554998, addr=10.10.10.2, port=5060, connId=0 for UDP
    *Mar 1 11:18:19.475: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK8183E
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>;tag=105B94-2315
    Date: Fri, 01 Mar 2002 11:18:19 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 102 PRACK
    Content-Length: 0






    *Mar 1 11:18:22.491: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_CONNECT
    *Mar 1 11:18:22.495: //6/71FED28D8028/SIP/Info/sipSPIValidateGtd: No rawMsg from CCAPI
    *Mar 1 11:18:22.503: //6/71FED28D8028/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer
    *Mar 1 11:18:22.503: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: msg=0x85554998, addr=10.10.10.2, port=63056, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x81060204
    *Mar 1 11:18:22.503: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Mar 1 11:18:22.503: //6/71FED28D8028/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Mar 1 11:18:22.503: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x85554998, addr=10.10.10.2, port=5060, connId=0 for UDP
    *Mar 1 11:18:22.507: //6/71FED28D8028/SIP/Info/sentInviteResponse200: Sent 200Ok for Invite in state STATE_RECD_INVITE
    *Mar 1 11:18:22.507: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteResponse200: Transaction active. Facilities will be queued.
    *Mar 1 11:18:22.507: //6/71FED28D8028/SIP/State/sipSPIChangeState: 0x88606548 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_SENT_SUCCESS, SUBSTATE_NONE)
    *Mar 1 11:18:22.507: //6/71FED28D8028/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
    *Mar 1 11:18:22.511: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK72509
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>;tag=105B94-2315
    Date: Fri, 01 Mar 2002 11:18:19 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Timestamp: 1420342915
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
    Supported: replaces
    Allow-Events: telephone-event
    Contact: <sip:7701@65.65.65.200:5060>
    Content-Type: application/sdp
    Content-Length: 191


    v=0
    o=CiscoSystemsSIP-GW-UserAgent 1365 6528 IN IP4 65.65.65.200
    s=SIP Call
    c=IN IP4 65.65.65.200
    t=0 0
    m=audio 16610 RTP/AVP 8
    c=IN IP4 65.65.65.200
    a=rtpmap:8 PCMA/8000
    a=ptime:20


    *Mar 1 11:18:22.551: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 10.10.10.2:63056
    *Mar 1 11:18:22.555: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Mar 1 11:18:22.555: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    ACK sip:7701@65.65.65.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 10.10.10.2:5060;branch=z9hG4bK922B3
    From: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    To: <sip:7701@65.65.65.200>;tag=105B94-2315
    Date: Sun, 04 Jan 2015 03:41:55 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Max-Forwards: 70
    CSeq: 101 ACK
    Content-Length: 0






    *Mar 1 11:18:22.555: //6/71FED28D8028/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x88606548
    *Mar 1 11:18:22.559: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.10.10.2,Port 63056, Transport 1, SentBy Port 5060
    *Mar 1 11:18:22.559: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Mar 1 11:18:22.563: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.10.10.2,Port 63056, Transport 1, SentBy Port 5060
    *Mar 1 11:18:22.563: //6/71FED28D8028/SIP/Info/act_sentsucc_new_message_request: Transaction Complete. Lock on Facilities released.
    *Mar 1 11:18:22.563: //6/71FED28D8028/SIP/State/sipSPIChangeState: 0x88606548 : State change from (STATE_SENT_SUCCESS, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE)
    *Mar 1 11:18:22.563: //6/71FED28D8028/SIP/Call/sipSPICallInfo:
    The Call Setup Information is:
    Call Control Block (CCB) : 0x88606548
    State of The Call : STATE_ACTIVE
    TCP Sockets Used : NO
    Calling Number : 6601
    Called Number : 7701
    Source IP Address (Sig ): 65.65.65.200
    Destn SIP Req Addr:Port : 10.10.10.2:5060
    Destn SIP Resp Addr:Port : 10.10.10.2:63056
    Destination Name : 10.10.10.2


    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Call/sipSPIMediaCallInfo:
    Number of Media Streams: 1
    Media Stream : 1
    Negotiated Codec : g711alaw
    Negotiated Codec Bytes : 160
    Negotiated Dtmf-relay : 0
    Dtmf-relay Payload : 0
    Source IP Address (Media): 65.65.65.200
    Source IP Port (Media): 16610
    Destn IP Address (Media): 10.10.10.2
    Destn IP Port (Media): 16702
    Orig Destn IP Address:Port (Media): 0.0.0.0:0


    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPICreateAndStartRtpTimer:
    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPIProcessHoldTimerForCall: Media IP Addr 10.10.10.2, RTCP Type 3
    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Connection=0x883160C4, addr=10.10.10.2, port=5060, connid=1 has been aged out
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.10.10.2, port=5060, connid=1
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x883160C4, connid=1, addr=10.10.10.2, port=5060, transport=udp
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x85554488,addr=10.10.10.2
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopAgeingTimer: Aging timer stopped for holder=0x85554488,addr=10.10.10.2
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnHolder: Deleted holder=0x85554488, addr=10.10.10.2, count=0
    *Mar 1 11:18:22.595: //-1/xxxxxxxxxxxx/SIP/Info/udpsock_close_connect: Socket fd: 1 closed for connid 1 with remote port: 5060
    *Mar 1 11:19:10.199: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
    *Mar 1 11:19:10.203: //6/71FED28D8028/SIP/Info/sipSPIValidateGtd: No rawMsg from CCAPI
    *Mar 1 11:19:10.203: //6/71FED28D8028/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
    *Mar 1 11:19:10.203: //6/71FED28D8028/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
    *Mar 1 11:19:10.207: //6/71FED28D8028/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer
    *Mar 1 11:19:10.207: //6/71FED28D8028/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
    *Mar 1 11:19:10.207: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: msg=0x85554488, addr=10.10.10.2, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x81060440
    *Mar 1 11:19:10.207: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Mar 1 11:19:10.207: //6/71FED28D8028/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Mar 1 11:19:10.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x85554878,addr=10.10.10.2
    *Mar 1 11:19:10.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x85554878, addr=10.10.10.2
    *Mar 1 11:19:10.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=10.10.10.2, port=5060, context=0x8831555C
    *Mar 1 11:19:10.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x88316168,addr=10.10.10.2, port=5060
    *Mar 1 11:19:10.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x88316168, connid=-1, addr=10.10.10.2, port=5060, transport=udp
    *Mar 1 11:19:10.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering ccb=0x88606548 with connection=0x88316168
    *Mar 1 11:19:10.215: //6/71FED28D8028/SIP/Transport/sipSPITransportSendMessage: Deferred sending msg=0x85554488
    *Mar 1 11:19:10.223: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWConnectionCreated: context=0x8831555C
    *Mar 1 11:19:10.223: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: gConnTab=0x8831555C, addr=10.10.10.2, port=5060, connid=1, transport=udp
    *Mar 1 11:19:10.223: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopConnWaitTimer: Wait timer stopped for connection=0x88316168,addr=10.10.10.2, port=5060
    *Mar 1 11:19:10.223: //6/71FED28D8028/SIP/Transport/sipTransportPostInternalMsg: Posting Internal Msg type=0
    *Mar 1 11:19:10.223: //6/71FED28D8028/SIP/Info/ccsip_lock_ccb: CCB locked; reference count=1
    *Mar 1 11:19:10.227: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessInternalMsg: context=0x88606548
    *Mar 1 11:19:10.231: //6/71FED28D8028/SIP/Info/ccsip_unlock_ccb: CCB unlocked; reference count=0
    *Mar 1 11:19:10.231: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x85554488, addr=10.10.10.2, port=5060, connId=1 for UDP
    *Mar 1 11:19:10.231: //6/71FED28D8028/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer
    *Mar 1 11:19:10.231: //6/71FED28D8028/SIP/State/sipSPIChangeState: 0x88606548 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
    *Mar 1 11:19:10.235: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    BYE sip:6601@10.10.10.2:5060 SIP/2.0
    Via: SIP/2.0/UDP 65.65.65.200:5060;branch=z9hG4bK2F04
    From: <sip:7701@65.65.65.200>;tag=105B94-2315
    To: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    Date: Fri, 01 Mar 2002 11:18:22 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    User-Agent: Cisco-SIPGateway/IOS-12.x
    Max-Forwards: 70
    Timestamp: 1014981550
    CSeq: 101 BYE
    Reason: Q.850;cause=16
    Content-Length: 0






    *Mar 1 11:19:10.275: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 10.10.10.2:5060
    *Mar 1 11:19:10.279: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Mar 1 11:19:10.279: //6/71FED28D8028/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x88606548
    *Mar 1 11:19:10.279: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 65.65.65.200:5060;branch=z9hG4bK2F04
    From: <sip:7701@65.65.65.200>;tag=105B94-2315
    To: "Lenzman" <sip:6601@10.10.10.2>;tag=6948E0-F2
    Date: Sun, 04 Jan 2015 03:42:46 GMT
    Call-ID: 7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200
    Server: Cisco-SIPGateway/IOS-12.x
    Timestamp: 1014981550
    Content-Length: 0
    CSeq: 101 BYE






    *Mar 1 11:19:10.283: //6/71FED28D8028/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 43630 DiscTime:112302 ConnTime 107524
    *Mar 1 11:19:10.287: //6/71FED28D8028/SIP/State/sipSPIChangeState: 0x88606548 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
    *Mar 1 11:19:10.287: //6/71FED28D8028/SIP/Call/sipSPICallInfo:
    The Call Setup Information is:
    Call Control Block (CCB) : 0x88606548
    State of The Call : STATE_DEAD
    TCP Sockets Used : NO
    Calling Number : 6601
    Called Number : 7701
    Source IP Address (Sig ): 65.65.65.200
    Destn SIP Req Addr:Port : 10.10.10.2:5060
    Destn SIP Resp Addr:Port : 10.10.10.2:63056
    Destination Name : 10.10.10.2


    *Mar 1 11:19:10.287: //6/71FED28D8028/SIP/Call/sipSPIMediaCallInfo:
    Number of Media Streams: 1
    Media Stream : 1
    Negotiated Codec : g711alaw
    Negotiated Codec Bytes : 160
    Negotiated Dtmf-relay : 0
    Dtmf-relay Payload : 0
    Source IP Address (Media): 65.65.65.200
    Source IP Port (Media): 16610
    Destn IP Address (Media): 10.10.10.2
    Destn IP Port (Media): 16702
    Orig Destn IP Address:Port (Media): 0.0.0.0:0


    *Mar 1 11:19:10.287: //6/71FED28D8028/SIP/Call/sipSPICallInfo:
    Disconnect Cause (CC) : 16
    Disconnect Cause (SIP) : 200


    *Mar 1 11:19:10.287: //6/71FED28D8028/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 6
    *Mar 1 11:19:10.291: //6/71FED28D8028/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
    *Mar 1 11:19:10.291: //6/71FED28D8028/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88606548 key=7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.2007701
    *Mar 1 11:19:10.291: //6/71FED28D8028/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
    *Mar 1 11:19:10.291: //6/71FED28D8028/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88606548 key=7637C454-92FA11E4-802BE665-6B7AEC4E@192.168.1.200105B94-2315
    *Mar 1 11:19:10.295: //6/71FED28D8028/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
    *Mar 1 11:19:10.295: //6/71FED28D8028/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88606548
    CME_B#
    CME_B#
    CME_B#un all
    All possible debugging has been turned off
    CME_B#
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPIProcessHoldTimerForCall: Media IP Addr 10.10.10.2, RTCP Type 3
    *Mar 1 11:18:22.567: //6/71FED28D8028/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Connection=0x883160C4, addr=10.10.10.2, port=5060, connid=1 has been aged out
    *Mar 1 11:18:22.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.10.10.2, port=5060, connid=1

    So here you can see RTP timer timing out and then ending the session.... on UDP port 5060.....

    the connection is made as you said but then zippo nadda and the RTP session times out....\

    that's probably you hanging up the phone and the session is closed

    if your using NAT or NAT overload or even PAT and you haven't told your router that UDP ports are ok. geez I'm thinking firewalls.... see novice here....
  • JeanMJeanM Member Posts: 1,117
    So on the EDGE_A I have a static entry like , 192.168.1.200 is CME_A and 10.10.10.2 is the outside interface of the edge router facing the WAN.
    ip nat inside source static 192.168.1.200 10.10.10.2

    And on the EDGE_B I have a similar entry to point traffic coming to 20.20.20.2 to the CME_B at 65.65.65.200
    ip nat inside source static 65.65.65.200 20.20.20.2


    I tried adding back an entry below and also sppecifically added permit udp any any , no difference, still just signaling works but no audio.

    ip nat inside source list TEST interface FastEthernet0/1 overload
    ip nat inside source static 192.168.1.200 10.10.10.2
    !
    ip access-list extended TEST
    permit ip any any
    permit udp any any
    2015 goals - ccna voice / vmware vcp.
  • JeanMJeanM Member Posts: 1,117
    Alright, looks to be working now, going to make some more calls and verify it.

    It seems adding a static ip nat inside source static udp CME_IP 5060 Edge_Outside_IP 5060 extendable on both edge routers fixed it.

    Glad I wasn't crazy when I thought I had my dial-peer configured right, and was thinking it's an RTP issue all along , woot!
    2015 goals - ccna voice / vmware vcp.
  • JeanMJeanM Member Posts: 1,117
    Confirmed, signaling and now rtp is working both ways.

    Here is a good debug :D

    CME_A_#debug ccsip all
    This may severely impact system performance. Continue? [confirm]
    All SIP Call tracing is enabled
    CME_A_#
    CME_A_#
    CME_A_#
    CME_A_#
    CME_A_#
    *Jan 4 05:22:11.180: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 20.20.20.2:59570
    *Jan 4 05:22:11.180: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Jan 4 05:22:11.180: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    INVITE sip:6601@192.168.1.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bK919B5
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>
    Date: Fri, 01 Mar 2002 12:58:35 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Supported: 100rel,timer,replaces
    Min-SE: 1800
    Cisco-Guid: 3688424679-743051734-2148715475-4247906904
    User-Agent: Cisco-SIPGateway/IOS-12.x
    Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
    CSeq: 101 INVITE
    Max-Forwards: 70
    Remote-Party-ID: "Goldie" <sip:7701@20.20.20.2>;party=calling;screen=no;privacy=off
    Timestamp: 1014987515
    Contact: <sip:7701@20.20.20.2:5060>
    Expires: 180
    Allow-Events: telephone-event
    Content-Type: application/sdp
    Content-Length: 189


    v=0
    o=CiscoSystemsSIP-GW-UserAgent 4151 6864 IN IP4 65.65.65.200
    s=SIP Call
    c=IN IP4 65.65.65.200
    t=0 0
    m=audio 19012 RTP/AVP 8
    c=IN IP4 20.20.20.2
    a=rtpmap:8 PCMA/8000
    a=ptime:20


    *Jan 4 05:22:11.188: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 20.20.20.2,Port 5060, Transport 1, SentBy Port 5060
    *Jan 4 05:22:11.188: //-1/DBD8E4E78012/SIP/State/sipSPIChangeState: 0x8561974C : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
    *Jan 4 05:22:11.188: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:11.188: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Jan 4 05:22:11.192: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:11.196: //-1/DBD8E4E78012/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: Goldie, current remote number: 7701
    *Jan 4 05:22:11.196: //-1/DBD8E4E78012/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=no ;privacy=off -> Setting Octet3A 0x80, extended_privacy 0x00
    *Jan 4 05:22:11.200: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetGtdBody: No valid GTD body found.
    *Jan 4 05:22:11.200: //-1/DBD8E4E78012/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
    *Jan 4 05:22:11.200: //-1/DBD8E4E78012/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x8561974C key=E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.2006601
    *Jan 4 05:22:11.200: //-1/DBD8E4E78012/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
    *Jan 4 05:22:11.200: //-1/DBD8E4E78012/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 6601
    *Jan 4 05:22:11.200: //-1/DBD8E4E78012/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 7701
    *Jan 4 05:22:11.204: //-1/DBD8E4E78012/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Goldie, number 7701, Calling oct3 0x00, oct_3a 0x80, Called number 6601
    *Jan 4 05:22:11.204: //-1/DBD8E4E78012/SIP/Info/sipSPIGetCallConfig: Peer tag 1 matched for incoming call
    *Jan 4 05:22:11.208: //-1/DBD8E4E78012/SIP/Info/sipSPIGetCallConfig: Not using Voice Class Codec
    *Jan 4 05:22:11.208: //-1/DBD8E4E78012/SIP/Info/sipSPIContinueNewMsgInvite: Calling name Goldie, number 7701, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 6601, oct3 0x00
    *Jan 4 05:22:11.208: //-1/DBD8E4E78012/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
    *Jan 4 05:22:11.208: //-1/DBD8E4E78012/SIP/Info/sipSPIContinueNewMsgInvite: Requires reliable-provisional support
    *Jan 4 05:22:11.208: //-1/DBD8E4E78012/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
    *Jan 4 05:22:11.208: //39/DBD8E4E78012/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
    *Jan 4 05:22:11.212: //39/DBD8E4E78012/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
    *Jan 4 05:22:11.212: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160
    *Jan 4 05:22:11.212: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
    *Jan 4 05:22:11.212: //39/DBD8E4E78012/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw
    *Jan 4 05:22:11.212: //39/DBD8E4E78012/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
    *Jan 4 05:22:11.212: //39/DBD8E4E78012/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred DTMF-RELAY option list!
    *Jan 4 05:22:11.212: //39/DBD8E4E78012/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice
    *Jan 4 05:22:11.216: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
    *Jan 4 05:22:11.216: //39/DBD8E4E78012/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
    *Jan 4 05:22:11.216: //39/DBD8E4E78012/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
    *Jan 4 05:22:11.216: //39/DBD8E4E78012/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
    payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=inband-voice
    stream_type=voice-only (0), dest_ip_address=20.20.20.2, dest_port=19012
    *Jan 4 05:22:11.216: //39/DBD8E4E78012/SIP/Media/sipSPIUpdCallWithSdpInfo:
    Preferred Codec : g711alaw, bytes :160
    Preferred DTMF relay : h245-alphanumeric
    Preferred NTE payload : 101
    Early Media : No
    Delayed Media : No
    Bridge Done : No
    New Media : No
    DSP DNLD Reqd : No


    *Jan 4 05:22:11.216: //39/DBD8E4E78012/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 192.168.1.200
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_report_media_to_peer:
    callId 39 peer 0 flags 0x201
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
    CallID 39, sdp 0x884BECCC channels 0x8561B2FC
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/copy_channels:
    callId 39 size 0 ptr 0x8816A250)
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
    Hndl ptype 8 mline 1
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw
    *Jan 4 05:22:11.220: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
    *Jan 4 05:22:11.220: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
    Adding codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 0 20.20.20.2:19012
    *Jan 4 05:22:11.224: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_report_media_to_peer:
    Report initial call media
    *Jan 4 05:22:11.224: //39/DBD8E4E78012/SIP/Info/copy_channels:
    callId 39 size 80 ptr 0x84AB59F0)
    *Jan 4 05:22:11.224: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_report_media_to_peer:
    CCSIP: Unable to report channel ind
    *Jan 4 05:22:11.224: //39/DBD8E4E78012/SIP/Media/sipSPIUpdCallWithSdpInfo:
    Stream type : voice-only
    Media line : 1
    State : STREAM_ADDING (2)
    Callid : -1
    Negotiated Codec : g711alaw, bytes :160
    Negotiated DTMF relay : inband-voice
    Negotiated NTE payload : 0
    Negotiated CN payload : 0
    Media Srce Addr/Port : 192.168.1.200:0
    Media Dest Addr/Port : 20.20.20.2:19012


    *Jan 4 05:22:11.224: //39/DBD8E4E78012/SIP/Info/sipSPIHandleInviteMedia:
    Negotiated Codec : g711alaw, bytes :160
    Preferred Codec : g711alaw, bytes :160
    Preferred DTMF relay 1 : 3
    Preferred DTMF relay 2 : 0
    Negotiated DTMF relay : 0
    Preferred and Negotiated NTE payloads: 101 0
    Preferred and Negotiated NSE payloads: 100 0
    Preferred and Negotiated Modem Relay: 0 0
    Preferred and Negotiated Modem Relay GwXid: 1 0


    *Jan 4 05:22:11.228: //39/DBD8E4E78012/SIP/Info/sipSPIDoQoSNegotiation: SDP body with media description
    *Jan 4 05:22:11.228: //39/DBD8E4E78012/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
    *Jan 4 05:22:11.228: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 17184 for stream 1
    *Jan 4 05:22:11.228: //39/DBD8E4E78012/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=17184
    *Jan 4 05:22:11.232: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
    *Jan 4 05:22:11.232: //39/DBD8E4E78012/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 17184
    *Jan 4 05:22:11.232: //39/DBD8E4E78012/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    *Jan 4 05:22:11.232: //39/DBD8E4E78012/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
    *Jan 4 05:22:11.232: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateRawMsg: No GTD passed.
    *Jan 4 05:22:11.236: //39/DBD8E4E78012/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
    *Jan 4 05:22:11.236: //39/DBD8E4E78012/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
    *Jan 4 05:22:11.236: //39/DBD8E4E78012/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x8561974C key=E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200C51530-236B
    *Jan 4 05:22:11.236: //39/DBD8E4E78012/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 27 to table
    *Jan 4 05:22:11.240: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: msg=0x887481D0, addr=20.20.20.2, port=59570, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
    *Jan 4 05:22:11.240: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Jan 4 05:22:11.240: //39/DBD8E4E78012/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Jan 4 05:22:11.240: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x887481D0, addr=20.20.20.2, port=5060, connId=0 for UDP
    *Jan 4 05:22:11.244: //39/DBD8E4E78012/SIP/State/sipSPIChangeState: 0x8561974C : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
    *Jan 4 05:22:11.244: //39/DBD8E4E78012/SIP/Info/sipSPIProcessContactInfo: Previous Hop 20.20.20.2:5060
    *Jan 4 05:22:11.248: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
    *Jan 4 05:22:11.252: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:
    *Jan 4 05:22:11.256: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 13icon_cool.gif
    *Jan 4 05:22:11.256: //39/DBD8E4E78012/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: peer ID 40 chans 0x8578F670 event 138 flags 0x12020038 0x601 data 0x8578F670
    *Jan 4 05:22:11.256: //39/DBD8E4E78012/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 40 chans 0x8578F670 event 138 flags 0x12020038 0x601 data 0x8578F670
    *Jan 4 05:22:11.256: //39/DBD8E4E78012/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 40 chans 0x8578F670 event 138 flags 0x12020038 0x601 data 0x8578F670, type = 6
    *Jan 4 05:22:11.256: //39/DBD8E4E78012/SIP/Info/ccsip_event_handler:
    ccsip_event_handler: !!!!!CC_EV_H245_SET_MODE: not clearing VTSP flag
    *Jan 4 05:22:11.256: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
    *Jan 4 05:22:11.268: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 100 Trying
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bK919B5
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Sun, 04 Jan 2015 05:22:11 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Timestamp: 1014987515
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Allow-Events: telephone-event
    Content-Length: 0






    *Jan 4 05:22:11.276: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROGRESS
    *Jan 4 05:22:11.276: //39/DBD8E4E78012/SIP/Info/ccsip_bridge: confID = 9, srcCallID = 39, dstCallID = 40
    *Jan 4 05:22:11.276: //39/DBD8E4E78012/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 39/40
    *Jan 4 05:22:11.276: //39/DBD8E4E78012/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=39
    *Jan 4 05:22:11.276: //39/DBD8E4E78012/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
    *Jan 4 05:22:11.276: //39/DBD8E4E78012/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice-only (callid 39) to the VOIP RTP library
    *Jan 4 05:22:11.280: //39/DBD8E4E78012/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 192.168.1.200
    *Jan 4 05:22:11.280: //39/DBD8E4E78012/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
    *Jan 4 05:22:11.280: //39/DBD8E4E78012/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
    laddr = 192.168.1.200, lport = 17184, raddr = 20.20.20.2, rport=19012, do_rtcp=TRUE
    src_callid = 39, dest_callid = 40, stream type = voice-only, stream direction = SENDRECV
    media_ip_addr = 20.20.20.2
    *Jan 4 05:22:11.280: //39/DBD8E4E78012/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
    *Jan 4 05:22:11.280: //39/DBD8E4E78012/SIP/Media/sipSPIGetNewLocalMediaDirection:
    New Remote Media Direction = SENDRECV
    Present Local Media Direction = SENDRECV
    New Local Media Direction = SENDRECV
    retVal = 0


    *Jan 4 05:22:11.288: //39/DBD8E4E78012/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=39, current_seq_num=0x1049
    *Jan 4 05:22:11.288: //39/DBD8E4E78012/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=39, current_seq_num=0x14E4
    *Jan 4 05:22:11.288: //39/DBD8E4E78012/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g711alaw, Bytes=160
    *Jan 4 05:22:11.288: //39/DBD8E4E78012/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
    *Jan 4 05:22:11.292: //39/DBD8E4E78012/SIP/Media/sipSPISetStreamInfo: 1 Active Streams
    *Jan 4 05:22:11.296: //39/DBD8E4E78012/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice-only) from media line 1
    *Jan 4 05:22:11.296: //39/DBD8E4E78012/SIP/Media/sipSPISetStreamInfo:
    caps.stream_count=1,caps.stream[0].stream_type=0x1, caps.stream_list.xmitFunc=
    *Jan 4 05:22:11.296: //39/DBD8E4E78012/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context=
    *Jan 4 05:22:11.296: //39/DBD8E4E78012/SIP/Media/sipSPISetStreamInfo: 0x887A6CA0 (gccb)
    *Jan 4 05:22:11.296: //39/DBD8E4E78012/SIP/Info/ccsip_caps_ind: Load DSP with codec : g711alaw, Bytes=160
    *Jan 4 05:22:11.296: //39/DBD8E4E78012/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->flags_ipip = 0x603
    *Jan 4 05:22:11.300: //39/DBD8E4E78012/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
    *Jan 4 05:22:11.300: //39/DBD8E4E78012/SIP/Info/sipSPIValidateGtd: No rawMsg from CCAPI
    *Jan 4 05:22:11.300: //39/DBD8E4E78012/SIP/Info/sipSPISendInviteResponse183: Session Type is Media/Qos/Security/RTR SDP body is attached
    *Jan 4 05:22:11.308: //39/DBD8E4E78012/SIP/Transport/sipSPISendInviteResponse: Sending 183 Response to the Transport Layer
    *Jan 4 05:22:11.308: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: msg=0x887482F0, addr=20.20.20.2, port=59570, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x8105FF1C
    *Jan 4 05:22:11.308: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Jan 4 05:22:11.308: //39/DBD8E4E78012/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Jan 4 05:22:11.308: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x887482F0, addr=20.20.20.2, port=5060, connId=0 for UDP
    *Jan 4 05:22:11.308: //39/DBD8E4E78012/SIP/Info/sentInviteResponse18x: Sent a 18x Response
    *Jan 4 05:22:11.308: //39/DBD8E4E78012/SIP/Info/setPrackLockIfNeeded: Transaction active. Facilities will be queued.
    *Jan 4 05:22:11.316: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 183 Session Progress
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bK919B5
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Sun, 04 Jan 2015 05:22:11 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Timestamp: 1014987515
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Require: 100rel
    RSeq: 7694
    Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
    Allow-Events: telephone-event
    Contact: <sip:6601@192.168.1.200:5060>
    Content-Disposition: session;handling=required
    Content-Type: application/sdp
    Content-Length: 194


    v=0
    o=CiscoSystemsSIP-GW-UserAgent 3190 4529 IN IP4 192.168.1.200
    s=SIP Call
    c=IN IP4 192.168.1.200
    t=0 0
    m=audio 17184 RTP/AVP 8
    c=IN IP4 192.168.1.200
    a=rtpmap:8 PCMA/8000
    a=ptime:20


    *Jan 4 05:22:11.368: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 20.20.20.2:59570
    *Jan 4 05:22:11.368: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Jan 4 05:22:11.368: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    PRACK sip:6601@192.168.1.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bKA2409
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Fri, 01 Mar 2002 12:58:35 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    CSeq: 102 PRACK
    RAck: 7694 101 INVITE
    Max-Forwards: 70
    Content-Length: 0






    *Jan 4 05:22:11.372: //39/DBD8E4E78012/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x8561974C
    *Jan 4 05:22:11.376: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:11.376: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Jan 4 05:22:11.380: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:11.380: //39/DBD8E4E78012/SIP/Info/act_recdinvite_new_message_request: Transaction Complete. Lock on Facilities released.
    *Jan 4 05:22:11.384: //39/DBD8E4E78012/SIP/Transport/sipSPISendPrackResponse: Sending PRACK Response to the transport layer
    *Jan 4 05:22:11.384: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: msg=0x887486E0, addr=20.20.20.2, port=59570, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
    *Jan 4 05:22:11.384: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Jan 4 05:22:11.384: //39/DBD8E4E78012/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Jan 4 05:22:11.384: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x887486E0, addr=20.20.20.2, port=5060, connId=0 for UDP
    *Jan 4 05:22:11.388: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bKA2409
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Sun, 04 Jan 2015 05:22:11 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 102 PRACK
    Content-Length: 0






    *Jan 4 05:22:17.096: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_CONNECT
    *Jan 4 05:22:17.100: //39/DBD8E4E78012/SIP/Info/sipSPIValidateGtd: No rawMsg from CCAPI
    *Jan 4 05:22:17.108: //39/DBD8E4E78012/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer
    *Jan 4 05:22:17.108: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: msg=0x887486E0, addr=20.20.20.2, port=59570, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x81060204
    *Jan 4 05:22:17.108: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Jan 4 05:22:17.108: //39/DBD8E4E78012/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Jan 4 05:22:17.108: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x887486E0, addr=20.20.20.2, port=5060, connId=0 for UDP
    *Jan 4 05:22:17.112: //39/DBD8E4E78012/SIP/Info/sentInviteResponse200: Sent 200Ok for Invite in state STATE_RECD_INVITE
    *Jan 4 05:22:17.112: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteResponse200: Transaction active. Facilities will be queued.
    *Jan 4 05:22:17.112: //39/DBD8E4E78012/SIP/State/sipSPIChangeState: 0x8561974C : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_SENT_SUCCESS, SUBSTATE_NONE)
    *Jan 4 05:22:17.112: //39/DBD8E4E78012/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
    *Jan 4 05:22:17.116: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bK919B5
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Sun, 04 Jan 2015 05:22:11 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Timestamp: 1014987515
    Server: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER
    Supported: replaces
    Allow-Events: telephone-event
    Contact: <sip:6601@192.168.1.200:5060>
    Content-Type: application/sdp
    Content-Length: 194


    v=0
    o=CiscoSystemsSIP-GW-UserAgent 3190 4529 IN IP4 192.168.1.200
    s=SIP Call
    c=IN IP4 192.168.1.200
    t=0 0
    m=audio 17184 RTP/AVP 8
    c=IN IP4 192.168.1.200
    a=rtpmap:8 PCMA/8000
    a=ptime:20


    *Jan 4 05:22:17.160: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 20.20.20.2:59570
    *Jan 4 05:22:17.160: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Jan 4 05:22:17.160: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    ACK sip:6601@192.168.1.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bKB2144
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Fri, 01 Mar 2002 12:58:35 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Max-Forwards: 70
    CSeq: 101 ACK
    Content-Length: 0






    *Jan 4 05:22:17.164: //39/DBD8E4E78012/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x8561974C
    *Jan 4 05:22:17.164: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:17.168: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Jan 4 05:22:17.168: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:17.168: //39/DBD8E4E78012/SIP/Info/act_sentsucc_new_message_request: Transaction Complete. Lock on Facilities released.
    *Jan 4 05:22:17.168: //39/DBD8E4E78012/SIP/State/sipSPIChangeState: 0x8561974C : State change from (STATE_SENT_SUCCESS, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE)
    *Jan 4 05:22:17.168: //39/DBD8E4E78012/SIP/Call/sipSPICallInfo:
    The Call Setup Information is:
    Call Control Block (CCB) : 0x8561974C
    State of The Call : STATE_ACTIVE
    TCP Sockets Used : NO
    Calling Number : 7701
    Called Number : 6601
    Source IP Address (Sig ): 192.168.1.200
    Destn SIP Req Addr:Port : 20.20.20.2:5060
    Destn SIP Resp Addr:Port : 20.20.20.2:59570
    Destination Name : 20.20.20.2


    *Jan 4 05:22:17.172: //39/DBD8E4E78012/SIP/Call/sipSPIMediaCallInfo:
    Number of Media Streams: 1
    Media Stream : 1
    Negotiated Codec : g711alaw
    Negotiated Codec Bytes : 160
    Negotiated Dtmf-relay : 0
    Dtmf-relay Payload : 0
    Source IP Address (Media): 192.168.1.200
    Source IP Port (Media): 17184
    Destn IP Address (Media): 20.20.20.2
    Destn IP Port (Media): 19012
    Orig Destn IP Address:Port (Media): 0.0.0.0:0


    *Jan 4 05:22:17.172: //39/DBD8E4E78012/SIP/Info/sipSPICreateAndStartRtpTimer:
    *Jan 4 05:22:17.172: //39/DBD8E4E78012/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
    *Jan 4 05:22:17.172: //39/DBD8E4E78012/SIP/Info/sipSPIProcessHoldTimerForCall: Media IP Addr 20.20.20.2, RTCP Type 3
    *Jan 4 05:22:17.172: //39/DBD8E4E78012/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
    CME_A_#
    CME_A_#
    CME_A_#
    *Jan 4 05:22:57.592: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpSocketReads: Msg enqueued for SPI with IP addr: 20.20.20.2:59570
    *Jan 4 05:22:57.596: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
    *Jan 4 05:22:57.596: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Received:
    BYE sip:6601@192.168.1.200:5060 SIP/2.0
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bKC6DD
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Fri, 01 Mar 2002 12:58:35 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    User-Agent: Cisco-SIPGateway/IOS-12.x
    Max-Forwards: 70
    Timestamp: 1014987561
    CSeq: 103 BYE
    Reason: Q.850;cause=16
    Content-Length: 0






    *Jan 4 05:22:57.600: //39/DBD8E4E78012/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x8561974C
    *Jan 4 05:22:57.600: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:57.600: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone PST to SIP default timezone = GMT
    *Jan 4 05:22:57.604: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 20.20.20.2,Port 59570, Transport 1, SentBy Port 5060
    *Jan 4 05:22:57.604: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[39], src[2]
    *Jan 4 05:22:57.604: //39/DBD8E4E78012/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer
    *Jan 4 05:22:57.604: //39/DBD8E4E78012/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(16) for incoming call
    *Jan 4 05:22:57.604: //39/DBD8E4E78012/SIP/State/sipSPIChangeState: 0x8561974C : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
    *Jan 4 05:22:57.612: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
    *Jan 4 05:22:57.620: //39/DBD8E4E78012/SIP/Transport/sipSPISendByeResponse: Sending BYE Response to the transport layer
    *Jan 4 05:22:57.620: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: msg=0x88748410, addr=20.20.20.2, port=59570, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x8106070C
    *Jan 4 05:22:57.620: //39/DBD8E4E78012/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
    *Jan 4 05:22:57.620: //39/DBD8E4E78012/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
    *Jan 4 05:22:57.620: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x88748410, addr=20.20.20.2, port=5060, connId=0 for UDP
    *Jan 4 05:22:57.620: //39/DBD8E4E78012/SIP/Info/sentByeResponse: Sent 200ok to the BYE, tearing down the call
    *Jan 4 05:22:57.624: //39/DBD8E4E78012/SIP/Info/sipSPIIcpifUpdate: CallState: 4 Playout: 39210 DiscTime:1296244 ConnTime 1292193
    *Jan 4 05:22:57.624: //39/DBD8E4E78012/SIP/State/sipSPIChangeState: 0x8561974C : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
    *Jan 4 05:22:57.628: //39/DBD8E4E78012/SIP/Call/sipSPICallInfo:
    The Call Setup Information is:
    Call Control Block (CCB) : 0x8561974C
    State of The Call : STATE_DEAD
    TCP Sockets Used : NO
    Calling Number : 7701
    Called Number : 6601
    Source IP Address (Sig ): 192.168.1.200
    Destn SIP Req Addr:Port : 20.20.20.2:5060
    Destn SIP Resp Addr:Port : 20.20.20.2:59570
    Destination Name : 20.20.20.2


    *Jan 4 05:22:57.628: //39/DBD8E4E78012/SIP/Call/sipSPIMediaCallInfo:
    Number of Media Streams: 1
    Media Stream : 1
    Negotiated Codec : g711alaw
    Negotiated Codec Bytes : 160
    Negotiated Dtmf-relay : 0
    Dtmf-relay Payload : 0
    Source IP Address (Media): 192.168.1.200
    Source IP Port (Media): 17184
    Destn IP Address (Media): 20.20.20.2
    Destn IP Port (Media): 19012
    Orig Destn IP Address:Port (Media): 0.0.0.0:0


    *Jan 4 05:22:57.628: //39/DBD8E4E78012/SIP/Call/sipSPICallInfo:
    Disconnect Cause (CC) : 16
    Disconnect Cause (SIP) : 200


    *Jan 4 05:22:57.628: //39/DBD8E4E78012/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 27
    *Jan 4 05:22:57.636: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
    Sent:
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 20.20.20.2:5060;branch=z9hG4bKC6DD
    From: "Goldie" <sip:7701@20.20.20.2>;tag=6C27D4-751
    To: <sip:6601@192.168.1.200>;tag=C51530-236B
    Date: Sun, 04 Jan 2015 05:22:57 GMT
    Call-ID: E01FDCD9-2C4A11D6-8015CBD3-FD31EA58@65.65.65.200
    Server: Cisco-SIPGateway/IOS-12.x
    Timestamp: 1014987561
    Content-Length: 0
    CSeq: 103 BYE


    CME_A_#
    CME_A_#
    CME_A_#
    CME_A_#
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    So opening UDP port 5060 on a ACL allows the voice stream to go through on the FXS analog SIP RTP connection ?

    And that is both ways?

    Ways cool!!!
  • JollycorkJollycork Member Posts: 149
    So any warbling or delay on the audio over the WAN? Just curious......
  • JeanMJeanM Member Posts: 1,117
    VoIP quality is fine, no issues that I can report. Now, my WAN is basically a LAB "wan" made of a couple routers. I'll play with different codecs once I have more time to compare as well. Yeah, so the 2600xm routers have the Voice modules and DSP with the FXS cards for the analog phones, from there it's VoIP on the other side of the router :)

    My next plan of action is to extend this lab over the internet, by finding another person who is willing to configure a CME router and dial-peer. That way it will really be over internet WAN .

    Let me know if you are interested to give it a shot.
    2015 goals - ccna voice / vmware vcp.
  • JollycorkJollycork Member Posts: 149
    So this is strictly FXS/FXO analog phone on CME where CME runs on the 2620xm & your using the single FA 0/0 as your WAN link out on the 2620xm? over SIP?

    just curious again.... I remember you labbing SIP voip a while back
  • JeanMJeanM Member Posts: 1,117
    This lab scenario is just as shown in the diagram in the 2nd post . Basically it's analog phone on fxs port / voice module in 2600xm running cme connected to 1st 2621 running as edge to 1st 3640 running as "service provider" wan link to 2nd 3640 as another SP, connected to 2nd 2621 running as remote edge, and connected to another 2600xm/fxs/analog phone. I basically wanted to "simulate" two branch locations , each one behind it's own internet connection with NAT on each side...

    SIP trunk I do have configured on one of the 2811, that was another lab exercise :)
    2015 goals - ccna voice / vmware vcp.
Sign In or Register to comment.