motoz / PellMon

Logging, monitoring and configuration for pellet burners.
27 stars 14 forks source link

NBE Plugin failure #78

Closed Claws81 closed 6 years ago

Claws81 commented 7 years ago

Hi

Im trying to run Pellmon on OpenSUSE 42.3, but after starting PellMon with:

./pellmonsrv debug -C /home/claus/PellMon/src/pellmon.conf -P /home/claus/PellMon/src/Pellmonsrv/plugins

I get below error repeatedly:

~/PellMon/src> ./pellmonsrv debug -C /home/claus/PellMon/src/pellmon.conf -P /home/claus/PellMon/src/Pellmonsrv/plugins
No option 'plugin_dirs' in section: 'plugin_settings'
2017-09-25 14:39:37,310 - INFO - invalid setting for plugin_dirs
2017-09-25 14:39:37,311 - INFO - starting PellMon
2017-09-25 14:39:37,311 - INFO - Looking for plugins in /home/claus/PellMon/src/Pellmonsrv/plugins
/home/claus/PellMon/src/Pellmonsrv/plugins/testplugin/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/calculate/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/exec/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/openweathermap/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/scottecom/__init__
No module named serial
/home/claus/PellMon/src/Pellmonsrv/plugins/nbecom/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/heatingcircuit/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/raspberrygpio/__init__
No module named RPi.GPIO
/home/claus/PellMon/src/Pellmonsrv/plugins/pelletcalc/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/cleaning/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/onewire/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/consumption/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/silolevel/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/customalarms/__init__
/home/claus/PellMon/src/Pellmonsrv/plugins/owfs/__init__
2017-09-25 14:39:37,352 - INFO - Activated plugins: SiloLevel, Consumption, Cleaning, NBEcom
get rsa 0
use rsa for xtea set 2377
wait controller
2017-09-25 14:39:38,352 - INFO - Connected to S/N 24706 on 10.0.0.23
other exc 97 2381 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
other exc 98 2381 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
get retry 1 2381
other exc 99 2381 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
get retry 2 2381
other exc 0 2381 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
get retry 3 2381
other exc 1 2381 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
get retry 4 2381
other exc 2 2382 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
get retry 5 2382
other exc 4 2382 'ascii' codec can't decode byte 0xc3 in position 848: ordinal not in range(128)
get retry 6 2382
no more get retry

Regards,

Claus

motoz commented 7 years ago

Probably this line: https://github.com/motoz/PellMon/blob/3e2511ada9e2cd5715c5c9ad67f45a41ef8d82f3/src/Pellmonsrv/plugins/nbecom/nbeprotocol/frames.py#L173

You could try some extended character set just to see what happens: self.payload = (record[i:i+self.size]).decode('latin1')

motoz commented 7 years ago

What version do you have in your controller? I don't see this issue at all so it's hard to do anything about it. Can you try to edit the code in frames.py to see if that changes anything?

Claws81 commented 7 years ago

Hi

The edit of frames.py as you suggested, worked well and cleared the error. Now I have a different one:

get rsa 0
use rsa for xtea set 1726
wait controller
get retry 1 1730
get retry 2 1731
get retry 3 1731
get retry 4 1731
get retry 5 1731
get retry 6 1732
no more get retry
protocol_error() direrror

Log file with 'debug' enabled:

2017-09-30 19:28:46,346 - DEBUG - error in [pollvalues]: d11 missing, written as undefined
2017-09-30 19:28:46,347 - DEBUG - error in [pollvalues]: d12 missing, written as undefined
2017-09-30 19:28:46,347 - DEBUG - error in [pollvalues]: d13 missing, written as undefined
2017-09-30 19:28:46,347 - DEBUG - error in [pollvalues]: d14 missing, written as undefined
2017-09-30 19:28:46,348 - DEBUG - error in [pollvalues]: d15 missing, written as undefined
2017-09-30 19:28:46,348 - DEBUG - Polling is on
2017-09-30 19:28:46,350 - INFO - invalid setting for plugin_dirs
2017-09-30 19:28:46,351 - INFO - starting PellMon
2017-09-30 19:28:46,351 - INFO - Looking for plugins in /home/pi/PellMon/src/Pellmonsrv/plugins
2017-09-30 19:28:46,354 - DEBUG - PluginManager walks into directory: /home/pi/PellMon/src/Pellmonsrv/plugins
2017-09-30 19:28:46,356 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/cleaning.pellmon-plugin
2017-09-30 19:28:46,357 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/pelletcalc.pellmon-plugin
2017-09-30 19:28:46,359 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/silolevel.pellmon-plugin
2017-09-30 19:28:46,361 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/scottecom.pellmon-plugin
2017-09-30 19:28:46,363 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/raspberrygpio.pellmon-plugin
2017-09-30 19:28:46,365 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/customalarms.pellmon-plugin
2017-09-30 19:28:46,367 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/consumption.pellmon-plugin
2017-09-30 19:28:46,369 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/nbecom.pellmon-plugin
2017-09-30 19:28:46,371 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/heatingcircuit.pellmon-plugin
2017-09-30 19:28:46,373 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/exec.pellmon-plugin
2017-09-30 19:28:46,375 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/testplugin.pellmon-plugin
2017-09-30 19:28:46,377 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/calculate.pellmon-plugin
2017-09-30 19:28:46,379 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/owfs.pellmon-plugin
2017-09-30 19:28:46,381 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/openweathermap.pellmon-plugin
2017-09-30 19:28:46,383 - DEBUG - PluginManager found a candidate: 
    /home/pi/PellMon/src/Pellmonsrv/plugins/onewire.pellmon-plugin
