New V3 keeps rebooting

@Elco,

Have had my new V3 running for a week now and it keeps rebooting at certain times. Have tried powering from 12v and 5v USB but this keeps happening.

Have been in my Brewery when this happens and the V3 beeps and reboots, Have not yet caught the V3 just before it beeps to see what colour the LED is.

Any ideas?

Jul 26 2017 17:53:46 Controller debug message: INFO MESSAGE 12: Received new setting: minCoolTime = 150
Jul 26 2017 17:54:24 Controller debug message: INFO MESSAGE 12: Received new setting: beer2fridge_kp = 8
Jul 26 2017 18:18:26 Controller debug message: INFO MESSAGE 12: Received new setting: beer2fridge_kp = 2
Jul 26 2017 20:01:35 Serial Error: read failed: [Errno 104] Connection reset by peer)
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/brewpi/backgroundserial.py", line 110, in __listen_thread
if self.writeln("") > 0:
File "/home/brewpi/backgroundserial.py", line 56, in writeln
return self.write(data + "\n")
File "/home/brewpi/backgroundserial.py", line 59, in write
self.exit_on_fatal_error()
File "/home/brewpi/backgroundserial.py", line 75, in exit_on_fatal_error
self.stop()
File "/home/brewpi/backgroundserial.py", line 38, in stop
self.thread.join() # wait for background thread to terminate
File "/usr/lib/python2.7/threading.py", line 931, in join
raise RuntimeError("cannot join current thread")
RuntimeError: cannot join current thread

Jul 26 2017 20:01:35 Lost serial connection. Cannot write to serial
Terminating due to fatal serial error
Jul 26 2017 20:02:08 Notification: Script started for beer 'Cellar-01'
Jul 26 2017 20:02:08 Connecting to controller...
Jul 26 2017 20:02:08 Opening serial port
Jul 26 2017 20:02:08 Checking software version on controller... 
Jul 26 2017 20:02:08 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666

Jul 27 2017 00:00:00 Notification: New day, creating new JSON file.
Jul 27 2017 06:58:33 Serial Error: read failed: [Errno 104] Connection reset by peer)
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/brewpi/backgroundserial.py", line 110, in __listen_thread
if self.writeln("") > 0:
File "/home/brewpi/backgroundserial.py", line 56, in writeln
return self.write(data + "\n")
File "/home/brewpi/backgroundserial.py", line 59, in write
self.exit_on_fatal_error()
File "/home/brewpi/backgroundserial.py", line 75, in exit_on_fatal_error
self.stop()
File "/home/brewpi/backgroundserial.py", line 38, in stop
self.thread.join() # wait for background thread to terminate
File "/usr/lib/python2.7/threading.py", line 931, in join
raise RuntimeError("cannot join current thread")
RuntimeError: cannot join current thread

Jul 27 2017 06:58:34 Lost serial connection. Cannot write to serial
Terminating due to fatal serial error
Jul 27 2017 06:59:04 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 06:59:04 Connecting to controller...
Jul 27 2017 06:59:04 Opening serial port
Jul 27 2017 06:59:05 Checking software version on controller... 
Jul 27 2017 06:59:05 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666

Jul 27 2017 15:29:36 Error: controller is not responding anymore. Exiting script.
Jul 27 2017 15:30:10 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 15:30:10 Connecting to controller...
Jul 27 2017 15:30:10 Opening serial port
Jul 27 2017 15:31:10 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: timed out

Jul 27 2017 15:31:40 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 15:31:40 Connecting to controller...
Jul 27 2017 15:31:40 Opening serial port
Jul 27 2017 15:31:40 Checking software version on controller... 
Jul 27 2017 15:31:40 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666

Jul 27 2017 15:31:51 Serial Error: read failed: [Errno 104] Connection reset by peer)
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/brewpi/backgroundserial.py", line 110, in __listen_thread
if self.writeln("") > 0:
File "/home/brewpi/backgroundserial.py", line 56, in writeln
return self.write(data + "\n")
File "/home/brewpi/backgroundserial.py", line 59, in write
self.exit_on_fatal_error()
File "/home/brewpi/backgroundserial.py", line 75, in exit_on_fatal_error
self.stop()
File "/home/brewpi/backgroundserial.py", line 38, in stop
self.thread.join() # wait for background thread to terminate
File "/usr/lib/python2.7/threading.py", line 931, in join
raise RuntimeError("cannot join current thread")
RuntimeError: cannot join current thread

Jul 27 2017 15:31:51 Lost serial connection. Cannot write to serial
Terminating due to fatal serial error
Jul 27 2017 15:32:22 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 15:32:22 Connecting to controller...
Jul 27 2017 15:32:22 Opening serial port
Jul 27 2017 15:32:40 Checking software version on controller... 
Jul 27 2017 15:32:40 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666

Jul 27 2017 16:45:48 Serial Error: read failed: [Errno 104] Connection reset by peer)
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/brewpi/backgroundserial.py", line 110, in __listen_thread
if self.writeln("") > 0:
File "/home/brewpi/backgroundserial.py", line 56, in writeln
return self.write(data + "\n")
File "/home/brewpi/backgroundserial.py", line 59, in write
self.exit_on_fatal_error()
File "/home/brewpi/backgroundserial.py", line 75, in exit_on_fatal_error
self.stop()
File "/home/brewpi/backgroundserial.py", line 38, in stop
self.thread.join() # wait for background thread to terminate
File "/usr/lib/python2.7/threading.py", line 931, in join
raise RuntimeError("cannot join current thread")
RuntimeError: cannot join current thread

Jul 27 2017 16:45:49 Lost serial connection. Cannot write to serial
Terminating due to fatal serial error
Jul 27 2017 16:46:19 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 16:46:19 Connecting to controller...
Jul 27 2017 16:46:19 Opening serial port
Jul 27 2017 16:46:19 Checking software version on controller... 
Jul 27 2017 16:46:19 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666

Jul 27 2017 17:29:05 Serial Error: read failed: [Errno 104] Connection reset by peer)
Jul 27 2017 17:29:06 Lost serial connection. Error: Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused)
Terminating due to fatal serial error
Jul 27 2017 17:29:36 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:29:36 Connecting to controller...
Jul 27 2017 17:29:36 Opening serial port
Jul 27 2017 17:29:46 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:30:16 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:30:16 Connecting to controller...
Jul 27 2017 17:30:16 Opening serial port
Jul 27 2017 17:30:26 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:30:57 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:30:57 Connecting to controller...
Jul 27 2017 17:30:57 Opening serial port
Jul 27 2017 17:31:07 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:31:37 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:31:37 Connecting to controller...
Jul 27 2017 17:31:37 Opening serial port
Jul 27 2017 17:31:47 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:32:17 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:32:17 Connecting to controller...
Jul 27 2017 17:32:17 Opening serial port
Jul 27 2017 17:32:27 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:32:57 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:32:57 Connecting to controller...
Jul 27 2017 17:32:57 Opening serial port
Jul 27 2017 17:33:07 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:33:37 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:33:37 Connecting to controller...
Jul 27 2017 17:33:37 Opening serial port
Jul 27 2017 17:33:47 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:34:17 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:34:17 Connecting to controller...
Jul 27 2017 17:34:17 Opening serial port
Jul 27 2017 17:34:27 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:34:58 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:34:58 Connecting to controller...
Jul 27 2017 17:34:58 Opening serial port
Jul 27 2017 17:35:08 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:35:38 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:35:38 Connecting to controller...
Jul 27 2017 17:35:38 Opening serial port
Jul 27 2017 17:35:48 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:36:18 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:36:18 Connecting to controller...
Jul 27 2017 17:36:18 Opening serial port
Jul 27 2017 17:36:28 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:36:58 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:36:58 Connecting to controller...
Jul 27 2017 17:36:58 Opening serial port
Jul 27 2017 17:37:08 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:37:38 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:37:38 Connecting to controller...
Jul 27 2017 17:37:38 Opening serial port
Jul 27 2017 17:37:48 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:38:18 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:38:18 Connecting to controller...
Jul 27 2017 17:38:18 Opening serial port
Jul 27 2017 17:38:28 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:38:59 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:38:59 Connecting to controller...
Jul 27 2017 17:38:59 Opening serial port
Jul 27 2017 17:39:09 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:39:39 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:39:39 Connecting to controller...
Jul 27 2017 17:39:39 Opening serial port
Jul 27 2017 17:39:49 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:40:19 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:40:19 Connecting to controller...
Jul 27 2017 17:40:19 Opening serial port
Jul 27 2017 17:40:29 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:40:59 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:40:59 Connecting to controller...
Jul 27 2017 17:40:59 Opening serial port
Jul 27 2017 17:41:09 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:41:39 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:41:39 Connecting to controller...
Jul 27 2017 17:41:39 Opening serial port
Jul 27 2017 17:41:49 Errors while opening serial port: 
Could not open port socket://192.168.0.147:6666: [Errno 111] Connection refused

