Hercules 3.12 (not 4.0) apparent HAO bug

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Hercules 3.12 (not 4.0) apparent HAO bug

Hercules390 - General mailing list
While doing some "unrelated" Hercules test,
I found the below issue in 3.07 & 3.12 which
appears to have been fixed in 4.0.

The problem is, that after successfully
triggering here:

12:14:37 01.14.37 STC   15  $HASP250 MOUNT    IS PURGED
12:14:37 HHCAO003I Firing command: 'script conf/subjobs2.rc'

If I then attempt the same trigger:

12:14:37 hao tgt HASP250 MOUNT
12:14:37 HHCAO016I Target placed at index 2
12:14:37 hao cmd script conf/termherc2.rc
12:14:37 HHCAO020I Command placed at index 2

It seems to immediately retrigger on the old
message, instead of waiting for a new
occurrence:

12:14:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
12:14:37 HHCAO003I Firing command: 'script conf/termherc2.rc'
12:14:37 script conf/termherc2.rc

Full log below.


Script subjobs2.rc is here:

hao clear

# If we get a prompt for a device, cancel it
hao tgt IEF238D
hao cmd script conf/cancel.rc

# If we get a prompt for a catalogue password, answer it
hao tgt IEC301A
hao cmd script conf/secret.rc


devinit 401 tapes/pctomf.tdf

# When we see TERMHERC get purged, our job is done
hao tgt HASP250 MOUNT
hao cmd script conf/termherc2.rc

# Now submit the job
devinit 00c jcl/hercauto.jcl eof



(Ignore the incorrect comments about TERMHERC)

Does anyone know what the fix was,
so that it can hopefully go into both
3.12 and my modified 3.07?

Thanks. Paul.




