getchar() fails after 1.19 hours (Problem with time_reached / at_the_end_of_time) #132

Closed
opened 2021-02-15 08:39:37 -06:00 by jepler · 11 comments
jepler commented 2021-02-15 08:39:37 -06:00 (Migrated from github.com)

I haven't reproduced this for myself, but user on the Adafruit Discord a user reported:

Program runs without generating any junk; but after nearly an hour it suddenly starts seeing an endless string of:
0xff 0xff 0xff 0xff .. from the USB port!

and showed this loop, citing https://github.com/wa1tnr/camelforth-rp2040-aU/blob/main/17-camelforth-a.d/pico-examples/camelforth-a/forth/rp2040_pico_getkey_usb.inc:

uint8_t ch_read;
do {
    ch_read = getchar();
} while (( ch_read == '\0' ) || ( ch_read == 0xff ));
// valid character now in ch_read

I noticed that getchar() uses a wait until at_the_end_of_time. However, at least superficially it looks like "the end of time" is just 1.19 hours after boot!

absolute_time_t is a 64-bit quantity, but at_the_end_of_time is initialized to ULONG_MAX, a 32-bit quantity (0xfffffffu):

src/common/pico_time/time.c:17: const absolute_time_t ABSOLUTE_TIME_INITIALIZED_VAR(at_the_end_of_time, ULONG_MAX);

Instead, it seems it should be initialized to another value, possibly UINT64_MAX from stdint.h.

A second problem is likely to arise when waiting for absolute times after 1.19 hours:

PICO_WEAK_FUNCTION_DEF(time_reached)
bool PICO_WEAK_FUNCTION_IMPL_NAME(time_reached)(absolute_time_t t) {
    uint64_t target = to_us_since_boot(t);
    if (target > 0xffffffffu) return false;
    return time_us_64() >= target;
}

The if line should possibly read if (target == at_the_end_of_time) return false; and similarly for other sites.

I haven't reproduced this for myself, but user on the Adafruit Discord a user reported: > Program runs without generating any junk; but after nearly an hour it suddenly starts seeing an endless string of: 0xff 0xff 0xff 0xff .. from the USB port! and showed this loop, citing https://github.com/wa1tnr/camelforth-rp2040-aU/blob/main/17-camelforth-a.d/pico-examples/camelforth-a/forth/rp2040_pico_getkey_usb.inc: ```c++ uint8_t ch_read; do { ch_read = getchar(); } while (( ch_read == '\0' ) || ( ch_read == 0xff )); // valid character now in ch_read ``` I noticed that `getchar()` uses a wait until `at_the_end_of_time`. However, at least superficially it looks like "the end of time" is just 1.19 hours after boot! `absolute_time_t` is a 64-bit quantity, but `at_the_end_of_time` is initialized to `ULONG_MAX`, a 32-bit quantity (0xfffffffu): > src/common/pico_time/time.c:17: const absolute_time_t ABSOLUTE_TIME_INITIALIZED_VAR(at_the_end_of_time, ULONG_MAX); Instead, it seems it should be initialized to another value, possibly UINT64_MAX from *stdint.h*. A second problem is likely to arise when waiting for absolute times after 1.19 hours: ``` PICO_WEAK_FUNCTION_DEF(time_reached) bool PICO_WEAK_FUNCTION_IMPL_NAME(time_reached)(absolute_time_t t) { uint64_t target = to_us_since_boot(t); if (target > 0xffffffffu) return false; return time_us_64() >= target; } ``` The `if` line should possibly read `if (target == at_the_end_of_time) return false;` and similarly for other sites.
wa1tnr commented 2021-02-15 13:29:43 -06:00 (Migrated from github.com)

Following. Thanks jepler.

Following. Thanks jepler.
kilograham commented 2021-02-15 13:42:59 -06:00 (Migrated from github.com)

Note the only place you'll hit this right now is with explicit use of at_the_end_of_time by code - likely the getchar_with_timeout method you mention; the second file (with the PICO_WEAK_FUNCTION_DEF) is for host compilation.

Note the only place you'll hit this right now is with explicit use of at_the_end_of_time by code - likely the getchar_with_timeout method you mention; the second file (with the PICO_WEAK_FUNCTION_DEF) is for host compilation.
CarryWise commented 2021-02-15 14:13:21 -06:00 (Migrated from github.com)

Note the only place you'll hit this right now is with explicit use of at_the_end_of_time by code - likely the getchar_with_timeout method you mention; the second file (with the PICO_WEAK_FUNCTION_DEF) is for host compilation.

I'm not quite following you - by code are you referring to end-user code? Because the issue's exposed by the implementation of getchar in stdio.c where the end-user isn't attempting to use any timeout.

> Note the only place you'll hit this right now is with explicit use of at_the_end_of_time by code - likely the getchar_with_timeout method you mention; the second file (with the PICO_WEAK_FUNCTION_DEF) is for host compilation. I'm not quite following you - by code are you referring to end-user code? Because the issue's exposed by the implementation of [getchar in stdio.c](https://github.com/raspberrypi/pico-sdk/blob/2d5789eca89658a7f0a01e2d6010c0f254605d72/src/rp2_common/pico_stdio/stdio.c#L258) where the end-user isn't attempting to use any timeout.
kilograham commented 2021-02-15 14:21:19 -06:00 (Migrated from github.com)

