oninit taking ages
Eric reported that oninit on 12.10 under RHEL/VMware took 25-46 minutes to start (hanging after locking the big shared memory segment, at "Initializing rhead structure"), while setting RESIDENT=0 cut startup to ~35 seconds; the same config on physical hardware started in 25 seconds. Others asked about VM vs. host memory and suspected swapping. That proved correct: the VMware resource pool capped the Informix VM at 12 GB while Informix had 24 GB of shared memory, so the VM had been swapping constantly (also explaining poor performance), with 60 other VMs competing. Fix: remove the VMware memory limit and reserve more CPU.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Hi all,
before I post a PMR:
did anyone see an informix instance take 25mn to start ?
25 minutes was with 12.10FC4 on a linux/red hat VMWare (big server according
to the vendors)
With 12.10FC5W1, i had to wait 46 mn before deciding to kill oninit.
I am using huge pages and RESIDENT=1
I had a feeling that setting RESIDENT=0 could help, and it DID!
Informix took 35 seconds to start without setting the first SHMEM segment as
resident.
Where is the explanation of such a phenomenon ?
online.log:
20:19:02 Parameter's user-configured value was adjusted. (INFORMIXCONTIME)
20:19:02 Parameter's user-configured value was adjusted. (GSKIT_VERSION)
20:19:02 Parameter's user-configured value was adjusted. (DS_NONPDQ_QUERY_MEM)
20:19:02 IBM Informix Dynamic Server Started.
20:19:02 Requested shared memory segment size rounded from 4308KB to 6144KB
20:19:02 Shared memory segment will use huge pages.
20:19:03 Segment locked: addr=0x44000000, size=6291456
Wed Dec 9 20:19:08 2015
20:19:08 Requested shared memory segment size rounded from 8789096KB to
8790016KB
20:19:08 Shared memory segment will use huge pages.
20:19:10 Segment locked: addr=0x1b7000000, size=9000976384
......... waiting 45 minutes here, then kill oninit .....................
only one oninit process running, consuming CPU time.
oninit -v output
oninit -vWarning: Parameter's user-configured value was adjusted. (ALARMPROGRAM)
Warning: Parameter's user-configured value was adjusted. (OPT_GOAL)
Warning: Parameter's user-configured value was adjusted. (DS_NONPDQ_QUERY_MEM)
Warning: Parameter's user-configured value was adjusted. (GSKIT_VERSION)
Reading configuration file
'/opt/informix/engines/ids_1210.FC5_EE64/etc/perfcounters.oncf'...succeeded
Creating /INFORMIXTMP/.infxdirs...succeeded
Allocating and attaching to shared memory...succeeded
Creating resident pool 30070 kbytes...succeeded
Creating infos file
"/opt/informix/engines/ids_1210.FC5_EE64/etc/.infos.perfcounters"...succeeded
Linking conf file
"/opt/informix/engines/ids_1210.FC5_EE64/etc/.conf.perfcounters"...succeeded
Initializing rhead structure...rhlock_t 65536 (2048K)... rlock_t (26562K)
.... stuck here for the same 45 mn
Any idea ?
Thanks
Eric
How much memory do you have configured on the virtual machine, and how much
memory does the real host have?
On Wed, Dec 9, 2015 at 10:21 PM, ERIC VERCELLETTO <
eric.vercelletto@begooden-it.com> wrote:
> Hi all,
>
> before I post a PMR:
> did anyone see an informix instance take 25mn to start ?
> 25 minutes was with 12.10FC4 on a linux/red hat VMWare (big server
> according
> to the vendors)
>
> With 12.10FC5W1, i had to wait 46 mn before deciding to kill oninit.
> I am using huge pages and RESIDENT=1
>
> I had a feeling that setting RESIDENT=0 could help, and it DID!
> Informix took 35 seconds to start without setting the first SHMEM segment
> as
> resident.
>
> Where is the explanation of such a phenomenon ?
>
> online.log:
> 20:19:02 Parameter's user-configured value was adjusted. (INFORMIXCONTIME)
> 20:19:02 Parameter's user-configured value was adjusted. (GSKIT_VERSION)
> 20:19:02 Parameter's user-configured value was adjusted.
> (DS_NONPDQ_QUERY_MEM)
> 20:19:02 IBM Informix Dynamic Server Started.
> 20:19:02 Requested shared memory segment size rounded from 4308KB to 6144KB
> 20:19:02 Shared memory segment will use huge pages.
> 20:19:03 Segment locked: addr=0x44000000, size=6291456
>
> Wed Dec 9 20:19:08 2015
>
> 20:19:08 Requested shared memory segment size rounded from 8789096KB to
> 8790016KB
> 20:19:08 Shared memory segment will use huge pages.
> 20:19:10 Segment locked: addr=0x1b7000000, size=9000976384
> .......... waiting 45 minutes here, then kill oninit .....................
>
> only one oninit process running, consuming CPU time.
>
> oninit -v output
> oninit -v> Warning: Parameter's user-configured value was adjusted. (ALARMPROGRAM)
> Warning: Parameter's user-configured value was adjusted. (OPT_GOAL)
> Warning: Parameter's user-configured value was adjusted.
> (DS_NONPDQ_QUERY_MEM)
> Warning: Parameter's user-configured value was adjusted. (GSKIT_VERSION)
> Reading configuration file
> '/opt/informix/engines/ids_1210.FC5_EE64/etc/perfcounters.oncf'...succeeded
> Creating /INFORMIXTMP/.infxdirs...succeeded
> Allocating and attaching to shared memory...succeeded
> Creating resident pool 30070 kbytes...succeeded
> Creating infos file
>
> "/opt/informix/engines/ids_1210.FC5_EE64/etc/.infos.perfcounters"...succeeded
> Linking conf file
>
> "/opt/informix/engines/ids_1210.FC5_EE64/etc/.conf.perfcounters"...succeeded
> Initializing rhead structure...rhlock_t 65536 (2048K)... rlock_t (26562K)
> ..... stuck here for the same 45 mn
>
> Any idea ?
>
> Thanks
> Eric
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
--047d7bdc15b2147dcc05267f22aa
How much memory in the real tin and does it exceed the sum of the memory
requirements of the images?
Cheers
Paul
Paul Watson
Oninit www.oninit.com
+1 913 387 7529
Oninit® is a Registered Trademark of Oninit LLC
> On Dec 9, 2015, at 16:21, ERIC VERCELLETTO
<eric.vercelletto@begooden-it.com> wrote:
>
> Hi all,
>
> before I post a PMR:
> did anyone see an informix instance take 25mn to start ?
> 25 minutes was with 12.10FC4 on a linux/red hat VMWare (big server according
> to the vendors)
>
> With 12.10FC5W1, i had to wait 46 mn before deciding to kill oninit.
> I am using huge pages and RESIDENT=1
>
> I had a feeling that setting RESIDENT=0 could help, and it DID!
> Informix took 35 seconds to start without setting the first SHMEM segment as
> resident.
>
> Where is the explanation of such a phenomenon ?
>
> online.log:
> 20:19:02 Parameter's user-configured value was adjusted. (INFORMIXCONTIME)
> 20:19:02 Parameter's user-configured value was adjusted. (GSKIT_VERSION)
> 20:19:02 Parameter's user-configured value was adjusted.
(DS_NONPDQ_QUERY_MEM)
> 20:19:02 IBM Informix Dynamic Server Started.
> 20:19:02 Requested shared memory segment size rounded from 4308KB to 6144KB
> 20:19:02 Shared memory segment will use huge pages.
> 20:19:03 Segment locked: addr=0x44000000, size=6291456
>
> Wed Dec 9 20:19:08 2015
>
> 20:19:08 Requested shared memory segment size rounded from 8789096KB to
> 8790016KB
> 20:19:08 Shared memory segment will use huge pages.
> 20:19:10 Segment locked: addr=0x1b7000000, size=9000976384
> .......... waiting 45 minutes here, then kill oninit .....................
>
> only one oninit process running, consuming CPU time.
>
> oninit -v output
> oninit -v> Warning: Parameter's user-configured value was adjusted. (ALARMPROGRAM)
> Warning: Parameter's user-configured value was adjusted. (OPT_GOAL)
> Warning: Parameter's user-configured value was adjusted.
(DS_NONPDQ_QUERY_MEM)
> Warning: Parameter's user-configured value was adjusted. (GSKIT_VERSION)
> Reading configuration file
> '/opt/informix/engines/ids_1210.FC5_EE64/etc/perfcounters.oncf'...succeeded
> Creating /INFORMIXTMP/.infxdirs...succeeded
> Allocating and attaching to shared memory...succeeded
> Creating resident pool 30070 kbytes...succeeded
> Creating infos file
> "/opt/informix/engines/ids_1210.FC5_EE64/etc/.infos.perfcounters"...succeeded
> Linking conf file
> "/opt/informix/engines/ids_1210.FC5_EE64/etc/.conf.perfcounters"...succeeded
> Initializing rhead structure...rhlock_t 65536 (2048K)... rlock_t (26562K)
> ..... stuck here for the same 45 mn
>
> Any idea ?
>
> Thanks
> Eric
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
A large rollback that was underway when the engine was last brought down???
Checkpoints too far apart??? Before thinking that there is a problem, check
what was going on when the server was last brought down.
Madison Pruet
Retired from IBM
On Wednesday, December 9, 2015 5:17 PM, ERIC VERCELLETTO
<eric.vercelletto@begooden-it.com> wrote:
Hi all,
before I post a PMR:
did anyone see an informix instance take 25mn to start ?
25 minutes was with 12.10FC4 on a linux/red hat VMWare (big server according
to the vendors)
With 12.10FC5W1, i had to wait 46 mn before deciding to kill oninit.
I am using huge pages and RESIDENT=1
I had a feeling that setting RESIDENT=0 could help, and it DID!
Informix took 35 seconds to start without setting the first SHMEM segment as
resident.
Where is the explanation of such a phenomenon ?
online.log:
20:19:02 Parameter's user-configured value was adjusted. (INFORMIXCONTIME)
20:19:02 Parameter's user-configured value was adjusted. (GSKIT_VERSION)
20:19:02 Parameter's user-configured value was adjusted. (DS_NONPDQ_QUERY_MEM)
20:19:02 IBM Informix Dynamic Server Started.
20:19:02 Requested shared memory segment size rounded from 4308KB to 6144KB
20:19:02 Shared memory segment will use huge pages.
20:19:03 Segment locked: addr=0x44000000, size=6291456
Wed Dec 9 20:19:08 2015
20:19:08 Requested shared memory segment size rounded from 8789096KB to
8790016KB
20:19:08 Shared memory segment will use huge pages.
20:19:10 Segment locked: addr=0x1b7000000, size=9000976384
.......... waiting 45 minutes here, then kill oninit .....................
only one oninit process running, consuming CPU time.
oninit -v output
oninit -vWarning: Parameter's user-configured value was adjusted. (ALARMPROGRAM)
Warning: Parameter's user-configured value was adjusted. (OPT_GOAL)
Warning: Parameter's user-configured value was adjusted. (DS_NONPDQ_QUERY_MEM)
Warning: Parameter's user-configured value was adjusted. (GSKIT_VERSION)
Reading configuration file
'/opt/informix/engines/ids_1210.FC5_EE64/etc/perfcounters.oncf'...succeeded
Creating /INFORMIXTMP/.infxdirs...succeeded
Allocating and attaching to shared memory...succeeded
Creating resident pool 30070 kbytes...succeeded
Creating infos file
"/opt/informix/engines/ids_1210.FC5_EE64/etc/.infos.perfcounters"...succeeded
Linking conf file
"/opt/informix/engines/ids_1210.FC5_EE64/etc/.conf.perfcounters"...succeeded
Initializing rhead structure...rhlock_t 65536 (2048K)... rlock_t (26562K)
..... stuck here for the same 45 mn
Any idea ?
Thanks
Eric
*******************************************************************************
Forum Note: Use "Reply" to post a response in the discussion forum.
Folks, this is a VMWare ESX 5. (I'll have to check) Box has 32 Gb configured I have a 2K bufferfool of 8 Gb and initial shmvirtsize of 6 Gbb (I know, it's huge but some applications pull hard on shmvirt). There was effectively some transactions are shudown, but only 4 pages Physical Recovery Started at Page (17:2892064). 2015-12-09 21:12:32 Physical Recovery Complete: 4 Pages Examined, 4 Pages Restored. 2015-12-09 21:12:33 Logical Recovery Started. 2015-12-09 21:12:33 12 recovery worker threads will be started. 2015-12-09 21:12:34 Logical Recovery has reached the transaction cleanup phase. 2015-12-09 21:12:34 Logical Recovery Complete. 2015-12-09 21:12:34 0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks 2015-12-09 21:12:36 Onconfig parameter RESIDENT modified from 1 to 0. When I changed RESIDENT to 0, the instance started in less than one minute, against 45minutes that I had to stop... I did the same operation with same parameters on a phys box in my lab, and it started in 25 secs. ( including huge pages )
How much memory is configured for that VM and are there any others VMs running? I'm wondering if it is swapping?... On Dec 10, 2015 5:52 AM, "ERIC VERCELLETTO" < eric.vercelletto@begooden-it.com> wrote: > Folks, > > this is a VMWare ESX 5. (I'll have to check) > Box has 32 Gb configured > > I have a 2K bufferfool of 8 Gb and initial shmvirtsize of 6 Gbb (I know, > it's > huge but some applications pull hard on shmvirt). > There was effectively some transactions are shudown, but only 4 pages > Physical Recovery Started at Page (17:2892064). > 2015-12-09 21:12:32 Physical Recovery Complete: 4 Pages Examined, 4 Pages > Restored. > 2015-12-09 21:12:33 Logical Recovery Started. > 2015-12-09 21:12:33 12 recovery worker threads will be started. > 2015-12-09 21:12:34 Logical Recovery has reached the transaction cleanup > phase. > 2015-12-09 21:12:34 Logical Recovery Complete. > 2015-12-09 21:12:34 0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks > 2015-12-09 21:12:36 Onconfig parameter RESIDENT modified from 1 to 0. > > When I changed RESIDENT to 0, the instance started in less than one minute, > against 45minutes that I had to stop... > I did the same operation with same parameters on a phys box in my lab, and > it > started in 25 secs. ( including huge pages ) > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a113fe51ead4ba10526861460
all insisting with the VMWare guys to check what they said, we found out that there a VM pool for informix that was limited to 12Gb of RAM, although Informix had 24 Gb allocated in all SHMEM segments. The VM has been permanently swapping for 3 months, although customers alarms didnt say anything, explaining the bad performance level we observed. Decision has been taken to remove this RAM allocation limitation at the VMWare level, and also reserve more CPU for the Informix VM. In fact 60 other VMs are competing with the Informix one, this was also have to be addressed at the VMWare level. SO issue explained, will be resolved tomorrow :-) Lesson to learn: never believe someone oddly remaining silent or saying "everythin ok" wothout checking... Thanks all Eric