Re: [3.16.1 BISECTED REGRESSION]: Simtec Entropy Key (cdc-acm) broken in 3.16

[Nix <nix@esperi.org.uk>]

On 14 Oct 2014, Johan Hovold verbalised:

> On Sun, Oct 12, 2014 at 10:36:30PM +0100, Nix wrote:
>> I have checked: this code is being executed against a symlink that
>> points to /dev/ttyACM0, and the tcsetattr() succeeds. (At least, it's
>> succeeding on the kernel I'm running now, but of course that's 3.16.5
>> with this commit reverted...)
>
> You could verify that by enabling debugging in the cdc-acm driver and
> making sure that the corresponding control messages are indeed sent on
> close.

I have a debugging dump at
<http://www.esperi.org.uk/~nix/temporary/cdc-acm.log>; it's fairly
voluminous because the ekeyd is constantly doing USB reads, but the end
says

Oct 22 10:19:13 fold kern debug: : [   88.423970] cdc_acm 2-1:1.0: acm_tty_close
Oct 22 10:19:13 fold kern debug: : [   88.424012] cdc_acm 2-1:1.0: acm_port_shutdown
Oct 22 10:19:13 fold kern debug: : [   88.440038] cdc_acm 2-1:1.0: acm_ctrl_msg - rq 0x22, val 0x0, len 0x0, result 0
Oct 22 10:19:13 fold kern debug: : [   88.440038] cdc_acm 2-1:1.0: acm_ctrl_irq - urb shutting down with status: -2
Oct 22 10:19:13 fold kern debug: : [   88.440038] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 0, len 0
Oct 22 10:19:13 fold kern debug: : [   88.440038] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.447588] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 1, len 0
Oct 22 10:19:13 fold kern debug: : [   88.447613] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.448575] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 2, len 0
Oct 22 10:19:13 fold kern debug: : [   88.448599] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.449576] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 3, len 0
Oct 22 10:19:13 fold kern debug: : [   88.449599] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.450578] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 4, len 0
Oct 22 10:19:13 fold kern debug: : [   88.450602] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.451573] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 5, len 0
Oct 22 10:19:13 fold kern debug: : [   88.451596] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.452574] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 6, len 0
Oct 22 10:19:13 fold kern debug: : [   88.452597] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.453567] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 7, len 0
Oct 22 10:19:13 fold kern debug: : [   88.453588] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.454570] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 8, len 0
Oct 22 10:19:13 fold kern debug: : [   88.454592] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.462591] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 9, len 0
Oct 22 10:19:13 fold kern debug: : [   88.462619] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.463568] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 10, len 0
Oct 22 10:19:13 fold kern debug: : [   88.463590] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.464564] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 11, len 0
Oct 22 10:19:13 fold kern debug: : [   88.464585] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.465578] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 12, len 0
Oct 22 10:19:13 fold kern debug: : [   88.465602] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2
Oct 22 10:19:13 fold kern debug: : [   88.466566] cdc_acm 2-1:1.1: acm_read_bulk_callback - urb 13, len 0
Oct 22 10:19:13 fold kern debug: : [   88.466587] cdc_acm 2-1:1.1: acm_read_bulk_callback - non-zero urb status: -2

which looks, hm, a bit suspicious to me.

> But you haven't seen any fw crashes since you reverted the commit in
> question?

Not a one.

> Another thing you could try is to add back the 
>
> 	acm_set_control(acm, 0);
>
> just after the dev_info message in probe.

Tried that (with, obviously, the commit not reverted) -- rebooted, and

BytesRead=0
BytesWritten=0
ConnectionNonces=0
ConnectionPackets=0
ConnectionRekeys=0
ConnectionResets=0
ConnectionTime=46
EntropyRate=0
FipsFrameRate=0
FrameByteLast=0
FramesOk=0
FramingErrors=0
KeyDbsdShannonPerByteL=0
KeyDbsdShannonPerByteR=0
KeyEnglishBadness=No failure
KeyRawBadness=0
KeyRawShannonPerByteL=0
KeyRawShannonPerByteR=0
KeyRawShannonPerByteX=0
KeyShortBadness=efm_ok
KeyTemperatureC=-273.15
KeyTemperatureF=-459.67
KeyTemperatureK=0
KeyVoltage=0
PacketErrors=0
PacketOK=0
ReadRate=0
TotalEntropy=0
WriteRate=0

So that doesn't help.

-- 
NULL && (void)