[Bug server/20557] New: It seems like that switching output file doesn't work.

[Bug server/20557] New: It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

            Bug ID: 20557
           Summary: It seems like that switching output file doesn't work.
           Product: systemtap
           Version: unspecified
            Status: UNCONFIRMED
          Severity: normal
          Priority: P2
         Component: server
          Assignee: systemtap at sourceware dot org
          Reporter: steve.tsai at nexusguard dot com
  Target Milestone: ---

I tried the following command.

stap -F -o tcpdump.log -S 1,2 tcp_dumplike.stp

I got a several GB log file "tcpdump.log.0". It didn't output 2 1MB size file.
My tcp_dumplike.stp script:
-----------------------------------
#! /usr/bin/env stap
// A TCP dump like example
probe begin, timer.s(1)
{
 ansi_clear_screen ()

 printf("-----------------------------------------------------------------\n")
 printf(" Source IP Dest IP SPort DPort U A P R S F \n")
 printf("-----------------------------------------------------------------\n")
}

probe udp.recvmsg /* ,udp.sendmsg */
{
  printf(" %15s %15s %5d %5d UDP\n", saddr, daddr, sport, dport)
}

probe tcp.receive
{
  printf(" %15s %15s %5d %5d %d %d %d %d %d %d\n", saddr, daddr, sport, dport,
urg, ack, psh, rst, syn, fin)
}
-----------------------------------------------

I don't want to run out of my disk.

thank you in advance.
Steve

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #1 from SteveTsai <steve.tsai at nexusguard dot com> ---
The result is the same without F option.

stap -o tcpdump.log -S 1,2 tcp_dumplike.stp

It output only one file.

Steve

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

David Smith <dsmith at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |dsmith at redhat dot com

--- Comment #2 from David Smith <dsmith at redhat dot com> ---
This certainly works for me (and testsuite/systemtap.base/flightrec2.exp tries
to test this behavior).

What version of systemtap are you running (i.e. what's the output of 'stap
-V')? What architecture and OS are you using?

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #3 from David Smith <dsmith at redhat dot com> ---
Just to be clear, here is how this is supposed to work:

1) Run 'stap -F ...'. Systemtap will run in the background, outputting data
files. It prints the pid of the background stap process.

# stap -F -o f.out -S 1,3 ../src/testsuite/systemtap.base/flightrec2.stp 
31067

2) System will output up to 3 (in my case) files of around 1 megabyte each. As
soon as the 4th file would be written, it deletes the earliest file.

After waiting a while, I see:

# ls -l f.out*
-rw-rw-r--. 1 dsmith dsmith 1034000 Sep  6 13:33 f.out.71
-rw-rw-r--. 1 dsmith dsmith 1034000 Sep  6 13:33 f.out.72
-rw-rw-r--. 1 dsmith dsmith  517000 Sep  6 13:33 f.out.73

then later:

# ls -l f.out*
-rw-rw-r--. 1 dsmith dsmith 1034000 Sep  6 13:35 f.out.175
-rw-rw-r--. 1 dsmith dsmith 1034000 Sep  6 13:35 f.out.176
-rw-rw-r--. 1 dsmith dsmith  770000 Sep  6  2016 f.out.177

3) To stop systemtap, kill the pid output earlier.

# kill 31067

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #4 from David Smith <dsmith at redhat dot com> ---
I tried your script and systemtap started putting data into the first file,
then stopped. I then realized it wasn't running any more.

When running it without the -F, -o, or -S options, I saw an error in reading
kernel data. After some more investigation, I see that the kernel code behind
skb_network_header() has changed and we'll need to update our __get_skb_iphdr()
tapset function.

Can you try running your script without the -F, -o, or -S options and see what
happens for you?

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #5 from SteveTsai <steve.tsai at nexusguard dot com> ---
Thank you, David.

My platform is Ubuntu 14.04 LTS. It's a VM instance from Google cloud platform.

I run my script successfully. It run several days. The size of log was up to
7GB. 

Without those options, it displayed the result on screen correctly, without any
error or warning.

