apparent console freeze

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

apparent console freeze

Hercules390 - General mailing list
I run a slightly-modified Hercules 3.07 automatically
via Windows batch files.

I tried setting it up to automatically do lots of
runs to see if I could reproduce an anomaly
I had discovered previously.

I was successful. In about 1 in 78 runs, the
console appears to freeze. Here is what
the console looks like:

04.37.49 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP                                                                                                                                              Command ==>                                                                                                                                                                                                        CPU0000 PSW=078D0000803708B8 31.....P..                                                                                                                                                       instcount=240,587,479

That was the first failure I documented.
The second looked very similar:

04.58.13 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP                                                                                                                                              Command ==>                                                                                                                                                                                                        CPU0000 PSW=078D1000800C437C 31.....P..                                                                                                                                                       instcount=245,442,500


It looked like Hercules was freezing on
the tape mount, but when I inspected
the hercules.log (for the first failure),
it showed:

15:37:49 04.37.49 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP
15:37:49 04.37.49 JOB    1  IEF234E K 402,MFTOPC,PVT,MVSGCC,COMP
15:37:49 04.37.49 JOB    1  IEFACTRT - Stepname  Procstep  Program   Retcode
15:37:49 04.37.49 JOB    1  MVSGCC     S1        COMP      GCC       RC= 0000
15:37:49 04.37.49 JOB    1  IEF404I MVSGCC - ENDED - TIME=04.37.49

ie the job ended cleanly, and it
even got to the "quit" stage. Here
is the end of the hercules.log:

15:37:49 04.37.49 JOB    2  $HASP250 TERMHERC IS PURGED
15:37:49 HHCAO003I Firing command: 'script conf/termherc2.rc'
15:37:49 script conf/termherc2.rc
15:37:49 quit
15:37:49 HHCIN900I Begin Hercules shutdown
15:37:49 HHCIN901I Releasing configuration


But the Hercules integrated console
was never updated.

The sequence I normally expect after
a "quit" is:

15:58:08 04.58.08 JOB    2  $HASP250 TERMHERC IS PURGED
15:58:08 HHCAO003I Firing command: 'script conf/termherc2.rc'
15:58:08 script conf/termherc2.rc
15:58:08 quit
15:58:08 HHCIN900I Begin Hercules shutdown
15:58:08 HHCIN901I Releasing configuration
15:58:08 HHCCP008I CPU0000 thread ended: tid=00002390, pid=8160
15:58:08 HHCCF047I Subchannel 0:0000 detached
15:58:08 HHCTT003I Timer thread ended
15:58:08 HHCCF047I Subchannel 0:0001 detached
15:58:08 HHCCF047I Subchannel 0:0002 detached
15:58:08 HHCCF047I Subchannel 0:0003 detached
15:58:08 HHCCF047I Subchannel 0:0004 detached
15:58:08 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
15:58:08 HHCCD211I                                                  readaheads   misses
15:58:08 HHCCD212I --------------------------------------------------------------------
15:58:08 HHCCD213I [*]   18648958   0%   20       1122      25      34    1037     2001
15:58:08 HHCCD214I                                                         161       23
15:58:08 HHCCD215I dasd/mvsres.148
15:58:08 HHCCD216I [0]   15179178   0%    1 ro     942       0      17
15:58:08 HHCCD217I shadow/mvsres_*.148
15:58:08 HHCCD218I [1]    3469780   0%   19        180      25      17
15:58:08 HHCCF047I Subchannel 0:0005 detached
15:58:08 HHCCD210I           size free  nbr st   reads  writes l2reads    hits switches
15:58:08 HHCCD212I --------------------------------------------------------------------
15:58:08 HHCCD213I [*]      35424   0%    1          1       0       1       0        1
15:58:08 HHCCD215I dasd/sort01.131

(etc)


Does anyone recognize the problem?

If not, I will attempt to reproduce the
problem with a later version of Hercules.
I'll need to change my job a bit though,
since it relies on OMA extensions.

Full log of first failure below.

Thanks. Paul.




15:37:44 Hercules Version 3.07:380-4.x
15:37:44 (c)Copyright 1999-2010 by Roger Bowler, Jan Jaeger, and others
15:37:44 Built on Dec  7 2016 at 12:43:32
15:37:44 Build information:
15:37:44   Windows (MSVC) build for AMD64
15:37:44   Modes: S/370 S/380 ESA/390 z/Arch
15:37:44   Max CPU Engines: 8
15:37:44   Using fthreads instead of pthreads
15:37:44   Dynamic loading support
15:37:44   Using shared libraries
15:37:44   HTTP Server support
15:37:44   No SIGABEND handler
15:37:44   Regular Expressions support
15:37:44   Automatic Operator support
15:37:44   Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8
15:37:44 Running on PAUL-DELL Windows_NT-6.2 AMD64 MP=8
15:37:44 HHCHD018I Loadable module directory is hercules
15:37:44 Crypto module loaded (c) Copyright Bernard van der Helm, 2003-2010
15:37:44   Active: Message Security Assist
15:37:44           Message Security Assist Extension 1
15:37:44           Message Security Assist Extension 2
15:37:44 HHCPN210I Default Allowed AUTOMOUNT directory = "c:\mvs380\"
15:37:44 HHCHT001I HTTP listener thread started: tid=00001C94, pid=17944
15:37:44 HHCCF065I Hercules: tid=00002AE8, pid=17944, pgid=17944, priority=8
15:37:44 HHCCF066E Invalid HTTPROOT: "c:\herc380\html": No such file or directory
15:37:44 HHCSD004I Device 000C bound to socket 127.0.0.1:3505
15:37:44 HHCSD020I Socketdevice listener thread started: tid=0000204C, pid=17944
15:37:44 HHCCF083I conf/mvs380.conf Including conf/mvs380_DASD.conf at 122 .
15:37:44 HHCDA004I opening dasd/mvsres.148 readonly
15:37:44 HHCDA020I dasd/mvsres.148 cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/sort01.131 readonly
15:37:44 HHCDA020I dasd/sort01.131 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/sort02.132 readonly
15:37:44 HHCDA020I dasd/sort02.132 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/sort03.133 readonly
15:37:44 HHCDA020I dasd/sort03.133 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/sort04.134 readonly
15:37:44 HHCDA020I dasd/sort04.134 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/sort05.135 readonly
15:37:44 HHCDA020I dasd/sort05.135 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/sort06.136 readonly
15:37:44 HHCDA020I dasd/sort06.136 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/work00.140 readonly
15:37:44 HHCDA020I dasd/work00.140 cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA020I dasd/hasp00.152 cyls=404 heads=19 tracks=7676 trklen=13312
15:37:44 HHCDA020I dasd/page00.160 cyls=698 heads=12 tracks=8376 trklen=8704
15:37:44 HHCDA020I dasd/page01.161 cyls=698 heads=12 tracks=8376 trklen=8704
15:37:44 HHCDA020I dasd/page02.162 cyls=698 heads=12 tracks=8376 trklen=8704
15:37:44 HHCDA020I dasd/work01.170 cyls=962 heads=12 tracks=11544 trklen=35840
15:37:44 HHCDA004I opening dasd/work02.180 readonly
15:37:44 HHCDA020I dasd/work02.180 cyls=886 heads=15 tracks=13290 trklen=47616
15:37:44 HHCDA004I opening dasd/work03.190 readonly
15:37:44 HHCDA020I dasd/work03.190 cyls=1114 heads=15 tracks=16710 trklen=56832
15:37:44 HHCDA004I opening dasd/mvscat.191 readonly
15:37:44 HHCDA020I dasd/mvscat.191 cyls=1114 heads=15 tracks=16710 trklen=56832
15:37:44 HHCDA004I opening dasd/seasik.192 readonly
15:37:44 HHCDA020I dasd/seasik.192 cyls=1114 heads=15 tracks=16710 trklen=56832
15:37:44 HHCDA020I dasd/mvssrc.193 cyls=2226 heads=15 tracks=33390 trklen=56832
15:37:44 HHCDA002E 01B4:File not found or invalid 'dasd/pub004.1b4'
15:37:44 HHCCF044E Initialization failed for device 01B4
15:37:44 HHCDA004I opening dasd/pub000.240 readonly
15:37:44 HHCDA020I dasd/pub000.240 cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/mvsdlb.248 readonly
15:37:44 HHCDA020I dasd/mvsdlb.248 cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/pub002.280 readonly
15:37:44 HHCDA020I dasd/pub002.280 cyls=1772 heads=15 tracks=26580 trklen=47616
15:37:44 HHCDA004I opening dasd/tmptmp.2b1 readonly
15:37:44 HHCDA020I dasd/tmptmp.2b1 cyls=1114 heads=15 tracks=16710 trklen=56832
15:37:44 HHCDA004I opening dasd/xmit90.2b2 readonly
15:37:44 HHCDA020I dasd/xmit90.2b2 cyls=1114 heads=15 tracks=16710 trklen=56832
15:37:44 HHCDA004I opening dasd/start1.150 readonly
15:37:44 HHCDA020I dasd/start1.150 cyls=808 heads=19 tracks=15352 trklen=13312
15:37:44 HHCDA004I opening dasd/spool0.151 readonly
15:37:44 HHCDA020I dasd/spool0.151 cyls=808 heads=19 tracks=15352 trklen=13312
15:37:44 HHCDA004I opening dasd/cbt000.340 readonly
15:37:44 HHCDA020I dasd/cbt000.340 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/cbt001.341 readonly
15:37:44 HHCDA020I dasd/cbt001.341 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/cbt002.342 readonly
15:37:44 HHCDA020I dasd/cbt002.342 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/cbtcat.343 readonly
15:37:44 HHCDA020I dasd/cbtcat.343 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/src000.348 readonly
15:37:44 HHCDA020I dasd/src000.348 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/src001.349 readonly
15:37:44 HHCDA020I dasd/src001.349 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/src002.34a readonly
15:37:44 HHCDA020I dasd/src002.34a cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/srccat.34b readonly
15:37:44 HHCDA020I dasd/srccat.34b cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/smp001.149 readonly
15:37:44 HHCDA020I dasd/smp001.149 cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/smp002.14a readonly
15:37:44 HHCDA020I dasd/smp002.14a cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/smp003.14b readonly
15:37:44 HHCDA020I dasd/smp003.14b cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/smp004.14c readonly
15:37:44 HHCDA020I dasd/smp004.14c cyls=560 heads=30 tracks=16800 trklen=19456
15:37:44 HHCDA004I opening dasd/js2sp0.700 readonly
15:37:44 HHCDA020I dasd/js2sp0.700 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/dlicat.138 readonly
15:37:44 HHCDA020I dasd/dlicat.138 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/dlisys.139 readonly
15:37:44 HHCDA020I dasd/dlisys.139 cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/dli000.13a readonly
15:37:44 HHCDA020I dasd/dli000.13a cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/dli001.13b readonly
15:37:44 HHCDA020I dasd/dli001.13b cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/dli002.13c readonly
15:37:44 HHCDA020I dasd/dli002.13c cyls=200 heads=20 tracks=4000 trklen=7680
15:37:44 HHCDA004I opening dasd/js3sp0.710 readonly
15:37:44 HHCDA020I dasd/js3sp0.710 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCDA004I opening dasd/js3res.711 readonly
15:37:44 HHCDA020I dasd/js3res.711 cyls=555 heads=30 tracks=16650 trklen=19456
15:37:44 HHCTE001I Console connection thread started: tid=00004790, pid=17944
15:37:44 HHCTE003I Waiting for console connection on port 3270
15:37:44 HHCTA066I 0400: option 'level' accepted.
15:37:44 HHCTA066I 0401: option 'level' accepted.
15:37:44 HHCTA066I 0402: option 'level' accepted.
15:37:44 HHCTA066I 0403: option 'level' accepted.
15:37:44 HHCCP002I CPU0000 thread started: tid=00001AE8, pid=17944, priority=0
15:37:44 HHCCP003I CPU0000 architecture mode S/380
15:37:44 HHCTT002I Timer thread started: tid=0000462C, pid=17944, priority=-20
15:37:44 HHCPN001I Control panel thread started: tid=00002AE8, pid=17944
15:37:44 HHCPN008I Script file processing started using file "conf/auto_run.rc"
15:37:44 HHCAO001I Hercules Automatic Operator thread started;
15:37:44           tid=00003358, pri=0, pid=17944
15:37:44 devlist
15:37:44 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof
15:37:44      (no one currently connected)
15:37:44 0:000D 3525 pch/pch00d.txt ascii crlf
15:37:44 0:000E 1403 prt/prt00e.txt crlf noclear
15:37:44 0:000F 1403 prt/prt00f.txt crlf noclear
15:37:44 0:001F 3215 *syscons cmdpref(/)
15:37:44 0:00C0 3270  
15:37:44 0:00C1 3270  
15:37:44 0:00C2 3270  
15:37:44 0:00C7 3287  
15:37:44 0:010C 3505 jcl/dummy eof
15:37:44 0:0131 2314 dasd/sort01.131 [200 cyls] open
15:37:44 0:0132 2314 dasd/sort02.132 [200 cyls] open
15:37:44 0:0133 2314 dasd/sort03.133 [200 cyls] open
15:37:44 0:0134 2314 dasd/sort04.134 [200 cyls] open
15:37:44 0:0135 2314 dasd/sort05.135 [200 cyls] open
15:37:44 0:0136 2314 dasd/sort06.136 [200 cyls] open
15:37:44 0:0138 2314 dasd/dlicat.138 [200 cyls] open
15:37:44 0:0139 2314 dasd/dlisys.139 [200 cyls] open
15:37:44 0:013A 2314 dasd/dli000.13a [200 cyls] open
15:37:44 0:013B 2314 dasd/dli001.13b [200 cyls] open
15:37:44 0:013C 2314 dasd/dli002.13c [200 cyls] open
15:37:44 0:0140 3350 dasd/work00.140 [560 cyls] open
15:37:44 0:0148 3350 dasd/mvsres.148 [560 cyls] open
15:37:44 0:0149 3350 dasd/smp001.149 [560 cyls] open
15:37:44 0:014A 3350 dasd/smp002.14a [560 cyls] open
15:37:44 0:014B 3350 dasd/smp003.14b [560 cyls] open
15:37:44 0:014C 3350 dasd/smp004.14c [560 cyls] open
15:37:44 0:0150 3330 dasd/start1.150 [808 cyls] open
15:37:44 0:0151 3330 dasd/spool0.151 [808 cyls] open
15:37:44 0:0152 3330 dasd/hasp00.152 [404 cyls] open
15:37:44 0:0160 3340 dasd/page00.160 [698 cyls] open
15:37:44 0:0161 3340 dasd/page01.161 [698 cyls] open
15:37:44 0:0162 3340 dasd/page02.162 [698 cyls] open
15:37:44 0:0170 3375 dasd/work01.170 [962 cyls] open
15:37:44 0:01A0 3380 dasd/work02.180 [886 cyls] open
15:37:44 0:01B0 3390 dasd/work03.190 [1114 cyls] open
15:37:44 0:01B1 3390 dasd/mvscat.191 [1114 cyls] open
15:37:44 0:01B2 3390 dasd/seasik.192 [1114 cyls] open
15:37:44 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] open
15:37:44 0:01C7 3287  
15:37:44 0:0240 3350 dasd/pub000.240 [560 cyls] open
15:37:44 0:0248 3350 dasd/mvsdlb.248 [560 cyls] open
15:37:44 0:02A0 3380 dasd/pub002.280 [1772 cyls] open
15:37:44 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] open
15:37:44 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] open
15:37:44 0:030E 1403 log/hardcopy.log crlf noclear
15:37:44 0:0340 3350 dasd/cbt000.340 [555 cyls] open
15:37:44 0:0341 3350 dasd/cbt001.341 [555 cyls] open
15:37:44 0:0342 3350 dasd/cbt002.342 [555 cyls] open
15:37:44 0:0343 3350 dasd/cbtcat.343 [555 cyls] open
15:37:44 0:0348 3350 dasd/src000.348 [555 cyls] open
15:37:44 0:0349 3350 dasd/src001.349 [555 cyls] open
15:37:44 0:034A 3350 dasd/src002.34a [555 cyls] open
15:37:44 0:034B 3350 dasd/srccat.34b [555 cyls] open
15:37:44 0:0400 3420 *
15:37:44 0:0401 3420 *
15:37:44 0:0402 3420 *
15:37:44 0:0403 3420 *
15:37:44 0:0700 3350 dasd/js2sp0.700 [555 cyls] open
15:37:44 0:0710 3350 dasd/js3sp0.710 [555 cyls] open
15:37:44 0:0711 3350 dasd/js3res.711 [555 cyls] open
15:37:44 logopt timestamp
15:37:44 HHCPN197I Log option set: TIMESTAMP
15:37:44 panrate 1000
15:37:44 # really need to wait for SVC120I, but if building MVS/380
15:37:44 # or some other stuffup with parms, need to trigger on an
15:37:44 # alternative. First one hit will clear targets.
15:37:44 # If we get a prompt for a device, cancel it
15:37:44 hao tgt IEF238D
15:37:44 HHCAO016I Target placed at index 0
15:37:44 hao cmd script conf/cancel.rc
15:37:44 HHCAO020I Command placed at index 0
15:37:44 hao tgt HASP395 DYNAMASK
15:37:44 HHCAO016I Target placed at index 1
15:37:44 hao cmd script conf/subjobs_slow.rc
15:37:44 HHCAO020I Command placed at index 1
15:37:44 hao tgt HASP373 SVC120I
15:37:44 HHCAO016I Target placed at index 2
15:37:44 hao cmd script conf/subjobs_fast.rc
15:37:44 HHCAO020I Command placed at index 2
15:37:44 hao tgt HASP436 REPLY
15:37:44 HHCAO016I Target placed at index 3
15:37:44 hao cmd script conf/replyy.rc
15:37:44 HHCAO020I Command placed at index 3
15:37:44 devinit 402 tapes/mftopc.het
15:37:44 HHCTA004I 0402: tapes/mftopc.het is a Hercules Emulated Tape file
15:37:44 HHCPN098I Device 0:0402 initialized
15:37:44 devinit 403 tapes/awstap.aws
15:37:44 HHCTA004I 0403: tapes/awstap.aws is a Hercules Emulated Tape file
15:37:44 HHCPN098I Device 0:0403 initialized
15:37:44 # co will give you a cold start of JES2 which is useful in
15:37:44 # automated runs
15:37:44 /(001F) r 00,clpa,cmd=co
15:37:44 #/r 00,clpa
15:37:44 ipl 148
15:37:44 HHCPN013I EOF reached on SCRIPT file. Processing complete.
15:37:45 IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
15:37:45 HHCCD001I Readahead thread 1 started: tid=0000239C, pid=17944
15:37:45 HHCCD001I Readahead thread 2 started: tid=0000203C, pid=17944
15:37:45 HHCCD002I Writer thread 1 started: tid=00001BF8, pid=17944
15:37:45 HHCCD003I Garbage collector thread started: tid=00003AC0, pid=17944
15:37:45 IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
15:37:45  PLPA ... SYS1.PAGELPA
15:37:45  COMMON . SYS1.PAGECSA
15:37:45  DUPLEX . SYS1.DUPLEX
15:37:45  LOCAL .. SYS1.PAGEL01
15:37:45  LOCAL .. SYS1.PAGEL02
15:37:45  LOCAL .. SYS1.PAGEL03
15:37:45 HHCCD002I Writer thread 2 started: tid=000036C4, pid=17944
15:37:46  IEE360I SMF NOW RECORDING ON SYS1.MANX ON MVSRES TIME=04.37.46
15:37:46  IGF992I  MIH INIT COMPLETE, PRI=000300, SEC=000015
15:37:46  IEF677I WARNING MESSAGE(S) FOR JOB JES2     ISSUED
15:37:47 *00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
15:37:47 HHCAO003I Firing command: 'script conf/replyy.rc'
15:37:47 script conf/replyy.rc
15:37:47 /(001F) reply 00,y
15:37:47 HHCPN013I EOF reached on SCRIPT file. Processing complete.
15:37:47  IEE600I REPLY TO 00 IS;SUPPRESSED
15:37:47  $HASP493 JES2 COLD-START IS IN PROGRESS
15:37:47  $HASP412 MAXIMUM OF 1   READER(S)  EXCEEDED
15:37:47 04.37.47           IEE041I THE SYSTEM LOG IS NOW ACTIVE
15:37:47 04.37.47           IEE302I 00E      ONLINE
15:37:47 04.37.47           IEE302I 00F      ONLINE
15:37:47 04.37.47           IEE313I 30E     UNIT REF INVALID
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           IEE450I 04.37.47 UNIT STATUS 159
15:37:47  UNIT TYPE STATUS  VOLSER VOLSTATE   UNIT TYPE STATUS  VOLSER VOLSTATE
15:37:47  400  3400 O                  /REMOV 401  3400 O                  /REMOV
15:37:47  402  3400 O                  /REMOV
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP000 OK
15:37:47 04.37.47           $HASP160 PRINTER1 INACTIVE - CLASS=AP
15:37:47 04.37.47           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:47 04.37.47           $HASP160 PUNCH1   INACTIVE - CLASS=B
15:37:47 04.37.47 STC    2  $HASP100 INIT     ON STCINRDR
15:37:47 04.37.47 STC    2  $HASP373 INIT     STARTED
15:37:47 04.37.47 STC    2  IEF403I INIT - STARTED - TIME=04.37.47
15:37:47 04.37.47 STC    3  $HASP100 INIT     ON STCINRDR
15:37:47 04.37.47 STC    3  $HASP373 INIT     STARTED
15:37:47 04.37.47 STC    3  IEF403I INIT - STARTED - TIME=04.37.47
15:37:47 04.37.47 STC    4  $HASP100 INIT     ON STCINRDR
15:37:47 04.37.47 STC    4  $HASP373 INIT     STARTED
15:37:47 04.37.47 STC    4  IEF403I INIT - STARTED - TIME=04.37.47
15:37:47 04.37.47 STC    5  $HASP100 INIT     ON STCINRDR
15:37:47 04.37.47 STC    5  $HASP373 INIT     STARTED
15:37:47 04.37.47 STC    5  IEF403I INIT - STARTED - TIME=04.37.47
15:37:47 04.37.47 STC    6  $HASP100 INIT     ON STCINRDR
15:37:48 04.37.48 STC    6  $HASP373 INIT     STARTED
15:37:48 04.37.48 STC    6  IEF403I INIT - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC    7  $HASP100 INIT     ON STCINRDR
15:37:48 04.37.48 STC    7  $HASP373 INIT     STARTED
15:37:48 04.37.48 STC    7  IEF403I INIT - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC    8  $HASP100 INIT     ON STCINRDR
15:37:48 04.37.48 STC    8  $HASP373 INIT     STARTED
15:37:48 04.37.48 STC    8  IEF403I INIT - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC    9  $HASP100 SVC120I  ON STCINRDR
15:37:48 04.37.48 STC    9  $HASP373 SVC120I  STARTED
15:37:48 HHCAO003I Firing command: 'script conf/subjobs_fast.rc'
15:37:48 script conf/subjobs_fast.rc
15:37:48 # Now we know that SVC120I has started. But due to some
15:37:48 # weird pausing, it may get locked out. So clear out
15:37:48 # other triggers and wait on this
15:37:48 hao clear
15:37:48 HHCAO022I All automatic operation rules cleared
15:37:48 hao tgt HASP250 SVC120I
15:37:48 HHCAO016I Target placed at index 0
15:37:48 hao cmd script conf/subjobs.rc
15:37:48 HHCAO020I Command placed at index 0
15:37:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
15:37:48 04.37.48 STC    9  IEF403I SVC120I - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   10  $HASP100 DYNABLDL ON STCINRDR
15:37:48 04.37.48 STC   10  $HASP373 DYNABLDL STARTED
15:37:48 04.37.48 STC   10  IEF403I DYNABLDL - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   11  $HASP100 DYNAMASK ON STCINRDR
15:37:48 04.37.48 STC   11  $HASP373 DYNAMASK STARTED
15:37:48 04.37.48 STC   11  IEF403I DYNAMASK - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   12  $HASP100 BSPPILOT ON STCINRDR
15:37:48 04.37.48 STC   12  $HASP373 BSPPILOT STARTED
15:37:48 04.37.48 STC   12  IEF403I BSPPILOT - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   13  $HASP100 BSPSETPF ON STCINRDR
15:37:48 04.37.48 STC   13  $HASP373 BSPSETPF STARTED
15:37:48 04.37.48 STC   13  IEF403I BSPSETPF - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   14  $HASP100 LOGRECI  ON STCINRDR
15:37:48 04.37.48 STC   14  $HASP373 LOGRECI  STARTED
15:37:48 04.37.48 STC   14  IEF403I LOGRECI - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   15  $HASP100 NET      ON STCINRDR
15:37:48 04.37.48 STC   15  $HASP373 NET      STARTED
15:37:48 04.37.48 STC   15  IEF403I NET - STARTED - TIME=04.37.48
15:37:48 04.37.48           $HASP309    INIT  1 INACTIVE ******** C=A
15:37:48 04.37.48           $HASP309    INIT  2 INACTIVE ******** C=BA
15:37:48 04.37.48           $HASP309    INIT  3 INACTIVE ******** C=CBA
15:37:48 04.37.48           $HASP309    INIT  4 INACTIVE ******** C=SHB
15:37:48 04.37.48           $HASP309    INIT  5 INACTIVE ******** C=SBA
15:37:48 04.37.48           $HASP309    INIT  6 INACTIVE ******** C=S
15:37:48 04.37.48           $HASP309    INIT  7 INACTIVE ******** C=E
15:37:48 04.37.48 STC    9  BSPGM40I -   200 MiB MAINSIZE memory available
15:37:48 04.37.48 STC    9  BSPGM41I -     2 Partitions of    64 MiB each
15:37:48 04.37.48 STC    9  BSPGM78I SVC 120 EP=00FE3248; MVS/380
15:37:48 04.37.48 STC    9  IEF404I SVC120I - ENDED - TIME=04.37.48
15:37:48 04.37.48 STC    9  $HASP395 SVC120I  ENDED
15:37:48 04.37.48 STC    9  $HASP150 SVC120I  ON PRINTER2        45 LINES
15:37:48 04.37.48 STC    9 *$HASP190 SVC120I  SETUP -- PRINTER2 -- F = 0001 -- C = 6    -- T = SN
15:37:48 04.37.48           $HASP000 OK
15:37:48 04.37.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:48 04.37.48 STC    9  $HASP250 SVC120I  IS PURGED
15:37:48 HHCAO003I Firing command: 'script conf/subjobs.rc'
15:37:48 script conf/subjobs.rc
15:37:48 hao clear
15:37:48 HHCAO022I All automatic operation rules cleared
15:37:48 # Every job gets an NL tape available as input, containing
15:37:48 # some binary of unknown contents, most likely needing to
15:37:48 # be read as RECFM=U, but RECFM=FB and even RECFM=V are also
15:37:48 # possible.
15:37:48 #
15:37:48 # The job also gets an SL tape available for output, and
15:37:48 # again, any type of content can be written to it, and
15:37:48 # with a bit of luck, hetget will be able to extract the
15:37:48 # data you are looking for.
15:37:48 #
15:37:48 # And finally the job gets an SL AWS tape available for
15:37:48 # input and/or output should you wish to construct a
15:37:48 # special tape. Tape must be called AWSTAP. User should
15:37:48 # back the tape up before submitting it, because it will
15:37:48 # be overwritten and anything could go wrong. AWS is
15:37:48 # expected to be exceptional use of this procedure anyway
15:37:48 #
15:37:48 # Only the NL tape needs an explicit mount. The SL tapes
15:37:48 # are premounted before IPL
15:37:48 hao tgt HASP250 MOUNT
15:37:48 HHCAO016I Target placed at index 0
15:37:48 hao cmd script conf/subjobs2.rc
15:37:48 HHCAO020I Command placed at index 0
15:37:48 /(001F) M 401,VOL=(NL,PCTOMF)
15:37:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
15:37:48 04.37.48 STC   16  $HASP100 MOUNT    ON STCINRDR
15:37:48 04.37.48 STC   16  $HASP373 MOUNT    STARTED
15:37:48 04.37.48 STC   16  IEF403I MOUNT - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   16 *IEF233A M 401,PCTOMF,,MOUNT,401
15:37:48 04.37.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
15:37:48 04.37.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
15:37:48 04.37.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
15:37:48 04.37.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
15:37:48 04.37.48 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
15:37:48 04.37.48 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
15:37:48 04.37.48 STC   15  IST110I  NETWORK SOLICITOR STARTED
15:37:48 04.37.48 STC   15  IST093I  APPLJRP  ACTIVE
15:37:48 04.37.48 STC   15  IST093I  APPLPIES ACTIVE
15:37:48 04.37.48 STC   15  IST093I  APPLPIAD ACTIVE
15:37:48 04.37.48 STC   15  IST093I  APPLTSO  ACTIVE
15:37:48 04.37.48 STC   15  IST093I  APPLTEST ACTIVE
15:37:48 04.37.48 STC   10  DYNABLDL STARTED
15:37:48 04.37.48 STC   15  IST093I  LCLMAJRP ACTIVE
15:37:48 04.37.48 STC   15  IST093I  LCLMAJ00 ACTIVE
15:37:48 04.37.48 STC   17  $HASP100 TSO      ON STCINRDR
15:37:48 04.37.48 STC   17  $HASP373 TSO      STARTED
15:37:48 04.37.48 STC   17  IEF403I TSO - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   18  $HASP100 JRP      ON STCINRDR
15:37:48 04.37.48 STC   18  $HASP373 JRP      STARTED
15:37:48 04.37.48 STC   18  IEF403I JRP - STARTED - TIME=04.37.48
15:37:48 04.37.48           $HASP000 OK
15:37:48 04.37.48           $HASP000 OK
15:37:48 04.37.48 STC   15  IST020I  VTAM INITIALIZATION COMPLETE
15:37:48 04.37.48 STC   15  IEA000I 0C0,IOE,05,0200,400000000001,,,NET     ,04.37.48
15:37:48 04.37.48 STC   15  IEA000I 0C1,IOE,05,0200,400000000001,,,NET     ,04.37.48
15:37:48 04.37.48 STC   15  IEA000I 0C2,IOE,05,0200,400000000001,,,NET     ,04.37.48
15:37:48 04.37.48 STC   10  IEF404I DYNABLDL - ENDED - TIME=04.37.48
15:37:48 04.37.48 STC   10  $HASP395 DYNABLDL ENDED
15:37:48 04.37.48 STC   10  $HASP150 DYNABLDL ON PRINTER2        21 LINES
15:37:48 04.37.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:48 04.37.48 STC   10  $HASP250 DYNABLDL IS PURGED
15:37:48 04.37.48 STC   11  DMSK00I DYNAMASK DONE ****
15:37:48 04.37.48 STC   11  DMSK06I  START
15:37:48 04.37.48 STC   11  IEF404I DYNAMASK - ENDED - TIME=04.37.48
15:37:48 04.37.48 STC   11  $HASP395 DYNAMASK ENDED
15:37:48 04.37.48 STC   11  $HASP150 DYNAMASK ON PRINTER2        30 LINES
15:37:48 04.37.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:48 04.37.48 STC   11  $HASP250 DYNAMASK IS PURGED
15:37:48 04.37.48 STC   13  BSPSP91I - Parms passed: NOREPLYU
15:37:48 04.37.48 STC   13  BSPSP93I - PFK definitions will be updated in memory
15:37:48 04.37.48 STC   13  BSPSP22I - Dataset processed: SYS1.PARMLIB
15:37:48 04.37.48 STC   13  BSPSP23I - on volume MVSRES
15:37:48 04.37.48 STC   13  BSPSP21I - Member being processed: SETPFK01
15:37:48 04.37.48 STC   13  +BSPSP98I - Member processed, LASTCC=0000
15:37:48 04.37.48 STC   13  +BSPSP21I - Member being processed: SETPFK02
15:37:48 04.37.48 STC   13  +BSPSP98I - Member processed, LASTCC=0000
15:37:48 04.37.48 STC   13  +BSPSP99I - End of processing, MAXRC=0000
15:37:48 04.37.48 STC   13  IEF404I BSPSETPF - ENDED - TIME=04.37.48
15:37:48 04.37.48 STC   13  $HASP395 BSPSETPF ENDED
15:37:48 04.37.48 STC   13  $HASP150 BSPSETPF ON PRINTER2        34 LINES
15:37:48 04.37.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:48 04.37.48 STC   13  $HASP250 BSPSETPF IS PURGED
15:37:48 04.37.48 STC   14  IFC001I  D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
15:37:48 04.37.48 STC   14  IEF404I LOGRECI - ENDED - TIME=04.37.48
15:37:48 04.37.48 STC   14  $HASP395 LOGRECI  ENDED
15:37:48 04.37.48 STC   14  $HASP150 LOGRECI  ON PRINTER2        20 LINES
15:37:48 04.37.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:48 04.37.48 STC   14  $HASP250 LOGRECI  IS PURGED
15:37:48 04.37.48 STC   16  IEF404I MOUNT - ENDED - TIME=04.37.48
15:37:48 04.37.48 STC   16  $HASP395 MOUNT    ENDED
15:37:48 04.37.48 STC   16  $HASP150 MOUNT    ON PRINTER2        18 LINES
15:37:48 04.37.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:48 04.37.48 STC   16  $HASP250 MOUNT    IS PURGED
15:37:48 HHCAO003I Firing command: 'script conf/subjobs2.rc'
15:37:48 script conf/subjobs2.rc
15:37:48 hao clear
15:37:48 HHCAO022I All automatic operation rules cleared
15:37:48 # If we get a prompt for a device, cancel it
15:37:48 hao tgt IEF238D
15:37:48 HHCAO016I Target placed at index 0
15:37:48 hao cmd script conf/cancel.rc
15:37:48 HHCAO020I Command placed at index 0
15:37:48 # If we get a prompt for a catalogue password, answer it
15:37:48 hao tgt IEC301A
15:37:48 HHCAO016I Target placed at index 1
15:37:48 hao cmd script conf/secret.rc
15:37:48 HHCAO020I Command placed at index 1
15:37:48 devinit 401 tapes/pctomf.tdf
15:37:48 HHCTA004I 0401: tapes/pctomf.tdf is a Optical Media Attachment (OMA) tape
15:37:48 HHCPN098I Device 0:0401 initialized
15:37:48 # When we see TERMHERC get purged, our job is done
15:37:48 hao tgt HASP373 TERMHERC
15:37:48 HHCAO016I Target placed at index 2
15:37:48 hao cmd script conf/termherc.rc
15:37:48 HHCAO020I Command placed at index 2
15:37:48 # Now submit the job
15:37:48 devinit 00c jcl/hercauto.jcl eof
15:37:48 HHCSD007I Device 000C unbound from socket 127.0.0.1:3505
15:37:48 HHCSD022I Socketdevice listener thread terminated
15:37:48 HHCPN098I Device 0:000C initialized
15:37:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
15:37:48 04.37.48 JOB    1  $HASP100 MVSGCC   ON READER1
15:37:48 04.37.48 JOB    2  $HASP100 TERMHERC ON READER1
15:37:48 04.37.48 JOB    1  $HASP373 MVSGCC   STARTED - INIT  3 - CLASS C - SYS BSP1
15:37:48 04.37.48 JOB    1  IEF403I MVSGCC - STARTED - TIME=04.37.48
15:37:48 04.37.48 STC   17  IKT007I TCAS ACCEPTING LOGONS
15:37:48 04.37.48 STC   17  IKT005I TCAS IS INITIALIZED
15:37:48 04.37.48 JOB    1 *IEF233A M 401,PCTOMF,,MVSGCC,COMP
15:37:49 04.37.49 STC   18  JRPI101 INITIALIZATION COMPLETE
15:37:49 04.37.49 STC   18 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
15:37:49 04.37.49 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP
15:37:49 04.37.49 JOB    1  IEF234E K 402,MFTOPC,PVT,MVSGCC,COMP
15:37:49 04.37.49 JOB    1  IEFACTRT - Stepname  Procstep  Program   Retcode
15:37:49 04.37.49 JOB    1  MVSGCC     S1        COMP      GCC       RC= 0000
15:37:49 04.37.49 JOB    1  IEF404I MVSGCC - ENDED - TIME=04.37.49
15:37:49 04.37.49 JOB    1  $HASP395 MVSGCC   ENDED
15:37:49 04.37.49 JOB    1  $HASP150 MVSGCC   ON PRINTER1        98 LINES
15:37:49 04.37.49 JOB    1 *$HASP190 MVSGCC   SETUP -- PRINTER1 -- F = 0001 -- C = 6    -- T = SN
15:37:49 04.37.49           $HASP000 OK
15:37:49 04.37.49           $HASP160 PRINTER1 INACTIVE - CLASS=AP
15:37:49 04.37.49 JOB    1  $HASP250 MVSGCC   IS PURGED
15:37:49 04.37.49 JOB    2  $HASP373 TERMHERC STARTED - INIT  3 - CLASS C - SYS BSP1
15:37:49 HHCAO003I Firing command: 'script conf/termherc.rc'
15:37:49 script conf/termherc.rc
15:37:49 # We do an unnecessary 2-stage terminate, first triggering
15:37:49 # on the start message, then triggering on the purged
15:37:49 # message, to overcome an apparent bug in hercules which
15:37:49 # causes it to sometimes trigger on the wrong jobname.
15:37:49 hao clear
15:37:49 HHCAO022I All automatic operation rules cleared
15:37:49 hao tgt HASP250 TERMHERC
15:37:49 HHCAO016I Target placed at index 0
15:37:49 hao cmd script conf/termherc2.rc
15:37:49 HHCAO020I Command placed at index 0
15:37:49 HHCPN013I EOF reached on SCRIPT file. Processing complete.
15:37:49 04.37.49 JOB    2  IEF403I TERMHERC - STARTED - TIME=04.37.49
15:37:49 04.37.49 JOB    2  IEFACTRT - Stepname  Procstep  Program   Retcode
15:37:49 04.37.49 JOB    2  TERMHERC   S1                  IEBGENER  RC= 0000
15:37:49 04.37.49 JOB    2  IEF404I TERMHERC - ENDED - TIME=04.37.49
15:37:49 04.37.49 JOB    2  $HASP395 TERMHERC ENDED
15:37:49 04.37.49           $HASP309    INIT  3 INACTIVE ******** C=CBA
15:37:49 04.37.49 JOB    2  $HASP150 TERMHERC ON PRINTER2        44 LINES
15:37:49 04.37.49 JOB    2  $HASP150 TERMHERC ON PRINTER1         1 LINE
15:37:49 04.37.49           $HASP160 PRINTER1 INACTIVE - CLASS=AP
15:37:49 04.37.49           $HASP160 PRINTER2 INACTIVE - CLASS=Z
15:37:49 04.37.49 JOB    2  $HASP250 TERMHERC IS PURGED
15:37:49 HHCAO003I Firing command: 'script conf/termherc2.rc'
15:37:49 script conf/termherc2.rc
15:37:49 quit
15:37:49 HHCIN900I Begin Hercules shutdown
15:37:49 HHCIN901I Releasing configuration
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In preparation for trying other flavors of
Hercules, I tried switching script from
mvsgcc (GCC compile) to mvshd
(hexdump), which also shaved 1
second off run time, and after 14
successful runs, the console
froze again, but at a different spot:

06.25.48 STC    9  BSPGM40I -   200 MiB MAINSIZE memory available                                                                                                                           06.25.48 STC    9  BSPGM41I -     2 Partitions of    64 MiB each                                                                                                                            06.25.48 STC    9  BSPGM78I SVC 120 EP=00FE31B0; MVS/380                                                                                                                                    Command ==>                                                                                                                                                                                                        CPU0000 PSW=040C00000002BAB2 24........                                                                                                                                                       instcount=211,556,057


Same symptom at end of hercules.log:

17:25:48 06.25.48 JOB    2  $HASP250 TERMHERC IS PURGED
17:25:48 HHCAO003I Firing command: 'script conf/termherc2.rc'
17:25:48 script conf/termherc2.rc
17:25:48 quit
17:25:48 HHCIN900I Begin Hercules shutdown
17:25:48 HHCIN901I Releasing configuration


BFN. Paul.




17:25:44 Hercules Version 3.07:380-4.x
17:25:44 (c)Copyright 1999-2010 by Roger Bowler, Jan Jaeger, and others
17:25:44 Built on Dec  7 2016 at 12:43:32
17:25:44 Build information:
17:25:44   Windows (MSVC) build for AMD64
17:25:44   Modes: S/370 S/380 ESA/390 z/Arch
17:25:44   Max CPU Engines: 8
17:25:44   Using fthreads instead of pthreads
17:25:44   Dynamic loading support
17:25:44   Using shared libraries
17:25:44   HTTP Server support
17:25:44   No SIGABEND handler
17:25:44   Regular Expressions support
17:25:44   Automatic Operator support
17:25:44   Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8
17:25:44 Running on PAUL-DELL Windows_NT-6.2 AMD64 MP=8
17:25:44 HHCHD018I Loadable module directory is hercules
17:25:44 Crypto module loaded (c) Copyright Bernard van der Helm, 2003-2010
17:25:44   Active: Message Security Assist
17:25:44           Message Security Assist Extension 1
17:25:44           Message Security Assist Extension 2
17:25:44 HHCPN210I Default Allowed AUTOMOUNT directory = "c:\mvs380\"
17:25:44 HHCHT001I HTTP listener thread started: tid=000032EC, pid=14940
17:25:44 HHCCF065I Hercules: tid=00003D48, pid=14940, pgid=14940, priority=8
17:25:44 HHCCF066E Invalid HTTPROOT: "c:\herc380\html": No such file or directory
17:25:44 HHCSD004I Device 000C bound to socket 127.0.0.1:3505
17:25:44 HHCSD020I Socketdevice listener thread started: tid=00003818, pid=14940
17:25:44 HHCCF083I conf/mvs380.conf Including conf/mvs380_DASD.conf at 122 .
17:25:44 HHCDA004I opening dasd/mvsres.148 readonly
17:25:44 HHCDA020I dasd/mvsres.148 cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/sort01.131 readonly
17:25:44 HHCDA020I dasd/sort01.131 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/sort02.132 readonly
17:25:44 HHCDA020I dasd/sort02.132 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/sort03.133 readonly
17:25:44 HHCDA020I dasd/sort03.133 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/sort04.134 readonly
17:25:44 HHCDA020I dasd/sort04.134 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/sort05.135 readonly
17:25:44 HHCDA020I dasd/sort05.135 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/sort06.136 readonly
17:25:44 HHCDA020I dasd/sort06.136 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/work00.140 readonly
17:25:44 HHCDA020I dasd/work00.140 cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA020I dasd/hasp00.152 cyls=404 heads=19 tracks=7676 trklen=13312
17:25:44 HHCDA020I dasd/page00.160 cyls=698 heads=12 tracks=8376 trklen=8704
17:25:44 HHCDA020I dasd/page01.161 cyls=698 heads=12 tracks=8376 trklen=8704
17:25:44 HHCDA020I dasd/page02.162 cyls=698 heads=12 tracks=8376 trklen=8704
17:25:44 HHCDA020I dasd/work01.170 cyls=962 heads=12 tracks=11544 trklen=35840
17:25:44 HHCDA004I opening dasd/work02.180 readonly
17:25:44 HHCDA020I dasd/work02.180 cyls=886 heads=15 tracks=13290 trklen=47616
17:25:44 HHCDA004I opening dasd/work03.190 readonly
17:25:44 HHCDA020I dasd/work03.190 cyls=1114 heads=15 tracks=16710 trklen=56832
17:25:44 HHCDA004I opening dasd/mvscat.191 readonly
17:25:44 HHCDA020I dasd/mvscat.191 cyls=1114 heads=15 tracks=16710 trklen=56832
17:25:44 HHCDA004I opening dasd/seasik.192 readonly
17:25:44 HHCDA020I dasd/seasik.192 cyls=1114 heads=15 tracks=16710 trklen=56832
17:25:44 HHCDA020I dasd/mvssrc.193 cyls=2226 heads=15 tracks=33390 trklen=56832
17:25:44 HHCDA002E 01B4:File not found or invalid 'dasd/pub004.1b4'
17:25:44 HHCCF044E Initialization failed for device 01B4
17:25:44 HHCDA004I opening dasd/pub000.240 readonly
17:25:44 HHCDA020I dasd/pub000.240 cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/mvsdlb.248 readonly
17:25:44 HHCDA020I dasd/mvsdlb.248 cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/pub002.280 readonly
17:25:44 HHCDA020I dasd/pub002.280 cyls=1772 heads=15 tracks=26580 trklen=47616
17:25:44 HHCDA004I opening dasd/tmptmp.2b1 readonly
17:25:44 HHCDA020I dasd/tmptmp.2b1 cyls=1114 heads=15 tracks=16710 trklen=56832
17:25:44 HHCDA004I opening dasd/xmit90.2b2 readonly
17:25:44 HHCDA020I dasd/xmit90.2b2 cyls=1114 heads=15 tracks=16710 trklen=56832
17:25:44 HHCDA004I opening dasd/start1.150 readonly
17:25:44 HHCDA020I dasd/start1.150 cyls=808 heads=19 tracks=15352 trklen=13312
17:25:44 HHCDA004I opening dasd/spool0.151 readonly
17:25:44 HHCDA020I dasd/spool0.151 cyls=808 heads=19 tracks=15352 trklen=13312
17:25:44 HHCDA004I opening dasd/cbt000.340 readonly
17:25:44 HHCDA020I dasd/cbt000.340 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/cbt001.341 readonly
17:25:44 HHCDA020I dasd/cbt001.341 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/cbt002.342 readonly
17:25:44 HHCDA020I dasd/cbt002.342 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/cbtcat.343 readonly
17:25:44 HHCDA020I dasd/cbtcat.343 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/src000.348 readonly
17:25:44 HHCDA020I dasd/src000.348 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/src001.349 readonly
17:25:44 HHCDA020I dasd/src001.349 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/src002.34a readonly
17:25:44 HHCDA020I dasd/src002.34a cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/srccat.34b readonly
17:25:44 HHCDA020I dasd/srccat.34b cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/smp001.149 readonly
17:25:44 HHCDA020I dasd/smp001.149 cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/smp002.14a readonly
17:25:44 HHCDA020I dasd/smp002.14a cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/smp003.14b readonly
17:25:44 HHCDA020I dasd/smp003.14b cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/smp004.14c readonly
17:25:44 HHCDA020I dasd/smp004.14c cyls=560 heads=30 tracks=16800 trklen=19456
17:25:44 HHCDA004I opening dasd/js2sp0.700 readonly
17:25:44 HHCDA020I dasd/js2sp0.700 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/dlicat.138 readonly
17:25:44 HHCDA020I dasd/dlicat.138 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/dlisys.139 readonly
17:25:44 HHCDA020I dasd/dlisys.139 cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/dli000.13a readonly
17:25:44 HHCDA020I dasd/dli000.13a cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/dli001.13b readonly
17:25:44 HHCDA020I dasd/dli001.13b cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/dli002.13c readonly
17:25:44 HHCDA020I dasd/dli002.13c cyls=200 heads=20 tracks=4000 trklen=7680
17:25:44 HHCDA004I opening dasd/js3sp0.710 readonly
17:25:44 HHCDA020I dasd/js3sp0.710 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCDA004I opening dasd/js3res.711 readonly
17:25:44 HHCDA020I dasd/js3res.711 cyls=555 heads=30 tracks=16650 trklen=19456
17:25:44 HHCTE001I Console connection thread started: tid=00001F20, pid=14940
17:25:44 HHCTE003I Waiting for console connection on port 3270
17:25:44 HHCTA066I 0400: option 'level' accepted.
17:25:44 HHCTA066I 0401: option 'level' accepted.
17:25:44 HHCTA066I 0402: option 'level' accepted.
17:25:44 HHCTA066I 0403: option 'level' accepted.
17:25:44 HHCCP002I CPU0000 thread started: tid=00000EA8, pid=14940, priority=0
17:25:44 HHCTT002I Timer thread started: tid=0000469C, pid=14940, priority=-20
17:25:44 HHCCP003I CPU0000 architecture mode S/380
17:25:44 HHCPN001I Control panel thread started: tid=00003D48, pid=14940
17:25:44 HHCAO001I Hercules Automatic Operator thread started;
17:25:44           tid=00002170, pri=0, pid=14940
17:25:44 HHCPN008I Script file processing started using file "conf/auto_run.rc"
17:25:44 devlist
17:25:44 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof
17:25:44      (no one currently connected)
17:25:44 0:000D 3525 pch/pch00d.txt ascii crlf
17:25:44 0:000E 1403 prt/prt00e.txt crlf noclear
17:25:44 0:000F 1403 prt/prt00f.txt crlf noclear
17:25:44 0:001F 3215 *syscons cmdpref(/)
17:25:44 0:00C0 3270  
17:25:44 0:00C1 3270  
17:25:44 0:00C2 3270  
17:25:44 0:00C7 3287  
17:25:44 0:010C 3505 jcl/dummy eof
17:25:44 0:0131 2314 dasd/sort01.131 [200 cyls] open
17:25:44 0:0132 2314 dasd/sort02.132 [200 cyls] open
17:25:44 0:0133 2314 dasd/sort03.133 [200 cyls] open
17:25:44 0:0134 2314 dasd/sort04.134 [200 cyls] open
17:25:44 0:0135 2314 dasd/sort05.135 [200 cyls] open
17:25:44 0:0136 2314 dasd/sort06.136 [200 cyls] open
17:25:44 0:0138 2314 dasd/dlicat.138 [200 cyls] open
17:25:44 0:0139 2314 dasd/dlisys.139 [200 cyls] open
17:25:44 0:013A 2314 dasd/dli000.13a [200 cyls] open
17:25:44 0:013B 2314 dasd/dli001.13b [200 cyls] open
17:25:44 0:013C 2314 dasd/dli002.13c [200 cyls] open
17:25:44 0:0140 3350 dasd/work00.140 [560 cyls] open
17:25:44 0:0148 3350 dasd/mvsres.148 [560 cyls] open
17:25:44 0:0149 3350 dasd/smp001.149 [560 cyls] open
17:25:44 0:014A 3350 dasd/smp002.14a [560 cyls] open
17:25:44 0:014B 3350 dasd/smp003.14b [560 cyls] open
17:25:44 0:014C 3350 dasd/smp004.14c [560 cyls] open
17:25:44 0:0150 3330 dasd/start1.150 [808 cyls] open
17:25:44 0:0151 3330 dasd/spool0.151 [808 cyls] open
17:25:44 0:0152 3330 dasd/hasp00.152 [404 cyls] open
17:25:44 0:0160 3340 dasd/page00.160 [698 cyls] open
17:25:44 0:0161 3340 dasd/page01.161 [698 cyls] open
17:25:44 0:0162 3340 dasd/page02.162 [698 cyls] open
17:25:44 0:0170 3375 dasd/work01.170 [962 cyls] open
17:25:44 0:01A0 3380 dasd/work02.180 [886 cyls] open
17:25:44 0:01B0 3390 dasd/work03.190 [1114 cyls] open
17:25:44 0:01B1 3390 dasd/mvscat.191 [1114 cyls] open
17:25:44 0:01B2 3390 dasd/seasik.192 [1114 cyls] open
17:25:44 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] open
17:25:44 0:01C7 3287  
17:25:44 0:0240 3350 dasd/pub000.240 [560 cyls] open
17:25:44 0:0248 3350 dasd/mvsdlb.248 [560 cyls] open
17:25:44 0:02A0 3380 dasd/pub002.280 [1772 cyls] open
17:25:44 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] open
17:25:44 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] open
17:25:44 0:030E 1403 log/hardcopy.log crlf noclear
17:25:44 0:0340 3350 dasd/cbt000.340 [555 cyls] open
17:25:44 0:0341 3350 dasd/cbt001.341 [555 cyls] open
17:25:44 0:0342 3350 dasd/cbt002.342 [555 cyls] open
17:25:44 0:0343 3350 dasd/cbtcat.343 [555 cyls] open
17:25:44 0:0348 3350 dasd/src000.348 [555 cyls] open
17:25:44 0:0349 3350 dasd/src001.349 [555 cyls] open
17:25:44 0:034A 3350 dasd/src002.34a [555 cyls] open
17:25:44 0:034B 3350 dasd/srccat.34b [555 cyls] open
17:25:44 0:0400 3420 *
17:25:44 0:0401 3420 *
17:25:44 0:0402 3420 *
17:25:44 0:0403 3420 *
17:25:44 0:0700 3350 dasd/js2sp0.700 [555 cyls] open
17:25:44 0:0710 3350 dasd/js3sp0.710 [555 cyls] open
17:25:44 0:0711 3350 dasd/js3res.711 [555 cyls] open
17:25:44 logopt timestamp
17:25:44 HHCPN197I Log option set: TIMESTAMP
17:25:44 panrate 1000
17:25:44 # really need to wait for SVC120I, but if building MVS/380
17:25:44 # or some other stuffup with parms, need to trigger on an
17:25:44 # alternative. First one hit will clear targets.
17:25:44 # If we get a prompt for a device, cancel it
17:25:44 hao tgt IEF238D
17:25:44 HHCAO016I Target placed at index 0
17:25:44 hao cmd script conf/cancel.rc
17:25:44 HHCAO020I Command placed at index 0
17:25:44 hao tgt HASP395 DYNAMASK
17:25:44 HHCAO016I Target placed at index 1
17:25:44 hao cmd script conf/subjobs_slow.rc
17:25:44 HHCAO020I Command placed at index 1
17:25:44 hao tgt HASP373 SVC120I
17:25:44 HHCAO016I Target placed at index 2
17:25:44 hao cmd script conf/subjobs_fast.rc
17:25:44 HHCAO020I Command placed at index 2
17:25:44 hao tgt HASP436 REPLY
17:25:44 HHCAO016I Target placed at index 3
17:25:44 hao cmd script conf/replyy.rc
17:25:44 HHCAO020I Command placed at index 3
17:25:44 devinit 402 tapes/mftopc.het
17:25:44 HHCTA004I 0402: tapes/mftopc.het is a Hercules Emulated Tape file
17:25:44 HHCPN098I Device 0:0402 initialized
17:25:44 devinit 403 tapes/awstap.aws
17:25:44 HHCTA004I 0403: tapes/awstap.aws is a Hercules Emulated Tape file
17:25:44 HHCTA401E 0403: Error opening tapes/awstap.aws: File error(Invalid argument)
17:25:44 HHCPN098I Device 0:0403 initialized
17:25:44 # co will give you a cold start of JES2 which is useful in
17:25:44 # automated runs
17:25:44 /(001F) r 00,clpa,cmd=co
17:25:44 #/r 00,clpa
17:25:44 ipl 148
17:25:44 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:25:45 IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
17:25:45 HHCCD001I Readahead thread 1 started: tid=000045D8, pid=14940
17:25:45 HHCCD001I Readahead thread 2 started: tid=000042E4, pid=14940
17:25:45 HHCCD002I Writer thread 1 started: tid=00003D40, pid=14940
17:25:45 HHCCD003I Garbage collector thread started: tid=00002C78, pid=14940
17:25:45 IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
17:25:45  PLPA ... SYS1.PAGELPA
17:25:45  COMMON . SYS1.PAGECSA
17:25:45  DUPLEX . SYS1.DUPLEX
17:25:45  LOCAL .. SYS1.PAGEL01
17:25:45  LOCAL .. SYS1.PAGEL02
17:25:45  LOCAL .. SYS1.PAGEL03
17:25:45 HHCCD002I Writer thread 2 started: tid=0000427C, pid=14940
17:25:46 *IEE362A SMF ENTER DUMP FOR SYS1.MANX ON MVSRES
17:25:46  IEE360I SMF NOW RECORDING ON SYS1.MANY ON MVSRES TIME=06.25.46
17:25:46  IGF992I  MIH INIT COMPLETE, PRI=000300, SEC=000015
17:25:47  IEF677I WARNING MESSAGE(S) FOR JOB JES2     ISSUED
17:25:47 *00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
17:25:47 HHCAO003I Firing command: 'script conf/replyy.rc'
17:25:47 script conf/replyy.rc
17:25:47 /(001F) reply 00,y
17:25:47 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:25:47  IEE600I REPLY TO 00 IS;SUPPRESSED
17:25:47  $HASP493 JES2 COLD-START IS IN PROGRESS
17:25:47  $HASP412 MAXIMUM OF 1   READER(S)  EXCEEDED
17:25:47 06.25.47           IEE041I THE SYSTEM LOG IS NOW ACTIVE
17:25:47 06.25.47           IEE302I 00E      ONLINE
17:25:47 06.25.47           IEE302I 00F      ONLINE
17:25:47 06.25.47           IEE313I 30E     UNIT REF INVALID
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           IEE450I 06.25.47 UNIT STATUS 160
17:25:47  UNIT TYPE STATUS  VOLSER VOLSTATE   UNIT TYPE STATUS  VOLSER VOLSTATE
17:25:47  400  3400 O                  /REMOV 401  3400 O                  /REMOV
17:25:47  402  3400 O                  /REMOV
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP000 OK
17:25:47 06.25.47           $HASP160 PRINTER1 INACTIVE - CLASS=AP
17:25:47 06.25.47           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:47 06.25.47           $HASP160 PUNCH1   INACTIVE - CLASS=B
17:25:47 06.25.47 STC    2  $HASP100 INIT     ON STCINRDR
17:25:47 06.25.47 STC    2  $HASP373 INIT     STARTED
17:25:47 06.25.47 STC    2  IEF403I INIT - STARTED - TIME=06.25.47
17:25:47 06.25.47 STC    3  $HASP100 INIT     ON STCINRDR
17:25:47 06.25.47 STC    3  $HASP373 INIT     STARTED
17:25:47 06.25.47 STC    3  IEF403I INIT - STARTED - TIME=06.25.47
17:25:47 06.25.47 STC    4  $HASP100 INIT     ON STCINRDR
17:25:47 06.25.47 STC    4  $HASP373 INIT     STARTED
17:25:47 06.25.47 STC    4  IEF403I INIT - STARTED - TIME=06.25.47
17:25:47 06.25.47 STC    5  $HASP100 INIT     ON STCINRDR
17:25:47 06.25.47 STC    5  $HASP373 INIT     STARTED
17:25:47 06.25.47 STC    5  IEF403I INIT - STARTED - TIME=06.25.47
17:25:47 06.25.47 STC    6  $HASP100 INIT     ON STCINRDR
17:25:47 06.25.47 STC    6  $HASP373 INIT     STARTED
17:25:47 06.25.47 STC    6  IEF403I INIT - STARTED - TIME=06.25.47
17:25:47 06.25.47 STC    7  $HASP100 INIT     ON STCINRDR
17:25:47 06.25.47 STC    7  $HASP373 INIT     STARTED
17:25:48 06.25.47 STC    7  IEF403I INIT - STARTED - TIME=06.25.47
17:25:48 06.25.48 STC    8  $HASP100 INIT     ON STCINRDR
17:25:48 06.25.48 STC    8  $HASP373 INIT     STARTED
17:25:48 06.25.48 STC    8  IEF403I INIT - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC    9  $HASP100 SVC120I  ON STCINRDR
17:25:48 06.25.48 STC    9  $HASP373 SVC120I  STARTED
17:25:48 HHCAO003I Firing command: 'script conf/subjobs_fast.rc'
17:25:48 script conf/subjobs_fast.rc
17:25:48 # Now we know that SVC120I has started. But due to some
17:25:48 # weird pausing, it may get locked out. So clear out
17:25:48 # other triggers and wait on this
17:25:48 hao clear
17:25:48 HHCAO022I All automatic operation rules cleared
17:25:48 hao tgt HASP250 SVC120I
17:25:48 HHCAO016I Target placed at index 0
17:25:48 hao cmd script conf/subjobs.rc
17:25:48 HHCAO020I Command placed at index 0
17:25:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:25:48 06.25.48 STC    9  IEF403I SVC120I - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   10  $HASP100 DYNABLDL ON STCINRDR
17:25:48 06.25.48 STC   10  $HASP373 DYNABLDL STARTED
17:25:48 06.25.48 STC   10  IEF403I DYNABLDL - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   11  $HASP100 DYNAMASK ON STCINRDR
17:25:48 06.25.48 STC   11  $HASP373 DYNAMASK STARTED
17:25:48 06.25.48 STC   11  IEF403I DYNAMASK - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   12  $HASP100 BSPPILOT ON STCINRDR
17:25:48 06.25.48 STC   12  $HASP373 BSPPILOT STARTED
17:25:48 06.25.48 STC   12  IEF403I BSPPILOT - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   13  $HASP100 BSPSETPF ON STCINRDR
17:25:48 06.25.48 STC   13  $HASP373 BSPSETPF STARTED
17:25:48 06.25.48 STC   13  IEF403I BSPSETPF - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   14  $HASP100 LOGRECI  ON STCINRDR
17:25:48 06.25.48 STC   14  $HASP373 LOGRECI  STARTED
17:25:48 06.25.48 STC   14  IEF403I LOGRECI - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   15  $HASP100 NET      ON STCINRDR
17:25:48 06.25.48 STC   15  $HASP373 NET      STARTED
17:25:48 06.25.48 STC   15  IEF403I NET - STARTED - TIME=06.25.48
17:25:48 06.25.48           $HASP309    INIT  1 INACTIVE ******** C=A
17:25:48 06.25.48           $HASP309    INIT  2 INACTIVE ******** C=BA
17:25:48 06.25.48           $HASP309    INIT  3 INACTIVE ******** C=CBA
17:25:48 06.25.48           $HASP309    INIT  4 INACTIVE ******** C=SHB
17:25:48 06.25.48           $HASP309    INIT  5 INACTIVE ******** C=SBA
17:25:48 06.25.48           $HASP309    INIT  6 INACTIVE ******** C=S
17:25:48 06.25.48           $HASP309    INIT  7 INACTIVE ******** C=E
17:25:48 06.25.48 STC    9  BSPGM40I -   200 MiB MAINSIZE memory available
17:25:48 06.25.48 STC    9  BSPGM41I -     2 Partitions of    64 MiB each
17:25:48 06.25.48 STC    9  BSPGM78I SVC 120 EP=00FE31B0; MVS/380
17:25:48 06.25.48 STC    9  IEF404I SVC120I - ENDED - TIME=06.25.48
17:25:48 06.25.48 STC    9  $HASP395 SVC120I  ENDED
17:25:48 06.25.48 STC    9  $HASP150 SVC120I  ON PRINTER2        45 LINES
17:25:48 06.25.48 STC    9 *$HASP190 SVC120I  SETUP -- PRINTER2 -- F = 0001 -- C = 6    -- T = SN
17:25:48 06.25.48           $HASP000 OK
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 STC    9  $HASP250 SVC120I  IS PURGED
17:25:48 HHCAO003I Firing command: 'script conf/subjobs.rc'
17:25:48 script conf/subjobs.rc
17:25:48 hao clear
17:25:48 HHCAO022I All automatic operation rules cleared
17:25:48 # Every job gets an NL tape available as input, containing
17:25:48 # some binary of unknown contents, most likely needing to
17:25:48 # be read as RECFM=U, but RECFM=FB and even RECFM=V are also
17:25:48 # possible.
17:25:48 #
17:25:48 # The job also gets an SL tape available for output, and
17:25:48 # again, any type of content can be written to it, and
17:25:48 # with a bit of luck, hetget will be able to extract the
17:25:48 # data you are looking for.
17:25:48 #
17:25:48 # And finally the job gets an SL AWS tape available for
17:25:48 # input and/or output should you wish to construct a
17:25:48 # special tape. Tape must be called AWSTAP. User should
17:25:48 # back the tape up before submitting it, because it will
17:25:48 # be overwritten and anything could go wrong. AWS is
17:25:48 # expected to be exceptional use of this procedure anyway
17:25:48 #
17:25:48 # Only the NL tape needs an explicit mount. The SL tapes
17:25:48 # are premounted before IPL
17:25:48 hao tgt HASP250 MOUNT
17:25:48 HHCAO016I Target placed at index 0
17:25:48 hao cmd script conf/subjobs2.rc
17:25:48 HHCAO020I Command placed at index 0
17:25:48 /(001F) M 401,VOL=(NL,PCTOMF)
17:25:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:25:48 06.25.48 STC   16  $HASP100 MOUNT    ON STCINRDR
17:25:48 06.25.48 STC   16  $HASP373 MOUNT    STARTED
17:25:48 06.25.48 STC   16  IEF403I MOUNT - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   16 *IEF233A M 401,PCTOMF,,MOUNT,401
17:25:48 06.25.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
17:25:48 06.25.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
17:25:48 06.25.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
17:25:48 06.25.48 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
17:25:48 06.25.48 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
17:25:48 06.25.48 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
17:25:48 06.25.48 STC   15  IST110I  NETWORK SOLICITOR STARTED
17:25:48 06.25.48 STC   15  IST093I  APPLJRP  ACTIVE
17:25:48 06.25.48 STC   15  IST093I  APPLPIES ACTIVE
17:25:48 06.25.48 STC   15  IST093I  APPLPIAD ACTIVE
17:25:48 06.25.48 STC   10  DYNABLDL STARTED
17:25:48 06.25.48 STC   15  IST093I  APPLTSO  ACTIVE
17:25:48 06.25.48 STC   15  IST093I  APPLTEST ACTIVE
17:25:48 06.25.48 STC   10  IEF404I DYNABLDL - ENDED - TIME=06.25.48
17:25:48 06.25.48 STC   10  $HASP395 DYNABLDL ENDED
17:25:48 06.25.48 STC   10  $HASP150 DYNABLDL ON PRINTER2        21 LINES
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 STC   10  $HASP250 DYNABLDL IS PURGED
17:25:48 06.25.48 STC   15  IST093I  LCLMAJRP ACTIVE
17:25:48 06.25.48 STC   15  IST093I  LCLMAJ00 ACTIVE
17:25:48 06.25.48 STC   17  $HASP100 TSO      ON STCINRDR
17:25:48 06.25.48 STC   17  $HASP373 TSO      STARTED
17:25:48 06.25.48 STC   17  IEF403I TSO - STARTED - TIME=06.25.48
17:25:48 06.25.48 STC   18  $HASP100 JRP      ON STCINRDR
17:25:48 06.25.48 STC   18  $HASP373 JRP      STARTED
17:25:48 06.25.48 STC   18  IEF403I JRP - STARTED - TIME=06.25.48
17:25:48 06.25.48           $HASP000 OK
17:25:48 06.25.48           $HASP000 OK
17:25:48 06.25.48 STC   15  IST020I  VTAM INITIALIZATION COMPLETE
17:25:48 06.25.48 STC   15  IEA000I 0C0,IOE,05,0200,400000000001,,,NET     ,06.25.48
17:25:48 06.25.48 STC   15  IEA000I 0C1,IOE,05,0200,400000000001,,,NET     ,06.25.48
17:25:48 06.25.48 STC   15  IEA000I 0C2,IOE,05,0200,400000000001,,,NET     ,06.25.48
17:25:48 06.25.48 STC   11  DMSK00I DYNAMASK DONE ****
17:25:48 06.25.48 STC   11  DMSK06I  START
17:25:48 06.25.48 STC   11  IEF404I DYNAMASK - ENDED - TIME=06.25.48
17:25:48 06.25.48 STC   11  $HASP395 DYNAMASK ENDED
17:25:48 06.25.48 STC   11  $HASP150 DYNAMASK ON PRINTER2        30 LINES
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 STC   11  $HASP250 DYNAMASK IS PURGED
17:25:48 06.25.48 STC   13  BSPSP91I - Parms passed: NOREPLYU
17:25:48 06.25.48 STC   13  BSPSP93I - PFK definitions will be updated in memory
17:25:48 06.25.48 STC   13  BSPSP22I - Dataset processed: SYS1.PARMLIB
17:25:48 06.25.48 STC   13  BSPSP23I - on volume MVSRES
17:25:48 06.25.48 STC   13  BSPSP21I - Member being processed: SETPFK01
17:25:48 06.25.48 STC   13  +BSPSP98I - Member processed, LASTCC=0000
17:25:48 06.25.48 STC   13  +BSPSP21I - Member being processed: SETPFK02
17:25:48 06.25.48 STC   13  +BSPSP98I - Member processed, LASTCC=0000
17:25:48 06.25.48 STC   13  +BSPSP99I - End of processing, MAXRC=0000
17:25:48 06.25.48 STC   13  IEF404I BSPSETPF - ENDED - TIME=06.25.48
17:25:48 06.25.48 STC   13  $HASP395 BSPSETPF ENDED
17:25:48 06.25.48 STC   13  $HASP150 BSPSETPF ON PRINTER2        34 LINES
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 STC   13  $HASP250 BSPSETPF IS PURGED
17:25:48 06.25.48 STC   14  IFC001I  D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
17:25:48 06.25.48 STC   14  IEF404I LOGRECI - ENDED - TIME=06.25.48
17:25:48 06.25.48 STC   14  $HASP395 LOGRECI  ENDED
17:25:48 06.25.48 STC   14  $HASP150 LOGRECI  ON PRINTER2        20 LINES
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 STC   14  $HASP250 LOGRECI  IS PURGED
17:25:48 06.25.48 STC   16  IEF404I MOUNT - ENDED - TIME=06.25.48
17:25:48 06.25.48 STC   16  $HASP395 MOUNT    ENDED
17:25:48 06.25.48 STC   16  $HASP150 MOUNT    ON PRINTER2        18 LINES
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 STC   16  $HASP250 MOUNT    IS PURGED
17:25:48 HHCAO003I Firing command: 'script conf/subjobs2.rc'
17:25:48 script conf/subjobs2.rc
17:25:48 hao clear
17:25:48 HHCAO022I All automatic operation rules cleared
17:25:48 # If we get a prompt for a device, cancel it
17:25:48 hao tgt IEF238D
17:25:48 HHCAO016I Target placed at index 0
17:25:48 hao cmd script conf/cancel.rc
17:25:48 HHCAO020I Command placed at index 0
17:25:48 # If we get a prompt for a catalogue password, answer it
17:25:48 hao tgt IEC301A
17:25:48 HHCAO016I Target placed at index 1
17:25:48 hao cmd script conf/secret.rc
17:25:48 HHCAO020I Command placed at index 1
17:25:48 devinit 401 tapes/pctomf.tdf
17:25:48 HHCTA004I 0401: tapes/pctomf.tdf is a Optical Media Attachment (OMA) tape
17:25:48 HHCPN098I Device 0:0401 initialized
17:25:48 # When we see TERMHERC get purged, our job is done
17:25:48 hao tgt HASP373 TERMHERC
17:25:48 HHCAO016I Target placed at index 2
17:25:48 hao cmd script conf/termherc.rc
17:25:48 HHCAO020I Command placed at index 2
17:25:48 # Now submit the job
17:25:48 devinit 00c jcl/hercauto.jcl eof
17:25:48 HHCSD007I Device 000C unbound from socket 127.0.0.1:3505
17:25:48 HHCSD022I Socketdevice listener thread terminated
17:25:48 HHCPN098I Device 0:000C initialized
17:25:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:25:48 06.25.48 JOB    1  $HASP100 HEXDUMP  ON READER1
17:25:48 06.25.48 JOB    2  $HASP100 TERMHERC ON READER1
17:25:48 06.25.48 JOB    1  $HASP373 HEXDUMP  STARTED - INIT  3 - CLASS C - SYS BSP1
17:25:48 06.25.48 JOB    1  IEF403I HEXDUMP - STARTED - TIME=06.25.48
17:25:48 06.25.48 JOB    1 *IEF233A M 401,PCTOMF,,HEXDUMP,HEXDUMP
17:25:48 06.25.48 STC   17  IKT007I TCAS ACCEPTING LOGONS
17:25:48 06.25.48 STC   17  IKT005I TCAS IS INITIALIZED
17:25:48 06.25.48 STC   18  JRPI101 INITIALIZATION COMPLETE
17:25:48 06.25.48 STC   18 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
17:25:48 06.25.48 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,HEXDUMP,HEXDUMP
17:25:48 06.25.48 JOB    1  IEF234E K 402,MFTOPC,PVT,HEXDUMP,HEXDUMP
17:25:48 06.25.48 JOB    1  IEFACTRT - Stepname  Procstep  Program   Retcode
17:25:48 06.25.48 JOB    1  HEXDUMP    HEXDUMP             HEXDUMP   RC= 0000
17:25:48 06.25.48 JOB    1  IEF404I HEXDUMP - ENDED - TIME=06.25.48
17:25:48 06.25.48 JOB    1  $HASP395 HEXDUMP  ENDED
17:25:48 06.25.48 JOB    1  $HASP150 HEXDUMP  ON PRINTER1        58 LINES
17:25:48 06.25.48 JOB    1 *$HASP190 HEXDUMP  SETUP -- PRINTER1 -- F = 0001 -- C = 6    -- T = SN
17:25:48 06.25.48           $HASP000 OK
17:25:48 06.25.48           $HASP160 PRINTER1 INACTIVE - CLASS=AP
17:25:48 06.25.48 JOB    1  $HASP250 HEXDUMP  IS PURGED
17:25:48 06.25.48 JOB    2  $HASP373 TERMHERC STARTED - INIT  3 - CLASS C - SYS BSP1
17:25:48 HHCAO003I Firing command: 'script conf/termherc.rc'
17:25:48 script conf/termherc.rc
17:25:48 # We do an unnecessary 2-stage terminate, first triggering
17:25:48 # on the start message, then triggering on the purged
17:25:48 # message, to overcome an apparent bug in hercules which
17:25:48 # causes it to sometimes trigger on the wrong jobname.
17:25:48 hao clear
17:25:48 HHCAO022I All automatic operation rules cleared
17:25:48 hao tgt HASP250 TERMHERC
17:25:48 HHCAO016I Target placed at index 0
17:25:48 hao cmd script conf/termherc2.rc
17:25:48 HHCAO020I Command placed at index 0
17:25:48 HHCPN013I EOF reached on SCRIPT file. Processing complete.
17:25:48 06.25.48 JOB    2  IEF403I TERMHERC - STARTED - TIME=06.25.48
17:25:48 06.25.48 JOB    2  IEFACTRT - Stepname  Procstep  Program   Retcode
17:25:48 06.25.48 JOB    2  TERMHERC   S1                  IEBGENER  RC= 0000
17:25:48 06.25.48 JOB    2  IEF404I TERMHERC - ENDED - TIME=06.25.48
17:25:48 06.25.48 JOB    2  $HASP395 TERMHERC ENDED
17:25:48 06.25.48           $HASP309    INIT  3 INACTIVE ******** C=CBA
17:25:48 06.25.48 JOB    2  $HASP150 TERMHERC ON PRINTER2        44 LINES
17:25:48 06.25.48 JOB    2  $HASP150 TERMHERC ON PRINTER1         1 LINE
17:25:48 06.25.48           $HASP160 PRINTER1 INACTIVE - CLASS=AP
17:25:48 06.25.48           $HASP160 PRINTER2 INACTIVE - CLASS=Z
17:25:48 06.25.48 JOB    2  $HASP250 TERMHERC IS PURGED
17:25:48 HHCAO003I Firing command: 'script conf/termherc2.rc'
17:25:48 script conf/termherc2.rc
17:25:48 quit
17:25:48 HHCIN900I Begin Hercules shutdown
17:25:48 HHCIN901I Releasing configuration
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
It took some effort, but I managed to dumb
MVS/380 down to a level that standard
Hercules could cope with. Hercules 3.08
and 3.12 (32-bit) had the same problem
with Hercules/380 3.07 64-bit.

