Modul 96_SIP

plin · 07 März 2023, 09:56:35

Zitat von: Homalix99 am 06 März 2023, 20:23:19
Leider funktioniert die Audioübertragung immer noch nicht.
Hat vielleicht noch jemand eine Idee?

Hi Alex, ich denke ein neuer Mitschnitt wäre gut.

Homalix99 · 07 März 2023, 11:23:53

Hallo,

anbei ein neuer Mitschnitt.
1. Log:

Code Auswählen


2023.03.07 11:09:50.621 3: alarm_out: Alarm_Test: off
2023.03.07 11:16:29.122 4: SIP_call, msg will be repeat 2 times
2023.03.07 11:16:29.122 5: SIP_call, MD5: !Dies ist ein Testalarm von Fheem -> bc093fb936b9c340455bf49fa8e8f127.mp3
2023.03.07 11:16:29.122 5: SIP_call, mp3 File file not found in cache
2023.03.07 11:16:29.161 3: alarm_out: Alarm_Test Alarm: on, Alarmtext: !Dies ist ein Testalarm von Fheem, Rufnummer_1: 015120177388
2023.03.07 11:16:29.162 3: alarm_out: Alarm: Kann keine Rufverbindung zum Anschluss 015120771207 aufbauen, da der Alarmruf fuer Test Alarm deaktiviert ist
2023.03.07 11:16:29.162 3: alarm_out: Alarm: Kann keine Mail zur e-mail al.zeit@t-online.de senden, da Alarmmail fuer Test Alarm deaktiviert ist
2023.03.07 11:16:29.162 3: alarm_out: Alarm: Kann keine Mail zur e-mail zeitlerab@t-online.de senden, da Alarmmail fuer Test Alarm deaktiviert ist
2023.03.07 11:16:29.472 4: SIP_call, wait_for_t2s file : cache/62d1a2142d218979d742cd67dd9c059e.mp3
2023.03.07 11:16:29.472 4: SIP_call, new T2S file cache/62d1a2142d218979d742cd67dd9c059e.mp3
2023.03.07 11:16:29.473 5: SIP_call, not converted - using cache/62d1a2142d218979d742cd67dd9c059e.alaw from cache
2023.03.07 11:16:29.474 4: SIP_call, msg will be repeat 2 times
2023.03.07 11:16:29.474 4: SIP_call, audio file cache/62d1a2142d218979d742cd67dd9c059e.alaw found
2023.03.07 11:16:29.474 4: SIP_call, SIP_call|015120177388|40|cache/62d1a2142d218979d742cd67dd9c059e.alaw|2
2023.03.07 11:16:29.491 4: SIP_call, call -> SIP_call|015120177388|40|cache/62d1a2142d218979d742cd67dd9c059e.alaw|2|0
2023.03.07 11:16:29.493 5: SIP_call, call has pid 1561182
2023.03.07 11:16:29.537 4: SIP_call[1561182], my parent is 6392
2023.03.07 11:16:29.538 4: SIP_call[1561182], trying to use port 5070
2023.03.07 11:16:29.601 4: SIP_call[1561182], register new expire : 2023-03-07 11:21:29
2023.03.07 11:16:29.605 5: SIP_call, readingS:state Val:calling
2023.03.07 11:16:29.626 4: SIP_call[1561182], CallStart with 3 files - first file : cache/62d1a2142d218979d742cd67dd9c059e.alaw - PCMA/8000 , repeat 2
2023.03.07 11:16:29.632 4: SIP_call[1561182], calling : 015120177388
2023.03.07 11:16:29.633 5: SIP_call, readingS:call_state Val:calling 015120177388
2023.03.07 11:16:33.809 4: SIP_call[1561182], cb_final - status : OK
2023.03.07 11:16:33.809 4: SIP_call[1561182], call established
2023.03.07 11:16:33.810 5: SIP_call, readingS:call_state Val:established
2023.03.07 11:16:37.046 5: SIP_call[1561182], 0. Ende des ersten Loops
2023.03.07 11:16:37.046 5: SIP_call[1561182], 1. rtp_done : Net::SIP::Simple::Call=HASH(0x55a0a7a1f8)
2023.03.07 11:16:37.046 5: SIP_call[1561182], 2. fi : 0
2023.03.07 11:16:37.046 5: SIP_call[1561182], 4. timeout : 0
2023.03.07 11:16:37.047 5: SIP_call[1561182], 6. call_established : 1
2023.03.07 11:16:37.048 4: SIP_call[1561182], next file : cache/62d1a2142d218979d742cd67dd9c059e.alaw
2023.03.07 11:16:37.198 4: SIP_call[1561182], cb_final - status : OK
2023.03.07 11:16:40.436 4: SIP_call[1561182], loop rtp_done : Net::SIP::Simple::Call=HASH(0x55a0a7a1f8)
2023.03.07 11:16:40.436 4: SIP_call[1561182], next file : cache/62d1a2142d218979d742cd67dd9c059e.alaw
2023.03.07 11:16:40.585 4: SIP_call[1561182], cb_final - status : OK
2023.03.07 11:16:43.822 4: SIP_call[1561182], loop rtp_done : Net::SIP::Simple::Call=HASH(0x55a0a7a1f8)
2023.03.07 11:16:43.822 5: SIP_call[1561182], call->bye
2023.03.07 11:16:43.837 5: SIP_call[1561182], RTP done : Net::SIP::Simple::Call=HASH(0x55a0a7a1f8)
2023.03.07 11:16:43.837 5: SIP_call[1561182], Timeout  : 0
2023.03.07 11:16:43.837 5: SIP_call[1561182], while    : 2
2023.03.07 11:16:43.837 5: SIP_call[1561182], Status   : OK
2023.03.07 11:16:43.837 4: SIP_call[1561182], Calltime : 10
2023.03.07 11:16:43.843 4: SIP_call, CALLDone -> SIP_call|1|ok|10
2023.03.07 11:16:43.851 5: SIP_call, fifo is empty
2023.03.07 11:16:43.851 5: SIP_call, no elbc
2023.03.07 11:16:49.169 3: alarm_out: Alarm_Test: off

