Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
1236543007:
MSE: Log buffered audio splice generation to media-internals (Closed)
|
Created:
5 years, 5 months ago by wolenetz Modified:
5 years, 5 months ago CC:
chromium-reviews, mlamouri+watch-content_chromium.org, posciak+watch_chromium.org, jam, mcasas+watch_chromium.org, feature-media-reviews_chromium.org, darin-cc_chromium.org, mkwst+moarreviews-renderer_chromium.org, wjia+watch_chromium.org Base URL:
https://chromium.googlesource.com/chromium/src.git@master Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionMSE: Log buffered audio splice generation to media-internals
Uses MediaLog to log a limited number of buffered audio splice
frame generation warnings and successes to chrome://media-internals.
BUG=492833, 490144, 505931, 482085
R=dalecurtis@chromium.org,chcunningham@chromium.org,xhwang@chromium.org
TEST=Manual
Committed: https://crrev.com/2bf99047afc7d15fb3a301c1ee5c2e6c06be9ee1
Cr-Commit-Position: refs/heads/master@{#339341}
Patch Set 1 #
Total comments: 8
Patch Set 2 : Use LIMITED_MEDIA_LOG instead: simpler impl and more log detail #
Total comments: 10
Patch Set 3 : Address comments from PS2 #
Messages
Total messages: 38 (13 generated)
wolenetz@chromium.org changed reviewers: + xhwang@chromium.org
Please take a look at patch set 1: dalecurtis@: everything, committer, splicer creator xhwang@: please review from perspective of media-internals potential log spam chcunningham@: everything, too (MSE-related) Thanks! Details: I've updated bug 490144 and bug 505931 with some data resulting from repros with this CL applied locally. Also, for a quick play attempt on YT, I did not see any buffered splice creation of any kind. https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... File content/browser/media/media_internals.cc (right): https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... content/browser/media/media_internals.cc:650: for (auto iter = pending_events.begin(); iter != pending_events.end(); This isn't a very efficient mechanism for enforcing at-most-one. wdyt? https://codereview.chromium.org/1236543007/diff/1/content/browser/resources/m... File content/browser/resources/media/main.js (right): https://codereview.chromium.org/1236543007/diff/1/content/browser/resources/m... content/browser/resources/media/main.js:169: key === 'audio_splice_count' || Likewise, this isn't a very efficient mechanism for filtering out. This could perhaps be changed in a separate CL to have some flag per-event-type populated by MediaLog such that the code here just needs to inspect a boolean instead of a bunch of string matching. wdyt?
The CQ bit was checked by wolenetz@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1236543007/1
I'm not sure we need to log all these with such detail, why not just log the error messages that already in each of these places with a limited log? Also, these technically aren't degenerate splices in the truest sense, since they are aborted early (without config change). A true degenerate splice makes it all the way through decoding and to rendering before being aborted: https://code.google.com/p/chromium/codesearch#chromium/src/media/base/audio_s... Splices aborted at this stage are harmless as far as I know, did you find this to be untrue? https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... File content/browser/media/media_internals.cc (right): https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... content/browser/media/media_internals.cc:650: for (auto iter = pending_events.begin(); iter != pending_events.end(); On 2015/07/14 23:23:37, wolenetz wrote: > This isn't a very efficient mechanism for enforcing at-most-one. wdyt? I think you want to do something similar to what RendererMediaLog does and just drop these events instead of saving them if media internals isn't open. https://codereview.chromium.org/1236543007/diff/1/content/browser/resources/m... File content/browser/resources/media/main.js (right): https://codereview.chromium.org/1236543007/diff/1/content/browser/resources/m... content/browser/resources/media/main.js:169: key === 'audio_splice_count' || On 2015/07/14 23:23:37, wolenetz wrote: > Likewise, this isn't a very efficient mechanism for filtering out. This could > perhaps be changed in a separate CL to have some flag per-event-type populated > by MediaLog such that the code here just needs to inspect a boolean instead of a > bunch of string matching. wdyt? I think this is long enough that we want a global const and to check if (key in <const>) instead of all these checks. https://codereview.chromium.org/1236543007/diff/1/media/base/media_log.h File media/base/media_log.h (right): https://codereview.chromium.org/1236543007/diff/1/media/base/media_log.h#newc... media/base/media_log.h:29: // Captures the parameter detail of a BUFFERED_AUDIO_SPLICE_STATISTICS_CHANGED Instead of adding a class for this, do we just want to serialize a dict object over the wire? I.e., don't have this class, just store this info in the splicer itself and call a function (count, degenerate_count, duration, min_duration, max_duration) https://codereview.chromium.org/1236543007/diff/1/media/base/media_log.h#newc... media/base/media_log.h:36: double total_duration, Why not TimeDelta for all these?
On 2015/07/14 23:37:47, DaleCurtis wrote: > I'm not sure we need to log all these with such detail, why not just log the > error messages that already in each of these places with a limited log? Also, > these technically aren't degenerate splices in the truest sense, since they are > aborted early (without config change). > > A true degenerate splice makes it all the way through decoding and to rendering > before being aborted: > > https://code.google.com/p/chromium/codesearch#chromium/src/media/base/audio_s... > > Splices aborted at this stage are harmless as far as I know, did you find this > to be untrue? > > https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... > File content/browser/media/media_internals.cc (right): > > https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... > content/browser/media/media_internals.cc:650: for (auto iter = > pending_events.begin(); iter != pending_events.end(); > On 2015/07/14 23:23:37, wolenetz wrote: > > This isn't a very efficient mechanism for enforcing at-most-one. wdyt? > > I think you want to do something similar to what RendererMediaLog does and just > drop these events instead of saving them if media internals isn't open. > > https://codereview.chromium.org/1236543007/diff/1/content/browser/resources/m... > File content/browser/resources/media/main.js (right): > > https://codereview.chromium.org/1236543007/diff/1/content/browser/resources/m... > content/browser/resources/media/main.js:169: key === 'audio_splice_count' || > On 2015/07/14 23:23:37, wolenetz wrote: > > Likewise, this isn't a very efficient mechanism for filtering out. This could > > perhaps be changed in a separate CL to have some flag per-event-type populated > > by MediaLog such that the code here just needs to inspect a boolean instead of > a > > bunch of string matching. wdyt? > > I think this is long enough that we want a global const and to check if (key in > <const>) instead of all these checks. > > https://codereview.chromium.org/1236543007/diff/1/media/base/media_log.h > File media/base/media_log.h (right): > > https://codereview.chromium.org/1236543007/diff/1/media/base/media_log.h#newc... > media/base/media_log.h:29: // Captures the parameter detail of a > BUFFERED_AUDIO_SPLICE_STATISTICS_CHANGED > Instead of adding a class for this, do we just want to serialize a dict object > over the wire? I.e., don't have this class, just store this info in the splicer > itself and call a function (count, degenerate_count, duration, min_duration, > max_duration) > > https://codereview.chromium.org/1236543007/diff/1/media/base/media_log.h#newc... > media/base/media_log.h:36: double total_duration, > Why not TimeDelta for all these? Yeah, LIMITED MEDIA LOG is probably good enough for now. I'll update this CL in the morning to greatly simplify it.
I am not familiar with audio splice so I'll defer to dalecurtis to review that part. Just some general comments for discussion. https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... File content/browser/media/media_internals.cc (right): https://codereview.chromium.org/1236543007/diff/1/content/browser/media/media... content/browser/media/media_internals.cc:650: for (auto iter = pending_events.begin(); iter != pending_events.end(); On 2015/07/14 23:37:47, DaleCurtis wrote: > On 2015/07/14 23:23:37, wolenetz wrote: > > This isn't a very efficient mechanism for enforcing at-most-one. wdyt? > > I think you want to do something similar to what RendererMediaLog does and just > drop these events instead of saving them if media internals isn't open. Maybe it's time to drop all DEBUG logs when the UI is not open? https://codereview.chromium.org/1236543007/diff/1/media/base/media_log_event.h File media/base/media_log_event.h (right): https://codereview.chromium.org/1236543007/diff/1/media/base/media_log_event.... media/base/media_log_event.h:90: BUFFERED_AUDIO_SPLICE_STATISTICS_CHANGED, +dalecurtis When I first looked at this list (Type), I found it a bit arbitrary. For example, what's the fundamental difference between an event with a specialized "type", and those general ERROR/INFO/DEBUG events below? Somehow I feel we have two systems here. Can we simply replace the "Type type" with a "string type" so that we don't need most of this list here? The downside is that we'll need to send a "type" string over the wire instead of a "type" integer, but that should be small compared to the whole data we are sending. We can still keep ERROR/INFO/DEBUG as log "Level"s so that we can filter them if we need to.
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: win8_chromium_ng on tryserver.chromium.win (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.win/builders/win8_chromium_ng/...)
Waiting for the coming simplification before I get started!
The CQ bit was checked by wolenetz@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1236543007/20001
Thanks for the comments. Please review patch set 2, which IMO is better (not just simpler) because it provides some greater explanation in explicit log entries to help diagnose potential content problems. The previous patch set's statistics were only marginally useful (really, the count of "degenerate" was a leading indicator of potential problems later during decode). The simplification in patch set 2 doesn't address the comments about MediaLog event type enum vs something else because a new event type is no longer in scope of this change. I suspect a more OO approach to event types might help (e.g., make each event type a specialization instead of an enum entry), but serialization/deserialization from/to such objects would still require essentially something like the enum, right?
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: This issue passed the CQ dry run.
Also, I wonder if the log messages in patch set 2 could be improved: instead of "generating splice", how about "pre-decode splice detected" or [something better....]?
https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... File media/filters/source_buffer_stream.cc (right): https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:51: static int kDefaultBufferDurationInMs = 125; These three should all be marked const. https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:53: // Limit the number of MEDIA_LOG() logs for splice buffer generation warnings I feel like these will be hit really fast. https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:1564: << "Skipping splice frame buffering: first new buffer at " s/buffering/generation/ ditto for all the rest. https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:1568: DVLOG(1) << "Skipping splice: overlapped buffers begin at or after the " Do we need both of these?
lgtm https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... File media/filters/source_buffer_stream.cc (right): https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:53: // Limit the number of MEDIA_LOG() logs for splice buffer generation warnings On 2015/07/16 20:39:21, DaleCurtis wrote: > I feel like these will be hit really fast. I wouldn't have guessed so. Do you expect we have a lot of splicing out there in the wild? I guess, for people that intentionally splice, they may splice a lot (play music). But 5 unintentional splices seems like a lot, no?
Thanks for comments. dalecurtis@ and xhwang@: Please take a look at patch set 3. https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... File media/filters/source_buffer_stream.cc (right): https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:51: static int kDefaultBufferDurationInMs = 125; On 2015/07/16 20:39:22, DaleCurtis wrote: > These three should all be marked const. Good catch! I've converted these to enum values, and put all of these impl statics into an unnamed namespace. https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:53: // Limit the number of MEDIA_LOG() logs for splice buffer generation warnings On 2015/07/17 01:36:26, chcunningham wrote: > On 2015/07/16 20:39:21, DaleCurtis wrote: > > I feel like these will be hit really fast. > > I wouldn't have guessed so. Do you expect we have a lot of splicing out there in > the wild? I guess, for people that intentionally splice, they may splice a lot > (play music). But 5 unintentional splices seems like a lot, no? I think there is room to increase, though there is a trade-off. Increasing these values in release builds is nigh impossible, so if they are too low, the value of these logs to developers (instead of just debug-build + DVLOGs) is greatly reduced. Badly muxed media is unfortunately causing pain to multiple developers due to downstream decode errors in audio splice sanitizers, and more of these logs upstream when the buffers are appended will help. However, we don't want to exhaust the saved event cache (currently 128 events) in media-internals. I've increased these values to 50 and 20, respectively, and added a comment. I'm beginning to wonder if, instead of not emitting logs (and reducing IPC churn), media-internals itself should own the policy of capping various log types. Then, no caps would be applied to logs being rendered real-time to chrome://media-internals, but caps could simultaneously be applied to the events being saved (for later chrome://media-internals viewing or tab refresh). This seems a more flexible approach, allowing developers who really need uncapped log events to get them if they first open a media-internals. xhwang@: would the specific player in chrome://media-internals need to be opened first, too? (This idea is out of scope of this CL, but I think might be quite helpful.) https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:1564: << "Skipping splice frame buffering: first new buffer at " On 2015/07/16 20:39:22, DaleCurtis wrote: > s/buffering/generation/ ditto for all the rest. Done https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:1568: DVLOG(1) << "Skipping splice: overlapped buffers begin at or after the " On 2015/07/16 20:39:21, DaleCurtis wrote: > Do we need both of these? I think the DVLOGs have value still (in the LIMITED_MEDIA_LOG case, but not really if we used uncapped MEDIA_LOG): If a developer exceeded the LIMITED_MEDIA_LOG cap, but had a debug build, no change other than cmdline including something like --v=1 --vmodule=source_buffer_stream*=1,*=0 would be needed to still get some log detail here. I went with similar approach previously in the AudioSplicer LIMITED_MEDIA_LOG CL's warning logs (https://codereview.chromium.org/1229123002/diff/20001/media/base/audio_splice...).
lgtm https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... File media/filters/source_buffer_stream.cc (right): https://codereview.chromium.org/1236543007/diff/20001/media/filters/source_bu... media/filters/source_buffer_stream.cc:53: // Limit the number of MEDIA_LOG() logs for splice buffer generation warnings On 2015/07/17 17:38:15, wolenetz_OoO_July_17_PM_PDT wrote: > On 2015/07/17 01:36:26, chcunningham wrote: > > On 2015/07/16 20:39:21, DaleCurtis wrote: > > > I feel like these will be hit really fast. > > > > I wouldn't have guessed so. Do you expect we have a lot of splicing out there > in > > the wild? I guess, for people that intentionally splice, they may splice a lot > > (play music). But 5 unintentional splices seems like a lot, no? > > I think there is room to increase, though there is a trade-off. Increasing these > values in release builds is nigh impossible, so if they are too low, the value > of these logs to developers (instead of just debug-build + DVLOGs) is greatly > reduced. Badly muxed media is unfortunately causing pain to multiple developers > due to downstream decode errors in audio splice sanitizers, and more of these > logs upstream when the buffers are appended will help. However, we don't want to > exhaust the saved event cache (currently 128 events) in media-internals. I've > increased these values to 50 and 20, respectively, and added a comment. > > I'm beginning to wonder if, instead of not emitting logs (and reducing IPC > churn), media-internals itself should own the policy of capping various log > types. Then, no caps would be applied to logs being rendered real-time to > chrome://media-internals, but caps could simultaneously be applied to the events > being saved (for later chrome://media-internals viewing or tab refresh). This > seems a more flexible approach, allowing developers who really need uncapped log > events to get them if they first open a media-internals. xhwang@: would the > specific player in chrome://media-internals need to be opened first, too? (This > idea is out of scope of this CL, but I think might be quite helpful.) Yes I definitely think we need a more programmatic limit. What ffmpeg does would be fine (last message repeats x times)
The CQ bit was checked by wolenetz@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1236543007/40001
rs lgtm :)
The CQ bit was unchecked by wolenetz@chromium.org
The CQ bit was checked by wolenetz@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from chcunningham@chromium.org Link to the patchset: https://codereview.chromium.org/1236543007/#ps40001 (title: "Address comments from PS2")
Thanks for reviews. I've filed bug 511362 regarding the discussion about changing the log capping to log coalescing (+maybe some capping if still needed).
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1236543007/40001
The CQ bit was unchecked by commit-bot@chromium.org
Try jobs failed on following builders: linux_chromium_chromeos_rel_ng on tryserver.chromium.linux (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_...)
The CQ bit was checked by wolenetz@chromium.org
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1236543007/40001
The CQ bit was unchecked by commit-bot@chromium.org
Try jobs failed on following builders: win8_chromium_ng on tryserver.chromium.win (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.win/builders/win8_chromium_ng/...)
The CQ bit was checked by wolenetz@chromium.org
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1236543007/40001
Message was sent while issue was closed.
Committed patchset #3 (id:40001)
Message was sent while issue was closed.
Patchset 3 (id:??) landed as https://crrev.com/2bf99047afc7d15fb3a301c1ee5c2e6c06be9ee1 Cr-Commit-Position: refs/heads/master@{#339341} |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
