question

@carsten2 what re you trying to log? The log file /var/log/dbus-sofarsolar would only hold log messages that have been derived from a service that is started by /service/dbus-sofarsolar/run.

Take a look at any of the other /service directories and your ill see a run file that starts a service, and a log/run that logs the output. So if you have service called dbus-sofarsolar, which is started by /servcie/dbus-sofarsolar/run, the output of that service will be in the relevant log file. Hope that makes sense.

A good resource to look at might be this and the section "Installing a driver that doesn't depend on a serial port". This section also refers out to deamon-tools which is what is using the various run files under the /service directory.

The service works find but does no logging. The processes are:

 4282 root     30836 R    python /opt/victronenergy/dbus-sofarsolar/dbus-sofarsolar.py
 5823 root      1612 S    supervise dbus-sofarsolar
11884 root      1624 S    multilog t s25000 n4 /var/log/dbus-sofarsolar

The file tree looks like this:

root@victron:/service# find dbus-sofarsolar/
dbus-sofarsolar/
dbus-sofarsolar/run
dbus-sofarsolar/supervise
dbus-sofarsolar/supervise/status
dbus-sofarsolar/supervise/ok
dbus-sofarsolar/supervise/control
dbus-sofarsolar/supervise/lock
dbus-sofarsolar/log
dbus-sofarsolar/log/run
dbus-sofarsolar/log/supervise
dbus-sofarsolar/log/supervise/status
dbus-sofarsolar/log/supervise/ok
dbus-sofarsolar/log/supervise/control
dbus-sofarsolar/log/supervise/lock

If I start the dbus-sofarsolar.py from the console, I can see all the logging, but when it is started as a service I see no logging. What can be the cause?

@carsten2 what is the service sending to the log file? If you start it from the command line, what debug does the service provide on the console. It is only output you would see in teh console that would end up in the log file.

Here is the full stripped down source code. The inverter is shown on the Cerbo-Display and the numbers are displayed correctly. When I start the script from the console I see all the logging but when it is started as a service there is no logging at all (but the service works).

#!/usr/bin/env python

from gi.repository import GLib as gobject
from dbus.mainloop.glib import DBusGMainLoop
import dbus
import dbus.service
import platform
import sys
import os
import logging

sys.path.insert(1, os.path.join(os.path.dirname(__file__), '/opt/victronenergy/dbus-modem'))
from vedbus import VeDbusService

logging.basicConfig(level=logging.DEBUG)
logging.info("Testinfo1")
logging.error("Testerror1")
logger=logging

DBusGMainLoop(set_as_default=True)

# Again not all of these needed this is just duplicating the Victron code.
class SystemBus(dbus.bus.BusConnection):
def __new__(cls):
return dbus.bus.BusConnection.__new__(cls, dbus.bus.BusConnection.TYPE_SYSTEM)

class SessionBus(dbus.bus.BusConnection):
def __new__(cls):
return dbus.bus.BusConnection.__new__(cls, dbus.bus.BusConnection.TYPE_SESSION)

def dbusconnection():
return SessionBus() if 'DBUS_SESSION_BUS_ADDRESS' in os.environ else SystemBus()

# Update values
def _update():
try:
dbusservice['pvinverter.pv0']['/Ac/L1/Current'] = 1
dbusservice['pvinverter.pv0']['/Ac/L2/Current'] = 1
dbusservice['pvinverter.pv0']['/Ac/L3/Current'] = 1
dbusservice['pvinverter.pv0']['/Ac/L1/Voltage'] = 220
dbusservice['pvinverter.pv0']['/Ac/L2/Voltage'] = 220
dbusservice['pvinverter.pv0']['/Ac/L3/Voltage'] = 220
dbusservice['pvinverter.pv0']['/Ac/Power'] = 0
dbusservice['pvinverter.pv0']['/Ac/L1/Power'] = 0
dbusservice['pvinverter.pv0']['/Ac/L2/Power'] = 0
dbusservice['pvinverter.pv0']['/Ac/L3/Power'] = 0
dbusservice['pvinverter.pv0']['/Ac/Energy/Forward'] = 10

