Photon freezing during interrupt function (maybe publish and/or other reason)

Troubleshooting
21

Might be worth a closer look then for the engineers - @rickkas7?

22

@ScruffR, @Ric, I would avoid the ATOMIC_BLOCK. The sprintf() is a hog. Have you tried running without any of those extras in there? Still, I still donā€™t see any debouncing which may be part of the problem if multiple timer starts are called before the FreeRTOS queued messages are flushed. I feel ignored :disappointed:

1 Like
23

As said, it shouldnā€™t be required for an ISR anyway (and also not used casually), but for testing I thought it would exclude some possible suspects from the list :wink:

If multiple timer starts cause a system freeze, thatā€™d be something to guard against on the system side, Iā€™d think.

And missing debouncing might be the way to find out :wink: We donā€™t ignore you, we are just stubborn :sunglasses:

24

At least two areas of attack then:

@peekay123 - debounce protection for the startFromISR(); There are a couple ways to do this.

The device_running_timer.startFromISR(); can be protected with a flag so that once it is called once, it does not get called again until the timer actually runs out.

Within static void motion_sensor_detection_handler () {

  if (!myTimerFlag) {
    myTimerFlag = true;
    device_running_timer.startFromISR();
  }

@ScruffR - minimize the ISR routine and put all the work in the loop();

2 Likes
25

@ScruffR, I agree with the debounce only being for testing. The multiple, consecutive timer restart is a hunch and thus why I suggested testing the code with the debounce and nothing extra in the ISR.

@cermak, great idea!

1 Like
26

Fundamental question: Can an ISR routine be interrupted by another interrupt? Or is that signal put on the stack until the current ISR finishes?

EDIT: The answer is in the doc after re-reading. ā€œGenerally, an ISR should be as short and fast as possible. If your sketch uses multiple ISRs, only one can run at a time, other interrupts will be executed after the current one finishes in an order that depends on the priority they have.ā€

27

To expand on that a bit:

Higher priority interrupts can interrupt lower priority ones.
Same and lower priority interrupts will only be registered once (even if there were multiple triggers) and may or may not (depending on code that clears the interrupt registers) be exectued after the first ISR finishes.

1 Like
28

Guys, I think all these would be workarounds but still it would not fulfill my requirements.

Problem is somewhere else maybe.

  1. I debugged this issue by digging out startFromISR(). I found startFromISR() returns success and failure. To trace the returned value (false) I used another LED indication and it is returning false, not sure whether it is with first call or consecutive calls.

  2. Apart from this, I explored startFromISR() further from platform end to know how it is using xTimerStartFromISR() for FreeRTOS. Looks like the code present at https://github.com/spark/firmware/blob/ad64959eac6e3e3e68c1e17ef817e5bbbf1dca29/hal/src/stm32f2xx/concurrent_hal.cpp
    os_timer_change() is not following all the instructions specified by http://www.freertos.org/FreeRTOS-timers-xTimerStartFromISR.html
    It is not looking at the value of woken. Looks like context switching is required to run timer task and it is blocked by interrupt task.

Interestingly, I found very much similar example on same FreeRTOS page.

Thanks

29

Since we have one ISR, then it should not interrupt itself. However, because of the potential queuing issue of the restart of the timer, we need to debounce it somehow.

The next question isā€¦ what is a reasonable debounce period for allowing startFromISR() to finish so we can legitimately call it again? Just setting the flag does part of the job, if motion is still being detected, we actually at some point want to restart the timer.

Question back to @mehulhirpara is how sensitive do you want this to be? The code will always see the first motion and set the timer into motion. The timer runs 10 seconds, so the debounce can really be up to that limit. If we gave the timer routine queue say 500 ms to process, is that sufficient? It is somewhat contingent on how busy the project is overall.

2 Likes
30

@mehulhirpara, the ISR is insulated from the Timer task via a command queue so there is no guarantee of when the command will actually be executed. As for doing a context switch:

taskYIELD() is used to request a context switch to another task. However, if there are no other tasks at a higher or equal priority to the task that calls taskYIELD() then the RTOS scheduler will simply select the task that called taskYIELD() to run again.

If configUSE_PREEMPTION is set to 1 then the RTOS scheduler will always be running the highest priority task that is able to run, so calling taskYIELD() will never result in a switch to a higher priority task.

The Particle firmware sets configUSE_PREEMPTION to 1 so there is no need to do a context switch.

31

Ok, I havenā€™t crashed this code yet. I moved the Serial.print(s) to the loop() with an extra flag tracking the state of the timer. It also counts the debounces so if the timer is running, you can still detect excessive motion or excessive (noise!) signal from the sensor. Debounce is the key.

// Working inside the timer and ISR
#define DEBOUNCEPERIOD 500
volatile long lastTimerStart = 0;
volatile int debouncecount = 0;

// Motion detection flag, based on a 
// timerFlag.
boolean timerFlag = false;

#define LED_PIN D7
#define MOTION_SENSOR_PIN D5

/* Delay before switching off device */
#define TURN_OFF_DELAY 10000

static void motion_sensor_detection_handler(void);
static void timer_callback_handler(void);

static Timer device_running_timer(TURN_OFF_DELAY, timer_callback_handler, true);

static void timer_callback_handler() {
  /* turn off LED after specified delay */
  digitalWrite(LED_PIN, HIGH);
}

static void motion_sensor_detection_handler () {

  // Debouncer
  if ((millis() - lastTimerStart) < DEBOUNCEPERIOD) {
    debouncecount++;
    return; 
  }
  lastTimerStart = millis();

  /* Reset the timer */
  device_running_timer.startFromISR();

  /* turn LED on */
  digitalWrite(LED_PIN, LOW);
}

void setup() {
  
  /* turn off led */
  pinMode(LED_PIN, OUTPUT);
  digitalWrite(LED_PIN, HIGH);

  /* attach ISR to sensor pin */
  pinMode(MOTION_SENSOR_PIN, INPUT_PULLDOWN);
  attachInterrupt(MOTION_SENSOR_PIN, motion_sensor_detection_handler, RISING);

  Serial.begin();

  Log.info("System version: %s", (const char*)System.version());
}

void loop () {

  if (timerFlag && !device_running_timer.isActive()) {
    Serial.println("Timer reset.");
    timerFlag = false;
  } 
  if (!timerFlag && device_running_timer.isActive()) {
    Serial.println("Motion detected.");
    timerFlag = true;
  }

  if (debouncecount > 0) {
    Serial.printlnf("Extra motion detected: %d", debouncecount);
    debouncecount = 0;
  }

}

Opening serial monitor for com port: "/dev/cu.usbmodem1421"
Serial monitor opened successfully:
0000015526 [system] INFO: ARM_WLAN_WD 2
0000015526 [hal.wlan] INFO: Bringing WiFi interface up with DHCP
0000015558 [system] INFO: CLR_WLAN_WD 1, DHCP success
0000015559 [system] INFO: Cloud: connecting
0000015560 [system] INFO: Read Server Address = type:1,domain:device.spark.io
0000015735 [system] INFO: Resolved host device.spark.io to 54.175.227.173
0000015894 [system] INFO: connected to cloud 54.175.227.173:5683
0000015895 [system] INFO: Cloud socket connected
0000015895 [system] INFO: Starting handshake: presense_announce=1
0000015895 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce
0000016058 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce
0000016105 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce
0000016106 [comm.sparkprotocol.handshake] INFO: Receive key
0000016273 [comm.sparkprotocol.handshake] INFO: Setting key
0000016462 [comm.sparkprotocol.handshake] INFO: Sending HELLO message
0000016463 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response
0000016680 [comm.sparkprotocol.handshake] INFO: Completed
0000016680 [system] INFO: Send spark/hardware/max_binary event
0000016680 [system] INFO: spark/hardware/ota_chunk_size event
0000016681 [system] INFO: Send spark/device/last_reset event
0000016681 [system] INFO: Send subscriptions
0000016682 [comm.sparkprotocol] INFO: Sending TIME request
0000016683 [system] INFO: Cloud connected
0000016684 [app] INFO: System version: 0.6.2
0000017007 [comm.sparkprotocol] INFO: Received TIME response: 1501696593
0000018261 [comm.sparkprotocol] INFO: Sending A describe message
0000018431 [comm.sparkprotocol] INFO: Sending S describe message
Motion detected.
Extra motion detected: 2
Extra motion detected: 3
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 4
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 3
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 1
Timer reset.
Motion detected.
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Timer reset.
Motion detected.
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 4
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 6
Extra motion detected: 1
Timer reset.
Motion detected.
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 4
Extra motion detected: 1
Extra motion detected: 4
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 11
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 4
Extra motion detected: 4
Extra motion detected: 7
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 2
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 1
Extra motion detected: 6
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 3
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 5
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 8
Extra motion detected: 14
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 6
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 5
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 6
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 2
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 4
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 2
Extra motion detected: 2
Extra motion detected: 6
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 4
Extra motion detected: 1
Extra motion detected: 1
Timer reset.
Motion detected.
Extra motion detected: 2
Extra motion detected: 1
Timer reset.
Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000015442 [system] INFO: ARM_WLAN_WD 2
0000015442 [hal.wlan] INFO: Bringing WiFi interface up with DHCP
0000015474 [system] INFO: CLR_WLAN_WD 1, DHCP success
0000015475 [system] INFO: Cloud: connecting
0000015476 [system] INFO: Read Server Address = type:1,domain:device.spark.io
0000020635 [system] INFO: Resolved host device.spark.io to 52.90.147.116
0000020801 [system] INFO: connected to cloud 52.90.147.116:5683
0000020802 [system] INFO: Cloud socket connected
0000020802 [system] INFO: Starting handshake: presense_announce=1
0000020802 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce
0000020965 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce
0000021012 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce
0000021013 [comm.sparkprotocol.handshake] INFO: Receive key
0000021179 [comm.sparkprotocol.handshake] INFO: Setting key
0000021368 [comm.sparkprotocol.handshake] INFO: Sending HELLO message
0000021369 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response
0000021556 [comm.sparkprotocol.handshake] INFO: Completed
0000021556 [system] INFO: Send spark/hardware/max_binary event
0000021557 [system] INFO: spark/hardware/ota_chunk_size event
0000021557 [system] INFO: Send spark/device/last_reset event
0000021558 [system] INFO: Send subscriptions
0000021558 [comm.sparkprotocol] INFO: Sending TIME request
0000021560 [system] INFO: Cloud connected
0000021561 [app] INFO: System version: 0.6.2
0000021880 [comm.sparkprotocol] INFO: Received TIME response: 1501696727
0000023013 [comm.sparkprotocol] INFO: Sending A describe message
0000023188 [comm.sparkprotocol] INFO: Sending S describe message
Motion detected.
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 9
Extra motion detected: 1
Extra motion detected: 1
Timer reset.
Motion detected.
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 6
Extra motion detected: 2
Extra motion detected: 1
Extra motion detected: 1
Extra motion detected: 1
1 Like
32

@cermak, better! However, my take on the ISR and motion detection varies. With SYSTEM_THREAD(ENABLED), loop() will run every 1ms. Setting a flag in the ISR and polling it in loop(), and letting loop() do the debounce delay, would simplify the code and remove any ISR issues. Well written, non blocking loop() code will impose little delay in the detection, especially with a long debounce period.

Buttons are noisy and the actual motion sensor will most likely have it own hysteresis slowing down the detection process and noise. Folks tend to get stuck in how fast ā€œreal timeā€ needs to be!

1 Like
33

@cermak, thanks for the working version :slight_smile:

Question back to @mehulhirpara is how sensitive do you want this to be?

I think, if I could detect an interrupt per second is more than sufficient to reset the timer back to next 10 seconds and in the same line I wrote follow working code:

#include "Particle.h"

//=======================================================================
// DEFINITIONS
//=======================================================================

#define DEVICE_PIN D1
#define MOTION_SENSE_PIN D5

#define dbg Serial.printf

//=======================================================================
// APPLICATON CONFIGURATIONS
//=======================================================================

/* Delay before switching off device */
#define TURN_OFF_TIME_IN_SECONDS 10
#define MOTION_CHECK_FREQUENCY_PER_SECOND 1
#define SECOND 1000
#define PERIOD (SECOND/MOTION_CHECK_FREQUENCY_PER_SECOND)

//=======================================================================
// GLOBLE VARIABLES
//=======================================================================

static void motion_detection_callback_handler(void);
static void timer_callback_handler(void);

static Timer device_running_timer(PERIOD, timer_callback_handler);

volatile bool is_motion_detected = false;
int motion_check_counter = 0;
bool is_timer_running = false;

//=======================================================================
// FUNCTIONS
//=======================================================================

static void timer_callback_handler() {
  if (is_motion_detected) {
    motion_check_counter = 0;
    is_motion_detected = false;
  }
  
  motion_check_counter++;
  
  if (motion_check_counter >= TURN_OFF_TIME_IN_SECONDS) {
    digitalWrite(DEVICE_PIN, HIGH);
    device_running_timer.stop();
    motion_check_counter = 0;
    is_timer_running = false;
  }
}

static void motion_detection_callback_handler () {
  is_motion_detected = true;
  
  digitalWrite(DEVICE_PIN, LOW);

  if (is_timer_running == false) {
    if(device_running_timer.startFromISR()) {
      is_motion_detected = false;
      is_timer_running = true;
    }
  }
}

void setup() {
  pinMode(DEVICE_PIN, OUTPUT);
  digitalWrite(DEVICE_PIN, HIGH);

  pinMode(MOTION_SENSE_PIN, INPUT_PULLDOWN);
  attachInterrupt(MOTION_SENSE_PIN, motion_detection_callback_handler, RISING);

  Serial.begin();
}
34

Getting better.

I believe the programming pattern @peekay123 and @ScruffR suggest is minimizing the code in the interrupt function and process any status changes within the loop() function. IE: Set some basic flag(s) or counter(s) in the ISR and process those events back in the loop().

It is probably wise to do same for the timer function(s).

If you get stuck, keep posting code and asking questions. I think you are heading in the right direction.

1 Like
35

If you get stuck, keep posting code and asking questions. I think you are heading in the right direction.

Sure @cermak.

Thanks to all for quick support.

1 Like