Closed Bug 970713 Opened 6 years ago Closed 5 years ago

Add ability to dump WebRTC log to disk after a call

Categories

(Core :: WebRTC: Audio/Video, defect, P1)

defect

Tracking

()

RESOLVED FIXED
mozilla32

People

(Reporter: abr, Assigned: pkerr)

References

(Blocks 1 open bug)

Details

(Whiteboard: [p=2, 1.5:p1, ft:webrtc])

Attachments

(4 files, 20 obsolete files)

2.89 KB, patch
Details | Diff | Splinter Review
5.12 KB, patch
jib
: review+
Details | Diff | Splinter Review
19.70 KB, patch
jesup
: review+
Details | Diff | Splinter Review
3.81 KB, patch
pkerr
: review+
Details | Diff | Splinter Review
Rather than requiring users to set the environment up to capture WebRTC logs at startup time, we need the ability to dump a circular buffer of WebRTC logging to disk for analysis of a call after it has begun (or even completed). This should be present only for Nightly and Aurora, turned off for Beta and release.
Blocks: 970426
We could also just log to disk, at least for nicer and webrtc.org logs, which are written from a proxy thread.  The signaling/getusermedia/etc logs would need to be proxied if we write them to disk.
Assignee: nobody → rjesup
Assignee: rjesup → pkerr
Priority: -- → P1
Whiteboard: [p=5, 1.5:p1, ft:webrtc]
Target Milestone: --- → mozilla32
Whiteboard: [p=5, 1.5:p1, ft:webrtc] → [p=2, 1.5:p1, ft:webrtc]
Added control of WebRTC trace mask, log file name, and multi-log generation enable flag to about:config non-default preferences. This allows the standard circular WebRTC log generation now controlled via environment defs plus the ability to create a numbered chain of log files.
I have added the ability to control webrtc module trace from about:config. At this point it configurable but is off by default.

1) What level of default logging do you want in the Nightly/Aurora build? (see media/webrtc/trunk/webrtc/common_types.h for the trace mask.) All of it?

2) When you refer to webrtc logging, do you mean what is currently controlled via the webrtc_trace module setting or do you want the ability to trace other NSPR_LOG_MODULES? Examples, LoadManager, MediaManager.
Flags: needinfo?(adam)
Webrtc logging is enabled in non-release builds by default
Attachment #8426262 - Attachment is obsolete: true
Clean up of lingering ifdef
Attachment #8427772 - Attachment is obsolete: true
Comment on attachment 8427775 [details] [diff] [review]
Part 1: Control webrtc logging from about:config settings

