diff mbox series

[v2] usb: core: add sysfs entry for usb device state

Message ID 20230601235531.2285354-1-royluo@google.com (mailing list archive)
State Superseded
Headers show
Series [v2] usb: core: add sysfs entry for usb device state | expand

Commit Message

Roy Luo June 1, 2023, 11:55 p.m. UTC 
Expose usb device state to userland as the information is useful in
detecting non-compliant setups and diagnosing enumeration failures.
For example:
- End-to-end signal integrity issues: the device would fail port reset
  repeatedly and thus be stuck in POWERED state.
- Charge-only cables (missing D+/D- lines): the device would never enter
  POWERED state as the HC would not see any pullup.

What's the status quo?
We do have error logs such as "Cannot enable. Maybe the USB cable is bad?"
to flag potential setup issues, but there's no good way to expose them to
userspace.

Why add a sysfs entry in struct usb_port instead of struct usb_device?
The struct usb_device is not device_add() to the system until it's in
ADDRESS state hence we would miss the first two states. The struct
usb_port is a better place to keep the information because its life
cycle is longer than the struct usb_device that is attached to the port.

Reviewed-by: Alan Stern <stern@rowland.harvard.edu>
Signed-off-by: Roy Luo <royluo@google.com>
---
This patch comes directly from RFC v2 after being reviewed by Alan Stern
Link: https://lore.kernel.org/all/20230531010134.1092942-1-royluo@google.com/
More discussion about implementation options is in RFC v1
Link: https://lore.kernel.org/all/20230525173818.219633-1-royluo@google.com/

Changes since v1:
* Address Alan Stern's comment: remove redundant NULL initializers in
  update_port_device_state().
---
 Documentation/ABI/testing/sysfs-bus-usb |  9 +++++++++
 drivers/usb/core/hub.c                  | 19 +++++++++++++++++++
 drivers/usb/core/hub.h                  |  2 ++
 drivers/usb/core/port.c                 | 11 +++++++++++
 4 files changed, 41 insertions(+)


base-commit: 933174ae28ba72ab8de5b35cb7c98fc211235096

Comments

kernel test robot June 5, 2023, 12:26 a.m. UTC | #1 
Hello,

kernel test robot noticed "BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c" on:

commit: 130794a2eeb26bc2fa5774dee181661612d0fabf ("[PATCH v2] usb: core: add sysfs entry for usb device state")
url: https://github.com/intel-lab-lkp/linux/commits/Roy-Luo/usb-core-add-sysfs-entry-for-usb-device-state/20230602-075645
patch link: https://lore.kernel.org/all/20230601235531.2285354-1-royluo@google.com/
patch subject: [PATCH v2] usb: core: add sysfs entry for usb device state

in testcase: boot

compiler: gcc-12
test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G

(please refer to attached dmesg/kmsg for entire log/backtrace)


+-----------------------------------------------------------------------------+------------+------------+
|                                                                             | 933174ae28 | 130794a2ee |
+-----------------------------------------------------------------------------+------------+------------+
| BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c | 0          | 12         |
+-----------------------------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <oliver.sang@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202306042228.e532af6e-oliver.sang@intel.com


