Superfluous USB suspend after USB configured

[Qbicz]

Describe the bug
After settings up USB communication, additional SUSPEND status occurs. This is normally a signal to stop HID communication and causes our application to stop sending HID data.

Bug occurs after re-plugging the USB or plugging it after Zephyr started. When the USB cable is attached during firmware startup, superfluous suspend will not occur.

To Reproduce
Found originally on custom hardware PCA20041 (nRF52840 gaming mouse), but can be also reproduced on nrf52840_pca10056 DK with usb/hid sample.

Steps to reproduce the behavior:

1. go to usb/hid sample, create and enter build directory
2. cmake .. -DBOARD=nrf52840_pca10056 -GNinja
3. ninja flash
4. See error:

# start with USB connected
[00:00:00.000,000] <dbg> main.main: Starting application
[00:00:00.000,000] <dbg> main.main: HID Device: dev 0x200061b8
[00:00:00.003,387] <dbg> main.status_cb: status 2 unhandled
[00:00:00.006,500] <dbg> main.status_cb: status 5 unhandled
[00:00:00.119,628] <dbg> main.status_cb: status 6 unhandled
[00:00:00.119,659] <dbg> main.status_cb: status 1 unhandled
[00:00:00.215,270] <dbg> main.status_cb: status 1 unhandled
[00:00:00.579,956] <dbg> main.status_cb: status 1 unhandled
[00:00:00.675,659] <dbg> main.status_cb: status 1 unhandled

[00:01:11.093,811] <dbg> main.send_report: Wrote 2 bytes with ret 0
[00:01:13.101,623] <dbg> main.send_report: Wrote 2 bytes with ret 0
[00:01:15.109,436] <dbg> main.send_report: Wrote 2 bytes with ret 0

# USB HID works here.
# disconnect cable:
[00:01:15.951,263] <dbg> main.status_cb: status 5 unhandled
[00:01:16.001,586] <dbg> main.status_cb: status 4 unhandled
[00:01:17.117,218] <dbg> main.send_report: Wrote -2147483648 bytes with ret -19

# reconnect USB cable:

[00:01:23.107,391] <dbg> main.status_cb: status 2 unhandled
[00:01:23.110,534] <dbg> main.status_cb: status 5 unhandled
[00:01:23.223,785] <dbg> main.status_cb: status 6 unhandled
[00:01:23.223,815] <dbg> main.status_cb: status 1 unhandled
[00:01:23.319,610] <dbg> main.status_cb: status 1 unhandled
[00:01:23.722,595] <dbg> main.status_cb: status 1 unhandled
[00:01:23.818,328] <dbg> main.status_cb: status 1 unhandled
[00:01:23.996,185] <dbg> main.status_cb: status 5 unhandled

# status 5 is USB_DC_SUSPEND!
# USB HID does not work anymore.

Expected behavior
The suspend status should not be added after USB is replugged.

Impact
Stops HID application from sending data after replugging USB.

Environment (please complete the following information):

• Toolchain: Zephyr SDK 0.10.0
• Commit b0bc68e

Additionally
I tried reproducing it on usb/hid-mouse sample, but this SUSPEND does not occur there. The only difference I see is that usb/hid-mouse only have 1 callback (status_cb) attached, while the bug occurs in usb/hid which has more callbacks attached:

static const struct hid_ops ops = {
	.int_in_ready = in_ready_cb,
	.status_cb = status_cb,
	.on_idle = idle_cb,
	.protocol_change = protocol_cb,
};

[Qbicz]

FYI @barsok

[Qbicz]

I did a short travel in time:
v1.14.0 cebe115 : problem does not happen
May 12th b0bc68e : problem exists
current master (May 29th) 8de64fc : problem does not happen

Tested on usb/hid sample.

There has been some regression - and we have bumped into it. It would be good to at least find out why this bug occured.

[anangl]

I tried to replicate the issue on the usb/hid sample, and although I haven't seen the extra status 5 message, the sample indeed stopped to work after reconnecting the cable - only one report was sent after USB_DC_CONFIGURED status notification, but then no more reports appeared because the .int_in_ready callback was not called. And after searching a bit in git log, I found that commit 1370f16 fixes this behavior. @finikorg Does my reasoning make sense?

[carlescufi]

@anangl more info here: #15917 which was fixed in this PR: #16193

[carlescufi]

Fixed by 1370f16

[finikorg]

I tried to replicate the issue on the usb/hid sample, and although I haven't seen the extra status 5 message, the sample indeed stopped to work after reconnecting the cable - only one report was sent after USB_DC_CONFIGURED status notification, but then no more reports appeared because the .int_in_ready callback was not called. And after searching a bit in git log, I found that commit 1370f16 fixes this behavior. @finikorg Does my reasoning make sense?

Sorry my reply took so long, was that commit [1370f16] applied long time ago?

[anangl]

Sorry my reply took so long, was that commit [1370f16] applied long time ago?

On May 22 (#16193 (comment)), so not very long ago. At least it was applied after the commit for which the issue was reported (b0bc68e):

I did a short travel in time:
v1.14.0 cebe115 : problem does not happen
May 12th b0bc68e : problem exists
current master (May 29th) 8de64fc : problem does not happen