Devices won't save when assigned

[Mikmonken]

On 2nd ESP, Devices appear Configure Sensors/Pins page, however when assigned they do not install (similar issue to that happened on brewpi that could be fixed the esprom reset) similar reset doesn't work.

all devices are active and work on 1st ESP.

[stone]

I had a similar problem some time ago, do you assign pins one by one?

[Mikmonken]

Yes I do, is there another way? I did wonder if it was something to do with the temp probes being also installed on another device (albeit one that isnt powered on)

[thorrak]

That shouldn't matter at all. Fermentrack doesn't actually track pins/sensors internally at all. Part of the reason for the "timeout" message when setting up pins/devices is that Fermentrack has to load them from the script every time. What you're describing sounds like either the script isn't properly invalidating the cache (which is odd, given the other issue) or the controller isn't properly saving the device configuration.

[Mikmonken]

With the 2nd ESP the time out timeout issue as per the other bug don't seem to occur.

[Mikmonken]

So with a bit of playing around, I've worked out how to add the devices and for them to save.

When I added the ESP and the script started both the fridge and beers setting read 20c

So I decided with no installed devices to set it to fridge constant at 20c the device esp updated the setting and put it into fridge constant mode, ESP went into fridge constant.

Then I was able to add all my devices as normal.

This ESP is also experiencing same issue with relay set to on as default.

[thorrak]

That's really, really strange. The temperature control mode should be completely disconnected from device settings - both on the firmware as well as in brewpi-script. You could make an argument that brewpi-script does suffer a tiny bit of overhead when managing a beer profile, but nothing when managing beer or fridge constants.

I'm guessing this is a duplicate of #109 and #116 -- If you can, upgrade to the latest codebase & test with the same controller, and let me know if you run into the same issues.

[Mikmonken]

upgraded latest code base, uninstalled device and the reinstall with no issues. (ESP remembered previous device assignment so removed and reinstalled)

Will attempt to Flash ESP and try and install from scratch and update

[thorrak]

Out of curiousity, are you having any issues installing onewire-addressable devices on the latest codebase (similar to this forum post?)

[Mikmonken]

No I've not come across this one.

I was hoping to flash my test unit out and then reinstall, but I've just realised it's a power only USB cable irritatingly.

When I get back I'll flash the ESP and then try and reinstall as new.

[Mikmonken]

Flashed the ESP and can confirm the problem is still there.

However as a slight variation it seems that the devices are in fact all installed as when I set to beer or fridge constant the relays will switch despite appearing as not assigned in the configure sensor page.

This is device 7 but I can't seem to find the STDerr or stdout readouts to share

[stone]

@Mikmonken if you upgrade, klick on the "?" in the upper right corner, then you should get a table of devices with their corresponding logs to view directly in the browser.

[Mikmonken]

i get this out put (similar for all devices) all outputs)

Error opening stderr logfile: [Errno 2] No such file or directory: '/home/fermentrack/fermentrack/log/dev-Test-stderr.log'

[Mikmonken]

but now I know where to find the logs!!

Hopefully they'll help, just to confirm though all the devices are installed and working they just don't appear to be showing as installed on the config screen

dev-test-stdout.txt dev-test-stderr.txt

[thorrak]

Thanks for providing the logs! This is a strange one, because the (current) architecture should prevent what you are seeing.

