python / cpython

The Python programming language
https://www.python.org
Other
62.35k stars 29.94k forks source link

OSError: Invalid argument in test_get_clock_info when testing thread_time clock on NetBSD #123974

Open furkanonder opened 6 days ago

furkanonder commented 6 days ago

Bug report

Bug description:

$ ./python -m test test_time -m test_get_clock_info
Using random seed: 4204534041
0:00:00 load avg: 2.21 Run 1 test sequentially in a single process
0:00:00 load avg: 2.21 [1/1] test_time
test test_time failed -- Traceback (most recent call last):
  File "/home/blue/cpython/Lib/test/test_time.py", line 588, in test_get_clock_info
    info = time.get_clock_info(name)
OSError: [Errno 22] Invalid argument

test_time failed (1 error)

== Tests result: FAILURE ==

1 test failed:
    test_time

Total duration: 260 ms
Total tests: run=1 (filtered)
Total test files: run=1/1 (filtered) failed=1
Result: FAILURE

OS: NetBSD 10.0 amd64

CPython versions tested on:

CPython main branch

Operating systems tested on:

Other

Linked PRs

furkanonder commented 6 days ago

According to the NetBSD documentation, CLOCK_THREAD_CPUTIME_ID is supported by clock_getres. However, when using clock_getres with the CLOCK_THREAD_CPUTIME_ID clock ID, the function returns -1 and sets errno to EINVAL.

Example:

#include <stdio.h>
#include <stdlib.h>
#include <time.h>

void print_clock_resolution(clockid_t clock_id, const char *name) {
    struct timespec res;

    if (clock_getres(clock_id, &res) == -1) {
        perror(name);
        return;
    }

    printf("Resolution of %s: %ld.%09ld seconds\n", name, res.tv_sec, res.tv_nsec);
}

int main() {
    print_clock_resolution(CLOCK_REALTIME, "CLOCK_REALTIME");
    print_clock_resolution(CLOCK_MONOTONIC, "CLOCK_MONOTONIC");
    print_clock_resolution(CLOCK_VIRTUAL, "CLOCK_VIRTUAL");
    print_clock_resolution(CLOCK_PROF, "CLOCK_PROF");
    print_clock_resolution(CLOCK_PROCESS_CPUTIME_ID, "CLOCK_PROCESS_CPUTIME_ID");
    print_clock_resolution(CLOCK_THREAD_CPUTIME_ID, "CLOCK_THREAD_CPUTIME_ID");
    return 0;
}

Output:

$ gcc -o test_clock test_clock.c
$ ./test_clock
Resolution of CLOCK_REALTIME: 0.000000010 seconds
Resolution of CLOCK_MONOTONIC: 0.000000010 seconds
CLOCK_VIRTUAL: Invalid argument
CLOCK_PROF: Invalid argument
CLOCK_PROCESS_CPUTIME_ID: Invalid argument
CLOCK_THREAD_CPUTIME_ID: Invalid argument
serhiy-storchaka commented 4 days ago

If I understand correctly, only CLOCK_REALTIME and CLOCK_MONOTONIC are supported: https://github.com/NetBSD/src/blob/6ea4bcb64b7e69b70ae27f37ea3b414cc2e37046/sys/kern/kern_time.c#L325-L343

The result depends on the frequency.

The source of clock_gettime() is more complex, but it looks reasonable that the resolution for CLOCK_THREAD_CPUTIME_ID is the same. What does time.clock_getres(time.CLOCK_MONOTONIC) return on your computer? Should not it be used instead of hardcoded 1e-8?

furkanonder commented 4 days ago

If I understand correctly, only CLOCK_REALTIME and CLOCK_MONOTONIC are supported: https://github.com/NetBSD/src/blob/6ea4bcb64b7e69b70ae27f37ea3b414cc2e37046/sys/kern/kern_time.c#L325-L343

The result depends on the frequency.

