kerravon86@yahoo.com.au [hercules-390]
2017-03-11 07:14:52 UTC
Now that I have bypassed the "quit" bug
by doing a "stopall" before the quit, I am
able to massively thrash Hercules.
I have been running sets of 1200 runs
(ie IPLing MVS, running IEFBR14 and
then quitting).
So far I have run 7200 tests:
1200 tests:
1
0
0
0
0
2
and there have been 0 hangs in "quit".
However, there is a new issue that is
now brought more into focus. Sometimes
commands that I enter are not taking
effect.
As per above, in the first batch of 1200
I had 1 single case where the run failed
to finish because of a command not
taking.
Here is what a good run looks like:
17:55:32 hao tgt HASP250 MOUNT
17:55:32 HHCAO016I Target placed at index 0
17:55:32 hao cmd script conf/subjobs2.rc
17:55:32 HHCAO020I Command placed at index 0
17:55:32 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:32 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:32 06.55.32 STC 16 $HASP100 MOUNT ON STCINRDR
17:55:32 06.55.32 STC 16 $HASP373 MOUNT STARTED
17:55:32 06.55.32 STC 16 IEF403I MOUNT - STARTED - TIME=06.55.32
17:55:32 06.55.32 STC 16 *IEF233A M 401,PCTOMF,,MOUNT,401
17:55:32 06.55.32 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:32 06.55.32 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:32 06.55.32 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
And here is the bad run:
17:55:37 hao tgt HASP250 MOUNT
17:55:37 HHCAO016I Target placed at index 0
17:55:37 hao cmd script conf/subjobs2.rc
17:55:37 HHCAO020I Command placed at index 0
17:55:37 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
(full bad log below)
As you can see, the "MOUNT" process
is not started. As per full log, after some
time:
17:55:37 06.55.37 STC 17 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
18:08:34 /(001F) M 401,VOL=(NL,PCTOMF)
I manually issued the same MOUNT command
as the script, and this time Hercules accepted
it and the automated process ran to completion.
I initially suspected this:
17:55:37 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
ie an incoming message about BLDL
happening at the same time as the
script was still running. The bottom of
the script looks like this:
subjobs.rc:
...
# Only the NL tape needs an explicit mount. The SL tapes
# are premounted before IPL
hao tgt HASP250 MOUNT
hao cmd script conf/subjobs2.rc
/M 401,VOL=(NL,PCTOMF)
So you can see that the mount command
is issued right before the end of the
script, with no delays, but as per the
console output, there was a time delay
between the mount and end of script
long enough for an incoming message.
I was wondering whether I could solve
this problem by issuing two mounts
so that one of them could get lost. Or
maybe I could put a "stopall" before the
mount command and a "startall" after
it. I'm not sure what effect that has. I
am in fact surprised that at IPL time
I can have this in my script:
autoipl.rc:
...
/r 00,clpa
ipl 148
ie I am able to give Hercules the expected
response, before I've even IPLed!!! So maybe
Hercules knows how to buffer console input
or something, and maybe stopall will invoke
the same buffering?
Please see next message coming
shortly ...
BFN. Paul.
17:55:33 Hercules Version 3.07:380-4.x
17:55:33 (c)Copyright 1999-2010 by Roger Bowler, Jan Jaeger, and others
17:55:33 Built on Dec 7 2016 at 12:43:32
17:55:33 Build information:
17:55:33 Windows (MSVC) build for AMD64
17:55:33 Modes: S/370 S/380 ESA/390 z/Arch
17:55:33 Max CPU Engines: 8
17:55:33 Using fthreads instead of pthreads
17:55:33 Dynamic loading support
17:55:33 Using shared libraries
17:55:33 HTTP Server support
17:55:33 No SIGABEND handler
17:55:33 Regular Expressions support
17:55:33 Automatic Operator support
17:55:33 Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8
17:55:33 Running on PAUL-DELL Windows_NT-6.2 AMD64 MP=8
17:55:33 HHCHD018I Loadable module directory is hercules
17:55:33 Crypto module loaded (c) Copyright Bernard van der Helm, 2003-2010
17:55:33 Active: Message Security Assist
17:55:33 Message Security Assist Extension 1
17:55:33 Message Security Assist Extension 2
17:55:33 HHCPN210I Default Allowed AUTOMOUNT directory = "c:\mvs380\"
17:55:33 HHCHT001I HTTP listener thread started: tid=00003950, pid=12296
17:55:33 HHCCF065I Hercules: tid=00002EB8, pid=12296, pgid=12296, priority=8
17:55:33 HHCHT013I Using HTTPROOT directory "c:\herc380\html\"
17:55:33 HHCHT006I Waiting for HTTP requests on port 8081
17:55:34 HHCSD004I Device 000C bound to socket 127.0.0.1:3505
17:55:34 HHCSD020I Socketdevice listener thread started: tid=00004404, pid=12296
17:55:34 HHCCF083I conf/mvs380.conf Including conf/mvs380_DASD.conf at 123 .
17:55:34 HHCDA004I opening dasd/mvsres.148 readonly
17:55:34 HHCDA020I dasd/mvsres.148 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/sort01.131 readonly
17:55:34 HHCDA020I dasd/sort01.131 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort02.132 readonly
17:55:34 HHCDA020I dasd/sort02.132 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort03.133 readonly
17:55:34 HHCDA020I dasd/sort03.133 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort04.134 readonly
17:55:34 HHCDA020I dasd/sort04.134 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort05.135 readonly
17:55:34 HHCDA020I dasd/sort05.135 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort06.136 readonly
17:55:34 HHCDA020I dasd/sort06.136 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/work00.140 readonly
17:55:34 HHCDA020I dasd/work00.140 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA020I dasd/hasp00.152 cyls=404 heads=19 tracks=7676 trklen=13312
17:55:34 HHCDA020I dasd/page00.160 cyls=698 heads=12 tracks=8376 trklen=8704
17:55:34 HHCDA020I dasd/page01.161 cyls=698 heads=12 tracks=8376 trklen=8704
17:55:34 HHCDA020I dasd/page02.162 cyls=698 heads=12 tracks=8376 trklen=8704
17:55:34 HHCDA020I dasd/work01.170 cyls=962 heads=12 tracks=11544 trklen=35840
17:55:34 HHCDA004I opening dasd/work02.180 readonly
17:55:34 HHCDA020I dasd/work02.180 cyls=886 heads=15 tracks=13290 trklen=47616
17:55:34 HHCDA004I opening dasd/work03.190 readonly
17:55:34 HHCDA020I dasd/work03.190 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/mvscat.191 readonly
17:55:34 HHCDA020I dasd/mvscat.191 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/seasik.192 readonly
17:55:34 HHCDA020I dasd/seasik.192 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA020I dasd/mvssrc.193 cyls=2226 heads=15 tracks=33390 trklen=56832
17:55:34 HHCDA002E 01B4:File not found or invalid 'dasd/pub004.1b4'
17:55:34 HHCCF044E Initialization failed for device 01B4
17:55:34 HHCDA004I opening dasd/pub000.240 readonly
17:55:34 HHCDA020I dasd/pub000.240 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/mvsdlb.248 readonly
17:55:34 HHCDA020I dasd/mvsdlb.248 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/pub002.280 readonly
17:55:34 HHCDA020I dasd/pub002.280 cyls=1772 heads=15 tracks=26580 trklen=47616
17:55:34 HHCDA004I opening dasd/tmptmp.2b1 readonly
17:55:34 HHCDA020I dasd/tmptmp.2b1 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/xmit90.2b2 readonly
17:55:34 HHCDA020I dasd/xmit90.2b2 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/start1.150 readonly
17:55:34 HHCDA020I dasd/start1.150 cyls=808 heads=19 tracks=15352 trklen=13312
17:55:34 HHCDA004I opening dasd/spool0.151 readonly
17:55:34 HHCDA020I dasd/spool0.151 cyls=808 heads=19 tracks=15352 trklen=13312
17:55:34 HHCDA004I opening dasd/cbt000.340 readonly
17:55:34 HHCDA020I dasd/cbt000.340 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/cbt001.341 readonly
17:55:34 HHCDA020I dasd/cbt001.341 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/cbt002.342 readonly
17:55:34 HHCDA020I dasd/cbt002.342 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/cbtcat.343 readonly
17:55:34 HHCDA020I dasd/cbtcat.343 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/src000.348 readonly
17:55:34 HHCDA020I dasd/src000.348 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/src001.349 readonly
17:55:34 HHCDA020I dasd/src001.349 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/src002.34a readonly
17:55:34 HHCDA020I dasd/src002.34a cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/srccat.34b readonly
17:55:34 HHCDA020I dasd/srccat.34b cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/smp001.149 readonly
17:55:34 HHCDA020I dasd/smp001.149 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/smp002.14a readonly
17:55:34 HHCDA020I dasd/smp002.14a cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/smp003.14b readonly
17:55:34 HHCDA020I dasd/smp003.14b cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/smp004.14c readonly
17:55:34 HHCDA020I dasd/smp004.14c cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/js2sp0.700 readonly
17:55:34 HHCDA020I dasd/js2sp0.700 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/dlicat.138 readonly
17:55:34 HHCDA020I dasd/dlicat.138 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dlisys.139 readonly
17:55:34 HHCDA020I dasd/dlisys.139 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dli000.13a readonly
17:55:34 HHCDA020I dasd/dli000.13a cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dli001.13b readonly
17:55:34 HHCDA020I dasd/dli001.13b cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dli002.13c readonly
17:55:34 HHCDA020I dasd/dli002.13c cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/js3sp0.710 readonly
17:55:34 HHCDA020I dasd/js3sp0.710 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/js3res.711 readonly
17:55:34 HHCDA020I dasd/js3res.711 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCTE001I Console connection thread started: tid=000048D8, pid=12296
17:55:34 HHCTE003I Waiting for console connection on port 3270
17:55:34 HHCTA066I 0400: option 'level' accepted.
17:55:34 HHCTA066I 0401: option 'level' accepted.
17:55:34 HHCTA066I 0402: option 'level' accepted.
17:55:34 HHCTA066I 0403: option 'level' accepted.
17:55:34 HHCCP002I CPU0000 thread started: tid=00004558, pid=12296, priority=0
17:55:34 HHCCP003I CPU0000 architecture mode S/380
17:55:34 HHCPN001I Control panel thread started: tid=00002EB8, pid=12296
17:55:34 HHCTT002I Timer thread started: tid=000052BC, pid=12296, priority=-20
17:55:34 HHCAO001I Hercules Automatic Operator thread started;
17:55:34 tid=000013CC, pri=0, pid=12296
17:55:34 HHCPN008I Script file processing started using file "conf/auto_run.rc"
17:55:34 devlist
17:55:34 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof
17:55:34 (no one currently connected)
17:55:34 0:000D 3525 pch/pch00d.txt ascii crlf
17:55:34 0:000E 1403 prt/prt00e.txt crlf noclear
17:55:34 0:000F 1403 prt/prt00f.txt crlf noclear
17:55:34 0:001F 3215 *syscons cmdpref(/)
17:55:34 0:00C0 3270
17:55:34 0:00C1 3270
17:55:34 0:00C2 3270
17:55:34 0:00C7 3287
17:55:34 0:010C 3505 jcl/dummy eof
17:55:34 0:0131 2314 dasd/sort01.131 [200 cyls] open
17:55:34 0:0132 2314 dasd/sort02.132 [200 cyls] open
17:55:34 0:0133 2314 dasd/sort03.133 [200 cyls] open
17:55:34 0:0134 2314 dasd/sort04.134 [200 cyls] open
17:55:34 0:0135 2314 dasd/sort05.135 [200 cyls] open
17:55:34 0:0136 2314 dasd/sort06.136 [200 cyls] open
17:55:34 0:0138 2314 dasd/dlicat.138 [200 cyls] open
17:55:34 0:0139 2314 dasd/dlisys.139 [200 cyls] open
17:55:34 0:013A 2314 dasd/dli000.13a [200 cyls] open
17:55:34 0:013B 2314 dasd/dli001.13b [200 cyls] open
17:55:34 0:013C 2314 dasd/dli002.13c [200 cyls] open
17:55:34 0:0140 3350 dasd/work00.140 [560 cyls] open
17:55:34 0:0148 3350 dasd/mvsres.148 [560 cyls] open
17:55:34 0:0149 3350 dasd/smp001.149 [560 cyls] open
17:55:34 0:014A 3350 dasd/smp002.14a [560 cyls] open
17:55:34 0:014B 3350 dasd/smp003.14b [560 cyls] open
17:55:34 0:014C 3350 dasd/smp004.14c [560 cyls] open
17:55:34 0:0150 3330 dasd/start1.150 [808 cyls] open
17:55:34 0:0151 3330 dasd/spool0.151 [808 cyls] open
17:55:34 0:0152 3330 dasd/hasp00.152 [404 cyls] open
17:55:34 0:0160 3340 dasd/page00.160 [698 cyls] open
17:55:34 0:0161 3340 dasd/page01.161 [698 cyls] open
17:55:34 0:0162 3340 dasd/page02.162 [698 cyls] open
17:55:34 0:0170 3375 dasd/work01.170 [962 cyls] open
17:55:34 0:01A0 3380 dasd/work02.180 [886 cyls] open
17:55:34 0:01B0 3390 dasd/work03.190 [1114 cyls] open
17:55:34 0:01B1 3390 dasd/mvscat.191 [1114 cyls] open
17:55:34 0:01B2 3390 dasd/seasik.192 [1114 cyls] open
17:55:34 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] open
17:55:34 0:01C7 3287
17:55:34 0:0240 3350 dasd/pub000.240 [560 cyls] open
17:55:34 0:0248 3350 dasd/mvsdlb.248 [560 cyls] open
17:55:34 0:02A0 3380 dasd/pub002.280 [1772 cyls] open
17:55:34 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] open
17:55:34 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] open
17:55:34 0:030E 1403 log/hardcopy.log crlf noclear
17:55:34 0:0340 3350 dasd/cbt000.340 [555 cyls] open
17:55:34 0:0341 3350 dasd/cbt001.341 [555 cyls] open
17:55:34 0:0342 3350 dasd/cbt002.342 [555 cyls] open
17:55:34 0:0343 3350 dasd/cbtcat.343 [555 cyls] open
17:55:34 0:0348 3350 dasd/src000.348 [555 cyls] open
17:55:34 0:0349 3350 dasd/src001.349 [555 cyls] open
17:55:34 0:034A 3350 dasd/src002.34a [555 cyls] open
17:55:34 0:034B 3350 dasd/srccat.34b [555 cyls] open
17:55:34 0:0400 3420 *
17:55:34 0:0401 3420 *
17:55:34 0:0402 3420 *
17:55:34 0:0403 3420 *
17:55:34 0:0700 3350 dasd/js2sp0.700 [555 cyls] open
17:55:34 0:0710 3350 dasd/js3sp0.710 [555 cyls] open
17:55:34 0:0711 3350 dasd/js3res.711 [555 cyls] open
17:55:34 logopt timestamp
17:55:34 HHCPN197I Log option set: TIMESTAMP
17:55:34 panrate 1000
17:55:34 # really need to wait for SVC120I, but if building MVS/380
17:55:34 # or some other stuffup with parms, need to trigger on an
17:55:34 # alternative. First one hit will clear targets.
17:55:34 # If we get a prompt for a device, cancel it
17:55:34 hao tgt IEF238D
17:55:34 HHCAO016I Target placed at index 0
17:55:34 hao cmd script conf/cancel.rc
17:55:34 HHCAO020I Command placed at index 0
17:55:34 hao tgt HASP395 DYNAMASK
17:55:34 HHCAO016I Target placed at index 1
17:55:34 hao cmd script conf/subjobs_slow.rc
17:55:34 HHCAO020I Command placed at index 1
17:55:34 hao tgt HASP373 SVC120I
17:55:34 HHCAO016I Target placed at index 2
17:55:34 hao cmd script conf/subjobs_fast.rc
17:55:34 HHCAO020I Command placed at index 2
17:55:34 hao tgt HASP436 REPLY
17:55:34 HHCAO016I Target placed at index 3
17:55:34 hao cmd script conf/replyy.rc
17:55:34 HHCAO020I Command placed at index 3
17:55:34 devinit 402 tapes/mftopc.het
17:55:34 HHCTA004I 0402: tapes/mftopc.het is a Hercules Emulated Tape file
17:55:34 HHCPN098I Device 0:0402 initialized
17:55:34 devinit 403 tapes/awstap.aws
17:55:34 HHCTA004I 0403: tapes/awstap.aws is a Hercules Emulated Tape file
17:55:34 HHCPN098I Device 0:0403 initialized
17:55:34 # co will give you a cold start of JES2 which is useful in
17:55:34 # automated runs
17:55:34 /(001F) r 00,clpa,cmd=co
17:55:34 #/r 00,clpa
17:55:34 ipl 148
17:55:34 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:34 IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
17:55:34 HHCCD001I Readahead thread 1 started: tid=000057AC, pid=12296
17:55:34 HHCCD001I Readahead thread 2 started: tid=00003280, pid=12296
17:55:34 HHCCD002I Writer thread 1 started: tid=000032A0, pid=12296
17:55:34 HHCCD003I Garbage collector thread started: tid=00003D74, pid=12296
17:55:34 IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
17:55:34 PLPA ... SYS1.PAGELPA
17:55:34 COMMON . SYS1.PAGECSA
17:55:34 DUPLEX . SYS1.DUPLEX
17:55:34 LOCAL .. SYS1.PAGEL01
17:55:34 LOCAL .. SYS1.PAGEL02
17:55:34 LOCAL .. SYS1.PAGEL03
17:55:34 HHCCD002I Writer thread 2 started: tid=0000084C, pid=12296
17:55:35 *IEE362A SMF ENTER DUMP FOR SYS1.MANY ON MVSRES
17:55:35 IEE360I SMF NOW RECORDING ON SYS1.MANX ON MVSRES TIME=06.55.35
17:55:35 IGF992I MIH INIT COMPLETE, PRI=000300, SEC=000015
17:55:36 IEF677I WARNING MESSAGE(S) FOR JOB JES2 ISSUED
17:55:36 *00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
17:55:36 HHCAO003I Firing command: 'script conf/replyy.rc'
17:55:36 script conf/replyy.rc
17:55:36 /(001F) reply 00,y
17:55:36 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:36 IEE600I REPLY TO 00 IS;SUPPRESSED
17:55:36 $HASP493 JES2 COLD-START IS IN PROGRESS
17:55:36 $HASP412 MAXIMUM OF 1 READER(S) EXCEEDED
17:55:36 06.55.36 IEE041I THE SYSTEM LOG IS NOW ACTIVE
17:55:36 06.55.36 IEE302I 00E ONLINE
17:55:36 06.55.36 IEE302I 00F ONLINE
17:55:36 06.55.36 IEE313I 30E UNIT REF INVALID
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 IEE450I 06.55.36 UNIT STATUS 160
17:55:36 UNIT TYPE STATUS VOLSER VOLSTATE UNIT TYPE STATUS VOLSER VOLSTATE
17:55:36 400 3400 O /REMOV 401 3400 O /REMOV
17:55:36 UNIT TYPE STATUS VOLSER VOLSTATE UNIT TYPE STATUS VOLSER VOLSTATE
17:55:36 400 3400 O /REMOV 401 3400 O /REMOV
17:55:36 402 3400 O /REMOV
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP160 PRINTER1 INACTIVE - CLASS=AP
17:55:36 06.55.36 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:36 06.55.36 $HASP160 PUNCH1 INACTIVE - CLASS=B
17:55:36 06.55.36 STC 2 $HASP100 INIT ON STCINRDR
17:55:36 06.55.36 STC 2 $HASP373 INIT STARTED
17:55:36 06.55.36 STC 2 IEF403I INIT - STARTED - TIME=06.55.36
17:55:36 06.55.36 STC 3 $HASP100 INIT ON STCINRDR
17:55:36 06.55.36 STC 3 $HASP373 INIT STARTED
17:55:36 06.55.36 STC 3 IEF403I INIT - STARTED - TIME=06.55.36
17:55:36 06.55.36 STC 4 $HASP100 INIT ON STCINRDR
17:55:36 06.55.36 STC 4 $HASP373 INIT STARTED
17:55:36 06.55.36 STC 4 IEF403I INIT - STARTED - TIME=06.55.36
17:55:37 06.55.37 STC 5 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 5 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 5 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 6 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 6 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 6 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 7 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 7 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 7 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 8 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 8 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 8 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 9 $HASP100 SVC120I ON STCINRDR
17:55:37 06.55.37 STC 9 $HASP373 SVC120I STARTED
17:55:37 HHCAO003I Firing command: 'script conf/subjobs_fast.rc'
17:55:37 script conf/subjobs_fast.rc
17:55:37 # Now we know that SVC120I has started. But due to some
17:55:37 # weird pausing, it may get locked out. So clear out
17:55:37 # other triggers and wait on this
17:55:37 hao clear
17:55:37 HHCAO022I All automatic operation rules cleared
17:55:37 hao tgt HASP250 SVC120I
17:55:37 HHCAO016I Target placed at index 0
17:55:37 hao cmd script conf/subjobs.rc
17:55:37 HHCAO020I Command placed at index 0
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:37 06.55.37 STC 9 IEF403I SVC120I - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 10 $HASP100 DYNABLDL ON STCINRDR
17:55:37 06.55.37 STC 10 $HASP373 DYNABLDL STARTED
17:55:37 06.55.37 STC 10 IEF403I DYNABLDL - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 11 $HASP100 DYNAMASK ON STCINRDR
17:55:37 06.55.37 STC 11 $HASP373 DYNAMASK STARTED
17:55:37 06.55.37 STC 11 IEF403I DYNAMASK - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 12 $HASP100 BSPPILOT ON STCINRDR
17:55:37 06.55.37 STC 12 $HASP373 BSPPILOT STARTED
17:55:37 06.55.37 STC 12 IEF403I BSPPILOT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 13 $HASP100 BSPSETPF ON STCINRDR
17:55:37 06.55.37 STC 13 $HASP373 BSPSETPF STARTED
17:55:37 06.55.37 STC 13 IEF403I BSPSETPF - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 14 $HASP100 LOGRECI ON STCINRDR
17:55:37 06.55.37 STC 14 $HASP373 LOGRECI STARTED
17:55:37 06.55.37 STC 14 IEF403I LOGRECI - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 15 $HASP100 NET ON STCINRDR
17:55:37 06.55.37 STC 15 $HASP373 NET STARTED
17:55:37 06.55.37 STC 15 IEF403I NET - STARTED - TIME=06.55.37
17:55:37 06.55.37 $HASP309 INIT 1 INACTIVE ******** C=A
17:55:37 06.55.37 $HASP309 INIT 2 INACTIVE ******** C=BA
17:55:37 06.55.37 $HASP309 INIT 3 INACTIVE ******** C=CBA
17:55:37 06.55.37 $HASP309 INIT 4 INACTIVE ******** C=SHB
17:55:37 06.55.37 $HASP309 INIT 5 INACTIVE ******** C=SBA
17:55:37 06.55.37 $HASP309 INIT 6 INACTIVE ******** C=S
17:55:37 06.55.37 $HASP309 INIT 7 INACTIVE ******** C=E
17:55:37 06.55.37 STC 9 BSPGM40I - 200 MiB MAINSIZE memory available
17:55:37 06.55.37 STC 9 BSPGM41I - 2 Partitions of 64 MiB each
17:55:37 06.55.37 STC 9 BSPGM78I SVC 120 EP=00FE3210; MVS/380
17:55:37 06.55.37 STC 9 IEF404I SVC120I - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 9 $HASP395 SVC120I ENDED
17:55:37 06.55.37 STC 9 $HASP150 SVC120I ON PRINTER2 45 LINES
17:55:37 06.55.37 STC 9 *$HASP190 SVC120I SETUP -- PRINTER2 -- F = 0001 -- C = 6 -- T = SN
17:55:37 06.55.37 $HASP000 OK
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 9 $HASP250 SVC120I IS PURGED
17:55:37 HHCAO003I Firing command: 'script conf/subjobs.rc'
17:55:37 script conf/subjobs.rc
17:55:37 hao clear
17:55:37 HHCAO022I All automatic operation rules cleared
17:55:37 # Every job gets an NL tape available as input, containing
17:55:37 # some binary of unknown contents, most likely needing to
17:55:37 # be read as RECFM=U, but RECFM=FB and even RECFM=V are also
17:55:37 # possible.
17:55:37 #
17:55:37 # The job also gets an SL tape available for output, and
17:55:37 # again, any type of content can be written to it, and
17:55:37 # with a bit of luck, hetget will be able to extract the
17:55:37 # data you are looking for.
17:55:37 #
17:55:37 # And finally the job gets an SL AWS tape available for
17:55:37 # input and/or output should you wish to construct a
17:55:37 # special tape. Tape must be called AWSTAP. User should
17:55:37 # back the tape up before submitting it, because it will
17:55:37 # be overwritten and anything could go wrong. AWS is
17:55:37 # expected to be exceptional use of this procedure anyway
17:55:37 #
17:55:37 # Only the NL tape needs an explicit mount. The SL tapes
17:55:37 # are premounted before IPL
17:55:37 hao tgt HASP250 MOUNT
17:55:37 HHCAO016I Target placed at index 0
17:55:37 hao cmd script conf/subjobs2.rc
17:55:37 HHCAO020I Command placed at index 0
17:55:37 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAK IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAK IN VTAMLIB
17:55:37 06.55.37 STC 15 IST110I NETWORK SOLICITOR STARTED
17:55:37 06.55.37 STC 15 IST093I APPLJRP ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLPIES ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLPIAD ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLTSO ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLTEST ACTIVE
17:55:37 06.55.37 STC 10 DYNABLDL STARTED
17:55:37 06.55.37 STC 15 IST093I LCLMAJRP ACTIVE
17:55:37 06.55.37 STC 10 IEF404I DYNABLDL - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 10 $HASP395 DYNABLDL ENDED
17:55:37 06.55.37 STC 10 $HASP150 DYNABLDL ON PRINTER2 21 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 10 $HASP250 DYNABLDL IS PURGED
17:55:37 06.55.37 STC 15 IST093I LCLMAJ00 ACTIVE
17:55:37 06.55.37 STC 16 $HASP100 TSO ON STCINRDR
17:55:37 06.55.37 STC 16 $HASP373 TSO STARTED
17:55:37 06.55.37 STC 16 IEF403I TSO - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 17 $HASP100 JRP ON STCINRDR
17:55:37 06.55.37 STC 17 $HASP373 JRP STARTED
17:55:37 06.55.37 STC 17 IEF403I JRP - STARTED - TIME=06.55.37
17:55:37 06.55.37 $HASP000 OK
17:55:37 06.55.37 $HASP000 OK
17:55:37 06.55.37 STC 15 IST020I VTAM INITIALIZATION COMPLETE
17:55:37 06.55.37 STC 15 IEA000I 0C0,IOE,05,0200,400000000001,,,NET ,06.55.37
17:55:37 06.55.37 STC 15 IEA000I 0C1,IOE,05,0200,400000000001,,,NET ,06.55.37
17:55:37 06.55.37 STC 15 IEA000I 0C2,IOE,05,0200,400000000001,,,NET ,06.55.37
17:55:37 06.55.37 STC 11 DMSK00I DYNAMASK DONE ****
17:55:37 06.55.37 STC 11 DMSK06I START
17:55:37 06.55.37 STC 11 IEF404I DYNAMASK - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 11 $HASP395 DYNAMASK ENDED
17:55:37 06.55.37 STC 11 $HASP150 DYNAMASK ON PRINTER2 30 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 11 $HASP250 DYNAMASK IS PURGED
17:55:37 06.55.37 STC 13 BSPSP91I - Parms passed: NOREPLYU
17:55:37 06.55.37 STC 13 BSPSP93I - PFK definitions will be updated in memory
17:55:37 06.55.37 STC 13 BSPSP22I - Dataset processed: SYS1.PARMLIB
17:55:37 06.55.37 STC 13 BSPSP23I - on volume MVSRES
17:55:37 06.55.37 STC 13 BSPSP21I - Member being processed: SETPFK01
17:55:37 06.55.37 STC 13 +BSPSP98I - Member processed, LASTCC=0000
17:55:37 06.55.37 STC 13 +BSPSP21I - Member being processed: SETPFK02
17:55:37 06.55.37 STC 13 +BSPSP98I - Member processed, LASTCC=0000
17:55:37 06.55.37 STC 13 +BSPSP99I - End of processing, MAXRC=0000
17:55:37 06.55.37 STC 13 IEF404I BSPSETPF - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 13 $HASP395 BSPSETPF ENDED
17:55:37 06.55.37 STC 13 $HASP150 BSPSETPF ON PRINTER2 34 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 13 $HASP250 BSPSETPF IS PURGED
17:55:37 06.55.37 STC 14 IFC001I D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
17:55:37 06.55.37 STC 14 IEF404I LOGRECI - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 14 $HASP395 LOGRECI ENDED
17:55:37 06.55.37 STC 14 $HASP150 LOGRECI ON PRINTER2 20 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 14 $HASP250 LOGRECI IS PURGED
17:55:37 06.55.37 STC 16 IKT007I TCAS ACCEPTING LOGONS
17:55:37 06.55.37 STC 16 IKT005I TCAS IS INITIALIZED
17:55:37 06.55.37 STC 17 JRPI101 INITIALIZATION COMPLETE
17:55:37 06.55.37 STC 17 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
18:08:34 /(001F) M 401,VOL=(NL,PCTOMF)
18:08:34 07.08.34 STC 18 $HASP100 MOUNT ON STCINRDR
18:08:34 07.08.34 STC 18 $HASP373 MOUNT STARTED
18:08:34 07.08.34 STC 18 IEF403I MOUNT - STARTED - TIME=07.08.34
18:08:34 07.08.34 STC 18 *IEF233A M 401,PCTOMF,,MOUNT,401
18:08:34 07.08.34 STC 18 IEF404I MOUNT - ENDED - TIME=07.08.34
18:08:34 07.08.34 STC 18 $HASP395 MOUNT ENDED
18:08:34 07.08.34 STC 18 $HASP150 MOUNT ON PRINTER2 18 LINES
18:08:34 07.08.34 $HASP160 PRINTER2 INACTIVE - CLASS=Z
18:08:34 07.08.34 STC 18 $HASP250 MOUNT IS PURGED
18:08:34 HHCAO003I Firing command: 'script conf/subjobs2.rc'
18:08:34 script conf/subjobs2.rc
18:08:34 hao clear
18:08:34 HHCAO022I All automatic operation rules cleared
18:08:34 # If we get a prompt for a device, cancel it
18:08:34 hao tgt IEF238D
18:08:34 HHCAO016I Target placed at index 0
18:08:34 hao cmd script conf/cancel.rc
18:08:34 HHCAO020I Command placed at index 0
18:08:34 # If we get a prompt for a catalogue password, answer it
18:08:34 hao tgt IEC301A
18:08:34 HHCAO016I Target placed at index 1
18:08:34 hao cmd script conf/secret.rc
18:08:34 HHCAO020I Command placed at index 1
18:08:34 devinit 401 tapes/pctomf.tdf
18:08:34 HHCTA004I 0401: tapes/pctomf.tdf is a Optical Media Attachment (OMA) tape
18:08:34 HHCPN098I Device 0:0401 initialized
18:08:34 # When we see TERMHERC get purged, our job is done
18:08:34 hao tgt HASP373 TERMHERC
18:08:34 HHCAO016I Target placed at index 2
18:08:34 hao cmd script conf/termherc.rc
18:08:34 HHCAO020I Command placed at index 2
18:08:34 # Now submit the job
18:08:34 devinit 00c jcl/hercauto.jcl eof
18:08:34 HHCSD007I Device 000C unbound from socket 127.0.0.1:3505
18:08:34 HHCSD022I Socketdevice listener thread terminated
18:08:34 HHCPN098I Device 0:000C initialized
18:08:34 HHCPN013I EOF reached on SCRIPT file. Processing complete.
18:08:34 07.08.34 JOB 1 $HASP100 HERC01A ON READER1
18:08:34 07.08.34 JOB 2 $HASP100 TERMHERC ON READER1
18:08:34 07.08.34 JOB 1 $HASP373 HERC01A STARTED - INIT 3 - CLASS C - SYS BSP1
18:08:34 07.08.34 JOB 1 IEF403I HERC01A - STARTED - TIME=07.08.34
18:08:34 07.08.34 JOB 1 IEFACTRT - Stepname Procstep Program Retcode
18:08:34 07.08.34 JOB 1 HERC01A IEFBR14 IEFBR14 RC= 0000
18:08:34 07.08.34 JOB 1 IEF404I HERC01A - ENDED - TIME=07.08.34
18:08:34 07.08.34 JOB 1 $HASP395 HERC01A ENDED
18:08:34 07.08.34 JOB 1 $HASP150 HERC01A ON PRINTER1 21 LINES
18:08:34 07.08.34 JOB 1 *$HASP190 HERC01A SETUP -- PRINTER1 -- F = 0001 -- C = 6 -- T = SN
18:08:34 07.08.34 $HASP000 OK
18:08:34 07.08.34 $HASP160 PRINTER1 INACTIVE - CLASS=AP
18:08:34 07.08.34 JOB 1 $HASP250 HERC01A IS PURGED
18:08:34 07.08.34 *IEE362A SMF ENTER DUMP FOR SYS1.MANX ON MVSRES
18:08:34 07.08.34 IEE361I SMF DATA LOST - SYS1.MANY NOT AVAILABLE TIME=07.08.34
18:08:34 07.08.34 STC 19 $HASP100 SMFDAILY ON STCINRDR
18:08:34 07.08.34 STC 19 $HASP373 SMFDAILY STARTED
18:08:34 07.08.34 STC 19 IEF403I SMFDAILY - STARTED - TIME=07.08.34
18:08:34 07.08.34 JOB 2 $HASP373 TERMHERC STARTED - INIT 3 - CLASS C - SYS BSP1
18:08:34 HHCAO003I Firing command: 'script conf/termherc.rc'
18:08:34 script conf/termherc.rc
18:08:34 # We do an unnecessary 2-stage terminate, first triggering
18:08:34 # on the start message, then triggering on the purged
18:08:34 # message, to overcome an apparent bug in hercules which
18:08:34 # causes it to sometimes trigger on the wrong jobname.
18:08:34 hao clear
18:08:34 HHCAO022I All automatic operation rules cleared
18:08:34 hao tgt HASP250 TERMHERC
18:08:34 HHCAO016I Target placed at index 0
18:08:34 hao cmd script conf/termherc2.rc
18:08:34 HHCAO020I Command placed at index 0
18:08:34 HHCPN013I EOF reached on SCRIPT file. Processing complete.
18:08:34 07.08.34 JOB 2 IEF403I TERMHERC - STARTED - TIME=07.08.34
18:08:34 07.08.34 STC 19 IEF453I SMFDAILY - JOB FAILED - JCL ERROR - TIME=07.08.34
18:08:34 07.08.34 STC 19 $HASP395 SMFDAILY ENDED
18:08:34 07.08.34 STC 19 $HASP150 SMFDAILY ON PRINTER2 25 LINES
18:08:34 07.08.34 IEE132I START COMMAND DEVICE ALLOCATION ERROR
18:08:34 07.08.34 $HASP160 PRINTER2 INACTIVE - CLASS=Z
18:08:34 07.08.34 STC 19 $HASP250 SMFDAILY IS PURGED
18:08:34 07.08.34 JOB 2 IEFACTRT - Stepname Procstep Program Retcode
18:08:34 07.08.34 JOB 2 TERMHERC S1 IEBGENER RC= 0000
18:08:34 07.08.34 JOB 2 IEF404I TERMHERC - ENDED - TIME=07.08.34
18:08:34 07.08.34 JOB 2 $HASP395 TERMHERC ENDED
18:08:34 07.08.34 $HASP309 INIT 3 INACTIVE ******** C=CBA
18:08:34 07.08.34 JOB 2 $HASP150 TERMHERC ON PRINTER1 1 LINE
18:08:34 07.08.34 JOB 2 $HASP150 TERMHERC ON PRINTER2 44 LINES
18:08:34 07.08.34 $HASP160 PRINTER1 INACTIVE - CLASS=AP
18:08:34 07.08.34 $HASP160 PRINTER2 INACTIVE - CLASS=Z
18:08:34 07.08.34 JOB 2 $HASP250 TERMHERC IS PURGED
18:08:34 HHCAO003I Firing command: 'script conf/termherc2.rc'
18:08:34 script conf/termherc2.rc
18:08:34 # we put in an unnecessary "stopall" to prevent Hercules
18:08:34 # (3.07 and 3.12 at least) from randomly hanging in the
18:08:34 # "quit" command in about 5% of runs.
18:08:34 # It is still unclear why Hercules is hanging
18:08:34 stopall
18:08:34 quit
18:08:34 HHCIN900I Begin Hercules shutdown
18:08:34 HHCIN901I Releasing configuration
18:08:34 HHCCP008I CPU0000 thread ended: tid=00004558, pid=12296
18:08:34 HHCCF047I Subchannel 0:0000 detached
18:08:34 HHCCF047I Subchannel 0:0001 detached
18:08:34 HHCCF047I Subchannel 0:0002 detached
18:08:34 HHCCF047I Subchannel 0:0003 detached
18:08:34 HHCTT003I Timer thread ended
18:08:34 HHCCF047I Subchannel 0:0004 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 19358135 5% 4 1137 4702 42 1019 1998
18:08:34 HHCCD214I 161 31
18:08:34 HHCCD215I dasd/mvsres.148
18:08:34 HHCCD216I [0] 15179178 0% 1 ro 950 0 19
18:08:34 HHCCD217I shadow/mvsres_*.148
18:08:34 HHCCD218I [1] 4178957 20% 3 187 4702 23
18:08:34 HHCCF047I Subchannel 0:0005 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort01.131
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort01_*.131
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0006 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort02.132
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort02_*.132
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0007 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort03.133
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort03_*.133
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0008 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort04.134
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort04_*.134
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0009 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort05.135
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort05_*.135
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:000A detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort06.136
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort06_*.136
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:000B detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 52422417 2% 77 1 0 2 0 1
18:08:34 HHCCD215I dasd/work00.140
18:08:34 HHCCD216I [0] 141963 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/work00_*.140
18:08:34 HHCCD218I [1] 52280454 2% 76 0 0 1
18:08:34 HHCCF047I Subchannel 0:000C detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 5023930 3% 5 1 0 1 0 1
18:08:34 HHCCD215I dasd/hasp00.152
18:08:34 HHCCD216I [0] 5023930 3% 5 rw 1 0 1
18:08:34 HHCCF047I Subchannel 0:000D detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 9896583 12% 17 1971 38432 32 1300 2576
18:08:34 HHCCD214I 695 66
18:08:34 HHCCD215I dasd/page00.160
18:08:34 HHCCD216I [0] 9896583 12% 17 rw 1971 38432 32
18:08:34 HHCCF047I Subchannel 0:000E detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 4719568 28% 3 213 77145 32 200 311
18:08:34 HHCCD214I 102 14
18:08:34 HHCCD215I dasd/page01.161
18:08:34 HHCCD216I [0] 4719568 28% 3 rw 213 77145 32
18:08:34 HHCCF047I Subchannel 0:000F detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 3833787 18% 4 120 45815 19 140 203
18:08:34 HHCCD214I 57 7
18:08:34 HHCCD215I dasd/page02.162
18:08:34 HHCCD216I [0] 3833787 18% 4 rw 120 45815 19
18:08:34 HHCCF047I Subchannel 0:0010 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 57202932 1% 102 1 0 1 0 1
18:08:34 HHCCD215I dasd/work01.170
18:08:34 HHCCD216I [0] 57202932 1% 102 rw 1 0 1
18:08:34 HHCCF047I Subchannel 0:0011 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 66815692 2% 425 1 0 2 0 1
18:08:34 HHCCD215I dasd/work02.180
18:08:34 HHCCD216I [0] 113799 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/work02_*.180
18:08:34 HHCCD218I [1] 66701893 2% 424 0 0 1
18:08:34 HHCCF047I Subchannel 0:0012 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 56476534 2% 264 1 0 2 0 1
18:08:34 HHCCD215I dasd/work03.190
18:08:34 HHCCD216I [0] 142257 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/work03_*.190
18:08:34 HHCCD218I [1] 56334277 2% 263 0 0 1
18:08:34 HHCCF047I Subchannel 0:0013 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 17037777 9% 16 17 1 5 15 31
18:08:34 HHCCD214I 2 3
18:08:34 HHCCD215I dasd/mvscat.191
18:08:34 HHCCD216I [0] 3658727 0% 1 ro 8 0 3
18:08:34 HHCCD217I shadow/mvscat_*.191
18:08:34 HHCCD218I [1] 13379050 11% 15 9 1 2
18:08:34 HHCCF047I Subchannel 0:0014 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 103500159 17% 1297 1 0 2 0 1
18:08:34 HHCCD215I dasd/seasik.192
18:08:34 HHCCD216I [0] 16164960 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/seasik_*.192
18:08:34 HHCCD218I [1] 87335199 20% 1297 0 0 1
18:08:34 HHCCF047I Subchannel 0:0015 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 168333900 4% 5454 1 0 1 0 1
18:08:34 HHCCD215I dasd/mvssrc.193
18:08:34 HHCCD216I [0] 168333900 4% 5454 rw 1 0 1
18:08:34 HHCCF047I Subchannel 0:0016 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 44516465 2% 22 33 0 9 39 66
18:08:34 HHCCD214I 6 2
18:08:34 HHCCD215I dasd/pub000.240
18:08:34 HHCCD216I [0] 7591138 3% 1 ro 12 0 5
18:08:34 HHCCD217I shadow/pub000_*.240
18:08:34 HHCCD218I [1] 36925327 2% 21 21 0 4
18:08:34 HHCCF047I Subchannel 0:0017 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 25722586 0% 5 24 1463 5 306 325
18:08:34 HHCCD214I 5 0
18:08:34 HHCCD215I dasd/mvsdlb.248
18:08:34 HHCCD216I [0] 25471539 0% 1 ro 3 0 3
18:08:34 HHCCD217I shadow/mvsdlb_*.248
18:08:34 HHCCD218I [1] 251047 39% 4 21 1463 2
18:08:34 HHCCF047I Subchannel 0:0018 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 100064666 8% 539 1 0 2 0 1
18:08:34 HHCCD215I dasd/pub002.280
18:08:34 HHCCD216I [0] 2171954 29% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/pub002_*.280
18:08:34 HHCCD218I [1] 97892712 8% 538 0 0 1
18:08:34 HHCCF047I Subchannel 0:0019 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 143545 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/tmptmp.2b1
18:08:34 HHCCD216I [0] 142257 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/tmptmp_*.2b1
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001A detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 143545 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/xmit90.2b2
18:08:34 HHCCD216I [0] 142257 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/xmit90_*.2b2
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001B detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 6099280 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/start1.150
18:08:34 HHCCD216I [0] 6098016 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/start1_*.150
18:08:34 HHCCD218I [1] 1264 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001C detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 4595678 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/spool0.151
18:08:34 HHCCD216I [0] 4594414 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/spool0_*.151
18:08:34 HHCCD218I [1] 1264 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001D detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 50622559 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbt000.340
18:08:34 HHCCD216I [0] 50621271 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbt000_*.340
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001E detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 53836805 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbt001.341
18:08:34 HHCCD216I [0] 53835517 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbt001_*.341
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001F detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 46082980 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbt002.342
18:08:34 HHCCD216I [0] 46081692 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbt002_*.342
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0020 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 27241782 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbtcat.343
18:08:34 HHCCD216I [0] 27240494 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbtcat_*.343
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0021 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 46003602 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/src000.348
18:08:34 HHCCD216I [0] 46002314 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/src000_*.348
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0022 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 45707725 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/src001.349
18:08:34 HHCCD216I [0] 45706437 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/src001_*.349
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0023 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 44403653 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/src002.34a
18:08:34 HHCCD216I [0] 44402365 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/src002_*.34a
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0024 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 6321674 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/srccat.34b
18:08:34 HHCCD216I [0] 6310767 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/srccat_*.34b
18:08:34 HHCCD218I [1] 10907 7% 1 0 0 0
18:08:34 HHCCF047I Subchannel 0:0025 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1118801 11% 2 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp001.149
18:08:34 HHCCD216I [0] 774654 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/smp001_*.149
18:08:34 HHCCD218I [1] 344147 38% 2 0 0 1
18:08:34 HHCCF047I Subchannel 0:0026 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1621663 24% 12 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp002.14a
18:08:34 HHCCD216I [0] 856740 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/smp002_*.14a
18:08:34 HHCCD218I [1] 764923 51% 12 0 0 1
18:08:34 HHCCF047I Subchannel 0:0027 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1077383 19% 3 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp003.14b
18:08:34 HHCCD216I [0] 592555 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/smp003_*.14b
18:08:34 HHCCD218I [1] 484828 42% 3 0 0 1
18:08:34 HHCCF047I Subchannel 0:0028 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 3437923 36% 4 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp004.14c
18:08:34 HHCCD216I [0] 2916431 35% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/smp004_*.14c
18:08:34 HHCCD218I [1] 521492 41% 3 0 0 1
18:08:34 HHCCF047I Subchannel 0:0029 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 11902899 18% 18 125 81303 66 775 873
18:08:34 HHCCD214I 29 7
18:08:34 HHCCD215I dasd/js2sp0.700
18:08:34 HHCCD216I [0] 142291 0% 1 ro 0 0 1
18:08:34 HHCCD217I shadow/js2sp0_*.700
18:08:34 HHCCD218I [1] 11760608 19% 17 125 81303 65
18:08:34 HHCCF047I Subchannel 0:002A detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 715081 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dlicat.138
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dlicat_*.138
18:08:34 HHCCD218I [1] 678451 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002B detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 880289 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dlisys.139
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dlisys_*.139
18:08:34 HHCCD218I [1] 843659 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002C detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 43495 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dli000.13a
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dli000_*.13a
18:08:34 HHCCD218I [1] 6865 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002D detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 46911 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dli001.13b
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dli001_*.13b
18:08:34 HHCCD218I [1] 10281 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002E detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 37718 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/dli002.13c
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dli002_*.13c
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:002F detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1233964 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/js3sp0.710
18:08:34 HHCCD216I [0] 141965 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/js3sp0_*.710
18:08:34 HHCCD218I [1] 1091999 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:0030 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 951745 0% 2 1 0 2 0 1
18:08:34 HHCCD215I dasd/js3res.711
18:08:34 HHCCD216I [0] 142093 0% 2 ro 1 0 1
18:08:34 HHCCD217I shadow/js3res_*.711
18:08:34 HHCCD218I [1] 809652 0% 0 0 0 1
18:08:34 HHCCD011I Readahead thread 2 stopping: tid=00003280, pid=12296
18:08:34 HHCCD011I Readahead thread 1 stopping: tid=000057AC, pid=12296
18:08:34 HHCCD013I Garbage collector thread stopping: tid=00003D74, pid=12296
18:08:34 HHCCD012I Writer thread 2 stopping: tid=0000084C, pid=12296
18:08:34 HHCCD012I Writer thread 1 stopping: tid=000032A0, pid=12296
18:08:34 HHCCF047I Subchannel 0:0031 detached
18:08:34 HHCCF047I Subchannel 0:0032 detached
18:08:34 HHCCF047I Subchannel 0:0033 detached
18:08:34 HHCCF047I Subchannel 0:0034 detached
18:08:34 HHCCF047I Subchannel 0:0035 detached
18:08:34 HHCCF047I Subchannel 0:0036 detached
18:08:34 HHCCF047I Subchannel 0:0037 detached
18:08:34 HHCTE004I Console connection thread terminated
18:08:34 HHCCF047I Subchannel 0:0038 detached
18:08:34 HHCCF047I Subchannel 0:0039 detached
18:08:34 HHCCF047I Subchannel 0:003A detached
18:08:34 HHCCF047I Subchannel 0:003B detached
18:08:34 HHCCF047I Subchannel 0:003C detached
18:08:34 HHCIN902I Configuration release complete
18:08:34 HHCIN903I Calling termination routines
18:08:34 HHCHD900I Begin shutdown sequence
18:08:34 HHCHD901I Calling panel_cleanup
18:08:34 HHCHD902I panel_cleanup complete
18:08:34 HHCHD901I Calling console_shutdown
18:08:34 HHCHD902I console_shutdown complete
18:08:34 HHCHD901I Calling term_sockdev
18:08:34 HHCHD902I term_sockdev complete
18:08:34 HHCHD901I Calling hdl_term
18:08:34 HHCHD950I Begin HDL termination sequence
18:08:34 HHCHD951I Calling module *Hercules cleanup routine
18:08:34 HHCHD952I Module *Hercules cleanup complete
18:08:34 HHCHD959I HDL Termination sequence complete
18:08:34 HHCHD902I hdl_term complete
18:08:34 HHCHD901I Calling logger_term
18:08:34 HHCLG014I logger thread terminating
by doing a "stopall" before the quit, I am
able to massively thrash Hercules.
I have been running sets of 1200 runs
(ie IPLing MVS, running IEFBR14 and
then quitting).
So far I have run 7200 tests:
1200 tests:
1
0
0
0
0
2
and there have been 0 hangs in "quit".
However, there is a new issue that is
now brought more into focus. Sometimes
commands that I enter are not taking
effect.
As per above, in the first batch of 1200
I had 1 single case where the run failed
to finish because of a command not
taking.
Here is what a good run looks like:
17:55:32 hao tgt HASP250 MOUNT
17:55:32 HHCAO016I Target placed at index 0
17:55:32 hao cmd script conf/subjobs2.rc
17:55:32 HHCAO020I Command placed at index 0
17:55:32 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:32 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:32 06.55.32 STC 16 $HASP100 MOUNT ON STCINRDR
17:55:32 06.55.32 STC 16 $HASP373 MOUNT STARTED
17:55:32 06.55.32 STC 16 IEF403I MOUNT - STARTED - TIME=06.55.32
17:55:32 06.55.32 STC 16 *IEF233A M 401,PCTOMF,,MOUNT,401
17:55:32 06.55.32 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:32 06.55.32 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:32 06.55.32 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
And here is the bad run:
17:55:37 hao tgt HASP250 MOUNT
17:55:37 HHCAO016I Target placed at index 0
17:55:37 hao cmd script conf/subjobs2.rc
17:55:37 HHCAO020I Command placed at index 0
17:55:37 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
(full bad log below)
As you can see, the "MOUNT" process
is not started. As per full log, after some
time:
17:55:37 06.55.37 STC 17 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
18:08:34 /(001F) M 401,VOL=(NL,PCTOMF)
I manually issued the same MOUNT command
as the script, and this time Hercules accepted
it and the automated process ran to completion.
I initially suspected this:
17:55:37 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
ie an incoming message about BLDL
happening at the same time as the
script was still running. The bottom of
the script looks like this:
subjobs.rc:
...
# Only the NL tape needs an explicit mount. The SL tapes
# are premounted before IPL
hao tgt HASP250 MOUNT
hao cmd script conf/subjobs2.rc
/M 401,VOL=(NL,PCTOMF)
So you can see that the mount command
is issued right before the end of the
script, with no delays, but as per the
console output, there was a time delay
between the mount and end of script
long enough for an incoming message.
I was wondering whether I could solve
this problem by issuing two mounts
so that one of them could get lost. Or
maybe I could put a "stopall" before the
mount command and a "startall" after
it. I'm not sure what effect that has. I
am in fact surprised that at IPL time
I can have this in my script:
autoipl.rc:
...
/r 00,clpa
ipl 148
ie I am able to give Hercules the expected
response, before I've even IPLed!!! So maybe
Hercules knows how to buffer console input
or something, and maybe stopall will invoke
the same buffering?
Please see next message coming
shortly ...
BFN. Paul.
17:55:33 Hercules Version 3.07:380-4.x
17:55:33 (c)Copyright 1999-2010 by Roger Bowler, Jan Jaeger, and others
17:55:33 Built on Dec 7 2016 at 12:43:32
17:55:33 Build information:
17:55:33 Windows (MSVC) build for AMD64
17:55:33 Modes: S/370 S/380 ESA/390 z/Arch
17:55:33 Max CPU Engines: 8
17:55:33 Using fthreads instead of pthreads
17:55:33 Dynamic loading support
17:55:33 Using shared libraries
17:55:33 HTTP Server support
17:55:33 No SIGABEND handler
17:55:33 Regular Expressions support
17:55:33 Automatic Operator support
17:55:33 Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8
17:55:33 Running on PAUL-DELL Windows_NT-6.2 AMD64 MP=8
17:55:33 HHCHD018I Loadable module directory is hercules
17:55:33 Crypto module loaded (c) Copyright Bernard van der Helm, 2003-2010
17:55:33 Active: Message Security Assist
17:55:33 Message Security Assist Extension 1
17:55:33 Message Security Assist Extension 2
17:55:33 HHCPN210I Default Allowed AUTOMOUNT directory = "c:\mvs380\"
17:55:33 HHCHT001I HTTP listener thread started: tid=00003950, pid=12296
17:55:33 HHCCF065I Hercules: tid=00002EB8, pid=12296, pgid=12296, priority=8
17:55:33 HHCHT013I Using HTTPROOT directory "c:\herc380\html\"
17:55:33 HHCHT006I Waiting for HTTP requests on port 8081
17:55:34 HHCSD004I Device 000C bound to socket 127.0.0.1:3505
17:55:34 HHCSD020I Socketdevice listener thread started: tid=00004404, pid=12296
17:55:34 HHCCF083I conf/mvs380.conf Including conf/mvs380_DASD.conf at 123 .
17:55:34 HHCDA004I opening dasd/mvsres.148 readonly
17:55:34 HHCDA020I dasd/mvsres.148 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/sort01.131 readonly
17:55:34 HHCDA020I dasd/sort01.131 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort02.132 readonly
17:55:34 HHCDA020I dasd/sort02.132 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort03.133 readonly
17:55:34 HHCDA020I dasd/sort03.133 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort04.134 readonly
17:55:34 HHCDA020I dasd/sort04.134 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort05.135 readonly
17:55:34 HHCDA020I dasd/sort05.135 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/sort06.136 readonly
17:55:34 HHCDA020I dasd/sort06.136 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/work00.140 readonly
17:55:34 HHCDA020I dasd/work00.140 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA020I dasd/hasp00.152 cyls=404 heads=19 tracks=7676 trklen=13312
17:55:34 HHCDA020I dasd/page00.160 cyls=698 heads=12 tracks=8376 trklen=8704
17:55:34 HHCDA020I dasd/page01.161 cyls=698 heads=12 tracks=8376 trklen=8704
17:55:34 HHCDA020I dasd/page02.162 cyls=698 heads=12 tracks=8376 trklen=8704
17:55:34 HHCDA020I dasd/work01.170 cyls=962 heads=12 tracks=11544 trklen=35840
17:55:34 HHCDA004I opening dasd/work02.180 readonly
17:55:34 HHCDA020I dasd/work02.180 cyls=886 heads=15 tracks=13290 trklen=47616
17:55:34 HHCDA004I opening dasd/work03.190 readonly
17:55:34 HHCDA020I dasd/work03.190 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/mvscat.191 readonly
17:55:34 HHCDA020I dasd/mvscat.191 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/seasik.192 readonly
17:55:34 HHCDA020I dasd/seasik.192 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA020I dasd/mvssrc.193 cyls=2226 heads=15 tracks=33390 trklen=56832
17:55:34 HHCDA002E 01B4:File not found or invalid 'dasd/pub004.1b4'
17:55:34 HHCCF044E Initialization failed for device 01B4
17:55:34 HHCDA004I opening dasd/pub000.240 readonly
17:55:34 HHCDA020I dasd/pub000.240 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/mvsdlb.248 readonly
17:55:34 HHCDA020I dasd/mvsdlb.248 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/pub002.280 readonly
17:55:34 HHCDA020I dasd/pub002.280 cyls=1772 heads=15 tracks=26580 trklen=47616
17:55:34 HHCDA004I opening dasd/tmptmp.2b1 readonly
17:55:34 HHCDA020I dasd/tmptmp.2b1 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/xmit90.2b2 readonly
17:55:34 HHCDA020I dasd/xmit90.2b2 cyls=1114 heads=15 tracks=16710 trklen=56832
17:55:34 HHCDA004I opening dasd/start1.150 readonly
17:55:34 HHCDA020I dasd/start1.150 cyls=808 heads=19 tracks=15352 trklen=13312
17:55:34 HHCDA004I opening dasd/spool0.151 readonly
17:55:34 HHCDA020I dasd/spool0.151 cyls=808 heads=19 tracks=15352 trklen=13312
17:55:34 HHCDA004I opening dasd/cbt000.340 readonly
17:55:34 HHCDA020I dasd/cbt000.340 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/cbt001.341 readonly
17:55:34 HHCDA020I dasd/cbt001.341 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/cbt002.342 readonly
17:55:34 HHCDA020I dasd/cbt002.342 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/cbtcat.343 readonly
17:55:34 HHCDA020I dasd/cbtcat.343 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/src000.348 readonly
17:55:34 HHCDA020I dasd/src000.348 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/src001.349 readonly
17:55:34 HHCDA020I dasd/src001.349 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/src002.34a readonly
17:55:34 HHCDA020I dasd/src002.34a cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/srccat.34b readonly
17:55:34 HHCDA020I dasd/srccat.34b cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/smp001.149 readonly
17:55:34 HHCDA020I dasd/smp001.149 cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/smp002.14a readonly
17:55:34 HHCDA020I dasd/smp002.14a cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/smp003.14b readonly
17:55:34 HHCDA020I dasd/smp003.14b cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/smp004.14c readonly
17:55:34 HHCDA020I dasd/smp004.14c cyls=560 heads=30 tracks=16800 trklen=19456
17:55:34 HHCDA004I opening dasd/js2sp0.700 readonly
17:55:34 HHCDA020I dasd/js2sp0.700 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/dlicat.138 readonly
17:55:34 HHCDA020I dasd/dlicat.138 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dlisys.139 readonly
17:55:34 HHCDA020I dasd/dlisys.139 cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dli000.13a readonly
17:55:34 HHCDA020I dasd/dli000.13a cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dli001.13b readonly
17:55:34 HHCDA020I dasd/dli001.13b cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/dli002.13c readonly
17:55:34 HHCDA020I dasd/dli002.13c cyls=200 heads=20 tracks=4000 trklen=7680
17:55:34 HHCDA004I opening dasd/js3sp0.710 readonly
17:55:34 HHCDA020I dasd/js3sp0.710 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCDA004I opening dasd/js3res.711 readonly
17:55:34 HHCDA020I dasd/js3res.711 cyls=555 heads=30 tracks=16650 trklen=19456
17:55:34 HHCTE001I Console connection thread started: tid=000048D8, pid=12296
17:55:34 HHCTE003I Waiting for console connection on port 3270
17:55:34 HHCTA066I 0400: option 'level' accepted.
17:55:34 HHCTA066I 0401: option 'level' accepted.
17:55:34 HHCTA066I 0402: option 'level' accepted.
17:55:34 HHCTA066I 0403: option 'level' accepted.
17:55:34 HHCCP002I CPU0000 thread started: tid=00004558, pid=12296, priority=0
17:55:34 HHCCP003I CPU0000 architecture mode S/380
17:55:34 HHCPN001I Control panel thread started: tid=00002EB8, pid=12296
17:55:34 HHCTT002I Timer thread started: tid=000052BC, pid=12296, priority=-20
17:55:34 HHCAO001I Hercules Automatic Operator thread started;
17:55:34 tid=000013CC, pri=0, pid=12296
17:55:34 HHCPN008I Script file processing started using file "conf/auto_run.rc"
17:55:34 devlist
17:55:34 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof
17:55:34 (no one currently connected)
17:55:34 0:000D 3525 pch/pch00d.txt ascii crlf
17:55:34 0:000E 1403 prt/prt00e.txt crlf noclear
17:55:34 0:000F 1403 prt/prt00f.txt crlf noclear
17:55:34 0:001F 3215 *syscons cmdpref(/)
17:55:34 0:00C0 3270
17:55:34 0:00C1 3270
17:55:34 0:00C2 3270
17:55:34 0:00C7 3287
17:55:34 0:010C 3505 jcl/dummy eof
17:55:34 0:0131 2314 dasd/sort01.131 [200 cyls] open
17:55:34 0:0132 2314 dasd/sort02.132 [200 cyls] open
17:55:34 0:0133 2314 dasd/sort03.133 [200 cyls] open
17:55:34 0:0134 2314 dasd/sort04.134 [200 cyls] open
17:55:34 0:0135 2314 dasd/sort05.135 [200 cyls] open
17:55:34 0:0136 2314 dasd/sort06.136 [200 cyls] open
17:55:34 0:0138 2314 dasd/dlicat.138 [200 cyls] open
17:55:34 0:0139 2314 dasd/dlisys.139 [200 cyls] open
17:55:34 0:013A 2314 dasd/dli000.13a [200 cyls] open
17:55:34 0:013B 2314 dasd/dli001.13b [200 cyls] open
17:55:34 0:013C 2314 dasd/dli002.13c [200 cyls] open
17:55:34 0:0140 3350 dasd/work00.140 [560 cyls] open
17:55:34 0:0148 3350 dasd/mvsres.148 [560 cyls] open
17:55:34 0:0149 3350 dasd/smp001.149 [560 cyls] open
17:55:34 0:014A 3350 dasd/smp002.14a [560 cyls] open
17:55:34 0:014B 3350 dasd/smp003.14b [560 cyls] open
17:55:34 0:014C 3350 dasd/smp004.14c [560 cyls] open
17:55:34 0:0150 3330 dasd/start1.150 [808 cyls] open
17:55:34 0:0151 3330 dasd/spool0.151 [808 cyls] open
17:55:34 0:0152 3330 dasd/hasp00.152 [404 cyls] open
17:55:34 0:0160 3340 dasd/page00.160 [698 cyls] open
17:55:34 0:0161 3340 dasd/page01.161 [698 cyls] open
17:55:34 0:0162 3340 dasd/page02.162 [698 cyls] open
17:55:34 0:0170 3375 dasd/work01.170 [962 cyls] open
17:55:34 0:01A0 3380 dasd/work02.180 [886 cyls] open
17:55:34 0:01B0 3390 dasd/work03.190 [1114 cyls] open
17:55:34 0:01B1 3390 dasd/mvscat.191 [1114 cyls] open
17:55:34 0:01B2 3390 dasd/seasik.192 [1114 cyls] open
17:55:34 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] open
17:55:34 0:01C7 3287
17:55:34 0:0240 3350 dasd/pub000.240 [560 cyls] open
17:55:34 0:0248 3350 dasd/mvsdlb.248 [560 cyls] open
17:55:34 0:02A0 3380 dasd/pub002.280 [1772 cyls] open
17:55:34 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] open
17:55:34 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] open
17:55:34 0:030E 1403 log/hardcopy.log crlf noclear
17:55:34 0:0340 3350 dasd/cbt000.340 [555 cyls] open
17:55:34 0:0341 3350 dasd/cbt001.341 [555 cyls] open
17:55:34 0:0342 3350 dasd/cbt002.342 [555 cyls] open
17:55:34 0:0343 3350 dasd/cbtcat.343 [555 cyls] open
17:55:34 0:0348 3350 dasd/src000.348 [555 cyls] open
17:55:34 0:0349 3350 dasd/src001.349 [555 cyls] open
17:55:34 0:034A 3350 dasd/src002.34a [555 cyls] open
17:55:34 0:034B 3350 dasd/srccat.34b [555 cyls] open
17:55:34 0:0400 3420 *
17:55:34 0:0401 3420 *
17:55:34 0:0402 3420 *
17:55:34 0:0403 3420 *
17:55:34 0:0700 3350 dasd/js2sp0.700 [555 cyls] open
17:55:34 0:0710 3350 dasd/js3sp0.710 [555 cyls] open
17:55:34 0:0711 3350 dasd/js3res.711 [555 cyls] open
17:55:34 logopt timestamp
17:55:34 HHCPN197I Log option set: TIMESTAMP
17:55:34 panrate 1000
17:55:34 # really need to wait for SVC120I, but if building MVS/380
17:55:34 # or some other stuffup with parms, need to trigger on an
17:55:34 # alternative. First one hit will clear targets.
17:55:34 # If we get a prompt for a device, cancel it
17:55:34 hao tgt IEF238D
17:55:34 HHCAO016I Target placed at index 0
17:55:34 hao cmd script conf/cancel.rc
17:55:34 HHCAO020I Command placed at index 0
17:55:34 hao tgt HASP395 DYNAMASK
17:55:34 HHCAO016I Target placed at index 1
17:55:34 hao cmd script conf/subjobs_slow.rc
17:55:34 HHCAO020I Command placed at index 1
17:55:34 hao tgt HASP373 SVC120I
17:55:34 HHCAO016I Target placed at index 2
17:55:34 hao cmd script conf/subjobs_fast.rc
17:55:34 HHCAO020I Command placed at index 2
17:55:34 hao tgt HASP436 REPLY
17:55:34 HHCAO016I Target placed at index 3
17:55:34 hao cmd script conf/replyy.rc
17:55:34 HHCAO020I Command placed at index 3
17:55:34 devinit 402 tapes/mftopc.het
17:55:34 HHCTA004I 0402: tapes/mftopc.het is a Hercules Emulated Tape file
17:55:34 HHCPN098I Device 0:0402 initialized
17:55:34 devinit 403 tapes/awstap.aws
17:55:34 HHCTA004I 0403: tapes/awstap.aws is a Hercules Emulated Tape file
17:55:34 HHCPN098I Device 0:0403 initialized
17:55:34 # co will give you a cold start of JES2 which is useful in
17:55:34 # automated runs
17:55:34 /(001F) r 00,clpa,cmd=co
17:55:34 #/r 00,clpa
17:55:34 ipl 148
17:55:34 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:34 IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
17:55:34 HHCCD001I Readahead thread 1 started: tid=000057AC, pid=12296
17:55:34 HHCCD001I Readahead thread 2 started: tid=00003280, pid=12296
17:55:34 HHCCD002I Writer thread 1 started: tid=000032A0, pid=12296
17:55:34 HHCCD003I Garbage collector thread started: tid=00003D74, pid=12296
17:55:34 IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
17:55:34 PLPA ... SYS1.PAGELPA
17:55:34 COMMON . SYS1.PAGECSA
17:55:34 DUPLEX . SYS1.DUPLEX
17:55:34 LOCAL .. SYS1.PAGEL01
17:55:34 LOCAL .. SYS1.PAGEL02
17:55:34 LOCAL .. SYS1.PAGEL03
17:55:34 HHCCD002I Writer thread 2 started: tid=0000084C, pid=12296
17:55:35 *IEE362A SMF ENTER DUMP FOR SYS1.MANY ON MVSRES
17:55:35 IEE360I SMF NOW RECORDING ON SYS1.MANX ON MVSRES TIME=06.55.35
17:55:35 IGF992I MIH INIT COMPLETE, PRI=000300, SEC=000015
17:55:36 IEF677I WARNING MESSAGE(S) FOR JOB JES2 ISSUED
17:55:36 *00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
17:55:36 HHCAO003I Firing command: 'script conf/replyy.rc'
17:55:36 script conf/replyy.rc
17:55:36 /(001F) reply 00,y
17:55:36 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:36 IEE600I REPLY TO 00 IS;SUPPRESSED
17:55:36 $HASP493 JES2 COLD-START IS IN PROGRESS
17:55:36 $HASP412 MAXIMUM OF 1 READER(S) EXCEEDED
17:55:36 06.55.36 IEE041I THE SYSTEM LOG IS NOW ACTIVE
17:55:36 06.55.36 IEE302I 00E ONLINE
17:55:36 06.55.36 IEE302I 00F ONLINE
17:55:36 06.55.36 IEE313I 30E UNIT REF INVALID
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 IEE450I 06.55.36 UNIT STATUS 160
17:55:36 UNIT TYPE STATUS VOLSER VOLSTATE UNIT TYPE STATUS VOLSER VOLSTATE
17:55:36 400 3400 O /REMOV 401 3400 O /REMOV
17:55:36 UNIT TYPE STATUS VOLSER VOLSTATE UNIT TYPE STATUS VOLSER VOLSTATE
17:55:36 400 3400 O /REMOV 401 3400 O /REMOV
17:55:36 402 3400 O /REMOV
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP000 OK
17:55:36 06.55.36 $HASP160 PRINTER1 INACTIVE - CLASS=AP
17:55:36 06.55.36 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:36 06.55.36 $HASP160 PUNCH1 INACTIVE - CLASS=B
17:55:36 06.55.36 STC 2 $HASP100 INIT ON STCINRDR
17:55:36 06.55.36 STC 2 $HASP373 INIT STARTED
17:55:36 06.55.36 STC 2 IEF403I INIT - STARTED - TIME=06.55.36
17:55:36 06.55.36 STC 3 $HASP100 INIT ON STCINRDR
17:55:36 06.55.36 STC 3 $HASP373 INIT STARTED
17:55:36 06.55.36 STC 3 IEF403I INIT - STARTED - TIME=06.55.36
17:55:36 06.55.36 STC 4 $HASP100 INIT ON STCINRDR
17:55:36 06.55.36 STC 4 $HASP373 INIT STARTED
17:55:36 06.55.36 STC 4 IEF403I INIT - STARTED - TIME=06.55.36
17:55:37 06.55.37 STC 5 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 5 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 5 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 6 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 6 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 6 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 7 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 7 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 7 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 8 $HASP100 INIT ON STCINRDR
17:55:37 06.55.37 STC 8 $HASP373 INIT STARTED
17:55:37 06.55.37 STC 8 IEF403I INIT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 9 $HASP100 SVC120I ON STCINRDR
17:55:37 06.55.37 STC 9 $HASP373 SVC120I STARTED
17:55:37 HHCAO003I Firing command: 'script conf/subjobs_fast.rc'
17:55:37 script conf/subjobs_fast.rc
17:55:37 # Now we know that SVC120I has started. But due to some
17:55:37 # weird pausing, it may get locked out. So clear out
17:55:37 # other triggers and wait on this
17:55:37 hao clear
17:55:37 HHCAO022I All automatic operation rules cleared
17:55:37 hao tgt HASP250 SVC120I
17:55:37 HHCAO016I Target placed at index 0
17:55:37 hao cmd script conf/subjobs.rc
17:55:37 HHCAO020I Command placed at index 0
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:37 06.55.37 STC 9 IEF403I SVC120I - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 10 $HASP100 DYNABLDL ON STCINRDR
17:55:37 06.55.37 STC 10 $HASP373 DYNABLDL STARTED
17:55:37 06.55.37 STC 10 IEF403I DYNABLDL - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 11 $HASP100 DYNAMASK ON STCINRDR
17:55:37 06.55.37 STC 11 $HASP373 DYNAMASK STARTED
17:55:37 06.55.37 STC 11 IEF403I DYNAMASK - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 12 $HASP100 BSPPILOT ON STCINRDR
17:55:37 06.55.37 STC 12 $HASP373 BSPPILOT STARTED
17:55:37 06.55.37 STC 12 IEF403I BSPPILOT - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 13 $HASP100 BSPSETPF ON STCINRDR
17:55:37 06.55.37 STC 13 $HASP373 BSPSETPF STARTED
17:55:37 06.55.37 STC 13 IEF403I BSPSETPF - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 14 $HASP100 LOGRECI ON STCINRDR
17:55:37 06.55.37 STC 14 $HASP373 LOGRECI STARTED
17:55:37 06.55.37 STC 14 IEF403I LOGRECI - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 15 $HASP100 NET ON STCINRDR
17:55:37 06.55.37 STC 15 $HASP373 NET STARTED
17:55:37 06.55.37 STC 15 IEF403I NET - STARTED - TIME=06.55.37
17:55:37 06.55.37 $HASP309 INIT 1 INACTIVE ******** C=A
17:55:37 06.55.37 $HASP309 INIT 2 INACTIVE ******** C=BA
17:55:37 06.55.37 $HASP309 INIT 3 INACTIVE ******** C=CBA
17:55:37 06.55.37 $HASP309 INIT 4 INACTIVE ******** C=SHB
17:55:37 06.55.37 $HASP309 INIT 5 INACTIVE ******** C=SBA
17:55:37 06.55.37 $HASP309 INIT 6 INACTIVE ******** C=S
17:55:37 06.55.37 $HASP309 INIT 7 INACTIVE ******** C=E
17:55:37 06.55.37 STC 9 BSPGM40I - 200 MiB MAINSIZE memory available
17:55:37 06.55.37 STC 9 BSPGM41I - 2 Partitions of 64 MiB each
17:55:37 06.55.37 STC 9 BSPGM78I SVC 120 EP=00FE3210; MVS/380
17:55:37 06.55.37 STC 9 IEF404I SVC120I - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 9 $HASP395 SVC120I ENDED
17:55:37 06.55.37 STC 9 $HASP150 SVC120I ON PRINTER2 45 LINES
17:55:37 06.55.37 STC 9 *$HASP190 SVC120I SETUP -- PRINTER2 -- F = 0001 -- C = 6 -- T = SN
17:55:37 06.55.37 $HASP000 OK
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 9 $HASP250 SVC120I IS PURGED
17:55:37 HHCAO003I Firing command: 'script conf/subjobs.rc'
17:55:37 script conf/subjobs.rc
17:55:37 hao clear
17:55:37 HHCAO022I All automatic operation rules cleared
17:55:37 # Every job gets an NL tape available as input, containing
17:55:37 # some binary of unknown contents, most likely needing to
17:55:37 # be read as RECFM=U, but RECFM=FB and even RECFM=V are also
17:55:37 # possible.
17:55:37 #
17:55:37 # The job also gets an SL tape available for output, and
17:55:37 # again, any type of content can be written to it, and
17:55:37 # with a bit of luck, hetget will be able to extract the
17:55:37 # data you are looking for.
17:55:37 #
17:55:37 # And finally the job gets an SL AWS tape available for
17:55:37 # input and/or output should you wish to construct a
17:55:37 # special tape. Tape must be called AWSTAP. User should
17:55:37 # back the tape up before submitting it, because it will
17:55:37 # be overwritten and anything could go wrong. AWS is
17:55:37 # expected to be exceptional use of this procedure anyway
17:55:37 #
17:55:37 # Only the NL tape needs an explicit mount. The SL tapes
17:55:37 # are premounted before IPL
17:55:37 hao tgt HASP250 MOUNT
17:55:37 HHCAO016I Target placed at index 0
17:55:37 hao cmd script conf/subjobs2.rc
17:55:37 HHCAO020I Command placed at index 0
17:55:37 /(001F) M 401,VOL=(NL,PCTOMF)
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAE IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAK IN VTAMLIB
17:55:37 06.55.37 STC 15 IST025I BLDL FAILED FOR IEDIAK IN VTAMLIB
17:55:37 06.55.37 STC 15 IST110I NETWORK SOLICITOR STARTED
17:55:37 06.55.37 STC 15 IST093I APPLJRP ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLPIES ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLPIAD ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLTSO ACTIVE
17:55:37 06.55.37 STC 15 IST093I APPLTEST ACTIVE
17:55:37 06.55.37 STC 10 DYNABLDL STARTED
17:55:37 06.55.37 STC 15 IST093I LCLMAJRP ACTIVE
17:55:37 06.55.37 STC 10 IEF404I DYNABLDL - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 10 $HASP395 DYNABLDL ENDED
17:55:37 06.55.37 STC 10 $HASP150 DYNABLDL ON PRINTER2 21 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 10 $HASP250 DYNABLDL IS PURGED
17:55:37 06.55.37 STC 15 IST093I LCLMAJ00 ACTIVE
17:55:37 06.55.37 STC 16 $HASP100 TSO ON STCINRDR
17:55:37 06.55.37 STC 16 $HASP373 TSO STARTED
17:55:37 06.55.37 STC 16 IEF403I TSO - STARTED - TIME=06.55.37
17:55:37 06.55.37 STC 17 $HASP100 JRP ON STCINRDR
17:55:37 06.55.37 STC 17 $HASP373 JRP STARTED
17:55:37 06.55.37 STC 17 IEF403I JRP - STARTED - TIME=06.55.37
17:55:37 06.55.37 $HASP000 OK
17:55:37 06.55.37 $HASP000 OK
17:55:37 06.55.37 STC 15 IST020I VTAM INITIALIZATION COMPLETE
17:55:37 06.55.37 STC 15 IEA000I 0C0,IOE,05,0200,400000000001,,,NET ,06.55.37
17:55:37 06.55.37 STC 15 IEA000I 0C1,IOE,05,0200,400000000001,,,NET ,06.55.37
17:55:37 06.55.37 STC 15 IEA000I 0C2,IOE,05,0200,400000000001,,,NET ,06.55.37
17:55:37 06.55.37 STC 11 DMSK00I DYNAMASK DONE ****
17:55:37 06.55.37 STC 11 DMSK06I START
17:55:37 06.55.37 STC 11 IEF404I DYNAMASK - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 11 $HASP395 DYNAMASK ENDED
17:55:37 06.55.37 STC 11 $HASP150 DYNAMASK ON PRINTER2 30 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 11 $HASP250 DYNAMASK IS PURGED
17:55:37 06.55.37 STC 13 BSPSP91I - Parms passed: NOREPLYU
17:55:37 06.55.37 STC 13 BSPSP93I - PFK definitions will be updated in memory
17:55:37 06.55.37 STC 13 BSPSP22I - Dataset processed: SYS1.PARMLIB
17:55:37 06.55.37 STC 13 BSPSP23I - on volume MVSRES
17:55:37 06.55.37 STC 13 BSPSP21I - Member being processed: SETPFK01
17:55:37 06.55.37 STC 13 +BSPSP98I - Member processed, LASTCC=0000
17:55:37 06.55.37 STC 13 +BSPSP21I - Member being processed: SETPFK02
17:55:37 06.55.37 STC 13 +BSPSP98I - Member processed, LASTCC=0000
17:55:37 06.55.37 STC 13 +BSPSP99I - End of processing, MAXRC=0000
17:55:37 06.55.37 STC 13 IEF404I BSPSETPF - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 13 $HASP395 BSPSETPF ENDED
17:55:37 06.55.37 STC 13 $HASP150 BSPSETPF ON PRINTER2 34 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 13 $HASP250 BSPSETPF IS PURGED
17:55:37 06.55.37 STC 14 IFC001I D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
17:55:37 06.55.37 STC 14 IEF404I LOGRECI - ENDED - TIME=06.55.37
17:55:37 06.55.37 STC 14 $HASP395 LOGRECI ENDED
17:55:37 06.55.37 STC 14 $HASP150 LOGRECI ON PRINTER2 20 LINES
17:55:37 06.55.37 $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:55:37 06.55.37 STC 14 $HASP250 LOGRECI IS PURGED
17:55:37 06.55.37 STC 16 IKT007I TCAS ACCEPTING LOGONS
17:55:37 06.55.37 STC 16 IKT005I TCAS IS INITIALIZED
17:55:37 06.55.37 STC 17 JRPI101 INITIALIZATION COMPLETE
17:55:37 06.55.37 STC 17 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
18:08:34 /(001F) M 401,VOL=(NL,PCTOMF)
18:08:34 07.08.34 STC 18 $HASP100 MOUNT ON STCINRDR
18:08:34 07.08.34 STC 18 $HASP373 MOUNT STARTED
18:08:34 07.08.34 STC 18 IEF403I MOUNT - STARTED - TIME=07.08.34
18:08:34 07.08.34 STC 18 *IEF233A M 401,PCTOMF,,MOUNT,401
18:08:34 07.08.34 STC 18 IEF404I MOUNT - ENDED - TIME=07.08.34
18:08:34 07.08.34 STC 18 $HASP395 MOUNT ENDED
18:08:34 07.08.34 STC 18 $HASP150 MOUNT ON PRINTER2 18 LINES
18:08:34 07.08.34 $HASP160 PRINTER2 INACTIVE - CLASS=Z
18:08:34 07.08.34 STC 18 $HASP250 MOUNT IS PURGED
18:08:34 HHCAO003I Firing command: 'script conf/subjobs2.rc'
18:08:34 script conf/subjobs2.rc
18:08:34 hao clear
18:08:34 HHCAO022I All automatic operation rules cleared
18:08:34 # If we get a prompt for a device, cancel it
18:08:34 hao tgt IEF238D
18:08:34 HHCAO016I Target placed at index 0
18:08:34 hao cmd script conf/cancel.rc
18:08:34 HHCAO020I Command placed at index 0
18:08:34 # If we get a prompt for a catalogue password, answer it
18:08:34 hao tgt IEC301A
18:08:34 HHCAO016I Target placed at index 1
18:08:34 hao cmd script conf/secret.rc
18:08:34 HHCAO020I Command placed at index 1
18:08:34 devinit 401 tapes/pctomf.tdf
18:08:34 HHCTA004I 0401: tapes/pctomf.tdf is a Optical Media Attachment (OMA) tape
18:08:34 HHCPN098I Device 0:0401 initialized
18:08:34 # When we see TERMHERC get purged, our job is done
18:08:34 hao tgt HASP373 TERMHERC
18:08:34 HHCAO016I Target placed at index 2
18:08:34 hao cmd script conf/termherc.rc
18:08:34 HHCAO020I Command placed at index 2
18:08:34 # Now submit the job
18:08:34 devinit 00c jcl/hercauto.jcl eof
18:08:34 HHCSD007I Device 000C unbound from socket 127.0.0.1:3505
18:08:34 HHCSD022I Socketdevice listener thread terminated
18:08:34 HHCPN098I Device 0:000C initialized
18:08:34 HHCPN013I EOF reached on SCRIPT file. Processing complete.
18:08:34 07.08.34 JOB 1 $HASP100 HERC01A ON READER1
18:08:34 07.08.34 JOB 2 $HASP100 TERMHERC ON READER1
18:08:34 07.08.34 JOB 1 $HASP373 HERC01A STARTED - INIT 3 - CLASS C - SYS BSP1
18:08:34 07.08.34 JOB 1 IEF403I HERC01A - STARTED - TIME=07.08.34
18:08:34 07.08.34 JOB 1 IEFACTRT - Stepname Procstep Program Retcode
18:08:34 07.08.34 JOB 1 HERC01A IEFBR14 IEFBR14 RC= 0000
18:08:34 07.08.34 JOB 1 IEF404I HERC01A - ENDED - TIME=07.08.34
18:08:34 07.08.34 JOB 1 $HASP395 HERC01A ENDED
18:08:34 07.08.34 JOB 1 $HASP150 HERC01A ON PRINTER1 21 LINES
18:08:34 07.08.34 JOB 1 *$HASP190 HERC01A SETUP -- PRINTER1 -- F = 0001 -- C = 6 -- T = SN
18:08:34 07.08.34 $HASP000 OK
18:08:34 07.08.34 $HASP160 PRINTER1 INACTIVE - CLASS=AP
18:08:34 07.08.34 JOB 1 $HASP250 HERC01A IS PURGED
18:08:34 07.08.34 *IEE362A SMF ENTER DUMP FOR SYS1.MANX ON MVSRES
18:08:34 07.08.34 IEE361I SMF DATA LOST - SYS1.MANY NOT AVAILABLE TIME=07.08.34
18:08:34 07.08.34 STC 19 $HASP100 SMFDAILY ON STCINRDR
18:08:34 07.08.34 STC 19 $HASP373 SMFDAILY STARTED
18:08:34 07.08.34 STC 19 IEF403I SMFDAILY - STARTED - TIME=07.08.34
18:08:34 07.08.34 JOB 2 $HASP373 TERMHERC STARTED - INIT 3 - CLASS C - SYS BSP1
18:08:34 HHCAO003I Firing command: 'script conf/termherc.rc'
18:08:34 script conf/termherc.rc
18:08:34 # We do an unnecessary 2-stage terminate, first triggering
18:08:34 # on the start message, then triggering on the purged
18:08:34 # message, to overcome an apparent bug in hercules which
18:08:34 # causes it to sometimes trigger on the wrong jobname.
18:08:34 hao clear
18:08:34 HHCAO022I All automatic operation rules cleared
18:08:34 hao tgt HASP250 TERMHERC
18:08:34 HHCAO016I Target placed at index 0
18:08:34 hao cmd script conf/termherc2.rc
18:08:34 HHCAO020I Command placed at index 0
18:08:34 HHCPN013I EOF reached on SCRIPT file. Processing complete.
18:08:34 07.08.34 JOB 2 IEF403I TERMHERC - STARTED - TIME=07.08.34
18:08:34 07.08.34 STC 19 IEF453I SMFDAILY - JOB FAILED - JCL ERROR - TIME=07.08.34
18:08:34 07.08.34 STC 19 $HASP395 SMFDAILY ENDED
18:08:34 07.08.34 STC 19 $HASP150 SMFDAILY ON PRINTER2 25 LINES
18:08:34 07.08.34 IEE132I START COMMAND DEVICE ALLOCATION ERROR
18:08:34 07.08.34 $HASP160 PRINTER2 INACTIVE - CLASS=Z
18:08:34 07.08.34 STC 19 $HASP250 SMFDAILY IS PURGED
18:08:34 07.08.34 JOB 2 IEFACTRT - Stepname Procstep Program Retcode
18:08:34 07.08.34 JOB 2 TERMHERC S1 IEBGENER RC= 0000
18:08:34 07.08.34 JOB 2 IEF404I TERMHERC - ENDED - TIME=07.08.34
18:08:34 07.08.34 JOB 2 $HASP395 TERMHERC ENDED
18:08:34 07.08.34 $HASP309 INIT 3 INACTIVE ******** C=CBA
18:08:34 07.08.34 JOB 2 $HASP150 TERMHERC ON PRINTER1 1 LINE
18:08:34 07.08.34 JOB 2 $HASP150 TERMHERC ON PRINTER2 44 LINES
18:08:34 07.08.34 $HASP160 PRINTER1 INACTIVE - CLASS=AP
18:08:34 07.08.34 $HASP160 PRINTER2 INACTIVE - CLASS=Z
18:08:34 07.08.34 JOB 2 $HASP250 TERMHERC IS PURGED
18:08:34 HHCAO003I Firing command: 'script conf/termherc2.rc'
18:08:34 script conf/termherc2.rc
18:08:34 # we put in an unnecessary "stopall" to prevent Hercules
18:08:34 # (3.07 and 3.12 at least) from randomly hanging in the
18:08:34 # "quit" command in about 5% of runs.
18:08:34 # It is still unclear why Hercules is hanging
18:08:34 stopall
18:08:34 quit
18:08:34 HHCIN900I Begin Hercules shutdown
18:08:34 HHCIN901I Releasing configuration
18:08:34 HHCCP008I CPU0000 thread ended: tid=00004558, pid=12296
18:08:34 HHCCF047I Subchannel 0:0000 detached
18:08:34 HHCCF047I Subchannel 0:0001 detached
18:08:34 HHCCF047I Subchannel 0:0002 detached
18:08:34 HHCCF047I Subchannel 0:0003 detached
18:08:34 HHCTT003I Timer thread ended
18:08:34 HHCCF047I Subchannel 0:0004 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 19358135 5% 4 1137 4702 42 1019 1998
18:08:34 HHCCD214I 161 31
18:08:34 HHCCD215I dasd/mvsres.148
18:08:34 HHCCD216I [0] 15179178 0% 1 ro 950 0 19
18:08:34 HHCCD217I shadow/mvsres_*.148
18:08:34 HHCCD218I [1] 4178957 20% 3 187 4702 23
18:08:34 HHCCF047I Subchannel 0:0005 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort01.131
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort01_*.131
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0006 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort02.132
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort02_*.132
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0007 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort03.133
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort03_*.133
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0008 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort04.134
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort04_*.134
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0009 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort05.135
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort05_*.135
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:000A detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 35424 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/sort06.136
18:08:34 HHCCD216I [0] 34336 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/sort06_*.136
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:000B detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 52422417 2% 77 1 0 2 0 1
18:08:34 HHCCD215I dasd/work00.140
18:08:34 HHCCD216I [0] 141963 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/work00_*.140
18:08:34 HHCCD218I [1] 52280454 2% 76 0 0 1
18:08:34 HHCCF047I Subchannel 0:000C detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 5023930 3% 5 1 0 1 0 1
18:08:34 HHCCD215I dasd/hasp00.152
18:08:34 HHCCD216I [0] 5023930 3% 5 rw 1 0 1
18:08:34 HHCCF047I Subchannel 0:000D detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 9896583 12% 17 1971 38432 32 1300 2576
18:08:34 HHCCD214I 695 66
18:08:34 HHCCD215I dasd/page00.160
18:08:34 HHCCD216I [0] 9896583 12% 17 rw 1971 38432 32
18:08:34 HHCCF047I Subchannel 0:000E detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 4719568 28% 3 213 77145 32 200 311
18:08:34 HHCCD214I 102 14
18:08:34 HHCCD215I dasd/page01.161
18:08:34 HHCCD216I [0] 4719568 28% 3 rw 213 77145 32
18:08:34 HHCCF047I Subchannel 0:000F detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 3833787 18% 4 120 45815 19 140 203
18:08:34 HHCCD214I 57 7
18:08:34 HHCCD215I dasd/page02.162
18:08:34 HHCCD216I [0] 3833787 18% 4 rw 120 45815 19
18:08:34 HHCCF047I Subchannel 0:0010 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 57202932 1% 102 1 0 1 0 1
18:08:34 HHCCD215I dasd/work01.170
18:08:34 HHCCD216I [0] 57202932 1% 102 rw 1 0 1
18:08:34 HHCCF047I Subchannel 0:0011 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 66815692 2% 425 1 0 2 0 1
18:08:34 HHCCD215I dasd/work02.180
18:08:34 HHCCD216I [0] 113799 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/work02_*.180
18:08:34 HHCCD218I [1] 66701893 2% 424 0 0 1
18:08:34 HHCCF047I Subchannel 0:0012 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 56476534 2% 264 1 0 2 0 1
18:08:34 HHCCD215I dasd/work03.190
18:08:34 HHCCD216I [0] 142257 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/work03_*.190
18:08:34 HHCCD218I [1] 56334277 2% 263 0 0 1
18:08:34 HHCCF047I Subchannel 0:0013 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 17037777 9% 16 17 1 5 15 31
18:08:34 HHCCD214I 2 3
18:08:34 HHCCD215I dasd/mvscat.191
18:08:34 HHCCD216I [0] 3658727 0% 1 ro 8 0 3
18:08:34 HHCCD217I shadow/mvscat_*.191
18:08:34 HHCCD218I [1] 13379050 11% 15 9 1 2
18:08:34 HHCCF047I Subchannel 0:0014 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 103500159 17% 1297 1 0 2 0 1
18:08:34 HHCCD215I dasd/seasik.192
18:08:34 HHCCD216I [0] 16164960 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/seasik_*.192
18:08:34 HHCCD218I [1] 87335199 20% 1297 0 0 1
18:08:34 HHCCF047I Subchannel 0:0015 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 168333900 4% 5454 1 0 1 0 1
18:08:34 HHCCD215I dasd/mvssrc.193
18:08:34 HHCCD216I [0] 168333900 4% 5454 rw 1 0 1
18:08:34 HHCCF047I Subchannel 0:0016 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 44516465 2% 22 33 0 9 39 66
18:08:34 HHCCD214I 6 2
18:08:34 HHCCD215I dasd/pub000.240
18:08:34 HHCCD216I [0] 7591138 3% 1 ro 12 0 5
18:08:34 HHCCD217I shadow/pub000_*.240
18:08:34 HHCCD218I [1] 36925327 2% 21 21 0 4
18:08:34 HHCCF047I Subchannel 0:0017 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 25722586 0% 5 24 1463 5 306 325
18:08:34 HHCCD214I 5 0
18:08:34 HHCCD215I dasd/mvsdlb.248
18:08:34 HHCCD216I [0] 25471539 0% 1 ro 3 0 3
18:08:34 HHCCD217I shadow/mvsdlb_*.248
18:08:34 HHCCD218I [1] 251047 39% 4 21 1463 2
18:08:34 HHCCF047I Subchannel 0:0018 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 100064666 8% 539 1 0 2 0 1
18:08:34 HHCCD215I dasd/pub002.280
18:08:34 HHCCD216I [0] 2171954 29% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/pub002_*.280
18:08:34 HHCCD218I [1] 97892712 8% 538 0 0 1
18:08:34 HHCCF047I Subchannel 0:0019 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 143545 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/tmptmp.2b1
18:08:34 HHCCD216I [0] 142257 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/tmptmp_*.2b1
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001A detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 143545 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/xmit90.2b2
18:08:34 HHCCD216I [0] 142257 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/xmit90_*.2b2
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001B detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 6099280 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/start1.150
18:08:34 HHCCD216I [0] 6098016 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/start1_*.150
18:08:34 HHCCD218I [1] 1264 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001C detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 4595678 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/spool0.151
18:08:34 HHCCD216I [0] 4594414 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/spool0_*.151
18:08:34 HHCCD218I [1] 1264 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001D detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 50622559 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbt000.340
18:08:34 HHCCD216I [0] 50621271 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbt000_*.340
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001E detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 53836805 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbt001.341
18:08:34 HHCCD216I [0] 53835517 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbt001_*.341
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:001F detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 46082980 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbt002.342
18:08:34 HHCCD216I [0] 46081692 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbt002_*.342
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0020 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 27241782 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/cbtcat.343
18:08:34 HHCCD216I [0] 27240494 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/cbtcat_*.343
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0021 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 46003602 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/src000.348
18:08:34 HHCCD216I [0] 46002314 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/src000_*.348
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0022 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 45707725 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/src001.349
18:08:34 HHCCD216I [0] 45706437 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/src001_*.349
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0023 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 44403653 0% 0 1 0 1 0 1
18:08:34 HHCCD215I dasd/src002.34a
18:08:34 HHCCD216I [0] 44402365 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/src002_*.34a
18:08:34 HHCCD218I [1] 1288 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:0024 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 6321674 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/srccat.34b
18:08:34 HHCCD216I [0] 6310767 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/srccat_*.34b
18:08:34 HHCCD218I [1] 10907 7% 1 0 0 0
18:08:34 HHCCF047I Subchannel 0:0025 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1118801 11% 2 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp001.149
18:08:34 HHCCD216I [0] 774654 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/smp001_*.149
18:08:34 HHCCD218I [1] 344147 38% 2 0 0 1
18:08:34 HHCCF047I Subchannel 0:0026 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1621663 24% 12 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp002.14a
18:08:34 HHCCD216I [0] 856740 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/smp002_*.14a
18:08:34 HHCCD218I [1] 764923 51% 12 0 0 1
18:08:34 HHCCF047I Subchannel 0:0027 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1077383 19% 3 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp003.14b
18:08:34 HHCCD216I [0] 592555 0% 0 ro 1 0 1
18:08:34 HHCCD217I shadow/smp003_*.14b
18:08:34 HHCCD218I [1] 484828 42% 3 0 0 1
18:08:34 HHCCF047I Subchannel 0:0028 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 3437923 36% 4 1 0 2 0 1
18:08:34 HHCCD215I dasd/smp004.14c
18:08:34 HHCCD216I [0] 2916431 35% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/smp004_*.14c
18:08:34 HHCCD218I [1] 521492 41% 3 0 0 1
18:08:34 HHCCF047I Subchannel 0:0029 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD211I readaheads misses
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 11902899 18% 18 125 81303 66 775 873
18:08:34 HHCCD214I 29 7
18:08:34 HHCCD215I dasd/js2sp0.700
18:08:34 HHCCD216I [0] 142291 0% 1 ro 0 0 1
18:08:34 HHCCD217I shadow/js2sp0_*.700
18:08:34 HHCCD218I [1] 11760608 19% 17 125 81303 65
18:08:34 HHCCF047I Subchannel 0:002A detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 715081 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dlicat.138
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dlicat_*.138
18:08:34 HHCCD218I [1] 678451 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002B detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 880289 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dlisys.139
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dlisys_*.139
18:08:34 HHCCD218I [1] 843659 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002C detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 43495 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dli000.13a
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dli000_*.13a
18:08:34 HHCCD218I [1] 6865 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002D detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 46911 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/dli001.13b
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dli001_*.13b
18:08:34 HHCCD218I [1] 10281 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:002E detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 37718 0% 1 1 0 1 0 1
18:08:34 HHCCD215I dasd/dli002.13c
18:08:34 HHCCD216I [0] 36630 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/dli002_*.13c
18:08:34 HHCCD218I [1] 1088 0% 0 0 0 0
18:08:34 HHCCF047I Subchannel 0:002F detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 1233964 0% 1 1 0 2 0 1
18:08:34 HHCCD215I dasd/js3sp0.710
18:08:34 HHCCD216I [0] 141965 0% 1 ro 1 0 1
18:08:34 HHCCD217I shadow/js3sp0_*.710
18:08:34 HHCCD218I [1] 1091999 0% 0 0 0 1
18:08:34 HHCCF047I Subchannel 0:0030 detached
18:08:34 HHCCD210I size free nbr st reads writes l2reads hits switches
18:08:34 HHCCD212I --------------------------------------------------------------------
18:08:34 HHCCD213I [*] 951745 0% 2 1 0 2 0 1
18:08:34 HHCCD215I dasd/js3res.711
18:08:34 HHCCD216I [0] 142093 0% 2 ro 1 0 1
18:08:34 HHCCD217I shadow/js3res_*.711
18:08:34 HHCCD218I [1] 809652 0% 0 0 0 1
18:08:34 HHCCD011I Readahead thread 2 stopping: tid=00003280, pid=12296
18:08:34 HHCCD011I Readahead thread 1 stopping: tid=000057AC, pid=12296
18:08:34 HHCCD013I Garbage collector thread stopping: tid=00003D74, pid=12296
18:08:34 HHCCD012I Writer thread 2 stopping: tid=0000084C, pid=12296
18:08:34 HHCCD012I Writer thread 1 stopping: tid=000032A0, pid=12296
18:08:34 HHCCF047I Subchannel 0:0031 detached
18:08:34 HHCCF047I Subchannel 0:0032 detached
18:08:34 HHCCF047I Subchannel 0:0033 detached
18:08:34 HHCCF047I Subchannel 0:0034 detached
18:08:34 HHCCF047I Subchannel 0:0035 detached
18:08:34 HHCCF047I Subchannel 0:0036 detached
18:08:34 HHCCF047I Subchannel 0:0037 detached
18:08:34 HHCTE004I Console connection thread terminated
18:08:34 HHCCF047I Subchannel 0:0038 detached
18:08:34 HHCCF047I Subchannel 0:0039 detached
18:08:34 HHCCF047I Subchannel 0:003A detached
18:08:34 HHCCF047I Subchannel 0:003B detached
18:08:34 HHCCF047I Subchannel 0:003C detached
18:08:34 HHCIN902I Configuration release complete
18:08:34 HHCIN903I Calling termination routines
18:08:34 HHCHD900I Begin shutdown sequence
18:08:34 HHCHD901I Calling panel_cleanup
18:08:34 HHCHD902I panel_cleanup complete
18:08:34 HHCHD901I Calling console_shutdown
18:08:34 HHCHD902I console_shutdown complete
18:08:34 HHCHD901I Calling term_sockdev
18:08:34 HHCHD902I term_sockdev complete
18:08:34 HHCHD901I Calling hdl_term
18:08:34 HHCHD950I Begin HDL termination sequence
18:08:34 HHCHD951I Calling module *Hercules cleanup routine
18:08:34 HHCHD952I Module *Hercules cleanup complete
18:08:34 HHCHD959I HDL Termination sequence complete
18:08:34 HHCHD902I hdl_term complete
18:08:34 HHCHD901I Calling logger_term
18:08:34 HHCLG014I logger thread terminating