New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 747612 link

Starred by 1 user
Status: Assigned
Owner:
█ charliemooney@chromium.org
Last visit > 30 days ago
Cc:
elijahtaylor@chromium.org
jorgelo@chromium.org
achuith@chromium.org
hidehiko@chromium.org
cychiang@chromium.org
chromeos-audio-bugs@google.com
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug



Sign in to add a comment

audio_Microphone wedged on edgar-paladin

Reported by jrbarnette@chromium.org, Jul 21 2017 
This edgar-paladin run failed:
    https://luci-milo.appspot.com/buildbot/chromeos/edgar-paladin/181

The reason was that this test job wedged and then timed out:
    http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=129533987

The hung test was audio_Microphone.

Nothing in the blamelist for the CQ run might plausibly cause such
a failure, so it seems likely the problem is in ToT.

Comment 1 by jrbarnette@chromium.org, Jul 21 2017 

For the record, wmatrix claims that the test is almost, but not quite
completely clean:
    https://wmatrix.googleplex.com/unfiltered?hide_missing=True&tests=audio_Microphone&releases=61

It's not clear if any of the ABORT failures are the same as this
one.  This problem is either very new, or exceedingly rare, or both.

Comment 2 by jrbarnette@chromium.org, Jul 21 2017 

In this log file:
    audio_Microphone/debug/audio_Microphone.DEBUG

You find that the test cuts off like so:
07/21 11:57:04.077 ERROR|         cmd_utils:0091| [0012] Recording WAVE '/tmp/tmp9XyKiL' : Signed 16 bit Little Endian, Rate 44100 Hz, Mono
07/21 11:57:04.087 ERROR|         cmd_utils:0091| [0012] 