After 47 runs, the Hercules 3.12 console hung here:

10.50.09 STC    5  IEF403I INIT - STARTED - TIME=10.50.09                                                                                                                                   Command ==>                                                                                                                                                                                 CPU0000 PSW=070C0000000312B4 24........                                                                                                                                                       instcount=312,898,491


The end of hercules.log is a little different
from my flavor of 3.07:

21:50:10 10.50.10 JOB    2  $HASP250 TERMHERC IS PURGED
21:50:10 HHCAO003I Firing command: 'script conf/termherc2.rc'
21:50:10 script conf/termherc2.rc
21:50:10 quit
21:50:10 HHCIN900I Begin Hercules shutdown
21:50:10 HHCIN901I Releasing configuration
21:51:09 HHCIN023W CLOSE Event received, SHUTDOWN previously requested...

Full log below.

Thanks. Paul.



21:50:06 Hercules Version 3.12
21:50:06 (c)Copyright 1999-2015 by Roger Bowler, Jan Jaeger, and others
21:50:06 Built on Nov 26 2015 at 18:05:07
21:50:06 Build information:
21:50:06   Windows (MSVC) build for i386
21:50:06   Modes: S/370 ESA/390 z/Arch
21:50:06   Max CPU Engines: 8
21:50:06   Using fthreads instead of pthreads
21:50:06   Dynamic loading support
21:50:06   Using shared libraries
21:50:06   HTTP Server support
21:50:06   No SIGABEND handler
21:50:06   Regular Expressions support
21:50:06   Automatic Operator support
21:50:06   Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8 fetch_dw store_dw
21:50:06 Running on PAUL-DELL Windows_NT-6.2 i686 MP=8
21:50:06 HHCHD018I Loadable module directory is hercules
21:50:06 Crypto module loaded (c) Copyright Bernard van der Helm, 2003-2010
21:50:06   Active: Message Security Assist
21:50:06           Message Security Assist Extension 1
21:50:06           Message Security Assist Extension 2
21:50:06           Message Security Assist Extension 3
21:50:06           Message Security Assist Extension 4
21:50:06 HHCPN210I Default Allowed AUTOMOUNT directory = "c:\mvs380\"
21:50:06 HHCCF065I Hercules: tid=000022DC, pid=12688, pgid=12688, priority=8
21:50:06 HHCHT001I HTTP listener thread started: tid=00003A14, pid=12688
21:50:06 HHCHT013I Using HTTPROOT directory "c:\herc380\html\"
21:50:06 HHCHT006I Waiting for HTTP requests on port 8081
21:50:06 HHCSD004I Device 000C bound to socket 127.0.0.1:3505
21:50:06 HHCSD020I Socketdevice listener thread started: tid=00001FE0, pid=12688
21:50:06 HHCCF083I conf/mvs380.conf Including conf/mvs380_DASD.conf at 122 .
21:50:06 HHCDA004I opening dasd/mvsres.148 readonly
21:50:06 HHCDA020I dasd/mvsres.148 cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/sort01.131 readonly
21:50:06 HHCDA020I dasd/sort01.131 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/sort02.132 readonly
21:50:06 HHCDA020I dasd/sort02.132 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/sort03.133 readonly
21:50:06 HHCDA020I dasd/sort03.133 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/sort04.134 readonly
21:50:06 HHCDA020I dasd/sort04.134 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/sort05.135 readonly
21:50:06 HHCDA020I dasd/sort05.135 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/sort06.136 readonly
21:50:06 HHCDA020I dasd/sort06.136 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/work00.140 readonly
21:50:06 HHCDA020I dasd/work00.140 cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA020I dasd/hasp00.152 cyls=404 heads=19 tracks=7676 trklen=13312
21:50:06 HHCDA020I dasd/page00.160 cyls=698 heads=12 tracks=8376 trklen=8704
21:50:06 HHCDA020I dasd/page01.161 cyls=698 heads=12 tracks=8376 trklen=8704
21:50:06 HHCDA020I dasd/page02.162 cyls=698 heads=12 tracks=8376 trklen=8704
21:50:06 HHCDA020I dasd/work01.170 cyls=962 heads=12 tracks=11544 trklen=35840
21:50:06 HHCDA004I opening dasd/work02.180 readonly
21:50:06 HHCDA020I dasd/work02.180 cyls=886 heads=15 tracks=13290 trklen=47616
21:50:06 HHCDA004I opening dasd/work03.190 readonly
21:50:06 HHCDA020I dasd/work03.190 cyls=1114 heads=15 tracks=16710 trklen=56832
21:50:06 HHCDA004I opening dasd/mvscat.191 readonly
21:50:06 HHCDA020I dasd/mvscat.191 cyls=1114 heads=15 tracks=16710 trklen=56832
21:50:06 HHCDA004I opening dasd/seasik.192 readonly
21:50:06 HHCDA020I dasd/seasik.192 cyls=1114 heads=15 tracks=16710 trklen=56832
21:50:06 HHCDA020I dasd/mvssrc.193 cyls=2226 heads=15 tracks=33390 trklen=56832
21:50:06 HHCDA002E 01B4:File not found or invalid 'dasd/pub004.1b4'
21:50:06 HHCCF044E Initialization failed for device 01B4
21:50:06 HHCDA004I opening dasd/pub000.240 readonly
21:50:06 HHCDA020I dasd/pub000.240 cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/mvsdlb.248 readonly
21:50:06 HHCDA020I dasd/mvsdlb.248 cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/pub002.280 readonly
21:50:06 HHCDA020I dasd/pub002.280 cyls=1772 heads=15 tracks=26580 trklen=47616
21:50:06 HHCDA004I opening dasd/tmptmp.2b1 readonly
21:50:06 HHCDA020I dasd/tmptmp.2b1 cyls=1114 heads=15 tracks=16710 trklen=56832
21:50:06 HHCDA004I opening dasd/xmit90.2b2 readonly
21:50:06 HHCDA020I dasd/xmit90.2b2 cyls=1114 heads=15 tracks=16710 trklen=56832
21:50:06 HHCDA004I opening dasd/start1.150 readonly
21:50:06 HHCDA020I dasd/start1.150 cyls=808 heads=19 tracks=15352 trklen=13312
21:50:06 HHCDA004I opening dasd/spool0.151 readonly
21:50:06 HHCDA020I dasd/spool0.151 cyls=808 heads=19 tracks=15352 trklen=13312
21:50:06 HHCDA004I opening dasd/cbt000.340 readonly
21:50:06 HHCDA020I dasd/cbt000.340 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/cbt001.341 readonly
21:50:06 HHCDA020I dasd/cbt001.341 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/cbt002.342 readonly
21:50:06 HHCDA020I dasd/cbt002.342 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/cbtcat.343 readonly
21:50:06 HHCDA020I dasd/cbtcat.343 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/src000.348 readonly
21:50:06 HHCDA020I dasd/src000.348 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/src001.349 readonly
21:50:06 HHCDA020I dasd/src001.349 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/src002.34a readonly
21:50:06 HHCDA020I dasd/src002.34a cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/srccat.34b readonly
21:50:06 HHCDA020I dasd/srccat.34b cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/smp001.149 readonly
21:50:06 HHCDA020I dasd/smp001.149 cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/smp002.14a readonly
21:50:06 HHCDA020I dasd/smp002.14a cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/smp003.14b readonly
21:50:06 HHCDA020I dasd/smp003.14b cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/smp004.14c readonly
21:50:06 HHCDA020I dasd/smp004.14c cyls=560 heads=30 tracks=16800 trklen=19456
21:50:06 HHCDA004I opening dasd/js2sp0.700 readonly
21:50:06 HHCDA020I dasd/js2sp0.700 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/dlicat.138 readonly
21:50:06 HHCDA020I dasd/dlicat.138 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/dlisys.139 readonly
21:50:06 HHCDA020I dasd/dlisys.139 cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/dli000.13a readonly
21:50:06 HHCDA020I dasd/dli000.13a cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/dli001.13b readonly
21:50:06 HHCDA020I dasd/dli001.13b cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/dli002.13c readonly
21:50:06 HHCDA020I dasd/dli002.13c cyls=200 heads=20 tracks=4000 trklen=7680
21:50:06 HHCDA004I opening dasd/js3sp0.710 readonly
21:50:06 HHCDA020I dasd/js3sp0.710 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCDA004I opening dasd/js3res.711 readonly
21:50:06 HHCDA020I dasd/js3res.711 cyls=555 heads=30 tracks=16650 trklen=19456
21:50:06 HHCTE001I Console connection thread started: tid=000045AC, pid=12688
21:50:06 HHCTE003I Waiting for console connection on port 3270
21:50:06 HHCTA066I 0400: option 'level' accepted.
21:50:06 HHCTA066I 0401: option 'level' accepted.
21:50:06 HHCTA066I 0402: option 'level' accepted.
21:50:06 HHCTA066I 0403: option 'level' accepted.
21:50:06 HHCCP002I CPU0000 thread started: tid=00003E34, pid=12688, priority=0
21:50:06 HHCCP003I CPU0000 architecture mode S/370
21:50:06 HHCPN001I Control panel thread started: tid=000022DC, pid=12688
21:50:06 HHCTT002I Timer thread started: tid=000012F4, pid=12688, priority=-20
21:50:06 HHCPN008I Script file processing started using file "conf/auto_run.rc"
21:50:06 HHCAO001I Hercules Automatic Operator thread started;
21:50:06           tid=000048BC, pri=0, pid=12688
21:50:06 devlist
21:50:06 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof
21:50:06      (no one currently connected)
21:50:06 0:000D 3525 pch/pch00d.txt ascii crlf
21:50:06 0:000E 1403 prt/prt00e.txt crlf noclear print fcbck
21:50:06 0:000F 1403 prt/prt00f.txt crlf noclear print fcbck
21:50:06 0:001F 3215 *syscons cmdpref(/)
21:50:06 0:00C0 3270  
21:50:06 0:00C1 3270  
21:50:06 0:00C2 3270  
21:50:06 0:00C7 3287  
21:50:06 0:010C 3505 jcl/dummy eof
21:50:06 0:0131 2314 dasd/sort01.131 [200 cyls] open
21:50:06 0:0132 2314 dasd/sort02.132 [200 cyls] open
21:50:06 0:0133 2314 dasd/sort03.133 [200 cyls] open
21:50:06 0:0134 2314 dasd/sort04.134 [200 cyls] open
21:50:06 0:0135 2314 dasd/sort05.135 [200 cyls] open
21:50:06 0:0136 2314 dasd/sort06.136 [200 cyls] open
21:50:06 0:0138 2314 dasd/dlicat.138 [200 cyls] open
21:50:06 0:0139 2314 dasd/dlisys.139 [200 cyls] open
21:50:06 0:013A 2314 dasd/dli000.13a [200 cyls] open
21:50:06 0:013B 2314 dasd/dli001.13b [200 cyls] open
21:50:06 0:013C 2314 dasd/dli002.13c [200 cyls] open
21:50:06 0:0140 3350 dasd/work00.140 [560 cyls] open
21:50:06 0:0148 3350 dasd/mvsres.148 [560 cyls] open
21:50:06 0:0149 3350 dasd/smp001.149 [560 cyls] open
21:50:06 0:014A 3350 dasd/smp002.14a [560 cyls] open
21:50:06 0:014B 3350 dasd/smp003.14b [560 cyls] open
21:50:06 0:014C 3350 dasd/smp004.14c [560 cyls] open
21:50:06 0:0150 3330 dasd/start1.150 [808 cyls] open
21:50:06 0:0151 3330 dasd/spool0.151 [808 cyls] open
21:50:06 0:0152 3330 dasd/hasp00.152 [404 cyls] open
21:50:06 0:0160 3340 dasd/page00.160 [698 cyls] open
21:50:06 0:0161 3340 dasd/page01.161 [698 cyls] open
21:50:06 0:0162 3340 dasd/page02.162 [698 cyls] open
21:50:06 0:0170 3375 dasd/work01.170 [962 cyls] open
21:50:06 0:01A0 3380 dasd/work02.180 [886 cyls] open
21:50:06 0:01B0 3390 dasd/work03.190 [1114 cyls] open
21:50:06 0:01B1 3390 dasd/mvscat.191 [1114 cyls] open
21:50:06 0:01B2 3390 dasd/seasik.192 [1114 cyls] open
21:50:06 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] open
21:50:06 0:01C7 3287  
21:50:06 0:0240 3350 dasd/pub000.240 [560 cyls] open
21:50:06 0:0248 3350 dasd/mvsdlb.248 [560 cyls] open
21:50:06 0:02A0 3380 dasd/pub002.280 [1772 cyls] open
21:50:06 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] open
21:50:06 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] open
21:50:06 0:030E 1403 log/hardcopy.log crlf noclear print fcbck
21:50:06 0:0340 3350 dasd/cbt000.340 [555 cyls] open
21:50:06 0:0341 3350 dasd/cbt001.341 [555 cyls] open
21:50:06 0:0342 3350 dasd/cbt002.342 [555 cyls] open
21:50:06 0:0343 3350 dasd/cbtcat.343 [555 cyls] open
21:50:06 0:0348 3350 dasd/src000.348 [555 cyls] open
21:50:06 0:0349 3350 dasd/src001.349 [555 cyls] open
21:50:06 0:034A 3350 dasd/src002.34a [555 cyls] open
21:50:06 0:034B 3350 dasd/srccat.34b [555 cyls] open
21:50:06 0:0400 3420 *
21:50:06 0:0401 3420 *
21:50:06 0:0402 3420 *
21:50:06 0:0403 3420 *
21:50:06 0:0700 3350 dasd/js2sp0.700 [555 cyls] open
21:50:06 0:0710 3350 dasd/js3sp0.710 [555 cyls] open
21:50:06 0:0711 3350 dasd/js3res.711 [555 cyls] open
21:50:06 logopt timestamp
21:50:06 HHCPN197I Log option set: TIMESTAMP
21:50:06 panrate 1000
21:50:06 # really need to wait for SVC120I, but if building MVS/380
21:50:06 # or some other stuffup with parms, need to trigger on an
21:50:06 # alternative. First one hit will clear targets.
21:50:06 # If we get a prompt for a device, cancel it
21:50:06 hao tgt IEF238D
21:50:06 HHCAO016I Target placed at index 0
21:50:06 hao cmd script conf/cancel.rc
21:50:06 HHCAO020I Command placed at index 0
21:50:06 hao tgt HASP395 DYNAMASK
21:50:06 HHCAO016I Target placed at index 1
21:50:06 hao cmd script conf/subjobs_slow.rc
21:50:06 HHCAO020I Command placed at index 1
21:50:06 hao tgt HASP373 SVC120I
21:50:06 HHCAO016I Target placed at index 2
21:50:06 hao cmd script conf/subjobs_fast.rc
21:50:06 HHCAO020I Command placed at index 2
21:50:06 hao tgt HASP436 REPLY
21:50:06 HHCAO016I Target placed at index 3
21:50:06 hao cmd script conf/replyy.rc
21:50:06 HHCAO020I Command placed at index 3
21:50:06 devinit 402 tapes/mftopc.het
21:50:06 HHCTA004I 0402: tapes/mftopc.het is a Hercules Emulated Tape file
21:50:06 HHCPN098I Device 0:0402 initialized
21:50:06 devinit 403 tapes/awstap.aws
21:50:06 HHCTA004I 0403: tapes/awstap.aws is a Hercules Emulated Tape file
21:50:06 HHCPN098I Device 0:0403 initialized
21:50:06 # co will give you a cold start of JES2 which is useful in
21:50:06 # automated runs
21:50:06 /(001F) r 00,clpa,cmd=co
21:50:06 #/r 00,clpa
21:50:06 ipl 148
21:50:06 HHCPN013I EOF reached on SCRIPT file. Processing complete.
21:50:06 IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
21:50:06 HHCCD001I Readahead thread 1 started: tid=00003440, pid=12688
21:50:06 HHCCD001I Readahead thread 2 started: tid=0000321C, pid=12688
21:50:06 HHCCD002I Writer thread 1 started: tid=00003DE8, pid=12688
21:50:06 HHCCD003I Garbage collector thread started: tid=00002FA8, pid=12688
21:50:06 IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
21:50:06  PLPA ... SYS1.PAGELPA
21:50:06  COMMON . SYS1.PAGECSA
21:50:06  DUPLEX . SYS1.DUPLEX
21:50:06  LOCAL .. SYS1.PAGEL01
21:50:06  LOCAL .. SYS1.PAGEL02
21:50:06  LOCAL .. SYS1.PAGEL03
21:50:06 HHCCD002I Writer thread 2 started: tid=00004880, pid=12688
21:50:08 *IEE362A SMF ENTER DUMP FOR SYS1.MANX ON MVSRES
21:50:08  IEE360I SMF NOW RECORDING ON SYS1.MANY ON MVSRES TIME=10.50.08
21:50:08  IGF992I  MIH INIT COMPLETE, PRI=000300, SEC=000015
21:50:08  IEF677I WARNING MESSAGE(S) FOR JOB JES2     ISSUED
21:50:08 *00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
21:50:08 HHCAO003I Firing command: 'script conf/replyy.rc'
21:50:08 script conf/replyy.rc
21:50:08 /(001F) reply 00,y
21:50:08 HHCPN013I EOF reached on SCRIPT file. Processing complete.
21:50:08  IEE600I REPLY TO 00 IS;SUPPRESSED
21:50:08  $HASP493 JES2 COLD-START IS IN PROGRESS
21:50:09  $HASP412 MAXIMUM OF 1   READER(S)  EXCEEDED
21:50:09 10.50.09           IEE041I THE SYSTEM LOG IS NOW ACTIVE
21:50:09 10.50.09           IEE302I 00E      ONLINE
21:50:09 10.50.09           IEE302I 00F      ONLINE
21:50:09 10.50.09           IEE313I 30E     UNIT REF INVALID
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           IEE450I 10.50.09 UNIT STATUS 161
21:50:09  UNIT TYPE STATUS  VOLSER VOLSTATE   UNIT TYPE STATUS  VOLSER VOLSTATE
21:50:09  400  3400 O                  /REMOV 401  3400 O                  /REMOV
21:50:09  402  3400 O                  /REMOV
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP160 PRINTER1 INACTIVE - CLASS=AP
21:50:09 10.50.09           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:09 10.50.09           $HASP160 PUNCH1   INACTIVE - CLASS=B
21:50:09 10.50.09 STC    2  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    2  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    2  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    3  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    3  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    3  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    4  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    4  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    4  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    5  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    5  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    5  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    6  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    6  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    6  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    7  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    7  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    7  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    8  $HASP100 INIT     ON STCINRDR
21:50:09 10.50.09 STC    8  $HASP373 INIT     STARTED
21:50:09 10.50.09 STC    8  IEF403I INIT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC    9  $HASP100 SVC120I  ON STCINRDR
21:50:09 10.50.09 STC    9  $HASP373 SVC120I  STARTED
21:50:09 HHCAO003I Firing command: 'script conf/subjobs_fast.rc'
21:50:09 script conf/subjobs_fast.rc
21:50:09 # Now we know that SVC120I has started. But due to some
21:50:09 # weird pausing, it may get locked out. So clear out
21:50:09 # other triggers and wait on this
21:50:09 hao clear
21:50:09 HHCAO022I All automatic operation rules cleared
21:50:09 hao tgt HASP250 SVC120I
21:50:09 HHCAO016I Target placed at index 0
21:50:09 hao cmd script conf/subjobs.rc
21:50:09 HHCAO020I Command placed at index 0
21:50:09 HHCPN013I EOF reached on SCRIPT file. Processing complete.
21:50:09 10.50.09 STC    9  IEF403I SVC120I - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   10  $HASP100 DYNABLDL ON STCINRDR
21:50:09 10.50.09 STC   10  $HASP373 DYNABLDL STARTED
21:50:09 10.50.09 STC   10  IEF403I DYNABLDL - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   11  $HASP100 DYNAMASK ON STCINRDR
21:50:09 10.50.09 STC   11  $HASP373 DYNAMASK STARTED
21:50:09 10.50.09 STC   11  IEF403I DYNAMASK - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   12  $HASP100 BSPPILOT ON STCINRDR
21:50:09 10.50.09 STC   12  $HASP373 BSPPILOT STARTED
21:50:09 10.50.09 STC   12  IEF403I BSPPILOT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   13  $HASP100 BSPSETPF ON STCINRDR
21:50:09 10.50.09 STC   13  $HASP373 BSPSETPF STARTED
21:50:09 10.50.09 STC   13  IEF403I BSPSETPF - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   14  $HASP100 LOGRECI  ON STCINRDR
21:50:09 10.50.09 STC   14  $HASP373 LOGRECI  STARTED
21:50:09 10.50.09 STC   14  IEF403I LOGRECI - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   15  $HASP100 NET      ON STCINRDR
21:50:09 10.50.09 STC   15  $HASP373 NET      STARTED
21:50:09 10.50.09 STC   15  IEF403I NET - STARTED - TIME=10.50.09
21:50:09 10.50.09           $HASP309    INIT  1 INACTIVE ******** C=A
21:50:09 10.50.09           $HASP309    INIT  2 INACTIVE ******** C=BA
21:50:09 10.50.09           $HASP309    INIT  3 INACTIVE ******** C=CBA
21:50:09 10.50.09           $HASP309    INIT  4 INACTIVE ******** C=SHB
21:50:09 10.50.09           $HASP309    INIT  5 INACTIVE ******** C=SBA
21:50:09 10.50.09           $HASP309    INIT  6 INACTIVE ******** C=S
21:50:09 10.50.09           $HASP309    INIT  7 INACTIVE ******** C=E
21:50:09 10.50.09 STC    9  BSPGM39E - Hercules and MVS 380 mods required
21:50:09 10.50.09 STC    9  IEF404I SVC120I - ENDED - TIME=10.50.09
21:50:09 10.50.09 STC    9  $HASP395 SVC120I  ENDED
21:50:09 10.50.09 STC    9  $HASP150 SVC120I  ON PRINTER2        41 LINES
21:50:09 10.50.09 STC    9 *$HASP190 SVC120I  SETUP -- PRINTER2 -- F = 0001 -- C = 6    -- T = SN
21:50:09 10.50.09           $HASP000 OK
21:50:09 10.50.09           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:09 10.50.09 STC    9  $HASP250 SVC120I  IS PURGED
21:50:09 HHCAO003I Firing command: 'script conf/subjobs.rc'
21:50:09 script conf/subjobs.rc
21:50:09 hao clear
21:50:09 HHCAO022I All automatic operation rules cleared
21:50:09 # Every job gets an NL tape available as input, containing
21:50:09 # some binary of unknown contents, most likely needing to
21:50:09 # be read as RECFM=U, but RECFM=FB and even RECFM=V are also
21:50:09 # possible.
21:50:09 #
21:50:09 # The job also gets an SL tape available for output, and
21:50:09 # again, any type of content can be written to it, and
21:50:09 # with a bit of luck, hetget will be able to extract the
21:50:09 # data you are looking for.
21:50:09 #
21:50:09 # And finally the job gets an SL AWS tape available for
21:50:09 # input and/or output should you wish to construct a
21:50:09 # special tape. Tape must be called AWSTAP. User should
21:50:09 # back the tape up before submitting it, because it will
21:50:09 # be overwritten and anything could go wrong. AWS is
21:50:09 # expected to be exceptional use of this procedure anyway
21:50:09 #
21:50:09 # Only the NL tape needs an explicit mount. The SL tapes
21:50:09 # are premounted before IPL
21:50:09 hao tgt HASP250 MOUNT
21:50:09 HHCAO016I Target placed at index 0
21:50:09 hao cmd script conf/subjobs2.rc
21:50:09 HHCAO020I Command placed at index 0
21:50:09 /(001F) M 401,VOL=(NL,PCTOMF)
21:50:09 HHCPN013I EOF reached on SCRIPT file. Processing complete.
21:50:09 10.50.09 STC   16  $HASP100 MOUNT    ON STCINRDR
21:50:09 10.50.09 STC   16  $HASP373 MOUNT    STARTED
21:50:09 10.50.09 STC   16  IEF403I MOUNT - STARTED - TIME=10.50.09
21:50:09 10.50.09 STC   16 *IEF233A M 401,PCTOMF,,MOUNT,401
21:50:09 10.50.09 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
21:50:09 10.50.09 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
21:50:09 10.50.09 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
21:50:09 10.50.09 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
21:50:09 10.50.09 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
21:50:09 10.50.09 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
21:50:09 10.50.09 STC   10  DYNABLDL STARTED
21:50:09 10.50.09 STC   15  IST110I  NETWORK SOLICITOR STARTED
21:50:09 10.50.09 STC   10  IEF404I DYNABLDL - ENDED - TIME=10.50.09
21:50:09 10.50.09 STC   10  $HASP395 DYNABLDL ENDED
21:50:09 10.50.09 STC   10  $HASP150 DYNABLDL ON PRINTER2        21 LINES
21:50:10 10.50.10           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:10 10.50.10 STC   10  $HASP250 DYNABLDL IS PURGED
21:50:10 10.50.10 STC   15  IST093I  APPLJRP  ACTIVE
21:50:10 10.50.10 STC   15  IST093I  APPLPIES ACTIVE
21:50:10 10.50.10 STC   15  IST093I  APPLPIAD ACTIVE
21:50:10 10.50.10 STC   15  IST093I  APPLTSO  ACTIVE
21:50:10 10.50.10 STC   15  IST093I  APPLTEST ACTIVE
21:50:10 10.50.10 STC   15  IST093I  LCLMAJRP ACTIVE
21:50:10 10.50.10 STC   15  IST093I  LCLMAJ00 ACTIVE
21:50:10 10.50.10 STC   17  $HASP100 TSO      ON STCINRDR
21:50:10 10.50.10 STC   17  $HASP373 TSO      STARTED
21:50:10 10.50.10 STC   17  IEF403I TSO - STARTED - TIME=10.50.10
21:50:10 10.50.10 STC   18  $HASP100 JRP      ON STCINRDR
21:50:10 10.50.10           $HASP000 OK
21:50:10 10.50.10           $HASP000 OK
21:50:10 10.50.10 STC   15  IST020I  VTAM INITIALIZATION COMPLETE
21:50:10 10.50.10 STC   18  $HASP373 JRP      STARTED
21:50:10 10.50.10 STC   18  IEF403I JRP - STARTED - TIME=10.50.10
21:50:10 10.50.10 STC   15  IEA000I 0C0,IOE,05,0200,400000000001,,,NET     ,10.50.10
21:50:10 10.50.10 STC   15  IEA000I 0C1,IOE,05,0200,400000000001,,,NET     ,10.50.10
21:50:10 10.50.10 STC   15  IEA000I 0C2,IOE,05,0200,400000000001,,,NET     ,10.50.10
21:50:10 10.50.10 STC   11  DMSK00I DYNAMASK DONE ****
21:50:10 10.50.10 STC   11  DMSK06I  START
21:50:10 10.50.10 STC   11  IEF404I DYNAMASK - ENDED - TIME=10.50.10
21:50:10 10.50.10 STC   11  $HASP395 DYNAMASK ENDED
21:50:10 10.50.10 STC   11  $HASP150 DYNAMASK ON PRINTER2        30 LINES
21:50:10 10.50.10           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:10 10.50.10 STC   11  $HASP250 DYNAMASK IS PURGED
21:50:10 10.50.10 STC   13  BSPSP91I - Parms passed: NOREPLYU
21:50:10 10.50.10 STC   13  BSPSP93I - PFK definitions will be updated in memory
21:50:10 10.50.10 STC   13  BSPSP22I - Dataset processed: SYS1.PARMLIB
21:50:10 10.50.10 STC   13  BSPSP23I - on volume MVSRES
21:50:10 10.50.10 STC   13  BSPSP21I - Member being processed: SETPFK01
21:50:10 10.50.10 STC   13  +BSPSP98I - Member processed, LASTCC=0000
21:50:10 10.50.10 STC   13  +BSPSP21I - Member being processed: SETPFK02
21:50:10 10.50.10 STC   13  +BSPSP98I - Member processed, LASTCC=0000
21:50:10 10.50.10 STC   13  +BSPSP99I - End of processing, MAXRC=0000
21:50:10 10.50.10 STC   13  IEF404I BSPSETPF - ENDED - TIME=10.50.10
21:50:10 10.50.10 STC   13  $HASP395 BSPSETPF ENDED
21:50:10 10.50.10 STC   13  $HASP150 BSPSETPF ON PRINTER2        34 LINES
21:50:10 10.50.10           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:10 10.50.10 STC   13  $HASP250 BSPSETPF IS PURGED
21:50:10 10.50.10 STC   14  IFC001I  D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
21:50:10 10.50.10 STC   14  IEF404I LOGRECI - ENDED - TIME=10.50.10
21:50:10 10.50.10 STC   14  $HASP395 LOGRECI  ENDED
21:50:10 10.50.10 STC   14  $HASP150 LOGRECI  ON PRINTER2        20 LINES
21:50:10 10.50.10           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:10 10.50.10 STC   14  $HASP250 LOGRECI  IS PURGED
21:50:10 10.50.10 STC   16  IEF404I MOUNT - ENDED - TIME=10.50.10
21:50:10 10.50.10 STC   16  $HASP395 MOUNT    ENDED
21:50:10 10.50.10 STC   16  $HASP150 MOUNT    ON PRINTER2        18 LINES
21:50:10 10.50.10           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:10 10.50.10 STC   16  $HASP250 MOUNT    IS PURGED
21:50:10 HHCAO003I Firing command: 'script conf/subjobs2.rc'
21:50:10 script conf/subjobs2.rc
21:50:10 hao clear
21:50:10 HHCAO022I All automatic operation rules cleared
21:50:10 # If we get a prompt for a device, cancel it
21:50:10 hao tgt IEF238D
21:50:10 HHCAO016I Target placed at index 0
21:50:10 hao cmd script conf/cancel.rc
21:50:10 HHCAO020I Command placed at index 0
21:50:10 # If we get a prompt for a catalogue password, answer it
21:50:10 hao tgt IEC301A
21:50:10 HHCAO016I Target placed at index 1
21:50:10 hao cmd script conf/secret.rc
21:50:10 HHCAO020I Command placed at index 1
21:50:10 devinit 401 tapes/pctomf.tdf
21:50:10 HHCTA004I 0401: tapes/pctomf.tdf is a Optical Media Attachment (OMA) tape
21:50:10 HHCPN098I Device 0:0401 initialized
21:50:10 # When we see TERMHERC get purged, our job is done
21:50:10 hao tgt HASP373 TERMHERC
21:50:10 HHCAO016I Target placed at index 2
21:50:10 hao cmd script conf/termherc.rc
21:50:10 HHCAO020I Command placed at index 2
21:50:10 # Now submit the job
21:50:10 devinit 00c jcl/hercauto.jcl eof
21:50:10 HHCSD007I Device 000C unbound from socket 127.0.0.1:3505
21:50:10 HHCSD022I Socketdevice listener thread terminated
21:50:10 HHCPN098I Device 0:000C initialized
21:50:10 HHCPN013I EOF reached on SCRIPT file. Processing complete.
21:50:10 10.50.10 JOB    1  $HASP100 HEXDUMP  ON READER1
21:50:10 10.50.10 JOB    2  $HASP100 TERMHERC ON READER1
21:50:10 10.50.10 JOB    1  $HASP373 HEXDUMP  STARTED - INIT  3 - CLASS C - SYS BSP1
21:50:10 10.50.10 JOB    1  IEF403I HEXDUMP - STARTED - TIME=10.50.10
21:50:10 10.50.10 JOB    1 *IEF233A M 401,PCTOMF,,HEXDUMP,HEXDUMP
21:50:10 10.50.10 STC   17  IKT007I TCAS ACCEPTING LOGONS
21:50:10 10.50.10 STC   17  IKT005I TCAS IS INITIALIZED
21:50:10 10.50.10 STC   18  JRPI101 INITIALIZATION COMPLETE
21:50:10 10.50.10 STC   18 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
21:50:10 10.50.10 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,HEXDUMP,HEXDUMP
21:50:10 10.50.10 JOB    1  IEF234E K 402,MFTOPC,PVT,HEXDUMP,HEXDUMP
21:50:10 10.50.10 JOB    1  IEFACTRT - Stepname  Procstep  Program   Retcode
21:50:10 10.50.10 JOB    1  HEXDUMP    HEXDUMP             HEXDUMP   RC= 0000
21:50:10 10.50.10 JOB    1  IEF404I HEXDUMP - ENDED - TIME=10.50.10
21:50:10 10.50.10 JOB    1  $HASP395 HEXDUMP  ENDED
21:50:10 10.50.10 JOB    1  $HASP150 HEXDUMP  ON PRINTER1        55 LINES
21:50:10 10.50.10 JOB    1 *$HASP190 HEXDUMP  SETUP -- PRINTER1 -- F = 0001 -- C = 6    -- T = SN
21:50:10 10.50.10           $HASP000 OK
21:50:10 10.50.10 JOB    2  $HASP373 TERMHERC STARTED - INIT  3 - CLASS C - SYS BSP1
21:50:10 HHCAO003I Firing command: 'script conf/termherc.rc'
21:50:10 script conf/termherc.rc
21:50:10 # We do an unnecessary 2-stage terminate, first triggering
21:50:10 # on the start message, then triggering on the purged
21:50:10 # message, to overcome an apparent bug in hercules which
21:50:10 # causes it to sometimes trigger on the wrong jobname.
21:50:10 hao clear
21:50:10 HHCAO022I All automatic operation rules cleared
21:50:10 hao tgt HASP250 TERMHERC
21:50:10 HHCAO016I Target placed at index 0
21:50:10 hao cmd script conf/termherc2.rc
21:50:10 HHCAO020I Command placed at index 0
21:50:10 HHCPN013I EOF reached on SCRIPT file. Processing complete.
21:50:10 10.50.10           $HASP160 PRINTER1 INACTIVE - CLASS=AP
21:50:10 10.50.10 JOB    1  $HASP250 HEXDUMP  IS PURGED
21:50:10 10.50.10 JOB    2  IEF403I TERMHERC - STARTED - TIME=10.50.10
21:50:10 10.50.10 JOB    2  IEFACTRT - Stepname  Procstep  Program   Retcode
21:50:10 10.50.10 JOB    2  TERMHERC   S1                  IEBGENER  RC= 0000
21:50:10 10.50.10 JOB    2  IEF404I TERMHERC - ENDED - TIME=10.50.10
21:50:10 10.50.10 JOB    2  $HASP395 TERMHERC ENDED
21:50:10 10.50.10           $HASP309    INIT  3 INACTIVE ******** C=CBA
21:50:10 10.50.10 JOB    2  $HASP150 TERMHERC ON PRINTER2        44 LINES
21:50:10 10.50.10 JOB    2  $HASP150 TERMHERC ON PRINTER1         1 LINE
21:50:10 10.50.10           $HASP160 PRINTER1 INACTIVE - CLASS=AP
21:50:10 10.50.10           $HASP160 PRINTER2 INACTIVE - CLASS=Z
21:50:10 10.50.10 JOB    2  $HASP250 TERMHERC IS PURGED
21:50:10 HHCAO003I Firing command: 'script conf/termherc2.rc'
21:50:10 script conf/termherc2.rc
21:50:10 quit
21:50:10 HHCIN900I Begin Hercules shutdown
21:50:10 HHCIN901I Releasing configuration
21:51:09 HHCIN023W CLOSE Event received, SHUTDOWN previously requested...
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
I went to this page to get Hyperion:

http://hercules-390.github.io/html/

That pages says I need:

Microsoft Visual C++ 2008 Runtime components

I believe I already have that installed, which
is what I use to do a 64-bit build of
Hercules/380 3.07.

But when I tried the executables from here:

https://github.com/hercules-390/hyperion/releases/tag/4.0.0-rc0
https://github.com/hercules-390/hyperion/releases/download/4.0.0-rc0/Hercules-4.0.0-rc0-win-x86.zip

I got an error saying that this:

VCRUNTIME140.dll

does not exist.

I thought there might be a Hyperion .MSI
installer I could use instead, but didn't
see one.

I was only after Hyperion to see if a bug
in Hercules 3.12 has been fixed.

Otherwise I'm happy to debug this
problem on Hercules 3.07 which I
am more familiar with, if someone
can guide me on what to try.

I'm happy to run hundreds of tests
waiting for the problem to be
reproduced.

Also I don't want my 3.07 build
environment to be disturbed by
upgrading compiler.

BFN. Paul.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
VCRUNTIME140.dll is the VC2015 DLL.

You need to install the VC2015 runtime redistributables...

https://www.microsoft.com/en-us/download/details.aspx?id=48145

Joe

On Wed, Jan 18, 2017 at 5:21 AM, [hidden email] [hercules-390] <
[hidden email]> wrote:

>
>
> I went to this page to get Hyperion:
>
> http://hercules-390.github.io/html/
>
> That pages says I need:
>
> Microsoft Visual C++ 2008 Runtime components
>
> I believe I already have that installed, which
> is what I use to do a 64-bit build of
> Hercules/380 3.07.
>
> But when I tried the executables from here:
>
> https://github.com/hercules-390/hyperion/releases/tag/4.0.0-rc0
> https://github.com/hercules-390/hyperion/releases/
> download/4.0.0-rc0/Hercules-4.0.0-rc0-win-x86.zip
>
> I got an error saying that this:
>
> VCRUNTIME140.dll
>
> does not exist.
>
> I thought there might be a Hyperion .MSI
> installer I could use instead, but didn't
> see one.
>
> I was only after Hyperion to see if a bug
> in Hercules 3.12 has been fixed.
>
> Otherwise I'm happy to debug this
> problem on Hercules 3.07 which I
> am more familiar with, if someone
> can guide me on what to try.
>
> I'm happy to run hundreds of tests
> waiting for the problem to be
> reproduced.
>
> Also I don't want my 3.07 build
> environment to be disturbed by
> upgrading compiler.
>
> BFN. Paul.
>
>
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
 - - - In [hidden email], <kerravon86@...> wrote:

> I run a slightly-modified Hercules 3.07 automatically
>via Windows batch files.
> I tried setting it up to automatically do lots of
>runs to see if I could reproduce an anomaly
>I had discovered previously.
> I was successful. In about 1 in 78 runs, the
>console appears to freeze. Here is what
>the console looks like:
> 04.37.49 JOB 1 IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP
>Command ==> CPU0000 PSW=078D0000803708B8 31.....P.. instcount=240,587,479
- - - remainder snipped - - -

Please define "freeze".

Console input was inhibited for five seconds or five minutes?
Console display stopped for five seconds of five minutes?

Could you also show the message before the "freeze"?

Could you have had an errant PAUSE coming from somewhere?.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
Joe Monk wrote:

> VCRUNTIME140.dll is the VC2015 DLL.
>
> You need to install the VC2015 runtime redistributables...
>
> https://www.microsoft.com/en-us/download/details.aspx?id=48145

AFAIK, "Microsoft Visual C++ 2015 Redistributable Update 3" is the latest and greatest:

https://www.microsoft.com/en-us/download/details.aspx?id=53840

--
"Fish" (David B. Trout)
Software Development Laboratories
http://www.softdevlabs.com
mail: [hidden email]





Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
---In [hidden email], <somitcw@...> wrote :

>> I was successful. In about 1 in 78 runs, the
>> console appears to freeze. Here is what
>> the console looks like:
>> 04.37.49 JOB 1 IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP
>> Command ==> CPU0000 PSW=078D0000803708B8 31.....P.. instcount=240,587,479

> Please define "freeze".

No instruction count being updated, no
more messages coming on the
integrated console, unable to type the
word "quit" or even "q", and being
forced to close the command
prompt window instead.

> Console input was inhibited for five seconds or five minutes?
> Console display stopped for five seconds of five minutes?

Eternity, as far as I know. I probably
waited a couple of minutes before
giving up the first time.

> Could you also show the message before the "freeze"?

I did above. It freezes at random points,
and in the case above, it was a tape-related
message. More messages prior to that
can be seen in the full log I posted.

> Could you have had an errant PAUSE coming from somewhere?.

I no longer have any pauses, as can be
seen from the full log I posted. Note that
the full log runs to completion of the
MVS work, and it is within the "quit"
processing that things fail, occasionally.

BFN. Paul.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
---In [hidden email], <david.b.trout@...> wrote :

>> VCRUNTIME140.dll is the VC2015 DLL.
>>
>> You need to install the VC2015 runtime redistributables...

> AFAIK, "Microsoft Visual C++ 2015 Redistributable Update 3" is the latest and greatest:

> https://www.microsoft.com/en-us/download/details.aspx?id=53840 https://www.microsoft.com/en-us/download/details.aspx?id=53840

I chose the "x64" version from there, and it
seemed to have installed successfully, but
I was still getting the error, so I rebooted,
but still got the error. I did a search, and
it installed into c:\windows\system32 which
I confirmed was in my path.

Unfortunately I didn't think of doing a search
for the DLL *before* doing the above
download, so I don't actually know if
anything changed or not.

Details below.

Any suggestions?

Thanks. Paul.



C:\>dir vcrunt*.dll /s
 Volume in drive C is OS
 Volume Serial Number is DE22-8195

 Directory of C:\Windows\System32

2016-08-25  23:06            87,880 vcruntime140.dll
               1 File(s)         87,880 bytes

 Directory of C:\Windows\WinSxS\amd64_avg.vc140.crt_f92d94485545da78_14.0.24210.0_none_69fa0197d9b096ae

2016-11-29  04:16            87,888 vcruntime140.dll
               1 File(s)         87,888 bytes

 Directory of C:\Windows\WinSxS\x86_avg.vc140.crt_f92d94485545da78_14.0.24210.0_none_b1a7386eee2cbfb4

2016-11-29  04:16            83,784 vcruntime140.dll
               1 File(s)         83,784 bytes

     Total Files Listed:
               3 File(s)        259,552 bytes
               0 Dir(s)  51,932,340,224 bytes free

C:\>path
PATH=c:\mvs380\cygwin;c:\mvs380\hercules;c:\mvs380\wc3270;C:\ProgramData\Oracle\Java\javapath;c:\Program Files (x86)\Intel\iCLS Client\;c:\Program Files\Intel\iCLS Client\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Program Files\Intel\Intel(R) Management Engine Components\DAL;C:\Program Files\Intel\Intel(R) Management Engine Components\IPT;C:\Program Files (x86)\Intel\Intel(R) Management Engine Components\DAL;C:\Program Files (x86)\Intel\Intel(R) Management Engine Components\IPT;C:\Borland\BCC55\Bin;c:\winpath;c:\dospath;c:\cygwin\bin;c:\herc380;c:\mvs380;c:\vm380;c:\vse380\run;c:\music390;c:\pdos;c:\mts\d6.0A;c:\tss;C:\Program Files (x86)\7-Zip;C:\Program Files (x86)\Bochs-2.6.1;C:\Program Files (x86)\Windows Live\Shared;C:\Program Files (x86)\Microsoft Visual Studio 8\VC\bin;C:\Program Files\Microsoft SDKs\Windows\v7.0\Bin;C:\Program Files (x86)\Skype\Phone\;C:\Users\Paul\AppData\Local\Microsoft\WindowsApps;

C:\>



Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
- - - In [hidden email], <kerravon86@...> wrote:

> - - - In [hidden email] mailto:[hidden email],
><somitcw@...> wrote:
>>> I was successful. In about 1 in 78 runs, the >> console appears to freeze. Here is what
>>> the console looks like:
>>> 04.37.49 JOB 1 IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,MVSGCC,COMP
>>> Command ==> CPU0000 PSW=078D0000803708B8 31.....P.. instcount=240,587,479
>> Please define "freeze".
> No instruction count being updated, no
>more messages coming on the
>integrated console, unable to type the
>word "quit" or even "q", and being
>forced to close the command
>prompt window instead.

From the one time of 04.37.49 to itself does not indicated
an issue.

>> Console input was inhibited for five seconds or five minutes?
>> Console display stopped for five seconds of five minutes?
> Eternity, as far as I know. I probably
>waited a couple of minutes before
>giving up the first time.

A couple of minutes would be greater than one message posted.
 
>> Could you also show the message before the "freeze"?
> I did above. It freezes at random points,
>and in the case above, it was a tape-related
>message. More messages prior to that
>can be seen in the full log I posted.

The times don't point to a freeze or the length of one.

Perhaps Hercules and MVS were merrily chugging
along but stopped communicating with the console?

Was the freeze before or after the one message?

>> Could you have had an errant PAUSE coming from somewhere?.
> I no longer have any pauses, as can be
>seen from the full log I posted. Note that
>the full log runs to completion of the
>MVS work, and it is within the "quit"
>processing that things fail, occasionally.
> BFN. Paul.

How do things fail in quit processing?
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

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

>>> Console input was inhibited for five seconds or five minutes?
>>> Console display stopped for five seconds of five minutes?

>> Eternity, as far as I know. I probably
>> waited a couple of minutes before
>> giving up the first time.

> A couple of minutes would be greater than one message posted.

There were lots of messages before the
last message seen. Those lots of
messages can be seen in the log
I posted.

The lots of messages that appear
in the log *after* the last console
message seen do *not* appear
on the console.

>>> Could you also show the message before the "freeze"?

>> I did above. It freezes at random points,
>> and in the case above, it was a tape-related
>> message. More messages prior to that
>> can be seen in the full log I posted.

> The times don't point to a freeze or the length of one.

Correct. The hercules log shows that MVS
ran successfully, fast, no freeze,, even
though the console was frozen. That's
what I reported.

> Perhaps Hercules and MVS were merrily chugging
> along but stopped communicating with the console?

Yes they were. That's what the log shows.
MVS/Hercules didn't just produce that
log out of thin air. It ran my job to
successful completion, even though I
couldn't see that on the console.

Seeing the hercules log was actually
a surprise to me, as I had assumed
that MVS/Hercules had frozen at the
last line I saw on the integrated
console.

> Was the freeze before or after the one message?

After the last message on the integrated
console.

>>> Could you have had an errant PAUSE coming from somewhere?.

>> I no longer have any pauses, as can be
>> seen from the full log I posted. Note that
>> the full log runs to completion of the
>> MVS work, and it is within the "quit"
>> processing that things fail, occasionally.

> How do things fail in quit processing?

I assume that "quit" causes all threads
to be terminated, but due to some
timing sensitivity the integrated console
thread isn't flushed and closed.

I will know more if someone can advise
where to put in debug messages to
find out what is happening.

BFN. Paul.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
Are you running 32 or 64 bit hercules? You might need to also install 32
bit version if you are running 32 bit hercules.


Joe

On Wed, Jan 18, 2017 at 9:07 PM, [hidden email] [hercules-390] <
[hidden email]> wrote:

>
>
> ---In [hidden email], <david.b.trout@...> wrote :
>
> >> VCRUNTIME140.dll is the VC2015 DLL.
> >>
> >> You need to install the VC2015 runtime redistributables...
>
> > AFAIK, "Microsoft Visual C++ 2015 Redistributable Update 3" is the
> latest and greatest:
>
> > https://www.microsoft.com/en-us/download/details.aspx?id=53840
> https://www.microsoft.com/en-us/download/details.aspx?id=53840
>
> I chose the "x64" version from there, and it
> seemed to have installed successfully, but
> I was still getting the error, so I rebooted,
> but still got the error. I did a search, and
> it installed into c:\windows\system32 which
> I confirmed was in my path.
>
> Unfortunately I didn't think of doing a search
> for the DLL *before* doing the above
> download, so I don't actually know if
> anything changed or not.
>
> Details below.
>
> Any suggestions?
>
> Thanks. Paul.
>
> C:\>dir vcrunt*.dll /s
> Volume in drive C is OS
> Volume Serial Number is DE22-8195
>
> Directory of C:\Windows\System32
>
> 2016-08-25 23:06 87,880 vcruntime140.dll
> 1 File(s) 87,880 bytes
>
> Directory of C:\Windows\WinSxS\amd64_avg.vc140.crt_f92d94485545da78_14.
> 0.24210.0_none_69fa0197d9b096ae
>
> 2016-11-29 04:16 87,888 vcruntime140.dll
> 1 File(s) 87,888 bytes
>
> Directory of C:\Windows\WinSxS\x86_avg.vc140.crt_f92d94485545da78_14.
> 0.24210.0_none_b1a7386eee2cbfb4
>
> 2016-11-29 04:16 83,784 vcruntime140.dll
> 1 File(s) 83,784 bytes
>
> Total Files Listed:
> 3 File(s) 259,552 bytes
> 0 Dir(s) 51,932,340,224 bytes free
>
> C:\>path
> PATH=c:\mvs380\cygwin;c:\mvs380\hercules;c:\mvs380\
> wc3270;C:\ProgramData\Oracle\Java\javapath;c:\Program Files
> (x86)\Intel\iCLS Client\;c:\Program Files\Intel\iCLS Client\;C:\Program
> Files (x86)\NVIDIA Corporation\PhysX\Common;C:\
> WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\
> WindowsPowerShell\v1.0\;C:\Program Files\Intel\Intel(R) Management Engine
> Components\DAL;C:\Program Files\Intel\Intel(R) Management Engine
> Components\IPT;C:\Program Files (x86)\Intel\Intel(R) Management Engine
> Components\DAL;C:\Program Files (x86)\Intel\Intel(R) Management Engine
> Components\IPT;C:\Borland\BCC55\Bin;c:\winpath;c:\
> dospath;c:\cygwin\bin;c:\herc380;c:\mvs380;c:\vm380;c:\
> vse380\run;c:\music390;c:\pdos;c:\mts\d6.0A;c:\tss;C:\Program Files
> (x86)\7-Zip;C:\Program Files (x86)\Bochs-2.6.1;C:\Program Files
> (x86)\Windows Live\Shared;C:\Program Files (x86)\Microsoft Visual Studio
> 8\VC\bin;C:\Program Files\Microsoft SDKs\Windows\v7.0\Bin;C:\Program
> Files (x86)\Skype\Phone\;C:\Users\Paul\AppData\Local\Microsoft\
> WindowsApps;
>
> C:\>
>
>
>
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

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

> Are you running 32 or 64 bit hercules?

32-bit.

> You might need to also install 32 bit version
> if you are running 32 bit hercules.

Thankyou. That did the trick. No need
to restart my PC. I totally didn't think
of that!

Bulk testing now being done.

BFN. Paul.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
Now running Hyperion 32-bit as seen by
full log below.

After 12 successful runs, it froze again,
but different from Hercules 3.12.

With Hyperion, the freeze takes away
the pretty integrated console which
has the instruction count etc, and
instead all I see is plain text on my screen.

Here is what the bottom of the frozen
console looks like:

/12.10.56 STC   15  IST020I  VTAM INITIALIZATION COMPLETE                                                                                                                                   /12.10.56 STC   18  $HASP373 JRP      STARTED                                                                                                                                               /12.10.56 STC   18  IEF403I JRP - STARTED - TIME=12.10.56                                                                                                                                   /12.10.56 STC   15  IEA000I 0C1,IOE,05,0200,400000000001,,,NET     ,12.10.56                                                                                                                /12.10.56 STC   15  IEA000I 0C0,IOE,05,0200,400000000001,,,NET     ,12.10.56                                                                                                                /12.10.56 STC   15  IEA000I 0C2,IOE,05,0200,400000000001,,,NET     ,12.10.56                                                                                                                /12.10.56 STC   13  BSPSP91I - Parms passed: NOREPLYU                                                                                                                                       /12.10.56 STC   13  BSPSP93I - PFK definitions will be updated in memory                                                                                                                    /12.10.56 STC   13  BSPSP22I - Dataset processed: SYS1.PARMLIB                                                                                                                              /12.10.56 STC   13  BSPSP23I - on volume MVSRES
HHC02272I Highest observed MIPS and IO/s rates
HHC02272I   from Thu Jan 19 00:00:00 2017
HHC02272I     to Thu Jan 19 23:10:56 2017
HHC02272I   MIPS: 75.171042  IO/s: 1879
HHC00101I Thread id 00000d3c, prio  0, name HTTP server ended
HHC00101I Thread id 00002b58, prio  0, name Processor CP00 ended


But I know in reality it ran more than that,
because I can see it in the full log:

23:10:56 /12.10.56 STC   13  BSPSP91I - Parms passed: NOREPLYU
23:10:56 /12.10.56 STC   13  BSPSP93I - PFK definitions will be updated in memory
23:10:56 /12.10.56 STC   13  BSPSP22I - Dataset processed: SYS1.PARMLIB
23:10:56 /12.10.56 STC   13  BSPSP23I - on volume MVSRES
23:10:56 /12.10.56 STC   13  BSPSP21I - Member being processed: SETPFK01
23:10:56 /12.10.56 STC   14  IFC001I  D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
23:10:56 /12.10.56 STC   14  IEF404I LOGRECI - ENDED - TIME=12.10.56
23:10:56 /12.10.56 STC   14  $HASP395 LOGRECI  ENDED
23:10:56 /12.10.56 STC   14  $HASP150 LOGRECI  ON PRINTER2        20 LINES
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 STC   14  $HASP250 LOGRECI  IS PURGED


Here is the end of the log of the failing instance:

23:10:56 /12.10.56 JOB    2  $HASP150 TERMHERC ON PRINTER2        44 LINES
23:10:56 /12.10.56 JOB    2  $HASP150 TERMHERC ON PRINTER1         1 LINE
23:10:56 /12.10.56           $HASP160 PRINTER1 INACTIVE - CLASS=AP
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 JOB    2  $HASP250 TERMHERC IS PURGED
23:10:56 HHC00081I Match at index 00, executing command script conf/termherc2.rc
23:10:56 HHC01603I script conf/termherc2.rc
23:10:56 HHC02260I Script 7: begin processing file conf/termherc2.rc
23:10:56 HHC01603I quit
23:10:56 HHC01420I Begin Hercules shutdown
23:10:56 HHC00101I Thread id 00001b4c, prio -20, name Timer ended
23:10:56 HHC01423I Calling termination routines
23:10:56 HHC02272I Highest observed MIPS and IO/s rates
23:10:56 HHC02272I   from Thu Jan 19 00:00:00 2017
23:10:56 HHC02272I     to Thu Jan 19 23:10:56 2017
23:10:56 HHC02272I   MIPS: 75.171042  IO/s: 1879
23:10:56 HHC00101I Thread id 00000d3c, prio  0, name HTTP server ended
23:10:56 HHC00101I Thread id 00002b58, prio  0, name Processor CP00 ended
23:17:20 HHC01402I CTRL_CLOSE_EVENT received: initiating emergency shutdown
23:17:20 HHC01420I Begin Hercules shutdown
23:17:20 HHC01423I Calling termination routines
23:17:20 HHC00101I Thread id 00001f40, prio  0, name Hercules Automatic Operator ended
23:17:20 HHC02103I Logger: logger thread terminating


You can see that it differs from a good
run, which looks like this:

23:10:49 /12.10.49 JOB    2  $HASP250 TERMHERC IS PURGED
23:10:49 HHC00081I Match at index 00, executing command script conf/termherc2.rc
23:10:49 HHC01603I script conf/termherc2.rc
23:10:49 HHC02260I Script 7: begin processing file conf/termherc2.rc
23:10:49 HHC01603I quit
23:10:49 HHC01420I Begin Hercules shutdown
23:10:49 HHC00101I Thread id 000036b4, prio -20, name Timer ended
23:10:49 HHC01423I Calling termination routines
23:10:49 HHC02272I Highest observed MIPS and IO/s rates
23:10:49 HHC02272I   from Thu Jan 19 00:00:00 2017
23:10:49 HHC02272I     to Thu Jan 19 23:10:49 2017
23:10:49 HHC02272I   MIPS: 80.151663  IO/s: 1708
23:10:49 HHC00101I Thread id 000009cc, prio  0, name HTTP server ended
23:10:49 HHC00101I Thread id 0000239c, prio  0, name Processor CP00 ended
23:10:49 HHC00333I 0:0148           size free  nbr st   reads  writes l2reads    hits switches
23:10:49 HHC00334I 0:0148                                                  readaheads   misses
23:10:49 HHC00335I 0:0148 --------------------------------------------------------------------
23:10:49 HHC00336I 0:0148 [*] 0018764440 001 % 0022    0001257 0000025 0000035 0001262  0002011
23:10:49 HHC00337I 0:0148                                                     0000518  0000084
(etc).


Full failing log below. I terminated by closing
the windows command prompt window, after
leaving the freeze for more than 5 minutes,
as you can tell from the time.

BTW, at first look it looks to me like
Hyperion is slower. I'll do a formal
speed test later. One problem at a
time. :-)

Any ideas?

Thanks. Paul.



