Available as Arduino library "AvrTracing"

🌎 Google Translate

A small (344 bytes) Arduino library to have real program traces and to find the place where your program hangs.
Trace your program by pressing a button connected at pin 2 or use startTracing() and stopTracing() to trace selected parts of your code. startTracing() sets pin 2 to LOW!
Currently only running on ATmega type processors like on the Arduino Uno, Nano, or Leonardo boards.

With tracing enabled and 115200 baud, 11 characters "PC=0x...\r\n" are sent each time, lasting around 1 millisecond. So the effective CPU frequency is around 1 kHz i.e. 16,000 times slower. for 1 cycle commands. 2 or 3 cycle commands require the same time, so the effective CPU frequency is 2 or 3 kHz respectively.
E.g. delayMicroseconds(1000) is slowed down by the factor of 7500 and lasts 7.5 seconds.
Interrupt service routines cannot be traced by this library. This results in millis() and micros() are slow, but they tell the real time. Thus delay() only takes 48 times the original value.

I observed, that Wire will hang if traced and no timeout is specified with Wire.setWireTimeout(). In general, functions depending on timing may not work or behave strange if traced.

#include "AvrTracing.hpp"

setup() {
    Serial.begin(115200);
    initTrace();
    // optional info output
    printTextSectionAddresses(); // PC=0x2818 Start of text section=0x402 end=0x40E8
    printNumberOfPushesForISR(); // Found 18 pushes in ISR
    ...
    Serial.flush(); // To avoid interfering with Serial still printing from its buffer
    startTracing();
    // the code to trace
    ...
    stopTracing();
}

If the MSB of the PC does not change, it is suppressed, to shrink output size.
Every value with a leading '-' is not in in text section.

PC=0x2818 Start of text section=0x402 end=0x40E8
Found 18 pushes in ISR
...
PC=20EE F0 F2 F4 FC FE 2100 3B3C 3E 40 42 44 46 48 4A 4C 4E 50 52 5A 5C 
-PC=0x6A0C -0E -10 -12 -14 -16 -18 -1A -1C -1E -20 -22 -24 -26 -28 -2A -2C -2E -30 -32 -34 -36 

If you see instructions like this just before stopTracing(), this is the start of stopTracing() code inlined in your program :-).

    236a:   5a 9a           sbi 0x0b, 2 ; 11
    236c:   52 98           cbi 0x0a, 2 ; 10

    ...
    startTracing();
    _NOP();
    _NOP(); // Both nop's are not printed, but they allow to see the program counter of the call instructions of digitalWrite().
    digitalWrite(LED_BUILTIN, HIGH); // Takes 24 ms for 27 prints.
    stopTracing(); // the first 2 instructions of stopTracing() are printed at last.
    digitalWrite(LED_BUILTIN, LOW);
    ...

In order to match PC values to your code, you require the assembler (*.lss) file to be generated.
This assembler file can be generated with avr-objdump --section-headers --source --line-numbers <myfilename>.elf > <myfilename>.lss.

You have to extend the platform.txt file. On my PC it is located at C:\Program Files\arduino-1.8.16\hardware\arduino\avr or C:\Users\<Username>\AppData\Local\Arduino15\packages\arduino\hardware\avr\1.8.3.
Insert the following line after the ## Save hex block.

recipe.hooks.objcopy.postobjcopy.1.pattern.windows=cmd /C "{compiler.path}avr-objdump" --disassemble --source --line-numbers --demangle --section=.text "{build.path}/{build.project_name}.elf" > "{build.path}/{build.project_name}.lss"

The path of the resulting *.lss assembler file is like C:\Users\<Username>\AppData\Local\Temp\arduino_build_\. The path is printed in the Arduino console if you check show verbose output during compilations in the File/Arduino/Preferences settings.
The ATTinyCore board package still generates this assembler file as a *.lst file.

Insert avr-objdump -h -S ${BuildArtifactFileBaseName}.elf > ${BuildArtifactFileBaseName}.lss in Project/Properties/C/C++ Build/Settings/Build Steps/Post-build steps/Command.
Examples for such a project configuration can be found here.

