Re: Memory corruption (?) I don't understand

Trampas Stern <[email protected]> Tue, 22 Jun 2021 14:10:17 -0400
Newsgroups gmane.comp.hardware.avr.gcc
Message-ID <CADqjcyiqcOSXe=znHtVMRKJcY3dvaTzdCikRkL+FG+KsCcWAcg@mail.gmail.com>
--0000000000006ba54d05c55eb436
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

So I would recommend that you put in the ASSERT for the LDL_PEDANTIC()
macro.

Secondly, you need to be careful with PROGMEM, that is with AVR being a
Harvard machine you can burn up SRAM quickly by not using PROGMEM  for
constants.  For example with the LDL library you need to be sure
that LDL_ENABLE_AVR is defined.

Note the AVR is a great processor, however I have personally not used one
in about 15 years.  The price and ease of programming ARM Cortex M have
gotten such AVR are no longer viable for new development as I can develop
products so much faster with ARM Cortex M parts, and their power and price
is comparable to AVR.

Another trick you can do is inside a function do this:

void printMem(void) {
   uint8_t *ptr;
   printf("stack 0x%X\n", &ptr); //this will be address on stack where ptr
is.
   ptr=3Dmalloc(10);
   printf("heap 0x%X\n", ptr); //this will be address as to heap
   free(ptr);
}

This will help as you can do some rough tracking of stack and heap usage,
assuming the AVR linker script has stack growing from top of memory to end
of heap it will help you check for stack overflow.





On Tue, Jun 22, 2021 at 1:39 PM BERTRAND Jo=C3=ABl <joel.bertrand@systella.=
fr>
wrote:

