DarkZeros / dbus-mppsolar

DBus VenusOS driver for Vevor inverter
4 stars 1 forks source link

Error install #1

Closed grydo closed 2 months ago

grydo commented 5 months ago

Could there be a simpler installation guide?

DarkZeros commented 5 months ago

@grydo Hi! I pushed a new Readme, let me know if it is not clear. I made it as easy as I could

grydo commented 5 months ago

NiImmagine Installation ok, venus doesn't read my voltronic inverter, edit other file .conf for USB Port?

grydo commented 4 months ago

@DarkZeros install is ok no error, my inverter voltronic it is not read.

DarkZeros commented 3 months ago

I haven't tested voltronic inverter sorry... I have only tested PI30 protocol inverter. It should be easy to port it to any inverter, but without having access to the Hardware to debug it might be difficult to do so.

w0vka commented 3 months ago

@DarkZeros I have the same problem as @grydo described. I have connected my MPP-Solar Inverter (pip-max8048) and it is recognized as ttyUSB0 and i get a valid response on my tests with the "test.py" script.

But unfortunately the venus does not recognize any inverter.

Is there an troubleshooting guide to identify the problem?

Happy for any kind of help. thx

DarkZeros commented 2 months ago

Hi @w0vka and @grydo.

If you want to develop the code feel free to do so. I do not have any other inverter other than the Chinese PI30 "SunPower" one, so i can't help you implementing support for those.

The repository what it does is:

To enable support for a new inverter I would start by doing:

If you need to check the logs are in /var/log/ and to check the dbus use "dbus-spy". Writing any value to the dbus service /restart path will trigger the service to restart, applying any changes done to the python script.

DarkZeros commented 2 months ago

Another alternative I can give you is:

w0vka commented 2 months ago

Hello @DarkZeros, thank you very much for your answer and your help. I don't think it's the protocol, as my inverter also works with the PI30 protocol:

root@raspberrypi2:/data/etc/dbus-mppsolar# mpp-solar -p /dev/ttyUSB0 -c QPI
Command: QPI - Protocol ID inquiry
------------------------------------------------------------
Parameter                       Value           Unit
protocol_id                     PI30               

The problem is that I can neither see the service "mppsolar" on dbus-spy nor find any log under /var/log/dbus-mppsolar. Is it possible, that the service does not start at all.

If I execute the script /data/etc/dbus-mppsolar/start-dbus-mppsolar.sh, I get the following error message:

root@raspberrypi2:/data/etc/dbus-mppsolar# ./start-dbus-mppsolar.sh 
UTC-2024.04.10-21:53:04 Starting dbus-mppsolar.py on 
Traceback (most recent call last):
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 46, in runInverterCommands
    parsed = [json.loads(o) for o in output]
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 46, in <listcomp>
    parsed = [json.loads(o) for o in output]
  File "/usr/lib/python3.8/json/__init__.py", line 357, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.8/json/decoder.py", line 340, in decode
    raise JSONDecodeError("Extra data", s, end)
json.decoder.JSONDecodeError: Extra data: line 1 column 5 (char 4)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 439, in <module>
    main()
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 430, in main
    mppservice = DbusMppSolarService(tty=args.serial.strip("/dev/"), deviceinstance=0)
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 100, in __init__
    self._invData = runInverterCommands(['QID','QVFW'])
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 52, in runInverterCommands
    mainloop.quit()
NameError: name 'mainloop' is not defined
rm: '/var/lock/serial-starter' is a directory

However, the query of the commands QID and QVFW can be queried without any problems:

root@raspberrypi2:/data/etc/dbus-mppsolar# mpp-solar -p /dev/ttyUSB0 -c QID
Command: QID - Device Serial Number inquiry
------------------------------------------------------------
Parameter                       Value           Unit
serial_number                   92932001144430    
root@raspberrypi2:/data/etc/dbus-mppsolar# mpp-solar -p /dev/ttyUSB0 -c QVFW
Command: QVFW - Main CPU firmware version inquiry
------------------------------------------------------------
Parameter                       Value           Unit
main_cpu_firmware_version       VERFW:00046.05  