dbusservice['pvinverter.pv0']['/StatusCode'] = 7
dbusservice['pvinverter.pv0']['/ErrorCode'] = 0
logger.debug("Update finished")
except Exception as ex:
logger.error('exception in _update.' + str(ex))
sys.exit()
return True

def new_service(base, type, physical, id, instance):
self = VeDbusService("{}.{}.{}_id{:02d}".format(base, type, physical, id), dbusconnection())
self.add_path('/Mgmt/ProcessName', __file__)
self.add_path('/Mgmt/ProcessVersion', "1.0")
self.add_path('/Connected', 1)
self.add_path('/HardwareVersion', 0)

_kwh = lambda p, v: (str(v) + 'kWh')
_a = lambda p, v: (str(v) + 'A')
_w = lambda p, v: (str(v) + 'W')
_v = lambda p, v: (str(v) + 'V')
_c = lambda p, v: (str(v) + 'C')

if physical == 'pvinverter':
self.add_path('/DeviceInstance', instance)
self.add_path('/FirmwareVersion', 1)
self.add_path('/DataManagerVersion', 1)
self.add_path('/Serial', 12345)
self.add_path('/Mgmt/Connection', 'TestConnection')
self.add_path('/ProductId', 777)
self.add_path('/ProductName', 'HYD 20KTL3PH')
self.add_path('/CustomName', 'HYD 20KTL3PH' + " WR")
self.add_path('/Ac/Energy/Forward', None, gettextcallback=_kwh)
self.add_path('/Ac/Power', None, gettextcallback=_w)
self.add_path('/Ac/L1/Power', None, gettextcallback=_w)
self.add_path('/Ac/L2/Power', None, gettextcallback=_w)
self.add_path('/Ac/L3/Power', None, gettextcallback=_w)
self.add_path('/Ac/L1/Current', None, gettextcallback=_a)
self.add_path('/Ac/L2/Current', None, gettextcallback=_a)
self.add_path('/Ac/L3/Current', None, gettextcallback=_a)
self.add_path('/Ac/L1/Voltage', None, gettextcallback=_v)
self.add_path('/Ac/L2/Voltage', None, gettextcallback=_v)
self.add_path('/Ac/L3/Voltage', None, gettextcallback=_v)
self.add_path('/Ac/MaxPower', 20000, gettextcallback=_w)
self.add_path('/ErrorCode', 0)
self.add_path('/Position', 0)
self.add_path('/StatusCode', None)
self.add_path('/AllowedRoles', ['grid', 'pvinverter', 'genset', 'acload'])
return self

dbusservice = {} # Dictonary to hold the multiple services
base = 'com.victronenergy'
dbusservice['pvinverter.pv0'] = new_service(base, 'pvinverter.pv0', 'pvinverter', 0, 20)
gobject.timeout_add(1000, _update)
logger.info('Connected to dbus, and switching over to GLib.MainLoop() (= event based)')

mainloop = gobject.MainLoop()
mainloop.run()

Try setting the log to /data/log/dbus-sofarsolar like all other services, not /var/log/dbus-sofarsolar

I found the problem: It was an extra space in the line "#! /bin/sh" of the log-service /service/dbus-sofarsolar/log/run. The services itsself workd but the logging service not. Now everything is working. Thanks for the support.

for the logging I now use the code:

import logging
#logging.basicConfig( level=logging.DEBUG )
logger=logging.getLogger("dbus-sofarsolar")
logger.setLevel(logging.DEBUG)

If the 2nd line is used also, it configures the root logger is configured as debug thus increasing the logging details of all used libraries also.

@carsten2 does the log directory exists.. what is in the log directory file wise?