💾 Archived View for gmi.noulin.net › markdown › straceMalloc_README.md captured on 2023-07-10 at 18:19:11.
-=-=-=-=-=-=-
malloc.c is a program allocating blocks of memory with malloc. strace logs the system calls to the linux kernel, __mmap__ is the syscall used by malloc to allocate large blocks of RAM. The time spend in each malloc is measured, as you can see in the log, there is only a small variation. malloc.c allocates buffers increasingly big starting with 1KB and ending with 32MB. On my system, glibc allocates 128KB initially, so the first 6 allocations dont trigger a syscall. For buffers larger than 128KB, malloc calls the mmap syscall and the time spent in malloc is on average the same. When allocating buffers with alloca, the time spent in alloca depends on the buffer size, it takes more time for larger buffers. alloca never triggers a syscall as seen in the strace log. Compiling and running:
sheepy -c malloc.c
./malloc
strace ./malloc
malloc output:
alloc
0 0x55949cb3a420 size: 1KB, time: 560ns
1 0x55949cb3a830 size: 2KB, time: 1612ns
2 0x55949cb3b040 size: 4KB, time: 1568ns
3 0x55949cb3c050 size: 8KB, time: 1303ns
4 0x55949cb3e060 size: 16KB, time: 1211ns
5 0x55949cb42070 size: 32KB, time: 1206ns
6 0x55949cb4a080 size: 64KB, time: 1217ns
7 0x7f6f87048010 size: 128KB, time: 2899ns
8 0x7f6f87007010 size: 256KB, time: 2574ns
9 0x7f6f86f86010 size: 512KB, time: 1868ns
10 0x7f6f867a8010 size: 1024KB, time: 2894ns
11 0x7f6f865a7010 size: 2048KB, time: 2189ns
12 0x7f6f861a6010 size: 4096KB, time: 2329ns
13 0x7f6f859a5010 size: 8192KB, time: 2323ns
14 0x7f6f849a4010 size: 16384KB, time: 1973ns
15 0x7f6f829a3010 size: 32768KB, time: 2191ns
s
alloca 0 0x7fff5b02ce70 size: 1KB, time: 39ns
alloca 1 0x7fff5b02c660 size: 2KB, time: 32ns
alloca 2 0x7fff5b02b650 size: 4KB, time: 31ns
alloca 3 0x7fff5b029640 size: 8KB, time: 1078ns
alloca 4 0x7fff5b025630 size: 16KB, time: 970ns
alloca 5 0x7fff5b01d620 size: 32KB, time: 1162ns
alloca 6 0x7fff5b00d610 size: 64KB, time: 978ns
alloca 7 0x7fff5afed600 size: 128KB, time: 1425ns
alloca 8 0x7fff5afad5f0 size: 256KB, time: 1044ns
alloca 9 0x7fff5af2d5e0 size: 512KB, time: 1148ns
alloca 10 0x7fff5ae2d5d0 size: 1024KB, time: 961ns
alloca 11 0x7fff5ac2d5c0 size: 2048KB, time: 1241ns
strace log on debian stretch:
write(1, "alloc\n", 6alloc
) = 6
write(1, "0 0x55e346706420 size: 1024, tim"..., 410 0x55e346706420 size: 1024, time: 837ns
) = 41
write(1, "1 0x55e346706830 size: 2048, tim"..., 421 0x55e346706830 size: 2048, time: 1960ns
) = 42
write(1, "2 0x55e346707040 size: 4096, tim"..., 422 0x55e346707040 size: 4096, time: 1712ns
) = 42
write(1, "3 0x55e346708050 size: 8192, tim"..., 423 0x55e346708050 size: 8192, time: 1588ns
) = 42
write(1, "4 0x55e34670a060 size: 16384, ti"..., 434 0x55e34670a060 size: 16384, time: 1573ns
) = 43
write(1, "5 0x55e34670e070 size: 32768, ti"..., 435 0x55e34670e070 size: 32768, time: 1486ns
) = 43
write(1, "6 0x55e346716080 size: 65536, ti"..., 436 0x55e346716080 size: 65536, time: 1487ns
) = 43
mmap(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475dc2f000
write(1, "7 0x7f475dc2f010 size: 131072, t"..., 457 0x7f475dc2f010 size: 131072, time: 20558ns
) = 45
mmap(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475dbee000
write(1, "8 0x7f475dbee010 size: 262144, t"..., 458 0x7f475dbee010 size: 262144, time: 19708ns
) = 45
mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475db6d000
write(1, "9 0x7f475db6d010 size: 524288, t"..., 459 0x7f475db6d010 size: 524288, time: 16711ns
) = 45
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475d38f000
write(1, "10 0x7f475d38f010 size: 1048576,"..., 4710 0x7f475d38f010 size: 1048576, time: 19502ns
) = 47
mmap(NULL, 2101248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475d18e000
write(1, "11 0x7f475d18e010 size: 2097152,"..., 4711 0x7f475d18e010 size: 2097152, time: 18659ns
) = 47
mmap(NULL, 4198400, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475cd8d000
write(1, "12 0x7f475cd8d010 size: 4194304,"..., 4712 0x7f475cd8d010 size: 4194304, time: 17346ns
) = 47
mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475c58c000
write(1, "13 0x7f475c58c010 size: 8388608,"..., 4713 0x7f475c58c010 size: 8388608, time: 18613ns
) = 47
mmap(NULL, 16781312, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475b58b000
write(1, "14 0x7f475b58b010 size: 16777216"..., 4814 0x7f475b58b010 size: 16777216, time: 17792ns
) = 48
mmap(NULL, 33558528, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f475958a000
write(1, "15 0x7f475958a010 size: 33554432"..., 4815 0x7f475958a010 size: 33554432, time: 16998ns
) = 48
write(1, "s\n", 2s
) = 2
write(1, "alloca 0 0x7ffd31053480 size: 1K"..., 46alloca 0 0x7ffd31053480 size: 1KB, time: 51ns
) = 46
write(1, "alloca 1 0x7ffd31052c70 size: 2K"..., 46alloca 1 0x7ffd31052c70 size: 2KB, time: 37ns
) = 46
write(1, "alloca 2 0x7ffd31051c60 size: 4K"..., 46alloca 2 0x7ffd31051c60 size: 4KB, time: 60ns
) = 46
write(1, "alloca 3 0x7ffd3104fc50 size: 8K"..., 48alloca 3 0x7ffd3104fc50 size: 8KB, time: 1897ns
) = 48
write(1, "alloca 4 0x7ffd3104bc40 size: 16"..., 49alloca 4 0x7ffd3104bc40 size: 16KB, time: 1224ns
) = 49
write(1, "alloca 5 0x7ffd31043c30 size: 32"..., 49alloca 5 0x7ffd31043c30 size: 32KB, time: 1266ns
) = 49
write(1, "alloca 6 0x7ffd31033c20 size: 64"..., 49alloca 6 0x7ffd31033c20 size: 64KB, time: 1318ns
) = 49
write(1, "alloca 7 0x7ffd31013c10 size: 12"..., 50alloca 7 0x7ffd31013c10 size: 128KB, time: 1908ns
) = 50
write(1, "alloca 8 0x7ffd30fd3c00 size: 25"..., 50alloca 8 0x7ffd30fd3c00 size: 256KB, time: 2673ns
) = 50
write(1, "alloca 9 0x7ffd30f53bf0 size: 51"..., 50alloca 9 0x7ffd30f53bf0 size: 512KB, time: 2582ns
) = 50
write(1, "alloca 10 0x7ffd30e53be0 size: 1"..., 52alloca 10 0x7ffd30e53be0 size: 1024KB, time: 1391ns
) = 52
write(1, "alloca 11 0x7ffd30c53bd0 size: 2"..., 52alloca 11 0x7ffd30c53bd0 size: 2048KB, time: 2118ns
) = 52
exit_group(0) = ?