locked
SIP/2.0 400 Missing correct Via header RRS feed

  • Question

  •  

    Hi

     

    I am having a problem integrating a Nortels MCM and OCS. I have MCM sitting on the OCS proxy and ll is happy. Proxy is forwarding traffic to mediation server however I get a SIP/2.0 400 Missing correct Via header error when trying to call a OC Client extension number. The call is not being presented as E164 however I have thi same configuration on a number of othr sites andall works fine.

     

    Full log below.

     

    Thanks in advance for any words of wisdom!

     

     

    Rob

     

     

    Log from mediation server trace:

     

     

     

    TL_INFO(TF_PROTOCOL) [1]01F8.11C0::11/05/2008-18:01:57.213.00003526 (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTcpConnection_1830FA4>], 10.233.36.91:5060<-10.233.36.89:3852
    INVITE sip:7980@europa.internal;user=phone;x-nt-redirect=redirect-server SIP/2.0
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;tag=1ebf6a00-82c0e90a-13c4-40030-352df1-580cde82-352df1
    TO: <sip:7980@europa.internal;user=phone>
    CSEQ: 1 INVITE
    CALL-ID: 1e39e2e0-82c0e90a-13c4-40030-352df1-2aae339c-352df1
    MAX-FORWARDS: 69
    VIA: SIP/2.0/TCP 10.233.36.89:3852;branch=z9hG4bKCD90E777.E6FF65BD;branched=TRUE
    VIA: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-352df1-cfbb7784-4598bfe3;ms-received-port=2524;ms-received-cid=1200
    RECORD-ROUTE: <sipTongue Tiederv3800.europa.internal;transport=tcp;lr>;tag=53C999DA609100A81D2D5D0843BF6777
    CONTACT: <sip:1411;phone-context=ipermcdp.ipermudp@europa.internal:5060;maddr=10.233.192.130;transport=tcp;user=phone>
    CONTENT-LENGTH: 239
    SUPPORTED: 100rel,x-nortel-sipvc,replaces,timer
    USER-AGENT: Nortel CS1000 SIP GW release_5.0 version_sse-5.00.31
    CONTENT-TYPE: application/SDP
    ALLOW: INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
    P-ASSERTED-IDENTITY: "Keith Eglington C&W"<sip:1411;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
    Privacy: none
    x-nt-ocn-id: <sip:7980;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
    History-Info: <sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>;index=1
    x-nt-corr-id: 0000011312012f050b@001ecaf04082-ecc9f522
    Min-SE: 0
    v=0
    o=- 1003 1 IN IP4 10.233.192.130
    s=-
    t=0 0
    m=audio 5200 RTP/AVP 8 0 18 101 111
    c=IN IP4 10.253.132.2
    a=fmtp:18 annexb=no
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=rtpmap:111 X-nt-inforeq/8000
    a=ptime:20
    a=sendrecv
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.16C0::11/05/2008-18:01:57.213.00003558 (S4,SipMessage.DataLoggingHelper:472.idx(500))
    >>>>>>>>>>>>Outgoing SipMessage c=[<SipTcpConnection_1830FA4>], 10.233.36.91:5060->10.233.36.89:3852
    SIP/2.0 100 Trying
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;tag=1ebf6a00-82c0e90a-13c4-40030-352df1-580cde82-352df1
    TO: <sip:7980@europa.internal;user=phone>
    CSEQ: 1 INVITE
    CALL-ID: 1e39e2e0-82c0e90a-13c4-40030-352df1-2aae339c-352df1
    VIA: SIP/2.0/TCP 10.233.36.89:3852;branch=z9hG4bKCD90E777.E6FF65BD;branched=TRUE,SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-352df1-cfbb7784-4598bfe3;ms-received-port=2524;ms-received-cid=1200
    CONTENT-LENGTH: 0
    ------------EndOfOutgoing SipMessage
    TL_INFO(TF_COMPONENT) [0]01F8.16C0::11/05/2008-18:01:57.323.0000359b (MediationServer,ProxyStream.ProcessConnectivityStateChangedEvent:816.idx(1608))( 012B33F1 )$$START-MEDIATIONSERVER
    MediationCall: f4e9a23f6c6145e2b05963172888733d
    CallId: 28a5580d-c976-41a0-9268-d89ff297a79e
    From: sip:1411;phone-context=dialstring@europa.internal;user=phone
    To: sip:7980;phone-context=Abbey_profile@europa.internal;user=phone
    Direction: Inbound
    Start-Line: Endpoint ConnectivityStateChanged state: LocalEndpointsAllocated
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [0]01F8.16C0::11/05/2008-18:01:57.323.0000359c (MediationServer,ProxyStream.ProcessConnectivityStateChangedEvent:816.idx(1701))( 012B33F1 )$$START-MEDIATIONSERVER
    MediationCall: f4e9a23f6c6145e2b05963172888733d
    CallId: 28a5580d-c976-41a0-9268-d89ff297a79e
    From: sip:1411;phone-context=dialstring@europa.internal;user=phone
    To: sip:7980;phone-context=Abbey_profile@europa.internal;user=phone
    Direction: Inbound
    Start-Line: Endpoint LocalEndpointsAllocatedwith reason: None
    $$END-MEDIATIONSERVER
    TL_INFO(TF_PROTOCOL) [1]01F8.16C0::11/05/2008-18:01:57.323.0000359d (MediationServer,ProxySDP.GetOffer:1.idx(144))( 008B42D2 )$$START-MEDIATIONSERVER
    MediationCall: f4e9a23f6c6145e2b05963172888733d
    CallId: 28a5580d-c976-41a0-9268-d89ff297a79e
    From: sip:1411;phone-context=dialstring@europa.internal;user=phone
    To: sip:7980;phone-context=Abbey_profile@europa.internal;user=phone
    Direction: Inbound
    Start-Line: Send invite to Proxy, SDP is: v=0
    o=- 0 0 IN IP4 10.233.36.90
    s=session
    c=IN IP4 10.233.36.90
    b=CT:1000
    t=0 0
    m=audio 61420 RTP/AVP 97 101 115 111 0 8
    c=IN IP4 10.233.36.90
    a=rtcp:60236
    a=candidate:QMdqOLPtE8fX8KF3BpDq4cgWxrl7PCNmJxwHYkqBV9M 1 TqJhZsSzZo40/AkxcJZ8XQ UDP 0.900 10.233.36.90 61420
    a=candidate:QMdqOLPtE8fX8KF3BpDq4cgWxrl7PCNmJxwHYkqBV9M 2 TqJhZsSzZo40/AkxcJZ8XQ UDP 0.900 10.233.36.90 60236
    a=candidate:BLALglp3QAJTcrsStvuN5j1lhhdfoX+iq1TLPLwwqwU 1 8tWZ3wSuPkaXmQGj3u4E9Q UDP 0.900 10.233.36.91 61734
    a=candidate:BLALglp3QAJTcrsStvuN5j1lhhdfoX+iq1TLPLwwqwU 2 8tWZ3wSuPkaXmQGj3u4E9Q UDP 0.900 10.233.36.91 61729
    a=cryptoscale:1 client AES_CM_128_HMAC_SHA1_80 inline:nZPS0APC88Z5OWtkc86rrUT1vXuPYiNqG/wQmy0d|2^31|1:1
    a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:nEP5zUobC0NC+BM8dtgLVyk9pXKkq/uKbqH8hJAM|2^31|1:1
    a=crypto:3 AES_CM_128_HMAC_SHA1_80 inlineSurpriseseP04R03JPoQYFOigFj0q2kWfkTqWmbTRn62iwC|2^31
    a=label:main-audio
    a=rtpmap:97 RED/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    a=rtpmap:115 x-msrta/8000
    a=fmtp:115 bitrate=11800
    a=rtpmap:111 SIREN/16000
    a=fmtp:111 bitrate=16000
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=ptime:20
    $$END-MEDIATIONSERVER
    TL_INFO(TF_PROTOCOL) [0]01F8.16C0::11/05/2008-18:01:57.338.0000365f (S4,SipMessage.DataLoggingHelper:472.idx(500))
    >>>>>>>>>>>>Outgoing SipMessage c=[<SipTlsConnection_362F907>], 10.233.36.91:1280->10.233.36.61:5061
    INVITE sip:7980;phone-context=Abbey_profile@europa.internal;user=phone SIP/2.0
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;epid=B7D20A3215;tag=b98c7cbdd
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>
    CSEQ: 14 INVITE
    CALL-ID: 28a5580d-c976-41a0-9268-d89ff297a79e
    MAX-FORWARDS: 70
    VIA: SIP/2.0/TLS 10.233.36.91:1280;branch=z9hG4bKd44feba7
    CONTACT: <sipTongue TiedERV3718.europa.internal@iperm.ie;gruu;opaque=srvr:MediationServer:rR4m6qqIikqQb3gmXY11KAAA;grid=f4e9a23f6c6145e2b05963172888733d>;isGateway
    CONTENT-LENGTH: 1151
    SUPPORTED: replaces
    SUPPORTED: gruu-10
    USER-AGENT: RTCC/3.0.0.0 MediationServer
    CONTENT-TYPE: application/sdp; charset=utf-8
    ALLOW: UPDATE
    ms-call-source: non-ms-rtc
    ALLOW: Ack, Cancel, Bye,Invite,Refer
    v=0
    o=- 0 0 IN IP4 10.233.36.90
    s=session
    c=IN IP4 10.233.36.90
    b=CT:1000
    t=0 0
    m=audio 61420 RTP/AVP 97 101 115 111 0 8
    c=IN IP4 10.233.36.90
    a=rtcp:60236
    a=candidate:QMdqOLPtE8fX8KF3BpDq4cgWxrl7PCNmJxwHYkqBV9M 1 TqJhZsSzZo40/AkxcJZ8XQ UDP 0.900 10.233.36.90 61420
    a=candidate:QMdqOLPtE8fX8KF3BpDq4cgWxrl7PCNmJxwHYkqBV9M 2 TqJhZsSzZo40/AkxcJZ8XQ UDP 0.900 10.233.36.90 60236
    a=candidate:BLALglp3QAJTcrsStvuN5j1lhhdfoX+iq1TLPLwwqwU 1 8tWZ3wSuPkaXmQGj3u4E9Q UDP 0.900 10.233.36.91 61734
    a=candidate:BLALglp3QAJTcrsStvuN5j1lhhdfoX+iq1TLPLwwqwU 2 8tWZ3wSuPkaXmQGj3u4E9Q UDP 0.900 10.233.36.91 61729
    a=cryptoscale:1 client AES_CM_128_HMAC_SHA1_80 inline:nZPS0APC88Z5OWtkc86rrUT1vXuPYiNqG/wQmy0d|2^31|1:1
    a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:nEP5zUobC0NC+BM8dtgLVyk9pXKkq/uKbqH8hJAM|2^31|1:1
    a=crypto:3 AES_CM_128_HMAC_SHA1_80 inlineSurpriseseP04R03JPoQYFOigFj0q2kWfkTqWmbTRn62iwC|2^31
    a=label:main-audio
    a=rtpmap:97 RED/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    a=rtpmap:115 x-msrta/8000
    a=fmtp:115 bitrate=11800
    a=rtpmap:111 SIREN/16000
    a=fmtp:111 bitrate=16000
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=ptime:20
    ------------EndOfOutgoing SipMessage
    TL_INFO(TF_PROTOCOL) [0]01F8.11C0::11/05/2008-18:01:57.416.000036a7 (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTlsConnection_362F907>], 10.233.36.91:1280<-10.233.36.61:5061
    SIP/2.0 100 Trying
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;epid=B7D20A3215;tag=b98c7cbdd
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>
    CSEQ: 14 INVITE
    CALL-ID: 28a5580d-c976-41a0-9268-d89ff297a79e
    VIA: SIP/2.0/TLS 10.233.36.91:1280;branch=z9hG4bKd44feba7;ms-received-port=1280;ms-received-cid=7A00
    CONTENT-LENGTH: 0
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.11C0::11/05/2008-18:01:57.604.000036e7 (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTlsConnection_362F907>], 10.233.36.91:1280<-10.233.36.61:5061
    SIP/2.0 101 Progress Report
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;epid=B7D20A3215;tag=b98c7cbdd
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>
    CSEQ: 14 INVITE
    CALL-ID: 28a5580d-c976-41a0-9268-d89ff297a79e
    VIA: SIP/2.0/TLS 10.233.36.91:1280;branch=z9hG4bKd44feba7;ms-received-port=1280;ms-received-cid=7A00
    CONTENT-LENGTH: 0
    SERVER: TranslationService/3.0.0.0
    ms-diagnostics: 14011;reason="Called Number translated";source="SERV3750.europa.internal";RuleName="Int ext starting 7xxx";RuleDN="CN={D85E8DBC-4C8B-4C64-BEC7-C19F5D295310},CN=Location Normalization Rules,CN=RTC Service,CN=Microsoft,CN=System,DC=europa,DC=internal";CalledNumber="7980";TranslatedNumber="7980";appName="TranslationService"
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.11C0::11/05/2008-18:01:57.604.0000370d (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTlsConnection_362F907>], 10.233.36.91:1280<-10.233.36.61:5061
    SIP/2.0 400 Missing correct Via header
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;epid=B7D20A3215;tag=b98c7cbdd
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>;tag=53C999DA609100A81D2D5D0843BF6777
    CSEQ: 14 INVITE
    CALL-ID: 28a5580d-c976-41a0-9268-d89ff297a79e
    VIA: SIP/2.0/TLS 10.233.36.91:1280;branch=z9hG4bKd44feba7;ms-received-port=1280;ms-received-cid=7A00
    CONTENT-LENGTH: 0
    ms-diagnostics: 1018;reason="Parsing failure";source="serv3800.europa.internal"
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.16C0::11/05/2008-18:01:57.604.0000376e (S4,SipMessage.DataLoggingHelper:472.idx(500))
    >>>>>>>>>>>>Outgoing SipMessage c=[<SipTlsConnection_362F907>], 10.233.36.91:1280->10.233.36.61:5061
    ACK sip:7980;phone-context=Abbey_profile@europa.internal;user=phone SIP/2.0
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;tag=b98c7cbdd;epid=B7D20A3215
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>;tag=53C999DA609100A81D2D5D0843BF6777
    CSEQ: 14 ACK
    CALL-ID: 28a5580d-c976-41a0-9268-d89ff297a79e
    MAX-FORWARDS: 70
    VIA: SIP/2.0/TLS 10.233.36.91:1280;branch=z9hG4bKd44feba7
    CONTENT-LENGTH: 0
    ------------EndOfOutgoing SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.17F0::11/05/2008-18:01:57.619.0000385e (S4,SipMessage.DataLoggingHelper:472.idx(500))
    >>>>>>>>>>>>Outgoing SipMessage c=[<SipTlsConnection_2FBA92D>], 10.233.36.91:1281->10.233.36.61:5061
    SERVICE sip:7980;phone-context=Abbey_profile@europa.internal;user=phone SIP/2.0
    FROM: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>;epid=B7D20A3215;tag=3ef999d4e0
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>
    CSEQ: 15 SERVICE
    CALL-ID: 49de206a2d274665a5a5311c65a11492
    MAX-FORWARDS: 70
    VIA: SIP/2.0/TLS 10.233.36.91:1281;branch=z9hG4bKfba74c62
    CONTENT-LENGTH: 916
    USER-AGENT: RTCC/3.0.0.0 MediationServer
    CONTENT-TYPE: application/msrtc-reporterror+xml
    <?xml version="1.0" encoding="us-ascii"?><reportError xmlns="http://schemas.microsoft.com/2006/09/sip/error-reporting"><error callId="28a5580d-c976-41a0-9268-d89ff297a79e" toUri="sip:7980;phone-context=Abbey_profile@europa.internal;user=phone" fromTag="b98c7cbdd" toTag="53C999DA609100A81D2D5D0843BF6777" requestType="INVITE" contentType="application/sdp;call-type=audio" responseCode="400"><diagHeader>1018;reason="Parsing failure";source="serv3800.europa.internal"</diagHeader><progressReports><progressReport><diagHeader>14011;reason="Called Number translated";source="SERV3750.europa.internal";RuleName="Int ext starting 7xxx";RuleDN="CN={D85E8DBC-4C8B-4C64-BEC7-C19F5D295310},CN=Location Normalization Rules,CN=RTC Service,CN=Microsoft,CN=System,DC=europa,DC=internal";CalledNumber="7980";TranslatedNumber="7980";appName="TranslationService"</diagHeader></progressReport></progressReports></error></reportError>------------EndOfOutgoing SipMessage
    TL_INFO(TF_COMPONENT) [1]01F8.16C0::11/05/2008-18:01:57.635.00003895 (MediationServer,ProxyStream.InternalDispose:816.idx(1379))( 012B33F1 )$$START-MEDIATIONSERVER
    MediationCall: f4e9a23f6c6145e2b05963172888733d
    CallId: 28a5580d-c976-41a0-9268-d89ff297a79e
    From: sip:1411;phone-context=dialstring@europa.internal;user=phone
    To: sip:7980;phone-context=Abbey_profile@europa.internal;user=phone
    Direction: Inbound
    Start-Line: Disposing Proxy Audio Channel
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [1]01F8.16C0::11/05/2008-18:01:57.635.00003896 (MediationServer,ProxyStream.InternalDispose:816.idx(1383))( 012B33F1 )$$START-MEDIATIONSERVER
    MediationCall: f4e9a23f6c6145e2b05963172888733d
    CallId: 28a5580d-c976-41a0-9268-d89ff297a79e
    From: sip:1411;phone-context=dialstring@europa.internal;user=phone
    To: sip:7980;phone-context=Abbey_profile@europa.internal;user=phone
    Direction: Inbound
    Start-Line: Finished disposing Proxy Audio Channel
    $$END-MEDIATIONSERVER
    TL_INFO(TF_PROTOCOL) [0]01F8.16C0::11/05/2008-18:01:57.791.000038c2 (S4,SipMessage.DataLoggingHelper:472.idx(500))
    >>>>>>>>>>>>Outgoing SipMessage c=[<SipTcpConnection_1830FA4>], 10.233.36.91:5060->10.233.36.89:3852
    SIP/2.0 400 Missing correct Via header
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;tag=1ebf6a00-82c0e90a-13c4-40030-352df1-580cde82-352df1
    TO: <sip:7980@europa.internal;user=phone>;tag=dec4fddf9a
    CSEQ: 1 INVITE
    CALL-ID: 1e39e2e0-82c0e90a-13c4-40030-352df1-2aae339c-352df1
    VIA: SIP/2.0/TCP 10.233.36.89:3852;branch=z9hG4bKCD90E777.E6FF65BD;branched=TRUE,SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-352df1-cfbb7784-4598bfe3;ms-received-port=2524;ms-received-cid=1200
    CONTENT-LENGTH: 0
    SERVER: RTCC/3.0.0.0 MediationServer
    ------------EndOfOutgoing SipMessage
    TL_INFO(TF_PROTOCOL) [0]01F8.11C0::11/05/2008-18:01:57.791.000038f5 (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTcpConnection_1830FA4>], 10.233.36.91:5060<-10.233.36.89:3852
    ACK sip:7980@europa.internal;user=phone;x-nt-redirect=redirect-server SIP/2.0
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;tag=1ebf6a00-82c0e90a-13c4-40030-352df1-580cde82-352df1
    TO: <sip:7980@europa.internal;user=phone>;tag=dec4fddf9a
    CSEQ: 1 ACK
    CALL-ID: 1e39e2e0-82c0e90a-13c4-40030-352df1-2aae339c-352df1
    MAX-FORWARDS: 70
    VIA: SIP/2.0/TCP 10.233.36.89:3852;branch=z9hG4bKCD90E777.E6FF65BD;branched=FALSE
    CONTENT-LENGTH: 0
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.11C0::11/05/2008-18:01:57.838.0000392c (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTlsConnection_2FBA92D>], 10.233.36.91:1281<-10.233.36.61:5061
    SIP/2.0 400 Missing correct Via header
    FROM: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>;epid=B7D20A3215;tag=3ef999d4e0
    TO: <sip:7980;phone-context=Abbey_profile@europa.internal;user=phone>;tag=53C999DA609100A81D2D5D0843BF6777
    CSEQ: 15 SERVICE
    CALL-ID: 49de206a2d274665a5a5311c65a11492
    VIA: SIP/2.0/TLS 10.233.36.91:1281;branch=z9hG4bKfba74c62;ms-received-port=1281;ms-received-cid=7C00
    CONTENT-LENGTH: 0
    ms-diagnostics: 1018;reason="Parsing failure";source="serv3800.europa.internal"
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [1]01F8.11C0::11/05/2008-18:01:57.901.0000396c (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTcpConnection_1830FA4>], 10.233.36.91:5060<-10.233.36.89:3852
    ACK sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone;x-nt-redirect=redirect-server SIP/2.0
    FROM: <sip:1411;phone-context=dialstring@europa.internal;user=phone>;tag=1ebf6a00-82c0e90a-13c4-40030-352df1-580cde82-352df1
    TO: <sip:7980@europa.internal;user=phone>;tag=dec4fddf9a
    CSEQ: 1 ACK
    CALL-ID: 1e39e2e0-82c0e90a-13c4-40030-352df1-2aae339c-352df1
    MAX-FORWARDS: 69
    VIA: SIP/2.0/TCP 10.233.36.89:3852;branch=z9hG4bKCD90E777.CB4EAF56;branched=TRUE
    VIA: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-352df1-cfbb7784-4598bfe3;ms-received-port=2524;ms-received-cid=1200
    CONTACT: <sip:1411;phone-context=ipermcdp.ipermudp@europa.internal:5060;maddr=10.233.192.130;transport=tcp;user=phone>
    CONTENT-LENGTH: 0
    USER-AGENT: Nortel CS1000 SIP GW release_5.0 version_sse-5.00.31
    ALLOW: INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
    x-nt-corr-id: 0000011312012f050b@001ecaf04082-ecc9f522
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [0]01F8.16C0::11/05/2008-18:01:59.354.000039d0 (S4,SipMessage.DataLoggingHelper:472.idx(550))
    <<<<<<<<<<<<Incoming SipMessage c=[<SipTcpConnection_3CAD6F0>], 10.233.36.91:5060<-10.233.36.89:3868
    OPTIONS sip:10.233.36.91:5060 SIP/2.0
    FROM: <sip:MCM@nortel.com>;tag=6bbfb45f-127a-4c97-ab8a-ba5ac0932f5b
    TO: <sip:10.233.36.91:5060>
    CSEQ: 1 OPTIONS
    CALL-ID: 41acbaf7-528d-4d0a-89c4-f1068643971f@nortel.com
    MAX-FORWARDS: 70
    VIA: SIP/2.0/TCP 10.233.36.89:3868;branch=z9hG4bK-422726df-8d69b1-2ac0
    CONTENT-LENGTH: 0
    SUPPORTED: 100rel,x-nortel-sipvc,replaces,timer
    ------------EndOfIncoming SipMessage
    TL_INFO(TF_PROTOCOL) [0]01F8.16C0::11/05/2008-18:01:59.354.00003a18 (S4,SipMessage.DataLoggingHelper:472.idx(500))
    >>>>>>>>>>>>Outgoing SipMessage c=[<SipTcpConnection_3CAD6F0>], 10.233.36.91:5060->10.233.36.89:3868
    SIP/2.0 405 Method Not Allowed
    FROM: <sip:MCM@nortel.com>;tag=6bbfb45f-127a-4c97-ab8a-ba5ac0932f5b
    TO: <sip:10.233.36.91:5060>;tag=23ab639e
    CSEQ: 1 OPTIONS
    CALL-ID: 41acbaf7-528d-4d0a-89c4-f1068643971f@nortel.com
    VIA: SIP/2.0/TCP 10.233.36.89:3868;branch=z9hG4bK-422726df-8d69b1-2ac0
    CONTENT-LENGTH: 0
    ALLOW: NOTIFY
    ALLOW: BeNotify
    SERVER: RTCC/3.0.0.0 MediationServer
    ------------EndOfOutgoing SipMessage
    Wednesday, November 5, 2008 9:24 PM

