SIP2Lync Anrufe können nur 3 Sekunden lang angenommen werden

[pascal-schumacher]

Guten Tag,

aktuell beschäftige ich mich mit Skype4Business und bin darüber auf Ihre Produkte gestoßen.

Nun habe ich viel gelesen und getestet und eigentlich bis auf einen kleinen, aber wichtigen, Punkt alles hinbekommen.

Zur Umgebung:
- alte Asterisk mit ISDN (soll weg/Umstellung auf VoIP)
- Officemaster Gate
- SIP2Lync
- Skype4Business FE Server
- Skype4Business Edge Server

was funktioniert:
- eingehende Anrufe, Asterisk->OMGate->S4B
- ausgehende Rufe, S4B->OMGate->Asterisk
- ausgehende Rufe, SIP->SIP2Lync,S4B->OMGate->Asterisk
- interne Anrufe, SIP->SIP2Lync->S4B
- interne Anrufe, S4B->SIP2Lync->SIP
- interne Anrufe, SIP->SIP2Lync->S4B->SIP2Lync->SIP

was erstanlicher Weise klappt:
- eingehende Anrufe, Asterisk->OMGate->S4B->IVR->SIP2Lync->SIP

was nicht klappt:
- eingehende Anrufe, Asterisk->OMGate->S4B->SIP2Lync->SIP
--> SIP Endgerät an SIP2Lync klingelt ca. 3 Sekunden vor S4B-Client
--> gehe ich sofort ran wenn das SIP Endgerät klingelt ist der Anruf OK
--> gehe ich ran nachdem der S4B-Client bereits klingelt bricht der Anruf ab
--> dies gilt nicht wenn der Anruf zuvor über eine Warteschlange ging

Das habe ich im Protokoll nun hoch und runter analysiert und die einzige Meldung welche aufschlägt ist "sip 488 not acceptable here". Diese kommt offensichtlich vom Skype4Business Server wobei ich nicht verstehe warum es klappt wenn der S4B-Client noch nicht klingelt.


10.10.10.15 ist der skype FE Server
10.10.10.168 ist das OMGate


Wäre für einen Tip dankbar, da ich aktuell nicht mehr weis wo ich noch schauen soll.

Danke für eure Mühe.


Log:
OMGVxxxxx sip_isdn:7352 (8) SIPCMD Rx: 488 Not Acceptable Here
OMGVxxxxx sip_isdn:7352 (8) Msg from:'ip:client:s:10.10.10.15:5067::V4:7362' to:'sip_isdn:sip_isdn-7355-1447782874' delay:'NIL' data_len:380
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: +++++ rec +++++ rec +++++ rec +++++ rec +++++ rec
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: SIP/2.0 488 Not Acceptable Here
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: FROM: "0152xxxxxxxx"<sip:0152xxxxxxxx@10.10.10.168:5067> ;tag=7360-1447782874
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: TO: +49xxxxxxxxx46<sip:+49xxxxxxxxx46@10.10.10.15>;tag =e53fa85a13;epid=C8DDA3D333
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: CSEQ: 7362 INVITE
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: CALL-ID: sip_isdn-7355-1447782874
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: VIA: SIP/2.0/TLS 10.10.10.168:5067;branch=z9hG4bK-7359-1447782874
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: CONTENT-LENGTH: 0
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: SERVER: RTCC/6.0.0.0 MediationServer
OMGVxxxxx sip_isdn:7352 (8) SIPMSG:
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: ----- rec ----- rec ----- rec ----- rec ----- rec
OMGVxxxxx sip_isdn:7352 (8) >>> WaitForOkFromLegA command='LegA_RESP488'
OMGVxxxxx sip_isdn:7352 (8) use 10.10.10.168
OMGVxxxxx sip_isdn:7352 (8) SIPCMD Tx: ACK sip:+49xxxxxxxxx46@10.10.10.15:5067;transport=tls
OMGVxxxxx sip_isdn:7352 (8) Msg from:'sip_isdn:7352' to:'ip:client:s:10.10.10.15:5067::V4:7362' delay:'0' data_len:504
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: +++++ snd +++++ snd +++++ snd +++++ snd +++++ snd
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: ACK sip:+49xxxxxxxxx46@10.10.10.15:5067;transport=tls SIP/2.0
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: CSeq: 7362 ACK
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: Call-ID: sip_isdn-7355-1447782874
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: User-Agent: Ferrari electronic OMG 4.0 (4.0-250.el6,4.0-250.el6,NIL)
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: Via: SIP/2.0/TLS 10.10.10.168:5067;branch=z9hG4bK-7359-1447782874
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: X-OmgBchannelInterface: 11.a/B12/PCM/loop
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: From: "0152xxxxxxxx"<sip:0152xxxxxxxx@10.10.10.168:5067> ;tag=7360-1447782874
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: To: "+49xxxxxxxxx46"<sip:+49xxxxxxxxx46@10.10.10.15>;t ag=e53fa85a13;epid=C8DDA3D333
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: Max-Forwards: 70
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: Content-Length: 0
OMGVxxxxx sip_isdn:7352 (8) SIPMSG:
OMGVxxxxx sip_isdn:7352 (8) SIPMSG: ----- snd ----- snd ----- snd ----- snd ----- snd

