db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Kristian Waagan <kristian.waa...@oracle.com>
Subject Re: Question on why indexStat deamon is being triggered
Date Fri, 30 Mar 2012 12:28:55 GMT
On 30.03.2012 01:02, Bergquist, Brett wrote:
>
> Here is the properties:
>
> derby.storage.indexStats.auto=true
>
> derby.storage.indexStats.debug.lndiffThreshold=4.0
>
> derby.storage.indexStats.log=true
>
> derby.storage.indexStats.trace=log
>
> The application is hitting the table 
> PKG_9145E_V1"."BC01_CONFIGURATION_SET frequently.   Many rows are 
> being added and deleted but the total number of rows is not really 
> changing that much if at all.
>

Is the table completely emptied at any point?
Do you run anything else than insert and delete (with predicate) that 
modifies the table?

> What I don't understand is the line:
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[DRDAConnThread_25,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>

abs(log(49) - log(44727)) = 6.816...

t-est is the estimated number of rows as seen by the table 
[conglomerate], whereas i-est is the estimated number of rows as seen by 
the current index statistics. These are very different, and based on the 
output below, it appears t-est is correct when it says the number of 
rows is 44'727 [1]. So why isn't i-est changing?

What do you see if you look at the results from querying SYS.SYSSTATISTICS?
(i.e. columns STATISTICS [2] and CREATIONTIMESTAMP)
What's the relevant DDL for the indexes/constraints in question?

> The same values are being shown each time.  Is this correct?
>

At least i-est seems off.
Do/did you see similar problems with other tables/indexes?
You can check the values by doing a select count and looking at the 
statistics stored in the system table.


> I am trying to tune the indexStat daemon so that it will run when 
> needed but not too frequently.    With the default value, I was seeing 
> about a 20% penalty when running the application and saw the indexStat 
> daemon nearly non-stop.   So I adjusted the lndiffThreshold to be 4.0 
> an it is not running too frequently but I still would like to 
> understand what the trace/log is telling me.
>

A lndiffThreshold of 4.0 means the table has to grow (or shrink) by a 
factor of roughly 54.6. In the specific case above, the index statistics 
for the table shouldn't be generated again before there are ([3]) nearly 
two and a half million rows in it (or less than 820).
I'd say a threshold of 4.0 is pretty relaxed - do you expect the 
distribution/cardinality of the values to be similar for a table with 
50K rows and 2500K rows?

I copied a line from below:
[q/p/s=0/268/268,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
q = queued
p = processed
s = scheduled
k = known errors (the daemon is prepared for these and can easily recover)
u = unknown errors
c = consecutive errors (daemon will disable itself if there are too many 
consecutive errors)
f = rejection due to full queue
d = rejection due to duplicate request (already in the queue)
o = other (currently only tracks scheduling attempts when the daemon has 
been disabled)


FYI, I'm aware that your options to fine-tune the statistics generation 
is rather limited.


Regards,
-- 
Kristian

[1] "wrote stats for index X (id): rows=44727, card=[44727]"
[2] In ij I had to cast this to see everything: cast(STATISTICS as 
VARCHAR(40))
[3] Or rather before Derby believes there are so many rows in the table 
-  we're working with estimates here.

> Here is a snippet of the output:
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681453075)
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681453158)
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=144ms,c30785=135ms)
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (300 ms)
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:48:02 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/266/266,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[DRDAConnThread_42,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681453158) 
> [q/p/s=1/266/267,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681462384)
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681462622)
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=152ms,c30785=138ms)
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (306 ms)
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:48:12 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/267/267,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[DRDAConnThread_25,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681462622) 
> [q/p/s=1/267/268,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681479731)
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681479756)
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=95ms,c30785=103ms)
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (214 ms)
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:48:33 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/268/268,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:44 EDT 2012 Thread[DRDAConnThread_26,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:48:44 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681479756) 
> [q/p/s=1/268/269,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:44 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:48:44 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681487715)
>
> Thu Mar 29 18:48:44 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:44 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681487764)
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=101ms,c30785=118ms)
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (231 ms)
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:48:45 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/269/269,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:46 EDT 2012 Thread[DRDAConnThread_39,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:48:46 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681487764) 
> [q/p/s=1/269/270,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:46 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:48:46 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681489467)
>
> Thu Mar 29 18:48:46 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681489541)
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=119ms,c30785=130ms)
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (269 ms)
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:48:47 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/270/270,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[DRDAConnThread_22,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681489541) 
> [q/p/s=1/270/271,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681495081)
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681495161)
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=200ms,c30785=126ms)
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (343 ms)
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:48:53 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/271/271,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:08 EDT 2012 Thread[DRDAConnThread_35,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:49:08 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681495161) 
> [q/p/s=1/271/272,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:08 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681510950)
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681511028)
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=228ms,c30785=111ms)
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (358 ms)
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:49:09 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/272/272,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[DRDAConnThread_25,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681511028) 
> [q/p/s=1/272/273,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681512771)
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681512851)
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=118ms,c30785=118ms)
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (259 ms)
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:49:11 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/273/273,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:17 EDT 2012 Thread[DRDAConnThread_38,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:49:17 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681512851) 
> [q/p/s=1/273/274,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:17 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:49:17 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681518290)
>
> Thu Mar 29 18:49:17 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:17 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681518363)
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=118ms,c30785=216ms)
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (351 ms)
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:49:18 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/274/274,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[DRDAConnThread_35,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681518363) 
> [q/p/s=1/274/275,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681534090)
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681534168)
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=112ms,c30785=217ms)
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (352 ms)
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:49:34 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/275/275,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:36 EDT 2012 Thread[DRDAConnThread_25,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:49:36 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681534168) 
> [q/p/s=1/275/276,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:36 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681536662)
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681536775)
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=133ms,c30785=127ms)
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (285 ms)
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:49:37 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/276/276,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[DRDAConnThread_29,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": update scheduled, 
> reason=[t-est=44727, i-est=49 => cmp=6.816512326985881] (queueSize=1)
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread started (xid=1681536775) 
> [q/p/s=1/276/277,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     processing 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET"
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681541238)
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL081029110445920 (e9a40921-011d-491f-3d8c-0000376d74d3): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     writing new stats (xid=1681541329)
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     invalidation completed
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": wrote stats for index 
> SQL100922214723290 (2c5f8294-012b-3c38-b55c-000043ea6398): rows=44727, 
> card=[44727]
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": scan durations 
> (c30785=132ms,c30785=124ms)
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] {istat} 
> "PKG_9145E_V1"."BC01_CONFIGURATION_SET": generation complete (273 ms)
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288}     queue empty
>
> Thu Mar 29 18:49:42 EDT 2012 Thread[index-stat-thread,5,main] 
> {istat,trace@154082288} worker thread exit 
> [q/p/s=0/277/277,err:k/u/c=0/0/0,rej:f/d/o=0/303/0]
>

Mime
View raw message