What am I doing wrong?? My /etc/venus/serial-starter.conf currently looks like this:

service cgwacs          dbus-cgwacs
service gps             gps-dbus
service modbus          dbus-modbus-client.serial
service modem           dbus-modem
service mkx             mk2-dbus
service vedirect        vedirect-interface
service fzsonick        dbus-fzsonick-48tl
service imt             dbus-imt-si-rs485tc
service mppsolar        dbus-mppsolar

alias   rs485           cgwacs:fzsonick:imt:modbus
alias   default         gps:vedirect:mppsolar

include /data/conf/serial-starter.d

I really appreciate your help.

DarkZeros commented 2 months ago

The code currently supports calling mpp-solar python package via PIP, or using the mpp-solar as a submodule. From what I tried, the upstream mpp-solar has gone over certain changed that didn't make it compatible with the code I had because it did not return valid JSON results, that are needed to automatically parse the results for the rest of the code. So I cherrypicked a certain revision, and used the python submodule (but I think the code still default to the installed version if you have one).

What I can see is that you are getting the error on parsed = [json.loads(o) for o in output]which is the upstream mppsolar one. Can you try to use the other one?

Comment: the lines

import mppsolar
MPP_INSTALLED = True

At the lines 33&34 of dbus-mppsolar.py

You also don't need to run the service manually, the VenusOS will run it for you as soon as you plug a USB-RS232 device compatible.

I should spend some time cleaning up that, and using only the version in the submodule that I know is compatible with the rest of the code.

DarkZeros commented 2 months ago

@w0vka could you try with the latest main commit? https://github.com/DarkZeros/dbus-mppsolar/commit/47244c06b4961c86c6db16944581bcf1053d682f

w0vka commented 2 months ago

Thank you for your feedback! I tried commenting out lines 33 & 34, but unfortunately with the same result. Now I've tried it with the latest commit, but unfortunately the result hasn't changed. I don't see any service under dbus-spy and I also don't see any logs under /var/log

DarkZeros commented 2 months ago

Given you feedback, it looks like the service does not even reach the point to start. Because it should save logs in /var/log/dbus-mppsolar... Maybe a problem in installing the service? Maybe a different service script is needed for your version of VenuOS? Try a reboot of the venus OS

w0vka commented 2 months ago

As already mentioned, I also believe that the service does not even start correctly. I have of course restarted it several times, but to no success. I even reinstalled the whole Venus OS (v 3.30), but that didn't help either.

If I now start the script /data/etc/dbus-mppsolar/start-dbus-mppsolar.sh manually (just for a test and with the latest commit), I get a different error message:

root@raspberrypi2:/data/etc/dbus-mppsolar# ./start-dbus-mppsolar.sh 
UTC-2024.04.12-23:04:58 Starting dbus-mppsolar.py on 
2024-04-12 23:04:59,838:ERROR:device:run_command@56: No communications port defined - unable to run command QID
2024-04-12 23:04:59,839:ERROR:device:run_command@56: No communications port defined - unable to run command QVFW
Traceback (most recent call last):
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 443, in <module>
    main()
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 434, in main
    mppservice = DbusMppSolarService(tty=args.serial.strip("/dev/"), deviceinstance=0)
  File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 113, in __init__
    self._dbusmulti = VeDbusService(f'com.victronenergy.multi.mppsolar.{tty}', dbusconnection())
  File "/data/etc/dbus-mppsolar/velib_python/vedbus.py", line 78, in __init__
    self._dbusname = dbus.service.BusName(servicename, self._dbusconn, do_not_queue=True)
  File "/usr/lib/python3.8/site-packages/dbus/service.py", line 112, in __new__
    validate_bus_name(name, allow_well_known=True, allow_unique=False)
ValueError: Invalid bus name 'com.victronenergy.multi.mppsolar.': must not end with '.'
rm: '/var/lock/serial-starter' is a directory

Does this help to identify the problem?

DarkZeros commented 2 months ago

