Bloom and CLion Embedded GDB Server issues

oltdaniel commented 2 years ago

In the planned use case for Bloom in our production ("education") environment, we would like to focus on the CLion internal Debugging functionality. We got it working after 1-2 hours of trying with the following steps and most of the stuff works, but we end up with some read memory errors.

As this is something I think that would nicely fit into the wiki later, I will document everything right away.

Setting up `Embedded GDB Server` in CLion

NOTE Normally CLion requires a gdbserver application here. However, as our Bloom command is actually our GDB Server we simply start bloom right here, which also has the nice effect of simply running automatically if we start debugging.

Starting a Debug session

Now a quick explanation, why you would choose Embedded GDB Server over Remote Debug. If you choose Remote Debug, CLion disables some embedded device features, like Peripherals. If we have these features, we can simply load an SVD File (yes an ARM targeted format, but the community has some tricks up its sleeve).

Loading an SVD File

We are happily greeted with the option to choose an SVD file here. However, in the AVR universe we only have .atdf files which contain this sort of information. But with the help of Rahix/avr-device we can simply convert these files and also patch some issues that may occur.

If done right, we can choose the newly generated svd file and start choosing our desired peripherals to debug.


	For now we simply choose the CPU peripheral to keep things simple. Choosing all peripherals would still work.

The current Bloom limit

Having the SVD loaded, we start causing some Bloom internal issues with the Read memory command.

As there aren't enough debug informations on hand as I installed with simply over the package manager, I will need to compile it and start testing to get deeper into the issue. I will continue to work on it and come back with any new information or even fix.

I'm really happy if I can help with the development or Wiki of this project. However my knowledge of the GDB Protocol is very limited. If you need any svd file that is supported by the mentioned repo, I'll be happy to send you the generated ones. Ask me on Discord via oltdaniel#8514.

oltdaniel commented 2 years ago

I've compiled it now with debugging enabled and tested it in the same way as described above and have the full logging output here.

Log Output after debugger connection established and first breakpoint triggered

