On Sat, Dec 24, 2011 at 01:31:21PM -0500, contemplating zombie wrote: > I am new to systemtap and I was trying out following example script > given in the documentation: > > probe kernel.function("*@net/socket.c") { >       printf ("%s -> %s\n", thread_indent(1), probefunc()) > } > > probe kernel.function("*@net/socket.c").return { >       printf ("%s <- %s\n", thread_indent(-1), probefunc()) > } > > I sshed into a remote machine and executed it. What I see is that the > stack frames just keep on growing to right and do not return. Won't > that cause a stack overflow eventually? Rather than a stack overflow it is possible (and probably more likely) that SystemTap is missing some return probes somehow. > Here is the output: > > root@ubuntu:~# touch t.stp > root@ubuntu:~# emacs -nw t.stp > root@ubuntu:~# stap t.stp > > 0 sshd(804): -> sock_poll > 11 sshd(804): <- sock_poll > 0 sshd(804): -> sock_aio_read > 2 sshd(804): -> alloc_sock_iocb > 3 sshd(804): <- alloc_sock_iocb > 5 sshd(804): -> do_sock_read > 7 sshd(804): -> __sock_recvmsg > 9 sshd(804): -> __sock_recvmsg_nosec Notice how do_sock_read() supposedly never returns while it should return immediately after __sock_recvmsg() (at least in the current mainline kernel): 830 static ssize_t do_sock_read(struct msghdr *msg, struct kiocb *iocb, 831 struct file *file, const struct iovec *iov, 832 unsigned long nr_segs) 833 { ... 849 return __sock_recvmsg(iocb, sock, msg, size, msg->msg_flags); 850 } I guess there is some kind of optimisation that interacts poorly with debug symbols and/or the way SystemTap interpret them. Details about the relevant object code and or stap-report output would probably help. > 15 sshd(804): <- sock_aio_read > 32 sshd(804): -> sock_poll > 34 sshd(804): <- sock_poll > 44 sshd(804): -> sock_poll > 46 sshd(804): <- sock_poll > 12636 sshd(804): -> sock_poll > 12644 sshd(804): <- sock_poll > 12678 sshd(804): -> sock_poll > 12683 sshd(804): <- sock_poll > 12692 sshd(804): -> sock_aio_write > 12696 sshd(804): -> alloc_sock_iocb > 12700 sshd(804): <- alloc_sock_iocb > 12704 sshd(804): -> do_sock_write > 12711 sshd(804): -> __sock_sendmsg > 12763 sshd(804): <- sock_aio_write > 12773 sshd(804): -> sock_poll > 12775 sshd(804): <- sock_poll > > 162634 sshd(804): -> sock_poll > 162642 sshd(804): <- sock_poll > 162680 sshd(804): -> sock_poll > 162683 sshd(804): <- sock_poll > 162688 sshd(804): -> sock_aio_write > 162690 sshd(804): -> alloc_sock_iocb > 162692 sshd(804): <- alloc_sock_iocb > 162693 sshd(804): -> do_sock_write > 162695 sshd(804): -> __sock_sendmsg > 162770 sshd(804): <- sock_aio_write > 162777 sshd(804): -> sock_poll > 162780 sshd(804): <- sock_poll > 202760 sshd(804): -> sock_poll > 202765 sshd(804): <- sock_poll > 202774 sshd(804): -> sock_aio_read > 202776 sshd(804): -> alloc_sock_iocb > 202778 sshd(804): <- alloc_sock_iocb > 202780 sshd(804): -> do_sock_read > 202782 sshd(804): -> __sock_recvmsg > 202784 sshd(804): -> __sock_recvmsg_nosec > 202788 sshd(804): <- sock_aio_read > 202796 sshd(804): -> sock_poll > 202799 sshd(804): <- sock_poll > 202807 sshd(804): -> sock_poll > 202810 sshd(804): <- sock_poll > 232494 sshd(804): -> sock_poll > 232503 sshd(804): <- sock_poll > 232535 sshd(804): -> sock_poll > 232540 sshd(804): <- sock_poll > 232550 sshd(804): -> sock_aio_write > 232555 sshd(804): -> alloc_sock_iocb > 232559 sshd(804): <- alloc_sock_iocb > 232564 sshd(804): -> do_sock_write > 232569 sshd(804): -> __sock_sendmsg > 232648 sshd(804): <- sock_aio_write > 232656 sshd(804): -> sock_poll > 232659 sshd(804): <- sock_poll > > 362500 sshd(804): -> sock_poll > 362509 sshd(804): <- sock_poll > 362576 sshd(804): -> sock_poll > 362579 sshd(804): <- sock_poll > 362584 sshd(804): -> sock_aio_write > 362586 sshd(804): -> alloc_sock_iocb > 362588 sshd(804): <- alloc_sock_iocb > 362591 sshd(804): -> do_sock_write > 362593 sshd(804): -> __sock_sendmsg > 362655 sshd(804): <- sock_aio_write > 362663 sshd(804): -> sock_poll > 362666 sshd(804): <- sock_poll > 479663 sshd(804): -> sock_poll > 479668 sshd(804): <- sock_poll > 479677 sshd(804): -> sock_aio_read > 479679 sshd(804): -> alloc_sock_iocb > 479682 sshd(804): <- alloc_sock_iocb > 479684 sshd(804): -> do_sock_read > 479686 sshd(804): -> __sock_recvmsg > 479689 sshd(804): -> __sock_recvmsg_nosec > 479693 sshd(804): <- sock_aio_read > 479702 sshd(804): -> sock_poll > 479705 sshd(804): <- sock_poll > 479713 sshd(804): -> sock_poll > 479716 sshd(804): <- sock_poll > 492567 sshd(804): -> sock_poll > 492575 sshd(804): <- sock_poll > 492592 sshd(804): -> sock_poll > 492595 sshd(804): <- sock_poll > 492599 sshd(804): -> sock_aio_write > 492602 sshd(804): -> alloc_sock_iocb > 492605 sshd(804): <- alloc_sock_iocb > 492607 sshd(804): -> do_sock_write > 492610 sshd(804): -> __sock_sendmsg > 492651 sshd(804): <- sock_aio_write > 492662 sshd(804): -> sock_poll > 492666 sshd(804): <- sock_poll > 562635 sshd(804): -> sock_poll > 562645 sshd(804): <- sock_poll > 562692 sshd(804): -> sock_poll > 562696 sshd(804): <- sock_poll > 562701 sshd(804): -> sock_aio_write > 562704 sshd(804): -> alloc_sock_iocb > 562706 sshd(804): <- alloc_sock_iocb > 562709 sshd(804): -> do_sock_write > 562712 sshd(804): -> __sock_sendmsg > 562821 sshd(804): <- sock_aio_write > 562830 sshd(804): -> sock_poll > 562834 sshd(804): <- sock_poll > 762649 sshd(804): -> sock_poll > 762659 sshd(804): <- sock_poll > 762687 sshd(804): -> sock_poll > 762690 sshd(804): <- sock_poll > 762695 sshd(804): -> sock_aio_write > 762698 sshd(804): -> alloc_sock_iocb > 762701 sshd(804): <- alloc_sock_iocb > 762704 sshd(804): -> do_sock_write > 762706 sshd(804): -> __sock_sendmsg > 762749 sshd(804): <- sock_aio_write > 762757 sshd(804): -> sock_poll > 762761 sshd(804): <- sock_poll > 962447 sshd(804): -> sock_poll > 962458 sshd(804): <- sock_poll > 962525 sshd(804): -> sock_poll > 962534 sshd(804): <- sock_poll > 962548 sshd(804): -> sock_aio_write > 962552 sshd(804): -> alloc_sock_iocb > 962555 sshd(804): <- alloc_sock_iocb > 962558 sshd(804): -> do_sock_write > 962561 sshd(804): -> __sock_sendmsg > 962643 sshd(804): <- sock_aio_write > 962652 sshd(804): -> sock_poll > 962656 sshd(804): <- sock_poll > 1162558 sshd(804): -> sock_poll > 1162563 sshd(804): <- sock_poll > 1162587 sshd(804): -> sock_poll > 1162591 sshd(804): <- sock_poll > 1162596 sshd(804): -> sock_aio_write > 1162600 sshd(804): -> alloc_sock_iocb > 1162603 sshd(804): <- alloc_sock_iocb > 1162606 sshd(804): -> do_sock_write > 1162609 sshd(804): -> __sock_sendmsg > 1162652 sshd(804): <- sock_aio_write > 1162664 sshd(804): -> sock_poll > 1162668 sshd(804): <- sock_poll > 1362636 sshd(804): -> sock_poll > 1362647 sshd(804): <- sock_poll > 1362684 sshd(804): -> sock_poll > 1362688 sshd(804): <- sock_poll > 1362693 sshd(804): -> sock_aio_write > 1362697 sshd(804): -> alloc_sock_iocb > 1362700 sshd(804): <- alloc_sock_iocb > 1362704 sshd(804): -> do_sock_write > 1362707 sshd(804): -> __sock_sendmsg > 1362788 sshd(804): <- sock_aio_write > 1362801 sshd(804): -> sock_poll > 1362805 sshd(804): <- sock_poll > 1562553 sshd(804): -> sock_poll > 1562565 sshd(804): <- sock_poll > 1562617 sshd(804): -> sock_poll > 1562626 sshd(804): <- sock_poll > 1562639 sshd(804): -> sock_aio_write > 1562643 sshd(804): -> alloc_sock_iocb > 1562646 sshd(804): <- alloc_sock_iocb > 1562650 sshd(804): -> do_sock_write > 1562653 sshd(804): -> __sock_sendmsg > 1562696 sshd(804): <- sock_aio_write > 1562708 sshd(804): -> sock_poll > 1562713 sshd(804): <- sock_poll > 1762582 sshd(804): -> sock_poll > 1762588 sshd(804): <- sock_poll > 1762614 sshd(804): -> sock_poll > 1762618 sshd(804): <- sock_poll > 1762624 sshd(804): -> sock_aio_write > 1762627 sshd(804): -> alloc_sock_iocb > 1762631 sshd(804): <- alloc_sock_iocb > 1762635 sshd(804): -> do_sock_write > 1762638 sshd(804): -> __sock_sendmsg > 1762681 sshd(804): <- sock_aio_write > 1762692 sshd(804): -> sock_poll > 1762696 sshd(804): <- sock_poll > 1962573 sshd(804): -> sock_poll > 1962579 sshd(804): <- sock_poll > 1962605 sshd(804): -> sock_poll > 1962609 sshd(804): <- sock_poll > 1962615 sshd(804): -> sock_aio_write > 1962619 sshd(804): -> alloc_sock_iocb > 1962623 sshd(804): <- alloc_sock_iocb > 1962627 sshd(804): -> do_sock_write > 1962631 sshd(804): -> __sock_sendmsg > 1962714 sshd(804): <- sock_aio_write > 1962724 sshd(804): -> sock_poll > 1962729 sshd(804): <- sock_poll > 2162633 sshd(804): -> sock_poll > 2162646 sshd(804): <- sock_poll > 2162683 sshd(804): -> sock_poll > 2162688 sshd(804): <- sock_poll > 2162694 sshd(804): -> sock_aio_write > 2162698 sshd(804): -> alloc_sock_iocb > 2162702 sshd(804): <- alloc_sock_iocb > 2162706 sshd(804): -> do_sock_write > 2162710 sshd(804): -> __sock_sendmsg > 2162789 sshd(804): <- sock_aio_write > 2162802 sshd(804): -> sock_poll > 2162807 sshd(804): <- sock_poll > 2362633 sshd(804): -> sock_poll > 2362646 sshd(804): <- sock_poll > 2362684 sshd(804): -> sock_poll > 2362688 sshd(804): <- sock_poll > 2362695 sshd(804): -> sock_aio_write > 2362699 sshd(804): -> alloc_sock_iocb > 2362703 sshd(804): <- alloc_sock_iocb > 2362707 sshd(804): -> do_sock_write > 2362711 sshd(804): -> __sock_sendmsg > 2362757 sshd(804): <- sock_aio_write > 2362767 sshd(804): -> sock_poll > 2362772 sshd(804): <- sock_poll > 2562462 sshd(804): -> sock_poll > 2562479 sshd(804): <- sock_poll > 2562522 sshd(804): -> sock_poll > 2562527 sshd(804): <- sock_poll > 2562534 sshd(804): -> sock_aio_write > 2562538 sshd(804): -> alloc_sock_iocb > 2562542 sshd(804): <- alloc_sock_iocb > 2562547 sshd(804): -> do_sock_write > 2562551 sshd(804): -> __sock_sendmsg > 2562595 sshd(804): <- sock_aio_write > 2562605 sshd(804): -> sock_poll > 2562612 sshd(804): <- sock_poll > 2762583 sshd(804): -> sock_poll > 2762596 sshd(804): <- sock_poll > 2762638 sshd(804): -> sock_poll > 2762643 sshd(804): <- sock_poll > 2762649 sshd(804): -> sock_aio_write > 2762654 sshd(804): -> alloc_sock_iocb > 2762658 sshd(804): <- alloc_sock_iocb > 2762663 sshd(804): -> do_sock_write > 2762667 sshd(804): -> __sock_sendmsg > 2762751 sshd(804): <- sock_aio_write > 2762761 sshd(804): -> sock_poll > 2762766 sshd(804): <- sock_poll > 2962386 sshd(804): -> sock_poll > 2962392 sshd(804): <- sock_poll > 2962420 sshd(804): -> sock_poll > 2962425 sshd(804): <- sock_poll > 2962432 sshd(804): -> sock_aio_write > 2962437 sshd(804): -> > alloc_sock_iocb > 2962442 sshd(804): <- > alloc_sock_iocb > 2962446 sshd(804): -> do_sock_write > 2962451 sshd(804): -> > __sock_sendmsg > 2962496 sshd(804): <- > sock_aio_write > 2962510 sshd(804): -> sock_poll > 2962515 sshd(804): <- sock_poll > ^C3162600 sshd(804): -> sock_poll > 3162615 sshd(804): <- sock_poll > 3162648 sshd(804): -> sock_poll > 3162653 sshd(804): <- sock_poll > 3162660 sshd(804): -> > sock_aio_write > 3162665 sshd(804): -> > alloc_sock_iocb > 3162670 sshd(804): <- > alloc_sock_iocb > 3162675 sshd(804): -> > do_sock_write > 3162679 sshd(804): -> > __sock_sendmsg > 3162765 sshd(804): <- > sock_aio_write > 3162776 sshd(804): -> sock_poll > 3162782 sshd(804): <- sock_poll > 3184606 sshd(804): -> sock_poll > 3184613 sshd(804): <- sock_poll > 3184624 sshd(804): -> > sock_aio_read > 3184630 sshd(804): -> > alloc_sock_iocb > 3184635 sshd(804): <- > alloc_sock_iocb > 3184640 sshd(804): -> > do_sock_read > 3184644 sshd(804): -> > __sock_recvmsg > 3184649 sshd(804): > -> __sock_recvmsg_nosec > 3184657 sshd(804): > <- sock_aio_read > 3184668 sshd(804): > -> sock_poll > 3184674 sshd(804): > <- sock_poll > 3184688 sshd(804): > -> sock_poll > 3184693 sshd(804): > <- sock_poll > Pass 5: run failed. Try again with another '--vp 00001' option. > root@ubuntu:~#