IDS Forum

Re: Insert into an indexed table is really SLOW!

Posted By: Art Kagel
Date: Tuesday, 7 July 2009, at 1:42 p.m.

In Response To: Insert into an indexed table is really SLOW! (MIKE DUNHAM-WILKIE)

I think that you have two problems:

1. Asking the engine to do the index IO at the same time as the table

data IO all to the different sections of the same single spindle is just

impractical.

2. You only have 1000 buffers configures so the engine is constantly

having to write those pages to disk and wait for the IOs to complete.

Suggestions? Obviously I think you need additional spindles, but that
aside, add more buffers, many more buffers. You have 6 million rows to load
at 240 bytes each so the data will require almost 3000 pages plus the
indexes so if you make the cache 4000 pages you may get the entire load into
memory at the same time. Honestly though, even 4000 cache pages is small,
that's not much of a live working set. The machine has 2GB of memory with
over 50MB free. IDS is currently using only 38MB of memory. If you
increase the buffer cache from 1000 pages to 10000 pages you will add only
20MB to the server's memory footprint and all of your operations will be
faster and smoother.

Another thing, are you using COOKED (filesystem) chunks or RAW? If
filesystem chunks then you should enable DIRECT_IO (which is currently
disabled in the ONCONFIG file) so that the engine can use KAIO threads for
IO instead of AIO VPs. KAIO is faster and more efficient in system
resources used. Also, if filesystem chunks what kind of filesystem? EXT4
is VERY BAD for database chunks and EXT3 isn't much better. If you want to
maximize your IO performance you should put the chunks in RAW space, or use
a COOKED (block) device rather than a filesystem, or at least put them in a
non-journaled filesystem like EXT2.

FYI: Linus Torvalds says that EXT4 (and EXT3 with write-back enabled) is not
safe, database performance issues aside!

Art

Art S. Kagel
Oninit (www.oninit.com)
IIUG Board of Directors (art@iiug.org)

Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Oninit, the IIUG, nor any other organization
with which I am associated either explicitly or implicitly. 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, Jul 7, 2009 at 1:06 PM, MIKE DUNHAM-WILKIE <mike@barrodale.com>wrote:

> I am running into performance problems inserting into an indexed table,
> using
> Informix 11.50. The following timings for loading into
> compressed/uncompressed, indexed/non-indexed tables using dbload/HPL-Deluxe
> more illustrate the problem. The number of rows inserted is 6 million.
>
> compressed/indexed/DBLoad or HPL/h:mm:ss.d
> Y/Y/DBLoad/3:47:39.9
> Y/N/DBLoad/0:10:58.1
> N/Y/DBLoad/3:31:13.4
> N/N/DBLoad/0:22:46.6
> Y/Y/HPL/3:26:17.6
> Y/N/HPL/0:08:31.7
> N/Y/HPL/3:28:16.1
> N/N/HPL/0:18:45.7
>
> Why are the inserts into the indexed tables so much slower? I would expect
> some performance hit of course, but not this much. I want the indexes left
> intact during the load, hence my use of HPL in Deluxe mode rather than
> Express
> mode.
>
> I'm using pretty much "out of the box" configuration parameters:
>
> ------------------------------------------------------------------------
> onstat -c:
>
> IBM Informix Dynamic Server Version 11.50.UC4 -- On-Line -- Up 4 days
> 17:59:
> 49 -- 38212 Kbytes
> Configuration File:
> /opt/informix/informix.11.50_UC4/etc/onconfig.bcslinuxprod
> ROOTNAME rootdbs
> ROOTOFFSET 0
> MIRROR 0
> MIRRORPATH /opt/IBM/informix/tmp/demo_on.root_mirror
> MIRROROFFSET 0
> PHYSFILE 200000
> PLOG_OVERFLOW_PATH /opt/IBM/informix/tmp
> PHYSBUFF 128
> LOGFILES 49
> LOGSIZE 10000
> DYNAMIC_LOGS 2
> LOGBUFF 64
> LTXHWM 70
> LTXEHWM 80
> CONSOLE /work1/stat/bcslinuxprod_console.log
> TBLTBLFIRST 0
> TBLTBLNEXT 0
> TBLSPACE_STATS 1
> DBSPACETEMP temp1db
> SBSPACETEMP temp1sb
> SBSPACENAME temp1sb
> SYSSBSPACENAME temp1sbifmx
> ONDBSPACEDOWN 2
> NETTYPE ipcshm,1,50,CPU
> LISTEN_TIMEOUT 60
> MAX_INCOMPLETE_CONNECTIONS 1024
> FASTPOLL 1
> MULTIPROCESSOR 0
> VP_MEMORY_CACHE_KB 0
> SINGLE_CPU_VP 0
> CLEANERS 8
> AUTO_AIOVPS 1
> DIRECT_IO 0
> LOCKS 20000
> DEF_TABLE_LOCKMODE page
> RESIDENT 0
> SHMBASE 0x44000000L
> SHMVIRTSIZE 32656
> SHMADD 8192
> EXTSHMADD 8192
> SHMTOTAL 0
> SHMVIRT_ALLOCSEG 0,3
> SHMNOACCESS
> CKPTINTVL 300
> AUTO_CKPTS 1
> RTO_SERVER_RESTART 0
> BLOCKTIMEOUT 3600
> TXTIMEOUT 300
> DEADLOCK_TIMEOUT 60
> HETERO_COMMIT 0
> TAPEBLK 32
> TAPESIZE 0
> LTAPEBLK 32
> LTAPESIZE 0
> BAR_DEBUG 0
> BAR_MAX_BACKUP 0
> BAR_RETRY 1
> BAR_NB_XPORT_COUNT 20
> BAR_XFER_BUF_SIZE 31
> RESTARTABLE_RESTORE ON
> BAR_PROGRESS_FREQ 0
> BAR_BSALIB_PATH
> BACKUP_FILTER
> RESTORE_FILTER
> BAR_PERFORMANCE 0
> ISM_DATA_POOL ISMData
> ISM_LOG_POOL ISMLogs
> DD_HASHSIZE 31
> DD_HASHMAX 10
> DS_HASHSIZE 31
> DS_POOLSIZE 127
> PC_HASHSIZE 31
> PC_POOLSIZE 127
> STMT_CACHE 0
> STMT_CACHE_HITS 0
> STMT_CACHE_SIZE 512
> STMT_CACHE_NOLIMIT 0
> STMT_CACHE_NUMPOOL 1
> USEOSTIME 0
> STACKSIZE 32
> ALLOW_NEWLINE 0
> USELASTCOMMITTED NONE
> FILLFACTOR 90
> MAX_FILL_DATA_PAGES 0
> ONLIDX_MAXMEM 5120
> MAX_PDQPRIORITY 100
> DS_MAX_QUERIES
> DS_TOTAL_MEMORY
> DS_MAX_SCANS 1048576
> DS_NONPDQ_QUERY_MEM 128
> DATASKIP
> OPTCOMPIND 2
> DIRECTIVES 1
> EXT_DIRECTIVES 0
> OPT_GOAL -1
> IFX_FOLDVIEW 0
> AUTO_REPREPARE 1
> RA_PAGES 64
> RA_THRESHOLD 16
> EXPLAIN_STAT 0
> IFX_EXTEND_ROLE 0
> SECURITY_LOCALCONNECTION
> UNSECURE_ONSTAT
> ADMIN_USER_MODE_WITH_DBSA
> ADMIN_MODE_USERS
> SSL_KEYSTORE_LABEL
> PLCY_POOLSIZE 127
> PLCY_HASHSIZE 31
> USRC_POOLSIZE 127
> USRC_HASHSIZE 31
> STAGEBLOB
> OPCACHEMAX 0
> ENCRYPT_HDR
> ENCRYPT_SMX
> ENCRYPT_CDR 0
> ENCRYPT_CIPHERS
> ENCRYPT_MAC
> ENCRYPT_MACFILE
> ENCRYPT_SWITCH
> CDR_EVALTHREADS 1,2
> CDR_DSLOCKWAIT 5
> CDR_QUEUEMEM 4096
> CDR_NIFCOMPRESS 0
> CDR_SERIAL 0
> CDR_DBSPACE
> CDR_QHDR_DBSPACE
> CDR_QDATA_SBSPACE
> CDR_MAX_DYNAMIC_LOGS 0
> CDR_SUPPRESS_ATSRISWARN
> DRAUTO 0
> DRINTERVAL 30
> DRTIMEOUT 30
> HA_ALIAS
> DRIDXAUTO 0
> LOG_INDEX_BUILDS
> SDS_ENABLE
> SDS_TIMEOUT 20
> SDS_TEMPDBS
> SDS_PAGING
> REDIRECTED_WRITES 0
> FAILOVER_CALLBACK
> TEMPTAB_NOLOG 0
> ON_RECVRY_THREADS 1
> OFF_RECVRY_THREADS 10
> DUMPSHMEM 1
> DUMPGCORE 0
> DUMPCORE 0
> DUMPCNT 1
> ALRM_ALL_EVENTS 0
> STORAGE_FULL_ALARM 600,3
> RAS_PLOG_SPEED 14900
> RAS_LLOG_SPEED 742
> EILSEQ_COMPAT_MODE 0
> QSTATS 0
> WSTATS 0
> JVPJAVALIB /bin
> JVPJAVAVM jvm
> AUTO_LRU_TUNING 1
> ROOTPATH /opt/IBM/informix/demo/server/online_root
> MSGPATH /work1/stat/bcslinuxprod_online.log
> TAPEDEV /dev/null
> LTAPEDEV /dev/null
> DBSERVERNAME bcslinuxprod
> DBSERVERALIASES
> SERVERNUM 0
> ALARMPROGRAM /opt/IBM/informix/etc/alarmprogram.sh
> DRLOSTFOUND /opt/IBM/informix/etc/dr.lostfound
> BAR_ACT_LOG /work1/stat/bar_act.log
> BAR_DEBUG_LOG /work1/stat/bar_debug.log
> SYSALARMPROGRAM /opt/IBM/informix/etc/evidence.sh
> DUMPDIR /work1/stat
> JVPJAVAHOME /opt/IBM/informix/extend/krakatoa/jre
> JVPHOME /opt/IBM/informix/extend/krakatoa/
> JVPPROPFILE /opt/IBM/informix/extend/krakatoa/.jvpprops
> JVPLOGFILE /opt/IBM/informix/demo/server/jvp.log
> JVPCLASSPATH
> /opt/IBM/informix/extend/krakatoa/krakatoa.jar:/opt/IBM/informix/ex
> tend/krakatoa/jdbc.jar
> ROOTSIZE 200000
> BUFFERPOOL size=2K,buffers=1000,lrus=8,lru_min_dirty=50.000000,lru_max_dirt
> y=60.000000
> VPCLASS cpu,num=1,noage
> BTSCANNER num=1,threshold=5000,rangesize=-1,alice=6
> UPDATABLE_SECONDARY 0
> --------------------------------------------------------------------
>
> Here is my table definition:
>
> --------------------------------------------------------------------
> create table "mdwilkie".noaa_sst_conventional_hpl_comp_24000000
> (
>
> type_of_observation integer,
>
> source_of_observation integer,
>
> dt datetime year to second,
>
> latitude float,
>
> longitude float,
>
> sst float,
>
> reliability integer,
>
> solar_zenith_angle float,
>
> satellite_zenith_angle float,
>
> analyzed_field_sst float,
>
> internal_error float,
>
> solar_azimuth_angle float,
>
> climatological_sst float,
>
> beginning_row integer,
>
> beginning_column integer,
>
> avhrr_ch_1_average float,
>
> avhrr_ch_2_average float,
>
> avhrr_ch_3_average float,
>
> avhrr_ch_4_average float,
>
> avhrr_ch_5_average float,
>
> space_view_ch_1 float,
>
> space_view_ch_2 float,
>
> space_view_ch_3 float,
>
> ch_4_blackbody_temperature float,
>
> ch_5_blackbody_temperature float,
>
> year_of_observation integer
> ) extent size 16 next size 16 lock mode page;
>
> start violations table for
> "mdwilkie".noaa_sst_conventional_hpl_comp_24000000
>
> using noaa_sst_conventional_hpl_comp_24000000_vio,
> noaa_sst_conventional_hpl_comp_24000000_dia;
>
> create index "mdwilkie".noaa_sst_conventional_hpl_comp_24000000_dt_idx
>
> on "mdwilkie".noaa_sst_conventional_hpl_comp_24000000 (dt)
>
> using btree in miscdbind;
> create index
> "mdwilkie".noaa_sst_conventional_hpl_comp_24000000_latitude_idx
>
> on "mdwilkie".noaa_sst_conventional_hpl_comp_24000000 (latitude)
>
> using btree in miscdbind;
> create index
> "mdwilkie".noaa_sst_conventional_hpl_comp_24000000_longitude_idx
>
> on "mdwilkie".noaa_sst_conventional_hpl_comp_24000000 (longitude)
>
> using btree in miscdbind;
>
>
> --------------------------------------------------------------------------------
>
> Note that my default dbspace (miscdbtab) is different from my index dbspace
> (miscdbind), but both are stored on the same disk (the only disk on my
> linux
> box). Also I'm using just 1 CPU.
>
> Here are the last few lines from the log file:
>
>
> -----------------------------------------------------------------------------
> 09:41:42 Maximum server connections 4
> 09:41:42 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked
> 1,
> Plog used 26253, Llog used 7
>
> 09:42:56 Checkpoint Completed: duration was 2 seconds.
> 09:42:56 Tue Jul 7 - loguniq 1610, logpos 0x26466a4, timestamp: 0x7c24d7c1
> Interval: 12113
>
> 09:42:56 Maximum server connections 5
> 09:42:56 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked
> 2,
> Plog used 26253, Llog used 7
>
> 09:44:09 Checkpoint Completed: duration was 3 seconds.
> 09:44:09 Tue Jul 7 - loguniq 1610, logpos 0x264e4b0, timestamp: 0x7c2697f5
> Interval: 12114
>
> 09:44:09 Maximum server connections 5
> 09:44:09 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked
> 1,
> Plog used 26253, Llog used 8
>
> 09:45:34 Checkpoint Completed: duration was 0 seconds.
> 09:45:34 Tue Jul 7 - loguniq 1610, logpos 0x2655560, timestamp: 0x7c285148
> Interval: 12115
>
> 09:45:34 Maximum server connections 5
> 09:45:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked
> 1,
> Plog used 26253, Llog used 7
>
> -----------------------------------------------------------------------
> My linux box has the following description:
>
> CPU: Intel Pentium D, 3.0 GHz, 2MB Cache, 32 bit
> RAM: 2 GB
> OS: Fedora Core 7
>
> Here are the first few lines of output from "top":
>
> -----------------------------------------------------------------------
> top - 09:50:39 up 11 days, 23:10, 12 users, load average: 21.83, 21.41,
> 21.35
> Tasks: 230 total, 1 running, 229 sleeping, 0 stopped, 0 zombie
> Cpu(s): 2.8%us, 2.3%sy, 0.0%ni, 40.5%id, 54.2%wa, 0.0%hi, 0.2%si, 0.0%st
> Mem: 2066880k total, 2015236k used, 51644k free, 14972k buffers
> Swap: 2031608k total, 196k used, 2031412k free, 1559480k cached
>
> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
> 3982 informix 5 -10 59888 45m 43m S 5 2.2 39:00.35 oninit
> 3996 root 6 -10 59868 6464 5124 D 1 0.3 1:21.52 oninit
> 9939 informix 15 0 2340 1088 788 R 1 0.1 0:00.06 top
> 3988 root 6 -10 59876 7440 6096 D 0 0.4 1:49.16 oninit
> 3991 root 6 -10 59876 6916 5572 D 0 0.3 1:38.22 oninit
> 3992 root 6 -10 59876 6680 5336 D 0 0.3 1:33.69 oninit
> 3994 root 5 -10 59868 6508 5168 D 0 0.3 1:26.88 oninit
> 3995 root 5 -10 59876 6772 5428 D 0 0.3 1:24.17 oninit
> 3997 root 6 -10 59868 6276 4936 D 0 0.3 1:18.85 oninit
> 4001 root 5 -10 59868 6312 4972 D 0 0.3 1:10.82 oninit
> 4003 root 5 -10 59876 6388 5044 D 0 0.3 1:08.10 oninit
> 4004 root 6 -10 59868 6048 4708 D 0 0.3 1:06.35 oninit
> 4006 root 6 -10 59876 6356 5012 D 0 0.3 1:03.41 oninit
> 4007 root 6 -10 59868 6320 4980 D 0 0.3 1:01.70 oninit
> ------------------------------------------------------------------------
>
> The machine appears to be heavily I/O bound.
>
> I don't have the option of splitting table and index onto different disks,
> disabling the index during the load, or adding more CPU's (I'm not sure if
> this would make a difference anyway). Do I have any other options? Are
> there
> some specific configuration parameters that I should try adjusting?
>
> Many thanks,
>
> Mike
>
>
>
> *******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>

--001636c5b496ad4e28046e2125c3

Messages In This Thread

• Insert into an indexed table is really SLOW!
  MIKE DUNHAM-WILKIE -- Tuesday, 7 July 2009, at 1:06 p.m.
  • Re: Insert into an indexed table is really SLOW!
    Obnoxio The Clown -- Tuesday, 7 July 2009, at 1:32 p.m.
  • Re: Insert into an indexed table is really SLOW!
    Art Kagel -- Tuesday, 7 July 2009, at 1:42 p.m.
  • Re: Insert into an indexed table is really SLOW!
    RALPH GENTRY -- Tuesday, 7 July 2009, at 1:45 p.m.
  • Re: Insert into an indexed table is really SLOW!
    Art Kagel -- Tuesday, 7 July 2009, at 1:46 p.m.
    • Re: Insert into an indexed table is really SLOW!
      Richard Kofler -- Tuesday, 7 July 2009, at 6:44 p.m.
      • Re: Insert into an indexed table is really SLOW!
        Art Kagel -- Tuesday, 7 July 2009, at 7:09 p.m.
  • Re: Insert into an indexed table is really SLOW!
    MIKE DUNHAM-WILKIE -- Friday, 10 July 2009, at 11:02 a.m.
    • Re: Insert into an indexed table is really SLOW!
      Richard Kofler -- Friday, 10 July 2009, at 1:51 p.m.

IDS Forum is maintained by Administrator with WebBBS 5.12.