Tuesday, March 12, 2013

Episode #166: Ping A Little Log For Me

We've been away for a while because, frankly, we ran out of material. In the meantime we tried to come up with some new ideas and there have had a few requests, but sadly they were all redundant, became scripts, or both. We've been looking long and hard for Fu that works in this format, and we've finally found it!

Nathan Sweaney wrote in with a great idea! It isn't a script, it isn't redundant, and it is quite useful. Three of the four of the criteria that makes a great episode (the fourth being beer fetching or beer opening). To top it off Nathan wrote the CMD.EXE portion himself. Thanks Nathan!


Nathan Sweaney writes in:

Ping Network Monitor

Occasionally we have issues in the field where we think a customer's device is occasionally losing a connection, but we're not sure if, or when, or for how long. We need a log of when the connection is dropping so that we can compare to the customer's reports of issues. Sure there are fancy network monitoring tools that can help, but we're in a hurry with no budget.

In Linux this would be easy, but these are Windows boxen. So I hacked together the following one-liner for our techs to use in the field.

This command will ping an IP address once every second and when it doesn't get a response, it will log the time-stamp in a text file. Then we can compare those time-stamps to failure reports from the customer.

To use it, simply change the IP address near the beginning to whatever IP we need to monitor. Then open a command prompt, CD into the directory you want the log file created, and run the command.

C:\> cmd.exe /v:on /c "FOR /L %i in (1,0,2) do @ping -n 1 |
find "Request timed out">NUL && (echo !date! !time! >> PingFail.txt) &
ping -n 2>NUL"

So let's dissect this. It's mostly just a combination of examples Ed has mentioned in the past.

First, we're using the "cmd.exe /v:on /c" command to allow for delayed environment variable expansion. Ed has explained in the past why that lets us do flexible variable parsing. This command wraps everything else.

The next layer of our onion is an infinite "FOR /L" loop that Ed mentioned WAY back. We're counting from 1 to 2 in steps of 0 so that our command will continue running until we manually stop it.

Inside of our FOR loop is where we really get to the meat. We've basically got 4 steps:

1) First we see @ping -n 1 The @ symbol says to hide the echo of the command to the screen. The switch (-n 1) says to only ping the IP once. And of course is the address we want to ping.

2) Next we pipe the results of our ping into the FIND command and search for "Request timed out" to see if the ping failed. The last part of that >NUL says to dump the output from this command into NUL, because we don't really need to see it.

3) Now we get fancy. The && says to only run this command if the previous command succeeded. In other words, if our FIND command finds the text, which means our ping failed, then we run this command. And we've enclosed this command in parenthesis contain it as a single command. We need to use the "cmd.exe /v:on /c" command at the beginning to allow for delayed environment variable expansion; that way our time & date changes each iteration. So %date% and %time% becomes !date! and !time!.

And finally we're redirecting our output to a file called PingFail.txt. We use the >> operator append each new entry rather than overwrite with just >.

4) And finally we're on to the last step. As mentioned before, the & says to run the next command no matter what has already happened. This command simply pings localhost with (-n 2) which will give us a one-second delay. The first ping happens immediately, and the second ping happens after one second. This slows down our original ping back in step 1 which would otherwise fire off like a machine gun as fast as the FOR loop can go. Lastly, we're redirecting the output with >NUL because we don't care to see it.

WOW. I said it was convoluted. But it works, and it's rather simple to use.

Tim finds a letter in the mail slot:

Wow, it has been a while since we've dusted off the ol' kung fu for a blog post. I've missed it and I know Hal as too. In fact, he hasn't showered since our last episode. True story. This was his silent (but deadly) protest against our lack of ideas and usable suggestions. The Northwest can breathe a sigh of relief (in the now fresher air) now that we are back for this episode. I for one, missed the blog. Back to the Fu...

Nathan wrote in with his idea to log Ping failures. What a great idea for a quick and dirty network monitor. Thanks to CMD.EXE he's got a bit of funkyness to his command. Fortunately, we can be a little smoother with our approach.

