locked
Media allocation failure. Audio call can't be escalted to video with external client RRS feed

  • Question

  • Hello, I am deployed simple trial skype for business server with multiple clients  and now I am trying to make federation with my own sip client.

    I made federation by adding route to my  sip domain like this:

    $myroute = New-CsStaticRoute -TLSRoute -destination "myserver.mydomain.com" -port 5061 -matchuri "mydomain.com" -usedefaultcertificate $true$route = New-CsStaticRoute -TLSRoute -destination "myserver.mydomain.com" -port 5061 -matchuri "mydomain.com" -usedefaultcertificate $true
    Set-CsStaticRoutingConfiguration -identity global -route @{Add=$myroute}

    So I have got a simple audio call by this moment.

    But when I try to make escalte the call to video I get a error "Call was not completed or has ended".

    INVITE from S4B client doesn't send.

    I tried to find root cause in logs and see:

    Media allocation failure

    So..the quiestion is what exactly am I doing wrong? 

    Skype logs are following:

    09/17/2018|14:36:11.823 1F5C:A04 INFO  :: INVITE sip:001@mydomain.com SIP/2.0
    Via: SIP/2.0/TLS 192.168.159.238:50878
    Max-Forwards: 70
    From: <sip:test.user5@skypedomain.com>;tag=6d0031460a;epid=b982a05e30
    To: <sip:001@mydomain.com>
    Call-ID: 66a69eb315c04e2fbef9d137b1906e93
    CSeq: 1 INVITE
    Contact: <sip:test.user5@skypedomain.com;opaque=user:epid:C0t_PD8X31SRCuH7m8oeDgAA;gruu>
    User-Agent: UCCAPI/16.0.10730.20102 OC/16.0.10730.20102 (Skype for Business)
    Supported: ms-dialog-route-set-update
    Ms-Conversation-ID: AdROeqDlskr9pG9RTIm35pq3u9hKvA==
    Supported: timer
    Supported: histinfo
    Supported: ms-safe-transfer
    Supported: ms-sender
    Supported: ms-early-media
    Supported: 100rel
    ms-keep-alive: UAC;hop-hop=yes
    Allow: INVITE, BYE, ACK, CANCEL, INFO, UPDATE, REFER, NOTIFY, BENOTIFY, OPTIONS
    ms-subnet: 192.168.159.0
    Accept-Language: en-US
    ms-endpoint-location-data: NetworkScope;ms-media-location-type=Intranet
    P-Preferred-Identity: <sip:test.user5@skypedomain.com>
    Supported: replaces
    Supported: ms-conf-invite
    Proxy-Authorization: TLS-DSK qop="auth", realm="SIP Communications Service", opaque="7168618A", targetname="winserver237.skypedomain.com", crand="b1332126", cnum="165", response="4e7ffa49287de15f00f2e3c3334f5f20769f4b0c25cd91599280a6009eb1951e425e20ac55deee48d8c4c468caaef84f"
    Content-Type: application/sdp
    Content-Length: 1569


    v=0
    o=- 0 0 IN IP4 192.168.159.238
    s=session
    c=IN IP4 192.168.159.238
    b=CT:99980
    t=0 0
    a=x-devicecaps:audio:send,recv;video:send,recv
    m=audio 1624 RTP/AVP 117 104 114 9 112 111 0 8 103 116 115 97 13 118 119 101
    a=x-ssrc-range:1622939730-1622939730
    a=rtcp-fb:* x-message app send:dsh recv:dsh
    a=rtcp-rsize
    a=label:main-audio
    a=x-source:main-audio
    a=ice-ufrag:PQWb
    a=ice-pwd:576m4aFNmODhkhgCDJdOQCS3
    a=candidate:1 1 UDP 2130706431 192.168.159.238 1624 typ host
    a=candidate:1 2 UDP 2130705918 192.168.159.238 1625 typ host
    a=candidate:2 1 TCP-ACT 1684798975 192.168.159.238 1624 typ srflx raddr 192.168.159.238 rport 1624
    a=candidate:2 2 TCP-ACT 1684798462 192.168.159.238 1624 typ srflx raddr 192.168.159.238 rport 1624
    a=maxptime:200
    a=rtcp:1625
    a=rtpmap:117 G722/8000/2
    a=rtpmap:104 SILK/16000
    a=fmtp:104 useinbandfec=1; usedtx=0
    a=rtpmap:114 x-msrta/16000
    a=fmtp:114 bitrate=29000
    a=rtpmap:9 G722/8000
    a=rtpmap:112 G7221/16000
    a=fmtp:112 bitrate=24000
    a=rtpmap:111 SIREN/16000
    a=fmtp:111 bitrate=16000
    a=rtpmap:0 PCMU/8000
    a=rtpmap:8 PCMA/8000
    a=rtpmap:103 SILK/8000
    a=fmtp:103 useinbandfec=1; usedtx=0
    a=rtpmap:116 AAL2-G726-32/8000
    a=rtpmap:115 x-msrta/8000
    a=fmtp:115 bitrate=11800
    a=rtpmap:97 RED/8000
    a=rtpmap:13 CN/8000
    a=rtpmap:118 CN/16000
    a=rtpmap:119 CN/24000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    a=rtcp-mux
    a=ptime:20
    a=extmap:1 http:\\www.webrtc.org\experiments\rtp-hdrext\abs-send-time
    a=extmap:3 http:\\skype.com\experiments\rtp-hdrext\fast_bandwidth_feedback
    a=x-bwealgorithm:bwc packetpair




    09/17/2018|14:36:12.926 1F5C:A04 INFO  :: SIP/2.0 200 OK
    Authentication-Info: TLS-DSK qop="auth", opaque="7168618A", srand="07ADA4F7", snum="191", rspauth="cf1be5c58f25fbdc7b83e719d0ed18ba7883b6832debda5f3ec270d1bca1ad23bde27611cc860af38c722a5c0b087f94", targetname="winserver237.skypedomain.com", realm="SIP Communications Service", version=4
    CSeq: 1 INVITE
    Call-ID: 66a69eb315c04e2fbef9d137b1906e93
    From: "Test User5" <sip:test.user5@skypedomain.com>;tag=6d0031460a;epid=b982a05e30
    To: <sip:001@mydomain.com>;tag=8203644_346d969_d48298b_00394576
    Via: SIP/2.0/TLS 192.168.159.238:50878;ms-received-port=50878;ms-received-cid=F9C00
    Record-Route: <sip:winserver237.skypedomain.com:5061;transport=tls;opaque=state:F:Ci.Rf9c00;lr;ms-route-sig=gbFxxZwKag55t07k59DmiIjmcRxkfGIo3aH6HlhBCNGLlfIX9tOy8N_AAA>
    Server: My Server
    Contact: <sip:001@192.168.127.254:5061;transport=tls>
    User-to-User: 00FA086B7700255B9F91AB;encoding=hex
    Supported: eventlist,outbound,replaces,timer
    ms-endpoint-location-data: NetworkScope;ms-media-location-type=Intranet
    Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,MESSAGE,REFER,INFO,PUBLISH,UPDATE
    Content-Type: application/sdp
    Content-Length: 298

    v=0
    o=AMS 4 2 IN IP4 192.168.128.238
    s=session
    e=unknown@invalid.net
    c=IN IP4 192.168.128.238
    t=0 0
    m=audio 6070 RTP/AVP 9 13 101
    c=IN IP4 192.168.128.238
    a=rtpmap:9 G722/8000
    a=rtpmap:13 CN/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15
    a=maxptime:200
    a=ptime:20
    a=sendrecv


    ACK sip:001@192.168.127.254:5061;transport=tls SIP/2.0
    Via: SIP/2.0/TLS 192.168.159.238:50878
    Max-Forwards: 70
    From: <sip:test.user5@skypedomain.com>;tag=6d0031460a;epid=b982a05e30
    To: <sip:001@mydomain.com>;tag=8203644_346d969_d48298b_00394576
    Call-ID: 66a69eb315c04e2fbef9d137b1906e93
    CSeq: 1 ACK
    Route: <sip:winserver237.skypedomain.com:5061;transport=tls;opaque=state:F:Ci.Rf9c00;lr;ms-route-sig=gbFxxZwKag55t07k59DmiIjmcRxkfGIo3aH6HlhBCNGLlfIX9tOy8N_AAA>
    User-Agent: UCCAPI/16.0.10730.20102 OC/16.0.10730.20102 (Skype for Business)
    Proxy-Authorization: TLS-DSK qop="auth", realm="SIP Communications Service", opaque="7168618A", targetname="winserver237.skypedomain.com", crand="61e64b48", cnum="166", response="da67ed285d055a2759570ab50e209c213e4454994e1c0abc6b914859683aeb9fc62a799ac058ea2be1d7d9a410c0b93b"
    Content-Length: 0

    Video error log:

    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: CUccVideoMediaChannel2::SetDevice - Device <ManyCam Virtual Webcam> was set on video channel[0x00000139C5387820] direction=1
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: It is not LRS. Hence disable smart crop based on whether device is RT or not.
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: Add channel(00000139C5387820)
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: IsInVDIDebugMode hr = 80070002, dwValue = 0
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: IsInVDIDebugMode hr = 80070002, dwValue = 0
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: Render Context for direction = 0x1 was cached, will be applied later
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: cache subscription mode(0)
    09/17/2018|14:36:17.215 1F5C:A04 INFO  :: Setting TtyEnabled to FALSE
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: media channels count: 2
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: media channelsEx count: 1
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: CMediaFlow::QueryMediaChannels IMediaChannel [00000139CD6EBE50], Existing IMediaChannel [00000139CD6EBE50]
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: CMediaFlow::QueryMediaChannels IMediaChannel [00000139CD0C5580], Existing IMediaChannel [00000139CD6EBE50]
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: CMediaFlow::QueryMediaChannels Creating new MediaChannelEx for [00000139CD0C5580]
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: media channels count: 2
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: ucc active channels count: 2
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: ucc removed channels count: 0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Active channel Media index:0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Active channel Media type :1
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Active channel Media Video type :0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Attach media channel, ucc channel: 00000139CAF86B30, media channel: 00000139CD4BF430
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Active channel Media index:0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Active channel Media type :2
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Active channel Media Video type :0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: Attach media channel, ucc channel: 00000139C5387820, media channel: 00000139CD4BEAD0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: IsInVDIDebugMode hr = 80070002, dwValue = 0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: IsInVDIDebugMode hr = 80070002, dwValue = 0
    09/17/2018|14:36:17.225 1F5C:A04 INFO  :: put_SubscriptionMode, mode(0)
    09/17/2018|14:36:17.296 1F5C:A04 WARN  :: Media allocation failure, 00000139CD0C5580
    09/17/2018|14:36:17.296 1F5C:A04 INFO  :: CUccOutgoingInviteOperation::Send - CompleteNegotiation(MM_EX_NS_LOCAL_INTERNAL_ERROR)
    09/17/2018|14:36:17.334 1F5C:A04 ERROR :: CUccSIPAwareTransaction::SendOperations: HRESULT failed: 80004005 = hr. Send operation
    09/17/2018|14:36:17.334 1F5C:A04 ERROR :: CUccMediaSessionParticipant2::ProcessNextTransactionIfPresent: HRESULT failed: 80004005 = hr. SendOperations
    09/17/2018|14:36:17.334 1F5C:A04 INFO  :: CUccOutgoingInviteOperation::Rollback(), this = 00000139CCAF4CF0
    09/17/2018|14:36:17.334 1F5C:A04 INFO  :: CUccOutgoingInviteOperation::Rollback - CompleteNegotiation(MM_EX_NS_LOCAL_CANCEL)
    09/17/2018|14:36:17.354 1F5C:A04 ERROR :: CUccOutgoingInviteOperation::Rollback: HRESULT failed: 8007139f = hr. CompleteNegotiation

    P.S.

    When I make escalation with inner skype users it work even if users are on different subnets.

    Thanks.

    Monday, September 17, 2018 11:58 AM