Steve

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #6 from SteveTsai <steve.tsai at nexusguard dot com> ---
(In reply to SteveTsai from comment #5)

$stap -V
Systemtap translator/driver (version 3.0/0.167, non-git sources)
Copyright (C) 2005-2015 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: NLS TR1_UNORDERED_MAP

Steve

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #7 from SteveTsai <steve.tsai at nexusguard dot com> ---
(In reply to SteveTsai from comment #5)

$stap -V
Systemtap translator/driver (version 3.0/0.167, non-git sources)
Copyright (C) 2005-2015 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: NLS TR1_UNORDERED_MAP

Steve

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #8 from David Smith <dsmith at redhat dot com> ---
(In reply to David Smith from comment #4)
> I tried your script and systemtap started putting data into the first file,
> then stopped. I then realized it wasn't running any more.
> 
> When running it without the -F, -o, or -S options, I saw an error in reading
> kernel data. After some more investigation, I see that the kernel code
> behind skb_network_header() has changed and we'll need to update our
> __get_skb_iphdr() tapset function.

After some further investigation, the error would only happen on a 32-bit
architecture. So, you are probably OK there if you are on x86_64.

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #9 from David Smith <dsmith at redhat dot com> ---
(In reply to SteveTsai from comment #5)
> Thank you, David.
> 
> My platform is Ubuntu 14.04 LTS. It's a VM instance from Google cloud
> platform.
> 
> I run my script successfully. It run several days. The size of log was up to
> 7GB. 
> 
> Without those options, it displayed the result on screen correctly, without
> any error or warning.

Let's try something simple and get the udp and tcp tapsets out of the picture.
Try the following (which is what flightrec2.exp runs):

# stap -F -o f.out -S 1,3 -e 'probe timer.ms(10) { for (j = 0; j < 1000; j++)
printf("1234567890\n") }'

If that just creates 1 big file instead of 3 little ones that rotate, we'll
have to go deeper.

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #10 from SteveTsai <steve.tsai at nexusguard dot com> ---
Steve(In reply to David Smith from comment #9)
> 
> Let's try something simple and get the udp and tcp tapsets out of the
> picture. Try the following (which is what flightrec2.exp runs):
> 
> # stap -F -o f.out -S 1,3 -e 'probe timer.ms(10) { for (j = 0; j < 1000;
> j++) printf("1234567890\n") }'
> 
> If that just creates 1 big file instead of 3 little ones that rotate, we'll
> have to go deeper.

# uname -a
Linux steve-systemtap 4.4.0-34-generic #53~14.04.1-Ubuntu SMP Wed Jul 27
16:56:40 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

I tried your example. It produce only one big file.

Steve

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #11 from David Smith <dsmith at redhat dot com> ---
(In reply to SteveTsai from comment #10)
> Steve(In reply to David Smith from comment #9)
> > 
> > Let's try something simple and get the udp and tcp tapsets out of the
> > picture. Try the following (which is what flightrec2.exp runs):
> > 
> > # stap -F -o f.out -S 1,3 -e 'probe timer.ms(10) { for (j = 0; j < 1000;
> > j++) printf("1234567890\n") }'
> > 
> > If that just creates 1 big file instead of 3 little ones that rotate, we'll
> > have to go deeper.
> 
> # uname -a
> Linux steve-systemtap 4.4.0-34-generic #53~14.04.1-Ubuntu SMP Wed Jul 27
> 16:56:40 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
> 
> I tried your example. It produce only one big file.

Something odd is going on then. Here's where we dig deeper. Run the following
commands:

# stap -p4 -m renamemod -F -o f.out -S 1,3 -e 'probe timer.ms(10) { for (j = 0;
j < 1000; j++) printf("1234567890\n") } probe timer.sec(5) { exit() }'
# sudo strace -f -ff -o strace.out /usr/local/bin/staprun -o f.out -R -S 1,3
renamemod.ko

If you are running the version of systemtap that came with Ubuntu, you'd change
the last command to:

# sudo strace -f -ff -o strace.out /usr/bin/staprun -o f.out -R -S 1,3
renamemod.ko

