Difference between revisions of "Mainline Android logger project"

From eLinux.org
Jump to: navigation, search
(December 2011 LKML discussion: add notes from discussions)
Line 200: Line 200:
  
 
Notes on specific issues:
 
Notes on specific issues:
* logbuf code seems to do this now
+
* [1] logbuf/syslog(2) code seems to do this now (Greg KH, Kay Sievers)
** see systemd usage
+
** see systemd usage, which appears to coalesce stuff into /dev/kmsg
 +
*** adding warts to logbuf doesn't seem like a great idea, it's already got realtime issues that were never solved
 +
*** but integration with user and kernel messages could be nice
 +
*** integration also requires some oddities
 +
**** do you convert the log message fields (pid and priority) to structured text, and parse them out again later
 +
**** note that systemd added support for priorities and/or tags to logbuf (Kay Seivers) see
 +
** the ioctl for logger looks a lot like syslog(2), any way to consolidate?
 +
*** you'd have to add channels to syslog(2), if you wanted to have separate channels
 +
 
 +
* [2] hardcoded names and number of logs in user-space and the kernel (David Brown, Neil Brown, Andrew Morton)
 +
** no argument there (Brian Swetland)
 +
 
 +
* [3] logbuf filesystem idea (Neil Brown)
 +
<pre>
 +
If you created a 'logbuf' filesystem that used libfs to provide a single
 +
directory in which privileged processes could create files then you wouldn't
 +
need the kernel to "know" the allowed logs: radio, events, main, system.
 +
The size could be set by ftruncate() (by privileged used again) rather than
 +
being hardcoded.
 +
 
 +
You would define 'read' and 'write' much like you currently do to create a list of
 +
datagrams in a circular buffer and replace the ioctls by more standard
 +
interfaces:
 +
 
 +
LOGGER_GET_LOG_BUG_SIZE would use 'stat' and the st_blocks field
 +
LOGGER_GET_LOG_LEN would use 'stat' and the st_size field
 +
LOGGER_GET_NEXT_ENTRY_LEN could use the FIONREAD ioctl
 +
LOGGER_FLUSH_LOG could use ftruncate
 +
</pre>
 +
 
 +
** this fixes (2) by allowing arbitrary logs created by user space
 +
*** unfortunately, the log channels don't exist until after user space is up a while
 +
*** maybe could hardcode a mechanism for a default system log at startup, with other to follow
 +
** Greg KH also asks why we need a new interface for this rather than logbuf/syslog(2)
 +
 
 +
* [4] features, requirements and wishlist (Brian Swetland)
 +
** avoid hardcoding the names and sizes of the logs
 +
** adjust permissions so that some apps can only read back their own log messages (security by pid or by channel?)
 +
** allow logs to survive reboot
 +
** allow an app to create it's own log, up to a specified size limit, but in a way that wouldn't
 +
consume too much memory systemwide
 +
<pre>
 +
The goals behind the logger driver have been:
 +
- keep userland and kernel logging separate (so that spammy userland
 +
logging doesn't make us lose critical kernel logs or the other way
 +
round)
 +
- make log writing very inexpensive -- avoid having to pass messages
 +
between processes (more critical on ARM9 platforms where this implied
 +
extra cache flushing), avoid having to make several syscalls to write
 +
a log message (getting time of day, etc), and so on
 +
- make log writing reliable -- don't trust userland to report its
 +
timestamp, PID, or to correctly format the datagrams, etc
 +
- allow a log watching process (logcat) to easily pull data from all
 +
logs at once
 +
- avoid committing a vast amount of memory to logging
 +
- try to prevent clients from spamming each other out of log space
 +
(only successful on a coarse granularity right now with the
 +
main/system/radio/events logs)
 +
- ensure logs are not lost at the moment an app crashes
 +
</pre>
 +
 
 +
* [6] separate log channels are not needed or desirable (Kay Sievers)
 +
** for early boot and debug, you want interleaving
 +
 
 +
* [7] write cost is not a problem (Kay Sievers, )
 +
** I have no numbers, but suspect there is no problem
 +
 
 +
* [8] userspace printk tty driver (Greg KH, Kay Sievers mentioned it)
 +
** I never heard of it - need to do some research I guess
 +
 
 +