All replies

  • Hi Developer 1432,

    As this issue only occurred when the Audio call escalate to video call with external client, and it shows the error “failed: 8007139f = hr. CompleteNegotiation” in the logs, it seems the Edge server issue. I suggest you could try to check the static routes on the Edge internal NIC, and the firewall settings, more details you could refer to the following blog to check the edge deployment:
    http://blog.schertz.name/2016/03/skype-for-business-2015-edge-pool-deployment/ 
    Check the Edge Server ports, you could follow this link:
    http://blog.schertz.name/2012/07/understanding-lync-edge-server-ports/ 

    In addition, you could check the federation in the SFB Server control panel. More details about the federation, you could refer to the following official document:
    https://technet.microsoft.com/en-us/library/gg182550%28v=ocs.15%29.aspx 

    Best Regard,
    Evan
    • Proposed as answer by woshixiaobai Wednesday, September 19, 2018 6:20 AM
    Tuesday, September 18, 2018 6:15 AM
  • Hi,

    Is there any update for this issue, if the reply is helpful to you, please try to mark it as an answer, it will help others who have the similar issue.

    Best Regard,
    Evan
    Thursday, September 20, 2018 9:59 AM
  • Hi, I have the same problem, but I haven't Edge Server in my deployment.

    The third solution (Enable or disable discovery of federation partners) didn't help me.

    Can this problem be related with SIP?

    In Microsoft case Skype for Business sends 183 answer with early media sdp. My sip client doesn't do it. 

    P.S.

    Escalating video calls between s4b client works.

    Friday, September 21, 2018 8:19 AM