February 12, 2008: Lot’s of Writing Today

Oreo made it all last evening and then all night without seemingly feeling ill at all. He was clearly very tired having missed one entire night of sleep and then having to go to daycare all day. This is going to be a really long week for him as he is going to have missed one night of sleep and will have a full five days of daycare. He is going to be in horrible shape by Thursday and on Friday we won’t even be able to get him to walk on his own. But he has President’s Day off with me on Monday so he will have three days to do some catching up on his sleep.

We all went to bed on the early side last night after relaxing most of the evening. We watched the first disc of the sixth season of The Cosby Show and then did a little reading before falling asleep. With Oreo feeling better I was able to sleep all night which I really needed. Yesterday was a really long day.

This morning I decided that going in early was a bad idea as things were slow and I needed to get enough sleep so that I could be actually useful in the office so I opted to go in at “normal time.” That means getting ready after Dominica instead of getting ready before her. Oreo also appreciates the company as he gets to stay in bed with me right up until he eats his breakfast and heads out the door.

I hit Airlie Cafe on the way into the office for some protein and apple juice. The air was brisk this morning but I was plenty warm having shaved my head this morning. Somehow that always keeps me warm. Too warm, in fact.

My day was quite busy. I had to spend a bit of the day explaining why Linux machines with tons of free memory were not actually out of memory. As you can see from my previous post I got tired of having to write the same explanation over and over again once a week so I finally just wrote a real article about it.

One of my colleagues is leaving to go work at another company in New York in a week so today some of us took him out for his farewell lunch just in case we don’t get another chance before he is done. We went to the Lemongrass which isn’t too far away. They do Thai cuisine and it was quite good. That really hit the spot. Crispy vegetarian rolls and vegetable pad Thai.

It was cold and wet as we walked over to the Lemongrass. The snow is really coming down now and there is a pretty good coating out there.

I stayed late at work today as the weather was really bad for driving and that way other people on the team would have a chance to get home without having to worry about the office. So I didn’t leave the office until seven. Dominica was already home for twenty minutes and had called to let me know that she had gotten home safely. Her drive was crappy but she only saw one car that had gone off the road so it looks as though there were no accidents on her commuting stretch which is amazing. She did say that my old route along Interstate 78 was backed up significantly. Boy am I glad that I commute on food these days. Especially in bad weather like this.

I managed to keep up on my homework before leaving so I am in good shape tonight even though I worked late.  It was a cold and wet walk home.  We were hoping that I would be able to pick up dinner from the Metro Cafe in the Gateway Center but when I got there it was almost eight and they close at seven.  So I walked almost all of the way home before I heard Garrison Keillor mention something about McDonald’s in the book “Pontoon” that I was listening to and suddenly I remembered that Dominica had said to get McDonald’s if the Metro Cafe was closed.  So I turned around and walked back to McDonald’s and picked up dinner.

I got home and picked up our latest Netflix rental from the mailbox.  Today we got Disney-Pixar’s latest film Meet the Robinsons.  We popped that in and ate our dinners in bed.  Meet the Robinsons was really good and we quite enjoyed it.  Not as good as The Invincibles which is my favourite of the Pixar movies.  But the storyline was really cute and well done.  And for once I was able to guess the plot long before Dominica did which never, ever, ever happens.

After our movie was just watched a little of The Cobsy Show and went off to sleep.  Oreo and I are still exhausted from Sunday night.

Linux Memory Monitoring

As a Linux System Administrator one question that I get asked quite often is to look into memory issues. The Linux memory model is rather more complex that many other systems and looking into memory utilization is not always as straightforward as one would hope, but this is for a good reason that will be apparently once we discuss it.

The Linux Virtual Memory System (or VM colloquially) is a complex beast and my objective here is to provide a practitioner’s overview and not to look at it from the standpoint of an architect.

The Linux VM handles all memory within Linux. Traditionally we think of memory as being either “in use” or “free” but this view is far too simplistic with modern virtual memory management systems (modern means since Digital Equipment Corporation produced VMS around 1975.) In a system like Linux memory is not simply either “in use” or “free” but can also be being used as buffer or cache space.

