Memory leak when SerialStreamer is used

[microbit-carlos]

This programme runs for about 1 min 30 s and then we get a MICROBIT_HEAP_ERROR 030 error.

#include "MicroBit.h"
#include "SerialStreamer.h"

MicroBit uBit;

int main() {
    uBit.init();

    SerialStreamer *streamer = new SerialStreamer(uBit.audio.processor->output, SERIAL_STREAM_MODE_BINARY);
    uBit.audio.requestActivation();
    uBit.audio.activateMic();

    while (true) {
        uBit.sleep(1000);
    }
}

[martinwork]

Most often the panic is in isReadOnlyInline() from incr() when refCount == 1, implying a buffer being copied has been destroyed. I have also seen a panic from decr().
https://github.com/lancaster-university/codal-core/blob/master/source/types/RefCounted.cpp#L52

It doesn’t seem to be heap corruption, but that a RefCounted buffer has been released too many times and destroyed.

I have seen a panic in CodalHeapAllocator when a ref counted buffer was being freed.
https://github.com/lancaster-university/codal-core/blob/master/source/core/CodalHeapAllocator.cpp#L378

I have seen SerialStreamer::lastBuffer crash when assigning a new pull because it’s previous ref counted object has been freed.

I think one problem is that the buffer operations are not interrupt safe.

I have analysed one example, built with GNU 12.3.1, involving DataStream::nextBuffer, which seems to show DataStream::pull() interrupted at the wrong instant, for a visit to DataStream::pullRequest(), which leads to a double release of DataStream::nextBuffer.
https://github.com/lancaster-university/codal-core/blob/master/source/streams/DataStream.cpp#L160
https://github.com/lancaster-university/codal-core/blob/master/source/streams/DataStream.cpp#L193

A panic occurs as DataStream::pull() tries to return tmp, because its ptr has been released and destroyed.

Line numbers above may be different because of added trace code:
https://github.com/martinwork/microbit-v2-samples/tree/test-serialstreamer
https://github.com/martinwork/codal-core/tree/test-serialstreamer
https://github.com/martinwork/codal-microbit-v2/tree/test-refcounted

Without the trace code additions, it can take a lot longer to panic, but it does eventually.

See the log below. As I understand it...

• In DataStream::pull(), this->nextBuffer = ManagedBuffer() is interrupted inside decr(), before the refCount is reduced, and before the ptr (0x20006EF0) is changed.
• Another buffer (0x200024B8) using 6EF0 is reassigned, which reduces the refCount.
• Inside DataStream::pullRequest, nextBuffer, with the same ptr 6EF0, is reassigned, so it reduces the 6EF0 refCount again (I think this is the extra decrement).
• When the interrupt returns to the original nextBuffer decr() call, it will go ahead with the original intended decrement, which brings the ref count to 1.

Log of RefCounted operations

Key:
iBufBuf		incr in the constructor
dBuf=/iBuf= 	decr/incr in operator =
dBuf~ 	        decr in destructor

some lines linking addresses to variables have a dummy NULL ptr.

0x20006EF0,1,0x2001FD58::iBufBuf refCount == 1

sequence	ptr	count	object	fn
439185	0x00000000	0	0x20008A18	lastBuffer SerialStreamer::pullRequest
439186	0x00000000	0	0x200024D4	nextBuffer DataStream::pull
// tmp is assigned
439187	0x20006EF0	5	0x2001FD30	iBufBuf
439188	0x00000000	0	0x2001FD30	tmp DataStream::pull
// nextBuffer enters operator =, then decr
439189	0x20006EF0	7	0x200024D4	dBuf=
// note: no iBuf=
// interrupt?
439190	0x200092E4	3	0x2001FC74	iBufBuf
// another variable using 6EF0 is reassigned
// note the refCount is unchanged from above
439191	0x20006EF0	7	0x200024B8	dBuf=
439192	0x200092E4	5	0x200024B8	iBuf=
439193	0x00000000	0	0x200024D4	nextBuffer DataStream::pullRequest
439194	0x200092E4	7	0x2001FC48	iBufBuf
// nextBuffer is assigned, calling decr on 6EF0 again
439195	0x20006EF0	5	0x200024D4	dBuf=
439196	0x200092E4	9	0x200024D4	iBuf=
// now the 6EF0 refCount is 3
// other irrelevant ops
439197	0x200092E4	11	0x2001FC48	dBuf~
439198	0x200092E4	9	0x2001FC74	dBuf~
439199	0x20008C78	3	0x2001FC74	init
439200	0x200092E4	7	0x200025DC	dBuf=
439201	0x20008C78	3	0x200025DC	iBuf=
439202	0x20008C78	5	0x2001FC74	dBuf~
// return from interrupt?
// complete the original decr() and destroy
439203	0x20006EF0	1	0x200024D4	destroy

[martinwork]

@JohnVidler I didn't have much luck catching it in the debugger, but I added some DMESG to the relevant functions and captured repeated traces like below.

SerialStreamer::pullRequest seems indirectly to pull the nextBuffer from the same DataStream (at 0x200024C8) that demux writes to,

NRF52ADCChannel::demux calls the ADC channel's non-blocking output DataStream::pullRequest to update its nextBuffer.

NRF52ADCChannel::demux 0x200024B0 output 0x200024C8
DataStream::pullRequest 0x200024C8 DataSink 0x20006118 DataSource 0x200024B0 blocking 0
DataStream::pullRequest 0x200024C8 setting nextBuffer
NRF52ADCChannel::demux EXIT

Next StreamSplitter::pullRequest routes down through SplitterChannel and StreamNormalizer to SerialStreamer::pullRequest.

StreamSplitter::pullRequest
SplitterChannel::pullRequest 0x2000616C output 0x2000618C
StreamNormalizer::pullRequest output 0x200061B0
DataStream::pullRequest 0x200061B0 DataSink 0x20006FC8 DataSource 0x20006190 blocking 1
SerialStreamer::pullRequest

SerialStreamer::pullRequest calls pull on StreamNormalizer::output (a blocking DataStream) which routes via StreamNormalizer, SplitterChannel, and StreamSplitter::getBuffer to the ADC channel's output DataStream:pull, which returns the nextBuffer.

DataStream::pull 0x200061B0 DataSink 0x20006FC8 DataSource 0x20006190 blocking 1
DataStream::pull 0x200061B0 calling upStream->pull()
StreamNormalizer::pull upstream 0x2000616C
SplitterChannel::pull 0x2000616C
StreamSplitter::getBuffer upstream 0x200024C8
DataStream::pull 0x200024C8 DataSink 0x20006118 DataSource 0x200024B0 blocking 0
DataStream::pull 0x200024C8 returning nextBuffer
SplitterChannel::pullRequest 0x200061D8 output 0x00000000
StreamSplitter::pullRequest EXIT