hercules-390 / hyperion

Hercules 390
Other
251 stars 70 forks source link

Disabled wait state on OS/390 R8V2 #13

Closed ChristianBirr closed 10 years ago

ChristianBirr commented 10 years ago

I just discovered a disabled wait state 000A0000 80009064 when ipl'ing OS/390 R8V2 on the hyperion distrubution on fishs homepage. Doesn't happen on Hercules 3.10. If I can help further, I'll be ready to do so. Christian

Fish-Git commented 10 years ago

Can you provide more information please? May we see your Hercules log file? Did it log a program check? If so, what was it? May we see your Hercules configuration file? What type of host hardware are you running Hercules on? Is this the 32-bit version of Hercules 4.0 hyperion or the 64-bit version of Hercules 4.0 hyperion? What version of WINDOWS are you running? Windows-7? older? newer? Etc.

Thanks.

ChristianBirr commented 10 years ago

Sure, here you go: This is a Win32 version of Windows XP on an Intel motherboard with a 2.8GHz Celeron CPU and 2 GB memory. My configuration file is:

DEFSYM    TAPEDIR "E:\DASD\OS390DB\tapes"
ARCHMODE  ESA/390
ALRF      ENABLE
CNSLPORT  3270
CONKPALV  (3,1,10)
CPUMODEL  9672
CPUSERIAL 050556
CPUVERID  00
ECPSVM    NO
HTTPROOT  "C:\Programme\Hercules\R3.10\"
LOADPARM  0A82DB..
LPARNAME  BIRRCONS
MAINSIZE  1024
MODPATH   C:\Programme\Hercules\R3.10\
MOUNTED_TAPE_REINIT  DISALLOW
NUMCPU    1
OSTAILOR  QUIET
PANRATE   50
PGMPRDOS  LICENSED
SYSEPOCH  1900
TIMERINT  50
TZOFFSET  +0000
YROFFSET  0
HERCPRIO  0
TODPRIO   -20
DEVPRIO   8
CPUPRIO   15
000C    2501    localhost:3505 sockdev
000E    1403    E:\DASD\OS390DB\prt\1403.00E.TXT crlf
000F    1403    E:\DASD\OS390DB\prt\1403.00F.TXT crlf
0700-0702    3270    *
0900-0903    3270    *
0120    3380    E:\DASD\OS390DB\dasd\DASD.3380-K.120$
0121    3380    E:\DASD\OS390DB\dasd\DASD.3380-K.121$
0260    3390    E:\DASD\OS390DB\dasd\SMS000.260$
0261    3390    E:\DASD\OS390DB\dasd\SMS001.261$
0262    3390    E:\DASD\OS390DB\dasd\SMS002.262$
0263    3390    E:\DASD\OS390DB\dasd\SMS003.263$
0264    3390    E:\DASD\OS390DB\dasd\SMS004.264$
0265    3390    E:\DASD\OS390DB\dasd\SMS005.265$
0266    3390    E:\DASD\OS390DB\dasd\SMS006.266$
0267    3390    E:\DASD\OS390DB\dasd\SMS007.267$
0268    3390    E:\DASD\OS390DB\dasd\SMS008.268$
0269    3390    E:\DASD\OS390DB\dasd\SMS009.269$
0270    3390    E:\DASD\OS390DB\dasd\SMS010.270$
0271    3390    E:\DASD\OS390DB\dasd\SMS011.271$
027A    3390    E:\DASD\OS390DB\dasd\SYSWK1.27A$
027B    3390    E:\DASD\OS390DB\dasd\SYSWK2.27B$
027C    3390    E:\DASD\OS390DB\dasd\SYSWK3.27C$
027D    3390    E:\DASD\OS390DB\dasd\SYSWK4.27D$
027E    3390    E:\DASD\OS390DB\dasd\SYSWK5.27E$
027F    3390    E:\DASD\OS390DB\dasd\SYSWK6.27F$
0A80    3390    E:\DASD\OS390DB\dasd\OS39R8.A80$
0A81    3390    E:\DASD\OS390DB\dasd\OS3R8A.A81$
0A82    3390    E:\DASD\OS390DB\dasd\OS39M1.A82$
0A83    3390    E:\DASD\OS390DB\dasd\OS39P8.A83$
0A84    3390    E:\DASD\OS390DB\dasd\OS3P8A.A84$
0A85    3390    E:\DASD\OS390DB\dasd\OS39D8.A85$
0A86    3390    E:\DASD\OS390DB\dasd\OS3D8A.A86$
0A87    3390    E:\DASD\OS390DB\dasd\OS39H8.A87$
0A88    3390    E:\DASD\OS390DB\dasd\OS3H8A.A88$
0A89    3390    E:\DASD\OS390DB\dasd\OS3P8B.A89$
0A90    3390    E:\DASD\OS390DB\dasd\HSM000.A90$
0A91    3390    E:\DASD\OS390DB\dasd\HSM001.A91$
0A92    3390    E:\DASD\OS390DB\dasd\OS39DX.A92$
0560-0564    3480    * awstape eotmargin=999
0580    3430    * awstape maxsizem=170 eotmargin=999
05B0-05B7   3490    * awstape eotmargin=999
0E20.2      CTCI    192.168.16.46 192.168.16.38
0E40    CTCT    3088 192.168.16.21 3088 1500

And here's the log file:

2014/07/24 15:17:28.243 ******** HHC046I Acceptance of PGMPRDOS LICENSED setting verified
2014/07/24 15:17:28.263 ******** Preferred executable files directory = C:/Programme/Hercules/R3.10/
2014/07/24 15:17:28.504 Hercules started; process-id=0000096C
2014/07/24 15:17:30.006 0000096C HHC01413I Hercules version 4.00.0-git-8035-g4f57167
2014/07/24 15:17:30.006 0000096C HHC01414I (c) Copyright 1999-2013 by Roger Bowler, Jan Jaeger, and others
2014/07/24 15:17:30.006 0000096C HHC01415I Built on Jul  5 2014 at 12:03:17
2014/07/24 15:17:30.006 0000096C HHC01416I Build information:
2014/07/24 15:17:30.006 0000096C HHC01417I Windows MSVC i386 host architecture build
2014/07/24 15:17:30.006 0000096C HHC01417I Modes: S/370 ESA/390 z/Arch
2014/07/24 15:17:30.006 0000096C HHC01417I Max CPU Engines: 32
2014/07/24 15:17:30.006 0000096C HHC01417I Using   Fish threads Threading Model
2014/07/24 15:17:30.006 0000096C HHC01417I Using   Error-Checking Mutex Locking Model
2014/07/24 15:17:30.006 0000096C HHC01417I With    Syncio support
2014/07/24 15:17:30.006 0000096C HHC01417I With    Dynamic loading support
2014/07/24 15:17:30.006 0000096C HHC01417I Using   shared libraries
2014/07/24 15:17:30.006 0000096C HHC01417I With    External GUI support
2014/07/24 15:17:30.006 0000096C HHC01417I With    IPV6 support
2014/07/24 15:17:30.006 0000096C HHC01417I With    HTTP Server support
2014/07/24 15:17:30.006 0000096C HHC01417I With    sqrtl support
2014/07/24 15:17:30.006 0000096C HHC01417I Without SIGABEND handler
2014/07/24 15:17:30.006 0000096C HHC01417I With    CCKD BZIP2 support
2014/07/24 15:17:30.006 0000096C HHC01417I With    HET BZIP2 support
2014/07/24 15:17:30.006 0000096C HHC01417I With    ZLIB support
2014/07/24 15:17:30.006 0000096C HHC01417I With    Regular Expressions support
2014/07/24 15:17:30.006 0000096C HHC01417I With    Object REXX support
2014/07/24 15:17:30.006 0000096C HHC01417I Without Regina REXX support
2014/07/24 15:17:30.006 0000096C HHC01417I With    Automatic Operator support
2014/07/24 15:17:30.006 0000096C HHC01417I Without National Language Support
2014/07/24 15:17:30.006 0000096C HHC01417I Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8 fetch_dw store_dw
2014/07/24 15:17:30.006 0000096C HHC01417I Running on OPPMUCPC15 Windows-5.1.2600. XP Professional , i686 LP=1, Cores=1, CPUs=1
2014/07/24 15:17:30.056 0000096C HHC00150I Crypto module loaded (c) Copyright 2003-2011 by Bernard van der Helm
2014/07/24 15:17:30.056 0000096C HHC00151I Activated facility: Message Security Assist
2014/07/24 15:17:30.056 0000096C HHC00151I Activated facility: Message Security Assist Extension 1, 2, 3 and 4
2014/07/24 15:17:30.096 0000096C HHC00100I Thread id 3720, prio 15, name Processor CP00 started
2014/07/24 15:17:30.106 0000096C HHC00811I Processor CP00: architecture mode z/Arch
2014/07/24 15:17:30.106 0000096C HHC00100I Thread id 3264, prio -20, name Timer started
2014/07/24 15:17:30.116 0000096C HHC00811I Processor CP00: architecture mode ESA/390
2014/07/24 15:17:30.126 0000096C HHC02256W Command ALRF is deprecated, use archlvl enable|disable|query asn_lx_reuse instead
2014/07/24 15:17:30.126 0000096C HHC02256W Command httproot is deprecated, use http root pathname instead
2014/07/24 15:17:30.126 0000096C HHC01802I HTTP server using root directory C:/Programme/Hercules/R3.10/
2014/07/24 15:17:30.166 0000096C HHC01204I 0:000C Card: option ascii is default for socket device
2014/07/24 15:17:30.176 0000096C HHC01042I 0:000C COMM: device bound to socket localhost:3505
2014/07/24 15:17:30.186 0000096C HHC00100I Thread id 2700, prio  0, name Socket device listener started
2014/07/24 15:17:30.216 0000096C HHC00100I Thread id 3948, prio  0, name Console connection started
2014/07/24 15:17:30.246 0000096C HHC00414I 0:0120 CKD file E:/DASD/OS390DB/dasd/DASD.3380-K.120$: cyls 2655 heads 15 tracks 39825 trklen 47616
2014/07/24 15:17:30.256 0000096C HHC01024I Waiting for console connections on port 3270
2014/07/24 15:17:30.266 0000096C HHC00414I 0:0121 CKD file E:/DASD/OS390DB/dasd/DASD.3380-K.121$: cyls 2655 heads 15 tracks 39825 trklen 47616
2014/07/24 15:17:30.276 0000096C HHC00414I 0:0260 CKD file E:/DASD/OS390DB/dasd/SMS000.260$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.296 0000096C HHC00414I 0:0261 CKD file E:/DASD/OS390DB/dasd/SMS001.261$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.336 0000096C HHC00414I 0:0262 CKD file E:/DASD/OS390DB/dasd/SMS002.262$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.377 0000096C HHC00414I 0:0263 CKD file E:/DASD/OS390DB/dasd/SMS003.263$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.407 0000096C HHC00414I 0:0264 CKD file E:/DASD/OS390DB/dasd/SMS004.264$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.527 0000096C HHC00414I 0:0265 CKD file E:/DASD/OS390DB/dasd/SMS005.265$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.527 0000096C HHC00414I 0:0266 CKD file E:/DASD/OS390DB/dasd/SMS006.266$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.527 0000096C HHC00414I 0:0267 CKD file E:/DASD/OS390DB/dasd/SMS007.267$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:30.897 0000096C HHC00414I 0:0268 CKD file E:/DASD/OS390DB/dasd/SMS008.268$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:31.568 0000096C HHC00414I 0:0269 CKD file E:/DASD/OS390DB/dasd/SMS009.269$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:31.899 0000096C HHC00414I 0:0270 CKD file E:/DASD/OS390DB/dasd/SMS010.270$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:31.919 0000096C HHC00414I 0:0271 CKD file E:/DASD/OS390DB/dasd/SMS011.271$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:31.959 0000096C HHC00414I 0:027A CKD file E:/DASD/OS390DB/dasd/SYSWK1.27A$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:31.989 0000096C HHC00414I 0:027B CKD file E:/DASD/OS390DB/dasd/SYSWK2.27B$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:32.019 0000096C HHC00414I 0:027C CKD file E:/DASD/OS390DB/dasd/SYSWK3.27C$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:32.029 0000096C HHC00414I 0:027D CKD file E:/DASD/OS390DB/dasd/SYSWK4.27D$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:32.039 0000096C HHC00414I 0:027E CKD file E:/DASD/OS390DB/dasd/SYSWK5.27E$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:32.059 0000096C HHC00414I 0:027F CKD file E:/DASD/OS390DB/dasd/SYSWK6.27F$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:32.069 0000096C HHC00414I 0:0A80 CKD file E:/DASD/OS390DB/dasd/OS39R8.A80$: cyls 3339 heads 15 tracks 50085 trklen 56832
2014/07/24 15:17:32.119 0000096C HHC00414I 0:0A81 CKD file E:/DASD/OS390DB/dasd/OS3R8A.A81$: cyls 3339 heads 15 tracks 50085 trklen 56832
2014/07/24 15:17:32.159 0000096C HHC00414I 0:0A82 CKD file E:/DASD/OS390DB/dasd/OS39M1.A82$: cyls 3339 heads 15 tracks 50085 trklen 56832
2014/07/24 15:17:32.209 0000096C HHC00414I 0:0A83 CKD file E:/DASD/OS390DB/dasd/OS39P8.A83$: cyls 2226 heads 15 tracks 33390 trklen 56832
2014/07/24 15:17:32.239 0000096C HHC00414I 0:0A84 CKD file E:/DASD/OS390DB/dasd/OS3P8A.A84$: cyls 2226 heads 15 tracks 33390 trklen 56832
2014/07/24 15:17:32.269 0000096C HHC00414I 0:0A85 CKD file E:/DASD/OS390DB/dasd/OS39D8.A85$: cyls 2226 heads 15 tracks 33390 trklen 56832
2014/07/24 15:17:32.309 0000096C HHC00414I 0:0A86 CKD file E:/DASD/OS390DB/dasd/OS3D8A.A86$: cyls 2226 heads 15 tracks 33390 trklen 56832
2014/07/24 15:17:32.750 0000096C HHC00414I 0:0A87 CKD file E:/DASD/OS390DB/dasd/OS39H8.A87$: cyls 2226 heads 15 tracks 33390 trklen 56832
2014/07/24 15:17:32.840 0000096C HHC00414I 0:0A88 CKD file E:/DASD/OS390DB/dasd/OS3H8A.A88$: cyls 1113 heads 15 tracks 16695 trklen 56832
2014/07/24 15:17:32.870 0000096C HHC00414I 0:0A89 CKD file E:/DASD/OS390DB/dasd/OS3P8B.A89$: cyls 2226 heads 15 tracks 33390 trklen 56832
2014/07/24 15:17:32.900 0000096C HHC00414I 0:0A90 CKD file E:/DASD/OS390DB/dasd/HSM000.A90$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:32.950 0000096C HHC00414I 0:0A91 CKD file E:/DASD/OS390DB/dasd/HSM001.A91$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:33.020 0000096C HHC00414I 0:0A92 CKD file E:/DASD/OS390DB/dasd/OS39DX.A92$: cyls 10017 heads 15 tracks 150255 trklen 56832
2014/07/24 15:17:33.191 0000096C HHC00222I 0:0560 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.191 0000096C HHC00222I 0:0560 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.191 0000096C HHC00224I 0:0560 Tape file *, type aws: display "        "
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0561 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0561 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.201 0000096C HHC00224I 0:0561 Tape file *, type aws: display "        "
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0562 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0562 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.201 0000096C HHC00224I 0:0562 Tape file *, type aws: display "        "
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0563 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0563 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.201 0000096C HHC00224I 0:0563 Tape file *, type aws: display "        "
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0564 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0564 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.201 0000096C HHC00224I 0:0564 Tape file *, type aws: display "        "
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0580 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0580 Tape file *, type aws: option maxsizem accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:0580 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.201 0000096C HHC00222I 0:05B0 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B0 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.211 0000096C HHC00224I 0:05B0 Tape file *, type aws: display "        "
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B1 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B1 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.211 0000096C HHC00224I 0:05B1 Tape file *, type aws: display "        "
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B2 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B2 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.211 0000096C HHC00224I 0:05B2 Tape file *, type aws: display "        "
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B3 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B3 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.211 0000096C HHC00224I 0:05B3 Tape file *, type aws: display "        "
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B4 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B4 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.211 0000096C HHC00224I 0:05B4 Tape file *, type aws: display "        "
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B5 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.211 0000096C HHC00222I 0:05B5 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.211 0000096C HHC00224I 0:05B5 Tape file *, type aws: display "        "
2014/07/24 15:17:33.221 0000096C HHC00222I 0:05B6 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.221 0000096C HHC00222I 0:05B6 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.221 0000096C HHC00224I 0:05B6 Tape file *, type aws: display "        "
2014/07/24 15:17:33.221 0000096C HHC00222I 0:05B7 Tape file *, type aws: option awstape accepted
2014/07/24 15:17:33.221 0000096C HHC00222I 0:05B7 Tape file *, type aws: option eotmargin accepted
2014/07/24 15:17:33.221 0000096C HHC00224I 0:05B7 Tape file *, type aws: display "        "
2014/07/24 15:17:33.471 0000096C HHC04100I C:\Programme\Hercules\R3.10\TunTap32.dll version 3.2.1.160 initiated
2014/07/24 15:17:33.831 0000096C HHC00901I 0:0E20 CTCI: interface tun0, type TUN opened
2014/07/24 15:17:36.866 0000096C HHC00972I 0:0E40 CTC: connected to 192.168.16.21:3088
2014/07/24 15:17:36.866 0000096C HHC01541I HDL: dyngui.dll initiated
2014/07/24 15:17:41.903 0000096C HHC01018I 0:0700 COMM: client 192.168.16.38 devtype 3270: connected
2014/07/24 15:17:48.473 0000096C HHC01603I ipl 0A80
2014/07/24 15:17:48.573 0000096C HHC00100I Thread id 924, prio  0, name Read-ahead thread-1 started
2014/07/24 15:17:48.573 0000096C HHC00100I Thread id 3476, prio  0, name Read-ahead thread-2 started
2014/07/24 15:18:04.065 0000096C HHC00006I SCLP console interface active
2014/07/24 15:18:06.458 0000096C HHC00100I Thread id 2396, prio  0, name Writer thread-1 started
2014/07/24 15:18:06.468 0000096C HHC00100I Thread id 3192, prio  0, name Garbage collector started
2014/07/24 15:18:16.603 0000096C HHC00100I Thread id 4024, prio  0, name Writer thread-2 started
2014/07/24 15:18:59.935 0000096C HHC00809I Processor CP00: disabled wait state 000A0000 80009064
2014/07/24 15:19:23.950 0000096C HHC01603I exit
2014/07/24 15:19:23.950 0000096C HHC01420I Begin Hercules shutdown
2014/07/24 15:19:23.950 0000096C HHC00101I Thread id 3264, prio -20, name Timer ended
2014/07/24 15:19:23.960 0000096C HHC01423I Calling termination routines
2014/07/24 15:19:23.980 0000096C HHC00101I Thread id 2700, prio  0, name Socket device listener ended
2014/07/24 15:19:23.980 0000096C HHC00101I Thread id 3720, prio 15, name Processor CP00 ended
2014/07/24 15:19:23.990 0000096C HHC01465I 0:000C subchannel 0:0000 detached
2014/07/24 15:19:23.990 0000096C HHC01465I 0:000E subchannel 0:0001 detached
2014/07/24 15:19:23.990 0000096C HHC01465I 0:000F subchannel 0:0002 detached
2014/07/24 15:19:24.290 0000096C HHC01465I 0:0700 subchannel 0:0003 detached
2014/07/24 15:19:24.290 0000096C HHC01465I 0:0701 subchannel 0:0004 detached
2014/07/24 15:19:24.290 0000096C HHC01465I 0:0702 subchannel 0:0005 detached
2014/07/24 15:19:24.290 0000096C HHC01465I 0:0900 subchannel 0:0006 detached
2014/07/24 15:19:24.290 0000096C HHC01465I 0:0901 subchannel 0:0007 detached
2014/07/24 15:19:24.290 0000096C HHC01465I 0:0902 subchannel 0:0008 detached
2014/07/24 15:19:24.300 0000096C HHC00101I Thread id 3948, prio  0, name Console connection ended
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0903 subchannel 0:0009 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0120           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0120 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0120 [*] 0002697214 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0120 E:/DASD/OS390DB/dasd/DASD.3380-K.120$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0120 [0] 0002697214 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0120 subchannel 0:000A detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0121           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0121 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0121 [*] 0003706798 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0121 E:/DASD/OS390DB/dasd/DASD.3380-K.121$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0121 [0] 0003706798 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0121 subchannel 0:000B detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0260           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0260 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0260 [*] 0619621685 000% 0047    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0260 E:/DASD/OS390DB/dasd/SMS000.260$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0260 [0] 0619621685 000% 0047 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0260 subchannel 0:000C detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0261           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0261 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0261 [*] 0966420429 000% 0063    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0261 E:/DASD/OS390DB/dasd/SMS001.261$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0261 [0] 0966420429 000% 0063 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0261 subchannel 0:000D detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0262           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0262 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0262 [*] 0399411533 000% 0001    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0262 E:/DASD/OS390DB/dasd/SMS002.262$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0262 [0] 0399411533 000% 0001 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0262 subchannel 0:000E detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0263           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0263 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0263 [*] 0809438278 000% 0003    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0263 E:/DASD/OS390DB/dasd/SMS003.263$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0263 [0] 0809438278 000% 0003 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0263 subchannel 0:000F detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0264           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0264 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0264 [*] 0819653963 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0264 E:/DASD/OS390DB/dasd/SMS004.264$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0264 [0] 0819653963 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0264 subchannel 0:0010 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0265           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0265 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0265 [*] 0869109152 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0265 E:/DASD/OS390DB/dasd/SMS005.265$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0265 [0] 0869109152 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0265 subchannel 0:0011 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0266           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0266 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0266 [*] 0361522692 000% 0013    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0266 E:/DASD/OS390DB/dasd/SMS006.266$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0266 [0] 0361522692 000% 0013 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0266 subchannel 0:0012 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0267           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0267 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0267 [*] 0001219657 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0267 E:/DASD/OS390DB/dasd/SMS007.267$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0267 [0] 0001219657 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0267 subchannel 0:0013 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0268           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0268 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0268 [*] 1108420540 000% 0001    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0268 E:/DASD/OS390DB/dasd/SMS008.268$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0268 [0] 1108420540 000% 0001 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0268 subchannel 0:0014 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0269           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0269 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0269 [*] 0070107510 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0269 E:/DASD/OS390DB/dasd/SMS009.269$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0269 [0] 0070107510 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0269 subchannel 0:0015 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0270           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0270 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0270 [*] 0003732280 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0270 E:/DASD/OS390DB/dasd/SMS010.270$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0270 [0] 0003732280 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0270 subchannel 0:0016 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:0271           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:0271 --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:0271 [*] 0473151760 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:0271 E:/DASD/OS390DB/dasd/SMS011.271$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:0271 [0] 0473151760 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:0271 subchannel 0:0017 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:027A           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:027A --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:027A [*] 0530397958 000% 0018    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:027A E:/DASD/OS390DB/dasd/SYSWK1.27A$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:027A [0] 0530397958 000% 0018 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:027A subchannel 0:0018 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:027B           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:027B --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:027B [*] 0370715786 000% 0018    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:027B E:/DASD/OS390DB/dasd/SYSWK2.27B$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:027B [0] 0370715786 000% 0018 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:027B subchannel 0:0019 detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:027C           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:027C --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:027C [*] 0065017939 001% 0002    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:027C E:/DASD/OS390DB/dasd/SYSWK3.27C$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:027C [0] 0065017939 001% 0002 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:027C subchannel 0:001A detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:027D           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:027D --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:027D [*] 0167744351 000% 0014    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:027D E:/DASD/OS390DB/dasd/SYSWK4.27D$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:027D [0] 0167744351 000% 0014 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:027D subchannel 0:001B detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:027E           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:027E --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:027E [*] 0001564970 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.300 0000096C HHC00338I 0:027E E:/DASD/OS390DB/dasd/SYSWK5.27E$
2014/07/24 15:19:24.300 0000096C HHC00339I 0:027E [0] 0001564970 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.300 0000096C HHC01465I 0:027E subchannel 0:001C detached
2014/07/24 15:19:24.300 0000096C HHC00333I 0:027F           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.300 0000096C HHC00335I 0:027F --------------------------------------------------------------------
2014/07/24 15:19:24.300 0000096C HHC00336I 0:027F [*] 0004050841 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:027F E:/DASD/OS390DB/dasd/SYSWK6.27F$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:027F [0] 0004050841 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:027F subchannel 0:001D detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A80           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00334I 0:0A80                                                  readaheads   misses
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A80 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A80 [*] 0518419020 000% 0011    0002462 0000000 0000024 0002297  0003113
2014/07/24 15:19:24.310 0000096C HHC00337I 0:0A80                                                     0001655  0000191
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A80 E:/DASD/OS390DB/dasd/OS39R8.A80$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A80 [0] 0518419020 000% 0011 rw 0002462 0000000 0000024
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A80 subchannel 0:001E detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A81           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00334I 0:0A81                                                  readaheads   misses
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A81 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A81 [*] 0193797081 000% 0284    0000074 0000000 0000003 0000034  0000080
2014/07/24 15:19:24.310 0000096C HHC00337I 0:0A81                                                     0000029  0000006
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A81 E:/DASD/OS390DB/dasd/OS3R8A.A81$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A81 [0] 0193797081 000% 0284 rw 0000074 0000000 0000003
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A81 subchannel 0:001F detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A82           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00334I 0:0A82                                                  readaheads   misses
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A82 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A82 [*] 0526121029 002% 1566    0001309 0001807 0000176 0001434  0001463
2014/07/24 15:19:24.310 0000096C HHC00337I 0:0A82                                                     0001281  0000087
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A82 E:/DASD/OS390DB/dasd/OS39M1.A82$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A82 [0] 0526121029 002% 1566 rw 0001309 0001807 0000176
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A82 subchannel 0:0020 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A83           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00334I 0:0A83                                                  readaheads   misses
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A83 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A83 [*] 0228921763 000% 0009    0000013 0000000 0000002 0000002  0000012
2014/07/24 15:19:24.310 0000096C HHC00337I 0:0A83                                                     0000005  0000003
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A83 E:/DASD/OS390DB/dasd/OS39P8.A83$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A83 [0] 0228921763 000% 0009 rw 0000013 0000000 0000002
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A83 subchannel 0:0021 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A84           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A84 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A84 [*] 0175712088 000% 0007    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A84 E:/DASD/OS390DB/dasd/OS3P8A.A84$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A84 [0] 0175712088 000% 0007 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A84 subchannel 0:0022 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A85           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A85 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A85 [*] 0428747374 000% 0001    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A85 E:/DASD/OS390DB/dasd/OS39D8.A85$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A85 [0] 0428747374 000% 0001 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A85 subchannel 0:0023 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A86           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A86 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A86 [*] 0481780796 000% 0002    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A86 E:/DASD/OS390DB/dasd/OS3D8A.A86$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A86 [0] 0481780796 000% 0002 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A86 subchannel 0:0024 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A87           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A87 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A87 [*] 0355188400 000% 0009    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A87 E:/DASD/OS390DB/dasd/OS39H8.A87$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A87 [0] 0355188400 000% 0009 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A87 subchannel 0:0025 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A88           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A88 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A88 [*] 0220518154 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A88 E:/DASD/OS390DB/dasd/OS3H8A.A88$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A88 [0] 0220518154 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A88 subchannel 0:0026 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A89           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A89 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A89 [*] 0062836721 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A89 E:/DASD/OS390DB/dasd/OS3P8B.A89$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A89 [0] 0062836721 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A89 subchannel 0:0027 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A90           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A90 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A90 [*] 0001934705 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A90 E:/DASD/OS390DB/dasd/HSM000.A90$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A90 [0] 0001934705 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A90 subchannel 0:0028 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A91           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A91 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A91 [*] 0644624227 000% 0184    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A91 E:/DASD/OS390DB/dasd/HSM001.A91$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A91 [0] 0644624227 000% 0184 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A91 subchannel 0:0029 detached
2014/07/24 15:19:24.310 0000096C HHC00333I 0:0A92           size free  nbr st   reads  writes l2reads    hits switches
2014/07/24 15:19:24.310 0000096C HHC00335I 0:0A92 --------------------------------------------------------------------
2014/07/24 15:19:24.310 0000096C HHC00336I 0:0A92 [*] 0441506204 000% 0000    0000001 0000000 0000001 0000000  0000001
2014/07/24 15:19:24.310 0000096C HHC00338I 0:0A92 E:/DASD/OS390DB/dasd/OS39DX.A92$
2014/07/24 15:19:24.310 0000096C HHC00339I 0:0A92 [0] 0441506204 000% 0000 rw 0000001 0000000 0000001
2014/07/24 15:19:24.310 0000096C HHC00101I Thread id 3476, prio  0, name Read-ahead thread-2 ended
2014/07/24 15:19:24.310 0000096C HHC00101I Thread id 924, prio  0, name Read-ahead thread-1 ended
2014/07/24 15:19:24.310 0000096C HHC00101I Thread id 3192, prio  0, name Garbage collector ended
2014/07/24 15:19:24.310 0000096C HHC00101I Thread id 2396, prio  0, name Writer thread-1 ended
2014/07/24 15:19:24.310 0000096C HHC00101I Thread id 4024, prio  0, name Writer thread-2 ended
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0A92 subchannel 0:002A detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0560 subchannel 0:002B detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0561 subchannel 0:002C detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0562 subchannel 0:002D detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0563 subchannel 0:002E detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0564 subchannel 0:002F detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:0580 subchannel 0:0030 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B0 subchannel 0:0031 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B1 subchannel 0:0032 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B2 subchannel 0:0033 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B3 subchannel 0:0034 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B4 subchannel 0:0035 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B5 subchannel 0:0036 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B6 subchannel 0:0037 detached
2014/07/24 15:19:24.310 0000096C HHC01465I 0:05B7 subchannel 0:0038 detached
2014/07/24 15:19:26.864 0000096C HHC01465I 0:0E20 subchannel 0:0039 detached
2014/07/24 15:19:26.874 0000096C HHC01465I 0:0E40 subchannel 0:003B detached
2014/07/24 15:19:26.974 0000096C HHC01427I Main storage released
2014/07/24 15:19:26.974 0000096C HHC01427I Expanded storage released
2014/07/24 15:19:26.974 0000096C HHC01422I Configuration released
2014/07/24 15:19:27.084 0000096C 
2014/07/24 15:19:27.084 0000096C HHC02103I Logger: logger thread terminating
2014/07/24 15:19:27.084 0000096C HHC01424I All termination routines complete
2014/07/24 15:19:27.084 0000096C HHC02103I Logger: logger thread terminating
2014/07/24 15:19:27.084 0000096C HHC01412I Hercules terminated
******************** (last line of logfile above) ********************

