So, I love that the GEM and the btmon that I have running just seems to work most of the time, but that means that the time between debugging issues is very large, and when something does go wrong, I feel like I'm starting again. Anyway, I was running btmon311, so the first thing I did was grab the latest version (320) and give it a try, but the result was the same.
I'm struggling to gather useful (to me) information, so I'm reaching out here. The logs gave a little info about when it stopped- everything seemed to be fine until 23:59:55 on the 18th, but when newsyslog rolled the logs, btmon gave no more log entries (as in, it crashed, or didn't restart) until almost 48 hours later, when I discovered it and manually tried to restart.
Here's (the top of) the log file from earlier this week, when it was working properly. This isn't debug output, because it was running fine:
Code: Select all
2018/09/18 13:18:04 btmon: 3.1.1
2018/09/18 13:18:05 python: 2.7.3 (default, Mar 26 2013, 17:57:50)
[GCC 4.2.1 20070831 patched [FreeBSD]]
2018/09/18 13:18:05 platform: freebsd8
2018/09/18 13:18:05 polarity is reversed
2018/09/18 13:18:05 device type: gem
2018/09/18 13:18:05 device list: ['']
2018/09/18 13:18:05 packet format: gem48ptbin
2018/09/18 13:18:05 schema: counters
2018/09/18 13:18:05 SOCKET: bind host:
2018/09/18 13:18:05 SOCKET: bind port: 5000
2018/09/18 13:18:05 RRD: update period: 60
2018/09/18 13:18:05 RRD: dir: /usr/local/www/apache22/data/cacti/rra
2018/09/18 13:18:05 RRD: step: 10
2018/09/18 13:18:05 RRD: heartbeat: 20
2018/09/18 13:18:23 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch26_pws.rrd with 1 values
2018/09/18 13:18:23 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch17_aws.rrd with 1 values
...
But now, it stops after the first packet. Here's the (non-debug) log file from two nights ago, when it failed:
Code: Select all
2018/09/20 23:55:42 btmon: 3.1.1
2018/09/20 23:55:42 python: 2.7.3 (default, Mar 26 2013, 17:57:50)
[GCC 4.2.1 20070831 patched [FreeBSD]]
2018/09/20 23:55:42 platform: freebsd8
2018/09/20 23:55:42 polarity is reversed
2018/09/20 23:55:42 device type: gem
2018/09/20 23:55:42 device list: ['']
2018/09/20 23:55:42 packet format: gem48ptbin
2018/09/20 23:55:42 schema: counters
2018/09/20 23:55:42 SOCKET: bind host:
2018/09/20 23:55:42 SOCKET: bind port: 5000
2018/09/20 23:55:42 RRD: update period: 60
2018/09/20 23:55:42 RRD: dir: /usr/local/www/apache22/data/cacti/rra
2018/09/20 23:55:42 RRD: step: 10
2018/09/20 23:55:42 RRD: heartbeat: 20
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch26_pws.rrd with 1 values
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch17_aws.rrd with 1 values
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch6_aws.rrd with 1 values
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch25_pws.rrd with 1 values
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch31_pws.rrd with 1 values
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch29_aws.rrd with 1 values
2018/09/20 23:55:55 RRD: updating /usr/local/www/apache22/data/cacti/rra/01000XXX_ch3_aws.rrd with 1 values
When i run it in debug mode, there's a little more info, but I can't make anything of it:
Code: Select all
2018/09/21 23:02:18 btmon: 3.2.0
2018/09/21 23:02:18 python: 2.7.3 (default, Mar 26 2013, 17:57:50)
[GCC 4.2.1 20070831 patched [FreeBSD]]
2018/09/21 23:02:18 platform: freebsd8
2018/09/21 23:02:18 polarity is reversed
2018/09/21 23:02:18 device type: gem
2018/09/21 23:02:18 device list: ['']
2018/09/21 23:02:18 packet format: gem48ptbin
2018/09/21 23:02:18 schema: counters
2018/09/21 23:02:18 buffer size: 120
2018/09/21 23:02:18 SOCKET: bind host:
2018/09/21 23:02:18 SOCKET: bind port: 5000
2018/09/21 23:02:18 RRD: update period: 60
2018/09/21 23:02:18 RRD: dir: /usr/local/www/apache22/data/cacti/rra
2018/09/21 23:02:18 RRD: step: 10
2018/09/21 23:02:18 RRD: heartbeat: 20
2018/09/21 23:02:18 packet format is GEM48PTBinaryPacket
2018/09/21 23:02:18 using collector SocketServerCollector
2018/09/21 23:02:18 using 1 processors:
2018/09/21 23:02:18 RRDProcessor
2018/09/21 23:02:18 setup SocketServerCollector
2018/09/21 23:02:18 SOCKET: binding to :5000
2018/09/21 23:02:18 setup RRDProcessor
2018/09/21 23:02:18 SOCKET: waiting for connection
2018/09/21 23:02:21 waiting for data from device
2018/09/21 23:02:21 reading 1 of 1 packets
2018/09/21 23:02:21 SOCKET: read 1 of 1 bytes from socket: fe
2018/09/21 23:02:21 SOCKET: read 1 of 1 bytes from socket: ff
2018/09/21 23:02:21 SOCKET: read 1 of 1 bytes from socket: 05
2018/09/21 23:02:21 SOCKET: read 8 of 619 bytes from socket: 04 b7 8e d5 cc ba 51 8c
2018/09/21 23:02:21 SOCKET: read 611 of 611 bytes from socket: 82 a6 c8 61 3c 51 bd 6b 39 d8 2c e1 7f 6b 19 b1 e8 69 64 05 62 d7 2e 70 3d bf 1a e4 02 2b 79 f2 96 00 46 e8 ce d1 01 16 f3 87 a2 01 d1 7d 89 a4 00 60 1e 8d f9 02 45 ec 48 9c 00 4b 1f 20 d2 00 08 d4 30 c5 02 96 72 36 10 00 09 4d f5 ab 00 e8 13 07 5c 05 8f 8c 6f 34 00 a9 44 3c c2 01 64 65 ee 14 01 15 c4 51 00 00 f0 b5 4f 00 00 52 26 59 00 01 f8 f0 50 00 00 22 1a a5 02 01 8b ea 48 00 00 39 9e 4a 00 00 45 e8 40 00 00 3d 1c 46 00 00 7e a5 6b 24 00 40 ed 68 06 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 e5 01 00 00 00 4a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4d 57 20 00 00 b2 81 26 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 a4 05 db 00 01 00 01 00 01 00 00 00 00 00 0b 00 71 02 48 00 01 00 00 00 00 00 0b 00 cb 00 00 00 02 00 72 00 04 00 1b 00 2c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 00 10 0f 0e 0d 0c 0b 0a 09 08 07 06 05 04 03 02 01 01 cf 00 0a ea 02 4f 00 00 00 00 00 05 00 04 00 0a 00 05 00 71 01 2a 00 00 00 00 00 04 00 1a 00 5e 00 00 00 04 00 37 00 07 00 14 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 07 00 00 1a f3 80 d8 02 80 22 01 80 b9 00 80 d7 00 80 e0 01 80 10 05 00 00 db a7 81 00 2c 80 04 01 80 bf 03 38 01 00 00 00 00 00 01 00 00 02 00 00 2c 00 00 02 00 02 00 00 00 00 00 00 00 02 1e 00 12 09 15 17 05 08
2018/09/21 23:02:21 SOCKET: read 1 of 1 bytes from socket: ff
2018/09/21 23:02:21 SOCKET: read 1 of 1 bytes from socket: fe
2018/09/21 23:02:21 SOCKET: read 1 of 1 bytes from socket: 59
2018/09/21 23:02:21 adding buffer for 01000XXX
2018/09/21 23:02:21 buffering packet ts:1537585341 sn:01000XXX
2018/09/21 23:02:21 SOCKET: closing connection
2018/09/21 23:02:21 buffer info:
2018/09/21 23:02:21 01000XXX: 1 of 120 (1537585341)
2018/09/21 23:02:21 processing with RRDProcessor
2018/09/21 23:02:21 not enough data for 01000XXX
2018/09/21 23:02:21 SOCKET: waiting for connection
2018/09/21 23:02:31 waiting for data from device
Can anyone enlighten me as to what may be going on, and how to rectify it?