Memory buffers and memory cache are advanced virtual memory techniques used by Linux, and many other operating systems, to make the overall system perform better by making more efficient use of the memory subsystem. Memory space used as cache, for example, is not strictly “in use” in the traditional sense of the term as no userspace process is holding it open and that space, should it be requested by an application, would become available. It is used as cache because the VM believes that this memory will be used again before the space is needed and that it would be more efficient to keep that memory cached rather than to flush to disk and need to reload which is a very slow process.

On the other hand there are times when there is not enough true memory available in the system for everything that we want to have loaded to fit into at the same time. When this occurs the VM looks for the portions of memory that it believes are the least likely to be used or those that can be moved onto and off of disk most effectively and transfers these out to the swap space. Anytime that we have to use swap instead of real memory we are taking a performance hit but this is far more effective than having the system simply “run out of memory” and either crash or stop loading new processes. By using swap space the system is degrading gracefully under excessive load instead of failing completely. This is very important when we consider that heavy memory utilization might only last a few seconds or minutes when a spike of usage occurs.

In the recent past memory was traditionally an extreme bottleneck for most systems. Memory was expensive. Today most companies as well as most home users are able to afford memory far in excess of what their systems need on a daily basis. In the 1990s we would commonly install as little memory as we could get away with and expect the machine to swap constantly because disk space was cheap in comparison. But over time more and more people at home and all but the most backwards businesses have come to recognize the immense performance gains made by supply the computer with ample memory resources. Additionally, having plenty of memory means that your disks are not working as hard or as often leading to lower power consumption, higher reliability and lower costs for parts replacement.

Because systems often have so much memory resources today, instead of seeing system working to move less-needed memory areas out to disk we instead see the system looking for likely-to-be-used sections of disk and moving them into memory. This reversal has proved to be incredibly effective at speeding up our computing experiences but it has also been very confusing to many users who are not prepared to look so deeply into their memory subsystems.

Now that we have an overview of the basics behind the Linux VM (this has been a very simplistic overview hitting just the highlights of how the system works) lets look at what tools we have to discover how out VM is behaving at any given point in time. Our first and most basic tool, but probably the most useful, is “free”. The “free” command provides us with basic usage information about true memory as well as swap space also known as “virtual memory”. The most common flag to use with “free” is “-m” which displays memory in megabytes. You can also use “-b” for bytes, “-k” for kilobytes or “-g” for gigabytes.

# free -m
             total  used  free  shared  buffers  cached
Mem:          3945   967  2977       0       54     725
-/+ buffers/cache:   187  3757
Swap:         4094     0  4094

From this output we can gain a lot of insight into our Linux system. On the first line we can see that our server has 4GB of memory (Mem/Total). These numbers are not always absolutely accurate so rounding may be in order. The mem/used amount here is 967MB and mem/free is 2977MB or ~3GB. So, according to the top line of output, our system is using ~1GB out of a total of 4GB. But also on the first like we see that mem/buffers is 54MB and that mem/cached is 725MB. Those are significant amounts compared to our mem/used number.

In the second line we see the same output but without buffers and cache being added in to the used and free metrics. This is the line that we really want to pay attention to. Here we see the truth, that the total “used” memory – in the traditional use of the term – is only a mere 187MB and that actually have ~3.76GB free! Quite a different picture of our memory utilization.

According to these measurements, approximately 81% of all memory in use in our system is for performance enhancing buffer/cache and not for traditional uses and less than 25% of our total memory is even in use for that.

In the third line we see basic information about our swap space. In this particular case we can see that we have 4GB total and that none of it is in use at all. Very simple indeed.

When reading information about the swap space, keep in mind that if memory utilization spikes and some memory has to be “swapped out” that some of that data may not be needed for a very long time, even if memory utilization drops and swap is no longer needed. This means that some amount of your swap space may be “in use” even though the VM is not actively reading or writing to the swap space. So seeing that swap is “in use” is only an indication that further investigation may be warranted and does not provide any concrete information on its own. If you see that some of your swap is used but there is plenty of free memory in line two then your current situation is fine but you need to be aware that you memory utilization likely spiked in the recent past.

