{"id":3953,"date":"2018-05-09T09:30:53","date_gmt":"2018-05-09T16:30:53","guid":{"rendered":"https:\/\/visualgdb.com\/w\/?p=3953"},"modified":"2018-05-09T09:30:53","modified_gmt":"2018-05-09T16:30:53","slug":"diagnosing-complex-memory-corruption-problems-with-segger-j-trace","status":"publish","type":"post","link":"https:\/\/visualgdb.com\/tutorials\/arm\/tracing\/traceback\/","title":{"rendered":"Diagnosing Complex Memory Corruption Problems with Segger J-Trace"},"content":{"rendered":"

This\u00a0tutorial shows how to diagnose complex memory corruption problems using the ARM ETM tracing with VisualGDB and Segger J-Trace.<\/p>\n

ETM tracing is a powerful debug technology that allows recording\u00a0each and every instruction executed by the ARM processor, so you can conveniently step back in time and understand\u00a0the events that lead to a strange unexpected crash.<\/p>\n

In this tutorial we will\u00a0create a basic FreeRTOS-based program with incompatible floating point settings (leading to a very tough-to-diagnose\u00a0memory\u00a0corruption under certain circumstances), will reproduce the problem and then show how to use the\u00a0tracing\u00a0functionality with Segger J-Trace to\u00a0help\u00a0pinpoint the problem better.<\/p>\n

Before you begin, install VisualGDB 5.4 or later and ensure\u00a0you have a Segger J-Trace Pro and a board with a trace connector (in this tutorial we will use the reference tracing board\u00a0that comes with the J-Trace).<\/p>\n

    \n
  1. Start Visual Studio and open the VisualGDB Embedded Project Wizard:\"01-prjname\"<\/a><\/li>\n
  2. Select “New Project -> Embedded binary”:\"02-newprj\"<\/a><\/li>\n
  3. Pick your toolchain and the device. The reference trace board comes with the STM32F407VE\u00a0microcontroller,\u00a0however if you are using a different board, select a device that matches it:\"03-device\"<\/a><\/li>\n
  4. On the\u00a0next page select the “LEDBlink (FreeRTOS)” sample.\u00a0You can try changing the LED numbers to match the Segger board layout, however this is not necessary as we won’t rely on the LEDs in this tutorial:\"04-rtos\"<\/a><\/li>\n
  5. Connect your J-Trace to your board and plug both into the USB ports of your computer:\"hardware\"<\/a><\/li>\n
  6. VisualGDB should automatically recognize the J-Trace\u00a0(shown as J-Link in the GUI) and pick the correct settings. Ensure you use the Segger software package v6.32 or later, as the previous versions don’t include the functionality used by VisualGDB:\"05-jlink\"<\/a><\/li>\n
  7. Press “Finish” to create the project. Now we will\u00a0introduce the bug. Switch the Floating Point Support<\/strong> setting to Hardware<\/strong>:
    \n    \"06-hardware\"<\/a><\/li>\n
  8. On the Embedded Frameworks page set the FreeRTOS CPU Core to ARM Cortex M3 or M4 with Software FP<\/strong>:\"07-softfp\"<\/a><\/li>\n
  9. Replace the main part of the source file with the following code:\n
    osSemaphoreDef(s_Semaphore);\r\nosSemaphoreId(s_SemaphoreId);\r\n\r\nint main(void)\r\n{\r\n    HAL_Init(); \r\n \r\n    __GPIOD_CLK_ENABLE();\r\n    GPIO_InitTypeDef GPIO_InitStructure;\r\n\r\n    GPIO_InitStructure.Pin = GPIO_PIN_12 | GPIO_PIN_13;\r\n\r\n    GPIO_InitStructure.Mode = GPIO_MODE_OUTPUT_PP;\r\n    GPIO_InitStructure.Speed = GPIO_SPEED_HIGH;\r\n    GPIO_InitStructure.Pull = GPIO_NOPULL;\r\n    HAL_GPIO_Init(GPIOD, &GPIO_InitStructure);\r\n\r\n    \/* Thread 1 definition *\/\r\n    osThreadDef(LED1, LED_Thread1, osPriorityNormal, 0, configMINIMAL_STACK_SIZE);\r\n \r\n    \/* Thread 2 definition *\/\r\n    osThreadDef(LED2, LED_Thread2, osPriorityNormal, 0, configMINIMAL_STACK_SIZE);\r\n \r\n    \/* Start thread 1 *\/\r\n    LEDThread1Handle = osThreadCreate(osThread(LED1), NULL);\r\n \r\n    \/* Start thread 2 *\/\r\n    LEDThread2Handle = osThreadCreate(osThread(LED2), NULL);\r\n \r\n    s_SemaphoreId = osSemaphoreCreate(osSemaphore(s_Semaphore), 32);\r\n\r\n \r\n    \/* Start scheduler *\/\r\n    osKernelStart();\r\n\r\n    \/* We should never get here as control is now taken by the scheduler *\/\r\n    for (;;)\r\n        ;\r\n}\r\n\r\nvoid SysTick_Handler(void)\r\n{\r\n    osSystickHandler();\r\n}\r\n\r\n#include <math.h>\r\n\r\nstatic void LED_Thread1(void const *argument)\r\n{\r\n    for (;;)\r\n    {\r\n        osDelay(100);\r\n \r\n#ifdef CRASH\r\n        volatile float arg = 3.14;\r\n        volatile float result = sinf(arg);\r\n#endif\r\n \r\n        osSemaphoreRelease(s_SemaphoreId);\r\n    }\r\n}\r\n\r\nstatic void LED_Thread2(void const *argument)\r\n{\r\n    for (;;)\r\n    {\r\n        osSemaphoreWait(s_SemaphoreId, osWaitForever);\r\n    }\r\n}<\/pre>\n<\/li>\n
  10. Open VisualGDB Project Properties and enable real-time tracing to support collecting\u00a0and analyzing trace data from the CPU:\"13-trace\"<\/li>\n
  11. The current version of the code doesn’t trigger the crash yet and is expected to run normally. Verify this by pressing F5 to build and start the program.\u00a0The easiest way to see\u00a0what the program is doing without stopping it is to enable recent code highlighting in the Live Tracing window (although this is not related to\u00a0the advanced troubleshooting that will be described later):\"live\"<\/a><\/li>\n
  12. You can also set a breakpoint in one of the\u00a0thread functions and wait for it to hit to ensure that the thread is running as expected:
    \n    \"08-works\"<\/a><\/li>\n
  13. Now we will trigger the crash. Open VisualGDB Project Properties and add “CRASH” to the “preprocessor macros” session. This will\u00a0enable the call to sinf() from the\u00a0LED1 thread:\"09-enablecode\"<\/a><\/li>\n
  14. Remove all breakpoints, build and run the program again. The Live Coverage view can easily show you that the program is now stuck in the Default_Handler() function and no other code is begin executed:\"stuck\"<\/a><\/li>\n
  15. Select “Debug->Break All” to stop\u00a0the program and confirm that it is stuck in the Default_Handler():
    \n    \"10-handler\"<\/a><\/li>\n
  16. The Default_Handler()\u00a0function is shared between all unimplemented interrupt\u00a0handlers, making it harder to understand which\u00a0interrupt triggered it. As the comment in the default handler suggests, add “DEBUG_DEFAULT_INTERRUPT_HANDLERS” to Preprocessor Macros to\u00a0define\u00a0a separate handler for each unused interrupt (at\u00a0a slight additional memory cost):
    \n    \"11-debugisr\"<\/a><\/li>\n
  17. If you your the program now, it will almost immediately get stopped in the\u00a0HardFault_handler() function that\u00a0is called when the ARM core tries executing an invalid instruction or reading from an invalid address:\"12-crashed\"<\/a>In most of the cases, the Call Stack window would be helpful in\u00a0identifying the caller of the current function, however in this case it is not very helpful, as it lists the prvPortStartFirstTask()<\/strong> as the caller, that doesn’t make much sense. If we were limited to conventional debugging methods, pinpointing the cause of the crash would be very tough.<\/li>\n
  18. As we are using J-Trace, we don’t have to rely on the Call Stack to reconstruct the preceding events. Instead we can\u00a0simply look through executed the instruction list reported by the ARM CPU via the trace interface. Open the Debug->Windows->Live Tracing window and switch it to the Recent Instructions view:\"14-break\"<\/a><\/li>\n
  19. Switch from the “Lines” subview to “Instructions”\u00a0and look through the recent instructions.\u00a0You\u00a0will see that last function running before HardFault_Handler()\u00a0was\u00a0xQueueGenericReceive()<\/strong>.\u00a0Although the ETM trace will show the\u00a0previously executed\u00a0instructions, it won’t reconstruct the\u00a0register and memory values from the past, so we would\u00a0still need to use\u00a0conventional breakpoints\u00a0to try\u00a0stopping at the right moment in time and doing more analysis. Click on the last instruction of this function in the trace view and set a breakpoint there. Then press the “Reset Embedded Device” button and hit F5 to continue:\"15-reset\"<\/a><\/li>\n
  20. Once the program restarts and the breakpoint triggers, check the value of the $sp<\/strong> register and the ((unsigned *)$sp)[1]<\/strong> memory slot (containing the\u00a0return address). The current return address (0x08003afb in this example) looks\u00a0like a valid FLASH memory address (you can check it by running “info\u00a0symbol <address>” in the GDB Session window):\"16-goodsp\"<\/a><\/li>\n
  21. To try catching the\u00a0moment with\u00a0the incorrect address, add the following condition to the breakpoint:\n
    ((unsigned *)$sp)[1] != <correct value shown currently><\/pre>\n
    \"17-cond\"<\/a><\/li>\n
  22. Resume the program. The\u00a0breakpoint will now hit, showing\u00a0that\u00a0the stack pointer is still the same, although the return value stored after it is wrong:
    \n    \"18-badvalue\"<\/a><\/li>\n
  23. We can\u00a0easily identify the instruction responsible for setting this value by adding a data breakpoint (via the Breakpoints window). Set it on the address\u00a0of the return\u00a0address slot (add 4 to current $sp value) and\u00a0make it conditional so it only breaks\u00a0when the\u00a0written value is\u00a0actually incorrect:
    \n    \"19-databp\"<\/a><\/li>\n
  24. Restart the program again. The breakpoint will now trigger in the prologue of the prbCopyDataFromQueue()<\/strong> function. Note that due to the internal logic of the ARM core, it will stop 2 instructions after the actual memory writing instruction:\"20-badwrite\"<\/a><\/li>\n
  25. The instruction is a part of the regular function prologue responsible for saving\u00a0registers into the stack, so\u00a0it would only overwrite the return address if the stack pointer was set incorrectly when the function was called. Using\u00a0\u00a0conventional\u00a0debugging methods would require looking through the related code and\u00a0trying to\u00a0find parts responsible for stack pointer manipulation, however with\u00a0the J-Trace you can simply see the\u00a0list of recently executed functions or instructions and search there:\"21-history\"<\/a><\/li>\n
  26. The code after the PendSV_Handler()<\/strong>\u00a0doesn’t do anything special with the stack pointer, however the PendSV_Handler()<\/strong> itself is\u00a0responsible for\u00a0restoring the stack pointer after a thread switch. Locate the first instruction called after\u00a0the\u00a0return from PendSV_Handler()\u00a0<\/strong>and set a breakpoint there:\"22-change\"<\/a>Also set a breakpoint on the instruction that requests a PendSV interrupt. The\u00a0normal sequence of events should look as follows:\n
      \n
    1. xQueueGenericReceive (running in thread #2) requests a PendSV interrupt.<\/li>\n
    2. The PendSV interrupt handler stores the current stack pointer and registers inside the thread object and switches the thread context to thread #1.<\/li>\n
    3. Eventually the thread #1 enters a wait state (or is preempted).<\/li>\n
    4. The PendSV handler would then restore the context of thread #2 and continue executing it.<\/li>\n<\/ol>\n<\/li>\n
    5. Once the first breakpoint hits, take a note of the $sp value. Normally it should stay the same once the thread context is\u00a0restored:
      \n      \"24-before\"<\/a><\/li>\n
    6. However in this case it doesn’t happen – the $sp value gets increased by 0x48 bytes after the\u00a0return from PendSV_Handler(), making the subsequent code overwrite\u00a0some of the stored values. Eventually the stack pointer is restored based on the frame pointer, but the damage done to the saved values triggers a crash later:\"25-after\"<\/a><\/li>\n
    7. The only remaining step for solving this puzzle is to understand why PendSV corrupts the stack pointer.\u00a0Restart the program again and let the first breakpoint (with the correct stack value) hit. Then set a breakpoint inside the PendSV handler and press F5 (don’t use single-stepping as it would suppress interrupts):\"26-stored\"<\/a>See\u00a0how the\u00a0$lr register contains a special value of 0xfffffd. This indicates the the processor automatically saved all registers to the stack and switched from the thread mode to the handler mode (that has its own stack).\u00a0The “process mode” stack pointer can be\u00a0observed via the $psp register (that is equal to the previously\u00a0observed $sp value minus 0x20).<\/li>\n
    8. Take a note of the pxCurrentTCB value, set a breakpoint\u00a0at the exit from PendSV_Handler() and continue\u00a0the\u00a0program. First time the breakpoint is hit, the pxCurrentTCB will point to a different thread:\"27-exit\"<\/a><\/li>\n
    9. As we are\u00a0only\u00a0interested in the\u00a0thread #2, continue the program until you see the old pxCurrentTCB value again (you can\u00a0set a breakpoint condition, or simply press F5 a couple of times):\"28-bxlr\"<\/a>See how the $psp register got restored correctly (0x20000598 in this example), however the $lr register contains\u00a00xffffffed that\u00a0corresponds to a thread-to-handler mode switch with FP data preservation. If you let the “bx lr” instruction run now, it will “restore” the FP register values from the stack,\u00a0that never contained them. As a result, it will free more space from the stack than it should, corrupting the stack pointer.<\/li>\n<\/ol>\n
      The reconstructed\u00a0sequence of events looks like this:<\/p>\n
        \n
      1. Before running any FP-related code,\u00a0thread #2 triggers the PendSV interrupt that saves the non-FP\u00a0registers on the stack and invokes PendSV_Handler()<\/strong>.<\/li>\n
      2. The PendSV handler\u00a0switches the context to\u00a0thread #1 and returns.<\/li>\n
      3. Thread #1 invokes the sinf() function that uses some FP registers and then triggers the PendSV interrupt again.<\/li>\n
      4. As the FP registers have non-zero values, the\u00a0ARM processor\u00a0saves them to the stack and sets $lr to a special\u00a0value of 0xffffffed that indicates\u00a0the presence of the FP registers on the stack.<\/li>\n
      5. The PendSV handler restores the context of thread #2 (that has not saved any FP registers).<\/li>\n
      6. The PendSV returns using the 0xffffffed value, causing the ARM CPU to\u00a0free more stack than was originally\u00a0used for saving the non-FP registers.<\/li>\n
      7. Subsequent code overwrites the return address stored in the stack before the context switch.<\/li>\n
      8. Eventually the stack pointer is restored to the correct value, but the return address stored in the stack is already wrong.<\/li>\n
      9. When xQueueGenericReceive() returns, it uses the incorrect return address,\u00a0triggering the HardFault exception.<\/li>\n<\/ol>\n
        The problem can be easily solved by switching back to an FP-aware port of FreeRTOS that will handle this case correctly, however as the problem involved several instances of register\/memory corruption before the final crash took place, finding the root cause of the crash\u00a0was not easy and was greatly simplified by using Segger J-Trace that allowed reconstructing the preceding events\u00a0despite\u00a0the fact that any evidence on the stack was long gone.<\/p>\n","protected":false},"excerpt":{"rendered":"
        This\u00a0tutorial shows how to diagnose complex memory corruption problems using the ARM ETM tracing with VisualGDB and Segger J-Trace. ETM<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"closed","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[27],"tags":[53,165,164,61],"_links":{"self":[{"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/posts\/3953"}],"collection":[{"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/comments?post=3953"}],"version-history":[{"count":1,"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/posts\/3953\/revisions"}],"predecessor-version":[{"id":3985,"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/posts\/3953\/revisions\/3985"}],"wp:attachment":[{"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/media?parent=3953"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/categories?post=3953"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/visualgdb.com\/w\/wp-json\/wp\/v2\/tags?post=3953"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}