How to perform a process trace using tusc
Abstract
The following article explains how to perform a process trace using the tusc command (Opensource).
Contents
Obtaining and Installing the tusc command
HP-UX versions of the tusc command are available at the HP-UX Performance and Analysis Tools and at The Porting and Archiving Centre for HP-UX.
Installation
The following procedure explains how to install the The Porting and Archiving Centre for HP-UX version of the tusc command. The HP-UX Performance and Analysis Tools just requires the file to me unshared and the binary and man page files to be copied in user defined directories.
1. Uncompress the distribution depot
# ls -l /var/tmp/tusc*
-rw-r--r-- 1 root sys 413352 Sep 8 10:57 /var/tmp/tusc-7.10-hppa-11.31.depot.gz
# /usr/contrib/bin/gunzip /var/tmp/tusc-7.10-hppa-11.31.depot.gz
# ls -l /var/tmp/tusc*
-rw-r--r-- 1 root sys 931840 Sep 8 10:57 /var/tmp/tusc-7.10-hppa-11.31.depot
2. Install the product
# swlist -s /var/tmp/tusc-7.10-hppa-11.31.depot
# Initializing...
# Contacting target "delta"...
#
# Target: delta:/var/tmp/tusc-7.10-hppa-11.31.depot
#
#
# No Bundle(s) on delta:/var/tmp/tusc-7.10-hppa-11.31.depot
# Product(s):
#
tusc 7.10 tusc
# swinstall -s /var/tmp/tusc-7.10-hppa-11.31.depot tusc @
======= 09/08/09 11:01:30 CST BEGIN swinstall SESSION
(non-interactive) (jobid=delta-0272)
* Session started for user "root@delta".
* Beginning Selection
* Target connection succeeded for "delta:/".
* Source: /var/tmp/tusc-7.10-hppa-11.31.depot
* Targets: delta:/
* Software selections:
tusc.tusc-RUN,r=7.10,a=HP-UX_B./800
* Selection succeeded.
* Beginning Analysis and Execution
* Session selections have been saved in the file
"/root/.sw/sessions/swinstall.last".
* The analysis phase succeeded for "delta:/".
* The execution phase succeeded for "delta:/".
* Analysis and Execution succeeded.
NOTE: More information may be found in the agent logfile using the
command "swjob -a log delta-0272 @ delta:/".
======= 09/08/09 11:01:35 CST END swinstall SESSION (non-interactive)
(jobid=delta-0272)
# whereis tusc
tusc: /usr/local/bin/tusc /usr/local/man/man1/tusc.1
Process tracing using tusc
The tusc traces a process in two modes:
1. Concurrently to the process startup.
The methods is somewhat similar to the time command. For example, to perform a tusc trace against of the date command, use the following sintax:
# tusc -fpkaev -b 256 -rall -o /tmp/date.tusc date Tue Sep 8 11:14:37 CST 2009
- Note that the -o option defines an output file different that standout (the default). To review the results, review this output file using standard tools.
# tail -n 100 /tmp/date.tusc
[23468] getuid() ......................................... = 0 (0)
[23468] getuid() ......................................... = 0 (0)
[23468] getgid() ......................................... = 3 (3)
[23468] getgid() ......................................... = 3 (3)
[23468] mmap(NULL, 8192, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7b04a000
[23468] open("/opt/graphics/OpenGL/lib/libogltls.sl", O_RDONLY, 0200) ERR#2 ENOENT
[23468] open("/usr/lib/libc.2", O_RDONLY, 0200) .......... = 4
[23468] fstat(4, 0x7f7f3730) ............................. = 0
st_dev: 64 0x000007
st_ino: 19627
st_mode: S_IFREG|0555
st_nlink: 1
st_rdev: 0
st_size: 2097152
st_blksize: 8192
st_blocks: 2048
st_uid: 2
st_gid: 2
st_atime: Tue Sep 8 11:14:37 2009
st_mtime: Tue Apr 7 23:04:46 2009
st_ctime: Thu Sep 3 11:39:44 2009
[23468] read(4, 0x7f7f37d0, 128) ......................... = 128
0214010e0512@ \0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\080
\0\0\0b4\0 \0\0@ \010\0\0\0018 \0\0\003\0\001a4\0\0\016\0\005P
\0\0\0\0\0\005P \0\001| \0\00514\0\0\003\0\ae3< \0\004Q \0\006d0
\0\0$ A \002dbe4\0\0\0\0\002dbe4\005\aT \0 \0\0\0\0\0\0G 0497p
[23468] lseek(4, 128, SEEK_SET) .......................... = 128
[23468] read(4, 0x7f7f3850, 48) .......................... = 48
10\0\004\0\0\0( \016e6< \0\010\0\0\b80\0\0\090\0@ \010\0\01fp \0
\0\0bc88\0\0\0\0\0\0\0f0\0\0\0\0
[23468] read(4, 0x7f7f3888, 12) .......................... = 12
80\0\0\v\0\0\004\0\0\0\0
[23468] mmap(NULL, 1503232, PROT_READ|PROT_EXEC, MAP_SHARED|MAP_SHLIB, 4, 557056) = 0xc0100000
[23468] mmap(NULL, 49152, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYMOUS|MAP_SHLIB, -1, 0) = 0x7b03c000
[23468] mmap(0x7b033000, 36864, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_SHLIB, 4, 2060288) = 0x7b033000
[23468] mmap(NULL, 16384, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7b02c000
[23468] close(4) ......................................... = 0
[23468] open("/usr/lib/libdld.2", O_RDONLY, 0200) ........ = 4
[23468] fstat(4, 0x7f7f38f0) ............................. = 0
st_dev: 64 0x000007
st_ino: 39094
st_mode: S_IFREG|0555
st_nlink: 1
st_rdev: 0
st_size: 24576
st_blksize: 8192
st_blocks: 24
st_uid: 2
st_gid: 2
st_atime: Tue Sep 8 11:14:37 2009
st_mtime: Tue Dec 2 02:45:35 2008
st_ctime: Thu Sep 3 11:40:11 2009
[23468] read(4, 0x7f7f3990, 128) ......................... = 128
02\v010e0512@ \0I 4 e501\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\080
\0\0014 \0\0` \0@ \010\0\0\001b8\0\0\002\0\002\0\0\0\0\f\0\004\b
\0\0\0\0\0\004\b\0\0014 \0\003e0\0\0\002\0\011dc\0\0\004\0\005@
\0\0\0Y \0\0\f4 \0\0\0\0\0\0\f4 \0\005a4\0\0` \0\0\0\0\00e- a5be
[23468] lseek(4, 128, SEEK_SET) .......................... = 128
[23468] read(4, 0x7f7f3a10, 48) .......................... = 48
10\0\004\0\0\0( \0\0) \ \0\010\0\0\0 \0\0\001e0@ \010\0\0\0P \0
\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
[23468] read(4, 0x7f7f3a48, 12) .......................... = 12
80\0\0\v\0\0\004\0\0\0\0
[23468] mmap(NULL, 12288, PROT_READ|PROT_EXEC, MAP_SHARED|MAP_SHLIB, 4, 8192) = 0xc0008000
[23468] mmap(NULL, 4096, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_SHLIB, 4, 20480) = 0x7b051000
[23468] close(4) ......................................... = 0
[23468] mmap(NULL, 16384, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7b028000
[23468] mmap(NULL, 144, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7b049000
[23468] sigsetreturn(0x7b02e586, 0x6211988, 1392) ........ = 0
[23468] sysconf(_SC_CPU_VERSION) ......................... = 532
cpu: CPU_PA_RISC2_0
[23468] brk(0x40001a90) .................................. = 0
[23468] brk(0x40003a78) .................................. = 0
[23468] brk(0x40005000) .................................. = 0
[23468] brk(0x40006000) .................................. = 0
[23468] open("/usr/lib/nls/loc/locales.3/C", O_RDONLY, 0200) ERR#2 ENOENT
[23468] brk(0x40007000) .................................. = 0
[23468] open("/usr/lib/nls/msg/C/date.cat", O_RDONLY, 0177777) = 4
[23468] fstat(4, 0x7f7f1d88) ............................. = 0
st_dev: 64 0x000007
st_ino: 10127
st_mode: S_IFREG|0444
st_nlink: 1
st_rdev: 0
st_size: 411
st_blksize: 8192
st_blocks: 8
st_uid: 2
st_gid: 2
st_atime: Wed Sep 2 16:14:43 2009
st_mtime: Thu Feb 15 15:36:51 2007
st_ctime: Wed Aug 26 10:14:28 2009
[23468] fcntl(4, F_SETFD, 1) ............................. = 0
[23468] time(0x4000155c) ................................. = 1252430077
date: Tue Sep 8 11:14:37 2009
[23468] brk(0x40008000) .................................. = 0
[23468] write(1, "T u e S e p 8 1 1 : 1 4 ".., 20) = 20
[23468] write(1, "C S T ", 3) ............................ = 3
[23468] write(1, " 2 0 0 9 \n", 6) ...................... = 6
[23468] exit(0) .......................................... WIFEXITED(0)
2. Attaching to an running process
In the mode, tusc attaches to an already running process. Tracing will start on command execution and tracing should be stopped manually using [Ctrl]-[C].
# export UNIX95=
# ps -ef | grep [s]endmail
root 8607 1 0 Sep 4 ? 00:01:36 sendmail: accepting connections
# tusc -fpkaev -b 256 -rall -o /tmp/sendmail.tusc 8607
( Detaching from process 8607 ("sendmail: accepting connections") )
- To review the results, review the output file using standard tools.
# tail -n 100 /tmp/sendmail.tusc
psd_arm: 182366
psd_vmtxt: 3592
psd_avmtxt: 1640
psd_rmtxt: 2560
psd_armtxt: 1119
psd_free: 72195
psd_avg_1/5/15/_min: 0.01 0.01 0.01
psd_cpu_time: 226943 0 484347 32264739 153801 0 0 0 0 0 0 0 0 0 0
psd_openlv: 9
psd_openvg: 1
psd_allocpbuf: 0
psd_usedpbuf: 0
psd_maxpbuf: 0
psd_activeprocs: 182
psd_activeinodes: 1038
psd_activefiles: 1667
psd_mpdcnt: 0
psd_procovf: 0
psd_inodeovf: 0
psd_fileovf: 0
psd_global_virtual: 0x6ff7716b
psd_valid: PSD_VM|PSD_AVM
psd_monarch_node: 0
psd_node_cnt: 1
psd_dnlc_size: 8976
psd_dnlc_hits: 0
psd_dnlc_misses: 0
psd_dnlc_long: 0
psd_num_psets: 1
psd_maxprocs: 4200
psd_numprocsallocd: 201
psd_maxkthreads: 8416
psd_numkthreadsallocd: 2097
psd_activethreads: 2005
psd_maxkthreads: 8416
psd_numkthreadsallocd: 2097
[8607] time(0x7f7f3ad8) .................................. = 1252430802
date: Tue Sep 8 11:26:42 2009
[8607] pstat(PSTAT_DYNAMIC, 0x7f7f3c10, 2960, 1, 0) ...... = 1
psd_proc_cnt: 2
psd_max_proc_cnt: 2
psd_last_pid: 0
psd_rq: 1
psd_dw: 1
psd_pw: 0
psd_sl: 103
psd_sw: 0
psd_vm: 876670
psd_avm: 559412
psd_rm: 234293
psd_arm: 182366
psd_vmtxt: 3592
psd_avmtxt: 1640
psd_rmtxt: 2560
psd_armtxt: 1119
psd_free: 72195
psd_avg_1/5/15/_min: 0.01 0.01 0.01
psd_cpu_time: 226943 0 484347 32264739 153801 0 0 0 0 0 0 0 0 0 0
psd_openlv: 9
psd_openvg: 1
psd_allocpbuf: 0
psd_usedpbuf: 0
psd_maxpbuf: 0
psd_activeprocs: 182
psd_activeinodes: 1038
psd_activefiles: 1667
psd_mpdcnt: 0
psd_procovf: 0
psd_inodeovf: 0
psd_fileovf: 0
psd_global_virtual: 0x6ff7716b
psd_valid: PSD_VM|PSD_AVM
psd_monarch_node: 0
psd_node_cnt: 1
psd_dnlc_size: 8976
psd_dnlc_hits: 0
psd_dnlc_misses: 0
psd_dnlc_long: 0
psd_num_psets: 1
psd_maxprocs: 4200
psd_numprocsallocd: 201
psd_maxkthreads: 8416
psd_numkthreadsallocd: 2097
psd_activethreads: 2005
psd_maxkthreads: 8416
psd_numkthreadsallocd: 2097
[8607] time(0x7f7f3b58) .................................. = 1252430802
date: Tue Sep 8 11:26:42 2009
[8607] sigprocmask(SIG_UNBLOCK, 0x7f7f3ae0, 0x7f7f3b00) .. = 0
set: SIGALRM
oset: SIGALRM
[8607] pstat(PSTAT_SETCMD, 0x7f7f4b50, 31, 0, 0) ......... = 0
command: "sendmail: accepting connections"
[8607] select(7, 0x7f7f3908, NULL, NULL, 0x7f7f3a08) ..... [sleeping]
nfds: 7
readfds: 5, 6
writefds: NULL
errorfds: NULL
timeout.tv_sec: 5
timeout.tv_usec: 0
Reference
- HP-UX Performance and Analysis Tools
- tusc-7.10 - The Porting and Archiving Centre for HP-UX
- SAW: HP-UX and Trace UNIX System Calls (TUSC) - How To Trace System Call Usage for a Process
- SAW: HP-UX 11i - Using TUSC to Trace System Calls on a Running Process
- SAW: SYS ADM: Getting TUSC (Trace UNIX System Call) for HP-UX 10.20