BTMON and GEM and error in reading packet header sometimes

Post any 3rd party software here.
adamall
Posts: 18
Joined: Wed Nov 10, 2010 3:22 pm

BTMON and GEM and error in reading packet header sometimes

Post by adamall » Mon May 08, 2017 8:31 pm

I recently replaced my ECM1240 with a GEM. I had been using BTMON with the ECM1240 and emoncms for a couple of years now. I am now trying to set this up with the GEM. The problem I am running into is not all the packets sent from the GEM to BTMON are being read. Some of the packets are being read allowing the kWh to be calculated but I would say about half of the packets received produce the error below. I have the GEM set to send at 10 second intervals and the packet format as BIN48-net-time.

As I said it works sometimes, I am sure it is a setting somewhere that I missed so any help would be appreciated.

Code: Select all

[/share/homes/adam/ecmread] # python btmon2.py -c ecmread2.cfg --print --debug
2017/05/08 21:09:26 btmon: 3.3.0
2017/05/08 21:09:26 python: 2.7.12 (default, Aug 10 2016, 17:16:35)
[GCC 4.9.2]
2017/05/08 21:09:26 platform: linux2
2017/05/08 21:09:26 device type: gem
2017/05/08 21:09:26 device list: ['']
2017/05/08 21:09:26 packet format: gem48ptbin
2017/05/08 21:09:26 schema: counters
2017/05/08 21:09:26 buffer size: 120
2017/05/08 21:09:26 SOCKET: timeout: 60
2017/05/08 21:09:26 SOCKET: server host: 10.0.0.236
2017/05/08 21:09:26 SOCKET: server port: 80
2017/05/08 21:09:26 packet format is GEM48PTBinaryPacket
2017/05/08 21:09:26 using collector BlockingSocketClientCollector
2017/05/08 21:09:26 using 1 processors:
2017/05/08 21:09:26   PrintProcessor
2017/05/08 21:09:26 setup BlockingSocketClientCollector
2017/05/08 21:09:26 setup PrintProcessor
2017/05/08 21:09:26 waiting for data from device
2017/05/08 21:09:26 opening socket connection to 10.0.0.236:80
2017/05/08 21:09:26 reading 1 of 1 packets
2017/05/08 21:09:29 adding buffer for 01000813
2017/05/08 21:09:29 buffering packet ts:1494292169 sn:01000813
2017/05/08 21:09:29 buffer info:
2017/05/08 21:09:29   01000813:   1 of 120 (1494292169)
2017/05/08 21:09:29 processing with PrintProcessor
2017/05/08 21:09:29 not enough data for 01000813
2017/05/08 21:09:29 waiting for data from device
2017/05/08 21:09:29 reading 1 of 1 packets
2017/05/08 21:09:38 failed read 1 of 0
2017/05/08 21:09:38 expected START_HEADER0 0xfe, got nothing
Traceback (most recent call last):
  File "btmon2.py", line 2069, in _blockingread
    self._read(packet_format)
  File "btmon2.py", line 2056, in _read
    packets.extend(packet_format.read(self))
  File "btmon2.py", line 1434, in read
    return self._read1(collector, self.DATA_BYTES_LENGTH, self.PACKET_ID)
  File "btmon2.py", line 1322, in _read1
    self._checkbyte(data, 'START_HEADER0', self.START_HEADER0)
  File "btmon2.py", line 1313, in _checkbyte
    (label, hex(evalue)))
EmptyReadError: expected START_HEADER0 0xfe, got nothing
2017/05/08 21:09:38 closing socket connection
2017/05/08 21:09:38 waiting 60 seconds before retry
ben
Site Admin
Posts: 4254
Joined: Fri Jun 04, 2010 9:39 am

Re: BTMON and GEM and error in reading packet header sometim

Post by ben » Tue May 09, 2017 12:12 pm