All replies

  • Can you post your MCM log, here you will be able to see more regarding CS1000 configuration.

    You find it on the proxy server in C:\Program Files\Nortel\MCM

    Remember to set the MCM application to loging.

    Start the MCM applikation in -> Tools -> Log level, and set it to SIP and Debug.

     

     

    Friday, November 7, 2008 4:24 PM
  • HI Jan,

     

    Please see MCM log below. Its taken a few days as I am only on this site 2 days a week. The errors seem to start with MCM not being able to resolve the correct SIP Uri for the dialed extension 1411, however the AD query tool works perfectly.

     

    Thanks in advance for your assistance

     

    Rob

     

    11/11/2008 12:07:08: 3.0.1.77: Debug: OnCustomCommand: got command: update config data
    11/11/2008 12:07:09: 3.0.1.77: Debug: ConfigurationData: ReadConfigFile: Invalid secondary NRS address: 0.0.0.0
    11/11/2008 12:07:09: 3.0.1.77: Debug: ServerEventHandler: got Event #2
    11/11/2008 12:07:09: 3.0.1.77: Debug: AD Cache: turning off
    11/11/2008 12:07:09: 3.0.1.77: SIP and Debug: NRSPolling: sendPolling: request sent to the Primary NRS
    11/11/2008 12:07:09: 3.0.1.77: Debug: AD Cache: it has been turned off
    11/11/2008 12:07:09: 3.0.1.77: Debug: ServerEventHandler: got Event #3
    11/11/2008 12:07:09: 3.0.1.77: SIP and Debug: NRSPolling: pollingResponseHandler
    SIP/2.0 200
    via: SIP/2.0/TCP 10.233.36.89:1177;branch=z9hG4bK-422726df-8d69b1-2ac0;received=10.233.36.89
    from: <sipTongue TiedERV3800@europa.internal>;tag=d8e07854-b14e-4d41-91f5-4ecc2dc62cd5
    to: <sipTongue TiedERV3800@europa.internal>;tag=30017
    call-id: 0000000-00000000-0000-00000000-000002-0000
    cseq: 3 REGISTER
    contact: <sipTongue TiedERV3800@europa.internal:5060>;expires=30;maddr=10.233.36.89;Transport=TCP
    expires: 30
    content-length: 0


    11/11/2008 12:07:11: 3.0.1.77: Debug: ServerEventHandler: got Event #0
    11/11/2008 12:07:11: 3.0.1.77: SIP: Received by MCM:
    -----------------------------------------------------------
     Request: INVITE sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone;x-nt-redirect=redirect-server
      via: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-3cc5a5-ed640f30-24ed8dad;ms-received-port=4602;ms-received-cid=7400
      from: <sip:3406;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>;tag=1ebcc160-82c0e90a-13c4-40030-3cc5a5-47c172e7-3cc5a5
      to: <sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
      call-id: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
      cseq: 1 INVITE
      max-forwards: 70
      supported: 100rel,x-nortel-sipvc,replaces,timer
      user-agent: Nortel CS1000 SIP GW release_5.0 version_sse-5.00.31
      p-asserted-identity: "Keith "<sip:3406;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
      privacy: user
      x-nt-ocn-id: <sip:1411;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
      History-Info: <sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>;index=1
      x-nt-corr-id: 000001990c06380b0b@001ecaf04082-ecc9f522
      contact: <sip:3406;phone-context=ipermcdp.ipermudp@europa.internal:5060;maddr=10.233.192.130;transport=tcp;user=phone>
      min-se: 0
      allow: INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
      content-type: multipart/mixed;boundary=unique-boundary-1
      content-length: 1223

    --unique-boundary-1
    Content-Type: application/sdp

    v=0
    o=- 1138 1 IN IP4 10.233.192.130
    s=-
    t=0 0
    m=audio 5452 RTP/AVP 8 0 18 101 111
    c=IN IP4 10.233.192.134
    a=fmtp:18 annexb=no
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=rtpmap:111 X-nt-inforeq/8000
    a=ptime:20
    a=sendrecv
    m=audio 5452 RTP/SAVP 8 0 18 101 111
    c=IN IP4 10.233.192.134
    a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:MTM4MDU3MDY2MTIzMTQ3MjEyMjMzMDg0MTEyMTQwMjQxMDM5MDQ5MTA5MDc4MTUxMDgzMDg3MTg0MDU0MjI0MTc2MTg4MDQyMTkzMDQzMDE0MTM2MjI5MTgy|2^031|000419069753:004
    a=fmtp:18 annexb=no
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=rtpmap:111 X-nt-inforeq/8000
    a=ptime:20
    a=sendrecv

    --unique-boundary-1
    Content-Type: application/x-nt-mcdn-frag-hex;version=sse-5.00.31;base=x2611
    Content-Disposition: signal;handling=optional

    0500c601
    0107130081900000a200
    09090f00e9a0830001004600
    1314070011fd0e00a10c0201010201a1300481020105
    1315070011fa0f00a10d02010102020100cc04680024c100
    1e0403008183
    460e01000a0001000100140000000000
    --unique-boundary-1
    Content-Type: application/x-nt-epid-frag-hex;version=sse-5.00.31;base=x2611
    Content-Disposition: signal;handling=optional

    011201
    00:1e:ca:f0:40:cb
    --unique-boundary-1--

    -----------------------------------------------------------
    11/11/2008 12:07:11: 3.0.1.77: Debug: ProcessRequestFromGateway Request= INVITE
    11/11/2008 12:07:11: 3.0.1.77: Debug: CallType=
    11/11/2008 12:07:11: 3.0.1.77: Debug: LookupUserData: search for msRTCSIP-Line=tel:*;ext = 3406
    11/11/2008 12:07:11: 3.0.1.77: Debug: LookUpValuesInAD: invoked for msRTCSIP-Line=tel:*;ext = 3406
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=europa,DC=internal
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=ForestDnsZones,DC=europa,DC=internal
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=DomainDnsZones,DC=europa,DC=internal
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: found nothing
    11/11/2008 12:07:11: 3.0.1.77: Debug: ProcessRequestFromGateway: there is no "sip-gw-id" parameter in the incoming INVITE
    11/11/2008 12:07:11: 3.0.1.77: Debug: LookupUserData: search for msRTCSIP-Line=tel:*;ext = 1411
    11/11/2008 12:07:11: 3.0.1.77: Debug: LookUpValuesInAD: invoked for msRTCSIP-Line=tel:*;ext = 1411
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=europa,DC=internal
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=ForestDnsZones,DC=europa,DC=internal
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=DomainDnsZones,DC=europa,DC=internal
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:11: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: found nothing
    11/11/2008 12:07:11: 3.0.1.77: SIP: Sent by MCM:
    -----------------------------------------------------------
     Request: INVITE sip:1411@europa.internal;user=phone;x-nt-redirect=redirect-server
      via: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-3cc5a5-ed640f30-24ed8dad;ms-received-port=4602;ms-received-cid=7400
      to: <sip:1411@europa.internal;user=phone>
      call-id: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
      cseq: 1 INVITE
      max-forwards: 70
      supported: 100rel,x-nortel-sipvc,replaces,timer
      user-agent: Nortel CS1000 SIP GW release_5.0 version_sse-5.00.31
      p-asserted-identity: "Keith "<sip:3406;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
      privacy: user
      x-nt-ocn-id: <sip:1411;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>
      History-Info: <sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>;index=1
      x-nt-corr-id: 000001990c06380b0b@001ecaf04082-ecc9f522
      contact: <sip:3406;phone-context=ipermcdp.ipermudp@europa.internal:5060;maddr=10.233.192.130;transport=tcp;user=phone>
      min-se: 0
      allow: INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
      content-type: application/SDP
      content-length: 620
      from: <sip:3406;phone-context=dialstring@europa.internal;user=phone>;tag=1ebcc160-82c0e90a-13c4-40030-3cc5a5-47c172e7-3cc5a5

    v=0
    o=- 1138 1 IN IP4 10.233.192.130
    s=-
    t=0 0
    m=audio 5452 RTP/AVP 8 0 18 101 111
    c=IN IP4 10.233.192.134
    a=fmtp:18 annexb=no
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=rtpmap:111 X-nt-inforeq/8000
    a=ptime:20
    a=sendrecv
    m=audio 5452 RTP/SAVP 8 0 18 101 111
    c=IN IP4 10.233.192.134
    a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:MTM4MDU3MDY2MTIzMTQ3MjEyMjMzMDg0MTEyMTQwMjQxMDM5MDQ5MTA5MDc4MTUxMDgzMDg3MTg0MDU0MjI0MTc2MTg4MDQyMTkzMDQzMDE0MTM2MjI5MTgy|2^031|000419069753:004
    a=fmtp:18 annexb=no
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=rtpmap:111 X-nt-inforeq/8000
    a=ptime:20
    a=sendrecv-----------------------------------------------------------
    11/11/2008 12:07:12: 3.0.1.77: Debug: ServerEventHandler: got Event #0
    11/11/2008 12:07:12: 3.0.1.77: SIP: Received by MCM:
    -----------------------------------------------------------
     Response: 504 Server time-out
      from: <sip:3406;phone-context=dialstring@europa.internal;user=phone>;tag=1ebcc160-82c0e90a-13c4-40030-3cc5a5-47c172e7-3cc5a5
      to: <sip:1411@europa.internal;user=phone>;tag=70FC57A590F68F6E0816ABA0ECDA0C91
      call-id: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
      cseq: 1 INVITE
      via: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-3cc5a5-ed640f30-24ed8dad;ms-received-port=4602;ms-received-cid=7400
      ms-diagnostics: 1007;reason="Temporarily cannot route";source="serv3800.europa.internal";ErrorType="Connect Attempt Failure";WinsockFailureDescription="The peer actively refused the connection attempt";WinsockFailureCode="274D(WSAECONNREFUSED)";Peer="europa.internal"


    -----------------------------------------------------------
    11/11/2008 12:07:12: 3.0.1.77: Debug: MediationServer 503/504 handler: there is no "sip-gw-id" parameter in the stored INVITE
    11/11/2008 12:07:12: 3.0.1.77: Debug: DeleteEntry: Call ID deleted from IMDB: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
    11/11/2008 12:07:12: 3.0.1.77: SIP: Sent by MCM:
    -----------------------------------------------------------
     Response: 504 Server time-out
      from: <sip:3406;phone-context=dialstring@europa.internal;user=phone>;tag=1ebcc160-82c0e90a-13c4-40030-3cc5a5-47c172e7-3cc5a5
      to: <sip:1411@europa.internal;user=phone>;tag=70FC57A590F68F6E0816ABA0ECDA0C91
      call-id: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
      cseq: 1 INVITE
      via: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-3cc5a5-ed640f30-24ed8dad;ms-received-port=4602;ms-received-cid=7400
      ms-diagnostics: 1007;reason="Temporarily cannot route";source="serv3800.europa.internal";ErrorType="Connect Attempt Failure";WinsockFailureDescription="The peer actively refused the connection attempt";WinsockFailureCode="274D(WSAECONNREFUSED)";Peer="europa.internal"


    -----------------------------------------------------------
    11/11/2008 12:07:12: 3.0.1.77: Debug: ServerEventHandler: got Event #0
    11/11/2008 12:07:12: 3.0.1.77: Debug: ServerEventHandler: got Event #0
    11/11/2008 12:07:12: 3.0.1.77: SIP: Received by MCM:
    -----------------------------------------------------------
     Request: ACK sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone;x-nt-redirect=redirect-server
      via: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-3cc5a5-ed640f30-24ed8dad;ms-received-port=4602;ms-received-cid=7400
      from: <sip:3406;phone-context=ipermcdp.ipermudp@europa.internal;user=phone>;tag=1ebcc160-82c0e90a-13c4-40030-3cc5a5-47c172e7-3cc5a5
      to: <sip:1411@europa.internal;user=phone>;tag=70FC57A590F68F6E0816ABA0ECDA0C91
      call-id: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
      cseq: 1 ACK
      max-forwards: 70
      user-agent: Nortel CS1000 SIP GW release_5.0 version_sse-5.00.31
      x-nt-corr-id: 000001990c06380b0b@001ecaf04082-ecc9f522
      contact: <sip:3406;phone-context=ipermcdp.ipermudp@europa.internal:5060;maddr=10.233.192.130;transport=tcp;user=phone>
      allow: INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
      content-length: 0


    -----------------------------------------------------------
    11/11/2008 12:07:12: 3.0.1.77: Debug: ProcessRequestFromGateway Request= ACK
    11/11/2008 12:07:12: 3.0.1.77: Debug: CallType=
    11/11/2008 12:07:12: 3.0.1.77: Debug: LookupUserData: search for msRTCSIP-Line=tel:*;ext = 3406
    11/11/2008 12:07:12: 3.0.1.77: Debug: LookUpValuesInAD: invoked for msRTCSIP-Line=tel:*;ext = 3406
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=europa,DC=internal
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=ForestDnsZones,DC=europa,DC=internal
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search domain /DC=DomainDnsZones,DC=europa,DC=internal
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: search result is null
    11/11/2008 12:07:12: 3.0.1.77: Debug: ADMapper: LookUpValuesInAD: found nothing
    11/11/2008 12:07:12: 3.0.1.77: SIP: Sent by MCM:
    -----------------------------------------------------------
     Request: ACK sip:78888;phone-context=ipermcdp.ipermudp@europa.internal;user=phone;x-nt-redirect=redirect-server
      via: SIP/2.0/TCP 10.233.192.130:5060;branch=z9hG4bK-3cc5a5-ed640f30-24ed8dad;ms-received-port=4602;ms-received-cid=7400
      to: <sip:1411@europa.internal;user=phone>;tag=70FC57A590F68F6E0816ABA0ECDA0C91
      call-id: 1e3b2c90-82c0e90a-13c4-40030-3cc5a5-7680b2b9-3cc5a5
      cseq: 1 ACK
      max-forwards: 70
      user-agent: Nortel CS1000 SIP GW release_5.0 version_sse-5.00.31
      x-nt-corr-id: 000001990c06380b0b@001ecaf04082-ecc9f522
      contact: <sip:3406;phone-context=ipermcdp.ipermudp@europa.internal:5060;maddr=10.233.192.130;transport=tcp;user=phone>
      allow: INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
      content-length: 0
      from: <sip:3406;phone-context=dialstring@europa.internal;user=phone>;tag=1ebcc160-82c0e90a-13c4-40030-3cc5a5-47c172e7-3cc5a5


    -----------------------------------------------------------
    11/11/2008 12:07:12: 3.0.1.77: Debug: ServerEventHandler: got Event #0
    11/11/2008 12:07:16: 3.0.1.77: Debug: KeepAliveSender: invoked
    11/11/2008 12:07:16: 3.0.1.77: Debug: ServerEventHandler: got Event #5
    11/11/2008 12:07:16: 3.0.1.77: Debug: KeepAliveHandler: invoked
    11/11/2008 12:07:16: 3.0.1.77: Debug: KeepAliveSender: success

    Tuesday, November 11, 2008 11:53 AM
  • OK, so I found the answer. I entered the OCS FE FQDN in the authorised hosts list on the OCS proxy and the OCS proxy FQDN on the OCS FE and it fixed the problem. I thought that the communication between these happened over TCP but obviously not. Still perplexed but it works!

     

    Tuesday, November 11, 2008 8:48 PM
  • I was just ready to post this (but you found it before me Smile )

     

    from the MCM log:

     ms-diagnostics: 1007;reason="Temporarily cannot route";source="serv3800.europa.internal";ErrorType="Connect Attempt Failure";WinsockFailureDescription="The peer actively refused the connection attempt";WinsockFailureCode="274D(WSAECONNREFUSED)";Peer="europa.internal"

     

    Yes it's  runnig on port 5060 =TCP, but i would like to test in my LAB how get running TLS =5061 .

     

     

     

    Tuesday, November 11, 2008 8:57 PM