[   20.403699][    T7] BUG: sleeping function called from invalid context at kernel/locking/rwsem.c:1519
[   20.404735][    T7] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 7, name: kworker/0:0
[   20.405720][    T7] preempt_count: 1, expected: 0
[   20.406268][    T7] RCU nest depth: 0, expected: 0
[   20.406828][    T7] 6 locks held by kworker/0:0/7:
[ 20.407053][ T7] #0: c13e67a4 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work (workqueue.c:?) 
[ 20.407053][ T7] #1: c129df48 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work (workqueue.c:?) 
[ 20.407053][ T7] #2: ed5968f4 (&dev->mutex){....}-{3:3}, at: hub_event (hub.c:?) 
[ 20.407053][ T7] #3: ed5edac8 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect (hub.c:?) 
[ 20.407053][ T7] #4: ed0c3dfc (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect (hub.c:?) 
[ 20.407053][ T7] #5: d4c9b550 (device_state_lock){....}-{2:2}, at: usb_set_device_state (??:?) 
[   20.407053][    T7] irq event stamp: 234
[ 20.407053][ T7] hardirqs last enabled at (233): _raw_spin_unlock_irq (??:?) 
[ 20.407053][ T7] hardirqs last disabled at (234): _raw_spin_lock_irqsave (??:?) 
[ 20.407053][ T7] softirqs last enabled at (0): copy_process (??:?) 
[ 20.407053][ T7] softirqs last disabled at (0): 0x0 
[   20.407053][    T7] CPU: 0 PID: 7 Comm: kworker/0:0 Tainted: G S                 6.4.0-rc3-00033-g130794a2eeb2 #29
[   20.407053][    T7] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[   20.407053][    T7] Workqueue: usb_hub_wq hub_event
[   20.407053][    T7] Call Trace:
[ 20.407053][ T7] dump_stack_lvl (??:?) 
[ 20.407053][ T7] dump_stack (??:?) 
[ 20.407053][ T7] __might_resched (??:?) 
[ 20.407053][ T7] __might_sleep (??:?) 
[ 20.407053][ T7] ? usb_set_device_state (??:?) 
[ 20.407053][ T7] down_read (??:?) 
[ 20.407053][ T7] ? _raw_spin_unlock_irq (??:?) 
[ 20.407053][ T7] ? pm_runtime_set_autosuspend_delay (??:?) 
[ 20.407053][ T7] kernfs_find_and_get_ns (??:?) 
[ 20.407053][ T7] update_port_device_state (hub.c:?) 
[ 20.407053][ T7] usb_set_device_state (??:?) 
[ 20.407053][ T7] hub_port_connect (hub.c:?) 
[ 20.407053][ T7] ? hub_port_connect_change (hub.c:?) 
[ 20.407053][ T7] ? lock_release (??:?) 
[ 20.407053][ T7] hub_port_connect_change (hub.c:?) 
[ 20.407053][ T7] ? mutex_unlock (??:?) 
[ 20.407053][ T7] ? hub_ext_port_status (hub.c:?) 
[ 20.407053][ T7] port_event (hub.c:?) 
[ 20.407053][ T7] ? lockdep_hardirqs_on_prepare (lockdep.c:?) 
[ 20.407053][ T7] ? pm_runtime_barrier (??:?) 
[ 20.407053][ T7] hub_event (hub.c:?) 
[ 20.407053][ T7] ? process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? trace_hardirqs_on (??:?) 
[ 20.407053][ T7] process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? rcuwait_wake_up (??:?) 
[ 20.407053][ T7] worker_thread (workqueue.c:?) 
[ 20.407053][ T7] kthread (kthread.c:?) 
[ 20.407053][ T7] ? process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? kthread_complete_and_exit (kthread.c:?) 
[ 20.407053][ T7] ret_from_fork (??:?) 
[   20.407053][    T7]
[   20.407053][    T7] =============================
[   20.407053][    T7] [ BUG: Invalid wait context ]
[   20.407053][    T7] 6.4.0-rc3-00033-g130794a2eeb2 #29 Tainted: G S      W
[   20.407053][    T7] -----------------------------
[   20.407053][    T7] kworker/0:0/7 is trying to lock:
[ 20.407053][ T7] c1272cb4 (&root->kernfs_rwsem){++++}-{3:3}, at: kernfs_find_and_get_ns (??:?) 
[   20.407053][    T7] other info that might help us debug this:
[   20.407053][    T7] context-{4:4}
[   20.407053][    T7] 6 locks held by kworker/0:0/7:
[ 20.407053][ T7] #0: c13e67a4 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work (workqueue.c:?) 
[ 20.407053][ T7] #1: c129df48 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work (workqueue.c:?) 
[ 20.407053][ T7] #2: ed5968f4 (&dev->mutex){....}-{3:3}, at: hub_event (hub.c:?) 
[ 20.407053][ T7] #3: ed5edac8 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect (hub.c:?) 
[ 20.407053][ T7] #4: ed0c3dfc (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect (hub.c:?) 
[ 20.407053][ T7] #5: d4c9b550 (device_state_lock){....}-{2:2}, at: usb_set_device_state (??:?) 
[   20.407053][    T7] stack backtrace:
[   20.407053][    T7] CPU: 0 PID: 7 Comm: kworker/0:0 Tainted: G S      W          6.4.0-rc3-00033-g130794a2eeb2 #29
[   20.407053][    T7] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[   20.407053][    T7] Workqueue: usb_hub_wq hub_event
[   20.407053][    T7] Call Trace:
[ 20.407053][ T7] dump_stack_lvl (??:?) 
[ 20.407053][ T7] dump_stack (??:?) 
[ 20.407053][ T7] __lock_acquire (lockdep.c:?) 
[ 20.407053][ T7] ? dump_stack_lvl (??:?) 
[ 20.407053][ T7] lock_acquire (??:?) 
[ 20.407053][ T7] ? kernfs_find_and_get_ns (??:?) 
[ 20.407053][ T7] ? __might_sleep (??:?) 
[ 20.407053][ T7] down_read (??:?) 
[ 20.407053][ T7] ? kernfs_find_and_get_ns (??:?) 
[ 20.407053][ T7] ? pm_runtime_set_autosuspend_delay (??:?) 
[ 20.407053][ T7] kernfs_find_and_get_ns (??:?) 
[ 20.407053][ T7] update_port_device_state (hub.c:?) 
[ 20.407053][ T7] usb_set_device_state (??:?) 
[ 20.407053][ T7] hub_port_connect (hub.c:?) 
[ 20.407053][ T7] ? hub_port_connect_change (hub.c:?) 
[ 20.407053][ T7] ? lock_release (??:?) 
[ 20.407053][ T7] hub_port_connect_change (hub.c:?) 
[ 20.407053][ T7] ? mutex_unlock (??:?) 
[ 20.407053][ T7] ? hub_ext_port_status (hub.c:?) 
[ 20.407053][ T7] port_event (hub.c:?) 
[ 20.407053][ T7] ? lockdep_hardirqs_on_prepare (lockdep.c:?) 
[ 20.407053][ T7] ? pm_runtime_barrier (??:?) 
[ 20.407053][ T7] hub_event (hub.c:?) 
[ 20.407053][ T7] ? process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? trace_hardirqs_on (??:?) 
[ 20.407053][ T7] process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? rcuwait_wake_up (??:?) 
[ 20.407053][ T7] worker_thread (workqueue.c:?) 
[ 20.407053][ T7] kthread (kthread.c:?) 
[ 20.407053][ T7] ? process_one_work (workqueue.c:?) 
[ 20.407053][ T7] ? kthread_complete_and_exit (kthread.c:?) 
[ 20.407053][ T7] ret_from_fork (??:?) 
[ 20.485486][ T1] initcall apanel_init+0x0/0x20c returned -19 after 88573 usecs 
[ 20.486325][ T1] calling atmel_captouch_driver_init+0x0/0x14 @ 1 
[ 20.487093][ T1] initcall atmel_captouch_driver_init+0x0/0x14 returned 0 after 68 usecs 
[ 20.488002][ T1] calling cm109_init+0x0/0x12c @ 1 
[   20.488571][    T1] cm109: Keymap for Komunikate KIP1000 phone loaded
[   20.489313][    T1] usbcore: registered new interface driver cm109
[   20.489992][    T1] cm109: CM109 phone driver: 20080805 (C) Alfred E. Heggestad
[ 20.490827][ T1] initcall cm109_init+0x0/0x12c returned 0 after 2256 usecs 
[ 20.491595][ T1] calling da9055_onkey_driver_init+0x0/0x14 @ 1 
[ 20.492327][ T1] initcall da9055_onkey_driver_init+0x0/0x14 returned 0 after 58 usecs 
[ 20.493218][ T1] calling e3x0_button_driver_init+0x0/0x14 @ 1 
[ 20.493906][ T1] initcall e3x0_button_driver_init+0x0/0x14 returned 0 after 23 usecs 
[ 20.494789][ T1] calling drv2667_driver_init+0x0/0x14 @ 1 
[ 20.495453][ T1] initcall drv2667_driver_init+0x0/0x14 returned 0 after 24 usecs 
[ 20.496299][ T1] calling gpio_beeper_platform_driver_init+0x0/0x14 @ 1 
[ 20.497073][ T1] initcall gpio_beeper_platform_driver_init+0x0/0x14 returned 0 after 23 usecs 
[ 20.498029][ T1] calling gpio_decoder_driver_init+0x0/0x14 @ 1 
[ 20.498725][ T1] initcall gpio_decoder_driver_init+0x0/0x14 returned 0 after 23 usecs 
[ 20.499617][ T1] calling gpio_vibrator_driver_init+0x0/0x14 @ 1 
[ 20.500324][ T1] initcall gpio_vibrator_driver_init+0x0/0x14 returned 0 after 22 usecs 
[ 20.501224][ T1] calling iqs269_i2c_driver_init+0x0/0x14 @ 1 
[ 20.501905][ T1] initcall iqs269_i2c_driver_init+0x0/0x14 returned 0 after 22 usecs 
[ 20.502785][ T1] calling iqs626_i2c_driver_init+0x0/0x14 @ 1 
[ 20.503474][ T1] initcall iqs626_i2c_driver_init+0x0/0x14 returned 0 after 27 usecs 
[ 20.504344][ T1] calling keyspan_driver_init+0x0/0x18 @ 1 
[   20.505007][    T1] usbcore: registered new interface driver keyspan_remote
[ 20.505756][ T1] initcall keyspan_driver_init+0x0/0x18 returned 0 after 776 usecs 
[ 20.506609][ T1] calling max77650_onkey_driver_init+0x0/0x14 @ 1 
[ 20.507341][ T1] initcall max77650_onkey_driver_init+0x0/0x14 returned 0 after 29 usecs 
[ 20.508247][ T1] calling max8925_onkey_driver_init+0x0/0x14 @ 1 
[ 20.508956][ T1] initcall max8925_onkey_driver_init+0x0/0x14 returned 0 after 27 usecs 
[ 20.509848][ T1] calling pcf8574_kp_driver_init+0x0/0x14 @ 1 
[ 20.510529][ T1] initcall pcf8574_kp_driver_init+0x0/0x14 returned 0 after 21 usecs 
[ 20.511411][ T1] calling regulator_haptic_driver_init+0x0/0x14 @ 1 
[ 20.512150][ T1] initcall regulator_haptic_driver_init+0x0/0x14 returned 0 after 27 usecs 
[ 20.513072][ T1] calling retu_pwrbutton_driver_init+0x0/0x14 @ 1 
[ 20.513791][ T1] initcall retu_pwrbutton_driver_init+0x0/0x14 returned 0 after 28 usecs 
[ 20.514692][ T1] calling rotary_encoder_driver_init+0x0/0x14 @ 1 
[ 20.515420][ T1] initcall rotary_encoder_driver_init+0x0/0x14 returned 0 after 23 usecs 
[ 20.516326][ T1] calling stpmic1_onkey_driver_init+0x0/0x14 @ 1 
[ 20.517028][ T1] initcall stpmic1_onkey_driver_init+0x0/0x14 returned 0 after 22 usecs 
[ 20.517928][ T1] calling tps6521x_pb_driver_init+0x0/0x20 @ 1 
[ 20.518620][ T1] initcall tps6521x_pb_driver_init+0x0/0x20 returned 0 after 28 usecs 
[ 20.519512][ T1] calling wb_module_init+0x0/0x1c4 @ 1 
[   20.520122][    T1] wistron_btns: System unknown
[ 20.520649][ T1] initcall wb_module_init+0x0/0x1c4 returned -19 after 534 usecs 
[ 20.521482][ T1] calling yealink_driver_init+0x0/0x20 @ 1 
[   20.522143][    T1] usbcore: registered new interface driver yealink
[ 20.522841][ T1] initcall yealink_driver_init+0x0/0x20 returned 0 after 724 usecs 


