Modul 96_SIP

Flachzange · 18 August 2025, 13:06:15

Zitat von: juemuc am 17 August 2025, 23:04:25Kannst Du eventuell eine VM erstellen und dort FHEM ohne Docker installieren?

Thereotisch ginge das, aber das ist ja auch wieder ein halber Tag Arbeit, zumal die Wahrscheinlichkeit, dass es da funktioniert ja extrem hoch ist.

Nach einem erneuten Tag Debugging bin ich nur bedingt schlauer. Es scheint als würden igendwie die SIP-Sessions nicht sauber zusammengehalten werden. Entweder für den SIP-Client oder für den Registrar/Proxy sieht es dann so aus als würde da eine neue Session laufen.

Ich habe nun den Docker-Container im Host-Mode gestartet und siehe da: Es funktioniert alles. Ursächlich ist also irgendwie das NATting vom Docker. Ist das normal oder ist das jetzt noch irgendeine konfigurierte Eigenheit meines Systems? Grundsätzlich kann ich das jetzt im Host-Mode lassen, aber ich würde es halt gerne verstehen. Zumindest laut Wiki geht man ja nicht vom Host-Mode aus. Es muss also auch irgendwie funktionieren....

Danke schon mal!

juemuc · 18 August 2025, 14:22:05

Das ist genau der Grund, warum ich kein Docker mehr nutze. Ich habe manche Dinge einfach nicht verstanden. Mit einer VM habe ich (für mich) alles selbst in der Hand.

laufhem · 28 Oktober 2025, 18:30:06

Hallo ich kann inzwischen meine Türsprechanlage anrufen, um dort per DTMF die Beleuchtung anzuschalten.

Code Auswählen

set FritzSIP call **1 5 ---#8 Leider erhalte ich bei einem darauffolgenden Anruf folgende Fehlermeldung " there is already a call activ for target **1 ", (egal wie lange später) bis ich mit

Code Auswählen

set FritzSIP reset das Ganze zurück setze.
An der Türsprechanlage hört sich das Ganze so an, als ob ordentlich aufgelegt wird.
Ist das so gewollt? Kriege ich das außer Reset anders in den Griff? Habe ich irgendwelche Attribute übersehen?

Attribute FritzSIP

Code Auswählen

T2S_Device
	
RaspberryText2Speech
	
deleteattr
T2S_Timeout
	
10
	
deleteattr
audio_converter
	
ffmpeg
	
deleteattr
history_file
	
./log/FritzSIP.sip
	
deleteattr
history_size
	
0
	
deleteattr
room
	
Unsorted
	
deleteattr
sip_call_audio_delay
	
2
	
deleteattr
sip_dtmf_loop
	
once
	
deleteattr
sip_dtmf_send
	
audio
	
deleteattr
sip_dtmf_size
	
2
	
deleteattr
sip_elbc
	
yes
	
deleteattr
sip_from
	
sip:telefon@fritz.box
	
deleteattr
sip_ip
	
192.168.178.111
	
deleteattr
sip_listen
	
none
	
deleteattr
sip_registrar
	
192.168.178.1
	
deleteattr
sip_ringtime
	
3
	
deleteattr
sip_user
	
telefon
	
deleteattr

Wzut · 29 Oktober 2025, 10:15:29

Die Meldung kommt wenn es intern noch $hash{CPID} gibt, wird i.d.R. gelöscht wenn :
a. das Ende des Anrufs erkannt wurde , oder
b. wenn das Reset Kommando geschickt wurde

Um deinen Fehler zu verstehen zu können :
a. das Modul auf mindestens verbose 4 stellen (besser 5)
b. gewünschter Ruf absetzen
c. Reset Kommando absetzen

d. Log Datei anschauen und alles von a bis c kopieren und in Code Tags gepackt hier posten.

laufhem · 30 Oktober 2025, 12:54:14

Die "there is a call active" schaffen es offenbar nicht ins logfile:
1) anruf niO
2) reset
3) anruf io
4) anruf nio

verbose 5:

Code Auswählen

