Problem mit MQTT (Sonoff Pow R2)

Alles was mit der Solaranzeige technisch zu tun hat. Einfache Konfiguration mit einem Gerät

Moderator: Ulrich

Antworten
Kilowatt
Beiträge: 9
Registriert: Mo 6. Jul 2020, 22:44
Danksagung erhalten: 1 Mal

Problem mit MQTT (Sonoff Pow R2)

Beitrag von Kilowatt »

Meine Solaranzeige hat immer wieder mal das Problem, dass keine Daten mehr vom Sonoff Pow R2 angenommen werden.
Der Fehler passiert immer nach Mitternacht, so zwischen 1 und 3 Uhr. Manchmal läuft es einige Tage ohne Probleme. Ist der Fehler da, so hilft nur ein Neustart des Raspi.
sudo systemctl restart mosquitto oder auch ein Neustart des Sonoff Pow R2 bringen nichts.

In der Tasmota-Konsole (Tasmota 9.3.1) erscheint beim Fehler:
10:42:22.987 MQT: Verbindungsversuch...
10:42:23.199 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.178.53:1883, rc -2. Wiederversuch in 120 s

Hier die aktuellen Softwarestände:

pi@solaranzeige:~ $ uname -a
Linux solaranzeige 5.10.25-v7+ #1408 SMP Mon Mar 22 12:47:11 GMT 2021 armv7l GNU/Linux

Solaranzeige: Software Version 4.7.1d update März 2021

Mosquitto 2.0.6 - den Fehler hatte ich auch schon mit Mosquitto 1.6.12

Im Folgenden Auszüge aus den Log-Dateien
/var/www/log/solaranzeige.log
/var/www/log/php.log

Code: Alles auswählen

/var/www/log/solaranzeige.log
=======================
06.04. 02:33:58    -OK. Datenübertragung erfolgreich.
06.04. 02:33:58 |----------------   Stop   sonoff_mqtt.php     --------------------
06.04. 02:34:01 |----------------   Start  sonoff_mqtt.php    ---------------------
06.04. 02:34:01    -Zentraler Timestamp: 1617669241
06.04. 02:34:01 +  -Die Daten werden ausgelesen...
06.04. 02:34:01    -Topic: tele/sonoff/LWT
06.04. 02:34:09    -Es handelt sich um ein Sonoff POW R2 Modul Nr.: 43
06.04. 02:34:10 *  -Daten zur entfernten InfluxDB [ datasolar ] gesendet.
06.04. 02:34:10 *  -Daten zur lokalen InfluxDB [ solaranzeige ] gesendet.
06.04. 02:34:57    -OK. Datenübertragung erfolgreich.
06.04. 02:34:57 |----------------   Stop   sonoff_mqtt.php     --------------------
06.04. 02:35:01 |----------------   Start  sonoff_mqtt.php    ---------------------
06.04. 02:35:01    -Zentraler Timestamp: 1617669301
06.04. 02:35:01 +  -Die Daten werden ausgelesen...
06.04. 02:35:01    -Topic: tele/sonoff/LWT
06.04. 02:35:09    -Keine Daten vom Sonoff Modul empfangen.
06.04. 02:35:09 !! -Keine gültigen Daten empfangen.
06.04. 02:35:09 |----------------   Stop   sonoff_mqtt.php     --------------------
06.04. 02:36:01 |----------------   Start  sonoff_mqtt.php    ---------------------
06.04. 02:36:01    -Zentraler Timestamp: 1617669361
06.04. 02:36:01 +  -Die Daten werden ausgelesen...
06.04. 02:36:09    -Keine Daten vom Sonoff Modul empfangen.
06.04. 02:36:09 !! -Keine gültigen Daten empfangen.
06.04. 02:36:09 |----------------   Stop   sonoff_mqtt.php     --------------------
...
...schnipp
...
06.04. 10:42:01 |----------------   Start  sonoff_mqtt.php    --------------------- 
06.04. 10:42:01    -Zentraler Timestamp: 1617698521
06.04. 10:42:01 +  -Die Daten werden ausgelesen...
06.04. 10:42:09    -Keine Daten vom Sonoff Modul empfangen.
06.04. 10:42:09 !! -Keine gültigen Daten empfangen.
06.04. 10:42:09 |----------------   Stop   sonoff_mqtt.php     -------------------- 

#Raspi reboot   <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

