Monthly Archives: April 2018

last

Every time you log in to your Linux® system, a log entry is made.  It is important for security, what if you logged in while you were asleep?  Either you were sleep typing or someone got your password.  Either way, that’s important information.  Lucky for us, Linux® logs this and there’s an easy way to see when you logged in.  That command is last.

If someone does log in and pretend to be you, then that person who isn’t you wants you not to know that you logged in when you didn’t actually log in.

Wait, let me try that again.

If the bad guy logs into the system, he wants to hide from you that he logged in.

Ultron went traipsing around the Internet and he didn’t care if anyone knew what he was up to.

Ultron up to no good

Ultron up to no good

Other bad guys do care so their first attempt is to remove these messages.

Linux® tries to make this hard.  Most log files are straight boring plain text.  That means you can look at them and even edit them and no one will know the difference.

The file that last reads from isn’t like that. It’s a binary file, which means that you an’t edit it at all without mucking things up.

The output of the command looks like this:

computerlamp    pts/2        console Thu Mar 15 20:53   still logged in
computerlamp    pts/2        console Wed Mar 14 20:52 - 20:53  (00:00)
computerlamp    pts/2        console Fri Mar  9 21:24 - 21:34  (00:10)
computerlamp    pts/1        console Sat Feb 24 15:56 - 17:13  (01:17)
computerlamp    pts/0        console Fri Feb 23 14:30 - 15:47  (01:17)
reboot   system boot         console Fri Feb 23 13:59         (20+05:53)
computerlamp    pts/2        console Wed Feb 21 20:06 - 20:16  (00:09)

It shows you when I logged into the system, when I logged out, it shows you that there was a reboot of the system as well.  If I looked over this and said ‘now wait a minute, I was out of town February 23, what happened there?’ then I would be investigating a possible break in of my system.

dmesg

Remember the Linux Kernel and Device Drivers?  They log like everything else.  They also write their log messages to a special file and there’s a command dmesg that lets you see what’s in the file.

The special file has a name and it’s the ring buffer.

The One Ring

The One Ring

This doesn’t mean you have a ring in your computer.  No hobbits are going to go on a quest to retrieve the one ring, sorry.  Go watch The Lord of the Rings to see that ring.

Instead, the ring buffer is a way of storing the messages.  Think of it like a pile of blocks.

A pile of blocks

A pile of blocks

We only want the pile of blocks to be four blocks high, so every time we add a block to the bottom, we must remove one of the blocks from the top.  That’s how the ring buffer works.  It only has a certain amount of information it can store so when that amount is reached, the oldest message in the ring buffer gets removed and the newest one is added.

Next question, what do the messages look like?  Well, you can run the command dmesg  and find out.  Some systems have that command restricted because the people who run the system think it’s a security leak.  It can be, if a device driver is complaining a lot a malicious person can take advantage of that.

I’m here to save the day, though, and show you what an output can look like:

___slab_alloc+0x37a/0x4a0
 ? __es_insert_extent+0x84/0x2f0
 ? ext4_ind_map_blocks+0x102/0xc70
 ? ext4_ind_map_blocks+0x584/0xc70
 __slab_alloc+0x27/0x40
 ? __slab_alloc+0x27/0x40
 ? __es_insert_extent+0x84/0x2f0
 kmem_cache_alloc+0xd5/0x180
 ? __es_insert_extent+0x84/0x2f0
 ? __es_insert_extent+0x84/0x2f0
 __es_insert_extent+0x84/0x2f0
 ext4_es_insert_extent+0xbf/0x190
 ext4_map_blocks+0x262/0x630
 ? __add_to_page_cache_locked+0xb0/0x170
 ext4_mpage_readpages+0x282/0xa20
 ? __raw_callee_save___pv_queued_spin_unlock+0x9/0x10
 ? queue_unplugged+0x33/0xa0
 ? alloc_pages_current+0x58/0xb0
 ext4_readpages+0x29/0x40
 ? ext4_readpages+0x29/0x40
 ? ext4_journalled_zero_new_buffers+0x110/0x110
 __do_page_cache_readahead+0x131/0x1e0

