Making a Super-Record and Using csagfef

Last Update 2000-05-07 by kcarlson

ARSC Making a `Super-Record` and Using `csagfef`

Overview (session, report, conclusion)

This example demonstrates how to construct a Super-record (session) file containing only selected jobs using the 'uakpacct -bin' option. The csagcon and csagfef programs are used to generate reports. This example also demonstrates a csa problem where nq_wallclock can be mis-reported.

Process:

Make a small Super-record with selected jobs:
Report using csagcon, csagfef, and nawk.

Conclusions on nq_wallclock discrepancy.

Making a "session file" or `Super-record` (top, report, conclusion)

Capture the Wnqacct1, Wpacct0, Wpacct1, and Puptime1 files from the 20000323.0001 accounting directory. Also capture the Super-record file as Super.org. Capture the Wnqacct1 file as Wnqacct.prv from the 20000322.0001 directory:

yukon: TEST=$TMPDIR/A.make; mkdir $TEST
yukon: ACCT=/var/local/output/acct
yukon: cd $ACCT/raw/20000323.0001
yukon: cp -p Wpacct0 Wpacct1 Wnqacct1 Puptime1 $TEST
yukon: cp -p $ACCT/session_file/20000323.0001  $TEST/Super.org
yukon: cd ../20000322.0001;     cp -p Wnqacct1 $TEST/Wnqacct.prv
yukon: cd $TEST;   cp -p $ACCT/Jobs/j-20000323 $TEST

Extract using uakpacct (see 'man -M /usr/local/adm/man uakpacct') just the seqno's (nqacct) and jobids (pacct) we are interested in:

yukon: uakpacct -v -file Wnqacct.prv,Wnqacct1 -bin nqacct1 -seq 57126,57113
File:   Wnqacct.prv
Report seqno:   57126 57113 
#NQS     Time  /  jid:uid     /seqno/type:sub-type    machname reqname     quename
20000321@044920/    0:bog03x  /57113/RECV:New         yukon    x64.3       gcp             
20000321@044920/21538:bog03x  /57113/SENT:started     yukon    x64.3       gcp             
20000321@044921/    0:bog03x  /57113/RECV:Local pipe  yukon    x64.3       gcp_xxlarge     
20000321@044921/21538:bog03x  /57113/SENT:stopped     yukon    x64.3       gcp_xxlarge     
20000321@072109/    0:myk31   /57126/RECV:New         yukon    step2.runk  Special         
20000321@120728/22788:myk31   /57126/INIT:started     yukon    step2.runk  Special         
20000321@172920/23707:bog03x  /57113/INIT:started     yukon    x64.3       gcp_xxlarge     
Records: 841, non-pacct: 841, Selected: 841, binary-out: 7
File:   Wnqacct1
20000322@012006/25008:bog03x  /57113/SPOOL:started    yukon    x64.3       gcp_xxlarge     
20000322@012006/25008:bog03x  /57113/SPOOL:stopped    yukon    x64.3       gcp_xxlarge     
20000322@012006/25009:bog03x  /57113/SPOOL:started    yukon    x64.3       gcp_xxlarge     
20000322@012006/25009:bog03x  /57113/SPOOL:stopped    yukon    x64.3       gcp_xxlarge     
20000322@012007/23707:bog03x  /57113/TERM:exited      yukon    x64.3       gcp_xxlarge     
20000322@012007/    0:bog03x  /57113/DISP:normally    yukon    x64.3       gcp_xxlarge     
20000322@080820/26126:myk31   /57126/SPOOL:started    yukon    step2.runk  Special         
20000322@080847/26126:myk31   /57126/SPOOL:stopped    yukon    step2.runk  Special         
20000322@080847/26127:myk31   /57126/SPOOL:started    yukon    step2.runk  Special         
20000322@080847/26127:myk31   /57126/SPOOL:stopped    yukon    step2.runk  Special         
20000322@080847/22788:myk31   /57126/TERM:exited      yukon    step2.runk  Special         
20000322@080847/    0:myk31   /57126/DISP:normally    yukon    step2.runk  Special         
Records: 1702, non-pacct: 1702, Selected: 1702, binary-out: 19
    6)        6 kernel: configuration
   15)     1696 daemon: NQS
yukon: JOBID="21538 23707 25008 25009 22788 26126 26127"
yukon: uakpacct -v -file Wpacct0,Wpacct1 -bin pacct1 -job "$JOBID" -out /dev/null
File:   Wpacct0
Report jobid:   21538 23707 25008 25009 22788 26126 26127 
Records: 18559, non-pacct: 81, Selected: 122, binary-out: 41
File:   Wpacct1
Records: 163159, non-pacct: 29730, Selected: 29789, binary-out: 61
    0)   133429 kernel: base
    3)       84 kernel: multi-PE-appl
    4)     4109 kernel: start job
    5)     4099 kernel: end job
    6)    21438 kernel: configuration

Rebuild a small Super-record by creating a fake "acct" and using a stripped down csarun:

yukon: mkdir -p $TMPDIR/acct/day $TMPDIR/acct/nite
yukon: cp pacct1 nqacct1 $TMPDIR/acct/day
yukon: cp Puptime1       $TMPDIR/acct/nite/Puptime
yukon: csarun.short		# A stripped down csarun command
Wed Apr  5 10:27:48 AKDT 2000 - starting accounting
Wed Apr  5 10:27:53 AKDT 2000 - SETUP: setup complete
Wed Apr  5 10:27:55 AKDT 2000 - VERIFY: verification complete
Wed Apr  5 10:27:56 AKDT 2000 - PREPROC: preprocessing complete
Wed Apr  5 10:27:57 AKDT 2000 - BUILD: session accounting file complete
-rw-rw----   1 kcarlson staff          0 Apr  5 10:27 /tmp/kcarlson/acct/nite/Ebld.DDTT
-rw-rw----   1 kcarlson staff          0 Apr  5 10:27 /tmp/kcarlson/acct/nite/Enqs.DDTT
Wed Apr  5 10:27:57 AKDT 2000 - CLEANUP: cleanup complete
Wed Apr  5 10:27:57 AKDT 2000 - system accounting completed
yukon: cp $TMPDIR/AC.DD/TT/Super-record .

Compare the sizes of the pacct1, nqacct1, and Super-record files in with the original (W* and Super.org) files:

yukon: uals -Z
- 0640 kcarlson staff       8 000323.0001 Puptime1
- 0640 kcarlson staff    9168 000405.1028 Super-record
- 0640 kcarlson staff     15m 000323.0002 Super.org
- 0640 kcarlson staff    112k 000322.0001 Wnqacct.prv
- 0640 kcarlson staff    114k 000323.0001 Wnqacct1
- 0640 kcarlson staff      2m 000322.0003 Wpacct0
- 0640 kcarlson staff     14m 000323.0001 Wpacct1
- 0640 kcarlson staff    8315 000323.0005 j-20000323
- 0640 kcarlson staff    2584 000405.1026 nqacct1
- 0640 kcarlson staff    7192 000405.1027 pacct1

Report using `csagcon`, `csagfef`, and `nawk` (top, session, conclusion)

Reduce the Super-record with csagcon and report with csagfef. A second level of reporting is done with a nawk script.

yukon: SDIR=/usr/local/adm/sbin
yukon: /usr/lib/acct/csagcon -S Super-record -ujac -R $SDIR/csagcon.yukon -o csagcon.out
yukon: /usr/lib/acct/csagfef -f csagcon.out -D expan=1 -D jobid=1 -D peseg=0 \
                                                      $SDIR/csagfef.yukon   >csagfef.out
