Hi,

Thanks for the response. I am running a custom compiled pristine
kernel 2.6.36 on ubuntu 10.04 KVM virtual machine.
Also attaching the output of stap-report.

-ctmzb

On Sat, Dec 24, 2011 at 2:17 PM, Adrien Kunysz <adrien@kunysz.be> wrote:
> 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:~#
>
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.10 (GNU/Linux)
>
> iEYEARECAAYFAk72JS4ACgkQKLX03ZSPZGwWewCgj5Uzz4nMlHeFNzzkK6cPdQCH
> q5YAn1EpCJ7TsC2f8iZumRg+LDzF/uW4
> =9ChX
> -----END PGP SIGNATURE-----
>