Often all you want to know is what the current “available” memory is on your Linux system. Here is a quick one liner that will provide you with this information. You can save it in a script called “avail” and place it in /usr/sbin and you can use it anytime you need to just see how much headroom your memory system has without touching the swap space. Just add “#!/bin/bash” at the top of your script and away you go.

echo $(free -m | grep 'buffers/' | awk '{print $4}') MB

This one liner is especially effective for non-administrator users to have at their disposal as it provides the information that they are usually looking for quickly and easily. This is generally preferred over giving extra information and having to explain how to decipher what is needed.

Moving on from “free” – not that we know the instantaneous state of our memory system we can look at more detailed information about the subsystem’s ongoing activities. The tool that we use for this is, very appropriately, named “vmstat”.

“vmstat” is most useful for investigating VM utilization when swap space is in use to some degree. This is where “vmstat” becomes particularly useful. When running “vmstat” we generally want to pass it a few basic parameters to get the most useful output from it. If you run the command without any options you will get some basic statistics collected since the time that the system was last rebooted. Interesting but not what we are looking for in particular. The real power of “vmstat” lies in its ability to output several instances (count) of activity over a period (delay.) We will see this in our example.

I prefer to use “-n” which suppresses header reprints. Do a few large “vmstat”s and you will know what I mean. I also like to translate everything to megabytes which we do with “-S M” on some systems and “-m” on others. To make “vmstat” output more than a single line of output we need to feed it a count and a delay. A good starting point is 10 and 5. This will take 40 seconds to complete ( count-1 * delay ). I always like to run “free” just before my “vmstat” just so that I have all of the information on my screen at one time. Let’s take a look at a memory intensive server.

free -m
             total     used      free    shared   buffers    cached
Mem:         64207    64151        56         0        73     24313
-/+ buffers/cache:    39763     24444
Swap:        32767        2     32765
vmstat -n -S M 10 5
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
 7  1      2     53     75  24313    0    0  8058    62   19     1 10  7 71 12
 2  2      2     44     74  24325    0    0 103251   209 2512 20476 15 13 54 18
 3  1      2     43     74  24325    0    0 105376   216 2155 16790 11 12 59 17
 2  1      2     50     74  24320    0    0 107762   553 2205 16819 12 10 60 17
 2  2      2     49     73  24322    0    0 105104   302 2323 18009 23  9 51 17

That is a lot of data. From the “free” command we see that we are dealing with a machine with 64GB of memory that has almost 40GB of that in use and 24GB of it being used for cache. A busy machine with a lot of memory but definitely not out of memory.

The “vmstat” output is rather complex and we will break it down into sections. Notice that the stats in the very first row are significantly different from the stats in the subsequent rows. This is because the first row is average stats since the box last rebooted. And each subsequent row is stats over the last delay period which, in this case, is ten seconds.

The first section is “procs”. In this section we have “r” and “b”. “R” is for runnable processes – that is, processes waiting for their turn to execute in the CPU. “B” is for blocked processes – those that are in uninterruptible sleep. This is process, not memory, data.

The next section is “memory” and this provides the same information that we can get from the free command. “Swpd” is the same as swap/used in “free”. “Free” is the same as mem/free. “Buff” is the same as mem/buffers and “cache” is the same as mem/cached. This view will help you see how the different levels are constantly in motion on a busy system.

If you system is being worked very hard them the real interesting stuff starts to come in the “swap” section. Under “swap” we have “si” for swap in and “so” for swap out. Swapping in means to move virtual memory off of disk and into real memory. Swapping out means to take real memory and to store it on disk. Seeing an occasional swap in or swap out event is not significant. What you should be interested in here is if there is a large amount of constant si/so events. If si/so is constantly quite busy then you have a system that is actively swapping. This does not mean that the box is overloaded but it does indicate that you need to be paying attention to your memory subsystem because it definitely could be overloaded. At the very least performance is beginning to degrade even if still gracefully and possibly imperceptibly.

Under “io” we see “bi” and “bo” which are blocks in and blocks out. This refers to total transfers through the systems block devices. This is to help you get a feel for how “busy” the i/o subsystem is in regards to memory, CPU and other statistics. This helps to paint an overall picture of system health and performance. But it is not directly memory related so be careful not to read the bi/bo numbers and attempt to make direct memory usage correlations.