Review of attachment 8427775 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/media/MediaManager.cpp
@@ +1433,5 @@
> +  // Check for WebRTC log settings and enable if there is a non-zero mask value
> +  uint32_t trace_mask = Preferences::GetUint("media.webrtc.debug.trace_mask");
> +
> +  if (trace_mask != 0) {
> +    bool enable_seq_files = Preferences::GetBool("media.webrtc.debug.multi_log");

It's unclear what this is meant to be.  Is it a separate enable/disable compared to setting the trace flags?  Can we simply use trace_mask == 0 to control enabling?

@@ +1441,5 @@
> +
> +    LOG(("%s Logging webrtc to %s level %d", __FUNCTION__, log_file.get(), trace_mask));
> +
> +    webrtc::Trace::set_level_filter(trace_mask);
> +    webrtc::Trace::SetTraceFile(log_file.get(), enable_seq_files);

If we're doing this, we should unify it with the SetTraceFile() calls in content/media/webrtc/MediaEngineWebRTC.cpp (or rather replace them and move the NSPR log controls here).  Also (since webrtc can be used without getUserMedia(), we should add calls to initialize webrtc logging if needed to Video and AudioConduits.

::: modules/libpref/src/init/all.js
@@ +252,5 @@
>  pref("media.navigator.video.default_minfps",10);
> +#ifndef RELEASE_BUILD
> +// Enable logging for nightly and aurora (for now)
> +pref("media.webrtc.debug.trace_mask", 65535);
> +pref("media.webrtc.debug.log_file", "WebRTC.log");

We probably need to have the default location be somewhere other than the current directory, especially on some platforms.  (/tmp on linux and maybe mac, etc).  Ask people who know each platform (gcp, ted, glandium, bsmedberg, etc) what the best choice is.

@@ +253,5 @@
> +#ifndef RELEASE_BUILD
> +// Enable logging for nightly and aurora (for now)
> +pref("media.webrtc.debug.trace_mask", 65535);
> +pref("media.webrtc.debug.log_file", "WebRTC.log");
> +#endif //RELEASE_BUILD

#else
pref("media.webrtc.debug.trace_mask", 0);
#endif
This makes it show to users as an option, so you can more easily tell them to capture a log (though we'll generally prefer they use part 2, which I presume is a button on about:webrtc)

Make the file location not depend on RELEASE_BUILD
(In reply to Randell Jesup [:jesup] from comment #6)
> Comment on attachment 8427775 [details] [diff] [review]
> Part 1: Control webrtc logging from about:config settings
> 
> Review of attachment 8427775 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: dom/media/MediaManager.cpp
> @@ +1433,5 @@
> > +  // Check for WebRTC log settings and enable if there is a non-zero mask value
> > +  uint32_t trace_mask = Preferences::GetUint("media.webrtc.debug.trace_mask");
> > +
> > +  if (trace_mask != 0) {
> > +    bool enable_seq_files = Preferences::GetBool("media.webrtc.debug.multi_log");
> 
> It's unclear what this is meant to be.  Is it a separate enable/disable
> compared to setting the trace flags?  Can we simply use trace_mask == 0 to
> control enabling?
> 
This exposes a currently unused feature of trace that will generate multiple log files instead of one file with a circular log. Each file has a sequence number appended to the base file name. I found this useful when tracking load adaptation; the log would often wrap and I would miss older data.
Updated based on feedback. Log initialization in audio and video conduit; does not rely on GUM for log setup. Default file location more appropriate for various platforms.
Attachment #8427775 - Attachment is obsolete: true
Bug fix in CSFLog.h: move set of gWebrtcTraceLoggingOn to past last possible error return.
Attachment #8436202 - Attachment is obsolete: true
Comment on attachment 8436228 [details] [diff] [review]
Part 1: Control webrtc logging from about:config settings

Review of attachment 8436228 [details] [diff] [review]:
-----------------------------------------------------------------

Still needs to handle enabling at getUserMedia initiation per IRC conversation (and access the prefs from MediaManager, and pass the config down into the MediaEngine to start tracing there)

::: media/webrtc/signaling/src/common/browser_logging/CSFLog.cpp
@@ +76,5 @@
> +
> +    if (branch) {
> +      branch->GetIntPref("media.webrtc.debug.trace_mask", &trace_mask);
> +      branch->GetBoolPref("media.webrtc.debug.multi_log", &multi_log);
> +      branch->GetCharPref("media.webrtc.debug.log_file", (char **)(&file_name));

switch to newer static-pref API.  (Optional)

@@ +80,5 @@
> +      branch->GetCharPref("media.webrtc.debug.log_file", (char **)(&file_name));
> +    }
> +  }
> +#endif
> +  // Fill in any missing attributes from the environment if possible.

Env should take precedence over prefs - swap order

@@ +93,5 @@
> +
> +  gWebrtcTraceLoggingOn = true;
> +
> +  if (!file_name) {
> +#if defined(XP_WIN)

We *can* move the default filename to all.js only, and disable if it gets manually un-set there.  all.js has platform ifdefs already for things.
Attachment #8436228 - Flags: feedback-
WIP - tracking a bug in environment var reading. Affected code comment out for new.
Attachment #8436228 - Attachment is obsolete: true
jib: To turn on webrtc logging on command, independent of the about:config, make a call to StartWebRTCLog(WEBRTC_LOG_LEVEL_DEFAULT). include CSFLog.h.
reviewable version with fix
Attachment #8436405 - Attachment is obsolete: true
Attachment #8436409 - Flags: review?(rjesup)
Comment on attachment 8436409 [details] [diff] [review]
Part 1: Control webrtc logging from about:config settings

Review of attachment 8436409 [details] [diff] [review]:
-----------------------------------------------------------------

Leaks need to be fixed, see other comments - live (though not in-call) update of prefs is needed too.  Also I don't see a way to turn off logging (though that could be a followup)

::: content/media/webrtc/MediaEngine.h
@@ +138,5 @@
>    int32_t mHeight;
>    int32_t mFPS;
>    int32_t mMinFPS;
> +  int32_t mTraceMask;
> +  char*   mLogFileName;

Raw ptr?  This likely leaks.  And this gets default copy constructors

::: content/media/webrtc/MediaEngineWebRTC.cpp
@@ +59,5 @@
>    , mVoiceEngine(nullptr)
>    , mVideoEngineInit(false)
>    , mAudioEngineInit(false)
>    , mHasTabVideoSource(false)
> +  , mPrefs(&aPrefs)

This implies the prefs are read once at start, and if you change them you have to restart.  That's a problem.

::: content/media/webrtc/MediaEngineWebRTC.h
@@ +394,5 @@
>    bool mVideoEngineInit;
>    bool mAudioEngineInit;
>    bool mHasTabVideoSource;
>  
> +  MediaEnginePrefs *mPrefs;

Leaks.

::: media/webrtc/signaling/src/common/browser_logging/CSFLog.cpp
@@ +52,5 @@
>  
>    return gWebRTCLogModuleInfo;
>  }
>  
> +static nsCString gWebRTCLogFile;

Statics that have non-fixed initializers are generally avoided to improve load/start times.

@@ +53,5 @@
>    return gWebRTCLogModuleInfo;
>  }
>  
> +static nsCString gWebRTCLogFile;
> +static const char *default_log = "WebRTC.log";

This for example is probably ok.  gDefaultWebRTCLog

@@ +80,5 @@
> +  return;
> +}
> +
> +#ifdef MOZILLA_INTERNAL_API
> +nsresult GetWebRTCLogPrefs(int *trace_mask, char ** log_file, int *multi_log)

extra space here

@@ +100,5 @@
> +  return rv;
> +}
> +#endif
> +
> +void GenerateWebRTCLogConfig(int *pTraceMask, const char **ppLogFile, int *pMultiLog)

