76_SMAInverter.pm - Abfrage von SMA Wechselrichter

[liumertz]

Hallo Heiko, hallo Marcel,

sorry, dass ich mich nicht zurück gemeldet habe aber wir waren im Urlaub.

Ich habe gerade ein update bei meinem FHEM gemacht und da war wirklich der Schuh begraben!

Danke für eure Hilfe!

LG
Uli

[buschmann88]

Hallo

nach einer kleinen FHEM Pause bin ich nun doch wieder dazu gekommen zu versuchen meinen SunnyBoy 2.5 in FHEM einzubinden nur scheitere ich immer noch daran das ich immer ein Timeout bekomme und ich nicht weiß warum vieleicht könnt ihr mir ja helfen!

hier mal ein Auszug aus dem LOG

Code Auswählen Erweitern

017.02.12 12:45:01 5: createNotifyHash
2017.02.12 12:45:01 5: End notify loop for global
2017.02.12 12:45:01 4: Connection closed for WEB_192.168.xxx.xxx_54453: Die Verbindung wurde vom Kommunikationspartner zurückgesetzt
2017.02.12 12:45:01 4: WEB_192.168.xxx.xxx_65420 GET /fhem?detail=SMA_Sunny_Boy_2.5&fw_id=; BUFLEN:0
2017.02.12 12:45:01 4: name: /fhem?detail=SMA_Sunny_Boy_2.5&fw_id= / RL:5526 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2017.02.12 12:45:02 4: WEB_192.168.xxx.xxx_65420 GET /fhem?cmd={AttrVal(%22SMA_Sunny_Boy_2.5%22,%22room%22,%22%22)}&XHR=1; BUFLEN:0
2017.02.12 12:45:02 5: Cmd: >{AttrVal("SMA_Sunny_Boy_2.5","room","")}<
2017.02.12 12:45:02 4: name: /fhem?cmd={AttrVal(%22SMA_Sunny_Boy_2.5%22,%22room%22,%22%22)}&XHR=1 / RL:23 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2017.02.12 12:45:02 4: WEB_192.168.179.156_65420 GET /fhem?XHR=1&inform=type=status;filter=SMA_Sunny_Boy_2.5;since=1486899900;fmt=JSON&fw_id=385×tamp=1486899915162; BUFLEN:0
2017.02.12 12:45:03 4: Connection accepted from WEB_192.168.xxx.xxx_65426
2017.02.12 12:45:03 4: WEB_192.168.xxx.xxx_65426 POST /fhem?cmd=save&XHR=1&fw_id=385; BUFLEN:0
2017.02.12 12:45:03 5: Cmd: >save<
2017.02.12 12:45:03 5: Starting notify loop for global, 1 event(s), first is SAVE
2017.02.12 12:45:03 5: createNotifyHash
2017.02.12 12:45:03 5: End notify loop for global
2017.02.12 12:45:03 4: name: /fhem?cmd=save&XHR=1&fw_id=385 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2017.02.12 12:45:05 4: WEB_192.168.xxx.xxx_65410 GET /fhem?cmd={AttrVal(%22SMA_Sunny_Boy_2.5%22,%22timeout%22,%22%22)}&XHR=1; BUFLEN:0
2017.02.12 12:45:05 5: Cmd: >{AttrVal("SMA_Sunny_Boy_2.5","timeout","")}<
2017.02.12 12:45:05 4: name: /fhem?cmd={AttrVal(%22SMA_Sunny_Boy_2.5%22,%22timeout%22,%22%22)}&XHR=1 / RL:24 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2017.02.12 12:45:05 4: Connection closed for WEB_192.168.xxx.xxx_65410: EOF
2017.02.12 12:45:06 4: WEB_192.168.xxx.xxx_65426 POST /fhem?detail=SMA_Sunny_Boy_2.5&dev.getSMA_Sunny_Boy_2.5=SMA_Sunny_Boy_2.5&cmd.getSMA_Sunny_Boy_2.5=get&arg.getSMA_Sunny_Boy_2.5=data&val.getSMA_Sunny_Boy_2.5=&XHR=1&addLinks=1&fw_id=385; BUFLEN:0
2017.02.12 12:45:06 5: Cmd: >get SMA_Sunny_Boy_2.5 data<
2017.02.12 12:45:06 3: SMAInverter SMA_Sunny_Boy_2.5 - WARNING - old process 4920 will be killed now to start a new BlockingCall
2017.02.12 12:45:06 1: Timeout for getstatus_DoParse reached, terminated process 4920
2017.02.12 12:45:06 1: SMAInverter SMA_Sunny_Boy_2.5 -> BlockingCall getstatus_DoParse timed out
2017.02.12 12:45:06 5: Starting notify loop for SMA_Sunny_Boy_2.5, 1 event(s), first is timeout
2017.02.12 12:45:06 5: End notify loop for SMA_Sunny_Boy_2.5
2017.02.12 12:45:06 4: SMA_Sunny_Boy_2.5 - ###############################################################
2017.02.12 12:45:06 4: SMA_Sunny_Boy_2.5 - ##########  Begin of new SMAInverter get data cycle  ##########
2017.02.12 12:45:06 4: SMA_Sunny_Boy_2.5 - ###############################################################
2017.02.12 12:45:06 4: SMA_Sunny_Boy_2.5 - timeout cycles since module start: 12
2017.02.12 12:45:06 4: BlockingCall (getstatus_DoParse): created child (4922), uses telnetPort to connect back
2017.02.12 12:45:06 4: name: /fhem?detail=SMA_Sunny_Boy_2.5&dev.getSMA_Sunny_Boy_2.5=SMA_Sunny_Boy_2.5&cmd.getSMA_Sunny_Boy_2.5=get&arg.getSMA_Sunny_Boy_2.5=data&val.getSMA_Sunny_Boy_2.5=&XHR=1&addLinks=1&fw_id=385 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2017.02.12 12:45:06 4: SMA_Sunny_Boy_2.5 -> Start BlockingCall getstatus_DoParse
2017.02.12 12:45:06 5: Compute sunrise/sunset for latitude 53.4195808 , longitude 10.1475625
2017.02.12 12:45:06 5: Compute sunrise/sunset for latitude 53.4195808 , longitude 10.1475625
2017.02.12 12:45:07 4: SMA_Sunny_Boy_2.5 - current time: 12.02.2017 12:45:07
2017.02.12 12:45:07 4: SMA_Sunny_Boy_2.5 - operation time begin: 12.02.2017 07:08:12
2017.02.12 12:45:07 4: SMA_Sunny_Boy_2.5 - operation time end: 12.02.2017 18:00:00
2017.02.12 12:45:07 4: SMA_Sunny_Boy_2.5 - Send login to 192.168.xxx.xy on Port 9522 with password 0000
2017.02.12 12:45:07 5: SMA_Sunny_Boy_2.5 - Send: 534D4100000402A000000001003A001060650EA0FFFFFFFFFFFF0001E90023BB590700010000000001800C04FDFF0700000084030000C34AA05800000000B9C0B8BBB9C1C0C08888888800000000
2017.02.12 12:45:07 5: SMA_Sunny_Boy_2.5 - Received: 534d4100000402a000000001002e001060650be0e90023bb590700012f018ad1097300010000000001800d04fdff0700000084030000c34aa0580000000000000000
2017.02.12 12:45:07 4: SMA_Sunny_Boy_2.5 - logged in to inverter serial: 1930023306, susyid: 303
2017.02.12 12:45:07 5: SMA_Sunny_Boy_2.5 - Logged in now
2017.02.12 12:45:07 3: SMA_Sunny_Boy_2.5 - Send request 00020058001E8200FF208200 to 192.168.xxx.xy on port 9522
2017.02.12 12:45:07 5: SMA_Sunny_Boy_2.5 - send: 534D4100000402A00000000100260010606509A0FFFFFFFFFFFF0000E90023BB5907000000000000028000020058001E8200FF20820000000000
2017.02.12 12:45:23 4: Connection closed for WEB_192.168.xxx.xxx_65409: EOF
2017.02.12 12:45:24 4: WEB_192.168.xxx.xxx_65426 GET /fhem/FileLog_logWrapper?dev=Logfile&type=text&file=fhem-2017-02.log; BUFLEN:0