[Johann Deutinger]

Na das ist ja mal eine ganz simple Konfiguration

Aber im Ernst: Da müsste man genauer einsteigen. Unter anderem sollte das Logging im FE (Standard Edition?) parallel genutzt werden, Ebenso Logging auf dem SIP2Lync; S4 und SIPStack, inbound/outbound routing etc.
Not acceptable here hat verschiedene Ursachen: Codecs, Verschlüsselung usw. Dazu muss man dann neben SIP auch auf die SDP-Inhalte schauen.

[pascal-schumacher]

danke für die schnelle Antwort.

ich bin mir sicher, dass es ein Codec Error ist, werde gleich auf dem Skype4Business ein Log ziehen.

SIP2Lync verhält sich im Log bei erfolgreichem und fehlgeschlagenem Anruf gleich. Lediglich die Dauer ist natürlich bei erfolgreich nicht nur 0,1-0,2 Sekunden:

2015-11-17 19:01:46.763: (31) Info: CallFromLync_StateChanged(+49152xxxxxxxx): because Established The previous AV call state was: Establishing and the current state is: Established
2015-11-17 19:01:46.904: (57) Info: User sip:user@domain.tld EndpointLync_PresenceNotificationReceivedHandler
2015-11-17 19:01:46.919: (28) Info: User sip:user@domain.tld EndpointLync_PresenceNotificationReceivedHandler
2015-11-17 19:01:46.966: (50) Info: CallFromLync_StateChanged(+49152xxxxxxxx): because TerminatedRemotely The previous AV call state was: Established and the current state is: Terminating

auf der Asterisk schlägt außer der Meldung "488" auch nichts auf:

<------------->
[Nov 17 16:03:17] VERBOSE[2976] logger.c: --- (12 headers 14 lines) ---
[Nov 17 16:03:17] VERBOSE[28177] logger.c: -- SIP/to-Lync-000001c9 is ringing
[Nov 17 16:03:17] VERBOSE[28177] logger.c: -- SIP/to-Lync-000001c9 is making progress passing it to SIP/9646-000001c8
[Nov 17 16:03:28] VERBOSE[2976] logger.c:
<--- SIP read from UDP://10.10.10.168:5060 --->
SIP/2.0 488 Not Acceptable Here
CSeq: 102 INVITE
Call-ID: 46703ff2525dd3330d3e8b9549c10e6b@domain.tld
Contact: <sip:+49xxxxxxxxx46@10.10.10.168;transport=udp>
X-OmgBchannelInterface: 11.b/B6/PCM/loop
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REGISTER, REFER
From: "0152xxxxxxxx"<sip:015253387065@domain.tld>;tag=as 5c09da98
User-Agent: Ferrari electronic OMG 4.0 (4.0-250.el6,4.0-250.el6,NIL)
To: <sip:+49xxxxxxxxx46@10.10.10.168:5060>;tag=5013-1447779802
Via: SIP/2.0/UDP 10.10.10.19:5060;branch=z9hG4bK50083871;rport
Reason: Q.850;cause=65
Content-Length: 0


