7 ms·

> If we send a large "native" message to /run/systemd/journal/socket ... the maximum size of a "native" entry is 768MB Why does journal allow such large messag

by pdkl95 8y ago

> If we send a large "native" message to /run/systemd/journal/socket ... the maximum size of a "native" entry is 768MB Why does journal allow such large messages over a socket? That alone might be a denial-of-service attack; are real messages delayed/blocked if someone sends spawns a bunch of processes that send 768MB of junk to that socket? commit c4aa09b06f835c91cea9e021df4c3605cff2318d Date: Mon Apr 8 20:32:03 2013 +0200 ... -#define ENTRY_SIZE_MAX (1024*1024*64) -#define DATA_SIZE_MAX (1024*1024*64) ... +#define ENTRY_SIZE_MAX (1024*1024*768) +#define DATA_SIZE_MAX (1024*1024*768) WTF? Why would you need to increase the max size so much? What are you intending to send over that socket?! Oh. From the commit[1], the missing lines at the 2nd "...": +/* Make sure not to make this smaller than the maximum coredump + * size. See COREDUMP_MAX in coredump.c */ Why would you send coredumps over a socket? Just write them to a file and send the file's path to journald. Increasing the max message size 1200% just to avoid writing a core file is crazy. [1] https://github.com/systemd/systemd/commit/c4aa09b06f835c91cea9e021df4c3605cff2318d https://github.com/systemd/systemd/commit/c4aa09b06f835c91ce...

xena 8y ago
Sockets are files internally to Linux.
int0x80 8y ago
Another big question is why does it use alloca at all. Considering that it is well known in the C world to be problematic and discouraged. For this very reason. - Are you performance-constrained? NO. - Is calling malloc/free such a big deal, instead of alloca? It is not. Yes. That neat join funcion will need to get an extra parameter and free the returned pointer when it's done with it. This is C. If you want neat convenient string joining functions use a different language.
- newnewpdro 8y ago
  > - Are you performance-constrained? NO. A significant portion of issues filed against journald are performance related. It's undesirable to have a bunch of mallocs and frees in the hot path of logging. It's not inappropriate to use the stack where possible, obviously in this case user-controlled input was being trusted where it shouldn't have. There have been many problems of this sort in journald, where the nature of the user-controlled input has the ability to bring journald to its knees in a global manner. Prior to the process metadata caching, you could cause journald to go absolutely nuts querying the sending processes metadata from /proc by sending it messages full of newlines. Every newline-separated field is treated as a separate message with its own metadata to be acquired. The routines for fetching all that stuff from /proc granularly allocated and freed the data via libc as well, it was very painful. Things are better now, but you still can't log particularly high rates through journald compared to a simple O_APPEND style logger like syslogd. Programs synchronously logging debug messages quickly become slowed down by journald pinning a CPU. You can still cause a world of hurt by spamming journald with tiny emergency messages, each of which forces a sync of the journal. But a user can also run `while true; do sync; done`
  - chris_wot 8y ago
    journald seems to be overall a very bad idea.
  - fao_ 8y ago
    > A significant portion of issues filed against journald are performance related. Right. Because instead of doing the SANE thing which is appending timestamped text to a read only file -- which gives you actually better guarantees of being written to the disk than the binary format journald uses, they have a ridiculously convoluted setup like this.
    - newnewpdro 8y ago
      I do think we'd be better off with the hot path being a simple append to a read-only file. All this database-like junk should have been done asynchronously and persisted in ancillary read-write files kept adjacent to the logs. Features like `systemctl status` that want to show the most recent log entries for a given service could have simply indicated 'potentially stale' when the logs were newer than the ancillary files, and support blocking on a refresh if desired. I'm not a fan of how it is done today, and I've hacked a bit on journald. It doesn't belong in the critical path. There's a lot of that in the systemd project in general; tightly coupling complexity where it really should be loosely coupled at best. But I believe a lot of that is to be expected from a project aspiring to do too much with too little resources, shortcuts are taken regularly. Everyone experienced knows tightly coupling components eases the development of them.
    - vectorEQ 8y ago
      my thoughts exactly. just because people are filing performance tickets doesn't mean that its performance bound application or framework. it could also, like illustrated many times before by people, just be bloated and convoluted code causing slowness.
      - newnewpdro 8y ago
        To take such a position is to not think charitably about the intentions and competency of the developers, which I find personally absurd. If you're not going to take the time to scrutinize the code and understand the problems, spreading uninformed FUD like a troll isn't helpful. I have spent significant time with the journald code in the past. I understand its inner-workings and what performance bottlenecks it has suffered from. Bloated and convoluted code is not how I would describe the causes. The systemd project's code is generally rather spartan, easy to read, simple C code. Journald attempts to associate myriad process metadata with the logs it receives. This information is useful to the log consumers, and is actually somewhat impossible to reliably collect in lockstep with the messages being received, using today's kernel interfaces. It will always be a racy endeavor to do this from userspace in the form of sampling /proc after the messages have been written and languished in a socket buffer for some non-deterministic amount of time. What journald attempts to do is a best-effort approach of acquiring and associating this information with the messages in-line with the logging, to get it as close as possible. I believe at some point, if we continue using this kind of metadata-rich logging in Linux, that the kernel will grow new interfaces to reliably deliver this information in a socket sidechannel, much like how minimal sender credentials may be retrieved on UNIX domain sockets today. Until then, journald will continue to find itself in the awkward position of being a kinda-sorta logging database which must sample piles of process metadata via /proc to describe the sender in what's appended to the journal. But this is a necessary phase of progress we must pass through. Upstream kernel developers generally refuse to add new interfaces for this kind of thing until there's an established use case demanding it. So what we're all using in journald today is arguably an MVP, establishing that there's a market need for this level of information in our logs, which can then be used to compel upstream to help us make it both efficient and 100% reliable. The process metadata caching that was added to improve the performance arguably traded accuracy of the metadata to do so. (and, one could argue, increased bloat and complexity) But in lieu of better kernel interfaces, it's the only choice other than giving up on logging the metadata entirely. The impression I got while working on the journald code pre-metadata-caching, was that the authors had assumed the kernel would evolve to make the information available efficiently. The kdbus debacle speaks to that trajectory, and its rejection from landing upstream definitely threw a wrench in the overall plan, I'm not sure the systemd project has ever fully recovered from that setback. So please, refrain from making such uninformed speculative comments. I encourage you to instead get involved and help improve things where you can, if you care about running modern Linux systems.