2017-09-30 19:28:46,791 - INFO - Activated plugins: SiloLevel, Consumption, Cleaning, NBEcom
2017-09-30 19:28:46,869 - DEBUG - handlerTread started by signal handler
2017-09-30 19:28:46,870 - DEBUG - created signalhandler
2017-09-30 19:28:46,874 - DEBUG - started timer
2017-09-30 19:28:47,792 - INFO - Connected to S/N 24706 on 10.0.0.23
2017-09-30 19:28:50,375 - DEBUG - last month: 0, last week: 0
2017-09-30 19:28:50,376 - DEBUG - last month estimate from last week * 4: 0

The version of my controller is 7.0640

What other information is useful?

Regards, Claus

motoz commented 7 years ago

I don't really know, I'm still on 7.0639 myself. First you could try the simpler 'nbetest' program to see if you have any more luck with that, it's a least simpler to debug than using the full pellmon program. https://github.com/motoz/nbetest.

Claws81 commented 7 years ago

The nbetest program works well. Autodiscovery finds the boiler and I can read data out. Anything I can do to troubleshoot?

motoz commented 7 years ago

That's strange, nbetest and the nbecom plugin uses more or less the same code. But since you have pellmon setup so you can run it in debug mode then it's easy to add print statements to the code to see what's happening. For instance you could add this frames.py before the failing .decode('ascii') statement:

print [ord(ch) for ch in record]

to see the exact contents of the frame.

motoz commented 7 years ago

Since it looks like it's the Proxy.dir() method in protocol.py that fails, you could intrument it with a couple of print statements like this:

    def dir(self):
        dirlist = []
        for s in self.settings:
            print 'try to get: ', s # Add this line
            dl = self.get(3, s+'.*', group=True)
            print 'received: ', dl # And this line
            for d in dl:
Claws81 commented 7 years ago

Hi Could you provide a quick example of how to inset that snippet into protocol.py? I have zero Python experience and get indentation errors. Thanks :)

motoz commented 7 years ago

Yeah I know, python is picky about indentation. But the example i provided above already has the correct indentation on every row, so copy pasting the print rows should work, as long as you copy the whole row including the spaces. If you indent yourself then us spaces instead of tabs (I do that and they shouldn't be mixed) and use simple text editor instead of something like a word processor and it should work.

Claws81 commented 7 years ago

Okay, then Im doing something else wrong :) Snip from line ~68:

    def get_rsakey(self):
        if hasattr(self.request, 'public_key'):
            return True
        if not self.controller_online:
            return False
        for retry in range(3):
            try:
                print 'get rsa', retry
                r = self.get(1, 'misc.rsa_key')
                key = base64.b64decode(r)
                self.request.public_key = RSA.importKey(key)
                return True 
            except Exception as e:
                print 'other except, get_rsakey', repr(e), time.time()
                pass # retry 3 times
            time.sleep(1)
        return False

    def dir(self):
        dirlist = []
        for s in self.settings:
            print 'try to get: ', s # Add this line
            dl = self.get(3, s+'.*', group=True)
            print 'received: ', dl # And this line
            for d in dl:

    def set_xteakey(self):
        xtea_key = ''.join([chr(SystemRandom().randrange(128)) for x in range(16)])
        try:
            self.set('misc.xtea_key', xtea_key)
        except protocol_error:
            logger.info('Key exchange failed, wrong password?')

..yields the following error:

Traceback (most recent call last):
  File "./pellmonsrv", line 22, in <module>
    pellmonsrv.run()
  File "/home/pi/PellMon/src/Pellmonsrv/pellmonsrv.py", line 850, in run
    commands[args.command]()
  File "/home/pi/PellMon/src/Pellmonsrv/pellmonsrv.py", line 437, in run
    conf.database = Database()
  File "/home/pi/PellMon/src/Pellmonsrv/pellmonsrv.py", line 89, in __init__
    plugin.plugin_object.activate(conf.plugin_conf[plugin.name], globals(), self)
  File "/home/pi/PellMon/src/Pellmonsrv/plugins/nbecom/__init__.py", line 38, in activate
    from nbeprotocol.protocol import Proxy
  File "/home/pi/PellMon/src/Pellmonsrv/plugins/nbecom/nbeprotocol/protocol.py", line 96
    def set_xteakey(self):
    ^
IndentationError: expected an indented block
motoz commented 7 years ago

You should just add those two rows starting with 'print' that are commented with Add this line and And this line

You have erased the rest of the 'dir' method, so it's complaining the the last row of the function "for d in dl:" isn't indented correctly because it is the start of a loop, and you are missing the rest of the loop.

I should have been more specific, of course everyone can't know every programming language. Hopefully we get this sorted out, I really have no idea whats failing.

Btw, did you see the 'contributing' page in the wiki, it has section describing how to setup Pellmon for debugging. You already found out the command line options required to make it work but there is an easier way described in the wiki.

Claws81 commented 7 years ago

Ah okay, I misunderstood :) This is the output I get now:

get rsa 0
use rsa for xtea set 1632
wait controller
try to get:  boiler
received:  ['temp=0,85,70,0', 'diff_over=10,20,10,0', 'diff_under=0,50,5,0', 'reduction=0,30,0,0', 'ext_stop_temp=0.0,99.9,0.0,1', 'ext_stop_diff=1.0,99.9,1.0,1', 'ext_switch=0,1,0,0', 'ext_off_delay=1,60,1,0', 'ext_on_delay=1,60,1,0', 'timer=0,1,0,0', 'monday=000000000000,222222222222,000000000000,000000000000', 'tuesday=000000000000,222222222222,000000000000,000000000000', 'wednesday=000000000000,222222222222,000000000000,000000000000', 'thursday=000000000000,222222222222,000000000000,000000000000', 'friday=000000000000,222222222222,000000000000,000000000000', 'saturday=000000000000,222222222222,000000000000,000000000000', 'sunday=000000000000,222222222222,000000000000,000000000000', 'min_return=0,75,0,0']
try to get:  hot_water
received:  ['temp=0,70,0,0', 'diff_under=5,30,10,0', 'dhw_remain=0,15,10,0', 'output=0,20,0,0', 'dwh_weather=0,3,0,0', 'dwh_weather2=0,3,0,0', 'timer=0,1,0,0', 'monday=000000000000,111111111111,000000000000,000000000000', 'tuesday=000000000000,111111111111,000000000000,000000000000', 'wednesday=000000000000,111111111111,000000000000,000000000000', 'thursday=000000000000,111111111111,000000000000,000000000000', 'friday=000000000000,111111111111,000000000000,000000000000', 'saturday=000000000000,111111111111,000000000000,000000000000', 'sunday=000000000000,111111111111,000000000000,000000000000']
try to get:  regulation 
-etc.
-etc.
get retry 1 1636
get retry 2 1636
get retry 3 1637
get retry 4 1637
get retry 5 1637
get retry 6 1637
no more get retry
protocol_error() direrror

Pellmon is configured with --enable-debug and is run from sources.

motoz commented 7 years ago

Ok, so far so good, the controller responds exactly like it should. Then you can remove those prints and add a new one further down in the same function after the next self.get:

        dl = self.get(5, '*', group=True)
        print dl

If it prints something, then repeat at the next get, so we find out which 'get' isn't getting a response.

Claws81 commented 7 years ago

Strange results. First test gave a verbose output, but after testing the next 'get' function, both situations now give the same output, with the occasional "timeout, func: 3 missed seqnum: 88 3416" error. See last log.

first 'get'

get rsa 0
use rsa for xtea set 2989
wait controller
get retry 1 2992
get retry 2 2993
get retry 3 2993
get retry 4 2993
get retry 5 2994
get retry 6 2994
no more get retry
protocol_error() direrror
get retry 1 2997
get retry 2 2997
get retry 3 2997
get retry 4 2998
timeout, func: 5 missed seqnum: 51 2998
get retry 5 2998
get retry 6 2999
no more get retry
protocol_error() direrror
timeout, func: 3 missed seqnum: 58 3001
timeout, func: 3 missed seqnum: 59 3001
get retry 1 3001
find controller retry 0 timeout('timed out',)
timeout, func: 3 missed seqnum: 61 3002
get retry 2 3002
timeout, func: 3 missed seqnum: 62 3003
get retry 3 3003
seqnum error 3 seqnum_error('---seqnum, res:58 req:63',) 3003
seqnum error 3 seqnum_error('---seqnum, res:59 req:63',) 3003
seqnum error 3 seqnum_error('---seqnum, res:60 req:63',) 3003
seqnum error 3 seqnum_error('---seqnum, res:61 req:63',) 3004
seqnum error 3 seqnum_error('---seqnum, res:62 req:63',) 3004
get retry 1 3005
get retry 2 3005
get retry 3 3006
get retry 4 3006
get retry 5 3006
get retry 6 3006
no more get retry
protocol_error() direrror

retesting:

get rsa 0
use rsa for xtea set 97
wait controller
get retry 1 101
get retry 2 101
get retry 3 102
get retry 4 102
get retry 5 102
get retry 6 102
no more get retry
protocol_error() direrror

hmm?

motoz commented 7 years ago

Try adding a 'print response' in the 'get' method

    def get(self, function, path, group=False):
        if not self.controller_online:
            raise protocol_offline('controller offline')
        for retry in range(7):
            try:
                with self.lock:
                    response = self.make_request(function, path)
                    print response
Claws81 commented 7 years ago
get rsa 0
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
use rsa for xtea set 1091
wait controller
timeout, func: 3 missed seqnum: 62 1093
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
get retry 1 1095
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
get retry 2 1096
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
get retry 3 1096
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
get retry 4 1096
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
get retry 5 1096
<nbeprotocol.frames.Response_frame object at 0x75a8b930>
get retry 6 1097
no more get retry
protocol_error() direrror
motoz commented 7 years ago

I'm sorry, I meant "print response.payload" :(

Claws81 commented 7 years ago

Alright :) Then I get this and the rest of the boiler info

get rsa 0
rsa_key=MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAKr3EOhDukLH0syjRrMQ5iEBzrkOcM3NAcyz3n5Q2XdDSjxe5JT44cZqnbhN8RNHkONO7RcWv9Ytrg3lcJtiwwECAwEAAQ==
use rsa for xtea set 1761
wait controller
temp=0,85,70,0;diff_over=10,20,10,0;diff_under=0,50,5,0;reduction=0,30,0,0;ext_stop_temp=0.0,99.9,0.0,1;ext_stop_diff=1.0,99.9,1.0,1;ext_switch=0,1,0,0;ext_off_delay=1,60,1,0;ext_on_delay=1,60,1,0;timer=0,1,0,0;monday=000000000000,222222222222,000000000000,000000000000;tuesday=000000000000,222222222222,000000000000,000000000000;wednesday=000000000000,222222222222,000000000000,000000000000;thursday=000000000000,222222222222,000000000000,000000000000;friday=000000000000,222222222222,000000000000,000000000000;saturday=000000000000,222222222222,000000000000,000000000000;sunday=000000000000,222222222222,000000000000,000000000000;min_return=0,75,0,0
motoz commented 7 years ago

The important thing is what does it print before the 'get retry', ie. what does it not understand and tries again.

Claws81 commented 7 years ago

Ah ok.