2. Wireshark, ab Paket 29: Im Anhang

Es laufen RTP Pakete im angegebenen Portbereich, aber es ist nichts zu hören.

VG

Alex

plin · 07 März 2023, 15:59:53

Mmmh, merkwürdig. Laut IP Trace gibt es einen Austausch von RTP Daten auf Port 2008. Sieht also prinzipiell gut aus.

Hast Du mal versucht eoinen internen Teilnehmer anzurufen?
Wie lange dauert der Anruf bis der SIP-Client auflegt?
Hast Du Dir mal das Audiofile cache/62d1a2142d218979d742cd67dd9c059e.mp3 auf Deinen PC kopiert und angehört (Stichwort Lautstärke)?

Homalix99 · 07 März 2023, 22:14:40

Guten Abend,

also bei internem Teilnehmer (es kommt auch kein Audio) wird die Verbindung nach 4 Sek. nach Abheben beendet.
Ein Trace (Anhang) läuft von Sek. 3.40 (SIP Request: Invite) bis Sek. 8.95 (SIP Request: Bye)
Sieht m. E. gut aus.
Log dazu:

Code Auswählen


2023.03.07 22:00:28.790 4: SIP_call, audio file ./cache/62d1a2142d218979d742cd67dd9c059e.mp3 found
2023.03.07 22:00:28.790 5: SIP_call, not converted - using ./cache/62d1a2142d218979d742cd67dd9c059e.alaw from cache
2023.03.07 22:00:28.790 4: SIP_call, SIP_call|**52|30|./cache/62d1a2142d218979d742cd67dd9c059e.alaw|0
2023.03.07 22:00:28.818 4: SIP_call, call -> SIP_call|**52|30|./cache/62d1a2142d218979d742cd67dd9c059e.alaw|0|0
2023.03.07 22:00:28.820 5: SIP_call, call has pid 2294364
2023.03.07 22:00:28.857 4: SIP_call[2294364], my parent is 6392
2023.03.07 22:00:28.858 4: SIP_call[2294364], trying to use port 5070
2023.03.07 22:00:28.908 4: SIP_call[2294364], register new expire : 2023-03-07 22:05:28
2023.03.07 22:00:28.913 5: SIP_call, readingS:state Val:calling
2023.03.07 22:00:28.935 4: SIP_call[2294364], CallStart with 1 files - first file : ./cache/62d1a2142d218979d742cd67dd9c059e.alaw - PCMA/8000 , repeat 0
2023.03.07 22:00:28.941 4: SIP_call[2294364], calling : **52
2023.03.07 22:00:28.942 5: SIP_call, readingS:call_state Val:calling **52
2023.03.07 22:00:31.258 4: SIP_call[2294364], cb_final - status : OK
2023.03.07 22:00:31.258 4: SIP_call[2294364], call established
2023.03.07 22:00:31.260 5: SIP_call, readingS:call_state Val:established
2023.03.07 22:00:34.495 5: SIP_call[2294364], 0. Ende des ersten Loops
2023.03.07 22:00:34.495 5: SIP_call[2294364], 1. rtp_done : Net::SIP::Simple::Call=HASH(0x55a0a33970)
2023.03.07 22:00:34.495 5: SIP_call[2294364], 2. fi : 0
2023.03.07 22:00:34.495 5: SIP_call[2294364], 4. timeout : 0
2023.03.07 22:00:34.495 5: SIP_call[2294364], 6. call_established : 1
2023.03.07 22:00:34.495 5: SIP_call[2294364], call->bye
2023.03.07 22:00:34.511 5: SIP_call[2294364], RTP done : Net::SIP::Simple::Call=HASH(0x55a0a33970)
2023.03.07 22:00:34.511 5: SIP_call[2294364], Timeout  : 0
2023.03.07 22:00:34.511 5: SIP_call[2294364], while    : 0
2023.03.07 22:00:34.511 5: SIP_call[2294364], Status   : OK
2023.03.07 22:00:34.511 4: SIP_call[2294364], Calltime : 3
2023.03.07 22:00:34.520 4: SIP_call, CALLDone -> SIP_call|1|ok|3
2023.03.07 22:00:34.529 5: SIP_call, fifo is empty
2023.03.07 22:00:34.529 5: SIP_call, no elbc

