1# Log Compression instead of Chatty in Android S 2 3## The problem 4 5* Log buffer space is precious, but suffers from the tragedy of the commons 6* Log spam fills the buffers making them less useful in logcat/bugreports 7* “Spam” is often in the eye of the beholder: which messages are important depends on what you’re trying to debug 8 9## The idea 10 11* Chatty isn’t helping as much as we’d hoped, and is surprisingly expensive 12* Compress logs to make more efficient use of the buffer 13* Address the root cause of log spam at its source: 14 * Do not hide log spam at runtime, which de-incentivize fixes 15 * Add presubmit coverage similar to SELinux violations to keep log spam down 16 17--- 18 19## Chatty in Theory 20 21* Delete messages classified as spam to extend the range of logs from other sources 22* “Spam” defined as: 23 * Logs from UIDs whose logs consume over 12.5% of a log buffer 24 * Back-to-back exact duplicate messages 25 26## Chatty in Practice 27 28* Developer confusion about missing and de-duplicated logs 29* Lowered incentive to fix the root cause of bad logging behavior 30* High CPU overhead 31* Memory usage greatly exceeds configured buffer size 32* Only marginal increase in log range 33 34--- 35 36## Log Compression in Theory 37 38* Store many more logs in the same log buffer size => better for diagnosis 39* Memory usage stays below configured log size => better system health 40* No gaps in logs, no de-duplicated logs => no developer confusion 41* No hiding bad behavior => increased accountability/incentive to fix root causes 42 43## Log Compression Preliminary Results 44 45* Captured 2, 5 day periods of full time personal usage of Pixel 4 and replayed the logs offline 46* Compression vs Chatty: 47 * **3.5x more log messages on average** 48 * **50% less CPU usage** 49 * **50% less memory usage** 50 51--- 52 53## Log Messages in 1MB 54 55* The number of log messages still available in logcat after ‘Message Count’ messages have been logged to a 1MB log buffer 56* Note: ‘Simple’ is the Chatty code without log spam detection and without de-duplication. 57 58 59 60--- 61 62## CPU Time 63 64* Total CPU time on ARM64 (Walleye) and 32bit x86 (Cuttlefish) 65* X axis represents different log buffer size configurations. 66 * Chatty uses significantly more CPU time at 1MB (the default Pixel configuration) 67 * Chatty scales poorly with increased log buffer sizes 68* Note: “simple” isn’t “compression without actually compressing”, it’s “chatty without doing the chatty elimination”, which is why “simple” is more expensive than “compression” on walleye. 69 70 71 72 73--- 74 75## Memory Usage 76 77* The memory used by ‘Message Count’ messages, on both Walleye and Cuttlefish 78* Note: Chatty does not consider the metadata (UID, PID, timestamp, etc) in its calculation of log buffer size, so a 1MB log buffer will consume more than 1MB. Note that there are 8 log buffers, 5 of which are typically filled. 79 80 81 82