Jul 27 2017 17:42:20 Notification: Script started for beer 'Cellar-01'
Jul 27 2017 17:42:20 Connecting to controller...
Jul 27 2017 17:42:20 Opening serial port
Jul 27 2017 17:42:21 Checking software version on controller... 
Jul 27 2017 17:42:21 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666

Jul 28 2017 00:00:00 Notification: New day, creating new JSON file

The controller will automatically reboot if it is stuck, due to the watchdog timer. Why it is stuck and where, that’s a much harder question to answer.

If you have any more info on your setup and what it is doing and if you can catch it happening, that would help. I’m especially puzzled by what happened around 17:35, it took some time to come back.

I have it setup in Beer constant mode at the moment controlling a Fridge/Kegorator.

What other information would you like to know. Do you want me to share my settings etc?

How is the WiFi reception? To be honest, I’m in the dark here. I don’t know what is causing this and not even which questions to ask. So any info would be good.

Maybe you can add ?logging=debug at the end of the port setting. That could give us some more info.

Is your BrewPi script up-to-date? What is the output of git log?

Wifi reception is very good, and no other item in the brewery has this issue have a V2 Photon also connected over Wifi and that has no issues

I’m running Docker on a Qnap NAS. That side seems to be ok, I’ll upload some info and update the port setting and try to setup a CCTV camera pointing at the V3 to see if I can catch the LED colours before the reboot.

I did sit there one night for an hour trying to catch it in the act but it did not do it.

git log output