>         Strange. Following function runs as expected.
>
> enum ldl_mac_status LDL_MAC_otaa(struct ldl_mac *self)
> {
>     enum ldl_mac_status retval;
>     union ldl_mac_response_arg arg;
>
>     LDL_PEDANTIC(self !=3D NULL)
>
>     if(self->ctx.joined){
>
>         retval =3D LDL_STATUS_JOINED;
>     }
>     else if(self->op =3D=3D LDL_OP_NONE){
>
>         if(self->devNonce <=3D U32(UINT16_MAX)){
>
>             forgetNetwork(self);
>
>             self->trials =3D 0;
>
>             self->day =3D U32(60) * U32(60) * U32(24) * timeTPS;
>
> #if defined(LDL_ENABLE_L2_1_1)
>             LDL_OPS_deriveJoinKeys(self);
> #endif
>             fillJoinBuffer(self, U16(self->devNonce));
>
>             self->devNonce++;
>
>             arg.dev_nonce_updated.nextDevNonce =3D self->devNonce;
>
> unsigned char t[80];
> sprintf(t, "self->handler=3D%p\r\n", self->handler);
>             self->handler(self->app, LDL_MAC_DEV_NONCE_UPDATED, &arg);
>
>             self->tx.power =3D 0;
>
>             self->op =3D LDL_OP_JOINING;
>
>             if(self->state =3D=3D LDL_STATE_IDLE){
>
>                 self->state =3D LDL_STATE_WAIT_OTAA;
>                 LDL_MAC_timerSet(self, LDL_TIMER_WAITA, 0);
>             }
>
>             retval =3D LDL_STATUS_OK;
>
>             LDL_DEBUG("OTAA is pending")
>         }
>         else{
>
>             /* need to re-init with a different JoinEUI */
>             retval =3D LDL_STATUS_DEVNONCE;
>         }
>     }
>     else{
>
>         retval =3D LDL_STATUS_BUSY;
>     }
>
>     return retval;
> }
>
>         If I comment out sprintf(), it crashes. If I deplace this debug
> trace
> before or _after_ self->handler call, firmware runs as expected. I don't
> understand. If there is a memory corruption somewhere, I could
> understand that a debug trace _before_ the line that triggers the bug
> can change something. But I don't understand why the following function
> runs as expected :
>
> enum ldl_mac_status LDL_MAC_otaa(struct ldl_mac *self)
> {
>     enum ldl_mac_status retval;
>     union ldl_mac_response_arg arg;
>
>     LDL_PEDANTIC(self !=3D NULL)
>
>     if(self->ctx.joined){
>
>         retval =3D LDL_STATUS_JOINED;
>     }
>     else if(self->op =3D=3D LDL_OP_NONE){
>
>         if(self->devNonce <=3D U32(UINT16_MAX)){
>
>             forgetNetwork(self);
>
>             self->trials =3D 0;
>
>             self->day =3D U32(60) * U32(60) * U32(24) * timeTPS;
>
> #if defined(LDL_ENABLE_L2_1_1)
>             LDL_OPS_deriveJoinKeys(self);
> #endif
>             fillJoinBuffer(self, U16(self->devNonce));
>
>             self->devNonce++;
>
>             arg.dev_nonce_updated.nextDevNonce =3D self->devNonce;
>
>             self->handler(self->app, LDL_MAC_DEV_NONCE_UPDATED, &arg);
>
>             self->tx.power =3D 0;
>
>             self->op =3D LDL_OP_JOINING;
>
>             if(self->state =3D=3D LDL_STATE_IDLE){
>
>                 self->state =3D LDL_STATE_WAIT_OTAA;
>                 LDL_MAC_timerSet(self, LDL_TIMER_WAITA, 0);
>             }
>
>             retval =3D LDL_STATUS_OK;
>
>             LDL_DEBUG("OTAA is pending")
>         }
>         else{
>
>             /* need to re-init with a different JoinEUI */
>             retval =3D LDL_STATUS_DEVNONCE;
>         }
>     }
>     else{
>
>         retval =3D LDL_STATUS_BUSY;
>     }
>
> unsigned char t[80];
> sprintf(t, "self->handler=3D%p\r\n", self->handler);
>     return retval;
> }
>
>         Of course, if I comment out :
>
> unsigned char t[80];
> sprintf(t, "self->handler=3D%p\r\n", self->handler);
>
> it crashes again :
>
> hilbert:[~/cvs/firmware-antivol] > simavr -t -vvv -m atmega1284 -f
> 16000000 firmware.elf
> Loaded 95670 .text at address 0x0
> Loaded 5654 .data
> Loaded 2276 .eeprom
> 01..
> ..
> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D..
>  Systella L100-A..
> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D..
> ..
> Booting firmware 2021062218..
> SPI initialized..
> Reset LORA..
> Reset LORA done..
> LoRaWAN 1.1..
> Initialization SX1262..
> Initialization SX1262 done..
> 0000000000000000..
> MAC initialization..
> LDL_MAC_addChannel:790>chIndex=3D0 freq=3D868100000 minRate=3D0 maxRate=
=3D5..
> LDL_MAC_addChannel:790>chIndex=3D1 freq=3D868300000 minRate=3D0 maxRate=
=3D5..
> LDL_MAC_addChannel:790>chIndex=3D2 freq=3D868500000 minRate=3D0 maxRate=
=3D5..
> cb type=3D11..
> processInit:994>set radio reset: ticks=3D151..
> processRadioReset:1009>clear radio reset: ticks=3D151..
> MAC initialization done..
> lora_send..
> processStartRadioForEntropy:1061>listen for entropy: ticks=3D152..
> processEntropy:1078>read entropy: ticks=3D152 entropy=3D0..
> cb type=3D0..
> LDL_MAC_ready..
> LDL_MAC_otaa..
> LDL_MAC_addChannel:790>chIndex=3D0 freq=3D868100000 minRate=3D0 maxRate=
=3D5..
> LDL_MAC_addChannel:790>chIndex=3D1 freq=3D868300000 minRate=3D0 maxRate=
=3D5..
> LDL_MAC_addChannel:790>chIndex=3D2 freq=3D868500000 minRate=3D0 maxRate=
=3D5..
> avr_gdb_init listening on port 1234
>
>
>

--0000000000006ba54d05c55eb436
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">So I would recommend that you put in the ASSERT for the=C2=
=A0LDL_PEDANTIC() macro.=C2=A0<div><br></div><div>Secondly, you need to be =
careful with PROGMEM, that is with AVR being a Harvard machine you can burn=
 up SRAM quickly by not using PROGMEM=C2=A0 for constants.=C2=A0 For exampl=
e with the LDL library you need to be sure that=C2=A0LDL_ENABLE_AVR is defi=
ned.=C2=A0 =C2=A0</div><div><br></div><div>Note the AVR is a great processo=
r, however I have personally not used one in about 15 years.=C2=A0 The pric=
e and ease of programming ARM Cortex M have gotten such AVR are no longer v=
iable for new development as I can develop products so much faster with ARM=
 Cortex M parts, and their power and price is comparable to AVR.=C2=A0</div=