* [9] Google doesn't see a need to invest in switching (Brian Swetland)
 +
<pre>
 +
Having a bunch of people suggest how we can just rewrite our userspace
 +
to get something similar but not really the same as the functionality
 +
we already have registers as "big waste of our time."
 +
 
 +
Replacing a tiny, self-contained, and reliable driver that's worked
 +
for us for five-ish years with a pile of userspace surgery is
 +
uninteresting to me.
 +
</pre>
 +
 
 +
* [10] Kay Siever's wishlist - kmsg with structured data (Kay Sievers - who else?)
 +
** supports structured data, with can use with current tools
 +
** each record has timestamp, log facility, log level, string (no pid)
 +
** timestamp converted on output (not saved as text in log)
 +
** record dictionary (key=value pairs)
 +
** single channel
 +
** systemd has ASCII-like stream format for structured data
 +
** on top of existing logbuf code
 +
 
 +
* [11] avoid log spam (Brian Swetland)
 +
** logger uses multiple channels
 +
** systemd journal maintains separate journal per uid (Kay)
 +
 
 +
* [12] allow for eventual per-process log security (Brian Swetland)
 +
** logger could use multiple channels
 +
** systemd journal maintains separate journal per uid (Kay)
  
 
== Project task list ==
 
== Project task list ==

Revision as of 18:16, 10 January 2012

This page is for managing information related to the "Mainline Android Logger" project of the CE Workgroup. This is part of the Android Mainlining Project.


Android logger issues

This section describes some attributes of the Android logger code, which are relevant for mainlining the code into Linux. Let's use a modified SWOT (Strengths, Weaknesses, Opportunities, Threats) analysis for strategic planning to mainline this code.

To find the logger's strengths and weaknesses, lets research and provide information and hard numbers for how it compares with existing logging alternatives.

Alternatives

What are the alternatives to the Android logger?

  • logbuf (the kernel log buffer)
    • apparently, systemd uses
  • syslog
  • "the journal" - a new logging system for systemd (by Lennart Poettering)
  • Neil Brown's log-pipe idea
  • Arnd Bergmann's tmpfs idea

What are the pros and cons of each system (see feature matrix below)

Existence

Does the system or proposed alternative currently exist?

How much work would it be to create it?

How much work would it be to test it to confirm that it had the same semantics as current Android logger?

Performance

How much overhead does each logging system have?

How long does it take to write 1 million messages, for each of the above systems?

How many context switches are required to log a single message?

How long is each message, on average?

How many data copies are performed for each message?

What is the average time to write each message, from the caller's perspective?

Size

What are the space requirements for each logging system?

what is the code footprint in the kernel?

What is the data footprint in the kernel?

What is the code footprint in user-space?

What is the data footprint in user-space?

Are any other modules are required solely to support logging?

What is the size required in persistent storage?

Can the size be limited (at compile-time?, at boot-time?, at run-time?)

Can the size be adjusted (at boot-time?, at run-time?)

Given default sizes, and expected logging rates, how much time does each system record?

Maintainability

How much does each system need to be maintained?

How many changes have been made to the each system in the last 3 years?

Are any significant changes expected in the future?

Configurability

What things can be configured at compile-time and run-time for each system?

Features

What features does each of the log systems have?

Attribute logger logbuf syslog Notes
multiple channels yes no no? allows for separation of data to prevent overrun
can limit space used yes yes ?
cost to write 1M messages ? ? ? need to benchmark
average cost to write a message ? ? ? need to measure
average message size ? ? ? need to measure
RAM required for complete logger system ? ? ? need to measure (should include code space)
amount of flash or disk required for complete logger system ? ? ? need to measure (should include code space)
user daemon required? no no yes syslog requires syslogd
networking required no no no* syslog requires network for some remote features
number of context switches per message ? ? ? need to measure
logs both kernel and user messages? no no yes? klogd puts logbuf messages into syslog?
ability to store messages persistently on target no no* yes klogd puts logbuf messages into syslog?
ability to store messages persistently on host yes* no yes
  • adb logcat is builtin command for android
  • you can use 'remote shell:dmesg >log.txt' on most embedded systems, but it's not really a design principle of logbuf
  • syslog is built with remote message access integrated into the system