adamall wrote:I recently replaced my ECM1240 with a GEM. I had been using BTMON with the ECM1240 and emoncms for a couple of years now. I am now trying to set this up with the GEM. The problem I am running into is not all the packets sent from the GEM to BTMON are being read. Some of the packets are being read allowing the kWh to be calculated but I would say about half of the packets received produce the error below. I have the GEM set to send at 10 second intervals and the packet format as BIN48-net-time.

As I said it works sometimes, I am sure it is a setting somewhere that I missed so any help would be appreciated.
Under the Adv section of the GEM Setup Webpage, can you check your keep-alive and packet chunk sizes. Post the values here (maybe screenshot the entire section and post it up). I'll look to see if anything there may be causing issues.

The chunk size and chunk time causes the packets to be sent in chunks instead of all at once, I'm wondering if that could be causing issues.

On a different tangent:

With the GEM and EmonCMS, I would suggest trying the built-in packet format. There's a lot less setup involved.

The Raspberry Pi section of the forum has some setup instructions on getting our devices going with it. We have our own fork of the Modules add-on for it that includes a GEM device binding.

viewtopic.php?f=40&t=1577
Ben
Brultech Research Inc.
E: ben(at)brultech.com
adamall
Posts: 18
Joined: Wed Nov 10, 2010 3:22 pm

Re: BTMON and GEM and error in reading packet header sometim

Post by adamall » Tue May 09, 2017 4:00 pm

Attached is a screenshot of the advanced section. I did not change anything in this section so it should all be factory default. Right now I am just trying to get btmon to work correctly first. Then I plan on forwarding my data via MQTT to Grafana. I am running btmon on my Qnap453 and have misquitto and Grafana with Influxdb running in containers on my Qnap

As for EmonCMS builtin packet, I will do that if I go back to EmonCMS.
GEM ADV Screenshoot.PNG
GEM ADV Screenshoot.PNG (154.33 KiB) Viewed 5819 times
ben
Site Admin
Posts: 4254
Joined: Fri Jun 04, 2010 9:39 am

Re: BTMON and GEM and error in reading packet header sometim

Post by ben » Wed May 10, 2017 9:45 am

Try disabling the Keep Alive pulse in case that is causing issues.
Ben
Brultech Research Inc.
E: ben(at)brultech.com
adamall
Posts: 18
Joined: Wed Nov 10, 2010 3:22 pm

Re: BTMON and GEM and error in reading packet header sometim

Post by adamall » Wed May 10, 2017 5:56 pm

Ok I disabled the keep alive pulse. That seems to make it so that it reads more of the packets but there is still something btmon is receiving that it can't read. see below.

Code: Select all

2017/05/10 18:48:51 waiting 30 seconds before retry
2017/05/10 18:49:21 opening socket connection to 10.0.0.236:80
2017/05/10 18:49:21 reading 1 of 1 packets
2017/05/10 18:49:22 buffering packet ts:1494456562 sn:01000813
2017/05/10 18:49:22 buffer info:
2017/05/10 18:49:22   01000813:   5 of 120 (1494456562)
2017/05/10 18:49:22 processing with PrintProcessor
2017/05/10 18:49:22 2 buffered packets sn:01000813
2017/05/10 18:49:22 1 calculated packets sn:01000813

