New issue
Advanced search Search tips

Issue 627141 link

Starred by 7 users

Issue metadata

Status: Verified
Owner:
Closed: Oct 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

CRAS: record failure if open input stream while USB mic unplugging

Project Member Reported by jen...@chromium.org, Jul 11 2016

Issue description

Some users, including Googlers, have reported lost microphone with webcam, since chromeOS 49 update. 

https://groups.google.com/a/google.com/forum/#!msg/cros-media-issues-feedback/3AZfi-l8-Rc/P3pu3dZ4BgAJ
https://groups.google.com/a/google.com/forum/#!msg/peppy-feedback-reports/jVA42TLJJVc/Dmq3GnO1O3MJ
https://groups.google.com/a/google.com/forum/#!msg/cros-media-issues-feedback/cSfKVA8cMOI/NPpjUZfwCAAJ

craigcitro@, can you fill in some details for the issue, including the platform version of the chromeos, which can be found chrome://version, and the brand of camera, and other details. Thanks!

 

Comment 1 by jen...@chromium.org, Jul 11 2016

Labels: OS-Chrome
Labels: -Pri-3 Pri-1

Comment 3 by mi...@mikelward.com, Jul 11 2016

Microphone works for me with Logitech B910, but not with Logitech C920. Tried Hangouts on two Chromeboxes, same result.

Audio for same webcam works in Hangouts on Linux (but I have to choose the C920 from the microphone dropdown in Hangouts).

Only microphone option in the Hangouts dropdown is Default. No green dots to indicate volume on the drop down when I speak.

On the system settings next to the volume slider, the icon looks like an HDMI port. Clicking on it shows my HDMI display device for video output at the top, and my C920 webcam for audio input at the bottom. They are the only options, both are checked.

Comment 4 by hychao@chromium.org, Jul 12 2016

Owner: hychao@chromium.org
Status: Assigned (was: Untriaged)
Hangouts app don't have access to the system audio status, that's why it always show 'Default' in device dropdown.

From one of the feedback log, I can see logs saying that CRAS fail to open Ligtech C920 audio. I'll try get one to test.
Are there USB devices other than 'Logitech C920' having the same issue?
So I'm using a Logitech C930e, and I've had mixed results. 

Just now, I checked input settings, opened hangouts, no mic.

I did it again, looking to hit the feedback button, and everything worked. (huzzah!)

I will use it a bit more for the next few days and hit the feedback button if I can spot it not working.

Comment 6 by hychao@chromium.org, Jul 13 2016

I have tested C920r and C930e with Chromebook Pixel and both work great.

Which Chrome OS device were you seeing issues on?

Comment 7 by mbw@google.com, Jul 13 2016

I was on panther on Sunday, and it would not work despite multiple restarts and unplug/replug attempts.  But of course today it works first try. :/

Comment 8 by mbw@google.com, Jul 13 2016

Pretty sure I tried on my tricky on Sunday and it didn't work then either.  Perhaps having used it in Ubuntu Linux since somehow fixed things? :/
So I just opened hangouts again, and this time mic isn't working at all. I hit the button to send feedback (via chromeos, not hangouts).

I'm on an HP Chromebox (zako), 8172.60.0 (Official Build) stable-channel zako.
Thanks Craig,
Got the report you filed, at http://feedback/#/Report/11153119834
According to log, this webcam disconnected when Hangout configures it for input.

