Closed Bug 1092855 (CVE-2014-1595) Opened 10 years ago Closed 10 years ago

jemalloc poisoning plus Apple uninitialized variable usage triggers keylogging in /tmp/ on OSX 10.10

Categories

(Core :: Security, defect)

Product:
Core
Component:
Security
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
VERIFIED FIXED
Milestone:
mozilla36
Tracking Flags:
Tracking Status
firefox33 - wontfix
firefox34 + verified
firefox35 + verified
firefox36 + verified
firefox-esr31 34+ verified

People

(Reporter: mozilla, Assigned: smichaud)

References

Details

(Keywords: sec-high, sec-vector, Whiteboard: [adv-main34+][adv-esr31.3+] rdar://18946701)

User Story

As the result of an Apple bug on OS X 10.10 (Yosemite), log files whose names follow the pattern /tmp/CGLog_app_pid are created by an OS component for Firefox and Thunderbird (all current branches), which contain a record of the input events that happen while the app is running.

This component is the CoreGraphics framework.  The CoreGraphics framework has long been able to record these logs (going back at least to OS X 10.6), but this functionality is off by default.  However, a bug introduced by Apple in OS X 10.10 turns this logging on by default for Firefox and Thunderbird, and possibly also for other apps that use a custom memory allocator.  (Firefox and Thunderbird use jemalloc.)  The bug is that the CoreGraphics variable is left uninitialized which determines whether or not logging of input events is on.

Mozilla has now landed a patch on all current branches (31esr, 34, 35 and 36) that works around this bug -- it explicitly turns off the CoreGraphics framework's logging of input events.  It will be included in the next releases on all those branches (including of Firefox and Thunderbird).

Attachments

(9 files, 3 obsolete files)

CGLog_Firefox_18197-sample.txt
2.55 KB, text/plain
Details
com.apple.WindowServer.plist
706 bytes, application/xml
Details
Interpose library for logging
8.01 KB, application/x-tar
Details
Another interpose library for logging
8.16 KB, application/x-gzip
Details
lldb all-thread backtrace
51.70 KB, text/plain
Details
lldb_backtrace.txt
74.17 KB, text/plain
Details
Interpose library that shows this bug happen in Firefox but not elsewhere
7.99 KB, application/x-gzip
Details
Fix rev1
4.20 KB, patch
spohl
: review+
lsblakk
: approval-mozilla-aurora+
lsblakk
: approval-mozilla-beta+
lmandel
: approval-mozilla-esr31+
Details | Diff | Splinter Review
Patch for esr31
6.39 KB, patch
smichaud
: review+
Details | Diff | Splinter Review 
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:33.0) Gecko/20100101 Firefox/33.0
Build ID: 20141027150301

Steps to reproduce:

I'm currently using Firefox 33.0.2 and Thunderbird 31.2.0 on MacOS 10.10 (Yosemite).


Actual results:

Both Firefox and Thunderbird are creating large log files in /tmp with the filename template of CGLog_Program_PID (ex. /tmp/CGLog_Firefox_18197 ).  Nothing special is required to cause these log files to be created, however, they do take some time to show up after starting the application; apparently the event log builds in memory first and is flushed periodically. The log file appears to contain all input events like mouse moves, clicks, and key-presses.  The mode on the file is 0644 so any process on the system could read these and thus presents a security issue especially on multi-user systems as it would contain username and password key-press data.

A small example of the log file is attached.  I didn't notice these files until after upgrading to Yosemite, but I'm not certain that was the trigger.


Expected results:

I would expect this logging would only be enabled for debug situations, and when enabled, the file mode should only allow the owning user to open it.
Steven, does this sound familiar at all?

Kent, does this show up when you run in safe mode?
Flags: needinfo?(smichaud)
> Steven, does this sound familiar at all?

No, I've never seen these at all.

And I just checked on an OS X 10.8.5 machine where I've been running Firefox 33.0.2 and Thunderbird 31.2.0 for several hours -- I don't see any such files.  Let me try running Firefox on Yosemite for a few hours, and see if they show up.

Frankly I don't think these logs are a security problem, if the attached sample is any guide.  They would only be if URLs and (especially) accounts and passwords appeared in them.  But it'd still be nice to get to the bottom of this.