Extern dauert es knappe 10 Sek.
Das Audio File hat am PC normale Lautstärke genauso laut wie andere am PC vorhandene mp3-Files.
Ich bin echt ratlos.

VG

Alex

plin · 08 März 2023, 13:21:38

Tja, merkwürdig.

Ich habe gerade ganz frisch einen Docker-Container mit fhem angelegt, SIP und TexttoSpeech eingerichtet, die Ports angepasst und bei mir funktioniert die Sprachausgabe, sowohl intern als auch extern.

Da muss mein Hinterstübchen jetzt mal etwas grübeln ...

Kannst Du eigentlich DTMF-Töne übermitteln?

Homalix99 · 08 März 2023, 18:43:45

Hallo,

Du meinst der SIP Client soll der Angerufene sein.
Nein, Verhalten so als ob der Client gar nicht da wäre, auch am Ethernet-Trace nichts sichtbar.
Ich habe zu Testzwecken den SIP Client mit Attr. disable deaktiviert, auf einem Laptop (IP: 192.168.3.30) einen SIP Client installiert und mit den Zugangsdaten erfolgreich interne und externe calls (incoming + outgoing) aufbauen können. Mein Verdacht war vor dem Test nämlich die FB, aber mit dem MicroSIP Client am Laptop funktioniert alles perfekt.
Komisch, dass der Eth.-Trace (outgoing von fhem) eigentlich gut aussieht. Leider kann man auf der FB keinen Paketmitschnitt auf der WAN-If zum Netzprovider anfertigen.

Gruß

Alex

plin · 08 März 2023, 19:50:33