><div><br></div><div>Another trick you can do is inside a function do this:=
=C2=A0</div><div><br></div><div>void printMem(void) {</div><div>=C2=A0 =C2=
=A0uint8_t *ptr;</div><div>=C2=A0 =C2=A0printf(&quot;stack 0x%X\n&quot;, &a=
mp;ptr); //this will be address on stack where ptr is.</div><div>=C2=A0 =C2=
=A0ptr=3Dmalloc(10);</div><div>=C2=A0=C2=A0

printf(&quot;heap 0x%X\n&quot;, ptr); //this will be address as to heap=C2=
=A0</div><div>=C2=A0 =C2=A0free(ptr);</div><div>}</div><div><br></div><div>=
This will help as you can do some rough tracking of stack and heap usage, a=
ssuming the AVR linker script has stack growing from top of memory to end o=
f heap it will help you check for stack overflow.=C2=A0</div><div><br></div=
><div><br></div><div>=C2=A0=C2=A0</div><div><br></div></div><br><div class=
=3D"gmail_quote"><div dir=3D"ltr" class=3D"gmail_attr">On Tue, Jun 22, 2021=
 at 1:39 PM BERTRAND Jo=C3=ABl &lt;<a href=3D"mailto:joel.bertrand@systella=
.fr">[email protected]</a>&gt; wrote:<br></div><blockquote class=3D=
"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(2=
04,204,204);padding-left:1ex">=C2=A0 =C2=A0 =C2=A0 =C2=A0 Strange. Followin=
g function runs as expected.<br>
<br>
enum ldl_mac_status LDL_MAC_otaa(struct ldl_mac *self)<br>
{<br>
=C2=A0 =C2=A0 enum ldl_mac_status retval;<br>
=C2=A0 =C2=A0 union ldl_mac_response_arg arg;<br>
<br>
=C2=A0 =C2=A0 LDL_PEDANTIC(self !=3D NULL)<br>
<br>
=C2=A0 =C2=A0 if(self-&gt;ctx.joined){<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_JOINED;<br>
=C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 else if(self-&gt;op =3D=3D LDL_OP_NONE){<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 if(self-&gt;devNonce &lt;=3D U32(UINT16_MAX)){<=
br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 forgetNetwork(self);<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;trials =3D 0;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;day =3D U32(60) * U32(60=
) * U32(24) * timeTPS;<br>
<br>
#if defined(LDL_ENABLE_L2_1_1)<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 LDL_OPS_deriveJoinKeys(self);<br>
#endif<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 fillJoinBuffer(self, U16(self-&gt=
;devNonce));<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;devNonce++;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 arg.dev_nonce_updated.nextDevNonc=
e =3D self-&gt;devNonce;<br>
<br>
unsigned char t[80];<br>
sprintf(t, &quot;self-&gt;handler=3D%p\r\n&quot;, self-&gt;handler);<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;handler(self-&gt;app, LD=
L_MAC_DEV_NONCE_UPDATED, &amp;arg);<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;tx.power =3D 0;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;op =3D LDL_OP_JOINING;<b=
r>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 if(self-&gt;state =3D=3D LDL_STAT=
E_IDLE){<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;state =3D =
LDL_STATE_WAIT_OTAA;<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 LDL_MAC_timerSet(se=
lf, LDL_TIMER_WAITA, 0);<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 }<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_OK;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 LDL_DEBUG(&quot;OTAA is pending&q=
uot;)<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 else{<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 /* need to re-init with a differe=
nt JoinEUI */<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_DEVNONCE;<b=
r>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 else{<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_BUSY;<br>
=C2=A0 =C2=A0 }<br>
<br>
=C2=A0 =C2=A0 return retval;<br>
}<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 If I comment out sprintf(), it crashes. If I de=
place this debug trace<br>
before or _after_ self-&gt;handler call, firmware runs as expected. I don&#=
39;t<br>
understand. If there is a memory corruption somewhere, I could<br>
understand that a debug trace _before_ the line that triggers the bug<br>
can change something. But I don&#39;t understand why the following function=
<br>
runs as expected :<br>
<br>
enum ldl_mac_status LDL_MAC_otaa(struct ldl_mac *self)<br>
{<br>
=C2=A0 =C2=A0 enum ldl_mac_status retval;<br>
=C2=A0 =C2=A0 union ldl_mac_response_arg arg;<br>
<br>
=C2=A0 =C2=A0 LDL_PEDANTIC(self !=3D NULL)<br>
<br>
=C2=A0 =C2=A0 if(self-&gt;ctx.joined){<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_JOINED;<br>
=C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 else if(self-&gt;op =3D=3D LDL_OP_NONE){<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 if(self-&gt;devNonce &lt;=3D U32(UINT16_MAX)){<=
br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 forgetNetwork(self);<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;trials =3D 0;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;day =3D U32(60) * U32(60=
) * U32(24) * timeTPS;<br>
<br>
#if defined(LDL_ENABLE_L2_1_1)<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 LDL_OPS_deriveJoinKeys(self);<br>
#endif<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 fillJoinBuffer(self, U16(self-&gt=
;devNonce));<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;devNonce++;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 arg.dev_nonce_updated.nextDevNonc=
e =3D self-&gt;devNonce;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;handler(self-&gt;app, LD=
L_MAC_DEV_NONCE_UPDATED, &amp;arg);<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;tx.power =3D 0;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;op =3D LDL_OP_JOINING;<b=
r>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 if(self-&gt;state =3D=3D LDL_STAT=
E_IDLE){<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 self-&gt;state =3D =
LDL_STATE_WAIT_OTAA;<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 LDL_MAC_timerSet(se=
lf, LDL_TIMER_WAITA, 0);<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 }<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_OK;<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 LDL_DEBUG(&quot;OTAA is pending&q=
uot;)<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 else{<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 /* need to re-init with a differe=
nt JoinEUI */<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_DEVNONCE;<b=
r>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 }<br>
=C2=A0 =C2=A0 else{<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 retval =3D LDL_STATUS_BUSY;<br>
=C2=A0 =C2=A0 }<br>
<br>
unsigned char t[80];<br>
sprintf(t, &quot;self-&gt;handler=3D%p\r\n&quot;, self-&gt;handler);<br>
=C2=A0 =C2=A0 return retval;<br>
}<br>
<br>
=C2=A0 =C2=A0 =C2=A0 =C2=A0 Of course, if I comment out :<br>
<br>
unsigned char t[80];<br>
sprintf(t, &quot;self-&gt;handler=3D%p\r\n&quot;, self-&gt;handler);<br>
<br>
it crashes again :<br>
<br>
hilbert:[~/cvs/firmware-antivol] &gt; simavr -t -vvv -m atmega1284 -f<br>
16000000 firmware.elf<br>
Loaded 95670 .text at address 0x0<br>
Loaded 5654 .data<br>
Loaded 2276 .eeprom<br>
01..<br>
..<br>
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D..<br>
=C2=A0Systella L100-A..<br>
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D..<br>
..<br>
Booting firmware 2021062218..<br>
SPI initialized..<br>
Reset LORA..<br>
Reset LORA done..<br>
LoRaWAN 1.1..<br>
Initialization SX1262..<br>
Initialization SX1262 done..<br>
0000000000000000..<br>
MAC initialization..<br>
LDL_MAC_addChannel:790&gt;chIndex=3D0 freq=3D868100000 minRate=3D0 maxRate=
=3D5..<br>
LDL_MAC_addChannel:790&gt;chIndex=3D1 freq=3D868300000 minRate=3D0 maxRate=
=3D5..<br>
LDL_MAC_addChannel:790&gt;chIndex=3D2 freq=3D868500000 minRate=3D0 maxRate=
=3D5..<br>
cb type=3D11..<br>
processInit:994&gt;set radio reset: ticks=3D151..<br>
processRadioReset:1009&gt;clear radio reset: ticks=3D151..<br>
MAC initialization done..<br>
lora_send..<br>
processStartRadioForEntropy:1061&gt;listen for entropy: ticks=3D152..<br>
processEntropy:1078&gt;read entropy: ticks=3D152 entropy=3D0..<br>
cb type=3D0..<br>
LDL_MAC_ready..<br>
LDL_MAC_otaa..<br>
LDL_MAC_addChannel:790&gt;chIndex=3D0 freq=3D868100000 minRate=3D0 maxRate=
=3D5..<br>
LDL_MAC_addChannel:790&gt;chIndex=3D1 freq=3D868300000 minRate=3D0 maxRate=
=3D5..<br>
LDL_MAC_addChannel:790&gt;chIndex=3D2 freq=3D868500000 minRate=3D0 maxRate=
=3D5..<br>
avr_gdb_init listening on port 1234<br>
<br>
<br>
</blockquote></div>

--0000000000006ba54d05c55eb436--