2025.10.30 12:47:51 4: FritzSIP, CALL Kill PID : 6041
2025.10.30 12:47:51 4: FritzSIP, Reset Call done.
2025.10.30 12:47:57 4: FritzSIP, message DTMF = ---#8
2025.10.30 12:47:57 4: FritzSIP, FritzSIP|**1|5|---#8|0
2025.10.30 12:47:57 4: FritzSIP, call -> FritzSIP|**1|5|---#8|0|0
2025.10.30 12:47:57 5: FritzSIP, call has pid 6098
2025.10.30 12:47:57 4: FritzSIP[6098], my parent is 890
2025.10.30 12:47:57 4: FritzSIP[6098], using Leg.pm to find a free port
2025.10.30 12:47:57 4: FritzSIP[6098], register new expire : 2025-10-30 12:52:57
2025.10.30 12:47:57 4: FritzSIP[6098], CallStart DTMF : --#8
2025.10.30 12:47:57 4: FritzSIP[6098], calling : **1
2025.10.30 12:47:57 4: FritzSIP[6098], cb_final - Status : OK
2025.10.30 12:47:57 4: FritzSIP[6098], call established
2025.10.30 12:47:59 5: FritzSIP[6098], 0. Ende des ersten Loops
2025.10.30 12:47:59 5: FritzSIP[6098], 1. rtp_done : OK
2025.10.30 12:47:59 5: FritzSIP[6098], 2. fi : 0
2025.10.30 12:47:59 5: FritzSIP[6098], 4. timeout : 0
2025.10.30 12:47:59 5: FritzSIP[6098], 6. call_established : 1
2025.10.30 12:47:59 5: FritzSIP[6098], call->bye
2025.10.30 12:47:59 5: FritzSIP[6098], RTP done : OK
2025.10.30 12:47:59 5: FritzSIP[6098], Timeout  : 0
2025.10.30 12:47:59 5: FritzSIP[6098], while    : -1
2025.10.30 12:47:59 4: FritzSIP[6098], Calltime : 2

Wzut · 30 Oktober 2025, 17:17:43

du hast das Log zu früh abgeschnitten. Es reicht nur bis zum Ende des Kind Prozess 6098 -> erfolgreiches Ende des ersten Calls - alles mit Zeitstempel 2025.10.30 12:47:57 bzw. 2025.10.30 12:47:59
Danach müssen aber wieder Einträge des Eltern Prozes kommen , so in der Art von FritzSIP, message DTMF = ---#8 und FritzSIP, FritzSIP|**1|5|---#8|0 usw. bzw. dein Reset Kommando und da ist intressant ob das den 6068 killt, der ja eigentlich zu Ende sein müsste.

laufhem · 02 November 2025, 15:50:13

Hallo, wie bereits geschrieben, kommen die nicht erfolgreichen calls nicht ins Logfile.
Ich habe hier mal einen nueen Log inklusiver aller Warnings (die ich vorher für nicht relevant hielt) angehängt. Zwischen den Resets habe ich einige Calls, die mit "there is a call active" nicht durchgeführt werden, versucht.

Code Auswählen