[Hellspawn]

@Straightforward

könntest Du mir mal Dein define des Charts schicken ?
Mit Logfiles und SVG-Plots tu ich mich irgendwie ziemlich schwer...

Dankeschön
Carsten

[DS_Starter]

Hallo buschmann88,

sieht auf den ersten Blick so aus, als ob dein Inverter nach dem login nicht mehr antwortet.
Du hast global oder auch fhemweb verbose hochgedreht. Stell das mal wieder auf 3 und nur dein Inverterdevice auf 5, dann sieht man mehr.
Ist die IP wirklich die deines Inverters oder hast du vllt. die des SMA Home Managers angegeben ?  Kam schon öfter vor ...

[buschmann88]

Danke erst mal für die schnelle Antwort

hier das neue LOG

Code Auswählen Erweitern

2017.02.12 18:26:08 3: SMAInverter SMA_Sunny_Boy_2.5 - WARNING - old process 10515 will be killed now to start a new BlockingCall
2017.02.12 18:26:08 1: Timeout for getstatus_DoParse reached, terminated process 10515
2017.02.12 18:26:08 1: SMAInverter SMA_Sunny_Boy_2.5 -> BlockingCall getstatus_DoParse timed out
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - ###############################################################
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - ##########  Begin of new SMAInverter get data cycle  ##########
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - ###############################################################
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - timeout cycles since module start: 4
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 -> Start BlockingCall getstatus_DoParse
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - current time: 12.02.2017 18:26:09
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - operation time begin: 12.02.2017 07:08:12
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - operation time end: 12.02.2017 18:00:00
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - Send login to 192.168.178.87 on Port 9522 with password 0000
2017.02.12 18:26:09 5: SMA_Sunny_Boy_2.5 - Send: 534D4100000402A000000001003A001060650EA0FFFFFFFFFFFF0001E90023BB590700010000000001800C04FDFF0700000084030000B19AA05800000000B9C0B8BBB9C1C0C08888888800000000
2017.02.12 18:26:09 5: SMA_Sunny_Boy_2.5 - Received: 534d4100000402a000000001002e001060650be0e90023bb590700012f018ad1097300010000000001800d04fdff0700000084030000b19aa0580000000000000000
2017.02.12 18:26:09 4: SMA_Sunny_Boy_2.5 - logged in to inverter serial: 1930023306, susyid: 303
2017.02.12 18:26:09 5: SMA_Sunny_Boy_2.5 - Logged in now
2017.02.12 18:26:09 3: SMA_Sunny_Boy_2.5 - Send request 00020058001E8200FF208200 to 192.168.178.87 on port 9522
2017.02.12 18:26:09 5: SMA_Sunny_Boy_2.5 - send: 534D4100000402A00000000100260010606509A0FFFFFFFFFFFF0000E90023BB5907000000000000028000020058001E8200FF20820000000000

