[systemd-devel] Slow startup of systemd-journal on BTRFS

[Lennart Poettering]

On Mon, 16.06.14 09:05, Josef Bacik (jbacik at fb.com) wrote:

> So you are doing all the right things from what I can tell, I'm just
> a little confused about when you guys run fsync.  From what I can
> tell it's only when you open the journal file and when you switch it
> to "offline."  I didn't look too much past this point so I don't
> know how often these things happen.  Are you taking an individual
> message, writing it, updating the head of the file and then
> fsync'ing?  Or are you getting a good bit of dirty log data and
> fsyncing occasionally?

The latter. Basically when opening a file for writing we mark it in the
header as "online", then fsync() it. When we close a file we fsync() it,
then change the header to "offline", ans sync() again. Also, 5min after
each write we will also put things to offline, until the next write,
when we will put things to online again. Finally, if something is logged
at priorities EMERG, ALERT or CRIT we will sync immediately (which
actually should never happen in real-life, unless something is really
broken -- a simple way to check if anything like this got written is
"journalctl -p crit").

Also, we rotate and start a new file every now and then, when we hit a
size limit, but that is usually very seldom.

Putting this together: we should normally fsync() only very
infrequently. 

> What would cause btrfs problems is if you fallocate(), write a small
> chunk, fsync, write a small chunk again, fsync again etc.  Fallocate
> saves you the first write around, but if the next write is within
> the same block as the previous write we'll end up triggering cow and
> enter fragmented territory.  If this is what is what journald is
> doing then that would be good to know, if not I'd like to know what
> is happening since we shouldn't be fragmenting this badly.

Hmm, the only way I see that that would happen is if a lot of stuff is
logged at these super-high log levels mentioned above. But then again,
that never really should happen in real-life.

Could anyone who's expereiencing the slowdowns have a look on the
journalctl output menionted above? Do you have more than a few lines
printed like that?

Lennart

-- 
Lennart Poettering, Red Hat