sys/shell: add heap command #10953

gschorcht · 2019-02-05T17:32:09Z

Contribution description

During the development of applications that are using dynamic memory by malloc and free, it is often helpful to get information about the current heap status. There was an old fragment of a heap shell command in the current master which was initially added only for LPC2387 some years ago but removed with PR #3530 with the introduction of the newlib_syscalls_default module.

With this PR provides a module heap_cmd which introduces a more general implementation of this heap command for all platforms. If module heap_cmd is enabled shell command heap is added. This command calls a function heap_stats which should print the heap statistic heap size, used bytes and free bytes. The function is either realized by newlib_syscalls_default or by the CPU if the CPU declares that it has such a function by define HAVE_HEAP_STATS. If the function does not exist, it simply prints that the function is not supported.

Following platforms are supported:

Platforms that use newlib_syscalls_default are working out of the box, e.g., all Cortex-M MCUs.
AVR MCUs implement function heap_stats~~, the implementation requires PR cpu/atmega_common: make remaining RAM available as heap #10934~~.
MIPS32R2 CPUs implement function heap_stats.
MSP430 CPUs implement function heap_stats~~, this implementation requires PR cpu/msp430_common: set top of heap for sbrk #10943 and cpu/msp430_common: add real malloc/free functions #10944~~.
ESP8266 and ESP32 implement function heap_stats
FE310 CPU implements function heap_stats.

Following platforms are not supported:

native

The PR also includes a shell-based test application tests/heap_cmd by which additional commands malloc and free can be used to test the heap functions.

Testing procedure

Use tests/heap_cmd and execute commands malloc, free and heap to test.

Issues/PRs references

~~Depends on PR #10934, #10943 and #10944.~~

smlng · 2019-04-15T09:01:34Z

tested on AVR (arduino-mega2560) but looks weird:

> heap
2019-04-15 10:58:44,825 - INFO #  heap
2019-04-15 10:58:44,864 - INFO # heap: -2563 (used -2563, free 0) [bytes]
> malloc 10
2019-04-15 10:58:54,936 - INFO #  malloc 10
2019-04-15 10:58:54,936 - INFO # ptr=0
> heap
2019-04-15 10:58:59,753 - INFO #  heap
2019-04-15 10:58:59,793 - INFO # heap: -2563 (used 0, free -2563) [bytes]
malloc 20
2019-04-15 10:59:15,816 - INFO #  malloc 20
2019-04-15 10:59:15,816 - INFO # ptr=0
> heap
2019-04-15 10:59:21,714 - INFO #  heap
2019-04-15 10:59:21,754 - INFO # heap: -2563 (used 0, free -2563) [bytes]

smlng · 2019-04-15T09:06:08Z

on ESP8266 it works, question: size is in HEX too, right? However, I think DEC is more natural to the user.

gschorcht · 2019-04-15T09:16:06Z

@smlng Thanks for testing.

tested on AVR (arduino-mega2560) but looks weird:

Strange, I tested it with arduino-mega2560 too before I opened the PR. It seems that variables __malloc_heap_start and __malloc_heap_end are not initialized correctly. Have you build it on top of PR #10934 which is doing that for Atmega?

gschorcht · 2019-04-15T09:17:02Z

on ESP8266 it works, question: size is in HEX too, right? However, I think DEC is more natural to the user.

No, should be in decimal.

smlng · 2019-04-15T09:18:41Z

on ESP8266 it works, question: size is in HEX too, right? However, I think DEC is more natural to the user.

No, should be in decimal.

Output on esp8266:

> heap
2019-04-15 11:04:13,874 - INFO #  heap
2019-04-15 11:04:13,898 - INFO # heap: 64880 (used 660, free 64220) [bytes]
> malloc 10
2019-04-15 11:04:17,868 - INFO #  malloc 10
2019-04-15 11:04:17,868 - INFO # ptr=0x3ffec530
heap
2019-04-15 11:04:26,205 - INFO #  heap
2019-04-15 11:04:26,228 - INFO # heap: 64880 (used 676, free 64204) [bytes]
> malloc 20
2019-04-15 11:04:55,004 - INFO #  malloc 20
2019-04-15 11:04:55,007 - INFO # ptr=0x3ffec540
> heap
2019-04-15 11:04:57,693 - INFO #  heap
2019-04-15 11:04:57,717 - INFO # heap: 64880 (used 708, free 64172) [bytes]