integrated into existing debug tools yes no? no? I don't know of anything but target-side tools (dmesg, cat /var/log) that "know" about logbuf and syslog
ability to filter messages by tag yes no ? does syslog require tagging, is grep used for syslog tagging?
ease of use high low medium
  • Android has facilities for logging available throughout the system (CLI, C/C++, Java), as well as good tool integration for readout and filtering
  • klogd has 'echo >/dev/kmsg', but nothing else integrated into user-space stack
  • syslog has logger, and libc calls (openlog, syslog, closelog)
tool support toolbox, adb busybox, standalone dmesg, klogd busybox, standalone logger, syslogd
API stability high* high high One change, to add 'system' channel in Android, in last 3 years. System channel separates system log messages from application log messages to prevent buffer exhaustion in case of a chatty application.

Extension questions

Here are some questions about how the systems could be integrated:

  • What features could each log system have, if extended?
  • Would extension to an existing system interfere with it's current primary purpose?
  • For each change contemplated, can it be implemented to minimize the impact to existing code?

Barriers to entry as is (Weaknesses)

Does logger duplicate functionality that exists elsewhere? Does it make sense to extend an existing system, rather than implement a new system?

What are barriers to entry:

  • use of ioctl?
  • hardcoded number of log channels
  • other style issues?
  • longterm maintainer?

Attractive features of logger as is (Strengths)

What are the differentiating features of logger, compared to alternatives?

  • minimal context switches for logging
  • use of ring buffer automatically limits log size
  • log is in memory (no cost to store unused log messages)
  • all messages are tagged
  • all messages have priority
  • all messages have timestamp
  • user-space program to filter messages by tag
  • channel selection by user-space policy

Discussions

This section has notes about discussions with the community kernel developers and with Google engineers, with regards to mainlining this code

Google engineer requests/questions

  • Google doesn't want to change their class libraries or debug system
    • These have already shipped to developers and are integrated into other tools (eclipse log viewer)
    • the Android system and over 200,000 applications already use the existing classes
    • (So, can changes be made "under the hood" without changing the existing user interface?)
  • Google requests that any changes submitted to mainline also be placed in their kernel repository (or Gerrit review queue), so they can see them when they do merges and are not caught off guard.
    • I'm not sure the detailed steps required to perform this
  • Question: Why did Google write their own code, instead of using syslog?
    • Was it simply expedience, lack of familiarity with syslog, or are there specific reasons they wrote a new system (missing features, etc.)?

