udp.sendmsg

udp.sendmsg

[webman]

Hi !

Not sure, if this is a developer list or something I can ask
about some unexpected behavior of Systemtap.

I am using Systemtap 2.6/0.159 on debian 8.5 with kernel
3.16.0-4.

My script does not produce any errors, but it definitively
does not catch all packets! The core is just this:

probe udp.sendmsg {
  if ( dport == 53 ) {
    printf ("PID %5d (%s) sent UDP to %15s 53\n", pid(), execname(), daddr)
  }
}

This should provide me with all processes which make DNS calls (per UDP).

This is similar to examples on the examples site. What I see are packets
bei user applications like iceweasel and thought, everything ok. Wrong.
Then I took nslookup and it's call was NOT to see. I fired up a tcpdump for
dst port 53 and this show the nslookup's outgoing call. There is plenty
of memory free (usually about 8 GB) und loadavg is below 0.5
Additionally, outgoing calls from LXC containers are not seen - but they
dont use remote tunneled ports, they use the local bridges. tcpdump
shows these packets too.

It not easy to provide a complete environment, but to note, that there
is additionally to regard:
- a mix of total 10 network interfaces on the box
- 3 x eth'xx (physical) in use
- OpenVswitch, which provides two bridges with ports to a total of that 10.
- the server uses port bonding under control of OpenVswitch

I found something similar in a serverfault.com discussion

(http://serverfault.com/questions/192893/how-i-can-identify-which-process-is
-making-udp-traffic-on-linux )

which is:

# stap -e 'probe netfilter.ip.local_out {
  if (dport == 53) # or parametrize
      printf("%s[%d] %s:%d\n", execname(), pid(), daddr, dport)
}'

Same problem.
Ther are no extra net namespaces in use!
Any hints, thoughts or pointers are welcome.

Best regards,
Manfred

Re: udp.sendmsg

[Timo Juhani Lindfors]

<webman@manfbraun.de> writes:
> probe udp.sendmsg {
>   if ( dport == 53 ) {
>     printf ("PID %5d (%s) sent UDP to %15s 53\n", pid(), execname(), daddr)
>   }
> }

On my system I see the call but dport == 0. Note that nslookup uses the
write syscall to send the data. If you want to simulate how programs
normally make DNS queries you should e.g. "getent hosts
www.google.com". That will use the sendto syscall and seems to help
systemtap get the port right.

$ nslookup www.google.com

PID 29910 (nslookup) sent UDP to         0.0.0.0 0
 0xffffffff81481770 : udp_sendmsg+0x0/0x910 [kernel]
 0xffffffff81405fbb : sock_sendmsg+0x8b/0xc0 [kernel]
 0xffffffff81406776 : ___sys_sendmsg+0x376/0x390 [kernel]
 0xffffffff81406e1e : __sys_sendmsg+0x3e/0x80 [kernel]
 0xffffffff8151420d : system_call_fast_compare_end+0x10/0x15 [kernel]

$ getent hosts www.google.com

PID 29905 (getent) sent UDP to [REDACTED] 53
 0xffffffff81481770 : udp_sendmsg+0x0/0x910 [kernel]
 0xffffffff81405fbb : sock_sendmsg+0x8b/0xc0 [kernel]
 0xffffffff81406121 : SYSC_sendto+0xf1/0x180 [kernel]
 0xffffffff8151420d : system_call_fast_compare_end+0x10/0x15 [kernel]

Re: udp.sendmsg

[Frank Ch. Eigler]

<webman@manfbraun.de> writes:

> [...]
> probe udp.sendmsg {
>   if ( dport == 53 ) {
> [...]
> This should provide me with all processes which make DNS calls (per UDP).

Yeah.  This should be more reliable.  Sometimes, the port number data
is not available to systemtap due to debuginfo quality or related
problems.  Once we solve https://sourceware.org/bugzilla/show_bug.cgi?id=19753
(redirect udp.* probes to netfilter.* probes), it should become reliable.

> # stap -e 'probe netfilter.ip.local_out {
>   if (dport == 53) # or parametrize
> [...]
> Same problem.

That part should be working.  Are you getting probe hits (e.g.,
counted via stap -t ...), just wrong dport values, for the dns
traffic?


- FChE

RE: udp.sendmsg

[webman]

Hi !

Thanks for reply - any sorry for my late answer. The mail lands
unexpectedly in my spam folder ...

In the meantime I build a little better usable script.
But something changed my Systemtap (no idea in mind).
The system tap script now failing after some time,
but was running for weeks without any problems. The
error is:

UDP53 1471300316.1471300316458  192.168.26.254 6071(iceweasel/DNS Res~ver
#60) 1(systemd)
ERROR: kernel string copy fault at 0x00000000000004f0 [man error::fault]
near identifier 'kernel_string' at
/usr/share/systemtap/tapset/linux/conversions.stp:18:10
WARNING: Number of errors: 1, skipped probes: 1
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed.  [man error::pass5]

May be, I am deeping into too much details, whithout
the right knowledge .... no time ...

I gave up with tracking port53 access - too difficult.
I'll house all webbrowsers now inside a LXC VM where
each has its own dns-proxy, which blocks, what I want.
All my other machines are generally blocked for dns.
I had to lern, that control over such things is the
same bad level like in windows.

Even my thougths were really incomplete: If I know, that,
say firefoy, made the request xyz, I do not know, from
wich tab or page. The only way to get control is to use
a browser plugin ... Ok, the other reason for my script
was to see, who makes dns calls at all - this part is
ok and I saw the "DNS Res~er #205" which must be some
system tool, but nothing about it to configure.

Thanks anyway,
Manfred



> -----Original Message-----
> From: Frank Ch. Eigler [mailto:fche@redhat.com]
> Sent: Tuesday, July 19, 2016 4:42 PM
> To: webman@manfbraun.de
> Cc: systemtap@sourceware.org
> Subject: Re: udp.sendmsg
> 
> <webman@manfbraun.de> writes:
> 
> > [...]
> > probe udp.sendmsg {
> >   if ( dport == 53 ) {
> > [...]
> > This should provide me with all processes which make DNS calls (per
> UDP).
> 
> Yeah.  This should be more reliable.  Sometimes, the port number data
> is not available to systemtap due to debuginfo quality or related
> problems.  Once we solve
> https://sourceware.org/bugzilla/show_bug.cgi?id=19753
> (redirect udp.* probes to netfilter.* probes), it should become reliable.
> 
> > # stap -e 'probe netfilter.ip.local_out {
> >   if (dport == 53) # or parametrize
> > [...]
> > Same problem.
> 
> That part should be working.  Are you getting probe hits (e.g.,
> counted via stap -t ...), just wrong dport values, for the dns
> traffic?
> 
> 
> - FChE

Re: udp.sendmsg

[David Smith]

On 08/18/2016 09:17 PM, webman@manfbraun.de wrote:
> Hi !
> 
> Thanks for reply - any sorry for my late answer. The mail lands
> unexpectedly in my spam folder ...
> 
> In the meantime I build a little better usable script.
> But something changed my Systemtap (no idea in mind).
> The system tap script now failing after some time,
> but was running for weeks without any problems. The
> error is:
> 
> UDP53 1471300316.1471300316458  192.168.26.254 6071(iceweasel/DNS Res~ver
> #60) 1(systemd)
> ERROR: kernel string copy fault at 0x00000000000004f0 [man error::fault]
> near identifier 'kernel_string' at
> /usr/share/systemtap/tapset/linux/conversions.stp:18:10
> WARNING: Number of errors: 1, skipped probes: 1
> WARNING: /usr/bin/staprun exited with status: 1
> Pass 5: run failed.  [man error::pass5]

Systemtap is trying to protect you here from reading a bad address and
potentially crashing the kernel.

Can you show us your current script so we can try to help you get around
this?

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

RE: udp.sendmsg

[webman]

Hello !

Many thanks for your answer!
Sometimes, writing "it's not working" reactivates some areas
in the own brain, do dig deeper ...
What ist failing for me, is my modified version of the original
script. I run the original and no errors at all ... ;-)

So, here is MY version - with my little newbies thinking about
this type of scripts ;-)

=======================
probe begin { printf("Monitoring use of port 53\n") }
probe end { printf("Stopped.\n") }

probe udp.sendmsg {
        if ( dport == 53 ) {
                task = pid2task(pid());
                printf(
                        "UDP53 %5d.%6d %15s %d(%s/%s) %d(%s)\n",
                        gettimeofday_s(),
                        gettimeofday_ms(),
                        daddr,
                        pid(),
                        task_execname(task),
                        execname(),
                        ppid(),
                        pexecname()
                        )
        }
}
============================
I came to this modified version, because I found out,
that there are some other programs attempt to get
mDNS resolution via port 5353 (not shown above).

So I made this above, to get more context information.
A hint would be great!

Thanks so far and
best regards,
Manfred


> -----Original Message-----
> From: David Smith [mailto:dsmith@redhat.com]
> Sent: Friday, August 19, 2016 6:32 PM
> To: webman@manfbraun.de; 'Frank Ch. Eigler'
> Cc: systemtap@sourceware.org
> Subject: Re: udp.sendmsg
> 
> On 08/18/2016 09:17 PM, webman@manfbraun.de wrote:
> > Hi !
> >
> > Thanks for reply - any sorry for my late answer. The mail lands
> > unexpectedly in my spam folder ...
> >
> > In the meantime I build a little better usable script.
> > But something changed my Systemtap (no idea in mind).
> > The system tap script now failing after some time,
> > but was running for weeks without any problems. The
> > error is:
> >
> > UDP53 1471300316.1471300316458  192.168.26.254 6071(iceweasel/DNS
> Res~ver
> > #60) 1(systemd)
> > ERROR: kernel string copy fault at 0x00000000000004f0 [man error::fault]
> > near identifier 'kernel_string' at
> > /usr/share/systemtap/tapset/linux/conversions.stp:18:10
> > WARNING: Number of errors: 1, skipped probes: 1
> > WARNING: /usr/bin/staprun exited with status: 1
> > Pass 5: run failed.  [man error::pass5]
> 
> Systemtap is trying to protect you here from reading a bad address and
> potentially crashing the kernel.
> 
> Can you show us your current script so we can try to help you get around
> this?
> 
> --
> David Smith
> dsmith@redhat.com
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)

Re: udp.sendmsg

[David Smith]

On 08/25/2016 11:18 AM, webman@manfbraun.de wrote:
> Hello !
> 
> Many thanks for your answer!
> Sometimes, writing "it's not working" reactivates some areas
> in the own brain, do dig deeper ...
> What ist failing for me, is my modified version of the original
> script. I run the original and no errors at all ... ;-)
> 
> So, here is MY version - with my little newbies thinking about
> this type of scripts ;-)
> 
> =======================
> probe begin { printf("Monitoring use of port 53\n") }
> probe end { printf("Stopped.\n") }
> 
> probe udp.sendmsg {
>         if ( dport == 53 ) {
>                 task = pid2task(pid());
>                 printf(
>                         "UDP53 %5d.%6d %15s %d(%s/%s) %d(%s)\n",
>                         gettimeofday_s(),
>                         gettimeofday_ms(),
>                         daddr,
>                         pid(),
>                         task_execname(task),
>                         execname(),
>                         ppid(),
>                         pexecname()
>                         )
>         }
> }

OK, here's a couple of things about your script.

  task = pid2task(pid())

is the same thing as:

  task = task_current()

Plus, since task is the current task, task_execname(task) and execname()
are always going to return the same string.

So, at that point you really don't need your 'task' variable.

If you are still getting that kernel_string copy fault error, you'll
need to delete/replace one function call at a time so that we can narrow
down which function is causing the fault.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: udp.sendmsg

[Frank Ch. Eigler]

Hi -

dsmith wrote:

> [...]
> If you are still getting that kernel_string copy fault error, you'll
> need to delete/replace one function call at a time so that we can narrow
> down which function is causing the fault.

... or invoke stap with --skip-badvars

- FChE

RE: udp.sendmsg

[webman]

Hello !

Thanks for this good information!
I just removed this code snippet and only use "execname()"
and the error went away!

I am new to Linux and it is really very hard for me ;-)
But I was able to use SystemTap to track some Virtualbox
calls, just to show them, what brings to whole server
to stop (!!) - but they are not interested .... and now,
I am trying to avoid Virtualbox like the devil the
holy water ;-)