root@9e08f49c7fa8:/home/brewpi# git log
commit 007cbbfe659aeef287def3a83497c142503e9554
Author: Elco Jacobs <elco@brewpi.com>
Date:   Wed Jul 19 22:30:30 2017 +0200

    Updated default settings and some extra debug printing
  "kind": "Control",
  "pids": [
    {
      "kind": "Pid",
      "name": "heater1pid",
      "enabled": true,
      "input": {
        "kind": "SensorSetPointPair",
        "sensor": {
          "kind": "TempSensorFallback",
          "onBackupSensor": false,
          "sensor": {
            "kind": "TempSensorDelegate",
            "name": "fridge",
            "delegate": {
              "kind": "OneWireTempSensor",
              "value": 11.5625,
              "connected": true,
              "address": "286589C00700004D",
              "calibrationOffset": 0
            }
          }
        },
        "setPoint": {
          "kind": "SetPointSimple",
          "name": "fridgeset",
          "value": 12.293
        }
      },
      "output": {
        "kind": "ActuatorPwm",
        "dutySetting": 11.0938,
        "period": 4,
        "minVal": 0,
        "maxVal": 100,
        "target": {
          "kind": "ActuatorMutexDriver",
          "mutexGroup": {
            "kind": "ActuatorMutexGroup",
            "deadTime": 1800000,
            "waitTime": 1613736
          },
          "target": {
            "kind": "ActuatorDigitalDelegate",
            "name": "heater1",
            "delegate": {
              "kind": "ActuatorOneWire",
              "state": false,
              "pio": 1,
              "invert": false
            }
          }
        }
      },
      "inputError": -0.6953,
      "Kp": 10,
      "Ti": 600,
      "Td": 60,
      "p": 6.9531,
      "i": 0,
      "d": 4.1406,
      "actuatorIsNegative": false
    },
    {
      "kind": "Pid",
      "name": "heater2pid",
      "enabled": true,
      "input": {
        "kind": "SensorSetPointPair",
        "sensor": {
          "kind": "TempSensorDelegate",
          "name": "beer2",
          "delegate": {
            "kind": "TempSensorDisconnected",
            "value": null,
            "connected": false
          }
        },
        "setPoint": {
          "kind": "SetPointSimple",
          "name": "beer2set",
          "value": null
        }
      },
      "output": {
        "kind": "ActuatorPwm",
        "dutySetting": 0,
        "period": 4,
        "minVal": 0,
        "maxVal": 100,
        "target": {
          "kind": "ActuatorMutexDriver",
          "mutexGroup": {
            "kind": "ActuatorMutexGroup",
            "deadTime": 1800000,
            "waitTime": 1613719
          },
          "target": {
            "kind": "ActuatorDigitalDelegate",
            "name": "heater2",
            "delegate": {
              "kind": "ActuatorNop",
              "state": false
            }
          }
        }
      },
      "inputError": null,
      "Kp": 10,
      "Ti": 600,
      "Td": 60,
      "p": 0,
      "i": 0,
      "d": 0,
      "actuatorIsNegative": false
    },
    {
      "kind": "Pid",
      "name": "coolerpid",
      "enabled": true,
      "input": {
        "kind": "SensorSetPointPair",
        "sensor": {
          "kind": "TempSensorFallback",
          "onBackupSensor": false,
          "sensor": {
            "kind": "TempSensorDelegate",
            "name": "fridge",
            "delegate": {
              "kind": "OneWireTempSensor",
              "value": 11.5625,
              "connected": true,
              "address": "286589C00700004D",
              "calibrationOffset": 0
            }
          }
        },
        "setPoint": {
          "kind": "SetPointSimple",
          "name": "fridgeset",
          "value": 12.293
        }
      },
      "output": {
        "kind": "ActuatorPwm",
        "dutySetting": 17.6797,
        "period": 1200,
        "minVal": 0,
        "maxVal": 100,
        "target": {
          "kind": "ActuatorMutexDriver",
          "mutexGroup": {
            "kind": "ActuatorMutexGroup",
            "deadTime": 1800000,
            "waitTime": 1613701
          },
          "target": {
            "kind": "ActuatorTimeLimited",
            "minOnTime": 150,
            "minOffTime": 180,
            "maxOnTime": 65535,
            "state": false,
            "target": {
              "kind": "ActuatorDigitalDelegate",
              "name": "cooler",
              "delegate": {
                "kind": "ActuatorOneWire",
                "state": false,
                "pio": 0,
                "invert": false
              }
            }
          }
        }
      },
      "inputError": -0.6953,
      "Kp": 10,
      "Ti": 1800,
      "Td": 200,
      "p": 6.9531,
      "i": -38.4219,
      "d": 13.7891,
      "actuatorIsNegative": true
    },
    {
      "kind": "Pid",
      "name": "beer2fridgepid",
      "enabled": true,
      "input": {
        "kind": "SensorSetPointPair",
        "sensor": {
          "kind": "TempSensorDelegate",
          "name": "beer1",
          "delegate": {
            "kind": "OneWireTempSensor",
            "value": 12,
            "connected": true,
            "address": "28FD78C007000036",
            "calibrationOffset": 0
          }
        },
        "setPoint": {
          "kind": "SetPointSimple",
          "name": "beer1set",
          "value": 12
        }
      },
      "output": {
        "kind": "ActuatorOffset",
        "target": {
          "kind": "SensorSetPointPair",
          "sensor": {
            "kind": "TempSensorFallback",
            "onBackupSensor": false,
            "sensor": {
              "kind": "TempSensorDelegate",
              "name": "fridge",
              "delegate": {
                "kind": "OneWireTempSensor",
                "value": 11.5625,
                "connected": true,
                "address": "286589C00700004D",
                "calibrationOffset": 0
              }
            }
          },
          "setPoint": {
            "kind": "SetPointSimple",
            "name": "fridgeset",
            "value": 12.293
          }
        },
        "reference": {
          "kind": "SensorSetPointPair",
          "sensor": {
            "kind": "TempSensorDelegate",
            "name": "beer1",
            "delegate": {
              "kind": "OneWireTempSensor",
              "value": 12,
              "connected": true,
              "address": "28FD78C007000036",
              "calibrationOffset": 0
            }
          },
          "setPoint": {
            "kind": "SetPointSimple",
            "name": "beer1set",
            "value": 12
          }
        },
        "useReferenceValue": false,
        "setting": 0.293,
        "achieved": -0.4375,
        "minimum": -10,
        "maximum": 10
      },
      "inputError": 0,
      "Kp": 2,
      "Ti": 7200,
      "Td": 1200,
      "p": 0,
      "i": -0.3789,
      "d": 0.6719,
      "actuatorIsNegative": false
    }
  ]
}

