Slow serial read causing profile Off [Solved]

I’m running a BrewPi on Arduino, built based off of FuzzeWuzze’s guide on HomeBrewTalk. I’ve run into this issue now twice while running my test run on water.

The temperature control works well until it enters a ramp up or ramp down, then it works for a while and randomly turns the profile off. Here are the logs:

Aug 01 2015 01:43:21 controller debug message: INFO MESSAGE 12: Received new setting: beerSet = 68.73
Aug 01 2015 01:45:09 controller debug message: INFO MESSAGE 12: Received new setting: beerSet = 68.74
Aug 01 2015 01:46:56 controller debug message: ERROR 10: Expected { got END OF INPUT
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: {
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: b
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: e
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: e
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: r
Aug 01 2015 01:46:56 controller debug message: INFO MESSAGE 14: Default settings loaded.
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: e
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: :
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: 6
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: 8
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: .
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: 7
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: 5
Aug 01 2015 01:46:56 controller debug message: WARNING 1: Invalid command received by controller: }
Aug 01 2015 02:00:00 controller debug message: INFO MESSAGE 17: Positive peak detected: 72.6, estimated: 75.1. Previous heat estimator: 0.199, New heat estimator: 0.156.

I’ve messaged with Elco on it when it happened the first time and we agree it looks like when it sends the j{beerSet:68.75} to set the next point “the characters are sent out over serial very slowly, and interpreted by the Arduino one by one.” But he didn’t have an idea on what might be causing it.

Now I’m trying to figure out what to do for the next step. The coder in me wants to add logic on the Arduino that if it receives an invalid input it reads until the next end line/end of input (or possibly reset the serial link or arduino?), or modify the beerSet command to be “beerset” instead of “beerSet” so at least it won’t turn off the profile (but it appears it will then dump the contents of eeprom twice).

Just looking for options, or maybe I just assume I have a bad Arduino?

Here’s the log from the first time it happened:

Jul 28 2015 06:58:21 controller debug message: INFO MESSAGE 12: Received new setting: beerSet = 63.41
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: b
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: e
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: e
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: r
Jul 28 2015 06:58:33 controller debug message: INFO MESSAGE 14: Default settings loaded.
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: e
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: :
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: 6
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: 3
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: .
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: 4
Jul 28 2015 06:58:33 controller debug message: WARNING 1: Invalid command received by controller: }
Traceback (most recent call last):
File “/home/brewpi/brewpi.py”, line 191, in
allProcesses.update()
File “/home/brewpi/BrewPiProcess.py”, line 124, in update
matching = [p for p in psutil.process_iter() if any(‘python’ in p.name() and 'brewpi.py’in s for s in p.cmdline())]
File “/usr/local/lib/python2.7/dist-packages/psutil/init.py”, line 584, in cmdline
return self._proc.cmdline()
File “/usr/local/lib/python2.7/dist-packages/psutil/_pslinux.py”, line 718, in wrapper
raise NoSuchProcess(self.pid, self._name)
psutil.NoSuchProcess: psutil.NoSuchProcess process no longer exists (pid=1371)
Jul 28 2015 09:44:05 Another instance of BrewPi is already running, which will conflict with this instance. This instance will exit
Jul 28 2015 16:36:04 Setting profile ‘Test%20Run’ as active profile
Jul 28 2015 16:36:04 Notification: Profile mode enabled
Jul 28 2015 16:36:04 controller debug message: INFO MESSAGE 12: Received new setting: mode = p
Jul 28 2015 16:36:04 controller debug message: INFO MESSAGE 12: Received new setting: beerSet = 35.33
Jul 28 2015 16:36:11 controller debug message: INFO MESSAGE 12: Received new setting: beerSet = 35.32

On which version are you?
I think this was fixed in 0.2.7.

If you downloaded your hex file from dl.brewpi.com, you are running something very outdated.
Releases moved to github, try this:
https://github.com/BrewPi/firmware/releases/tag/0.2.10

Awesome, I’ll try to update that and see if it resolves the issue. Perhaps http://docs.brewpi.com/after-install/program-arduino.html should be updated to reference the new location?

I just had this same issue, and wondering how would I check the version of the hex file and determine which to update to? I’m running the older brewPi and not the spark.

Thanks Elco!!

EDIT: I applied the update linked below and will proceed with that unless informed of a newer release for the revC shields.

I’m also having a similar issue. I have just completed a build using an Arduino and esp8266 to connect the Arduino over wifi.

It is working, I have no sensors, but can see the script running, as well as switch to beer constant and back to off (can see the confirmation messages in the logs)

However I have the same warning errors as the original poster when I try to configure devices, I am stuck for ideas for how to fix it, can anyone help?

Have you tried turning it off and on again… :flushed:
I restarted everything hoping to debug it systematically and it just started working. I’m happy! but perplexed about what was broken.