SVN 5486 hangs during exit or quit command

View: New views

2 Messages — Rating Filter: Alert me

SVN 5486 hangs during exit or quit command

by pfg504 :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

While trying to quit hercules, hercules hangs processing 3380 dasd files. The web interface is still active, so I am able to get some information about the state of the machine:
---------------------------
ipending
HHCPN123I CPU0000: offline
HHCPN123I CPU0001: offline
HHCPN123I CPU0002: offline
HHCPN123I CPU0003: offline
HHCPN123I CPU0004: offline
HHCPN123I CPU0005: offline
HHCPN123I CPU0006: offline
HHCPN123I CPU0007: offline
Config mask 00000000 started mask 00000000 waiting mask 00000000
Syncbc mask 00000000
Signaling facility not busy
TOD lock not held
Mainlock not held; owner ffff
Intlock not held; owner ffff
Ioq lock not held
DEV 0:0700: suspended
DEV 0:0700: lock held
DEV 0:080A: suspended
I/O interrupt queue:
DEV 0:5C0E, normal, pri 0
version
Hercules Version 3.06 svn 5486
(c)Copyright 1999-2009 by Roger Bowler, Jan Jaeger, and others
Built on Oct 12 2009 at 11:30:40
Build information:
Modes: S/370 ESA/390 z/Arch
Max CPU Engines: 8
Using setresuid() for setting privileges
Dynamic loading support
Using shared libraries
HTTP Server support
Regular Expressions support
Automatic Operator support
National Language Support
Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8
Running on legmainx86 Linux-2.6.16.60-0.42.5-sm.#1 SMP Mon Aug 24 09:41:41 UTC 2009 x86_64 MP=2
---------------------------
Path Management Control Word
Interruption Parameter 00000000
Q 0 ISC 00 A E LM MM D T V DEVNUM
0 0 0 1 10 11 1 0 1 0700
LPM PNOM LPUM PIM
FF 00 80 80
MBI POM PAM
000D FF 80
CHPID=0 CHPID=1 CHPID=2 CHPID=3
07 00 00 00
CHPID=4 CHPID=5 CHPID=6 CHPID=7
00 00 00 00
ZONE 00000 VISC 00000000 I 000000 S
00 0 0 1
-------------------------------

sfd0700

HHCCD210I size free nbr st reads writes l2reads hits switches
HHCCD211I readaheads misses
HHCCD212I --------------------------------------------------------------------
HHCCD213I [*] 38865805 0% 4 1169 199 40 544 895
HHCCD214I 818 488
HHCCD215I /OLIS/disks/310W05.C3381
HHCCD216I [0] 36328532 0% 0 rd 815 0 20
HHCCD217I /OLIS/shadows/310W05_*.C3381
HHCCD218I [1] 2370276 0% 0 rd 20 1 2
HHCCD218I [2] 166997 26% 4 rw 334 196 18

------------------
configuration file information:
CCKD RA=9,RAQ=16,RAT=16,WR=9,gcstart=1,gcparm=8,gcint=1,fsync=1
HERCPRIO 0
TODPRIO -20
DEVPRIO 1
CPUPRIO 0

ps -aef

root 17155 4506 1 Oct19 pts/0 00:16:35 hercules -f OLIS2003.cnf
root 17257 17155 0 Oct19 pts/0 00:00:00 [hercules] <defunct>

What else would be helpful?

Thanks
Paul

Re: SVN 5486 hangs during exit or quit command

by pfg504 :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

The problem appears to be in cckddasd.c processing the cckd_lock_devchain function.

ppt_pthread_cond_wait()
pthread_cond_wait returns 0

cckdblk.devwaiters = 1