What kind of heater do you have? Maybe the start of heating and the lockup is not a coincidence.

Its a small 60w tube heater, ran via SSR, this is also via the SSR one-wire expansion board.

That doesn’t sound like it would cause issues.

To test, you could take these steps:

  • Set control to OFF
  • Go to device manager and uninstall heater (function none -> apply)
  • Reinstall heater as ‘Manual Actuator’
  • Toggle heater from device list.

Ok, I’ll give that a try

Have tried and heater is now on with no reboot. I also toggled it on/off/on/off over a period and still no reboot.

Do you think it worth trying to capture cctv footage of the V3’s LED and correlate this to a reboot by time? I saw a previous post about red LED just before reboot but have not been able to capture this.

Managed to catch the V3 LED on CCTV video, Seems the green breathing stops for 30 seconds then 1 red long flash followed by 9 fast, 1 slow and 9 fast then reboot,.

and with the serial debug output.

INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 14:45:22 Error: controller is not responding anymore. Exiting script.
Jul 28 2017 14:45:52 Notification: Script started for beer 'Cellar-01'
Jul 28 2017 14:45:52 Connecting to controller...
Jul 28 2017 14:45:52 Opening serial port
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored reset_output_buffer
Jul 28 2017 14:45:52 Checking software version on controller... 
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 14:45:52 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666?logging=debug

INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 14:52:35 Serial Error: read failed: [Errno 104] Connection reset by peer)
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/brewpi/backgroundserial.py", line 110, in __listen_thread
if self.writeln("") > 0:
File "/home/brewpi/backgroundserial.py", line 56, in writeln
return self.write(data + "\n")
File "/home/brewpi/backgroundserial.py", line 59, in write
self.exit_on_fatal_error()
File "/home/brewpi/backgroundserial.py", line 75, in exit_on_fatal_error
self.stop()
File "/home/brewpi/backgroundserial.py", line 38, in stop
self.thread.join() # wait for background thread to terminate
File "/usr/lib/python2.7/threading.py", line 931, in join
raise RuntimeError("cannot join current thread")
RuntimeError: cannot join current thread

Jul 28 2017 14:52:36 Lost serial connection. Cannot write to serial
Terminating due to fatal serial error
Jul 28 2017 14:53:06 Notification: Script started for beer 'Cellar-01'
Jul 28 2017 14:53:06 Connecting to controller...
Jul 28 2017 14:53:06 Opening serial port
DEBUG:pySerial.socket:enabled logging
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored reset_output_buffer
Jul 28 2017 14:53:07 Checking software version on controller... 
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 14:53:08 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666?logging=debug

INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored port configuration change

That is good info!

It is documented here what the red flashes mean:
https://docs.particle.io/guide/getting-started/modes/photon/#red-flash-sos

It’s first an SOS signal, then a number of blinks. If the first 9 blinks are an SOS signal, then you only have 1 other blink, which indicates hard fault. A hard fault could be caused by accessing an invalid memory address for example.

I’m going to dig through the code to see if I can find any possible causes. If you can help me narrow down the cause in any way or can describe what the controller was doing at the time, that would help.

I wonder whether it is related to this long standing bug:



Which just got fixed in particle firmware 0.7.0-rc2

The green blinking stopping for 30 seconds before the hard fault is why I think it could maybe be related.

But if the photon is right next to it with the same wifi, that maybe rules it out.

@mdma, any ideas?

Could that be caused if I have multiple AP’s?

Good question and I don’t know. We might have uncovered a new bug in the particle stack. If there is a way to test this, that would be interesting info. Can temporarily switch one of the AP’s to a separate SSID?

i’ll temporary turn one of the AP’s off, signal will diminish but still be fair, just not good.