12:14:25 Hercules Version 3.12
12:14:25 (c)Copyright 1999-2015 by Roger Bowler, Jan Jaeger, and others
12:14:25 Built on Nov 26 2015 at 18:05:07
12:14:25 Build information:
12:14:25   Windows (MSVC) build for i386
12:14:25   Modes: S/370 ESA/390 z/Arch
12:14:25   Max CPU Engines: 8
12:14:25   Using fthreads instead of pthreads
12:14:25   Dynamic loading support
12:14:25   Using shared libraries
12:14:25   HTTP Server support
12:14:25   No SIGABEND handler
12:14:25   Regular Expressions support
12:14:25   Automatic Operator support
12:14:25   Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8 fetch_dw store_dw
12:14:25 Running on PAUL-DELL Windows_NT-6.2 i686 MP=8
12:14:25 HHCHD018I Loadable module directory is hercules
12:14:25 Crypto module loaded (c) Copyright Bernard van der Helm, 2003-2010
12:14:25   Active: Message Security Assist
12:14:25           Message Security Assist Extension 1
12:14:25           Message Security Assist Extension 2
12:14:25           Message Security Assist Extension 3
12:14:25           Message Security Assist Extension 4
12:14:25 HHCPN210I Default Allowed AUTOMOUNT directory = "c:\mvs380\"
12:14:25 HHCCF065I Hercules: tid=00004680, pid=16768, pgid=16768, priority=8
12:14:25 HHCHT001I HTTP listener thread started: tid=00004004, pid=16768
12:14:25 HHCHT013I Using HTTPROOT directory "c:\herc380\html\"
12:14:25 HHCHT006I Waiting for HTTP requests on port 8081
12:14:25 HHCSD004I Device 000C bound to socket 127.0.0.1:3505
12:14:25 HHCSD020I Socketdevice listener thread started: tid=00004AD4, pid=16768
12:14:25 HHCCF083I conf/mvs380.conf Including conf/mvs380_DASD.conf at 123 .
12:14:25 HHCDA004I opening dasd/mvsres.148 readonly
12:14:25 HHCDA020I dasd/mvsres.148 cyls=560 heads=30 tracks=16800 trklen=19456
12:14:25 HHCDA004I opening dasd/sort01.131 readonly
12:14:25 HHCDA020I dasd/sort01.131 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:25 HHCDA004I opening dasd/sort02.132 readonly
12:14:25 HHCDA020I dasd/sort02.132 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:25 HHCDA004I opening dasd/sort03.133 readonly
12:14:25 HHCDA020I dasd/sort03.133 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:25 HHCDA004I opening dasd/sort04.134 readonly
12:14:25 HHCDA020I dasd/sort04.134 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:25 HHCDA004I opening dasd/sort05.135 readonly
12:14:25 HHCDA020I dasd/sort05.135 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:25 HHCDA004I opening dasd/sort06.136 readonly
12:14:25 HHCDA020I dasd/sort06.136 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:25 HHCDA004I opening dasd/work00.140 readonly
12:14:25 HHCDA020I dasd/work00.140 cyls=560 heads=30 tracks=16800 trklen=19456
12:14:25 HHCDA020I dasd/hasp00.152 cyls=404 heads=19 tracks=7676 trklen=13312
12:14:25 HHCDA020I dasd/page00.160 cyls=698 heads=12 tracks=8376 trklen=8704
12:14:25 HHCDA020I dasd/page01.161 cyls=698 heads=12 tracks=8376 trklen=8704
12:14:25 HHCDA020I dasd/page02.162 cyls=698 heads=12 tracks=8376 trklen=8704
12:14:25 HHCDA020I dasd/work01.170 cyls=962 heads=12 tracks=11544 trklen=35840
12:14:25 HHCDA004I opening dasd/work02.180 readonly
12:14:25 HHCDA020I dasd/work02.180 cyls=886 heads=15 tracks=13290 trklen=47616
12:14:25 HHCDA004I opening dasd/work03.190 readonly
12:14:25 HHCDA020I dasd/work03.190 cyls=1114 heads=15 tracks=16710 trklen=56832
12:14:25 HHCDA004I opening dasd/mvscat.191 readonly
12:14:25 HHCDA020I dasd/mvscat.191 cyls=1114 heads=15 tracks=16710 trklen=56832
12:14:25 HHCDA004I opening dasd/seasik.192 readonly
12:14:25 HHCDA020I dasd/seasik.192 cyls=1114 heads=15 tracks=16710 trklen=56832
12:14:25 HHCDA020I dasd/mvssrc.193 cyls=2226 heads=15 tracks=33390 trklen=56832
12:14:26 HHCDA002E 01B4:File not found or invalid 'dasd/pub004.1b4'
12:14:26 HHCCF044E Initialization failed for device 01B4
12:14:26 HHCDA004I opening dasd/pub000.240 readonly
12:14:26 HHCDA020I dasd/pub000.240 cyls=560 heads=30 tracks=16800 trklen=19456
12:14:26 HHCDA004I opening dasd/mvsdlb.248 readonly
12:14:26 HHCDA020I dasd/mvsdlb.248 cyls=560 heads=30 tracks=16800 trklen=19456
12:14:26 HHCDA004I opening dasd/pub002.280 readonly
12:14:26 HHCDA020I dasd/pub002.280 cyls=1772 heads=15 tracks=26580 trklen=47616
12:14:26 HHCDA004I opening dasd/tmptmp.2b1 readonly
12:14:26 HHCDA020I dasd/tmptmp.2b1 cyls=1114 heads=15 tracks=16710 trklen=56832
12:14:26 HHCDA004I opening dasd/xmit90.2b2 readonly
12:14:26 HHCDA020I dasd/xmit90.2b2 cyls=1114 heads=15 tracks=16710 trklen=56832
12:14:26 HHCDA004I opening dasd/start1.150 readonly
12:14:26 HHCDA020I dasd/start1.150 cyls=808 heads=19 tracks=15352 trklen=13312
12:14:26 HHCDA004I opening dasd/spool0.151 readonly
12:14:26 HHCDA020I dasd/spool0.151 cyls=808 heads=19 tracks=15352 trklen=13312
12:14:26 HHCDA004I opening dasd/cbt000.340 readonly
12:14:26 HHCDA020I dasd/cbt000.340 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/cbt001.341 readonly
12:14:26 HHCDA020I dasd/cbt001.341 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/cbt002.342 readonly
12:14:26 HHCDA020I dasd/cbt002.342 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/cbtcat.343 readonly
12:14:26 HHCDA020I dasd/cbtcat.343 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/src000.348 readonly
12:14:26 HHCDA020I dasd/src000.348 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/src001.349 readonly
12:14:26 HHCDA020I dasd/src001.349 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/src002.34a readonly
12:14:26 HHCDA020I dasd/src002.34a cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/srccat.34b readonly
12:14:26 HHCDA020I dasd/srccat.34b cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/smp001.149 readonly
12:14:26 HHCDA020I dasd/smp001.149 cyls=560 heads=30 tracks=16800 trklen=19456
12:14:26 HHCDA004I opening dasd/smp002.14a readonly
12:14:26 HHCDA020I dasd/smp002.14a cyls=560 heads=30 tracks=16800 trklen=19456
12:14:26 HHCDA004I opening dasd/smp003.14b readonly
12:14:26 HHCDA020I dasd/smp003.14b cyls=560 heads=30 tracks=16800 trklen=19456
12:14:26 HHCDA004I opening dasd/smp004.14c readonly
12:14:26 HHCDA020I dasd/smp004.14c cyls=560 heads=30 tracks=16800 trklen=19456
12:14:26 HHCDA004I opening dasd/js2sp0.700 readonly
12:14:26 HHCDA020I dasd/js2sp0.700 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/dlicat.138 readonly
12:14:26 HHCDA020I dasd/dlicat.138 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:26 HHCDA004I opening dasd/dlisys.139 readonly
12:14:26 HHCDA020I dasd/dlisys.139 cyls=200 heads=20 tracks=4000 trklen=7680
12:14:26 HHCDA004I opening dasd/dli000.13a readonly
12:14:26 HHCDA020I dasd/dli000.13a cyls=200 heads=20 tracks=4000 trklen=7680
12:14:26 HHCDA004I opening dasd/dli001.13b readonly
12:14:26 HHCDA020I dasd/dli001.13b cyls=200 heads=20 tracks=4000 trklen=7680
12:14:26 HHCDA004I opening dasd/dli002.13c readonly
12:14:26 HHCDA020I dasd/dli002.13c cyls=200 heads=20 tracks=4000 trklen=7680
12:14:26 HHCDA004I opening dasd/js3sp0.710 readonly
12:14:26 HHCDA020I dasd/js3sp0.710 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCDA004I opening dasd/js3res.711 readonly
12:14:26 HHCDA020I dasd/js3res.711 cyls=555 heads=30 tracks=16650 trklen=19456
12:14:26 HHCTE001I Console connection thread started: tid=0000476C, pid=16768
12:14:26 HHCTE003I Waiting for console connection on port 3270
12:14:26 HHCTA066I 0400: option 'level' accepted.
12:14:26 HHCTA066I 0401: option 'level' accepted.
12:14:26 HHCTA066I 0402: option 'level' accepted.
12:14:26 HHCTA066I 0403: option 'level' accepted.
12:14:26 HHCCP002I CPU0000 thread started: tid=00003164, pid=16768, priority=0
12:14:26 HHCCP003I CPU0000 architecture mode S/370
12:14:26 HHCTT002I Timer thread started: tid=000033F4, pid=16768, priority=-20
12:14:26 HHCPN001I Control panel thread started: tid=00004680, pid=16768
12:14:26 HHCPN008I Script file processing started using file "conf/auto_run.rc"
12:14:26 devlist
12:14:26 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof
12:14:26      (no one currently connected)
12:14:26 0:000D 3525 pch/pch00d.txt ascii crlf
12:14:26 0:000E 1403 prt/prt00e.txt crlf noclear print fcbck
12:14:26 0:000F 1403 prt/prt00f.txt crlf noclear print fcbck
12:14:26 0:001F 3215 *syscons cmdpref(/)
12:14:26 0:00C0 3270  
12:14:26 0:00C1 3270  
12:14:26 0:00C2 3270  
12:14:26 0:00C7 3287  
12:14:26 0:010C 3505 jcl/dummy eof
12:14:26 0:0131 2314 dasd/sort01.131 [200 cyls] open
12:14:26 0:0132 2314 dasd/sort02.132 [200 cyls] open
12:14:26 0:0133 2314 dasd/sort03.133 [200 cyls] open
12:14:26 0:0134 2314 dasd/sort04.134 [200 cyls] open
12:14:26 0:0135 2314 dasd/sort05.135 [200 cyls] open
12:14:26 0:0136 2314 dasd/sort06.136 [200 cyls] open
12:14:26 0:0138 2314 dasd/dlicat.138 [200 cyls] open
12:14:26 0:0139 2314 dasd/dlisys.139 [200 cyls] open
12:14:26 0:013A 2314 dasd/dli000.13a [200 cyls] open
12:14:26 0:013B 2314 dasd/dli001.13b [200 cyls] open
12:14:26 0:013C 2314 dasd/dli002.13c [200 cyls] open
12:14:26 0:0140 3350 dasd/work00.140 [560 cyls] open
12:14:26 0:0148 3350 dasd/mvsres.148 [560 cyls] open
12:14:26 0:0149 3350 dasd/smp001.149 [560 cyls] open
12:14:26 0:014A 3350 dasd/smp002.14a [560 cyls] open
12:14:26 0:014B 3350 dasd/smp003.14b [560 cyls] open
12:14:26 0:014C 3350 dasd/smp004.14c [560 cyls] open
12:14:26 0:0150 3330 dasd/start1.150 [808 cyls] open
12:14:26 0:0151 3330 dasd/spool0.151 [808 cyls] open
12:14:26 0:0152 3330 dasd/hasp00.152 [404 cyls] open
12:14:26 0:0160 3340 dasd/page00.160 [698 cyls] open
12:14:26 0:0161 3340 dasd/page01.161 [698 cyls] open
12:14:26 0:0162 3340 dasd/page02.162 [698 cyls] open
12:14:26 0:0170 3375 dasd/work01.170 [962 cyls] open
12:14:26 0:01A0 3380 dasd/work02.180 [886 cyls] open
12:14:26 0:01B0 3390 dasd/work03.190 [1114 cyls] open
12:14:26 0:01B1 3390 dasd/mvscat.191 [1114 cyls] open
12:14:26 0:01B2 3390 dasd/seasik.192 [1114 cyls] open
12:14:26 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] open
12:14:26 0:01C7 3287  
12:14:26 0:0240 3350 dasd/pub000.240 [560 cyls] open
12:14:26 0:0248 3350 dasd/mvsdlb.248 [560 cyls] open
12:14:26 0:02A0 3380 dasd/pub002.280 [1772 cyls] open
12:14:26 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] open
12:14:26 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] open
12:14:26 0:030E 1403 log/hardcopy.log crlf noclear print fcbck
12:14:26 0:0340 3350 dasd/cbt000.340 [555 cyls] open
12:14:26 0:0341 3350 dasd/cbt001.341 [555 cyls] open
12:14:26 0:0342 3350 dasd/cbt002.342 [555 cyls] open
12:14:26 0:0343 3350 dasd/cbtcat.343 [555 cyls] open
12:14:26 0:0348 3350 dasd/src000.348 [555 cyls] open
12:14:26 0:0349 3350 dasd/src001.349 [555 cyls] open
12:14:26 0:034A 3350 dasd/src002.34a [555 cyls] open
12:14:26 0:034B 3350 dasd/srccat.34b [555 cyls] open
12:14:26 0:0400 3420 *
12:14:26 0:0401 3420 *
12:14:26 0:0402 3420 *
12:14:26 0:0403 3420 *
12:14:26 0:0700 3350 dasd/js2sp0.700 [555 cyls] open
12:14:26 0:0710 3350 dasd/js3sp0.710 [555 cyls] open
12:14:26 0:0711 3350 dasd/js3res.711 [555 cyls] open
12:14:26 logopt timestamp
12:14:26 HHCPN197I Log option set: TIMESTAMP
12:14:26 panrate 1000
12:14:26 # really need to wait for SVC120I, but if building MVS/380
12:14:26 # or some other stuffup with parms, need to trigger on an
12:14:26 # alternative. First one hit will clear targets.
12:14:26 # If we get a prompt for a device, cancel it
12:14:26 hao tgt IEF238D
12:14:26 HHCAO016I Target placed at index 0
12:14:26 hao cmd script conf/cancel.rc
12:14:26 HHCAO020I Command placed at index 0
12:14:26 hao tgt HASP395 DYNAMASK
12:14:26 HHCAO016I Target placed at index 1
12:14:26 hao cmd script conf/subjobs_slow.rc
12:14:26 HHCAO020I Command placed at index 1
12:14:26 hao tgt HASP373 SVC120I
12:14:26 HHCAO016I Target placed at index 2
12:14:26 hao cmd script conf/subjobs_fast.rc
12:14:26 HHCAO020I Command placed at index 2
12:14:26 hao tgt HASP436 REPLY
12:14:26 HHCAO016I Target placed at index 3
12:14:26 hao cmd script conf/replyy.rc
12:14:26 HHCAO020I Command placed at index 3
12:14:26 devinit 402 tapes/mftopc.het
12:14:26 HHCTA004I 0402: tapes/mftopc.het is a Hercules Emulated Tape file
12:14:26 HHCPN098I Device 0:0402 initialized
12:14:26 devinit 403 tapes/awstap.aws
12:14:26 HHCTA004I 0403: tapes/awstap.aws is a Hercules Emulated Tape file
12:14:26 HHCPN098I Device 0:0403 initialized
12:14:26 # co will give you a cold start of JES2 which is useful in
12:14:26 # automated runs
12:14:26 /(001F) r 00,clpa,cmd=co
12:14:26 #/r 00,clpa
12:14:26 ipl 148
12:14:26 HHCPN013I EOF reached on SCRIPT file. Processing complete.
12:14:26 HHCAO001I Hercules Automatic Operator thread started;
12:14:26           tid=00000608, pri=0, pid=16768
12:14:26 IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
12:14:26 HHCCD001I Readahead thread 1 started: tid=0000094C, pid=16768
12:14:26 HHCCD001I Readahead thread 2 started: tid=00003CE4, pid=16768
12:14:26 HHCCD002I Writer thread 1 started: tid=000047D4, pid=16768
12:14:26 HHCCD003I Garbage collector thread started: tid=00002E20, pid=16768
12:14:26 IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
12:14:26  PLPA ... SYS1.PAGELPA
12:14:26  COMMON . SYS1.PAGECSA
12:14:26  DUPLEX . SYS1.DUPLEX
12:14:26  LOCAL .. SYS1.PAGEL01
12:14:26  LOCAL .. SYS1.PAGEL02
12:14:26  LOCAL .. SYS1.PAGEL03
12:14:27 HHCCD002I Writer thread 2 started: tid=000039BC, pid=16768
12:14:31 *IEE362A SMF ENTER DUMP FOR SYS1.MANY ON MVSRES
12:14:31  IEE360I SMF NOW RECORDING ON SYS1.MANX ON MVSRES TIME=01.14.31
12:14:31  IGF992I  MIH INIT COMPLETE, PRI=000300, SEC=000015
12:14:32  IEF677I WARNING MESSAGE(S) FOR JOB JES2     ISSUED
12:14:32 *00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
12:14:32 HHCAO003I Firing command: 'script conf/replyy.rc'
12:14:32 script conf/replyy.rc
12:14:32 /(001F) reply 00,y
12:14:32 HHCPN013I EOF reached on SCRIPT file. Processing complete.
12:14:32  IEE600I REPLY TO 00 IS;SUPPRESSED
12:14:32  $HASP493 JES2 COLD-START IS IN PROGRESS
12:14:34  $HASP412 MAXIMUM OF 1   READER(S)  EXCEEDED
12:14:34 01.14.34           IEE041I THE SYSTEM LOG IS NOW ACTIVE
12:14:34 01.14.34           IEE302I 00E      ONLINE
12:14:34 01.14.34           IEE302I 00F      ONLINE
12:14:34 01.14.34           IEE313I 30E     UNIT REF INVALID
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           IEE450I 01.14.34 UNIT STATUS 161
12:14:34  UNIT TYPE STATUS  VOLSER VOLSTATE   UNIT TYPE STATUS  VOLSER VOLSTATE
12:14:34  400  3400 O                  /REMOV 401  3400 O                  /REMOV
12:14:34  402  3400 O                  /REMOV
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           IEE305I X        COMMAND INVALID
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP000 OK
12:14:34 01.14.34           $HASP160 PRINTER1 INACTIVE - CLASS=AP
12:14:34 01.14.34           $HASP160 PRINTER2 INACTIVE - CLASS=Z
12:14:34 01.14.34           $HASP160 PUNCH1   INACTIVE - CLASS=B
12:14:34 01.14.34 STC    2  $HASP100 INIT     ON STCINRDR
12:14:34 01.14.34 STC    2  $HASP373 INIT     STARTED
12:14:34 01.14.34 STC    2  IEF403I INIT - STARTED - TIME=01.14.34
12:14:34 01.14.34 STC    3  $HASP100 INIT     ON STCINRDR
12:14:34 01.14.34 STC    3  $HASP373 INIT     STARTED
12:14:34 01.14.34 STC    3  IEF403I INIT - STARTED - TIME=01.14.34
12:14:34 01.14.34 STC    4  $HASP100 INIT     ON STCINRDR
12:14:34 01.14.34 STC    4  $HASP373 INIT     STARTED
12:14:34 01.14.34 STC    4  IEF403I INIT - STARTED - TIME=01.14.34
12:14:34 01.14.34 STC    5  $HASP100 INIT     ON STCINRDR
12:14:34 01.14.34 STC    5  $HASP373 INIT     STARTED
12:14:34 01.14.34 STC    5  IEF403I INIT - STARTED - TIME=01.14.34
12:14:34 01.14.34 STC    6  $HASP100 INIT     ON STCINRDR
12:14:34 01.14.34 STC    6  $HASP373 INIT     STARTED
12:14:34 01.14.34 STC    6  IEF403I INIT - STARTED - TIME=01.14.34
12:14:34 01.14.34 STC    7  $HASP100 INIT     ON STCINRDR
12:14:35 01.14.35 STC    7  $HASP373 INIT     STARTED
12:14:35 01.14.35 STC    7  IEF403I INIT - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC    8  $HASP100 INIT     ON STCINRDR
12:14:35 01.14.35 STC    8  $HASP373 INIT     STARTED
12:14:35 01.14.35 STC    8  IEF403I INIT - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC    9  $HASP100 SVC120I  ON STCINRDR
12:14:35 01.14.35 STC    9  $HASP373 SVC120I  STARTED
12:14:35 HHCAO003I Firing command: 'script conf/subjobs_fast.rc'
12:14:35 script conf/subjobs_fast.rc
12:14:35 # Now we know that SVC120I has started. But due to some
12:14:35 # weird pausing, it may get locked out. So clear out
12:14:35 # other triggers and wait on this
12:14:35 hao clear
12:14:35 HHCAO022I All automatic operation rules cleared
12:14:35 hao tgt HASP250 SVC120I
12:14:35 HHCAO016I Target placed at index 0
12:14:35 hao cmd script conf/subjobs.rc
12:14:35 HHCAO020I Command placed at index 0
12:14:35 HHCPN013I EOF reached on SCRIPT file. Processing complete.
12:14:35 01.14.35 STC    9  IEF403I SVC120I - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC   10  $HASP100 DYNAMASK ON STCINRDR
12:14:35 01.14.35 STC   10  $HASP373 DYNAMASK STARTED
12:14:35 01.14.35 STC   10  IEF403I DYNAMASK - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC   11  $HASP100 BSPPILOT ON STCINRDR
12:14:35 01.14.35 STC   11  $HASP373 BSPPILOT STARTED
12:14:35 01.14.35 STC   11  IEF403I BSPPILOT - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC   12  $HASP100 BSPSETPF ON STCINRDR
12:14:35 01.14.35 STC   12  $HASP373 BSPSETPF STARTED
12:14:35 01.14.35 STC   12  IEF403I BSPSETPF - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC   13  $HASP100 LOGRECI  ON STCINRDR
12:14:35 01.14.35 STC   13  $HASP373 LOGRECI  STARTED
12:14:35 01.14.35 STC   13  IEF403I LOGRECI - STARTED - TIME=01.14.35
12:14:35 01.14.35 STC   14  $HASP100 NET      ON STCINRDR
12:14:35 01.14.35 STC   14  $HASP373 NET      STARTED
12:14:35 01.14.35 STC   14  IEF403I NET - STARTED - TIME=01.14.35
12:14:35 01.14.35           $HASP309    INIT  1 INACTIVE ******** C=A
12:14:35 01.14.35           $HASP309    INIT  2 INACTIVE ******** C=BA
12:14:35 01.14.35           $HASP309    INIT  3 INACTIVE ******** C=CBA
12:14:35 01.14.35           $HASP309    INIT  4 INACTIVE ******** C=SHB
12:14:35 01.14.35           $HASP309    INIT  5 INACTIVE ******** C=SBA
12:14:35 01.14.35           $HASP309    INIT  6 INACTIVE ******** C=S
12:14:35 01.14.35           $HASP309    INIT  7 INACTIVE ******** C=E
12:14:35 01.14.35 STC    9  BSPGM39E - Hercules and MVS 380 mods required
12:14:35 01.14.35 STC   14  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
12:14:35 01.14.35 STC   14  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
12:14:35 01.14.35 STC   14  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
12:14:35 01.14.35 STC   14  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
12:14:35 01.14.35 STC   14  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
12:14:35 01.14.35 STC   14  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
12:14:35 01.14.35 STC   14  IST110I  NETWORK SOLICITOR STARTED
12:14:35 01.14.35 STC   14  IST093I  APPLJRP  ACTIVE
12:14:35 01.14.35 STC   14  IST093I  APPLPIES ACTIVE
12:14:35 01.14.35 STC   14  IST093I  APPLPIAD ACTIVE
12:14:35 01.14.35 STC   14  IST093I  APPLTSO  ACTIVE
12:14:35 01.14.35 STC   14  IST093I  APPLTEST ACTIVE
12:14:35 01.14.35 STC   14  IST093I  LCLMAJRP ACTIVE
12:14:35 01.14.35 STC    9  IEF404I SVC120I - ENDED - TIME=01.14.35
12:14:35 01.14.35 STC    9  $HASP395 SVC120I  ENDED
12:14:35 01.14.35 STC    9  $HASP150 SVC120I  ON PRINTER2        41 LINES
12:14:35 01.14.35 STC    9 *$HASP190 SVC120I  SETUP -- PRINTER2 -- F = 0001 -- C = 6    -- T = SN
12:14:35 01.14.35           $HASP000 OK
12:14:35 01.14.35           $HASP160 PRINTER2 INACTIVE - CLASS=Z
12:14:35 01.14.35 STC    9  $HASP250 SVC120I  IS PURGED
12:14:35 HHCAO003I Firing command: 'script conf/subjobs.rc'
12:14:35 script conf/subjobs.rc
12:14:35 hao clear
12:14:35 HHCAO022I All automatic operation rules cleared
12:14:36 # Every job gets an NL tape available as input, containing
12:14:36 # some binary of unknown contents, most likely needing to
12:14:36 # be read as RECFM=U, but RECFM=FB and even RECFM=V are also
12:14:36 # possible.
12:14:36 #
12:14:36 # The job also gets an SL tape available for output, and
12:14:36 # again, any type of content can be written to it, and
12:14:36 # with a bit of luck, hetget will be able to extract the
12:14:36 # data you are looking for.
12:14:36 #
12:14:36 # And finally the job gets an SL AWS tape available for
12:14:36 # input and/or output should you wish to construct a
12:14:36 # special tape. Tape must be called AWSTAP. User should
12:14:36 # back the tape up before submitting it, because it will
12:14:36 # be overwritten and anything could go wrong. AWS is
12:14:36 # expected to be exceptional use of this procedure anyway
12:14:36 #
12:14:36 # Only the NL tape needs an explicit mount. The SL tapes
12:14:36 # are premounted before IPL
12:14:36 hao tgt HASP250 MOUNT
12:14:36 HHCAO016I Target placed at index 0
12:14:36 hao cmd script conf/subjobs2.rc
12:14:36 HHCAO020I Command placed at index 0
12:14:36 /(001F) M 401,VOL=(NL,PCTOMF)
12:14:36 HHCPN013I EOF reached on SCRIPT file. Processing complete.
12:14:36 01.14.36 STC   15  $HASP100 MOUNT    ON STCINRDR
12:14:36 01.14.36 STC   15  $HASP373 MOUNT    STARTED
12:14:36 01.14.36 STC   15  IEF403I MOUNT - STARTED - TIME=01.14.36
12:14:36 01.14.36 STC   14  IST093I  LCLMAJ00 ACTIVE
12:14:36 01.14.36 STC   15 *IEF233A M 401,PCTOMF,,MOUNT,401
12:14:36 01.14.36 STC   16  $HASP100 TSO      ON STCINRDR
12:14:36 01.14.36 STC   16  $HASP373 TSO      STARTED
12:14:36 01.14.36 STC   16  IEF403I TSO - STARTED - TIME=01.14.36
12:14:36 01.14.36 STC   17  $HASP100 JRP      ON STCINRDR
12:14:36 01.14.36 STC   17  $HASP373 JRP      STARTED
12:14:36 01.14.36 STC   17  IEF403I JRP - STARTED - TIME=01.14.36
12:14:36 01.14.36           $HASP000 OK
12:14:36 01.14.36           $HASP000 OK
12:14:36 01.14.36 STC   14  IST020I  VTAM INITIALIZATION COMPLETE
12:14:36 01.14.36 STC   14  IEA000I 0C1,IOE,05,0200,400000000001,,,NET     ,01.14.36
12:14:36 01.14.36 STC   14  IEA000I 0C0,IOE,05,0200,400000000001,,,NET     ,01.14.36
12:14:36 01.14.36 STC   14  IEA000I 0C2,IOE,05,0200,400000000001,,,NET     ,01.14.36
12:14:36 01.14.36 STC   10  DMSK00I DYNAMASK DONE ****
12:14:36 01.14.36 STC   10  DMSK06I  START
12:14:36 01.14.36 STC   10  IEF404I DYNAMASK - ENDED - TIME=01.14.36
12:14:36 01.14.36 STC   10  $HASP395 DYNAMASK ENDED
12:14:36 01.14.36 STC   10  $HASP150 DYNAMASK ON PRINTER2        30 LINES
12:14:36 01.14.36           $HASP160 PRINTER2 INACTIVE - CLASS=Z
12:14:36 01.14.36 STC   10  $HASP250 DYNAMASK IS PURGED
12:14:36 01.14.36 STC   12  BSPSP91I - Parms passed: NOREPLYU
12:14:36 01.14.36 STC   12  BSPSP93I - PFK definitions will be updated in memory
12:14:36 01.14.36 STC   12  BSPSP22I - Dataset processed: SYS1.PARMLIB
12:14:36 01.14.36 STC   12  BSPSP23I - on volume MVSRES
12:14:36 01.14.36 STC   12  BSPSP21I - Member being processed: SETPFK01
12:14:36 01.14.36 STC   12  +BSPSP98I - Member processed, LASTCC=0000
12:14:36 01.14.36 STC   12  +BSPSP21I - Member being processed: SETPFK02
12:14:36 01.14.36 STC   12  +BSPSP98I - Member processed, LASTCC=0000
12:14:36 01.14.36 STC   12  +BSPSP99I - End of processing, MAXRC=0000
12:14:36 01.14.36 STC   12  IEF404I BSPSETPF - ENDED - TIME=01.14.36
12:14:36 01.14.36 STC   12  $HASP395 BSPSETPF ENDED
12:14:36 01.14.36 STC   12  $HASP150 BSPSETPF ON PRINTER2        34 LINES
12:14:36 01.14.36           $HASP160 PRINTER2 INACTIVE - CLASS=Z
12:14:36 01.14.36 STC   12  $HASP250 BSPSETPF IS PURGED
12:14:36 01.14.36 STC   13  IFC001I  D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
12:14:36 01.14.36 STC   13  IEF404I LOGRECI - ENDED - TIME=01.14.36
12:14:36 01.14.36 STC   13  $HASP395 LOGRECI  ENDED
12:14:36 01.14.36 STC   13  $HASP150 LOGRECI  ON PRINTER2        20 LINES
12:14:36 01.14.36           $HASP160 PRINTER2 INACTIVE - CLASS=Z
12:14:36 01.14.36 STC   13  $HASP250 LOGRECI  IS PURGED
12:14:36 01.14.36 STC   15  IEF404I MOUNT - ENDED - TIME=01.14.36
12:14:36 01.14.36 STC   15  $HASP395 MOUNT    ENDED
12:14:36 01.14.36 STC   15  $HASP150 MOUNT    ON PRINTER2        18 LINES
12:14:37 01.14.37           $HASP160 PRINTER2 INACTIVE - CLASS=Z
12:14:37 01.14.37 STC   15  $HASP250 MOUNT    IS PURGED
12:14:37 HHCAO003I Firing command: 'script conf/subjobs2.rc'
12:14:37 script conf/subjobs2.rc
12:14:37 hao clear
12:14:37 HHCAO022I All automatic operation rules cleared
12:14:37 # If we get a prompt for a device, cancel it
12:14:37 hao tgt IEF238D
12:14:37 HHCAO016I Target placed at index 0
12:14:37 hao cmd script conf/cancel.rc
12:14:37 HHCAO020I Command placed at index 0
12:14:37 # If we get a prompt for a catalogue password, answer it
12:14:37 hao tgt IEC301A
12:14:37 HHCAO016I Target placed at index 1
12:14:37 hao cmd script conf/secret.rc
12:14:37 HHCAO020I Command placed at index 1
12:14:37 devinit 401 tapes/pctomf.tdf
12:14:37 HHCTA004I 0401: tapes/pctomf.tdf is a Optical Media Attachment (OMA) tape
12:14:37 HHCPN098I Device 0:0401 initialized
12:14:37 # When we see TERMHERC get purged, our job is done
12:14:37 hao tgt HASP250 MOUNT
12:14:37 HHCAO016I Target placed at index 2
12:14:37 hao cmd script conf/termherc2.rc
12:14:37 HHCAO020I Command placed at index 2
12:14:37 # Now submit the job
12:14:37 devinit 00c jcl/hercauto.jcl eof
12:14:37 HHCSD007I Device 000C unbound from socket 127.0.0.1:3505
12:14:37 HHCSD022I Socketdevice listener thread terminated
12:14:37 HHCPN098I Device 0:000C initialized
12:14:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
12:14:37 HHCAO003I Firing command: 'script conf/termherc2.rc'
12:14:37 script conf/termherc2.rc
12:14:37 # we put in an unnecessary "stopall" to prevent Hercules
12:14:37 # (3.07 and 3.12 at least) from randomly hanging in the
12:14:37 # "quit" command in about 5% of runs.
12:14:37 # It is still unclear why Hercules is hanging
12:14:37 stopall
12:14:37 quit
12:14:37 HHCIN900I Begin Hercules shutdown
12:14:37 HHCIN901I Releasing configuration
12:14:37 HHCCP008I CPU0000 thread ended: tid=00003164, pid=16768
12:14:37 HHCCF047I Subchannel 0:0000 detached
12:14:37 HHCTT003I Timer thread ended
12:14:37 HHCCF047I Subchannel 0:0001 detached
12:14:37 HHCCF047I Subchannel 0:0002 detached
12:14:37 HHCCF047I Subchannel 0:0003 detached
12:14:37 HHCCF047I Subchannel 0:0004 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD211I                                                  readaheads   misses
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   19154590   4%   14       1095     144      36     931     1873
12:14:37 HHCCD214I                                                         155       29
12:14:37 HHCCD215I dasd/mvsres.148
12:14:37 HHCCD216I [0]   15179178   0%    1 ro     917       0      17
12:14:37 HHCCD217I shadow/mvsres_*.148
12:14:37 HHCCD218I [1]    3975412  16%   13        178     144      19
12:14:37 HHCCF047I Subchannel 0:0005 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/sort01.131
12:14:37 HHCCD216I [0]      34336   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/sort01_*.131
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0006 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/sort02.132
12:14:37 HHCCD216I [0]      34336   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/sort02_*.132
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0007 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/sort03.133
12:14:37 HHCCD216I [0]      34336   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/sort03_*.133
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0008 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/sort04.134
12:14:37 HHCCD216I [0]      34336   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/sort04_*.134
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0009 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/sort05.135
12:14:37 HHCCD216I [0]      34336   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/sort05_*.135
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:000A detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/sort06.136
12:14:37 HHCCD216I [0]      34336   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/sort06_*.136
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:000B detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   51370780   0%    1          1       0       2       0        1
12:14:37 HHCCD215I dasd/work00.140
12:14:37 HHCCD216I [0]     141963   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/work00_*.140
12:14:37 HHCCD218I [1]   51228817   0%    0          0       0       1
12:14:37 HHCCF047I Subchannel 0:000C detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    4837580   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/hasp00.152
12:14:37 HHCCD216I [0]    4837580   0%    0 rw       1       0       1
12:14:37 HHCCF047I Subchannel 0:000D detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD211I                                                  readaheads   misses
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   14444625  39%  390       1823    1382      10    1075     2335
12:14:37 HHCCD214I                                                         563       55
12:14:37 HHCCD215I dasd/page00.160
12:14:37 HHCCD216I [0]   14444625  39%  390 rw    1823    1382      10
12:14:37 HHCCF047I Subchannel 0:000E detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD211I                                                  readaheads   misses
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    3957659  17%   49         46    1811      32      35       56
12:14:37 HHCCD214I                                                          25        2
12:14:37 HHCCD215I dasd/page01.161
12:14:37 HHCCD216I [0]    3957659  17%   49 rw      46    1811      32
12:14:37 HHCCF047I Subchannel 0:000F detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD211I                                                  readaheads   misses
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    3455049  10%   50         40     401      19      28       53
12:14:37 HHCCD214I                                                          15        1
12:14:37 HHCCD215I dasd/page02.162
12:14:37 HHCCD216I [0]    3455049  10%   50 rw      40     401      19
12:14:37 HHCCF047I Subchannel 0:0010 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   56089225   0%    2          1       0       1       0        1
12:14:37 HHCCD215I dasd/work01.170
12:14:37 HHCCD216I [0]   56089225   0%    2 rw       1       0       1
12:14:37 HHCCF047I Subchannel 0:0011 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   65313171   0%    3          1       0       2       0        1
12:14:37 HHCCD215I dasd/work02.180
12:14:37 HHCCD216I [0]     113799   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/work02_*.180
12:14:37 HHCCD218I [1]   65199372   0%    2          0       0       1
12:14:37 HHCCF047I Subchannel 0:0012 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   55237069   0%    3          1       0       2       0        1
12:14:37 HHCCD215I dasd/work03.190
12:14:37 HHCCD216I [0]     142257   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/work03_*.190
12:14:37 HHCCD218I [1]   55094812   0%    2          0       0       1
12:14:37 HHCCF047I Subchannel 0:0013 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   15481595   0%    2          4       0       3       0        4
12:14:37 HHCCD215I dasd/mvscat.191
12:14:37 HHCCD216I [0]    3658727   0%    1 ro       3       0       2
12:14:37 HHCCD217I shadow/mvscat_*.191
12:14:37 HHCCD218I [1]   11822868   0%    1          1       0       1
12:14:37 HHCCF047I Subchannel 0:0014 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]  103500159  17% 1297          1       0       2       0        1
12:14:37 HHCCD215I dasd/seasik.192
12:14:37 HHCCD216I [0]   16164960   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/seasik_*.192
12:14:37 HHCCD218I [1]   87335199  20% 1297          0       0       1
12:14:37 HHCCF047I Subchannel 0:0015 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]  168333900   4% 5454          1       0       1       0        1
12:14:37 HHCCD215I dasd/mvssrc.193
12:14:37 HHCCD216I [0]  168333900   4% 5454 rw       1       0       1
12:14:37 HHCCF047I Subchannel 0:0016 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD211I                                                  readaheads   misses
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   43468834   0%    3         25       0       8      11       32
12:14:37 HHCCD214I                                                           4        2
12:14:37 HHCCD215I dasd/pub000.240
12:14:37 HHCCD216I [0]    7591138   3%    1 ro      10       0       4
12:14:37 HHCCD217I shadow/pub000_*.240
12:14:37 HHCCD218I [1]   35877696   0%    2         15       0       4
12:14:37 HHCCF047I Subchannel 0:0017 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   25746441   0%    2          5      24       5       1        6
12:14:37 HHCCD215I dasd/mvsdlb.248
12:14:37 HHCCD216I [0]   25471539   0%    1 ro       3       0       3
12:14:37 HHCCD217I shadow/mvsdlb_*.248
12:14:37 HHCCD218I [1]     274902  35%    1          2      24       2
12:14:37 HHCCF047I Subchannel 0:0018 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]  100064666   8%  539          1       0       2       0        1
12:14:37 HHCCD215I dasd/pub002.280
12:14:37 HHCCD216I [0]    2171954  29%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/pub002_*.280
12:14:37 HHCCD218I [1]   97892712   8%  538          0       0       1
12:14:37 HHCCF047I Subchannel 0:0019 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]     143545   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/tmptmp.2b1
12:14:37 HHCCD216I [0]     142257   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/tmptmp_*.2b1
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:001A detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]     143545   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/xmit90.2b2
12:14:37 HHCCD216I [0]     142257   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/xmit90_*.2b2
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:001B detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    6099280   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/start1.150
12:14:37 HHCCD216I [0]    6098016   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/start1_*.150
12:14:37 HHCCD218I [1]       1264   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:001C detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    4595678   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/spool0.151
12:14:37 HHCCD216I [0]    4594414   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/spool0_*.151
12:14:37 HHCCD218I [1]       1264   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:001D detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   50622559   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/cbt000.340
12:14:37 HHCCD216I [0]   50621271   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/cbt000_*.340
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:001E detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   53836805   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/cbt001.341
12:14:37 HHCCD216I [0]   53835517   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/cbt001_*.341
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:001F detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   46082980   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/cbt002.342
12:14:37 HHCCD216I [0]   46081692   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/cbt002_*.342
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0020 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   27241782   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/cbtcat.343
12:14:37 HHCCD216I [0]   27240494   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/cbtcat_*.343
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0021 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   46003602   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/src000.348
12:14:37 HHCCD216I [0]   46002314   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/src000_*.348
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0022 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   45707725   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/src001.349
12:14:37 HHCCD216I [0]   45706437   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/src001_*.349
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0023 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]   44403653   0%    0          1       0       1       0        1
12:14:37 HHCCD215I dasd/src002.34a
12:14:37 HHCCD216I [0]   44402365   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/src002_*.34a
12:14:37 HHCCD218I [1]       1288   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:0024 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    6321674   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/srccat.34b
12:14:37 HHCCD216I [0]    6310767   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/srccat_*.34b
12:14:37 HHCCD218I [1]      10907   7%    1          0       0       0
12:14:37 HHCCF047I Subchannel 0:0025 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    1118801  11%    2          1       0       2       0        1
12:14:37 HHCCD215I dasd/smp001.149
12:14:37 HHCCD216I [0]     774654   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/smp001_*.149
12:14:37 HHCCD218I [1]     344147  38%    2          0       0       1
12:14:37 HHCCF047I Subchannel 0:0026 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    1621663  24%   12          1       0       2       0        1
12:14:37 HHCCD215I dasd/smp002.14a
12:14:37 HHCCD216I [0]     856740   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/smp002_*.14a
12:14:37 HHCCD218I [1]     764923  51%   12          0       0       1
12:14:37 HHCCF047I Subchannel 0:0027 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    1077383  19%    3          1       0       2       0        1
12:14:37 HHCCD215I dasd/smp003.14b
12:14:37 HHCCD216I [0]     592555   0%    0 ro       1       0       1
12:14:37 HHCCD217I shadow/smp003_*.14b
12:14:37 HHCCD218I [1]     484828  42%    3          0       0       1
12:14:37 HHCCF047I Subchannel 0:0028 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    3437923  36%    4          1       0       2       0        1
12:14:37 HHCCD215I dasd/smp004.14c
12:14:37 HHCCD216I [0]    2916431  35%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/smp004_*.14c
12:14:37 HHCCD218I [1]     521492  41%    3          0       0       1
12:14:37 HHCCF047I Subchannel 0:0029 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD211I                                                  readaheads   misses
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    4078967  17%   79        109    3369      66     554      637
12:14:37 HHCCD214I                                                          28        6
12:14:37 HHCCD215I dasd/js2sp0.700
12:14:37 HHCCD216I [0]     142291   0%    1 ro       0       0       1
12:14:37 HHCCD217I shadow/js2sp0_*.700
12:14:37 HHCCD218I [1]    3936676  18%   78        109    3369      65
12:14:37 HHCCF047I Subchannel 0:002A detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]     715081   0%    1          1       0       2       0        1
12:14:37 HHCCD215I dasd/dlicat.138
12:14:37 HHCCD216I [0]      36630   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/dlicat_*.138
12:14:37 HHCCD218I [1]     678451   0%    0          0       0       1
12:14:37 HHCCF047I Subchannel 0:002B detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]     880289   0%    1          1       0       2       0        1
12:14:37 HHCCD215I dasd/dlisys.139
12:14:37 HHCCD216I [0]      36630   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/dlisys_*.139
12:14:37 HHCCD218I [1]     843659   0%    0          0       0       1
12:14:37 HHCCF047I Subchannel 0:002C detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      43495   0%    1          1       0       2       0        1
12:14:37 HHCCD215I dasd/dli000.13a
12:14:37 HHCCD216I [0]      36630   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/dli000_*.13a
12:14:37 HHCCD218I [1]       6865   0%    0          0       0       1
12:14:37 HHCCF047I Subchannel 0:002D detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      46911   0%    1          1       0       2       0        1
12:14:37 HHCCD215I dasd/dli001.13b
12:14:37 HHCCD216I [0]      36630   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/dli001_*.13b
12:14:37 HHCCD218I [1]      10281   0%    0          0       0       1
12:14:37 HHCCF047I Subchannel 0:002E detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]      37718   0%    1          1       0       1       0        1
12:14:37 HHCCD215I dasd/dli002.13c
12:14:37 HHCCD216I [0]      36630   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/dli002_*.13c
12:14:37 HHCCD218I [1]       1088   0%    0          0       0       0
12:14:37 HHCCF047I Subchannel 0:002F detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]    1233964   0%    1          1       0       2       0        1
12:14:37 HHCCD215I dasd/js3sp0.710
12:14:37 HHCCD216I [0]     141965   0%    1 ro       1       0       1
12:14:37 HHCCD217I shadow/js3sp0_*.710
12:14:37 HHCCD218I [1]    1091999   0%    0          0       0       1
12:14:37 HHCCF047I Subchannel 0:0030 detached
12:14:37 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
12:14:37 HHCCD212I --------------------------------------------------------------------
12:14:37 HHCCD213I [*]     951745   0%    2          1       0       2       0        1
12:14:37 HHCCD215I dasd/js3res.711
12:14:37 HHCCD216I [0]     142093   0%    2 ro       1       0       1
12:14:37 HHCCD217I shadow/js3res_*.711
12:14:37 HHCCD218I [1]     809652   0%    0          0       0       1
12:14:37 HHCCD011I Readahead thread 2 stopping: tid=00003CE4, pid=16768
12:14:37 HHCCD011I Readahead thread 1 stopping: tid=0000094C, pid=16768
12:14:37 HHCCD013I Garbage collector thread stopping: tid=00002E20, pid=16768
12:14:37 HHCCD012I Writer thread 2 stopping: tid=000039BC, pid=16768
12:14:37 HHCCD012I Writer thread 1 stopping: tid=000047D4, pid=16768
12:14:37 HHCCF047I Subchannel 0:0031 detached
12:14:37 HHCCF047I Subchannel 0:0032 detached
12:14:37 HHCCF047I Subchannel 0:0033 detached
12:14:37 HHCCF047I Subchannel 0:0034 detached
12:14:37 HHCCF047I Subchannel 0:0035 detached
12:14:37 HHCCF047I Subchannel 0:0036 detached
12:14:37 HHCCF047I Subchannel 0:0037 detached
12:14:37 HHCTE004I Console connection thread terminated
12:14:37 HHCCF047I Subchannel 0:0038 detached
12:14:37 HHCCF047I Subchannel 0:0039 detached
12:14:37 HHCCF047I Subchannel 0:003A detached
12:14:37 HHCCF047I Subchannel 0:003B detached
12:14:37 HHCCF047I Subchannel 0:003C detached
12:14:37 HHCIN902I Configuration release complete
12:14:37 HHCIN903I Calling termination routines
12:14:37 HHCHD900I Begin shutdown sequence
12:14:37 HHCHD901I Calling panel_cleanup
12:14:37 HHCHD902I panel_cleanup complete
12:14:37 HHCHD901I Calling console_shutdown
12:14:37 HHCHD902I console_shutdown complete
12:14:37 HHCHD901I Calling term_sockdev
12:14:37 HHCHD902I term_sockdev complete
12:14:37 HHCHD901I Calling hdl_term
12:14:37 HHCHD950I Begin HDL termination sequence
12:14:37 HHCHD951I Calling module *Hercules cleanup routine
12:14:37 HHCHD952I Module *Hercules cleanup complete
12:14:37 HHCHD959I HDL Termination sequence complete
12:14:37 HHCHD902I hdl_term complete
12:14:37 HHCHD901I Calling logger_term
12:14:37 HHCLG014I logger thread terminating
Reply | Threaded
Open this post in threaded view
|

Re: Hercules 3.12 (not 4.0) apparent HAO bug

Hercules390 - General mailing list
---In [hidden email], <kerravon86@...> wrote :

> While doing some "unrelated" Hercules test,
> I found the below issue in 3.07 & 3.12 which
> appears to have been fixed in 4.0.

On the other hand, the "fix" in 4.0 may be
what triggered this problem:

https://groups.yahoo.com/neo/groups/hercules-390/conversations/messages/81558

BFN. Paul.