Hercules Windows GUI -- Version 1.11.1.5265
Copyright (c) 2001-2007 Software Development Laboratories

HercGUI URL:      http://www.softdevlabs.com/Hercules
HercGUI support:  fish@softdevlabs.com

Hercules URL:     http://www.hercules-390.org/
Hercules support: hercules-390@yahoogroups.com

The wait state occures during NIP processing, so no program check, so the only to lines on the console are:

  IEA247I USING IEASYSDB FOR OS/390 02.08.00 HBB6608                           
  IEA304W SYSTEM WAIT STATE CODE 80009064 DURING IEAVNP10 INITIALIZATION

If you need more, just ask. Christian

Ps, I just tested it again with same configuration file and same machine in Hercules 3.10, no issues...

Christian

Fish-Git commented 10 years ago

If you need more, just ask. Christian

Please try again using the latest build of Hyperion with your OSTAILOR statement changed to "OS/390", with an "LPARMNUM 10" statement added, and with/without "CPUVERID" changed to "47".

A download link to the latest pre-built version of Hyperion can be found on either of the following web pages:

http://hercules-390.github.io/html/ http://www.softdevlabs.com/hyperion.html

The "OSTAILOR OS/390" statement will allow us to verify whether a program-check is occurring or not. (I'm thinking one might be occurring but we are not seeing it. Using OSTAILOR OS/390 should allow us to see it.)

The LPARNUM and CPUVERID statements are just wild guesses. I'm thinking (guessing) either IEAVNP10 is either not finding your CPU model in its table (because of that incorrect CPUVERID value) or some other NIP phase is getting confused due to the LPAR number defaulting to 01.

You might also consider trying a test with/without ALRF enabled too ("ARCHLVL DISABLE ASN_LX_REUSE"). Others have had similar problems in the past and disabling or enabling ALRF seemed to help.

Another thing you might also consider trying: using a different LOADPARM. One that doesn't start DB2 for example (e.g. one that only initializes the absolute minimum set of OS/390 features possible).

I realize running all of the above tests will take some time and effort, but I can see no better (easier or faster) method to create a starting list of likely causes.

Thanks.

"Fish" (David B. Trout) Software Development Laboratories http://www.softdevlabs.com (TEMP): david.b.trout@gmail.com

ChristianBirr commented 10 years ago

Thanks Fish, will do so and forward my observatins

Christian

ChristianBirr commented 10 years ago

Ok Fish, did the tests, attached the hercules logs and their corresponding configs. Console output is the same for all three tests. IEFSSNxx isn't fetched in this early stage of IPL, different LODAPARM made no difference. If you need more, let me know.

Greetings from lower Bavaria

Christian

Fish-Git commented 10 years ago

GitHub does not support attachments?

I have not received any email from you.

No email.

No attachments.

ChristianBirr commented 10 years ago

Sent the attachments to your gmail account yesterday. Christian

ghost commented 10 years ago

Apologies for the delayed response.

Thank you. I did receive your attachments.

Unfortunately however, only the first test (005) is meaningful. Your other two tests (006 and 007) are basically repeats of your original test. They all tested the same thing. None of them were different. They were all the same test.

In test 006 you added the configuration statement "ARCHLVL DISABLE", which was rejected as being invalid. The proper format is: ARCHLVL DISABLE ASN_LX_REUSE. Notice the required "ASN_LX_REUSE" keyword which indicates what facility you are disabling. Simply saying "disable" without identifying what you wish to disable is silly.

A similar error exists in test 007: your statement was "ARCHLVL ASN_LX_REUSE" which identified the facility, but did not indicate whether you wanted to ENABLE the facility or DISABLE it.

As a result, tests 006 and 007 are invalid since they tested the same thing that test 005 already tested!

You need to perform tests 006 and 007 again, using the correct statement format:

    ARCHLVL   DISABLE  ASN_LX_REUSE       # test 006: facility DISabled
    ARCHLVL   ENABLE   ASN_LX_REUSE       # test 007: facility ENabled

For the record, the test runs you supplied (which as I explained all tested the same thing) all failed for the same reason: an "Instruction Fetch Error":

    HHC00801I Processor CP00:  Specification exception code 0006  ilc 4
    PSW=070C2000805F0063 Instruction fetch error
    GR00=00000368 GR01=0000004B GR02=01661860 GR03=0006E3A0
    GR04=0006E38C GR05=0005239C GR06=00000001 GR07=0000000C
    GR08=005F005F GR09=000001A0 GR10=8006C2B8 GR11=0006D2B7
    GR12=0006E2B6 GR13=01EA6538 GR14=8006C954 GR15=005F005F
    HHC00809I Processor CP00: disabled wait state 000A0000 80009064

The instruction fetch error occurred because the instruction address in the PSW was odd. Address 5F0063 is not a valid instruction address. All instructions must on halfword (2 byte) boundaries (i.e. the instruction address must always be an even number; the low order bit must always be off).

How OS/390 reached an odd instruction address I do not know, but that is the cause of your disabled wait.

What I would suggest you do (in addition to re-running tests 006 and 007 again) is to enable instruction tracing before you IPL. Be prepared for a LOT of log messages from Hercules! (Several for each instruction executed!)

I should also warn you that if you do not have the logfile size limits option enabled within HercGUI, your resulting Hercules logfile will be very, very large. Many megabytes and possibly many gigabytes, so be sure you have plenty of disk space.

IN SUMMARY:

  1. Please perform tests 006 and 007 again, using the correct ARCHLVL statement.
  2. Please perform an instruction tracing test. ("t+ command before IPLing)

Also, after performing item 2 above (instruction tracing test), please be sure to compress the resulting logfile with WinZip or some other tool before uploading it to the "incoming" folder on my FTP site:

    ftp://www.softdevlabs.com/incoming

(Note that you will not be able to see any files that you upload since the "incoming" directory is write-only and does not have the read permission set.)

Thank you for your continued patience.

Fish

ChristianBirr commented 10 years ago

Hi Fish, sorry for been silly; my documentation is still 3.07 based, all this newer control statements haven't been documented properly yet, as you mentioned earlier yourself in a post. But never mind, I changed the config to your suggestions and started with the DISABLE ASN_LX_REUSE and t+ a new test. HercGui gave up with a runtime error after half an hour, so I started again with a command prompt. This is running now for nearly 3.5 hours, the amount of trace produced so far is nearly 6GB, will your incoming folder handle this, even after having been compressed? And is it normal to run so long, even if writing out the trace will slow down the whole IPL process?

Greetings from lower Bavaria

Christian

ChristianBirr commented 10 years ago

Test is still running, IPL can't take that long! Will let it go 'till tomorrow and if nothing changed I'll cancel it. Tried to reach you on the phone, will do again tomorrow, there are other issues, well, things I'd like to discuss with you. Since then, cheers, Christian

ghost commented 10 years ago

(ACK!) I'm very sorry Christian! I forgot to tell you to change your HercGUI Memory Logging Preference!

Edit --> Preferences: Logging, Memory: [x] Enable scrollback memory limit = 5000 lines (or some other reasonable value).

That option is not normally enabled by default since Hercules does not normally generate a lot of messages as it runs.

Since you are doing a trace however (which generates a HUGE number of messages), if you don't have the Memory limit option enabled, then HercGUI runs out of memory and crashes!

I will fix that in the next release of HercGUI so that option is enabled by default.

I'm very sorry about that!

ghost commented 10 years ago

Doing an instruction trace can slow processing to a crawl., so yes, an IPL might take a VERY long time.

It is also possible that doing an instruction trace caused your problem to not occur. What messages have appeared on your OS/390 master console? Has it reached the point yet when it usually fails? Or is it passed that point?

We might need to add a "log file segmentation" feature/option to both Hercules and HercGUI so that very verbose instruction tracing test runs (like you are doing) creates multiple smaller sized files instead of one huge file.

If you have a tool to "split" the file, you might consider splitting it into smaller chunks before compressing them and uploading them to my FTP site, At present, I only have about 3GB of space allocated. (I might be able to increase that by a couple of GB in the future, but today I believe it is only 3GB.)

Nevertheless, compressing the file should reduce its size tremendously since it is all text, and text files compress very well.

Using Hercules in command-prompt mode will also slow down Hercules too. Hercules runs much faster when you use HercGUI since its message handling it much more efficient.

Fish-Git commented 10 years ago

Christian:

I did receive you telephone calls. I apologize for not answering when you called. I was sleep both times.

I have a sleeping disorder which affects my asleep/awake times. Sometimes I'm awake during the day and sleep at night like normal people, but other times I am awake at night and work at night and sleep during the day. Lately I have been on "night shift" and was asleep by the time you called, and I did not notice I had a voice mail message until too late. Please accept my sincere apologies.

Regarding your question, yes, delaying the instruction trace until just before the problem occurs would speed things up and help reduce the length of time for the IPL and the resulting size of the log file.

However, depending on precisely what the problem actually is, the resulting trace file might not contain the evidence of the problem. I believe it should, but "the problem" -- whatever it is (we don't know what it is yet!) -- might occur very early in the IPL but we are just not seeing it until much later (unlikely but <possible).

In summary, yes, what you suggested is a good idea: try to delay the instruction tracing until the last possible moment. We might get lucky and the log file might contain the evidence of what went wrong. (me: fingers crossed.)

Has your original trace finally finished yet? Or is it still running? If it is still running, then you might want to cancel it and try your new idea instead.

Thank you for you patience.

ChristianBirr commented 10 years ago

Apologies for being late, but if've been in a personal disorder for a couple of days. Now, the trace was not finished this morning, so I decided to cancel it, it simply can't run that long. I remembered you suggesting to start up with a minimal system (IEFSSNxx), so I did with only JES2, RACF and SMS, guess what, it came up nicely, then I reipled with full function IEFSSNxx and one again, it came up nicely, too! Ok, can live with that, but it still doesn't explain, why it worked with R3.10 and I hate mysteries. During some final tests I discovered a codepage (here hercules default) problem, the "\" (x'E0') gets translated to " "( X'40') when processing a rexx under TSSO. In VISTA32 I have screen code page set to United States and keybord modifications to Germany as I did all the years, no idea why this is now. Christian Addendum: Codepage issue solved, the problem was sitting in front of the screen (DIAG8CMD disabled, CPCMD wouldn't get through)

Fish-Git commented 10 years ago

Christian Birr wrote:

Apologies for being late, but if've been in a personal disorder for a couple of days.

No need to apologize. I know what that's like. :)

Now, the trace was not finished this morning, so I decided to cancel it, it simply can't run that long. I remembered you suggesting to start up with a minimal system (IEFSSNxx), so I did with only JES2, RACF and SMS, guess what, it came up nicely.

That's good to hear!

Then I reipled with full function IEFSSNxx and one again, it came up nicely, too!

Interesting...

Ok, can live with that, but it still doesn't explain, why it worked with R3.10 and I hate mysteries.

Me too Christian, me too. I fear the only way we will ever get to the bottom of this mystery is if you still have a copy of your Hercules dasd from before this problem first started, and sent them to someone like me so I could then recreate the problem here on my own system.

Is that possible? Do you still have backup copies of your Hercules dasd from BEFORE this problem started happening? Can you upload them to my FTP site so I can try to recreate the original problem on my own system?

During some final tests I discovered a codepage (here hercules default) problem, the "\" (x'E0') gets translated to " "( X'40') when processing a rexx under TSSO.

Not all codepages provide "lossless" translation between ASCII and EBCDIC. (Some do, but most do not.) Only the 1252/1140 codepage provides lossless end-to-end binary ASCII <--> EBCDIC translation (i.e. translating from ASCII to EBCDIC and then back to ASCII again (or from EBCDIC to ASCII and then back to EBCDIC again) will result in the exactly the same original values that you started out with). Only codepage 1252/1140 provides this ability. (All of the other codepages cause one or more characters to get scrambled/changed. Only 1252/1140 does not.)

For additional information regarding codepages refer to the following HerculesPlusPlus posting:

https://groups.yahoo.com/neo/groups/HerculesPlusPlus/conversations/messages/19

But I doubt your choice of codepage was the cause of your original instruction fetch error (disabled wait).

Of course, I've been wrong before. :)

Is your problem resolved now? Should we close this issue? Or would you like me to research it further?

If you have your Hercules dasd files as they were from before this problem first started occurring and can upload them to my FTP site, I can look into this mystery a little deeper.

Otherwise, we should probably close this issue now if your problem is no longer occurring.

Has your problem been resolved? Is everything working okay for you now?

"Fish" (David B. Trout) Software Development Laboratories http://www.softdevlabs.com (TEMP): david.b.trout@gmail.com

ChristianBirr commented 10 years ago

Hi Fish, you might have overlooked the addendum in my last post, the codepage problem is right now looking at you on the left upper corner of this post (in git).

As for the original dasd files, we might be lucky having the "old" ones in a backup I made before messing around with this wait state, I'll have a look at it this evening and come back to you afterwards, but be warned, those files gonna be huge, we might have to use a different drop zone for this, may be my own ftp server, will talk to my collegues about this, we are very restrictive when it comes to access to our servers, but there would be room enough. Now gone for earning money....

Christian

ChristianBirr commented 10 years ago

Well Fish, good and bad news. I restored from backup , started hercules and noticed some dasd inconsistencies on startup, hercules repaired them with cckdcdsk -1 -f, IPLd and the wait state occurred again.

I then shutdown, did a cckdcdsk -3 -f and then a cckdcomp -f -3 on all dasd files, reIPLd and the problem disappeared, so would it be possible that some important libraries like LINKLIB or LPA have been corrupt? I redid the complete test and it made no difference, everything seem to be fine! So I come to the conclusion that this is NOT a Hercules related problem and suggest to close this issue.

Next thing, my team agreed on making a drop zone available, would be 200G enough. It takes some preparation: creating an account for you (email, domain and ftp access) because we don't accept anonymous access; there we could exchange whole machines without to many hustle. If you agree, it would be set up by the middle of next week.

Christian

Fish-Git commented 10 years ago

Christian Birr wrote:

(Note: minor editing and reformatting of text)

Well Fish, good and bad news. I restored from backup, started Hercules, and noticed some dasd inconsistencies on startup, which I then repaired with "cckdcdsk -1 -f".

I IPLed and the waitstate occurred again.

I then shutdown, did "cckdcdsk -3 -f" and "cckdcomp -f -3" on all dasd files, and then reIPLed again, and the problem disappeared.

So would it be possible that some important libraries like LINKLIB or LPA have been corrupt?

It's possible, yes. CCKD dasd files are more easily prone to corruption than uncompressed CKD dasd. The good news however, is CCKD corruption is much more easily repaired than CKD dasd corruption. If CKD dasd gets corrupted your only choice is to restore from backup. With CCKD dasd however, a simple "cckdcdsk" is usually able to repair it quite quickly and easily as you have discovered.

Plus, compressed CCKD dasd supports shadow files which CKD format does not. (Shadow files are a very powerful and often overlooked feature of the CCKD dasd format.)

I redid the complete test and it made no difference: every- thing appears to be just fine!

So I come to the conclusion that this is NOT a Hercules related problem and suggest to close this issue.

I agree 100%. It sounds like a simple dasd corruption issue and will close the issue as soon as I post this response.

Thank you for being so patient with me Christian, and I apologize for not thinking about possible dasd corruption in the first place. If I had originally thought about it and had suggested that you check your dasd with cckdcdsk when you first reported this issue, it would have taken us so long to resolve it (and you wouldn't have wasted so much time doing those traces). I apologize for that.

Next thing, my team agreed on making a drop zone available. Would 200G be enough? It would take some preparation: we'd have to create an account for you (email, domain and ftp access) because we don't accept anonymous access. There, we could exchange whole machines without too much hassle. If you agree, it could be set up by the middle of next week.

Christian

Your offer is very kind, but no. I do not need you to do that. Since your problem has been resolved, and since it is not a Hercules issue, it is no longer necessary. Tell your team thank you from me, but since this issue has now been resolved I am withdrawing my request since it is no longer needed.

Thanks again for your patience.

"Fish" (David B. Trout) Software Development Laboratories http://www.softdevlabs.com (TEMP): david.b.trout@gmail.com