printf not waiting before leaving function

[lefebvresam]

I have a function that is called in a loop:

    for (uint16_t i = 0; i < _findex.details.imgindexsize; i++) {
        uint16_t id;
        bd_addr_t addr =  _findex.details.imgindexaddr + i*(sizeof(id) + sizeof(imginfo_s));        
        uint16_t res = _lcd.DMARead(&id, addr, sizeof(id));
        addr += sizeof(id);
        res += _lcd.DMARead(&_imgindex[id], addr, sizeof(imginfo_s));
        if (res) { ERROR("dma read error %u", res); return 1; }
        printiindex(_imgindex[id], id);
    }

void DMAFlash::printiindex(const imginfo_s&  iindex, uint16_t  id) {
    FINE("image index %u {", id);
    FINE(" addr: %llu", iindex.addr);
    FINE(" height: %u", iindex.height);
    FINE(" width: %u", iindex.width);
    // printf("[FINE    %-11s %4d] }\n", MODULE, __LINE__);
    // printf("[FINE    %-11s  241] }\n", MODULE);
    printf("[FINE    DMA_FLASH    241] }\n");
    // FINE("}");
}

I tried several posibilities but the last lines at the end of the loop are not printed.

...
[FINE    DMA_FLASH    239]  height: 272
[FINE    DMA_FLASH    240]  width: 480
[FINE    DMA_FLASH    241] }
[FINE    DMA_FLASH    237] image index 36 {
[FINE    DMA_FLASH    238]  addr: 532480
[FINE    DMA_FLASH    239]  height: 252
[FINE    DMA_FLASH    240]  width: 4
[FINE    DMA_FLASH    241] }
[FINE    DMA_FLASH    237] image index 37 {
[FINE    DMA_FLASH    238]  addr: 536576
[FINE    DMA_FLASH    239]  height: 70
[
 [FINE    DMA_FLASH    220] -------------------------

It looks like the memory reservation of the string is away when the loop terminates and the printf is still sending data. When I put a delay function in the loop it is solved but this is not the best way to solve this I think. If I printed twice in the loop the issue stays at the end. So it's not a buffering issue. If I replace the data with fixed value the issue stays.

[lefebvresam]

If I put this in the for loop it is solved. It looks like a buffering issue. No idea how to increase the stdio buffer.

        if (i==_findex.details.imgindexsize/2) { // buffer overflow when sending too fast
            ThisThread::sleep_for(100);
        }

[JohnK1987]

I think, this is caused because default console use BufferedSerial. Try to set the default console to UnbufferedSerial.
Set this parametr to 0 in your project - https://github.com/mbed-ce/mbed-ce-hello-world/blob/0e92b9b4fa503657820e30b167a378ebb69d20f6/mbed_app.json#L5

[lefebvresam]

I could also use something like this:

if (!i%20 && LOGLEVEL == L_FINE) ThisThread::sleep_for(100); // buffer overflow when sending too fast

but if I move from this:

            "platform.stdio-baud-rate": 460800,

to this:

            "platform.stdio-baud-rate": 67800,

it is also solved.

The idea was that if you use a very high serial speed the buffer is flushed faster if you use higher clockrates, but this is clearly not the case. It is just the opposite.

I'm not so familiar with what is happening with the serial port behind the scene.

I tested the speed limits and in both modes (buffered/non buffered) 67800 is a safe margin. Lower is also working and higher gives sometimes or always a risk of data loss. There is not much difference between buffered and non buffered.

[lefebvresam]

This looks weird because if you do bulk transfer you should be able to use higher speeds. Maybe there is something in the uart clock config?

[JojoS62]

have you tried a fflush(stdio) after the print?

[lefebvresam]

I don't think in this case but I remember another case if you are printing and doing a sleep immediately after the printf it will only work if you do a flush first. It means that sleeping blocks the serial transfer while it's still in the buffer. Here there is no sleep, it's a timing/speed issue. I experienced that the faster you send data, the more chance you have that the serial communication is blocking at a certain point with bulk transfer. Maybe the buffer is filled in chunks and the CPU can not follow or something like this.

I think the printf is also thread safe but with other interfaces (like the self made SPI) you didn't made thread safe you have to derefer all SPI transactions to the main thread with a queue injected from the main in the class, otherwise it will also be meshed up.

[JohnK1987]

@lefebvresam did you found the root cause?

[lefebvresam]

No, but I use the restrictions mentioned above and have no issues anymore, despite the fact that I could potentially use higher serial speeds. To investigate this further I should create a striped down test project for it and dive into the depth of the mbed serial stuff. I'm currently limited in time to do this.

[JohnK1987]

I made new issue for better tracking. Closed