process takes long time

[Niraj Kumar Verma]

Hi,

I have a problem with HP N class server running 11.11

please see the tusc output below

Problem server
==============
Running job locally
write(1, "R u n n i n g j o b l o c a ".., 20) ...................... = 20
sigprocmask(SIG_BLOCK, 0x7a000eb0, 0x7a000e90) .......................... = 0
sigprocmask(SIG_SETMASK, 0x7a000e90, NULL) .............................. = 0
sigprocmask(SIG_BLOCK, 0x7a000e30, 0x7a000e10) .......................... = 0
sigprocmask(SIG_SETMASK, 0x7a000e10, NULL) .............................. = 0
fork() .................................................................. = 17412
sigvec(SIGCLD, 0x7a002070, 0x7a002080) .................................. = 0
waitpid(-1, 0x7a001ffc, WUNTRACED) ...................................... [sleeping]



Working server
=============
sigprocmask(SIG_SETMASK, 0x7b040e50, NULL) ........................ = 0
Running job locally
write(1, "R u n n i n g j o b l o c a ".., 20) ................ = 20
sigprocmask(SIG_BLOCK, 0x7b040ef0, 0x7b040ed0) .................... = 0
sigprocmask(SIG_SETMASK, 0x7b040ed0, NULL) ........................ = 0
sigprocmask(SIG_BLOCK, 0x7b040e70, 0x7b040e50) .................... = 0
sigprocmask(SIG_SETMASK, 0x7b040e50, NULL) ........................ = 0
fork() ............................................................ = 17184
sigvec(SIGCLD, 0x7b0420b0, 0x7b0420c0) ............................ = 0
waitpid(-1, 0x7b04203c, WUNTRACED) ................................ [sleeping]
Logging to /home/nirajv/temposync_log/dss_05182005_124119.log
V4.0-0815

stcl>


It waits for 5 to 10 minutes before giving me the prompt.

any clues ??

Regards
-Niraj

[Niraj Kumar Verma]

Any Help ?

Regards
- Niraj

[Stephen Keane]

Try running tusc with -f flag so we can actually see what it is that you are doing. For example, where does the stcl> prompt come from?

[Niraj Kumar Verma]

Hi,

the size of the file is bigger than 1 MB i am not able to upload it .. is there any other flag to try with ..

[Niraj Kumar Verma]

stcl is temposync tool ( cad tool)

[Stephen Keane]

Just need the portion of the file up to and say 100 lines past the fork command. The last 50 lines of the file might be interesting too.

[Niraj Kumar Verma]