malloc 10 reduces heap by 16 and then malloc 20 by 32, looks like HEX to me

smlng · 2019-04-15T09:19:04Z

@smlng Thanks for testing.

tested on AVR (arduino-mega2560) but looks weird:

Strange, I tested it with arduino-mega2560 too. It seems that variables __malloc_heap_start and __malloc_heap_end are not initialized correctly. Have you build it on top of PR #10934 which is doing that for Atmega?

isn't that one included here?

smlng · 2019-04-15T09:22:18Z

Oh I see, it is not 😞 my bad, will retry ...

gschorcht · 2019-04-15T09:23:13Z

Strange, I tested it with arduino-mega2560 too. It seems that variables __malloc_heap_start and __malloc_heap_end are not initialized correctly. Have you build it on top of PR #10934 which is doing that for Atmega?

isn't that one included here?

No, it is kept completely separate since compilation of this PR works also without the changes of PR #10934.

smlng · 2019-04-15T09:27:09Z

okay rebased on top of #10934, and it works:

> heap
2019-04-15 11:23:09,120 - INFO #  heap
2019-04-15 11:23:09,158 - INFO # heap: 6099 (used 0, free 6099) [bytes]
> malloc 10
2019-04-15 11:23:13,351 - INFO #  malloc 10
2019-04-15 11:23:13,352 - INFO # ptr=0xa05
> heap
2019-04-15 11:23:15,510 - INFO #  heap
2019-04-15 11:23:15,549 - INFO # heap: 6099 (used 12, free 6087) [bytes]
> malloc 20
2019-04-15 11:23:25,997 - INFO #  malloc 20
2019-04-15 11:23:26,003 - INFO # ptr=0xa11
> heap
2019-04-15 11:23:28,403 - INFO #  heap
2019-04-15 11:23:28,441 - INFO # heap: 6099 (used 34, free 6065) [bytes]
free 0xa05
2019-04-15 11:24:06,386 - INFO #  free 0xa05
2019-04-15 11:24:06,386 - INFO # free 0xa05
> heap
2019-04-15 11:24:07,462 - INFO #  heap
2019-04-15 11:24:07,501 - INFO # heap: 6099 (used 24, free 6075) [bytes]
> free 0xa11
2019-04-15 11:25:17,925 - INFO #  free 0xa11
2019-04-15 11:25:17,925 - INFO # free 0xa11
> heap
2019-04-15 11:25:19,115 - INFO #  heap
2019-04-15 11:25:19,152 - INFO # heap: 6099 (used 0, free 6099) [bytes]

gschorcht · 2019-04-15T09:37:21Z

malloc 10 reduces heap by 16 and then malloc 20 by 32, looks like HEX to me

Ok, it seems to be HEX for you but it isn't 😉

There is some overhead for chunk management structures that decreases the heap. For example, if you use malloc 1000, you will see that the heap decreases by 1.008 bytes. The additional 8 bytes are the pointer to the chunk plus its size. The size of the overhead can differ since it makes a difference whether malloc has to allocate a new chunk of bigger size or just a block inside an existing chunk.

smlng · 2019-04-15T09:54:14Z

yeah, was already expecting some kind of overhead being involved here - but it fits so nicely with HEX. However, I tried more values for malloc and can confirm it is not HEX but rather DEC as it should be. so my initial limited tests matched just by chance.

smlng · 2019-04-15T11:18:18Z

please rebase and squash as needed

gschorcht · 2019-04-15T11:51:48Z

@smlng I had to resolve conflicts for MSP430. Therefore, I would like to test it with WSN430 nodes in IoT-LAB again before I push it, but the testbed is down at the moment.

gschorcht · 2019-04-15T23:11:12Z

Tested again msp430_common with WSN430 in IoT-LAB. It still works.

smlng

tested again, still works. I would include this and improve/change later to (maybe) separate the print from getting the stats, as I suggested earlier. However, that can be done in a separate PR.

I also checked code sizes, it has no effect if not used ... as expected, so all good here.

smlng · 2019-09-05T09:49:07Z

please check and fix CI errors (cppcheck is not happy) and also squash (if needed)

gschorcht · 2019-09-05T10:19:08Z

Hm ... wierd

Running './dist/tools/cppcheck/check.sh'
	cpu/esp32/syscalls.c:238: portability (invalidPrintfArgType_uint): %u in format string (no. 1) requires 'unsigned int' but the argument type is 'size_t {aka unsigned long}'.