23:10:50 HHC01413I Hercules version 4.0.0.0 (4.0.0.0)
23:10:50 HHC01414I (C) Copyright 1999-2016 by Roger Bowler, Jan Jaeger, and others
23:10:50 HHC01415I Build date: Dec 16 2016 at 14:14:30
23:10:50 HHC01417I Built with: Microsoft Visual C 190024215 1
23:10:50 HHC01417I Build type: Windows MSVC i386 host architecture build
23:10:50 HHC01417I Modes: S/370 ESA/390 z/Arch
23:10:50 HHC01417I Max CPU Engines: 32
23:10:50 HHC01417I Using   Fish threads Threading Model
23:10:50 HHC01417I Using   Error-Checking Mutex Locking Model
23:10:50 HHC01417I With    Syncio support
23:10:50 HHC01417I With    Shared Devices support
23:10:50 HHC01417I With    Dynamic loading support
23:10:50 HHC01417I Using   shared libraries
23:10:50 HHC01417I With    External GUI support
23:10:50 HHC01417I With    Partial TCP keepalive support
23:10:50 HHC01417I With    IPV6 support
23:10:50 HHC01417I With    HTTP Server support
23:10:50 HHC01417I With    sqrtl support
23:10:50 HHC01417I Without SIGABEND handler
23:10:50 HHC01417I With    CCKD BZIP2 support
23:10:50 HHC01417I With    HET BZIP2 support
23:10:50 HHC01417I With    ZLIB support
23:10:50 HHC01417I With    Regular Expressions support
23:10:50 HHC01417I With    Object REXX support
23:10:50 HHC01417I With    Regina REXX support
23:10:50 HHC01417I With    Automatic Operator support
23:10:50 HHC01417I Without National Language Support
23:10:50 HHC01417I Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8 fetch_dw store_dw hatomics=msvcIntrinsics
23:10:50 HHC01417I Running on: PAUL-DELL (Windows-6.2.9200 Intel(R) x64) LP=8, Cores=4, CPUs=1
23:10:50 HHC00018W Hercules is NOT running in elevated mode
23:10:50 HHC02323W This build of Hercules has only partial TCP keepalive support
23:10:50 HHC01508I HDL: loadable module directory is c:/herc380/
23:10:50 HHC00150I Crypto module loaded (c) Copyright 2003-2016 by Bernard van der Helm
23:10:50 HHC00151I Activated facility: Message Security Assist
23:10:50 HHC00151I Activated facility: Message Security Assist Extension 1, 2, 3 and 4
23:10:50 HHC00100I Thread id 00002b58, prio 15, name Processor CP00 started
23:10:50 HHC00100I Thread id 00001b4c, prio -20, name Timer started
23:10:50 HHC00811I Processor CP00: architecture mode z/Arch
23:10:50 HHC02204I cpuserial      set to 000611
23:10:50 HHC02204I cpumodel       set to 4381
23:10:50 HHC17003I MAIN     storage is 200M (mainsize); storage is not locked
23:10:50 HHC17003I EXPANDED storage is 0 (xpndsize); storage is not locked
23:10:50 HHC00811I Processor CP00: architecture mode S/370
23:10:50 HHC02204I archmode       set to S/370
23:10:50 HHC02203I default allowed automount directory: c:/mvs380/
23:10:50 HHC02204I mounted_tape_reinit set to disabled
23:10:50 HHC01474I Using internal codepage conversion table 819/1047
23:10:50 HHC02256W Command httpport is deprecated, use http port nnnn [[noauth]|[auth user pass]] instead
23:10:50 HHC02204I httpport       set to port=8081 noauth
23:10:50 HHC01807I HTTP server signaled to start
23:10:50 HHC02204I todprio        set to -20
23:10:50 HHC02204I hercprio       set to 8
23:10:50 HHC00100I Thread id 00000d3c, prio  0, name HTTP server started
23:10:50 HHC02204I devprio        set to 0
23:10:50 HHC02204I cpuprio        set to 0
23:10:50 HHC01802I HTTP server using root directory c:/herc380/html/
23:10:50 HHC02204I loadparm       set to ........
23:10:50 HHC02204I numcpu         set to 1
23:10:50 HHC01803I HTTP server waiting for requests on port 8081
23:10:50 HHC02204I panrate        set to FAST
23:10:50 HHC02204I pantitle       set to MVS/380 v1.2 running under Hercules-3.07:380-4.0
23:10:50 HHC01042I 0:000C COMM: device bound to socket 127.0.0.1:3505
23:10:50 HHC00100I Thread id 00002fcc, prio  0, name Socket device listener started
23:10:50 HHC01437I Config file[122] conf/mvs380.conf: including file conf/mvs380_DASD.conf
23:10:50 HHC00403I 0:0148 CKD file dasd/mvsres.148: opening as r/o
23:10:50 HHC00414I 0:0148 CKD file dasd/mvsres.148: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:0131 CKD file dasd/sort01.131: opening as r/o
23:10:50 HHC00414I 0:0131 CKD file dasd/sort01.131: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0132 CKD file dasd/sort02.132: opening as r/o
23:10:50 HHC00414I 0:0132 CKD file dasd/sort02.132: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0133 CKD file dasd/sort03.133: opening as r/o
23:10:50 HHC00414I 0:0133 CKD file dasd/sort03.133: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0134 CKD file dasd/sort04.134: opening as r/o
23:10:50 HHC00414I 0:0134 CKD file dasd/sort04.134: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0135 CKD file dasd/sort05.135: opening as r/o
23:10:50 HHC00414I 0:0135 CKD file dasd/sort05.135: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0136 CKD file dasd/sort06.136: opening as r/o
23:10:50 HHC00414I 0:0136 CKD file dasd/sort06.136: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0140 CKD file dasd/work00.140: opening as r/o
23:10:50 HHC00414I 0:0140 CKD file dasd/work00.140: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00414I 0:0152 CKD file dasd/hasp00.152: cyls 404 heads 19 tracks 7676 trklen 13312
23:10:50 HHC00414I 0:0160 CKD file dasd/page00.160: cyls 698 heads 12 tracks 8376 trklen 8704
23:10:50 HHC00414I 0:0161 CKD file dasd/page01.161: cyls 698 heads 12 tracks 8376 trklen 8704
23:10:50 HHC00414I 0:0162 CKD file dasd/page02.162: cyls 698 heads 12 tracks 8376 trklen 8704
23:10:50 HHC00414I 0:0170 CKD file dasd/work01.170: cyls 962 heads 12 tracks 11544 trklen 35840
23:10:50 HHC00403I 0:01A0 CKD file dasd/work02.180: opening as r/o
23:10:50 HHC00414I 0:01A0 CKD file dasd/work02.180: cyls 886 heads 15 tracks 13290 trklen 47616
23:10:50 HHC00403I 0:01B0 CKD file dasd/work03.190: opening as r/o
23:10:50 HHC00414I 0:01B0 CKD file dasd/work03.190: cyls 1114 heads 15 tracks 16710 trklen 56832
23:10:50 HHC00403I 0:01B1 CKD file dasd/mvscat.191: opening as r/o
23:10:50 HHC00414I 0:01B1 CKD file dasd/mvscat.191: cyls 1114 heads 15 tracks 16710 trklen 56832
23:10:50 HHC00403I 0:01B2 CKD file dasd/seasik.192: opening as r/o
23:10:50 HHC00414I 0:01B2 CKD file dasd/seasik.192: cyls 1114 heads 15 tracks 16710 trklen 56832
23:10:50 HHC00414I 0:01B3 CKD file dasd/mvssrc.193: cyls 2226 heads 15 tracks 33390 trklen 56832
23:10:50 HHC00401E 0:01B4 CKD file dasd/pub004.1b4: open error: not found
23:10:50 HHC01463E 0:01B4 device initialization failed
23:10:50 HHC00403I 0:0240 CKD file dasd/pub000.240: opening as r/o
23:10:50 HHC00414I 0:0240 CKD file dasd/pub000.240: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:0248 CKD file dasd/mvsdlb.248: opening as r/o
23:10:50 HHC00414I 0:0248 CKD file dasd/mvsdlb.248: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:02A0 CKD file dasd/pub002.280: opening as r/o
23:10:50 HHC00414I 0:02A0 CKD file dasd/pub002.280: cyls 1772 heads 15 tracks 26580 trklen 47616
23:10:50 HHC00403I 0:02B1 CKD file dasd/tmptmp.2b1: opening as r/o
23:10:50 HHC00414I 0:02B1 CKD file dasd/tmptmp.2b1: cyls 1114 heads 15 tracks 16710 trklen 56832
23:10:50 HHC00403I 0:02B2 CKD file dasd/xmit90.2b2: opening as r/o
23:10:50 HHC00414I 0:02B2 CKD file dasd/xmit90.2b2: cyls 1114 heads 15 tracks 16710 trklen 56832
23:10:50 HHC00403I 0:0150 CKD file dasd/start1.150: opening as r/o
23:10:50 HHC00414I 0:0150 CKD file dasd/start1.150: cyls 808 heads 19 tracks 15352 trklen 13312
23:10:50 HHC00403I 0:0151 CKD file dasd/spool0.151: opening as r/o
23:10:50 HHC00414I 0:0151 CKD file dasd/spool0.151: cyls 808 heads 19 tracks 15352 trklen 13312
23:10:50 HHC00403I 0:0340 CKD file dasd/cbt000.340: opening as r/o
23:10:50 HHC00414I 0:0340 CKD file dasd/cbt000.340: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0341 CKD file dasd/cbt001.341: opening as r/o
23:10:50 HHC00414I 0:0341 CKD file dasd/cbt001.341: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0342 CKD file dasd/cbt002.342: opening as r/o
23:10:50 HHC00414I 0:0342 CKD file dasd/cbt002.342: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0343 CKD file dasd/cbtcat.343: opening as r/o
23:10:50 HHC00414I 0:0343 CKD file dasd/cbtcat.343: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0348 CKD file dasd/src000.348: opening as r/o
23:10:50 HHC00414I 0:0348 CKD file dasd/src000.348: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0349 CKD file dasd/src001.349: opening as r/o
23:10:50 HHC00414I 0:0349 CKD file dasd/src001.349: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:034A CKD file dasd/src002.34a: opening as r/o
23:10:50 HHC00414I 0:034A CKD file dasd/src002.34a: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:034B CKD file dasd/srccat.34b: opening as r/o
23:10:50 HHC00414I 0:034B CKD file dasd/srccat.34b: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0149 CKD file dasd/smp001.149: opening as r/o
23:10:50 HHC00414I 0:0149 CKD file dasd/smp001.149: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:014A CKD file dasd/smp002.14a: opening as r/o
23:10:50 HHC00414I 0:014A CKD file dasd/smp002.14a: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:014B CKD file dasd/smp003.14b: opening as r/o
23:10:50 HHC00414I 0:014B CKD file dasd/smp003.14b: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:014C CKD file dasd/smp004.14c: opening as r/o
23:10:50 HHC00414I 0:014C CKD file dasd/smp004.14c: cyls 560 heads 30 tracks 16800 trklen 19456
23:10:50 HHC00403I 0:0700 CKD file dasd/js2sp0.700: opening as r/o
23:10:50 HHC00414I 0:0700 CKD file dasd/js2sp0.700: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0138 CKD file dasd/dlicat.138: opening as r/o
23:10:50 HHC00414I 0:0138 CKD file dasd/dlicat.138: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0139 CKD file dasd/dlisys.139: opening as r/o
23:10:50 HHC00414I 0:0139 CKD file dasd/dlisys.139: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:013A CKD file dasd/dli000.13a: opening as r/o
23:10:50 HHC00414I 0:013A CKD file dasd/dli000.13a: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:013B CKD file dasd/dli001.13b: opening as r/o
23:10:50 HHC00414I 0:013B CKD file dasd/dli001.13b: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:013C CKD file dasd/dli002.13c: opening as r/o
23:10:50 HHC00414I 0:013C CKD file dasd/dli002.13c: cyls 200 heads 20 tracks 4000 trklen 7680
23:10:50 HHC00403I 0:0710 CKD file dasd/js3sp0.710: opening as r/o
23:10:50 HHC00414I 0:0710 CKD file dasd/js3sp0.710: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00403I 0:0711 CKD file dasd/js3res.711: opening as r/o
23:10:50 HHC00414I 0:0711 CKD file dasd/js3res.711: cyls 555 heads 30 tracks 16650 trklen 19456
23:10:50 HHC00100I Thread id 0000362c, prio  0, name Console connection started
23:10:50 HHC01024I Waiting for console connections on port 3270
23:10:50 HHC00222I 0:0400 Tape file *, type aws: option level accepted
23:10:50 HHC00222I 0:0401 Tape file *, type aws: option level accepted
23:10:50 HHC00222I 0:0402 Tape file *, type aws: option level accepted
23:10:50 HHC00222I 0:0403 Tape file *, type aws: option level accepted
23:10:50 HHC00100I Thread id 0000237c, prio  0, name Control panel started
23:10:50 HHC02260I Script 1: begin processing file conf/auto_run.rc
23:10:50 HHC01603I devlist
23:10:50 HHC02279I 0:000C 3505 127.0.0.1:3505 sockdev ascii trunc eof IO[0]
23:10:50 HHC02279I      (no one currently connected)
23:10:50 HHC02279I 0:000D 3525 pch/pch00d.txt ascii crlf IO[0]
23:10:50 HHC02279I 0:000E 1403 prt/prt00e.txt crlf noclear print fcbck IO[0]
23:10:50 HHC02279I 0:000F 1403 prt/prt00f.txt crlf noclear print fcbck IO[0]
23:10:50 HHC02279I 0:001F 3215 *syscons cmdpref(/) noprompt IO[0] open
23:10:50 HHC02279I 0:00C0 3270 * IO[0]
23:10:50 HHC02279I 0:00C1 3270 * IO[0]
23:10:50 HHC02279I 0:00C2 3270 * IO[0]
23:10:50 HHC02279I 0:00C7 3287 * IO[0]
23:10:50 HHC02279I 0:010C 3505 jcl/dummy eof IO[0]
23:10:50 HHC02279I 0:0131 2314 dasd/sort01.131 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0132 2314 dasd/sort02.132 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0133 2314 dasd/sort03.133 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0134 2314 dasd/sort04.134 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0135 2314 dasd/sort05.135 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0136 2314 dasd/sort06.136 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0138 2314 dasd/dlicat.138 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0139 2314 dasd/dlisys.139 [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:013A 2314 dasd/dli000.13a [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:013B 2314 dasd/dli001.13b [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:013C 2314 dasd/dli002.13c [200 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0140 3350 dasd/work00.140 [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0148 3350 dasd/mvsres.148 [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0149 3350 dasd/smp001.149 [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:014A 3350 dasd/smp002.14a [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:014B 3350 dasd/smp003.14b [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:014C 3350 dasd/smp004.14c [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0150 3330 dasd/start1.150 [808 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0151 3330 dasd/spool0.151 [808 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0152 3330 dasd/hasp00.152 [404 cyls] [0 sfs] IO[0] open
23:10:50 HHC02279I 0:0160 3340 dasd/page00.160 [698 cyls] [0 sfs] IO[0] open
23:10:50 HHC02279I 0:0161 3340 dasd/page01.161 [698 cyls] [0 sfs] IO[0] open
23:10:50 HHC02279I 0:0162 3340 dasd/page02.162 [698 cyls] [0 sfs] IO[0] open
23:10:50 HHC02279I 0:0170 3375 dasd/work01.170 [962 cyls] [0 sfs] IO[0] open
23:10:50 HHC02279I 0:01A0 3380 dasd/work02.180 [886 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:01B0 3390 dasd/work03.190 [1114 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:01B1 3390 dasd/mvscat.191 [1114 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:01B2 3390 dasd/seasik.192 [1114 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:01B3 3390 dasd/mvssrc.193 [2226 cyls] [0 sfs] IO[0] open
23:10:50 HHC02279I 0:01C7 3287 * IO[0]
23:10:50 HHC02279I 0:0240 3350 dasd/pub000.240 [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0248 3350 dasd/mvsdlb.248 [560 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:02A0 3380 dasd/pub002.280 [1772 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:02B1 3390 dasd/tmptmp.2b1 [1114 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:02B2 3390 dasd/xmit90.2b2 [1114 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:030E 1403 log/hardcopy.log crlf noclear print fcbck IO[0]
23:10:50 HHC02279I 0:0340 3350 dasd/cbt000.340 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0341 3350 dasd/cbt001.341 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0342 3350 dasd/cbt002.342 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0343 3350 dasd/cbtcat.343 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0348 3350 dasd/src000.348 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0349 3350 dasd/src001.349 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:034A 3350 dasd/src002.34a [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:034B 3350 dasd/srccat.34b [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0400 3420 * IO[0] maxsize=0 eotmargin=128K deonirq=N
23:10:50 HHC02279I 0:0401 3420 * IO[0] maxsize=0 eotmargin=128K deonirq=N
23:10:50 HHC02279I 0:0402 3420 * IO[0] maxsize=0 eotmargin=128K deonirq=N
23:10:50 HHC02279I 0:0403 3420 * IO[0] maxsize=0 eotmargin=128K deonirq=N
23:10:50 HHC02279I 0:0700 3350 dasd/js2sp0.700 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0710 3350 dasd/js3sp0.710 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC02279I 0:0711 3350 dasd/js3res.711 [555 cyls] [1 sfs] IO[0] open
23:10:50 HHC01603I logopt timestamp
23:10:50 HHC02204I logopt         set to TIMESTAMP
23:10:50 HHC01603I panrate 1000
23:10:50 HHC02204I panrate        set to 1000
23:10:50 HHC01603I hao tgt IEF238D
23:10:50 HHC00077I The target was placed at index 0
23:10:50 HHC01603I hao cmd script conf/cancel.rc
23:10:50 HHC00100I Thread id 00001f40, prio  0, name Hercules Automatic Operator started
23:10:50 HHC00077I The command was placed at index 0
23:10:50 HHC01603I hao tgt HASP395 DYNAMASK
23:10:50 HHC00077I The target was placed at index 1
23:10:50 HHC01603I hao cmd script conf/subjobs_slow.rc
23:10:50 HHC00077I The command was placed at index 1
23:10:50 HHC01603I hao tgt HASP373 SVC120I
23:10:50 HHC00077I The target was placed at index 2
23:10:50 HHC01603I hao cmd script conf/subjobs_fast.rc
23:10:50 HHC00077I The command was placed at index 2
23:10:50 HHC01603I hao tgt HASP436 REPLY
23:10:50 HHC00077I The target was placed at index 3
23:10:50 HHC01603I hao cmd script conf/replyy.rc
23:10:50 HHC00077I The command was placed at index 3
23:10:50 HHC01603I devinit 402 tapes/mftopc.het
23:10:50 HHC00221I 0:0402 Tape file tapes/mftopc.het, type het: format type Hercules Emulated Tape file
23:10:50 HHC02245I 0:0402 device initialized
23:10:50 HHC01603I devinit 403 tapes/awstap.aws
23:10:50 HHC00221I 0:0403 Tape file tapes/awstap.aws, type het: format type Hercules Emulated Tape file
23:10:50 HHC02245I 0:0403 device initialized
23:10:50 /r 00,clpa,cmd=co
23:10:50 HHC01603I ipl 148
23:10:50 HHC02264I Script 1: file conf/auto_run.rc processing ended
23:10:50 HHC00107I Starting thread cckd_ra(), active=0, started=0, max=2
23:10:50 HHC00100I Thread id 000011ec, prio  0, name Read-ahead thread-1 started
23:10:50 HHC00107I Starting thread cckd_ra() from cckd_ra(), active=1, started=1, max=2
23:10:50 HHC00100I Thread id 00003540, prio  0, name Read-ahead thread-2 started
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP01, PARM 00000000: CC 3
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP02, PARM 00000000: CC 3
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP03, PARM 00000000: CC 3
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP04, PARM 00000000: CC 3
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP05, PARM 00000000: CC 3
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP06, PARM 00000000: CC 3
23:10:51 HHC00814I Processor CP00: SIGP Initial program reset            (07) CP07, PARM 00000000: CC 3
23:10:51 /IEA101A SPECIFY SYSTEM PARMS FOR MVS/380 1.2 v03.8 TK3+
23:10:51 HHC00107I Starting thread cckd_writer(), active=0, started=0, max=2
23:10:51 HHC00100I Thread id 00003b78, prio  0, name Writer thread-1 started
23:10:51 HHC00107I Starting thread cckd_gcol(), active=0, started=0, max=1
23:10:51 HHC00100I Thread id 00002e64, prio  0, name Garbage collector started
23:10:51 /IEA940I THE FOLLOWING PAGE DATA SETS ARE IN USE
23:10:51 / PLPA ... SYS1.PAGELPA
23:10:51 / COMMON . SYS1.PAGECSA
23:10:51 / DUPLEX . SYS1.DUPLEX
23:10:51 / LOCAL .. SYS1.PAGEL01
23:10:51 / LOCAL .. SYS1.PAGEL02
23:10:51 / LOCAL .. SYS1.PAGEL03
23:10:51 HHC00107I Starting thread cckd_writer() from cckd_writer(), active=1, started=1, max=2
23:10:51 HHC00100I Thread id 000021e8, prio  0, name Writer thread-2 started
23:10:53 / IGF992I  MIH INIT COMPLETE, PRI=000300, SEC=000015
23:10:53 /*IEE362A SMF ENTER DUMP FOR SYS1.MANX ON MVSRES
23:10:53 / IEE360I SMF NOW RECORDING ON SYS1.MANY ON MVSRES TIME=12.10.53
23:10:54 / IEF677I WARNING MESSAGE(S) FOR JOB JES2     ISSUED
23:10:54 /*00 $HASP436 REPLY Y OR N TO CONFIRM CHECKPOINT RECORD CHANGE
23:10:54 HHC00081I Match at index 03, executing command script conf/replyy.rc
23:10:54 HHC01603I script conf/replyy.rc
23:10:54 HHC02260I Script 2: begin processing file conf/replyy.rc
23:10:54 /reply 00,y
23:10:54 HHC02264I Script 2: file conf/replyy.rc processing ended
23:10:54 / IEE600I REPLY TO 00 IS;SUPPRESSED
23:10:54 / $HASP493 JES2 COLD-START IS IN PROGRESS
23:10:55 / $HASP412 MAXIMUM OF 1   READER(S)  EXCEEDED
23:10:55 /12.10.55           IEE041I THE SYSTEM LOG IS NOW ACTIVE
23:10:55 /12.10.55           IEE302I 00E      ONLINE
23:10:55 /12.10.55           IEE302I 00F      ONLINE
23:10:55 /12.10.55           IEE313I 30E     UNIT REF INVALID
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           IEE450I 12.10.55 UNIT STATUS 161
23:10:55 / UNIT TYPE STATUS  VOLSER VOLSTATE   UNIT TYPE STATUS  VOLSER VOLSTATE
23:10:55 / 400  3400 O                  /REMOV 401  3400 O                  /REMOV
23:10:55 / 402  3400 O                  /REMOV
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP160 PRINTER1 INACTIVE - CLASS=AP
23:10:55 /12.10.55           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:55 /12.10.55           $HASP160 PUNCH1   INACTIVE - CLASS=B
23:10:55 /12.10.55 STC    2  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    3  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    4  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    2  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    2  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    3  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    3  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    5  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    4  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    4  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    5  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    6  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    5  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    7  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    6  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    6  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    7  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    7  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    8  $HASP100 INIT     ON STCINRDR
23:10:55 /12.10.55 STC    9  $HASP100 SVC120I  ON STCINRDR
23:10:55 /12.10.55 STC    8  $HASP373 INIT     STARTED
23:10:55 /12.10.55 STC    8  IEF403I INIT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   10  $HASP100 DYNABLDL ON STCINRDR
23:10:55 /12.10.55 STC    9  $HASP373 SVC120I  STARTED
23:10:55 HHC00081I Match at index 02, executing command script conf/subjobs_fast.rc
23:10:55 HHC01603I script conf/subjobs_fast.rc
23:10:55 HHC02260I Script 3: begin processing file conf/subjobs_fast.rc
23:10:55 HHC01603I hao clear
23:10:55 HHC00080I All HAO rules are cleared
23:10:55 HHC01603I hao tgt HASP250 SVC120I
23:10:55 HHC00077I The target was placed at index 0
23:10:55 HHC01603I hao cmd script conf/subjobs.rc
23:10:55 HHC00077I The command was placed at index 0
23:10:55 HHC02264I Script 3: file conf/subjobs_fast.rc processing ended
23:10:55 /12.10.55 STC    9  IEF403I SVC120I - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   11  $HASP100 DYNAMASK ON STCINRDR
23:10:55 /12.10.55 STC   10  $HASP373 DYNABLDL STARTED
23:10:55 /12.10.55 STC   10  IEF403I DYNABLDL - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   11  $HASP373 DYNAMASK STARTED
23:10:55 /12.10.55 STC   11  IEF403I DYNAMASK - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   12  $HASP100 BSPPILOT ON STCINRDR
23:10:55 /12.10.55 STC   13  $HASP100 BSPSETPF ON STCINRDR
23:10:55 /12.10.55 STC   12  $HASP373 BSPPILOT STARTED
23:10:55 /12.10.55 STC   12  IEF403I BSPPILOT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   13  $HASP373 BSPSETPF STARTED
23:10:55 /12.10.55 STC   13  IEF403I BSPSETPF - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   14  $HASP100 LOGRECI  ON STCINRDR
23:10:55 /12.10.55 STC   15  $HASP100 NET      ON STCINRDR
23:10:55 /12.10.55           $HASP309    INIT  1 INACTIVE ******** C=A
23:10:55 /12.10.55 STC   14  $HASP373 LOGRECI  STARTED
23:10:55 /12.10.55           $HASP309    INIT  2 INACTIVE ******** C=BA
23:10:55 /12.10.55 STC   14  IEF403I LOGRECI - STARTED - TIME=12.10.55
23:10:55 /12.10.55           $HASP309    INIT  3 INACTIVE ******** C=CBA
23:10:55 /12.10.55           $HASP309    INIT  4 INACTIVE ******** C=SHB
23:10:55 /12.10.55           $HASP309    INIT  5 INACTIVE ******** C=SBA
23:10:55 /12.10.55           $HASP309    INIT  6 INACTIVE ******** C=S
23:10:55 /12.10.55 STC   15  $HASP373 NET      STARTED
23:10:55 /12.10.55           $HASP309    INIT  7 INACTIVE ******** C=E
23:10:55 /12.10.55 STC   15  IEF403I NET - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC    9  BSPGM39E - Hercules and MVS 380 mods required
23:10:55 /12.10.55 STC    9  IEF404I SVC120I - ENDED - TIME=12.10.55
23:10:55 /12.10.55 STC    9  $HASP395 SVC120I  ENDED
23:10:55 /12.10.55 STC    9  $HASP150 SVC120I  ON PRINTER2        41 LINES
23:10:55 /12.10.55 STC    9 *$HASP190 SVC120I  SETUP -- PRINTER2 -- F = 0001 -- C = 6    -- T = SN
23:10:55 /12.10.55           $HASP000 OK
23:10:55 /12.10.55           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:55 /12.10.55 STC    9  $HASP250 SVC120I  IS PURGED
23:10:55 HHC00081I Match at index 00, executing command script conf/subjobs.rc
23:10:55 HHC01603I script conf/subjobs.rc
23:10:55 HHC02260I Script 4: begin processing file conf/subjobs.rc
23:10:55 HHC01603I hao clear
23:10:55 HHC00080I All HAO rules are cleared
23:10:55 HHC01603I hao tgt HASP250 MOUNT
23:10:55 HHC00077I The target was placed at index 0
23:10:55 HHC01603I hao cmd script conf/subjobs2.rc
23:10:55 HHC00077I The command was placed at index 0
23:10:55 /M 401,VOL=(NL,PCTOMF)
23:10:55 HHC02264I Script 4: file conf/subjobs.rc processing ended
23:10:55 /12.10.55 STC   16  $HASP100 MOUNT    ON STCINRDR
23:10:55 /12.10.55 STC   10  DYNABLDL STARTED
23:10:55 /12.10.55 STC   16  $HASP373 MOUNT    STARTED
23:10:55 /12.10.55 STC   16  IEF403I MOUNT - STARTED - TIME=12.10.55
23:10:55 /12.10.55 STC   16 *IEF233A M 401,PCTOMF,,MOUNT,401
23:10:55 /12.10.55 STC   10  IEF404I DYNABLDL - ENDED - TIME=12.10.55
23:10:55 /12.10.55 STC   10  $HASP395 DYNABLDL ENDED
23:10:55 /12.10.55 STC   10  $HASP150 DYNABLDL ON PRINTER2        21 LINES
23:10:55 /12.10.55           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:55 /12.10.55 STC   10  $HASP250 DYNABLDL IS PURGED
23:10:55 /12.10.55 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
23:10:55 /12.10.55 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
23:10:55 /12.10.55 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
23:10:55 /12.10.55 STC   15  IST025I  BLDL FAILED FOR IEDIAE   IN VTAMLIB
23:10:55 /12.10.55 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
23:10:55 /12.10.55 STC   15  IST025I  BLDL FAILED FOR IEDIAK   IN VTAMLIB
23:10:55 /12.10.55 STC   15  IST110I  NETWORK SOLICITOR STARTED
23:10:55 /12.10.55 STC   15  IST093I  APPLJRP  ACTIVE
23:10:55 /12.10.55 STC   15  IST093I  APPLPIES ACTIVE
23:10:56 /12.10.56 STC   15  IST093I  APPLPIAD ACTIVE
23:10:56 /12.10.56 STC   11  DMSK00I DYNAMASK DONE ****
23:10:56 /12.10.56 STC   11  DMSK06I  START
23:10:56 /12.10.56 STC   15  IST093I  APPLTSO  ACTIVE
23:10:56 /12.10.56 STC   15  IST093I  APPLTEST ACTIVE
23:10:56 /12.10.56 STC   11  IEF404I DYNAMASK - ENDED - TIME=12.10.56
23:10:56 /12.10.56 STC   11  $HASP395 DYNAMASK ENDED
23:10:56 /12.10.56 STC   11  $HASP150 DYNAMASK ON PRINTER2        30 LINES
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 STC   11  $HASP250 DYNAMASK IS PURGED
23:10:56 /12.10.56 STC   15  IST093I  LCLMAJRP ACTIVE
23:10:56 /12.10.56 STC   15  IST093I  LCLMAJ00 ACTIVE
23:10:56 /12.10.56 STC   17  $HASP100 TSO      ON STCINRDR
23:10:56 /12.10.56 STC   18  $HASP100 JRP      ON STCINRDR
23:10:56 /12.10.56 STC   17  $HASP373 TSO      STARTED
23:10:56 /12.10.56 STC   17  IEF403I TSO - STARTED - TIME=12.10.56
23:10:56 /12.10.56           $HASP000 OK
23:10:56 /12.10.56           $HASP000 OK
23:10:56 /12.10.56 STC   15  IST020I  VTAM INITIALIZATION COMPLETE
23:10:56 /12.10.56 STC   18  $HASP373 JRP      STARTED
23:10:56 /12.10.56 STC   18  IEF403I JRP - STARTED - TIME=12.10.56
23:10:56 /12.10.56 STC   15  IEA000I 0C1,IOE,05,0200,400000000001,,,NET     ,12.10.56
23:10:56 /12.10.56 STC   15  IEA000I 0C0,IOE,05,0200,400000000001,,,NET     ,12.10.56
23:10:56 /12.10.56 STC   15  IEA000I 0C2,IOE,05,0200,400000000001,,,NET     ,12.10.56
23:10:56 /12.10.56 STC   13  BSPSP91I - Parms passed: NOREPLYU
23:10:56 /12.10.56 STC   13  BSPSP93I - PFK definitions will be updated in memory
23:10:56 /12.10.56 STC   13  BSPSP22I - Dataset processed: SYS1.PARMLIB
23:10:56 /12.10.56 STC   13  BSPSP23I - on volume MVSRES
23:10:56 /12.10.56 STC   13  BSPSP21I - Member being processed: SETPFK01
23:10:56 /12.10.56 STC   14  IFC001I  D=3350 N=0B F=01AB0000 L=01AC0005 S=01AB000002 DIP COMPLETE
23:10:56 /12.10.56 STC   14  IEF404I LOGRECI - ENDED - TIME=12.10.56
23:10:56 /12.10.56 STC   14  $HASP395 LOGRECI  ENDED
23:10:56 /12.10.56 STC   14  $HASP150 LOGRECI  ON PRINTER2        20 LINES
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 STC   14  $HASP250 LOGRECI  IS PURGED
23:10:56 /12.10.56 STC   16  IEF404I MOUNT - ENDED - TIME=12.10.56
23:10:56 /12.10.56 STC   16  $HASP395 MOUNT    ENDED
23:10:56 /12.10.56 STC   16  $HASP150 MOUNT    ON PRINTER2        18 LINES
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 STC   16  $HASP250 MOUNT    IS PURGED
23:10:56 HHC00081I Match at index 00, executing command script conf/subjobs2.rc
23:10:56 HHC01603I script conf/subjobs2.rc
23:10:56 HHC02260I Script 5: begin processing file conf/subjobs2.rc
23:10:56 HHC01603I hao clear
23:10:56 HHC00080I All HAO rules are cleared
23:10:56 HHC01603I hao tgt IEF238D
23:10:56 HHC00077I The target was placed at index 0
23:10:56 HHC01603I hao cmd script conf/cancel.rc
23:10:56 HHC00077I The command was placed at index 0
23:10:56 HHC01603I hao tgt IEC301A
23:10:56 HHC00077I The target was placed at index 1
23:10:56 HHC01603I hao cmd script conf/secret.rc
23:10:56 HHC00077I The command was placed at index 1
23:10:56 HHC01603I devinit 401 tapes/pctomf.tdf
23:10:56 HHC00221I 0:0401 Tape file tapes/pctomf.tdf, type oma: format type Optical Media Attachment (OMA) tape
23:10:56 HHC02245I 0:0401 device initialized
23:10:56 HHC01603I hao tgt HASP373 TERMHERC
23:10:56 HHC00077I The target was placed at index 2
23:10:56 HHC01603I hao cmd script conf/termherc.rc
23:10:56 HHC00077I The command was placed at index 2
23:10:56 HHC01603I devinit 00c jcl/hercauto.jcl eof
23:10:56 HHC01046I 0:000C COMM: device unbound from socket 127.0.0.1:3505
23:10:56 HHC00101I Thread id 00002fcc, prio  0, name Socket device listener ended
23:10:56 HHC02245I 0:000C device initialized
23:10:56 HHC02264I Script 5: file conf/subjobs2.rc processing ended
23:10:56 /12.10.56 JOB    1  $HASP100 HEXDUMP  ON READER1
23:10:56 /12.10.56 JOB    2  $HASP100 TERMHERC ON READER1
23:10:56 /12.10.56 STC   13  +BSPSP98I - Member processed, LASTCC=0000
23:10:56 /12.10.56 STC   13  +BSPSP21I - Member being processed: SETPFK02
23:10:56 /12.10.56 JOB    1  $HASP373 HEXDUMP  STARTED - INIT  3 - CLASS C - SYS BSP1
23:10:56 /12.10.56 JOB    1  IEF403I HEXDUMP - STARTED - TIME=12.10.56
23:10:56 /12.10.56 JOB    1 *IEF233A M 401,PCTOMF,,HEXDUMP,HEXDUMP
23:10:56 /12.10.56 STC   13  +BSPSP98I - Member processed, LASTCC=0000
23:10:56 /12.10.56 STC   13  +BSPSP99I - End of processing, MAXRC=0000
23:10:56 /12.10.56 STC   13  IEF404I BSPSETPF - ENDED - TIME=12.10.56
23:10:56 /12.10.56 STC   13  $HASP395 BSPSETPF ENDED
23:10:56 /12.10.56 STC   13  $HASP150 BSPSETPF ON PRINTER2        34 LINES
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 STC   13  $HASP250 BSPSETPF IS PURGED
23:10:56 /12.10.56 STC   17  IKT007I TCAS ACCEPTING LOGONS
23:10:56 /12.10.56 STC   17  IKT005I TCAS IS INITIALIZED
23:10:56 /12.10.56 JOB    1  IEC705I TAPE ON 402,MFTOPC,SL,6250 BPI,HEXDUMP,HEXDUMP
23:10:56 HHC00201I 0:0401 Tape file tapes/pctomf.tdf, type oma: tape closed
23:10:56 /12.10.56 STC   18  JRPI101 INITIALIZATION COMPLETE
23:10:56 /12.10.56 STC   18 *01 JRP100I - ENTER ICLOSE TO SHUT DOWN
23:10:56 HHC00201I 0:0401 Tape file tapes/pctomf.tdf, type oma: tape closed
23:10:56 HHC00201I 0:0402 Tape file tapes/mftopc.het, type het: tape closed
23:10:56 /12.10.56 JOB    1  IEF234E K 402,MFTOPC,PVT,HEXDUMP,HEXDUMP
23:10:56 /12.10.56 JOB    1  IEFACTRT - Stepname  Procstep  Program   Retcode
23:10:56 /12.10.56 JOB    1  HEXDUMP    HEXDUMP             HEXDUMP   RC= 0000
23:10:56 /12.10.56 JOB    1  IEF404I HEXDUMP - ENDED - TIME=12.10.56
23:10:56 /12.10.56 JOB    1  $HASP395 HEXDUMP  ENDED
23:10:56 /12.10.56 JOB    1  $HASP150 HEXDUMP  ON PRINTER1        55 LINES
23:10:56 /12.10.56 JOB    1 *$HASP190 HEXDUMP  SETUP -- PRINTER1 -- F = 0001 -- C = 6    -- T = SN
23:10:56 /12.10.56           $HASP000 OK
23:10:56 /12.10.56 JOB    2  $HASP373 TERMHERC STARTED - INIT  3 - CLASS C - SYS BSP1
23:10:56 HHC00081I Match at index 02, executing command script conf/termherc.rc
23:10:56 HHC01603I script conf/termherc.rc
23:10:56 HHC02260I Script 6: begin processing file conf/termherc.rc
23:10:56 HHC01603I hao clear
23:10:56 HHC00080I All HAO rules are cleared
23:10:56 HHC01603I hao tgt HASP250 TERMHERC
23:10:56 HHC00077I The target was placed at index 0
23:10:56 HHC01603I hao cmd script conf/termherc2.rc
23:10:56 HHC00077I The command was placed at index 0
23:10:56 HHC02264I Script 6: file conf/termherc.rc processing ended
23:10:56 /12.10.56 JOB    2  IEF403I TERMHERC - STARTED - TIME=12.10.56
23:10:56 /12.10.56           $HASP160 PRINTER1 INACTIVE - CLASS=AP
23:10:56 /12.10.56 JOB    1  $HASP250 HEXDUMP  IS PURGED
23:10:56 /12.10.56 JOB    2  IEFACTRT - Stepname  Procstep  Program   Retcode
23:10:56 /12.10.56 JOB    2  TERMHERC   S1                  IEBGENER  RC= 0000
23:10:56 /12.10.56 JOB    2  IEF404I TERMHERC - ENDED - TIME=12.10.56
23:10:56 /12.10.56 JOB    2  $HASP395 TERMHERC ENDED
23:10:56 /12.10.56           $HASP309    INIT  3 INACTIVE ******** C=CBA
23:10:56 /12.10.56 JOB    2  $HASP150 TERMHERC ON PRINTER2        44 LINES
23:10:56 /12.10.56 JOB    2  $HASP150 TERMHERC ON PRINTER1         1 LINE
23:10:56 /12.10.56           $HASP160 PRINTER1 INACTIVE - CLASS=AP
23:10:56 /12.10.56           $HASP160 PRINTER2 INACTIVE - CLASS=Z
23:10:56 /12.10.56 JOB    2  $HASP250 TERMHERC IS PURGED
23:10:56 HHC00081I Match at index 00, executing command script conf/termherc2.rc
23:10:56 HHC01603I script conf/termherc2.rc
23:10:56 HHC02260I Script 7: begin processing file conf/termherc2.rc
23:10:56 HHC01603I quit
23:10:56 HHC01420I Begin Hercules shutdown
23:10:56 HHC00101I Thread id 00001b4c, prio -20, name Timer ended
23:10:56 HHC01423I Calling termination routines
23:10:56 HHC02272I Highest observed MIPS and IO/s rates
23:10:56 HHC02272I   from Thu Jan 19 00:00:00 2017
23:10:56 HHC02272I     to Thu Jan 19 23:10:56 2017
23:10:56 HHC02272I   MIPS: 75.171042  IO/s: 1879
23:10:56 HHC00101I Thread id 00000d3c, prio  0, name HTTP server ended
23:10:56 HHC00101I Thread id 00002b58, prio  0, name Processor CP00 ended
23:17:20 HHC01402I CTRL_CLOSE_EVENT received: initiating emergency shutdown
23:17:20 HHC01420I Begin Hercules shutdown
23:17:20 HHC01423I Calling termination routines
23:17:20 HHC00101I Thread id 00001f40, prio  0, name Hercules Automatic Operator ended
23:17:20 HHC02103I Logger: logger thread terminating
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
- - - In [hidden email], <kerravon86@...> wrote:
> Now running Hyperion 32-bit as seen by >full log below.
> After 12 successful runs, it froze again,
>but different from Hercules 3.12.
> With Hyperion, the freeze takes away
>the pretty integrated console which
>has the instruction count etc, and
>instead all I see is plain text on my screen.
> Here is what the bottom of the frozen
>console looks like:
 - - - remainder snipped - - -

I don't follow your description of the logs perfectly but,
The first "freeze" was on a statement intercepted by
HAO but the system running did not "freeze".
The "freeze" now was within and HAO "quit" with no
indication if processing was or was not continuing.

To try to identify the current "freeze" why not try to
bypass it with different scripts.

hao clear
quit

hao clear
stopall
suspend
quit

Other weird combos.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

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

> I don't follow your description of the logs perfectly but,
> The first "freeze" was on a statement intercepted by
> HAO but the system running did not "freeze".

I don't understand what you are talking
about. The console freeze does not
occur on an intercepted message.
It's just some random MVS message.

The freeze occurs when I execute the
"quit" command, which is indeed
triggered from an MVS message.
An MVS message that appears in
the log, but not on the frozen console.

> To try to identify the current "freeze" why not try to
> bypass it with different scripts.

> hao clear
> quit

I'm pretty sure a "pause 1", which is
sort of what I had before, will bypass
the problem. Would that be helpful
to confirm?

BFN. Paul.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
Hi,


Again, just a random thought popping up in my head while I read this
thread, but perhaps someone is in possession of a debugger (and a debug
build) they can use to more clearly see what is going on ?


- Maarten
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
In reply to this post by Hercules390 - General mailing list
I just saw this thread now didn't follow it completely however I got a freeze on the hercules console log as well

I then ran under visual Studio and saw where it did OBTAIN LOCK ---> entermycriticalsection

Just do a Break All and Call Stack too see where the code is locked I commented that OBTAIN LOCK out there probably is a better way but I wanted to get through something quickly



> On Jan 19, 2017, at 9:28 AM, [hidden email] [hercules-390] <[hidden email]> wrote:
>
> - - - In [hidden email], <kerravon86@...> wrote:
> > Now running Hyperion 32-bit as seen by >full log below.
> > After 12 successful runs, it froze again,
> >but different from Hercules 3.12.
> > With Hyperion, the freeze takes away
> >the pretty integrated console which
> >has the instruction count etc, and
> >instead all I see is plain text on my screen.
> > Here is what the bottom of the frozen
> >console looks like:
> - - - remainder snipped - - -
>
> I don't follow your description of the logs perfectly but,
> The first "freeze" was on a statement intercepted by
> HAO but the system running did not "freeze".
> The "freeze" now was within and HAO "quit" with no
> indication if processing was or was not continuing.
>
> To try to identify the current "freeze" why not try to
> bypass it with different scripts.
>
> hao clear
> quit
>
> hao clear
> stopall
> suspend
> quit
>
> Other weird combos.
>
>
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

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

> I just saw this thread now didn't follow it
> completely however I got a freeze on the
> hercules console log as well

Great!

> I then ran under visual Studio and saw
> where it did OBTAIN LOCK ---> entermycriticalsection

I think you mean myentercriticalsection

> Just do a Break All and Call Stack too see
> where the code is locked I commented
> that OBTAIN LOCK out there probably
> is a better way but I wanted to get through
> something quickly

So that I don't need to repeat your work,
could you tell me which of these I need
to comment out?

C:\devel\hercules>grep -i myentercriticalsection *.c
fthreads.c:        MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
fthreads.c:        MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
fthreads.c:            MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
fthreads.c:        MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
fthreads.c:        MyEnterCriticalSection ( &pFT_COND_VAR->CondVarLock );
fthreads.c:        MyEnterCriticalSection ( &pFT_COND_VAR->CondVarLock );
fthreads.c:        MyEnterCriticalSection ( &pFT_COND_VAR->CondVarLock );

C:\devel\hercules>grep -i myentercriticalsection *.h
fishhang.h:        #define MyEnterCriticalSection(pCS)                     (FishHang_EnterCriticalSection(pszFile,nLine,(CRITICAL_SECTION*)(pCS)))
fishhang.h:        #define MyEnterCriticalSection(pCS)                     (FishHang_EnterCriticalSection(__FILE__,__LINE__,(CRITICAL_SECTION*)(pCS)))
fishhang.h:    #define MyEnterCriticalSection(pCS)                     (EnterCriticalSection((CRITICAL_SECTION*)(pCS)))

C:\devel\hercules>


(this is a slightly modified Hercules 3.07
which is what I would prefer to do
testing on).

Thanks. Paul.
Reply | Threaded
Open this post in threaded view
|

Re: apparent console freeze

Hercules390 - General mailing list
Sorry for the late response I am Sabbath observant

I run hercules under Windows

So do you know how to run under The Visual studio Debugger

Run Visual Studio Debug for the command its hercules.exe -f.  .....

When the hercules console locks go debug --> break all then under the debug menu go threads

The thread you want is the one running panel.c

If that's isn't running nothing is getting updated on the console right click and switch to that thread do a call stack once you see a hercules function do switch to frame that should get you where things are locked up



> On Jan 20, 2017, at 8:50 PM, [hidden email] [hercules-390] <[hidden email]> wrote:
>
> ---In [hidden email], <reichmanjoe@...> wrote :
>
> > I just saw this thread now didn't follow it
> > completely however I got a freeze on the
> > hercules console log as well
>
> Great!
>
> > I then ran under visual Studio and saw
> > where it did OBTAIN LOCK ---> entermycriticalsection
>
> I think you mean myentercriticalsection
>
> > Just do a Break All and Call Stack too see
> > where the code is locked I commented
> > that OBTAIN LOCK out there probably
> > is a better way but I wanted to get through
> > something quickly
>
> So that I don't need to repeat your work,
> could you tell me which of these I need
> to comment out?
>
> C:\devel\hercules>grep -i myentercriticalsection *.c
> fthreads.c: MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
> fthreads.c: MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
> fthreads.c: MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
> fthreads.c: MyEnterCriticalSection ( &pFT_MUTEX->MutexLock );
> fthreads.c: MyEnterCriticalSection ( &pFT_COND_VAR->CondVarLock );
> fthreads.c: MyEnterCriticalSection ( &pFT_COND_VAR->CondVarLock );
> fthreads.c: MyEnterCriticalSection ( &pFT_COND_VAR->CondVarLock );
>
> C:\devel\hercules>grep -i myentercriticalsection *.h
> fishhang.h: #define MyEnterCriticalSection(pCS) (FishHang_EnterCriticalSection(pszFile,nLine,(CRITICAL_SECTION*)(pCS)))
> fishhang.h: #define MyEnterCriticalSection(pCS) (FishHang_EnterCriticalSection(__FILE__,__LINE__,(CRITICAL_SECTION*)(pCS)))
> fishhang.h: #define MyEnterCriticalSection(pCS) (EnterCriticalSection((CRITICAL_SECTION*)(pCS)))
>
> C:\devel\hercules>
>
> (this is a slightly modified Hercules 3.07
> which is what I would prefer to do
> testing on).
>
> Thanks. Paul.
>
12345