get rsa 0
rsa_key=MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAKr3EOhDukLH0syjRrMQ5iEBzrkOcM3NAcyz3n5Q2XdDSjxe5JT44cZqnbhN8RNHkONO7RcWv9Ytrg3lcJtiwwECAwEAAQ==
use rsa for xtea set 2069
wait controller
temp=0,85,70,0;diff_over=10,20,10,0;diff_under=0,50,5,0;reduction=0,30,0,0;ext_stop_temp=0.0,99.9,0.0,1;ext_stop_diff=1.0,99.9,1.0,1;ext_switch=0,1,0,0;ext_off_delay=1,60,1,0;ext_on_delay=1,60,1,0;timer=0,1,0,0;monday=000000000000,222222222222,000000000000,000000000000;tuesday=000000000000,222222222222,000000000000,000000000000;wednesday=000000000000,222222222222,000000000000,000000000000;thursday=000000000000,222222222222,000000000000,000000000000;friday=000000000000,222222222222,000000000000,000000000000;saturday=000000000000,222222222222,000000000000,000000000000;sunday=000000000000,222222222222,000000000000,000000000000;min_return=0,75,0,0
temp=0,70,0,0;diff_under=5,30,10,0;dhw_remain=0,15,10,0;output=0,20,0,0;dwh_weather=0,3,0,0;dwh_weather2=0,3,0,0;timer=0,1,0,0;monday=000000000000,111111111111,000000000000,000000000000;tuesday=000000000000,111111111111,000000000000,000000000000;wednesday=000000000000,111111111111,000000000000,000000000000;thursday=000000000000,111111111111,000000000000,000000000000;friday=000000000000,111111111111,000000000000,000000000000;saturday=000000000000,111111111111,000000000000,000000000000;sunday=000000000000,111111111111,000000000000,000000000000
boiler_gain_p=0.5,20.0,2.5,1;boiler_gain_i=0.05,10.00,0.10,2;power_per_minute=1,10,10,0;boiler_power_min=10,100,10,0;boiler_power_max=10,100,100,0;dhw_gain_p=0.5,20.0,5.0,1;dhw_gain_i=0.05,10.00,0.10,2;dhw_setpoint_addition=5,30,20,0;dhw_power_min=10,100,10,0;dhw_power_max=30,100,100,0
output_up=0,20,0,0;output_down=0,20,0,0;output_pump=0,20,0,0;active=0,1,0,0;avg_out_time=0,48,24,0;input_forward=0,20,0,0;chill_weight=0,150,0,0;gain_p=0.1,10.0,1.0,1;ref_1=-50.0,50.0,16.0,1;ref_2=-50.0,50.0,15.0,1;ref_3=-50.0,50.0,10.0,1;ref_4=-50.0,50.0,5.0,1;ref_5=-50.0,50.0,0.0,1;ref_6=-50.0,50.0,-5.0,1;ref_7=-50.0,50.0,-10.0,1;temp_1=0.0,100.0,45.0,1;temp_2=0.0,100.0,45.0,1;temp_3=0.0,100.0,50.0,1;temp_4=0.0,100.0,55.0,1;temp_5=0.0,100.0,60.0,1;temp_6=0.0,100.0,65.0,1;temp_7=0.0,100.0,70.0,1;pow_1=0,100,0,0;pow_2=0,100,50,0;pow_3=0,100,100,0;pow_4=0,100,100,0;pow_5=0,100,100,0;pow_6=0,100,100,0;pow_7=0,100,100,0;input_reference=0,20,0,0
output_up=0,20,0,0;output_down=0,20,0,0;output_pump=0,20,0,0;active=0,1,0,0;avg_out_time=0,48,24,0;input_forward=0,20,0,0;chill_weight=0,150,0,0;gain_p=0.1,10.0,1.0,1;ref_1=-50.0,50.0,16.0,1;ref_2=-50.0,50.0,15.0,1;ref_3=-50.0,50.0,10.0,1;ref_4=-50.0,50.0,5.0,1;ref_5=-50.0,50.0,0.0,1;ref_6=-50.0,50.0,-5.0,1;ref_7=-50.0,50.0,-10.0,1;temp_1=0.0,100.0,45.0,1;temp_2=0.0,100.0,45.0,1;temp_3=0.0,100.0,50.0,1;temp_4=0.0,100.0,55.0,1;temp_5=0.0,100.0,60.0,1;temp_6=0.0,100.0,65.0,1;temp_7=0.0,100.0,70.0,1;pow_1=0,100,0,0;pow_2=0,100,50,0;pow_3=0,100,100,0;pow_4=0,100,100,0;pow_5=0,100,100,0;pow_6=0,100,100,0;pow_7=0,100,100,0;input_reference=0,20,0,0
regulation=0,2,0,0;o2_low=10.0,21.0,17.0,1;o2_medium=6.0,17.0,12.0,1;o2_high=1.0,12.0,8.0,1;start_calibrate=0,240,0,0;calibration_number=50,200,0,0;block_time=1,30,10,0;regulation_time=5,120,30,0;fan_gain_p=0.10,20.00,5.00,2;fan_gain_i=0.00,9.95,0.20,2;corr_fan_10=0,100,30,0;corr_fan_50=0,100,30,0;corr_fan_100=0,100,30,0;pellets_gain_p=0.00,1.00,0.50,2;pellets_gain_i=0.00,1.00,0.05,2;lambda_type=0,2,1,0;lambda_expansion_module=0,1,0,0
output_ash=0,20,0,0;output_burner=0,20,0,0;output_boiler1=0,20,0,0;output_boiler2=0,20,0,0;fan_period=0,120,10,0;fan_time=0,99,3,0;fan_speed=0,100,50,0;comp_period=0,9999,30,0;valve_period=2.0,20.0,6.0,1;valve_time=0.2,2.0,0.2,1;pellets_stop=0,999,360,0;comp_fan_speed=0,100,50,0;pressure_t7=0,1,0,0
content=-30000,30000,0,0;min_content=0,500,0,0;auger_capacity=200,19999,1800,0;trip1=0,32500,0,0;trip2=0,0,0,0;distance_top=0,500,5,0;distance_bottom=0,500,5,0;auto_fill=0,30000,0,0;distance_sensor=0,1,0,0
output_exhaust=0,20,0,0;speed_10=5,50,12,0;speed_50=5,75,20,0;speed_100=5,100,30,0;use_fan_rpm=0,1,0,0;alarm_fan_rpm=0,1,0,0;alarm_fan_current=0,1,0,0;exhaust_10=0,100,38,0;exhaust_50=0,100,50,0;exhaust_100=0,100,60,0
forced_run=0,600,0,0;auger_capacity=200,19999,1800,0;auto_calculation=0,1,1,0;auger_10=0.50,25.00,1.75,2;auger_50=1.0,75.0,0.0,1;auger_100=1.0,100.0,17.5,1;kw_min=0.5,50.0,2.0,1;kw_max=5,250,10,0;runs_minute=1,6,3,0;min_dose=1.0,200.0,5.0,1
pellets=40.0,200.0,60.0,1;power=30,100,50,0;fan_10=5,100,30,0;fan_50=5,100,20,0;fan_100=5,100,40,0;max_time=5,15,6,0;preheat_time=0,300,30,0;exhaust_speed=0,100,50,0;ignition_number=0,0,0,0;clear_ignitions=0,1,0,0
output=0,20,0,0;start_temp_run=0,85,30,0;start_temp_idle=0,85,50,0;flow_liters=0,100,1,0;flow_freq=0.0,9.9,4.5,1
collector_temp=0,100,70,0;pump_start_diff=1,20,10,0;pump_stop_diff=1,20,5,0;pump_min_speed=10,100,100,0;dhw_max_temp=0,100,75,0;output_pump=0,20,0,0;output_excess=0,20,0,0;input_collector=0,20,0,0;input_collector_2=0,20,0,0;input_dhw=0,20,0,0;input_excess=0,20,0,0;flow_liters=1,1000,10,0
run_24h=0,0,0,0
dl_version=0,9999,0,0;shaft_sensor=0,1,0,0;smoke_sensor=0,1,0,0;expansion_module=0,1,0,0;clock_year=0,99,15,0;clock_month=1,12,1,0;clock_date=1,31,1,0;clock_hour=0,23,0,0;clock_minute=0,59,0,0;clock_second=0,59,0,0;clock_changed=0,1,0,0;start=0,1,0,0;stop=0,1,0,0;reset_alarm=0,1,0,0;push_version=0,0,0,0;push_prog_size=0,0,0,0;rsa_key=0,0,0,0;push_picture=0,0,0,0;commit_picture=0,9999,0,0;fahrenheit=0,1,0,0;xtea_key=0,0,0,0;dummy=0,32000,0,0
output=0,20,0,0;min_boiler_temp=0,50,30,0;max_shaft_temp=50,80,60,0
manual_mode=0,1,0,0;output_std=0,1023,0,0;output_ext=0,1023,0,0;output_wireless=0,1023,0,0;keep_alive=0,1,0,0
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
get retry 1 2074
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
get retry 2 2074
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
get retry 3 2074
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
get retry 4 2075
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
get retry 5 2075
mean2_out_temp=13.9;forward2_ref=0.0;house2_valve_state=0;chill2_out=13.9;forward2_temp=999.9;boiler_setpoint=60.0;boiler_diff=34.6;boiler_diffsum=224.9;boiler_gain_p=0.0;boiler_gain_i=0.00;boiler_part_p=0;boiler_part_i=0;boiler_power_total=0;boiler_power_actual=39;boiler_power_kw=6.8;dhw_diff=34.6;dhw_diffsum=0.0;dhw_gain_p=0.0;dhw_gain_i=0.00;dhw_part_p=0;dhw_part_i=0;dhw_power_total=0;dhw_power_actual=0;dhw_power_kw=0.0;dhw_boiler_setpoint=60.0;o2_corr_low=98.24;o2_corr_medium=97.70;o2_setpoint=20.9;o2_diff=0.8;o2_diffsum=45.9;o2_gain_p=5.00;o2_gain_i=0.20;o2_part_p=0.0;o2_part_i=0.0;o2_power_total=0.0;o2_power_max=0.0;o2_power_actual=0.0;o2_gain_pellets=0.0;o2_corr_high=98.45;auger_run=0.0;auger_pause=0.0;dhw_consumption_24hours=0;total_consumption_24hours=111;dhw_part_24hours=0;o2_gain_pellets_i=0.00;program_version=640;city=Langå;humidity=87;air_pressure=1004;wind_speed=3.60;wind_direction=220;clouds=75;outdoor_temp=14.00
get retry 6 2076
no more get retry
protocol_error() direrror
motoz commented 7 years ago

