Skip to main content

Ralsina.Me — Roberto Alsina's website

Logging in style

Let's try a lit­tle clas­si­cal log­ic:

Logs are the ad­min­is­tra­tor's best friend.

Lin­ux is the favourite op­er­at­ing sys­tem for many ad­min­is­tra­tors.

Er­go, Lin­ux has a very nice log­ging sys­tem.

BZZZZZT Lin­ux has an ad­e­quate log­ging sys­tem. At least com­pared to what you get with some oth­er op­er­at­ing sys­tem­s, where of­ten you have no place to look for the rea­son of your mis­ery.

On Lin­ux, your mis­ery is usu­al­ly vis­i­ble :-)

How You Are Probably Doing It Now

You are very like­ly to be run­ning sys­logd, which is a pret­ty tra­di­tion­al unixy sys­log im­ple­men­ta­tion, or sys­log-ng, which is the same thing, on­ly dif­fer­en­t. We'll as­sume you are us­ing sys­log from now on.

It's con­fig­ured via /etc/sys­log.­con­f, which usu­al­ly looks like this:

# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.*                                                 /dev/console

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none                /var/log/messages

# The authpriv file has restricted access.
authpriv.*                                              /var/log/secure

# Log all the mail messages in one place.
mail.*                                                  -/var/log/maillog


# Log cron stuff
cron.*                                                  /var/log/cron

# Everybody gets emergency messages
*.emerg                                                 *

# Save news errors of level crit and higher in a special file.
uucp,news.crit                                          /var/log/spooler

# Save boot messages also to boot.log
local7.*                                                /var/log/boot.log

To make a long sto­ry short: the left col­umn is fa­cil­i­ty.pri­or­i­ty The right col­umn is where you log it.

For ex­am­ple, a crit­i­cal mes­sage from your mail serv­er soft­ware, will prob­a­bly be mail.­crit­i­cal and be logged to /var/log/­mail­log.

A sin­gle mes­sage can be logged in as many places as you wan­t.

The ap­pli­ca­tions de­cide what fa­cil­i­ty they use and what pri­or­i­ty their mes­sages are.

Sim­ple, right? Yes. But not very good.

Rotation

Sup­pose I know that when­ev­er I con­nect to your mail server, you log a line, about 60 bytes.

Now, sup­pose I con­nect to your serv­er 10 times per sec­ond for three days. That's 150MB of logs.

Now sup­pose my 20 best friends do it, too. That's 3GB of logs.

Ba­si­cal­ly, with some ef­fort, any­one can clog your disk.

Oh, but your logs ro­tate I hear. Log ro­ta­tion means you cut your logs ev­ery once in a while, delete old­er data, maybe com­press not-­so-old data, and that way the logs don't grow in­def­i­nite­ly. You prob­a­bly use logro­tate for this.

But just how large will your log get? Con­sid­er that the de­fault ro­ta­tion pe­ri­od is usu­al­ly week­ly, and usu­al­ly you keep 4 old­er copies... but it does­n't mat­ter: if you ro­tate based on time, you have no up­per bound to the size of your logs.

It would be bet­ter to ro­tate by size of the log, or a com­bi­na­tion of both things.

Who Manages Logs?

I usu­al­ly man­age the whole sys­tem. How­ev­er, I think it's a good idea if you have the pos­si­bil­i­ty of del­e­gat­ing spe­cif­ic sub­sys­tems to oth­er ad­min­s.

Now sup­pose you are my sub­-ad­min in charge of ser­vice FOO.

Now, you want to de­bug some­thing, so you need to change FOO's log­ging to catch de­bug pri­or­i­ty mes­sages.

How do you do that? Well, you have to call me, be­cause there is a cen­tral­ized log con­fig­u­ra­tion. (Un­less FOO sim­ply ig­nores sys­tem log­ging, which sucks in a com­plete­ly dif­fer­ent way).

Ba­si­cal­ly, we are not putting the man­age­ment of log­ging for FOO close to FOO. We are putting it close to sys­log. Maybe that's good. Maybe not.

Where's the log?

Un­less you have a clear idea of what fa­cil­i­ty and pri­or­i­ty your app us­es, how do you know where it's log­ging? What hap­pens if you on­ly catch part of the log?

