pico-sdk icon indicating copy to clipboard operation
pico-sdk copied to clipboard

`pico_stdio_usb` silently drops data being sent

Open AlexApps99 opened this issue 2 years ago • 14 comments

I'm using fwrite() to stdout to implement a protobuf message protocol for a project over USB CDC. When I send enough data at once, some bytes are silently lost.

Either:

  • there needs to be a way to properly check when data is being dropped rather than sent (the fwrite API already returns the number of bytes written, but it's improperly returned by the SDK)
  • there needs to be a blocking API created, that guarantees all data is sent
  • the current API needs to be made blocking until all data is sent

The obvious solution is to return the correct number of bytes to _write, and by extension fread.

Simply dropping data is not acceptable in nearly all applications, and there is no documentation on this, which led me to spend a frustrating amount of time debugging the issue. Nobody would reasonably expect this behavior for all but the simplest of text logging.

AlexApps99 avatar Aug 30 '22 01:08 AlexApps99

After looking closer at the code, it seems returning the number of bytes written would be impossible with the current API design, as you can have multiple stdio implementations active at once.

I think that making the APIs block isn't a great solution, as it has unacceptable performance costs and isn't feasible for things that might require IRQs etc.

So the only reasonable solution I can see is to add new APIs, or to restrict usage of functions such as fwrite to one stdio implementation so the number can be properly returned

AlexApps99 avatar Aug 30 '22 02:08 AlexApps99

Thought I'd throw in some other places where the API is inadequate:

  • as previously mentioned, there is no blocking API or API that returns with the number of bytes written
  • there is no way to read into a buffer of data with a timeout (only getchar supports it)
  • there is no way to read once, without looping until a timeout (unless you count setting until = beginning of time)

AlexApps99 avatar Aug 30 '22 02:08 AlexApps99

the existing API is blocking (in terms of at least delivering the data to TinyUSB). However stdio_usb has a timeout after which data is discarded (defaults to 1/2 a second).

You could try setting PICO_STDIO_USB_STDOUT_TIMEOUT_US=2000000000 in your CMakeLists.txt to see if that helps (at least to diagnose that is what the problem is)

kilograham avatar Aug 30 '22 13:08 kilograham

In my debugging of stdio_usb, the timeout-handling else condition is never even hit when data is silently dropped and thus that PICO_STDIO_USB_STDOUT_TIMEOUT_US is meaningless for this case. The bug appears to be in tinyusb or its rp2040 usb implementation.

JamesDunne avatar Sep 04 '22 20:09 JamesDunne

While I haven't tested changing the timeout duration, I agree with your findings. Data seemed to be dropped far before the default timeout hit.

AlexApps99 avatar Sep 04 '22 20:09 AlexApps99

you could try the develop branch which has a newer TinyUSB to see if the bug has been fixed.

kilograham avatar Sep 04 '22 21:09 kilograham

Upgraded pico-sdk to develop and still see the same data drop issue.

JamesDunne avatar Sep 04 '22 21:09 JamesDunne

just checking... did you update the submodules too.

kilograham avatar Sep 04 '22 21:09 kilograham

I did, but the hash pointed to in develop seems incorrect in .gitmodules:

$ git submodule
 195dfcc10bb6f379e3dea45147590db2203d3c7b lib/cyw43-driver (195dfcc)
 239918ccc173cb2c2a62f41a40fd893f57faf1d6 lib/lwip (STABLE-2_1_0_RELEASE-548-g239918cc)
 b0b155c9491d9e8cfc3d40366f77accfd3302cec lib/tinyusb (0.13.0-355-gb0b155c94)
 
$ # git log
 b624664f5 2022-08-26 (HEAD -> master, origin/master, origin/HEAD) Merge pull request #1614 from kasjer/kasjer/fix-nrf5x-with-iso [Ha Thach]
5e3cfe7b5 2022-08-26 nrf5x: Fix endpoint internal state when closed [Jerzy Kasenberg]
101cbf6e3 2022-08-25 Merge pull request #1613 from Lan-Hekary/video-descriptors-fix [Ha Thach]
8a537a009 2022-08-23 Remove Hardcoded interface numbers from video descriptors [Ahmed El-Sharnoby]
e3b4d3f40 2022-08-23 Merge pull request #1611 from hathach/fix-release-body [Ha Thach]
660e8f50a 2022-08-23 try to fix release body in tinyusb_src (not tested) [hathach]
9e91b02ec 2022-08-23 (tag: 0.14.0) Merge pull request #1609 from hathach/release-0.14.0-p2 [Ha Thach]
3e815c709 2022-08-23 update repository.yml [hathach]
05e19b784 2022-08-19 Update feature_request.yml [Ha Thach]
f6c1ce5b1 2022-08-19 Merge pull request #1569 from hathach/release-0.14.0 [Ha Thach]
961e83e08 2022-08-19 more docs update [hathach]
792b2fb95 2022-08-17 Merge pull request #1603 from Ryzee119/hub_improv [Ha Thach]
2b2354d30 2022-08-15 Hub: Clear other port feature changes [Ryzee119]
3c7b5dcaf 2022-08-15 Hub: Handle hub device status change interrupt [Ryzee119]
585f37a79 2022-08-15 Merge pull request #1489 from kasjer/kasjer/fix-nrf5x-dma-access [Ha Thach]
aafea8ef5 2022-08-15 Hub: Rename port status callback to be more generic [Ryzee119]
5efef4393 2022-08-15 Hub: Expand hub helpers to handle device events [Ryzee119]
8a28e7cd7 2022-08-10 Merge pull request #1597 from kasjer/kasjer/dfu-coexistence [Ha Thach]
7ade0d0ce 2022-08-10 Merge pull request #1588 from majbthrd/stm32l052 [Ha Thach]
c7469ce98 2022-08-09 dfu: Allow DFU coexistence with other interfaces [Jerzy Kasenberg]
d1c61e33a 2022-08-03 add 'stm32l052dap52' (STM32L052K8 MCU) board target [Peter Lawrence]
251ce9899 2022-08-01 Merge pull request #1586 from hathach/fix-TUD_OPT_HIGH_SPEED [Ha Thach]
a219ba86e 2022-08-01 fix issue with TUD_OPT_HIGH_SPEED [hathach]
d36ea6ddc 2022-07-28 update issue template [hathach]
23ea8d1e2 2022-07-25 update doc [hathach]
fd5bb6e5d 2022-07-19 Merge pull request #1514 from maddyaby/audiod_typo [Ha Thach]
b0b155c94 2022-07-19 increase version for release [hathach]

I'll try again with latest master version of tinyusb

JamesDunne avatar Sep 04 '22 21:09 JamesDunne

Still seeing data loss. I've reduced my minimal example to ridiculously minimal with:

while(true) {
  printf("0123456789abcdef0123456789abcdef0123456789abcdef0123456789abcde\n");
}
target_compile_definitions(${PROJECT_NAME} PUBLIC
        PICO_ENTER_USB_BOOT_ON_EXIT=1
        PICO_STDIO_ENABLE_CRLF_SUPPORT=0
        PICO_STDIO_USB_STDOUT_TIMEOUT_US=2000000000
        )

This test works perfectly and suffers no data loss because the printf emits exactly 64 bytes every time. If I remove a character to write 63 bytes then I get data loss. If I add a character to write 65 bytes then I get data loss as well.

It also appears to be timing-sensitive. If I insert a sleep_ms(50); before the printf with 65 bytes I get no data loss.

JamesDunne avatar Sep 04 '22 21:09 JamesDunne

I seem to remember vague rumblings in the past about lack of support for ZLP transmission in tinyUSB and/or its rp2040 port. Possibly related.

P33M avatar Dec 15 '22 16:12 P33M

Please upload a complete project (with CMakeLists.txt and sample code) implementing a minimal testcase that shows the issue.

P33M avatar Jan 11 '23 11:01 P33M

@AlexApps99 could you post the full code that exhibits your issue?

progvault avatar Feb 11 '24 06:02 progvault

I haven't worked on the project in years sorry, hopefully someone else encountering the issue can share their code instead

AlexApps99 avatar Feb 11 '24 06:02 AlexApps99