= 0
write(1, "s t c l > ", 6) ............................................. = 6
read(0, "e ", 1) ........................................................ = 1
write(1, "e ", 1) ....................................................... = 1
read(0, "x ", 1) ........................................................ = 1
write(1, "x ", 1) ....................................................... = 1
read(0, "i ", 1) ........................................................ = 1
write(1, "i ", 1) ....................................................... = 1
read(0, "t ", 1) ........................................................ = 1
write(1, "t ", 1) ....................................................... = 1
read(0, "\n", 1) ........................................................ = 1
write(1, "\n", 1) ....................................................... = 1
write(1, "\r", 1) ....................................................... = 1
ioctl(0, TCSETATTR, 0x400172b0) ......................................... = 0
brk(0x405e0000) ......................................................... = 0
readlink("/home", "z", 1024) ............................................ ERR#22 EINVAL
readlink("/home/nirajv", "z", 1024) ..................................... ERR#22 EINVAL
readlink("/home/nirajv/.caddata", "z", 1024) ............................ ERR#22 EINVAL
readlink("/home/nirajv/.caddata/synchronicity", "/cadappl/ictools/synchronicity/4.0-0815p5/syncinc", 1024) = 49
readlink("/cadappl", "/sys/cadappl_hppa", 1024) ......................... = 17
readlink("/sys", "/sys/cadappl_hppa/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_hppa", "/sys/cadappl_hppa/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_hppa/ictools", "/sys/cadappl_hppa/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_hppa/ictools/synchronicity", "/cadappl_shared/ictools/synchronicity", 1024) = 37
readlink("/cadappl_shared", "/sys/cadappl_shared", 1024) ................ = 19
readlink("/sys", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools/synchronicity", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
readlink("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library", "/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/", 1024) ERR#22 EINVAL
stat64("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/history.tcl", 0x7a002f78) = 0
open("/sys/cadappl_shared/ictools/synchronicity/4.0-0815p5/syncinc/share/tcl/library/history.tcl", O_RDONLY|O_LARGEFILE, 0644) = 7
fcntl(7, F_SETFD, 1) .................................................... = 0
ioctl(7, TCGETA, 0x7a0032d8) ............................................ ERR#25 ENOTTY
read(7, "# h i s t o r y . t c l - - ".., 4096) ..................... = 4096
read(7, "c u t i n g , t h e n t h e ".., 4096) ..................... = 4096
read(7, "s p e c i f i e r t o t h e ".., 4096) ..................... = 866
read(7, 0x405c00c0, 4096) ............................................... = 0
close(7) ................................................................ = 0
write(6, "e x i t ", 4) ................................................. = 4
write(6, "\n", 1) ....................................................... = 1
write(6, "# * e x i t ", 8) ......................................... = 8
write(6, "\n", 1) ....................................................... = 1
stat64("/home/nirajv/.synchronicity/UserRegistry.reg", 0x7a001e60) ...... = 0
getpid() ................................................................ = 1894 (1827)
time(0x7a0018d4) ........................................................ = 1116408419
getpid() ................................................................ = 1894 (1827)
close(4) ................................................................ = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_145203.log", 0x7a0016e8) = 0
time(NULL) .............................................................. = 1116408419
open("/home/nirajv/.synchronicity/logs/", O_RDONLY|0x200000, 01) ........ = 4
fstat(4, 0x7a001868) .................................................... = 0
fcntl(4, F_SETFD, 1) .................................................... = 0
getdents(4, 0x4014d890, 8192) ........................................... = 608
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_122529.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_123242.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_124118.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_125104.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_144349.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_144645.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_144903.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_144934.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_145053.log", 0x7a001770) = 0
stat64("/home/nirajv/.synchronicity/logs/sync_client_trace_05182005_145203.log", 0x7a001770) = 0
getdents(4, 0x4014d890, 8192) ........................................... = 0
close(4) ................................................................ = 0
open("/home/nirajv/.synchronicity/stclHistory", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4
ioctl(4, TCGETA, 0x7a0017d8) ............................................ ERR#25 ENOTTY
write(4, "e x i t \n", 5) ............................................... = 5
close(4) ................................................................ = 0
close(6) ................................................................ = 0
getpid() ................................................................ = 1894 (1827)
unlink("/var/spool/sockets/pwgr/client1894") ............................ = 0
exit(0) ................................................................. WIFEXITED(0)
waitpid(-1, WIFEXITED(0), WUNTRACED) .................................... = 1894
sigvec(SIGCLD, 0x7a002080, 0x7a002090) .................................. = 0
sigprocmask(SIG_BLOCK, 0x7a000a00, 0x7a0009e0) .......................... = 0
read(2046, 0x40004810, 1024) ............................................ = 0
sigprocmask(SIG_SETMASK, 0x7a0009e0, NULL) .............................. = 0
exit(0) ................................................................. WIFEXITED(0)

[Ermin Borovac]

Other helpful tusc flags are

-ccc will show CPU time spent in each system call
-T'%T' will show timestamp for each system call

Then you may be able to isolate system call(s) that hang/take a long time.

[Niraj Kumar Verma]

waitpid(-1, 0x7a001ffc, WUNTRACED) ...................................... [sleeping]


the waitpid take more time ...
don't know why ???


-Niraj

[Stephen Keane]

The waitpid is waiting for the child process to stop or terminate. If the waitpid is taking more time on the server that doesn't work, that would indicate that the child process (whatever it is) is taking longer to stop/terminate. Without knowing much about the child process, it's difficult to be much more helpful.

[Geoff Wild]

Just a stab in the dark here - I have found sometimes that processes take a long time (when not expected to) because of an incorrect LAN setting...

IE - your Interface is set to AUTO-NEGOTIATE - and it decides on 100 HD - when the switch is set for 100 FULL...

Little scrpt to check your lancards:

# cat /usr/local/bin/lancards
#!/usr/bin/sh
# script to check speed and settings of lan cards
PATH=/usr/sbin:/usr/bin
ppas=`lanscan | awk '$3~/^[0-9]$/{print $3}' | xargs`
for i in $ppas
do
printf "Card at PPA %s - " $i
ipa=`ifconfig lan${i} 2>/dev/null | awk '{ip=$2}END{if(ip==""){printf("Not assigned")}else{printf("%s ",ip)}}'`
printf "IP Address: %15s- " "$ipa"
lanadmin -x $i 2>/dev/null | awk '{$1="";printf("%s",$0)}'
echo ""
done


Rgds...Geoff

[A. Clay Stephenson]

You've already been given the key data. As soon as you saw the waitpid(), you should have realized your are tusc'ing the wrong process. You need to tusc the child process that the waitpid() is sleeping on.