To reproduce:

        # build kernel
	cd linux
	cp config-6.4.0-rc3-00033-g130794a2eeb2 .config
	make HOSTCC=gcc-12 CC=gcc-12 ARCH=i386 olddefconfig prepare modules_prepare bzImage modules
	make HOSTCC=gcc-12 CC=gcc-12 ARCH=i386 INSTALL_MOD_PATH=<mod-install-dir> modules_install
	cd <mod-install-dir>
	find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.
diff mbox series

Patch

diff --git a/Documentation/ABI/testing/sysfs-bus-usb b/Documentation/ABI/testing/sysfs-bus-usb
index cb172db41b34..155770f18f9c 100644
--- a/Documentation/ABI/testing/sysfs-bus-usb
+++ b/Documentation/ABI/testing/sysfs-bus-usb
@@ -292,6 +292,15 @@  Description:
 		which is marked with early_stop has failed to initialize, it will ignore
 		all future connections until this attribute is clear.
 
+What:		/sys/bus/usb/devices/.../<hub_interface>/port<X>/state
+Date:		May 2023
+Contact:	Roy Luo <royluo@google.com>
+Description:
+		Indicates current state of the USB device attached to the port. Valid
+		states are: 'not-attached', 'attached', 'powered',
+		'reconnecting', 'unauthenticated', 'default', 'addressed',
+		'configured', and 'suspended'.
+
 What:		/sys/bus/usb/devices/.../power/usb2_lpm_l1_timeout
 Date:		May 2013
 Contact:	Mathias Nyman <mathias.nyman@linux.intel.com>