For the AVR Eclipse Plugin (de.innot.avreclipse.p2repository-2.4.2.zip), check the Create Extended Listing option in Project/Properties/C/C++ Build/Settings/Additional Tools in toolchain and insert -g in Project/Properties/C/C++ Build/Settings/Linker/General/Other Arguments.

Sometimes the assembler output is easier to understand, if you disable the compiler optimization. For this, in the the platform.txt file, change all occurences of -Os to -Og and remove all occurences of -flto. This also increases the code size and therefore might not be applicable for large programs, they may not fit into the program memory any more.

void loop() { // 11 clock cycles // 687,5 ns
    digitalWriteFast(TEST_OUT_PIN, HIGH); // 2 clock cycles / 125 ns 15 ms with trace
 1ea:   5c 9a           sbi 0x0b, 4 ; 11
    digitalWriteFast(TEST_OUT_PIN, LOW); // 2 clock cycles / 125 ns 15 ms with trace
 1ec:   5c 98           cbi 0x0b, 4 ; 11
    digitalWriteFast(TEST_OUT_PIN, HIGH);
 1ee:   5c 9a           sbi 0x0b, 4 ; 11
    digitalWriteFast(TEST_OUT_PIN, LOW);
 1f0:   5c 98           cbi 0x0b, 4 ; 11
}
 1f2:   08 95           ret

    for (;;) {
        loop();
 77a:   37 dd           rcall   .-1426      ; 0x1ea 
        if (serialEventRun) serialEventRun();
 77c:   20 97           sbiw    r28, 0x00   ; 0
 77e:   e9 f3           breq    .-6         ; 0x77a 
 780:   fc dd           rcall   .-1032      ; 0x37a <_Z14serialEventRunv>
 782:   fb cf           rjmp    .-10        ; 0x77a 

void serialEventRun(void)
{
#if defined(HAVE_HWSERIAL0)
  if (Serial0_available && serialEvent && Serial0_available()) serialEvent();
 37a:   8e e0           ldi r24, 0x0E   ; 14
 37c:   93 e0           ldi r25, 0x03   ; 3
 37e:   89 2b           or  r24, r25
 380:   41 f0           breq    .+16        ; 0x392 <_Z14serialEventRunv+0x18>
 382:   80 e0           ldi r24, 0x00   ; 0
 384:   90 e0           ldi r25, 0x00   ; 0
 386:   89 2b           or  r24, r25
 388:   21 f0           breq    .+8         ; 0x392 <_Z14serialEventRunv+0x18>
 38a:   48 d1           rcall   .+656       ; 0x61c <_Z17Serial0_availablev>
 38c:   81 11           cpse    r24, r1
 38e:   0c 94 00 00     jmp 0   ; 0x0 <__vectors>
  if (Serial2_available && serialEvent2 && Serial2_available()) serialEvent2();
#endif
#if defined(HAVE_HWSERIAL3)
  if (Serial3_available && serialEvent3 && Serial3_available()) serialEvent3();
#endif
}
 392:   08 95           ret

Besides of using Serial.print() statements, there is an extension of the simple print method, the ArduinoTrace library. But be aware, that the calls and especially the strings used by this methods require a lot of program memory.

If NUMBER_OF_PUSH is defined (static mode): 284 bytes
If NUMBER_OF_PUSH is not defined (recommended dynamic mode): 344 bytes (60 bytes more than static)

You can first use the dynamic mode without DEBUG_INIT defined, and call printNumberOfPushesForISR() to get the right number of pushes and then switch to static mode using this value, to save around 60 bytes of program memory or to proof, that you have counted the pushes of the ISR correct :-).

If you comment out the line #define DEBUG_INIT you see internal information at the call of initTrace(). This costs 52 (static) / 196 (dynamic) bytes of program memory.

https://github.com/jdolinay/avr_debug https://hinterm-ziel.de/index.php/2021/07/19/debugging3-debugging-is-like-being-the-detective-in-a-crime-movie-where-you-are-also-the-murderer

• Added SEARCH_LOWEST_STACKPOINTER_MODE compile switch and corresponding function printLowestStackpointerAndProgramAddress().

• Keep -Os for the library.

Initial Arduino library version.