06.04. 10:43:01 |----------------   Start  sonoff_mqtt.php    --------------------- 
06.04. 10:43:01    -Zentraler Timestamp: 1617698581
06.04. 10:43:01 +  -Die Daten werden ausgelesen...
06.04. 10:43:12    -
T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 1
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0002 Rev=05.10
S:  Manufacturer=Linux 5.10.25-v7+ dwc_otg_hcd
S:  Product=DWC OTG Controller
S:  SerialNumber=3f980000.usb
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=0mA
I:  If#=0x0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub

T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480 MxCh= 4
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=02 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=2514 Rev=0b.b3
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#=0x0 Alt= 1 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=02 Driver=hub

T:  Bus=01 Lev=02 Prnt=02 Port=00 Cnt=01 Dev#=  3 Spd=480 MxCh= 3
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=02 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=2514 Rev=0b.b3
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#=0x0 Alt= 1 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=02 Driver=hub

T:  Bus=01 Lev=03 Prnt=03 Port=00 Cnt=01 Dev#=  4 Spd=480 MxCh= 0
D:  Ver= 2.10 Cls=ff(vend.) Sub=00 Prot=ff MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=7800 Rev=03.00
C:  #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=2mA
I:  If#=0x0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=00 Prot=ff Driver=lan78xx

T:  Bus=01 Lev=03 Prnt=03 Port=01 Cnt=02 Dev#=  5 Spd=480 MxCh= 0
D:  Ver= 2.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=152d ProdID=0578 Rev=03.01
S:  Manufacturer=USB 3.0 Device
S:  Product=USB 3.0 Device
S:  SerialNumber=000000004D18
C:  #Ifs= 1 Cfg#= 1 Atr=80 MxPwr=500mA
I:  If#=0x0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage

06.04. 10:43:13    -Daten:
array (
  17 => 'SCSI 00.0: 10600 Disk',
  '' => '[Created at block.245]',
  'Unique ID' => 'xtlt.DkTkx_X9bM2',
  'Parent ID' => '3t9U.TAOITtdfnIE',
  'SysFS ID' => '/class/block/sda',
  'SysFS BusID' => '0:0:0:0',
  'SysFS Device Link' => '/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0/host0/target0:0:0/0:0:0:0',
  'Hardware Class' => 'disk',
  'Model' => '"FM-25S2I -64GBFII"',
  'Vendor' => 'usb 0x152d "FM-25S2I"',
  'Device' => 'usb 0x0578 "-64GBFII"',
  'Revision' => '"0301"',
  'Serial ID' => '"00000000457C"',
  'Driver' => '"usb-storage", "sd"',
  'Driver Modules' => '"usb_storage"',
  'Device File' => '/dev/sda (/dev/sg0)',
  'Device Files' => '/dev/sda, /dev/disk/by-path/platform-3f980000.usb-usb-0:1.1.2:1.0-scsi-0:0:0:0, /dev/disk/by-id/usb-FM-25S2I_-64GBFII_000000004D18-0:0',
  'Device Number' => 'block 8:0-8:15 (char 21:0)',
  'Geometry (Logical)' => 'CHS 61057/64/32',
  'Size' => '125045424 sectors a 512 bytes',
  'Capacity' => '59 GB (64023257088 bytes)',
  'Speed' => '480 Mbps',
  'Module Alias' => '"usb:v152Dp0578d0301dc00dsc00dp00ic08isc06ip50in00"',
  'Driver Info #0' => '',
  'Driver Status' => 'uas is active',
  'Driver Activation Cmd' => '"modprobe uas"',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#1 (USB Controller)',
)
06.04. 10:43:13    -Daten:
array (
  18 => 'None 00.0: 11300 Partition',
  '' => '[Created at block.434]',
  'Unique ID' => 'bdUI.SE1wIdpsiiC',
  'Parent ID' => 'xtlt.DkTkx_X9bM2',
  'SysFS ID' => '/class/block/sda/sda1',
  'Hardware Class' => 'partition',
  'Model' => '"Partition"',
  'Device File' => '/dev/sda1',
  'Device Files' => '/dev/sda1, /dev/disk/by-partuuid/8978ce14-01, /dev/disk/by-id/usb-FM-25S2I_-64GBFII_000000004D18-0:0-part1, /dev/disk/by-label/boot, /dev/disk/by-uuid/0C61-73F5, /
dev/disk/by-path/platform-3f980000.usb-usb-0:1.1.2:1.0-scsi-0:0:0:0-part1',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#17 (Disk)',
)
06.04. 10:43:13    -Daten:
array (
  19 => 'None 00.0: 11300 Partition',
  '' => '[Created at block.434]',
  'Unique ID' => '2pkM.SE1wIdpsiiC',
  'Parent ID' => 'xtlt.DkTkx_X9bM2',
  'SysFS ID' => '/class/block/sda/sda2',
  'Hardware Class' => 'partition',
  'Model' => '"Partition"',
  'Device File' => '/dev/sda2',
  'Device Files' => '/dev/sda2, /dev/disk/by-label/rootfs, /dev/disk/by-partuuid/8978ce14-02, /dev/disk/by-id/usb-FM-25S2I_-64GBFII_000000004D18-0:0-part2, /dev/disk/by-uuid/43f2d0bb-8
3be-464f-94d0-9a751f376c64, /dev/disk/by-path/platform-3f980000.usb-usb-0:1.1.2:1.0-scsi-0:0:0:0-part2',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#17 (Disk)',
)
06.04. 10:43:13    -Daten:
array (
  25 => 'USB 00.0: 0200 Ethernet controller',
  '' => '[Created at usb.122]',
  'Unique ID' => 'Vl7j.8_I5RcIC_05',
  'Parent ID' => 'lfzD.YCWTDwYJz_B',
  'SysFS ID' => '/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.1/1-1.1.1:1.0',
  'SysFS BusID' => '1-1.1.1:1.0',
  'Hardware Class' => 'network',
  'Model' => '"Standard Microsystems Ethernet controller"',
  'Hotplug' => 'USB',
  'Vendor' => 'usb 0x0424 "Standard Microsystems Corp."',
  'Device' => 'usb 0x7800',
  'Revision' => '"3.00"',
  'Driver' => '"lan78xx"',
  'Driver Modules' => '"lan78xx"',
  'Device File' => 'eth0',
  'Speed' => '480 Mbps',
  'HW Address' => 'b8:27:eb:35:49:b2',
  'Permanent HW Address' => 'b8:27:eb:35:49:b2',
  'Link detected' => 'no',
  'Module Alias' => '"usb:v0424p7800d0300dcFFdsc00dpFFicFFisc00ipFFin00"',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#28 (Hub)',
)
06.04. 10:43:13    -Daten:
array (
  26 => 'USB 00.0: 10a00 Hub',
  '' => '[Created at usb.122]',
  'Unique ID' => 'k4bc.D6ER+lJeRh3',
  'Parent ID' => '3t9U.TAOITtdfnIE',
  'SysFS ID' => '/devices/platform/soc/3f980000.usb/usb1/1-0:1.0',
  'SysFS BusID' => '1-0:1.0',
  'Hardware Class' => 'hub',
  'Model' => '"Linux Foundation 2.0 root hub"',
  'Hotplug' => 'USB',
  'Vendor' => 'usb 0x1d6b "Linux Foundation"',
  'Device' => 'usb 0x0002 "2.0 root hub"',
  'Revision' => '"5.10"',
  'Serial ID' => '"3f980000.usb"',
  'Driver' => '"hub"',
  'Driver Modules' => '"usbcore"',
  'Speed' => '480 Mbps',
  'Module Alias' => '"usb:v1D6Bp0002d0510dc09dsc00dp01ic09isc00ip00in00"',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#1 (USB Controller)',
)
06.04. 10:43:13    -Daten:
array (
  28 => 'USB 00.0: 10a00 Hub',
  '' => '[Created at usb.122]',
  'Unique ID' => 'lfzD.YCWTDwYJz_B',
  'Parent ID' => 'ADDn.YCWTDwYJz_B',
  'SysFS ID' => '/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1:1.0',
  'SysFS BusID' => '1-1.1:1.0',
  'Hardware Class' => 'hub',
  'Model' => '"Standard Microsystems USB 2.0 Hub"',
  'Hotplug' => 'USB',
  'Vendor' => 'usb 0x0424 "Standard Microsystems Corp."',
  'Device' => 'usb 0x2514 "USB 2.0 Hub"',
  'Revision' => '"b.b3"',
  'Driver' => '"hub"',
  'Driver Modules' => '"usbcore"',
  'Speed' => '480 Mbps',
  'Module Alias' => '"usb:v0424p2514d0BB3dc09dsc00dp02ic09isc00ip02in00"',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#29 (Hub)',
)
06.04. 10:43:13    -Daten:
array (
  29 => 'USB 00.0: 10a00 Hub',
  '' => '',
  'Unique ID' => 'ADDn.YCWTDwYJz_B',
  'Parent ID' => 'k4bc.D6ER+lJeRh3',
  'SysFS ID' => '/devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.0',
  'SysFS BusID' => '1-1:1.0',
  'Hardware Class' => 'hub',
  'Model' => '"Standard Microsystems USB 2.0 Hub"',
  'Hotplug' => 'USB',
  'Vendor' => 'usb 0x0424 "Standard Microsystems Corp."',
  'Device' => 'usb 0x2514 "USB 2.0 Hub"',
  'Revision' => '"b.b3"',
  'Driver' => '"hub"',
  'Driver Modules' => '"usbcore"',
  'Speed' => '480 Mbps',
  'Module Alias' => '"usb:v0424p2514d0BB3dc09dsc00dp02ic09isc00ip02in00"',
  'Config Status' => 'cfg=new, avail=yes, need=no, active=unknown',
  'Attached to' => '#26 (Hub)',
)
06.04. 10:43:13    -USB Devices: 
array (
  1 => 
  array (
    'Device' => '0x7800',
    'File' => 'eth0',
    'Vendor' => 'usb 0x0424 "Standard Microsystems Corp."',
    'Model' => 'Standard Microsystems Ethernet controller',
    'Driver Modules' => 'lan78xx',
    'Driver' => 'lan78xx',
  ),
  2 => 
  array (
    'Device' => '0x2514',
  ),
)
06.04. 10:43:13    -Regler: 23
06.04. 10:43:13    -Device: MQTT wird in die user.config.php geschrieben.
06.04. 10:43:13    -Zeile gefunden. Device kann ausgetauscht werden. Index: 506   $USBRegler         = "MQTT";

