[smokeping-users] TCPPing probe doesn't generate data

[G.W. Haywood]

Hi there,

On Tue, 17 Jun 2008, David Tomic wrote:

> G.W. Haywood wrote:
> > <snip>
> > Here's the debug output in /var/log/messages from probes to a couple
> > of machines on my LAN:
> >
> > 8<----------------------------------------------------------------------
> > Jun 17 08:57:33 tornado smokeping[28713]: TCPPing: TCPPing.pm: pingone: Got output: 'pk2.local.jubileegroup.co.uk : 0.140 0.182 0.182'
> > Jun 17 08:57:33 tornado smokeping[27472]: TCPPing: pk2.local.jubileegroup.co.uk: got 1.4000000000e-04 1.8200000000e-04 1.8200000000e-04
> > Jun 17 08:57:33 tornado smokeping[28712]: TCPPing: TCPPing.pm: pingone: Got output: '192.168.0.252 : 5.722 8.353 5.410'
> > Jun 17 08:57:33 tornado smokeping[27472]: TCPPing: 192.168.0.252: got 5.4100000000e-03 5.7220000000e-03 8.3530000000e-03
> > 8<----------------------------------------------------------------------
>
> Right ... here's what I've done then.
>
> 1. Edited/saved TCPPing.pm as above [adding the debug line].
>
> 2. Killed speedy_backend.

That's only necessary for changes to the cgi scripts, but it can't hurt.


> 3. Restarted smokeping. [I know that shouldn't be necessary

Actually I think that might be necessary but I haven't checked.
Again, it can't hurt and as you say it marks the log well.


> 4. Run smokeping --debug
>
> Now ... this is where it gets a little bit weird.
>
> I'm still not seeing anything from the TCPPing probe in
> /var/log/messages ... but I *DO* see it in the smokeping debug screen,

Hmmmm.  Well at least you're seeing it. :)  Logging is a subject all to
itself, but basically you can send log messages wherever you like, based
on criteria such as how important you think it is that anyone sees them.
You can make log messages go through syslog (or syslog-ng), which decides
what to do with them (it can decide to write them to a file, to send them
to another process, which can be on a remote machine, or throw them away)
or you can have the process which created the messages write them itself
directly to a file.  Sometimes it can be confusing and tedious trying to
find out where your log messages went.  Producers of the many and various
distributions of Linux all seem to do it that little bit differently from
each other for no doubt very good reasons.  Welcome to the world of *nix.
This is one reason why I tend to write something like "print STDERR ..."
instead of relying on whatever logging setup happens to be in place.  It
can remove a bit of uncertainty in an unfamiliar environment.

> 8<----------------------------------------------------------------------
> TCPPing: TCPPing.pm: pingone: Got output: ' 23.089 23.167 23.379 22.508 22.495'
> TCPPing: 203.16.214.17: got
> TCPPing: TCPPing.pm: pingone: Got output: ' 24.218 24.580 21.799 23.696 24.042'
> TCPPing: internode.on.net: got
> 8<----------------------------------------------------------------------
>
> So ... where do we now stand after all of that then?

There's a bit I don't understand but I think we're getting somewhere. :)

The bit I don't understand is how you're getting the exact output that
you've posted here with the code that you seem to have.  There should
be a line that says "Got output:" followed by the IP address (or FQHN)
and some ping times.  The data in the line should be a bit like this,
which I took from the output in my logs that I posted an is copied in
this mail (above):

'pk2.local.jubileegroup.co.uk : 0.140 0.182 0.182'

Your lines seem to look like this:

' 23.089 23.167 23.379 22.508 22.495'

If there's no IP/hostname in the line I don't quite see how you're
getting a line "TCPPing: 203.16.214.17: got" for example because that
IP address should have been extracted from the line that was printed
immediately above it.  The line

       @times = split /\s+/;

separates the line stored in $_ at any spaces, and each part of the
line is then stored in an element of the Perl array @times.  Perl
data can appear as if by magic, and can disappear in the same way.
With my first line of data, the elements of the @times array would
then contain (one element per line):

pk2.local.jubileegroup.co.uk
:
0.140
0.182
0.182

In other words although the array is called '@times' its first two
elements are a fully-qualified hostname and a colon.  Then this line:

       my $ip = shift @times;

Shifts the IP off the top of the array, leaving the IP/hostname in the
scalar variable $ip and the array looking like this:

:
0.140
0.182
0.182

All we have to do is get rid of that colon, that's what this line does:

       next unless ':' eq shift @times; #drop the colon

However your lines don't seem to have a colon, and so are ignored -
the 'next' happens if the first element of the array is NOT a colon,
and when it happens, control jumps back to the start of the loop.

I think you must be using different smokeping code, and/or different
tools from those that I have.  You can either grab the latest tools
from the URLs mentioned on the Smokeping site, or tweak the code.

Here's another nasty hack, it might help verify the theory:

        chomp;
        $self->do_debug("TCPPing.pm: pingone: Got output: '$_'");
#       next unless /^\S+\s+:\s+[\d\.]/; #filter out error messages from tcpping
        @times = split /\s+/;
         my $ip = shift @times;
        $self->do_debug("TCPPing.pm: pingone: Parsed times: @times");
#       next unless ':' eq shift @times; #drop the colon

The line "next unless /^\S..." simply goes back to the top of the loop
if the string contained in $_ (which we printed in the previous line
if debugging is enabled) does *not* match the awesome-looking regex.
TCPPing seems to think these must be error messages which are to be
ignored.  I've commented out that line.  Then there's the line that
makes an array of strings by splitting up $_ at any spaces, we need
that line, and also the line which takes the IP/host from the first
element of the array.  I've added another debug line and commented
out the line which shifts the colon out of the array, because your
array doesn't seem to have one.

See what happens?

--

73,
Ged.