That’s not very helpful, is it?  It requires a lot of knowledge to understand the output of dmesg and it’s usually used when the person running the system notes a problem.  When a system is restarted, the ring buffer is full of information about starting processes, so that can be useful then as well.

Syslog aka System Log

In the last post we talked about how syslog is the central method for logging messages.  It really saves us from having to search all over the system for logs and it also lets the developer log messages without writing their own way of doing it.

Now for the big question, what does syslog do with all those messages?

That’s a good question, we still don’t want to be searching for those messages on our Linux® system.

Looking for the Logs in all the wrong places

Looking for the Logs in all the wrong places

Luckily for us, syslog has a configuration file that tells us everything we need to know.  That file is often in /etc/syslog.conf, but depending on your system, it might be somewhere else.  Check the man page for syslogd (that’s the actual program that does the logging) and it will tell you where the file is.  No matter where it’s located, it bas the same purpose.  To tell you where messages are put, based on the priority or the facility.

We know what the priority is, we saw that last time.  What’s the facility?  That’s the purpose of the program making the log message.  For example, if e-mail is logging, then the facility is mail.  If the Linux® kernel is logging, then the facility is kernel.

We know that emerg messages are ‘OH NO THE SYSTEM IS GOING DOWN’, so we probably want to see those on the screen, not shoved away to a log file.    The configuration that does that looks like:

*.emerg							/dev/console

What about mail messages?  Those we would like to put in a file.  It ‘s standard on most Linux® systems to put log messages in /var/log/.  So we’ll put all our messages from the mail system in one place.

mail.*                      /var/log/mail

You can get really complex with the configurations, you want to put mail.debug in one place, mail.alert somewhere else, then you can also put duplicates of everything in a third.  Or you can just stick them all in one place.  The person running the system usually decides this and often the decision is made to leave the defaults alone.  What are the defaults?  Those are the configurations that the system has when everything is first installed.

 

Logging

I bet every time Iron Man does something in his suit, Jarvis makes a note of it.  ‘Shot a Chitauri out of the ski’, ‘did a flip’, ‘took Pepper on a flight’.  That way if something goes wrong, there’s a record of it.  In the computing world, this is called logging.

Making a note every time a computer does something interesting is a good thing.  If something breaks, you have notes that will hopefully let you figure out what happened.  If every program on your computer logged differently, that would be a nightmare, especially if they all put their logs in different places.  Troubleshooting would not be fun.

Instead, Linux® has a program that will do the logging for you.  You just tell syslog what you want to log and how important it is.  Then the syslog daemon will take care of everything for you.   The importance of a message, also known as the priority, has several defined meanings.

From the syslog man page, we can see the list:

  • LOG_EMERG system is unusable
  • LOG_ALERT action must be taken immediately
  • LOG_CRIT critical conditions
  • LOG_ERR error conditions
  • LOG_WARNING warning conditions
  • LOG_NOTICE normal, but significant, condition
  • LOG_INFO informational message
  • LOG_DEBUG debug-level message

A message logged with the level LOG_EMERG means ‘Danger!  Eek!  Fix me now!’ or ‘It’s too late, we’re going down Iron Man!’.  It can happen when the hard drive decides to fail dramatically.  The syslog can scream ‘Dead Hard drive ahead!’ then fall over dead.

That’s not exactly what happens, but it sounds fun!  My computer yelling ‘Dead Hard drive ahead!’ would certainly get my attention.

On the other end of the list is the LOG_DEBUG message.  Debug messages are usually used by developers, that is, the people who make the programs that run on your system.  The developers use them to debug, that is, find the bugs in their code.  These aren’t literal bugs, of course, but rather things that are unexpectedly happening that shouldn’t be.

Actual bug not found in computer

Actual bug not found in computer

Next time we’ll talk more about logging and syslog.