Bug 13713 - MAXTRACE/MAXBACKTRACE undocumented feature
Summary: MAXTRACE/MAXBACKTRACE undocumented feature
Status: RESOLVED FIXED
Alias: None
Product: systemtap
Classification: Unclassified
Component: documentation (show other bugs)
Version: unspecified
: P2 normal
Target Milestone: ---
Assignee: Unassigned
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-02-20 05:59 UTC by brendan.gregg
Modified: 2012-02-22 09:01 UTC (History)
1 user (show)

See Also:
Host:
Target:
Build:
Last reconfirmed:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description brendan.gregg 2012-02-20 05:59:32 UTC
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.
Comment 1 Mark Wielaard 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.
Comment 2 brendan.gregg 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.
Comment 3 Mark Wielaard 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 :)