* Re: RFC: android logger feedback request
From: Greg KH @ 2011-12-22 1:49 UTC (permalink / raw)
To: NeilBrown
Cc: Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <20111222122026.3a0fae36@notabene.brown>
On Thu, Dec 22, 2011 at 12:20:26PM +1100, NeilBrown wrote:
> On Wed, 21 Dec 2011 16:36:21 -0800 Tim Bird <tim.bird@am.sony.com> wrote:
>
> > On 12/21/2011 03:19 PM, Greg KH wrote:
> > > That all describes the current code, but you haven't described what's
> > > wrong with the existing syslog interface that requires this new driver
> > > to be written. And why can't the existing interface be fixed to address
> > > these (potential) shortcomings?
> >
> >
> > >> One specific question I have is where is the most appropriate
> > >> place for this code to live, in the kernel source tree?
> > >> Other embedded systems might want to use this system (it
> > >> is simpler than syslog, and superior in some ways), so I don't
> > >> think it should remain in an android-specific directory.
> > >
> > > What way is it superior?
> >
> > Here are some ways that this code is superior to syslog:
>
> It is certainly nice and simple. It really looks more like a filesystem than
> a char device though... though they aren't really files so much as lossy
> pipes. I don't think that's a problem though, lots of things in filesystems
> don't behave exactly like files.
>
> 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 defined '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
>
> The result would be much the same amount of code, but an interface which has
> fewer details hard-coded and is generally more versatile and accessible.
But, almost all of this is already in the syslog system call today,
right? So why create a new user api for something we have?
greg k-h
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Tim Bird @ 2011-12-22 2:12 UTC (permalink / raw)
To: Greg KH
Cc: linux-embedded, linux kernel, Arnd Bergmann, john stultz,
Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <20111222014718.GA13085@suse.de>
On 12/21/2011 05:47 PM, Greg KH wrote:
> On Wed, Dec 21, 2011 at 05:32:36PM -0800, Tim Bird wrote:
>> On 12/21/2011 04:51 PM, Greg KH wrote:
>>> On Wed, Dec 21, 2011 at 04:36:21PM -0800, Tim Bird wrote:
>>>> On 12/21/2011 03:19 PM, Greg KH wrote:
>>
>>> Huh, I'm not talking about syslogd, I'm talking about the syslog(2)
>>> syscall we have.
>>
>> OK - switching gears. Since the kernel log buffer isn't normally
>> used to store use-space messages, I thought you were referring
>> to syslog(3) and the associated (logger(1) and syslogd(8)).
>
> The kernel log buffer has been storing userspace messages for a while
> now, look at your boot log on the latest Fedora and openSUSE releases
> (or any other distro using systemd for booting).
Sorry - I don't have a distro that uses systemd.
I'm completely unaware of this use of the kernel log for user-space
message logging. No wonder Lennart and Kay
are so hot on making a new logging system. It seems sub-optimal
to me, to intermingle a structured log with a pure-ASCII log.
> Again, please see what we are already doing in the kernel and userspace,
> I think a lot of the above is already implemented.
I don't know what systemd has got going on in user-space. I'm looking
at a very recent kernel, and I see no support for multiple log channels,
or an optimized open/write path.
Maybe Lennart could save me some time doing this research.
Lennart,
How does current systemd prevent user-space messages from crowding
out kernel messages? (or vice-versa). Since you've been doing
a lot of work on logging, do you have any existing metrics for logging
overhead via the kernel log buffer?
> Which brings me back to my original question, what does this code do,
> that is not already present in the kernel, and why is a totally new
> interface being proposed for it?
At the least, it supports multiple log channels. Quite frankly my mind
has been blown a bit by the suggestion to overload the kernel log buffer
with user-space messages. I would never have gone that route. But I'll have
to find out more about this systemd thing to answer your question.
Secondly, this is not a particularly new or radical interface. It is new
to legacy Linux, but it's been in the Android Linux kernel for some years
now, and it has worked well.
-- Tim
=============================
Tim Bird
Architecture Group Chair, CE Workgroup of the Linux Foundation
Senior Staff Engineer, Sony Network Entertainment
=============================
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Tim Bird @ 2011-12-22 2:14 UTC (permalink / raw)
To: NeilBrown
Cc: Greg KH, linux-embedded, linux kernel, Arnd Bergmann, john stultz,
Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <20111222122026.3a0fae36@notabene.brown>
On 12/21/2011 05:20 PM, NeilBrown wrote:
> It is certainly nice and simple. It really looks more like a filesystem than
> a char device though... though they aren't really files so much as lossy
> pipes. I don't think that's a problem though, lots of things in filesystems
> don't behave exactly like files.
>
> 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 defined '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
>
> The result would be much the same amount of code, but an interface which has
> fewer details hard-coded and is generally more versatile and accessible.
This is a very interesting suggestion. I think it would be good to
create a prototype of this and see how it affects the user-space code
as well as what the kernel-side issues would be (and to check whether
this would change any of the current logger semantics).
It would also have the side effect of allowing runtime modification of
the buffer size, though I'm not sure whether that's useful or not.
Thanks!
-- Tim
=============================
Tim Bird
Architecture Group Chair, CE Workgroup of the Linux Foundation
Senior Staff Engineer, Sony Network Entertainment
=============================
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Brian Swetland @ 2011-12-22 2:34 UTC (permalink / raw)
To: NeilBrown
Cc: Tim Bird, Greg KH, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <20111222122026.3a0fae36@notabene.brown>
On Wed, Dec 21, 2011 at 5:20 PM, NeilBrown <neilb@suse.de> wrote:
> On Wed, 21 Dec 2011 16:36:21 -0800 Tim Bird <tim.bird@am.sony.com> wrote:
>
>> On 12/21/2011 03:19 PM, Greg KH wrote:
>> > That all describes the current code, but you haven't described what's
>> > wrong with the existing syslog interface that requires this new driver
>> > to be written. And why can't the existing interface be fixed to address
>> > these (potential) shortcomings?
>>
>> >> One specific question I have is where is the most appropriate
>> >> place for this code to live, in the kernel source tree?
>> >> Other embedded systems might want to use this system (it
>> >> is simpler than syslog, and superior in some ways), so I don't
>> >> think it should remain in an android-specific directory.
>> >
>> > What way is it superior?
>>
>> Here are some ways that this code is superior to syslog:
>
> It is certainly nice and simple. It really looks more like a filesystem than
> a char device though... though they aren't really files so much as lossy
> pipes. I don't think that's a problem though, lots of things in filesystems
> don't behave exactly like files.
>
> 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 defined '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
>
> The result would be much the same amount of code, but an interface which has
> fewer details hard-coded and is generally more versatile and accessible.
Moving away from hard coding the names/sizes of the logs in the driver
is something that has been on the todo list for a while. One thing
we'd likely want to accomplish there is avoid creating a vector for
consuming large amounts of memory by creating new logs.
One planned change (likely to happen in the Android J release
timeframe) is to adjust permissions such that any process can write
messages, but unless they belong to the correct group they can only
read back messages written by their own PID. This is to allow apps to
grab their own log output after a crash or during a user problem
report without needing to grant them the ability to read all log
messages.
Currently the logger driver does not provide a mechanism for allowing
logs to survive a reboot (unlike the ramconsole), but this is
functionality that we've thought about adding. Generally the kernel
logs are most interesting after an unexpected panic/reboot, but
getting a picture of what userspace has been up to can be useful too.
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
On one hand, having each app (per PID) be able to create their own
logs up to a specified size limit could be really useful and is
something we've kicked around -- for one it would allow us to avoid
the ever present request from userspace developers to increase the log
size because of too much log spam ("reduce log spam" never seems to be
an answer that makes them happy) -- but we haven't come up with a
reasonable plan for dealing with "well if we allow 16KB of log per app
and the user installs 100 apps, they may be pinning up to 1.6MB of ram
worst case", and so on.
Brian
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Kay Sievers @ 2011-12-22 2:34 UTC (permalink / raw)
To: Greg KH
Cc: Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Brian Swetland, Lennart Poettering
In-Reply-To: <20111222014718.GA13085@suse.de>
On Thu, Dec 22, 2011 at 02:47, Greg KH <gregkh@suse.de> wrote:
> On Wed, Dec 21, 2011 at 05:32:36PM -0800, Tim Bird wrote:
>> On 12/21/2011 04:51 PM, Greg KH wrote:
>> > On Wed, Dec 21, 2011 at 04:36:21PM -0800, Tim Bird wrote:
>> >> On 12/21/2011 03:19 PM, Greg KH wrote:
>>
>> > Huh, I'm not talking about syslogd, I'm talking about the syslog(2)
>> > syscall we have.
>>
>> OK - switching gears. Â Since the kernel log buffer isn't normally
>> used to store use-space messages, I thought you were referring
>> to syslog(3) and the associated (logger(1) and syslogd(8)).
>
> The kernel log buffer has been storing userspace messages for a while
> now, look at your boot log on the latest Fedora and openSUSE releases
> (or any other distro using systemd for booting).
Right, and the kernel's printk buffer support numbered facilities,
like the syslog protocol defines, just fine.
Stuff injected into the kernel from userspace can easily distinguished
from kernel generated messages when pulled out by userspace.
We use that currently to do early boot logging, when no syslog is running:
http://git.kernel.org/?p=linux/kernel/git/torvalds/linux.git;a=commitdiff;h=9d90c8d9cde929cbc575098e825d7c29d9f45054
Kay
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Kay Sievers @ 2011-12-22 3:44 UTC (permalink / raw)
To: Tim Bird
Cc: Greg KH, linux-embedded, linux kernel, Arnd Bergmann, john stultz,
Brian Swetland, Lennart Poettering
In-Reply-To: <4EF29217.7040408@am.sony.com>
On Thu, Dec 22, 2011 at 03:12, Tim Bird <tim.bird@am.sony.com> wrote:
> On 12/21/2011 05:47 PM, Greg KH wrote:
>> Again, please see what we are already doing in the kernel and userspace,
>> I think a lot of the above is already implemented.
>
> I don't know what systemd has got going on in user-space. I'm looking
> at a very recent kernel, and I see no support for multiple log channels,
> or an optimized open/write path.
> How does current systemd prevent user-space messages from crowding
> out kernel messages? (or vice-versa).
It intentionally doesn't. Splitting messages in separate stores is not
what we want in the general use case.
Syslog has the 'facility' for that, and it works just good enough. We
think that filtering in the receiver is more flexible and useful, than
to have multiple stores of pretty much the same type.
If you have multiple stores, you always have to fight the ordering
problem, and that really creates problems sometimes.
We are very convinced, that there should be a single entry only for
logging, and not multiple, and the filtering should happen on the
receiver side.
> Since you've been doing
> a lot of work on logging, do you have any existing metrics for logging
> overhead via the kernel log buffer?
Which overhead? I don't really think that is too interesting. Writing
to a device node or socket and copy it to the kernel's ring buffer,
not sure if it has an interesting potential of being optimized, if you
don't use fancy consoles and such.
We have no numbers, but until I see numbers of a real world problem, I
would expect there is no actual problem.
>> Which brings me back to my original question, what does this code do,
>> that is not already present in the kernel, and why is a totally new
>> interface being proposed for it?
>
> At the least, it supports multiple log channels. Quite frankly my mind
> has been blown a bit by the suggestion to overload the kernel log buffer
> with user-space messages. I would never have gone that route. But I'll have
> to find out more about this systemd thing to answer your question.
It's just fine. And honestly, for early boot and debugging
interleaving is exactly what you want, because userspace is triggering
the actions in the kernel, and you want to see that in the same
channel.
Also you can use netconsole and all the weird stuff people support for
the kernel and get the messages from early boot userspace including
intramfs there.
> Secondly, this is not a particularly new or radical interface. It is new
> to legacy Linux, but it's been in the Android Linux kernel for some years
> now, and it has worked well.
Sure, it's understandable, it sounds like something that made sense
when it was invented, and which probably still make a lot of sense for
Android today. But I don't think it should be discussed as a general
purpose Linux use case, or something that replaces kmsg. It does not
look like too interesting for general needs today outside of Android.
We probably just want the simple stuff we have today, or something
that really solves the structured logging problem in a proper way.
Something slightly better, with almost the same model and limitations,
than what we have already, is probably not that important enough to
make changes.
Thanks,
Kay
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Greg KH @ 2011-12-22 3:45 UTC (permalink / raw)
To: Tim Bird
Cc: linux-embedded, linux kernel, Arnd Bergmann, john stultz,
Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <4EF29217.7040408@am.sony.com>
On Wed, Dec 21, 2011 at 06:12:39PM -0800, Tim Bird wrote:
> Secondly, this is not a particularly new or radical interface. It is new
> to legacy Linux, but it's been in the Android Linux kernel for some years
> now, and it has worked well.
Sorry, but you know full well that is not a justification for _any_
chunk of code to be included in the main kernel tree. Staging is fine,
but to add a new kernel/user api that looks at first glance, to merely
duplicate the existing in-kernel apis needs a very good explaination for
why it needs to be included.
greg k-h
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Greg KH @ 2011-12-22 3:47 UTC (permalink / raw)
To: Tim Bird
Cc: linux-embedded, linux kernel, Arnd Bergmann, john stultz,
Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <4EF29217.7040408@am.sony.com>
On Wed, Dec 21, 2011 at 06:12:39PM -0800, Tim Bird wrote:
> > Again, please see what we are already doing in the kernel and userspace,
> > I think a lot of the above is already implemented.
>
> I don't know what systemd has got going on in user-space. I'm looking
> at a very recent kernel, and I see no support for multiple log channels,
> or an optimized open/write path.
How is the existing syslog read path not "optimized"? What kind of
speed and numbers are we talking about here?
Oh, and you do know about the userspace printk tty driver, right? What
about using that combined with the existing syslog system call?
systemd doesn't use it, but I know of a few embedded systems that are
already using it today, and I think it might solve the android issues
already.
thanks,
greg k-h
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Greg KH @ 2011-12-22 3:49 UTC (permalink / raw)
To: Brian Swetland
Cc: NeilBrown, Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <CANqkERC+mdSGxk4tiU7+dbauSXqqANN+Z+TTb_pVXoPq+k=rJg@mail.gmail.com>
On Wed, Dec 21, 2011 at 06:34:08PM -0800, Brian Swetland wrote:
> 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)
Wouldn't a simple userspace daemon solve this, writing the data to a
ramfs file?
> - 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
ramfs?
> - make log writing reliable -- don't trust userland to report its
> timestamp, PID, or to correctly format the datagrams, etc
existing userspace printk tty driver?
> - allow a log watching process (logcat) to easily pull data from all
> logs at once
what do you mean by "at once"?
> - avoid committing a vast amount of memory to logging
memory where, in code or in the data being logged?
> - 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
Which logs?
> On one hand, having each app (per PID) be able to create their own
> logs up to a specified size limit could be really useful and is
> something we've kicked around -- for one it would allow us to avoid
> the ever present request from userspace developers to increase the log
> size because of too much log spam ("reduce log spam" never seems to be
> an answer that makes them happy) -- but we haven't come up with a
> reasonable plan for dealing with "well if we allow 16KB of log per app
> and the user installs 100 apps, they may be pinning up to 1.6MB of ram
> worst case", and so on.
I think the userspace printk and syslog might already handle most of
this today. Tim, care to look into that and see if it does or not?
thanks,
greg k-h
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Kay Sievers @ 2011-12-22 4:12 UTC (permalink / raw)
To: Greg KH
Cc: Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Brian Swetland, Lennart Poettering
In-Reply-To: <20111222034717.GB14174@suse.de>
On Thu, Dec 22, 2011 at 04:47, Greg KH <gregkh@suse.de> wrote:
> On Wed, Dec 21, 2011 at 06:12:39PM -0800, Tim Bird wrote:
>> > Again, please see what we are already doing in the kernel and userspace,
>> > I think a lot of the above is already implemented.
>>
>> I don't know what systemd has got going on in user-space. I'm looking
>> at a very recent kernel, and I see no support for multiple log channels,
>> or an optimized open/write path.
>
> How is the existing syslog read path not "optimized"? What kind of
> speed and numbers are we talking about here?
>
> Oh, and you do know about the userspace printk tty driver, right? What
> about using that combined with the existing syslog system call?
>
> systemd doesn't use it, but I know of a few embedded systems that are
> already using it today, and I think it might solve the android issues
> already.
We would like to have for the general Linux use case is a kmsg, that
supports structured data, but looks the same as it looks today to
current and legacy tools.
We would like to have every printk that does not start with a
KERN_CONT to create a record in the kmsg buffer. This record would
carry directly a timestamp, the log facility and the log level and a
reference to the usual human readable string.
The current kmsg prefixing of the timestamp would be a runtime switch,
and just added when the records are traversed, instead of the current
buffer printing.
In addition to this common data, every record can carry a
'dictionary', which basically looks like a process environment, means
KEY=value pairs. The additional data can carry all the stuff that is
needed for structured logging and provides the base for machine
readable log information.
We don't want to separate multiple stores to avoid ordering problems
when the messages need to be merged from the multiple streams on the
receiver side.
I think this is theoretically all possible with the current kmsg,
without breaking anything. The current interfaces would iterate over
the record list and print out the human readable parts and skip the
metadata, instead of just copying a linear byte stream. To tools, it
could look the same as it is currently. It's just that the ring buffer
is not a byte- but a record-buffer.
Advanced tools could get a new interface or switch the old interface
to pipe out the structured data too.
In the systemd journal, we have an ASCII-like stream format that
carries out structured data and is binary data capable.
If we want to think about any next generation logging, I'm convinced,
we need to support records, structured data and binary data; anything
else is unlikely worth to change the current stuff.
Kay
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Brian Swetland @ 2011-12-22 4:22 UTC (permalink / raw)
To: Kay Sievers
Cc: Greg KH, Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Lennart Poettering
In-Reply-To: <CAPXgP10ikqHFn41wc1HPsKHyaC7fe1WGC2eHqs-hdRaZ7XCTLw@mail.gmail.com>
On Wed, Dec 21, 2011 at 8:12 PM, Kay Sievers <kay.sievers@vrfy.org> wrote:
>
> We would like to have for the general Linux use case is a kmsg, that
> supports structured data, but looks the same as it looks today to
> current and legacy tools.
>
> We would like to have every printk that does not start with a
> KERN_CONT to create a record in the kmsg buffer. This record would
> carry directly a timestamp, the log facility and the log level and a
> reference to the usual human readable string.
>
> The current kmsg prefixing of the timestamp would be a runtime switch,
> and just added when the records are traversed, instead of the current
> buffer printing.
>
> In addition to this common data, every record can carry a
> 'dictionary', which basically looks like a process environment, means
> KEY=value pairs. The additional data can carry all the stuff that is
> needed for structured logging and provides the base for machine
> readable log information.
>
> We don't want to separate multiple stores to avoid ordering problems
> when the messages need to be merged from the multiple streams on the
> receiver side.
>
> I think this is theoretically all possible with the current kmsg,
> without breaking anything. The current interfaces would iterate over
> the record list and print out the human readable parts and skip the
> metadata, instead of just copying a linear byte stream. To tools, it
> could look the same as it is currently. It's just that the ring buffer
> is not a byte- but a record-buffer.
>
> Advanced tools could get a new interface or switch the old interface
> to pipe out the structured data too.
>
> In the systemd journal, we have an ASCII-like stream format that
> carries out structured data and is binary data capable.
>
> If we want to think about any next generation logging, I'm convinced,
> we need to support records, structured data and binary data; anything
> else is unlikely worth to change the current stuff.
Any thoughts as to how one could allow N userspace agents to log to a
single shared buffer without one agent, if buggy or malicious,
spamming out all the other contents of the log? This is one of the
main reasons we maintain separate logs in Android today, and are
likely to continue doing so until we figure out how resolve the issue.
Having everything in one unified log definitely has benefits (it
certainly makes keeping everything ordered and reading everything back
simpler), however we can't control third party applications (by
design), so systems that require apps to "just don't do that" are not
really solving that problem for us.
Also, as I mentioned earlier, from a security standpoint it is highly
desirable to be able to restrict which records certain readers can
read. Convincing third party app developers to not log sensitive or
PII data remains a challenge -- providing the ability for filtered
read access allows some mitigation (app can retrieve it's own logs for
a bug report but can't sift through all logs looking for interesting
tidbits).
Brian
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Kay Sievers @ 2011-12-22 4:36 UTC (permalink / raw)
To: Greg KH
Cc: Brian Swetland, NeilBrown, Tim Bird, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Lennart Poettering
In-Reply-To: <20111222034953.GC14174@suse.de>
On Thu, Dec 22, 2011 at 04:49, Greg KH <gregkh@suse.de> wrote:
> On Wed, Dec 21, 2011 at 06:34:08PM -0800, Brian Swetland wrote:
>> 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)
>
> Wouldn't a simple userspace daemon solve this, writing the data to a
> ramfs file?
That's what the systemd journal does in /run when /var is not writable
or the /var/log/journal directory does not exist. All just lands on a
tmpfs until the next reboot. The journal database just acts as a
ringbuffer on a filesystem.
>> - 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
>
> ramfs?
The receiver gets almost all of this from the socket with
SCM_TIMESTAP, and SCM_CREDENTIALS. Needed stuff can be added in a
similar way. This is trusted, reliable and pretty cheap to retrieve
data.
>> - make log writing reliable -- don't trust userland to report its
>> timestamp, PID, or to correctly format the datagrams, etc
>
> existing userspace printk tty driver?
Sockets provide all that today already in a trusted way.
>> - allow a log watching process (logcat) to easily pull data from all
>> logs at once
>
> what do you mean by "at once"?
/proc/kmsg provides that today, which is basically just a file wrapper
around the kernel's (misleadingly named) syslog() call.
>> - avoid committing a vast amount of memory to logging
>
> memory where, in code or in the data being logged?
>
>> - 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
>
> Which logs?
Things need rate limits and quota based on the remaining buffer or
disk space. The systemd journal maintains a separate journal for every
login-uid, so every logged in user gets his own journal database,
which can not overflow the systems database or the databases of the
other users.
Every user can log to the journal, but only the journal daemon can
write to the databases. The user can directly read back its own
journal database, but not write it.
>> On one hand, having each app (per PID) be able to create their own
>> logs up to a specified size limit could be really useful and is
>> something we've kicked around -- for one it would allow us to avoid
>> the ever present request from userspace developers to increase the log
>> size because of too much log spam ("reduce log spam" never seems to be
>> an answer that makes them happy) -- but we haven't come up with a
>> reasonable plan for dealing with "well if we allow 16KB of log per app
>> and the user installs 100 apps, they may be pinning up to 1.6MB of ram
>> worst case", and so on.
>
> I think the userspace printk and syslog might already handle most of
> this today. Â Tim, care to look into that and see if it does or not?
It's very simple what we have here in the kernel, and if syslog
facility prefixes are used, it can probably replace most of the
Android log solution just fine. We can not really protect one store to
flush the entire buffer though, that's what the 4 separated stores can
easily provide.
But as mentioned, I think we want the ability to work with structured
data, which both kernel tools are incapable of.
Kay
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 4:42 UTC (permalink / raw)
To: Tim Bird
Cc: Greg KH, linux-embedded, linux kernel, Arnd Bergmann, john stultz,
Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <4EF27B85.9080801@am.sony.com>
On Wed, 21 Dec 2011, Tim Bird wrote:
> On 12/21/2011 03:19 PM, Greg KH wrote:
>> That all describes the current code, but you haven't described what's
>> wrong with the existing syslog interface that requires this new driver
>> to be written. And why can't the existing interface be fixed to address
>> these (potential) shortcomings?
>
>
>>> One specific question I have is where is the most appropriate
>>> place for this code to live, in the kernel source tree?
>>> Other embedded systems might want to use this system (it
>>> is simpler than syslog, and superior in some ways), so I don't
>>> think it should remain in an android-specific directory.
>>
>> What way is it superior?
>
> Here are some ways that this code is superior to syslog:
>
> Speed and overhead
> ------------------
> syslogd requires a separate user-space process to manage
> the log area, where this code does not. The overhead
> for any user-space process is at least 16K, and usually much
> more than this (not including the size of the log storage
> area). On one of my embedded systems, where syslogd is
> provided by busybox, the unique set size for syslogd
> is 96K. This code, built in to the Linux kernel is less
> than 4K code and data (again, not including the size of
> the log storage area).
>
> To deliver a message to syslog requires a socket operation
> and a few context switches. With the logger code,
> the operation is a file operation (writev) to kernel memory,
> with only one context switch into and out of the kernel.
>
> The open and write paths through the Linux kernel are
> arguably more optimized than the networking paths.
> This is a consideration since the log operations should
> optimized for the "create-a-log-entry" case (the open/write
> path), since logs are mostly written and almost never read
> on production devices.
comparing this to a userspace syslog daemon, you are correct that doing
things in the kernel is slightly faster, but just because putting
something in the kernel may be faster, doesn't mean that it belongs there
(the tux webserver anyone??). How much faster, and is this something that
actually matters? it doens't matter if something is 1000x faster if it's
only called infrequently. what rate of log messages do you expect to
support (and note that userspace syslog daemons can handle up to a
million logs/sec, on the right hardware)
> No dependence on persistent storage
> -----------------------------------
> syslogd requires either persistent storage to store the log,
> or a network connection to an outside device. Being
> purely memory-based, the logger requires neither of these.
> With logger, persistence of the log data is left to the
> implementor. In Android, the data is delivered over a USB
> connection via adb or to the console as ascii text, using
> logcat. In other embedded systems, other mechanisms might
> be used if long-term storage of the messages is desired.
> With logger, there is no automatic notion of on-device
> persistent storage for the log data.
>
> No dependence on networking kernel code
> ---------------------------------------
> The syslog communication mechanism requires sockets. This
> prevents one from configuring the kernel with no networking
> support, which is sometimes done in embedded systems to save
> size.
>
> Simpler constraint on log size
> ------------------------------
> The busybox syslog daemon uses a log rotation feature to constrain
> the size of the log in persistent storage. This is overly
> cumbersome in both speed and complexity compared to the logger's
> simple ring buffer.
>
> Licensing
> ---------
> The code implementing library and command line tool support
> for this logger (in user space) is available under an Apache license,
> rather than a GPL license, which is desirable for some vendors.
All of these issues are only true if you consider the existing syslog
daemones, but it sounds like it would be pretty trivial to write a new
syslog daemon (or hack up a BSD licensed one) to listen on multiple
sockets (which most of the existing syslgo daemond can do already), assign
a priority to each different socket, and then keep the logs in it's own
buffer, with an api to retrieve them.
it wouldn't be quite as small or as fast as doing it in the kernel, but it
would not be large, and I have trouble believing that it would be slow
enough to notice.
>> Again, why not extend syslog? Why not "fix"
>> syslog if this really is a superior thing?
>
> "extend" syslog would not really the the right
> direction. This system is simpler than syslog,
> while simultaneously having at least one valuable
> extra feature (separate log channels).
>
> syslog has a standard set of interfaces in libc
> and various syslogd implementations, which are
> heavier weight in nature than what is provided here.
> It is unclear that an attempt at reducing these attributes
> (such as memory overhead, number of context switches,
> dependence on persistent storage, and socket utilization) would
> yield a system substantially different from the logger.
I once saw a company spend 6 months of developer effort optimizing a
readof a config file (at the start it took 30 seconds to read the config
100,000 times at the end it to .5 seconds), this was a great speedup,
until you looked at the numbers and realized that across 50 servers this
function was called 50,000 times in an hour (configs for cgis), so this 6
month development effort saved 15 sec of cpu time in a peak hour, spread
across 50 machines. In other words a waste of time and diversion of
resources that could have been far better employed fixing bigger issues.
I suspect that logging is in the same category, it just doesn't happen
enough for the performance difference to really matter.
making this be a 'standard' syslog(3) interface, or even a very close
cousin to it (if you want apps to be able to dump raw strings to it rather
than formatted data for example) would not hurt the pure android on a
low-end phone noticably, but would make it much easier for android on a
high-end device (tablets, netbooks, etc) to plug in a full blown syslog
daemon that could save the logs to disk, or to send them over the network,
etc. these things are very useful to have and much easier to do in
userspace than in the kernel.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Kay Sievers @ 2011-12-22 4:43 UTC (permalink / raw)
To: Brian Swetland
Cc: Greg KH, Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Lennart Poettering
In-Reply-To: <CANqkERCcciVxybh=66K5xxzzGmgw=fg0vwmcitWZ1y=DTxxtOA@mail.gmail.com>
On Thu, Dec 22, 2011 at 05:22, Brian Swetland <swetland@google.com> wrote:
> On Wed, Dec 21, 2011 at 8:12 PM, Kay Sievers <kay.sievers@vrfy.org> wrote:
>>
>> We would like to have for the general Linux use case is a kmsg, that
>> supports structured data, but looks the same as it looks today to
>> current and legacy tools.
>>
>> We would like to have every printk that does not start with a
>> KERN_CONT to create a record in the kmsg buffer. This record would
>> carry directly a timestamp, the log facility and the log level and a
>> reference to the usual human readable string.
>>
>> The current kmsg prefixing of the timestamp would be a runtime switch,
>> and just added when the records are traversed, instead of the current
>> buffer printing.
>>
>> In addition to this common data, every record can carry a
>> 'dictionary', which basically looks like a process environment, means
>> KEY=value pairs. The additional data can carry all the stuff that is
>> needed for structured logging and provides the base for machine
>> readable log information.
>>
>> We don't want to separate multiple stores to avoid ordering problems
>> when the messages need to be merged from the multiple streams on the
>> receiver side.
>>
>> I think this is theoretically all possible with the current kmsg,
>> without breaking anything. The current interfaces would iterate over
>> the record list and print out the human readable parts and skip the
>> metadata, instead of just copying a linear byte stream. To tools, it
>> could look the same as it is currently. It's just that the ring buffer
>> is not a byte- but a record-buffer.
>>
>> Advanced tools could get a new interface or switch the old interface
>> to pipe out the structured data too.
>>
>> In the systemd journal, we have an ASCII-like stream format that
>> carries out structured data and is binary data capable.
>>
>> If we want to think about any next generation logging, I'm convinced,
>> we need to support records, structured data and binary data; anything
>> else is unlikely worth to change the current stuff.
>
> Any thoughts as to how one could allow N userspace agents to log to a
> single shared buffer without one agent, if buggy or malicious,
> spamming out all the other contents of the log?
In systemd journal, users get separate databases, but still all
databases are written by the same process.
All input is rate-limited based on log priority and remaining space.
> This is one of the
> main reasons we maintain separate logs in Android today, and are
> likely to continue doing so until we figure out how resolve the issue.
Right, it's a problem, but we think it can be solved with still having
a single interface, and a single representation on the log consumer
side.
> Having everything in one unified log definitely has benefits (it
> certainly makes keeping everything ordered and reading everything back
> simpler), however we can't control third party applications (by
> design), so systems that require apps to "just don't do that" are not
> really solving that problem for us.
Yeah sure, but rate limiting and separating databases should make that possible.
> Also, as I mentioned earlier, from a security standpoint it is highly
> desirable to be able to restrict which records certain readers can
> read. Â Convincing third party app developers to not log sensitive or
> PII data remains a challenge -- providing the ability for filtered
> read access allows some mitigation (app can retrieve it's own logs for
> a bug report but can't sift through all logs looking for interesting
> tidbits).
Yes, Android is a bit different with the model of assigning uids to
apps. We focus mainly on the 1 system and the N logged-in users, which
all get their own database. I think the same model could work just
fine for the app-uids on Android. The important difference to separate
stores is that there is a single process writing all that, and that
can assign sequence numbers regardless in which database the record
will be stored for later merging/sorting of the records.
Kay
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 4:47 UTC (permalink / raw)
To: Brian Swetland
Cc: Kay Sievers, Greg KH, Tim Bird, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Lennart Poettering
In-Reply-To: <CANqkERCcciVxybh=66K5xxzzGmgw=fg0vwmcitWZ1y=DTxxtOA@mail.gmail.com>
On Wed, 21 Dec 2011, Brian Swetland wrote:
> Any thoughts as to how one could allow N userspace agents to log to a
> single shared buffer without one agent, if buggy or malicious,
> spamming out all the other contents of the log? This is one of the
> main reasons we maintain separate logs in Android today, and are
> likely to continue doing so until we figure out how resolve the issue.
note that you still don't prevent one app from blowing out the logs, all
you do is separate the logs into a handfulof categories and limit the app
(through standard filesystem permissions) to only blowing out one category
of logs.
or do I misunderstand this and you actually keep a separate queue for each
pid (which would seem to be a problem as you no longer know how much space
you need)
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 4:49 UTC (permalink / raw)
To: Kay Sievers
Cc: Greg KH, Tim Bird, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Brian Swetland, Lennart Poettering
In-Reply-To: <CAPXgP10ikqHFn41wc1HPsKHyaC7fe1WGC2eHqs-hdRaZ7XCTLw@mail.gmail.com>
On Thu, 22 Dec 2011, Kay Sievers wrote:
> If we want to think about any next generation logging, I'm convinced,
> we need to support records, structured data and binary data; anything
> else is unlikely worth to change the current stuff.
note that current generation syslog supports records, structured data,
metadata capture of the sending process, everything you listed except
unencoded binary data.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 4:52 UTC (permalink / raw)
To: NeilBrown
Cc: Tim Bird, Greg KH, linux-embedded, linux kernel, Arnd Bergmann,
john stultz, Brian Swetland, Kay Sievers, Lennart Poettering
In-Reply-To: <20111222122026.3a0fae36@notabene.brown>
On Thu, 22 Dec 2011, NeilBrown wrote:
> On Wed, 21 Dec 2011 16:36:21 -0800 Tim Bird <tim.bird@am.sony.com> wrote:
>
>> On 12/21/2011 03:19 PM, Greg KH wrote:
>>> That all describes the current code, but you haven't described what's
>>> wrong with the existing syslog interface that requires this new driver
>>> to be written. And why can't the existing interface be fixed to address
>>> these (potential) shortcomings?
>>
>>
>>>> One specific question I have is where is the most appropriate
>>>> place for this code to live, in the kernel source tree?
>>>> Other embedded systems might want to use this system (it
>>>> is simpler than syslog, and superior in some ways), so I don't
>>>> think it should remain in an android-specific directory.
>>>
>>> What way is it superior?
>>
>> Here are some ways that this code is superior to syslog:
>
> It is certainly nice and simple. It really looks more like a filesystem than
> a char device though... though they aren't really files so much as lossy
> pipes. I don't think that's a problem though, lots of things in filesystems
> don't behave exactly like files.
>
> 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 defined '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
>
> The result would be much the same amount of code, but an interface which has
> fewer details hard-coded and is generally more versatile and accessible.
That sounds better than what has been done in android, but it is still
_far_ more limited than doing something that could be replaced by a fairly
standard syslog daemon.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Brian Swetland @ 2011-12-22 4:58 UTC (permalink / raw)
To: david
Cc: Kay Sievers, Greg KH, Tim Bird, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Lennart Poettering
In-Reply-To: <alpine.DEB.2.02.1112212044240.28597@asgard.lang.hm>
On Wed, Dec 21, 2011 at 8:47 PM, <david@lang.hm> wrote:
> On Wed, 21 Dec 2011, Brian Swetland wrote:
>> Any thoughts as to how one could allow N userspace agents to log to a
>> single shared buffer without one agent, if buggy or malicious,
>> spamming out all the other contents of the log? Â This is one of the
>> main reasons we maintain separate logs in Android today, and are
>> likely to continue doing so until we figure out how resolve the issue.
>
> note that you still don't prevent one app from blowing out the logs, all you
> do is separate the logs into a handfulof categories and limit the app
> (through standard filesystem permissions) to only blowing out one category
> of logs.
>
> or do I misunderstand this and you actually keep a separate queue for each
> pid (which would seem to be a problem as you no longer know how much space
> you need)
You're correct -- that's the model at present. We'd like to move to a
model where we have better control and are kicking around ideas for
how to do this for the next platform version.
The rate at which apps push data into logs is pretty amazing at times.
The system booting (maybe 10-20 services and 10+ apps starting up)
can blow through 256K of ringbuffer in seconds.
Having enough context available when something crashes to be able to
diagnose what went wrong, especially when problems could involve
interaction between multiple agents in multiple processes is important
for the frameworks and apps teams.
Trying to get individual developers to be frugal with their logging
has turned out to be mostly a losing battle.
Brian
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 5:01 UTC (permalink / raw)
To: Brian Swetland
Cc: NeilBrown, Tim Bird, Greg KH, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <CANqkERC+mdSGxk4tiU7+dbauSXqqANN+Z+TTb_pVXoPq+k=rJg@mail.gmail.com>
[-- Attachment #1: Type: TEXT/PLAIN, Size: 4788 bytes --]
On Wed, 21 Dec 2011, Brian Swetland wrote:
> On Wed, Dec 21, 2011 at 5:20 PM, NeilBrown <neilb@suse.de> wrote:
>> On Wed, 21 Dec 2011 16:36:21 -0800 Tim Bird <tim.bird@am.sony.com> wrote:
>>
>>> On 12/21/2011 03:19 PM, Greg KH wrote:
>>>> That all describes the current code, but you haven't described what's
>>>> wrong with the existing syslog interface that requires this new driver
>>>> to be written. And why can't the existing interface be fixed to address
>>>> these (potential) shortcomings?
>>>
>>>>> One specific question I have is where is the most appropriate
>>>>> place for this code to live, in the kernel source tree?
>>>>> Other embedded systems might want to use this system (it
>>>>> is simpler than syslog, and superior in some ways), so I don't
>>>>> think it should remain in an android-specific directory.
>>>>
>>>> What way is it superior?
>>>
>>> Here are some ways that this code is superior to syslog:
>>
>> It is certainly nice and simple. It really looks more like a filesystem than
>> a char device though... though they aren't really files so much as lossy
>> pipes. I don't think that's a problem though, lots of things in filesystems
>> don't behave exactly like files.
>>
>> 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.
<<SNIP>>
>> The result would be much the same amount of code, but an interface which has
>> fewer details hard-coded and is generally more versatile and accessible.
>
> Moving away from hard coding the names/sizes of the logs in the driver
> is something that has been on the todo list for a while. One thing
> we'd likely want to accomplish there is avoid creating a vector for
> consuming large amounts of memory by creating new logs.
>
> One planned change (likely to happen in the Android J release
> timeframe) is to adjust permissions such that any process can write
> messages, but unless they belong to the correct group they can only
> read back messages written by their own PID. This is to allow apps to
> grab their own log output after a crash or during a user problem
> report without needing to grant them the ability to read all log
> messages.
>
> Currently the logger driver does not provide a mechanism for allowing
> logs to survive a reboot (unlike the ramconsole), but this is
> functionality that we've thought about adding. Generally the kernel
> logs are most interesting after an unexpected panic/reboot, but
> getting a picture of what userspace has been up to can be useful too.
>
> 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
>
> On one hand, having each app (per PID) be able to create their own
> logs up to a specified size limit could be really useful and is
> something we've kicked around -- for one it would allow us to avoid
> the ever present request from userspace developers to increase the log
> size because of too much log spam ("reduce log spam" never seems to be
> an answer that makes them happy) -- but we haven't come up with a
> reasonable plan for dealing with "well if we allow 16KB of log per app
> and the user installs 100 apps, they may be pinning up to 1.6MB of ram
> worst case", and so on.
At this point you are starting to sound like something much closer to a
traditional syslog daemon. you are adding so many variations, persistant
storage, etc that you really don't want to have to have all this in the
kernel, make these be interfaces into a userspace logging tool (ideally
syslog compatible), and you have the option to easily have different
policies, consuming different amounts of space, depending on the device
and how resource limited it is.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Brian Swetland @ 2011-12-22 5:06 UTC (permalink / raw)
To: david
Cc: NeilBrown, Tim Bird, Greg KH, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <alpine.DEB.2.02.1112212050060.28597@asgard.lang.hm>
On Wed, Dec 21, 2011 at 8:52 PM, <david@lang.hm> wrote:
> On Thu, 22 Dec 2011, NeilBrown wrote:
>>
>> You would defined '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
>>
>> The result would be much the same amount of code, but an interface which
>> has
>> fewer details hard-coded and is generally more versatile and accessible.
>
> That sounds better than what has been done in android, but it is still _far_
> more limited than doing something that could be replaced by a fairly
> standard syslog daemon.
We're really not interested in adding another daemon to the platform
-- the logging system we have has served us well, is integrated with
our existing development tools, and we're definitely interested in
improving it, but throwing it out and replacing it with a userspace
solution is not interesting to us right now.
Brian
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 5:07 UTC (permalink / raw)
To: Brian Swetland
Cc: Kay Sievers, Greg KH, Tim Bird, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Lennart Poettering
In-Reply-To: <CANqkERDwpVqnYsC_0kQSyVohcoFK1vCEjXe+CwgdpMcNdKTkLQ@mail.gmail.com>
[-- Attachment #1: Type: TEXT/PLAIN, Size: 2125 bytes --]
On Wed, 21 Dec 2011, Brian Swetland wrote:
> On Wed, Dec 21, 2011 at 8:47 PM, <david@lang.hm> wrote:
>> On Wed, 21 Dec 2011, Brian Swetland wrote:
>>> Any thoughts as to how one could allow N userspace agents to log to a
>>> single shared buffer without one agent, if buggy or malicious,
>>> spamming out all the other contents of the log? This is one of the
>>> main reasons we maintain separate logs in Android today, and are
>>> likely to continue doing so until we figure out how resolve the issue.
>>
>> note that you still don't prevent one app from blowing out the logs, all you
>> do is separate the logs into a handfulof categories and limit the app
>> (through standard filesystem permissions) to only blowing out one category
>> of logs.
>>
>> or do I misunderstand this and you actually keep a separate queue for each
>> pid (which would seem to be a problem as you no longer know how much space
>> you need)
>
> You're correct -- that's the model at present. We'd like to move to a
> model where we have better control and are kicking around ideas for
> how to do this for the next platform version.
>
> The rate at which apps push data into logs is pretty amazing at times.
> The system booting (maybe 10-20 services and 10+ apps starting up)
> can blow through 256K of ringbuffer in seconds.
>
> Having enough context available when something crashes to be able to
> diagnose what went wrong, especially when problems could involve
> interaction between multiple agents in multiple processes is important
> for the frameworks and apps teams.
this makes it sound more like this belongs in userspace instead of the
kernel. if something crashes and they can flip a flag in userspace to say
'keep more logs now' and try to duplicate the crash is going to be far
easier than having to compile a new kernel to extend the size of the log.
> Trying to get individual developers to be frugal with their logging
> has turned out to be mostly a losing battle.
that's for sure, anything that's success depends on developers doing
things right that aren't visible to the user are pretty much doomed.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 5:14 UTC (permalink / raw)
To: Brian Swetland
Cc: NeilBrown, Tim Bird, Greg KH, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <CANqkERBPayBWjFp2nCDZA2CByJQwHMoeXe62ZutZr8QkWtcTLg@mail.gmail.com>
On Wed, 21 Dec 2011, Brian Swetland wrote:
>>> The result would be much the same amount of code, but an interface which
>>> has
>>> fewer details hard-coded and is generally more versatile and accessible.
>>
>> That sounds better than what has been done in android, but it is still _far_
>> more limited than doing something that could be replaced by a fairly
>> standard syslog daemon.
>
> We're really not interested in adding another daemon to the platform
> -- the logging system we have has served us well, is integrated with
> our existing development tools, and we're definitely interested in
> improving it, but throwing it out and replacing it with a userspace
> solution is not interesting to us right now.
Think very hard before you reject any possibility of doing this in
userspace, especially with all the things that you are talking about doing
with logging in the future. I really don't think aht a lot of your
long-0term plans for logging are going to sit well with the kernel
developers, and if your justification is "you don't want to change your
build process", I really doubt that you will get this upstream.
It should be possible to do this without having to change the tools
writing the logs, any change in logging will change what it takes to read
the logs.
I am not saying that you need to have a logging daemon as heavyweight as
syslog-ng or rsyslog for the low-end phones, but I do think that as
android moves up the stack a bit into talets and netbooks (especially in
applications where it will have wifi connectivity almost all the time)
having the capability to move to a full-blown syslog daemon will make a
huge amount of sense, so you should look at how big a minimalist daemon
would be, and what sort of performance it would have.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: david @ 2011-12-22 5:21 UTC (permalink / raw)
To: Brian Swetland
Cc: Kay Sievers, Greg KH, Tim Bird, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Lennart Poettering
In-Reply-To: <CANqkERDwpVqnYsC_0kQSyVohcoFK1vCEjXe+CwgdpMcNdKTkLQ@mail.gmail.com>
On Wed, 21 Dec 2011, Brian Swetland wrote:
> The rate at which apps push data into logs is pretty amazing at times.
> The system booting (maybe 10-20 services and 10+ apps starting up)
> can blow through 256K of ringbuffer in seconds.
a smidge more information here.
256K of logs in 'seconds'
are we talking single digit seconds, tens of seconds, what?
any idea the average message size
on my server farms, the average log size is ~256 byttes, so if this was
over 10 seconds we would be talking ~100 logs/sec. "slow" syslog daemons
can handle this sort of load trivially, they start to take significant
amounts of CPU (10%+) around two orders of magnatude higher data rates.
now, it may be that the logs on the android are smaller, and you hit the
256K injust a couple of seconds, at which point things would be a little
harder, but since the job is so much simpler it shouldn't be that hard.
David Lang
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Brian Swetland @ 2011-12-22 5:25 UTC (permalink / raw)
To: david
Cc: NeilBrown, Tim Bird, Greg KH, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <alpine.DEB.2.02.1112212107550.28597@asgard.lang.hm>
On Wed, Dec 21, 2011 at 9:14 PM, <david@lang.hm> wrote:
> On Wed, 21 Dec 2011, Brian Swetland wrote:
>>
>> We're really not interested in adding another daemon to the platform
>> -- the logging system we have has served us well, is integrated with
>> our existing development tools, and we're definitely interested in
>> improving it, but throwing it out and replacing it with a userspace
>> solution is not interesting to us right now.
>
> Think very hard before you reject any possibility of doing this in
> userspace, especially with all the things that you are talking about doing
> with logging in the future. I really don't think aht a lot of your
> long-0term plans for logging are going to sit well with the kernel
> developers, and if your justification is "you don't want to change your
> build process", I really doubt that you will get this upstream.
>
> It should be possible to do this without having to change the tools writing
> the logs, any change in logging will change what it takes to read the logs.
>
> I am not saying that you need to have a logging daemon as heavyweight as
> syslog-ng or rsyslog for the low-end phones, but I do think that as android
> moves up the stack a bit into talets and netbooks (especially in
> applications where it will have wifi connectivity almost all the time)
> having the capability to move to a full-blown syslog daemon will make a huge
> amount of sense, so you should look at how big a minimalist daemon would be,
> and what sort of performance it would have.
Long term things could certainly move around, but *right now* we
really don't see the value in gutting what we've got in favor of
writing a new userspace daemon, which is going to require somebody to
do that work, maintain it, chase down any behavioural quirks
introduced by the changes, etc. Or to throw it out in favor of trying
to bolt our logging infrastructure on top of existing syslogds, etc.
We're happy to maintain the logger driver out of tree as we have for
the past four years.
If all discussions of bringing Android kernel support to mainline end
up as another round of "you should just rewrite it all in userspace"
or "you should use this other subsystem that doesn't actually solve
your problem but we think it's close enough", then there's not a lot
of point to having the discussions in the first place.
If somebody wants to go write a complete compatible replacement that
just drops in, we certainly could take a look at it and see how it
works, but given that the benefits are not clear to us, we're not
interested in going off and doing that work ourselves.
Brian
^ permalink raw reply
* Re: RFC: android logger feedback request
From: Greg KH @ 2011-12-22 6:09 UTC (permalink / raw)
To: Brian Swetland
Cc: david, NeilBrown, Tim Bird, linux-embedded, linux kernel,
Arnd Bergmann, john stultz, Kay Sievers, Lennart Poettering
In-Reply-To: <CANqkERCH15aGi5TJwUk6Yg3fnrPA0aiTJa=Nz9sUeZLbWs20HA@mail.gmail.com>
On Wed, Dec 21, 2011 at 09:25:52PM -0800, Brian Swetland wrote:
> Long term things could certainly move around, but *right now* we
> really don't see the value in gutting what we've got in favor of
> writing a new userspace daemon, which is going to require somebody to
> do that work, maintain it, chase down any behavioural quirks
> introduced by the changes, etc. Or to throw it out in favor of trying
> to bolt our logging infrastructure on top of existing syslogds, etc.
>
> We're happy to maintain the logger driver out of tree as we have for
> the past four years.
This all came about because Tim asked to merge this to the main tree
as-is, and so, people rightfully pointed out different options that
might be considered if it were to be merged that way.
I have no problem leaving the logger driver in staging, but it seems
that Tim is taking on the task to do the harder thing here, which
probably would entail work on both sides, which as a openhandset
alliance company member, he might have a change that someone like me
might not :)
Tim, it's now in your court it seems, have a great holiday,
greg k-h
^ permalink raw reply
page: next (older) | prev (newer) | latest
- recent:[subjects (threaded)|topics (new)|topics (active)]
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox