Alexandre, thanks for your reply.
I have do a full update statistics after migration, dbimport do that for
me. And I do an update statistics this morning.
I add more cpu's vps. Now I have 7. I have KAIO support. I also add a
BTSCANNER and change alice mode to 11. After restart of informix now i
have 80% of cpu in Waiting.
As I read in Informix information center, with KAIO, my cpu vps are used
for IO. Maybe that's why I have 80% of my cpu in waiting state.
I open a ticket in informix support, so I keep you updated with what
they say.
Thanks again and Regards
Alexandre Marini escribió:
> Mr. Romero,
> 1) It is always recommended doing a full update statistics after a
> version migration. Did you do it?
> 2) If you new machine has 8 cores (2 quad cores), you could optimize
> your cpu´s vps
> 3) are you using KAIO modes to improve the IO transfers ???
> 4) After all above, check on manuals how to optimize the b-tree index
> scanning (alice mode is great!!!!)
>
> Regards.
>
> Alexandre Marini
>
> Tecnologia da Informação - DBA
>
> SEFAZ-MS / SGI-UIMP / Sistemas IBM-Informix
>
> IIUG Member
>
> <http://www.iiug.org>
>
> Emiliano Romero escreveu:
>
>> Hi list,
>>
>> First sorry about my english,
>>
>> I have migrate my informix server from 10.0 to 11.5FC5 and also migrate
>> hardware. I move to a new 2xQuad Xeon+4x150 Gb Disk 10000RPM+8Gb of Ram.
>> In tests it seems to be a much faster, but when i go to my production
>> enviroment I see some Queries taking too much to be resolved.
>>
>> My plataform is Linux.
>>
>> Syntoms when I execute theses queries:
>> 1) Like 35% of CPU in Waiting (I/O)
>> 2) Status of session changing between "IO WAIT" and "yield bufwait-"
>>
>> Example of query:
>> Explain out:
>> QUERY: (OPTIMIZATION TIMESTAMP: 09-14-2009 15:27:32)
>> ------
>> SELECT posicion.fechaposicion as fechaposicion , posicion.holderid as^M
>>
>> holderid , posicion.eventoid as eventoid , holder.dominio as
>> dominio ^M
>>
>> FROM posicion INNER JOIN holder ON
>> (holder.holderid=posicion.holderid) ^M
>>
>> WHERE ( posicion.holderid in^M
>>
>>
>>
>>
> (14273,14440,14448,14274,14442,15171,14275,14271,14443,14253,13045,14278,14292,14279,14250,13044,13011,13002,14306,14305,14291)
>
>> ) AND (^M
>>
>> posicion.eventoid in (7, 6, 4) ) AND ( posicion.fechaposicion >=^M
>>
>> '2009-09-08 04:00:00' ) AND ( posicion.fechaposicion <= '2009-09-14
>> 03:59:00' ) ORDER BY fechaposicion
>>
>> Estimated Cost: 87861
>> Estimated # of Rows Returned: 9117
>> Temporary Files Required For: Order By
>>
>> 1) informix.holder: INDEX PATH
>>
>> (1) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14273
>>
>> (2) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14440
>>
>> (3) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14448
>>
>> (4) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14274
>>
>> (5) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14442
>>
>> (6) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 15171
>>
>> (7) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14275
>>
>> (8) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> (9) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14443
>>
>> (10) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14253
>>
>> (11) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 13045
>>
>> (12) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14278
>>
>> (13) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14292
>>
>> (14) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14279
>>
>> (15) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14250
>>
>> (16) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 13044
>>
>> (17) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 13011
>>
>> (18) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 13002
>>
>> (19) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14306
>>
>> (20) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14305
>>
>> (21) Index Name: root. 216_289
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid = 14291
>>
>> 2) informix.posicion: INDEX PATH
>>
>> Filters: ((informix.posicion.fechaposicion >=
>> datetime(2009-09-08 04:00:00) year to second AND
>> informix.posicion.eventoid IN (7 , 6 , 4 )) AND
>> informix.posicion.fechaposicion <= datetime(2009-09-14 03:59:00) year to
>> second )
>>
>> (1) Index Name: root. 100_909
>>
>> Index Keys: holderid (Serial, fragments: ALL)
>>
>> Lower Index Filter: informix.holder.holderid =
>> informix.posicion.holderid
>> NESTED LOOP JOIN
>>
>> Query statistics:
>> -----------------
>>
>> Table map :
>> ----------------------------
>> Internal name Table name
>> ----------------------------
>> t1 holder
>> t2 posicion
>>
>> type table rows_prod est_rows rows_scan time est_cost
>> -------------------------------------------------------------------
>> scan t1 21 21 21 00:00.00 5
>>
>> type table rows_prod est_rows rows_scan time est_cost
>> -------------------------------------------------------------------
>> scan t2 49511 9117 844729 06:31.26 4006
>>
>> type rows_prod est_rows time est_cost
>> -------------------------------------------------
>> nljoin 49511 9118 06:31.27 87861
>>
>> type rows_sort est_rows rows_cons time
>> -------------------------------------------------
>> sort 49511 9118 49511 06:32.55
>>
>> # onstat -g ses 5382
>>
>> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up
>> 01:39:11 -- 6651320 Kbytes
>>
>> session effective #RSAM
>> total used dynamic
>> id user user tty pid hostname threads
>> memory memory explain
>> 5382 informix - reflex 8 Emiliano 1
>> 253952 225008 off
>>
>> tid name rstcb flags curstk status
>> 5532 sqlexec 19ee4ebd8 ---PR-- 13488 *IO Wait-*
>>
>> Memory pools count 3
>> name class addr totalsize freesize #allocfrag
>> #freefrag
>> 5382 V 1a027b040 167936 17168 240
>> 16
>> 5382*O0 V 1a1131040 4096 808 1
>> 1
>> 5382_SORT_0 V 1a23e8040 81920 10968 19
>> 3
>>
>> name free used name free
>> used
>> overhead 0 9864 scb 0
>> 144
>> opentable 0 8096 filetable 0
>> 2240
>> ru 0 600 log 0
>> 16536
>> temprec 0 2320 keys 0
>> 216
>> ralloc 0 74160 gentcb 0
>> 1584
>> ostcb 0 2920 sort 0
>> 67488
>> sqscb 0 21736 sql 0
>> 72
>> srtmembuf 0 200 rdahead 0
>> 1120
>> hashfiletab 0 552 osenv 0
>> 2072
>> sqtcb 0 8528 fragman 0
>> 3640
>> shmblklist 0 776 sapi 0
>> 64
>>
>> sqscb info
>> scb sqscb optofc pdqpriority sqlstats
>> optcompind directives
>> 1a15dd028 19f728028 0 0 0
>> 2 1
>>
>> Sess SQL Current Iso Lock SQL ISAM F.E.
>> Id Stmt type Database Lvl Mode ERR ERR
>> Vers Explain
>> 5382 SELECT db3g CR Not Wait 0 0
>> 9.29 On
>>
>> Current statement name : _ixceb
>>
>> #onstat -g ses 5382
>> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up
>> 01:39:20 -- 6651320 Kbytes
>>
>> session effective #RSAM
>> total used dynamic
>> id user user tty pid hostname threads
>> memory memory explain
>> 5382 informix - reflex 8 Emiliano 1
>> 253952 225008 off
>>
>> tid name rstcb flags curstk status
>> 5532 sqlexec 19ee4ebd8 B--PR-- 12432 *yield bufwait-*
>>
>> Memory pools count 3
>> name class addr totalsize freesize #allocfrag
>> #freefrag
>> 5382 V 1a027b040 167936 17168 240
>> 16
>> 5382*O0 V 1a1131040 4096 808 1
>> 1
>> 5382_SORT_0 V 1a23e8040 81920 10968 19
>> 3
>>
>> name free used name free
>> used
>> overhead 0 9864 scb 0
>> 144
>> opentable 0 8096 filetable 0
>> 2240
>> ru 0 600 log 0
>> 16536
>> temprec 0 2320 keys 0
>> 216
>> ralloc 0 74160 gentcb 0
>> 1584
>> ostcb 0 2920 sort 0
>> 67488
>> sqscb 0 21736 sql 0
>> 72
>> srtmembuf 0 200 rdahead 0
>> 1120
>> hashfiletab 0 552 osenv 0
>> 2072
>> sqtcb 0 8528 fragman 0
>> 3640
>> shmblklist 0 776 sapi 0
>> 64
>>
>> sqscb info
>> scb sqscb optofc pdqpriority sqlstats
>> optcompind directives
>> 1a15dd028 19f728028 0 0 0
>> 2 1
>>
>> Sess SQL Current Iso Lock SQL ISAM F.E.
>> Id Stmt type Database Lvl Mode ERR ERR
>> Vers Explain
>> 5382 SELECT db3g CR Not Wait 0 0
>> 9.29 On
>>
>> Current statement name : _ixceb
>>
>> # onstat -g iof
>> gfd pathname bytes read page reads bytes write page
>> writes io/s
>> 3 rootdbs 1521664 743 751740928
>> 367061 79.1
>>
>> op type count avg. time
>>
>> seeks 0 N/A
>>
>> reads 0 N/A
>>
>> writes 0 N/A
>>
>> kaio_reads 464 0.0106
>>
>> kaio_writes 238035 0.0126
>>
>> 4 tempdbs1 510468096 249252 541411328
>> 264361 108.7
>>
>> op type count avg. time
>>
>> seeks 0 N/A
>>
>> reads 0 N/A
>>
>> writes 0 N/A
>>
>> kaio_reads 10944 0.0091
>>
>> kaio_writes 15505 0.0093
>>
>> 5 tempdbs2 510189568 249116 534435840
>> 260955 73.7
>>
>> op type count avg. time
>>
>> seeks 0 N/A
>>
>> reads 0 N/A
>>
>> writes 0 N/A
>>
>> kaio_reads 11252 0.0143
>>
>> kaio_writes 15417 0.0130
>>
>> 6 datadbs 5195923456 2537072 291811328
>> 142486 71.0
>>
>> op type count avg. time
>>
>> seeks 0 N/A
>>
>> reads 0 N/A
>>
>> writes 0 N/A
>>
>> kaio_reads 2006322 0.0136
>>
>> kaio_writes 103883 0.0227
>>
>> online.log:
>> 13:48:38 IBM Informix Dynamic Server Started.
>>
>> Mon Sep 14 13:48:39 2009
>>
>> 13:48:39 pid 31174: can't get real path of
>> 13:48:40 Event alarms enabled. ALARMPROG =
>> '/opt/informix/etc/alarmprogram.sh'
>> 13:48:40 Booting Language <c> from module <>
>> 13:48:40 Loading Module <CNULL>
>> 13:48:40 Booting Language <builtin> from module <>
>> 13:48:40 Loading Module <BUILTINNULL>
>> 13:48:40 Affinitied VP 1 to phys proc 1
>> 13:48:40 Affinitied VP 3 to phys proc 2
>> 13:48:40 Affinitied VP 4 to phys proc 3
>> 13:48:45 DR: DRAUTO is 0 (Off)
>> 13:48:45 DR: ENCRYPT_HDR is 0 (HDR encryption Disabled)
>> 13:48:45 Event notification facility epoll enabled.
>> 13:48:47 IBM Informix Dynamic Server Version 11.50.FC5 Software
>> Serial Number AAA#B000000
>> 13:48:49 IBM Informix Dynamic Server Initialized -- Shared Memory
>> Initialized.
>>
>> 13:48:49 Started 1 B-tree scanners.
>> 13:48:49 B-tree scanner threshold set at 5000.
>> 13:48:49 B-tree scanner range scan size set to -1.
>> 13:48:49 B-tree scanner ALICE mode set to 6.
>> 13:48:49 B-tree scanner index compression level set to med.
>> 13:48:49 Physical Recovery Started at Page (1:1207439).
>> 13:48:49 Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored.
>> 13:48:49 Logical Recovery Started.
>> 13:48:49 10 recovery worker threads will be started.
>> 13:48:50 Logical Recovery has reached the transaction cleanup phase.
>> 13:48:50 Logical Recovery Complete.
>>
>> 0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks
>> 13:48:51 Onconfig parameter PHYSFILE modified from 2500000 to 20000.
>> 13:48:51 Onconfig parameter LOGFILES modified from 58 to 12.
>> 13:48:51 Dataskip is now OFF for all dbspaces
>> 13:48:52 Checkpoint Completed: duration was 1 seconds.
>> 13:48:52 Mon Sep 14 - loguniq 45, logpos 0x5507018, timestamp:
>> 0x89c892e1 Interval: 1321
>>
>> 13:48:52 Maximum server connections 0
>> 13:48:52 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns
>> blocked 0, Plog used 2, Llog used 1
>>
>> 13:48:52 On-Line Mode
>> 13:48:53 SCHAPI: Started dbScheduler thread.
>> 13:48:53 Booting Language <spl> from module <>
>> 13:48:53 Loading Module <SPLNULL>
>> 13:48:53 SCHAPI: Started 2 dbWorker threads.
>> 13:49:26 Loading Module </opt/informix/lib/libcubi.so>
>> 13:49:26 pid 31177: can't get real path of
>> 13:49:26 The C Language Module </opt/informix/lib/libcubi.so> loaded
>> 13:49:58 Loading Module </opt/informix/lib/libcheckzona.so>
>> 13:49:58 pid 31174: can't get real path of
>> 13:49:58 The C Language Module </opt/informix/lib/libcheckzona.so> loaded
>> 13:53:55 Explain file for session 5382 : /home/informix/sqexplain.out
>> 13:54:00 Checkpoint Completed: duration was 9 seconds.
>> 13:54:00 Mon Sep 14 - loguniq 45, logpos 0x8489018, timestamp:
>> 0x89cd46e1 Interval: 1322
>>
>> 13:54:00 Maximum server connections 65
>> 13:54:00 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns
>> blocked 1, Plog used 6439, Llog used 12265
>>
>> 13:59:15 Checkpoint Completed: duration was 13 seconds.
>> 13:59:15 Mon Sep 14 - loguniq 45, logpos 0xae6d018, timestamp:
>> 0x89d3045e Interval: 1323
>>
>> 13:59:15 Maximum server connections 65
>> 13:59:15 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns
>> blocked 2, Plog used 5533, Llog used 11095
>>
>> 14:01:13 Logical Log 45 Complete, timestamp: 0x89d4ddc9.
>> 14:01:14 Process exited with return code 126: /bin/sh /bin/sh -c
>> /opt/informix/etc/alarmprogram.sh 2 23 "" "Logical Log 45 Complete,
>> timestamp: 0x89d4ddc9." ""
>> 14:04:30 Checkpoint Completed: duration was 14 seconds.
>> 14:04:30 Mon Sep 14 - loguniq 46, logpos 0x1ed3018, timestamp:
>> 0x89d7be90 Interval: 1324
>>
>> 14:04:30 Maximum server connections 65
>> 14:04:30 Checkpoint Statistics - Avg. Txn Block Time 0.065, # Txns
>> blocked 5, Plog used 6429, Llog used 13539
>>
>> I upload my onconfig file to: http://pastebin.com/f1295b23d
>>
>> Any idea of how could I tune that times? In my another instance of
>> Informix 10.0 with older hardware that queries works much better.
>>
>> Regards and thanks for any help.
>>
>> Emiliano Romero
>>
>> This email and any attachments thereof may contain confidential, privileged,
>> proprietary, or otherwise private information. This email is intended solely
>> for the use of the individual to whom it is addressed. If you are not the
>> intended recipient of the email and its attachments please inform the sender
>> immediately and do not disclose the contents to any other person, use it for
>> any purpose or store or copy the information in any way and delete this
>>
> e-mail
>
>> and its attachments from your system. Any views or opinions expressed are
>> solely those of the author.
>>
>>
>>
>>
> *******************************************************************************
>
>> Forum Note: Use "Reply" to post a response in the discussion forum.
>>
>>
>>
>>
>>
>
>
> *******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
>
This email and any attachments thereof may contain confidential, privileged, proprietary, or otherwise private information. This email is intended solely for the use of the individual to whom it is addressed. If you are not the intended recipient of the email and its attachments please inform the sender immediately and do not disclose the contents to any other person, use it for any purpose or store or copy the information in any way and delete this e-mail and its attachments from your system. Any views or opinions expressed are solely those of the author.
