| 2010-08-23 11:53:14 |
Данило Шеган |
description |
cronscripts/rosetta-pofile-stats-daily.py takes ages to complete, either due to DBLoopTuner being insane, or due to bad usage of it.
This is how a typical run looks like:
2010-08-14 06:37:04 INFO Creating lockfile: /var/lock/launchpad-pofile-stats-daily.lock
2010-08-14 06:37:15 INFO Verifying stats of POFiles updated in the last 7 days.
2010-08-14 06:37:35 INFO Verifying a total of 98599 POFiles.
2010-08-14 06:37:46 DEBUG Iteration 0 (size 1.0): 11.037 seconds
2010-08-14 06:37:46 INFO Blocked on 6:26:44.992256 old xact postgres@launchpad_prod_3/18668 - <HIDDEN>.
2010-08-14 06:37:46 INFO Blocked on 6:25:08.238912 old xact slony@launchpad_prod_3/29559 - <HIDDEN>.
2010-08-14 06:37:46 INFO Blocked on 1:22:44.646834 old xact fiera@launchpad_prod_3/19300 - <IDLE> in transaction.
2010-08-14 06:37:46 INFO Sleeping for up to 10 minutes.
2010-08-14 06:47:47 INFO Blocked on 6:36:45.967862 old xact postgres@launchpad_prod_3/18668 - <HIDDEN>.
2010-08-14 06:47:47 INFO Blocked on 6:35:09.214518 old xact slony@launchpad_prod_3/29559 - <HIDDEN>.
2010-08-14 06:47:47 INFO Blocked on 1:32:45.622440 old xact fiera@launchpad_prod_3/19300 - <IDLE> in transaction.
2010-08-14 06:47:47 INFO Sleeping for up to 10 minutes.
2010-08-14 06:57:48 INFO Blocked on 6:46:46.757742 old xact postgres@launchpad_prod_3/18668 - <HIDDEN>.
2010-08-14 06:57:48 INFO Blocked on 6:45:10.004398 old xact slony@launchpad_prod_3/29559 - <HIDDEN>.
2010-08-14 06:57:48 INFO Blocked on 1:42:46.412320 old xact fiera@launchpad_prod_3/19300 - <IDLE> in transaction.
2010-08-14 06:57:48 INFO Sleeping for up to 10 minutes.
...
2010-08-14 08:37:57 INFO Sleeping for up to 10 minutes.
2010-08-14 08:47:58 INFO Blocked on 1:47:57.103012 old xact postgres@launchpad_prod_3/31251 - <HIDDEN>.
2010-08-14 08:47:58 INFO Sleeping for up to 10 minutes.
2010-08-14 08:58:00 INFO Blocked on 1:57:58.284515 old xact postgres@launchpad_prod_3/31251 - <HIDDEN>.
2010-08-14 08:58:00 INFO Sleeping for up to 10 minutes.
2010-08-14 09:08:01 INFO Blocked on 2:07:59.294789 old xact postgres@launchpad_prod_3/31251 - <HIDDEN>.
2010-08-14 09:08:01 INFO Sleeping for up to 10 minutes.
2010-08-14 09:13:43 DEBUG Iteration 1 (size 1.0): 42.150 seconds
2010-08-14 09:13:55 DEBUG Iteration 2 (size 1.0): 11.925 seconds
2010-08-14 09:14:06 DEBUG Iteration 3 (size 1.0): 10.319 seconds
2010-08-14 09:14:15 DEBUG Iteration 4 (size 1.0): 9.151 seconds
2010-08-14 09:14:24 DEBUG Iteration 5 (size 1.0): 9.456 seconds
2010-08-14 09:14:35 DEBUG Iteration 6 (size 1.0): 10.665 seconds
...
After it gets unblocked, it takes ages to process stuff, doing one item per iteration. For reference, regular pofile-stats script which runs over all our POFiles (all 900k of them) finishes in roughly 24h. |
cronscripts/rosetta-pofile-stats-daily.py takes ages to complete, either due to DBLoopTuner being insane (bug 622670), or due to bad usage of it.
This is how a typical run looks like:
2010-08-14 06:37:04 INFO Creating lockfile: /var/lock/launchpad-pofile-stats-daily.lock
2010-08-14 06:37:15 INFO Verifying stats of POFiles updated in the last 7 days.
2010-08-14 06:37:35 INFO Verifying a total of 98599 POFiles.
2010-08-14 06:37:46 DEBUG Iteration 0 (size 1.0): 11.037 seconds
2010-08-14 06:37:46 INFO Blocked on 6:26:44.992256 old xact postgres@launchpad_prod_3/18668 - <HIDDEN>.
2010-08-14 06:37:46 INFO Blocked on 6:25:08.238912 old xact slony@launchpad_prod_3/29559 - <HIDDEN>.
2010-08-14 06:37:46 INFO Blocked on 1:22:44.646834 old xact fiera@launchpad_prod_3/19300 - <IDLE> in transaction.
2010-08-14 06:37:46 INFO Sleeping for up to 10 minutes.
2010-08-14 06:47:47 INFO Blocked on 6:36:45.967862 old xact postgres@launchpad_prod_3/18668 - <HIDDEN>.
2010-08-14 06:47:47 INFO Blocked on 6:35:09.214518 old xact slony@launchpad_prod_3/29559 - <HIDDEN>.
2010-08-14 06:47:47 INFO Blocked on 1:32:45.622440 old xact fiera@launchpad_prod_3/19300 - <IDLE> in transaction.
2010-08-14 06:47:47 INFO Sleeping for up to 10 minutes.
2010-08-14 06:57:48 INFO Blocked on 6:46:46.757742 old xact postgres@launchpad_prod_3/18668 - <HIDDEN>.
2010-08-14 06:57:48 INFO Blocked on 6:45:10.004398 old xact slony@launchpad_prod_3/29559 - <HIDDEN>.
2010-08-14 06:57:48 INFO Blocked on 1:42:46.412320 old xact fiera@launchpad_prod_3/19300 - <IDLE> in transaction.
2010-08-14 06:57:48 INFO Sleeping for up to 10 minutes.
...
2010-08-14 08:37:57 INFO Sleeping for up to 10 minutes.
2010-08-14 08:47:58 INFO Blocked on 1:47:57.103012 old xact postgres@launchpad_prod_3/31251 - <HIDDEN>.
2010-08-14 08:47:58 INFO Sleeping for up to 10 minutes.
2010-08-14 08:58:00 INFO Blocked on 1:57:58.284515 old xact postgres@launchpad_prod_3/31251 - <HIDDEN>.
2010-08-14 08:58:00 INFO Sleeping for up to 10 minutes.
2010-08-14 09:08:01 INFO Blocked on 2:07:59.294789 old xact postgres@launchpad_prod_3/31251 - <HIDDEN>.
2010-08-14 09:08:01 INFO Sleeping for up to 10 minutes.
2010-08-14 09:13:43 DEBUG Iteration 1 (size 1.0): 42.150 seconds
2010-08-14 09:13:55 DEBUG Iteration 2 (size 1.0): 11.925 seconds
2010-08-14 09:14:06 DEBUG Iteration 3 (size 1.0): 10.319 seconds
2010-08-14 09:14:15 DEBUG Iteration 4 (size 1.0): 9.151 seconds
2010-08-14 09:14:24 DEBUG Iteration 5 (size 1.0): 9.456 seconds
2010-08-14 09:14:35 DEBUG Iteration 6 (size 1.0): 10.665 seconds
...
After it gets unblocked, it takes ages to process stuff, doing one item per iteration. For reference, regular pofile-stats script which runs over all our POFiles (all 900k of them) finishes in roughly 24h.
|
|
