Locking and Logging issue
A site using the Excalibur Text (etx) DataBlade on IDS 9.40/11.50 reported two problems: every SELECT using etx_contains opened a logged transaction, filling logical logs far faster than before, and concurrent INSERTs into the same table failed immediately with error -937 ('a select is in progress, so updating the index is not allowed') instead of waiting for the lock. Suggestions included checking onstat -x/onlog output, sbspace ACCESSTIME logging (already ruled out), select triggers, and the DataBlade release notes on etx concurrency (shared vs promotable locks). No fix was found; the poster was pointed to the free BTS DataBlade in 11.50 or IBM support as alternatives.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Hi All,
[Please let me know what other information I should provide]
Here's the full story on our problem. First off: versions!
Informix Dynamic Server Version 11.50.FC6 (development) and 9.40.FC4
(production)
Excalibur Datablade ETX.1.30.FC7
UNIX SunOS 5.9 Generic_122300-51
Issue Synopsis: We use the Excalibur Datablade to search legal
documents, utilizing the etx_contains function. New documents are
inserted on an as-needed basis (potentially several times a day). The
users complained that 'large' documents were failing to load, since
time of installation.
In the last month, however, they can now only insert the smallest of
documents. Coincidentally, we observed a higher load of searches on
our database. Also, the Logical Log usage has increased exponentially
(from roughly 6 5MB logs filled per day to over 100!).
Document content is stored in an sbspace, connected to the Datablade.
No code changes have been made in over 9 months.
We noticed in our logs that the Inserts take roughly 600 - 700 msecs.
The searches take upwards of 1600 msecs.
*** Problem1: Logical Logs are filling excessively fast, when only
searches are being performed. Searches are NOT done inside of
explicit transactions. However, onstat -x shows every select using
the etx_contains function is creating a logged transaction.
*** Problem2: Sometimes, a Select using the etx_contains function
begins and then an Insert is started on the same table, while the
Select is in 'prepare' mode. When the Select begins to process, the
insert statement fails!
onstat -k shows HDR+IS locks being placed on the Large Smart ObjectHeader as soon as the Select kicks off:
10af47ee8 0 14f0ba9c8 10af19168
HDR+IS 40000b 0 0
Could this be blocking the Insert from exclusively locking the table?
Why wouldn't one statement wait for the other to finish?
SET LOCK MODE TO WAIT 30 for the insert
SET LOCK MODE TO WAIT 10 for the select
Both processes are using Isolation Level Committed Read -- we cannot
use Dirty Read for the select due to business requirements. But we
tried Dirty Read anyway, and the HDR+IS locks were still placed.
There are no errors listed in the Informix message log (onstat -m).
===========================
Our error logs read:
------
[9/13/10 12:25:12:558 MDT] 00000044 SystemOut O [0000] anonymous
DEBUG ContentDAO -
insert into ct(ct_id, sdoc_id, xml_1) values (?,?,?)[9/13/10 12:25:12:801 MDT] 00000044 SystemOut O [0000] anonymous
ERROR .CtDAO -
java.sql.SQLException: A select is in progress, so updating the index
is not
allowed.
[9/13/10 12:25:12:807 MDT] 00000044 SystemOut O [0000] anonymous
ERROR FileERDAO -
Exception in FileERDAO.insertNewCt:com.rustts.model.DAO.DAOException:
Error in CtDAO.create(Connection, CtVO).
A select is in progress, so updating the index is not allowed.Error
Code:-937
------
Most of the inserts process without incident, but the issue arises
when a different thread passes a Select to the 'ct' table at the same
time.
The Select statement takes about 400 msecs to Prepare, and as soon as
it kicks off, the Insert is blocked and causes an error.
This is from a second log file, ***compare the timestamps***:
-------
[9/13/10 12:25:12:382 MDT] 0000003e SystemOut O [0000] anonymous
INFO KeywordSearchDAO -
select p.ct_id, p.xml_1, s.sdoc_id,cc.ccrnum,cc.ccrn_vol
from ct p,sdoc s,ccd cc
where p.sdoc_id=s.sdoc_id and s.ccd_id=cc.ccd_id
and etx_contains(p.xml_1, Row(?, 'SEARCH_TYPE=PHRASE_EXACT &
MAX_MATCHES=1000'), rc # etx_ReturnType)
order by cc.ccrn_vol, p.ct_id[9/13/10 12:25:12:383 MDT] 0000003e SystemOut O [0000] anonymous
INFO KeywordSearchDAO - Binding keyword "silence", 100
[9/13/10 12:25:12:800 MDT] 0000003e SystemOut O [0000] anonymous
INFO KeywordSearchDAO - START ROW100
[9/13/10 12:25:12:801 MDT] 0000003e SystemOut O [0000] anonymous
INFO KeywordSearchDAO - total time 428 msecs
--------
Thanks for any and all assistance!
Michael Hoffman
On 16 Sep, 16:43, offdisc <offd...@gmail.com> wrote:
> Hi All,
> [Please let me know what other information I should provide]
>
> Here's the full story on our problem. First off: versions!
> Informix Dynamic Server Version 11.50.FC6 (development) and 9.40.FC4
> (production)
> Excalibur Datablade ETX.1.30.FC7
> UNIX SunOS 5.9 Generic_122300-51
>
> Issue Synopsis: We use the Excalibur Datablade to search legal
> documents, utilizing the etx_contains function. New documents are
> inserted on an as-needed basis (potentially several times a day). The
> users complained that 'large' documents were failing to load, since
> time of installation.
> In the last month, however, they can now only insert the smallest of
> documents. Coincidentally, we observed a higher load of searches on
> our database. Also, the Logical Log usage has increased exponentially
> (from roughly 6 5MB logs filled per day to over 100!).
>
> Document content is stored in an sbspace, connected to the Datablade.
>
> No code changes have been made in over 9 months.
>
> We noticed in our logs that the Inserts take roughly 600 - 700 msecs.
> The searches take upwards of 1600 msecs.
>
> *** Problem1: Logical Logs are filling excessively fast, when only
> searches are being performed. Searches are NOT done inside of
> explicit transactions. However, onstat -x shows every select using
> the etx_contains function is creating a logged transaction.
>
Where is the onstat -x output? have you uses onlog to confirm it is
actually generating log records?
> *** Problem2: Sometimes, a Select using the etx_contains function
> begins and then an Insert is started on the same table, while the
> Select is in 'prepare' mode. When the Select begins to process, the
> insert statement fails!
>
> onstat -k shows HDR+IS locks being placed on the Large Smart Object> Header as soon as the Select kicks off:
> 10af47ee8 0 14f0ba9c8 10af19168
> HDR+IS 40000b 0 0
selects will take intent shared locks on the table to stop someone
dropping the table whilst the select is using the table.
>
> Could this be blocking the Insert from exclusively locking the table?
Check with onstat -k, why would inserts exclusively lock the whole
table? Is this something special for the datablade?
> Why wouldn't one statement wait for the other to finish?
> SET LOCK MODE TO WAIT 30 for the insert
> SET LOCK MODE TO WAIT 10 for the select>
Why nnot just SET LOCK MODE TO WAIT for the insert? Why specify a
timeout?
> Both processes are using Isolation Level Committed Read -- we cannot
> use Dirty Read for the select due to business requirements. But we
> tried Dirty Read anyway, and the HDR+IS locks were still placed.
>
> There are no errors listed in the Informix message log (onstat -m).
>
> ===========================
> Our error logs read:
> ------
> [9/13/10 12:25:12:558 MDT] 00000044 SystemOut O [0000] anonymous
> DEBUG ContentDAO -
> insert into ct(ct_id, sdoc_id, xml_1) values (?,?,?)> [9/13/10 12:25:12:801 MDT] 00000044 SystemOut O [0000] anonymous
> ERROR .CtDAO -
> java.sql.SQLException: A select is in progress, so updating the index
> is not
> allowed.
> [9/13/10 12:25:12:807 MDT] 00000044 SystemOut O [0000] anonymous
> ERROR FileERDAO -
> Exception in FileERDAO.insertNewCt:com.rustts.model.DAO.DAOException:
> Error in CtDAO.create(Connection, CtVO).
> A select is in progress, so updating the index is not allowed.Error
> Code:-937
> ------
>
> Most of the inserts process without incident, but the issue arises
> when a different thread passes a Select to the 'ct' table at the same
> time.
> The Select statement takes about 400 msecs to Prepare, and as soon as
> it kicks off, the Insert is blocked and causes an error.
>
> This is from a second log file, ***compare the timestamps***:
> -------
> [9/13/10 12:25:12:382 MDT] 0000003e SystemOut O [0000] anonymous
> INFO KeywordSearchDAO -
> select p.ct_id, p.xml_1, s.sdoc_id,cc.ccrnum,cc.ccrn_vol
> from ct p,sdoc s,ccd cc
> where p.sdoc_id=s.sdoc_id and s.ccd_id=cc.ccd_id
> and etx_contains(p.xml_1, Row(?, 'SEARCH_TYPE=PHRASE_EXACT &
> MAX_MATCHES=1000'), rc # etx_ReturnType)
> order by cc.ccrn_vol, p.ct_id> [9/13/10 12:25:12:383 MDT] 0000003e SystemOut O [0000] anonymous
> INFO KeywordSearchDAO - Binding keyword "silence", 100
> [9/13/10 12:25:12:800 MDT] 0000003e SystemOut O [0000] anonymous
> INFO KeywordSearchDAO - START ROW100
> [9/13/10 12:25:12:801 MDT] 0000003e SystemOut O [0000] anonymous
> INFO KeywordSearchDAO - total time 428 msecs
> --------
>
> Thanks for any and all assistance!
> Michael Hoffman
http://publib.boulder.ibm.com/infocenter/ifxhelp/v0/topic/com.ibm.relnotes.doc/relnotes/exdb130uc3.txt
Section "CONCURRENCY AND THE EXCALIBUR TEXT DATABLADE MODULE"
describes the locking rules for that version. Somewhere under
$iNFORMIXDIR/release should be the locking rules for your version.
Informix 11.50 does have a BTS (Basic Text Search) datablades free
with that version that may better suit your needs else contact IBM.
sounds like you have enabled accesstime for your sbspaces:
manual:
Last-Access Time
When you create an sbspace, you can specify whether or not the
database server
should keep the last time that the smart large object was read or
updated with the
ACCESSTIME tag of the onspaces -c -Df option. The default is
“ACCESSTIME=OFF”. The database server keeps this last-access time in
the
metadata area.
changing stuff will get logged if the sbspace is logged.
oncheck -pS <nameofsbpace> may tell you.
Superboer.
On 16 sep, 13:52, "da...@smooth1.co.uk" <da...@smooth1.co.uk> wrote:
> On 16 Sep, 16:43, offdisc <offd...@gmail.com> wrote:
>
>
>
> > Hi All,
> > [Please let me know what other information I should provide]
>
> > Here's the full story on our problem. First off: versions!
> > Informix Dynamic Server Version 11.50.FC6 (development) and 9.40.FC4
> > (production)
> > Excalibur Datablade ETX.1.30.FC7
> > UNIX SunOS 5.9 Generic_122300-51
>
> > Issue Synopsis: We use the Excalibur Datablade to search legal
> > documents, utilizing the etx_contains function. New documents are
> > inserted on an as-needed basis (potentially several times a day). The
> > users complained that 'large' documents were failing to load, since
> > time of installation.
> > In the last month, however, they can now only insert the smallest of
> > documents. Coincidentally, we observed a higher load of searches on
> > our database. Also, the Logical Log usage has increased exponentially
> > (from roughly 6 5MB logs filled per day to over 100!).
>
> > Document content is stored in an sbspace, connected to the Datablade.
>
> > No code changes have been made in over 9 months.
>
> > We noticed in our logs that the Inserts take roughly 600 - 700 msecs.
> > The searches take upwards of 1600 msecs.
>
> > *** Problem1: Logical Logs are filling excessively fast, when only
> > searches are being performed. Searches are NOT done inside of
> > explicit transactions. However, onstat -x shows every select using
> > the etx_contains function is creating a logged transaction.
>
> Where is the onstat -x output? have you uses onlog to confirm it is
> actually generating log records?
>
> > *** Problem2: Sometimes, a Select using the etx_contains function
> > begins and then an Insert is started on the same table, while the
> > Select is in 'prepare' mode. When the Select begins to process, the
> > insert statement fails!
>
> > onstat -k shows HDR+IS locks being placed on the Large Smart Object> > Header as soon as the Select kicks off:
> > 10af47ee8 0 14f0ba9c8 10af19168
> > HDR+IS 40000b 0 0
>
> selects will take intent shared locks on the table to stop someone
> dropping the table whilst the select is using the table.
>
>
>
> > Could this be blocking the Insert from exclusively locking the table?
>
> Check with onstat -k, why would inserts exclusively lock the whole
> table? Is this something special for the datablade?
>
> > Why wouldn't one statement wait for the other to finish?
> > SET LOCK MODE TO WAIT 30 for the insert
> > SET LOCK MODE TO WAIT 10 for the select>
> Why nnot just SET LOCK MODE TO WAIT for the insert? Why specify a
> timeout?
>
>
>
> > Both processes are using Isolation Level Committed Read -- we cannot
> > use Dirty Read for the select due to business requirements. But we
> > tried Dirty Read anyway, and the HDR+IS locks were still placed.
>
> > There are no errors listed in the Informix message log (onstat -m).
>
> > ===========================
> > Our error logs read:
> > ------
> > [9/13/10 12:25:12:558 MDT] 00000044 SystemOut O [0000] anonymous
> > DEBUG ContentDAO -
> > insert into ct(ct_id, sdoc_id, xml_1) values (?,?,?)> > [9/13/10 12:25:12:801 MDT] 00000044 SystemOut O [0000] anonymous
> > ERROR .CtDAO -
> > java.sql.SQLException: A select is in progress, so updating the index
> > is not
> > allowed.
> > [9/13/10 12:25:12:807 MDT] 00000044 SystemOut O [0000] anonymous
> > ERROR FileERDAO -
> > Exception in FileERDAO.insertNewCt:com.rustts.model.DAO.DAOException:
> > Error in CtDAO.create(Connection, CtVO).
> > A select is in progress, so updating the index is not allowed.Error
> > Code:-937
> > ------
>
> > Most of the inserts process without incident, but the issue arises
> > when a different thread passes a Select to the 'ct' table at the same
> > time.
> > The Select statement takes about 400 msecs to Prepare, and as soon as
> > it kicks off, the Insert is blocked and causes an error.
>
> > This is from a second log file, ***compare the timestamps***:
> > -------
> > [9/13/10 12:25:12:382 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO -
> > select p.ct_id, p.xml_1, s.sdoc_id,cc.ccrnum,cc.ccrn_vol
> > from ct p,sdoc s,ccd cc
> > where p.sdoc_id=s.sdoc_id and s.ccd_id=cc.ccd_id
> > and etx_contains(p.xml_1, Row(?, 'SEARCH_TYPE=PHRASE_EXACT &
> > MAX_MATCHES=1000'), rc # etx_ReturnType)
> > order by cc.ccrn_vol, p.ct_id> > [9/13/10 12:25:12:383 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO - Binding keyword "silence", 100
> > [9/13/10 12:25:12:800 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO - START ROW100
> > [9/13/10 12:25:12:801 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO - total time 428 msecs
> > --------
>
> > Thanks for any and all assistance!
> > Michael Hoffman
>
> http://publib.boulder.ibm.com/infocenter/ifxhelp/v0/topic/com.ibm.rel...
> Section "CONCURRENCY AND THE EXCALIBUR TEXT DATABLADE MODULE"
> describes the locking rules for that version. Somewhere under
> $iNFORMIXDIR/release should be the locking rules for your version.
>
> Informix 11.50 does have a BTS (Basic Text Search) datablades free
> with that version that may better suit your needs else contact IBM.
hmm i was a bit too trigger happy,
it can also be that someone has created select triggers on some of
your tables which on its turn do insert/update stuff dono,
i would check that as well!!!!
And yes there are concurency issues but David has already pointed that
out to you.
Superboer
On 17 sep, 03:00, Superboer <superbo...@t-online.de> wrote:
> sounds like you have enabled accesstime for your sbspaces:
>
> manual:
>
> Last-Access Time
> When you create an sbspace, you can specify whether or not the
> database server
> should keep the last time that the smart large object was read or
> updated with the
> ACCESSTIME tag of the onspaces -c -Df option. The default is
> “ACCESSTIME=OFF”. The database server keeps this last-access time in
> the
> metadata area.
>
> changing stuff will get logged if the sbspace is logged.
>
> oncheck -pS <nameofsbpace> may tell you.>
> Superboer.
>
> On 16 sep, 13:52, "da...@smooth1.co.uk" <da...@smooth1.co.uk> wrote:
>
> > On 16 Sep, 16:43, offdisc <offd...@gmail.com> wrote:
>
> > > Hi All,
> > > [Please let me know what other information I should provide]
>
> > > Here's the full story on our problem. First off: versions!
> > > Informix Dynamic Server Version 11.50.FC6 (development) and 9.40.FC4
> > > (production)
> > > Excalibur Datablade ETX.1.30.FC7
> > > UNIX SunOS 5.9 Generic_122300-51
>
> > > Issue Synopsis: We use the Excalibur Datablade to search legal
> > > documents, utilizing the etx_contains function. New documents are
> > > inserted on an as-needed basis (potentially several times a day). The
> > > users complained that 'large' documents were failing to load, since
> > > time of installation.
> > > In the last month, however, they can now only insert the smallest of
> > > documents. Coincidentally, we observed a higher load of searches on
> > > our database. Also, the Logical Log usage has increased exponentially
> > > (from roughly 6 5MB logs filled per day to over 100!).
>
> > > Document content is stored in an sbspace, connected to the Datablade.
>
> > > No code changes have been made in over 9 months.
>
> > > We noticed in our logs that the Inserts take roughly 600 - 700 msecs.
> > > The searches take upwards of 1600 msecs.
>
> > > *** Problem1: Logical Logs are filling excessively fast, when only
> > > searches are being performed. Searches are NOT done inside of
> > > explicit transactions. However, onstat -x shows every select using
> > > the etx_contains function is creating a logged transaction.
>
> > Where is the onstat -x output? have you uses onlog to confirm it is
> > actually generating log records?
>
> > > *** Problem2: Sometimes, a Select using the etx_contains function
> > > begins and then an Insert is started on the same table, while the
> > > Select is in 'prepare' mode. When the Select begins to process, the
> > > insert statement fails!
>
> > > onstat -k shows HDR+IS locks being placed on the Large Smart Object> > > Header as soon as the Select kicks off:
> > > 10af47ee8 0 14f0ba9c8 10af19168
> > > HDR+IS 40000b 0 0
>
> > selects will take intent shared locks on the table to stop someone
> > dropping the table whilst the select is using the table.
>
> > > Could this be blocking the Insert from exclusively locking the table?
>
> > Check with onstat -k, why would inserts exclusively lock the whole
> > table? Is this something special for the datablade?
>
> > > Why wouldn't one statement wait for the other to finish?
> > > SET LOCK MODE TO WAIT 30 for the insert
> > > SET LOCK MODE TO WAIT 10 for the select>
> > Why nnot just SET LOCK MODE TO WAIT for the insert? Why specify a
> > timeout?
>
> > > Both processes are using Isolation Level Committed Read -- we cannot
> > > use Dirty Read for the select due to business requirements. But we
> > > tried Dirty Read anyway, and the HDR+IS locks were still placed.
>
> > > There are no errors listed in the Informix message log (onstat -m).
>
> > > ===========================
> > > Our error logs read:
> > > ------
> > > [9/13/10 12:25:12:558 MDT] 00000044 SystemOut O [0000] anonymous
> > > DEBUG ContentDAO -
> > > insert into ct(ct_id, sdoc_id, xml_1) values (?,?,?)> > > [9/13/10 12:25:12:801 MDT] 00000044 SystemOut O [0000] anonymous
> > > ERROR .CtDAO -
> > > java.sql.SQLException: A select is in progress, so updating the index
> > > is not
> > > allowed.
> > > [9/13/10 12:25:12:807 MDT] 00000044 SystemOut O [0000] anonymous
> > > ERROR FileERDAO -
> > > Exception in FileERDAO.insertNewCt:com.rustts.model.DAO.DAOException:
> > > Error in CtDAO.create(Connection, CtVO).
> > > A select is in progress, so updating the index is not allowed.Error
> > > Code:-937
> > > ------
>
> > > Most of the inserts process without incident, but the issue arises
> > > when a different thread passes a Select to the 'ct' table at the same
> > > time.
> > > The Select statement takes about 400 msecs to Prepare, and as soon as
> > > it kicks off, the Insert is blocked and causes an error.
>
> > > This is from a second log file, ***compare the timestamps***:
> > > -------
> > > [9/13/10 12:25:12:382 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO -
> > > select p.ct_id, p.xml_1, s.sdoc_id,cc.ccrnum,cc.ccrn_vol
> > > from ct p,sdoc s,ccd cc
> > > where p.sdoc_id=s.sdoc_id and s.ccd_id=cc.ccd_id
> > > and etx_contains(p.xml_1, Row(?, 'SEARCH_TYPE=PHRASE_EXACT &
> > > MAX_MATCHES=1000'), rc # etx_ReturnType)
> > > order by cc.ccrn_vol, p.ct_id> > > [9/13/10 12:25:12:383 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO - Binding keyword "silence", 100
> > > [9/13/10 12:25:12:800 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO - START ROW100
> > > [9/13/10 12:25:12:801 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO - total time 428 msecs
> > > --------
>
> > > Thanks for any and all assistance!
> > > Michael Hoffman
>
> >http://publib.boulder.ibm.com/infocenter/ifxhelp/v0/topic/com.ibm.rel...
> > Section "CONCURRENCY AND THE EXCALIBUR TEXT DATABLADE MODULE"
> > describes the locking rules for that version. Somewhere under
> > $iNFORMIXDIR/release should be the locking rules for your version.
>
> > Informix 11.50 does have a BTS (Basic Text Search) datablades free
> > with that version that may better suit your needs else contact IBM.
Superboer,
The AccessTime was one of my first steps to solving this issue. It
made no difference on the locking.
But glad to see I wasn't far off in my thinking. :-)
Michael
On Sep 17, 1:00 am, Superboer <superbo...@t-online.de> wrote:
> sounds like you have enabled accesstime for your sbspaces:
>
> manual:
>
> Last-Access Time
> When you create an sbspace, you can specify whether or not the
> database server
> should keep the last time that the smart large object was read or
> updated with the
> ACCESSTIME tag of the onspaces -c -Df option. The default is
> “ACCESSTIME=OFF”. The database server keeps this last-access time in
> the
> metadata area.
>
> changing stuff will get logged if the sbspace is logged.
>
> oncheck -pS <nameofsbpace> may tell you.>
> Superboer.
>
> On 16 sep, 13:52, "da...@smooth1.co.uk" <da...@smooth1.co.uk> wrote:
>
> > On 16 Sep, 16:43, offdisc <offd...@gmail.com> wrote:
>
> > > Hi All,
> > > [Please let me know what other information I should provide]
>
> > > Here's the full story on our problem. First off: versions!
> > > Informix Dynamic Server Version 11.50.FC6 (development) and 9.40.FC4
> > > (production)
> > > Excalibur Datablade ETX.1.30.FC7
> > > UNIX SunOS 5.9 Generic_122300-51
>
> > > Issue Synopsis: We use the Excalibur Datablade to search legal
> > > documents, utilizing the etx_contains function. New documents are
> > > inserted on an as-needed basis (potentially several times a day). The
> > > users complained that 'large' documents were failing to load, since
> > > time of installation.
> > > In the last month, however, they can now only insert the smallest of
> > > documents. Coincidentally, we observed a higher load of searches on
> > > our database. Also, the Logical Log usage has increased exponentially
> > > (from roughly 6 5MB logs filled per day to over 100!).
>
> > > Document content is stored in an sbspace, connected to the Datablade.
>
> > > No code changes have been made in over 9 months.
>
> > > We noticed in our logs that the Inserts take roughly 600 - 700 msecs.
> > > The searches take upwards of 1600 msecs.
>
> > > *** Problem1: Logical Logs are filling excessively fast, when only
> > > searches are being performed. Searches are NOT done inside of
> > > explicit transactions. However, onstat -x shows every select using
> > > the etx_contains function is creating a logged transaction.
>
> > Where is the onstat -x output? have you uses onlog to confirm it is
> > actually generating log records?
>
> > > *** Problem2: Sometimes, a Select using the etx_contains function
> > > begins and then an Insert is started on the same table, while the
> > > Select is in 'prepare' mode. When the Select begins to process, the
> > > insert statement fails!
>
> > > onstat -k shows HDR+IS locks being placed on the Large Smart Object> > > Header as soon as the Select kicks off:
> > > 10af47ee8 0 14f0ba9c8 10af19168
> > > HDR+IS 40000b 0 0
>
> > selects will take intent shared locks on the table to stop someone
> > dropping the table whilst the select is using the table.
>
> > > Could this be blocking the Insert from exclusively locking the table?
>
> > Check with onstat -k, why would inserts exclusively lock the whole
> > table? Is this something special for the datablade?
>
> > > Why wouldn't one statement wait for the other to finish?
> > > SET LOCK MODE TO WAIT 30 for the insert
> > > SET LOCK MODE TO WAIT 10 for the select>
> > Why nnot just SET LOCK MODE TO WAIT for the insert? Why specify a
> > timeout?
>
> > > Both processes are using Isolation Level Committed Read -- we cannot
> > > use Dirty Read for the select due to business requirements. But we
> > > tried Dirty Read anyway, and the HDR+IS locks were still placed.
>
> > > There are no errors listed in the Informix message log (onstat -m).
>
> > > ===========================
> > > Our error logs read:
> > > ------
> > > [9/13/10 12:25:12:558 MDT] 00000044 SystemOut O [0000] anonymous
> > > DEBUG ContentDAO -
> > > insert into ct(ct_id, sdoc_id, xml_1) values (?,?,?)> > > [9/13/10 12:25:12:801 MDT] 00000044 SystemOut O [0000] anonymous
> > > ERROR .CtDAO -
> > > java.sql.SQLException: A select is in progress, so updating the index
> > > is not
> > > allowed.
> > > [9/13/10 12:25:12:807 MDT] 00000044 SystemOut O [0000] anonymous
> > > ERROR FileERDAO -
> > > Exception in FileERDAO.insertNewCt:com.rustts.model.DAO.DAOException:
> > > Error in CtDAO.create(Connection, CtVO).
> > > A select is in progress, so updating the index is not allowed.Error
> > > Code:-937
> > > ------
>
> > > Most of the inserts process without incident, but the issue arises
> > > when a different thread passes a Select to the 'ct' table at the same
> > > time.
> > > The Select statement takes about 400 msecs to Prepare, and as soon as
> > > it kicks off, the Insert is blocked and causes an error.
>
> > > This is from a second log file, ***compare the timestamps***:
> > > -------
> > > [9/13/10 12:25:12:382 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO -
> > > select p.ct_id, p.xml_1, s.sdoc_id,cc.ccrnum,cc.ccrn_vol
> > > from ct p,sdoc s,ccd cc
> > > where p.sdoc_id=s.sdoc_id and s.ccd_id=cc.ccd_id
> > > and etx_contains(p.xml_1, Row(?, 'SEARCH_TYPE=PHRASE_EXACT &
> > > MAX_MATCHES=1000'), rc # etx_ReturnType)
> > > order by cc.ccrn_vol, p.ct_id> > > [9/13/10 12:25:12:383 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO - Binding keyword "silence", 100
> > > [9/13/10 12:25:12:800 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO - START ROW100
> > > [9/13/10 12:25:12:801 MDT] 0000003e SystemOut O [0000] anonymous
> > > INFO KeywordSearchDAO - total time 428 msecs
> > > --------
>
> > > Thanks for any and all assistance!
> > > Michael Hoffman
>
> >http://publib.boulder.ibm.com/infocenter/ifxhelp/v0/topic/com.ibm.rel...
> > Section "CONCURRENCY AND THE EXCALIBUR TEXT DATABLADE MODULE"
> > describes the locking rules for that version. Somewhere under
> > $iNFORMIXDIR/release should be the locking rules for your version.
>
> > Informix 11.50 does have a BTS (Basic Text Search) datablades free
> > with that version that may better suit your needs else contact IBM.
David,
I did not capture the 'onstat -x' output, but we were able to confirm
by running on a test sevrer. Every time we ran a query with the
etx_contains in the where clause, we saw the locks placed and the
transaction appeared on the 'onstat -x' list. We also saw the
transaction and logs used via 'onstat -u'.
We ran the test several times with no other users --- same results
every time, so no denying the cause/effect link.
"selects will take intent shared locks on the table to stop someone
dropping the table whilst the select is using the table. "
I can understand that... makes sense. But should they also block
inserts and updates?
The locks are on the smart large object headers, so they block any
insert/update access to the sbspace.
I misspoke when I said the insert was "exclusively locking the
table". The insert will place an exclusive lock on the row and the
index though, and that is what is being blocked.
Because this is a public site, we need to have a deadlock timeout, so
we use the time parameter for SET LOCK MODE TO WAIT 30. Doesn't seem
to matter though, the timeout occurs within a single millisecond, not
after waiting 30 seconds.
The concurrency section explains that a "shared" lock is placed during
selects, a "promotable" lock is placed during inserts and updates.
The "promotable" lock still allows other "shared" locks to be placed,
but no other "promotable" locks. When the insert/update is committed,
the "promotable" lock is supposed to turn "exclusive", but will wait
for all "shared" locks to release, then block any new "shared" locks
from acquiring.
In our situation, as soon as the shared lock is placed, it seems to
block any "promotable" locks from acquiring. This is not
documented. Informix seems to think a deadlock situation has occurred
and returns an error to the Insert call.
Thanks,
Michael Hoffman
On Sep 16, 11:52 am, "da...@smooth1.co.uk" <da...@smooth1.co.uk>
wrote:
> On 16 Sep, 16:43, offdisc <offd...@gmail.com> wrote:
>
> > Hi All,
> > [Please let me know what other information I should provide]
>
> > Here's the full story on our problem. First off: versions!
> > Informix Dynamic Server Version 11.50.FC6 (development) and 9.40.FC4
> > (production)
> > Excalibur Datablade ETX.1.30.FC7
> > UNIX SunOS 5.9 Generic_122300-51
>
> > Issue Synopsis: We use the Excalibur Datablade to search legal
> > documents, utilizing the etx_contains function. New documents are
> > inserted on an as-needed basis (potentially several times a day). The
> > users complained that 'large' documents were failing to load, since
> > time of installation.
> > In the last month, however, they can now only insert the smallest of
> > documents. Coincidentally, we observed a higher load of searches on
> > our database. Also, the Logical Log usage has increased exponentially
> > (from roughly 6 5MB logs filled per day to over 100!).
>
> > Document content is stored in an sbspace, connected to the Datablade.
>
> > No code changes have been made in over 9 months.
>
> > We noticed in our logs that the Inserts take roughly 600 - 700 msecs.
> > The searches take upwards of 1600 msecs.
>
> > *** Problem1: Logical Logs are filling excessively fast, when only
> > searches are being performed. Searches are NOT done inside of
> > explicit transactions. However, onstat -x shows every select using
> > the etx_contains function is creating a logged transaction.
>
> Where is the onstat -x output? have you uses onlog to confirm it is
> actually generating log records?
>
> > *** Problem2: Sometimes, a Select using the etx_contains function
> > begins and then an Insert is started on the same table, while the
> > Select is in 'prepare' mode. When the Select begins to process, the
> > insert statement fails!
>
> > onstat -k shows HDR+IS locks being placed on the Large Smart Object> > Header as soon as the Select kicks off:
> > 10af47ee8 0 14f0ba9c8 10af19168
> > HDR+IS 40000b 0 0
>
> selects will take intent shared locks on the table to stop someone
> dropping the table whilst the select is using the table.
>
>
>
> > Could this be blocking the Insert from exclusively locking the table?
>
> Check with onstat -k, why would inserts exclusively lock the whole
> table? Is this something special for the datablade?
>
> > Why wouldn't one statement wait for the other to finish?
> > SET LOCK MODE TO WAIT 30 for the insert
> > SET LOCK MODE TO WAIT 10 for the select>
> Why nnot just SET LOCK MODE TO WAIT for the insert? Why specify a
> timeout?
>
>
>
> > Both processes are using Isolation Level Committed Read -- we cannot
> > use Dirty Read for the select due to business requirements. But we
> > tried Dirty Read anyway, and the HDR+IS locks were still placed.
>
> > There are no errors listed in the Informix message log (onstat -m).
>
> > ===========================
> > Our error logs read:
> > ------
> > [9/13/10 12:25:12:558 MDT] 00000044 SystemOut O [0000] anonymous
> > DEBUG ContentDAO -
> > insert into ct(ct_id, sdoc_id, xml_1) values (?,?,?)> > [9/13/10 12:25:12:801 MDT] 00000044 SystemOut O [0000] anonymous
> > ERROR .CtDAO -
> > java.sql.SQLException: A select is in progress, so updating the index
> > is not
> > allowed.
> > [9/13/10 12:25:12:807 MDT] 00000044 SystemOut O [0000] anonymous
> > ERROR FileERDAO -
> > Exception in FileERDAO.insertNewCt:com.rustts.model.DAO.DAOException:
> > Error in CtDAO.create(Connection, CtVO).
> > A select is in progress, so updating the index is not allowed.Error
> > Code:-937
> > ------
>
> > Most of the inserts process without incident, but the issue arises
> > when a different thread passes a Select to the 'ct' table at the same
> > time.
> > The Select statement takes about 400 msecs to Prepare, and as soon as
> > it kicks off, the Insert is blocked and causes an error.
>
> > This is from a second log file, ***compare the timestamps***:
> > -------
> > [9/13/10 12:25:12:382 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO -
> > select p.ct_id, p.xml_1, s.sdoc_id,cc.ccrnum,cc.ccrn_vol
> > from ct p,sdoc s,ccd cc
> > where p.sdoc_id=s.sdoc_id and s.ccd_id=cc.ccd_id
> > and etx_contains(p.xml_1, Row(?, 'SEARCH_TYPE=PHRASE_EXACT &
> > MAX_MATCHES=1000'), rc # etx_ReturnType)
> > order by cc.ccrn_vol, p.ct_id> > [9/13/10 12:25:12:383 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO - Binding keyword "silence", 100
> > [9/13/10 12:25:12:800 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO - START ROW100
> > [9/13/10 12:25:12:801 MDT] 0000003e SystemOut O [0000] anonymous
> > INFO KeywordSearchDAO - total time 428 msecs
> > --------
>
> > Thanks for any and all assistance!
> > Michael Hoffman
>
> http://publib.boulder.ibm.com/infocenter/ifxhelp/v0/topic/com.ibm.rel...
> Section "CONCURRENCY AND THE EXCALIBUR TEXT DATABLADE MODULE@@DQ@
We are in the process of upgrading to 11.5 and will take a look at the BTS blade. Thanks for the heads-up! Michael On Sep 16, 11:52 am, "da...@smooth1.co.uk" <da...@smooth1.co.uk> wrote: > > Informix 11.50 does have a BTS (Basic Text Search) datablades free > with that version that may better suit your needs else contact IBM.