2016-07-10T17:04:47.672369-07:00 INFO kernel: [  556.686452] usb 1-6: reset high-speed USB device number 9 using xhci_hcd
2016-07-10T17:04:47.683993-07:00 INFO kernel: [  556.697713] usb 1-6: device firmware changed
2016-07-10T17:04:47.684012-07:00 INFO kernel: [  556.697759] usb 1-6: USB disconnect, device number 9
2016-07-10T17:04:47.684015-07:00 WARNING kernel: [  556.698346] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88014aedf840
2016-07-10T17:04:47.783347-07:00 ERR cras_server[4259]: snd_pcm_open_failed: No such file or directory
2016-07-10T17:04:47.783372-07:00 ERR cras_server[4259]: Failed to update formats
2016-07-10T17:04:47.783378-07:00 ERR chrom[474]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=<IPv4: 12>92-r1 --ppapi-flash-args=enable_hw_video_decode=1 --enable-fixed-position-compositing --enable-impl-side-painting --max-tiles-for-interest-area=512 --ui-enable-per-tile-painting --ui-prioritize-in-gpu-process --use-gl=egl --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --aura-legacy-power-button --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/oem_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/oem_small.jpg --default-wallpaper-is-oem --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=14 --enterprise-enrollment-modulus-limit=18 --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*ui/display/chromeos*=1,*ash/display*=1,*ui/ozone*=1,*zygote*=1,*plugin*=2,*chromeos/login/*=1 --login-manager --first-exec-after-boot: cras_client: Error Setting up stream -12
2016-07-10T17:04:47.837593-07:00 INFO kernel: [  556.851708] usb 1-6: new high-speed USB device number 10 using xhci_hcd
2016-07-10T17:04:48.952367-07:00 INFO kernel: [  557.965362] usb 1-6: New USB device found, idVendor=046d, idProduct=082d
2016-07-10T17:04:48.952385-07:00 INFO kernel: [  557.965378] usb 1-6: New USB device strings: Mfr=0, Product=2, SerialNumber=1
2016-07-10T17:04:48.952387-07:00 INFO kernel: [  557.965391] usb 1-6: Product: HD Pro Webcam C920
2016-07-10T17:04:48.952389-07:00 INFO kernel: [  557.965402] usb 1-6: SerialNumber: E357D1FF
2016-07-10T17:04:48.953356-07:00 INFO kernel: [  557.965874] uvcvideo: Found UVC 1.00 device HD Pro Webcam C920 (046d:082d)
Is that the right bug report? (It looks like it's from two days ago.)

Interestingly, the camera was working fine -- just no mic.
I am not sure what is the cause to this problem. Will do more test on my side using C930e and C920.
If this is really a regression, I can check what has landed in kernel in M49.
Yes I think this one is correct. Submitted on: 2016-07-13 03:23 UTC, on a Zako.
I am back to this issue.

Not sure if other "No microphone" reports have the same error pattern as in #10.
The log describes a scenario that the USB mic disconnected and immediately Hangout app tries to open input stream but failed because of that.
After 50 ms this USB mic connects again, but the input stream was left in the error state.

ChromeOS audio server assumes this open failure should happen very rarely and do nothing more than error log when it happens. That gives user bad experience because the only way to solve it is reload Hangout app or the web page he/she is browsing.

Since quick unplug then plug USB device is legit and it could happen when userspace tries to open it.  Maybe we should do something to keep stream alive when this kind of error happens, and give it a chance to re-open the selected audio node.
But before that I'll need more experiment with these USB mics and try collect more failure logs.


Is this with a pinned stream?  If the stream isn't pinned, it should switch to some other dev and then switch back, when the USB device is available again.

If it is pinned, maybe we should drop it to the empty dev, then bring it back if the USB device comes back.  Can we keep that simple from a code stand point?
Cc: cychiang@chromium.org
Jimmy proposed a fix by always attach the stream to empty device when this kind of error happens. And at the next time when active node changes, move all the streams on empty device to that node.
This behavior aligns with what we're doing now: when switching output node from A to B and open dev A takes too long, empty device is used as a temp holder for that stream.
pinned stream is a bit tricky, if client uses the "M:N" index of node, USB unplug/plug would have a new pair of numbers.
So it seems reproducible by making the unplug event and open call happen close to < 100ms, tested on my Link device.

2016-09-01T19:06:05.651361+08:00 INFO kernel: [189307.815078] usb 2-1.3: reset high-speed USB device number 9 using ehci-pci
2016-09-01T19:06:05.741215+08:00 ERR cras_server[3920]: hw_params: No such device: rate: 48000, ret_rate: 48000, channel: 2, format: 2
2016-09-01T19:06:05.742729+08:00 ERR cras_test_client[7432]: cras_client: Error Setting up stream -12
2016-09-01T19:06:05.744086+08:00 INFO cras_test_client[7432]: cras_client: remove stream 2387542016
2016-09-01T19:06:07.745327+08:00 INFO kernel: [189309.908622] uvcvideo: Found UVC 1.00 device Logitech Webcam C930e (046d:0843)

Attached the script I used to emulate unplug/plug USB mic. Once this is fixed we can write a chameleon test to stress USB plug/unplug while audio input/output.

Labels: -Type-Bug-Regression M-54 Type-Bug
Summary: CRAS: record failure if open input stream while USB mic unplugging (was: No microphone since ChromeOS 49 update)
really attached the script
link-unplug-usb-mic.py
305 bytes View Download
Can the error get sent up to the client?  If the device disappears, the client should get an error.  It can then decide if it wants to reattach when the device reappears.
Labels: -M-54 M-55
Yes currently we have the error sent up to client. cras_rclient checks the return code of stream_list_add() and reply error to client so that cras_stream_params->cras_error_cb_t is triggered.

However I think the problem described in #17 is something we should handle in server side. The stream was unlucky that it connects at a bad timing that USB headset is physically unplugged but not yet processed by CRAS and switch to the node that available for input/output. 

Uploaded Cl for that:
https://chromium-review.googlesource.com/400298



Project Member

Comment 21 by bugdroid1@chromium.org, Oct 19 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/f7bd96bb9df7910849fd20d28c567930ffddf11d

commit f7bd96bb9df7910849fd20d28c567930ffddf11d
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Tue Oct 18 10:22:49 2016

CRAS: iodev_list - Accept stream connect when seeing -ENOENT err

If a stream connects while headset is being unplugged, there is a
chance that open device got -ENOENT error and rejects the stream
depend on the timing.
CRAS should handle this type of error for non-pinned stream because
connecting a new stream shouldn't be affected by the transient
state of device switching. Fix this by checking the error code
returned by init_device. The new stream will be attached to fallback
device and move to a real device later when Chrome selects a valid
audio node.

BUG= chromium:627141 
TEST=Use the script attached in the bug to emulate the unplug.
Verify that input stream doesn't drop and successfully record sound.

Change-Id: Ibb79d64ba8c2d6dd5e7c1dbf7cc20b3defb038c3
Reviewed-on: https://chromium-review.googlesource.com/400298
Commit-Ready: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>

[modify] https://crrev.com/f7bd96bb9df7910849fd20d28c567930ffddf11d/cras/src/server/cras_iodev_list.c

Labels: Merge-Request-55
Status: Started (was: Assigned)

Comment 23 by dimu@chromium.org, Oct 20 2016

Labels: -Merge-Request-55 Merge-Approved-55 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M55 (branch: 2883)
Project Member

Comment 24 by bugdroid1@chromium.org, Oct 20 2016

Labels: merge-merged-release-R55-8872.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/adhd/+/8fc3b5e12206b024f17f4fc43f00817d6194ecbb

commit 8fc3b5e12206b024f17f4fc43f00817d6194ecbb
Author: Hsin-Yu Chao <hychao@chromium.org>
Date: Tue Oct 18 10:22:49 2016

CRAS: iodev_list - Accept stream connect when seeing -ENOENT err

If a stream connects while headset is being unplugged, there is a
chance that open device got -ENOENT error and rejects the stream
depend on the timing.
CRAS should handle this type of error for non-pinned stream because
connecting a new stream shouldn't be affected by the transient
state of device switching. Fix this by checking the error code
returned by init_device. The new stream will be attached to fallback
device and move to a real device later when Chrome selects a valid
audio node.

BUG= chromium:627141 
TEST=Use the script attached in the bug to emulate the unplug.
Verify that input stream doesn't drop and successfully record sound.

Change-Id: Ibb79d64ba8c2d6dd5e7c1dbf7cc20b3defb038c3
Reviewed-on: https://chromium-review.googlesource.com/400298
Commit-Ready: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>
(cherry picked from commit f7bd96bb9df7910849fd20d28c567930ffddf11d)
Reviewed-on: https://chromium-review.googlesource.com/401081
Reviewed-by: Hsinyu Chao <hychao@chromium.org>
Commit-Queue: Hsinyu Chao <hychao@chromium.org>

[modify] https://crrev.com/8fc3b5e12206b024f17f4fc43f00817d6194ecbb/cras/src/server/cras_iodev_list.c

Status: Fixed (was: Started)
Project Member

Comment 26 by sheriffbot@chromium.org, Oct 23 2016

This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Labels: -Hotlist-Merge-Approved -Merge-Approved-55

Comment 28 by son...@google.com, Oct 26 2016

Status: Verified (was: Fixed)
Verified on build 8872.25.0

Sign in to add a comment