"Generate" is probably the wrong word

@@ +144,5 @@
> +    } else {
> +      // Use the Windows TEMP environment variable as part of the default location.
> +      gWebRTCLogFile.Assign(temp_dir);
> +      gWebRTCLogFile.Append('/');
> +      gWebRTCLogFile.Append(default_log, strlen(default_log));

is the length needed here?

::: modules/libpref/src/init/all.js
@@ +258,5 @@
>  pref("media.navigator.video.default_fps",30);
>  pref("media.navigator.video.default_minfps",10);
> +#ifndef RELEASE_BUILD
> +// Enable logging for nightly and aurora (for now)
> +pref("media.webrtc.debug.trace_mask", 65535);

This may cause problems in TBPL, and it does generate a lot of logging.  We may need to leave it off or at least not saving to disk by default.
Attachment #8436409 - Flags: review?(rjesup) → review-
> 
> ::: modules/libpref/src/init/all.js
> @@ +258,5 @@
> >  pref("media.navigator.video.default_fps",30);
> >  pref("media.navigator.video.default_minfps",10);
> > +#ifndef RELEASE_BUILD
> > +// Enable logging for nightly and aurora (for now)
> > +pref("media.webrtc.debug.trace_mask", 65535);
> 
> This may cause problems in TBPL, and it does generate a lot of logging.  We
> may need to leave it off or at least not saving to disk by default.

I have an open needs-info asking about the appropriate level. It can be dropped below a full trace.
JS patch to get reviews starting.

Button calls these non-existent functions:

- WebrtcGlobalInformation.setDebugMode(65535)
- WebrtcGlobalInformation.getDebugMode()

I'll be in later today to complete. If anyone else wants to add them that would work too!
Attachment #8436511 - Flags: review?(rjesup)
Fixed a bug.
Attachment #8436513 - Flags: review?(rjesup)
Attachment #8436511 - Attachment is obsolete: true
Attachment #8436511 - Flags: review?(rjesup)
Comment on attachment 8436513 [details] [diff] [review]
Part 2: Add 'Start Debug Mode' button to about:webrtc (2)

Review of attachment 8436513 [details] [diff] [review]:
-----------------------------------------------------------------

Needs fxteam review as well
Attachment #8436513 - Flags: review?(rjesup) → review+
I am going to set the default log level for nightly/aurora to kTraceDefault which is 255.
(In reply to Randell Jesup [:jesup] from comment #18)
> Comment on attachment 8436513 [details] [diff] [review]
> Part 2: Add 'Start Debug Mode' button to about:webrtc (2)
> 
> Needs fxteam review as well

I'm not near a computer, could someone add an fx team member as a reviewer for me to get things moving? Not certain who that would be.
Flags: needinfo?(rjesup)
(In reply to Paul Kerr [:pkerr] from comment #12)
> jib: To turn on webrtc logging on command, independent of the about:config,
> make a call to StartWebRTCLog(WEBRTC_LOG_LEVEL_DEFAULT). include CSFLog.h.

Thanks, I didn't see your comment right away. I'll do that as soon as I'm near a computer.
WIP - simplified with common code, prefs read in GetUserMedia.
Attachment #8436409 - Attachment is obsolete: true
Now calls StartWebRTCLog() so it actually does something. Adds WebIDL as well. Needs DOM review.
Attachment #8436513 - Attachment is obsolete: true
Attachment #8436561 - Flags: review?(bugs)
Comment on attachment 8436561 [details] [diff] [review]
Part 2: Add 'Start Debug Mode' button to about:webrtc (3)

>+
>+  attribute long debugLevel;
I think you wanted this to be static.
This could use some comment too.




>+WebrtcGlobalInformation::SetDebugMode(const GlobalObject& aGlobal, long level) {
aLevel and { goes to its own line.


>+  StartWebRTCLog(level);
>+  sLastSetLevel = level;
>+}
>+
>+long
>+WebrtcGlobalInformation::GetDebugMode(const GlobalObject& aGlobal)
ditto about {
(assuming webrtc follows Mozilla coding style)

>+  static void SetDebugMode(const GlobalObject& aGlobal, long level);
aLevel
Attachment #8436561 - Flags: review?(bugs) → review+
Attachment #8436561 - Flags: review?(bmcbride)
(In reply to Olli Pettay [:smaug] from comment #24)
> >+  attribute long debugLevel;
> I think you wanted this to be static.
> This could use some comment too.

Definitely. Will do.

> (assuming webrtc follows Mozilla coding style)

We do, we just have a lot of legacy code to confuse us. Thanks!
Comment on attachment 8436561 [details] [diff] [review]
Part 2: Add 'Start Debug Mode' button to about:webrtc (3)

Review of attachment 8436561 [details] [diff] [review]:
-----------------------------------------------------------------

r=me on the toolkit changes
Attachment #8436561 - Flags: review?(bmcbride) → review+
Addressed feedback. Carrying forward r=smaug, r=Unfocused
Attachment #8436561 - Attachment is obsolete: true
Attachment #8436567 - Flags: review+
Attachment #8436567 - Flags: review?(rjesup)
Flags: needinfo?(rjesup)
move log management into its own module
Attachment #8436550 - Attachment is obsolete: true
Attachment #8436569 - Flags: review?(rjesup)
move log management into its own module
Attachment #8436569 - Attachment is obsolete: true
Attachment #8436569 - Flags: review?(rjesup)
Attachment #8436571 - Attachment is obsolete: true
Attachment #8436572 - Flags: review?(rjesup)
Comment on attachment 8436567 [details] [diff] [review]
Part 2: Add 'Start Debug Mode' button to about:webrtc (4) r=smaug, r=Unfocused

Review of attachment 8436567 [details] [diff] [review]:
-----------------------------------------------------------------

r+ with some type massaging

::: media/webrtc/signaling/src/peerconnection/WebrtcGlobalInformation.cpp
@@ +231,5 @@
>  
>    aRv = rv;
>  }
>  
> +static int sLastSetLevel = 0;

level isn't an int (well, almost)

@@ +234,5 @@
>  
> +static int sLastSetLevel = 0;
> +
> +void
> +WebrtcGlobalInformation::SetDebugLevel(const GlobalObject& aGlobal, long aLevel)

Level isn't a long

@@ +236,5 @@
> +
> +void
> +WebrtcGlobalInformation::SetDebugLevel(const GlobalObject& aGlobal, long aLevel)
> +{
> +  StartWebRTCLog(aLevel);

This I presume ends in SetTraceFilter(), which takes "unsigned int".

@@ +243,5 @@
> +
> +long
> +WebrtcGlobalInformation::DebugLevel(const GlobalObject& aGlobal)
> +{
> +  return sLastSetLevel;

type mismatch :-)
Attachment #8436567 - Flags: review?(rjesup) → review+
Comment on attachment 8436572 [details] [diff] [review]
Part 1: Control webrtc logging from about:config settings

Review of attachment 8436572 [details] [diff] [review]:
-----------------------------------------------------------------

r- for android/b2g issues

::: dom/media/MediaManager.cpp
@@ +1429,5 @@
>    if (!Preferences::GetBool("media.navigator.video.enabled", true)) {
>      c.mVideo.SetAsBoolean() = false;
>    }
>  
> +  StartWebRtcLog();

Note this will start logging on every gum call, including ones that are denied or use fake:true...  Right now we don't do that for fake:true or denials

::: media/webrtc/signaling/src/common/browser_logging/CSFLog.cpp
@@ +13,5 @@
>  #include "cpr_threads.h"
>  #include "prrwlock.h"
>  #include "prthread.h"
>  #include "nsThreadUtils.h"
> +

remove

::: media/webrtc/signaling/src/common/browser_logging/WebRtcLog.cpp
@@ +13,5 @@
> +
> +static int gWebrtcTraceLoggingOn = 0;
> +static const char *default_log = "WebRTC.log";
> +
> +static PRLogModuleInfo* GetWebRtcTraceLog()

Very minor style thing: style guide says
type
function_name(...)

Not in any way critical, but for a new file, please match.

@@ +17,5 @@
> +static PRLogModuleInfo* GetWebRtcTraceLog()
> +{
> +  static PRLogModuleInfo *sLog;
> +  if (!sLog)
> +  sLog = PR_NewLogModule("webrtc_trace");

braces, indent

@@ +35,5 @@
> +
> +static WebRtcTraceCallback gWebRtcCallback;
> +
> +#ifdef MOZILLA_INTERNAL_API
> +nsresult GetWebRtcLogPrefs(int *trace_mask, nsACString* log_file, bool *multi_log)

trace mask is "uint32_t" in set_level_filter; probably best to convert it when reading the pref

@@ +46,5 @@
> +  return rv;
> +}
> +#endif
> +
> +void CheckOverrides(int *pTraceMask, nsACString *pLogFile, bool *pMultiLog)

type ditto
aFoo, not pFoo

@@ +70,5 @@
> +  if (file_name) {
> +    pLogFile->Assign(file_name);
> +  }
> +
> +  return;

remove blank end return

@@ +73,5 @@
> +
> +  return;
> +}
> +
> +void ConfigWebRtcLog(int trace_mask, nsCString &log_file, bool multi_log)

aFoo, type

@@ +95,5 @@
> +    /* Leave the file name set to the old default so that the log can be linked
> +       into adb logcat. */
> +    log_file.Assign(default_log);
> +#else
> +    // UNIX-like place for the others

We want to not adb log by default in nightly/aurora.  And on B2g not to /tmp; to nspr by default for now - when it gets turned on.

::: media/webrtc/signaling/src/common/browser_logging/WebRtcLog.h
@@ +1,4 @@
> +/* This Source Code Form is subject to the terms of the Mozilla Public
> + * License, v. 2.0. If a copy of the MPL was not distributed with this
> + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
> +

Include guards

::: modules/libpref/src/init/all.js
@@ +258,5 @@
>  pref("media.navigator.video.default_fps",30);
>  pref("media.navigator.video.default_minfps",10);
> +#ifndef RELEASE_BUILD
> +// Enable logging for nightly and aurora (for now)
> +pref("media.webrtc.debug.trace_mask", 255);

65535 again
Attachment #8436572 - Flags: review?(rjesup) → review-
(In reply to Randell Jesup [:jesup] from comment #31)
> > +  StartWebRTCLog(aLevel);
> 
> This I presume ends in SetTraceFilter(), which takes "unsigned int".

StartWebRTCLog takes webrtc::TraceLevel, an enum, which makes it an int I think.
Addressed nits. Carrying forward r+ from smaug, bmcbride and jesup.
Attachment #8436567 - Attachment is obsolete: true
Attachment #8436582 - Flags: review+
Works again (always helps, fixed JS typos). Carrying forward r+ from smaug, bmcbride and jesup.
Attachment #8436582 - Attachment is obsolete: true
Attachment #8436585 - Flags: review+
Unbitrot (, and another typo). Carrying forward r+ from smaug, bmcbride and jesup.
Attachment #8436585 - Attachment is obsolete: true
Attachment #8436596 - Flags: review+
with turn off logic
Attachment #8436572 - Attachment is obsolete: true
Attachment #8436599 - Attachment is obsolete: true
Attachment #8436602 - Flags: review?(rjesup)
off bug fix
Attachment #8436602 - Attachment is obsolete: true
Attachment #8436602 - Flags: review?(rjesup)
Attachment #8436605 - Attachment is obsolete: true
Attachment #8436606 - Flags: review?(rjesup)
Attachment #8436607 - Flags: review?(pkerr)
We'll want to re-enable lazy logging or improve the logic for beta/release, or decide the memory hit is worth it in release.
Attachment #8436607 - Flags: review?(pkerr) → review+
Comment on attachment 8436606 [details] [diff] [review]
Part 1: Control webrtc logging from about:config settings

Review of attachment 8436606 [details] [diff] [review]:
-----------------------------------------------------------------

::: media/webrtc/signaling/src/common/browser_logging/WebRtcLog.cpp
@@ +112,5 @@
> +  if (gWebRtcTraceLoggingOn && log_level != 0) {
> +    return;
> +  }
> +
> +  if (log_level == 0) { 

trailing space
Attachment #8436606 - Flags: review?(rjesup) → review+
Depends on: 1022764
Flags: needinfo?(adam)
You need to log in before you can comment on or make changes to this bug.