[Bug documentation/13713] New: MAXTRACE/MAXBACKTRACE undocumented feature

[Bug documentation/13713] New: MAXTRACE/MAXBACKTRACE undocumented feature

[brendan.gregg at joyent dot com]

http://sourceware.org/bugzilla/show_bug.cgi?id=13713

             Bug #: 13713
           Summary: MAXTRACE/MAXBACKTRACE undocumented feature
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: documentation
        AssignedTo: systemtap@sourceware.org
        ReportedBy: brendan.gregg@joyent.com
    Classification: Unclassified


I was to file a bug about backtrace() being truncated to 20 entries (21,
including the current function), but after some digging realized that this can
be tuned - it's just not in the documentation.

MAXTRACE - number of stack frames - can be increased to trace stack back traces
longer than 20.  If it helps, here is an example of a long stack (after
increasing MAXTRACE):

 0xffffffffa003f009 : tcp_packet+0x29/0x14e0 [nf_conntrack]
 0xffffffffa003a72b : nf_conntrack_in+0x3bb/0xaf0 [nf_conntrack]
 0xffffffffa0058691 : ipv4_conntrack_in+0x21/0x30 [nf_conntrack_ipv4]
 0xffffffff814fdfb5 : nf_iterate+0x85/0xc0 [kernel]
 0xffffffff814fe065 : nf_hook_slow+0x75/0x150 [kernel]
 0xffffffff81508a44 : ip_rcv+0x224/0x300 [kernel]
 0xffffffff814d2633 : __netif_receive_skb+0x523/0x5c0 [kernel]
 0xffffffff814d3230 : netif_receive_skb+0x80/0x90 [kernel]
 0xffffffffa001fe69 : virtnet_poll+0x5c9/0x830 [virtio_net]
 0xffffffff814d3a7b : net_rx_action+0x12b/0x270 [kernel]
 0xffffffff81075378 : __do_softirq+0xb8/0x230 [kernel]
 0xffffffff815ebbec : call_softirq+0x1c/0x30 [kernel]
 0xffffffff81016275 : do_softirq+0x65/0xa0 [kernel]
 0xffffffff810748e4 : local_bh_enable+0x94/0xa0 [kernel]
 0xffffffff814d4f02 : dev_queue_xmit+0x1c2/0x600 [kernel]
 0xffffffff8150d10b : ip_finish_output+0x16b/0x2f0 [kernel]
 0xffffffff8150dc68 : ip_output+0x98/0xa0 [kernel]
 0xffffffff8150d369 : ip_local_out+0x29/0x30 [kernel]
 0xffffffff8150d4bf : ip_queue_xmit+0x14f/0x3f0 [kernel]
 0xffffffff815248f4 : tcp_transmit_skb+0x3e4/0x8d0 [kernel]
 0xffffffff81525447 : tcp_write_xmit+0xf7/0xa20 [kernel]
 0xffffffff81525da0 : tcp_push_one+0x30/0x40 [kernel]
 0xffffffff81517635 : tcp_sendmsg+0xcb5/0xd90 [kernel]
 0xffffffff8153c7e4 : inet_sendmsg+0x64/0xb0 [kernel]
 0xffffffff814bb39a : sock_aio_write+0x13a/0x160 [kernel]
 0xffffffff811786c2 : do_sync_write+0xd2/0x110 [kernel]
 0xffffffff8117905d : vfs_write+0x16d/0x180 [kernel]
 0xffffffff811792ca : sys_write+0x4a/0x90 [kernel]
 0xffffffff815e9982 : system_call_fastpath+0x16/0x1b [kernel]

Without increasing MAXTRACE, this is truncated.  If this is the correct
tunable, its existence can be added to the function::backtrace man page (which
currently just has MAXSTRINGLEN).  20 frames is often enough, but sometimes
isn't.

There is another tunable, MAXBACKTRACE (set to 20), which can't be redefined
using -D.  It didn't affect the stack length when I tried tuning it on my
system, but it looks related, so may need to in some situations.

If it matters, I was testing on:

# stap -V
Systemtap translator/driver (version 1.6/0.152 non-git sources)
Copyright (C) 2005-2011 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR
TR1_UNORDERED_MAP NLS
# uname -a
Linux 9d219ce8-cf52-409f-a14a-b210850f3231 3.2.6-3.fc16.x86_64 #1 SMP Mon Feb
13 20:35:42 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
# cat /etc/redhat-release 
Fedora release 16 (Verne)

This is Fedora as a guest running under KVM.  SystemTap was installed via yum.

