Service Logs - For Users

For a long time I was worried about the problem that the shared hosting user does not always know what is happening with his account - did anyone log in via ftp , did the cron job complete , was there access via ssh , where did the message go and was it sent at all. For most hosters (including ours), the user could ask a question to the technical support service and wait for a specialist with the appropriate rights and qualifications to make a selection of the necessary logs. Bonus problem - you can’t just take one command and look at the log entries related to the user. This creates difficulties for the system administrator.

It would seem a simple task from the very beginning to bring surprises.


Firstly, it turned out that not all programs can work with the systemsyslog . For example, proftpd can write the main log to syslog , but it cannot write the log of working with files there. The documentation has a “crutch” for this situation (by the way, not working), which implies a separate “daemon” that listens to the FIFO file (into which suddenly proftpd can write any journal). But as a result, the log entries are strange and by the amount of backups I decided to abandon the idea of ​​writing a filter that is run from syslogd .

Secondly, it turned out that for some programs a “tracking” system should be introduced (which saves the lines and writes them to the log only when a line appears that allows the user to be identified) with a non-trivial analysis of the log lines. The poorest log in the OpenSSH server. To understand under which key the user is logged in, you have to enable debug mode, the connection to the terminal is written only in the strongest debug mode (and I refused), the tunnels are not allocated in any way in a special way. The key is not written to the journal itself, but fingerprint (tell me, how many of those reading this way can immediately see the fingerprint of the ssh key?), I had to write a backup, writing the beginning and end of the key to the journal from authorized_keysto make it clear. The established connections do not have an identifier and you have to remember them by the pid of the process, after a successful login, the log is not marked with the username and again you have to keep in mind which pid serves which user. We have to carefully monitor all possible options for completing the process in order to avoid “leaks” or incorrect interpretations. In particular, I wrote a “garbage collector”, given that I might accidentally “lose” some lines of the log. The proftpd log also has a difficult to track connection problem . The simplest oddly enough was sendmail. He puts down all the letters the number of the queue, which he writes to the journal. Wherever appropriate, he reports which system user he was dealing with. At the same time, sendmail’s journal format itself is a bit brain-bearing.

The process of implementing the “folding bed” after clarifying the features and choosing the method of reading the logs was also entertaining.

I decided to go according to the ideology of UNIX to use the existing tools. I traditionally wrote the “folding-out" itself in perl, the task was to track the magazines. The choice fell on the tail utilitywith the -f switch for each magazine of interest and the subsequent analysis of what was read. But what to do with the rotation of the logs that we read? And then, in old age, my eyes opened on the key -F. For simplicity, I decided to do a process for each journal ... and "died" in the scheduling of processes. When an external signal arrives, it is necessary to send a signal to everyone, that one should have its own handlers, it is necessary to work out the system crash, reboot. And then I remembered that tail can monitor several files at once. Compilation of algorithms for determining which file belongs to which line turned out to be nontrivial. 'tail' writes from which file it is currently outputting lines, but you have to make a tracking system that remembers what he wrote. In the afternoon torment, it turned out that in the system implementation of tailthere is an error in FreeBSD, when working with a terminal other than the terminal, the file name is written after outputting lines from it, and not before. In the end, I just made my own implementation of continuous reading of files in Perl language with tracking of their renaming. On the issue of bicycles and standard solutions. Sometimes a bicycle in all respects is more profitable.

How did I rotate user logs? Like the rotation of the rest, the system utility deals with this. When receiving a line for the user’s log, the “folding” script looks if I have it in open files, if not, it opens and remembers. After renaming and rotating user logs, the system service for log rotation sends the classic SIGHUP to our “layout”. The handler of this signal in the “folding” simply cleans the list of open descriptors, simultaneously closing them. Accordingly, when data arrives, the files are reopened.

The result was impressive. So many interesting things turned out in user behavior. And by the way, about nice add-ons that decorate any good utility. In addition to putting logs in user home directories, I made a copy of the record separately in one place for system administrators. Now you can at a glance evaluate the current situation of each user for the service of interest. Logs in an additional place during rotation are simply killed, since the current assessment does not require an archive.

Summary. When you write a program, think for whom you write the logs of this program. When you choose a tool, think about it - but this is definitely not an ideological choice?

PS I express my deep gratitude to my readers on Juick for their help in developing the system. Without you, there was every chance not to cope with the task.

UPDATE: github.com/schors/peruserlog