``` Debugger connected to tcp:localhost:1442 2022-05-12 17:17:04 CEST [DS] [119]: [DEBUG] Read GDB packet: $Z0,18d8,2#19 2022-05-12 17:17:04 CEST [DS] [120]: [DEBUG] Handling SetBreakpoint packet 2022-05-12 17:17:04 CEST [DS] [121]: [DEBUG] Issuing SetBreakpoint command (ID: 6) to TargetController 2022-05-12 17:17:04 CEST [DS] [122]: [DEBUG] Delivering response for SetBreakpoint command (ID: 6) 2022-05-12 17:17:04 CEST [DS] [123]: [DEBUG] Writing GDB packet: $OK#9a 2022-05-12 17:17:04 CEST [DS] [124]: [DEBUG] Read GDB packet: $vCont?#49 2022-05-12 17:17:04 CEST [DS] [125]: [DEBUG] Unknown GDB RSP packet: vCont? - returning empty response 2022-05-12 17:17:04 CEST [DS] [126]: [DEBUG] Writing GDB packet: $ #00 2022-05-12 17:17:04 CEST [DS] [127]: [DEBUG] Read GDB packet: $Hc0#db 2022-05-12 17:17:04 CEST [DS] [128]: [DEBUG] Unknown GDB RSP packet: Hc0 - returning empty response 2022-05-12 17:17:04 CEST [DS] [129]: [DEBUG] Writing GDB packet: $ #00 2022-05-12 17:17:04 CEST [DS] [130]: [DEBUG] Read GDB packet: $c#63 2022-05-12 17:17:04 CEST [DS] [131]: [DEBUG] Handling ContinueExecution packet 2022-05-12 17:17:04 CEST [DS] [132]: [DEBUG] Issuing ResumeTargetExecution command (ID: 7) to TargetController 2022-05-12 17:17:05 CEST [DS] [133]: [DEBUG] Delivering response for ResumeTargetExecution command (ID: 7) 2022-05-12 17:17:08 CEST [TC] [134]: [DEBUG] Target state changed - STOPPED 2022-05-12 17:17:08 CEST [TC] [135]: [DEBUG] Event "TargetExecutionStopped" (8) registered for listener DebugServerEventListener 2022-05-12 17:17:08 CEST [DS] [136]: [DEBUG] GDB RSP interrupted 2022-05-12 17:17:08 CEST [DS] [137]: [DEBUG] Dispatching event TargetExecutionStopped (8). 2022-05-12 17:17:08 CEST [DS] [138]: [DEBUG] Writing GDB packet: $T05#b9 2022-05-12 17:17:08 CEST [DS] [139]: [DEBUG] Read GDB packet: $g#67 2022-05-12 17:17:08 CEST [DS] [140]: [DEBUG] Handling ReadRegisters packet 2022-05-12 17:17:08 CEST [DS] [141]: [DEBUG] Issuing ReadTargetRegisters command (ID: 8) to TargetController 2022-05-12 17:17:08 CEST [DS] [142]: [DEBUG] Delivering response for ReadTargetRegisters command (ID: 8) 2022-05-12 17:17:08 CEST [DS] [143]: [DEBUG] Writing GDB packet: $0000000000000000000000000000000000000000000000002e0000000000000002fc0fd8180000#bd 2022-05-12 17:17:08 CEST [DS] [144]: [DEBUG] Read GDB packet: $qL1200000000000000000#50 2022-05-12 17:17:08 CEST [DS] [145]: [DEBUG] Unknown GDB RSP packet: qL1200000000000000000 - returning empty response 2022-05-12 17:17:08 CEST [DS] [146]: [DEBUG] Writing GDB packet: $ #00 2022-05-12 17:17:08 CEST [DS] [147]: [DEBUG] Read GDB packet: $z0,18d8,2#39 2022-05-12 17:17:08 CEST [DS] [148]: [DEBUG] Removing breakpoint at address 6360 2022-05-12 17:17:08 CEST [DS] [149]: [DEBUG] Issuing RemoveBreakpoint command (ID: 9) to TargetController 2022-05-12 17:17:08 CEST [DS] [150]: [DEBUG] Delivering response for RemoveBreakpoint command (ID: 9) 2022-05-12 17:17:08 CEST [DS] [151]: [DEBUG] Writing GDB packet: $OK#9a 2022-05-12 17:17:08 CEST [DS] [152]: [DEBUG] Read GDB packet: $qL1200000000000000000#50 2022-05-12 17:17:08 CEST [DS] [153]: [DEBUG] Unknown GDB RSP packet: qL1200000000000000000 - returning empty response 2022-05-12 17:17:08 CEST [DS] [154]: [DEBUG] Writing GDB packet: $ #00 2022-05-12 17:17:08 CEST [DS] [155]: [DEBUG] Read GDB packet: $m1890,40#cf 2022-05-12 17:17:08 CEST [DS] [156]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:08 CEST [DS] [157]: [DEBUG] Issuing ReadTargetMemory command (ID: 10) to TargetController 2022-05-12 17:17:08 CEST [DS] [158]: [DEBUG] Delivering response for ReadTargetMemory command (ID: 10) 2022-05-12 17:17:08 CEST [DS] [159]: [DEBUG] Writing GDB packet: $ff93ffb7f894ff93ef93df93cf93bf93af939f938f937f936f935f934f933f932f931f930f93ff92ef92df92cf92bf92af929f928f927f926f925f924f923f92#96 2022-05-12 17:17:08 CEST [DS] [160]: [DEBUG] Read GDB packet: $m800ffe,2#94 2022-05-12 17:17:08 CEST [DS] [161]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:08 CEST [DS] [162]: [DEBUG] Issuing ReadTargetMemory command (ID: 11) to TargetController 2022-05-12 17:17:08 CEST [DS] [163]: [DEBUG] Delivering response for ReadTargetMemory command (ID: 11) 2022-05-12 17:17:08 CEST [DS] [164]: [DEBUG] Writing GDB packet: $0000#c0 2022-05-12 17:17:12 CEST [DS] [165]: [DEBUG] Read GDB packet: $m3e,4#65 2022-05-12 17:17:12 CEST [DS] [166]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [167]: [DEBUG] Issuing ReadTargetMemory command (ID: 12) to TargetController 2022-05-12 17:17:12 CEST [DS] [168]: [DEBUG] Delivering response for ReadTargetMemory command (ID: 12) 2022-05-12 17:17:12 CEST [DS] [169]: [DEBUG] Writing GDB packet: $44020c94#ca 2022-05-12 17:17:12 CEST [DS] [170]: [DEBUG] Read GDB packet: $m4a,5#63 2022-05-12 17:17:12 CEST [DS] [171]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [172]: [DEBUG] Issuing ReadTargetMemory command (ID: 13) to TargetController 2022-05-12 17:17:12 CEST [DS] [173]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 13). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [174]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [175]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [176]: [DEBUG] Read GDB packet: $m4a,1#5f 2022-05-12 17:17:12 CEST [DS] [177]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [178]: [DEBUG] Issuing ReadTargetMemory command (ID: 14) to TargetController 2022-05-12 17:17:12 CEST [DS] [179]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 14). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [180]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [181]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [182]: [DEBUG] Read GDB packet: $m4e,1#63 2022-05-12 17:17:12 CEST [DS] [183]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [184]: [DEBUG] Issuing ReadTargetMemory command (ID: 15) to TargetController 2022-05-12 17:17:12 CEST [DS] [185]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 15). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [186]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [187]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [188]: [DEBUG] Read GDB packet: $m53,6#37 2022-05-12 17:17:12 CEST [DS] [189]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [190]: [DEBUG] Issuing ReadTargetMemory command (ID: 16) to TargetController 2022-05-12 17:17:12 CEST [DS] [191]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 16). Error: AVR8 Read memory command failed - Failure reason: Asked for badly aligned data 2022-05-12 17:17:12 CEST [DS] [192]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Asked for badly aligned data 2022-05-12 17:17:12 CEST [DS] [193]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [194]: [DEBUG] Read GDB packet: $m53,1#32 2022-05-12 17:17:12 CEST [DS] [195]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [196]: [DEBUG] Issuing ReadTargetMemory command (ID: 17) to TargetController 2022-05-12 17:17:12 CEST [DS] [197]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 17). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [198]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [199]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [200]: [DEBUG] Read GDB packet: $m58,1#37 2022-05-12 17:17:12 CEST [DS] [201]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [202]: [DEBUG] Issuing ReadTargetMemory command (ID: 18) to TargetController 2022-05-12 17:17:12 CEST [DS] [203]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 18). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [204]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [205]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [206]: [DEBUG] Read GDB packet: $m61,9#39 2022-05-12 17:17:12 CEST [DS] [207]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [208]: [DEBUG] Issuing ReadTargetMemory command (ID: 19) to TargetController 2022-05-12 17:17:12 CEST [DS] [209]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 19). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [210]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [211]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [212]: [DEBUG] Read GDB packet: $m61,1#31 2022-05-12 17:17:12 CEST [DS] [213]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [214]: [DEBUG] Issuing ReadTargetMemory command (ID: 20) to TargetController 2022-05-12 17:17:12 CEST [DS] [215]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 20). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [216]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [217]: [DEBUG] Writing GDB packet: $E01#a6 2022-05-12 17:17:12 CEST [DS] [218]: [DEBUG] Read GDB packet: $m69,1#39 2022-05-12 17:17:12 CEST [DS] [219]: [DEBUG] Handling ReadMemory packet 2022-05-12 17:17:12 CEST [DS] [220]: [DEBUG] Issuing ReadTargetMemory command (ID: 21) to TargetController 2022-05-12 17:17:12 CEST [DS] [221]: [DEBUG] TargetController returned error in response to ReadTargetMemory command (ID: 21). Error: AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [222]: [ERROR] Failed to read memory from target - AVR8 Read memory command failed - Failure reason: Too many or too few bytes 2022-05-12 17:17:12 CEST [DS] [223]: [DEBUG] Writing GDB packet: $E01#a6 ```