Kent:  Try running other browsers (like Safari and Chrome) for a few hours, and check if you see similar log files for them.
Flags: needinfo?(smichaud)
(In reply to Steven Michaud from comment #2)
> Frankly I don't think these logs are a security problem, if the attached
> sample is any guide.  They would only be if URLs and (especially) accounts
> and passwords appeared in them.  But it'd still be nice to get to the bottom
> of this.

I'm concerned about the key events in there -- nice little keylogger.
I did a little bit of Googling and I found a reference to a log with a similar name in the source code for iTerm, which is some open source terminal:
  http://en.sourceforge.jp/projects/iterm-jp/scm/svn/blobs/9/trunk/iTerm/CGSInternal/CGSDebug.h

"Dumps information about an application's resource usage to `/tmp/CGResources_<NAME>_<PID>`."
> I'm concerned about the key events in there -- nice little keylogger.

Oops.  Yes, you're right.
Kamil had the same log (on Yosemite).  I don't see one on 10.9.
Status: UNCONFIRMED → NEW
Ever confirmed: true
I've been running FF 33.0.2 in Yosemite for the last hour, and still don't see these log files.

For what it's worth, my copy of Yosemite is the release version (build 14A389), and is a clean install (not an upgrade).

Kent, please try restarting your computer (to get rid of existing log files), the running Firefox in safe mode to see if new log files are created.

Please also try running Safari and Chrome for a while, to see if log files also get created for them.

Are you using the Yosemite release?  How did you get/install your version of Yosemite?  Did you upgrade from pre-release versions of Yosemite (betas or developer previews)?
Kamil and Kent, are either of you using iTerm or something?
(From the link in comment #5)

/*! Dumps a very verbose debug log of all processes to /tmp/CGLog_<NAME>_<PID>. */
kCGSDebugOptionVerboseLoggingAllApps = 0x80000007,

This makes it sound like something at the OS level (or the user settings level) is triggering debug logging for all apps.  Let my sharpen my reverse engineering tools and dig around for more information.

We very seriously need to see if these logs get created for all apps.  Andrew, please lean on Kamil right away.  Kent, please answer my questions from comment #8 right away.
> This makes it sound like something at the OS level (or the user settings level)

But yes, it could also be a single app like iTerm.  Or a Firefox extension.
Kamil was going to check if he's seeing this issue in Chrome, too.  It didn't show up immediately, but he was going to use it for a few hours to see if it shows up there too.

ni for the question in comment 9
Flags: needinfo?(kamiljoz)
Kamil, please also answer my questions from comment #8.
Kamil and Kent:  By any chance are either of you using an Apple developer tool called Quartz Debug?

It's probably capable of changing a debug setting to make these log files appear for any app.  I don't yet know whether or not the setting change would be permanent -- whether it would persist after quitting Quartz Debug and/or restarting your computer.
> Are you using the Yosemite release?  How did you get/install your version of
> Yosemite?  Did you upgrade from pre-release versions of Yosemite (betas or
> developer previews)?

I upgraded to Yosemite from Mavericks 10.9.5 via the Apple Store. I wasn't using any 10.10 betas or developer previews previous to upgrading.

> Kamil and Kent, are either of you using iTerm or something?

Nope, I'm just using the plain Terminal (v2.5) that comes with OSX with the "Pro" theme selected (haven't changed anything else).

> But yes, it could also be a single app like iTerm.  Or a Firefox extension.

Speaking of extensions/add-ons, I do have the Gecko Profiler installed:
- https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Profiling_with_the_Built-in_Profiler

However, the log file is still being created after running fx in safe mode:
- removed the log files from /tmp/
- restarted the machine and ensured the logs weren't present when re-launching fx
- started fx in safe mode via the Hamburger Menu -> Help Menu -> Restart with Add-ons Disabled...
- once fx started in safe mode, double checked to make sure that there weren't any logs

After about 20 minutes or so, CGLog_Nightly_437 was created under /tmp/. I'm running Chrome 38.0.2125.111 and Safari Version 8.0 (10600.1.25) at the same time and haven't seen any logs from those two browsers.

> Kamil and Kent: By any chance are either of you using an Apple developer tool called Quartz Debug?

I haven't installed Quartz Debug directly but I did upgrade xCode to version 6.1 (6A1052d) via the Apple Store a few days after installing Yosemite. I haven't anything other than upgrading it.
Flags: needinfo?(kamiljoz)
Steven said: "Are you using the Yosemite release?  How did you get/install your version of Yosemite?  Did you upgrade from pre-release versions of Yosemite (betas or developer previews)?"

Yes, I'm running the GA release 10.10.  I upgraded from the GA release of 10.9.  I've not involved myself with any of the beta releases of OS X.

I'm currently running Firefox in safe-mode and after about 20 minutes the CGLog_Firefox_PID log showed up.  Note also that this happens in Thunderbird as well so the condition seems to be in a shared component.  That's while I filed this under Core.

I run Safari regularly and has not create any similar log file (at least not in /tmp).  I don't like Chrome but I do have it installed so I'll see if anything happens with a 30 minute session there.
I noticed a couple more questions to answer.

* I don't have iTerm installed.

* Like Kamil, I upgraded XCode to 6.1 after installing Yosemite.  It's installed to let macports do its builds; and that's the extent of my usage of it, at this point.  I'm not using Quartz Debug.
Can you use something like lsof to determine which process is writing to the file?
Kamil and Kent:  Thanks very much for your detailed information.  For the moment I can't think of any more questions, but when I do I'll let you know here.

This is all very puzzling.

The CoreGraphics framework does have an undocumented CGSSetDebugOptionsPSN() method, which presumably sets a particular option only for a particular process id.  I'd guess this is how Firefox and Thunderbird are getting these log files when they run.  But the tree doesn't contain any calls to any of the CGSSetDebugOptions() variants, and neither does the Gecko Profiler.

I don't think that whatever program did this is malicious.  A key logger would just log your keystrokes, and would presumably be much less obvious about it.  But I'd still very much like to know what's going on.

I'll keep digging and thinking.
(In reply to David Keeler (:keeler) [use needinfo?] from comment #18)
> Can you use something like lsof to determine which process is writing to the
> file?

Using the fuser command shows the log files are not held open.  They appear to be opened by the process periodically to flush records to it and then closed.  I just captured the firefox process accessing the logs using iosnoop.

  UID   PID D    BLOCK   SIZE       COMM PATHNAME
  502 46528 R 365588248   4096    firefox ??/tmp/CGLog_Firefox_46528
  502 46528 W 365588248   4096    firefox ??/tmp/CGLog_Firefox_46528
  502 46528 W 366811848 1044480    firefox ??/tmp/CGLog_Firefox_46528
  502 46528 W 366813888 155648    firefox ??/tmp/CGLog_Firefox_46528
Later I'll post an interpose library that you can attach to Firefox (or Thunderbird), and which will log stack traces for calls made to any of the CGSSetDebugOptions() variants.  Here I'm assuming the debug logging setting isn't permanent.

But maybe it is.  In that case you *might* be able to catch where the setting is stored by running the following two commands from Terminal:

grep -r -s CGSDebugOption /Library/
grep -r -s CGSDebugOption ~/
Another request, on the off chance it may reveal something interesting:

Please attach the contents of your /System/Library/LaunchDaemons/com.apple.WindowServer.plist file.
Attached, let me know if you need anything else Steven.
> Attached

Thanks!  Nothing unusual there.  It looks exactly like mine.
I've been running Chrome/Safari for a few hours without seeing any logs being created under /tmp. Nightly is still dumping data into "CGLog_Nightly_437". Really strange...
Kamil, please do try the following two commands from Terminal (mentioned above in comment #21):

grep -r -s CGSDebugOption /Library/
grep -r -s CGSDebugOption ~/
Kamil and Kent, here's another command to try (in a Terminal prompt):

defaults read com.apple.QuartzDebug
Results:

* grep -r -s CGSDebugOption /Library/ > out.txt (didn't find any patches/results, out.txt was completely blank)

* defaults read com.apple.QuartzDebug:

2014-11-04 20:09:15.088 defaults[3893:1654875] 
Domain com.apple.QuartzDebug does not exist

* grep -r -s CGSDebugOption ~/ > out.txt

for some reason, this command is taking a very long time to complete.. I'm not sure if it's because I have all the mozilla branches in my ~/ and the scan is taking a long time? I'm gonna head home as its 8pm here but I'll run the command once I get home and leave it running.
Thanks, Kamil.

When you have time please also try the following:

1) grep -r -s CGSSetDebugOptions /Applications/

I expect matches in the XCode SDKs directory.  Tell us if you find other matches.

2) grep -r -s CGSSetDebugOptions /System/Library/

I expect matches in the CoreGraphics framework, and error messages for the Ruby framework.  Tell us if you find other matches.

3) grep -r -s CGSSetDebugOptions /Library/

I don't expect any matches at all.
One more, for good measure:

grep -r -s CGSSetDebugOptions ~/Library/Internet Plug-Ins/
Results:

* grep -r -s CGSSetDebugOptions /Applications/ > out.txt

All the matches were found only in "/SDKs/MacOSX10.10.sdk/" and "/SDKs/MacOSX10.9.sdk/". However, I did receive some "recursive directory loop" warnings under:
- /Developer/SDKs/MacOSX10.10.sdk/System/Library/Frameworks/Ruby.framework/
- /Developer/SDKs/MacOSX10.9.sdk/System/Library/Frameworks/Ruby.framework/

* grep -r -s CGSSetDebugOptions /System/Library/ > out.txt

All the matches were found under "CoreGraphics". I didn't receive any error messages regarding the Ruby framework

* grep -r -s CGSSetDebugOptions /Library/ > out.txt

no matches found

* grep -r -s CGSSetDebugOptions ~/Library/Internet Plug-Ins/ > out.txt

no matches found
Results:

* grep -r -s CGSDebugOption ~/ > out.txt

-> Binary file /Users/kjozwiak//Documents/Virtual Machines.localized/Windows 7 Pro x64.vmwarevm/564d4f60-4ad6-d4bc-1696-77cf39b2672b.vmem matches
Interesting.  So this could conceivably be a VMWare thing.

Kent, do you also have VMWare installed?

Kamil, can you make the logging stop by (temporarily) deinstalling VMWare and restarting your computer?

(I don't have any Yosemite partitions suitable for installing VMWare, though I do have a license.  In fact one of those partitions is itself a VMWare VM.)
Kamil and Kent, here's another command to try in Terminal:

plutil -p /Library/Preferences/com.apple.windowserver.plist
Kamil, what's your version of VMWare Fusion?
(In reply to Steven Michaud from comment #33)
> Interesting.  So this could conceivably be a VMWare thing.
> 
> Kent, do you also have VMWare installed?

I don't.  However I do have VirtualBox installed.
Not sure how helpful this is, but I played with dtrace a bit with the following probe.

	pid$1:CoreGraphics:*Debug*:entry { trace(arg0); trace(arg1); ustack(); }

and this is what it returned after displaying the initial window (first two entries) and then bringing that window into the foreground (second two entries)


CPU     ID                    FUNCTION:NAME
  1   4646      CGSUpdateDebugOptions:entry             37723                2
              CoreGraphics`CGSUpdateDebugOptions
              CoreGraphics`CGSNewWindowWithOpaqueShape+0x73
              AppKit`_NSCreateWindowWithOpaqueShape2+0x218
              AppKit`-[NSWindow _commonAwake]+0x710
              AppKit`-[NSWindow _makeKeyRegardlessOfVisibility]+0x55
              AppKit`-[NSWindow makeKeyAndOrderFront:]+0x1b
              XUL`0x0000000101dc3b50+0x658

  1   4647        _CGSGetDebugOptions:entry              9223  140735114771568
              CoreGraphics`_CGSGetDebugOptions
              CoreGraphics`CGSUpdateDebugOptions+0x2a
              CoreGraphics`CGSNewWindowWithOpaqueShape+0x73
              AppKit`_NSCreateWindowWithOpaqueShape2+0x218
              AppKit`-[NSWindow _commonAwake]+0x710
              AppKit`-[NSWindow _makeKeyRegardlessOfVisibility]+0x55
              AppKit`-[NSWindow makeKeyAndOrderFront:]+0x1b
              XUL`0x0000000101dc3b50+0x658

  0   4646      CGSUpdateDebugOptions:entry             37723                2
              CoreGraphics`CGSUpdateDebugOptions
              CoreGraphics`CGSNewWindowWithOpaqueShape+0x73
              HIToolbox`MBWindows::CreateWindow(CGRect, unsigned int)+0xac
              HIToolbox`MBWindows::GetWindowIDOnDisplay(unsigned int, unsigned char)+0xae
              HIToolbox`MenuBarInstance::ForEachWindowDo(void (unsigned int, unsigned int) block_pointer)+0xa2
              HIToolbox`MenuBarInstance::UpdateWindowBoundsAndResolution()+0x9b
              HIToolbox`MenuBarInstance::Show(MenuBarAnimationStyle, unsigned char, unsigned char, unsigned char)+0xe5
              HIToolbox`SetMenuBarObscured+0xe8
              HIToolbox`HIApplication::HandleActivated(OpaqueEventRef*, unsigned char, OpaqueWindowPtr*)+0xb8
              HIToolbox`HIApplication::EventObserver(unsigned int, OpaqueEventRef*, void*)+0xee
              HIToolbox`_NotifyEventLoopObservers+0x9b
              HIToolbox`AcquireEventFromQueue+0x335
              HIToolbox`ReceiveNextEventCommon+0xea
              HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter+0x47
              AppKit`_DPSNextEvent+0x3c4
              AppKit`-[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]+0xc2
              XUL`0x0000000101dbdbb0+0x52

  0   4646      CGSUpdateDebugOptions:entry             37723                2
              CoreGraphics`CGSUpdateDebugOptions
              CoreGraphics`CGSNewWindowWithOpaqueShape+0x73
              HIToolbox`HIMenuBarView::DrawSelf(short, __HIShape const*, CGContext*)+0x16a
              HIToolbox`HIView::DrawCacheOrSelf(short, __HIShape const*, CGContext*)+0x157
              HIToolbox`HIView::EventHandler(OpaqueEventHandlerCallRef*, OpaqueEventRef*, void*)+0xbae
              HIToolbox`DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)+0x4ec
              HIToolbox`SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)+0x182
              HIToolbox`SendEventToEventTargetWithOptions+0x2b
              HIToolbox`HIView::SendDraw(short, OpaqueGrafPtr*, __HIShape const*, CGContext*)+0x151
              HIToolbox`HIView::RecursiveDrawComposited(__HIShape const*, __HIShape const*, unsigned int, HIView*, CGContext*, unsigned char, double)+0x2c6
              HIToolbox`HIView::RecursiveDrawComposited(__HIShape const*, __HIShape const*, unsigned int, HIView*, CGContext*, unsigned char, double)+0x542
              HIToolbox`HIView::DrawComposited(short, OpaqueGrafPtr*, __HIShape const*, unsigned int, HIView*, CGContext*)+0x3c5
              HIToolbox`HIView::Render(unsigned int, CGContext*)+0x36
              HIToolbox`WindowData::PrepareForVisibility()+0xa8
              HIToolbox`_ShowHideWindows+0x189
              HIToolbox`ShowHide+0x22
              HIToolbox`MBWindows::CreateWindow(CGRect, unsigned int)+0x179
              HIToolbox`MBWindows::GetWindowIDOnDisplay(unsigned int, unsigned char)+0xae
              HIToolbox`MenuBarInstance::ForEachWindowDo(void (unsigned int, unsigned int) block_pointer)+0xa2
              HIToolbox`MenuBarInstance::UpdateWindowBoundsAndResolution()+0x9b
> Kamil and Kent, here's another command to try in Terminal:
> 
> plutil -p /Library/Preferences/com.apple.windowserver.plist

* plutil -p /Library/Preferences/com.apple.windowserver.plist
--> http://pastebin.mozilla.org/7130847

> Kamil, what's your version of VMWare Fusion?

I'm using VMware Fusion 7.0.1 (2235595). I was using Fusion 5 but the 10.10 update screwed everything up and VMware eded up dropping it's support. So I uninstalled Fusion 5 and installed Fusion 7.0.1 with brand new VM's via the "More Isolated" route rather than "More Seamless". This way the VM's are not running side by side with OSX.

> Kamil, can you make the logging stop by (temporarily) deinstalling VMWare and restarting your computer?

I closed VMware and restarted the machine but the log appeared after 20 minutes of using Nightly with VMware closed.
(In reply to Steven Michaud from comment #34)
> Kamil and Kent, here's another command to try in Terminal:
> 
> plutil -p /Library/Preferences/com.apple.windowserver.plist

{
  "DisplayMainOnInternal" => 1
  "DisplayLayoutToRight" => 0
  "CGSInterocitorSelectMode" => 0
  "ForceOldStyleMemoryManagement" => 0
}
> I closed VMware and restarted the machine

You probably really do need to (temporarily) uninstall VMWare Fusion.  I believe that while it's installed, some parts of it are always running, even if the Fusion app isn't -- including at least one kernel extension.

Fusion used to have a nice uninstaller.  But now that I look again it seems to have disappeared.  I also have Fusion 7.0.1.  I don't know what's up with this.  I can't believe Fusion no longer uses kernel extensions.
> plutil -p /Library/Preferences/com.apple.windowserver.plist
>
> {
>   "DisplayMainOnInternal" => 1
>   "DisplayLayoutToRight" => 0
>   "CGSInterocitorSelectMode" => 0
>   "ForceOldStyleMemoryManagement" => 0
> }

Interesting.  Mine is empty.

I don't think any of the entries here is responsible for the logging.
But I do see that you at least occasionally have an external monitor
connected.

So the next question is, does the logging only happen while an
external monitor is connected?
(In reply to comment #36)

>> Kent, do you also have VMWare installed?
>
> I don't.  However I do have VirtualBox installed.

So does the logging stop happening if you temporarily uninstall or
disable it?
(In reply to comment #37)

Interesting.  CGSUpdateDebugOptions() is an internal (non-exported) method.  Let me see what I can find out about it in lldb and my disassembler (Hopper Disassembler http://www.hopperapp.com/).
(In reply to Steven Michaud from comment #44)
> (In reply to comment #37)
> 
> Interesting.  CGSUpdateDebugOptions() is an internal (non-exported) method. 
> Let me see what I can find out about it in lldb and my disassembler (Hopper
> Disassembler http://www.hopperapp.com/).

This is what I could get using tool.

_CGSUpdateDebugOptions:
000000000000b136        pushq   %rbp
000000000000b137        movq    %rsp, %rbp
000000000000b13a        callq   _CGSRunningInServer
000000000000b13f        testb   %al, %al
000000000000b141        jne     0xb167
000000000000b143        movb    _CGSUpdateDebugOptions.debugOptionsInit(%rip), %al
000000000000b149        testb   %al, %al
000000000000b14b        jne     0xb167
000000000000b14d        callq   _CGSServerPort
000000000000b152        leaq    __CGSDebugOptionFlags_(%rip), %rsi
000000000000b159        movl    %eax, %edi
000000000000b15b        callq   __CGSGetDebugOptions
000000000000b160        movb    $0x1, 0x8926f1(%rip)
000000000000b167        popq    %rbp
000000000000b168        retq
(Following up comment #40)

Fusion 7.0.1 does still use kernel extensions -- you can see them in the output from kextstat.  But if you quit the Fusion app they get unloaded (which you can also see using kextstat).

So don't bother trying to uninstall Fusion 7.0.1.  And no, it doesn't seem to be responsible for the logging.
Steven, let me know if there's anything else that I can do. Is there a tool/debugger that I can install that can help us?
I'm working on an interpose library that will log the CoreGraphics framework's current debug options value when it's initialized and whenever it changes.  Once I'm done I'll ask you (Kamil) and Kent to run it and see what the logs say.
OK, Kamil and Kent, here's my interpose library.

Despite the format, it contains no binaries.  So you need to untar it and call "make".  If you don't already have them, you need the XCode commandline tools (which I think you can get from inside XCode).

The top of the interpose.mm file contains more instructions for use.

Please let me know if you have any questions.

And also of course please let us know what shows up in your logs.

In my own logs, I only see one call to _CGSGetDebugOptions(), which returns that the debug options are '0'.
> This is what I could get using tool.

What is "tool", Kent.

I think Hopper Disassembler is truly excellent, but I'm always on the lookout for decent disassemblers.
(In reply to Steven Michaud from comment #50)
> > This is what I could get using tool.
> 
> What is "tool", Kent.
> 
> I think Hopper Disassembler is truly excellent, but I'm always on the
> lookout for decent disassemblers.

Sorry, typo.  I meant otool, but Safari autocorrected.  Grrr..
Still running the process and waiting for the log file to be created, but I thought I'd provide some early results.  Looks basically like the dtrace probe but you were able to capture the arguments and return value.  I'll see if this fires again.

_CGSGetDebugOptions(): serverPort 0x2707, options 0x0, returning 0
    (interpose.dylib) PrintStackTrace() + 0xb1
    (interpose.dylib) Hooked__CGSGetDebugOptions(__CFMachPort*, unsigned int*) + 0x69
    (CoreGraphics) CGSUpdateDebugOptions + 0x2a
    (CoreGraphics) CGSNewWindowWithOpaqueShape + 0x73
    (AppKit) _NSCreateWindowWithOpaqueShape2 + 0x218
    (AppKit) -[NSWindow _commonAwake] + 0x710
    (AppKit) -[NSWindow _makeKeyRegardlessOfVisibility] + 0x55
    (AppKit) -[NSWindow makeKeyAndOrderFront:] + 0x1b
    (XUL) mac_plugin_interposing_child_OnShowCursor + 0x69ee8
The log file just showed up but nothing additional was caught by the interpose library.
> The log file just showed up but nothing additional was caught by the interpose library.

OK, it looks like I'll need to start doing stuff to emulate what you guys see.  For example I'll need to start playing with CGSSetDebugOptions(), using the Quartz Debugger or directly.  That'll hopefully give me a better idea of what might be going on.

But CGSSetDebugOptions() might not be involved.  It ultimately just causes a message to be sent over a mach port to the WindowServer.  So it's possible that whatever triggers these logs is doing that directly.

It will take time, possibly a *lot* of time, to discover the source of these logs.  And I've got lots of other things to do, so I can't just work on this continuously.  The one thing I'm reasonably confident of is that whatever triggers these logs isn't malicious -- otherwise its traces would be a lot more difficult to discover.  So this bug isn't drop-dead urgent.
Absolutely agreed; I don't think it's malicious either.  The logs can get very large so that's still an issue but /tmp is cleared whenever MacOS reboots.  I currently just have a background script truncating the files every 5 minutes.  I'll continue working on gathering more information as time permits.  It gives me an excuse to get better at dtrace.  :)
By the way, playing around with Quartz Debug can change a running program's debug settings.  This does trigger calls to debug_options_changed(), which do show up in my interpose library's logs.  So at least I'm now sure that the interpose library does what it's supposed to.
Attached file Another interpose library for logging (obsolete) — 
Kent and Kamil, please try this.
Steps used: (please let know if I did this correctly)

- tar xvzf bugzilla1092855-interpose-lib-rev1.tgz
- make
- export DYLD_INSERT_LIBRARIES=/Users/kjozwiak/Downloads/interpose/interpose.dylib
- /Applications/FirefoxNightly.app/Contents/MacOS/firefox

Results:

(Thu Nov  6 12:56:33 2014) /Applications/FirefoxNightly.app/Contents/MacOS/firefox[3827] print_log_entries()
    (interpose.dylib) PrintStackTrace() + 0xb1
    (interpose.dylib) Hooked_print_log_entries(void*, void*) + 0x52
    (CoreGraphics) (anonymous namespace)::MessageLogger::add_log(std::__1::unique_ptr<(anonymous namespace)::Log, std::__1::default_delete<(anonymous namespace)::Log> >) + 0x262
    (CoreGraphics) CGSEventLogEvent + 0x199
    (CoreGraphics) CGSGetNextEventRecordInternal + 0x112
    (CoreGraphics) CGEventCreateNextEvent + 0x32
    (HIToolbox) PullEventsFromWindowServerOnConnection(unsigned int, unsigned char, __CFMachPortBoost*) + 0x66
    (HIToolbox) MessageHandler(__CFMachPort*, void*, long, void*) + 0x33
    (CoreFoundation) __CFMachPortPerform + 0xf7
    (CoreFoundation) __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__ + 0x29
    (CoreFoundation) __CFRunLoopDoSource1 + 0x1db
    (CoreFoundation) __CFRunLoopRun + 0x947
    (CoreFoundation) CFRunLoopRunSpecific + 0x128
    (AppKit) _NSEventThread + 0x89
    (libsystem_pthread.dylib) _pthread_body + 0x83
    (libsystem_pthread.dylib) _pthread_body + 0x0
    (libsystem_pthread.dylib) thread_start + 0xd
Kamil:

Yes, you did everything right.  And thanks for the info.  It advances our knowledge, and I hope to have another interpose library for you and Kent before too long.  But we still haven't figured this bug out.

Kent's results with my first interpose library show that debug options aren't what determines what's logged, and whether or not logging takes place.  Kamil's results with my rev1 interpose library show that the CoreGraphics framework is definitely doing the logging.

What remains to be figured out is why.

And Kamil's results add a new puzzle.  They show WindowServer events (input events like mouse and keyboard events) being processed on a secondary thread.  I've never seen this before (or at least I've never noticed it), and I didn't realize it was possible.
Kamil and Kent:

Please try breaking in lldb (without my interpose library) at the following label, then getting an all-thread stack trace:

_ZN12_GLOBAL__N_113MessageLogger17print_log_entriesERKNSt3__16vectorINS1_10unique_ptrINS_3LogENS1_14default_deleteIS4_EEEENS1_9allocatorIS7_EEEE
> then getting an all-thread stack trace

"bt all"
> Kent's results with my first interpose library show that debug options
> aren't what determines what's logged, and whether or not logging takes
> place.  Kamil's results with my rev1 interpose library show that the
> CoreGraphics framework is definitely doing the logging.

You can actually see in a disassembly of the ::shared_logger() function in the CoreGraphics framework where it generates the /tmp/CGLog_program_pid filename.  Maybe I should have mentioned that earlier but I thought we had already concluded that it was CoreGraphics doing this.
We couldn't be entirely sure CoreGraphics is doing the logging until we caught it in the act -- as Kamil did with my rev1 interpose library.
(Following up comment #60)

To be useful, the all-thread stack trace needs to be made for a mozilla-central nightly.  All other distros have their symbols stripped.
Steven, I've never used lldb before so I could use some help :) So far, I've done the following:

- lldb /Applications/FirefoxNightly.app/Contents/MacOS/firefox

Trying to figure out what option to use with "breakpoint set"
If you're familiar with gdb, http://lldb.llvm.org/lldb-gdb.html will help.

Neither gdb nor lldb will "run" Firefox properly.  You need to run it yourself, then use lldb to attach to the process.

So what you'd need to do (once Firefox is running) is something like this:

lldb
attach -p [firefox-pid]
b [label]
continue

Then once the breakpoint is hit:

bt all
Here's another interpose library to try.  This obsoletes the rev1 version.  So if you haven't already tried that, try this instead.
Attachment #8518219 - Attachment is obsolete: true
(In reply to Steven Michaud from comment #67)

Immediately at invocation, Firefox 33.0.3 logs the following.

(Thu Nov  6 16:03:17 2014) /Users/kent/Applications/Firefox.app/Contents/MacOS/firefox[77464] OnAddImage(): print_log_entries_ptr 0x10008a000, CGSLogOpen_ptr 0x10008a020, CGSEventLoggingStop_ptr 0x10008a060, get_shared_logger_ptr 0x7fff84d9c6de
Another thing I tried is running Firefox 33.0.3 in a fresh user account with no extensions installed (only the globally installed plugins). The log file eventually showed up same as it does in my normal user account.
Another test I thought should be tried at least once was to run without any plug-ins installed (except for the embedded Cisco H.264 plugin).  I moved everything out of "/Library/Internet Plug-Ins" and "$HOME/Library/Internet Plug-Ins". The log file still showed up.
(In reply to comment #68)

That message is just a sanity check.  I forgot to comment it out.
The breakpoint appeared to have been hit just before the log file was created.  Once I continued the program my /tmp watcher script alarmed.
Attached file lldb_backtrace.txt — 
Ran into the same behavior as Kent described in comment #72. The breakpoint was hit before the log file was created. Once I continued, the log file was created under /tmp.
I'll have more to say about those all-thread stack traces in a bit.  Thanks!

But what I'd really like both of you to do now is try my latest (rev2) interpose library, and leave it running until a log gets written.  It hooks (and logs) the same calls as my rev1 interpose library, plus calls to CGSEventLoggingStart() and CGSEventLoggingStop().

If the last two are being called, I'd *really* like to know how.

(Just ignore the sanity check message that I accidentally left in.)
Results from interpose library (rev2):

(Fri Nov  7 11:38:48 2014) /Applications/FirefoxNightly.app/Contents/MacOS/firefox[658] print_log_entries()
    (interpose.dylib) PrintStackTrace() + 0xb1
    (interpose.dylib) Hooked_print_log_entries(void*, void*) + 0x52
    (CoreGraphics) (anonymous namespace)::MessageLogger::add_log(std::__1::unique_ptr<(anonymous namespace)::Log, std::__1::default_delete<(anonymous namespace)::Log> >) + 0x262
    (CoreGraphics) CGSEventLogEvent + 0x199
    (CoreGraphics) CGSGetNextEventRecordInternal + 0x112
    (CoreGraphics) CGEventCreateNextEvent + 0x32
    (HIToolbox) PullEventsFromWindowServerOnConnection(unsigned int, unsigned char, __CFMachPortBoost*) + 0x66
    (HIToolbox) MessageHandler(__CFMachPort*, void*, long, void*) + 0x33
    (CoreFoundation) __CFMachPortPerform + 0xf7
    (CoreFoundation) __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__ + 0x29
    (CoreFoundation) __CFRunLoopDoSource1 + 0x1db
    (CoreFoundation) __CFRunLoopRun + 0x947
    (CoreFoundation) CFRunLoopRunSpecific + 0x128
    (AppKit) _NSEventThread + 0x89
    (libsystem_pthread.dylib) _pthread_body + 0x83
    (libsystem_pthread.dylib) _pthread_body + 0x0
    (libsystem_pthread.dylib) thread_start + 0xd
So, Kamil, it looks like you didn't see calls to CGSEventLoggingStart() and CGSEventLoggingStop().  If so, that's *very* peculiar.  In fact I don't currently know how to explain it.

Please double-check to make sure you were using my rev2 interpose library.  In fact I'd suggest rebooting your computer before testing again.
About WindowServer events being processed on a secondary thread:

I think I now understand this (at least partly).  And I'm reasonably confident it's unrelated to this bug.  But it's also *very* peculiar.

Since OS X 10.9 (Mavericks), the OS (the AppKit framework) has had the ability to process WindowServer events on a secondary thread, using an _NSEventThread method.  So I'll call this thread the "event thread".

However, Firefox releases (with bundle id org.mozilla.firefox) are opted out of this by the OS.  So you normally only see the "event thread" when running non-beta nightlies (whose bundle id is different), even on Mavericks and Yosemite.  But if you change a Firefox release's bundle id to something else (I changed FF 33.0.3's bundle id in Info.plist to "org.blah.blah"), now you see an "event thread" when you run it.

Google has a few hits for _NSEventThread, but nothing very interesting, and certainly nothing (that I could find) telling why Apple did this.  What I said above I found out on my own, by trial and error.
(In reply to comment #72 and comment #73)

> The breakpoint was hit before the log file was created. Once I
> continued, the log file was created under /tmp.

Glad to hear this.  It confirms that the CoreGraphics framework is
really writing those logs.
I also have this log file on my system. I've only used on Firefox 33.0.2 in this Mac. No Nightly. I do run VMWare and iTerm. Happy to help figure out what is going on.
(In reply to Stefan Arentz [:st3fan] from comment #79)
> I also have this log file on my system. I've only used on Firefox 33.0.2 in
> this Mac. No Nightly. I do run VMWare and iTerm. Happy to help figure out
> what is going on.

Clean install of Yosemite 10.10. No previous betas. MacBook Pro 13" Retina.
Come to think of it, here's another experiment to try:

1) Create a spare copy of Firefox (release or m-c nightly).
2) Run it and confirm that your /tmp/CGLog_Program_PID event logs get created.
3) Quit Firefox, then change its CFBundleID (in Contents/Info.plist) from "org.mozilla.[something]" to "com.blah.blah".
4) Run this copy from the command line (which you'll need to do since you've invalidated its signature).
5) Wait to see if the event logs still get created.

(Stefan, now that you've joined the club you can try this too.)
Stefan, please also try my rev2 interpose library (attachment 8518488 [details]).  Instructions for use are at the top of interpose.mm.
(In reply to comment #80)

> Clean install of Yosemite 10.10.

You mean that it wasn't an upgrade from a previous OS X release (like 10.9.5)?
Two WindowServer related entries in my system logs:

system.log:Nov  7 11:54:44 Defiant.local WindowServer[23780]: disable_update_timeout: UI updates were forcibly disabled by application "Firefox" for over 1.00 seconds. Server has re-enabled them.

system.log:Nov  7 11:54:45 Defiant.local WindowServer[23780]: common_reenable_update: UI updates were finally reenabled by application "Firefox" after 2.65 seconds (server forcibly re-enabled them after 1.00 seconds)

Not sure if relevant.
(In reply to Steven Michaud from comment #83)
> (In reply to comment #80)
> 
> > Clean install of Yosemite 10.10.
> 
> You mean that it wasn't an upgrade from a previous OS X release (like
> 10.9.5)?

No, sorry. When I bought this machine last week it had 10.9.x on it. I upgraded it to 10.10 via the App Store.

I do have another Mac at home that I did cleanly install from a 10.10 USB Drive. I'll investigate there.

 S.
> Not sure if relevant.

Possibly relevant.  I don't have the event logs and I don't have any of these messages.

Kamil and Kent, do you see these?
I can confirm this as well. I have logs for both Fx Nightly and Thunderbird (which definitely seems to implicate libxul). This was an upgrade from 10.9.(5?) to 10.10.
On my work laptop:

% ls -l CGLog_*
-rw-r--r--@ 1 sarentz  wheel   1206926  5 Nov 09:19 CGLog_Firefox_13127
-rw-r--r--@ 1 sarentz  wheel   9954818  3 Nov 15:04 CGLog_Firefox_7777
-rw-r--r--  1 sarentz  wheel  33329015  7 Nov 10:27 CGLog_Nightly_16428

I was thinking maybe this is enable by a plugin. But on my other Mac I have nothing installed except for OpenH264 and QuickTime.
> Please double-check to make sure you were using my rev2 interpose library. 
> In fact I'd suggest rebooting your computer before testing again.

- downloaded the rev2 interpose library from comment # 82
- restarted the machine
- tar xvzf bugzilla1092855-interpose-lib-rev2.tgz
- export DYLD_INSERT_LIBRARIES=/Users/kjozwiak/Downloads/interpose/interpose.dylib
- /Applications/FirefoxNightly.app/Contents/MacOS/firefox

(Fri Nov  7 13:07:53 2014) /Applications/FirefoxNightly.app/Contents/MacOS/firefox[436] print_log_entries()
    (interpose.dylib) PrintStackTrace() + 0xb1
    (interpose.dylib) Hooked_print_log_entries(void*, void*) + 0x52
    (CoreGraphics) (anonymous namespace)::MessageLogger::add_log(std::__1::unique_ptr<(anonymous namespace)::Log, std::__1::default_delete<(anonymous namespace)::Log> >) + 0x262
    (CoreGraphics) CGSEventLogEvent + 0x199
    (CoreGraphics) CGSGetNextEventRecordInternal + 0x112
    (CoreGraphics) CGEventCreateNextEvent + 0x32
    (HIToolbox) PullEventsFromWindowServerOnConnection(unsigned int, unsigned char, __CFMachPortBoost*) + 0x66
    (HIToolbox) MessageHandler(__CFMachPort*, void*, long, void*) + 0x33
    (CoreFoundation) __CFMachPortPerform + 0xf7
    (CoreFoundation) __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__ + 0x29
    (CoreFoundation) __CFRunLoopDoSource1 + 0x1db
    (CoreFoundation) __CFRunLoopRun + 0x947
    (CoreFoundation) CFRunLoopRunSpecific + 0x128
    (AppKit) _NSEventThread + 0x89
    (libsystem_pthread.dylib) _pthread_body + 0x83
    (libsystem_pthread.dylib) _pthread_body + 0x0
    (libsystem_pthread.dylib) thread_start + 0xd

> Kamil and Kent, do you see these?

Searched through a bunch of my system.log files and couldn't find anything similar to those error messages involving fx.
Whoever sees these logs:

What you most urgently need to do is follow my request in comment #81.

Plugins have already been ruled out above (see comment #69 and comment #70).  So have extensions (since the logs still appear in safe mode).  Kamil has already satisfied me wrt comment #82.
Kamil and Stefan:

Could you upload your CoreGraphics framework binary somewhere so I could download it?  I suggest using your people.mozilla.com account.  By "CoreGraphics framework binary" I mean this file:

/System/Library/Frameworks/CoreGraphics.framework/CoreGraphics
(In reply to Steven Michaud from comment #91)
> Kamil and Stefan:
> 
> Could you upload your CoreGraphics framework binary somewhere so I could
> download it?  I suggest using your people.mozilla.com account.  By
> "CoreGraphics framework binary" I mean this file:
> 
> /System/Library/Frameworks/CoreGraphics.framework/CoreGraphics

Before I send it:

% md5 CoreGraphics
MD5 (CoreGraphics) = cc11a2e83d79be27f2b514504798baf4

Let me know if you still need it.

I'm in meetings, can do more later. Will run the interpose lib.
(From comment #84)

> Two WindowServer related entries in my system logs:
>
> system.log:Nov 7 11:54:44 Defiant.local WindowServer[23780]:
> disable_update_timeout: UI updates were forcibly disabled by
> application "Firefox" for over 1.00 seconds. Server has re-enabled
> them.
>
> system.log:Nov 7 11:54:45 Defiant.local WindowServer[23780]:
> common_reenable_update: UI updates were finally reenabled by
> application "Firefox" after 2.65 seconds (server forcibly re-enabled
> them after 1.00 seconds)
>
> Not sure if relevant.

(From comment #89)

> Searched through a bunch of my system.log files and couldn't find
> anything similar to those error messages involving fx.

So they're probably not relevant.
(In reply to comment #92 and following up comment #91)

> % md5 CoreGraphics
> MD5 (CoreGraphics) = cc11a2e83d79be27f2b514504798baf4
>
> Let me know if you still need it.

No, I don't.  Mine has the same hash value.
Please, please, please follow my steps in comment #81.
Steven, unfortunately I haven't setup a people.mozilla.com account, used S3 instead:

* https://s3.amazonaws.com/otherDocuments/CoreGraphics

Appears that mine is the same as Stefan's as per comment # 92:

* MD5 (CoreGraphics) = cc11a2e83d79be27f2b514504798baf4
(In reply to Steven Michaud from comment #95)
> Please, please, please follow my steps in comment #81.

I will. But as a first step, I moved the logs away and restarted Nightly. They are not created immediately.
(In reply to Stefan Arentz [:st3fan] from comment #97)
> (In reply to Steven Michaud from comment #95)
> > Please, please, please follow my steps in comment #81.
> 
> I will. But as a first step, I moved the logs away and restarted Nightly.
> They are not created immediately.

Took about 10 minutes for the logs to be back after restarting Nightly.

Now running a Nightly with modified CFBundleIdentifier. Will report back.
(In reply to Steven Michaud from comment #74)
> But what I'd really like both of you to do now is try my latest (rev2) interpose
> library, and leave it running until a log gets written.  It hooks (and logs) the
> same calls as my rev1 interpose library, plus calls to CGSEventLoggingStart() and
> CGSEventLoggingStop().

(Fri Nov  7 09:14:56 2014) /Users/kent/Applications/Firefox.app/Contents/MacOS/firefox[1465] OnAddImage(): print_log_entries_ptr 0x10008a000, CGSLogOpen_ptr 0x10008a020, CGSEventLoggingStop_ptr 0x10008a060, get_shared_logger_ptr 0x7fff8f39c6de
(Fri Nov  7 09:18:42 2014) /Users/kent/Applications/Firefox.app/Contents/MacOS/plugin-container.app/Contents/MacOS/plugin-container[1657] OnAddImage(): print_log_entries_ptr 0x104390000, CGSLogOpen_ptr 0x104390020, CGSEventLoggingStop_ptr 0x104390060, get_shared_logger_ptr 0x7fff8f39c6de
(Fri Nov  7 10:20:53 2014) /Users/kent/Applications/Firefox.app/Contents/MacOS/firefox[1465] print_log_entries()
    (interpose.dylib) PrintStackTrace() + 0xb1
    (interpose.dylib) Hooked_print_log_entries(void*, void*) + 0x52
    (CoreGraphics) (anonymous namespace)::MessageLogger::add_log(std::__1::unique_ptr<(anonymous namespace)::Log, std::__1::default_delete<(anonymous namespace)::Log> >) + 0x260
    (CoreGraphics) CGSEventLogEvent + 0x1a8
    (CoreGraphics) CGSGetNextEventRecordInternal + 0x112
    (CoreGraphics) CGEventCreateNextEvent + 0x30
    (HIToolbox) PullEventsFromWindowServerOnConnection(unsigned int, unsigned char, __CFMachPortBoost*) + 0x66
    (HIToolbox) MessageHandler(__CFMachPort*, void*, long, void*) + 0x33
    (CoreFoundation) __CFMachPortPerform + 0xf7
    (CoreFoundation) __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__ + 0x29
    (CoreFoundation) __CFRunLoopDoSource1 + 0x1db
    (CoreFoundation) __CFRunLoopRun + 0x947
    (CoreFoundation) CFRunLoopRunSpecific + 0x128
    (AppKit) _NSEventThread + 0x89
    (libsystem_pthread.dylib) _pthread_body + 0x83
    (libsystem_pthread.dylib) _pthread_body + 0x0
    (libsystem_pthread.dylib) thread_start + 0xd
(Fri Nov  7 10:23:30 2014) /Users/kent/Applications/Firefox.app/Contents/MacOS/plugin-container.app/Contents/MacOS/plugin-container[5668] OnAddImage(): print_log_entries_ptr 0x104390000, CGSLogOpen_ptr 0x104390020, CGSEventLoggingStop_ptr 0x104390060, get_shared_logger_ptr 0x7fff8f39c6de
(In reply to Steven Michaud from comment #95)
> Please, please, please follow my steps in comment #81.

1) Created a copy of FirefoxNightly.app --> FirefoxNightly1.app
2) Ran fx from the terminal: /Applications/FirefoxNightly1.app/Contents/MacOS/firefox
3) Waited about 20 minutes and the log file was been created
4) Edited: /Applications/FirefoxNightly1.app/Contents/Info.plist and changed the following:

<key>CFBundleIdentifier</key>
<string>com.blah.blah</string>

5) Saved the change under /Applications/FirefoxNightly1.app/Contents/Info.plist
6) Ran fx from the terminal: /Applications/FirefoxNightly1.app/Contents/MacOS/firefox
7) Waited between 15-20 minutes and eventually "CGLog_Nightly_1074" was created under /tmp
Thanks, Kamil!  Stefan just told me on IRC that he got the same result.

Another theory bites the dust :-(

Stefan has a clean install (not an upgrade install) that he's currently testing on.  If he doesn't get any log files I'll start experimenting with upgrade installs myself.  I currently don't have one, but I can make them.
Stefan now tells me he sees the logs even on his clean install of Yosemite.  So there's probably no benefit to creating my own upgrade installs.

I'm close to being out of leads.  Stefan suggests I "type a lot", including with the arrow keys, not necessarily in any text field.  Does that ring a bell with others?  Does anyone have more specific suggestions?
Sorry, that was me "typing a lot" :-)
(In reply to Steven Michaud from comment #102)
> Stefan now tells me he sees the logs even on his clean install of Yosemite. 
> So there's probably no benefit to creating my own upgrade installs.
> 
> I'm close to being out of leads.  Stefan suggests I "type a lot", including
> with the arrow keys, not necessarily in any text field.  Does that ring a
> bell with others?  Does anyone have more specific suggestions?

I suggested this not to trigger the start of the logging but to trigger what the Log says at the top:

--- flushing event log at 301582.0088838 ---

My suspicion is that for the people who are seeing these files, that the event log starts as soon as you start up Firefox. It is just not flushed to disk until later.

So I suggested to dance on the keyboard simply to generate events that grow the log and eventually trigger the flushing of that log to disk. I'm not suggesting that the key events trigger some bug.
Is everyone who sees these logs using a laptop?  A MacBook Pro?

If you *are* using a laptop, do you have an external keyboard or mouse (or other kind of input device)?
And no, my "typing a lot" didn't cause any logs to appear, on my Retina MacBook Pro without any external keyboard or mouse.
(In reply to Steven Michaud from comment #106)
> Is everyone who sees these logs using a laptop?  A MacBook Pro?
> 
> If you *are* using a laptop, do you have an external keyboard or mouse (or
> other kind of input device)?

I am using a MacBookPro5,3 and, when home, use it with an external monitor and Apple's Bluetooth keyboard.  Sounds like you are suggesting a test where I disconnect one or both?
Actually, I can now reproduce enough of the problem to count ... even though I still haven't seen any logs.

I'm seeing calls to the internal CoreGraphics MessageLogger::add_log() method.

Stefan, you were right!  I just hadn't yet logged enough events for them to be logged to disk.

There's still a lot I need to figure out.  But at least I can now do it on my own machine.
I don't see the calls to MessageLogger::add_log() in either Safari or Chrome.  I'll need to figure out why.
(In reply to Steven Michaud from comment #110)
> I don't see the calls to MessageLogger::add_log() in either Safari or
> Chrome.  I'll need to figure out why.

Would it make sense to make a build that links to the 10.9 or 10.10 SDK and see if that makes a difference?
(In reply to Steven Michaud from comment #106)
> Is everyone who sees these logs using a laptop?  A MacBook Pro?
> 
> If you *are* using a laptop, do you have an external keyboard or mouse (or
> other kind of input device)?

I'm using MacBookPro11,3 and only use the external apple mouse. Never used an external monitor/keyboard.
> Would it make sense to make a build that links to the 10.9 or 10.10
> SDK and see if that makes a difference?

It might.

But we can't do that for release builds.  And I've got a very simple
"fix" in mind, which I'm about to try.
That simple fix didn't work, but I'll keep looking for one.
I just did some builds with the 10.9 and 10.10 SDKs.  All of them have this bug, so that's not the direction to look for a solution.

All were done on Yosemite, with the latest version for Yosemite of XCode's command line tools.  All were 64-bit opt builds, but otherwise as much like mozilla-central nightlies as possible.  Two used the 10.9 SDK, one with --enable-macos-target=10.6 and one without any macos-target setting.  One used the 10.10 SDK without any macos-target setting.

I'm going to be putting this on the back burner for a while, as I've got lots of other things to do.  But it may be good to come back to this after a break.
I should mention that I've also started playing with changes to our Info.plist file -- so far without any positive results.
I'm probably best suited to take this bug.  But I don't mean to stop others working on it.  I'd be very happy to see someone else fix it (or more likely find a workaround for what is probably an Apple bug).
Assignee: nobody → smichaud
Anyone know of a clang/gcc option that guarantees uninitialized memory is always NULLed, even in dynamically linked libraries (like the CoreGraphics framework)?  Or of a linker option that does the same thing?

I think it's quite likely that would fix this bug.
The whole CoreGraphics logging mechanism changed a lot with the Yosemite release.  The Mavericks implementation is very much like the Mountain Lion one, and very different.  That's probably why we don't see this bug on OS X 10.9.X and earlier.
Next week I'll open an Apple bug on this.  I don't think it's very likely they'll fix it ... but at least we'll have done our due diligence.
This is *not* a fix.  But I think it shows conclusively that this is an Apple bug.  The bug is that the first byte of the "shared logger" returned by (anonymous namespace)::shared_logger() is uninitialized.  Space is allocated for this object by the "new" operator.  But though many of its fields are initialized to correct values, the first byte isn't.  It's the value of this byte which determines whether logging is on or off (it determines the return value of CGSEventShouldLogEvents()).

Run any version of Firefox or Thunderbird with this interpose library, following the instructions at the top of interpose.mm.  You'll find that the logging stops.

This kind of bug is impossible to fix directly.  But, as Safari, Chrome and Opera aren't effected, I think there's hope that we can find an indirect solution -- a workaround.
Actually, my "proof" isn't quite so conclusive, after all.

This is a jemalloc bug ... sort of :-(
If you call (anonymous namespace)::shared_logger() early enough, before jemalloc is initialized (as my interpose library from comment #121 does), the bug doesn't happen.  That's because, without jemalloc, unitialized memory *is* NULLed.  (Note that (anonymous namespace)::shared_logger() creates the shared logger only once, the first time it's called.)

But jemalloc poisons unitialized memory to byte values of 0x5a -- just as it does with freed memory.

This is still an Apple bug.  But the reason only we're effected is that only we use jemalloc.  So this is one bug Apple is almost certainly not going to fix.

I don't quite know where we go from here.  But my brain needs a rest.  Let's pick this up again next week.
Here's yet another interpose library.

This also *fixes* the bug in Firefox.  But in addition it shows the bug happening in Firefox and not happening in other apps.
Attachment #8519321 - Attachment is obsolete: true
Summary: insecure and unnecessary /tmp/CGLog_Program_PID event logging → jemalloc poisoning plus Apple uninitialized variable usage triggers keylogging in /tmp/ on OSX 10.10
(In reply to Steven Michaud from comment #123)
> If you call (anonymous namespace)::shared_logger() early enough, before
> jemalloc is initialized (as my interpose library from comment #121 does),
> the bug doesn't happen.  That's because, without jemalloc, unitialized
> memory *is* NULLed.  (Note that (anonymous namespace)::shared_logger()
> creates the shared logger only once, the first time it's called.)
> 
> But jemalloc poisons unitialized memory to byte values of 0x5a -- just as it
> does with freed memory.

Is that right? Last I checked, jemalloc treats uninitialized and freed regions separately -- opt_junk and opt_poison respectively. If opt_junk is enabled, uninitialized memory gets 0xa5 (not 0x5a), but we don't enable opt_junk in release builds.
(In reply to comment #125)

All I can say is that the uninitialized byte in question is set to 0x5a in both FF 33.0.2 and a recent m-c nightly.  And in both cases zeroing it "fixes" this bug.  Try testing on Yosemite with my rev4 interpose library from comment #124.  The same byte is always already 0 in other browsers (Safari, Chrome, Opera).  And that byte is 0 even in Firefox if the shared_logger object is allocated before jemalloc is initialized.

So it's almost certainly jemalloc that originally sets this byte to 0x5a, but I'm not sure exactly how this happens.  Possibly it's because the shared_logger object is re-using memory that was originally released by jemalloc, and poisoned at that time to 0x5a.
By the way, I've already thought of several ways to work around this bug without changing jemalloc.  I'll try them out on Monday.
Steven, would it be useful for me to run the new interpose library from comment #124 and adding the results here?
(In reply to comment #128)

Go ahead, please do.
(In reply to Steven Michaud from comment #126)
> So it's almost certainly jemalloc that originally sets this byte to 0x5a,
> but I'm not sure exactly how this happens.

Likely sequence is that something frees a buffer, which jemalloc then poisons with 0x5a, and shared_logger allocates a new block and jemalloc gives that previously freed buffer.
IOW, it's a straightforward use of uninitialized memory, and it makes visible problems depending on what particular part of memory is given out by the allocator.
apologies for the spam not sure what happened there..!
Attached patch Fix (obsolete) — — Splinter Review 
Here's a patch that works around this bug in my tests.

I've started a set of tryserver builds:
https://tbpl.mozilla.org/?tree=Try&rev=d5a856f318b8

I'll wait to ask for review until I hear testing results from the people who reported this bug.

It was going to be difficult or impossible to create the shared_logger object before jemalloc is initialized.  But it turns out there's an easy way to use CGSSetDebugOptions() to explicitly turn CGEvent logging off (or on, for that matter).
I've tried it out myself, and found that CGEvents can still get logged by the plugin process (in non-e10s mode).  So I'll need to add something to my patch to prevent this.  New patch coming up tomorrow.
Steven, I ran the new interpose library from comment #124 for a few hours and didn't see the log file being created under /tmp. Usually the file would have been created by now. Log entries:

* (Tue Nov 11 12:43:32 2014) /Applications/FirefoxNightly.app/Contents/MacOS/plugin-container.app/Contents/MacOS/plugin-container[854] shared_logger(): returning 0x10ce9c4c0, changed first byte from '0x5a' to '0'

* (Tue Nov 11 13:07:50 2014) /Applications/FirefoxNightly.app/Contents/MacOS/plugin-container.app/Contents/MacOS/plugin-container[943] shared_logger(): returning 0x108bb15c0, changed first byte from '0x5a' to '0'

* (Tue Nov 11 13:31:44 2014) /Applications/FirefoxNightly.app/Contents/MacOS/plugin-container.app/Contents/MacOS/plugin-container[1033] shared_logger(): returning 0x10c79d880, changed first byte from '0x5a' to '0'
Keywords: sec-high
Keywords: sec-high
Attached patch Fix rev1 — — Splinter Review 
Here's another patch, which fixes the problem I mentioned in comment #136 (which by the way happened when you opened a context menu above a Flash movie).

I've started another run of tryserver builds:
https://tbpl.mozilla.org/?tree=Try&rev=91afa580c4c6
Attachment #8520346 - Attachment is obsolete: true
> Keywords: sec-high

Though the creator of these log files (the CoreGraphics framework) is definitely not malicious, I agree with this.  The problem is that, unless we can work around this problem quickly, other, truly malicious apps may be written to take advantage of the presence of this bug's log files.
Yeah, it doesn't quite fit in with our classification of sec-high, given that it requires code running on your machine locally already, but the severity of the information leaked made it feel like more than a sec-moderate.
Attachment #8520784 - Flags: review?(spohl.mozilla.bugs)
Attachment #8520784 - Flags: review?(spohl.mozilla.bugs) → review+
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

Landed on fx-team:
https://hg.mozilla.org/integration/fx-team/rev/9a33d0207b18

I want to let this bake on m-c for a couple of days.  But then I'll request uplift to aurora and beta ... and possibly also release for a possible 33.1.1 release.

Not that I think this bug would justify such a release by itself.  But the bug is serious enough (and easy enough to fix) that I think it could ride along.
Have you filed a bug w/ Apple about this? Regardless of whether we think they will fix it, they should definitely be made aware of the issue. We're certainly not the only project that uses a custom allocator.
Flags: needinfo?(smichaud)
> Have you filed a bug w/ Apple about this?

Not yet.  I'll do so now.
Flags: needinfo?(smichaud)
> I want to let this bake on m-c for a couple of days.  But then I'll request
> uplift to aurora and beta ... and possibly also release for a possible
> 33.1.1 release.
status-firefox33: --- → affected
status-firefox34: --- → affected
status-firefox35: --- → affected
tracking-firefox33: --- → ?
tracking-firefox34: --- → ?
tracking-firefox35: --- → ?
Also FWIW this really isn't a custom allocator issue, there are no guarantees that the memory you get from |malloc| is zeroed on OSX. They're just getting lucky. A super simple example to show the issue:

test.cpp:

#include "stdlib.h"
#include "stdio.h"

int main() {
  char* test = (char*)malloc(100);
  for (size_t i = 0; i < 100; i++) {
    printf("%x, ", (int)test[i]);
  }
  return 0;
}

clang++ test.cpp && ./a.out
(In reply to comment #146)

> Also FWIW this really isn't a custom allocator issue

I'm not so sure.  There may be special linker or compiler options that cause uninitialized memory to be NULLed, unless a custom allocator interferes (the sort of thing I was asking about in comment #118).  And the uninitialized byte (at the beginning of the shared_logger object) is definitely '0' in all other apps that I tried -- Safari, Chrome and Opera.  It's only non-zero (0x5a) in Mozilla apps.

But in any case the real bug here is that the first byte of the shared_logger object is uninitialized.  That's what I'll report to Apple.
Here's the bug report I submitted to Apple:

The CoreGraphics framework has long had the capability of logging
CGEvents pulled from the WindowServer.  This is off by default, but
can be turned on using a call to CGSSetDebugOptions(0x80000008).

Starting with Yosemite (OS X 10.10), the CoreGraphics framework uses a
MessageLogger::shared_logger()::shared_instance object to do the
logging.  This object is allocated (and initialized) only once -- the
first time ::shared_logger() is called.  The value of its first byte
is used to determine whether logging is on or not (in calls to
CGSEventShouldLogEvents()) -- if it's zero logging is off, otherwise
logging is on.

The only problem with this is that the first byte of the shared_logger
object is never initialized.  The ::shared_logger() method uses "new"
to allocate memory for the shared_logger object, and initializes many
of its fields.  But it never initializes the first byte.

So if that first byte is non-zero, CGEvent logging is on by default.
This causes two problems:  1) The resulting /tmp/CGLog_app_pid files
can grow quite large, especially if you rarely restart your
computer.  2) And much more seriously, these logs contain entries for
all your keystrokes -- so they could be used by a malicious
third-party app as a key logger.

For most apps this unitialized first byte doesn't cause trouble -- for
example, in Safari, Chrome and Opera it's always '0'.  But it does
cause trouble for Mozilla apps (like Firefox and Thunderbird),
probably because they use a custom memory allocator (jemalloc) that
"poisons" released memory with the byte value 0x5a.  So in Firefox and
Thunderbird (unless we do something about it), the first byte of the
shared_logger object is always '0x5a', and CGEvent logging is always
on (when running on Yosemite).

At Mozilla we've found a workaround for this, which will get into the
next releases of Firefox and Thunderbird.  So we don't need a fix from
Apple.  But there may be other apps that use custom memory allocators,
which are also effected by this bug, and which haven't yet discovered
workarounds.

This bug was originally reported here, where further discussion will
continue:

https://bugzilla.mozilla.org/show_bug.cgi?id=1092855

Because this is a security bug, access to it is restricted.  If any
Apple developers wish to see it, they'll need to create accounts at
http://bugzilla.mozilla.org, then contact me (by email).  I'll give
their accounts permission to see the bug.
Whiteboard: rdar://18946701
I've opened bug 1097340 about having jemalloc zero newly allocated memory.
(In reply to comment #146)

Eric, try rewriting your example using new instead of malloc.

"new" is what's used to allocate the shared_logger object.
Tracking for Aurora & Nightly, we're almost out the door with Beta so it might be too late there, will have to make a case for risk vs. reward here.
status-firefox36: --- → affected
tracking-firefox35: ? → +
tracking-firefox36: --- → +
(In reply to Steven Michaud from comment #150)
> (In reply to comment #146)
> 
> Eric, try rewriting your example using new instead of malloc.
> 
> "new" is what's used to allocate the shared_logger object.

Same issue w/ new. Simple test:

#include "stdlib.h"
#include "stdio.h"

class Test {
  public:
  int a, b, c, d, e, f, g, h, i, j, k, l, m, n, o, p, q, r, s, t, u, v, w, x, y, z;
};

int main() {
  char* test = new char[100];
  for (size_t i = 0; i < 100; i++) {
    printf("%d, ", test[i]);
  }
  printf("\n");
  Test* t = new Test;
  printf("%d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d, %d\n",
         t->a, t->b, t->c, t->d, t->e, t->f, t->g, t->h, t->i, t->j, t->k, t->l, t->m, t->n, t->o, t->p, t->q, t->r, t->s, t->t, t->u, t->v, t->w, t->x, t->y, t->z);
}
And that's why one needs to do new Test() instead of new Test;
https://hg.mozilla.org/mozilla-central/rev/9a33d0207b18
Status: NEW → RESOLVED
Closed: 10 years ago
status-firefox36: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla36
(In reply to comment #146 and comment #152)

Eric, where did you run your tests, and which clang did you use?

I just ran them both on OS X 10.8.5, using Apple's clang for that OS (from XCode's command line tools), and I got all '0's.  On Yosemite, though, I saw some non-zero values with both tests (with Apple's clang from the latest XCode command line tools for Yosemite).

So whether uninitialized memory is zeroed may depend on which version of clang you're using, or perhaps even on which version of OS X you compile on (or run on).  But there are definitely some cases of it, and we're definitely seeing one with this bug.

Apple's clang for OS X 10.8.5:

$ clang -v
Apple LLVM version 5.1 (clang-503.0.40) (based on LLVM 3.4svn)
Target: x86_64-apple-darwin12.5.0
Thread model: posix

Apple's clang for OS X 10.10:

clang -v
Apple LLVM version 6.0 (clang-600.0.54) (based on LLVM 3.5svn)
Target: x86_64-apple-darwin14.0.0
Thread model: posix
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

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

::: dom/plugins/ipc/PluginProcessChild.cpp
@@ +136,5 @@
> +      // causes those events to be written to disk.  But at this point no
> +      // CGEvents have yet been processed.  CGEvents are events (usually
> +      // input events) pulled from the WindowServer.  An option of 0x80000008
> +      // turns on CGEvent logging.
> +      CGSSetDebugOptions(0x80000007);

If the 0x8 in 0x80000008 is the bit that enables logging, then while 0x80000007 flips that bit, it also flips 3 other bits, which may or may not have other meanings.

I guess you really want 0x80000000. Or, better, CGGetDebugOptions() & ~0x8 if such a function exists.
Mike, that stuff is all wrong.

I went straight to the binary, which I looked at in Hopper Disassembler.  I also did my own tests, of course.
Also, it's not a bit that's checked.  The entire value is checked, and 0x80000007 results in a call to CGSEventLoggingStop(), while 0x80000008 results in a call to to CGSEventLoggingStart().  The relevant code is in the debug_options_changed() method, if you care to look for yourself.
Also note that options values >= 0x80000000 aren't stored as debug options (in debug_options_changed()).  Instead they're acted on directly.
(In reply to Steven Michaud from comment #158)
> Mike, that stuff is all wrong.
> 
> I went straight to the binary, which I looked at in Hopper Disassembler.  I
> also did my own tests, of course.

Did you check older versions? Because Google suggests there are things using those headers that do rely on 0x80000007 enabling the logging...
(In reply to Steven Michaud from comment #155)
> So whether uninitialized memory is zeroed may depend on which version of
> clang you're using, or perhaps even on which version of OS X you compile on
> (or run on).  But there are definitely some cases of it, and we're
> definitely seeing one with this bug.

No, it should only depend on runtime. It would probably be more obvious if the test program did some allocations and filled them first, then freed them, and allocated some more without initialization. That would raise the probability of picking one of the previous initialized allocations.
Here's a definition for debug_options_changed():

void debug_options_changed(uint32_t notificationType, void *data, unsigned long dataLength, void *userData);

It's a callback registered by a call to

void CGSRegisterNotifyProc(void *callback, uint32_t notificationType, void *userData);
> Did you check older versions?

No, because my fix is only used on Yosemite and up.

But I suspect the stuff you found was always wrong, or at least profoundly misleading.  Note that internal analysis shows it all has the same source (look at the wording and so forth).
The CoreGraphics framework on Mountain Lion also has a debug_options_changed() method.  Like the one on Yosemite, it acts directly on any "options" >= 0x80000000 (and doesn't store them as true debug options).  And also like on Yosemite, option == 0x80000007 means "stop logging" (and write any existing log contents to disk).  But in addition to option == 0x80000008, there appear to be two additional options that can be used to start logging (0x80000006 and 0x80000009).  These appear to be used for different "log modes", though I haven't tried to reverse engineer what those modes are.

Use the source, Luke!  And if that's not available use the machine code :-)
(Following up comment #165)

Mavericks (OS X 10.9.X) is like Yosemite.  Lion (OS X 10.7.X) is like Mountain Lion.

The callback method name is debugOptionsChanged() on Lion.
(Following up comment #166)

SnowLeopard (OS X 10.6.X) is like Lion.
(In reply to Steven Michaud from comment #155)
> (In reply to comment #146 and comment #152)
> 
> Eric, where did you run your tests, and which clang did you use?
> 
> I just ran them both on OS X 10.8.5, using Apple's clang for that OS (from
> XCode's command line tools), and I got all '0's.  On Yosemite, though, I saw
> some non-zero values with both tests (with Apple's clang from the latest
> XCode command line tools for Yosemite).
> 
> So whether uninitialized memory is zeroed may depend on which version of
> clang you're using, or perhaps even on which version of OS X you compile on
> (or run on).  But there are definitely some cases of it, and we're
> definitely seeing one with this bug.
> 
> Apple's clang for OS X 10.8.5:
> 
> $ clang -v
> Apple LLVM version 5.1 (clang-503.0.40) (based on LLVM 3.4svn)
> Target: x86_64-apple-darwin12.5.0
> Thread model: posix
> 
> Apple's clang for OS X 10.10:
> 
> clang -v
> Apple LLVM version 6.0 (clang-600.0.54) (based on LLVM 3.5svn)
> Target: x86_64-apple-darwin14.0.0
> Thread model: posix

I was looking at 10.10:
erahm-25043:tmp ericrahm$ clang++ -v
Apple LLVM version 6.0 (clang-600.0.54) (based on LLVM 3.5svn)
Target: x86_64-apple-darwin14.0.0
Thread model: posix

Mike pointed out that |new Test| is different than |new Test()|, initial results show I am seeing zeroes for the latter. But then doing something like:

  |Test* tests = new Test[10];|

indicates they're not always zero initialized:
> printing tests[0]
> 0, -536870912, 0, -536870912, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

So overall I'm not convinced we can say "new always default initializes to zero," but it does seem like it often does. OTOH, malloc clearly does not, array new on primitives clearly does not, new w/o a default constructor clearly does not, and array new doesn't always seem to do the right thing.
> So overall I'm not convinced we can say "new always default initializes to zero," but it does seem like it often does.

new does, if you use (). Both for arrays and non arrays:

new Test();
new Test[10]();

vs.

new Test;
new Test[10];

which both don't.

But that's for POD types. There is more.
See http://stackoverflow.com/questions/620137/do-the-parentheses-after-the-type-name-make-a-difference-with-new
If we're going to take this fix in Beta it needs to land today/early tomorrow. The fix should be in the latest Nightly build. Kamil, can you verify the fix today?

dveditz - This bug is rated sec-high. How critical is it that we ship a fix in 34?
Flags: needinfo?(kamiljoz)
Flags: needinfo?(dveditz)
Tracking 34 but this doesn't mean we're necessarily going to take the fix in 34. Not tracking 33 as this isn't rated highly enough to warrant a chemspill.
status-firefox33: affected → wontfix
tracking-firefox33: ? → -
tracking-firefox34: ? → +
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

I think this bug is serious enough to want to get it fixed in our next release -- FF 34.  A separate, third-party app would be needed to turn this bug's logs into a keylogger.  But the /tmp directory is world-readable, so I suspect it wouldn't be hard to create such an app.  And this bug is serious even without the keylogger aspect:  The logs can get *huge* over a few days.

Approval Request Comment
[Feature/regressing bug #]: Apple bug on Yosemite
[User impact if declined]: All Yosemite users exposed to seriously increased usage of hard disk space and possibly very serious security problem.
[Describe test coverage new/current, TBPL]: My own manual tests, soon followed by Kamils's. Baked on m-c for a day with no reported problems.
[Risks and why]: Low risk.  My patch uses an undocumented API, which though poorly understood by others is well-understood (and tested) by me.  Also the patch is only exercised on Yosemite and up.
[String/UUID change made/needed]: None
Attachment #8520784 - Flags: approval-mozilla-beta?
Attachment #8520784 - Flags: approval-mozilla-aurora?
Another aspect of this that makes it so we want to fix this quickly is that it is very discoverable: anybody who uses Firefox on OSX Yosemite for a little while and looks in their /tmp/ directory can see this log, which is obviously from Firefox and is obviously logging keystrokes.
I ran the try build from comment # 141 for a few hours yesterday (4-5hrs) and didn't see the log file being created. I also ran today's Nightly build for about 3hrs and didn't see the log under /tmp/. With the older Nightly builds, I usually received the log file within 15 minutes of using fx.

I also opened several context menu's above/below and to the side of flash video's and made sure that the log file wasn't being created as per comment # 136 & comment # 138.

Builds Used:

* http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/smichaud@pobox.com-91afa580c4c6/try-macosx64/firefox-36.0a1.en-US.mac.dmg
* http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-11-12-03-02-02-mozilla-central/
status-firefox36: fixed → verified
Flags: needinfo?(kamiljoz)
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

Also approving for Beta because of the sec level and discoverability.
Attachment #8520784 - Flags: approval-mozilla-beta?
Attachment #8520784 - Flags: approval-mozilla-beta+
Attachment #8520784 - Flags: approval-mozilla-aurora?
Attachment #8520784 - Flags: approval-mozilla-aurora+
> Does this need to land on esr31?

Esr31 is definitely effected, so I suppose it does.
status-firefox-esr31: ? → affected
Flags: needinfo?(smichaud)
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

[Approval Request Comment]
If this is not a sec:{high,crit} bug, please state case for ESR consideration:
User impact if declined: All Yosemite users exposed to seriously increased usage of hard disk space and easily discoverable security problem.
Fix Landed on Version: 36
Risk to taking this patch (and alternatives if risky): Low risk
String or UUID changes made by this patch: None

See https://wiki.mozilla.org/Release_Management/ESR_Landing_Process for more info.
Attachment #8520784 - Flags: approval-mozilla-esr31?
QA Contact: kamiljoz
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

Thanks for keeping us honest Ryan. Let's get this on ESR31 as well.
Attachment #8520784 - Flags: approval-mozilla-esr31? → approval-mozilla-esr31+
Comment on attachment 8520784 [details] [diff] [review]
Fix rev1

I backed this out for bustage:
https://hg.mozilla.org/releases/mozilla-esr31/rev/c8b40bcdf571

I'll deal with it tomorrow.
Flags: needinfo?(smichaud)
Attached patch Patch for esr31 — — Splinter Review 
Backported support for calls to nsCocoaFeatures::OnYosemiteOrLater().  Carrying forward r+.
Attachment #8522345 - Flags: review+
I ran the build listed below while actively using the browser [4hrs] without receiving the log file under /tmp. As stated before, originally the log file would be created within 15 minutes of using fx.

Build Used:

* Aurora [20141113004001]
** http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-11-13-00-40-01-mozilla-aurora/

Steven, will the bustage in comment # 181 affect m-c and aurora at all or was this just relating to esr31?
Flags: needinfo?(smichaud)
> Steven, will the bustage in comment #181 affect m-c and aurora at
> all or was this just relating to esr31?

It was just related to esr31, which was old enough not to have support
for calls to nsCocoaFeatures::OnYosemiteOrLater().
Flags: needinfo?(smichaud)
I ran the build listed below while actively using the browser [5hrs] without receiving the log file under /tmp. Originally the log file would have been created within 15 minutes of using fx.

Builds Used:

* fx 34 [BuildID: 20141113192814 changeset: 8a30f7117b2e]
** http://ftp.mozilla.org/pub/mozilla.org/firefox/candidates/34.0b9-candidates/build1/mac/en-US/
status-firefox34: fixed → verified
> dveditz - This bug is rated sec-high. How critical is it that we ship a fix in 34?

"Very Important", a step below "critical" because it's not exploitable from remote and Macs mostly aren't shared. But it's also highly discoverable and several other programs with logging woes have been in the security news lately (not in a good way). Would like not to join them.
Flags: needinfo?(dveditz)
The duped bug links to some discussion of this issue on the Mozilla support forums:
  https://support.mozilla.org/en-US/questions/1028140
Some person on Twitter also noticed this on 11/5:
  https://twitter.com/tomaon/status/529925191246168064
Google translates that as "What's this? > /tmp/CGLog_Firefox* something Did <something garbled> infected?"
(I found that with a Google search.)

So that's like a half dozen or so people who noticed this and posted about it.
(In reply to comment #191)

I read the second sentence as something like "Am I infected?".
Should we make some kind of announcement that this is an Apple bug that will be fixed/worked-around in our next releases on all the "live" branches?  (Meaning 31esr, 34, 35 and 36.)

I don't know, though, where would be appropriate.
I ran the build listed below while actively using the browser [5hrs] without getting the log file under /tmp. Originally the log file would have been created within 15 minutes of using fx.

Builds Used:

* fx-esr31: [BuildID: 20141117000501 changeset: abd43f9b90d9]
** http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-11-17-00-05-01-mozilla-esr31/
Status: RESOLVED → VERIFIED
status-firefox-esr31: fixed → verified
(In reply to Steven Michaud from comment #193)
> Should we make some kind of announcement that this is an Apple bug that will
> be fixed/worked-around in our next releases on all the "live" branches? 
> (Meaning 31esr, 34, 35 and 36.)
> 
> I don't know, though, where would be appropriate.

I'm not sure what the best approach would be, but I agree what we should probably mention something in some form or another. I personally think users should be told that their key strokes are being logged because of this bug. Following the link from comment # 190, it seems like a lot of users want more information but can't view this bug as it's marked as sec-sensitive. Releasing some form of an information/announcement would definitely put the users at ease who think they're infected. (the first reaction they have)
User Story: (updated)
I've put possible text for an announcement in User Story.  dveditz (and others), please comment on its wording.  I tried not to give too much away.  But the fact that these logs contain input events (including keyboard events) is so obvious that we should consider it already public.

Even if we don't announce this publicly, the text in User Story will hopefully make it easier for people to understand this long and complex bug.  It can't have escaped your notice that none of the public discussions of this bug linked here have accurate descriptions, even where those descriptions were written by people who have access to this bug.
Flags: needinfo?(dveditz)
User Story: (updated)
User Story: (updated)
What happens in the future when/if Apple changes the definition of the debug options, as they apparently have in the past? We should keep an eye on Apple's response, and if they fix it make the check isYosemite() without the "orLater" part (do we have such a function?).

I'll check with press@ about whether we want to make an announcement prior to our release, and if so what's the best vehicle for it.
tracking-firefox-esr31: --- → 34+
Keywords: sec-vector
> What happens in the future when/if Apple changes the definition of the debug options

The one my patch uses is unchanged since at least OS X 10.6.  It should be very safe to continue using it, even when it's no longer needed.

In any case, if past practice is any guide, Apple is unlikely to fix this bug anytime soon.
Whiteboard: rdar://18946701 → [adv-main34+][adv-esr31.3+] rdar://18946701
We'll use the User Story as the basis for our advisory, thanks.
Flags: needinfo?(dveditz)
Alias: CVE-2014-1595
Apple fixed this in OS X v10.10.2

http://support.apple.com/en-us/HT204244

CoreGraphics
Available for:  OS X Yosemite v10.10 and v10.10.1
Impact:  Some third-party applications with non-secure text entry and
mouse events may log those events
Description:  Due to the combination of an uninitialized variable and
an application's custom allocator, non-secure text entry and mouse
events may have been logged. This issue was addressed by ensuring
that logging is off by default. This issue did not affect systems
prior to OS X Yosemite.
CVE-ID
CVE-2014-1595 : Steven Michaud of Mozilla working with Kent Howard
Group: core-security → core-security-release
Group: core-security-release
Depends on: 1681242
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: