[SOLVED] latest git-snapshot causes freezes

[tekka]

@cimba007 Thanks, I'll try to reproduce it. What Arduino IDE & AVR Board defs are you using?
@ikkeT Same here, can you upload your (minimal) sketch to reproduce and also indicate MySensors, Arduino IDE and AVR board def versions?

[scalz]

@cimba007
just an idea..i don't know if it can help at all..but it looks there is a while loop in FaBo3Axis::readI2c
do you think if adding some debug here you get something??
i was just thinking..a freeze that's weird..no wdt?

[cimba007]

@tekka Arduiono 1.6.12

##############################################################
# Add the new board to boards.txt (normally located at "C:\Program Files\Arduino\hardware\arduino\avr"
# The *.bootloader.* etries only matters if you want to program bootloader (and fuses) from Arduino IDE. 
# See http://www.engbedded.com/fusecalc (select Atmega328p) for interpretation of fuse values and how 
# extended fuses are written in different applications (07h in Arduino IDE = FFh in Atmel studio).
##############################################################

apm96.name=APM Optiboot internal 1MHz noBOD 9600baud

apm96.upload.tool=avrdude
apm96.upload.protocol=arduino
apm96.upload.maximum_size=32256
apm96.upload.speed=9600
apm96.bootloader.tool=avrdude
apm96.bootloader.low_fuses=0x62
apm96.bootloader.high_fuses=0xde
apm96.bootloader.extended_fuses=0x06
apm96.bootloader.path=optiboot_v50
apm96.bootloader.file=atmega328_1a.hex
apm96.bootloader.unlock_bits=0x3F
apm96.bootloader.lock_bits=0x2F
apm96.build.board=AVR_APM96
apm96.build.mcu=atmega328p
apm96.build.f_cpu=1000000L
apm96.build.core=arduino
apm96.build.variant=standard

##############################################################

I changed the fuses to include BDOUT @ 1,8Volt
VCC of my setup is 2-3Volt

[cimba007]

@scalz Thanks for the hint with the while-loop. I changed the i2c-read the following way:

void FaBo3Axis::readI2c(uint8_t register_addr, uint8_t num, uint8_t buffer[])
{
  Wire.beginTransmission(_i2caddr);
  Wire.write(register_addr);
  Wire.endTransmission();

  Wire.requestFrom(_i2caddr, num);

  int i = 0;
  uint8_t limit = num;
  while(Wire.available() && limit--)
  {
	Serial.print("r");
    buffer[i] = Wire.read();
    i++;
  }
}

Now it should under no circumstanced read more then the number given. Sadly this had no impact:

 | 34291
34291 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
34357 TSF:MSG:ACK
134390 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0
r34471 MCO:SLP:MS=16,SMS=0,I1=1,M1=3,I2=255,M2=255
34537 MCO:SLP:TPD
34553 MCO:SLP:WUP=1
 | 34553
34553 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
34553 TSF:MSG:ACK
134553 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0

Just before the sleep ..

I then added a Serial.flush() to the "r"-output ..

void FaBo3Axis::readI2c(uint8_t register_addr, uint8_t num, uint8_t buffer[])
{
	Serial.print("readI2c");
	Serial.flush();
  Wire.beginTransmission(_i2caddr);
  Wire.write(register_addr);
  Wire.endTransmission();

  Wire.requestFrom(_i2caddr, num);

  int i = 0;
  uint8_t limit = num;
  while(Wire.available() && limit--)
  {
	Serial.print("r");
	Serial.flush();
    buffer[i] = Wire.read();
    i++;
  }
}

54706 MCO:SLP:WUP=1
 | 54706
54706 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
54706 TSF:MSG:ACK
154706 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0

Now the freeze is clearly before entering the sleep function ..

but then .. on another round ..

 | 56623
56623 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
56623 TSF:MSG:ACK
156623 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0
readI2c

readI2cgot # from slave: 1
r78987 MCO:SLP:MS=16,SMS=0,I1=1,M1=3,I2=255,M2=255
79052 MCO:SLP:TPD
79069 MCO:SLP:WUP=1
 | 79069
79069 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
79069 TSF:MSG:ACK
179069 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0
readI2c

