[Bug 221103] xhci_hcd: System lockup under CPU load during usbfs polling of USB devices on AMD platforms

[bugzilla-daemon@kernel.org]

https://bugzilla.kernel.org/show_bug.cgi?id=221103

--- Comment #3 from Paul Alesius (paul@unnservice.com) ---
Sorry, you may be right that the bug is elsewhere. I just triggered it again
without O_RDWR using a program that also logs the exact point of the freeze.

1. It's always on opening the same USB root hub on my machine.
2. The freeze always occurs on the "    Opening device..."
3. The ioctl seems to complete on the device where the freeze occurs.

PS/2 - We don't have PS/2 ports on these MBs
SysRq - I don't have that on my Logitech Mechanical keyboard

I just tried with "dmesg -W" (follow mode so it prints messages directly) and
it didn't print anything before the system freeze, and there's nothing in the
logs, reflecting the experience of the others in the ADB bug report.


Here's the last logged line from the program before the freeze:


Iteration 189 complete — attempted 9 devices
------------------------------------------------
=== Starting iteration 190 ===
Processing bus 011
  Device: /dev/bus/usb/011/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 010
  Device: /dev/bus/usb/010/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 009
  Device: /dev/bus/usb/009/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 008
  Device: /dev/bus/usb/008/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 007
  Device: /dev/bus/usb/007/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 006
  Device: /dev/bus/usb/006/001
    Opening device...
    Open failed: Invalid argument
Processing bus 005
  Device: /dev/bus/usb/005/001
    Opening device...
    Open failed: Invalid argument
Processing bus 004
  Device: /dev/bus/usb/004/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 003
  Device: /dev/bus/usb/003/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 002
  Device: /dev/bus/usb/002/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 001
  Device: /dev/bus/usb/001/004
    Opening device...
    Skipping non-root hub device
  Device: /dev/bus/usb/001/003
    Opening device...
    Skipping non-root hub device
  Device: /dev/bus/usb/001/002
    Opening device...
    Skipping non-root hub device
  Device: /dev/bus/usb/001/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd

Iteration 190 complete — attempted 9 devices
------------------------------------------------
=== Starting iteration 191 ===
Processing bus 011
  Device: /dev/bus/usb/011/001
    Opening device...
    Opened fd=6
    Issuing USBDEVFS_CONTROL ioctl (GET_DESCRIPTOR)...
    ioctl completed
    Closed fd
Processing bus 010
  Device: /dev/bus/usb/010/001
    Opening device...


The C program used that only tries root hubs, while the system is under load
with "stress-ng --cpu 0":

#include <stdio.h>
#include <stdlib.h>
#include <dirent.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/ioctl.h>
#include <linux/usbdevice_fs.h>
#include <string.h>
#include <limits.h>
#include <errno.h>
#include <stdarg.h>

static FILE *logfile = NULL;

void log_and_sync(const char *format, ...)
{
    va_list args;
    va_start(args, format);
    vprintf(format, args);
    va_end(args);
    fflush(stdout);

    if (logfile) {
        va_list args_copy;
        va_start(args, format);
        va_copy(args_copy, args);
        vfprintf(logfile, format, args_copy);
        va_end(args_copy);
        va_end(args);
        fflush(logfile);
        fsync(fileno(logfile));
    }
}

void enumerate_usb() {
    static int iteration = 0;
    int device_count = 0;

    log_and_sync("=== Starting iteration %d ===\n", iteration + 1);

    DIR *usb_dir = opendir("/dev/bus/usb");
    if (!usb_dir) {
        log_and_sync("Error: opendir /dev/bus/usb failed: %s\n",
strerror(errno));
        return;
    }

    struct dirent *bus_entry;
    while ((bus_entry = readdir(usb_dir)) != NULL) {
        if (bus_entry->d_type != DT_DIR || bus_entry->d_name[0] == '.')
continue;

        char bus_path[PATH_MAX];
        snprintf(bus_path, sizeof(bus_path), "/dev/bus/usb/%s",
bus_entry->d_name);

        log_and_sync("Processing bus %s\n", bus_entry->d_name);

        DIR *bus_dir = opendir(bus_path);
        if (!bus_dir) {
            log_and_sync("  Warning: opendir %s failed: %s\n", bus_path,
strerror(errno));
            continue;
        }

        struct dirent *dev_entry;
        while ((dev_entry = readdir(bus_dir)) != NULL) {
            if (dev_entry->d_name[0] == '.') continue;

            char dev_path[PATH_MAX];
            snprintf(dev_path, sizeof(dev_path), "%s/%s", bus_path,
dev_entry->d_name);

            log_and_sync("  Device: %s\n", dev_path);
            log_and_sync("    Opening device...\n");

                        // Skip root hubs (usually /001)
                        if (strcmp(dev_entry->d_name, "001") != 0) {
                        log_and_sync("    Skipping non-root hub device\n");
                        continue;
                        }

            int fd = open(dev_path, O_RDONLY);
            if (fd < 0) {
                log_and_sync("    Open failed: %s\n", strerror(errno));
                continue;
            }

            log_and_sync("    Opened fd=%d\n", fd);

            unsigned char desc[18];
            struct usbdevfs_ctrltransfer ctrl = {
                .bRequestType = 0x80,
                .bRequest     = 6,      // GET_DESCRIPTOR
                .wValue       = 1 << 8, // Device descriptor
                .wIndex       = 0,
                .wLength      = sizeof(desc),
                .data         = desc,
                .timeout      = 1000
            };

            log_and_sync("    Issuing USBDEVFS_CONTROL ioctl
(GET_DESCRIPTOR)...\n");

            ioctl(fd, USBDEVFS_CONTROL, &ctrl);  // Errors ignored, as in
original

            log_and_sync("    ioctl completed\n");

            close(fd);
            log_and_sync("    Closed fd\n");

            device_count++;
        }
        closedir(bus_dir);
    }
    closedir(usb_dir);

    iteration++;
    log_and_sync("\nIteration %d complete — attempted %d devices\n", iteration,
device_count);
    log_and_sync("------------------------------------------------\n");
}

int main() {
    logfile = fopen("usb_poll6_roothubs.log", "w");
    if (!logfile) {
        perror("Failed to open usb_poll.log for writing (will continue without
file logging)");
    }

    log_and_sync("USB usbfs polling test started (1-second interval)\n");
    log_and_sync("You should now see device paths from all buses.\n");
    log_and_sync("On affected systems, freeze typically occurs within
minutes.\n");
    log_and_sync("Detailed logging with fsync() to 'usb_poll.log' for
post-freeze analysis.\n");
    log_and_sync("If freeze occurs during ioctl, you should see 'Issuing ...'
but not 'ioctl completed' for that device.\n\n");

    while (1) {
        enumerate_usb();
        //usleep(1000000);  // 1 second
                usleep(500000); // 0.5s
    }

    if (logfile) fclose(logfile);
    return 0;
}

Is there anything else that you can suggest to get further diagnosis?

Thank you

-- 
You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.