Einen SMA Home Manager habe ich nicht und ich komme auch über die IP auf meinen SunnyBoy drauf

Gruß Christian

[DS_Starter]

Hi Christian,

wenn

send: 534D4100000402A00000000100260010606509A0FFFFFFFFFFFF0000E90023BB5907000000000000028000020058001E8200FF20820000000000

das letzte ist was kommt und danach kein (ein Beispiel von mir):

Code Auswählen Erweitern

2017.02.12 17:33:18.366 5: MySTP_5000 - Received: 534d4100000402a00000000100c6001060653190e90023bb590700a0b500169b2d120000000000000280010200580000000003000000011e82106b0ca058534e3a2033303439373837313000000000000000000000000000000000000000011f82086b0ca058411f0001feffff00000000000000000000000000000000000000000000000000012082086b0ca0588a2300018b2300008c2300008e2300008f230000412400004224000043240000012082086b0ca058feffff000000000000000000000000000000000000000000000000000000000000000000
2017.02.12 17:33:18.366 5: MySTP_5000 - Data identifier 33310
2017.02.12 17:33:18.366 5: MySTP_5000 - Found Data CLASS=8001 and TYPE=9098
2017.02.12 17:33:18.367 3: MySTP_5000 - Send request 0002005400012600FF222600 to 192.168.2.40 on port 9522
2017.02.12 17:33:18.367 5: MySTP_5000 - send: ................


Dann antwortet dein Inverter nicht.
Frage , hast du die Attribute target-serial, target-susyid ? Wenn ja, die richtigen Werte ?
Mach am Bestem mal ein "list SMA_Sunny_Boy_2.5". Vielleicht fällt dann noch etwas auf.  Firewalls oder andere Einstellungen die die Kommunikation behindern könnten gibt es nicht ?

Grüße
Heiko

[buschmann88]

Nein bei mir ist da immer Schluss

die Ausgabe ergibt bei mir

Code Auswählen Erweitern

