Openbravo Issue Tracking System - Openbravo ERP
View Issue Details
IDProjectCategoryView StatusDate SubmittedLast Update
0008575Openbravo ERPA. Platformpublic2009-04-15 11:032011-09-28 12:54
Reporterschmidtm 
Assigned Tomarvintm 
PriorityhighSeveritymajorReproducibilityalways
StatusclosedResolutionno change required 
PlatformOS50OS VersionMac OSX 10.5.6
Product Version2.40 
Target VersionFixed in Version 
Merge Request Status
Review Assigned To
OBNetwork customer
Web browser
ModulesCore
Support ticket
Regression level
Regression date
Regression introduced in release
Regression introduced by commit
Triggers an Emergency PackNo
Summary0008575: Delete client operation takes about 1,5h
DescriptionDeleting a client (either manual or automated using selenium) takes aprox. 1,5 hrs.

As this process blocks (intentionally) others users this is too long.

While this operation is ongoing postgres consumes more than 90 % of CPU.

Please see attached files for the proclist and threaddump
Steps To ReproduceGo to General Setup/Client/Delete Client and delete "SampleClient"
Proposed Solution
Additional Information
Tags250MP1
Relationships
related to defect 0000211 closed cromero AT235MP4 - Delete client error 
related to defect 00176413.0MP4 closed marvintm Delete Client process does not work (this issue also groups other tickets related to the Delete Client process) 
has duplicate feature request 0006272 closed iperdomo Delete client slow processing 
Attached Filestxt pg-proclist.txt (9,220) 2009-04-15 11:03
https://issues.openbravo.com/file_download.php?file_id=1180&type=bug
txt threaddump.txt (130,717) 2009-04-15 11:04
https://issues.openbravo.com/file_download.php?file_id=1181&type=bug
gz automation-report.tar.gz (7,862) 2009-04-15 15:10
https://issues.openbravo.com/file_download.php?file_id=1184&type=bug
diff postgresql.conf-troubshooting.diff (930) 2009-04-16 09:59
https://issues.openbravo.com/file_download.php?file_id=1186&type=bug
txt durations.txt (31,127) 2009-04-16 09:59
https://issues.openbravo.com/file_download.php?file_id=1187&type=bug
Issue History
Date ModifiedUsernameFieldChange
2009-04-15 11:03schmidtmNew Issue
2009-04-15 11:03schmidtmAssigned To => rafaroda
2009-04-15 11:03schmidtmFile Added: pg-proclist.txt
2009-04-15 11:04schmidtmFile Added: threaddump.txt
2009-04-15 11:13shuehnerIssue Monitored: shuehner
2009-04-15 15:10schmidtmFile Added: automation-report.tar.gz
2009-04-15 15:11schmidtmNote Added: 0015370
2009-04-15 16:30schmidtmNote Added: 0015371
2009-04-15 22:04psarobeAssigned Torafaroda => shuehner
2009-04-15 22:04psarobePrioritynormal => high
2009-04-15 22:04psarobeSeveritycritical => major
2009-04-15 22:04psarobeStatusnew => scheduled
2009-04-16 09:59schmidtmNote Added: 0015377
2009-04-16 09:59schmidtmFile Added: postgresql.conf-troubshooting.diff
2009-04-16 09:59schmidtmFile Added: durations.txt
2009-04-16 10:17schmidtmNote Added: 0015378
2009-04-23 16:05psarobeTag Attached: 250MP1
2009-05-11 11:19shuehnerNote Added: 0016247
2009-05-12 11:13schmidtmNote Added: 0016288
2009-05-13 09:10shuehnerNote Added: 0016310
2009-05-13 09:10shuehnerSummaryUnable to log into OpenBravo while delete client operation is running => Delete client operation takes about 1,5h
2009-05-13 09:10shuehnerDescription Updated
2009-08-18 14:23iperdomoRelationship addedhas duplicate 0006272
2009-09-02 14:36rafarodaRelationship addedrelated to 0000211
2011-06-14 16:37dmitry_mezentsevRelationship addedrelated to 0017641
2011-08-30 17:29shuehnerAssigned Toshuehner => marvintm
2011-09-28 12:54marvintmNote Added: 0041344
2011-09-28 12:54marvintmStatusscheduled => closed
2011-09-28 12:54marvintmResolutionopen => no change required

Notes
(0015370)
schmidtm   
2009-04-15 15:11   
Please take a look at the attached file: automation-report.tar.gz

It shows the 2.40 automation framework timeout happening in the second test.
(0015371)
schmidtm   
2009-04-15 16:30   
Some more information. The process which hogs the CPU is doing this:

postgres 3773 98.7 1,6 673528 67884 ?? Rs 3:02pm 82:03.99 postgres: tad openbravo 127.0.0.1(52615) SELECT

In addition, looking at the pg_locks table it shows 1768 locks occupied by this very process.
(0015377)
schmidtm   
2009-04-16 09:59   
Meanwhile I've tweaked the PostgreSQL logging to get timestamps and warning of long-running queries (see attachement).

I've grep-ed the pain-points into the attachment 'durations' they take some 70-80 minutes. Now someone way more knowledgeable should take a closer look at these.
(0015378)
schmidtm   
2009-04-16 10:17   
Yet more information: The 'hot' tables in this scenarion are:

openbravo=# select relname,relfilenode from pg_class where oid=40297 or oid=39915 or oid=40434;
         relname | relfilenode
-------------------------+-------------
 ad_process_scheduling | 40434
 ad_model_object_mapping | 40297
 ad_client | 39915
(0016247)
shuehner   
2009-05-11 11:19   
I did check that process and the inability to work while it is running is intentional. The process does disable triggers and fk-constraints so working while it is running would lead to problems.

However the runtime reported in your case should normally be much better. I did test the 2.50 community virtual appliance and the process to delete the preconfigured client was only about 90s.

@schmidtm: Is it okay to retitle this issue to track/adress the slowness problem after this explanation?
(0016288)
schmidtm   
2009-05-12 11:13   
Yes, it's fine to change the title now that i understand that the behavior itself is intentional.

Nevertheless i would love to get this one resolved, since it's definitely a show-stopper for me.
(0016310)
shuehner   
2009-05-13 09:10   
Retitle to adress the slowness issue, as the blocking behavior is intentional after discussion with reporter.
(0041344)
marvintm   
2011-09-28 12:54   
The new Delete client process works quite fast on big clients, so this should no longer happen.