Closed Bug 1430118 Opened 2 years ago Closed 2 years ago

Child process logging doesn't work (again) when sandboxing is on

Categories

(Core :: Security: Process Sandboxing, defect, major)

Unspecified
Windows
defect
Not set
major

Tracking

()

RESOLVED FIXED
mozilla59
Tracking Status
firefox59 --- fixed

People

(Reporter: mayhemer, Assigned: gcp)

References

(Blocks 1 open bug)

Details

(Keywords: sec-other, Whiteboard: [adv-main59-] sb+)

Attachments

(1 file, 1 obsolete file)

current nightly, latest win10, clean profile.

I'll try to find the reg range.
Blocks: 1297740
Group: core-security
Flags: needinfo?(jld)
Flags: needinfo?(gpascutto)
I'm assuming that this is hitting because the regressor is a sec bug, rather than it being a security issue itself.
Keywords: sec-other
Err, "hidden" instead of "hitting".
(In reply to Andrew McCreight [:mccr8] from comment #2)
> I'm assuming that this is hitting because the regressor is a sec bug, rather
> than it being a security issue itself.
(In reply to Andrew McCreight [:mccr8] from comment #3)
> Err, "hidden" instead of "hitting".

Yes!
https://hg.mozilla.org/mozilla-central/rev/8fdd1dda7efc#l6.107

Need to check what MOZ_LOG_FILE is in the children.
Flags: needinfo?(gpascutto)
Note that we append the parent log file name with .child-N extension for each child processe, where N is the increasing number of spawned child processes.

https://hg.mozilla.org/integration/mozilla-inbound/rev/8fdd1dda7efc#l6.55
I need to check that the code isn't outright broken first. It obviously worked, at some point, but much pain was had trying to get it to compile on all platforms, and especially all 3 Windows compilers. So something might've broken while fixing that.

From the topic, can I assume it works if sandboxing is disabled? That would point to an issue with the 2 different process launch paths on Windows...
Flags: needinfo?(jld)
Debugging indicates we're passing the right things to ::CreateProcessAsUserW, i.e. a new env block with MOZ_LOG_FILE properly substituted.

I didn't manage to get MSVC to break into a point right after startup to inspect the log variable, but after my attempts I noticed I had a foobar.txt-child-1 file. Which can only appear if this stuff is actually working?
(In reply to Gian-Carlo Pascutto [:gcp] from comment #8)
> Debugging indicates we're passing the right things to
> ::CreateProcessAsUserW, i.e. a new env block with MOZ_LOG_FILE properly
> substituted.
> 
> I didn't manage to get MSVC to break into a point right after startup to
> inspect the log variable, but after my attempts I noticed I had a
> foobar.txt-child-1 file. Which can only appear if this stuff is actually
> working?

No, it's not working.  I'll get only an empty (zero length) log for child-1 (which is the same as before this bug, not sure what process the first child is..) and then no other child-N (N>1) log file at all.  We fail to open .child-2 and on log files.
Bob Owen pointed out the file that gets written is likely from the unsandboxed GPU process. (The good news is that the argument substitution at least works there)

Couldn't get printf to show up on the console and writing a logfile is unfortunately the subject of the bug. Apparently redirection stdout/stderr to a file might work, or WinDbg. I'll try that next.
With some tips from jimm I switched to printf_stderr (using OutputDebugString) that allowed me to get some logging from within the sandboxed processes (attaching to them does not seem to work!).

Logging from ContentChild::Init() shows:

[131940] Web Content: MOZ_LOG_FILE=C:\mozilla\mozilla-central\test.txt.child-2
[122108] Web Content: MOZ_LOG_FILE=C:\mozilla\mozilla-central\test.txt.child-3
[106184] Web Content: MOZ_LOG_FILE=C:\mozilla\mozilla-central\test.txt.child-4
[106184] WebExtensions: MOZ_LOG_FILE=C:\mozilla\mozilla-central\test.txt.child-4

And so on. So the environment variables look fine in the child, too. I'm not sure how my bug can be involved, then. I'll check around the regression range.
<bobowen> gcp: it'll be because this code relies on the variables being changed in the parent https://searchfox.org/mozilla-central/source/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp#215
bobowen> I guess just need to look in the map instead
Given that this bug is unrelated to the security issue, and the discussion here doesn't have anything revealing, I think it's OK to unhide this bug.
Assignee: nobody → gpascutto
Attachment #8943151 - Flags: review?(bobowencode)
Comment on attachment 8943151 [details] [diff] [review]
Look at the passed environment for logfile names.

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

::: security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp
@@ +16,5 @@
>  #include "mozilla/NSPRLogModulesParser.h"
>  #include "mozilla/UniquePtr.h"
>  #include "mozilla/Telemetry.h"
>  #include "mozilla/WindowsVersion.h"
> +#include "mozilla/ipc/EnvironmentMap.h"

nit: this is already included in the header.

@@ +216,5 @@
>    // Enable the child process to write log files when setup
> +  wchar_t const* logFileName =
> +    aEnvironment[ENVIRONMENT_LITERAL("MOZ_LOG_FILE")].c_str();
> +  if (!logFileName) {
> +    logFileName = _wgetenv(L"MOZ_LOG_FILE");

Can we actually get into a situation where it's not in the map but the env var is present?
Attachment #8943151 - Flags: review?(bobowencode) → review+
>Can we actually get into a situation where it's not in the map but the env var is present?

Probably not in SandboxBrokers' version of LaunchApp. I'll get rid of the fallback.
Group: core-security
Comment on attachment 8943316 [details]
Bug 1430118 - Look for log file names in the passed environment.

https://reviewboard.mozilla.org/r/213628/#review219372

::: security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp:217
(Diff revision 1)
>    }
>  #endif
>  
>    // Enable the child process to write log files when setup
> -  wchar_t const* logFileName = _wgetenv(L"MOZ_LOG_FILE");
> +  wchar_t const* logFileName =
> +    aEnvironment[ENVIRONMENT_LITERAL("MOZ_LOG_FILE")].c_str();

Sorry I didn't spot this before, but this is going to add an empty entry into the map if it isn't there already.
We should use find.
Comment on attachment 8943316 [details]
Bug 1430118 - Look for log file names in the passed environment.

https://reviewboard.mozilla.org/r/213628/#review219628

It always annoys me how clumsy this is to use in the STL.
Attachment #8943316 - Flags: review?(bobowencode) → review+
Attachment #8943151 - Attachment is obsolete: true
Attachment #8943151 - Flags: review+
Pushed by gpascutto@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/caae648c5dab
Look for log file names in the passed environment. r=bobowen
Blocks: sb-print
Whiteboard: sb+
Blocks: sb-log
No longer blocks: sb-print
https://hg.mozilla.org/mozilla-central/rev/caae648c5dab
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
Whiteboard: sb+ → [adv-main59-] sb+
You need to log in before you can comment on or make changes to this bug.