Devices are read when BrewPi-script launches from the controller into a cache within BrewPi-script itself. The controller returns installed devices separately from uninstalled devices, and reads the installed devices directly from the same memory used by the control algorithm (which is to say - it doesn't make sense for the controller to state that all devices are connected but uninstalled and then correctly use them/display them on the LCD).

Within BrewPi-script (under Fermentrack) the cache of devices is invalidated and refreshed only when a new device is set up. It's refreshed in the background whenever the "set up devices" page is accessed - the invalidation is what was causing the generic "connection error" you forwarded a screenshot of. The only thing I can think is that the cache isn't being properly invalidated after devices are being added and BrewPi-script isn't interpreting the device list it is being sent.

...that said - the logs @Mikmonken show that BrewPi-script is actually working just fine:

Mar 20 2017 18:32:35 Installed devices received: [{"a": "28FF66022E040099", "c": 1, "b": 0, "d": 0, "f": 5, "i": 0, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 18.438}, {"a": "28FF15D662160423", "c": 1, "b": 1, "d": 0, "f": 9, "i": 1, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 19.688}, {"c": 1, "b": 0, "d": 0, "f": 3, "i": 2, "h": 1, "p": 14, "t": 3, "v": 0, "x": 1}, {"c": 1, "b": 0, "d": 0, "f": 3, "i": 3, "h": 1, "p": 14, "t": 3, "v": 0, "x": 1}, {"c": 1, "b": 0, "d": 0, "f": 2, "i": 4, "h": 1, "p": 16, "t": 3, "v": 0, "x": 1}] Mar 20 2017 18:32:46 Available devices received: [{"c": 1, "b": 0, "d": 0, "f": 0, "i": -1, "h": 1, "p": 13, "t": 0, "x": 1}]

The only other thing I can think of is that it may be a caching thing in Django (but that sounds weird as caching is disabled if I recall correctly). I'll tag the device setup pages as never_cache later and see if that helps. No harm in this case, so why not?

[Mikmonken]

I'm beginning to wonder whether it may be a dodgy ESP that I have that is causing issues with the interface? as the other device is working perfectly (holding my FV of water) to within 0.06c aiming for 15c and getting 14.94c (59f - 58.928f) which is very respectable. held that temp consistently for 13 hours now)

Edit, this is not a dodgy ESP have had the same issue on a second unit now too.

I am going to try and set up a second iteration of Fermentrack on an RPI3 (it's currently on an RPI zero W) as I wonder whether it might be something to do with the RPI rather than the ESP, as the problem seems very intermittent.

[Mikmonken]

Ok so seemingly the same relay is appearing twice, not sure if this related or not to this bug but I think it may be.

[thorrak]

Hey @Mikmonken - How does everything look in the most recent version? I've pushed a bunch of code that I think should have helped fix this bug. There still is going to be an issue where the device will appear to not detect freshly attached OneWire devices - but that's the only bug I expect to remain at this point.

[Mikmonken]

Well good news is that I managed to delete the device which was a bonus.

Bad news though is that the script on my other ESP was refusing to start so I rebooted the Pi and it comes up with an error 502 Bad Gateway and I can't access Fermentrack at all.

[stone]

@Mikmonken could you upload the logs which are in the directory /home/fermentrack/fermentrack/log to this issue?

[Mikmonken]

One of the files is 9.5meg so I'm not sure whats going on there. There are more logs but these are the ones from today that relate to the time I ran the update, I should have done this on my test RPI first rather than mid brew, school boy error!!

fermentrack-brewpi-spawner.txt dev-olag-stdout.txt dev-olag-stderr.txt fermentrack.txt

[Mikmonken]

oh and here is the upgrade log from /home/fermentrack/fermentrack/

upgrade.txt

[Mikmonken]

and finally here are the error logs from var/log/nginx

error.txt

[thorrak]

I am 99% sure the issue was caused by this commit:

https://github.com/thorrak/fermentrack/commit/97707fef7e4795abf0483a87d1b910122c1a3648

I forgot to add u+x to the script. You have two ways to fix this:

Method 1 (easy):

Ssh in, and run sudo chmod u+x ~fermentrack/fermentrack/brewpi-script/utils/updateCronCircus.sh (If you connect as a user other than pi just drop the sudo)

Method 2 (harder):

Ssh in, change to the Fermentrack user, edit crontab, and delete the two entries for Fermentrack. Run sudo chmod u+x ~fermentrack/fermentrack/brewpi-script/utils/updateCronCircus.sh and then run ~fermentrack/fermentrack/utils/updateCronCircus.sh add2cron.

[Mikmonken]

that seems to work after a reboot.

under method 2 though when I run the 2nd command I get this.

ERROR: Could not find python virtualenv enviroment

[Mikmonken]

The ESP still seems to be hanging on 'Script starting up' element though which is what prompted me to reboot the RPI in the first place.

Heres the output I have

Mar 29 2017 06:02:02   Controller debug message: INFO MESSAGE 18: Negative peak detected:  9.6, estimated:  9.9. Previous cool estimator:  4.678, New cool estimator:  4.678.
 Mar 29 2017 06:36:19   Controller debug message: INFO MESSAGE 18: Negative peak detected:  8.9, estimated:  9.0. Previous cool estimator:  4.678, New cool estimator:  4.678.
 Mar 29 2017 07:19:06   Connection type WiFi selected.  Trying TCP serial (WiFi)
 Mar 29 2017 07:19:06   Connecting to BrewPi esp863888.local on port 23
 Mar 29 2017 07:19:13   Notification: Script started for beer 'Doppelbock GY045'
 Mar 29 2017 07:19:23   Checking software version on controller... 
 Mar 29 2017 07:19:23   Found BrewPi v0.2.4, running commit 00000000, running on an ESP ESP8266 on port esp863888.local:23

 Mar 29 2017 07:19:23   BrewPi version received was 0.2.4 which this script supports in 'legacy' branch mode.
 Mar 29 2017 07:19:23   Bound to TCP socket on port 2877, interface localhost 
 Mar 29 2017 07:19:24   Installed devices received: [{"a": "28FFE27E7114045E", "c": 1, "b": 0, "d": 0, "f": 5, "i": 0, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 8.563}, {"a": "28FF2F332D0400A0", "c": 1, "b": 1, "d": 0, "f": 9, "i": 1, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 10.063}, {"c": 1, "b": 0, "d": 0, "f": 2, "i": 2, "h": 1, "p": 16, "t": 3, "v": 0, "x": 1}, {"c": 1, "b": 0, "d": 0, "f": 3, "i": 3, "h": 1, "p": 14, "t": 3, "v": 0, "x": 1}]
 Mar 29 2017 07:19:31   Available devices received: [{"c": 1, "b": 0, "d": 0, "f": 0, "i": -1, "h": 1, "p": 13, "t": 0, "x": 1}]
Exception in thread zeroconf-Reaper (most likely raised during interpreter shutdown):
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner
  File "/home/fermentrack/venv/local/lib/python2.7/site-packages/zeroconf.py", line 1181, in run
  File "/home/fermentrack/venv/local/lib/python2.7/site-packages/zeroconf.py", line 1716, in wait
  File "/usr/lib/python2.7/threading.py", line 289, in __exit__
  File "/usr/lib/python2.7/threading.py", line 216, in __exit__
  File "/usr/lib/python2.7/threading.py", line 203, in release
<type 'exceptions.TypeError'>: 'NoneType' object is not callable
 Mar 29 2017 11:40:46   Connection type WiFi selected.  Trying TCP serial (WiFi)
 Mar 29 2017 11:40:46   Connecting to BrewPi esp863888.local on port 23
 Mar 29 2017 11:42:39   Connection type WiFi selected.  Trying TCP serial (WiFi)
 Mar 29 2017 11:42:39   Connecting to BrewPi esp863888.local on port 23
 Mar 29 2017 11:42:46   Notification: Script started for beer 'Doppelbock GY045'
 Mar 29 2017 11:42:56   Checking software version on controller... 
 Mar 29 2017 11:42:57   Found BrewPi v0.2.4, running commit 00000000, running on an ESP ESP8266 on port esp863888.local:23

 Mar 29 2017 11:42:57   BrewPi version received was 0.2.4 which this script supports in 'legacy' branch mode.
 Mar 29 2017 11:42:57   Bound to TCP socket on port 2877, interface localhost 
 Mar 29 2017 11:42:58   Installed devices received: [{"a": "28FFE27E7114045E", "c": 1, "b": 0, "d": 0, "f": 5, "i": 0, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 9.75}, {"a": "28FF2F332D0400A0", "c": 1, "b": 1, "d": 0, "f": 9, "i": 1, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 10.125}, {"c": 1, "b": 0, "d": 0, "f": 2, "i": 2, "h": 1, "p": 16, "t": 3, "v": 0, "x": 1}, {"c": 1, "b": 0, "d": 0, "f": 3, "i": 3, "h": 1, "p": 14, "t": 3, "v": 0, "x": 1}]
 Mar 29 2017 11:43:04   Available devices received: [{"c": 1, "b": 0, "d": 0, "f": 0, "i": -1, "h": 1, "p": 13, "t": 0, "x": 1}]
Exception in thread zeroconf-Reaper (most likely raised during interpreter shutdown):
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner
  File "/home/fermentrack/venv/local/lib/python2.7/site-packages/zeroconf.py", line 1181, in run
  File "/home/fermentrack/venv/local/lib/python2.7/site-packages/zeroconf.py", line 1716, in wait
  File "/usr/lib/python2.7/threading.py", line 289, in __exit__
  File "/usr/lib/python2.7/threading.py", line 216, in __exit__
  File "/usr/lib/python2.7/threading.py", line 203, in release
<type 'exceptions.TypeError'>: 'NoneType' object is not callable
 Mar 29 2017 11:47:49   Connection type WiFi selected.  Trying TCP serial (WiFi)
 Mar 29 2017 11:47:49   Connecting to BrewPi esp863888.local on port 23
 Mar 29 2017 11:47:56   Notification: Script started for beer 'Doppelbock GY045'
 Mar 29 2017 11:48:06   Checking software version on controller... 
 Mar 29 2017 11:48:06   Found BrewPi v0.2.4, running commit 00000000, running on an ESP ESP8266 on port esp863888.local:23

 Mar 29 2017 11:48:06   BrewPi version received was 0.2.4 which this script supports in 'legacy' branch mode.
 Mar 29 2017 11:48:06   Bound to TCP socket on port 2877, interface localhost 
 Mar 29 2017 11:48:07   Installed devices received: [{"a": "28FFE27E7114045E", "c": 1, "b": 0, "d": 0, "f": 5, "i": 0, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 9.875}, {"a": "28FF2F332D0400A0", "c": 1, "b": 1, "d": 0, "f": 9, "i": 1, "h": 2, "j": 0.0, "p": 12, "t": 1, "v": 10.125}, {"c": 1, "b": 0, "d": 0, "f": 2, "i": 2, "h": 1, "p": 16, "t": 3, "v": 0, "x": 1}, {"c": 1, "b": 0, "d": 0, "f": 3, "i": 3, "h": 1, "p": 14, "t": 3, "v": 0, "x": 1}]
 Mar 29 2017 11:48:13   Available devices received: [{"c": 1, "b": 0, "d": 0, "f": 0, "i": -1, "h": 1, "p": 13, "t": 0, "x": 1}]

The script does eventually start just takes about 10 mins or so.

[thorrak]

Hmm. That zeroconf error is a strange one - not the error I'm used to seeing from zeroconf. Are you restarting anything when that error occurs, or is it happening naturally?

As a side note, the update I pushed last night should at least permanently fix the script from not launching after a reboot for existing Fermentrack users. Eventually I'll rewrite it to handle the cron change. Not a high priority fix though - the extra 2kb of code doesn't exactly break the bank ;)

[Mikmonken]

My process was update Fermentrack via link. Then the the starting script message is displayed in the LCD.

Waiting 5 minutes or so and rebooted the RPI and get prompted with the same message.

I can access the log at the moment but it seems that the wifi just isnt connecting and it times out, but I can see both the RPI and the ESP have ip addresses assigned according to my router (AirPort Extreme)

It does eventually connect but just takes a very long time. This has only seemed to occur since the serial connection has been introduced and I wonder if it's linked to the slow connection issues I had when it was brewpi? Which I think was scan for serial first and then look for wifi?

Then running your line of code prompts that error message

Same thing happens on two different RPIs with two different ESPs

[thorrak]

Very odd - No changes have been made to any of the code that would impact this. The changes to enable serial support are within blocks of code that are only activated if the "serial" connection type is selected. I'll have to play with it a bit later and see if I can replicate on my end.

[Mikmonken]

yeah I have no idea what is causing it, you can see in the dev-olag-stderr.txt I linked earlier between Mar 19 2017 19:51:48 Connection type WiFi selected. Trying TCP serial (WiFi) Mar 19 2017 19:51:48 Connecting to BrewPi esp864010.local on port 23

and

Mar 19 2017 20:15:29 Connection type WiFi selected. Trying TCP serial (WiFi) Mar 19 2017 20:15:29 Connecting to BrewPi esp864010.local on port 23 Mar 19 2017 20:15:37 Notification: Script started for beer '' Mar 19 2017 20:15:47 Checking software version on controller... Mar 19 2017 20:15:47 Found BrewPi v0.2.4, running commit 00000000, running on an ESP ESP8266 on port esp864010.local:23

this is the period that it is trying to connect to wifi and can't and it's show as starting script.

and it's the same on my other brewpi and different RPI, generally after an RPI reset (which I'm not going to do now on my live RPI until I've finished the brew)

I'm happy to break the other one so long as it's finished cooking dinner

[thorrak]

You and your sous vide. I'll admit something though - you've got me thinking about making these now. I saw a recipe awhile back but didn't have a means of cooking it. Now, I just need to figure out a good heat source.

I attempted to break my raspberry pi by restarting it a few times, but unfortunately wasn't able to get it to demonstrate the behavior you're describing. I'll try to see if I can play with it a bit more this weekend and get it to start. Worst case, I'll bump up the logging for WiFi connections and we'll see if that helps diagnose the issue.

All in the name of progress!

[Mikmonken]

I suspect if you can't replicate it it may have something to do with my set up then given it happens on all my units.

In terms of heat source I just just a crock pot, shove the beer and fridge probes inside it and give me it a heating head start by mixing a kettle or two of boiling water with cold water.

[Mikmonken]

With the last 2 updates this seems to have sped up the time it takes for the devices to connect to wifi, I don't know whether anything has change but it all seems OK not touch wood.

[thorrak]

I'm hoping that with some of the recent changes made due to bug reports on HBT forums this issue is now resolved. Going to close it out for the time being - we can reopen if necessary later.