Here, cppcheck and gcc have different opinions. When I change the format string to %lu as cppcheck requires, the compiler complains:

cpu/esp32/syscalls.c:238:12: error: format '%lu' expects argument of type 'long unsigned int', but argument 2 has type 'size_t {aka unsigned int}' [-Werror=format=]
     printf("heap: %lu (used %lu free %lu) [bytes]\n",

So, cppcheck suppose that size_t is unsigned long while gcc says it is unsigned int.

I could solve it only by hard casting data types. But casting to unsigned int on a 32 platform with 32 bit integer size should be OK in any case since we could address 4 GByte with it.

gschorcht · 2019-09-05T12:13:00Z

@smlng I had to blacklist arduino-nano because of it memory limitation, but now, all lights are green.

BTW, I have already opened an issue #12173 for refactoring heap_stats according to the discussion in this PR.

smlng · 2019-09-05T13:46:53Z

I'd like to maybe get a second opinion: maybe @kaspar030, @MrKevinWeiss or @MichelRottleuthner : any objections from your sides?

To me this looks good to go, it doesn't increase binary size when unused but might still be handy for debugging and such.

MrKevinWeiss · 2019-09-09T10:00:23Z

I would like to see an on target test to go along with this.

Just a simple heap, malloc, heap, free, heap just so it is easy to run tests on all boards. Also the TEST_ON_CI_WHITELIST += all only makes sense if there is a test that can be run from murdock.

kaspar030 · 2019-09-09T10:15:07Z

Also the TEST_ON_CI_WHITELIST += all only makes sense if there is a test that can be run from murdock.

Also, isn't that default by now?

gschorcht · 2019-09-25T14:51:04Z

I would like to see an on target test to go along with this.

Just a simple heap, malloc, heap, free, heap just so it is easy to run tests on all boards.

Just to clarify. Although it should be possible to execute such a sequence of these commands, the output of the heap command in bytes can not be checked because the total number of allocated bytes depends on the heap implementation. It differs from platform to platform.

gschorcht · 2019-09-25T21:19:45Z

@MrKevinWeiss I wrote a short test [UPDATE] but I have the problem that the free command is executed twice. You can see in the following output that the same free command is executed a second time, even though heap command is sent. I have no idea what the reason might be.[SOLVED]

2019-09-25 19:30:58,218 - INFO # main(): This is RIOT! (Version: 2019.10-devel-627-g21e8c-sys/shell/heap_cmd/pr)
2019-09-25 19:30:58,285 - INFO # Shell-based test application for heap functions.
2019-09-25 19:30:58,326 - INFO # Use the 'help' command to get more information on how to use it.
> heap
2019-09-25 19:31:00,328 - INFO #  heap
2019-09-25 19:31:00,346 - INFO # heap: 6048 (used 0, free 6048) [bytes]
> malloc 100
2019-09-25 19:31:00,433 - INFO #  malloc 100
2019-09-25 19:31:00,434 - INFO # allocated ptr=0xa3b
> heap
2019-09-25 19:31:00,523 - INFO #  heap
2019-09-25 19:31:00,544 - INFO # heap: 6048 (used 102, free 5946) [bytes]
> free 0xa3b
2019-09-25 19:31:00,631 - INFO #  free 0xa3b
2019-09-25 19:31:00,632 - INFO # freed ptr=0xa3b
> heap
2019-09-25 19:31:00,662 - INFO #  free 0xa3b
2019-09-25 19:31:00,663 - INFO # freed ptr=0xa3b
> 2019-09-25 19:31:00,719 - INFO #  heap
2019-09-25 19:31:00,740 - INFO # heap: 6048 (used -100, free 6148) [bytes]

gschorcht · 2019-09-27T08:14:21Z

@MrKevinWeiss The test program is working. The PR would have to be squashed.

MrKevinWeiss · 2019-10-01T11:26:28Z

Great, I will look at it shortly. Many thanks for all the work!

MrKevinWeiss

Retested with the automatic test provided. ACK and please squash.

The any boards failed due to terminal problems and not the implementation:

# Build '10953' with 'tests/heap_cmd'

#### arduino-mega2560/failuresummary.md


#### cc2650-launchpad/failuresummary.md


#### ek-lm4f120xl/failuresummary.md


#### esp32-wroom-32/failuresummary.md

Failures during test:
- [tests/heap_cmd](tests/heap_cmd/test.failed)

#### frdm-k64f/failuresummary.md


#### frdm-kw41z/failuresummary.md


#### msba2/failuresummary.md


#### mulle/failuresummary.md

Failures during test:
- [tests/heap_cmd](tests/heap_cmd/test.failed)

#### nrf52dk/failuresummary.md


#### nucleo-f103rb/failuresummary.md


#### pba-d-01-kw2x/failuresummary.md


#### sltb001a/failuresummary.md


#### stm32f3discovery/failuresummary.md

smlng · 2019-10-02T09:37:24Z

please squash

gschorcht · 2019-10-02T13:58:30Z

Squashed

gschorcht · 2019-10-04T11:51:32Z

@MrKevinWeiss Thanks for your support.

MrKevinWeiss · 2019-10-04T12:39:55Z

Anytime 😎

gschorcht force-pushed the sys/shell/heap_cmd/pr branch from 9ba068c to 82cedd4 Compare February 6, 2019 12:10

RIOT-OS deleted a comment Feb 6, 2019

gschorcht force-pushed the sys/shell/heap_cmd/pr branch from 73eea1f to d1431d7 Compare February 6, 2019 15:33

gschorcht removed the State: WIP State: The PR is still work-in-progress and its code is not in its final presentable form yet label Feb 6, 2019

gschorcht added this to the Release 2019.04 milestone Mar 3, 2019

gschorcht mentioned this pull request Mar 14, 2019

cpu/esp8266: complete reimplementation based on ESP8266 RTOS SDK #11108

Merged

20 tasks

gschorcht force-pushed the sys/shell/heap_cmd/pr branch from d1431d7 to 740618d Compare April 15, 2019 23:10

smlng approved these changes Sep 5, 2019

View reviewed changes

gschorcht mentioned this pull request Sep 5, 2019

sys: heap_stats module required #12173

Closed

gschorcht mentioned this pull request Sep 30, 2019

cpu/fe310: use common names for heap markers #12328

Closed

MrKevinWeiss approved these changes Oct 2, 2019

View reviewed changes

gschorcht added 4 commits October 2, 2019 14:21

tests/heap_cmd: shell-based heap function test app

edae6b5

cpu/esp32: fix conflicts after rebase

3c47cc5

cpu/esp: fix conflicts after rebase

5521a6c

tests/heap_cmd: blacklist arduino-nano due to memory limit

37debfd

gschorcht force-pushed the sys/shell/heap_cmd/pr branch from 5a4038a to 37debfd Compare October 2, 2019 12:21

MrKevinWeiss merged commit 4b7c591 into RIOT-OS:master Oct 4, 2019

gschorcht deleted the sys/shell/heap_cmd/pr branch October 4, 2019 11:53

sys/shell: add heap command #10953

sys/shell: add heap command #10953

Uh oh!

Conversation

gschorcht commented Feb 5, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Contribution description

Testing procedure

Issues/PRs references

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

gschorcht commented Apr 15, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

gschorcht commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

gschorcht commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

gschorcht commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

smlng commented Apr 15, 2019

Uh oh!

gschorcht commented Apr 15, 2019

Uh oh!

gschorcht commented Apr 15, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

smlng left a comment

Choose a reason for hiding this comment

Uh oh!

smlng commented Sep 5, 2019

Uh oh!

gschorcht commented Sep 5, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

gschorcht commented Sep 5, 2019

Uh oh!

smlng commented Sep 5, 2019

Uh oh!

MrKevinWeiss commented Sep 9, 2019

Uh oh!

kaspar030 commented Sep 9, 2019

Uh oh!

gschorcht commented Sep 25, 2019

Uh oh!

gschorcht commented Sep 25, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

gschorcht commented Sep 27, 2019

Uh oh!

MrKevinWeiss commented Oct 1, 2019

Uh oh!

MrKevinWeiss left a comment

Choose a reason for hiding this comment

Uh oh!

smlng commented Oct 2, 2019

Uh oh!

gschorcht commented Oct 2, 2019

Uh oh!

gschorcht commented Oct 4, 2019

Uh oh!

MrKevinWeiss commented Oct 4, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

gschorcht commented Feb 5, 2019 •

edited

Loading

gschorcht commented Apr 15, 2019 •

edited

Loading

gschorcht commented Apr 15, 2019 •

edited

Loading

gschorcht commented Sep 5, 2019 •

edited

Loading

gschorcht commented Sep 25, 2019 •

edited

Loading