Internals:
   DEF        0000 192.168.178.87
   HOST       192.168.178.87
   INTERVAL   60
   LASTUPDATE 12.02.2017 / 19:08:13
   NAME       SMA_Sunny_Boy_2.5
   NR         137
   PASS       0000
   STATE      timeout
   TYPE       SMAInverter
   VERSION    2.8.1
   Helper:
     DEFAULT_TARGET_SERIAL 4294967295
     DEFAULT_TARGET_SUSYID 65535
     FAULTEDCYCLES 66
     INTERVAL   60
     MAXBYTES   300
     MYSERIALNUMBER 123321123
     MYSUSYID   233
     PKT_ID     32769
     Running_pid:
       abortFn    SMAI_ParseAborted
       arg        SMA_Sunny_Boy_2.5
       bc_pid     69
       finishFn   getstatus_ParseDone
       fn         getstatus_DoParse
       pid        11440
       timeout    120
       Abortarg:
   Readings:
     2017-02-12 19:08:13   background_processing_time 0.2178
     2017-02-12 19:08:13   modulstate      sleep
     2017-02-12 19:08:13   opertime_start  12.02.2017 07:08:12
     2017-02-12 19:08:13   opertime_stop   12.02.2017 18:00:00
     2017-02-12 19:27:20   state           timeout
Attributes:
   SBFSpotComp 0
   detail-level 2
   devStateIcon .*:day_night
   disable    0
   mode       automatic
   room       pv
   showproctime 1
   suppressSleep 1
   timeout    120
   verbose    5

eine Firewall hab ich nicht der raspi und SunnyBoy hängen zusammen an einer FritzBox7490

[Straightforward]

Bei mir hat damals ein Update von FHEM geholfen.

[DS_Starter]

Bei mir hat damals ein Update von FHEM geholfen.

Aktuelles FHEM ist prinzipiell immer gut.

Ansonsten setze dir mal die Attribute target-serial, target-susyid auf die richtigen Werte deines WR. Die bekommst du am ehesten über die Eigenschaften deines WR im Sunny-Portal heraus. Ein paar Beiträge weiter vorn haben wir das Thema schonmal betrachtet.
Also es ist das Grundproblem dass der WR nicht antwortet bzw. diese Antwort nicht bei deinem Raspi ankommt. Deswegen die Frage nach der Firewall.
Bluetoth (wenn der WR so etwas hat) ist deaktiviert ?

Grüße
Heiko

[buschmann88]

Nun hab ich die beiden Einstellungen gemacht jedoch ohne Änderung

Der Wechselrichter hat nur Speedwire

kann es vieleicht sein das meine fritzbox den Port blockiert?
und wenn ja welchen muss ich da freigeben

Gruß Christian

[DS_Starter]

Hmm.... kenne zwar FB nicht, aber ich denke nicht dass die im internen Netz den Verkehr/Port blockiert.
Antwortet denn dein WR auf einen ping 192.168.178.87, wenn du ihn von Raspi aus ausführst ?
Die Adresse ist auch die des WR, richtig ?
Hast du andere LAN-gestützte Geräte schon am RPi dran die auch funktionieren ? Nur zur Sicherheit dass mit deinem LAN-Interface etwas nicht funktioniert, aber der login hat ja geklappt wie es aussieht. Als Protokoll wird UDP verwendet ... nur zur Info.

Grüße
Heiko

[buschmann88]

einen Ping über den Raspi bekomme ich laut Ausgabe:

Code Auswählen Erweitern

root@raspberrypi:~# ping 192.168.178.87
PING 192.168.178.87 (192.168.178.87) 56(84) bytes of data.
40 bytes from 192.168.178.87: icmp_seq=1 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=2 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=3 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=4 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=5 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=6 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=7 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=8 ttl=64 (truncated)
40 bytes from 192.168.178.87: icmp_seq=9 ttl=64 (truncated)


ich weiß auch langsam nicht mehr weiter

Gruß Christian

[DS_Starter]

ich weiß auch langsam nicht mehr weiter

Geht mir ähnlich. Bleibt noch die Frage ob es mit dem UDP Protokoll irgendwelche Probleme gibt. Der Ping ist nur ein Indiz dass die Kommunikation prinzipiell klappt, ist aber TCP.

Wenn du dir die Arbeit machen willst, könntest du dir mal SBFSpot installieren und wir schauen ob dann noch etwas herauszubekommen ist.
https://sbfspot.codeplex.com/

Vielleicht hat ein anderer Mitstreiter noch Ideen ...