Yeah, it's this: city=Lang�¥ Your 'city' messes up my program, maybe you could consider moving to someplace where the cityname fits into the first 127 characters in the ascii table? :-)

Jokes aside, it's most probably utf-8 encoded. This is probably not this simple, but you could try changing both encode('ascii') to encode('utf-8') in the get function and see what happens.

Claws81 commented 7 years ago

There we go :) I shall consider moving, meanwhile the pellmonsrv now starts and pellmonweb generates a webpage. However, no information is printed on webpage, except auger capacity. State is OK, I can read out the parameters, but kW is '--' and temp is '--'

Output from pellmonsrv

get rsa 0
use rsa for xtea set 3006
wait controller
timeout, func: 1 missed seqnum: 71 3050
timeout, func: 1 missed seqnum: 10 3090
timeout, func: 1 missed seqnum: 3 3170
timeout, func: 1 missed seqnum: 52 3178

I don't know if this is related to the encoding though.

motoz commented 7 years ago

It's actually normal for it to miss a couple of frames every now and then. So you have all settings/data in the parameters view? The 'city' should be under 'Advanced data', is that displayd correctly?

The system image on the frontpage is made for a V6 controller, so it needs to be modified to fit the data that the NBECom plugin provides. The wiki has some info on that, and the ID:s can be found from the parameters view.

