Discussion:
[hercules-390] Hercules 3.12 (not 4.0) apparent HAO bug
kerravon86@yahoo.com.au [hercules-390]
2017-03-26 01:26:21 UTC
Permalink
While doing some "unrelated" Hercules test,
I found the below issue in 3.07 & 3.12 which
appears to have been fixed in 4.0.

The problem is, that after successfully
triggering here:

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

If I then attempt the same trigger:

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

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

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

Full log below.


Script subjobs2.rc is here:

hao clear

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

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


devinit 401 tapes/pctomf.tdf

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

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



(Ignore the incorrect comments about TERMHERC)

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

Thanks. Paul.




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

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

BFN. Paul.

Loading...