yes it is a bug; i was saying it really for practical purposes only affects getchar unless you use at_the_end_of_time yourself

yes it is a bug; i was saying it really for practical purposes only affects getchar unless you use at_the_end_of_time yourself
CarryWise commented 2021-02-15 14:24:27 -06:00 (Migrated from github.com)

multicore.c may also have some weird behavior once the pico's been running for more than a ULONG_MAX. I haven't dug into it far enough to determine if it's expecting to be using an absolute or relative "until".

[multicore.c](https://github.com/raspberrypi/pico-sdk/blob/2d5789eca89658a7f0a01e2d6010c0f254605d72/src/rp2_common/pico_multicore/multicore.c#L239) may also have some weird behavior once the pico's been running for more than a ULONG_MAX. I haven't dug into it far enough to determine if it's expecting to be using an absolute or relative "until".
kilograham commented 2021-02-15 14:26:32 -06:00 (Migrated from github.com)

that was the "for all practical purposes" bit... it will obviously be fixed in passing, but there is no reason to sit in that method for a long time

that was the "for all practical purposes" bit... it will obviously be fixed in passing, but there is no reason to sit in that method for a long time
philipstarkey commented 2021-02-20 19:32:17 -06:00 (Migrated from github.com)

I just want to clarify for others reading that this does break the use of getchar() (which does not take a time as an argument, instead using at_the_end_of_time internally). Using getchar_timeout_us will be OK if you use a finite timeout. However, the SDK documentation suggests using getchar() in 2.7.1 (the documentation/examples for reading characters is in general pretty sparse...see raspberrypi/pico-examples#51). I've also seen similar problems with fgetc and fgets when reading from stdin. Pretty much anything other than the pico specific getchar_timeout_us with a finite timeout will eventually cause the pico to crash.

I realise there is a PR to fix this already (which I will test shortly). I mainly wanted to document this so it's easy for other people to find via search terms because I've been bashing my head against a wall for several weekends wondering why my serial communication locks up after 1.19 hours when almost identical code on other microcontrollers does not. I'm pretty sure this is why. I'll add a comment in a few hours to the PR should I verify it fixes my issue.

I just want to clarify for others reading that this does break the use of `getchar()` (which does not take a time as an argument, instead using `at_the_end_of_time` internally). Using `getchar_timeout_us` will be OK if you use a finite timeout. However, the SDK documentation suggests using `getchar()` in 2.7.1 (the documentation/examples for reading characters is in general pretty sparse...see raspberrypi/pico-examples#51). I've also seen similar problems with `fgetc` and `fgets` when reading from stdin. Pretty much anything other than the pico specific `getchar_timeout_us` with a finite timeout will eventually cause the pico to crash. I realise there is a PR to fix this already (which I will test shortly). I mainly wanted to document this so it's easy for other people to find via search terms because I've been bashing my head against a wall for several weekends wondering why my serial communication locks up after 1.19 hours when almost identical code on other microcontrollers does not. I'm pretty sure this is why. I'll add a comment in a few hours to the PR should I verify it fixes my issue.
wa1tnr commented 2021-02-21 03:27:19 -06:00 (Migrated from github.com)
https://github.com/wa1tnr/camelforth-rp2040-aU/blob/main/17-camelforth-a.d/pico-examples/camelforth-a/forth/rp2040_pico_getkey_usb.inc#L3
jepler commented 2021-02-21 20:28:51 -06:00 (Migrated from github.com)

I've re-titled the issue to mention getchar().

I've re-titled the issue to mention `getchar()`.
kilograham commented 2021-02-25 10:17:27 -06:00 (Migrated from github.com)

merged into develop

merged into develop
philipstarkey commented 2021-02-28 03:02:09 -06:00 (Migrated from github.com)

I seem to be having an issue with the fix in #145 where serial communication using getchar() is blocked in core 0 while core 1 is busy. It's fine when core 1 is blocked on reading from the multicore fifo, but while core 1 is doing something it seems like serial communication in core 0 is buffered until core 1 stops/blocks (at which point getchar() works as normal again). This issue does not appear in SDK v1.0.1, but does appear from the first commit onwards in #145.

I haven't had time to create a minimal working example (probably won't until next weekend) so I was wondering if anyone else had seen something like this while using #145?

I seem to be having an issue with the fix in #145 where serial communication using `getchar()` is blocked in core 0 while core 1 is busy. It's fine when core 1 is blocked on reading from the multicore fifo, but while core 1 is doing something it seems like serial communication in core 0 is buffered until core 1 stops/blocks (at which point `getchar()` works as normal again). This issue does not appear in SDK v1.0.1, but does appear from the first commit onwards in #145. I haven't had time to create a minimal working example (probably won't until next weekend) so I was wondering if anyone else had seen something like this while using #145?
Sign in to join this conversation.
No milestone
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
gh-raspberrypi/pico-sdk#132
No description provided.