gdb output:
(gdb) s
cckd_lock_devchain [inlined] () at /Users/hercules/SourceCode/cckddasd.c:4476
4476 cckdblk.devwaiters--;
(gdb) p cckdblk.devwaiters
$2 = 1
(gdb) s
cckd_lock_devchain [inlined] () at /Users/hercules/SourceCode/cckddasd.c:4466
4466 while ((flag && cckdblk.devusers != 0)
(gdb) p cckdblk.devwaiters
$3 = 0
(gdb) p flag
$4 = <value temporarily unavailable, due to optimizations>
(gdb) p cckdblk.devusers
$5 = 1
(gdb) n
cckd_lock_devchain [inlined] () at /Users/hercules/SourceCode/cckddasd.c:4472
4472 cckdblk.devwaiters++;
(gdb) list
4467 || (!flag && cckdblk.devusers < 0))
4468 {
4469 //gettimeofday(&now,NULL);
4470 //tm.tv_sec = now.tv_sec + 2;
4471 //tm.tv_nsec = now.tv_usec * 1000;
4472 cckdblk.devwaiters++;
4473 wait_condition(&cckdblk.devcond, &cckdblk.devlock);
4474 //timeout = timed_wait_condition(&cckdblk.devcond, &cckdblk.devlock, &tm);
4475 //if (timeout) cckd_print_itrace();
4476 cckdblk.devwaiters--;
------
cckd_lock_devchain [inlined] () at /Users/hercules/SourceCode/cckddasd.c:4473
4473 wait_condition(&cckdblk.devcond, &cckdblk.devlock);
(gdb) s
0x000000010042e890 in dyld_stub_ptt_pthread_cond_wait ()
(gdb) p cckdblk
$6 = {
id = "CCKDBLK ",
dev1st = 0x1008be200,
batch = 0,
sfmerge = 0,
sfforce = 0,
sflevel = 0,
comps = 3 '\003',
comp = 255 '?',
compparm = -1,
gclock = {
__sig = 1297437784,
__opaque = "\000\000\000\000`\000\001\000\000\000\000\000\000\000\000\000h\031\024\022", '\0' <repeats 35 times>
},
gccond = {
__sig = 1129270852,
__opaque = "\000\000\000\000\000\000\000?", '\0' <repeats 31 times>
},
gcs = 1,
gcmax = 1,
gcwait = 10,
gcparm = 0,
wrlock = {
__sig = 1297437784,
__opaque = "\000\000\000\000`", '\0' <repeats 35 times>, "??C\000\001\000\000\000\000\000\000\000\000\000\000"
},
wrcond = {
__sig = 1129270852,
__opaque = "\000\000\000\000\004\000\000?", '\0' <repeats 16 times>, "@?C\000\001\000\000\000\003\035\000\000\000\000\000"
},
wrpending = 0,
wrwaiting = 4,
wrs = 4,
wrmax = 1,
wrprio = 16,
ralock = {
__sig = 1297437784,
__opaque = "\000\000\000\000`", '\0' <repeats 35 times>, "\b?C\000\001\000\000\000\000\000\000\000\000\000\000"
},
racond = {
__sig = 1129270852,
__opaque = "\000\000\000\000\t\000\000?", '\0' <repeats 16 times>, "??C\000\001\000\000\000\003e\000\000\000\000\000"
},
ras = 9,
ramax = 1,
rawaiting = 9,
ranbr = 0,
readaheads = 0,
ra = {{
dev = 0x101831e00,
trk = 12180,
prev = -1,
next = -1
}, {
dev = 0x101847600,
trk = 18357,
prev = -1,
next = 2
}, {
dev = 0x101847600,
trk = 18351,
prev = -1,
next = 0
}, {
dev = 0x101847600,
trk = 18359,
prev = -1,
next = 1
}, {
dev = 0x0,
trk = 0,
prev = 0,
next = 0
} <repeats 12 times>},
ra1st = -1,
ralast = -1,
rafree = 3,
devlock = {
__sig = 1297437784,
__opaque = "\000\000\000\000`\000\001\000\000\000\000\000\000\000\000\000h\031\024\022", '\0' <repeats 35 times>
},
devcond = {
__sig = 1129270852,
__opaque = "\000\000\000\000\000\000\000?", '\0' <repeats 31 times>
},
devusers = 1,
devwaiters = 1,
freepend = -1,
nostress = 0,
linuxnull = 0,
fsync = 0,
termcond = {
__sig = 1129270852,
__opaque = "\000\000\000\000\000\000\000?", '\0' <repeats 31 times>
},
stats_switches = 95474,
stats_cachehits = 93418,
stats_cachemisses = 2056,
stats_readaheads = 95499,
stats_readaheadmisses = 3844,
stats_syncios = 0,
stats_synciomisses = 0,
stats_iowaits = 124,
stats_cachewaits = 0,
stats_stresswrites = 48,
stats_l2cachehits = 7856,
stats_l2cachemisses = 641,
stats_l2reads = 640,
stats_reads = 97253,
stats_readbytes = 819421842,
stats_writes = 270,
stats_writebytes = 2068355,
stats_gcolmoves = 15,
stats_gcolbytes = 1072920,
itrace = 0x0,
itracep = 0x0,
itracex = 0x0,
itracen = 0,
bytemsgs = 0
}
(gdb)

========
Is there a way to flush the cache before quitting?

Paul

--- In hercules-390@..., "pfg504" <pfg504@...> wrote:

>
> While trying to quit hercules, hercules hangs processing 3380 dasd files. The web interface is still active, so I am able to get some information about the state of the machine:
> ---------------------------
> ipending
> HHCPN123I CPU0000: offline
> HHCPN123I CPU0001: offline
> HHCPN123I CPU0002: offline
> HHCPN123I CPU0003: offline
> HHCPN123I CPU0004: offline
> HHCPN123I CPU0005: offline
> HHCPN123I CPU0006: offline
> HHCPN123I CPU0007: offline
> Config mask 00000000 started mask 00000000 waiting mask 00000000
> Syncbc mask 00000000
> Signaling facility not busy
> TOD lock not held
> Mainlock not held; owner ffff
> Intlock not held; owner ffff
> Ioq lock not held
> DEV 0:0700: suspended
> DEV 0:0700: lock held
> DEV 0:080A: suspended
> I/O interrupt queue:
> DEV 0:5C0E, normal, pri 0
> version
> Hercules Version 3.06 svn 5486
> (c)Copyright 1999-2009 by Roger Bowler, Jan Jaeger, and others
> Built on Oct 12 2009 at 11:30:40
> Build information:
> Modes: S/370 ESA/390 z/Arch
> Max CPU Engines: 8
> Using setresuid() for setting privileges
> Dynamic loading support
> Using shared libraries
> HTTP Server support
> Regular Expressions support
> Automatic Operator support
> National Language Support
> Machine dependent assists: cmpxchg1 cmpxchg4 cmpxchg8
> Running on legmainx86 Linux-2.6.16.60-0.42.5-sm.#1 SMP Mon Aug 24 09:41:41 UTC 2009 x86_64 MP=2
> ---------------------------
> Path Management Control Word
> Interruption Parameter 00000000
> Q 0 ISC 00 A E LM MM D T V DEVNUM
> 0 0 0 1 10 11 1 0 1 0700
> LPM PNOM LPUM PIM
> FF 00 80 80
> MBI POM PAM
> 000D FF 80
> CHPID=0 CHPID=1 CHPID=2 CHPID=3
> 07 00 00 00
> CHPID=4 CHPID=5 CHPID=6 CHPID=7
> 00 00 00 00
> ZONE 00000 VISC 00000000 I 000000 S
> 00 0 0 1
> -------------------------------
>
> sfd0700
>
> HHCCD210I size free nbr st reads writes l2reads hits switches
> HHCCD211I readaheads misses
> HHCCD212I --------------------------------------------------------------------
> HHCCD213I [*] 38865805 0% 4 1169 199 40 544 895
> HHCCD214I 818 488
> HHCCD215I /OLIS/disks/310W05.C3381
> HHCCD216I [0] 36328532 0% 0 rd 815 0 20
> HHCCD217I /OLIS/shadows/310W05_*.C3381
> HHCCD218I [1] 2370276 0% 0 rd 20 1 2
> HHCCD218I [2] 166997 26% 4 rw 334 196 18
>
> ------------------
> configuration file information:
> CCKD RA=9,RAQ=16,RAT=16,WR=9,gcstart=1,gcparm=8,gcint=1,fsync=1
> HERCPRIO 0
> TODPRIO -20
> DEVPRIO 1
> CPUPRIO 0
>
> ps -aef
>
> root 17155 4506 1 Oct19 pts/0 00:16:35 hercules -f OLIS2003.cnf
> root 17257 17155 0 Oct19 pts/0 00:00:00 [hercules] <defunct>
>
>
> What else would be helpful?
>
> Thanks
> Paul
>