Problem

For no apparent reason my Snom phone ends the current call after about 15 minutes!

Solution

To Understand the issue let's take a look at the following SIP communication between Snom Phone and PBX:

  • The Snom Phone with number 123456 sends an Invite to 7890;
  • The call comes in and is established between 123456 and 7890, so far so good.

Note: For better overview we have removed some SIP headers from the communication and highlighted the most important ones in this error analysis.


Sent to Udp:217.x.xx.xx:5060 from Udp:192.168.2.124:50422 at Jan 30 12:57:23.743 (1419 bytes):
INVITE sip:7890@testpbx.de;user=phone SIP/2.0
From: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
To: <sip:7890@testpbx.de;user=phone>
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 2 INVITE
User-Agent: snomD765/10.1.49.11
Contact: <sip:123456@192.168.2.124:50422>;reg-id=1
X-Serialnumber: 000413xxxxxx

Supported: timer, 100rel, replaces, from-change
Accept: application/sdp
Session-Expires: 3600
Min-SE: 90
------------------------

Received from Udp:217.x.xx.xx:5060 on Udp:192.168.2.124:50422 at Jan 30 12:57:28.017 (1339 bytes):

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.124:50422;received=84.141.56.123;rport=50422;branch=z9hG4bK-qa5k4ddrhvok
To: <sip:7890@testpbx.de;user=phone>;tag=h7g4Esbg_p65542t1580385444m252622c553395349s1_688083261-1877431650
From: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 2 INVITE
Contact: <sip:partner@217.x.xx.xx;transport=udp>
Session-Expires: 1800;refresher=uas
Supported: timer


In this case it is very important what is negotiated between the Snom phone and the other party (PBX server).

  • Let us concentrate on the parameters that are important for the duration of the session ( call ).
  • The Snom phone suggests a session duration of 3600 seconds; see: Session Expires: 3600
  • In the 200 OK the PBX changes this value to Session Expires: 1800 (=30 minutes).
  • Additionally it defines who renews the session: refresher=uas. This means that the (uas: user agent server) takes over the session refresh. In this case the PBX.

What does the RFC say: The refresher has to send an update after the half of the time. In our case it is exactly 15 minutes.

  • If the client (in this case the Snom phone) does not receive any message from the server after half the time to keep the session running, the client terminates the session.
  • What the Snom phone also does with the sending of the BYE.
  • This procedure is described here: https://tools.ietf.org/html/rfc4028


Here you can see the BYE being sent by the phone after 15 minutes and 13 seconds:

Sent to Udp:217.x.xx.xx:5060 from Udp:192.168.2.124:50422 at Jan 30 13:12:41.714 (699 bytes):

BYE sip:partner@217.x.xx.xx;transport=udp SIP/2.0
From: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
To: <sip:7890@testpbx.de;user=phone>;tag=h7g4Esbg_p65542t1580385444m252622c553395349s1_688083261-1877431650
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 4 BYE
User-Agent: snomD765/10.1.49.11
Contact: <sip:123456@192.168.2.124:50422>;reg-id=1
Content-Length: 0


In the SIP Trace we also see that right after the Snom phone sends the BYE, the PBX sends an update for the session, but this comes late(13:12:43.583).

Received from Udp:217.x.xx.xx:5060 on Udp:192.168.2.124:50422 at Jan 30 13:12:43.583 (716 bytes):

UPDATE sip:123456@192.168.2.124:50422 SIP/2.0
To: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
From: <sip:7890@testpbx.de;user=phone>;tag=h7g4Esbg_p65542t1580385444m252622c553395349s1_688083261-1877431650
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 3 UPDATE
Contact: <sip:partner@217.x.xx.xx;transport=udp>
Min-Se: 900
Session-Expires: 1800;refresher=uac
Supported: timer
Content-Length: 0


Conclusion:

  • This proves that the problem is on the server side, because it does not update the session in time.


Problem

Ohne ersichtlichen Grund beendet mein Snom-Telefon das laufende Gespräch nach etwa 15 Minuten!

Lösung

Um das Problem zu verstehen, schauen wir uns die folgende SIP-Kommunikation zwischen Snom Telefon und PBX an:

  • Das Snom Telefon mit der Nummer 123456 sendet einen Invite an die 7890.
  • Der Anruf kommt an und wird zwischen 123456 und 7890 aufgebaut, so weit so gut.