The next section is “system” and has “in” for interrupts per second. The “in” number includes clock interrupts so even the most truly idle system will still have some interrupts. “Cs” is context switches per second. I will not go into details about interrupts and context switching at this time.

The final section is “cpu” which contains fairly standard user “us”, system “sy”, idle “id” and waiting on i/o “wa” numbers. These are percentage numbers that should add up to roughly 100 but will not always do so due to rounding. I will refrain from going into details about CPU utilization monitoring here. That is a separate topic entirely but it is important to be able to study memory, processor and i/o loads all in a single view which “vmstat” provides.

If you will be using a script to automate the collection of “vmstat” output you should use “tail” to trim off the header information and the first line of numerical output since that is cumulative since system reboot. It is the second numerical line that you are interested in if you will be collecting data. In this example one-liner we take a single snapshot of a fifteen second interval that could be used easily in a larger script.

vmstat 15 2 | tail -n1

This will provide just a single line of useful output for sending to a log, attaching to a bug report or for filing into a database.

Additional, deeper, memory information can be found from a few important sources. Firstly let’s look at “vmstat -s”. This is a very different use of this command.

vmstat -s
  32752428  total memory
  32108524  used memory
  13610016  active memory
  17805412  inactive memory
    643904  free memory
    152168  buffer memory
  23799404  swap cache
  25165812  total swap
       224  used swap
  25165588  free swap
   4464930 non-nice user cpu ticks
         4 nice user cpu ticks
   1967484 system cpu ticks
 193031159 idle cpu ticks
    308124 IO-wait cpu ticks
     37364 IRQ cpu ticks
    262095 softirq cpu ticks
  69340924 pages paged in
  86966611 pages paged out
        15 pages swapped in
        62 pages swapped out
 488064743 interrupts
  9370356 CPU context switches
1202605359 boot time
   1304028 forks

As you can see we get a lot of information from this “-s” summary option. Many of these numbers are static such as “total memory” and will not change on a running system. Others, such as “interrupts” is a counter that is used to generate the “since reboot” statistics for the regular “vmstat” options.

The “free” and “vmstat” commands draw their data from the /proc file system as you would expect. You can see their underlying information through:

cat /proc/meminfo
cat /proc/vmstat
cat /proc/slabinfo

Of course, no talk of Linux performance monitoring can be complete without mentioning the king of monitoring the “top” command. However, the memory information available from “top” is little more than we can see more concisely in “vmstat” and “free”. At the top of “top” we get the “free” summary is a slightly modified form but containing the same data. If this does not appear you can toggle it on and off with the “m” command. You can then sort top‘s listing with “M” to force it to sort processes by memory utilization instead of processor utilization. Very handy for finding memory hogging applications.

Armed with this information you should now be able to diagnose a running Linux system to determine how its memory is being used, when is it being used, how much is being used, how much headroom is available and when more memory should be added if necessary.

References:

Monitoring Virtual Memory with vmstat from Linux Journal
vmstat Man Page on Die.net
free Man Page on Die.net
/proc/meminfo from Red Hat

February 11, 2008: No Sleep

We were right that there was going to be no sleep last night.  We tried going to bed at eleven after having just walked Oreo three times in the last hour.  But he needed to go out again at midnight.  Then at one thirty.  Then at three and again at a little after four.  So I really didn’t get a chance to fall asleep at all during that time.  Constantly lying in bed awake knowing that he was going to need to go out any minute and that I didn’t want to risk not waking up as he would panic.  Each trip was an emergency.

Going out all night was awful.  Not only was it keeping me from sleeping but the weather was so cold and there was so much wind that Oreo kept having to get baths as the wind would blow everything all over him.  It was so awful for him.  And he won’t do his business unless we go all of the way down to the corner where there is mulch and ground cover.  So each trip takes twenty to thirty minutes in total with Oreo and I running all the way from the building to the corner and back.  So my heart is really racing by the time that we return and sleep is not easily achieved.