It would be nicer if each ser­vice had a spe­cif­ic place where it logged! Uni­form is good.

What happens if syslog dies?

Well, you don't log any­more. So please make it a man­aged ser­vice, be­cause life with­out logs suck­s.

So, what can we use?

Well, as long as you use some­thing like runit or dae­mon­tools, you can use one of the bazil­lion log­ging tools that use the "give me a fold­er name and da­ta on std­in" mod­el. I am par­tial to svlogd but there are a mil­lion oth­er­s.

That solves many things:

  • There is no sys­log, so it can't die. There is one log­ger for each ser­vice. And it's man­aged any­way, so it bounces back up.

  • The log is wher­ev­er you tell it to be. Stan­­dard­­ize in /var/log/­­FOO or some­­such.

  • You can choose un­der what us­er the log­ger run­s. So, who­ev­er you want man­ages it.

  • Most log­gers of­fer you size or time-based ro­­ta­­tion. And you don't need to con­­fig­ure logro­­tate (y­ou don't need logro­­tate)

But what about the apps that want to use sys­logd and don't work as a man­aged ser­vice with log­ging?

Well, they do it by writ­ing to /de­v/log, a pseu­do-de­vice which pipes the da­ta to sys­log.

Then, you can use sock­log a love­ly drop-in drop-dead gor­geous re­place­ment for sys­logd. Use it, con­fig­ure it for unix sock­et (us­ing sock­log-­con­f), start it (us­ing runit's runsv), and en­joy:

[root@myhost socklog]# pwd
/var/log/socklog
[root@myhost socklog]# ls -lR
.:
total 48
drwxr-x--- 2 root root 4096 Sep 14 21:16 auth
drwxr-x--- 2 root root 4096 Sep 14 21:16 cron
drwxr-x--- 2 root root 4096 Sep 14 21:16 daemon
drwxr-x--- 2 root root 4096 Sep 14 21:16 debug
drwxr-x--- 2 root root 4096 Sep 14 21:16 ftp
drwxr-x--- 2 root root 4096 Sep 14 21:16 kern
drwxr-x--- 2 root root 4096 Sep 14 21:16 local
drwxr-x--- 2 root root 4096 Sep 14 21:16 mail
drwxr-x--- 2 root root 4096 Sep 14 21:16 main
drwxr-x--- 2 root root 4096 Sep 14 21:16 news
drwxr-x--- 2 root root 4096 Sep 14 21:16 syslog
drwxr-x--- 2 root root 4096 Sep 14 21:16 user

./auth:
total 8
-rw-r--r-- 1 root root   34 Sep 14 21:16 config
-rw-r--r-- 1 root root 1003 Sep 14 22:03 current
-rw------- 1 root root    0 Sep 14 21:16 lock

./cron:
total 4
-rw-r--r-- 1 root root 22 Sep 14 21:16 config
-rw-r--r-- 1 root root  0 Sep 14 21:16 current
-rw------- 1 root root  0 Sep 14 21:16 lock

One fold­er for each fa­cil­i­ty, you can fil­ter the da­ta if you want to avoid log­ging spe­cif­ic stuff, time­stamp any way you wan­t, ro­tate at will, ya­da ya­da ya­da.

On Arch Lin­ux, you can try this by in­stalling my runit and sock­log pack­ages from AU­R.

It should be pret­ty painless, but try it in a vir­tu­al box first ;-)

nonnano / 2006-09-15 20:30:

Such scheme still does not support properly being truly cross platform, the needs of different systems/software (more fields, efficient filtering abilities), proper security methods (log items tied properly to the authentication/crypto stuff), more advanced centralized management features and so on...

Horrible. Plain horrible. Just like everything you can find at least from freshmeat.net and sf.net. Trust me, I have browsed through all the projects that contain the word "log" in their descriptions in any form. Absolutely none of them is worth anything.

Roberto Alsina / 2006-09-15 23:01:

In what way is an ascii pipe not cross platform?

Fields? What exactly do you mean by that?

Filtering? You can filter on regular expresions, hell, you can do bayesian filtering of events if you want.

Log items tied to auth/crypto? What log items should? please explain.

These mechanisms are much more flexible thatn you think.


Contents © 2000-2020 Roberto Alsina