The source of clock_gettime() is more complex, but it looks reasonable that the resolution for CLOCK_THREAD_CPUTIME_ID is the same. What does time.clock_getres(time.CLOCK_MONOTONIC) return on your computer? Should not it be used instead of hardcoded 1e-8?

Yes, CLOCK_REALTIME and CLOCK_MONOTONIC are supported.

>>> import time
>>> time.clock_getres(time.CLOCK_MONOTONIC)
1e-09
>>>

I updated the code with resolution 1e-09.

serhiy-storchaka commented 4 days ago

Does the test for CLOCK_PROCESS_CPUTIME_ID fail as well?

@vstinner, should get_clock_info() return some value here or fail? Even if resolution cannot be obtained, the information about implementation can be useful.

vstinner commented 4 days ago

@vstinner, should get_clock_info() return some value here or fail?

I merged the PR with a hardcoded resolution of 1 ns. It's not great, but better than nothing. It allows to get other information about the clock at least.

vstinner commented 4 days ago

@furkanonder: You may report the issue to NetBSD. clock_getres() should return "some value" rather than fail with EINVAL as if the clock doesn't exist.

furkanonder commented 4 days ago

@furkanonder: You may report the issue to NetBSD. clock_getres() should return "some value" rather than fail with EINVAL as if the clock doesn't exist.

Sorry, I forgot to mention. I reported the issue.

furkanonder commented 4 days ago

Does the test for CLOCK_PROCESS_CPUTIME_ID fail as well? Could you please write the name of the test?

This is the only failed test(https://github.com/python/cpython/pull/123979) at the moment.

vstinner commented 4 days ago

I close again the issue, I'm not sure why you reopened it. The remaining test failure is tracked by https://github.com/python/cpython/issues/123978.

furkanonder commented 4 days ago

I close again the issue, I'm not sure why you reopened it. The remaining test failure is tracked by #123978.

I couldn't make comment without reopen. Also I asked question to @serhiy-storchaka . I was waiting her response.

vstinner commented 4 days ago

I couldn't make comment without reopen.

Oh ok. Thanks for your bug report and fix, by the way ;-)

furkanonder commented 4 days ago

I couldn't make comment without reopen.

Oh ok. Thanks for your bug report and fix, by the way ;-)

Your are welcome :)

serhiy-storchaka commented 3 days ago

Are test_process_time and test_get_clock_info passed? What does time.get_clock_info('process_time') return?

test_thread_time is also affected by this issue, but it fails earlier for other reason.

furkanonder commented 3 days ago

Are test_process_time and test_get_clock_info passed? What does time.get_clock_info('process_time') return?

test_thread_time is also affected by this issue, but it fails earlier for other reason.

Python 3.13.0rc2+ (heads/3.13:112b1704fa6, Sep 14 2024, 02:50:28) [GCC 10.5.0] on netbsd10
Type "help", "copyright", "credits" or "license" for more information.
warning: can't use pyrepl: No module named 'msvcrt'
>>> import time
>>> time.get_clock_info('process_time')
namespace(implementation='getrusage(RUSAGE_SELF)', monotonic=True, adjustable=False, resolution=1e-06)
>>> time.get_clock_info('thread_time')
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
    time.get_clock_info('thread_time')
    ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^
OSError: [Errno 22] Invalid argument
>>> time.thread_time()
5.73
>>>
-bash-5.2$ ./python -m test test_time -m test_process_time
Using random seed: 3952309378
0:00:00 load avg: 5.08 Run 1 test sequentially in a single process
0:00:00 load avg: 5.08 [1/1] test_time

== Tests result: SUCCESS ==

1 test OK.

Total duration: 556 ms
Total tests: run=1 (filtered)
Total test files: run=1/1 (filtered)
Result: SUCCESS
-bash-5.2$ ./python -m test test_time -m test_get_clock_info
Using random seed: 544442658
0:00:00 load avg: 5.07 Run 1 test sequentially in a single process
0:00:00 load avg: 5.07 [1/1] test_time
test test_time failed -- Traceback (most recent call last):
  File "/home/blue/cpython/Lib/test/test_time.py", line 588, in test_get_clock_info
    info = time.get_clock_info(name)