2017/05/10 18:49:22: Serial: 01000813
2017/05/10 18:49:22: Voltage:  121.90V
2017/05/10 18:49:22: Ch01:     -2.359821KWh (  450W) (   6.12A)
2017/05/10 18:49:22: Ch02:     59.647308KWh ( -242W) (   2.24A)
2017/05/10 18:49:22: Ch03:      0.543482KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch04:      0.628053KWh (    3W) (   0.08A)
2017/05/10 18:49:22: Ch05:      4.437321KWh (   32W) (   0.56A)
2017/05/10 18:49:22: Ch06:      9.601194KWh (  107W) (   1.08A)
2017/05/10 18:49:22: Ch07:      0.000000KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch08:      0.004726KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch09:      1.035774KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch10:      5.086372KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch11:      4.482184KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch12:      0.148142KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch13:      0.098931KWh (    7W) (   0.10A)
2017/05/10 18:49:22: Ch14:      0.743598KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch15:      0.000018KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch16:     43.824673KWh (   70W) (   0.56A)
2017/05/10 18:49:22: Ch17:     37.483095KWh (  217W) (   2.46A)
2017/05/10 18:49:22: Ch18:      0.026868KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch19:      0.000221KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch20:      1.661757KWh (    7W) (   0.08A)
2017/05/10 18:49:22: Ch21:     11.206133KWh (    6W) (   0.10A)
2017/05/10 18:49:22: Ch22:      3.468988KWh (   26W) (   0.32A)
2017/05/10 18:49:22: Ch23:      1.031073KWh (    0W) (   0.00A)
2017/05/10 18:49:22: Ch24:      5.922304KWh (   90W) (   0.88A)
2017/05/10 18:49:22: Ch25:      4.163413KWh (   14W) (   0.22A)
2017/05/10 18:49:22: Ch26:      0.902872KWh (    5W) (   0.34A)
2017/05/10 18:49:22: Ch27:      0.772203KWh (    2W) (   0.08A)
2017/05/10 18:49:22: Ch28:      1.553276KWh (    1W) (   0.08A)
2017/05/10 18:49:22: Ch29:      2.762677KWh (   16W) (   0.20A)
2017/05/10 18:49:22: Ch30:      0.501258KWh (    3W) (   0.00A)
2017/05/10 18:49:22: Ch31:      9.609298KWh (   12W) (   0.22A)
2017/05/10 18:49:22: Ch32:      6.740381KWh (    9W) (   0.08A)
2017/05/10 18:49:22: p1:               0
2017/05/10 18:49:22: p2:               0
2017/05/10 18:49:22: p3:               0
2017/05/10 18:49:22: p4:               0
2017/05/10 18:49:22: t1:        0.000000
2017/05/10 18:49:22: t2:        0.000000
2017/05/10 18:49:22: t3:        0.000000
2017/05/10 18:49:22: t4:        0.000000
2017/05/10 18:49:22: t5:        0.000000
2017/05/10 18:49:22: t6:        0.000000
2017/05/10 18:49:22: t7:        0.000000
2017/05/10 18:49:22: t8:        0.000000
2017/05/10 18:49:22 waiting for data from device
2017/05/10 18:49:22 reading 1 of 1 packets
2017/05/10 18:49:31 failed read 1 of 0
2017/05/10 18:49:31 expected START_HEADER0 0xfe, got nothing
Traceback (most recent call last):
  File "btmon2.py", line 2069, in _blockingread
    self._read(packet_format)
  File "btmon2.py", line 2056, in _read
    packets.extend(packet_format.read(self))
  File "btmon2.py", line 1434, in read
    return self._read1(collector, self.DATA_BYTES_LENGTH, self.PACKET_ID)
  File "btmon2.py", line 1322, in _read1
    self._checkbyte(data, 'START_HEADER0', self.START_HEADER0)
  File "btmon2.py", line 1313, in _checkbyte
    (label, hex(evalue)))
EmptyReadError: expected START_HEADER0 0xfe, got nothing
2017/05/10 18:49:31 closing socket connection
2017/05/10 18:49:31 waiting 30 seconds before retry
ben
Site Admin
Posts: 4254
Joined: Fri Jun 04, 2010 9:39 am

Re: BTMON and GEM and error in reading packet header sometim

Post by ben » Fri May 12, 2017 12:34 pm

Can you post your BTMon config? Hide any values you don't want public.

I'm using it currently BTMon in client mode, connecting to a GEM. I'm not getting the same error. I'm wondering if it's linked to server mode.
Ben
Brultech Research Inc.
E: ben(at)brultech.com
adamall
Posts: 18
Joined: Wed Nov 10, 2010 3:22 pm