Looking next at crashinfo.chromeos2-row5-rack2-host9/var/log/messages,
you can find this happening at the same moment:
2017-07-21T18:57:04.077450+00:00 DEBUG kernel: [  140.154025] writing to lpe: 00000000: 01 01 01 01 00 00 08 00 ff ff ff ff 55 00 00 00  ............U...
2017-07-21T18:57:04.085321+00:00 NOTICE autotest[3540]: 11:57:04.077 ERROR|         cmd_utils:0091| [0012] Recording WAVE '/tmp/tmp9XyKiL' : Signed 16 bit Little Endian, Rate 44100 Hz, Mono
2017-07-21T18:57:04.089337+00:00 INFO kernel: [  140.164590] sst-mfld-platform sst-mfld-platform: Enter: enable=1 port_name=ssp2-port
2017-07-21T18:57:04.089362+00:00 DEBUG kernel: [  140.164664] writing to lpe: 00000000: 01 01 01 01 00 00 1a 00 ff ff ff ff 75 00 12 00  ............u...
2017-07-21T18:57:04.089365+00:00 DEBUG kernel: [  140.164668] writing to lpe: 00000010: 03 00 03 00 18 09 0f ff 0f ff 03 00 01 01 01 00  ................
2017-07-21T18:57:04.089367+00:00 DEBUG kernel: [  140.164671] writing to lpe: 00000020: 00 00                                            ..
2017-07-21T18:57:04.095784+00:00 NOTICE autotest[3542]: 11:57:04.087 ERROR|         cmd_utils:0091| [0012] 
2017-07-21T18:57:04.103295+00:00 INFO kernel: [  140.180051] intel_sst_acpi 808622A8:00: Alloc for str 3 pipe 0xe
2017-07-21T18:57:04.104320+00:00 DEBUG kernel: [  140.180941] writing to lpe: 00000000: 01 02 01 01 00 00 1e 00 ff ff ff ff 82 00 16 00  ................
2017-07-21T18:57:04.104345+00:00 DEBUG kernel: [  140.180946] writing to lpe: 00000010: 82 00 12 00 03 00 01 02 04 08 10 20 40 80 01 02  ........... @...
2017-07-21T18:57:04.104349+00:00 DEBUG kernel: [  140.180949] writing to lpe: 00000020: 04 08 10 20 40 80                                ... @.
2017-07-21T18:57:04.104350+00:00 DEBUG kernel: [  140.181191] writing to lpe: 00000000: 01 02 01 01 00 00 3c 00 00 82 94 00 81 00 00 00  ......<.........
2017-07-21T18:57:04.104352+00:00 DEBUG kernel: [  140.181195] writing to lpe: 00000010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.104354+00:00 DEBUG kernel: [  140.181198] writing to lpe: 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.104355+00:00 DEBUG kernel: [  140.181200] writing to lpe: 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.104357+00:00 DEBUG kernel: [  140.181203] writing to lpe: 00000040: 00 00 00 00                                      ....
2017-07-21T18:57:04.104358+00:00 DEBUG kernel: [  140.181535] writing to lpe: 00000000: 01 02 01 01 00 00 14 00 ff ff ff ff 21 00 0c 00  ............!...
2017-07-21T18:57:04.104360+00:00 DEBUG kernel: [  140.181538] writing to lpe: 00000010: 01 00 00 82 67 00 00 00 00 00 32 00              ....g.....2.
2017-07-21T18:57:04.105288+00:00 DEBUG kernel: [  140.181743] writing to lpe: 00000000: 01 01 01 01 00 00 14 00 ff ff ff ff 72 00 0c 00  ............r...
2017-07-21T18:57:04.105305+00:00 DEBUG kernel: [  140.181747] writing to lpe: 00000010: ff 06 ff ff 03 00 01 00 ff 82 ff ff              ............
2017-07-21T18:57:04.105308+00:00 DEBUG kernel: [  140.181908] writing to lpe: 00000000: 01 01 01 01 00 00 14 00 ff ff ff ff 72 00 0c 00  ............r...
2017-07-21T18:57:04.105310+00:00 DEBUG kernel: [  140.181912] writing to lpe: 00000010: ff 0e ff ff 03 00 01 00 ff 86 ff ff              ............
2017-07-21T18:57:04.105314+00:00 DEBUG kernel: [  140.182049] writing to lpe: 00000000: 01 01 01 01 00 00 0e 00 ff 06 ff ff 76 00 06 00  ............v...
2017-07-21T18:57:04.105316+00:00 DEBUG kernel: [  140.182052] writing to lpe: 00000010: 03 00 ff 69 00 00                                ...i..
2017-07-21T18:57:04.106347+00:00 DEBUG kernel: [  140.182709] writing to lpe: 00000000: 01 02 01 01 00 00 18 01 00 06 81 00 80 00 00 00  ................
2017-07-21T18:57:04.106356+00:00 DEBUG kernel: [  140.182713] writing to lpe: 00000010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106358+00:00 DEBUG kernel: [  140.182716] writing to lpe: 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106360+00:00 DEBUG kernel: [  140.182718] writing to lpe: 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106362+00:00 DEBUG kernel: [  140.182721] writing to lpe: 00000040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106364+00:00 DEBUG kernel: [  140.182724] writing to lpe: 00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106365+00:00 DEBUG kernel: [  140.182727] writing to lpe: 00000060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106367+00:00 DEBUG kernel: [  140.182729] writing to lpe: 00000070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106369+00:00 DEBUG kernel: [  140.182732] writing to lpe: 00000080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106371+00:00 DEBUG kernel: [  140.182735] writing to lpe: 00000090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106373+00:00 DEBUG kernel: [  140.182737] writing to lpe: 000000a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106374+00:00 DEBUG kernel: [  140.182740] writing to lpe: 000000b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106376+00:00 DEBUG kernel: [  140.182743] writing to lpe: 000000c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106378+00:00 DEBUG kernel: [  140.182746] writing to lpe: 000000d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106380+00:00 DEBUG kernel: [  140.182748] writing to lpe: 000000e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106381+00:00 DEBUG kernel: [  140.182751] writing to lpe: 000000f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106383+00:00 DEBUG kernel: [  140.182754] writing to lpe: 00000100: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106384+00:00 DEBUG kernel: [  140.182757] writing to lpe: 00000110: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106386+00:00 DEBUG kernel: [  140.183523] writing to lpe: 00000000: 01 02 01 01 00 00 34 01 00 06 82 00 81 00 00 00  ......4.........
2017-07-21T18:57:04.106388+00:00 DEBUG kernel: [  140.183527] writing to lpe: 00000010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106389+00:00 DEBUG kernel: [  140.183530] writing to lpe: 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106391+00:00 DEBUG kernel: [  140.183532] writing to lpe: 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106392+00:00 DEBUG kernel: [  140.183535] writing to lpe: 00000040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106394+00:00 DEBUG kernel: [  140.183538] writing to lpe: 00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106395+00:00 DEBUG kernel: [  140.183551] writing to lpe: 00000060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106397+00:00 DEBUG kernel: [  140.183555] writing to lpe: 00000070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106399+00:00 DEBUG kernel: [  140.183558] writing to lpe: 00000080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106400+00:00 DEBUG kernel: [  140.183572] writing to lpe: 00000090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106402+00:00 DEBUG kernel: [  140.183580] writing to lpe: 000000a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106403+00:00 DEBUG kernel: [  140.183591] writing to lpe: 000000b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106405+00:00 DEBUG kernel: [  140.183602] writing to lpe: 000000c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106406+00:00 DEBUG kernel: [  140.183617] writing to lpe: 000000d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106408+00:00 DEBUG kernel: [  140.183628] writing to lpe: 000000e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106421+00:00 DEBUG kernel: [  140.183633] writing to lpe: 000000f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106424+00:00 DEBUG kernel: [  140.183636] writing to lpe: 00000100: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106426+00:00 DEBUG kernel: [  140.183639] writing to lpe: 00000110: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106427+00:00 DEBUG kernel: [  140.183642] writing to lpe: 00000120: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.106429+00:00 DEBUG kernel: [  140.183644] writing to lpe: 00000130: 00 00 00 00 00 00 00 00 00 00 00 00              ............
2017-07-21T18:57:04.107434+00:00 DEBUG kernel: [  140.184477] writing to lpe: 00000000: 01 02 01 01 00 00 26 01 00 06 79 00 74 00 00 00  ......&...y.t...
2017-07-21T18:57:04.107446+00:00 DEBUG kernel: [  140.184481] writing to lpe: 00000010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107448+00:00 DEBUG kernel: [  140.184484] writing to lpe: 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107450+00:00 DEBUG kernel: [  140.184486] writing to lpe: 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107452+00:00 DEBUG kernel: [  140.184489] writing to lpe: 00000040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107453+00:00 DEBUG kernel: [  140.184492] writing to lpe: 00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107455+00:00 DEBUG kernel: [  140.184494] writing to lpe: 00000060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107457+00:00 DEBUG kernel: [  140.184497] writing to lpe: 00000070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107458+00:00 DEBUG kernel: [  140.184500] writing to lpe: 00000080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107460+00:00 DEBUG kernel: [  140.184503] writing to lpe: 00000090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107461+00:00 DEBUG kernel: [  140.184505] writing to lpe: 000000a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107463+00:00 DEBUG kernel: [  140.184508] writing to lpe: 000000b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107464+00:00 DEBUG kernel: [  140.184511] writing to lpe: 000000c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107466+00:00 DEBUG kernel: [  140.184514] writing to lpe: 000000d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107467+00:00 DEBUG kernel: [  140.184516] writing to lpe: 000000e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107469+00:00 DEBUG kernel: [  140.184519] writing to lpe: 000000f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107470+00:00 DEBUG kernel: [  140.184522] writing to lpe: 00000100: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107472+00:00 DEBUG kernel: [  140.184525] writing to lpe: 00000110: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
2017-07-21T18:57:04.107474+00:00 DEBUG kernel: [  140.184527] writing to lpe: 00000120: 00 00 00 00 00 00 00 00 00 00 00 00 00 00        ..............
2017-07-21T18:57:04.108376+00:00 DEBUG kernel: [  140.185309] writing to lpe: 00000000: 01 02 01 01 00 00 14 00 ff ff ff ff 21 00 0c 00  ............!...
2017-07-21T18:57:04.108384+00:00 DEBUG kernel: [  140.185313] writing to lpe: 00000010: 01 00 00 06 67 00 00 00 00 00 32 00              ....g.....2.
2017-07-21T18:57:04.108387+00:00 DEBUG kernel: [  140.185485] writing to lpe: 00000000: 01 01 01 01 00 00 0a 00 ff 0e ff ff 77 00 02 00  ............w...
2017-07-21T18:57:04.108389+00:00 DEBUG kernel: [  140.185489] writing to lpe: 00000010: 01 00                                            ..
2017-07-21T18:57:04.109299+00:00 DEBUG kernel: [  140.185819] writing to lpe: 00000000: 01 02 01 01 00 00 14 00 ff ff ff ff 21 00 0c 00  ............!...
2017-07-21T18:57:04.109317+00:00 DEBUG kernel: [  140.185823] writing to lpe: 00000010: 01 00 00 0e 67 00 00 00 00 00 32 00              ....g.....2.
2017-07-21T18:57:04.109319+00:00 DEBUG kernel: [  140.186054] writing to lpe: 00000000: 01 02 01 01 00 00 14 00 ff ff ff ff 21 00 0c 00  ............!...
2017-07-21T18:57:04.109321+00:00 DEBUG kernel: [  140.186057] writing to lpe: 00000010: 01 00 00 0e 67 00 00 00 00 00 32 00              ....g.....2.
2017-07-21T18:57:04.109324+00:00 ERR kernel: [  140.186502] intel_sst_acpi 808622A8:00: sst: Busy wait failed, cant send this msg


So, let's blame the kernel.
►

Sign in to add a comment