Claws81 commented 7 years ago

It is displayed like this "city Langå".

What section am I looking for in the wiki?

motoz commented 7 years ago

This page: https://github.com/motoz/PellMon/wiki/Custom-system-image

But I almost forgot, I added a system image suitable for use with the NBECom plugin in the latest release, so you just have to switch the default system image to system_nbe_v7.svg in webinterface.conf

Claws81 commented 7 years ago

Cool. That is a really convenient way to create and update the system view. I've already have it displaying all the data I am interested in. I also got the graph going just now, by uncommenting the parameters in database.conf. One thing that hasn't worked yet, is the logview tab. What file is it looking for here?

motoz commented 7 years ago

Great. You should have the path to the log file in your configuration, just make sure it's pointing somewhere you have write access. The configure --enable_debug and make should set it up to 'just work'. Btw you shouldn't have to give any options to pellmonsrv to start it (other than the 'debug' command if you want it to run in the foreground)

Claws81 commented 7 years ago

Weird. I haven't changed anything with regards to logging, and the logfile below is fed with state changes ok, but there is no log showing in the webpage.

/home/pi/PellMon/src/dev_var/log/pellmonsrv/pellmon.log

When I change to the log tab, the webserver receives this: 10.0.0.2 - - [03/Oct/2017:15:04:40] "GET /logview/logView HTTP/1.1" 200 3391 "http://10.0.0.4:8081/" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0 ...but returns nothing apparently Anywhere I can look for errors?

motoz commented 7 years ago

Something about your debug setup. How do you start pellmonweb? And why do you start pellmonsrv with the -C and-P options? Doesn't it work without them?

motoz commented 7 years ago

Weird, I checked and I had the same behaviour after --enable-debug, and it was due to '/home' missing from the logfile path in the generated pellmon.conf file. After adding '/home' it worked, and then I tried cleaning the project and doing ./autogen.sh&&./configure --enable-debug&&make again and then the path was correct. Strange...

Claws81 commented 7 years ago

I have started it in different ways while I was messing around with it. Right now, I have tried a system install. /etc/pellmon/pellmon.conf log points to /var/log/pellmonsrv/pellmon.log (I corrected it from /usr/var/log...) and I've made sure all users have read/write permissions. The log is updated on startup, but pellmonweb does not show log or events. I started pellmonweb with the -C parameter to make sure it reads /etc/pellmon/pellmon.conf, but no success. I've enabled the error.log in webinterfaceconf and made sure the permissions are correct, but theres no output in that file.

motoz commented 7 years ago

Well I suppose you have to start instrumenting pellmonweb.py with print statements then to see what happens. Here it retreives the config file name from the arguments, the default is 'pellmon.conf' if not given: https://github.com/motoz/PellMon/blob/3e2511ada9e2cd5715c5c9ad67f45a41ef8d82f3/src/Pellmonweb/pellmonweb.py#L760

