Kegboard not showing up; kegberry

I am attaching the kegboard to a kegberry running on a rasberrry pi. Everything works great except I can’t get the device to show up. Clearly it’s on /dev/ttyACM0, and

usb 1-1.3: USB disconnect, device number 6
Jan 26 21:13:01 raspberrypi kernel: [ 3916.322310] usb 1-1.3: new full-speed USB device number 7 using dwc_otg
Jan 26 21:13:01 raspberrypi kernel: [ 3916.437177] usb 1-1.3: New USB device found, idVendor=03eb, idProduct=0436
Jan 26 21:13:01 raspberrypi kernel: [ 3916.437213] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jan 26 21:13:01 raspberrypi kernel: [ 3916.437229] usb 1-1.3: Product: KegboardProMini
Jan 26 21:13:01 raspberrypi kernel: [ 3916.437243] usb 1-1.3: Manufacturer: Unknown
Jan 26 21:13:01 raspberrypi kernel: [ 3916.444489] cdc_acm 1-1.3:1.0: ttyACM0: USB ACM device

But the server doesn’t pick it up when I plug it in. So I edited supervisord’s config and added --kegboard_device=/dev/ttyACM0 but this doesn’t seem to help either.

The kegboard appears to be working nicely (lights blinking properly, etc).

What else can I do to troubleshoot?

Here is what the kegbot server app shows…

I just noticed the following. I assume that this is bad…

root@raspberrypi:~# supervisorctl status
kegbot:celery FATAL Exited too quickly (process log may have details)
kegbot:gunicorn RUNNING pid 3010, uptime 0:10:28
kegbot:kegboard_daemon RUNNING pid 3009, uptime 0:10:28
kegbot:kegbot_core RUNNING pid 3127, uptime 0:07:30

Here is the USB device list, seems ok…

Jan 26 22:24:57 raspberrypi kernel: [ 633.903819] usb 1-1.3: USB disconnect, device number 4
Jan 26 22:25:02 raspberrypi kernel: [ 638.495326] usb 1-1.3: new full-speed USB device number 6 using dwc_otg
Jan 26 22:25:02 raspberrypi kernel: [ 638.611084] usb 1-1.3: New USB device found, idVendor=03eb, idProduct=0436
Jan 26 22:25:02 raspberrypi kernel: [ 638.611121] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jan 26 22:25:02 raspberrypi kernel: [ 638.611137] usb 1-1.3: Product: KegboardProMini
Jan 26 22:25:02 raspberrypi kernel: [ 638.611150] usb 1-1.3: Manufacturer: Unknown
Jan 26 22:25:02 raspberrypi kernel: [ 638.618332] cdc_acm 1-1.3:1.0: ttyACM0: USB ACM device
root@raspberrypi:~# lsusb
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp.
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp.
Bus 001 Device 006: ID 03eb:0436 Atmel Corp.
Bus 001 Device 005: ID 0bda:8176 Realtek Semiconductor Corp. RTL8188CUS 802.11n WLAN Adapter

root@raspberrypi:~# lsusb -D /dev/bus/usb/001/006
Device: ID 03eb:0436 Atmel Corp.
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0 (Defined at Interface level)
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0x03eb Atmel Corp.
idProduct 0x0436
bcdDevice 1.00
iManufacturer 1 Unknown
iProduct 2 KegboardProMini

And lastly, I stopped kegboard_daemon.py and ran it by hand. Does this look ok?

root@raspberrypi:~# /home/kegberry/kegbot-pycore.venv/bin/kegboard_daemon.py --kegboard_device=/dev/bus/usb/001/006
2015-01-26 23:19:20,100 INFO (main) Main loop starting.
2015-01-26 23:19:20,147 INFO (main) Device added: /dev/ttyACM0
2015-01-26 23:19:27,369 INFO (main) unknown device: <HelloMessage: protocol_version=None firmware_version=19218 serial_number=None>
2015-01-26 23:19:27,376 INFO (main) Device is named: kegboard
2015-01-26 23:19:37,360 INFO (main) kegboard: <HelloMessage: protocol_version=None firmware_version=18 serial_number=KB-0102-0E18-7B9CB9C9>
2015-01-26 23:19:47,441 INFO (main) kegboard: <HelloMessage: protocol_version=None firmware_version=18 serial_number=KB-0102-0E18-7B9CB9C9>
2015-01-26 23:19:57,427 INFO (main) kegboard: <HelloMessage: protocol_version=None firmware_version=18 serial_number=KB-0102-0E18-7B9CB9C9>

From the logs the board appears healthy and connected.