06.04. 10:43:13    -Zeile gefunden. Device kann ausgetauscht werden. Index: 507   $USBWechselrichter = "/dev/ttyUSB1";

06.04. 10:43:13    -Zeile gefunden. Platine kann ausgetauscht werden. Index: 523   $Platine = "Raspberry Pi 3 Model B Plus Rev 1.3";

06.04. 10:44:30 |----------------   Start  sonoff_mqtt.php    --------------------- 
06.04. 10:44:30    -Zentraler Timestamp: 1617698670
06.04. 10:44:30 +  -Die Daten werden ausgelesen...
06.04. 10:44:30    -Topic: tele/sonoff/LWT
06.04. 10:44:38    -Es handelt sich um ein Sonoff POW R2 Modul Nr.: 43
06.04. 10:44:38 *  -Daten zur entfernten InfluxDB [ datasolar ] gesendet. 
06.04. 10:44:38 *  -Daten zur lokalen InfluxDB [ solaranzeige ] gesendet. 
06.04. 10:45:26    -OK. Datenübertragung erfolgreich.
06.04. 10:45:26 |----------------   Stop   sonoff_mqtt.php     -------------------- 
06.04. 10:46:01 |----------------   Start  sonoff_mqtt.php    --------------------- 
06.04. 10:46:02    -Zentraler Timestamp: 1617698761
06.04. 10:46:02 +  -Die Daten werden ausgelesen...
06.04. 10:46:02    -Topic: tele/sonoff/LWT
06.04. 10:46:09    -Es handelt sich um ein Sonoff POW R2 Modul Nr.: 43
06.04. 10:46:10 *  -Daten zur entfernten InfluxDB [ datasolar ] gesendet. 
06.04. 10:46:10 *  -Daten zur lokalen InfluxDB [ solaranzeige ] gesendet. 
06.04. 10:46:57    -OK. Datenübertragung erfolgreich.
06.04. 10:46:57 |----------------   Stop   sonoff_mqtt.php     -------------------- 

#############################################################################

/var/www/log/php.log   
======================
[03-Apr-2021 10:05:01 Europe/Berlin] PHP Fatal error:  Uncaught Mosquitto\Exception: The client is not currently connected. in /var/
www/html/sonoff_mqtt.php:126
Stack trace:
#0 /var/www/html/sonoff_mqtt.php(126): Mosquitto\Client->loop(100)
#1 /var/www/html/regler_auslesen.php(157): require('/var/www/html/s...')
#2 {main}
  thrown in /var/www/html/sonoff_mqtt.php on line 126