./start-dbus-mppsolar.sh is supposed to be called by VenusOS automatically when a USB serial device is discovered. VenusOS will pass as argument the ttyUSB0 (or whichever number it needs). The error there is that you did not pass an argument, so it does not know which port to run the commands to.

It could be that another of the services is trying to communicate with the ttyUSB and failing, so the mppsolar service doesn't start. Can you try changing the priorities? Maybe even enabling it for rs485:

alias   rs485           mppsolar:cgwacs:fzsonick:imt:modbus
alias   default         mppsolar:gps:vedirect

You should be able to see in /var/log/{servicename}.ttyUSB0 which services have started for the TTY you have the device connected.

w0vka commented 2 months ago

Hi,

we're getting closer 😬. The priority was a good hint. I have changed the priority as you suggested and the service starts now. I can now see both the service in dbus-spy and the corresponding log file under /var/log/. 🎉

But since the inverter was not yet displayed in the Venus OS, I checked the log and saw the following error message (with the latest commit 47244c0):

root@raspberrypi2:~# tail -F /var/log/dbus-mppsolar.ttyUSB1/current 
@40000000661cc8bd1e3e12b4 NameError: name 'MPP_INSTALLED' is not defined
@40000000661cc9020b75a994 *** starting dbus-mppsolar ***
@40000000661cc90335426064 Traceback (most recent call last):
@40000000661cc903354277d4   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 443, in <module>
@40000000661cc90335428774     main()
@40000000661cc90335428f44   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 434, in main
@40000000661cc90335429ee4     mppservice = DbusMppSolarService(tty=args.serial.strip("/dev/"), deviceinstance=0)
@40000000661cc9033542b26c   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 220, in __init__
@40000000661cc9033542c20c     GLib.timeout_add(10000 if MPP_INSTALLED else 2000, self._update)
@40000000661cc9033544296c NameError: name 'MPP_INSTALLED' is not defined

If I switch to the previous commit 50f2ea7aa3276f12c83275e224e0211ea7b630cd, the inverter is now displayed in the Venus OS, but only as "disconnected" and without values. Now I see the following message in the log:

root@raspberrypi2:~# tail -F /var/log/dbus-mppsolar.ttyUSB1/current 
@40000000661cccfe0af5715c   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 54, in runInverterCommands
@40000000661cccfe0af584e4     return parsed
@40000000661cccfe0af58cb4 UnboundLocalError: local variable 'parsed' referenced before assignment
@40000000661ccd430877dab4 *** starting dbus-mppsolar ***
@40000000661ccd530a1d513c Traceback (most recent call last):
@40000000661ccd530a1d68ac   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 239, in _update
@40000000661ccd530a1d7c34     raw = runInverterCommands(['QPIGS','QMOD','QPIWS'])
@40000000661ccd530a1d87ec   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 54, in runInverterCommands
@40000000661ccd530a1d9b74     return parsed
@40000000661ccd530a1da344 UnboundLocalError: local variable 'parsed' referenced before assignment
@40000000661ccd9736aad5bc *** starting dbus-mppsolar ***

If you have any ideas or I can test something else, please let me know.

DarkZeros commented 2 months ago

Ups I missed the old MPP_INSTALLED variable in the commit. I will fix that now. try with the new amended main branch. cfbce68

w0vka commented 2 months ago

I have tested the latest commit cfbce68 and get the same errors like the commit 50f2ea7:

root@raspberrypi2:~# tail -F /var/log/dbus-mppsolar.ttyUSB1/current 
@40000000661d2dd4028d965c *** starting dbus-mppsolar ***
@40000000661d2dd829fd428c Traceback (most recent call last):
@40000000661d2dd829fd59fc   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 243, in _update
@40000000661d2dd829fd6d84     raw = runInverterCommands(['QPIGS','QMOD','QPIWS'])
@40000000661d2dd829fd793c   File "/data/etc/dbus-mppsolar/dbus-mppsolar.py", line 57, in runInverterCommands
@40000000661d2dd829fd8cc4     return parsed
@40000000661d2dd829fd9494 UnboundLocalError: local variable 'parsed' referenced before assignment
DarkZeros commented 2 months ago

