Subject | Re: Firebird Usage Load Problem |
---|---|
Author | Maurice Ling |
Post date | 2005-07-14T23:39:10Z |
--- In firebird-support@yahoogroups.com, "Kevin Hamilton"
<Kevin.Hamilton@s...> wrote:
output here....
Database "muscopedia.fdb"
Database header page information:
Flags 0
Checksum 12345
Generation 1584942
Page size 4096
ODS version 10.1
Oldest transaction 1569535
Oldest active 1569536
Oldest snapshot 1569533
Next transaction 1584914
Bumped transaction 1
Sequence number 0
Next attachment ID 0
Implementation ID 19
Shadow count 0
Page buffers 75
Next header page 0
Database dialect 3
Creation date Jul 4, 2005 12:07:21
Attributes
Variable header data:
Sweep interval: 20000
Continuation file:
/mnt/disk/home/mling/muscorian/BioDatabases/muscopedia.fd2
Last logical page: 500000
*END*
Database file sequence:
File muscopedia.fdb continues as file
/mnt/disk/home/mling/muscorian/BioDatabases/muscopedia.fd2
........[snipped the rest]..........
Database log page information:
Creation date
Log flags: 2
No write ahead log
Next log page: 0
Variable log data:
Control Point 1:
File name:
Partition offset: 0 Seqno: 0 Offset: 0
Control Point 2:
File name:
Partition offset: 0 Seqno: 0 Offset: 0
Current File:
File name:
Partition offset: 0 Seqno: 0 Offset: 0
*END*
Analyzing database pages ...
......[snipped some irrelevant tables].........
ML_SVO (138)
Primary pointer page: 175, Index root page: 176
Average record length: 0.00, total records: 33546
Average version length: 45.32, total versions: 33546, max versions: 1
Data pages: 711, data page slots: 711, average fill: 92%
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 0
60 - 79% = 1
80 - 99% = 710
Index RDB$PRIMARY6 (0)
Depth: 3, leaf buckets: 550, nodes: 33546
Average data length: 28.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 548
60 - 79% = 2
80 - 99% = 0
NAME_HUNT_WAITING (165)
Primary pointer page: 268776, Index root page: 268777
Average record length: 9.87, total records: 841454
Average version length: 10.00, total versions: 10533, max versions: 1
Data pages: 10389, data page slots: 10535, average fill: 54%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 10256
60 - 79% = 3
80 - 99% = 129
PG_NAME (166)
Primary pointer page: 268783, Index root page: 268784
Average record length: 28.71, total records: 93099
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 1586, data page slots: 1586, average fill: 66%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 1585
80 - 99% = 0
Index RDB$PRIMARY9 (0)
Depth: 3, leaf buckets: 775, nodes: 93099
Average data length: 15.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 462
60 - 79% = 164
80 - 99% = 149
PMC_ABSTRACT (131)
Primary pointer page: 160, Index root page: 161
Average record length: 1523.59, total records: 853355
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 424056, data page slots: 424056, average fill: 76%
Fill distribution:
0 - 19% = 22
20 - 39% = 3772
40 - 59% = 93191
60 - 79% = 120746
80 - 99% = 206325
Index PMC_ABSTRACT_PMID (1)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 1
60 - 79% = 2
80 - 99% = 2471
Index RDB$PRIMARY2 (0)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 2
60 - 79% = 0
80 - 99% = 2472
PMC_ARTICLE_INFO (132)
Primary pointer page: 162, Index root page: 163
Average record length: 153.98, total records: 853355
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 41544, data page slots: 41544, average fill: 86%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 41543
Index PMC_ARTICLE_PMID (1)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 1
60 - 79% = 2
80 - 99% = 2471
Index RDB$PRIMARY3 (0)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 2
60 - 79% = 0
80 - 99% = 2472
PMC_AUTHOR (133)
Primary pointer page: 164, Index root page: 165
Average record length: 30.19, total records: 3372633
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 58709, data page slots: 58709, average fill: 67%
Fill distribution:
0 - 19% = 0
20 - 39% = 1
40 - 59% = 0
60 - 79% = 58708
80 - 99% = 0
Index PMC_AUTHOR_LIST (0)
Depth: 3, leaf buckets: 6865, nodes: 3372633
Average data length: 1.00, total dup: 2430956, max dup: 832
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 1268
60 - 79% = 1
80 - 99% = 5596
PMC_INDEX_LIST (134)
Primary pointer page: 167, Index root page: 168
Average record length: 31.75, total records: 4
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 1, data page slots: 1, average fill: 5%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 0
Index PMC_TERM_LIST (1)
Depth: 1, leaf buckets: 1, nodes: 4
Average data length: 7.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 0
Index RDB$PRIMARY4 (0)
Depth: 1, leaf buckets: 1, nodes: 4
Average data length: 1.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 0
PMC_INDEX_TERM_MAP (135)
Primary pointer page: 169, Index root page: 170
Average record length: 14.99, total records: 875504
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 11674, data page slots: 11674, average fill: 59%
Fill distribution:
0 - 19% = 0
20 - 39% = 1
40 - 59% = 11673
60 - 79% = 0
80 - 99% = 0
TEXT_REPLACE_ABSTRACT (137)
Primary pointer page: 173, Index root page: 174
Average record length: 1221.89, total records: 854009
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 324684, data page slots: 324684, average fill: 80%
Fill distribution:
0 - 19% = 680
20 - 39% = 1703
40 - 59% = 22831
60 - 79% = 121600
80 - 99% = 177870
TEXT_REPLACE_ABSTRACT_UPRO (164)
Primary pointer page: 227, Index root page: 228
Average record length: 426.76, total records: 339
Average version length: 1571.00, total versions: 251, max versions: 1
Data pages: 170, data page slots: 257, average fill: 79%
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 0
60 - 79% = 126
80 - 99% = 44
3 concurrent running scripts does the following:
script A: loads new data into PMC_* tables, process raw text and
inserts results into TEXT_REPLACE_ABSTRACT and
TEXT_REPLACE_ABSTRACT_UPRO tables. Does that 300 times. Then do a
select * from TEXT_REPLACE_ABSTRACT_UPRO, process each record, then
insert the results into ML_SVO table and delete the processed record
from TEXT_REPLACE_ABSTRACT_UPRO table. [this script is a pure CPU
eater. FB process called from this runs at 99.7% without any drop in
intensity.]
script B: select <primary key> from TEXT_REPLACE_ABSTRACT table and
retrieve an attribute (varchar(18000), if that is important) from
TEXT_REPLACE_ABSTRACT table, process it and insert the results into
ML_SVO table. This repeats for 870k times. I cannot do select PK, txt
from .... because in Mac OSX (where I 1st ran my program), the OS
kernel gave me a vm_allocate() error. This had been verified in Python
mailing list and Python has no vm_allocate() method in its codes.
script C: select * from NAME_HUNT_WAITING table (1 field but 870k
records. It is a primary key in PMC_ABSTRACT table) and for each
record, uses it to retrieve a text field (varchar(18000) again) from
PMC_ABSTRACT table, process it, then insert into PG_NAME table.
What I find interesting is this...... When ran non-concurrently, FB
process uses >96% CPU after after about 36-42 hrs (script B and C will
take about 10 weeks to run), FB seems to behave itself and no longer
using that much CPU. Wonder why? What happened at the beginning?
Cheers
Maurice
<Kevin.Hamilton@s...> wrote:
>I do not quite see the problem. I've pasted relevant parts of the
> Something you can do to identify if you are suffering from #1 or #2 in
> Nando's list is to run gstat -r -a against your database and then look
> at the max dup on indexes and max versions on tables. For some
> discussion about what all the output of gstat -r -a means, refer to this
> thread in the archives:
> http://groups.yahoo.com/group/firebird-support/message/61993
>
output here....
Database "muscopedia.fdb"
Database header page information:
Flags 0
Checksum 12345
Generation 1584942
Page size 4096
ODS version 10.1
Oldest transaction 1569535
Oldest active 1569536
Oldest snapshot 1569533
Next transaction 1584914
Bumped transaction 1
Sequence number 0
Next attachment ID 0
Implementation ID 19
Shadow count 0
Page buffers 75
Next header page 0
Database dialect 3
Creation date Jul 4, 2005 12:07:21
Attributes
Variable header data:
Sweep interval: 20000
Continuation file:
/mnt/disk/home/mling/muscorian/BioDatabases/muscopedia.fd2
Last logical page: 500000
*END*
Database file sequence:
File muscopedia.fdb continues as file
/mnt/disk/home/mling/muscorian/BioDatabases/muscopedia.fd2
........[snipped the rest]..........
Database log page information:
Creation date
Log flags: 2
No write ahead log
Next log page: 0
Variable log data:
Control Point 1:
File name:
Partition offset: 0 Seqno: 0 Offset: 0
Control Point 2:
File name:
Partition offset: 0 Seqno: 0 Offset: 0
Current File:
File name:
Partition offset: 0 Seqno: 0 Offset: 0
*END*
Analyzing database pages ...
......[snipped some irrelevant tables].........
ML_SVO (138)
Primary pointer page: 175, Index root page: 176
Average record length: 0.00, total records: 33546
Average version length: 45.32, total versions: 33546, max versions: 1
Data pages: 711, data page slots: 711, average fill: 92%
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 0
60 - 79% = 1
80 - 99% = 710
Index RDB$PRIMARY6 (0)
Depth: 3, leaf buckets: 550, nodes: 33546
Average data length: 28.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 548
60 - 79% = 2
80 - 99% = 0
NAME_HUNT_WAITING (165)
Primary pointer page: 268776, Index root page: 268777
Average record length: 9.87, total records: 841454
Average version length: 10.00, total versions: 10533, max versions: 1
Data pages: 10389, data page slots: 10535, average fill: 54%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 10256
60 - 79% = 3
80 - 99% = 129
PG_NAME (166)
Primary pointer page: 268783, Index root page: 268784
Average record length: 28.71, total records: 93099
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 1586, data page slots: 1586, average fill: 66%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 1585
80 - 99% = 0
Index RDB$PRIMARY9 (0)
Depth: 3, leaf buckets: 775, nodes: 93099
Average data length: 15.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 462
60 - 79% = 164
80 - 99% = 149
PMC_ABSTRACT (131)
Primary pointer page: 160, Index root page: 161
Average record length: 1523.59, total records: 853355
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 424056, data page slots: 424056, average fill: 76%
Fill distribution:
0 - 19% = 22
20 - 39% = 3772
40 - 59% = 93191
60 - 79% = 120746
80 - 99% = 206325
Index PMC_ABSTRACT_PMID (1)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 1
60 - 79% = 2
80 - 99% = 2471
Index RDB$PRIMARY2 (0)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 2
60 - 79% = 0
80 - 99% = 2472
PMC_ARTICLE_INFO (132)
Primary pointer page: 162, Index root page: 163
Average record length: 153.98, total records: 853355
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 41544, data page slots: 41544, average fill: 86%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 41543
Index PMC_ARTICLE_PMID (1)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 1
60 - 79% = 2
80 - 99% = 2471
Index RDB$PRIMARY3 (0)
Depth: 3, leaf buckets: 2474, nodes: 853355
Average data length: 5.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 2
60 - 79% = 0
80 - 99% = 2472
PMC_AUTHOR (133)
Primary pointer page: 164, Index root page: 165
Average record length: 30.19, total records: 3372633
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 58709, data page slots: 58709, average fill: 67%
Fill distribution:
0 - 19% = 0
20 - 39% = 1
40 - 59% = 0
60 - 79% = 58708
80 - 99% = 0
Index PMC_AUTHOR_LIST (0)
Depth: 3, leaf buckets: 6865, nodes: 3372633
Average data length: 1.00, total dup: 2430956, max dup: 832
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 1268
60 - 79% = 1
80 - 99% = 5596
PMC_INDEX_LIST (134)
Primary pointer page: 167, Index root page: 168
Average record length: 31.75, total records: 4
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 1, data page slots: 1, average fill: 5%
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 0
Index PMC_TERM_LIST (1)
Depth: 1, leaf buckets: 1, nodes: 4
Average data length: 7.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 0
Index RDB$PRIMARY4 (0)
Depth: 1, leaf buckets: 1, nodes: 4
Average data length: 1.00, total dup: 0, max dup: 0
Fill distribution:
0 - 19% = 1
20 - 39% = 0
40 - 59% = 0
60 - 79% = 0
80 - 99% = 0
PMC_INDEX_TERM_MAP (135)
Primary pointer page: 169, Index root page: 170
Average record length: 14.99, total records: 875504
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 11674, data page slots: 11674, average fill: 59%
Fill distribution:
0 - 19% = 0
20 - 39% = 1
40 - 59% = 11673
60 - 79% = 0
80 - 99% = 0
TEXT_REPLACE_ABSTRACT (137)
Primary pointer page: 173, Index root page: 174
Average record length: 1221.89, total records: 854009
Average version length: 0.00, total versions: 0, max versions: 0
Data pages: 324684, data page slots: 324684, average fill: 80%
Fill distribution:
0 - 19% = 680
20 - 39% = 1703
40 - 59% = 22831
60 - 79% = 121600
80 - 99% = 177870
TEXT_REPLACE_ABSTRACT_UPRO (164)
Primary pointer page: 227, Index root page: 228
Average record length: 426.76, total records: 339
Average version length: 1571.00, total versions: 251, max versions: 1
Data pages: 170, data page slots: 257, average fill: 79%
Fill distribution:
0 - 19% = 0
20 - 39% = 0
40 - 59% = 0
60 - 79% = 126
80 - 99% = 44
3 concurrent running scripts does the following:
script A: loads new data into PMC_* tables, process raw text and
inserts results into TEXT_REPLACE_ABSTRACT and
TEXT_REPLACE_ABSTRACT_UPRO tables. Does that 300 times. Then do a
select * from TEXT_REPLACE_ABSTRACT_UPRO, process each record, then
insert the results into ML_SVO table and delete the processed record
from TEXT_REPLACE_ABSTRACT_UPRO table. [this script is a pure CPU
eater. FB process called from this runs at 99.7% without any drop in
intensity.]
script B: select <primary key> from TEXT_REPLACE_ABSTRACT table and
retrieve an attribute (varchar(18000), if that is important) from
TEXT_REPLACE_ABSTRACT table, process it and insert the results into
ML_SVO table. This repeats for 870k times. I cannot do select PK, txt
from .... because in Mac OSX (where I 1st ran my program), the OS
kernel gave me a vm_allocate() error. This had been verified in Python
mailing list and Python has no vm_allocate() method in its codes.
script C: select * from NAME_HUNT_WAITING table (1 field but 870k
records. It is a primary key in PMC_ABSTRACT table) and for each
record, uses it to retrieve a text field (varchar(18000) again) from
PMC_ABSTRACT table, process it, then insert into PG_NAME table.
What I find interesting is this...... When ran non-concurrently, FB
process uses >96% CPU after after about 36-42 hrs (script B and C will
take about 10 weeks to run), FB seems to behave itself and no longer
using that much CPU. Wonder why? What happened at the beginning?
Cheers
Maurice