5 ms·

Apple CoreGraphics framework logging input data to /tmp

138 points by rbdn 12y ago

stinos 12y ago
Well every programmer probably made a mistake like that once, twice or more (or just, every programmers makes mistakes tout-court), but imo something like this should have been caught in the pull request/code review/general testing stage as it concerns a major OS? That being said I obviously have no idea what stages precede an actual release of an OS. Anyone does?
- richardwhiuk 12y ago
  More interesting, I think, would be seeing the code change itself, which might make it easier to work out how this got through code review / testing.
- ceronman 12y ago
  The bug is triggered by using a custom memory allocator. It's clearly an edge case. There will be bugs that slip over code review and/or testing no matter what. That's a fact in software development.
  - stinos 12y ago
    Sure, but the thing is: one developper (or a group of) said 'well let's enable this' and then nobody else reviewed that or thought 'hmm, surely it can't be good to just start logging pretty much everything'? Just wondering how that happens in large companies.
    - heinrich5991 12y ago
      From the article: >In OS X 10.10, this logging was turned on by default for some applications that use a custom memory allocator, such as jemalloc, because of an initialization bug in the framework. So it seems to be a bug that it even got enabled.
    - kbar13 12y ago
      mistakes happen
    - rmorell 12y ago
      Nobody explicitly decided to enable the logging by default. It was caused by an uninitialized variable. Uninitialized variables result in undefined behavior, but can often go unnoticed in practice if the code around them results in the value in memory (or register) for that variable usually being a certain value. In this case, it happened to result in logging being disabled by default in most situations. But using jemalloc for the process rather than the standard malloc implementation was enough to cause the opposite result, apparently due to jemalloc poisoning malloc()ed regions (which overwrote the "usual" value).
      - saidajigumi 12y ago
        > It was caused by an uninitialized variable. And in case anyone thinks that sheer developer machismo (or 'rigor' or whatever) can keep you out of harm's way here, then I suggest reading John Carmack's excellent writeups on the horrors found by static code analysis.[1][2] Even the best programmers out there will get caught by any number of language traps. [1] Sadly/happily, still available via archive.org. CSS seems to be busted here, so scroll to the bottom for Carmack's article: https://web.archive.org/web/20120104024203/http://altdevblogaday.com/2011/12/24/static-code-analysis/ [2] The above was discussed on HN, and that thread is pretty good as well: https://news.ycombinator.com/item?id=3388290 https://news.ycombinator.com/item?id=3388290
- didgeoridoo 12y ago
  Erm... goto fail; goto fail;
coldcode 12y ago
Very very few OSX apps use an alternate allocator so this was probably not noticed. Having written a commercial memory allocator before (for MacOS prior to OSX) the one in OSX is actually quite good for most people. I don't know why Mozilla decided they needed jemalloc but maybe it tested better for their usage. Still you would think tracking what's written to such a common directory would have been seen by someone at Apple. Firefox isn't exactly obscure.
- deleted 12y ago
  [deleted]
- acdha 12y ago
  jemalloc goes back to Firefox 3: http://blog.pavlov.net/2007/12/04/vlad-and-analysis-of-dtrace-was-used/ http://blog.pavlov.net/2007/12/04/vlad-and-analysis-of-dtrac... http://blog.pavlov.net/2008/03/11/firefox-3-memory-usage/ http://blog.pavlov.net/2008/03/11/firefox-3-memory-usage/ It looks like that was driven by cross-platform concerns – I don't know how good the OS X allocator was in that era but it looks like most of the benchmarking focused on Windows and having a single malloc which performed well on all of their platforms. At that time, Firefox still supported at least as far back as Windows 2000 and the rise of consumer Mac usage hadn't reached current levels.
  - coldcode 12y ago
    The WinHeap allocator before 7 was pretty awful, but apparently improved with 7. Chrome is actually using it (or at least thinking of it). It still amazes me that allocation is still a hard problem 15 years after I wrote mine.
  - duaneb 12y ago
    The performance of the memory allocator is very much load-specific on darwin these days, and it would be easy to justify jemalloc. It's certainly not a poor choice of an allocator.
    - acdha 12y ago
dahjelle 12y ago
I'm using Firefox Developer Edition, and I don't see any CGLog_* files in /tmp at all. Am I missing something?
- ZoF 12y ago
  >This issue has been addressed in Mozilla products by explicitly turning off the framework's logging of input events. It's fixed now and anything you had in there was already auto-deleted at some point. You're likely not missing anything.
  - dahjelle 12y ago
    Awesome—thanks!
