truss results

gogogo · #1 (**permalink**) 11-29-2006

I have tried to analyze the log of truss shown below. I haven’t found anything clear for me indicating the problem. The process is the server that accepts client connections. To establish the connection it starts the child thread then it should transfer data. In reality it gets only connection. Child thread can’t confirm connection to and transfer data.
Could anyone recommend if the problems of the process are in the log?

Code:

1:10749:        psargs: /home/saturn
2:10749:        accept(18, 0xFFBEF778, 0xFFBEF788, 1) (sleeping...)
3:10749:        signotifywait()                 (sleeping...)
4:10749:        lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) (sleeping...)
5:10749:        door_return(0x00000000, 0, 0x00000000, 0) (sleeping...)
6:10749:        accept(18, 0xFFBEF778, 0xFFBEF788, 1)           = 23
8:10749:        lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) = 0
10749:  door_return(0x00000000, 0, 0x00000000, 0)       Err#4 EINTR
10749:  getpid()                                        = 10749 [1]
10749:  door_return(0x00000000, 0, 0x00000000, 0)       Err#4 EINTR
10749:  getpid()                                        = 10749 [1] 
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
…..
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  signotifywait()                                 Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  signotifywait()                                 Err#4 EINTR
10749:  lwp_mutex_lock(0xFF3155D8)                      Err#4 EINTR
10749:  signotifywait()                                 Err#4 EINTR
10749:  door_return(0x00000000, 0, 0x00000000, 0)       Err#4 EINTR
10749:  getpid()                                        = 10749 [1]
10749:  signotifywait()                                 Err#4 EINTR
10749:  door_return(0x00000000, 0, 0x00000000, 0)       Err#4 EINTR
10749:  getpid()                                        = 10749 [1]
10749:  signotifywait()                                 Err#4 EINTR
10749:  door_return(0x00000000, 0, 0x00000000, 0)       Err#4 EINTR
10649:10749:    fork()                                          = 22900
10650:22900:    fork()          (returning as child ...)        = 10749
10651:22900:    door_create(0xFF2F6BCC, 0x00000000, 0x00000002) = 24
10653:22900:    lwp_schedctl(SC_STATE|SC_BLOCK, 24, 0xFFBEEFDC) = 0
10654:22900:    door_info(24, 0xFF314AC0)                       = 0
10655:22900:    mmap(0x00000000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIV
ATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFF0C0000
10656:22900:    mprotect(0xFF0C0000, 8192, PROT_NONE)           = 0
10657:22900:    lwp_create(0xFFBEEDC0, LWP_DETACHED|LWP_SUSPENDED, 0xFF0C5DB4) =
 5
10658:22900:    lwp_create()    (returning as new lwp ...)      = 0
10659:22900:    lwp_continue(5)                                 = 0
10660:22900:    lwp_schedctl(SC_STATE|SC_BLOCK, -1, 0xFF0C5CB4) = 0
10661:22900:    lwp_schedctl(SC_DOOR, 0, 0x00000000)            Err#22 EINVAL
10662:22900:    time()                                          = 1164747148
10663:22900:    close(24)                                       = 0
10664:22900:    write(2, " * * * *   S e r v e r".., 46)      = 46
10665:22900:    sigaction(SIGALRM, 0xFFBEED98, 0xFFBEEE98)      = 0
10666:22900:    lwp_alarm(120)                                  = 0
10667:22900:    lwp_mutex_lock(0xFF3155D8)                      = 0
10668:22900:    time()                                          = 1164747148
10670:22900:    door_return(0x00000000, 0, 0x00000000, 0)       Err#22 EINVAL
10671:22900:    sigprocmask(SIG_SETMASK, 0xFF31ADE0, 0x00000000) = 0
10672:22900:    lwp_cond_signal(0xFF3155C8)                     = 0
10673:22900:    lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0C5C48) = 0
10674:22900:    lwp_mutex_wakeup(0xFF3155D8)                    = 0
10675:22900:    lwp_mutex_lock(0xFF3155D8)                      = 0
10676:22900:    lwp_mutex_wakeup(0xFF31B250)                    = 0
10677:22900:    lwp_mutex_lock(0xFF31B250)                      = 0
10678:22900:    lwp_cond_broadcast(0xFF31B288)                  = 0
10679:22900:    munmap(0xFF0D0000, 24576)                       = 0
10680:22900:    lwp_exit()
10682:10749:    lwp_mutex_wakeup(0xFF3155D8)                    = 0
10683:10749:    lwp_mutex_lock(0xFF3155D8)                      = 0
10684:10749:    time()                                          = 1164747148
10685:10749:    write(2, " # # # #   C l i e n t  ".., 44)      = 44
10686:10749:    close(23)                                       = 0
10687:10749:    write(2, " # # # #   S e r v e r".., 54)      = 54
10688:22900:    recv(23, 0xFFBEF65C, 28, 0)     (sleeping...)
10689:22900:    signotifywait()                 (sleeping...)
10690:22900:    lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) (sleeping...)
10691:22900:    lwp_sema_wait(0xFEF0DE30)       (sleeping...)
10692:10749:    accept(18, 0xFFBEF778, 0xFFBEF788, 1) (sleeping...)
10693:10749:    signotifywait()                 (sleeping...)
10694:10749:    lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) (sleeping...)
10695:10749:    door_return(0x00000000, 0, 0x00000000, 0) (sleeping...)
10696:22900:        Received signal #14, SIGALRM, in recv() [caught]
10698:22900:    sigprocmask(SIG_SETMASK, 0xFF30F010, 0x00000000) = 0
10699:22900:    sigaction(SIGALRM, 0xFFBEE900, 0x00000000)      = 0
10700:22900:    sigprocmask(SIG_SETMASK, 0xFF31ADE0, 0x00000000) = 0
10701:22900:    setcontext(0xFFBEE928)
10702:22900:    lwp_alarm(0)                                    = 0
10703:22900:    write(2, "\n # # # #   L O G   S A".., 23)      = 23
10704:22900:    write(2, " S o c k e t   t i m e -".., 44)      = 44
10705:22900:    write(2, "   # # # #\n", 6)                     = 6
10706:22900:    time()                                          = 1164747268
10707:22900:    write(15, " 2 0 0 6 1 1 2 8 1 5 5 4".., 80)     = 80
10708:22900:    time()                                          = 1164747268
10709:22900:    write(23, "E9DFABCD E lA204\0\0\0 F".., 28)     = 28
10710:22900:    write(23, "\0\0\0\b\0\0\0\0", 8)                = 8
10711:22900:    write(2, "\n D e c o n n e c t i o".., 45)      = 45
10712:22900:    close(23)                                       = 0
10713:22900:    write(2, "\n # # # #   L O G   S A".., 23)      = 23
10714:22900:    write(2, " / * * * S E R V E R   O".., 40)      = 40
10715:22900:    write(2, "   # # # #\n", 6)                     = 6
10716:22900:    time()                                          = 1164747268
10717:22900:    write(15, " 2 0 0 6 1 1 2 8 1 5 5 4".., 80)     = 80
10718:22900:    llseek(15, 0, SEEK_CUR)                         = 4362800
10719:22900:    close(15)                                       = 0
10720:22900:    close(14)                                       = 0
10721:22900:    close(13)                                       = 0
10722:22900:    close(12)                                       = 0
10723:22900:    close(11)                                       = 0
10724:22900:    close(10)                                       = 0
10725:22900:    fcntl(20, F_SETLK, 0xFFBEEC14)                  = 0
10726:22900:    fcntl(19, F_SETLK, 0xFFBEEBB4)                  = 0
10727:22900:    close(19)                                       = 0
10728:22900:    close(20)                                       = 0
10729:22900:    fcntl(17, F_SETLK, 0xFFBEEC14)                  = 0
10730:22900:    fcntl(16, F_SETLK, 0xFFBEEBB4)                  = 0
10731:22900:    close(16)                                       = 0
10732:22900:    close(17)                                       = 0
10733:22900:    fcntl(5, F_SETLK, 0xFFBEEC14)                   = 0
10734:22900:    fcntl(4, F_SETLK, 0xFFBEEBB4)                   = 0
10735:22900:    close(4)                                        = 0
10736:22900:    close(5)                                        = 0
10737:22900:    fcntl(22, F_SETLK, 0xFFBEEC14)                  = 0
10738:22900:    fcntl(21, F_SETLK, 0xFFBEEBB4)                  = 0
10739:22900:    close(21)                                       = 0
10740:22900:    close(22)                                       = 0
10741:22900:    close(8)                                        = 0
10742:22900:    close(9)                                        = 0
10743:22900:    close(6)                                        = 0
10744:22900:    close(7)                                        = 0
10745:22900:    close(3)                                        = 0
10746:22900:    write(2, "\n * * * *   E n d   o f".., 36)      = 36
10747:22900:    llseek(0, 0, SEEK_CUR)                          = 0
10748:22900:    write(1, " 2 0 0 6 / 1 1 / 2 8    ".., 120)     = 120
10749:22900:    _exit(0)
10750:10749:    lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) Err#62 ETIME
10751:10749:    time()                                          = 1164747447
10752:10749:    accept(18, 0xFFBEF778, 0xFFBEF788, 1) (sleeping...)
10753:10749:    signotifywait()                 (sleeping...)
10754:10749:    lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) (sleeping...)
10755:10749:    door_return(0x00000000, 0, 0x00000000, 0) (sleeping...)
10756:10749:    accept(18, 0xFFBEF778, 0xFFBEF788, 1)           = 23
10758:10749:    lwp_cond_wait(0xFF3155C8, 0xFF3155D8, 0xFF0E5BF0) = 0
….