Community feedback/input/questions

  • Alessio - In my opinion syslog shouldn't be compared with neither Android's logger nor logbuf because:
  1. Buggy syslog implementation (or future changes) could shutdown the entire log infrastructure (logger and logbuf aren't supposed to change a lot in future)
  2. Logbuf and logger don't require writeable file system access which is mandatory for syslog. A no-writeable files-system (or a file-system which allow only few writes) is a common situation in embedded world.
  3. Logbuf and logger don't require maintenance work (no rotate, compress or purge old log files). A mandatory feature in consumer devices.

The advantages of logger over logbuf are:

  1. Logger's logs are shared among a unknown number of user space programs logbuf are writable only by kernel itself
  2. Logger's log are separated: An wild user space program couldn't fill up all logs.
  3. Write path in logger is optimized over all else

December 2011 LKML discussion

Here is the thread:

Notes on specific issues:

  • [1] logbuf/syslog(2) code seems to do this now (Greg KH, Kay Sievers)
    • see systemd usage, which appears to coalesce stuff into /dev/kmsg
      • adding warts to logbuf doesn't seem like a great idea, it's already got realtime issues that were never solved
      • but integration with user and kernel messages could be nice
      • integration also requires some oddities
        • do you convert the log message fields (pid and priority) to structured text, and parse them out again later
        • note that systemd added support for priorities and/or tags to logbuf (Kay Seivers) see
    • the ioctl for logger looks a lot like syslog(2), any way to consolidate?
      • you'd have to add channels to syslog(2), if you wanted to have separate channels
  • [2] hardcoded names and number of logs in user-space and the kernel (David Brown, Neil Brown, Andrew Morton)
    • no argument there (Brian Swetland)
  • [3] logbuf filesystem idea (Neil Brown)
If you created a 'logbuf' filesystem that used libfs to provide a single
directory in which privileged processes could create files then you wouldn't
need the kernel to "know" the allowed logs: radio, events, main, system.
The size could be set by ftruncate() (by privileged used again) rather than
being hardcoded.

You would define 'read' and 'write' much like you currently do to create a list of
datagrams in a circular buffer and replace the ioctls by more standard
interfaces:

LOGGER_GET_LOG_BUG_SIZE would use 'stat' and the st_blocks field
LOGGER_GET_LOG_LEN would use 'stat' and the st_size field
LOGGER_GET_NEXT_ENTRY_LEN could use the FIONREAD ioctl
LOGGER_FLUSH_LOG could use ftruncate
    • this fixes (2) by allowing arbitrary logs created by user space
      • unfortunately, the log channels don't exist until after user space is up a while
      • maybe could hardcode a mechanism for a default system log at startup, with other to follow
    • Greg KH also asks why we need a new interface for this rather than logbuf/syslog(2)
  • [4] features, requirements and wishlist (Brian Swetland)
    • avoid hardcoding the names and sizes of the logs
    • adjust permissions so that some apps can only read back their own log messages (security by pid or by channel?)
    • allow logs to survive reboot
    • allow an app to create it's own log, up to a specified size limit, but in a way that wouldn't

consume too much memory systemwide

The goals behind the logger driver have been:
- keep userland and kernel logging separate (so that spammy userland
logging doesn't make us lose critical kernel logs or the other way
round)
- make log writing very inexpensive -- avoid having to pass messages
between processes (more critical on ARM9 platforms where this implied
extra cache flushing), avoid having to make several syscalls to write
a log message (getting time of day, etc), and so on
- make log writing reliable -- don't trust userland to report its
timestamp, PID, or to correctly format the datagrams, etc
- allow a log watching process (logcat) to easily pull data from all
logs at once
- avoid committing a vast amount of memory to logging
- try to prevent clients from spamming each other out of log space
(only successful on a coarse granularity right now with the
main/system/radio/events logs)
- ensure logs are not lost at the moment an app crashes
  • [6] separate log channels are not needed or desirable (Kay Sievers)
    • for early boot and debug, you want interleaving
  • [7] write cost is not a problem (Kay Sievers, )
    • I have no numbers, but suspect there is no problem
  • [8] userspace printk tty driver (Greg KH, Kay Sievers mentioned it)
    • I never heard of it - need to do some research I guess
  • [9] Google doesn't see a need to invest in switching (Brian Swetland)
Having a bunch of people suggest how we can just rewrite our userspace
to get something similar but not really the same as the functionality
we already have registers as "big waste of our time."

Replacing a tiny, self-contained, and reliable driver that's worked
for us for five-ish years with a pile of userspace surgery is
uninteresting to me.
  • [10] Kay Siever's wishlist - kmsg with structured data (Kay Sievers - who else?)
    • supports structured data, with can use with current tools
    • each record has timestamp, log facility, log level, string (no pid)
    • timestamp converted on output (not saved as text in log)
    • record dictionary (key=value pairs)
    • single channel
    • systemd has ASCII-like stream format for structured data
    • on top of existing logbuf code
  • [11] avoid log spam (Brian Swetland)
    • logger uses multiple channels
    • systemd journal maintains separate journal per uid (Kay)
  • [12] allow for eventual per-process log security (Brian Swetland)
    • logger could use multiple channels
    • systemd journal maintains separate journal per uid (Kay)

Project task list

  • Get needed hardware
  • Make sure contractors have all required source code:
    • AOSP, Android kernels, and logger code
  • Identify and review code before submission
    • identify possible mainline objections to code, and plan how to respond
    • compare with alternatives
      • compare and contrast logger code with kernel log buffer (e.g. dmesg vs. logcat)
        • performance, features, size,
      • compare and contrast logger code with syslog (syslogd, /var/log)
  • Submit code to LKML
  • Respond to feedback received
  • Add logger code to busybox?
    • Should this be done first?
    • log
    • logwrapper
    • logsync
    • What about logd_write.c code
      • included in bionic - should be included in busybox directly, because it's missing in glibc?
  • what about udev?
    • should mainline Linux automatically create logger devices nodes?
    • they are created by 'init' in Android systems

Volunteers

  • Sisir Koppaka

History

The proposals that led to this project are at: