Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
495983002:
Improve logging related to start/stop and failure of audio input streams in Chrome (Closed)
|
Created:
6 years, 4 months ago by henrika (OOO until Aug 14) Modified:
6 years, 3 months ago CC:
chromium-reviews, posciak+watch_chromium.org, jam, mcasas+watch_chromium.org, feature-media-reviews_chromium.org, darin-cc_chromium.org, wjia+watch_chromium.org, miu+watch_chromium.org Base URL:
svn://svn.chromium.org/chrome/trunk/src Project:
chromium Visibility:
Public. |
DescriptionImprove logging related to start/stop and failure of audio input streams in Chrome.
BUG=405449
TEST=Manual testing using different WebRTC clients
Committed: https://crrev.com/8eec55ab69fe94838dc7a0e5d23102423d54ac76
Cr-Commit-Position: refs/heads/master@{#292622}
Patch Set 1 #Patch Set 2 : Added AIC logs #Patch Set 3 : Fine tuning #Patch Set 4 : Experimental version of AudioManagerBase logging #
Total comments: 30
Patch Set 5 : rebased #Patch Set 6 : Feedback from xians@ and grunell@ #Patch Set 7 : Improved logging in AudioManagerBase #
Total comments: 9
Patch Set 8 : Feedback from xians@ #
Total comments: 37
Patch Set 9 : nits #
Total comments: 10
Patch Set 10 : Removed notifier in AudioManager #Patch Set 11 : Feedback from tommi@ #Patch Set 12 : nits #Patch Set 13 : Fixed error in merge #
Total comments: 5
Patch Set 14 : Fixed issue where we log UMA stats too early #
Total comments: 1
Patch Set 15 : nit #
Total comments: 14
Patch Set 16 : tommi@ #Patch Set 17 : xians@ #
Total comments: 2
Messages
Total messages: 39 (1 generated)
Please take a look. Logging now looks like shown in the BUG. My plan was to land this first and then see how I can improve logging in the media layer. It requires more work since the native logger can't be used in media.
Patch Set 4 is an attempt to add logging also in media (AudioManagerBase in this case). Not sure if this solution is OK. Adding it as a reference. Now we can do stuff like: [15836:15863:0822/155804:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=1] AMB::MakeAudioInputStream(device_id=default) [15836:15863:0822/155804:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=1] AMB::MakeAudioInputStream => num_input_streams = 1 [15836:15863:0822/155830:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=1] AMB::ReleaseInputStream => num_input_streams = 0 [15836:15863:0822/155831:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=2] AMB::MakeAudioInputStream(device_id=alsa_input.usb-Creative_Technology_SB_Arena_Headset-00-Headset.analog-stereo) [15836:15863:0822/155831:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=2] AMB::MakeAudioInputStream => num_input_streams = 1 [15836:15863:0822/155839:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=2] AMB::ReleaseInputStream => num_input_streams = 0 [15836:15863:0822/155841:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=3] AMB::MakeAudioInputStream(device_id=default) [15836:15863:0822/155841:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=3] AMB::MakeAudioInputStream => num_input_streams = 1 [15836:15863:0822/155846:VERBOSE1:audio_input_renderer_host.cc(29)] [stream_id=3] AMB::ReleaseInputStream => num_input_streams = 0 which is nice.
The general approach looks good. Do we have clear cases for that the added logs are useful to a fairly large extent? I don't want to spam the logs. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:230: base::StringPrintf("AIC::DoCreate(device_id=%s)", device_id.c_str()); What device id is this? Unique in what way? Can it be used to identify someone? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:347: audio_manager_->RemoveStateChangeListener(this); Should the raw |audio_manager_| pointer be set to NULL here? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manager.h File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager.h:150: virtual void OnStateChange(const std::string state) = 0; const std::string& https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.cc:191: "MakeAudioInputStream(device_id=%s)", device_id.c_str()); Is this id something that can identify someone? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.cc:226: "MakeAudioInputStream => num_input_streams = %d", num_input_streams_); Do we need the above if we have this? What about the fail cases? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... File media/audio/audio_manager_base.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.h:105: // TODO ---- Add text to comment or remove. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.h:189: // Track ..... Track down pink ducks? Tracks with Kaj Kindwall? So hard to tell. :)
Initial reply to: "Do we have clear cases for that the added logs are useful to a fairly large extent? I don't want to spam the logs." Check the BUG=405449 for example usage. We do have a long list of issues where all we know is that "for some reason, data just simply is not recorded and we end up with NO_DATA_ERROR", but we are unable to figure out why. My plan was to add more logs until we can find what causes most of these issues. Then I can perhaps remove logs again. But right now we simply must do something (speculative) to figure out what fails. Sound OK?
https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... File content/renderer/media/audio_input_message_filter.cc (right): https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... content/renderer/media/audio_input_message_filter.cc:203: LogMessage(stream_id_, "CreateStream"); Do we really need to log each operation? It seems to me the new loggings do not add much value. https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... content/renderer/media/audio_input_message_filter.cc:215: LogMessage(stream_id_, "RecordStream"); ditto https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... content/renderer/media/audio_input_message_filter.cc:227: LogMessage(stream_id_, "CloseStream"); ditto https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:230: base::StringPrintf("AIC::DoCreate(device_id=%s)", device_id.c_str()); This is the uniqie id of the device, we can't log it due to privacy reason. Also, AudioInputRendererHost line 366 has: MediaStreamManager::SendMessageToNativeLog( "Audio input stream created successfully. Device name: " + device_name); You probably don't need to log the device again https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:317: handler_->OnLog(this, "AIC::DoRecord"); I don't really think you should log these, DoRecord and DoClose() are also used by non webrtc clients, can it be corrupting our loggings? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:412: ? handler_->OnLog(this, "AIC::FirstCheckForNoData => data is active") this does not look like clang format, could you please run the script? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.h:311: media::AudioManager* audio_manager_; nit, media::AudioManager* const https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manager.h File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager.h:148: class StateChangeListener { you probably need Dale to look at the change in AudioManager. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.cc:191: "MakeAudioInputStream(device_id=%s)", device_id.c_str()); as I pointed out, we can't log the device_id due to privacy concern.
Thanks, PTAL. https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... File content/renderer/media/audio_input_message_filter.cc (right): https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... content/renderer/media/audio_input_message_filter.cc:203: LogMessage(stream_id_, "CreateStream"); The idea was to add on all levels to ensure that we have the full path. Today, I am assigned to several issues where we have no idea why audio does not work. I am only trying to cover all angles here. Is it OK if I keep it and add a TODO to remove when we know more? https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... content/renderer/media/audio_input_message_filter.cc:215: LogMessage(stream_id_, "RecordStream"); see above https://codereview.chromium.org/495983002/diff/60001/content/renderer/media/a... content/renderer/media/audio_input_message_filter.cc:227: LogMessage(stream_id_, "CloseStream"); see above https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:230: base::StringPrintf("AIC::DoCreate(device_id=%s)", device_id.c_str()); Removing. Thanks. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:317: handler_->OnLog(this, "AIC::DoRecord"); Well, if it does that may very well be a reason why things go wrong and something we want to catch. Again, I am trying to see the full picture since I don't know what type of issue I am looking for ;-) https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:347: audio_manager_->RemoveStateChangeListener(this); It could but I can't really see the gain actually since we never NULL check it anyhow. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.cc:412: ? handler_->OnLog(this, "AIC::FirstCheckForNoData => data is active") I did run git cl format and this is what it gives me. Not sure if I should change it. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_input_... media/audio/audio_input_controller.h:311: media::AudioManager* audio_manager_; const media::AudioManager* audio_manager_ does not work actually since I am not allowed to add listeners then. Can't compile. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manager.h File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager.h:148: class StateChangeListener { I was thinking of asking Dale or Tommi for a second opinion, yes. Wanted OK from you guys first. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager.h:150: virtual void OnStateChange(const std::string state) = 0; On 2014/08/22 16:14:43, Henrik Grunell wrote: > const std::string& Done. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.cc:191: "MakeAudioInputStream(device_id=%s)", device_id.c_str()); Removed. But Shijing, we do log it at other places? Why is it not always a privacy concern? https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.cc:226: "MakeAudioInputStream => num_input_streams = %d", num_input_streams_); Thanks. Improved. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... File media/audio/audio_manager_base.h (right): https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.h:105: // TODO ---- Renamed and improved. Will need second opinion if this approach is OK as well. https://codereview.chromium.org/495983002/diff/60001/media/audio/audio_manage... media/audio/audio_manager_base.h:189: // Track ..... Will improve ;-)
I am planning to add some more (using the same style as here). Tommi, care to comment on the changes done in media/audio/audio_manager*? As stated in the comments, plan is not to maintain the code forever but to remove when we see if there are any issues related to how the audio input streams are created. Hope you are OK with the current way of adding notifiers for log strings.
Added some more logs but will pause until feedback from Tommi on the observer part in AudioManagerBase. If OK, my plan was to extend to AudioInputStream as well. Note that we need it since media/ can't do native logging directly due to dependency issues. I would like to add logging in the AudioInputStream class as well but I am not sure how to do that in a clean way. I could extend AudioInputStream::AudioInputCallback with one more callback but it is not set until in Start, hence I can't check construction and Close.
I am going to defer to Henrik and Tommi on if these loggings should be added to webrtc. Though my opinion is that they probably can be more compact. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (left): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:362: "Audio input stream created successfully. Device name: " + device_name); If we don't have any problem with the existing logging, I suggest not remove it. Other people might have been using this "Audio input stream created successfully" logging to determine if the stream is created successfully, removing it will confuse other people since different version of chrome will give different loggings. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:230: std::string err_msg = nit const std::string https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:306: oss << ": device_id=" << device_id << ", device_name=" << device_name; privacy concern. https://codereview.chromium.org/495983002/diff/120001/media/audio/audio_input... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/120001/media/audio/audio_input... media/audio/audio_input_controller.h:322: media::AudioManager* audio_manager_; const media::AudioManager*audio_manager_; won't work. Use media::AudioManager* const audio_manager_;
Thanks. I will remove all usage of device_id.
Thanks Shijing. Done changes based on your feedback. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (left): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:362: "Audio input stream created successfully. Device name: " + device_name); I think we need an improved way of reading the error log where the new way allows for filtering. The new log will still contain this info, just in a new format. Hope that is OK. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:230: std::string err_msg = On 2014/08/26 08:38:08, xians1 wrote: > nit const std::string Done. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:306: oss << ": device_id=" << device_id << ", device_name=" << device_name; Removed device_id. https://codereview.chromium.org/495983002/diff/120001/media/audio/audio_input... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/120001/media/audio/audio_input... media/audio/audio_input_controller.h:322: media::AudioManager* audio_manager_; On 2014/08/26 08:38:08, xians1 wrote: > const media::AudioManager*audio_manager_; won't work. > Use media::AudioManager* const audio_manager_; > Done.
Thanks Shijing. Done changes based on your feedback. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (left): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:362: "Audio input stream created successfully. Device name: " + device_name); I think we need an improved way of reading the error log where the new way allows for filtering. The new log will still contain this info, just in a new format. Hope that is OK. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:230: std::string err_msg = On 2014/08/26 08:38:08, xians1 wrote: > nit const std::string Done. https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:306: oss << ": device_id=" << device_id << ", device_name=" << device_name; Removed device_id. https://codereview.chromium.org/495983002/diff/120001/media/audio/audio_input... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/120001/media/audio/audio_input... media/audio/audio_input_controller.h:322: media::AudioManager* audio_manager_; On 2014/08/26 08:38:08, xians1 wrote: > const media::AudioManager*audio_manager_; won't work. > Use media::AudioManager* const audio_manager_; > Done.
https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (left): https://codereview.chromium.org/495983002/diff/120001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:362: "Audio input stream created successfully. Device name: " + device_name); On 2014/08/26 10:30:10, henrika wrote: > I think we need an improved way of reading the error log where the new way > allows for filtering. The new log will still contain this info, just in a new > format. Hope that is OK. To be clear, the new log will still contain the string as: Audio input stream created successfully. Device name: xxxxx If so, then it is fine. otherwise I will highly suggest keeping the existing log, so that we won't surprise the ML team.
tommi@chromium.org changed reviewers: + dalecurtis@chromium.org
+Dale since this is modifying audiomanager. I personally think this is stretching things a bit as far as adding printf style debugging facilities to Chrome for marginal convenience of perhaps not so many developers. At the very least we should be careful to not bloat release builds with string building debug code. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:23: void LogMessage(int stream_id, std::string msg, bool add_prefix) { const & https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:24: std::string log_string = instead of constructing strings and using StringPrintf, you could use a string stream. That delays the construction of the string until it's actually needed. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:29: DVLOG(1) << log_string; Since this is a DVLOG, this whole function should only exist in debug builds. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:213: return; should this be considered an error case or is it expected? If expected, can you add a comment for when this happens? https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:222: entry->num_no_data_errors++; is num_no_data_errors only used in debug builds? If so, you could add a method to AudioEntry that's empty in release builds but in debug builds does a few different things: - DCHECKs that the member variable is being touched on the correct thread. - increments the member variable - if > 5, log one thing, else log the other thing. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:224: LogMessage(entry->stream_id, "AIC => stream looks dead", false); what about logging num_no_data_errors? https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:231: base::StringPrintf("AIC reports error_code=%d", error_code); this should be debug only https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:277: SendErrorMessage(stream_id, STREAM_ALREADY_EXISTS); would we want to call SendMessageToNativeLog() in this case or below when/if GetOpenedDeviceInfoById fails? https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:309: DVLOG(1) << oss.str(); nit: don't think you need the |.str()| part https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:421: std::string err_msg = debug only https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... File content/renderer/media/audio_input_message_filter.cc (right): https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:16: void LogMessage(int stream_id, std::string msg) { const & https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:17: std::string log_string = use ostringstream https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:21: DVLOG(1) << log_string; this method should only have an implementation in debug builds https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... media/audio/audio_input_controller.cc:411: GetDataIsActive() instead of having two call sites for OnLog, do the ?: check inside the call to OnLog: handler_->OnLog(this, GetDataIsActive() : "string1" : "string2"); https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... media/audio/audio_input_controller.h:238: virtual void OnStateChange(const std::string& state) OVERRIDE; having |state| be a string is a bit strange... https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... media/audio/audio_manager.h:157: virtual void OnStateChange(const std::string& state) = 0; Having |state| be a string is not what I'd expect. Should/can this be an enum? If not then it sounds like this is more of a logging specific function. Is it only to be used for DLOGing stuff or is this for the webrtc log? If the former, I'd like to avoid having an interface for it cause this is stretching the architecture to include ad-hoc printf tracing for developers, but if this is for the webrtc log, let's make that very clear... and if that's really the case, I'm not sure it belongs in AudioManager :-/ https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... media/audio/audio_manager_base.cc:192: std::ostringstream oss; doesn't look like you need an ostringstream for this. https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... File media/audio/audio_manager_base.h (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... media/audio/audio_manager_base.h:188: // Track ..... fix?
Thanks Tommi. Added one general question to you but did not make any changes at this stage. Waiting for feedback from Dale as well before I do any further changes. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:29: DVLOG(1) << log_string; Not sure if I understand. I want the add native WebRTC logging always but also add a DVLOG for local debugging.
Hmm, you use SendMessageToNativeLog() in AudioRendererHost, while the AudioInputMessageFilter uses WebRtcLogMessage(), on top of that we've got the AudioLog code in AIRH writing data to chrome://media-internals. I don't think we should be spreading the logging across multiple subsystems like this. We should instead have it all go to a single point where it can be filtered and accessed. Ideally I'd love to see all this information on chrome://media-internals under the created audio controller. Even better would be the listing there including the title of the tab using the stream (plus some counter for multiple streams of course). It's also kind of unusual to DVLOG() these messages if it's going to be present inside some internal log system anyways. https://codereview.chromium.org/495983002/diff/160001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_sync_writer.cc (right): https://codereview.chromium.org/495983002/diff/160001/content/browser/rendere... content/browser/renderer_host/media/audio_input_sync_writer.cc:59: std::ostringstream oss; Hmm, since this is called at a high frequency you should move this into a function that is only called when oss will be updated. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager.h:148: // It is possible to register listeners for logging of important state I don't understand why this is necessary? AudioInputController can already get DeviceChange notifications. What other state change events are you sending? https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager_base.cc:195: NotifyAllStateChangeListeners(oss.str()); This seems wrong. Only the creating controller should get this information. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager_base.cc:201: oss << "MakeAudioInputStream => " Ditto. All this is doing is spamming all listeners, of which there may be many. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager_base.cc:333: std::string log_string = base::StringPrintf( Further, none of this is actually a state change, it's merely an action log which corresponds to a single controller.
Thanks Dale. I hear you and just want to make some explanations before I change the CL. The way we send logging to native logs has been discussed for months and has landed as is; I can't start changing that now. Yes, there are two different ways: one for the render process and one for the browser. I don't have the full background to comment on why it is as is. The intention of this CL is to add logs that will allow us to figure out why audio is often missing in WebRTC clients, especially on Mac. All we know today is that we get informed about "no data" but have no clue why that is. The parts in the AudioManager is new stuff and I will remove that. The rest of the code is copy-paste of what's done already. Bad excuse but that's how it is. So, as a compromise I will start by removing the bad state listener I added in AMB and take it from the there. Hope that sounds OK. One more, any added DVLOG is to be able to match whats added to the native log locally without having to download a log result, unzip and then view. That's all.
On 2014/08/27 10:51:06, henrika wrote: > Thanks Dale. I hear you and just want to make some explanations before I change > the CL. > > The way we send logging to native logs has been discussed for months and has > landed as is; I can't start changing that now. Yes, there are two different > ways: one for the render process and one for the browser. I don't have the full > background to comment on why it is as is. > > The intention of this CL is to add logs that will allow us to figure out why > audio is often missing in WebRTC clients, especially on Mac. All we know today > is that we get informed about "no data" but have no clue why that is. The parts > in the AudioManager is new stuff and I will remove that. The rest of the code > is copy-paste of what's done already. Bad excuse but that's how it is. > > So, as a compromise I will start by removing the bad state listener I added in > AMB and take it from the there. Hope that sounds OK. > > One more, any added DVLOG is to be able to match whats added to the native log > locally without having to download a log result, unzip and then view. That's > all. Yeah, the function in the renderer forwards the logs to the browser. Re: my first question, whether we're sure the added logs are useful, and the reply: my understanding is that this is an experimental addition to evaluate if it helps us, if not remove logs. I haven't been involved that much in the audio pipeline details, but if this is the best way forward I think we must ensure that we do evaluate the usefulness and do remove logs. Maybe file a bug with a milestone for that if we go ahead? Todos on all logs we're not sure of? The reason I'm hesitating is that we can end up with a monster and we don't want that. :)
Cleaned up by removing AudioManager from this CL. Henrik G, the problem is that we have a long list of reports all saying that "audio is missing" but we have no idea why it happens. If I knew why I did not need any logs. And yes, I did add a TODO in this CL to remove as we learn. Will take it another spin next using feedback from Tommi and Dale.
Changes based on input from Tommi. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:23: void LogMessage(int stream_id, std::string msg, bool add_prefix) { On 2014/08/26 11:42:30, tommi wrote: > const & Done. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:29: DVLOG(1) << log_string; Discussed off-line. Seems like we are in phase on this one. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:213: return; Good comment. Old style that I've reused here. "Should not happen" but can happen if the caller (AudioInputController) can't be found in the map which contains all AICs this AIRH has created. Hence, call comes from a "bad AIC". Same style can be found on ~8 different places. Audio Output Renderer Host does: AudioEntry* const entry = LookupById(stream_id); if (!entry) return; Actually, it is not clear to me why this safety was added or if it is even needed. Let me give it a try. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:222: entry->num_no_data_errors++; Thx, given where we are I decided to remove it. It was a "nice-to-have" thing that improved reading of the logs but does not add any new information. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:224: LogMessage(entry->stream_id, "AIC => stream looks dead", false); see above https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:231: base::StringPrintf("AIC reports error_code=%d", error_code); A similar log is used today in Release. Would like to keep since we do see it a lot. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:277: SendErrorMessage(stream_id, STREAM_ALREADY_EXISTS); Yes, and we do since it is included in SendErrorMessage ;-) https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:309: DVLOG(1) << oss.str(); On 2014/08/26 11:42:30, tommi wrote: > nit: don't think you need the |.str()| part Done. https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:421: std::string err_msg = As discussed off-line. Plan was to keep as is since we need it for release as well. https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... File content/renderer/media/audio_input_message_filter.cc (right): https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:16: void LogMessage(int stream_id, std::string msg) { On 2014/08/26 11:42:30, tommi wrote: > const & Done. https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:17: std::string log_string = On 2014/08/26 11:42:30, tommi wrote: > use ostringstream Done. https://codereview.chromium.org/495983002/diff/140001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:21: DVLOG(1) << log_string; Commented before. https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... media/audio/audio_input_controller.cc:411: GetDataIsActive() On 2014/08/26 11:42:30, tommi wrote: > instead of having two call sites for OnLog, do the ?: check inside the call to > OnLog: > > handler_->OnLog(this, GetDataIsActive() : "string1" : "string2"); Done. https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... File media/audio/audio_input_controller.h (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_input... media/audio/audio_input_controller.h:238: virtual void OnStateChange(const std::string& state) OVERRIDE; Removed. https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... media/audio/audio_manager.h:157: virtual void OnStateChange(const std::string& state) = 0; Removed! https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... media/audio/audio_manager_base.cc:192: std::ostringstream oss; Removed https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... File media/audio/audio_manager_base.h (right): https://codereview.chromium.org/495983002/diff/140001/media/audio/audio_manag... media/audio/audio_manager_base.h:188: // Track ..... On 2014/08/26 11:42:31, tommi wrote: > fix? Done.
All comments from Dale are addressed by the last check-in as well. https://codereview.chromium.org/495983002/diff/160001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_sync_writer.cc (right): https://codereview.chromium.org/495983002/diff/160001/content/browser/rendere... content/browser/renderer_host/media/audio_input_sync_writer.cc:59: std::ostringstream oss; Sorry, not sure if I follow. I have not changed anything here just some plain text changes. Not sure what you propose actually and what it would save. Care to elaborate? The if (!oss.str().empty()) {} scope will only be triggered under error conditions. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... File media/audio/audio_manager.h (right): https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager.h:148: // It is possible to register listeners for logging of important state Removed. Thanks. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... File media/audio/audio_manager_base.cc (right): https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager_base.cc:195: NotifyAllStateChangeListeners(oss.str()); On 2014/08/26 20:09:29, DaleCurtis wrote: > This seems wrong. Only the creating controller should get this information. Done. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager_base.cc:201: oss << "MakeAudioInputStream => " On 2014/08/26 20:09:29, DaleCurtis wrote: > Ditto. All this is doing is spamming all listeners, of which there may be many. Done. https://codereview.chromium.org/495983002/diff/160001/media/audio/audio_manag... media/audio/audio_manager_base.cc:333: std::string log_string = base::StringPrintf( On 2014/08/26 20:09:29, DaleCurtis wrote: > Further, none of this is actually a state change, it's merely an action log > which corresponds to a single controller. Done.
CL is now condensed and cleaned up. Was hoping for some more comments before I do more work. Tommi felt I should do this and then we can see if more work is needed. Hence, PTAL.
Dale, no more AM.... guess you are off the hook then ;-)
https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/140001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:309: DVLOG(1) << oss.str(); Actually we do. No log is printed otherwise.
lgtm. We should file a bug to clean all this up once we get to the bottom of the problems we're trying to solve now. This bloats the code quite a bit. https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... media/audio/audio_input_controller.cc:267: } fix https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... media/audio/audio_input_controller.cc:423: ? "AIC::FirstCheckForNoData => data is active" nit: I think the convention is to have operators at end of the previous line (see e.g. a couple of lines above).
some nits. lgtm if you address them. https://codereview.chromium.org/495983002/diff/280001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/280001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:23: void LogMessage(int stream_id, const std::string& msg, bool add_prefix) { nit, empty line after the namespace { https://codereview.chromium.org/495983002/diff/280001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:32: } ditto https://codereview.chromium.org/495983002/diff/280001/content/renderer/media/... File content/renderer/media/audio_input_message_filter.cc (right): https://codereview.chromium.org/495983002/diff/280001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:15: namespace { combine this anonymous namespace with the existing anonymous namespace in line 27 https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:231: if (handler_) { nit, you don't need {} here https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:240: last_audio_level_log_time_ = base::TimeTicks::Now(); great. https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:268: } ?? https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:423: GetDataIsActive() shouldn't the format be like GetDataIsActive() ? "AIC::FirstCheckForNoData => data is active" : "AIC::FirstCheckForNoData => data is NOT active");
Fixes based on feedback from Tommi first. Filed crbug.com/408967 to keep track of "remove logging when not needed". PS, not sure what to do with style proposed by git cl format which is not inline with review comment. https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... media/audio/audio_input_controller.cc:267: } On 2014/08/29 11:32:03, tommi wrote: > fix Done. https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... media/audio/audio_input_controller.cc:423: ? "AIC::FirstCheckForNoData => data is active" Actually, it was git cl format which did it ;-)
Thanks Shijing. Will try to land. https://codereview.chromium.org/495983002/diff/280001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/280001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:23: void LogMessage(int stream_id, const std::string& msg, bool add_prefix) { On 2014/08/29 12:33:20, xians1 wrote: > nit, empty line after the namespace { Done. https://codereview.chromium.org/495983002/diff/280001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:32: } On 2014/08/29 12:33:20, xians1 wrote: > ditto Done. https://codereview.chromium.org/495983002/diff/280001/content/renderer/media/... File content/renderer/media/audio_input_message_filter.cc (right): https://codereview.chromium.org/495983002/diff/280001/content/renderer/media/... content/renderer/media/audio_input_message_filter.cc:15: namespace { On 2014/08/29 12:33:20, xians1 wrote: > combine this anonymous namespace with the existing anonymous namespace in line > 27 Done. https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:231: if (handler_) { On 2014/08/29 12:33:20, xians1 wrote: > nit, you don't need {} here Done. https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:240: last_audio_level_log_time_ = base::TimeTicks::Now(); thanks ;-) https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:268: } On 2014/08/29 12:33:20, xians1 wrote: > ?? Done. https://codereview.chromium.org/495983002/diff/280001/media/audio/audio_input... media/audio/audio_input_controller.cc:423: GetDataIsActive() Tried that but git cl format keeps changing it back...
The CQ bit was checked by henrika@chromium.org
CQ is trying da patch. Follow status at https://chromium-status.appspot.com/cq/henrika@chromium.org/495983002/320001
lgtm https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/240001/media/audio/audio_input... media/audio/audio_input_controller.cc:423: ? "AIC::FirstCheckForNoData => data is active" On 2014/08/29 12:39:37, henrika wrote: > Actually, it was git cl format which did it ;-) Ah well, here's an example of where git cl format is going against the convention. So, thanks for fixing. https://codereview.chromium.org/495983002/diff/260001/media/audio/audio_input... File media/audio/audio_input_controller.cc (right): https://codereview.chromium.org/495983002/diff/260001/media/audio/audio_input... media/audio/audio_input_controller.cc:240: last_audio_level_log_time_ = base::TimeTicks::Now(); Nice. Perhaps we should file a bug for this issue so that we can track it and fix it with this cl.
LGTM. Thanks for cleaning up. A general readability detail opinion. I interpret "A => B" as "A leads/led to B". Maybe it's only me, but I actually get a little confused when that's not the case when I read the code. You don't have to do more changes in this CL, just my input. https://codereview.chromium.org/495983002/diff/320001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/320001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:29: oss << msg; I'm not sure how this is supposed to be formatted. Seems like it will be "[stream_id=1] AIRH::This is a log message." Isn't the :: strange in this case? Maybe prefix "AIRH: "?
Message was sent while issue was closed.
Committed patchset #17 (id:320001) as e0f6ed64804183c90ff97ffda2825db5580d8cbf
Message was sent while issue was closed.
Tommi, still valid to file a bug (CL landed before I read you comment)? Guess I must link it manually somehow then, right? Henrik G, will try to address your comments in a trivial followup. Sorry for not checking with you before => CQ ;-) https://codereview.chromium.org/495983002/diff/320001/content/browser/rendere... File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): https://codereview.chromium.org/495983002/diff/320001/content/browser/rendere... content/browser/renderer_host/media/audio_input_renderer_host.cc:29: oss << msg; Good comment. Almost all messages starts with funcname, hence :: makes sense. But there are some that does not. Will fix in separate CL.
Message was sent while issue was closed.
On 2014/08/29 14:05:14, henrika wrote: > Tommi, still valid to file a bug (CL landed before I read you comment)? Guess I > must link it manually somehow then, right? > > Henrik G, will try to address your comments in a trivial followup. Sorry for not > checking with you before => CQ ;-) Great. :) > > https://codereview.chromium.org/495983002/diff/320001/content/browser/rendere... > File content/browser/renderer_host/media/audio_input_renderer_host.cc (right): > > https://codereview.chromium.org/495983002/diff/320001/content/browser/rendere... > content/browser/renderer_host/media/audio_input_renderer_host.cc:29: oss << msg; > Good comment. Almost all messages starts with funcname, hence :: makes sense. > But there are some that does not. Will fix in separate CL.
Fwiw => also has a different meaning (leads to or eq+gt) to me than how it's used in the log statements so if more feel that way we should keep that in mind as we update it. On Aug 29, 2014 4:23 PM, <grunell@chromium.org> wrote: > On 2014/08/29 14:05:14, henrika wrote: > >> Tommi, still valid to file a bug (CL landed before I read you comment)? >> Guess >> > I > >> must link it manually somehow then, right? >> > > Henrik G, will try to address your comments in a trivial followup. Sorry >> for >> > not > >> checking with you before => CQ ;-) >> > > Great. :) > > > > https://codereview.chromium.org/495983002/diff/320001/ > content/browser/renderer_host/media/audio_input_renderer_host.cc > >> File content/browser/renderer_host/media/audio_input_renderer_host.cc >> (right): >> > > > https://codereview.chromium.org/495983002/diff/320001/ > content/browser/renderer_host/media/audio_input_renderer_host.cc#newcode29 > >> content/browser/renderer_host/media/audio_input_renderer_host.cc:29: oss >> << >> > msg; > >> Good comment. Almost all messages starts with funcname, hence :: makes >> sense. >> But there are some that does not. Will fix in separate CL. >> > > > > https://codereview.chromium.org/495983002/ > To unsubscribe from this group and stop receiving emails from it, send an email to chromium-reviews+unsubscribe@chromium.org.
Message was sent while issue was closed.
henrika@chromium.org changed reviewers: - dalecurtis@chromium.org
Message was sent while issue was closed.
Patchset 17 (id:??) landed as https://crrev.com/8eec55ab69fe94838dc7a0e5d23102423d54ac76 Cr-Commit-Position: refs/heads/master@{#292622} |
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