linuxbynight · #2 (**permalink**) 12-23-2006

It seems to me that your code might be confused when you are forking off the child. The reason I say this is that it appears that the child is calling accept() which is usually something you would want the server to do to accept a connection request from a client. Additionally, there is a message print that is signifying the message is from the server but it looks like it is being printed by the child.

When you do the fork(), make sure you check the return code and then make the proper decision as to which code you can each process to execute. Providing the actual code snippet here would be helpful to determine if what I am saying is correct.

More UNIX and Linux Forum Topics You Might Find Helpful
Thread	Thread Starter	Forum	Replies	Last Post
how to use truss?	wrapster	Shell Programming and Scripting	5	03-26-2008 12:54 PM
truss output	happyadm	UNIX for Advanced & Expert Users	0	01-28-2008 04:55 PM
truss results	gogogo	SUN Solaris	0	11-29-2006 04:00 PM
truss	fraze	UNIX for Advanced & Expert Users	2	07-21-2004 11:31 AM
Process calls - making sense of truss results	jpeery	UNIX for Advanced & Expert Users	3	06-16-2004 09:25 AM

Thread Tools	Search this Thread
Show Printable Version Email this Page	Search this Thread: Advanced Search
Display Modes	Rate This Thread
Switch to Linear Mode Hybrid Mode Switch to Threaded Mode	Rate This Thread:


	Powered by