Create 12y ago
OpenSSL came with its own memory allocator, which is basically an optimistic allocator and caching wrapper around libc malloc()/free() that tries to save calls to malloc() by not actually free()ing blocks immediately but holding onto them for some time. This allows them to skip the actual memory allocation as long as they can accommodate any incomming malloc() calls from their unused blocks buffer, and if it actually has to allocate fresh memory it doesn't just allocate the amount of memory needed but speculatively allocates more and stashes the excess in its unused blocks buffer. One of the artifacts of this behavior is that OpenSSL data isn't evenly spread throughout a processes heap, which is what one would expect if the memory was allocated purely on demand, but tends to cluster in regions that can be fairly long-lived. Now, what actually happens with Heartbleed is that it can only leak data directly adjacent in virtual memory to the data segment containing the Heartbeat payload, but due to that clustering of memory in use by OpenSSL the chances are fairly high this isn't just some random block of memory from the application's heap but a block containing other OpenSSL data. Like decrypted HTTPS requests, with passwords and stuff.
- to3m 12y ago
  I don't understand the relevance.
  - Create 12y ago
    The bug is triggered by using a custom memory allocator. It's clearly an edge case.
  - eis 12y ago
    This user seems to be a bot posting snippets of text he found "relevant".
- tljr 12y ago
  wut?
jheriko 12y ago
another apple 101 screwup. lets hope that this helps encourage them improve their QA process to the point where they at least test real world applications a bit more heavily (or at all). :)
stevep98 12y ago
I didn't see any logs for firefox, but did see a similar file for Google Earth... "/tmp/CGLog_Google Earth_7790" full of: 7629.0413465 (Google Earth): CGSGetNextEventRecordInternal: 7629.0410916 loc (90.4, 934.0) conn 0x34b5f MouseMoved win 0x4a0 (click 1) 7629.0581342 (Google Earth): CGSGetNextEventRecordInternal: 7629.0578892 loc (84.4, 929.0) conn 0x34b5f MouseMoved win 0x4a0 (click 1) 7629.0750728 (Google Earth): CGSGetNextEventRecordInternal: 7629.0749128 loc (70.4, 918.0) conn 0x34b5f MouseExited win 0x4a0 tArea 0x19494 7629.0750766 (Google Earth): CGSGetNextEventRecordInternal: 7629.0749338 loc (70.4, 918.0) conn 0x34b5f MouseExited win 0x4a0 tArea 0x19493

138 points by rbdn 12y ago

Well every programmer probably made a mistake like that once, twice or more (or just, every programmers makes mistakes tout-court), but imo something like this should have been caught in the pull request/code review/general testing stage as it concerns a major OS? That being said I obviously have no idea what stages precede an actual release of an OS. Anyone does?

richardwhiuk 12y ago
More interesting, I think, would be seeing the code change itself, which might make it easier to work out how this got through code review / testing.
ceronman 12y ago
The bug is triggered by using a custom memory allocator. It's clearly an edge case. There will be bugs that slip over code review and/or testing no matter what. That's a fact in software development.
- stinos 12y ago
  Sure, but the thing is: one developper (or a group of) said 'well let's enable this' and then nobody else reviewed that or thought 'hmm, surely it can't be good to just start logging pretty much everything'? Just wondering how that happens in large companies.
  - heinrich5991 12y ago
    From the article: >In OS X 10.10, this logging was turned on by default for some applications that use a custom memory allocator, such as jemalloc, because of an initialization bug in the framework. So it seems to be a bug that it even got enabled.
  - kbar13 12y ago
    mistakes happen
  - rmorell 12y ago
    Nobody explicitly decided to enable the logging by default. It was caused by an uninitialized variable. Uninitialized variables result in undefined behavior, but can often go unnoticed in practice if the code around them results in the value in memory (or register) for that variable usually being a certain value. In this case, it happened to result in logging being disabled by default in most situations. But using jemalloc for the process rather than the standard malloc implementation was enough to cause the opposite result, apparently due to jemalloc poisoning malloc()ed regions (which overwrote the "usual" value).
    - saidajigumi 12y ago
      > It was caused by an uninitialized variable. And in case anyone thinks that sheer developer machismo (or 'rigor' or whatever) can keep you out of harm's way here, then I suggest reading John Carmack's excellent writeups on the horrors found by static code analysis.[1][2] Even the best programmers out there will get caught by any number of language traps. [1] Sadly/happily, still available via archive.org. CSS seems to be busted here, so scroll to the bottom for Carmack's article: https://web.archive.org/web/20120104024203/http://altdevblogaday.com/2011/12/24/static-code-analysis/ [2] The above was discussed on HN, and that thread is pretty good as well: https://news.ycombinator.com/item?id=3388290 https://news.ycombinator.com/item?id=3388290