That should probably produce around 5 strace.out.PID files. Please attach those
to this bug. When I look for references to f.out.* files in my strace.out.*
files, I see the following:

# egrep 'f.out.[0-9]' strace.out.*
strace.out.29488:open("/home/dsmith/f.out.0",
O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 6
strace.out.29491:open("/home/dsmith/f.out.1",
O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 6
strace.out.29491:open("/home/dsmith/f.out.2",
O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 6
strace.out.29491:unlink("/home/dsmith/f.out.0")          = 0
strace.out.29491:open("/home/dsmith/f.out.3",
O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 6
strace.out.29491:unlink("/home/dsmith/f.out.1")          = 0
strace.out.29491:open("/home/dsmith/f.out.4",
O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 6
strace.out.29491:unlink("/home/dsmith/f.out.2")          = 0
strace.out.29491:open("/home/dsmith/f.out.5",
O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE|O_CLOEXEC, 0666) = 6

One possibility here might be that opening of 'f.out.1' is failing somehow for
you, so stap keeps writing to 'f.out.0'.

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #13 from SteveTsai <steve.tsai at nexusguard dot com> ---
Created attachment 9501
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9501&action=edit
2nd

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #12 from SteveTsai <steve.tsai at nexusguard dot com> ---
Created attachment 9500
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9500&action=edit
1st

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #14 from SteveTsai <steve.tsai at nexusguard dot com> ---
Created attachment 9502
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9502&action=edit
3rd 29048

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #15 from SteveTsai <steve.tsai at nexusguard dot com> ---
Created attachment 9503
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9503&action=edit
4th 29049

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #16 from SteveTsai <steve.tsai at nexusguard dot com> ---
Created attachment 9504
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9504&action=edit
5th 29050

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[steve.tsai at nexusguard dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #17 from SteveTsai <steve.tsai at nexusguard dot com> ---
Created attachment 9505
  --> https://sourceware.org/bugzilla/attachment.cgi?id=9505&action=edit
6th 29051

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

--- Comment #18 from David Smith <dsmith at redhat dot com> ---
After looking at the strace files you attached, I'm quite confused:

====
# grep f.out strace.out.*
strace.out.29045:execve("/usr/bin/staprun", ["/usr/bin/staprun", "-o", "f.out",
"-R", "-S", "1,3", "renamemod.ko"], [/* 20 vars */]) = 0
strace.out.29045:execve("/usr/lib/systemtap/stapio",
["/usr/lib/systemtap/stapio", "-o", "f.out", "-R", "-S", "1,3", "ren_29045",
"-F3"], [/* 20 vars */]) = 0
strace.out.29045:open("/root/systemtap/examples/f.out.0",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 6
strace.out.29048:open("/root/systemtap/examples/f.out.1",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 6
strace.out.29048:open("/root/systemtap/examples/f.out.2",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 6
strace.out.29048:unlink("/root/systemtap/examples/f.out.0") = 0
strace.out.29048:open("/root/systemtap/examples/f.out.3",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 6
strace.out.29048:unlink("/root/systemtap/examples/f.out.1") = 0
strace.out.29048:open("/root/systemtap/examples/f.out.4",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 6
strace.out.29048:unlink("/root/systemtap/examples/f.out.2") = 0
strace.out.29048:open("/root/systemtap/examples/f.out.5",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 6
====

That strace output clearly shows systemtap creating f.out.0, f.out.1, f.out.2,
unlinking f.out.0, creating f.out.3, unlinking f.out.1, creating f.out.4,
unlinking f.out.2, and creating f.out.5. All the open() and unlink() syscalls
succeed.

At this point I'm not sure what is going on with your system. Perhaps you
should try running systemtap again in an empty directory?

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug server/20557] It seems like that switching output file doesn't work.

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=20557

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|UNCONFIRMED                 |RESOLVED
         Resolution|---                         |WORKSFORME
                 CC|                            |fche at redhat dot com

--- Comment #19 from Frank Ch. Eigler <fche at redhat dot com> ---
testsuite includes some file rotation elements, and these are passing

-- 
You are receiving this mail because:
You are the assignee for the bug.