-- 
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug documentation/13713] MAXTRACE/MAXBACKTRACE undocumented feature

[mjw at redhat dot com]

http://sourceware.org/bugzilla/show_bug.cgi?id=13713

Mark Wielaard <mjw at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
                 CC|                            |mjw at redhat dot com
         Resolution|                            |FIXED

--- Comment #1 from Mark Wielaard <mjw at redhat dot com> 2012-02-20 13:54:41 UTC ---
This has been fixed in Systemtap 1.7, from the NEWS file:

- MAXBACKTRACE did work in earlier releases, but has now been documented
  in the stap 1 manual page.

commit 14bf445209e09681d9caa7eab2205d549fe43b3c
Author: Mark Wielaard <mjw@redhat.com>
Date:   Mon Jul 25 15:52:30 2011 +0200

    Clean up maximum backtrace level code. And document MAXBACKTRACE.

    Lots of functions passed around the maximum level of backtraces allowed.
    Now all consolidated inside stack.s. And documented in stap.1.

-- 
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug documentation/13713] MAXTRACE/MAXBACKTRACE undocumented feature

[brendan.gregg at joyent dot com]

http://sourceware.org/bugzilla/show_bug.cgi?id=13713

--- Comment #2 from brendan.gregg at joyent dot com 2012-02-21 23:20:40 UTC ---
Ok, thanks, I'll use MAXBACKTRACE on 1.7.

...

FWIW, only MAXTRACE was working for me on 1.6 (if that's what you meant by
earlier versions).  MAXBACKTRACE is a better term (more descriptive), but
couldn't be set:

[root@9d219ce8-cf52-409f-a14a-b210850f3231 ~]# stap -D MAXBACKTRACE=100
--all-modules -ve 'global s; probe timer.profile { s[backtrace()] <<< 1; }
probe end { foreach (i in s+) { print_stack(i); printf("\t%d\n", @count(s[i]));
} exit(); } probe timer.s(10) { exit(); }'
Pass 1: parsed user script and 77 library script(s) using
202212virt/22908res/3040shr kb, in 10usr/0sys/115real ms.
Pass 2: analyzed script: 3 probe(s), 3 function(s), 2 embed(s), 1 global(s)
using 202752virt/23908res/3360shr kb, in 0usr/0sys/4real ms.
Pass 3: translated to C into
"/tmp/stapLLi3uv/stap_966ef62429e87336cef74c0b1225a90e_2152.c" using
352792virt/40000res/12056shr kb, in 470usr/0sys/773real ms.
In file included from
/tmp/stapLLi3uv/stap_966ef62429e87336cef74c0b1225a90e_2152.c:60:0:
/usr/share/systemtap/runtime/stack.c:28:0: error: "MAXBACKTRACE" redefined
[-Werror]
<command-line>:0:0: note: this is the location of the previous definition
cc1: all warnings being treated as errors

make[1]: *** [/tmp/stapLLi3uv/stap_966ef62429e87336cef74c0b1225a90e_2152.o]
Error 1
make: *** [_module_/tmp/stapLLi3uv] Error 2
Warning: make exited with status: 2
Pass 4: compiled C into "stap_966ef62429e87336cef74c0b1225a90e_2152.ko" in
2690usr/310sys/3802real ms.
Pass 4: compilation failed.  Try again with another '--vp 0001' option.

and didn't work when manually hacking runtime either.  Again, this doesn't
matter now, I only write this if someone else is trying on 1.6 and hits the
same thing.

-- 
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug documentation/13713] MAXTRACE/MAXBACKTRACE undocumented feature

[mjw at redhat dot com]

http://sourceware.org/bugzilla/show_bug.cgi?id=13713

--- Comment #3 from Mark Wielaard <mjw at redhat dot com> 2012-02-22 09:01:30 UTC ---
(In reply to comment #2)
> Ok, thanks, I'll use MAXBACKTRACE on 1.7.
> 
> ...
> 
> FWIW, only MAXTRACE was working for me on 1.6 (if that's what you meant by
> earlier versions).  MAXBACKTRACE is a better term (more descriptive), but
> couldn't be set:
> [...]
> and didn't work when manually hacking runtime either.  Again, this doesn't
> matter now, I only write this if someone else is trying on 1.6 and hits the
> same thing.

Thanks. Looking at it again in hindsight we should have made MAXTRACE the
documented way because smart users would have used that one in earlier versions
even though it hadn't been documented. But smart users hopefully adapt to the
new and shiny official name :)

-- 
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.