OSError: [Errno 22] Invalid argument

test_time failed (1 error)

== Tests result: FAILURE ==

1 test failed:
    test_time

Total duration: 284 ms
Total tests: run=1 (filtered)
Total test files: run=1/1 (filtered) failed=1
Result: FAILURE
-bash-5.2$

After the merge(https://github.com/python/cpython/pull/123975);

-bash-5.2$ ./python
Python 3.14.0a0 (heads/main:b1d6f8a2ee0, Sep 14 2024, 02:36:32) [GCC 10.5.0] on netbsd10
Type "help", "copyright", "credits" or "license" for more information.
warning: can't use pyrepl: No module named 'msvcrt'
>>> import time
>>> time.get_clock_info('process_time')
namespace(implementation='getrusage(RUSAGE_SELF)', monotonic=True, adjustable=False, resolution=1e-06)
>>> time.get_clock_info('thread_time')
namespace(implementation='clock_gettime(CLOCK_THREAD_CPUTIME_ID)', monotonic=True, adjustable=False, resolution=1e-09)
>>> time.thread_time()
5.04
>>>
-bash-5.2$ ./python -m test test_time -m test_process_time
Using random seed: 2503680930
0:00:00 load avg: 7.21 Run 1 test sequentially in a single process
0:00:00 load avg: 7.21 [1/1] test_time

== Tests result: SUCCESS ==

1 test OK.

Total duration: 505 ms
Total tests: run=1 (filtered)
Total test files: run=1/1 (filtered)
Result: SUCCESS
-bash-5.2$ ./python -m test test_time -m test_get_clock_info
Using random seed: 465373399
0:00:00 load avg: 6.94 Run 1 test sequentially in a single process
0:00:00 load avg: 6.94 [1/1] test_time

== Tests result: SUCCESS ==

1 test OK.

Total duration: 227 ms
Total tests: run=1 (filtered)
Total test files: run=1/1 (filtered)
Result: SUCCESS
-bash-5.2$

There was no issue with thread_time. Because the Info argument is sent as NULL.

static PyObject *
time_thread_time(PyObject *self, PyObject *unused)
{
    PyTime_t t;
    if (_PyTime_GetThreadTimeWithInfo(&t, NULL) < 0) {
        return NULL;
    }
    return _PyFloat_FromPyTime(t);
}
static int
_PyTime_GetThreadTimeWithInfo(PyTime_t *tp, _Py_clock_info_t *info)
{
    struct timespec ts;
    const clockid_t clk_id = CLOCK_THREAD_CPUTIME_ID;
    const char *function = "clock_gettime(CLOCK_THREAD_CPUTIME_ID)";

    if (clock_gettime(clk_id, &ts)) {
        PyErr_SetFromErrno(PyExc_OSError);
        return -1;
    }
    if (info) {
        struct timespec res;
        info->implementation = function;
        info->monotonic = 1;
        info->adjustable = 0;
        if (clock_getres(clk_id, &res)) {
            PyErr_SetFromErrno(PyExc_OSError);
            return -1;
        }
        info->resolution = res.tv_sec + res.tv_nsec * 1e-9;
    }

    if (_PyTime_FromTimespec(tp, &ts) < 0) {
        return -1;
    }
    return 0;
}
serhiy-storchaka commented 3 days ago

See the discussion in https://github.com/python/cpython/pull/123979. It seems that thread_time() does not work on NetBSD as intended. It should return a result close to process_time() on single-thread program, but instead it returns a result close to time() and monotonic().

After this, I am not sure that we should support thread_time() on NetBSD.

vstinner commented 1 day ago

I would be fine with removing time.thread_time() on NetBSD.

furkanonder commented 1 day ago

I would be fine with removing time.thread_time() on NetBSD.

Should it be removed immediately, or should a DeprecationWarning be introduced in version 3.14, with complete removal scheduled for version 3.15?

vstinner commented 1 day ago

It can be removed immediatly if it's broken