<------------->
[Nov 17 16:03:28] VERBOSE[2976] logger.c: --- (12 headers 0 lines) ---
[Nov 17 16:03:28] VERBOSE[2976] logger.c: Transmitting (no NAT) to 10.10.10.168:5060:
ACK sip:+49xxxxxxxxx46@10.10.10.168:5060 SIP/2.0
Via: SIP/2.0/UDP 10.10.10.19:5060;branch=z9hG4bK50083871;rport
Max-Forwards: 70
From: "0152xxxxxxxx" <sip:0152xxxxxxxx@domain.tld>;tag=as5c09da98
To: <sip:+49xxxxxxxxx46@10.10.10.168:5060>;tag=5013-1447779802
Contact: <sip:0152xxxxxxxx@10.10.10.19>
Call-ID: 46703ff2525dd3330d3e8b9549c10e6b@domain.tld
CSeq: 102 ACK
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Remote-Party-ID: "0152xxxxxxxx" <sip:0152xxxxxxxx@domain.tld>;privacy=off;screen=n o
Content-Length: 0


---
[Nov 17 16:03:28] VERBOSE[28177] logger.c: -- SIP/to-Lync-000001c9 is circuit-busy
[Nov 17 16:03:28] VERBOSE[28177] logger.c: == Everyone is busy/congested at this time (1:0/1/0)
[Nov 17 16:03:28] VERBOSE[28177] logger.c: -- Auto fallthrough, channel 'SIP/9646-000001c8' status is 'CONGESTION'
[Nov 17 16:03:28] VERBOSE[2976] logger.c: Really destroying SIP dialog '46703ff2525dd3330d3e8b9549c10e6b@domain.tld' Method: INVITE
[Nov 17 16:03:34] VERBOSE[2976] logger.c: Reliably Transmitting (no NAT) to 10.10.10.168:5060:


Der Skype4Business Trunk:
Identity : Global
PstnUsages : {Local}
Description :
ConcentratedTopology : True
EnableBypass : False //testweise
EnableMobileTrunkSupport : False
EnableReferSupport : True //testweise
EnableSessionTimer : True //Umstellung für on Hold
EnableSignalBoost : False
MaxEarlyDialogs : 20
RemovePlusFromUri : False
RTCPActiveCalls : False //Umstellung für on Hold
RTCPCallsOnHold : False //Umstellung für on Hold
SRTPMode : Optional
EnablePIDFLOSupport : False
EnableRTPLatching : True
EnableOnlineVoice : False
ForwardCallHistory : True
Enable3pccRefer : False
ForwardPAI : True
EnableFastFailoverTimer : False
EnableLocationRestriction : False
NetworkSiteID :

Trunk auf Asterisk:

[to-Lync]
type=peer
transport=udp
qualify=yes
port=5060
insecure=port,invite
host=10.10.10.168
fromdomain=domain.tld
dtmfmode=rfc2833
context=from-internal
canreinvite=no //temporär auf no
;disallow=all //temporär auskommentiert
;allow=alaw //temporär auskommentiert
;allow=ulaw //temporär auskommentiert

[pascal-schumacher]

Ich hoffe das ist alles nicht zu verwirrend :-D

anbei noch das letzte Log. Zuvor wird der Anruf noch auf einen CallPickupOrbit geparkt, dies hatte ich aber auch schon rausgenommen.

Skype FE Server LOG:

TL_INFO(TF_PROTOCOL) [0]24F4.275C::11/17/2015-20:39:47.016.00000607 (SIPStack,SIPAdminLog::ProtocolRecord::Flush:Proto colRecord.cpp(261))[1509902280] $$begin_record
Trace-Correlation-Id: 1509902280
Instance-Id: 5B6
Direction: outgoing
Peer: sip2lync.domain.tld:8000
Message-Type: request
Start-Line: BYE sip:sip2lync.domain.tld:8000;transport=Tls;ms-opaque=57a7ec9166711068;grid SIP/2.0
From: <sip:0152xxxxxxxx;phone-context=DefaultProfile@domain.tld;user=phone>;epid =E78FCC0235;tag=5fc103caa
To: <sip:+49xxxxxxxxx46@domain.tld;user=phone>;epid=CC 15C6C7C1;tag=1eff5aad24
Call-ID: 44bab361-e04a-4a23-872f-2037a4b2d05d
CSeq: 14 BYE
Contact: <sip:skype-fe.domain.tld@domain.tld;gruu;opaque=srvr:Mediatio nServer:6oF06RRyt1-VTp0Xi5rBFwAA;grid=369ce768e1d44fcdb78b2c8cf823c30 5>;isGateway
Via: SIP/2.0/TLS 10.10.10.15:49962;branch=z9hG4bK6D504958.6D270D009 F1D6953;branched=FALSE
Via: SIP/2.0/TLS 10.10.10.15:49978;branch=z9hG4bK62a336e3;ms-received-port=49978;ms-received-cid=4200
Max-Forwards: 69
CONTENT-LENGTH: 0
ms-diagnostics: 10006;source="skype-fe.domain.tld";reason="Proxy side Media negotiation failed";component="MediationServer"
ms-diagnostics-public: 10006;reason="Proxy side Media negotiation failed";component="MediationServer"
ms-edge-proxy-message-trust: ms-source-type=Pstn;ms-ep-fqdn=skype-fe.domain.tld;ms-source-verified-user=verified
P-Asserted-Identity: "0152xxxxxxxx"<sip:0152xxxxxxxx;phone-context=DefaultProfile@domain.tld;user=phone>
Supported: ms-dialog-route-set-update
Supported: gruu-10
User-Agent: RTCC/6.0.0.0 MediationServer
ms-endpoint-location-data: NetworkScope;ms-media-location-type=intranet
ms-application-via: ms-udc.cdr%3D85103c604e5918006fbfe5bc2c579871%3A1;ms-pool=skype-fe.domain.tld;ms-application=http%3A%2F%2Fwww.microsoft.com%2FLCS%2 FUdcAgent;ms-server=skype-fe.domain.tld
$$end_record

[Johann Deutinger]

reason="Proxy side Media negotiation failed";component="MediationServer"
Wie erwähnt: Deutet auf Codec oder Verschlüsselung hin. Dazu fehlt aber SDP in den Protokollausschnitten...

[Johann Deutinger]

Hallo,

ich kann das jetzt nachstellen, indem ich Media Bypass ausschalte. Im Skype4B Log ist nicht zu sehen, warum das nicht klappt. Mit Media Bypass passiert es nicht.

[pascal-schumacher]

Hallo Herr Deutinger,

das war der entscheidende Hinweis.
MediaBypass war zwar auf dem Trunk aktiviert, jedoch nicht global. Die Trunkeinstellung hatte somit keine Wirkung.

Die globale Einstellungen habe ich in „Get-CsNetworkConfiguration“ und dem Wert „MediaBypassSettings“ gefunden.

Danke.

Viel Grüße
Pascal Schumacher

[pascal-schumacher]

Herr Deutinger,

eine weitere Frage, evtl. haben Sie bereits eine Lösung parat.

Sollte man am DECT Telefon auch auf den CallPickup Orbit zugreifen können?
Wenn ich mit dem DECT Telefon ein Gespräch versuche heranzuholen:
- höre ich am DECT Telefon ein klingeln
- beim Anrufer stille
- beim ursprünglich Angerufenen sehe ich die Meldung, dass der Anruf übernommen wurde.

nach x Sekunden bricht der Ruf dann gleichzeitig auf beiden Seiten ab.


Danke im voraus

Pascal Schumacher
(Logs/OMG/Sip2Lync/S4B-SIP im Ticket)