My longest stretch of “rest” was from four thirty until Dominica alarm went off a little before six.  Oreo was feeling a bit better by that point and had moved up to snuggle next to me more like he usually does.  He was sleeping in his t-shirt, hardness and sweater, though, since there wasn’t time to get him dressed before each run outside.  I know that I woke up to Min’s alarm and that I was awake when she left for work at seven.  At that point I got my BlackBerry and plugged it in so that I could keep up with the office. Dominica called shortly after she left to say that the wind chill was at negative eleven degrees.  So I was not about to walk to work.  Today was going to be rough enough as it was.

So, at best, I started the day with one to two hours of sleep.  We sent Oreo to daycare instead of staying home with me because we couldn’t keep having him go out into those horrible weather conditions and I would be unable to work at all with the frequency of his trips.  At daycare he will be warm and can use the facilities as often as he likes.

Daycare emailed Dominica around lunchtime to let her know that Oreo was playing and seemed to be feeling much better.  Hopefully he will be back to normal tonight.  We think that he just had a really bad tummy ache caused by eating dry food on Friday night.  He doesn’t seem to handle dry food very well.  His stomach is very sensitive.

I got some cleaning done today.  We weren’t able to get that far through everything over the weekend so it is helpful that I can clean today but it does mean that we have a four day stretch without me being home now which will be tough.

I did some bill paying today and cleaning out the clutter in the office area.  And I did some homework.  I was pretty productive today.

Oreo was doing pretty well at daycare until the middle of the afternoon when he got sick 🙁  He didn’t have any food in his system and that might have affected him.  He is definitely not feeling very well.

Daycare said that Oreo’s afternoon improved after he got some Immodium into his system and that he was in good shape by the time that he headed for home.  He was very hungry when he got his first meal of the day.

I ordered in Domino’s Pizza before Dominica got home so that she wouldn’t have to wait for dinner.  It arrived shortly after she got home.  We settled in to watch some season six of The Cosby Show that came today on DVD from Amazon.  We are all really tired.  We also got  Dragons of Autumn Twilight on DVD which we are very excited about but do not have the time or energy to watch tonight.

I did get a chance to read a bit in my new “Backup and Recovery” book that arrived today.  I have been waiting for this one and hope to be through it in a day or two.

February 10, 2008: Oreo Isn’t Feeling Well

Dominica decided that she was so close to finishing the entire first season of Dexter in a single sitting that she decided to just make a run for it and wrapped up around two in the morning.

Oreo got me up in the middle of the night, as expected, for a walk. This always happens anytime that he has dry food. Dry food doesn’t sit well on his tummy. So I walked him from three thirty until four in the morning. Then it was back to bed. But only until ten this morning when he needed to walk again. We really shouldn’t let him have dry food. It is no more fair to him to make him have to go outside in the cold in the middle of the night than it is to us. And he takes a risk of not being able to wake us up as well. Although I think that he is normally able to do that.

After walking him I started working on the workstation for CCA that I was working on last night. I also worked on changing our router to handle a large set of IP addresses as we have simply exhausted everything in the subnet that we had been using up until now. We had assigned ourselves just fourteen IP addresses and this was working fine until recently when we added the Netgear SC101 SAN device which uses, in our configuration, six IP addresses of its own. It was right around that time that we hooked back up our Cisco ATA unit that works with our Vonage phone system. That was another IP address permanently assigned and taken out of the pool. We went from plenty to being short more or less overnight. So now we have thirty and anticipate that this will hold us for a while. Although the list of machines in the house that use IP addresses isn’t short – the desktops and laptops include the OLPC, the Wii and the AppleTV, the SC101 (6), the three IP phones, the firewall, etc. It is no wonder the world is running out of IP space. Luckily these are all on a private address scheme or we would have real problems.

I joined Linked In today. So anyone looking for me on there, look again. There I am.

Rochester suffered a thirty-six car pile-up by the Rochester International Airport tonight. The region was hit by white-out conditions and wind speeds in the high forty miles per hour range.

Oreo is feeling pretty sick today and has needed to go outside much more often than usual.  We were really lucky that he decided that he needed to take a walk while it was bright and sunny and relatively warm.  Right after we got back from working him it turned into crazy winds and total white out conditions.  He didn’t need to go back out again until after that had stopped.  But for the rest of the evening he had to go out about every twenty to thirty minutes and it was bitterly cold.  We ended up just leaving his harness and sweater on so that we could take him out more quickly.