Then, if started with the 'user' argument (ie. it must be running as root, otherwise it can't switch user), it will append the config file name to CONFDIR to retreive the full path to the installed config file. Here you could add a print config_file https://github.com/motoz/PellMon/blob/3e2511ada9e2cd5715c5c9ad67f45a41ef8d82f3/src/Pellmonweb/pellmonweb.py#L768

The logfile setting is read from the config here: https://github.com/motoz/PellMon/blob/3e2511ada9e2cd5715c5c9ad67f45a41ef8d82f3/src/Pellmonweb/pellmonweb.py#L883

Add a print logfile after the exception clause to see what it found.

The contents of the logfile is not returned in the GET /logview/logView request, instead the response body contains a call to a javascript function that calls GET /logview/getlines to populate the log. The server endpoint of that request is here: https://github.com/motoz/PellMon/blob/3e2511ada9e2cd5715c5c9ad67f45a41ef8d82f3/src/Pellmonweb/logview.py#L44 where you can add some print statement to see what happens, for instance print self.logfile to see where it's trying to read the logfile.

The 'system installation' places two init scripts made to work with a debian based distro in /etc/init.d (pellmonsrv and pellmonweb). These may or may not work with openSUSE, I have never tried pellmon with any rpm-based distro. They should be converted to systemd unit files at some point to get rid of such problems.

Claws81 commented 7 years ago

I should have mentioned earlier, that I switched to my Raspberry to make sure we were working on the same platform. I've added the lines to pellmonweb.py and logview.py and the output is below. Notice the "exception in thread" does not happen when I just run it as user 'pi':

root@raspberrypi:/# pellmonweb -U pi
/etc/pellmon/pellmon.conf
/var/log/pellmonsrv/pellmon.log
[05/Oct/2017:11:44:53] ENGINE Bus STARTING
[05/Oct/2017:11:44:53] ENGINE Starting WebSocket processing
[05/Oct/2017:11:44:53] ENGINE Started monitor thread 'Autoreloader'.
[05/Oct/2017:11:44:53] ENGINE PID 3039 written to '/tmp/pellmonweb.pid'.
[05/Oct/2017:11:44:53] ENGINE Started monitor thread '_TimeoutMonitor'.
[05/Oct/2017:11:44:53] ENGINE Serving on http://0.0.0.0:8081
[05/Oct/2017:11:44:53] ENGINE Started as uid: 'root' gid: 'root'
[05/Oct/2017:11:44:53] ENGINE Running as uid: 'pi' gid: 'nogroup'
[05/Oct/2017:11:44:53] ENGINE umask old: 022, new: 033
[05/Oct/2017:11:44:53] ENGINE Bus STARTED
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/dist-packages/ws4py/manager.py", line 303, in run
    for fd in polled:
  File "/usr/lib/python2.7/dist-packages/ws4py/manager.py", line 138, in poll
    events = self.poller.poll(timeout=self.timeout)
IOError: [Errno 4] Interrupted system call

server is running
[05/Oct/2017:11:45:00] ENGINE Started monitor thread 'Session cleanup'.
10.0.0.2 - - [05/Oct/2017:11:45:01] "GET / HTTP/1.1" 200 10718 "http://10.0.0.4:8081/logview/logView" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
10.0.0.2 - - [05/Oct/2017:11:45:02] "GET /systemimage?rand=0.988237991263 HTTP/1.1" 200 46228 "http://10.0.0.4:8081/" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
10.0.0.2 - - [05/Oct/2017:11:45:02] "GET /consumptionview/flotconsumption24h?_=1507196702279 HTTP/1.1" 200 847 "http://10.0.0.4:8081/" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
10.0.0.2 - - [05/Oct/2017:11:45:02] "GET /flotsilolevel?_=1507196702280 HTTP/1.1" 200 1435 "http://10.0.0.4:8081/" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
10.0.0.2 - - [05/Oct/2017:11:45:03] "GET /export?width=1140&timeoffset=0&_=1507196702281 HTTP/1.1" 200 24975 "http://10.0.0.4:8081/" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
10.0.0.2 - - [05/Oct/2017:11:45:03] "GET /websocket/ws/?parameters=operating_data-shaft_temp,operating_data-photo_level,operating_data-off_on_alarm,operating_data-smoke_temp,operating_data-state,operating_data-boiler_temp,operating_data-power_kw,operating_data-power_pct,hopper-content,operating_data-dhw_temp,operating_data-return_temp,operating_data-flow1,advanced_data-outdoor_temp,feeder_capacity,operating_data-substate,consumption_data-counter,operating_data-boiler_ref&events=yes HTTP/1.1" 101 - "" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
10.0.0.2 - - [05/Oct/2017:11:45:06] "GET /logview/logView HTTP/1.1" 200 3391 "http://10.0.0.4:8081/" "Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
motoz commented 7 years ago

I don't see any printsouts, you probably still have the system installations left so it's using the installed python modules instead of the local ones you edited. You need to uninstall first. Since you are on a rasberry now, did you try the .deb file? I assume you mean 'sudo make install' by system install?

Claws81 commented 7 years ago

Actually, it prints out the paths in the beginning

root@raspberrypi:/# pellmonweb -U pi
/etc/pellmon/pellmon.conf
/var/log/pellmonsrv/pellmon.log

Yes, I tried the .deb file earlier, but reverted to source files to debug. I've installed with sudo make install and I've renamed the source folder, so Pellmon doesn't accidentally grab the old files.

I put in the print statement like this:

    global logfile
    try:
        logfile = parser.get('conf', 'logfile')
    except:
        logfile = None
    print logfile
motoz commented 7 years ago

Seems I'm going blind... Yes it's there. But it still seems to be some mixups between the debug env and the installed system. Normally when I do a configure --enable-debug&&make I get a system where pellmon.conf is set up like this:

[conf]
# Read all *.conf files found in and below the "config_dir" directory
config_dir = /home/anders/Documents/PellMon/src/conf.d.dev

# Full path to the logfile
logfile = /home/anders/Documents/PellMon/src/dev_var/log/pellmonsrv/pellmon.log

# logging level = info/debug
loglevel = info

Where everything is setup to run below the source directory with the configuration in conf.d.dev/... and logfile in dev_var/... dev/var and the logfile is created when pellmonsrv is started.

Do you have a src/Pellmonsrv/directories.py file? That one is created when installing, if you still have it from the installation you did then maybe you shold delete it, otherwise is probably will pick up the directories used by an installed system from there. Or try from the beginning with a clean source checkout and just ./autogen.sh&&./configure --enable-debug&&make then

cd src
./pellmonsrv debug

And in another terminal ./pellmonweb (with the dbus session bus started according to the wiki if you are running in an ssh session)

Still works for me (even though I have not looked at this project for a while so I seem to have forgotten a lot of what I have done...)

Claws81 commented 7 years ago

Hi

I went back to square one; I deleted everything related to pellmon on the system, and cloned git again, and added the fixes for the encoding and left everything else I could alone. Created with "./autogen.sh&&./configure --enable-debug&&make" A log is being generated in "/home/pi/PellMon/src/dev_var/log/pellmonsrv/pellmon.log"

pellmonweb and pellmonsrc is running generating the page, but log and 'events' are still not displayed.

The session is over VNC, so it should be in a native environment. hmm

Claws81 commented 7 years ago

Grrrr! The missing log and events was caused by uBlock origin and Adblock plus ! That was a bit unexpected, but now everything seems to work as it should :) Thank you for your patience and fast responses :)

motoz commented 7 years ago

Ok, that explains it. Probably not adblock plus, since I have been using that on all my computer for many years, so more likely uBlock origin.

Could you do a git diff where you have the nbeplugin working and post the output, I'll have to sort out the unicode encode/decode mess at some point. The 'mess' was introduced by me trying to support both python 2 and 3 in the nbetest program, which made things needlessly complex.

motoz commented 7 years ago