yukon: cat csagfef.out
#2000-04-05 10:31  report for sn6327 (2.0.5.21 unicosmk)
#2000-04-05 10:27  end, includes data for only Completed Sessions
#
#nq_quename            pm_t_pe_max  pb_t_    pm_t_pe  pm_t_pe nq_wall nq            nq_btime    nq_   nq_reqname
#                                  usr:time   _time    _ctime   clock _qwtime                   seqno
#                              PEs  CPUtime  MPPtime  DEDtime WallClk Q_Wait  Expan -- Queue --
#Queue Name  Project  Userid   max  (hours)  (hours)  (hours) (hours) seconds Fact. Date   Time SeqNo RequestName
#==========  =======  ======   ===  =======  =======  ======= ======= ======= ===== ===== ===== ===== ===========
gcp_xxlarge  ONRDCC29 bog03x    64  442.359  442.260  449.107  20.513   45600  2.61 03/21 04:49 57113 x64.3
Special      NWUMCD   myk31     64 1249.404 1249.403 1280.549  20.022   17179  1.31 03/21 12:07 57126 step2.runk
*root        root     .          0    0.000    0.000    0.000    .       .      .  
*minimum     minimum  .          2    0.000    0.000    0.000    .       .      .  
#                             ====  =======  =======  ======= ======= ======= =====
#     4:     2:nqs     0:tty     2   1691.8   1691.7   1729.7    40.5   62779  1.76
#cpu.gt.60 seconds
yukon: sort csagfef.out | nawk -f $SDIR/csanawk.yukon
#              num  exp Expan  CPUtime  MPPtime  DEDtime  PE-Rsrv Execute Q_Wait 
#Queue Name   jobs jobs Fact.  (hours)  (hours)  (hours)  (hours) (hours) (hours)
#==========   ==== ==== =====  =======  =======  =======  ======= ======= =======
gcp_xxlarge      1    1  2.61    0.099    442.3    449.1    502.2     7.8    12.7
Special          1    0   .      0.001   1249.4   1280.5   1280.5    15.3     4.8
*minimum         2    0   .      0.000      0.0      0.0      0.0     0.0     0.0
#==========   ==== ==== =====  =======  =======  =======  ======= ======= =======
#    4,0         4    1  2.61    0.100   1691.7   1729.7   1782.7    23.1    17.4

Conclusions on `nq_wallclock` discrepancy (top, session, report)

Note above with the nawk reporting that the myk31 job (Special queue) no longer has an expansion factor, what went wrong? Refering back to nqs accounting records:

#NQS     Time  /  jid:uid     /seqno/type:sub-type    machname reqname     quename
20000321@044920/    0:bog03x  /57113/RECV:New         yukon    x64.3       gcp             
20000321@044921/    0:bog03x  /57113/RECV:Local pipe  yukon    x64.3       gcp_xxlarge     
20000321@172920/23707:bog03x  /57113/INIT:started     yukon    x64.3       gcp_xxlarge     
20000322@012007/23707:bog03x  /57113/TERM:exited      yukon    x64.3       gcp_xxlarge     
  Execution time:  7.8 hours
  Time in system: 20.5 hours, reported nq_wallclock is 20.5 hours
  Queued time:    12.7 hours

#NQS     Time  /  jid:uid     /seqno/type:sub-type    machname reqname     quename
20000321@072109/    0:myk31   /57126/RECV:New         yukon    step2.runk  Special         
20000321@120728/22788:myk31   /57126/INIT:started     yukon    step2.runk  Special         
20000322@080847/22788:myk31   /57126/TERM:exited      yukon    step2.runk  Special         
  Execution time: 20.0 hours
  Time in system: 24.8 hours, reported nq_wallclock is 20.0 hours (incorrect!)
  Queued time:     4.8 hours

The myk31 job has an erroneous nq_wallclock excluding the queued time.
The csanawk.yukon script checks whether the maximum PEs * elapsed time is (must be) greater than or equal to the dedicated PE time, in the case of the myk31 job it was not so no expansion factor was calculated. The expansion factor reported with csagfef.yukon is incorrect.
Why is the nq_wallclock incorrect for myk31?
Both the myk31 and bog03x jobs spanned two csarun executions. The myk31 job did not go through a pipe queue, that appears to be the cause for mis-reporting nq_wallclock.

ARSC Making a Super-Record and Using csagfef

Overview (session, report, conclusion)

Making a "session file" or Super-record (top, report, conclusion)

Report using csagcon, csagfef, and nawk (top, session, conclusion)

Conclusions on nq_wallclock discrepancy (top, session, report)

ARSC Making a `Super-Record` and Using `csagfef`

Making a "session file" or `Super-record` (top, report, conclusion)

Report using `csagcon`, `csagfef`, and `nawk` (top, session, conclusion)

Conclusions on `nq_wallclock` discrepancy (top, session, report)