diff --git a/drivers/usb/core/hub.c b/drivers/usb/core/hub.c
index 97a0f8faea6e..d6bc5622e45e 100644
--- a/drivers/usb/core/hub.c
+++ b/drivers/usb/core/hub.c
@@ -2018,6 +2018,23 @@  bool usb_device_is_owned(struct usb_device *udev)
 	return !!hub->ports[udev->portnum - 1]->port_owner;
 }
 
+static void update_port_device_state(struct usb_device *udev)
+{
+	struct usb_hub *hub;
+	struct usb_port *port_dev;
+	struct kernfs_node *state_node;
+
+	if (udev->parent) {
+		hub = usb_hub_to_struct_hub(udev->parent);
+		port_dev = hub->ports[udev->portnum - 1];
+		WRITE_ONCE(port_dev->state, udev->state);
+		state_node = sysfs_get_dirent(port_dev->dev.kobj.sd, "state");
+		if (state_node) {
+			sysfs_notify_dirent(state_node);
+		}
+	}
+}
+
 static void recursively_mark_NOTATTACHED(struct usb_device *udev)
 {
 	struct usb_hub *hub = usb_hub_to_struct_hub(udev);
@@ -2030,6 +2047,7 @@  static void recursively_mark_NOTATTACHED(struct usb_device *udev)
 	if (udev->state == USB_STATE_SUSPENDED)
 		udev->active_duration -= jiffies;
 	udev->state = USB_STATE_NOTATTACHED;
+	update_port_device_state(udev);
 }
 
 /**
@@ -2086,6 +2104,7 @@  void usb_set_device_state(struct usb_device *udev,
 				udev->state != USB_STATE_SUSPENDED)
 			udev->active_duration += jiffies;
 		udev->state = new_state;
+		update_port_device_state(udev);
 	} else
 		recursively_mark_NOTATTACHED(udev);
 	spin_unlock_irqrestore(&device_state_lock, flags);
diff --git a/drivers/usb/core/hub.h b/drivers/usb/core/hub.h
index e23833562e4f..cd13fe189726 100644
--- a/drivers/usb/core/hub.h
+++ b/drivers/usb/core/hub.h
@@ -84,6 +84,7 @@  struct usb_hub {
  * @peer: related usb2 and usb3 ports (share the same connector)
  * @req: default pm qos request for hubs without port power control
  * @connect_type: port's connect type
+ * @state: device state of the usb device attached to the port
  * @location: opaque representation of platform connector location
  * @status_lock: synchronize port_event() vs usb_port_{suspend|resume}
  * @portnum: port index num based one
@@ -100,6 +101,7 @@  struct usb_port {
 	struct usb_port *peer;
 	struct dev_pm_qos_request *req;
 	enum usb_port_connect_type connect_type;
+	enum usb_device_state state;
 	usb_port_location_t location;
 	struct mutex status_lock;
 	u32 over_current_count;
diff --git a/drivers/usb/core/port.c b/drivers/usb/core/port.c
index 06a8f1f84f6f..745f2a3aafba 100644
--- a/drivers/usb/core/port.c
+++ b/drivers/usb/core/port.c
@@ -160,6 +160,16 @@  static ssize_t connect_type_show(struct device *dev,
 }
 static DEVICE_ATTR_RO(connect_type);
 
+static ssize_t state_show(struct device *dev,
+			  struct device_attribute *attr, char *buf)
+{
+	struct usb_port *port_dev = to_usb_port(dev);
+	enum usb_device_state state = READ_ONCE(port_dev->state);
+
+	return sprintf(buf, "%s\n", usb_state_string(state));
+}
+static DEVICE_ATTR_RO(state);
+
 static ssize_t over_current_count_show(struct device *dev,
 				       struct device_attribute *attr, char *buf)
 {
@@ -259,6 +269,7 @@  static DEVICE_ATTR_RW(usb3_lpm_permit);
 
 static struct attribute *port_dev_attrs[] = {
 	&dev_attr_connect_type.attr,
+	&dev_attr_state.attr,
 	&dev_attr_location.attr,
 	&dev_attr_quirks.attr,
 	&dev_attr_over_current_count.attr,