The Spice Girls, for those few of you who can remember who they are, played the Prudential Center tonight.  What a cold night to go out to a concert.  Later in the evening when I was walking Oreo one time I noticed a small group of women pounding on the doors of Catholic Health Care’s car garage which is used heavily for these events.  The show, Dominica thought, ran late tonight and I am guessing that these were stragglers who were now locked out of the garage because the garage closes early and were in insanely cold temperatures – most likely drunk – trying to figure out how to get their car.  They definitely were not getting into their car tonight.  One of the issues with concerts in Newark – if they run late you have few options.  All of the garages close early.  Even the ones, like that one, that cater to the late night events.

We went to bed at eleven after Oreo’s last “late night” walk.  We are assuming that there is going to be little to no sleep tonight as he has been going out far too frequently.  We tried watching a little of the new Doctor Who series from 2005 via Netflix online download service.  The show was pretty good and the Netflix service works really well.  No technical problems at all once we got the player installed.  We only managed to watch two episodes, though, with Oreo needing to go out so frequently.  We are going to be loving this Netflix service though.  That is so cheap and handy.  Netflix is definitely the “cable killer” with unlimited “on demand”, over the Internet viewing for just a tiny fraction of the cost of cable.  And no commercials either!  They are really demonstrating just how much money their is in the cable system.

February 9, 2008: Working All Day

Oreo was “featured” in an episode of 60 SecondsSee if you can spot him.

I woke up early this morning. At a quarter after five I woke up and found myself not to be sleepy at all. I tried going back to sleep but had to luck. So I got up at five thirty and got started on the day. I did a little reading and a little writing. I hopped onto the office network since I had work coming up at eight in the morning. One of the advantages of working my weekends with people in Bahrain is that we are often able to start early as long as I am awake. Today we were able to start at just a quarter after seven which worked out perfectly.

Dominica got up at eight thirty which was very surprising for a weekend day. This is a good sign that she won’t be exhausted all week. Her shifting weekend sleep hours are really tough for her to make up for in a week of sleep. She watched License to Wed while I was working. Oreo was sleepy and didn’t want to get out of bed so they just snuggled in for a while.

I finished reading Simon Winchester’s “Outposts”. It is a fascinating look at the remaining British Crown Colonies as visited by Winchester in the 1980s. It seldom that we, as Americans, think about far flung British possessions such as Saint Helena, Pit Cairn Island, Ascension or others. And yet there are populations there, cultures and history.

Breakfast for me this morning was coffee and pop tarts. Doesn’t get much better than that. After her movie Dominica went on to watch the television show Dexter that she picked up for herself on DVD. I have seen one episode of it and it was okay but I am not into murder, serial killer, gross-out shows. Even light hearted ones, if such a thing exists. I am really tired of entertainment involving unhappy subjects. That really is not entertaining. I have no idea why people enjoy that. It isn’t like a thriller. At least a thriller is suspenseful and “scary”.

It was a busy morning for work with Bahrain. I was expecting the usual one hour of work but we started early and they ended up needing me for support into late in the afternoon. I ended up working more than eight hours!

I took the ASP.NET 2.0 Brainbench exam today scoring a Masters and ranking at number five in New Jersey and tying for thirty-fifth in the nation. I then took the older ASP.NET exam based on version 1.0 and also scored a Masters tying for ninth in New Jersey.  My final test for the day was the ASP.NET Fundamentals exam.  I know have all of the ASP.NET tests done and out of the way.

Dominica decided that it was a lazy day and she spent the entire day in bed with Oreo watching DVDs.  Oreo loved it.  It is often that he gets to spend the entire day actually in bed.

I listened to some IT Conversations tonight – Bill Buxton from Microsoft and Jon Udell talking about “Sketching User Experience“.

My evening project was working on an OpenSUSE 10.3 32bit AMD workstation (HP d325) for Castile Christian Academy.  While I worked on that I started listening to Garrison Keillor’s latest book “Pontoon“.

I ended up working until after one in the morning.  Dominica watched almost the entire first season of Dexter in, more or less, a single sitting.  Only two more episodes to go to save for tomorrow.