After digging around a bit more and run Bloom directly in debug mode to set some breakpoints I pulled out the raw GDB console and played around with the x command to read some memory manually. It turns out, there is some "currently random pattern" when GDB throws an Cannot access memory at address error. Following commands work/don't work with my currently flashed ELF and the Atmega644.

~~If someone has new theories what else I should test to maybe find the source of this issue, feel free to comment.~~

oltdaniel commented 2 years ago

I've compared the generated svd file with one from an rp2040 ARM Processor and compared the two. Looks like, as we address the full address space here, the SVD file needs to take care of the 0x800000 offset. So these errors I guess make sense. Additionally I checked the read memory command values which determine the address as flash which would be correct considering the 0x800000 offset is missing. Will test this later and see if the features is then fully working.

oltdaniel commented 2 years ago

Update: Can confirm, the tool just converted it in the wrong way and inserted a bunch of baseAddress items and no offsets at any point. If these are manually changed, they read the correct values and everything works as expected.

navnavnav commented 2 years ago

Hi @oltdaniel

Thanks for reporting this.

Hmm, I don't think the problem is the addresses in the SVD. The ORing of 0x800000 to SRAM/register addresses is specific to GDB. GDB does this to encode the memory type in a memory address.

I think I see the problem here: You're using the GDB that is bundled with CLion. Although that GDB supports multiple architectures, it does not support the AVR architecture:

You need to install avr-gdb. This is a GDB that is configured (at compile time) to be used with the AVR architecture. Oh, and be sure to install a fairly new version. You can download a .deb from https://packages.debian.org/sid/gdb-avr. Install that package and then point CLion to your avr-gdb executable:

Give that a go and let me know how it goes. TBH, I've not used SVD files in CLion, so it's possible that you need to do both (use avr-gdb and convert the address in the SVD). That would be a shame if it's the case - the addresses in the SVD file should not have to accommodate GDB specific functionality. Let's hope you only have to use avr-gdb to resolve the issue.

I will reopen this issue to allow you to post an update. Feel free to close afterwards.

Thanks!

oltdaniel commented 2 years ago

In this case related to this specific feature set required to show and set a breakpoint, there is no difference between using the multiarch or actual gdb client (had been tested by us before, even though the avr gdb is in this case definitely recommended). The address issue is the main thing that went wrong with the following indicators, that can be verified with the Insight Window Data:

Using the integrated memory view of CLion, we receive the same data as the Insight Internal SRAM by using 0x800100 as the address. 0x800000 as the offset to the SRAM itself, 0x100 for the offset of internal registers and stuff.
Thereby, if you e.g. change the baseaddress of the CPU peripheral by adding the 0x800000 offset, the data will be also correct within the CLion Peripheral view.

This means, fixing the baseaddress within the generated SVD file fixed all the issues. Still thanks for checking in to solve this. Awesome work you've done here.

EDIT I'll be able to post comments independent of the close or open state of this issue.

navnavnav commented 2 years ago

Also, just FYI, there is a known issue with configuring Bloom to run as an 'Embedded GDB Server' - CLion doesn't allow it enough time to shutdown. In fact, it's currently unclear how CLion is shutting Bloom down. Not allowing Bloom to shutdown properly may result in subsequent startup failures.

I created a ticket regarding this issue with the CLion team, a few weeks back: https://youtrack.jetbrains.com/issue/CPP-28843

Hopefully they will improve the server termination routine at some point. 👍🏽

oltdaniel commented 2 years ago

Ah ok. With the Atmel ICE 3 we had luck so far, with no startup issues (at least in this configuration). Let's hope Jetbrains will at least give some insight and maybe close it with a sensible timeout (the only thing required and the easiest solution).

And lets hope Jetbrains is better at solving this kind of stuff than Microchip...

bloombloombloom / Bloom