2025.11.02 15:42:16 1: Logfile gelöscht
2025.11.02 15:42:20 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6289955) line 6, <GEN98> line 34928.
2025.11.02 15:42:20 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6289957) line 6, <GEN98> line 34928.
2025.11.02 15:42:38 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290230) line 6.
2025.11.02 15:42:38 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290232) line 6.
2025.11.02 15:43:00 1: [FritzBox | 0000 | 113.07.60 | Readout_Aborted.8623] - ERROR:Error: Timeout when reading Fritz!Box data. 144 | BlockingStart
2025.11.02 15:43:05 1: Connection refused from 192.168.178.111:42898
2025.11.02 15:43:08 4: FritzSIP, CALL Kill PID : 24022
2025.11.02 15:43:08 4: FritzSIP, Reset Call done
2025.11.02 15:43:17 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290734) line 6.
2025.11.02 15:43:17 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290736) line 6.
2025.11.02 15:43:19 4: FritzSIP, message DTMF = ---#8
2025.11.02 15:43:19 4: FritzSIP, FritzSIP|**1|5|---#8|0
2025.11.02 15:43:19 4: FritzSIP, call -> FritzSIP|**1|5|---#8|0|0
2025.11.02 15:43:19 5: FritzSIP, call has pid 24071
2025.11.02 15:43:19 4: FritzSIP[24071], my parent is 890
2025.11.02 15:43:19 4: FritzSIP[24071], using Leg.pm to find a free port
2025.11.02 15:43:19 4: FritzSIP[24071], register new expire : 2025-11-02 15:48:19
2025.11.02 15:43:19 1: Connection refused from 192.168.178.111:34660
2025.11.02 15:43:19 4: FritzSIP[24071], CallStart DTMF : --#8
2025.11.02 15:43:19 4: FritzSIP[24071], calling : **1
2025.11.02 15:43:19 4: FritzSIP[24071], cb_final - Status : OK
2025.11.02 15:43:19 4: FritzSIP[24071], call established
2025.11.02 15:43:22 5: FritzSIP[24071], 0. Ende des ersten Loops
2025.11.02 15:43:22 5: FritzSIP[24071], 1. rtp_done : OK
2025.11.02 15:43:22 5: FritzSIP[24071], 2. fi : 0
2025.11.02 15:43:22 5: FritzSIP[24071], 4. timeout : 0
2025.11.02 15:43:22 5: FritzSIP[24071], 6. call_established : 1
2025.11.02 15:43:22 1: PERL WARNING: Use of uninitialized value $anz in numeric gt (>) at ./FHEM/96_SIP.pm line 563.
2025.11.02 15:43:22 5: FritzSIP[24071], call->bye
2025.11.02 15:43:22 5: FritzSIP[24071], RTP done : OK
2025.11.02 15:43:22 5: FritzSIP[24071], Timeout  : 0
2025.11.02 15:43:22 5: FritzSIP[24071], while    : -1
2025.11.02 15:43:22 4: FritzSIP[24071], Calltime : 2
2025.11.02 15:43:23 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290839) line 6, <GEN98> line 34934.
2025.11.02 15:43:24 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290841) line 6, <GEN98> line 34934.
2025.11.02 15:43:33 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290925) line 6.
2025.11.02 15:43:33 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6290927) line 6.
2025.11.02 15:43:49 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6291085) line 6.
2025.11.02 15:43:50 1: PERL WARNING: Use of uninitialized value in sprintf at (eval 6291087) line 6.
2025.11.02 15:44:02 4: FritzSIP, CALL Kill PID : 24071
2025.11.02 15:44:02 1: [FritzBox | 0000 | 113.07.60 | Readout_Aborted.8623] - ERROR:Error: Timeout when reading Fritz!Box data. 144 | BlockingStart
2025.11.02 15:44:02 4: FritzSIP, Reset Call done
2025.11.02 15:44:10 1: Connection refused from 192.168.178.111:58020
2025.11.02 15:44:12 4: FritzSIP, message DTMF = ---#8
2025.11.02 15:44:12 4: FritzSIP, FritzSIP|**1|5|---#8|0
2025.11.02 15:44:12 4: FritzSIP, call -> FritzSIP|**1|5|---#8|0|0
2025.11.02 15:44:12 5: FritzSIP, call has pid 24095
2025.11.02 15:44:12 4: FritzSIP[24095], my parent is 890
2025.11.02 15:44:12 4: FritzSIP[24095], using Leg.pm to find a free port
2025.11.02 15:44:12 4: FritzSIP[24095], register new expire : 2025-11-02 15:49:12
2025.11.02 15:44:12 1: Connection refused from 192.168.178.111:58030
2025.11.02 15:44:12 4: FritzSIP[24095], CallStart DTMF : --#8
2025.11.02 15:44:12 4: FritzSIP[24095], calling : **1
2025.11.02 15:44:13 4: FritzSIP[24095], cb_final - Status : OK
2025.11.02 15:44:13 4: FritzSIP[24095], call established
2025.11.02 15:44:15 5: FritzSIP[24095], 0. Ende des ersten Loops
2025.11.02 15:44:15 5: FritzSIP[24095], 1. rtp_done : OK
2025.11.02 15:44:15 5: FritzSIP[24095], 2. fi : 0
2025.11.02 15:44:15 5: FritzSIP[24095], 4. timeout : 0
2025.11.02 15:44:15 5: FritzSIP[24095], 6. call_established : 1
2025.11.02 15:44:15 1: PERL WARNING: Use of uninitialized value $anz in numeric gt (>) at ./FHEM/96_SIP.pm line 563.
2025.11.02 15:44:15 5: FritzSIP[24095], call->bye
2025.11.02 15:44:15 5: FritzSIP[24095], RTP done : OK
2025.11.02 15:44:15 5: FritzSIP[24095], Timeout  : 0
2025.11.02 15:44:15 5: FritzSIP[24095], while    : -1
2025.11.02 15:44:15 4: FritzSIP[24095], Calltime : 2

Ich sehe gerade, dass meine SIP Version sehr als zu sein scheint. Ist das die neuste? Wie kann ich die aktualisieren? Eigentlich habe ich ein update durchgeführt:
96_SIP.pm 21469 2020-03-21 19:30:58Z Wzut

Wzut · 03 November 2025, 09:42:04

ich fang mal hinten an :
1. ja die Version ist von März 2020, aber sie ist aktuell weil es seit damals nix zu schrauben gab (das hat sich nun geändert ....)

2. dein Log zeigt das das Modul im laufenden Call bei Zeile 563 aussteigt, weil $anz keinen Wert hat.
Das ist in deinem Fall auch ok, da $anz sich nur auf die Anzahl der abzuspielenden Audiofiles bezieht, die in deinem DTMF Fall ja null ist. Und genau damit hätte ich $anz damals zur Sicherheit vorbesetzen müssen

Traust du dir zu im Modul die Zeile 444 von my $anz; auf my $anz = 0; zu ändern ?
Danach muss das Modul entweder neu geladen werden mit relaod 96_SIP oder FHEM neu gestartet werden.

Ich gehe jetzt mal blind davon aus wenn die Zeile 563 keinen Perl Fehler mehr produziert läuft das Modul sauber bis zum CAll Ende durch und ist dann auch bereit für den nächsten DTMF Anruf.

Aber ganz losgelöst davon : schau die mal dein Log da gibt es noch mehr zu tun ...