So, this is the same machine and was my new delay ....

Best regards,
Manfred

BTW: I am of that type, that will not use "--skip-badvars",
at least, in a permanent running script ;-)

> -----Original Message-----
> From: systemtap-owner@sourceware.org [mailto:systemtap-
> owner@sourceware.org] On Behalf Of David Smith
> Sent: Thursday, August 25, 2016 9:52 PM
> To: webman@manfbraun.de; 'Frank Ch. Eigler'
> Cc: systemtap@sourceware.org
> Subject: Re: udp.sendmsg
> 
> On 08/25/2016 11:18 AM, webman@manfbraun.de wrote:
> > Hello !
> >
> > Many thanks for your answer!
> > Sometimes, writing "it's not working" reactivates some areas
> > in the own brain, do dig deeper ...
> > What ist failing for me, is my modified version of the original
> > script. I run the original and no errors at all ... ;-)
> >
> > So, here is MY version - with my little newbies thinking about
> > this type of scripts ;-)
> >
> > =======================
> > probe begin { printf("Monitoring use of port 53\n") }
> > probe end { printf("Stopped.\n") }
> >
> > probe udp.sendmsg {
> >         if ( dport == 53 ) {
> >                 task = pid2task(pid());
> >                 printf(
> >                         "UDP53 %5d.%6d %15s %d(%s/%s) %d(%s)\n",
> >                         gettimeofday_s(),
> >                         gettimeofday_ms(),
> >                         daddr,
> >                         pid(),
> >                         task_execname(task),
> >                         execname(),
> >                         ppid(),
> >                         pexecname()
> >                         )
> >         }
> > }
> 
> OK, here's a couple of things about your script.
> 
>   task = pid2task(pid())
> 
> is the same thing as:
> 
>   task = task_current()
> 
> Plus, since task is the current task, task_execname(task) and execname()
> are always going to return the same string.
> 
> So, at that point you really don't need your 'task' variable.
> 
> If you are still getting that kernel_string copy fault error, you'll
> need to delete/replace one function call at a time so that we can narrow
> down which function is causing the fault.
> 
> --
> David Smith
> dsmith@redhat.com
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)