klog repeats the last screen over and over again and eats all memory

[Jakub Jermář]

This is reproducible with mainline 933, default build for HelenOS/arm32/gxemul.

After the system boots, go to kconsole and run:

kconsole> test slab2
kconsole> continue

Upon return, the klog application will be repeating the last output (i.e. screen or so) from kconsole over and over again. It will also eat all available memory when doing so. kconsole itself appears idle.

[Jakub Jermář]

Seems like the problem is that the userspace klog can't keep up with the kernel sending an klog event for every 9 printed characters. What I think happens is this:

1. there's lots of output printed to kconsole
2. the kernel will generate a klog event call for basically each 9 character printed to kconsole
3. in the klog app, these events will be processed by an interrupt fibril
4. the interrupt fibrils will attempt to:
   1. print to console
   2. write to /log/klog
5. the previous step is slow, so one interrupt fibril will block many others while it is in some criticial section associated with 4a or 4b
6. the blocked interrupt fibrils will consume memory e.g. for their stacks and also the message
7. significant amount of fibrils can't run due to the above blocking until some time after the kconsole test command finishes
8. the resumed interrupt fibrils will start printing the klog buffer, which does not change anymore, leading thus to the effect of repeating the last content of the buffer over and over again
9. all interrupt fibrils will eventually finish (perhaps after a very long time), but the memory will not be returned back to the kernel because the user space allocator cannot not shrink the heap yet

[Martin Decky]

As of mainline,948, the points (2), (4), (5), (7) and (8) should be solved or their impact considerably reduced.

However, one major issue still remains even with the reimplementation: uspace klog will leak physical memory because the address space areas used for the uspace heap are never physically shrunk so far (heap_shrink() in malloc.c is not implemented properly).

[Jakub Jermář]

IMHO this ticket may be closed now.

Heap shrinking was integrated in mainline,955 and since mainline,950, the klog data flow is handled correctly.