So .. your tip was very good .. it seems to be related to the

  Wire.beginTransmission(_i2caddr);
  Wire.write(register_addr);
  Wire.endTransmission();

-call .. only one questions remains .. why was it working perfectly on the stable library?

Just to be sure I will run exactly the same code in a non-stop loop with the stable library ..

[tekka]

@cimba007 What AVR board defs are you on?

[cimba007]

@tekka said:

AVR board def

What do you mean with AVR board def?

https://forum.mysensors.org/topic/4999/latest-git-snapshot-causes-freezes/17

I am using an arduino pro-mini china clone (328p) with 8mhz internal oscillator and DIV_8 fuse.

The bootloader is an "APM Optiboot 1Mhz" .. cant find the link right now.

[tekka]

@cimba007 You'll find the information in your Boards Manager (under Tools | Board | Boards Manager)

[cimba007]

yeah .. sorry

[tekka]

@cimba007 ok, do you see it hapepening if you downgrade the AVR board defs to 1.6.12 or 13?

[cimba007]

btw .. the "old" library is running happy for 6 minutes now ... still continuing

TSP:MSG:READ 0-0-14 s=0,c=1,t=16,pt=2,l=2,sg=0:0
1TSP:MSG:SEND 14-14-0-0 s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=ok:0
readI2cgot # from slave: 1
r | 373997
TSP:MSG:READ 0-0-14 s=0,c=1,t=16,pt=2,l=2,sg=0:0
1TSP:MSG:SEND 14-14-0-0 s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=ok:0
readI2cgot # from slave: 1
r | 374177

@tekka: I will try the "new snapshot" with the board defs you mentioned .. standby

[cimba007]

@1.6.12 board defs

r68550 MCO:SLP:MS=16,SMS=0,I1=1,M1=3,I2=255,M2=255
68599 MCO:SLP:TPD
68632 MCO:SLP:WUP=1
 | 68632
68632 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
68632 TSF:MSG:ACK
168632 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0
readI2c

@1.6.13 board defs

readI2cgot # from slave: 1
r62914 MCO:SLP:MS=16,SMS=0,I1=1,M1=3,I2=255,M2=255
62980 MCO:SLP:TPD
62996 MCO:SLP:WUP=1
 | 62996
62996 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0
62996 TSF:MSG:ACK
162996 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0
readI2c

[scalz]

hmm..too bad that didn't do the trick..but there was something (and that's an issue which can appear easily when using other libs, "hidden" while) and difficult to reproduce exactly the same case on my side as i'm not using the same radio.
i've dl the latest snpashot. so i will check on my side if one of my sketch is still running fine (with 4ints) and if i get the problem i'll try to debug it too. but i hope to not get it lol :)

[cimba007]

That would be nice .. my latest findings point out that the i2c-function is getting stuck. I investigated the i2c-source of arduino a bit and found out it is quite depending on interrupts.

This is now

wild speculation

For some reason interrupts got disabled while the i2c library is trying to write some data on the i2c-bus ..

wild-speculation-end

[cimba007]

Code working: (4minutes+)

  sei();
  fabo3axis.readIntStatus();

Code not working:

  //sei();
  fabo3axis.readIntStatus();

I noticed that interrupts in the sleep function are only detached if the intrrupt occurs ..

whereas in the stable

	detachInterrupt(interrupt1);
	if (interrupt2!=0xFF) detachInterrupt(interrupt2);

They get detached after the wakeup in the sleep ..

What if .. for some strange reason the interrupt is interfearing with .. whatever?!

EDIT: with the added sei(); the node is running for 10 minutes now ...
EDIT2: Running for 20 minutes now ..

[ikkeT]

@cimba007 I cloned the master branch from git about week ago. Or which ever is the default. I'll come back tomorrow, already in bed now.

[ikkeT]

@tekka the scetch is here along with the libraries, just use it as Arduino folder to reproduce:

https://github.com/ikke-t/sensebender

I'll check the versions tomorrow (UTC+3). The arduino ide is 1.6.xx whatever is the very latest in Fedora 24.

[ikkeT]

@tekka, the versions are:

Mysensors is development branch, I didn't pay attention while cloning, it's set to default to development:

commit 8cacb4825b256f63aa2fc51468fd11a90bb19678
Merge: 75a100f 8ccb1ca
Author: Patrick Fallberg <patrick@fallberg.net>
Date:   Thu Sep 22 19:02:11 2016 +0200

Arduino IDE is 1.6.4

$ rpm -qa arduino*
arduino-core-1.6.4-8.fc24.noarch
arduino-doc-1.6.4-8.fc24.noarch
arduino-1.6.4-8.fc24.noarch

My IDE board manager shows Arduino AVR boards version 1.6.7, and it seems there is newer one available, 1.6.14. I will update that.

Mysensors AVR board definition for Micro version is 1.0.1

[scalz]

so far, on my side, using custom sleep() and other mix, my ints are still working..i'm using latest snap' now, and still in 1.6.8..
but that's not the same usecase as i'm not using mys sleep for this node..
I will try your case; at least mine is working well :) . it could be sort of race..always a dilemma somewhere..

[cimba007]

I got suspecious about the code working with the manual adding of sei() before calling the i2cread-function.

So I changed the end of hwPowerDown to include a serial output with a flush.

	// restore saved WDT settings
	WDTCSR = WDTsave;
	Serial.println("sei()");
	Serial.flush();
	sei();
	// enable ADC
	ADCSRA |= (1 << ADEN);
}

Now have a close look at how sei()-output is missing just before the freeze:

57114 MCO:SLP:TPD<\n>
sei()<\r><\n>
57147 MCO:SLP:WUP=-1<\n>
 | 57180<\r><\n>
57180 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0<\n>
57245 TSF:MSG:ACK<\n>
157262 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0<\n>
readI2cgot # from slave: 1<\r><\n>
r57376 MCO:SLP:MS=16,SMS=0,I1=1,M1=3,I2=255,M2=255<\n>
57442 MCO:SLP:TPD<\n>
sei()<\r><\n>
57475 MCO:SLP:WUP=-1<\n>
 | 57491<\r><\n>
57507 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0<\n>
57573 TSF:MSG:ACK<\n>
157589 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0<\n>
readI2cgot # from slave: 1<\r><\n>
r57704 MCO:SLP:MS=16,SMS=0,I1=1,M1=3,I2=255,M2=255<\n>
57769 MCO:SLP:TPD<\n>
57786 MCO:SLP:WUP=1<\n>
 | 57786<\r><\n>
57786 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0<\n>
57786 TSF:MSG:ACK<\n>
157786 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0<\n>
readI2c

Just after "57769 MCO:SLP:TPD<\n>" the sei()-output is missing. Thus I suspect that interrupts are not enabled when the readI2c-function is called .. and as i2c is depending on interrupts the code gets stuck there.

Still no idea why the sei() is "sometimes" not called ...

Notice how the "millis" interrupt is not called after the missing sei .. thus all timestamps are the same:

57786 MCO:SLP:WUP=1<\n>
 | 57786<\r><\n>
57786 TSF:MSG:READ,0-0-14,s=0,c=1,t=16,pt=2,l=2,sg=0:0<\n>
57786 TSF:MSG:ACK<\n>
157786 TSF:MSG:SEND,14-14-0-0,s=0,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0<\n>
readI2c

[cimba007]

Comparing the code to the atmel documentation here:

http://www.atmel.com/webdoc/AVRLibcReferenceManual/group__avr__sleep.html

mysensors explicit disables interrupts after wake from sleep:

	sei();
	
    // Directly sleep CPU, to prevent race conditions! (see chapter 7.7 of ATMega328P datasheet)
	sleep_cpu();
    sleep_disable();	
	// restore previous WDT settings
	cli();

whereas the atmel documentation enables interrupts

#include <avr/interrupt.h>
    #include <avr/sleep.h>

...
  set_sleep_mode(<mode>);
  cli();
  if (some_condition)
  {
    sleep_enable();
    sleep_bod_disable();
    sei();
    sleep_cpu();
    sleep_disable();
  }
  sei();

Might not be totally related as the code did not change from last stable .. except one line:

	WDTCSR |= (1 << WDIE); // set the WDIE flag to enable interrupt callback function.

is now missing in the snapshot ..

Adding an extra sei() after the sleep_disable() is not the solution .. still thought it might be noteworthy