groestl 8y ago
Playing the devil's advocate here: not every box has a writeable filesystem.
- geofft 8y ago
  I think this is the right answer - more specifically, a program may not have write access to the filesystem (e.g., with the systemd "ProtectSystem" option). Linux lets you spawn a process to handle a core dump, but I believe the process runs as if it were a child process of the crashing one, i.e., in the same namespace and with the same filesystem permissions.
- pdkl95 8y ago
  Or the only writable filesystem could be a tiny tmpfs/ramdisk. In both situations, do you even want core dumps?
  - loeg 8y ago
    https://linux.die.net/man/8/netdump https://linux.die.net/man/8/netdump https://www.freebsd.org/cgi/man.cgi?query=netdump https://www.freebsd.org/cgi/man.cgi?query=netdump
- StreamBright 8y ago
  The do not core dump.
- loeg 8y ago
  You could imagine kernel.core_pattern pointing at an NFS mount, or a psuedo-filesystem that otherwise redirected to the network (could even be a small FUSE FS, allowing for userspace handling). Of course, neither of these suggestions necessarily gives control back to systemd to then relocate or process the file. But you couldn't do that on a RO system anyway.
userbinator 8y ago
As Linus might say, "this is complete idiocy". Even if you need to write a lot of data, the correct way is to write it in blocks using a fixed-size buffer, not try to stuff the whole thing in at once... Maybe it's not possible to completely eliminate all dynamic allocation, but striving to make your code O(1) space (and time) should be a relatively important goal.
- Someone 8y ago
  The choice may be incorrect, but the alternatives aren’t all around optimal, either. A logging system must write each message atomically. That can be done when “writing in blocks using a fixed-size” buffer, but it complicates code, and, I guess, would introduce additional latency (something you really do not want in a logging system) when processes race for using the logging system.
