[systemd-devel] stop+start of nspawn scope aborts: 's-state == SCOPE_DEAD'
Hi list, I hit a bug today in the scope unit support. Reproducible like this: systemd-nspawn -bD /srv/subarch systemctl stop machine-subarch.scope systemctl start machine-subarch.scope I wasn't sure whether start would do anything or not so I gave it a shot, but it turned out to crash the host systemd with: Assertion 's-state == SCOPE_DEAD' failed at src/core/scope.c:246, function scope_start(). Aborting Tested with systemd 206 as well as current git master (206.103.g631c922) on Arch Linux. /srv/subarch is a plain Arch Linux installation created according to: https://wiki.archlinux.org/index.php/Arch_systemd_container Regards, Marti gdb backtrace: #0 0x7fa684ee21c9 in raise () from /usr/lib/libc.so.6 #1 0x7fa684ee35c8 in abort () from /usr/lib/libc.so.6 #2 0x0045d823 in log_assert () #3 0x0045e0c0 in log_assert_failed () #4 0x0047ea2f in scope_start () #5 0x00479721 in job_run_and_invalidate () #6 0x0040e3ee in manager_dispatch_run_queue () #7 0x0041152f in manager_loop () #8 0x00409726 in main () Full log: Aug 12 19:30:32 arch systemd[1]: Stopping Container subarch Aug 12 19:30:33 arch systemd[1]: machine-subarch.scope stopping timed out. Killing Aug 12 19:30:33 arch systemd[1]: Stopped Container subarch Aug 12 19:30:33 arch systemd[1]: Unit machine-subarch.scope entered failed state Aug 12 19:30:33 arch systemd-machined[403]: Machine subarch terminated Aug 12 19:30:33 arch systemd[1]: Stopped Container subarch Aug 12 19:30:35 arch systemd[1]: Starting Container subarch Aug 12 19:30:35 arch systemd[1]: Assertion 's-state == SCOPE_DEAD' failed at src/core/scope.c:246, function scope_start(). Aborting Aug 12 19:30:35 arch systemd[1]: Caught ABRT, dumped core as pid 486 Aug 12 19:30:35 arch systemd[1]: Freezing execution Aug 12 19:30:35 arch systemd-coredump[487]: Process 486 (systemd) dumped core ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] [RFC PATCH] systemd-python: add SYSLOG_IDENTIFIER to JournalHandler
On Mon, Apr 22, 2013 at 11:31 PM, Zbigniew Jędrzejewski-Szmek
zbys...@in.waw.pl wrote:
Otherwise, we get SYSLOG_IDENTIFIER=python or something
similar, which is completely useless.
I think we shouldn't be creating one-off arguments for every possible
field someone might want to add, but something more generic -- take a
dict as argument for example.
Ideally it would be possible to attach custom journal fields to the
Python root logger and have them propagate to all loggers from there.
But I tried and couldn't make it work without the code getting really
ugly. Here are some of my thoughts on the topic:
http://lists.freedesktop.org/archives/systemd-devel/2012-October/006937.html
And a reply:
http://lists.freedesktop.org/archives/systemd-devel/2012-November/007372.html
Note that Python's SysLogHandler has something vaguely similar, but
it's pretty annoying to use. It's not a constructor argument, but an
attribute you have to override and is simply prepended to the syslog
message so you also have to include the separating colon and space
(like in the C syslog API).
import logging, logging.handlers
h=logging.handlers.SysLogHandler(address='/dev/log')
h.ident='somename: '
l= logging.getLogger('froggerlogger')
l.propagate = False
l.addHandler(h)
l.warning('foo')
Regards,
Marti
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] PATCH: Integration with Python logging framework
On Tue, Nov 13, 2012 at 12:23 PM, Zbigniew Jędrzejewski-Szmek
zbys...@in.waw.pl wrote:
I went ahead and merged the patch with some small changes, please have
a look.
JournalHandler is already useful right now
Cool, thanks! Agreed, the rest could just be built on top of this code.
On Tue, Nov 13, 2012 at 12:43 PM, Zbigniew Jędrzejewski-Szmek
zbys...@in.waw.pl wrote:
On Mon, Oct 15, 2012 at 11:30:09PM +0300, Marti Raudsepp wrote:
1. Event data
One clear use case that's fairly easy to support is supplying custom
message-specific data, such as MESSAGE_ID. Or details of the event
that caused the log message; for example, a HTTP request log has
fields for client's IP address, request URL, User-Agent string, etc.
The extra= way of providing these works well enough, but there needs
to be a way to mark which fields are intended to go to systemd and
which not.
I think that apart from the fields which are already supported
(MESSAGE_ID, CODE_*), there will not be any fields that are widely
used, and that fields will be specific to the message or group of
messages. So I don't see a reason to try to attach the translation
from extra-dict key to systemd field name to the root logger.
Yeah, the intention was that the app developer wouldn't attach these
to the root logger, but to the specific logger where they are using
those extra fields.
2. Context data
Python offers LoggerAdapter, but sadly the context they provide is
only attached to one logger. Since they add fields to the LogRecord,
the above API already suffices for them.
When I look at LoggerAdapter, it seems to me that it could do the job
just fine. A SystemdLoggerAdapter could add ._systemd_fields dict to
the record object, which would contain the mapping
extra-dict-systemd. It's not particularly efficient, since it
creates an extra LoggerAdapter object per Logger, but logging
is not very fast anyway.
I think you missed my point: it should be possible for the caller to
specify context fields and *values* without having to plaster all
callee log messages with an extra={} dict, nor requiring them to wrap
every logger they use in a SystemdLoggerAdapter.
While developing some Django applications, I found logging to be
almost useless because many layers of the application don't (and
shouldn't) have access to details of the request. E.g. errors from a
third party PDF renderer module. Yet request context details are
crucial when analyzing logs: did two subsequent log messages come from
the same request or two completely unrelated requests? Which user
caused this message to be logged?
There's one place that's well positioned to add these fields: the
request dispatcher. It should be possible to add these fields to all
log messages by any callee by only patching one place. If we can make
it as easy as that, I can see common upstreams like web frameworks
coming with nice journal integration by default. If they have to
change every module to supply some journal fields -- forget it.
Regards,
Marti
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] when will mount / df get fixed?
On Mon, Oct 1, 2012 at 8:22 PM, Jan Engelhardt jeng...@inai.de wrote: and how they should do this after the change that there is no flag? dispaly a RANDOM line? That is a possibility. Based upon that you are only interested in the device anyway, I conclude the mountpoint is irrelevant. I didn't read the whole thread so maybe this has already been proposed, but... 1) we want df to show space usage by disk 2) we want df to show mount points 3) the mapping from disks to mount points is one-to-many Why not just collect all the relevant mount points on one line, for each disk? This way we don't throw away any information, but prevent repeating redundant information that's always the same for each disk. Using the original example this would look something like: Filesystem Size Used Avail Use% Mounted on /dev/md2 3.5T 2.1T 1.3T 62% /mnt/data, /home, /tmp, /var/tmp, /Volumes/dune/www-servers, /Volumes/dune/www-servers/phpincludes And maybe for console output, the mount point column should be split on multiple lines based on terminal width (disabled for non-tty output for greppability)... Filesystem Size Used Avail Use% Mounted on /dev/md2 3.5T 2.1T 1.3T 62% /mnt/data, /home, /tmp, /var/tmp, /Volumes/dune/www-servers, /Volumes/dune/www-servers/phpincludes Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] PATCH: Integration with Python logging framework
Hi list,
The attached patch implements journal integration for the Python
logging framework. Tested on my Arch Linux machine, using Python 2.7
and 3.2, but should be compatible with all versions from 2.5 through
3.3
The logging framework has a mechanism for supplying additional
key-value pairs, but I'm currently only passing through MESSAGE_ID.
Are there any other common custom fields that apps are supposed to
use?
Unfortunately it's impossible to tell apart extra fields from the
standard ones, and dumping all fields into journal seems like a bad
idea since they're mostly redundant. The values may also be Python
objects and not strings. Thoughts?
Also, exception tracebacks are logged as one multi-line log message.
Is this a good idea? I see that journalctl has recently gained support
for displaying multiline messages.
Description from docstring:
Journal handler class for the Python logging framework.
Please see the Python logging module documentation for an
overview: http://docs.python.org/library/logging.html
To create a custom logger whose messages go only to journal:
log = logging.getLogger('custom_logger_name')
log.propagate = False
log.addHandler(journal.JournalHandler())
log.warn(Some message: %s, detail)
Note that by default, message levels INFO and DEBUG are ignored
by the logging framework. To enable those log levels:
log.setLevel(logging.DEBUG)
To attach journal MESSAGE_ID, an extra field is supported:
log.warn(Message with ID,
extra={'MESSAGE_ID': '22bb01335f724c959ac4799627d1cb61'})
To redirect all logging messages to journal regardless of where
they come from, attach it to the root logger:
logging.root.addHandler(journal.JournalHandler())
For more complex configurations when using dictConfig/fileConfig,
specify 'systemd.journal.JournalHandler' as the handler class.
Only standard handler configuration options are supported:
level, formatter, filters.
The following journal fields are supported: MESSAGE, PRIORITY,
LOGGER (name as supplied to getLogger call), THREAD_NAME,
CODE_FILE, CODE_LINE, CODE_FUNC, MESSAGE_ID (optional, see above)
This is what an example message looks like:
MESSAGE=Message with ID
PRIORITY=4
LOGGER=custom_logger_name
THREAD_NAME=MainThread
CODE_FILE=test.py
CODE_LINE=20
CODE_FUNC=test_journal
MESSAGE_ID=e38633ad25104c50a3f6a43ebe862368
Also available from my GitHub fork:
https://github.com/intgr/systemd/ branch py-logging
Regards,
Marti
0001-python-integration-with-Python-logging-framework.patch
Description: Binary data
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] System stability when journald locks up
On Wed, May 30, 2012 at 4:45 PM, Lennart Poettering lenn...@poettering.net wrote: OK, there indeed was a loop here, where we ended up processing messages we ourselves wrote to kmsg. I have fixed that now in git. Could you test please if this solves your problems? Thanks. Yes, looks like this fixes my issue. I filled my disk, made sure that journald starts consuming 100% CPU. Then replaced /usr/lib/systemd/systemd-journald with one built from git, killed and the problem disappeared. On Tue, May 29, 2012 at 11:29 PM, Lennart Poettering lenn...@poettering.net wrote: The journal is still very new. I think so far it is quite stable, but there is definitely more work necessary to make it rock solid in all corner cases. Well, any concrete ideas? Locking the user out of his/her own system is the best way to become hated by sysadmins. I certainly don't want to see journald on my servers until that's addressed. Maybe a client-side timeout in libsystemd-journal? While that could still effectively crash applications by slowing them down too much, at least it's possible to log in to inspect and fix the issue. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] journal corruption on SIGKILL and mostly full disk: Bad message
Hi list, As usual, attempting to debug one problem inevitably leads to another bug. I found out that after filling my disk and SIGKILLing journald a few times, it seems to corrupt the journal archive. Seems to be reproducible every time. journalctl reports: Failed to iterate through journal: Bad message Running systemd-journald from git HEAD. # Allocate large file to mostly fill the disk (770 MB free out of 32 GB) fallocate --length=125 /filler rm -rf /var/log/journal/* killall -9 systemd-journald journalctl -n10 May 30 22:38:37 newn systemd-journal[28656]: Journal started May 30 22:38:37 newn systemd[1]: systemd-journald.service: main process exited, code=killed, status=9 killall -9 systemd-journald journalctl -n10 May 30 22:38:37 newn systemd-journal[28656]: Journal started May 30 22:38:37 newn systemd[1]: systemd-journald.service: main process exited, code=killed, status=9 killall -9 systemd-journald journalctl -n10 Failed to iterate through journal: Bad message ls -lA /var/log/journal/dd9596f699f65b18472a55a24aa17111 -rw-r- 1 root adm 36864 May 30 22:46 system@e82653abcaa74d8e9bb413325f98813b-0002-.journal -rw-r- 1 root root 36864 May 30 22:46 system.journal The two broken files (mostly consisting of zeroes) attached. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] journal corruption on SIGKILL and mostly full disk: Bad message
On Wed, May 30, 2012 at 10:52 PM, Marti Raudsepp ma...@juffo.org wrote: The two broken files (mostly consisting of zeroes) attached. Well, they are now... :) Regards, Marti broken-journal.tar.gz Description: GNU Zip compressed data ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] System stability when journald locks up
On Wed, May 30, 2012 at 10:59 PM, Lennart Poettering lenn...@poettering.net wrote: Many people have configured their classic syslog daemon to output logs on /dev/tty12. If you press C-s there (or accidentally hit Scroll Lock) you end up freezing syslog too and thus freezing the entire machine sooner or later. It's kind of a known problem. Oh, for some reason I was under the impression that this problem was caused by journald. But you're right, all my systems are already at the mercy of syslogd. Sorry, I didn't mean to be unfair. :) Adding the timeout change there (which would actually be dead-easy, simply by using SO_SNDTIMEO) would not really fix the problem too well though: given the amount of messages that are generated the system might not be locked up entirely but still very slow. True. Or O_NONBLOCK, but then we'd start dropping messages as soon as the kernel packet queue fills up. Well, one potential solution would be to spawn a thread whose only job is to pop messages from /dev/log and copy them to a larger user-space buffer, shared with journald. If this memory buffer fills up, we know for a fact that an application is sustainably generating more messages than we can write out, so dropping them might be a good idea to prevent journald from becoming the bottleneck. Additionally, journald could emit a notice about the dropped messages. On the one hand, this could in theory be used by an attacker to conceal log messages (s)he doesn't want the administrator to see. On the other hand, it would alleviate a local DoS hole that can currently be used to slow down the machine. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] System stability when journald locks up
Hi list,
Long story short, I believe there are two problems with journald:
1) journald gets stuck in an infinte loop, trying to send the message
Dropping message, as we can't find a place to store the data to
somewhere -- occurs in v44 and v183 (Arch Linux)
2) A journald problem can effectively lock up the whole system. I
agree that reliable logging is a worthwhile goal, but it shouldn't
compromise the reliability of the whole system. Are there any plans to
address this failure mode?
I'm sure there are other ways how journald can get stuck -- attaching
a debugger or trying to write to a crashed hard drive or network file
system for instance.
I'll see if I can figure out a temporary solution for #1 to get my
computer back :)
Rant version:
Last night, I noticed my desktop computer (still using systemd v44)
spinning up its fans for no apparent reason. A quick inspection with
htop revealed that systemd-journald was using 100% CPU. Soon enough
the system became unusable entirely; I couldn't launch any more
terminals and current ones were stuck at sudo, nor could I ssh in. I
presume everything was blocked behing logging.
Today I upgraded to systemd v183, rebooted, and after logging in the
same happened again. I managed to capture an strace snippet:
stat(/etc/localtime, {st_mode=S_IFREG|0644, st_size=2175, ...}) = 0
sendmsg(5, {msg_name(29)={sa_family=AF_FILE,
sun_path=/run/systemd/journal/syslog}, msg_iov(5)=[{44, 4},
{May 28 19:39:32 , 16}, {systemd-journald, 16}, {: , 2},
{Dropping message, as we can't find a place to store the data.,
61}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 ENOENT (No
such file or directory)
uname({sys=Linux, node=newn, ...}) = 0
writev(6, [{44, 4}, {systemd-journald, 16}, {[1352]: , 8},
{Dropping message, as we can't find a place to store the data., 61},
{\n, 1}], 5) = 90
Removing /var/log/journal/* didn't help -- journald created new files
and got stuck again. Killing journald didn't help either -- of course
systemd launched it up again.
In desperation, I typed systemctl stop systemd-journald.socket and
systemd helpfully stopped my whole system. :)
Another reboot and now gdm and text consoles freeze when attempting to
log in. Dunno how I managed to log in before.
Regards,
Marti
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] System stability when journald locks up
On Mon, May 28, 2012 at 8:33 PM, Marti Raudsepp ma...@juffo.org wrote: Removing /var/log/journal/* didn't help -- journald created new files and got stuck again. Well removing the whole /var/log/journal and restarting journald fixed the problem. Re-creating and restarting reproduced int every time. Turns out I was kind-of low on disk space (1GB out of 32 left) After cleaning up some and re-creating /var/log/journal, the problem is gone. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] Doing kexec reboot right in systemd
On Mon, Mar 26, 2012 at 21:07, Lennart Poettering lenn...@poettering.net wrote: Marti, sorry for changing my mind on this: would be great if you could prep a patch for this for systemd itself. D'oh, I already prepared a patch for kexec, although I haven't sent it out yet. Hmm, so since this would then belong in the shutdown path of systemd, and only be added for the kexec shutdown path I actually think it would make more sense to add this into systemd itself instead of kexec-tools, to ensure the right ordering. Um, why is including in systemd necessary for guaranteeing order? Seems like this should do it... [Unit] DefaultDependencies=no Before=shutdown.target umount.target final.target [Install] WantedBy=kexec.target I'd like to keep kexec.target different from reboot.target by default, so that people have both options available. Fair enough. a) we introduce kexec-load.service which is always in the kexec.target shutdown path, never in reboot.target. Doesn't need to be enabled. b) kexec-load.service becomes a NOP if a kernel is already loaded c) systemctl reboot continues to check whether a kernel is already loaded, and if so results in kexec.target being started rather than reboot.target d) If the user wants that the machine is always rebooted via kexec, never with traditional reboot, he can manually create a symlink /etc/systemd/system/reboot.target to /etc/systemd/system/kexec.target. Yeah, agreed. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] Doing kexec reboot right in systemd
Hi list, I was recently pondering how systemd could use kexec properly, in a reasonably general way, to make reboots faster. I exchanged an email with Poettering on the systemd list and he suggested me to ask here. My current proposal: 1. Include a template 'kexec-load.service' with kexec-tools, which distros/users could customize to load the right kernel and initrd via /sbin/kexec 2. If the user does 'systemctl enable kexec-load.service', then this service would trigger before every reboot. Loading the kernel any earlier would waste memory (5+14 MB on Ubuntu Server). Also a common reason for rebooting is to boot into a newly-installed kernel. Loading it any earlier would boot you into an older kernel. 3. During a reboot, after systemd has finished shutting down, it detects via /sys/kernel/kexec_loaded whether the kexec kernel is loaded. If 1, it performs a 'kexec -e'. If not, it does a normal reboot. Lennart commented on #2 that kexec might have problems finding contiguous memory to load the kernel into, this late in the lifecycle. Do you think this is a deal-breaker for such a feature? If it's rare enough, then it might not be a problem -- we can always fall back to a normal reboot. I'm also assuming that kexec --load will fail atomically -- that it won't try to boot a half-loaded kernel, or boot a kernel whose initrd failed to load. Also, #3 doesn't yet work that way in systemd (currently it detects before shutdown) and Poettering hasn't agreed yet. Does this proposal seem sane to kexec folks? Did I miss anything? Here are my and Poettering's initial thoughts on this matter: http://lists.freedesktop.org/archives/systemd-devel/2012-March/004760.html http://lists.freedesktop.org/archives/systemd-devel/2012-March/004764.html PS: I hope I haven't broken any rules by cross-posting this. This question seems relevant to both projects. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] Right way to do kexec
Hi,
I've been trying to figure out how to use systemd's kexec functionality right.
When one runs systemctl kexec, systemd simply shuts down and
executes 'kexec -e'. For this to work, a kexec-able kernel has to be
already loaded.
Now, when do I load this kernel? Loading at startup means that I'm
simply wasting the memory most of the time when I'm not rebooting. And
if I upgrade the kernel, the old kernel sticks around in memory -- but
the point of rebooting is usually to load the *new* kernel?
So it probably should be done just before shutdown. I created a
'kexec-load.service' file with:
[Unit]
DefaultDependencies=no
Before=shutdown.target umount.target final.target
[Service]
Type=oneshot
ExecStart=/sbin/kexec --load /boot/vmlinuz-linux
--initrd=/boot/initramfs-linux.img --reuse-cmdline
And added 'Requires=kexec-load.service' to kexec.target
Now systemctl kexec works, so far so good!
Maybe we could add an empty kexec-load.service into systemd itself, so
distros and users just need to override its ExecStart to do what they
want and it would work automagically?
Next, we have a chicken-and-egg kind of problem. systemctl reboot
has logic like:
if (strstr(program_invocation_short_name, reboot)) {
if (kexec_loaded())
arg_action = ACTION_KEXEC;
else
arg_action = ACTION_REBOOT;
}
Obviously the kexec kernel won't be loaded yet at this time, so
systemd won't actually do a kexec. Dunno what to do about this. Maybe
drop kexec.{service,target} entirely and do this checking at
reboot.service time? That would also deprecate the systemctl kexec
command.
Regards,
Marti
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] Right way to do kexec
On Thu, Mar 22, 2012 at 02:16, Mirco Tischler mt...@gmx.de wrote: Unless you want to use kexec on panic. In that case the kexec kernel should be loaded at boot, doesn't it? But I don't know if this is actually in use or more a debugging tool for kernel devs. Sure, the crashdump kernel is loaded with 'kexec --load-panic' and is usually a different image/initrd anyway. So systemd's usage of kexec for reboot doesn't affect that at all. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] StandardOutput to file
2012/3/15 Martín Marqués martin.marq...@gmail.com: I the old system, I had the script make a redirection of the pg_ctl (postgresql script for starting, stopping, etc the server) output to a file, which would be the log file (default behaviour in Debian). If you're talking about catching errors from pg_ctl itself then that's not possible (as described by Lennart and Kay). Note that these errors are written to stderr, not stdout. If you want to redirect logs from the server process then pg_ctl provides the -l argument for this. (Or better, you could set logging_collector=on, so PostgreSQL will write to $PGDATA/pg_log and rotate log files itself) Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] Multiline log mesages in journal
On Wed, Mar 14, 2012 at 20:10, Lennart Poettering lenn...@poettering.net wrote: I think I would prefer if do not repeat the the meta data in the output, and just output the actual message, line-by-line, prefixed with whitespace. So that we'd get this: Mar 07 12:23:57 host postgres[6326]: line1 line2 Yeah, that seems like a better idea. I guess we should do the same thing in verbose output mode. Does PostgreSQL actually write those multi-line messages into syslog datagrams? interesting i must say, I didn't expect that people do that No, currently it sends a separate syslog message for each line. But I wrote a PostgreSQL module to send messages directly to journal (since there's a lot of useful context information that gets lost with syslog) and was wondering how to handle multiline messages: https://github.com/intgr/pg_journal/blob/master/doc/pg_journal.md The display routines for those messages could use some love probably. For example, I know a couple of services which log messages with tabs in them. Also, we recently added functions to check utf8 validity of strings to systemd. Yeah, I took a stab at the message printing code and concluded that it needs to be rewritten anyway if we want to handle non-ASCII messages right: * validating UTF-8 in messages (depending on locale) * making sure that ellipsize doesn't corrupt multibyte UTF-8 chars * expand tabs, as you pointed out * double-width Unicode characters (e.g. み takes up two terminal columns) * newline handling Maybe we should give up on ellipsize and just let 'less -S' do the work. That would avoid a lot of complexity with width-counting. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] [PATCH] journal: Don't hold pointers to journal while remapping
Hi!
I was trying out the journal and the journalctl utility sometimes
crashed on me. After some debugging, I tracked it down to the fact
that next_with_matches() holds the c object pointer through the
journal_file_next_entry_for_data() call -- which apparently may re-map
the journal file, invalidating the pointer.
The attached patch fixes this crash for me, but being unfamiliar with
the code, I don't know if I'm doing the right thing.
This patch is also available from my github repository:
git://github.com/intgr/systemd.git
https://github.com/intgr/systemd
Regards,
Marti
For the record, here's the original stack trace at the time of remapping:
#0 journal_file_move_to (f=0xbd7210, wt=3, offset=6414200, size=480,
ret=0x7fff1d5cdec0) at src/journal/journal-file.c:330
#1 journal_file_move_to_object (f=0xbd7210, type=3, offset=6414200,
ret=0x7fff1d5cdf28) at src/journal/journal-file.c:414
#2 generic_array_get (f=0xbd7210, first=69328, i=2546,
ret=0x7fff1d5ce0a0, offset=0x7fff1d5ce098) at
src/journal/journal-file.c:1101
#3 generic_array_get_plus_one (f=0xbd7210, extra=67744, first=69328,
i=5705, ret=0x7fff1d5ce0a0, offset=0x7fff1d5ce098) at
src/journal/journal-file.c:1147
#4 journal_file_next_entry_for_data (f=0xbd7210, o=0x7f7cc1c36d28,
p=6413608, data_offset=66600, direction=DIRECTION_DOWN,
ret=0x7fff1d5ce0a0, offset=0x7fff1d5ce098) at
src/journal/journal-file.c:1626
#5 next_with_matches (j=0xbc0010, f=0xbd7210,
direction=DIRECTION_DOWN, ret=0x7fff1d5ce120, offset=0x7fff1d5ce128)
at src/journal/sd-journal.c:533
#6 next_beyond_location (j=0xbc0010, f=0xbd7210,
direction=DIRECTION_DOWN, ret=0x7fff1d5ce170, offset=0x7fff1d5ce178)
at src/journal/sd-journal.c:595
#7 real_journal_next (j=0xbc0010, direction=DIRECTION_DOWN) at
src/journal/sd-journal.c:651
#8 sd_journal_next (j=0xbc0010) at src/journal/sd-journal.c:686
#9 main (argc=5, argv=0x7fff1d5ce308) at src/journal/journalctl.c:263
From 9266fc6a58065a7c5dab67430fd78925e519dce9 Mon Sep 17 00:00:00 2001
From: Marti Raudsepp ma...@juffo.org
Date: Fri, 9 Mar 2012 16:23:00 +0200
Subject: [PATCH] journal: Don't hold pointers to journal while remapping
This would cause a segfault otherwise.
---
src/journal/sd-journal.c | 12 +++-
1 file changed, 11 insertions(+), 1 deletion(-)
diff --git a/src/journal/sd-journal.c b/src/journal/sd-journal.c
index baf51db..86ac267 100644
--- a/src/journal/sd-journal.c
+++ b/src/journal/sd-journal.c
@@ -527,6 +527,9 @@ static int next_with_matches(sd_journal *j, JournalFile *f, direction_t directio
* matches are not OK */
r = journal_file_next_entry_for_data(f, c, cp, le64toh(c-entry.items[k].object_offset), direction, qo, q);
+/* This pointer is invalidated if the window was
+ * remapped. May need to re-fetch it later */
+c = NULL;
if (r 0)
return r;
@@ -552,8 +555,15 @@ static int next_with_matches(sd_journal *j, JournalFile *f, direction_t directio
/* Did this entry match against all matches? */
if (found) {
-if (ret)
+if (ret) {
+if (c == NULL) {
+/* Re-fetch the entry */
+r = journal_file_move_to_object(f, OBJECT_ENTRY, cp, c);
+if (r 0)
+return r;
+}
*ret = c;
+}
if (offset)
*offset = cp;
return 1;
--
1.7.9.3
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] Multiline log mesages in journal
Hi list, Some applications, such as PostgreSQL have log messages consisting of multiple lines. When reporting to syslog, these messages are artificially split into multiple log lines. But it would be nice to get rid of that legacy with journal -- to prevent lines from being interleaved with other unrelated log messages and to make the lives of log scrapers easier. Also, other fields don't need to be duplicated for each message line. However, currently whenever applications send a message to the journal that includes newlines, it gets displayed as [##B blob data] I hereby propose that the short output mode should first split the message into separate lines, and then simply repeat the timestamp/etc prefix for each line. Perhaps with a limit on the number of max lines per message. e.g: Mar 07 12:23:57 host postgres[6326]: line1 Mar 07 12:23:57 host postgres[6326]: line2 If this is considered a good idea, I can have a try at implementing it. Some examples of multiline log messages: LOG: checkpoints are occurring too frequently (2 seconds apart) HINT: Consider increasing the configuration parameter checkpoint_segments. ERROR: deadlock detected DETAIL: Process 5463 waits for ShareLock on transaction 113367268; blocked by process 5457. Process 5457 waits for ShareLock on transaction 113367000; blocked by process 5463. Process 5463: SELECT sys_stats_daily(); Process 5457: SELECT schedule_process_entry( 20382 ) HINT: See server log for query details. CONTEXT: SQL statement SELECT 1 FROM ONLY public.loan_annex x WHERE annex_id OPERATOR(pg_catalog.=) $1 FOR SHARE OF x SQL function stats_investment_make_prognosis statement 2 SQL statement SELECT stats_investment_make_prognosis() PL/pgSQL function sys_stats_daily line 25 at PERFORM STATEMENT: SELECT sys_stats_daily(); Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] After upgrading glibc: Received environment initctl request
On Tue, Nov 1, 2011 at 19:26, Lennart Poettering lenn...@poettering.net wrote: I didn't really give this much testing, so it would be good if you could check out if this works for you! I built git version as of 263653e10353d8ad155f1faba01981816a2bb712 and indeed this fixes the simple case. I have now commited a simple fix that will simply cause initctl to terminate itself after sending SIGTERM. If there's more data queued in the FIFO then systemd will respawn us anew, so things should be fine. But this only solves half the problem. It doesn't cover the case when you have systemd-initctl running, then issue systemctl daemon-reexec manually and try run SysV /sbin/reboot. Test case: telinit q# spawn systemd-initctl systemctl daemon-reexec reboot# doesn't do anything syslog: systemd-initctl[349]: Failed to start unit: Did not receive a reply. [...] And there's a new problem now. When I manually start the initctl service and it exits: systemctl start systemd-initctl.service telinit u Then systemd thinks it's still running: systemd-initctl.service - /dev/initctl Compatibility Daemon Loaded: loaded (/lib/systemd/system/systemd-initctl.service; static) Active: active (running) since Wed, 02 Nov 2011 18:43:21 +0200; 16s ago Main PID: 327 Status: Shutting down... CGroup: name=systemd:/system/systemd-initctl.service When trying to stop it, systemctl hangs for a long time, the service is now in state: Active: deactivating (stop-sigterm) since Wed, 02 Nov 2011 18:45:07 +0200; 39s ago And eventually it goes into failed state after several minutes pass. PS: Thanks to systemd, my VM now reboots in 1.5 seconds, so testing this was pure pleasure. ;) Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] After upgrading glibc: Received environment initctl request
On Fri, 09.09.11 13:57, Marti Raudsepp (ma...@juffo.org) wrote: Tom Gundersen on #systemd reduced the problem down to this: telinit u reboot When I run the above, I get into the same state that /sbin/reboot doesn't function. On Tue, Sep 20, 2011 at 04:47, Lennart Poettering lenn...@poettering.net wrote: Try to use gdb on systemd-initctl and check if you can figure out where the service chokes on the commands. I finally got around to debugging this further and found the problem. When systemd-initctl is launched, it opens a connection to the systemd D-Bus socket straight away. After executing telinit u, systemd-initctl sends a SIGTERM signal back to systemd, forcing it to reexec. When systemd starts up again, the old D-Bus connection from initctl is no longer functional, thus it can't tell systemd to reboot. I was looking at the wrong log file before, so I missed these messages: Oct 27 19:13:11 arch systemd-initctl[409]: Failed to start unit: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Oct 27 19:13:19 arch systemd-initctl[409]: Failed to start unit: Connection is closed I'm not sure what the right fix is. Here's what occured to me: 1. Don't open a D-Bus connection from systemd-initctl at startup time, but only for the duration of sending a message. 2. Create a retry wrapper around dbus_connection_send_with_reply_and_block() to reconnect to D-Bus when sending fails. 3. Change systemd not to break existing D-Bus connections on daemon-reexec -- not sure if possible 4. Use prctl(PR_SET_PDEATHSIG, SIGTERM); in systemd-initctl. This way the kernel terminates the initctl daemon every time systemd re-executes, but this is racy. Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] After upgrading glibc: Received environment initctl request
On Fri, Sep 9, 2011 at 13:57, Marti Raudsepp ma...@juffo.org wrote: I'm using systemd 35 on Arch Linux testing. Recently I had an upgrade for the glibc package and following that, I couldn't use sysvinit's /sbin/reboot -- the command would broadcast its message, wait for a few seconds and then quit. 'systemctl reboot' still works as supposed. Bump! ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] After upgrading glibc: Received environment initctl request
Dear list, I'm using systemd 35 on Arch Linux testing. Recently I had an upgrade for the glibc package and following that, I couldn't use sysvinit's /sbin/reboot -- the command would broadcast its message, wait for a few seconds and then quit. 'systemctl reboot' still works as supposed. This is what I get in syslog after upgrading glibc: Sep 9 13:50:13 arch systemd[1]: Reexecuting. Sep 9 13:50:13 arch systemd[1]: systemd 35 running in system mode. (+PAM -LIBWRAP -AUDIT -SELINUX +SYSVINIT +LIBCRYPTSETUP; arch) And when I issue /sbin/reboot: Sep 9 13:50:16 arch shutdown[392]: shutting down for system reboot Sep 9 13:50:16 arch systemd-initctl[387]: Received environment initctl request. This is not implemented in systemd. Tom Gundersen on #systemd reduced the problem down to this: telinit u reboot When I run the above, I get into the same state that /sbin/reboot doesn't function. /sbin/reboot is owned by sysvinit 2.88-3 It seems that another Arch Linux users has also experienced this problem: https://bbs.archlinux.org/viewtopic.php?pid=938398#p938398 Regards, Marti ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
