Hi,
Heikki Linnakangas wrote:
I still suspect there's something wrong with plans, I doubt you can get
that bad performance unless it's doing something really stupid.
Agreed, but I'm still looking for that really stupid thing... AFAICT,
there are really no seqscans..., see the pg_stat_user_tables below.
I'd
suggest setting log_min_duration_statement = 5000, and seeing what you
get. Also check pg_stat_user_table.seq_scan just to be extra sure
there's no seq scans.
I've also added some of the log messages for min_duration_statement
below. Both were taken after two or three test runs.
I'm really wondering, if the RAID 6 of the ARECA 1260 hurts so badly.
That would be disappointing, IMO. I'll try if I can reconfigure it to do
RAID 1+0, and then test again. (Unfortunately the box has already been
shipped to the customer, so that's getting tricky to do via ssh..:-( ).
Regards
Markus
*** pg_stat_user_tables ***
relid | schemaname | relname | seq_scan | seq_tup_read | idx_scan |
idx_tup_fetch | n_tup_ins | n_tup_upd | n_tup_del | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze
-------+------------+------------+----------+--------------+----------+---------------+-----------+-----------+-----------+-------------+-------------------------------+--------------+-------------------------------
16390 | public | district | 0 | 0 | 206335 |
206335 | 0 | 100771 | 0 | |
2007-06-05 15:40:44.39573+02 | | 2007-06-05 15:39:41.636736+02
16396 | public | new_order | 0 | 0 | 91860 |
41402317 | 51372 | 0 | 45844 | |
| |
16400 | public | order_line | 0 | 0 | 101195 |
933197 | 538442 | 436140 | 0 | |
| |
16402 | public | item | 0 | 0 | 538942 |
538442 | 0 | 0 | 0 | |
| |
16404 | public | stock | 0 | 0 | 1093528 |
1077782 | 0 | 538442 | 0 | |
| |
16394 | public | history | 0 | 0 | |
| 49399 | 0 | 0 | |
| |
16388 | public | warehouse | 0 | 0 | 150170 |
150170 | 0 | 49399 | 0 | |
2007-06-05 15:39:41.059572+02 | | 2007-06-05 15:38:39.976122+02
16398 | public | orders | 0 | 0 | 96490 |
96519 | 51372 | 45930 | 0 | |
| |
16392 | public | customer | 0 | 0 | 233263 |
599917 | 0 | 95329 | 0 | |
| |
*** database log snippet ***
2007-06-05 15:42:09 CEST LOG: duration: 6020.820 ms statement: SELECT
* FROM order_status(1747, 291, 3, '')
2007-06-05 15:42:09 CEST LOG: duration: 688.730 ms statement: SELECT
payment(47, 2, 1533, 47, 2, '', 4295.460000)
2007-06-05 15:42:09 CEST LOG: duration: 5923.518 ms statement: SELECT
payment(319, 8, 0, 319, 8, 'OUGHTATIONEING', 2331.470000)
2007-06-05 15:42:09 CEST LOG: duration: 6370.433 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6463.583 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6358.047 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6114.972 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6193.684 ms statement: SELECT
payment(96, 10, 0, 96, 10, 'ESEOUGHTBAR', 997.050000)
2007-06-05 15:42:09 CEST LOG: duration: 6375.163 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6139.613 ms statement: SELECT
payment(454, 8, 0, 454, 8, 'ANTIOUGHTEING', 1575.110000)
2007-06-05 15:42:09 CEST LOG: duration: 6336.462 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6420.227 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6447.025 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 15549.277 ms statement: SELECT
delivery(124, 7)
2007-06-05 15:42:09 CEST LOG: duration: 1432.199 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 6478.086 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 1405.925 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:09 CEST LOG: duration: 8399.567 ms statement: SELECT
delivery(374, 4)
2007-06-05 15:42:10 CEST LOG: duration: 657.939 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 1159.131 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 840.907 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 616.234 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 1115.098 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 1332.445 ms statement: SELECT
payment(465, 6, 0, 465, 6, 'ABLEESEESE', 4660.790000)
2007-06-05 15:42:10 CEST LOG: duration: 855.661 ms statement: SELECT
payment(267, 6, 0, 267, 6, 'OUGHTEINGOUGHT', 4214.080000)
2007-06-05 15:42:10 CEST LOG: duration: 580.983 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 883.528 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 7757.581 ms statement: SELECT
delivery(126, 6)
2007-06-05 15:42:10 CEST LOG: duration: 537.642 ms statement: SELECT
payment(493, 2, 0, 493, 2, 'BARBARANTI', 2881.500000)
2007-06-05 15:42:10 CEST LOG: duration: 1035.529 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:10 CEST LOG: duration: 1007.521 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:11 CEST LOG: duration: 1088.356 ms statement: FETCH
ALL IN mycursor
2007-06-05 15:42:11 CEST LOG: duration: 1749.507 ms statement: SELECT
delivery(442, 5)
