locked
Inbound calls getting lost in the mediation server RRS feed

  • Question

  • Hi there.

    Here's my setup:

    The World <-> Asterisk1.4 <-> OpenSIPS <-> OCS Mediation <-> OCS Standard

    Outbound from OCS works fine, both to extensions on the Asterisk and the outside world.

    Inbound to OCS however, seems to get lost in the Mediation server somewhere.

    I attach a copy of the MediationServer log in the hope that someone will have some ideas.

    For Info:
    Asterisk - 10.10.100.1
    OpenSIPS - 10.10.100.217
    OCS Mediation - 10.10.100.216 & 1.2.243.216
    OCS Standard - 1.2.243.236
    OCS SIP Domain - sipdomain.local

    012345678 is the phone number of the cell-phone that's trying to ring the OCS Extension.

    (The public IPs and the SIP Domain have been obfuscated in the log)

    +441 is the OCS extension I'm trying to ring. On the Mediation Server, the Enterprise Voice Route Helper (from R2 ResKit) correctly translates +441 to the correct user.

    TL_INFO(TF_COMPONENT) [2]0D98.0A18::09/22/2009-16:14:43.956.0000009f (MediationServer,GatewayListener.GatewaySessionReceivedEventHandler:gatewaylistener.cs(347))( 0000000000B7AB7B )Received new Gateway incoming session.
    TL_INFO(TF_PROTOCOL) [2]0D98.0A18::09/22/2009-16:14:44.175.000000a3 (MediationServer,GatewaySDP.ParseSdpOffer:gatewaysdp.cs(801))( 00000000023404EE )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 0766b9b13010746c219a5da86c86e25d@SIPDOMAIN.local
    From: sip:012345678@SIPDOMAIN.local
    To: sip:+441@10.10.100.217
    Direction: Inbound
    Start-Line: Receive invite from Gateway, SDP is: v=0
    o=root 10015 10015 IN IP4 10.10.100.1
    s=session
    c=IN IP4 10.10.100.1
    b=CT:384
    t=0 0
    m=audio 15442 RTP/AVP 0 8 101
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    a=silenceSupp:off - - - -
    a=ptime:20
    a=sendrecv
    m=video 17516 RTP/AVP 34 99
    a=rtpmap:34 H263/90000
    a=rtpmap:99 H264/90000
    a=sendrecv

    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [2]0D98.0A18::09/22/2009-16:14:44.546.000000aa (MediationServer,MediaSessionAgent.constructor:mediasessionagent.cs(609))$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line:  MediaSessionAgent component initialized. Encryption policy: Supported
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [2]0D98.0A18::09/22/2009-16:14:44.573.000000ab (MediationServer,MediaAsyncResult<TEx>.MediaAsyncResult:asyncresult.cs(368))( 0000000002B3B1BE )<GenerateOfferWorkitemAsyncResult_2B3B1BE> Owner: <MediaSessionAgent_3F8B095>, Microsoft.Rtc.Collaboration.AudioVideo.MediaSessionAgent+GenerateOfferWorkitemAsyncResult created. External callback:<AsyncCallback_EF8F80A0>, OperationId: NULL
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.593.000000ac (MediationServer,MediaSessionAgent.SetNextState:mediasessionagent.cs(4338))( 0000000003F8B095 )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line:  MediaSessionAgent state transition: Initial -> Negotiating
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.601.000000ad (MediationServer,MediaAsyncResult<TEx>.MediaAsyncResult:asyncresult.cs(368))( 00000000020266E5 )<InstantiateNewMediaWorkitemAsyncResult_20266E5> Owner: <MediaSessionAgent_3F8B095>, Microsoft.Rtc.Collaboration.AudioVideo.MediaSessionAgent+InstantiateNewMediaWorkitemAsyncResult created. External callback:<AsyncCallback_EF8F80A0>, OperationId: NULL
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.683.000000b0 (MediationServer,MediaAsyncResult<TEx>.MediaAsyncResult:asyncresult.cs(368))( 0000000003DD3515 )<CountingAsyncResult_3DD3515> Owner: <MediaSessionAgent_3F8B095>, Microsoft.Rtc.Collaboration.AudioVideo.CountingAsyncResult created. External callback:<AsyncCallback_EF8F80A0>, OperationId: NULL
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.687.000000b1 (MediationServer,CountingAsyncResult.IncrementOperationCount:asyncresult.cs(1052))( 0000000003DD3515 )<CountingAsyncResult_3DD3515> Owner: <MediaSessionAgent_3F8B095> Adding operations 2 (0/2)
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b2 (MediationServer,MediaSessionAgent.ProcessRtpEndpointStateChangedWorkitem:mediasessionagent.cs(4630))( 0000000003F8B095 )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line:  <OBJ><T>MediaSessionAgent</T><ADR>3F8B095</ADR><MSG>Local endpoint allocation completed (Succeeded) for RtpEndpoint [10104599]</MSG></OBJ>
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b3 (MediationServer,CountingAsyncResult.WrappedOperationComplete:asyncresult.cs(1023))( 0000000003DD3515 )<CountingAsyncResult_3DD3515> Owner: <MediaSessionAgent_3F8B095> WrappedOperationComplete: 1/2 Async = <null>
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b4 (MediationServer,MediaSessionAgent.ProcessRtpEndpointConnectivityEventWorkitem:mediasessionagent.cs(4457))( 0000000003F8B095 )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line:  ICEv19 RtpEndpoint Connectivity EndpointEvent: LocalEndpointsAllocated; Status: None
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b5 (MediationServer,CountingAsyncResult.WrappedOperationComplete:asyncresult.cs(1023))( 0000000003DD3515 )<CountingAsyncResult_3DD3515> Owner: <MediaSessionAgent_3F8B095> WrappedOperationComplete: 2/2 Async = <null>
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b6 (MediationServer,MediaAsyncResult<TEx>.Complete:asyncresult.cs(617))( 0000000003DD3515 )<CountingAsyncResult_3DD3515> Owner: <MediaSessionAgent_3F8B095> Completing operation: Microsoft.Rtc.Collaboration.AudioVideo.CountingAsyncResult
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b7 (MediationServer,MediaAsyncResult<TEx>.MakeCallback:asyncresult.cs(695))( 0000000003DD3515 )<CountingAsyncResult_3DD3515> Owner: <MediaSessionAgent_3F8B095> External callback=<AsyncCallback_EF8F80A0>
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b8 (MediationServer,MediaAsyncResult<TEx>.Complete:asyncresult.cs(617))( 00000000020266E5 )<InstantiateNewMediaWorkitemAsyncResult_20266E5> Owner: <MediaSessionAgent_3F8B095> Completing operation: Microsoft.Rtc.Collaboration.AudioVideo.MediaSessionAgent+InstantiateNewMediaWorkitemAsyncResult
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.714.000000b9 (MediationServer,MediaAsyncResult<TEx>.MakeCallback:asyncresult.cs(695))( 00000000020266E5 )<InstantiateNewMediaWorkitemAsyncResult_20266E5> Owner: <MediaSessionAgent_3F8B095> External callback=<AsyncCallback_EF8F80A0>
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.839.000000ba (MediationServer,MediaAsyncResult<TEx>.Complete:asyncresult.cs(617))( 0000000002B3B1BE )<GenerateOfferWorkitemAsyncResult_2B3B1BE> Owner: <MediaSessionAgent_3F8B095> Completing operation: Microsoft.Rtc.Collaboration.AudioVideo.MediaSessionAgent+GenerateOfferWorkitemAsyncResult
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:14:44.839.000000bb (MediationServer,MediaAsyncResult<TEx>.MakeCallback:asyncresult.cs(695))( 0000000002B3B1BE )<GenerateOfferWorkitemAsyncResult_2B3B1BE> Owner: <MediaSessionAgent_3F8B095> External callback=<AsyncCallback_EF8F80A0>
    TL_INFO(TF_PROTOCOL) [0]0D98.0BEC::09/22/2009-16:14:44.866.000000bc (MediationServer,ProxySDP.GetOffer:proxysdp.cs(48))( 00000000030E9943 )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line: Send invite to Proxy, SDP is: v=0
    o=- 0 0 IN IP4 1.2.243.216
    s=session
    c=IN IP4 1.2.243.216
    b=CT:1000
    t=0 0
    m=audio 60584 RTP/AVP 0 8 115 13 118 97 101
    c=IN IP4 10.10.100.216
    a=rtcp:60488
    a=candidate:+HkrQcLpG9xiRFCTS3qcZzCznm/giMPm7P7wuF/bbhQ 1 xEwjYSicB+3EWr71GNEiHQ UDP 0.830 10.10.100.216 60584
    a=candidate:+HkrQcLpG9xiRFCTS3qcZzCznm/giMPm7P7wuF/bbhQ 2 xEwjYSicB+3EWr71GNEiHQ UDP 0.830 10.10.100.216 60488
    a=candidate:C5O/Zrs4wVOQW5EHCI1Qqehr/WKT+Hdg6Ztya1gpk08 1 QyESMX5KinjGWbSIG3dZhA UDP 0.840 1.2.243.216 63572
    a=candidate:C5O/Zrs4wVOQW5EHCI1Qqehr/WKT+Hdg6Ztya1gpk08 2 QyESMX5KinjGWbSIG3dZhA UDP 0.840 1.2.243.216 62457
    a=cryptoscale:1 client AES_CM_128_HMAC_SHA1_80 inline:Pscfdo0BbPSN5Ar15X9iXWU7rjzvj0g4xkLpbU1E|2^31|1:1
    a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:twUpf4w65ukeyuOmBdJ9C40d6Hb3OgAvwwCuKafp|2^31|1:1
    a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:nGilIA4HQoWpLumNcRFYP+GZGcE6HqzHlEmYzMWm|2^31
    a=label:main-audio
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:115 x-msrta/8000
    a=fmtp:115 bitrate=11800
    a=rtpmap:13 CN/8000
    a=rtpmap:118 CN/16000
    a=rtpmap:97 RED/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    v=0
    o=- 0 0 IN IP4 1.2.243.216
    s=session
    c=IN IP4 1.2.243.216
    b=CT:1000
    t=0 0
    m=audio 61684 RTP/AVP 0 8 115 13 118 97 101
    c=IN IP4 10.10.100.216
    a=rtcp:62974
    a=ice-ufrag:jpDh
    a=ice-pwd:1fZa86AikM6LLM9JF8YYwMPd
    a=candidate:1 1 UDP 2130706431 10.10.100.216 61684 typ host
    a=candidate:1 2 UDP 2130705918 10.10.100.216 62974 typ host
    a=candidate:2 1 UDP 2130705919 1.2.243.216 62379 typ host
    a=candidate:2 2 UDP 2130705406 1.2.243.216 62869 typ host
    a=candidate:3 1 tcp-act 1684798463 10.10.100.216 61684 typ srflx raddr 10.10.100.216 rport 61684
    a=candidate:3 2 tcp-act 1684797950 10.10.100.216 61684 typ srflx raddr 10.10.100.216 rport 61684
    a=cryptoscale:1 client AES_CM_128_HMAC_SHA1_80 inline:Pscfdo0BbPSN5Ar15X9iXWU7rjzvj0g4xkLpbU1E|2^31|1:1
    a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:twUpf4w65ukeyuOmBdJ9C40d6Hb3OgAvwwCuKafp|2^31|1:1
    a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:nGilIA4HQoWpLumNcRFYP+GZGcE6HqzHlEmYzMWm|2^31
    a=label:main-audio
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:115 x-msrta/8000
    a=fmtp:115 bitrate=11800
    a=rtpmap:13 CN/8000
    a=rtpmap:118 CN/16000
    a=rtpmap:97 RED/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16

    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [0]0D98.0B18::09/22/2009-16:15:03.175.000000bf (MediationServer,MediaAsyncResult<TEx>.MediaAsyncResult:asyncresult.cs(368))( 00000000005C39D4 )<SendReportAsyncResult_5C39D4> Owner: <null>, Microsoft.Rtc.Qoe.QoeReportSender+SendReportAsyncResult created. External callback:<AsyncCallback_EF8F80A0>, OperationId: NULL
    TL_INFO(TF_COMPONENT) [0]0D98.0B18::09/22/2009-16:15:03.175.000000c0 (MediationServer,QoeReportSender.BeginSendReportInternal:qoeagent.cs(221))<OBJ><T>static QoeReportSender, hash of QoeAgent</T><ADR>0390BE75</ADR><MSG>QoE report not sent. DialogStart not set.  </MSG></OBJ>
    TL_INFO(TF_COMPONENT) [0]0D98.0B18::09/22/2009-16:15:03.175.000000c1 (MediationServer,MediaAsyncResult<TEx>.Complete:asyncresult.cs(617))( 00000000005C39D4 )<SendReportAsyncResult_5C39D4> Owner: <null> Completing operation: Microsoft.Rtc.Qoe.QoeReportSender+SendReportAsyncResult
    TL_INFO(TF_COMPONENT) [0]0D98.0B18::09/22/2009-16:15:03.175.000000c2 (MediationServer,MediaAsyncResult<TEx>.MakeCallback:asyncresult.cs(695))( 00000000005C39D4 )<SendReportAsyncResult_5C39D4> Owner: <null> External callback=<AsyncCallback_EF8F80A0>
    TL_INFO(TF_COMPONENT) [2]0D98.0B18::09/22/2009-16:15:03.218.000000c3 (MediationServer,MediaAsyncResult<TEx>.MediaAsyncResult:asyncresult.cs(368))( 00000000033A0929 )<TerminateMediaSessionWorkitemAsyncResult_33A0929> Owner: <MediaSessionAgent_3F8B095>, Microsoft.Rtc.Collaboration.AudioVideo.MediaSessionAgent+TerminateMediaSessionWorkitemAsyncResult created. External callback:<AsyncCallback_EF8F80A0>, OperationId: NULL
    TL_INFO(TF_COMPONENT) [1]0D98.0BEC::09/22/2009-16:15:03.234.000000c5 (MediationServer,MediaSessionAgent.TerminateMediaSession:mediasessionagent.cs(4207))( 0000000003F8B095 )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line:  Terminating media session, reason: MediaSessionTerminated
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [1]0D98.0BEC::09/22/2009-16:15:03.234.000000c6 (MediationServer,MediaSessionAgent.SetNextState:mediasessionagent.cs(4338))( 0000000003F8B095 )$$START-MEDIATIONSERVER
    MediationCall: ff57a7c2017c44669116e87bfa6d96cf
    CallId: 3432acfd-e54d-4218-9d43-b1b790064ec7
    From: sip:012345678;phone-context=dialstring@SIPDOMAIN.local;user=phone
    To: sip:+441@SIPDOMAIN.local;user=phone
    Direction: Inbound
    Start-Line:  MediaSessionAgent state transition: Negotiating -> Terminated
    $$END-MEDIATIONSERVER
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:15:03.367.000000c7 (MediationServer,MediaAsyncResult<TEx>.Complete:asyncresult.cs(617))( 00000000033A0929 )<TerminateMediaSessionWorkitemAsyncResult_33A0929> Owner: <MediaSessionAgent_3F8B095> Completing operation: Microsoft.Rtc.Collaboration.AudioVideo.MediaSessionAgent+TerminateMediaSessionWorkitemAsyncResult
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:15:03.367.000000c8 (MediationServer,MediaAsyncResult<TEx>.MakeCallback:asyncresult.cs(695))( 00000000033A0929 )<TerminateMediaSessionWorkitemAsyncResult_33A0929> Owner: <MediaSessionAgent_3F8B095> External callback=<AsyncCallback_EF8F80A0>
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:15:03.386.000000c9 (MediationServer,MediaAsyncResult<TEx>.MediaAsyncResult:asyncresult.cs(368))( 0000000002D2B0B7 )<SendReportAsyncResult_2D2B0B7> Owner: <null>, Microsoft.Rtc.Qoe.QoeReportSender+SendReportAsyncResult created. External callback:<AsyncCallback_EF8F80A0>, OperationId: NULL
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:15:03.386.000000ca (MediationServer,QoeReportSender.BeginSendReportInternal:qoeagent.cs(221))<OBJ><T>static QoeReportSender, hash of QoeAgent</T><ADR>029341EE</ADR><MSG>QoE report not sent. DialogStart not set.  </MSG></OBJ>
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:15:03.386.000000cb (MediationServer,MediaAsyncResult<TEx>.Complete:asyncresult.cs(617))( 0000000002D2B0B7 )<SendReportAsyncResult_2D2B0B7> Owner: <null> Completing operation: Microsoft.Rtc.Qoe.QoeReportSender+SendReportAsyncResult
    TL_INFO(TF_COMPONENT) [0]0D98.0BEC::09/22/2009-16:15:03.386.000000cc (MediationServer,MediaAsyncResult<TEx>.MakeCallback:asyncresult.cs(695))( 0000000002D2B0B7 )<SendReportAsyncResult_2D2B0B7> Owner: <null> External callback=<AsyncCallback_EF8F80A0>

    Tuesday, September 22, 2009 4:37 PM

Answers

  • Problem solved - SSL error on the OCS Standard server...


    DOH!
    Tuesday, September 22, 2009 5:04 PM

All replies

  • How many network interface cards are on the Mediation server?
    Jeff Schertz, PointBridge | MVP | MCITP: Enterprise Messaging | MCTS: OCS
    Tuesday, September 22, 2009 4:46 PM
    Moderator
  • 2. One communicating with OpenSIPS (10.10.100.0/24) and the other with OCS (1.2.243.192/26)
    Tuesday, September 22, 2009 4:50 PM
  • Problem solved - SSL error on the OCS Standard server...


    DOH!
    Tuesday, September 22, 2009 5:04 PM