EDIT: bist du dir sicher dass das Passwort stimmt ? Ich habe das PW angegeben welches ich im SMA-Portal für die Anlage gesetzt habe.

Grüße
Heiko

[Hassi95]

Hallo zusammen,

ich habe gestern Abend das Modul mit meinem SunnyBoy 2.5 ausgetestet.
Da es schon dunkel war lieferte es nur die Antworten für Operation_time.
Suppresssleep hatte ich gestern nicht mehr ausprobiert. Als ich heute nach Hause gekommen bin gab das Modul allerdings gar keine Werte mehr zurück.
State ist nun Login failed.

Per ping ist das Gerät auf seiner Adresse 10.0.0.20 noch erreichbar, auch eine Abfrage mit SBFspot funktioniert einwandfrei.
Daraufhin habe ich die Werte für susyid und Serial gesetzt, aber ohne Erfolg.

Hier noch ein Auszug des Logs:

Code Auswählen Erweitern

2017.03.22 18:11:29 4: PV_Inverter - ###############################################################
2017.03.22 18:11:29 4: PV_Inverter - ##########  Begin of new SMAInverter get data cycle  ##########
2017.03.22 18:11:29 4: PV_Inverter - ###############################################################
2017.03.22 18:11:29 4: PV_Inverter - timeout cycles since module start: 2
2017.03.22 18:11:29 4: PV_Inverter -> Start BlockingCall getstatus_DoParse
2017.03.22 18:11:30 4: PV_Inverter - current time: 22.03.2017 18:11:30
2017.03.22 18:11:30 4: PV_Inverter - operation time begin: 22.03.2017 05:52:27
2017.03.22 18:11:30 4: PV_Inverter - operation time end: 22.03.2017 19:13:13
2017.03.22 18:11:30 4: PV_Inverter - Send login to 10.0.0.20 on Port 9522 with password SunnyBoy123
2017.03.22 18:11:30 5: PV_Inverter - Send: 534D4100000402A000000001003A001060650EA02F0155040A730001E90023BB590700010000000001800C04FDFF070000008403000042B0D25800000000DBFDF6F610CAF710B9BABB8800000000
2017.03.22 18:11:30 5: PV_Inverter - Received: 534d4100000402a000000001002e001060650be0e90023bb590700012f0155040a7300010001000001800d04fdff070000008403000042b0d2580000000000000000
2017.03.22 18:11:30 1: PV_Inverter - Inverter answer does not match our parameters.
2017.03.22 18:11:30 5: PV_Inverter - Request/Response: SusyID 233/233, Serial 123321123/123321123, Packet ID 32769/32769, Command 0xFFFD040D/4294771725, Error 256
2017.03.22 18:11:30 4: PV_Inverter - Send logout to 10.0.0.20 on Port 9522
2017.03.22 18:11:30 5: PV_Inverter - Send: 534D4100000402A00000000100220010606508A02F0155040A730003E90023BB590700030000000002800E01FDFFFFFFFFFF00000000
2017.03.22 18:11:30 4: PV_Inverter - logged out now from inverter serial: 1930036309, susyid: 303
2017.03.22 18:11:30 5: PV_Inverter -> row_array before encoding:
2017.03.22 18:11:30 5: PV_Inverter -> state Login failed
2017.03.22 18:11:30 5: PV_Inverter -> modulstate login failed
2017.03.22 18:11:30 4: PV_Inverter -> BlockingCall getstatus_DoParse finished
2017.03.22 18:11:30 4: PV_Inverter -> Start BlockingCall getstatus_ParseDone
2017.03.22 18:11:30 5: PV_Inverter -> row_array after decoding:
2017.03.22 18:11:30 5: PV_Inverter -> state Login failed
2017.03.22 18:11:30 5: PV_Inverter -> modulstate login failed
2017.03.22 18:11:30 4: PV_Inverter -> BlockingCall getstatus_ParseDone finished

Was mir jetzt hier auf den ersten Blick aufgefallen war, ist dass das Modul wohl mit einer anderen susyid und serial anfragt, wie ich angegeben habe. Zumindest interpretiere ich den Log so.
Für eure Hilfe diesbezüglich wäre ich sehr dankbar.
Falls noch weitere Informationen benötigt werden, probiere ich diese natürlich anzugeben.

[buschmann88]

Hallo Hassi95

das ist genau das Problem was ich auch habe!

Bin da auch noch nicht weiter gekommen bin auch schon am verzweifeln

Gruß Christian