Can you try the following:

  • Stop kegboard daemons
  • Unplug kegboard
  • Run kegboard-monitor.py from the command line
  • Report results

Works perfect. Could the problem be that I installed everything without the flow meter connected? I installed/setup the rasberry pi on my desk, then plugged in the flow meter at the keg later…

kegberry@raspberrypi:~/kegbot-pycore.venv/bin$ ./kegboard-monitor.py
Waiting for a kegboard …
Found: Kegboard path=/dev/ttyACM0 speed=115200>
Listening to board …
MeterStatusMessage: meter_name=flow0 meter_reading=5>
MeterStatusMessage: meter_name=flow0 meter_reading=1112211470>
MeterStatusMessage: meter_name=flow0 meter_reading=24>
MeterStatusMessage: meter_name=flow0 meter_reading=26>
HelloMessage: protocol_version=None firmware_version=18 serial_number=KB-0102-0E18-7B9CB9C9>

Alright! So the good news is the hardware is working; I’m guessing this is some sort of issue auto-detecting the meter.

While I try to reproduce it, are there any other USB-Serial devices connected to the RPi? The “auto detection” is a little primitive, and might be confused by similar-looking devices appearing on the bus. (And yes, it should be fine to plug it in later…)

Mikey,

First of all thx for the help.

The only other USB device on the RPi is the USB Wifi module.

FWIW:

mysql> desc core_controller;
±--------------±-------------±-----±----±--------±---------------+
| Field | Type | Null | Key | Default | Extra |
±--------------±-------------±-----±----±--------±---------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| name | varchar(128) | NO | UNI | NULL | |
| model_name | varchar(128) | YES | | NULL | |
| serial_number | varchar(128) | YES | | NULL | |
±--------------±-------------±-----±----±--------±---------------+
4 rows in set (0.00 sec)

mysql> desc core_device;
±-------------±-------------±-----±----±--------±---------------+
| Field | Type | Null | Key | Default | Extra |
±-------------±-------------±-----±----±--------±---------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| name | varchar(255) | NO | | NULL | |
| created_time | datetime | NO | | NULL | |
±-------------±-------------±-----±----±--------±---------------+
3 rows in set (0.01 sec)

mysql> select * from core_controller;
Empty set (0.00 sec)

Try running kegbot_core.py in one shell, and kegboard-daemon.py in another. The logs output from kegbot_core.py should show us whether the two programs are talking. (once a board is detected, core should report it back to the web server)

From core:

2015-01-27 01:24:49,607 INFO (kegnet) Listening on redis channel “kegnet”
2015-01-27 01:24:49,854 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:25:37,089 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:25:49,992 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:26:19,398 INFO (TapManager) Not creating controller: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:26:19,409 INFO (TapManager) Not creating controller: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:26:37,226 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:26:50,132 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded

more…