Zitat von: Homalix99 am 08 März 2023, 18:43:45
Du meinst der SIP Client soll der Angerufene sein.

Hallo Alex, nein, ich meinte wirklich vom SIP Client zum Angerufenen übermitteln. Statt !Text gibst Du z.B. -#47 an. Das "-" steht für DTMF-Übermittlung. Da Du rfc2833 als Format gewählt hast wird es nur knacksen, aber dann wissen wir, dass wenigstens etwas rüber geht.

VG Peter

Homalix99 · 08 März 2023, 20:09:17

Hallo Peter,

habe ich gerade probiert, leider Fehlanzeige.
In den Traces sieht man zwar RTP Pakete, die sind aber alle von der FB zu fhem. Vom clientz kommt nichts.

Gruß

Alex

plin · 08 März 2023, 20:56:33

Zitat von: Homalix99 am 08 März 2023, 20:09:17
In den Traces sieht man zwar RTP Pakete, die sind aber alle von der FB zu fhem. Vom clientz kommt nichts.

Dem muss ich widersprechen. Ich habe den zweiten RTP Thread (192.168.3.20->192.168.3.1) rausgefiltert, in Wireshark auf den RTP-Stream gefiltert und exportiert, in Audacity importiert und höre beim Abspielen ein sehr krächzendes "Dies ist ein Testalarm von Fheem".

Homalix99 · 08 März 2023, 22:15:01

Okay,

das klingt ja schon mal nicht nach einem fhem Problem.
Vielen Dank für die aufwendige Analyse. Aber was kann es sonst sein?

plin · 09 März 2023, 12:53:48

ok, dann probier doch mal folgendes: Richte einen weiteren FritzBox-User für Deinen MicroSIP Client am Laptop ein. Sende die Alarm-Nachrticht an diesen Client und schneide das ganze mit. Dann sehen wir, ob die RTP-Pakete in brauchbarer Form an den Client weitergeleitet werden.

Homalix99 · 09 März 2023, 16:35:20

Hallo Peter,
also:
Master FB: 192.168.3.1
Laptop, IP: 192.168.3.30 (WLAN, an Slave FB als Mesh)
Docker-Host: 192.168.3.20 (LAN 3, eth2, direkt an der Master FB)
Fhem-Container: 172.19.0.5
Fhem-IP-Telefonnummer: 620

Fhem: Aufbau Testanruf (zur Nummer: **621) zum MicroSIP Client
Zwei Tracedateien vom einzigen Anruf zum MicroSIP Client im Anhang:
1. iad-if-eth2_09.03.23_1611.eth (Interface eth2 der Master FB)
2. iad-if-wlan_09.03.23_1611.eth (Interface WLAN der Slave FB)

Hinweis: Vom Laptop Richtung Fhem werden in den RTP Paketen die Geräusche vom Laptop Micro übertragen.

plin · 09 März 2023, 18:17:02

Tja, auf dem Weg 192.168.3.1->192.168.3.30 sehe ich auf den ersten Blick als Payload quasi nur alles x'd5, obwohl laut Wireshark in beiden Fällen PCMA gesprochen wird.

Was veranlasst die Fritzbox dazu den Audiostream zu nullen?

plin · 09 März 2023, 20:04:08

Ich habe gerade noch mal meine FHEM-Instanz im Docker-Container gestartet und eine Session mitgeschnitten. Bei mir läuft die RTP-Session zwischen der internen IP-Adresse des Containers und der 192.168.3.1. Bei Dir ist die Sender-IP die des Docker-Hosts (192.168.3.20).

Keine Ahnung, ob's einen Unterschied macht.

Homalix99 · 09 März 2023, 20:17:32

Guten Abend Peter,

danke für den Hinweis. Ich habe mir schon gedacht, dass das ein Problem sein kann. Die RTP Pakete zur Fritzbox haben die IP des Docker-Host und zu fhem hin die IP des Fhem Containers.
Aber wo stellt man das richtig?
Könnte das was bringen, den SIP-Client in fhem zu löschen und neu zu definieren?