didgeoridoo 12y ago
Erm... goto fail; goto fail;

coldcode 12y ago

Very very few OSX apps use an alternate allocator so this was probably not noticed. Having written a commercial memory allocator before (for MacOS prior to OSX) the one in OSX is actually quite good for most people. I don't know why Mozilla decided they needed jemalloc but maybe it tested better for their usage. Still you would think tracking what's written to such a common directory would have been seen by someone at Apple. Firefox isn't exactly obscure.

deleted 12y ago
[deleted]
acdha 12y ago
jemalloc goes back to Firefox 3: http://blog.pavlov.net/2007/12/04/vlad-and-analysis-of-dtrace-was-used/ http://blog.pavlov.net/2007/12/04/vlad-and-analysis-of-dtrac... http://blog.pavlov.net/2008/03/11/firefox-3-memory-usage/ http://blog.pavlov.net/2008/03/11/firefox-3-memory-usage/ It looks like that was driven by cross-platform concerns – I don't know how good the OS X allocator was in that era but it looks like most of the benchmarking focused on Windows and having a single malloc which performed well on all of their platforms. At that time, Firefox still supported at least as far back as Windows 2000 and the rise of consumer Mac usage hadn't reached current levels.
- coldcode 12y ago
  The WinHeap allocator before 7 was pretty awful, but apparently improved with 7. Chrome is actually using it (or at least thinking of it). It still amazes me that allocation is still a hard problem 15 years after I wrote mine.
- duaneb 12y ago
  The performance of the memory allocator is very much load-specific on darwin these days, and it would be easy to justify jemalloc. It's certainly not a poor choice of an allocator.
  - acdha 12y ago

dahjelle 12y ago

I'm using Firefox Developer Edition, and I don't see any CGLog_* files in /tmp at all. Am I missing something?

ZoF 12y ago
>This issue has been addressed in Mozilla products by explicitly turning off the framework's logging of input events. It's fixed now and anything you had in there was already auto-deleted at some point. You're likely not missing anything.
- dahjelle 12y ago
  Awesome—thanks!

Create 12y ago

OpenSSL came with its own memory allocator, which is basically an optimistic allocator and caching wrapper around libc malloc()/free() that tries to save calls to malloc() by not actually free()ing blocks immediately but holding onto them for some time. This allows them to skip the actual memory allocation as long as they can accommodate any incomming malloc() calls from their unused blocks buffer, and if it actually has to allocate fresh memory it doesn't just allocate the amount of memory needed but speculatively allocates more and stashes the excess in its unused blocks buffer. One of the artifacts of this behavior is that OpenSSL data isn't evenly spread throughout a processes heap, which is what one would expect if the memory was allocated purely on demand, but tends to cluster in regions that can be fairly long-lived. Now, what actually happens with Heartbleed is that it can only leak data directly adjacent in virtual memory to the data segment containing the Heartbeat payload, but due to that clustering of memory in use by OpenSSL the chances are fairly high this isn't just some random block of memory from the application's heap but a block containing other OpenSSL data. Like decrypted HTTPS requests, with passwords and stuff.

to3m 12y ago
I don't understand the relevance.
- Create 12y ago
  The bug is triggered by using a custom memory allocator. It's clearly an edge case.
- eis 12y ago
  This user seems to be a bot posting snippets of text he found "relevant".
tljr 12y ago
wut?

jheriko 12y ago

another apple 101 screwup. lets hope that this helps encourage them improve their QA process to the point where they at least test real world applications a bit more heavily (or at all). :)

stevep98 12y ago

I didn't see any logs for firefox, but did see a similar file for Google Earth... "/tmp/CGLog_Google Earth_7790" full of: 7629.0413465 (Google Earth): CGSGetNextEventRecordInternal: 7629.0410916 loc (90.4, 934.0) conn 0x34b5f MouseMoved win 0x4a0 (click 1) 7629.0581342 (Google Earth): CGSGetNextEventRecordInternal: 7629.0578892 loc (84.4, 929.0) conn 0x34b5f MouseMoved win 0x4a0 (click 1) 7629.0750728 (Google Earth): CGSGetNextEventRecordInternal: 7629.0749128 loc (70.4, 918.0) conn 0x34b5f MouseExited win 0x4a0 tArea 0x19494 7629.0750766 (Google Earth): CGSGetNextEventRecordInternal: 7629.0749338 loc (70.4, 918.0) conn 0x34b5f MouseExited win 0x4a0 tArea 0x19493