2015-01-27 01:27:37,355 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:27:50,276 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:28:37,498 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:28:49,518 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=28 last=None total=0
2015-01-27 01:28:49,534 INFO (flowmanager) Starting flow: <Flow 0x54c6e8d4: meter_name=kegboard-7b9cb9c9.flow0 ticks=0 username=’’ max_idle=0:00:10>
2015-01-27 01:28:49,544 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=28 last=None total=0
2015-01-27 01:28:49,563 INFO (flowmanager) Starting flow: <Flow 0x54c6e8e1: meter_name=kegboard-7b9cb9c9.flow0 ticks=0 username=’’ max_idle=0:00:10>
2015-01-27 01:28:49,620 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=33 last=28 total=0
2015-01-27 01:28:49,624 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=33 last=28 total=0
2015-01-27 01:28:49,720 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=41 last=33 total=5
2015-01-27 01:28:49,714 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=41 last=33 total=5
2015-01-27 01:28:49,914 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=46 last=41 total=13
2015-01-27 01:28:49,941 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=46 last=41 total=13
2015-01-27 01:28:49,975 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=47 last=46 total=18
2015-01-27 01:28:49,989 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=47 last=46 total=18
2015-01-27 01:28:50,067 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=48 last=47 total=19
2015-01-27 01:28:50,097 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=48 last=47 total=19
2015-01-27 01:28:50,295 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=49 last=48 total=20
2015-01-27 01:28:50,322 INFO (flowmeter-kegboard-7b9cb9c9.flow0) SetTicks: ticks=49 last=48 total=20
2015-01-27 01:28:50,404 WARNING (sync-thread) API exception during sync: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:29:00,931 INFO (flowmanager) Flow has become too idle, ending: <Flow 0x54c6e8e1: meter_name=kegboard-7b9cb9c9.flow0 ticks=21 username=’’ max_idle=0:00:10>
2015-01-27 01:29:00,936 INFO (flowmanager) Stopping flow: <Flow 0x54c6e8e1: meter_name=kegboard-7b9cb9c9.flow0 ticks=21 username=’’ max_idle=0:00:10>
2015-01-27 01:29:00,942 INFO (DrinkManager) Flow completed: flow_id=0x54c6e8e1
2015-01-27 01:29:00,944 INFO (DrinkManager) Posting 1 pending event(s)
2015-01-27 01:29:00,947 INFO (DrinkManager) Processing pending drink: flow_id=0x54c6e8e1, meter=kegboard-7b9cb9c9.flow0, volume=None
2015-01-27 01:29:01,088 INFO (flowmanager) Flow has become too idle, ending: <Flow 0x54c6e8d4: meter_name=kegboard-7b9cb9c9.flow0 ticks=21 username=’’ max_idle=0:00:10>
2015-01-27 01:29:01,094 INFO (flowmanager) Stopping flow: <Flow 0x54c6e8d4: meter_name=kegboard-7b9cb9c9.flow0 ticks=21 username=’’ max_idle=0:00:10>
2015-01-27 01:29:01,113 INFO (DrinkManager) Flow completed: flow_id=0x54c6e8d4
2015-01-27 01:29:01,122 INFO (DrinkManager) Posting 1 pending event(s)
2015-01-27 01:29:01,128 INFO (DrinkManager) Processing pending drink: flow_id=0x54c6e8d4, meter=kegboard-7b9cb9c9.flow0, volume=None
2015-01-27 01:29:01,223 WARNING (DrinkManager) Error posting drink: Invalid JSON response from server: No JSON object could be decoded
2015-01-27 01:29:01,297 WARNING (DrinkManager) Error posting drink: Invalid JSON response from server: No JSON object could be decoded

The plot thickens… Can you head over to /kegadmin on the server and look in the logs section? Hopefully an error is visible there.

Ah!

Traceback (most recent call last):
File “/home/kegberry/kegbot-server.venv/local/lib/python2.7/site-packages/pykeg/web/api/middleware.py”, line 72, in process_view
util.check_api_key(request)
File “/home/kegberry/kegbot-server.venv/local/lib/python2.7/site-packages/pykeg/web/api/util.py”, line 64, in check_api_key
raise kbapi.NoAuthTokenError(‘The parameter “api_key” is required’)
NoAuthTokenError: The parameter “api_key” is required

I verified everything else works fine, sans API key being presented to the API for a pour from the kegboard. I went ahead and added the data for the flowmeter directly to the DB, and called the API with my API key and the proper parameters. It indeed did record the pour and everything is dandy.

So that leaves this problem squarely with the API requiring a API key and the kegboard not sending one. I am not sure what the intended behavior is, perhaps the API is upgraded to require the API key and the kegboard needs new firmware to send it? (totally guessing here).

Mikey, what is your advise here? I will start poking at the code a bit and get myself oriented…

FWIW, kegbot server:

Powered by Kegbot™, version 1.1.0b2 — © 2003-2014 Bevbot LLC — Charts by Highcharts

kegboard:

(main) Main loop starting.
2015-01-27 19:21:44,724 INFO (main) Device added: /dev/ttyACM0
2015-01-27 19:21:44,924 INFO (main) unknown device: <HelloMessage: protocol_version=None firmware_version=18 serial_number=KB-0102-0E18-7B9CB9C9>
2015-01-27 19:21:44,934 INFO (main) Device is named: kegboard-7b9cb9c9

Ok, the kegberry/kegbot version is a bit old. Unfortunately we still need to cut a new image. In the meantime, can you try the following?

  1. Install a fresh raspbian image.
  2. Install latest kegberry program from install instructions.

If you want to try something less certain to work, but potentially faster:

$ kegberry erase
$ sudo rmuser kegberry; sudo rmuser kegbot   # one of these commands will fail
$ sudo rm -f /etc/nginx/sites-available/default /etc/supervisor/conf.d/kegbot.conf
$ sudo pip install -U kegberry
$ kegberry install
$ sudo reboot

Installed brand new rasbian image, and installed kegberry from scratch. I have things up and running and will test here in a bit.

One thing is the kegbot.conf for supervisord will need to have the line changed for starting gunicorn, I can pull request that here in a bit…

I am having very similar issues. I would REALLY like a new image of Kegberry. I tried a manual upgrade and it went… ok.
I will trying wiping and re-installing as well.