Hinweis: Zur besseren Übersicht haben wir einige SIP-Header aus der Kommunikation entfernt und die wichtigsten in dieser Fehleranalyse hervorgehoben.


Sent to Udp:217.x.xx.xx:5060 from Udp:192.168.2.124:50422 at Jan 30 12:57:23.743 (1419 bytes):
INVITE sip:7890@testpbx.de;user=phone SIP/2.0
From: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
To: <sip:7890@testpbx.de;user=phone>
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 2 INVITE
User-Agent: snomD765/10.1.49.11
Contact: <sip:123456@192.168.2.124:50422>;reg-id=1
X-Serialnumber: 000413xxxxxx

Supported: timer, 100rel, replaces, from-change
Accept: application/sdp
Session-Expires: 3600
Min-SE: 90
------------------------

Received from Udp:217.x.xx.xx:5060 on Udp:192.168.2.124:50422 at Jan 30 12:57:28.017 (1339 bytes):

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.124:50422;received=84.141.56.123;rport=50422;branch=z9hG4bK-qa5k4ddrhvok
To: <sip:7890@testpbx.de;user=phone>;tag=h7g4Esbg_p65542t1580385444m252622c553395349s1_688083261-1877431650
From: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 2 INVITE
Contact: <sip:partner@217.x.xx.xx;transport=udp>
Session-Expires: 1800;refresher=uas
Supported: timer


In diesem Fall ist es sehr wichtig, was zwischen dem Snom-Telefon und der anderen Partei (PBX-Server) ausgehandelt wird.

  • Konzentrieren wir uns auf die Parameter, die für die Dauer der Sitzung ( Anruf ) wichtig sind.
  • Das Snom-Telefon schlägt eine Sitzungsdauer von 3600 Sekunden vor; siehe: Session Expires: 3600
  • Im 200 OK ändert die PBX diesen Wert auf Session Expires: 1800 (=30 Minuten).
  • Zusätzlich definiert sie, wer die Sitzung erneuert: refresher=uas. Das bedeutet, dass der (uas: user agent server) die Sitzungserneuerung übernimmt. In diesem Fall die PBX.


Was besagt der RFC: Der Refresher muss nach der Hälfte der Zeit ein Update senden. In unserem Fall sind das genau 15 Minuten.

  • Wenn der Client (in diesem Fall das Snom-Telefon) nach der Hälfte der Zeit keine Nachricht vom Server erhält, um die Sitzung aufrecht zu erhalten, beendet der Client die Sitzung.
  • Was das Snom-Telefon auch mit dem Senden des BYEs macht.
  •  Dieser Vorgang ist hier beschrieben: https://tools.ietf.org/html/rfc4028


Hier sehen Sie, wie das BYE vom Telefon nach 15 Minuten und 13 Sekunden gesendet wird:

Sent to Udp:217.x.xx.xx:5060 from Udp:192.168.2.124:50422 at Jan 30 13:12:41.714 (699 bytes):

BYE sip:partner@217.x.xx.xx;transport=udp SIP/2.0
From: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
To: <sip:7890@testpbx.de;user=phone>;tag=h7g4Esbg_p65542t1580385444m252622c553395349s1_688083261-1877431650
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 4 BYE
User-Agent: snomD765/10.1.49.11
Contact: <sip:123456@192.168.2.124:50422>;reg-id=1
Content-Length: 0


Im SIP-Trace sehen wir auch, dass direkt nachdem das Snom-Telefon das BYE sendet, die Telefonanlage ein Update für die Sitzung sendet, aber das kommt zu spät(13:12:43.583).

Received from Udp:217.x.xx.xx:5060 on Udp:192.168.2.124:50422 at Jan 30 13:12:43.583 (716 bytes):

UPDATE sip:123456@192.168.2.124:50422 SIP/2.0
To: "Test" <sip:123456@testpbx.de>;tag=dzadbqiwhi
From: <sip:7890@testpbx.de;user=phone>;tag=h7g4Esbg_p65542t1580385444m252622c553395349s1_688083261-1877431650
Call-ID: 313538303338353434303531333530-mxeagr7ulapk
CSeq: 3 UPDATE
Contact: <sip:partner@217.x.xx.xx;transport=udp>
Min-Se: 900
Session-Expires: 1800;refresher=uac
Supported: timer
Content-Length: 0


Schlussfolgerung:

  • Dies beweist, dass das Problem auf der Serverseite liegt, da er die Sitzung nicht rechtzeitig aktualisiert.