PS C:\> for (;;) { Start-Sleep 2; ping -n 1 >$null; if(-not $?) { Get-Date -Format s | Tee-
Object mylog.txt -Append }}

We start off with an infinite loop using the For loop but without any loop control structures. Without these structures there is nothing to limit the loop, and it will run forever...it will be UNSTOPPABLE! MWAAAAAHAHAHAHAHA! <cough> <cough> Sorry about that, it's been a while.

Inside our infinite loop we sleep for a few seconds. We could do it at the end, but for some reason I get inconsistent results when I do that. I have no idea why, and I've tried troubleshooting it for hours. That's OK, a pre-command nap never killed anyone.

After our brief nap, we do the ping. The results are sent into the garbage can that is the $NULL variable. Following this command we check the error state of the previous command by checking the value of $?. This variable is True if the previous command ran without error, if there was an error the the command is False. The If Statement is used to branch our logic based on this value. If it is False, the ping failed, and we need to log the error.

Inside our branch we get the current date with Get-Date (duh!) and change the format to the sortable format. We could use any format, but the OCD part of me likes this format. The formatted date is piped into the Tee-Object command which will append the date to a file as well as output to our console.

Notice we used the For loop here instead of a While loop. I did this to save single character. We can save a few more characters by using this command using aliases, shortened parameter names, and a little magic in our For loop.

PS C:\> for (;;sleep 2) {ping -n 1 >$null; if(-not $?) { date -f s | tee mylog.txt -a }}

I moved the Start-Sleep (alias sleep) cmdlet inside the For loop control. The For loops looks like this:

for ( variable initialization; condition; variable update ) {
  Code to execute while the condition is true

The variable initialization is run once before our loop starts. The condition is checked every time through the loop to see if we should continue the loop. We have no variable we care to initialize, and we want the loop to run forever so we don't use a condition. The variable update piece is executed after each time through the loop, and this we can use. Instead of modifying a variable used in the loop, we take a lovely two second nap. This gives us our nice delay between each ping.

There you have the long awaited PowerShell version of this command. It is better than CMD.EXE, but there is no nice way to use the short-circuit operator && or || operators to make this command more efficient. Don't tell Hal, but I'm really jealous of the way his shell can be used to complete this task. I'm jealous of his terseness...and his full head of hair.

Hal washes clean

Let's be clear. The only thing that smells around here is the Windows shells. Have to use ping to put a sleep in your loop? Sleep that works at the start of the loop but not the end? What kind of Mickey Mouse operating system is that?

The Linux solution doesn't look a lot different from the Windows solutions:

while :; do ping -c 1 -W 1 >/dev/null || date; sleep 1; done

"while :; do ... done" is the most convenient way of doing an infinite loop in the shell. The ping command uses the "-c 1" option to only send a single ping and "-W 1" to only wait one second for the response. We send the ping output to /dev/null so that it doesn't clutter the output of our loop. Whenever the ping fails, it returns false and we end up running the date command on the right-hand side to output a timestamp. The last thing in the loop is a sleep for one second. And yes, Tim, it actually works at the end of the loop in my shell.

Well that was easy. Hmmm, I don't want to embarrass Nathan and Tim by making my part of the Episode too short. How about we make the output of the date command a little nicer:

while :; do ping -c 1 -W 1 >/dev/null || date '+%F %T'; sleep 1; done
"%F" is the "full" ANSI-style date format "2013-03-12" and "%T" is the time in 24-hour notation. So we get "2013-03-12 04:56:22" instead of the default "Tue Mar 12 04:56:22 EST 2013"

Oh, you want to save the output in a file as well as having it show up in your terminal window? No problemo:

while :; do ping -c 1 -W 1 >/dev/null || date; sleep 1; done | tee mylog.txt

Hooray for tee!

Well I can't tart this up any more to save Tim and Nathan's fragile egos. So I'm outta here to go find a shower.