Add MediaError.message

content/renderer/media/render_media_log.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "content/renderer/media/render_media_log.h"
 
 #include <sstream>
 
 #include "base/bind.h"
 #include "base/location.h"
@@ skipping 74 matching lines @@
         // SendQueuedMediaEvents() will enqueue the most recent event of this
         // kind, if any, prior to sending the event batch.
         break;
 
       case media::MediaLogEvent::DURATION_SET:
         // Similar to the extents changed message, this may fire many times for
         // badly muxed media. Suppress within our rate limits here.
         last_duration_changed_event_.swap(event);
         break;
 
-      // Hold onto the most recent PIPELINE_ERROR and MEDIA_LOG_ERROR_ENTRY for
-      // use in GetLastErrorMessage().
+      // Hold onto the most recent PIPELINE_ERROR and the first, if any,

[DaleCurtis, 2017/04/20 20:57:13]

I thought we wanted the earliest one ?

[wolenetz, 2017/04/20 21:09:03]

Interesting. I hadn't considered that we might report a sequence of different
pipeline errors, too, for a single eventual MediaError instance. Like the first
MEDIA_ERROR_LOG_ENTRY, would the first PIPELINE_ERROR event also be the most
specific?

[wolenetz, 2017/04/20 21:23:40]

I dug a little further: it looks like we only report at most one PIPELINE_ERROR
event currently before top-level error is determined, causing MediaError.message
creation from the result of this method. That PIPELINE_ERROR event originates
only in WMPI at
https://cs.chromium.org/chromium/src/media/blink/webmediaplayer_impl.cc?rcl=a...
which is also the location from where WebMediaPlayerClient is signalled that
there is a top-level error. So I think we're ok here.

The discussion we previously had about multiple error messages was specific (I
thought) to MEDIA_LOG_ERROR_ENTRY events, where the first of those would be the
most precise. It appears that remains correct. And even if there were multiple
PIPELINE_ERRORs, the one that would be most current/relevant to the top-level
error would be that determined right before signalling the top-level error.

+      // MEDIA_LOG_ERROR_ENTRY for use in GetErrorMessage().
       case media::MediaLogEvent::PIPELINE_ERROR:
         queued_media_events_.push_back(*event);
         last_pipeline_error_.swap(event);
         break;
       case media::MediaLogEvent::MEDIA_ERROR_LOG_ENTRY:
         queued_media_events_.push_back(*event);
-        last_media_error_log_entry_.swap(event);
+        if (!cached_media_error_for_message_)
+          cached_media_error_for_message_ = std::move(event);
         break;
 
       // Just enqueue all other event types for throttled transmission.
       default:
         queued_media_events_.push_back(*event);
     }
 
     if (ipc_send_pending_)
       return;
 
@@ skipping 13 matching lines @@
   // It's been more than a second so send ASAP.
   if (task_runner_->BelongsToCurrentThread()) {
     SendQueuedMediaEvents();
     return;
   }
   task_runner_->PostTask(
       FROM_HERE,
       base::Bind(&RenderMediaLog::SendQueuedMediaEvents, weak_this_));
 }
 
-std::string RenderMediaLog::GetLastErrorMessage() {
+std::string RenderMediaLog::GetErrorMessage() {
   base::AutoLock auto_lock(lock_);
 
-  // Return the conditional concatenation of the last pipeline error and the
-  // last media error log.
-  std::stringstream result;
+  // Keep message structure in sync with
+  // HTMLMediaElement::BuildElementErrorMessage().
+
+  std::string result = "";

[DaleCurtis, 2017/04/20 20:57:13]

Why did you drop the std::stringstream? Generally you want to avoid extraneous
string allocations. Given the asynchronous nature of the errors reported, this
sometimes generates messages like:

": blah"
"PIPELINE_ERROR_READ"

Versus always generating something of the format "<a> (<#>): <c>" which is what
we discussed earlier. Between two subsequent calls to this function you're going
to end up with incomplete messages. I.e

ERROR_READ on one call, then "ERROR_READ: extra error"

If this all happens before we surface an error to client we're probably okay,
but otherwise telemetry may end up pulling partially completed messages. Can you
talk a bit more about this and why / why not it's an issue?

[wolenetz, 2017/04/20 21:09:03]

Before a MediaError is constructed by the HTMLMediaElement (due to top-level
fatal media error being determined), yes the pipeline_status events do not occur
at the same time as other events like MEDIA_LOG_ERROR_ENTRY events. However,
once that fatal media error is reported up to the media element, the *render*
media log should contain this state. If there are paths that, say, log pertinent
error information *after* reporting the error condition to WebMediaPlayerClient,
then that error info would not be included in the MediaError.message.

tl;dr: any events pertinent to the top-level error must be added to the
RenderMediaLog prior to signalling the top-level error, otherwise yes there
would be partial error messages produced. I think we're ok.

[wolenetz, 2017/04/20 21:58:08]

w.r.t. my not using std::stringstream here: Oops! That crept in during an
interim patch set.

I just now checked with a modified media_perftest, and stringstream operator<<
and str() usage in similar case is about 20% faster than std::string operator+=
on linux Z620 Debug build.

Fixed in patch set 9.

[wolenetz, 2017/04/20 22:13:38]

In patch set 10, I've added a comment to media_log.h's declaration of this
virtual method to help clarify in the code.

   if (last_pipeline_error_) {
-    result << MediaEventToLogString(*last_pipeline_error_)
-           << (last_media_error_log_entry_ ? ", " : "");
+    result += MediaEventToMessageString(*last_pipeline_error_);
   }
-  if (last_media_error_log_entry_)
-    result << MediaEventToLogString(*last_media_error_log_entry_);
-  return result.str();
+
+  if (cached_media_error_for_message_) {
+    DCHECK(last_pipeline_error_)
+        << "Message with detail should be associated with a pipeline error";
+    // This ':' lets web apps extract the UA-specific-error-code from the
+    // MediaError.message prefix.
+    result += ": ";
+    result += MediaEventToMessageString(*cached_media_error_for_message_);
+  }
+
+  return result;
 }
 
 void RenderMediaLog::RecordRapporWithSecurityOrigin(const std::string& metric) {
   if (!task_runner_->BelongsToCurrentThread()) {
     task_runner_->PostTask(
         FROM_HERE, base::Bind(&RenderMediaLog::RecordRapporWithSecurityOrigin,
                               weak_this_, metric));
     return;
   }
 
@@ skipping 36 matching lines @@
   tick_clock_.swap(tick_clock);
   last_ipc_send_time_ = tick_clock_->NowTicks();
 }
 
 void RenderMediaLog::SetTaskRunnerForTesting(
     const scoped_refptr<base::SingleThreadTaskRunner>& task_runner) {
   task_runner_ = task_runner;
 }
 
 }  // namespace content