[06-Apr-2021 10:43:01 Europe/Berlin] PHP Fatal error:  Uncaught Mosquitto\Exception: The connection was lost. in /var/www/html/sonof
f_mqtt.php:167
Stack trace:
#0 /var/www/html/sonoff_mqtt.php(167): Mosquitto\Client->loop(100)
#1 /var/www/html/regler_auslesen.php(157): require('/var/www/html/s...')
#2 {main}
  thrown in /var/www/html/sonoff_mqtt.php on line 167
Für jeden Hinweis dankbar,
Uwe

Benutzeravatar
Ulrich
Administrator
Beiträge: 2150
Registriert: Sa 7. Nov 2015, 10:33
Wohnort: Essen
Hat sich bedankt: 3 Mal
Danksagung erhalten: 73 Mal
Kontaktdaten:

Re: Problem mit MQTT (Sonoff Pow R2)

Beitrag von Ulrich »

--------------------------------------
Ulrich [Admin]

Kilowatt
Beiträge: 9
Registriert: Mo 6. Jul 2020, 22:44
Danksagung erhalten: 1 Mal

Re: Problem mit MQTT (Sonoff Pow R2)

Beitrag von Kilowatt »

Es funktioniert ja nur sporadisch nicht.
Und wie ich bereits schrieb, der Fehler war auch schon unter der alten Mosquitto-Version 1.6.12 vorhanden.

Die Datei habe ich am 24.3. angelegt:
pi@solaranzeige:/etc/mosquitto/conf.d $ ls -al
drwxr-xr-x 2 root root 4096 Mär 24 11:50 .
drwxr-xr-x 5 root root 4096 Mär 24 11:30 ..
-rw-r--r-- 1 root root 35 Mär 24 11:50 mqtt-solaranzeige.conf
-rw-r--r-- 1 root root 142 Feb 18 2019 README

pi@solaranzeige:/etc/mosquitto/conf.d $ more mqtt-solaranzeige.conf
allow_anonymous true
listener 1883

Benutzeravatar
Ulrich
Administrator
Beiträge: 2150
Registriert: Sa 7. Nov 2015, 10:33
Wohnort: Essen
Hat sich bedankt: 3 Mal
Danksagung erhalten: 73 Mal
Kontaktdaten:

Re: Problem mit MQTT (Sonoff Pow R2)

Beitrag von Ulrich »

Laut deinen LOG Auszügen kann die Solaranzeige nicht auf den lokal installierten Mosquitto Broker zugreifen.
D.h. der Port 1883 ist zeitweise durch irgend etwas blockiert. Läuft auf dem Raspberry noch eine andere Software, die den Port 1883 in Beschlag nimmt oder blockiert irgend ein anderes Gerät von außen den Port 1883? In die Richtung musst du suchen.
--------------------------------------
Ulrich [Admin]

Kilowatt
Beiträge: 9
Registriert: Mo 6. Jul 2020, 22:44
Danksagung erhalten: 1 Mal

Re: Problem mit MQTT (Sonoff Pow R2)

Beitrag von Kilowatt »

Hallo Ulrich,

auf dem Pi läuft nur die Solaranzeige. Andere MQTT-Devices habe ich nicht.
Es sind auch keine Zugriffe unter Netstat sichtbar. Wenn der Fehler das nächste Mal auftritt,
werde ich nochmal mit Netstat schauen.

Ist es normal, dass von der Solaranzeige ständig Ports geschlossen und geöffnet werden?
Der Sonoff Pow R2 hält den Port dauerhaft geöffnet.

Code: Alles auswählen

[size=45]pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:51:05 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:40912         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:40924         VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:40924         127.0.0.1:1883          VERBUNDEN   3771/php            
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto      

pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:52:08 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:40932         VERBUNDEN   2218/mosquitto      
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:40924         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 127.0.0.1:40932         127.0.0.1:1883          VERBUNDEN   3801/php            
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto 
     
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:54:28 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:40940         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 127.0.0.1:1883          127.0.0.1:40952         VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:40952         127.0.0.1:1883          VERBUNDEN   3837/php            
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto   
   
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:55:13 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:40960         127.0.0.1:1883          VERBUNDEN   3858/php            
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:40960         VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto 
     
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:56:28 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:40968         VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:40968         127.0.0.1:1883          VERBUNDEN   3885/php            
tcp        0      0 127.0.0.1:40960         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto  
    
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:57:39 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:40976         127.0.0.1:1883          VERBUNDEN   3907/php            
tcp        0      0 127.0.0.1:40968         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:40976         VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
      
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:58:06 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:40976         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:40984         127.0.0.1:1883          VERBUNDEN   3929/php            
tcp        0      0 127.0.0.1:1883          127.0.0.1:40984         VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
      
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 15:59:11 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:40992         127.0.0.1:1883          VERBUNDEN   3955/php            
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:40984         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 127.0.0.1:1883          127.0.0.1:40992         VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
      
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 16:00:42 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:41000         VERBUNDEN   2218/mosquitto      
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:41000         127.0.0.1:1883          VERBUNDEN   3975/php            
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
      
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 16:04:02 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:41028         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 127.0.0.1:1883          127.0.0.1:41040         VERBUNDEN   2218/mosquitto      
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:41040         127.0.0.1:1883          VERBUNDEN   4051/php            
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
      
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 16:11:32 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:41088         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:1883          127.0.0.1:41100         VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:41100         127.0.0.1:1883          VERBUNDEN   4228/php            
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
      
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 16:13:20 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:41116         127.0.0.1:1883          VERBUNDEN   4266/php            
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:41108         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 127.0.0.1:1883          127.0.0.1:41116         VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto  
    
pi@solaranzeige:~ $ date; sudo netstat -nap | grep 1883
Mi 7. Apr 16:19:08 CEST 2021
tcp        0      0 0.0.0.0:1883            0.0.0.0:*               LISTEN      2218/mosquitto      
tcp        0      0 127.0.0.1:41168         127.0.0.1:1883          VERBUNDEN   4386/php            
tcp        0      0 192.168.178.53:1883     192.168.178.51:64279    VERBUNDEN   2218/mosquitto      
tcp        0      0 127.0.0.1:41160         127.0.0.1:1883          TIME_WAIT   -                   
tcp        0      0 127.0.0.1:1883          127.0.0.1:41168         VERBUNDEN   2218/mosquitto      
tcp6       0      0 :::1883                 :::*                    LISTEN      2218/mosquitto
[/size] 
Ich melde mich erneut, wenn es wieder hängt.

Uwe aka Kilowatt

Benutzeravatar
Ulrich
Administrator
Beiträge: 2150
Registriert: Sa 7. Nov 2015, 10:33
Wohnort: Essen
Hat sich bedankt: 3 Mal
Danksagung erhalten: 73 Mal
Kontaktdaten:

Re: Problem mit MQTT (Sonoff Pow R2)

Beitrag von Ulrich »

Die Solaranzeige belegt die Ports immer nur soange wie nötig, damit andere Software auch eine Chance haben.
--------------------------------------
Ulrich [Admin]

Kilowatt
Beiträge: 9
Registriert: Mo 6. Jul 2020, 22:44
Danksagung erhalten: 1 Mal

Re: Problem mit MQTT (Sonoff Pow R2)

Beitrag von Kilowatt »

Im Fehlerfall konnte ich eine Gosund SP1 sofort mit der Solaranzeige (Mosquitto) verbinden.
Der Fehler kommt also aus Richtung Sonoff Pow R2.

In der Tasmota-FAQ ist auch mein Fehler "already connected, closing old connection" beschrieben.

Diese Zeilen finde ich sehr häufig im Mosquitto-Log:
1617923914: New connection from 192.168.178.51:55203 on port 1883.
1617923914: Client DVES_4FAE23 already connected, closing old connection.
1617923914: New client connected from 192.168.178.51:55203 as DVES_4FAE23 (p2, c1, k30, u' ').


Damit ich die zeitlichen Abstände besser lesen kann, habe ich jetzt erst einmal das Log-Format umgestellt.

Dies kann man mit folgenden Zeilen in der /etc/mosquitto.conf erreichen:

log_dest file /var/log/mosquitto/mosquitto.log # Zeile bereits vorhanden
log_timestamp true
log_timestamp_format %H:%M:%S %d.%m.%y

Nach einem
sudo systemctl restart mosquitto
erfolgt das Logging jetzt mit lesbaren Zeitstempeln:

15:14:39 10.04.21: mosquitto version 2.0.9 starting
15:14:39 10.04.21: Config loaded from /etc/mosquitto/mosquitto.conf.
15:14:39 10.04.21: Opening ipv4 listen socket on port 1883.
15:14:39 10.04.21: mosquitto version 2.0.9 running
15:14:40 10.04.21: New connection from 192.168.178.51:56558 on port 1883.
15:14:40 10.04.21: New client connected from 192.168.178.51:56558 as DVES_4FAE23 (p2, c1, k30, u' ').

Antworten