Checked out uBlock origin, it blocks the script logview.js from loading. You can fix it by adding a rule. One way is by opening the uBlock logger from the pellmon page, when reloading the pellmon page you should see a red line for the blocked script in the logger. There you can click the '--' and change the setting to 'green', which apparently will create a custom rule for you that allows the script. Then you can 'commit' the rule in the uBlock settings -> my Rules, which probably makes it stick around. Don't know why uBlock finds that script more suspect than all the other scripts pellmon uses...

Claws81 commented 7 years ago

Hmm no I wouldn't know why uBlock picks up on the script, but in my settings I've whitelisted the particular IP that pellmon runs from. That works. I've posted the diff below. I ended up changing both to latin1 and that solved the problem for both 'srv' and 'web'. I still have problems with a system installation, but that is for another issue # Right now I want to use it for a while before I break it again.

diff --git a/src/Pellmonsrv/plugins/nbecom/nbeprotocol/frames.py b/src/Pellmonsrv/plugins/nbecom/nbeprotocol/frames.py
index ad23450..7c0f1d9 100644
--- a/src/Pellmonsrv/plugins/nbecom/nbeprotocol/frames.py
+++ b/src/Pellmonsrv/plugins/nbecom/nbeprotocol/frames.py
@@ -170,7 +170,7 @@ class Response_frame(object):
         i += 3
         if not len(record) == self.size + self.RESPONSE_HEADER_SIZE:
             raise protocol_error('wrong length')
-        self.payload = (record[i:i+self.size]).decode('ascii')
+        self.payload = (record[i:i+self.size]).decode('latin1')
         i += self.size
         if not record[i] == END[0]:
             raise protocol_error('end missing')
diff --git a/src/Pellmonsrv/plugins/nbecom/nbeprotocol/protocol.py b/src/Pellmonsrv/plugins/nbecom/nbeprotocol/protocol.py
index a668294..ee79672 100644
--- a/src/Pellmonsrv/plugins/nbecom/nbeprotocol/protocol.py
+++ b/src/Pellmonsrv/plugins/nbecom/nbeprotocol/protocol.py
@@ -141,9 +141,9 @@ class Proxy:
                     response = self.make_request(function, path)
                     if response.status == 0:
                         if not group:
-                            return response.payload.encode('ascii').split('=', 1)[1]
+                            return response.payload.encode('latin1').split('=', 1)[1]
Claws81 commented 7 years ago

While checking Pellmon today out of nowhere, it throws the error below and stops serving the web page. I changed 'latin1' to 'utf-8' in 'protocol.py' and I seem to be able to get it going again now.

_value': '-', 'longname': 'Measured temp. 5', 'type': 'R/W', 'name': 'weather2-ref_5'}, {'cached_value': '-5.0', 'description': 'Specifying the temperature for regulation point 6. At this temperature wanted temperature 6 is used.', 'tags': ['All', 'Basic', 'weather2'], 'max': '50.0', 'min': '-50.0', 'label': 'ref 6', '_value': '-', 'longname': 'Measured temp. 6', 'type': 'R/W', 'name': 'weather2-ref_6'}, {'cached_value': '-10.0', 'description': 'Specifying the temperature for regulation point 7. At this temperature wanted temperature 7 is used.', 'tags': ['All', 'Basic', 'weather2'], 'max': '50.0', 'min': '-50.0', 'label': 'ref 7', '_value': '-', 'longname': 'Measured temp. 7', 'type': 'R/W', 'name': 'weather2-ref_7'}, {'cached_value': '45.0', 'description': 'Enter the wanted temperature for regulation point 1.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 1', '_value': '-', 'longname': 'Wanted temp. 1', 'type': 'R/W', 'name': 'weather2-temp_1'}, {'cached_value': '45.0', 'description': 'Enter the wanted temperature for regulation point 2.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 2', '_value': '-', 'longname': 'Wanted temp. 2', 'type': 'R/W', 'name': 'weather2-temp_2'}, {'cached_value': '50.0', 'description': 'Enter the wanted temperature for regulation point 3.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 3', '_value': '-', 'longname': 'Wanted temp. 3', 'type': 'R/W', 'name': 'weather2-temp_3'}, {'cached_value': '55.0', 'description': 'Enter the wanted temperature for regulation point 4.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 4', '_value': '-', 'longname': 'Wanted temp. 4', 'type': 'R/W', 'name': 'weather2-temp_4'}, {'cached_value': '60.0', 'description': 'Enter the wanted temperature for regulation point 5.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 5', '_value': '-', 'longname': 'Wanted temp. 5', 'type': 'R/W', 'name': 'weather2-temp_5'}, {'cached_value': '65.0', 'description': 'Enter the wanted temperature for regulation point 6.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 6', '_value': '-', 'longname': 'Wanted temp. 6', 'type': 'R/W', 'name': 'weather2-temp_6'}, {'cached_value': '70.0', 'description': 'Enter the wanted temperature for regulation point 7.', 'tags': ['All', 'Basic', 'weather2'], 'max': '100.0', 'min': '0.0', 'label': 'temp 7', '_value': '-', 'longname': 'Wanted temp. 7', 'type': 'R/W', 'name': 'weather2-temp_7'}],) to message with signature aa{sv}: <type 'exceptions.UnicodeError'>: String parameters to be sent over D-Bus must be valid UTF-8 with no noncharacter code points

motoz commented 6 years ago

I think you should change both of them to utf-8, then you might even get your city name in readable format in the browser.

Claws81 commented 6 years ago

Actually, the 'latin1' in both fixed the display of city name in the webserver. When I reverted back to utf-8 in both, the name is displayed as "Langå". The service has run solid for over a week now though, so that is awesome :) Small bug here and there, but separate issues from this thread.

motoz commented 6 years ago

Ok, good to know. I'll have to try to find some time to do something about this...