Now that is interesting, just turned one AP off and the V3 just rebooted at the same time and associated with the other AP.

I’ll leave it like that for a few days and let you know if it reboots at all.

It is now moving between the other AP’s, here is a list of where the P1 has been associated

As you can see it just associated with Landing and a little later with Log Cabin, just the it also rebooted.

Mobility Trail (Last 7 days)
 
Access Points 
Date/Time 
Log Cabin
Fri, 28 Jul 2017 18:56:13 GMT
Landing
Fri, 28 Jul 2017 18:50:10 GMT
Living
Fri, 28 Jul 2017 16:45:41 GMT
Landing
Fri, 28 Jul 2017 13:54:56 GMT
Living
Fri, 28 Jul 2017 13:46:54 GMT
Landing
Fri, 28 Jul 2017 13:44:55 GMT
Living
Thu, 27 Jul 2017 15:47:06 GMT
Landing
Thu, 27 Jul 2017 14:34:06 GMT

INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 19:51:09 Error: controller is not responding anymore. Exiting script.
Jul 28 2017 19:51:39 Notification: Script started for beer 'Cellar-01'
Jul 28 2017 19:51:39 Connecting to controller...
Jul 28 2017 19:51:39 Opening serial port
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored reset_output_buffer
Jul 28 2017 19:51:39 Checking software version on controller... 
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 19:51:39 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666?logging=debug

INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 19:55:20 Serial Error: read failed: [Errno 104] Connection reset by peer)
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/brewpi/backgroundserial.py", line 110, in __listen_thread
if self.writeln("") > 0:
File "/home/brewpi/backgroundserial.py", line 56, in writeln
return self.write(data + "\n")
File "/home/brewpi/backgroundserial.py", line 59, in write
self.exit_on_fatal_error()
File "/home/brewpi/backgroundserial.py", line 75, in exit_on_fatal_error
self.stop()
File "/home/brewpi/backgroundserial.py", line 38, in stop
self.thread.join() # wait for background thread to terminate
File "/usr/lib/python2.7/threading.py", line 931, in join
raise RuntimeError("cannot join current thread")
RuntimeError: cannot join current thread

Jul 28 2017 19:55:20 Lost serial connection. Cannot write to serial
Terminating due to fatal serial error
Jul 28 2017 19:55:51 Notification: Script started for beer 'Cellar-01'
Jul 28 2017 19:55:51 Connecting to controller...
Jul 28 2017 19:55:51 Opening serial port
DEBUG:pySerial.socket:enabled logging
DEBUG:pySerial.socket:enabled logging
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored _update_dtr_state(True)
INFO:pySerial.socket:ignored _update_rts_state(True)
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored reset_output_buffer
Jul 28 2017 19:55:52 Checking software version on controller... 
INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored reset_output_buffer
INFO:pySerial.socket:ignored port configuration change
Jul 28 2017 19:55:52 Found BrewPi v0.5.2 build 0.5.2-0-g72e633171, running on a Particle p1 with a V3 shield on port socket://192.168.0.147:6666?logging=debug

INFO:pySerial.socket:ignored port configuration change
INFO:pySerial.socket:ignored port configuration change

Good info, feels like we are narrowing down the cause! Especially if you turn off one AP and it causes the SOS immediately. That sounds like a repeatable test case :slight_smile:, which will make fixing the bug a lot easier.

This is defiantly repeatable, I have just rebooted Log Cabin at 20:06 and

Jul 28 2017 20:06:48 Lost serial connection. Cannot write to serial

ends up in the logs

Do both access points have the same SSID?
The Spark can remember multiple SSIDs, and will remember 5 networks if I remember correctly.

To remove all access points from the memory of the Spark and start fresh, you can hold the setup button for about 10 seconds until you get fast blue flashing. But if you have multipe APs with the same credentials, that’s not the problem here.

If the Spark decides to connect to a different access point and gets a new IP, then it is of course normal that the connection is lost. A hard fault should still not occur of course, but maybe we could detect that and prevent the hard fault.

Yes, they all broadcast the same SSID’s with active roaming between them, I’ll check the DHCP reservation is correct but as you say it should just loose connection not hard fault.