Coming from this issue:
Memory Leak in fptest UnitI found that the Unit
heaptrc does not write its report when the
STDERR is redirected.
The normal behaviour is that
heaptrc write its report to
STDERRas seen in this
strace log:
$ strace -f -o strace_demo_2020-10-22-2.log ./demo_hash-lists.run
Key: 'gob': 'gob_value'
Key: 'bog': 'bog_value'
Key: 'bob': ''
hsh map (cnt: '2'):
str map 'es' (cnt: '4'):
; key: 'key6' => 'value6'; key: 'bog' => 'bog_value'; key: 'gob' => 'gob_value'; key: 'trying a somwhat very long key 1' => 'inserting it's somewhat very long value 1'
str map 'en' (cnt: '3'):
; key: 'ab' => 'cd'; key: 'ij' => 'kl'; key: 'ef' => 'gh'
Heap dump by heaptrc unit
66 memory blocks allocated : 3144/3168
66 memory blocks freed : 3144/3168
0 unfreed memory blocks : 0
True heap size : 131072
True free heap : 131072
produces this
strace activity log:
$ grep -ni "" strace_demo_2020-10-22-2.log
1:2581 execve("./demo_hash-lists.run", ["./demo_hash-lists.run"], 0x7ffd15c72448 /* 46 vars */) = 0
2:2581 getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
3:2581 rt_sigaction(SIGFPE, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
4:2581 rt_sigaction(SIGSEGV, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
5:2581 rt_sigaction(SIGBUS, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
6:2581 rt_sigaction(SIGILL, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
7:2581 ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
8:2581 ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0
9:2581 ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
10:2581 ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0
11:2581 readlink("/proc/self/exe", "/home/bodo/Projekte/pascal/hash-"..., 255) = 57
12:2581 open("/etc/timezone", O_RDONLY|O_LARGEFILE) = 3
13:2581 read(3, "Atlantic/Canary\n", 255) = 16
14:2581 close(3) = 0
15:2581 open("/usr/share/zoneinfo/Atlantic/Canary", O_RDONLY|O_LARGEFILE) = 3
16:2581 read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\6\0\0\0\0"..., 2048) = 1911
17:2581 mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaefe000
18:2581 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaef6000
19:2581 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaeee000
20:2581 close(3) = 0
21:2581 time([1603402165 /* 2020-10-22T22:29:25+0100 */]) = 1603402165 (2020-10-22T22:29:25+0100)
22:2581 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaee6000
23:2581 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaede000
24:2581 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaed6000
25:2581 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcfdaece000
26:2581 write(1, "Key: 'gob': '", 13) = 13
27:2581 write(1, "gob_value", 9) = 9
28:2581 write(1, "'\n", 2) = 2
29:2581 write(1, "Key: 'bog': '", 13) = 13
30:2581 write(1, "bog_value", 9) = 9
31:2581 write(1, "'\n", 2) = 2
32:2581 write(1, "Key: 'bob': '", 13) = 13
33:2581 write(1, "'\n", 2) = 2
34:2581 write(1, "hsh map (cnt: '2'):\n", 20) = 20
35:2581 write(1, "str map 'es' (cnt: '4'):\n", 25) = 25
36:2581 write(1, "; key: 'key6' => 'value6'", 25) = 25
37:2581 write(1, "; key: 'bog' => 'bog_value'", 27) = 27
38:2581 write(1, "; key: 'gob' => 'gob_value'", 27) = 27
39:2581 write(1, "; key: 'trying a somwhat very lo"..., 88) = 88
40:2581 write(1, "\n", 1) = 1
41:2581 write(1, "str map 'en' (cnt: '3'):\n", 25) = 25
42:2581 write(1, "; key: 'ab' => 'cd'", 19) = 19
43:2581 write(1, "; key: 'ij' => 'kl'", 19) = 19
44:2581 write(1, "; key: 'ef' => 'gh'", 19) = 19
45:2581 write(1, "\n", 1) = 1
46:2581 munmap(0x7fcfdaefe000, 262144) = 0
47:2581 munmap(0x7fcfdaef6000, 32768) = 0
48:2581 munmap(0x7fcfdaeee000, 32768) = 0
49:2581 write(2, "Heap dump by heaptrc unit\n", 26) = 26
50:2581 write(2, "66 memory blocks allocated : 314"..., 39) = 39
51:2581 write(2, "66 memory blocks freed : 314"..., 39) = 39
52:2581 write(2, "0 unfreed memory blocks : 0\n", 28) = 28
53:2581 write(2, "True heap size : 131072", 23) = 23
54:2581 write(2, "\n", 1) = 1
55:2581 write(2, "True free heap : 131072\n", 24) = 24
56:2581 munmap(0x7fcfdaee6000, 32768) = 0
57:2581 munmap(0x7fcfdaede000, 32768) = 0
58:2581 munmap(0x7fcfdaed6000, 32768) = 0
59:2581 munmap(0x7fcfdaece000, 32768) = 0
60:2581 exit_group(0) = ?
61:2581 +++ exited with 0 +++
Between lines 49 - 54 it shows that the Report is written to STDERR
Now redirecting the STDERR this whole section is missing:
$ strace -f -o strace_demo_2020-10-22-1.log ./demo_hash-lists.run 2>demo_error.log 1>demo_report.log
$ grep -ni "" strace_demo_2020-10-22-1.log
1:2566 execve("./demo_hash-lists.run", ["./demo_hash-lists.run"], 0x7fffb7d8b7d8 /* 46 vars */) = 0
2:2566 getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
3:2566 rt_sigaction(SIGFPE, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
4:2566 rt_sigaction(SIGSEGV, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
5:2566 rt_sigaction(SIGBUS, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
6:2566 rt_sigaction(SIGILL, {sa_handler=0x4244e0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x4026b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8 ) = 0
7:2566 ioctl(1, TCGETS, 0x7fffb4bf5f80) = -1 ENOTTY (Función ioctl no apropiada para el dispositivo)
8:2566 ioctl(2, TCGETS, 0x7fffb4bf5f80) = -1 ENOTTY (Función ioctl no apropiada para el dispositivo)
9:2566 ioctl(1, TCGETS, 0x7fffb4bf5f80) = -1 ENOTTY (Función ioctl no apropiada para el dispositivo)
10:2566 ioctl(2, TCGETS, 0x7fffb4bf5f80) = -1 ENOTTY (Función ioctl no apropiada para el dispositivo)
11:2566 readlink("/proc/self/exe", "/home/bodo/Projekte/pascal/hash-"..., 255) = 57
12:2566 open("/etc/timezone", O_RDONLY|O_LARGEFILE) = 3
13:2566 read(3, "Atlantic/Canary\n", 255) = 16
14:2566 close(3) = 0
15:2566 open("/usr/share/zoneinfo/Atlantic/Canary", O_RDONLY|O_LARGEFILE) = 3
16:2566 read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\6\0\0\0\0"..., 2048) = 1911
17:2566 mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d6986000
18:2566 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d697e000
19:2566 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d6976000
20:2566 close(3) = 0
21:2566 time([1603401977 /* 2020-10-22T22:26:17+0100 */]) = 1603401977 (2020-10-22T22:26:17+0100)
22:2566 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d696e000
23:2566 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d6966000
24:2566 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d695e000
25:2566 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f15d6956000
26:2566 write(1, "Key: 'gob': 'gob_value'\nKey: 'bo"..., 256) = 256
27:2566 write(1, " very long value 1'\nstr map 'en'"..., 103) = 103
28:2566 munmap(0x7f15d6986000, 262144) = 0
29:2566 munmap(0x7f15d697e000, 32768) = 0
30:2566 munmap(0x7f15d6976000, 32768) = 0
31:2566 munmap(0x7f15d696e000, 32768) = 0
32:2566 munmap(0x7f15d6966000, 32768) = 0
33:2566 munmap(0x7f15d695e000, 32768) = 0
34:2566 munmap(0x7f15d6956000, 32768) = 0
35:2566 exit_group(0) = ?
36:2566 +++ exited with 0 +++
Between lines 31 and 32 the
heaptrc is expected but it simply does not happen.
This issue is especially relevant because it hinders any use of
heaptrc in any reliable
CI pipeline.
I like this feature very much because it helps to develop solid and reliable applications. I would not like just to disable it because the code quality would suffer.