How to perform a process trace using tusc

From Wiki-UX.info
Jump to: navigation, search

Abstract

The following article explains how to perform a process trace using the tusc command (Opensource).

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

Authors