Re: BTMON and GEM and error in reading packet header sometim

Post by adamall » Sat May 13, 2017 9:17 pm

So I seem to have BTMON and gem working now. What you see below is what I had when it wasn't working.

Code: Select all

[source] 
device_type = gem 
ip_read = true 
ip_host = 10.0.0.236 
ip_port = 80
ip_mode = client
INCLUDE_CURRENT = 1
REVERSE_POLARITY = 1

[mqtt]
mqtt_out=true
mqtt_host=10.0.0.12
mqtt_port=1883
mqtt_clientid=btmon
mqtt_base_topic=/house/energy
mqtt_upload_period=10
mqtt_map=01000813_volts,volts,01000813_ch1_w,main_w,01000813_ch2_w
How I have it setup now is pretty much the same except I turned off the "real time status" on the GEM and set the "ip_poll_interval" in BTMON. I do not get any errors and everything seems to be working correctly. Now I just need to get telegraf and influxdb to play nice.
ben
Site Admin
Posts: 4254
Joined: Fri Jun 04, 2010 9:39 am

Re: BTMON and GEM and error in reading packet header sometim

Post by ben » Mon May 15, 2017 9:22 am

adamall wrote:So I seem to have BTMON and gem working now. What you see below is what I had when it wasn't working.

Code: Select all

[source] 
device_type = gem 
ip_read = true 
ip_host = 10.0.0.236 
ip_port = 80
ip_mode = client
INCLUDE_CURRENT = 1
REVERSE_POLARITY = 1

[mqtt]
mqtt_out=true
mqtt_host=10.0.0.12
mqtt_port=1883
mqtt_clientid=btmon
mqtt_base_topic=/house/energy
mqtt_upload_period=10
mqtt_map=01000813_volts,volts,01000813_ch1_w,main_w,01000813_ch2_w
How I have it setup now is pretty much the same except I turned off the "real time status" on the GEM and set the "ip_poll_interval" in BTMON. I do not get any errors and everything seems to be working correctly. Now I just need to get telegraf and influxdb to play nice.


I made some changes to btmon to allow the other packet formats to work with Influx here:

https://github.com/BenK22/mtools/blob/i ... n/btmon.py

As-is, the GEM just sends the counters to Influx, it can be a bit of a pain to work with. I've updated it to send the ecmreadext format with the GEM which will send delta watt-hours, watts, amps, etc.
Ben
Brultech Research Inc.
E: ben(at)brultech.com
adamall
Posts: 18
Joined: Wed Nov 10, 2010 3:22 pm

Re: BTMON and GEM and error in reading packet header sometim

Post by adamall » Mon Jun 12, 2017 8:40 am

So I thought that I had this fixed. Today I noticed that btmon is randomly not receiving packets from GEM when requested. It is the same error as stated earlier in this thread, "error in reading packet header"

My configuration file for btmon is

Code: Select all

[source] 
device_type = gem 
ip_read = true 
ip_host = 10.0.0.236 
ip_port = 80
ip_mode = client
INCLUDE_CURRENT = 1
REVERSE_POLARITY = 1
ip_poll_interval = 30
TRUST_DEVICE_CLOCK = 1
I have the GEM set to not send real time packets.

The problem seems to be very random. When I review the influxdb everything seems to work fine for 5 to 60 minutes and then there will be one missing data point and thing will work fine for another 5 to 60 minutes.
ben
Site Admin
Posts: 4254
Joined: Fri Jun 04, 2010 9:39 am

Re: BTMON and GEM and error in reading packet header sometim

Post by ben » Mon Jun 12, 2017 11:28 am

Try changing:

RETRY_WAIT = 60

to

RETRY_WAIT = 0

it should immediately retry if it thinks it has a bad packet.

Not a proper bug fix, but it should work as a work-around.
Ben
Brultech Research Inc.
E: ben(at)brultech.com
Post Reply