Re: Oninit from cron leaves engine in permanent fast recovery
Posted in 2005
Topics: Backup & Restore
Hi
The online log shows;
05:38:51 On-Line Mode
05:41:02 Shutdown Mode
05:41:03 Quiescent Mode
05:41:05 IBM Informix Dynamic Server Stopped.
05:41:26 IBM Informix Dynamic Server Started.
Thu Oct 20 05:41:28 2005
05:41:28 Event alarms enabled. ALARMPROG =
'/usr/informix/etc/alarmprogram.sh'
05:41:28 Booting Language <c> from module <>
05:41:28 Loading Module <CNULL>
05:41:28 Booting Language <builtin> from module <>
05:41:28 Loading Module <BUILTINNULL>
05:41:28 VP pid=811246 priority fixed at 60, former = 103
05:41:33 Requested shared memory segment size rounded from 2776KB to2784KB
05:41:33 IBM Informix Dynamic Server Version 9.40.FC6 SoftwareSerial Number AAA#B000000
05:41:34 IBM Informix Dynamic Server Initialized -- Shared MemoryInitialized.
05:41:34 Started 1 btree scanners.
05:41:34 Low priority set for the btree scanners.
05:41:34 Btree scanner threshold set at 50000.
05:41:34 Btree scanner range scan size set at -1.
05:41:34 Physical Recovery Started at Page (2:28085).
05:41:34 Physical Recovery Complete: 0 Pages Examined, 0 Pages
Restored.
05:41:34 Logical Recovery Started.
05:41:34 10 recovery worker threads will be started.
Ï obviously have to get a complete oninit process list each time I
have to forceably kill the engine. It shows;
informix 557132 790670 0 05:41:28 - 0:00 oninit -v
informix 585960 790670 0 05:41:31 - 0:00 oninit -v
informix 635134 790670 0 05:41:33 - 0:00 oninit -v
informix 700464 790670 0 05:41:33 - 0:00 oninit -v
informix 708762 790670 0 05:41:29 - 0:00 oninit -v
informix 725048 790670 0 05:41:28 - 0:00 oninit -v
informix 762012 680042 0 05:41:26 - 0:00 oninit -v
informix 770124 790670 0 05:41:30 - 0:00 oninit -v
informix 774186 790670 0 05:41:28 - 0:00 oninit -v
informix 778312 790670 0 05:41:33 - 0:00 oninit -v
informix 782550 790670 0 05:41:33 - 0:00 oninit -v
informix 786480 790670 0 05:41:32 - 0:00 oninit -v
informix 790670 811246 0 05:41:28 - 0:00 oninit -v
informix 811246 762012 120 05:41:26 - 3:47 oninit -v
There are no backup processes running (onbar or ontape) ... in fact,
nothing else beginning with 'on'.
Back to the drawing board :(
TBP wrote:
> gerry.cassidy@dsl.pipex.com wrote:
> > Sorry ...
> >
> > ... Nog does not have it. In fact, although there have been numerous
> > suggestions in response to this posting, all had already been tried or
> > were in place and nothing works. If anyone is interested, this problem
> > has been passed to IBM and they don't know why it won't start either.
> >
> > The only information I have not been able to supply IBM is an analysis
> > of a core dump of the instance process.
> >
>
> What about the online.log?
>
> That has been asked for before in this thread and yet ...
>
> Also, what does a ps -ef output show, immediately after the "explicit"
> oninit -v command is run (just do ps -ef | grep on if you want to limit> the output, would be interesting to see the oninit processes running,
> along with anything else starting with "on").
gerry.cassidy@dsl.pipex.com wrote:
> Hi
>
<snip>
> informix 557132 790670 0 05:41:28 - 0:00 oninit -v
> informix 585960 790670 0 05:41:31 - 0:00 oninit -v
> informix 635134 790670 0 05:41:33 - 0:00 oninit -v
> informix 700464 790670 0 05:41:33 - 0:00 oninit -v
> informix 708762 790670 0 05:41:29 - 0:00 oninit -v
> informix 725048 790670 0 05:41:28 - 0:00 oninit -v
> informix 762012 680042 0 05:41:26 - 0:00 oninit -v
> informix 770124 790670 0 05:41:30 - 0:00 oninit -v
> informix 774186 790670 0 05:41:28 - 0:00 oninit -v
> informix 778312 790670 0 05:41:33 - 0:00 oninit -v
> informix 782550 790670 0 05:41:33 - 0:00 oninit -v
> informix 786480 790670 0 05:41:32 - 0:00 oninit -v
> informix 790670 811246 0 05:41:28 - 0:00 oninit -v
> informix 811246 762012 120 05:41:26 - 3:47 oninit -v
>
> There are no backup processes running (onbar or ontape) ... in fact,
> nothing else beginning with 'on'.
>
> Back to the drawing board :(
>
>
> TBP wrote:
>
>>gerry.cassidy@dsl.pipex.com wrote:
>>
>>>Sorry ...
>>>
>>>... Nog does not have it. In fact, although there have been numerous
>>>suggestions in response to this posting, all had already been tried or
>>>were in place and nothing works. If anyone is interested, this problem
>>>has been passed to IBM and they don't know why it won't start either.
>>>
What about suggesting getting in touch with AIX support regarding
starting a ksh script which runs a processes which forks children and
what are the caveats.
>>>The only information I have not been able to supply IBM is an analysis
>>>of a core dump of the instance process.
>>>
>>
>>What about the online.log?
>>
>>That has been asked for before in this thread and yet ...
>>
>>Also, what does a ps -ef output show, immediately after the "explicit"
>>oninit -v command is run (just do ps -ef | grep on if you want to limit>>the output, would be interesting to see the oninit processes running,
>>along with anything else starting with "on").
>
>
Right, I think you need to read up on cron and queuedefs ...
I mucked around a bit today, and managed to get into a similar situation
by mucking around with parent and child process with a debugger.
The giveaway from the ps -ef output is that the main oninit process
still has a parent shell, and not a parent pid of 1.
I would suggest that this is not an informix product issue, but more
"what on earth is cron doing when it starts processes which have to fork
children". Reading up on cron on AIX, there appear to be quite a few
"things to bear in mind".
Having said that :
1. Why do you have to bounce the engine?
We have a requirement to automatically bounce our 9.40.FC6 instance on
AIX 5.2.
2. Can you provide the contents of dba_profile?
========================
-----------------------------------------
#!/bin/ksh
. /opt/informixdba/Profiles/dba_profile 940 shm
/usr/informix/bin/onmode -yuk
sleep 30
/usr/informix/bin/oninit -v
========================
Thanks TBP, I think you may have hit on something there. The
difference between ps outputs taken from the cron startup and the
manual startup is shown below;
< informix 585744 770152 0 02:54:26 - 0:00 oninit -v
< informix 643312 585744 76 02:54:27 - 84:26 oninit -v
< informix 680146 803060 0 02:54:30 - 0:00 oninit -v
< informix 684190 803060 0 02:54:33 - 0:00 oninit -v
< informix 688160 803060 0 02:54:28 - 0:00 oninit -v
< informix 704580 803060 0 02:54:33 - 0:00 oninit -v
< informix 708738 803060 0 02:54:28 - 0:00 oninit -v
< informix 729210 803060 0 02:54:29 - 0:00 oninit -v
< informix 733304 803060 0 02:54:31 - 0:00 oninit -v
< informix 765966 803060 0 02:54:32 - 0:00 oninit -v
< informix 790632 803060 0 02:54:33 - 0:00 oninit -v
< informix 803060 643312 0 02:54:28 - 0:00 oninit -v
< informix 811086 803060 0 02:54:33 - 0:00 oninit -v
< informix 827566 803060 0 02:54:28 - 0:00 oninit -v
---
> informix 643318 1 0 04:20:49 - 0:03 oninit -v
> informix 680148 803066 0 04:20:55 - 0:00 oninit -v
> informix 684192 803066 0 04:20:51 - 0:00 oninit -v
> informix 688168 803066 0 04:20:51 - 0:00 oninit -v
> informix 704582 803066 0 04:20:50 - 0:00 oninit -v
> informix 708744 803066 0 04:20:52 - 0:00 oninit -v
> informix 729212 803066 0 04:20:54 - 0:00 oninit -v
> informix 733306 803066 0 04:20:56 - 0:00 oninit -v
> informix 765968 803066 0 04:20:56 - 0:00 oninit -v
> informix 790634 803066 0 04:20:50 - 0:00 oninit -v
> informix 803066 643318 0 04:20:50 - 0:00 oninit -v
> informix 827568 803066 0 04:20:53 - 0:00 oninit -v
> informix 831622 803066 0 04:20:56 - 0:00 oninit -v
I agree that the main oninit should have a PID of 1 ... don't know how
I missed it :( I think I will travel down this route for the moment.
We have very good AIX guys, but raising a call with AIX support would
certainly be the next step.
In answer to your questions;
1) The customer has a requirement to bounce, so we say ... how high
shall we bounce?
2) If I get time I will post dba_profile, but it's routine stuff. The
environments are not different between cron and ksh. Tested
thoroughly.
Thanks again. Seems like a big clue.
Gerry