Hmmm, it is failing silently in some point between these lines.

    try: 
        if USE_SYSTEM_MPPSOLAR:
            output = [sp.getoutput("mapp-solar -b {} -P {} -p {} -o json -c {}".format(args.baudrate, protocol, args.serial, c)).split('\n')[0] for c in commands]
            parsed = [json.loads(o) for o in output]
        else:
            dev = mppsolar.helpers.get_device_class("mppsolar")(port=args.serial, protocol=protocol, baud=args.baudrate)
            results = [dev.run_command(command=c) for c in commands]
            parsed = [mppsolar.outputs.to_json(r, False, None, None) for r in results]           
    except Exception:
        mainloop.quit()
        exit
    return parsed

But if it was an exception, it would call the mainloop.quit()....

I added some extra logs to main code, test that and will tell you what is wrong in the inverter commands.

w0vka commented 2 months ago

A few updates from my side:

I have tested the three commands (QPIGS,QMOD,QPIWS) that your script queries from the inverter directly and found that my inverter returns an "unexpected" response for the QIPWS command:

root@raspberrypi2:~# mpp-solar -p /dev/ttyUSB1 -c QPIWS
Traceback (most recent call last):
  File "/usr/bin/mpp-solar", line 8, in <module>
    sys.exit(main())
  File "/usr/lib/python3.8/site-packages/mppsolar/__init__.py", line 408, in main
    results = _device.run_command(command=_command)
  File "/usr/lib/python3.8/site-packages/mppsolar/devices/device.py", line 333, in run_command
    decoded_response = self._protocol.decode(raw_response, command)
  File "/usr/lib/python3.8/site-packages/mppsolar/protocols/abstractprotocol.py", line 284, in decode
    key = resp_format[2][j]
IndexError: list index out of range

Since my Inverter is a PIP-MAX8048, I changed the protocol in line 43 to PI30MAX as a test and the inverter is now connected and i get some values 👍 🎉: image How could you make the protocol variable so that you don't have to customize the python file manually? Maybe a .conf file would help? Is it worth a new issue?

I will test your last commit tonight and give you some feedback.

At first glance it looks good and I already have a few additional ideas on how we can extend it, but I'll open separate issues for that, OK?

Thank you very much for your great support!

DarkZeros commented 2 months ago

Im glad that it worked for you! The main idea is that different protocols support different commands, messages, and information. So what can be done is implement a _update() and _change() function per protocol. Right now only the PI30 version is implemented.

If your inverter is detected as PI30MAX in the code like (check /var/log): Connected to inverter on ttyUSB2 (PI30MAX), then it should be easy, just creating a separate PI30MAX function and modifying as needed. If it detects it as PI30, but actually is a different one.... then we might need to have some heuristic.

Config files is just too complicated in my opinion, is better if the code is as generic as possible, and works out of the box with inverters that follow the protocols implemented in the code.

w0vka commented 2 months ago

I tested the latest commit bc4d95f yesterday.

Unfortunately the inverter is recognized with the PI30 protocol, so I had to change the protocol in the file manually. Connected to inverter on ttyUSB1 (PI30) At the moment i can't find any hint for the PI30MAX Protocol to automate the choice.

What I have noticed with the latest commit bc4d95f is, that the data query runs only once and not in a loop.

With the commit 50f2ea7, I get the data continuously, at least for a few hours, but I would open a new issue for the problem

DarkZeros commented 2 months ago

I tested the latest commit bc4d95f yesterday.

Unfortunately the inverter is recognized with the PI30 protocol, so I had to change the protocol in the file manually. Connected to inverter on ttyUSB1 (PI30) At the moment i can't find any hint for the PI30MAX Protocol to automate the choice.

What I have noticed with the latest commit bc4d95f is, that the data query runs only once and not in a loop.

With the commit 50f2ea7, I get the data continuously, at least for a few hours, but I would open a new issue for the problem

Sure lets close this one. I also noticed all my data is broken in the latest commit. I will fix that and add a change in the readme that the installation should be on the first priority

DarkZeros commented 2 months ago

Closing with commit e4774617.

@w0vka this change should work on your inverter out of the box.