Skip to content

hotplug branch -- higher CPU load for libusb backend compared to the hidraw backend #789

Closed

Description

@mcuee

Just wondering if the following observation is expected or not, even after the merge of PR #783.

CPU load of the libusb backend tends to be higher than hidraw backend.

Activity

  1. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    Test code generated by free Google Gemini.

    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:00  cat test_pr783.c 
    #include <stdio.h>
    #include <stdlib.h>
    #include <pthread.h>
    #include <sys/time.h>
    #include <unistd.h>
    #include <errno.h>
    
    pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;
    pthread_cond_t cond = PTHREAD_COND_INITIALIZER;
    int keep_running = 1;
    
    void* hotplug_thread_func(void* arg) {
        struct timespec ts;
        
        // We lock once outside to simulate the contention/wait state
        pthread_mutex_lock(&mutex);
    
        while (keep_running) {
            // Simulating the bug: Relative timespec (100ms)
            ts.tv_sec = 0;
            ts.tv_nsec = 100000000; 
    
            // If this returns EINVAL or ETIMEDOUT immediately, 
            // the while loop will spin as fast as possible.
            pthread_cond_timedwait(&cond, &mutex, &ts);
        }
        
        pthread_mutex_unlock(&mutex);
        return NULL;
    }
    
    int main() {
        pthread_t thread_id;
    
        if (pthread_create(&thread_id, NULL, hotplug_thread_func, NULL) != 0) {
            return 1;
        }
    
        // Keep the main thread alive for 10 seconds to allow the script to sample
        printf("Spinning for 10 seconds... check CPU usage now.\n");
        sleep(10); 
    
        keep_running = 0;
        pthread_join(thread_id, NULL);
    
        return 0;
    }
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:00  cat test.sh 
    #!/bin/bash
    
    # Configuration
    #TEST_SRC="test_pr783.c"
    TEST_BIN="./test_pr783"
    DURATION=5
    
    echo "--- libusb/hidapi CPU Usage Verification ---"
    
    # 1. Compile
    #if ! gcc -Wall "$TEST_SRC" -o "$TEST_BIN" -pthread -lhidapi-hidraw; then
    #    echo "Error: Compilation failed."
    #    exit 1
    #fi
    
    # 2. Run in background
    $TEST_BIN &
    TEST_PID=$!
    
    # Give the process a moment to initialize and start spinning
    sleep 0.5
    
    echo "Started test program with PID: $TEST_PID"
    echo "Monitoring CPU usage..."
    
    SUM_CPU=0
    COUNT=0
    
    for ((i=1; i<=DURATION; i++)); do
        sleep 1
        # Improved CPU extraction: 'pcpu=' hides the header row entirely
        CPU=$(ps -p $TEST_PID -o pcpu= | xargs)
        # Alternative sampling line for Ubuntu 26.04
        #CPU=$(top -b -n 1 -p $TEST_PID | grep $TEST_PID | awk '{print $9}')
        # Check if we actually got a number
        if [[ -n "$CPU" ]]; then
            echo "Sample $i: $CPU%"
            SUM_CPU=$(echo "$SUM_CPU + $CPU" | bc)
            COUNT=$((COUNT + 1))
        else
            echo "Sample $i: Process not found or CPU data unavailable."
        fi
    done
    
    # 3. Cleanup
    kill $TEST_PID 2>/dev/null
    
    # 4. Results calculation
    if [ $COUNT -gt 0 ]; then
        AVERAGE_CPU=$(echo "scale=2; $SUM_CPU / $COUNT" | bc)
        echo "---------------------------------------"
        echo "Average CPU Load: $AVERAGE_CPU%"
    
        if (( $(echo "$AVERAGE_CPU > 10.0" | bc -l) )); then
            echo "RESULT: FAIL (High CPU detected - Bug is present)"
        else
            echo "RESULT: PASS (Low CPU detected - Fix is effective)"
        fi
    else
        echo "Error: No samples collected. Check if the test program crashed."
    fi
    
  2. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    I just use the Makefile from hidapitester for hidraw backend, and then make minor modification to use libusb backend.

    With libusb backend

    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:05  make -f Makefile.libusb 
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c test_pr783.c -o test_pr783.o
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" ../../hidapi_hotplug/libusb/hid.o test_pr783.o -o test_pr783 -ludev -lusb-1.0
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:06  ldd ./test_pr783
    	linux-vdso.so.1 (0x00007c2552009000)
    	libusb-1.0.so.0 => /usr/local/lib/libusb-1.0.so.0 (0x00007c2551fb7000)
    	libc.so.6 => /usr/lib/x86_64-linux-gnu/libc.so.6 (0x00007c2551c00000)
    	libudev.so.1 => /usr/lib/x86_64-linux-gnu/libudev.so.1 (0x00007c2551f70000)
    	/lib64/ld-linux-x86-64.so.2 (0x00007c255200b000)
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:06  ./test.sh 
    --- libusb/hidapi CPU Usage Verification ---
    Spinning for 10 seconds... check CPU usage now.
    Started test program with PID: 39612
    Monitoring CPU usage...
    Sample 1: 91.3%
    Sample 2: 88.0%
    Sample 3: 87.0%
    Sample 4: 87.9%
    Sample 5: 88.7%
    ---------------------------------------
    Average CPU Load: 88.58%
    RESULT: FAIL (High CPU detected - Bug is present)
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:06  make -f Makefile.libusb clean
    rm -f ../../hidapi_hotplug/libusb/hid.o test_pr783.o
    rm -f test_pr783
    

    With hidraw backend.

    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:06  make 
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c test_pr783.c -o test_pr783.o
    cc   test_pr783.o   -o test_pr783
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:07  ldd ./test_pr783
    	linux-vdso.so.1 (0x0000714928cfe000)
    	libc.so.6 => /usr/lib/x86_64-linux-gnu/libc.so.6 (0x0000714928a00000)
    	/lib64/ld-linux-x86-64.so.2 (0x0000714928d00000)
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:06  ./test.sh 
    --- libusb/hidapi CPU Usage Verification ---
    Spinning for 10 seconds... check CPU usage now.
    Started test program with PID: 39799
    Monitoring CPU usage...
    Sample 1: 82.1%
    Sample 2: 81.3%
    Sample 3: 80.8%
    Sample 4: 80.7%
    Sample 5: 81.2%
    ---------------------------------------
    Average CPU Load: 81.22%
    RESULT: FAIL (High CPU detected - Bug is present)
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:15  make clean
    rm -f ../../hidapi_hotplug/linux/hid.o test_pr783.o
    rm -f test_pr783
    
  3. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    I believe the high CPU usage is caused by the test codes. But then there are obvious differences between the two backends. Just wondering if it is expected or not.

  4. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    I believe the high CPU usage is caused by the test codes.

    Google Gemini did not quite agree though.

    Anyway, the following test code from Google Gemini shows nearly 0 % CPU usage.

    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:17  make
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c test_pr783.c -o test_pr783.o
    cc   test_pr783.o   -o test_pr783
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:17  ./test.sh 
    --- libusb/hidapi CPU Usage Verification ---
    Fixed version: Thread should be sleeping. Sampling for 10s...
    Started test program with PID: 40649
    Monitoring CPU usage...
    Sample 1: 0.0%
    Sample 2: 0.0%
    Sample 3: 0.0%
    Sample 4: 0.0%
    Sample 5: 0.0%
    ---------------------------------------
    Average CPU Load: 0%
    RESULT: PASS (Low CPU detected - Fix is effective)
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:17  make clean
    rm -f ../../hidapi_hotplug/linux/hid.o test_pr783.o
    rm -f test_pr783
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:18  make -f Makefile.libusb
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c ../../hidapi_hotplug/libusb/hid.c -o ../../hidapi_hotplug/libusb/hid.o
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c test_pr783.c -o test_pr783.o
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" ../../hidapi_hotplug/libusb/hid.o test_pr783.o -o test_pr783 -ludev -lusb-1.0
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:18  ./test.sh 
    --- libusb/hidapi CPU Usage Verification ---
    Fixed version: Thread should be sleeping. Sampling for 10s...
    Started test program with PID: 40843
    Monitoring CPU usage...
    Sample 1: 0.0%
    Sample 2: 0.0%
    Sample 3: 0.0%
    Sample 4: 0.0%
    Sample 5: 0.0%
    ---------------------------------------
    Average CPU Load: 0%
    RESULT: PASS (Low CPU detected - Fix is effective)
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:18  cat test_pr783.c
    #include <stdio.h>
    #include <stdlib.h>
    #include <pthread.h>
    #include <sys/time.h>
    #include <unistd.h>
    #include <errno.h>
    
    pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;
    pthread_cond_t cond = PTHREAD_COND_INITIALIZER;
    int keep_running = 1;
    
    void* hotplug_thread_func(void* arg) {
        struct timespec ts;
        struct timeval tv;
    
        pthread_mutex_lock(&mutex);
    
        while (keep_running) {
            // --- PR #783 LOGIC START ---
            gettimeofday(&tv, NULL);
    
            ts.tv_sec = tv.tv_sec;
            ts.tv_nsec = (tv.tv_usec + 100000) * 1000; // 100ms absolute offset
    
            // Standard POSIX carry-over logic
            if (ts.tv_nsec >= 1000000000) {
                ts.tv_sec++;
                ts.tv_nsec -= 1000000000;
            }
            // --- PR #783 LOGIC END ---
    
            // This will now properly block the thread for 100ms
            pthread_cond_timedwait(&cond, &mutex, &ts);
        }
    
        pthread_mutex_unlock(&mutex);
        return NULL;
    }
    
    int main() {
        pthread_t thread_id;
    
        if (pthread_create(&thread_id, NULL, hotplug_thread_func, NULL) != 0) {
            return 1;
        }
    
        // Keep alive for the script to sample
        printf("Fixed version: Thread should be sleeping. Sampling for 10s...\n");
        sleep(10);
    
        keep_running = 0;
        pthread_join(thread_id, NULL);
    
        return 0;
    }
    
  5. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    The above test codes do not really use hidapi though. Gemini is trying to simulate the logic.

    Anyway, the following code use hidapi hotplug branch and no issues.

    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:59  cat test_pr783.c
    #include <stdio.h>
    #include <stdlib.h>
    #include <unistd.h>
    #include "hidapi.h"
    
    // Callback for hotplug events
    int HID_API_EXPORT HID_API_CALL hotplug_callback(hid_hotplug_callback_handle handle,
                                                    struct hid_device_info *device,
                                                    hid_hotplug_event event,
                                                    void *user_data) {
        return 0;
    }
    
    int main() {
        if (hid_init() < 0) {
            fprintf(stderr, "Failed to initialize HIDAPI\n");
            return 1;
        }
    
        hid_hotplug_callback_handle handle;
        
        // Note the added HID_API_ prefixes and the '0' for the flags argument
        int res = hid_hotplug_register_callback(
            0x0, 0x0, 
            HID_API_HOTPLUG_EVENT_DEVICE_ARRIVED | HID_API_HOTPLUG_EVENT_DEVICE_LEFT,
            0,                 // flags argument (newly required)
            hotplug_callback, 
            NULL, 
            &handle
        );
    
        if (res < 0) {
            fprintf(stderr, "Hotplug registration failed\n");
            return 1;
        }
    
        printf("HIDAPI Initialized. Hotplug thread is active.\n");
        printf("Monitoring for 10 seconds...\n");
    
        sleep(10);
    
        hid_exit();
        return 0;
    }
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:59  make -f Makefile.libusb clean
    rm -f ../../hidapi_hotplug/libusb/hid.o test_pr783.o
    rm -f test_pr783
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:59  make -f Makefile.libusb
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c ../../hidapi_hotplug/libusb/hid.c -o ../../hidapi_hotplug/libusb/hid.o
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" -c test_pr783.c -o test_pr783.o
    cc  -I ../../hidapi_hotplug/hidapi -DHIDAPITESTER_VERSION=\""""v20260424"""\" ../../hidapi_hotplug/libusb/hid.o test_pr783.o -o test_pr783 -ludev -lusb-1.0
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:59  cat test.sh
    #!/bin/bash
    # test.sh
    ./test_pr783 &
    TEST_PID=$!
    
    sleep 1 # Give the process a second to initialize
    
    echo "Monitoring CPU for PID: $TEST_PID"
    for i in {1..5}; do
        # -b for batch, -n1 for one iteration, -p for specific PID
        top -b -n 1 -p $TEST_PID | grep $TEST_PID | awk '{print "Sample '$i': " $9 "%"}'
        sleep 1
    done
    
    kill $TEST_PID 2>/dev/null
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  21:59  ./test.sh 
    HIDAPI Initialized. Hotplug thread is active.
    Monitoring for 10 seconds...
    Monitoring CPU for PID: 48597
    Sample 1: 0.0%
    Sample 2: 0.0%
    Sample 3: 0.0%
    Sample 4: 0.0%
    Sample 5: 0.0%
    
    
  6. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    More practical test code.

    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  22:28  cat test_pr783.c
    #include <stdio.h>
    #include <stdlib.h>
    #include <unistd.h>
    #include "hidapi.h"
    
    int main() {
        if (hid_init() < 0) {
            fprintf(stderr, "Failed to initialize HIDAPI\n");
            return 1;
        }
    
        printf("Opening device 0925:1234...\n");
        hid_device *dev = hid_open(0x0925, 0x1234, NULL);
    
        if (!dev) {
            fprintf(stderr, "Could not open device. Check permissions (udev rules).\n");
            hid_exit();
            return 1;
        }
    
        printf("Device opened. Starting timed reads to trigger dprintf...\n");
        printf("Monitoring for 10 seconds. Check terminal for [DEBUG] lines.\n");
    
        unsigned char buf[64];
        int res;
        for (int i = 0; i < 10; i++) {
            // This will call hidapi_thread_cond_timedwait inside the library
            // It waits for 1000ms (1 second) for an input report
            res = hid_read_timeout(dev, buf, sizeof(buf), 1000);
    
            if (res < 0) {
                fprintf(stderr, "Read error occurred.\n");
                break;
            }
            printf("Pulse %d...\n", i + 1);
        }
    
        hid_close(dev);
        hid_exit();
        printf("Test complete.\n");
        return 0;
    }             
    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  22:38  cat test.sh 
    #!/bin/bash
    # test.sh
    ./test_pr783 &
    TEST_PID=$!
    
    sleep 1 # Give the process a second to initialize
    
    echo "Monitoring CPU for PID: $TEST_PID"
    for i in {1..5}; do
        # -b for batch, -n1 for one iteration, -p for specific PID
        top -b -n 1 -p $TEST_PID | grep $TEST_PID | awk '{print "Sample '$i': " $9 "%"}'
        sleep 1
    done
    
    kill $TEST_PID 2>/dev/null
    

    Adding debug info to the libusb backend of the hotplug branch.

    mcuee  …/hidapi_hotplug   connection-callback !    v15.2.0  22:40  git diff
    diff --git a/libusb/hid.c b/libusb/hid.c
    index 7e186ad..024a07a 100644
    --- a/libusb/hid.c
    +++ b/libusb/hid.c
    @@ -40,7 +40,7 @@
     #include <wchar.h>
     
     /* GNU / LibUSB */
    -#include <libusb.h>
    +#include <libusb-1.0/libusb.h>
     #if !defined(__ANDROID__) && !defined(NO_ICONV)
     #include <iconv.h>
     #ifndef ICONV_CONST
    diff --git a/libusb/hidapi_thread_pthread.h b/libusb/hidapi_thread_pthread.h
    index 0abe733..2114dfa 100644
    --- a/libusb/hidapi_thread_pthread.h
    +++ b/libusb/hidapi_thread_pthread.h
    @@ -130,6 +130,11 @@ static void hidapi_thread_cond_wait(hidapi_thread_state *state)
     
     static int hidapi_thread_cond_timedwait(hidapi_thread_state *state, hidapi_timespec *ts)
     {
    +        /* --- DEBUG LINE --- */
    +        // This will print the target seconds and nanoseconds of every wait
    +        //fprintf(stderr, "[DEBUG] Timedwait target: %ld.%09ld\n", ts->tv_sec, ts->tv_nsec);
    +        // Use dprintf to write directly to the file descriptor (bypass stdout/stderr buffering)
    +        dprintf(2, "[DEBUG] Timedwait target: %ld.%09ld\n", (long)ts->tv_sec, (long)ts->tv_nsec);
            return pthread_cond_timedwait(&state->condition, &state->mutex, ts);
     }
    

    Runlog -- no issues.

    
    mcuee  …/libusb/hidapi_test/test_pr783    v15.2.0  22:41  ./test.sh 
    Opening device 0925:1234...
    Device opened. Starting timed reads to trigger dprintf...
    Monitoring for 10 seconds. Check terminal for [DEBUG] lines.
    [DEBUG] Timedwait target: 1777041711.420913295
    Monitoring CPU for PID: 58335
    Pulse 1...
    [DEBUG] Timedwait target: 1777041712.421010349
    Sample 1: 0.0%
    Pulse 2...
    [DEBUG] Timedwait target: 1777041713.421280127
    Sample 2: 0.0%
    Pulse 3...
    [DEBUG] Timedwait target: 1777041714.421398075
    Sample 3: 0.0%
    Pulse 4...
    [DEBUG] Timedwait target: 1777041715.421943866
    Sample 4: 0.0%
    Pulse 5...
    [DEBUG] Timedwait target: 1777041716.422078161
    Pulse 6...
    [DEBUG] Timedwait target: 1777041717.422172162
    Sample 5: 0.0%
    Pulse 7...
    [DEBUG] Timedwait target: 1777041718.422306555
    
  7. Youw commented on Apr 24, 2026

    @Youw
    Member

    Quick follow-up: ran the 4th reproducer under WSL Ubuntu with #783 merged (1889e9f). Both backends idle at ~0.4–0.5 % CPU (tick-level samples from /proc/<pid>/stat over 10-second windows).

    The 88 / 81 % numbers from the first reproducer were a broken test harness — Gemini's code passed a {0, 1e8} relative timespec to pthread_cond_timedwait, but that call takes an absolute timespec (since epoch), so the wait returned ETIMEDOUT immediately and the thread spun. Literally the bug #783 fixed, reintroduced in the test. And neither of the first two reproducers actually linked into hidapi's hotplug code path; they were just spinning in their own test thread. Only the 4th reproducer exercises the real code, and that one is already ~0 %.

    There is a small architectural reason libusb runs a hair hotter than hidraw, though:

    • Both backends poll every 5 ms while idle — ~200 wake-ups/sec (libusb/hid.c:1275, linux/hid.c:1229).
    • Per strace -c, libusb's libusb_handle_events_timeout_completed averages ~100 µs per poll syscall; hidraw's raw select() on the udev netlink fd averages ~42 µs per pselect6. libusb has to lock its internal event-handling mutex and walk its pollfd / timer / transfer lists on every wake.
    • libusb also spawns its own netlink-listener thread once a hotplug callback is registered, so the libusb backend runs one more thread than hidraw. Thread snapshot while idle:
      libusb: main(sleep) + libusb_event(poll) + hotplug_thread(poll) + callback_thread(futex_wait)
      hidraw: main(sleep) + hotplug_thread(do_select)
      

    All tiny in absolute terms. If we want to push this closer to zero, the real improvement on both backends is replacing the 5 ms timeout with an eventfd that teardown writes to, then blocking indefinitely in select / poll / libusb's event handler. That cuts idle syscalls from ~200/sec to 0 and drops teardown latency from up-to-5 ms to sub-ms. Worth a separate follow-up issue IMO.

    TL;DR: the fix works; the residual libusb vs. hidraw delta is libusb-side event-loop bookkeeping + its internal netlink thread, not a bug.


    Measurement / analysis done with Claude (claude-opus-4.7) under WSL Ubuntu.

  8. mcuee commented on Apr 24, 2026

    @mcuee
    MemberAuthor

    Haha, free Google Gemini agrees.

    Final Audit Conclusion
    PR #783 is verified. The "Read error" and high CPU was caused by invalid/relative timespec math which is now corrected.

    Performance is optimal for the current architecture. The remaining CPU usage is a known property of the libusb event loop.

    Harness corrected. You've successfully distinguished between a library bug and a test-logic bug.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    hotplugRelated to hotpluglibusbRelated to libusb backend

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions