Bug #1000195 “Performance issue in invoice analysis” : Bugs : Odoo Addons (MOVED TO GITHUB)

Revision history for this message

Lorenzo Battistini (elbati) wrote on 2012-05-22:

#1

Hello, same problem here.

Maybe this is related to bug 932524 .

Our customer has ~2500 invoices and ~1000 rows in res_currency_rate table.

While opening
accounting -> reporting -> statistics reports -> invoices analysis
on our server, postgresql logs the following durations:

2012-05-18 09:44:14 CEST [1458]: [1-1] user=openerp,db=xxxxx,remote=127.0.0.1(49168) LOG: duration: 12964.719 ms statement: SELECT min(account_invoice_report.id) AS id, count(account_invoice_report.id) AS categ_id_count,"account_invoice_report".categ_id, sum("account_invoice_report"."nbr") AS nbr, sum("account_invoice_report"."product_qty") AS product_qty, sum("account_invoice_report"."price_total") AS price_total FROM "account_invoice_report" WHERE ((((account_invoice_report."date" <= '2012-05-18') AND (account_invoice_report."date" >= '2012-01-01')) AND ((account_invoice_report."state" not in ('draft','cancel')) OR account_invoice_report."state" IS NULL)) AND ((account_invoice_report."type" = 'out_invoice') OR (account_invoice_report."type" = 'out_refund'))) GROUP BY "account_invoice_report".categ_id

2012-05-18 09:51:23 CEST [1458]: [2-1] user=openerp,db=xxxxx,remote=127.0.0.1(49168) LOG: duration: 429323.694 ms statement: SELECT "account_invoice_report".id FROM "account_invoice_report" LEFT JOIN "product_category" ON ("account_invoice_report"."categ_id" = "product_category"."id") WHERE (account_invoice_report."id" in (4219)) ORDER BY "product_category"."parent_left"

2012-05-18 09:58:42 CEST [1458]: [3-1] user=openerp,db=xxxxx,remote=127.0.0.1(49168) LOG: duration: 438652.536 ms statement: SELECT account_invoice_report."categ_id",account_invoice_report.id FROM "account_invoice_report" WHERE account_invoice_report.id IN (4219) ORDER BY date desc

Naresh(OpenERP) (nch-openerp) on 2012-05-23

Changed in openobject-addons:
assignee:	nobody → OpenERP Publisher's Warranty Team (openerp-opw)
tags:	added: maintenance

Revision history for this message

Numérigraphe (numerigraphe) wrote on 2012-07-06:

#2

The comments on bug #932524 certainly have a point: the currency rate feature is really dubious.
But even when I remove it, the query tiles out on our database (66000 invoice lines, 1200 products, 3 partners).
So there is probably more optimization work to do.
Lionel.

summary:	- Performance issue in sale 6.1 + Performance issue in invoice analysis
Changed in openobject-addons:
status:	New → Confirmed

Revision history for this message

Numérigraphe (numerigraphe) wrote on 2012-07-06:

#3

Dear OpenERP Publisher's Warranty Team, I marked bug #932524 a duplicate of this.
It was assigned to OpenERP R&D Addons Team 3. Can you please check who this bug should be assigned to?
Lionel.

Revision history for this message

Kellogs (jm-poure) wrote on 2012-07-09:

#4

Download full text (14.5 KiB)

This is a real design bug.

To analyse any query, please run:
EXPLAIN ANALYSE yourSQL query

i.e.
EXPLAIN ANALYSE
SELECT min(account_invoice_report.id) AS id, count(account_invoice_report.id) AS categ_id_count,"account_invoice_report".categ_id, sum("account_invoice_report"."nbr") AS nbr, sum("account_invoice_report"."product_qty") AS product_qty, sum("account_invoice_report"."price_total") AS price_total FROM "account_invoice_report" WHERE ((((account_invoice_report."date" <= '2012-05-18') AND (account_invoice_report."date" >= '2012-01-01')) AND ((account_invoice_report."state" not in ('draft','cancel')) OR account_invoice_report."state" IS NULL)) AND ((account_invoice_report."type" = 'out_invoice') OR (account_invoice_report."type" = 'out_refund'))) GROUP BY "account_invoice_report".categ_id

On my server, even with on 3000 clients ...
the query returns a result in 20 seconds.

"HashAggregate (cost=267661920.65..267661925.15 rows=200 width=32) (actual time=20619.984..20619.986 rows=2 loops=1)"
" -> GroupAggregate (cost=2363456.42..267585641.15 rows=3051180 width=184) (actual time=20459.610..20617.810 rows=1257 loops=1)"
" -> Sort (cost=2363456.42..2371084.37 rows=3051180 width=184) (actual time=20459.384..20459.784 rows=1265 loops=1)"
" Sort Key: ail.product_id, ai.date_invoice, ai.id, cr.rate, (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'MM'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY-MM-DD'::text)), ai.partner_id, ai.payment_term, ai.period_id, u.name, ai.currency_id, ai.journal_id, ai.fiscal_position, ai.user_id, ai.company_id, ai.type, ai.state, pt.categ_id, ai.date_due, ai.address_contact_id, ai.address_invoice_id, ai.account_id, ai.partner_bank_id, ai.residual, ai.amount_total, u.uom_type, u.category_id"
" Sort Method: quicksort Memory: 701kB"
" -> Merge Join (cost=0.00..1492526.05 rows=3051180 width=184) (actual time=11.478..20452.364 rows=1265 loops=1)"
" Merge Cond: (ail.invoice_id = ai.id)"
" -> Nested Loop Left Join (cost=0.00..1475.72 rows=3084 width=86) (actual time=0.067..25.090 rows=2646 loops=1)"
" Join Filter: (u.id = ail.uos_id)"
" -> Nested Loop Left Join (cost=0.00..1058.26 rows=3084 width=68) (actual time=0.047..15.025 rows=2646 loops=1)"
" -> Index Scan using account_invoice_line_invoice_id_index on account_invoice_line ail (cost=0.00..170.50 rows=3084 width=64) (actual time=0.034..3.749 rows=2646 loops=1)"
" -> Index Scan using product_template_pkey on product_template pt (cost=0.00..0.28 rows=1 width=8) (actual time=0.002..0.003 rows=1 loops=2646)"
" Index Cond: (pt.id = ail.product_id)"
" -> Materialize (cost=0.00..1.14 rows=9 width=26) (actual time=0.000..0.001 rows=9 loops=2646)"
" -> Seq Scan on product_uom u (cost=0.00..1.09 rows=9 width=26) (actual time=0.004..0.010 rows=9 loops=1)"
" ...

This is a real design bug.

To analyse any query, please run:
EXPLAIN ANALYSE yourSQL query

i.e.
EXPLAIN ANALYSE 
SELECT min(account_invoice_report.id) AS id, count(account_invoice_report.id) AS categ_id_count,"account_invoice_report".categ_id, sum("account_invoice_report"."nbr") AS nbr, sum("account_invoice_report"."product_qty") AS product_qty, sum("account_invoice_report"."price_total") AS price_total FROM "account_invoice_report" WHERE ((((account_invoice_report."date" <= '2012-05-18') AND (account_invoice_report."date" >= '2012-01-01')) AND ((account_invoice_report."state" not in ('draft','cancel')) OR account_invoice_report."state" IS NULL)) AND ((account_invoice_report."type" = 'out_invoice') OR (account_invoice_report."type" = 'out_refund'))) GROUP BY "account_invoice_report".categ_id

On my server, even with on 3000 clients ...
the query returns a result in 20 seconds.

"HashAggregate  (cost=267661920.65..267661925.15 rows=200 width=32) (actual time=20619.984..20619.986 rows=2 loops=1)"
"  ->  GroupAggregate  (cost=2363456.42..267585641.15 rows=3051180 width=184) (actual time=20459.610..20617.810 rows=1257 loops=1)"
"        ->  Sort  (cost=2363456.42..2371084.37 rows=3051180 width=184) (actual time=20459.384..20459.784 rows=1265 loops=1)"
"              Sort Key: ail.product_id, ai.date_invoice, ai.id, cr.rate, (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'MM'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY-MM-DD'::text)), ai.partner_id, ai.payment_term, ai.period_id, u.name, ai.currency_id, ai.journal_id, ai.fiscal_position, ai.user_id, ai.company_id, ai.type, ai.state, pt.categ_id, ai.date_due, ai.address_contact_id, ai.address_invoice_id, ai.account_id, ai.partner_bank_id, ai.residual, ai.amount_total, u.uom_type, u.category_id"
"              Sort Method:  quicksort  Memory: 701kB"
"              ->  Merge Join  (cost=0.00..1492526.05 rows=3051180 width=184) (actual time=11.478..20452.364 rows=1265 loops=1)"
"                    Merge Cond: (ail.invoice_id = ai.id)"
"                    ->  Nested Loop Left Join  (cost=0.00..1475.72 rows=3084 width=86) (actual time=0.067..25.090 rows=2646 loops=1)"
"                          Join Filter: (u.id = ail.uos_id)"
"                          ->  Nested Loop Left Join  (cost=0.00..1058.26 rows=3084 width=68) (actual time=0.047..15.025 rows=2646 loops=1)"
"                                ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line ail  (cost=0.00..170.50 rows=3084 width=64) (actual time=0.034..3.749 rows=2646 loops=1)"
"                                ->  Index Scan using product_template_pkey on product_template pt  (cost=0.00..0.28 rows=1 width=8) (actual time=0.002..0.003 rows=1 loops=2646)"
"                                      Index Cond: (pt.id = ail.product_id)"
"                          ->  Materialize  (cost=0.00..1.14 rows=9 width=26) (actual time=0.000..0.001 rows=9 loops=2646)"
"                                ->  Seq Scan on product_uom u  (cost=0.00..1.09 rows=9 width=26) (actual time=0.004..0.010 rows=9 loops=1)"
"                    ->  Materialize  (cost=0.00..1416063.69 rows=1565388 width=102) (actual time=1.818..20416.193 rows=1264 loops=1)"
"                          ->  Nested Loop  (cost=0.00..1412150.22 rows=1565388 width=102) (actual time=1.812..20415.160 rows=445 loops=1)"
"                                Join Filter: (SubPlan 6)"
"                                ->  Index Scan using account_invoice_pkey on account_invoice ai  (cost=0.00..145.14 rows=354 width=92) (actual time=0.867..4.586 rows=445 loops=1)"
"                                      Filter: ((date_invoice <= '2012-05-18'::date) AND (date_invoice >= '2012-01-01'::date) AND (((state)::text <> ALL ('{draft,cancel}'::text[])) OR (state IS NULL)) AND (((type)::text = 'out_invoice'::text) OR ((type)::text = 'out_refund'::text)))"
"                                ->  Materialize  (cost=0.00..206.66 rows=8844 width=18) (actual time=0.000..0.798 rows=8763 loops=445)"
"                                      ->  Seq Scan on res_currency_rate cr  (cost=0.00..162.44 rows=8844 width=18) (actual time=0.009..2.100 rows=8763 loops=1)"
"                                SubPlan 6"
"                                  ->  Limit  (cost=0.01..0.86 rows=1 width=4) (actual time=0.005..0.005 rows=1 loops=3899535)"
"                                        ->  Result  (cost=0.01..184.56 rows=216 width=4) (actual time=0.004..0.004 rows=1 loops=3899535)"
"                                              One-Time Filter: ((($3 IS NOT NULL) AND ($4 <= $3)) OR (($3 IS NULL) AND ($4 <= now())))"
"                                              ->  Seq Scan on res_currency_rate cr2  (cost=0.01..184.56 rows=216 width=4) (actual time=0.007..0.007 rows=1 loops=2354355)"
"                                                    Filter: (currency_id = $2)"
"        SubPlan 1"
"          ->  Seq Scan on product_uom  (cost=0.00..1.14 rows=1 width=3) (never executed)"
"                Filter: (((uom_type)::text = 'reference'::text) AND (category_id = $0))"
"        SubPlan 2"
"          ->  Aggregate  (cost=16.62..16.63 rows=1 width=4) (actual time=0.009..0.009 rows=1 loops=1257)"
"                ->  Nested Loop  (cost=0.00..16.61 rows=2 width=4) (actual time=0.006..0.007 rows=4 loops=1257)"
"                      ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=4) (actual time=0.003..0.003 rows=1 loops=1257)"
"                            Index Cond: (id = $1)"
"                      ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=8) (actual time=0.002..0.002 rows=4 loops=1257)"
"                            Index Cond: (l.invoice_id = $1)"
"        SubPlan 3"
"          ->  Aggregate  (cost=26.11..26.14 rows=1 width=12) (actual time=0.054..0.054 rows=1 loops=1265)"
"                ->  Nested Loop Left Join  (cost=0.00..26.10 rows=6 width=12) (actual time=0.008..0.022 rows=22 loops=1265)"
"                      Join Filter: (a.id = l.invoice_id)"
"                      ->  Nested Loop  (cost=0.00..17.68 rows=3 width=8) (actual time=0.005..0.009 rows=5 loops=1265)"
"                            ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=1265)"
"                                  Index Cond: (id = $1)"
"                            ->  Index Scan using account_move_line_move_id_index on account_move_line aml  (cost=0.00..9.38 rows=3 width=8) (actual time=0.002..0.003 rows=5 loops=1265)"
"                                  Index Cond: (aml.move_id = a.move_id)"
"                      ->  Materialize  (cost=0.00..8.33 rows=2 width=12) (actual time=0.001..0.001 rows=4 loops=6590)"
"                            ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=12) (actual time=0.002..0.003 rows=4 loops=1260)"
"                                  Index Cond: (invoice_id = $1)"
"        SubPlan 4"
"          ->  Aggregate  (cost=26.11..26.14 rows=1 width=8) (actual time=0.037..0.037 rows=1 loops=1265)"
"                ->  Nested Loop Left Join  (cost=0.00..26.10 rows=6 width=8) (actual time=0.009..0.021 rows=22 loops=1265)"
"                      Join Filter: (a.id = l.invoice_id)"
"                      ->  Nested Loop  (cost=0.00..17.68 rows=3 width=12) (actual time=0.005..0.008 rows=5 loops=1265)"
"                            ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=16) (actual time=0.002..0.002 rows=1 loops=1265)"
"                                  Index Cond: (id = $1)"
"                            ->  Index Scan using account_move_line_move_id_index on account_move_line aml  (cost=0.00..9.38 rows=3 width=4) (actual time=0.002..0.004 rows=5 loops=1265)"
"                                  Index Cond: (aml.move_id = a.move_id)"
"                      ->  Materialize  (cost=0.00..8.33 rows=2 width=4) (actual time=0.001..0.001 rows=4 loops=6590)"
"                            ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=4) (actual time=0.002..0.004 rows=4 loops=1260)"
"                                  Index Cond: (invoice_id = $1)"
"        SubPlan 5"
"          ->  Aggregate  (cost=16.62..16.63 rows=1 width=4) (actual time=0.007..0.007 rows=1 loops=1257)"
"                ->  Nested Loop  (cost=0.00..16.61 rows=2 width=4) (actual time=0.004..0.006 rows=4 loops=1257)"
"                      ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=1257)"
"                            Index Cond: (id = $1)"
"                      ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=8) (actual time=0.001..0.002 rows=4 loops=1257)"
"                            Index Cond: (l.invoice_id = $1)"
"Total runtime: 20621.529 ms"

Let's try to understand what is going on.

account_invoice_report is a view, which definition is:

-- View: account_invoice_report

CREATE OR REPLACE VIEW account_invoice_report AS 
 SELECT min(ail.id) AS id, ai.date_invoice AS date, to_char(ai.date_invoice::timestamp with time zone, 'YYYY'::text) AS year, to_char(ai.date_invoice::timestamp with time zone, 'MM'::text) AS month, to_char(ai.date_invoice::timestamp with time zone, 'YYYY-MM-DD'::text) AS day, ail.product_id, ai.partner_id, ai.payment_term, ai.period_id, 
        CASE
            WHEN u.uom_type::text <> 'reference'::text THEN ( SELECT product_uom.name
               FROM product_uom
              WHERE product_uom.uom_type::text = 'reference'::text AND product_uom.category_id = u.category_id)
            ELSE u.name
        END AS uom_name, ai.currency_id, ai.journal_id, ai.fiscal_position, ai.user_id, ai.company_id, count(ail.*) AS nbr, ai.type, ai.state, pt.categ_id, ai.date_due, ai.address_contact_id, ai.address_invoice_id, ai.account_id, ai.partner_bank_id, sum(
        CASE
            WHEN ai.type::text = ANY (ARRAY['out_refund'::character varying, 'in_invoice'::character varying]::text[]) THEN ail.quantity / u.factor::double precision * (-1)::double precision
            ELSE ail.quantity / u.factor::double precision
        END) AS product_qty, sum(
        CASE
            WHEN ai.type::text = ANY (ARRAY['out_refund'::character varying, 'in_invoice'::character varying]::text[]) THEN ail.quantity * ail.price_unit::double precision * (-1)::double precision
            ELSE ail.quantity * ail.price_unit::double precision
        END) / cr.rate::double precision AS price_total, sum(
        CASE
            WHEN ai.type::text = ANY (ARRAY['out_refund'::character varying, 'in_invoice'::character varying]::text[]) THEN ai.amount_total * (-1)::numeric
            ELSE ai.amount_total
        END) / (( SELECT count(l.id) AS count
           FROM account_invoice_line l
      LEFT JOIN account_invoice a ON a.id = l.invoice_id
     WHERE a.id = ai.id))::numeric / cr.rate AS price_total_tax, 
        CASE
            WHEN ai.type::text = ANY (ARRAY['out_refund'::character varying, 'in_invoice'::character varying]::text[]) THEN sum(ail.quantity * ail.price_unit::double precision * (-1)::double precision)
            ELSE sum(ail.quantity * ail.price_unit::double precision)
        END / 
        CASE
            WHEN ai.type::text = ANY (ARRAY['out_refund'::character varying, 'in_invoice'::character varying]::text[]) THEN sum(ail.quantity / u.factor::double precision * (-1)::double precision)
            ELSE sum(ail.quantity / u.factor::double precision)
        END / cr.rate::double precision AS price_average, cr.rate AS currency_rate, sum(( SELECT date_part('epoch'::text, avg(date_trunc('day'::text, aml.date_created::timestamp with time zone) - date_trunc('day'::text, l.create_date)::timestamp with time zone)) / (24 * 60 * 60)::numeric(16,2)::double precision
           FROM account_move_line aml
      LEFT JOIN account_invoice a ON a.move_id = aml.move_id
   LEFT JOIN account_invoice_line l ON a.id = l.invoice_id
  WHERE a.id = ai.id)) AS delay_to_pay, sum(( SELECT date_part('epoch'::text, avg(date_trunc('day'::text, a.date_due::timestamp with time zone) - date_trunc('day'::text, a.date_invoice::timestamp with time zone))) / (24 * 60 * 60)::numeric(16,2)::double precision
           FROM account_move_line aml
      LEFT JOIN account_invoice a ON a.move_id = aml.move_id
   LEFT JOIN account_invoice_line l ON a.id = l.invoice_id
  WHERE a.id = ai.id)) AS due_delay, 
        CASE
            WHEN ai.type::text = ANY (ARRAY['out_refund'::character varying, 'in_invoice'::character varying]::text[]) THEN ai.residual * (-1)::numeric
            ELSE ai.residual
        END / (( SELECT count(l.id) AS count
           FROM account_invoice_line l
      LEFT JOIN account_invoice a ON a.id = l.invoice_id
     WHERE a.id = ai.id))::numeric / cr.rate AS residual
   FROM account_invoice_line ail
   LEFT JOIN account_invoice ai ON ai.id = ail.invoice_id
   LEFT JOIN product_template pt ON pt.id = ail.product_id
   LEFT JOIN product_uom u ON u.id = ail.uos_id, res_currency_rate cr
  WHERE (cr.id IN ( SELECT cr2.id
   FROM res_currency_rate cr2
  WHERE cr2.currency_id = ai.currency_id AND (ai.date_invoice IS NOT NULL AND cr.name <= ai.date_invoice OR ai.date_invoice IS NULL AND cr.name <= now())
 LIMIT 1))
  GROUP BY ail.product_id, ai.date_invoice, ai.id, cr.rate, to_char(ai.date_invoice::timestamp with time zone, 'YYYY'::text), to_char(ai.date_invoice::timestamp with time zone, 'MM'::text), to_char(ai.date_invoice::timestamp with time zone, 'YYYY-MM-DD'::text), ai.partner_id, ai.payment_term, ai.period_id, u.name, ai.currency_id, ai.journal_id, ai.fiscal_position, ai.user_id, ai.company_id, ai.type, ai.state, pt.categ_id, ai.date_due, ai.address_contact_id, ai.address_invoice_id, ai.account_id, ai.partner_bank_id, ai.residual, ai.amount_total, u.uom_type, u.category_id;

ALTER TABLE account_invoice_report
  OWNER TO openerp;

First, there are design problems in the view.

1) In a view, you never use conversion to cast a type.
to_char(ai.date_invoice::timestamp with time zone, 'YYYY'::text) AS year
In PostgreSQL, casting is done automatically in queries, not views.

2) use of case ...
will make the database run sequential scans.

This should be replaced either with a UNION/INTERSEC or temporary table.
There is no possibility to make this query run better.

This is really an incledible query, as it tries to achieve something relatively easy but breaks nearly ALL SQL optimization rules.

Revision history for this message

Kellogs (jm-poure) wrote on 2012-07-09:

#5

Download full text (9.0 KiB)

EXPLAIN ANALYSE
SELECT *
FROM account_invoice_report
LIMIT 1

returns a result in ... 110 seconds.

If this is a usual design problem in OpenERP, I would suggest that you invest in SSD disc and boost PostgreSQL memory.
When a database has a bad designe, it is always necessary to run SSD disc to make sequential scans much faster.

The result of the EXPLAIN ANALYSE:

"Limit (cost=16545936.29..16546023.23 rows=1 width=554) (actual time=110458.111..110458.111 rows=1 loops=1)"
" -> Subquery Scan on account_invoice_report (cost=16545936.29..1202110162.52 rows=13637448 width=554) (actual time=110458.109..110458.109 rows=1 loops=1)"
" -> GroupAggregate (cost=16545936.29..1201973788.04 rows=13637448 width=184) (actual time=110458.107..110458.107 rows=1 loops=1)"
" -> Sort (cost=16545936.29..16580029.91 rows=13637448 width=184) (actual time=110457.872..110457.873 rows=2 loops=1)"
" Sort Key: ail.product_id, ai.date_invoice, ai.id, cr.rate, (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'MM'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY-MM-DD'::text)), ai.partner_id, ai.payment_term, ai.period_id, u.name, ai.currency_id, ai.journal_id, ai.fiscal_position, ai.user_id, ai.company_id, ai.type, ai.state, pt.categ_id, ai.date_due, ai.address_contact_id, ai.address_invoice_id, ai.account_id, ai.partner_bank_id, ai.residual, ai.amount_total, u.uom_type, u.category_id"
" Sort Method: quicksort Memory: 1660kB"
" -> Nested Loop (cost=0.00..12505977.72 rows=13637448 width=184) (actual time=285.840..110434.834 rows=3032 loops=1)"
" Join Filter: (SubPlan 6)"
" -> Nested Loop Left Join (cost=0.00..1642.35 rows=3084 width=174) (actual time=0.093..71.748 rows=3085 loops=1)"
" -> Nested Loop Left Join (cost=0.00..754.58 rows=3084 width=170) (actual time=0.081..39.953 rows=3085 loops=1)"
" Join Filter: (u.id = ail.uos_id)"
" -> Merge Right Join (cost=0.00..337.13 rows=3084 width=152) (actual time=0.063..27.645 rows=3085 loops=1)"
" Merge Cond: (ai.id = ail.invoice_id)"
" -> Index Scan using account_invoice_pkey on account_invoice ai (cost=0.00..125.44 rows=1576 width=92) (actual time=0.021..2.644 rows=1578 loops=1)"
" -> Index Scan using account_invoice_line_invoice_id_index on account_invoice_line ail (cost=0.00..170.50 rows=3084 width=64) (actual time=0.024..9.737 rows=3085 loops=1)"
" -> Materialize (cost=0.00..1.14 rows=9 width=26) (actual time=0.000..0.001 rows=9 loops=3085)"
" -> Seq Scan on product_uom u (cost=0.00..1.09 rows=9 width=26) (actual time=0.004..0.008 rows=9 loops=1)"
" -> Index Scan using product_template_pkey on product_template pt (cost=0.00..0.28 rows=1 width...

EXPLAIN ANALYSE 
SELECT *
FROM account_invoice_report
LIMIT 1

returns a result in ... 110 seconds.

If this is a usual design problem in OpenERP, I would suggest that you invest in SSD disc and boost PostgreSQL memory.
When a database has a bad designe, it is always necessary to run SSD disc to make sequential scans much faster.

The result of the EXPLAIN ANALYSE:

"Limit  (cost=16545936.29..16546023.23 rows=1 width=554) (actual time=110458.111..110458.111 rows=1 loops=1)"
"  ->  Subquery Scan on account_invoice_report  (cost=16545936.29..1202110162.52 rows=13637448 width=554) (actual time=110458.109..110458.109 rows=1 loops=1)"
"        ->  GroupAggregate  (cost=16545936.29..1201973788.04 rows=13637448 width=184) (actual time=110458.107..110458.107 rows=1 loops=1)"
"              ->  Sort  (cost=16545936.29..16580029.91 rows=13637448 width=184) (actual time=110457.872..110457.873 rows=2 loops=1)"
"                    Sort Key: ail.product_id, ai.date_invoice, ai.id, cr.rate, (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'MM'::text)), (to_char((ai.date_invoice)::timestamp with time zone, 'YYYY-MM-DD'::text)), ai.partner_id, ai.payment_term, ai.period_id, u.name, ai.currency_id, ai.journal_id, ai.fiscal_position, ai.user_id, ai.company_id, ai.type, ai.state, pt.categ_id, ai.date_due, ai.address_contact_id, ai.address_invoice_id, ai.account_id, ai.partner_bank_id, ai.residual, ai.amount_total, u.uom_type, u.category_id"
"                    Sort Method:  quicksort  Memory: 1660kB"
"                    ->  Nested Loop  (cost=0.00..12505977.72 rows=13637448 width=184) (actual time=285.840..110434.834 rows=3032 loops=1)"
"                          Join Filter: (SubPlan 6)"
"                          ->  Nested Loop Left Join  (cost=0.00..1642.35 rows=3084 width=174) (actual time=0.093..71.748 rows=3085 loops=1)"
"                                ->  Nested Loop Left Join  (cost=0.00..754.58 rows=3084 width=170) (actual time=0.081..39.953 rows=3085 loops=1)"
"                                      Join Filter: (u.id = ail.uos_id)"
"                                      ->  Merge Right Join  (cost=0.00..337.13 rows=3084 width=152) (actual time=0.063..27.645 rows=3085 loops=1)"
"                                            Merge Cond: (ai.id = ail.invoice_id)"
"                                            ->  Index Scan using account_invoice_pkey on account_invoice ai  (cost=0.00..125.44 rows=1576 width=92) (actual time=0.021..2.644 rows=1578 loops=1)"
"                                            ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line ail  (cost=0.00..170.50 rows=3084 width=64) (actual time=0.024..9.737 rows=3085 loops=1)"
"                                      ->  Materialize  (cost=0.00..1.14 rows=9 width=26) (actual time=0.000..0.001 rows=9 loops=3085)"
"                                            ->  Seq Scan on product_uom u  (cost=0.00..1.09 rows=9 width=26) (actual time=0.004..0.008 rows=9 loops=1)"
"                                ->  Index Scan using product_template_pkey on product_template pt  (cost=0.00..0.28 rows=1 width=8) (actual time=0.005..0.008 rows=1 loops=3085)"
"                                      Index Cond: (pt.id = ail.product_id)"
"                          ->  Materialize  (cost=0.00..206.66 rows=8844 width=18) (actual time=0.000..0.759 rows=8763 loops=3085)"
"                                ->  Seq Scan on res_currency_rate cr  (cost=0.00..162.44 rows=8844 width=18) (actual time=0.008..2.570 rows=8763 loops=1)"
"                          SubPlan 6"
"                            ->  Limit  (cost=0.01..0.86 rows=1 width=4) (actual time=0.004..0.004 rows=0 loops=27033855)"
"                                  ->  Result  (cost=0.01..184.56 rows=216 width=4) (actual time=0.003..0.003 rows=0 loops=27033855)"
"                                        One-Time Filter: ((($3 IS NOT NULL) AND ($4 <= $3)) OR (($3 IS NULL) AND ($4 <= now())))"
"                                        ->  Seq Scan on res_currency_rate cr2  (cost=0.01..184.56 rows=216 width=4) (actual time=0.007..0.007 rows=1 loops=12014463)"
"                                              Filter: (currency_id = $2)"
"              SubPlan 1"
"                ->  Seq Scan on product_uom  (cost=0.00..1.14 rows=1 width=3) (never executed)"
"                      Filter: (((uom_type)::text = 'reference'::text) AND (category_id = $0))"
"              SubPlan 2"
"                ->  Aggregate  (cost=16.62..16.63 rows=1 width=4) (actual time=0.012..0.012 rows=1 loops=1)"
"                      ->  Nested Loop  (cost=0.00..16.61 rows=2 width=4) (actual time=0.008..0.009 rows=2 loops=1)"
"                            ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=4) (actual time=0.004..0.004 rows=1 loops=1)"
"                                  Index Cond: (id = $1)"
"                            ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=8) (actual time=0.002..0.003 rows=2 loops=1)"
"                                  Index Cond: (l.invoice_id = $1)"
"              SubPlan 3"
"                ->  Aggregate  (cost=26.11..26.14 rows=1 width=12) (actual time=0.059..0.059 rows=1 loops=1)"
"                      ->  Nested Loop Left Join  (cost=0.00..26.10 rows=6 width=12) (actual time=0.024..0.033 rows=6 loops=1)"
"                            Join Filter: (a.id = l.invoice_id)"
"                            ->  Nested Loop  (cost=0.00..17.68 rows=3 width=8) (actual time=0.008..0.011 rows=3 loops=1)"
"                                  ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=8) (actual time=0.002..0.003 rows=1 loops=1)"
"                                        Index Cond: (id = $1)"
"                                  ->  Index Scan using account_move_line_move_id_index on account_move_line aml  (cost=0.00..9.38 rows=3 width=8) (actual time=0.001..0.003 rows=3 loops=1)"
"                                        Index Cond: (aml.move_id = a.move_id)"
"                            ->  Materialize  (cost=0.00..8.33 rows=2 width=12) (actual time=0.005..0.005 rows=2 loops=3)"
"                                  ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=12) (actual time=0.003..0.004 rows=2 loops=1)"
"                                        Index Cond: (invoice_id = $1)"
"              SubPlan 4"
"                ->  Aggregate  (cost=26.11..26.14 rows=1 width=8) (actual time=0.078..0.078 rows=1 loops=1)"
"                      ->  Nested Loop Left Join  (cost=0.00..26.10 rows=6 width=8) (actual time=0.044..0.054 rows=6 loops=1)"
"                            Join Filter: (a.id = l.invoice_id)"
"                            ->  Nested Loop  (cost=0.00..17.68 rows=3 width=12) (actual time=0.026..0.029 rows=3 loops=1)"
"                                  ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=16) (actual time=0.014..0.014 rows=1 loops=1)"
"                                        Index Cond: (id = $1)"
"                                  ->  Index Scan using account_move_line_move_id_index on account_move_line aml  (cost=0.00..9.38 rows=3 width=4) (actual time=0.007..0.010 rows=3 loops=1)"
"                                        Index Cond: (aml.move_id = a.move_id)"
"                            ->  Materialize  (cost=0.00..8.33 rows=2 width=4) (actual time=0.003..0.004 rows=2 loops=3)"
"                                  ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=4) (actual time=0.007..0.008 rows=2 loops=1)"
"                                        Index Cond: (invoice_id = $1)"
"              SubPlan 5"
"                ->  Aggregate  (cost=16.62..16.63 rows=1 width=4) (actual time=0.010..0.010 rows=1 loops=1)"
"                      ->  Nested Loop  (cost=0.00..16.61 rows=2 width=4) (actual time=0.006..0.007 rows=2 loops=1)"
"                            ->  Index Scan using account_invoice_pkey on account_invoice a  (cost=0.00..8.27 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=1)"
"                                  Index Cond: (id = $1)"
"                            ->  Index Scan using account_invoice_line_invoice_id_index on account_invoice_line l  (cost=0.00..8.32 rows=2 width=8) (actual time=0.001..0.001 rows=2 loops=1)"
"                                  Index Cond: (l.invoice_id = $1)"
"Total runtime: 110459.471 ms"

The query is running slow because of

GROUP BY .... to_char(ai.date_invoice::timestamp with time zone, 'YYYY'::text), to_char(ai.date_invoice::timestamp with time zone, 'MM'::text), to_char(ai.date_invoice::timestamp with time zone, 'YYYY-MM-DD'::text)

This obliges PostgreSQL to run a huge sequential scan on each query, just to build the data corresponding to yyyy (year), mm (month), etc ... I suspect if this was hard-coded in the table, the query would run faster.

Revision history for this message

Kellogs (jm-poure) wrote on 2012-07-09:

#6

I am buying an SSD :)
There is no simple way to around ...

Revision history for this message

Numérigraphe (numerigraphe) wrote on 2012-07-09: Re: [Bug 1000195] Re: Performance issue in invoice analysis

#7

Le 09/07/2012 17:26, Kellogs a écrit :
> I am buying an SSD :)
> There is no simple way to around ...
>
To bad, I'm already using and SSD :)
I hope someone has the time (and courage :) ) to tackle this.
Lionel.

Revision history for this message

Normunds (Alistek) (3pm) wrote on 2013-02-14:

#8

We checked overall performance with SSD and ordinary disk along with not fast processor- no noticable difference.

Revision history for this message

Ronald Portier (Therp) (rportier1962) wrote on 2013-02-14:

#9

No amount of hardware is going to solve problems with bad design.

These kind of queries should simply not be run on opening an application, like going to the sales module. Or should not be run at all, if hte information is needed, rewrite and redesign to get acceptabel performance, instead of hoping that throwing hardware at a problem will make it go away.

In the meantime people might be helped by the following branch, created by Akretion, that among other things allows to disable the sale dashboard:

https://code.launchpad.net/~akretion-team/+junk/addons-no-fluff

Revision history for this message

Francisco Peiro (francisco-peiro) wrote on 2013-05-16:

#10

update_account_invoice_report.patch Edit (1.3 KiB, text/plain)

Hello,

I have read your bug report,

After analyzing the issue, I've been able to create the table account_invoice_report reducing computational time from 3 min to 10 secs. I attach the patch.

Thanks and waiting for your comments!

Francisco Peiró
Factor Libre

Martin Trigaux (OpenERP) (mat-openerp) on 2013-10-04

Changed in openobject-addons:
status:	Confirmed → Fix Released

Revision history for this message

Martin Trigaux (OpenERP) (mat-openerp) wrote on 2013-10-04:

#11

account_invoice_report_zero.diff Edit (1.4 KiB, text/plain)

Hello,

As you have noticed, the delay is due to the computation of the fields delay_to_pay and due_delay. We have improved the computation to a faster version of the query.

revno: 7254
revision-id: <email address hidden>

Please note that this is not a full fix, it will improve the delay but it's still slow on big databases. If these two fields are not mandatory to you, removing the computation (patch attached, will always return 0) will have way better results.

On a test database, a simple query on account_invoice_report, went from impossible to compute (stopped the computation after some time) to 24sec with the merged patch at revision 7254. Without these two fields (attached patch), it takes 3sec.

Also please note that these fields have been removed in 7.0 (too slow and had an ambiguous meaning)

Serpent Consulting Services (serpent-consulting-services) on 2013-10-07

Changed in openobject-addons:
importance:	Undecided → Medium
milestone:	none → 6.1

Revision history for this message

Yann Papouin (yann-papouin) wrote on 2013-12-11:

#12

This fix [1] is not released in the official 6.1 branch [2].
Please update bug status.

[1] http://bazaar.launchpad.net/~openerp-dev/openobject-addons/6.1-opw-575095-acl/view/head:/account/report/account_invoice_report.py
[2] http://bazaar.launchpad.net/~openerp/openobject-addons/6.1/view/head:/account/report/account_invoice_report.py

Odoo Addons (MOVED TO GITHUB)

Performance issue in invoice analysis

Bug Description

Related branches

Duplicates of this bug

Other bug subscribers

Patches

Remote bug watches