openerp-community team mailing list archive

Thread
Date
Re: mrp scheduler

To: openerp-community@xxxxxxxxxxxxxxxxxxx
From: Alexandre Fayolle <alexandre.fayolle@xxxxxxxxxxxxxx>
Date: Wed, 18 Dec 2013 08:48:08 +0100
In-reply-to: <52B12BFF.3060500@theforce.com.au>
Organization: camptocamp
User-agent: Mozilla/5.0 (X11; Linux i686; rv:24.0) Gecko/20100101 Thunderbird/24.2.0
Is your cron configured with Repeat Missed set ? If so this could be the
case.

Alexandre



On 18/12/2013 06:00, Grahame Jordan wrote:
> Hi,
>
> I have a problem with the mrp scheduler when running on 7,000 products.
>
> I am running on 2 x quad core 3.0GHz, 32 GB RAM, RAID10 SSD for DB,
> Ubuntu 12.04 LTS. V6.1.
>
> When running from Warehouse -> Schedulers -> Compute Schedulers the
> performance is as expected. ~30 minutes to complete on 4351 procurements.
>
> When running from ir.cron the performance is up to 20x worse.  6 - 10
> hours.
>
> Is there some extra overhead when running from ir.cron?
> Is it possible to enhance this?
>
> Some timings below to show the problem. The first one is from manually
> invoking the scheduler, the second is invoked from ir.cron.
> Read from the bottom to the top.
>
> 2013-12-18 04:48:21,854 8706 INFO ? procurement:
> procurement.order._procure_orderpoint_confirm(): #1: qty: 385        
> START::             44/100 : 2144/4351 : 2144 : V75-4x2.5
> 2013-12-18 04:48:21,884 8706 INFO ? stock:
> stock.move.create_chained_picking(): #1:                 
> TIMING::            0.002s
> 2013-12-18 04:48:21,887 8706 INFO ? procurement:
> procurement.order._procure_orderpoint_confirm(): #6: button_confirm: 
> TIMING::            0.048s
> 2013-12-18 04:48:21,911 8706 INFO ? procurement:
> procurement.order.check_produce(): #3:                 
> TIMING::                    0.015s
> 2013-12-18 04:48:21,949 8706 INFO ? mrp:
> procurement.order.make_mo():                             #1:
> prod.create():   TIMING::                    0.036s
> 2013-12-18 04:48:21,985 8706 INFO ? mrp:
> mrp.bom._bom_explode():                                  #1: bom
> :          TIMING::                           0.005s
> 2013-12-18 04:48:21,985 8706 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #1: bom :          
> TIMING::                           0.026s
> 2013-12-18 04:48:21,986 8706 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #2: :         
> TIMING::                           0.000s
> 2013-12-18 04:48:22,050 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               0.107s
> 2013-12-18 04:48:22,074 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.039s
> 2013-12-18 04:48:22,074 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.040s
> 2013-12-18 04:48:22,142 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               0.113s
> 2013-12-18 04:48:22,178 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.059s
> 2013-12-18 04:48:22,178 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.060s
> 2013-12-18 04:48:22,258 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               0.134s
> 2013-12-18 04:48:22,305 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.078s
> 2013-12-18 04:48:22,305 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.079s
> 2013-12-18 04:48:22,381 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               0.126s
> 2013-12-18 04:48:22,437 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.092s
> 2013-12-18 04:48:22,437 8706 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.093s
> 2013-12-18 04:48:22,437 8706 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #3: :         
> TIMING::                           0.752s
> 2013-12-18 04:48:22,479 8706 INFO ? mrp_geicp:
> mrp.production.update_production_bom_information():#1: :          
> TIMING::                               0.070s
> 2013-12-18 04:48:22,505 8706 INFO ? mrp_geicp:
> mrp.production.update_production_bom_information():#2: :          
> TIMING::                               0.043s
> 2013-12-18 04:48:22,534 8706 INFO ? mrp_geicp:
> mrp.production.update_production_bom_information():#3: :          
> TIMING::                               0.048s
> 2013-12-18 04:48:22,534 8706 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #4:
> update:          TIMING::                           0.162s
> 2013-12-18 04:48:22,534 8706 INFO ? mrp:
> mrp.production.test_if_product():                        #1:
> action_compute:  TIMING::                        0.966s
> 2013-12-18 04:48:22,573 8706 INFO ? mrp:
> procurement.order.make_mo():                             #3:
> button_confirm:  TIMING::                    1.040s
> 2013-12-18 04:48:22,573 8706 INFO ? mrp_geicp:
> procurement.order.make_mo():                       #1:
> super.make_mo()  TIMING::                1.079s
> 2013-12-18 04:48:22,582 8706 INFO ? procurement:
> procurement.order._procure_orderpoint_confirm(): #7: button_check:   
> TIMING::            1.158s
>
>
>
> 2013-12-18 03:59:53,691 7820 INFO ? procurement:
> procurement.order._procure_orderpoint_confirm(): #1: qty: 3075       
> START::             60/100 : 1460/4351 : 1460 : 50-100-0812
> 2013-12-18 03:59:54,182 7820 INFO ? stock:
> stock.move.create_chained_picking(): GBJ #0: moves =
> [browse_record(stock.move, 405450)] : context = None
> 2013-12-18 03:59:54,196 7820 INFO ? stock:
> stock.move.action_confirm(): #1:                  TIMING::           
> 0.12s : 0.12s
> 2013-12-18 03:59:54,295 7820 INFO ? procurement:
> procurement.order._procure_orderpoint_confirm(): #6: button_confirm: 
> TIMING::            0.856s
> 2013-12-18 03:59:54,581 7820 INFO ? procurement:
> procurement.order.check_produce(): #3:                 
> TIMING::                    0.07s
> 2013-12-18 03:59:54,913 7820 INFO ? mrp:
> procurement.order.make_mo():                             #1:
> prod.create():   TIMING::                    0.33s
> 2013-12-18 03:59:56,177 7820 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #1: bom :          
> TIMING::                           0.261s
> 2013-12-18 03:59:56,177 7820 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #2: :         
> TIMING::                           0.000s
> 2013-12-18 03:59:56,873 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               1.160s
> 2013-12-18 03:59:57,084 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.350s
> 2013-12-18 03:59:57,084 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.351s
> 2013-12-18 03:59:57,786 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               1.170s
> 2013-12-18 03:59:58,111 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.541s
> 2013-12-18 03:59:58,111 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.542s
> 2013-12-18 03:59:58,831 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               1.200s
> 2013-12-18 03:59:59,269 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.729s
> 2013-12-18 03:59:59,269 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.730s
> 2013-12-18 04:00:00,001 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               1.219s
> 2013-12-18 04:00:00,542 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   0.901s
> 2013-12-18 04:00:00,542 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               0.902s
> 2013-12-18 04:00:01,273 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #1:
> super:           TIMING::                               1.218s
> 2013-12-18 04:00:01,915 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.reset_states():     #1: :          
> TIMING::                                   1.069s
> 2013-12-18 04:00:01,915 7820 INFO ? mrp_geicp:
> mrp.production.workcenter.line.create():           #2:
> reset_states():  TIMING::                               1.070s
> 2013-12-18 04:00:01,915 7820 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #3: :         
> TIMING::                           9.563s
> 2013-12-18 04:00:02,421 7820 INFO ? mrp_geicp:
> mrp.production.update_production_bom_information():#1: :          
> TIMING::                               0.843s
> 2013-12-18 04:00:02,652 7820 INFO ? mrp_geicp:
> mrp.production.update_production_bom_information():#2: :          
> TIMING::                               0.385s
> 2013-12-18 04:00:03,043 7820 INFO ? mrp_geicp:
> mrp.production.update_production_bom_information():#3: :          
> TIMING::                               0.652s
> 2013-12-18 04:00:03,043 7820 INFO ? mrp_geicp:
> mrp.production.action_compute():                   #4:
> update:          TIMING::                           1.880s
> 2013-12-18 04:00:03,043 7820 INFO ? mrp:
> mrp.production.test_if_product():                        #1:
> action_compute:  TIMING::                        13.44s
> 2013-12-18 04:00:03,310 7820 INFO ? mrp:
> procurement.order.make_mo():                             #3:
> button_confirm:  TIMING::                    14.00s
> 2013-12-18 04:00:03,488 7820 INFO ? procurement:
> procurement.order._procure_orderpoint_confirm(): #7: button_check:   
> TIMING::            15.323s
>
>
> Appreciate your expert help and insight.
>
> Grahame Jordan
>
>
>
> _______________________________________________
> Mailing list: https://launchpad.net/~openerp-community
> Post to     : openerp-community@xxxxxxxxxxxxxxxxxxx
> Unsubscribe : https://launchpad.net/~openerp-community
> More help   : https://help.launchpad.net/ListHelp


-- 
Alexandre Fayolle
Chef de Projet
Tel : + 33 (0)4 79 26 57 94

Camptocamp France SAS
Savoie Technolac, BP 352
73377 Le Bourget du Lac Cedex
http://www.camptocamp.com
Follow ups

Re: mrp scheduler
From: Grahame Jordan, 2013-12-18
Re: mrp scheduler
From: ferdinand, 2013-12-18
References

mrp scheduler
From: Grahame Jordan, 2013-12-18