Re: Problems with long checkpoints
Posted in 2011
Here's the cause, in your onstat header during the checkpoint:
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line (CKPT INP) --
Up 02:48:10 -- 6638456 Kbytes
Blocked:DBS_DROP
The checkpoint is blocked while a dbspace is being dropped. Probably very
slow IO response. You should not be using NFS mounted volumes for chunks.
Art
Art S. Kagel
Advanced DataTools (www.advancedatatools.com)
Blog: http://informix-myview.blogspot.com/
Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Advanced DataTools, the IIUG, nor any other
organization with which I am associated either explicitly, implicitly, or by
inference. Neither do those opinions reflect those of other individuals
affiliated with any entity with which I am affiliated nor those of the
entities themselves.
On Tue, Sep 27, 2011 at 4:15 PM, Sean Baker <SBaker@moneymailer.com> wrote:
> > -----Original Message-----
> > From: informix-list-bounces@iiug.org [mailto:informix-list-
> > bounces@iiug.org] On Behalf Of jrenaut
> > Sent: Tuesday, September 27, 2011 1:06 PM
> > To: informix-list@iiug.org
> > Subject: Re: Problems with long checkpoints
> >
> > On Sep 27, 2:48 pm, Sean Baker <SBa...@moneymailer.com> wrote:
> > > > -----Original Message-----
> > > > From: informix-list-boun...@iiug.org [mailto:informix-list-
> > > > boun...@iiug.org] On Behalf Of jrenaut
> > > > Sent: Tuesday, September 27, 2011 12:41 PM
> > > > To: informix-l...@iiug.org
> > > > Subject: Re: Problems with long checkpoints
> > >
> > > > On Sep 27, 2:05 pm, Sean Baker <SBa...@moneymailer.com> wrote:
> > > > > Hello,
> > >
> > > > > We're stuck without a dba after some massive layoffs. I know a
> > > > little, but I'm no dba.
> > >
> > > > > IDS 11.50.FC6 on RHEL 5.3
> > >
> > > > > We have a development instance that is suddenly going into long
> > > > checkpoints (43 minutes, 61 minutes, 90 minutes!). We've rebooted
> > the
> > > > server and restarted the instance, and even did a restore from our
> > > > production server to the dev server. It lasts for a while (maybe
> > 30
> > > > minutes) then goes into long checkpoints.
> > >
> > > > > One of our developers has been creating new dbspaces, and it
> > seems
> > > > that might be the cause. Although he's added a few over the past
> > > > several months without any problems. After the restore today, he
> > added
> > > > a dbspace, and we're stuck in long checkpoints again:
> > >
> > > > > IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line
> > (CKPT
> > > > INP) -- Up 01:39:05 -- 6638456 Kbytes> > >
> > > > > I've listed the last few log entries from today below. Can
> > anyone
> > > > give me some obvious things to check? Or some better data to
> > provide
> > > > to the list for some help?
> > >
> > > > > Thanks,
> > >
> > > > > Sean
> > >
> > > > > Log:
> > >
> > > > > 11:31:41 Checkpoint Completed: duration was 0 seconds.
> > > > > 11:31:41 Tue Sep 27 - loguniq 15415, logpos 0x33f1018,
> > timestamp:> > > > 0x4f4c8892 Interval: 209340
> > >
> > > > > 11:31:41 Maximum server connections 12
> > > > > 11:31:41 Checkpoint Statistics - Avg. Txn Block Time 0.000, #> > Txns
> > > > blocked 0, Plog used 0, Llog used 2
> > >
> > > > > 11:35:02 Space 'sm_dbs0' added.
> > > > > 11:35:02 Checkpoint Completed: duration was 0 seconds.
> > > > > 11:35:02 Tue Sep 27 - loguniq 15415, logpos 0x33fb2e4,
> > timestamp:> > > > 0x4f4c8a3d Interval: 209341
> > >
> > > > > 11:35:02 Maximum server connections 12
> > > > > 11:35:02 Checkpoint Statistics - Avg. Txn Block Time 0.000, #> > Txns
> > > > blocked 0, Plog used 16, Llog used 10
> > >
> > > > > 11:35:13 Checkpoint Completed: duration was 0 seconds.
> > > > > 11:35:13 Tue Sep 27 - loguniq 15415, logpos 0x33fe018,
> > timestamp:> > > > 0x4f4c8b0c Interval: 209342
> > >
> > > > > 11:35:13 Maximum server connections 12
> > > > > 11:35:13 Checkpoint Statistics - Avg. Txn Block Time 0.000, #> > Txns
> > > > blocked 0, Plog used 0, Llog used 3
> > >
> > > > > 11:40:40 Checkpoint Completed: duration was 1 seconds.
> > > > > 11:40:40 Tue Sep 27 - loguniq 15415, logpos 0x3867018,
> > timestamp:> > > > 0x4f4cdac8 Interval: 209343
> > >
> > > > > 11:40:40 Maximum server connections 12
> > > > > 11:40:40 Checkpoint Statistics - Avg. Txn Block Time 0.000, #> > Txns
> > > > blocked 0, Plog used 134, Llog used 1129
> > >
> > > > > 11:44:58 Adjusting LRU for bufferpool - id 0 size 2k
> > > > > 11:44:58 Old max 60.0 min 50.0 New max 59.4 min 49.5
> > > > > 11:46:07 Adjusting LRU for bufferpool - id 0 size 2k
> > > > > 11:46:07 Old max 59.4 min 49.5 New max 58.8 min 49.0> > >
> > > > Well, we can't really get much from what you've posted as the
> > > > checkpoint duration's listed in that snipped of MSGPATH file are 0
> > > > seconds. How about you post onstat -g ckp output after a long
> > > > checkpoint happens? Perhaps that will be more helpful.
> > >
> > > Will do. Although we're going on an hour since the last
> > checkpoint...
> >
> > Well, if it's happening right now, how about you post and onstat -g
> > ath and then find the thread id for the main_loop() thread and post an
> > onstat -g stk <thread id of main_loop() thread> to see what main_loop> > is doing, or what it might be waiting for.
> >
> > Jacques Renaut
> > IBM Informix Advanced Support
> > APD Team
>
> The developer tried dropping the dbspace he created, so now we're blocked
> with "DBS_DROP". Here's the onstat -g ath for the main_loop():
>
> IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line (CKPT INP) --
> Up 02:48:10 -- 6638456 Kbytes
> Blocked:DBS_DROP
>
> Threads:> tid tcb rstcb prty status
> vp-class name
> 18 15f37a548 15e56f028 3 sleeping secs: 1
> 5cpu main_loop()
>
> And here's onstat -g stk 18:
>
> IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line (CKPT INP) --
> Up 02:49:56 -- 6638456 Kbytes
> Blocked:DBS_DROP>
> Stack for thread: 18 main_loop()
> base: 0x000000015f3c6000
> len: 69632
> pc: 0x0000000001073d0e
> tos: 0x000000015f3d5a40> state: sleeping
> vp: 4
>
> 0x0000000001073d0e (/opt/IBM/informix/bin/oninit) yield_processor_mvp
> 0x000000000107556b (/opt/IBM/informix/bin/oninit) mt_yield
> 0x0000000000bb951a (/opt/IBM/informix/bin/oninit) dskflush_bfpool
> 0x0000000000bb98c2 (/opt/IBM/informix/bin/oninit) dskflush
> 0x0000000000b56165 (/opt/IBM/informix/bin/oninit) checkpoint
> 0x00000000005336e9 (/opt/IBM/informix/bin/oninit) main_loop
> 0x000000000108560f (/opt/IBM/informix/bin/oninit) startup
>
> Thanks,
>
> Sean.
> _______________________________________________
> Informix-list mailing list
> Informix-list@iiug.org
> http://www.iiug.org/mailman/listinfo/informix-list
>