- Quekid5 8y ago
  Do you have a close-to-perfect implementation, perchance? Any logging implementation I have ever seen is full of tradeoffs along all sorts of axes. At some point something has to give. Examples: Your log cannot accept more messages (maybe it's a local disk), what do you do? Do you store it in memory? Do you throw it away and record that you threw messages away? What happens if the machine dies before you can record the failures? Are there some log messages that are important enough to actually halt the application? etc. etc. EDIT: ... and let's not even get into remote logging. It's actually a really complicated problem and not enough people appreciate that.
StreamBright 8y ago
Because systemd tries to hijack as much functionality it can.
- WalterGR 8y ago
  This is demonstrably false.
avar 8y ago
I'd imagine that the use-case for this was e.g. aggregating core dumps via some sytsemd/journald-powered centralized logging from a fleet of machines so they could be collected & analyzed. If you dump core locally and log the path you'll need other side-channel to do the aggregation.
- rleigh 8y ago
  I would never expect that core dumps to belong in a system logger of any description. A stack trace from the dump, maybe. But the actual core itself, could be tens of gigabytes. A constraint upon the maximum message size to a few kilobytes would be no bad thing, perhaps with a continuation mechanism for longer messages.
a-dub 8y ago
I believe it's so they can manage disk usage by core dumps (and disable them in low disk conditions). It's certainly weird, but they're only exploiting this to slow things down just a little bit. The big problem is the unchecked length of the incoming environment (args) string...
Asooka 8y ago
Additionally, the one time I actually needed coredumps, they didn't fit in 768MB and so I had to turn off systemd's coredump interceptor. It's probably useful in certain scenarios, but I really don't see why you would enable coredumpctl on a desktop system. Or why the limit would be hardcoded. Or why you wouldn't intelligently try to write the coredump to disk if it's too big to fit in the log.
- pas 8y ago
  if it's more than ~5M I don't want it on my desktop. usually it's not set up anyway to warrant sending it to developers for debugging. (missing symbols, unclean environment, etc) and even if it's less than ~5M, who will send it to where? coredumps are completely useless to do automatically. if the developers expect to get them, use a guardian process or some other error reporting framework.
gmueckl 8y ago
Systemd's insistence to gobble up core dumps is one of my favorite misfeatures of that thing. I lost many an interesting (large) dump because they wouldn't be logged in the journal and not be written to file as expected. Luckily this can be disabled (until the next system update resets the syscfg variable again). I don't even get what problem this "feature" is supposed to solve.
- vidoc 8y ago
  and at some point it was even comedy gold when the system would compress them with ... xz! lol

by pdkl95 8y ago

xena 8y ago

Sockets are files internally to Linux.

int0x80 8y ago

Another big question is why does it use alloca at all. Considering that it is well known in the C world to be problematic and discouraged. For this very reason. - Are you performance-constrained? NO. - Is calling malloc/free such a big deal, instead of alloca? It is not. Yes. That neat join funcion will need to get an extra parameter and free the returned pointer when it's done with it. This is C. If you want neat convenient string joining functions use a different language.

newnewpdro 8y ago
> - Are you performance-constrained? NO. A significant portion of issues filed against journald are performance related. It's undesirable to have a bunch of mallocs and frees in the hot path of logging. It's not inappropriate to use the stack where possible, obviously in this case user-controlled input was being trusted where it shouldn't have. There have been many problems of this sort in journald, where the nature of the user-controlled input has the ability to bring journald to its knees in a global manner. Prior to the process metadata caching, you could cause journald to go absolutely nuts querying the sending processes metadata from /proc by sending it messages full of newlines. Every newline-separated field is treated as a separate message with its own metadata to be acquired. The routines for fetching all that stuff from /proc granularly allocated and freed the data via libc as well, it was very painful. Things are better now, but you still can't log particularly high rates through journald compared to a simple O_APPEND style logger like syslogd. Programs synchronously logging debug messages quickly become slowed down by journald pinning a CPU. You can still cause a world of hurt by spamming journald with tiny emergency messages, each of which forces a sync of the journal. But a user can also run `while true; do sync; done`
- chris_wot 8y ago
  journald seems to be overall a very bad idea.
- fao_ 8y ago
  > A significant portion of issues filed against journald are performance related. Right. Because instead of doing the SANE thing which is appending timestamped text to a read only file -- which gives you actually better guarantees of being written to the disk than the binary format journald uses, they have a ridiculously convoluted setup like this.
  - newnewpdro 8y ago
    I do think we'd be better off with the hot path being a simple append to a read-only file. All this database-like junk should have been done asynchronously and persisted in ancillary read-write files kept adjacent to the logs. Features like `systemctl status` that want to show the most recent log entries for a given service could have simply indicated 'potentially stale' when the logs were newer than the ancillary files, and support blocking on a refresh if desired. I'm not a fan of how it is done today, and I've hacked a bit on journald. It doesn't belong in the critical path. There's a lot of that in the systemd project in general; tightly coupling complexity where it really should be loosely coupled at best. But I believe a lot of that is to be expected from a project aspiring to do too much with too little resources, shortcuts are taken regularly. Everyone experienced knows tightly coupling components eases the development of them.
  - vectorEQ 8y ago
    my thoughts exactly. just because people are filing performance tickets doesn't mean that its performance bound application or framework. it could also, like illustrated many times before by people, just be bloated and convoluted code causing slowness.
    - newnewpdro 8y ago
      To take such a position is to not think charitably about the intentions and competency of the developers, which I find personally absurd. If you're not going to take the time to scrutinize the code and understand the problems, spreading uninformed FUD like a troll isn't helpful. I have spent significant time with the journald code in the past. I understand its inner-workings and what performance bottlenecks it has suffered from. Bloated and convoluted code is not how I would describe the causes. The systemd project's code is generally rather spartan, easy to read, simple C code. Journald attempts to associate myriad process metadata with the logs it receives. This information is useful to the log consumers, and is actually somewhat impossible to reliably collect in lockstep with the messages being received, using today's kernel interfaces. It will always be a racy endeavor to do this from userspace in the form of sampling /proc after the messages have been written and languished in a socket buffer for some non-deterministic amount of time. What journald attempts to do is a best-effort approach of acquiring and associating this information with the messages in-line with the logging, to get it as close as possible. I believe at some point, if we continue using this kind of metadata-rich logging in Linux, that the kernel will grow new interfaces to reliably deliver this information in a socket sidechannel, much like how minimal sender credentials may be retrieved on UNIX domain sockets today. Until then, journald will continue to find itself in the awkward position of being a kinda-sorta logging database which must sample piles of process metadata via /proc to describe the sender in what's appended to the journal. But this is a necessary phase of progress we must pass through. Upstream kernel developers generally refuse to add new interfaces for this kind of thing until there's an established use case demanding it. So what we're all using in journald today is arguably an MVP, establishing that there's a market need for this level of information in our logs, which can then be used to compel upstream to help us make it both efficient and 100% reliable. The process metadata caching that was added to improve the performance arguably traded accuracy of the metadata to do so. (and, one could argue, increased bloat and complexity) But in lieu of better kernel interfaces, it's the only choice other than giving up on logging the metadata entirely. The impression I got while working on the journald code pre-metadata-caching, was that the authors had assumed the kernel would evolve to make the information available efficiently. The kdbus debacle speaks to that trajectory, and its rejection from landing upstream definitely threw a wrench in the overall plan, I'm not sure the systemd project has ever fully recovered from that setback. So please, refrain from making such uninformed speculative comments. I encourage you to instead get involved and help improve things where you can, if you care about running modern Linux systems.

groestl 8y ago

Playing the devil's advocate here: not every box has a writeable filesystem.

geofft 8y ago
I think this is the right answer - more specifically, a program may not have write access to the filesystem (e.g., with the systemd "ProtectSystem" option). Linux lets you spawn a process to handle a core dump, but I believe the process runs as if it were a child process of the crashing one, i.e., in the same namespace and with the same filesystem permissions.
pdkl95 8y ago
Or the only writable filesystem could be a tiny tmpfs/ramdisk. In both situations, do you even want core dumps?
- loeg 8y ago
  https://linux.die.net/man/8/netdump https://linux.die.net/man/8/netdump https://www.freebsd.org/cgi/man.cgi?query=netdump https://www.freebsd.org/cgi/man.cgi?query=netdump
StreamBright 8y ago
The do not core dump.
loeg 8y ago
You could imagine kernel.core_pattern pointing at an NFS mount, or a psuedo-filesystem that otherwise redirected to the network (could even be a small FUSE FS, allowing for userspace handling). Of course, neither of these suggestions necessarily gives control back to systemd to then relocate or process the file. But you couldn't do that on a RO system anyway.

userbinator 8y ago

As Linus might say, "this is complete idiocy". Even if you need to write a lot of data, the correct way is to write it in blocks using a fixed-size buffer, not try to stuff the whole thing in at once... Maybe it's not possible to completely eliminate all dynamic allocation, but striving to make your code O(1) space (and time) should be a relatively important goal.

Someone 8y ago
The choice may be incorrect, but the alternatives aren’t all around optimal, either. A logging system must write each message atomically. That can be done when “writing in blocks using a fixed-size” buffer, but it complicates code, and, I guess, would introduce additional latency (something you really do not want in a logging system) when processes race for using the logging system.
Quekid5 8y ago
Do you have a close-to-perfect implementation, perchance? Any logging implementation I have ever seen is full of tradeoffs along all sorts of axes. At some point something has to give. Examples: Your log cannot accept more messages (maybe it's a local disk), what do you do? Do you store it in memory? Do you throw it away and record that you threw messages away? What happens if the machine dies before you can record the failures? Are there some log messages that are important enough to actually halt the application? etc. etc. EDIT: ... and let's not even get into remote logging. It's actually a really complicated problem and not enough people appreciate that.

StreamBright 8y ago

Because systemd tries to hijack as much functionality it can.

WalterGR 8y ago
This is demonstrably false.

avar 8y ago

I'd imagine that the use-case for this was e.g. aggregating core dumps via some sytsemd/journald-powered centralized logging from a fleet of machines so they could be collected & analyzed. If you dump core locally and log the path you'll need other side-channel to do the aggregation.

rleigh 8y ago
I would never expect that core dumps to belong in a system logger of any description. A stack trace from the dump, maybe. But the actual core itself, could be tens of gigabytes. A constraint upon the maximum message size to a few kilobytes would be no bad thing, perhaps with a continuation mechanism for longer messages.

a-dub 8y ago

I believe it's so they can manage disk usage by core dumps (and disable them in low disk conditions). It's certainly weird, but they're only exploiting this to slow things down just a little bit. The big problem is the unchecked length of the incoming environment (args) string...

Asooka 8y ago

Additionally, the one time I actually needed coredumps, they didn't fit in 768MB and so I had to turn off systemd's coredump interceptor. It's probably useful in certain scenarios, but I really don't see why you would enable coredumpctl on a desktop system. Or why the limit would be hardcoded. Or why you wouldn't intelligently try to write the coredump to disk if it's too big to fit in the log.

pas 8y ago
if it's more than ~5M I don't want it on my desktop. usually it's not set up anyway to warrant sending it to developers for debugging. (missing symbols, unclean environment, etc) and even if it's less than ~5M, who will send it to where? coredumps are completely useless to do automatically. if the developers expect to get them, use a guardian process or some other error reporting framework.

gmueckl 8y ago

Systemd's insistence to gobble up core dumps is one of my favorite misfeatures of that thing. I lost many an interesting (large) dump because they wouldn't be logged in the journal and not be written to file as expected. Luckily this can be disabled (until the next system update resets the syscfg variable again). I don't even get what problem this "feature" is supposed to solve.

vidoc 8y ago
and at some point it was even comedy gold when the system would compress them with ... xz! lol