#6227 Forking on src.fp.o takes forever
Closed: Fixed Opened by ignatenkobrain.

https://src.fedoraproject.org/wait/22c6a223-46c1-476a-a8b0-29bb593f521c

I've started it at ~08:55 CEST and while writing this ticket (~09:16) it is still running...


Metadata Update from @pingou:
- Issue tagged with: src.fp.o

This has been improved by https://pagure.io/pagure/c/9076d210e071434fb3eda72de8b57a2024094050

But some compilation steps are still taking over 1000 seconds (while the average is around 200), some numbers:

[2017-08-11 13:24:11,578: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[da791fdb-13f0-4589-ac33-54275ffc9048] succeeded in 1248.12564323s: None
[2017-08-11 11:35:14,962: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[680726e1-c350-4d1a-8d6d-2b7c7166a3d7] succeeded in 1018.59114266s: None
[2017-08-11 09:13:45,405: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[c7de7796-5767-43ce-a1a2-e593a27317ac] succeeded in 230.31486443s: None
[2017-08-11 09:09:55,088: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[1995da72-33c9-4999-be62-825ad0bf01ab] succeeded in 227.57863001s: None
[2017-08-11 09:05:43,490: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[78644d24-b938-4b5c-ad05-f96cec58ca60] succeeded in 180.080129372s: None
[2017-08-11 08:56:59,446: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[695a5c0f-cf83-423f-8498-f94e662e415e] succeeded in 208.359721805s: None
[2017-08-11 08:50:03,365: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[cb99cf23-0dff-4f4c-9f4e-14c2981900c1] succeeded in 232.318497078s: None
[2017-08-11 08:28:30,649: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[b214af26-48e8-4524-9394-1616cd8e3167] succeeded in 206.227377281s: None
[2017-08-11 08:25:04,419: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[8b8bfc28-5f69-467e-ab6e-cb769cb3b0b5] succeeded in 299.005137158s: None
[2017-08-11 08:19:58,016: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4e8545bc-7584-4985-a107-b91c0563e09f] succeeded in 249.71986907s: None
[2017-08-11 08:05:47,388: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[e1f102d5-da15-4c9c-9105-1d1faa809d32] succeeded in 209.550455903s: None
[2017-08-11 07:57:06,750: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[a0cd5366-c8e5-419b-b3cd-c6600ff368d8] succeeded in 158.459290853s: None
[2017-08-11 07:51:06,972: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[1562e37f-2e4c-425f-996c-0d86418f5256] succeeded in 273.45357853s: None
[2017-08-11 07:37:39,193: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[8e0c3c10-d174-4c1f-ba51-6a58f83e8235] succeeded in 238.224006676s: None
[2017-08-11 07:20:41,468: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f46b8bd4-fd2c-4a54-bf9d-7a8878411ebc] succeeded in 195.137388565s: None
[2017-08-11 07:11:25,359: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f0b27446-0ed4-423f-9238-071994a40c99] succeeded in 1113.64347997s: None
[2017-08-11 04:29:27,995: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[87518875-d889-436d-98eb-770459c58260] succeeded in 1872.66088062s: None
[2017-08-10 21:13:39,051: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[cf524406-28b5-4de3-b3f4-7f208b468944] succeeded in 223.95468313s: None
[2017-08-10 21:09:55,094: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f34e467d-a65c-41a9-bf52-52fa5ad3d9af] succeeded in 543.471271005s: None
[2017-08-10 18:46:08,625: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4586ba45-4630-409d-9c7a-56063337f64d] succeeded in 241.835456375s: None
[2017-08-10 18:42:06,789: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[dcae1cb4-d7e1-41da-9555-1e07a28ceca4] succeeded in 186.332810987s: None
[2017-08-10 18:39:00,454: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[54595d1e-021b-4a03-89a0-424a8f0d841d] succeeded in 221.119141548s: None
[2017-08-10 18:35:19,333: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4458c22d-42a7-47a4-a58b-e47f9290cc8f] succeeded in 205.444818849s: None
[2017-08-10 18:31:53,886: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[7f0ff3dd-a059-468f-bf69-bb3bf9bc919a] succeeded in 211.94532755s: None
[2017-08-10 18:28:21,938: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[040a6f19-7124-457f-8fcc-aaad97b0235f] succeeded in 235.623506839s: None
[2017-08-10 18:24:26,313: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[1ffbc197-6fa7-4ce3-8d4c-e4dd0acc9a7f] succeeded in 181.464215815s: None
[2017-08-10 18:21:24,847: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4f76ba12-28f9-4252-b73a-0a9f3ddb95b9] succeeded in 248.116505968s: None
[2017-08-10 18:17:16,728: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[758fe19f-3dc4-4b80-8493-fb47e471de5b] succeeded in 183.098558188s: None
[2017-08-10 18:14:13,627: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[6d0b4410-3a03-42cc-baeb-32b9dfa64e5a] succeeded in 222.432124759s: None
[2017-08-10 18:10:31,192: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f7142c8f-8645-42e0-9ab8-94e18c5a0fbf] succeeded in 176.389598823s: None
[2017-08-10 18:07:34,801: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[d631af16-8124-418c-829c-7dd022a5b0d3] succeeded in 162.450073574s: None
[2017-08-10 18:04:52,348: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[c1ec438a-c337-413d-aa4e-46c727e2264f] succeeded in 156.317116138s: None
[2017-08-10 18:02:16,029: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[268ab15f-9262-481a-94f7-fedc475f6c7f] succeeded in 180.934918096s: None
[2017-08-10 17:59:15,092: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[0153f438-8e30-4300-be80-bdfd9663c9c4] succeeded in 180.827143345s: None
[2017-08-10 17:56:14,263: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[323524fd-ba7f-4022-94c0-f0d8e1c1a7cb] succeeded in 160.371332541s: None
[2017-08-10 17:53:33,889: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[dc25e3ed-3c41-4439-b1c8-2ea603703c40] succeeded in 172.274339125s: None
[2017-08-10 17:50:41,612: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[8ae1b651-b56f-472d-a70a-c008bef98c9f] succeeded in 178.037492794s: None
[2017-08-10 17:47:43,573: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[ab284da9-e2a8-4752-8ff2-baf8b8e688b4] succeeded in 166.609390325s: None
[2017-08-10 17:44:56,961: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[c475b02b-1aa2-4898-b31e-ba8ff9172c17] succeeded in 154.227090838s: None
[2017-08-10 17:42:22,731: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f24633fd-9a1a-447f-a9cd-04a507c7ac7c] succeeded in 163.608160246s: None
[2017-08-10 17:39:39,121: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[e5d903c7-40b3-49a0-b258-d2546e5b47c4] succeeded in 162.148103643s: None
[2017-08-10 17:36:56,970: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[3b19c0b0-a6dd-413b-8755-fc67ae304499] succeeded in 161.753778947s: None
[2017-08-10 17:34:15,214: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[34072330-c3cd-4be6-8a27-648115cc95f6] succeeded in 157.565704275s: None
[2017-08-10 17:31:37,646: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f0be6c61-aaac-43ab-85a4-09184f0dc44d] succeeded in 162.589929151s: None
[2017-08-10 17:28:55,054: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[7156a3ab-912c-4028-ae2e-fed5cf4279c1] succeeded in 148.981798121s: None
[2017-08-10 17:26:26,070: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[9448bf26-8289-49b1-9720-cf1b7c50eed2] succeeded in 159.39759255s: None
[2017-08-10 17:23:46,670: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[2dfc8ca4-5f4c-4c25-b1c9-73f8de09ad1c] succeeded in 156.392411472s: None
[2017-08-10 17:21:10,275: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[5fa121cf-0aac-45e4-be1b-3901ad04a652] succeeded in 165.120983219s: None
[2017-08-10 17:18:25,153: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[bf7cf4f7-741f-41fd-ac40-126383cc3e8d] succeeded in 148.59992312s: None
[2017-08-10 17:15:56,550: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[31920173-4970-46bb-b543-16049eb421e5] succeeded in 160.053859742s: None
[2017-08-10 17:13:16,494: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[5bf2efab-8d6f-46ed-8aaa-dce5cda2455d] succeeded in 166.814350893s: None
[2017-08-10 17:10:29,678: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[37000771-634b-45c3-a241-6b4f61014d2d] succeeded in 146.493384935s: None
[2017-08-10 17:08:03,182: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[e5050ff6-b43d-4930-8606-0d35526f7088] succeeded in 167.413770226s: None
[2017-08-10 17:05:15,767: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[1acb8664-e80a-44f4-8eee-27341f37bd12] succeeded in 156.321202397s: None
[2017-08-10 17:02:39,443: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[89ab8941-c16c-4f12-9313-1d7939e29e56] succeeded in 189.234904061s: None
[2017-08-10 16:59:30,206: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[1159b834-3ec8-48b5-b935-2bf356dcbe05] succeeded in 157.377308255s: None
[2017-08-10 16:56:52,827: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[aa2ebb92-3177-4212-8252-928421917da7] succeeded in 154.982910584s: None
[2017-08-10 16:54:06,988: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[cf1210cb-55d9-447e-8b56-1bf38a2b92e9] succeeded in 149.537720781s: None
[2017-08-10 16:51:37,448: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[18218f2c-043a-417b-a65f-6e94741f28a7] succeeded in 201.583634156s: None
[2017-08-10 16:45:38,129: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[5cf516b7-3d29-4b57-be0f-1b26d59cbd37] succeeded in 191.802961313s: None
[2017-08-10 16:42:26,323: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4f51c9ce-c852-4de7-ac7b-b1c96d387588] succeeded in 191.332656954s: None
[2017-08-10 16:31:30,472: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[e15d70fd-6598-45cd-aad4-95ddac62892a] succeeded in 172.264767726s: None
[2017-08-10 15:35:31,586: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f46e8347-6829-493a-a6af-4d5a2addaae2] succeeded in 150.665981778s: None
[2017-08-10 15:33:00,918: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[c74d4719-a1c6-45bd-98c6-c3c8e698cf15] succeeded in 206.713652366s: None
[2017-08-10 15:11:46,781: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[bc8e7149-f78c-45d2-88f8-c448e56f0b97] succeeded in 154.05744933s: None
[2017-08-10 15:09:12,722: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[ae442edd-3f7f-4f08-8fb6-19a4644f2041] succeeded in 141.349086934s: None
[2017-08-10 14:32:49,843: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4be86724-bb3a-4f73-a4a2-24a391033873] succeeded in 201.838135015s: None
[2017-08-10 14:15:42,595: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[7fbbccc2-4e0e-4cc9-9957-8dd2997443f8] succeeded in 168.432785231s: None
[2017-08-10 14:03:47,961: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[4b3edff4-9103-4e34-b289-26f7f8984440] succeeded in 176.860306175s: None
[2017-08-10 14:00:51,099: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[79ff0cde-20ba-4471-86d3-230c5b413c7f] succeeded in 192.338090982s: None
[2017-08-10 13:53:38,403: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[223327c9-caa3-4240-8127-1a5150d3dea3] succeeded in 183.234429838s: None
[2017-08-10 10:02:05,432: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[1496d281-3476-44b9-be87-e75a08ed3bfc] succeeded in 208.425636651s: None
[2017-08-10 09:47:22,361: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[43ffb738-59c5-4124-ae26-9615b5d2dbeb] succeeded in 209.14051818s: None
[2017-08-10 09:34:20,297: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[e323779b-ea70-4908-9287-55a88263fe9e] succeeded in 164.915334859s: None
[2017-08-10 09:31:35,379: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[51131fe9-029b-46d4-ba7d-ce51f31208ee] succeeded in 211.770235763s: None
[2017-08-10 09:28:03,606: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[663076ca-ce68-4c9a-91a5-9dd15f8634e8] succeeded in 241.480237214s: None
[2017-08-10 09:24:02,124: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f9c3f179-4b44-4783-b91c-e85ca63da7df] succeeded in 196.914097052s: None
[2017-08-10 09:20:45,208: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[55512729-a768-4885-98aa-ca871bea162c] succeeded in 1908.97198841s: None

So, I just forked some repos here and it took around 5 seconds each time, with acls compile taking ~180seconds or less...

It would be nice to get that compile down...

I have a draft of a patch from upstream to test in stg but I have recommendation not to try it in prod atm.

I've tested gitolite's upstream patch in stg:

Before:

# time sudo -u pagure HOME=/srv/git gitolite compile
real    8m54.441s
user    0m35.241s
sys 0m51.677s

After:

# time sudo -u pagure HOME=/srv/git gitolite compile
real    5m12.166s
user    0m30.465s
sys 0m31.517s
# time sudo -u pagure HOME=/srv/git gitolite compile
real    0m24.271s
user    0m23.796s
sys 0m0.464s
# time sudo -u pagure HOME=/srv/git gitolite compile
real    0m23.998s
user    0m23.574s
sys 0m0.423s

In the first run after the patch is applied, gitolite builds a cache that is then re-used thus the slower perf of the first run.

Upstream patch has been published: https://github.com/sitaramc/gitolite/commit/41b7885b77cfe992ad3c96d0b021ece51ce1b3e3

PR for the RPM open: https://src.fedoraproject.org/rpms/gitolite3/pull-request/1

New rpm deployed:

pkgs02 ~][PROD]# time sudo -u pagure HOME=/srv/git gitolite compile
real    2m49.671s
user    1m3.331s
sys 0m53.397s
pkgs02 ~][PROD]# time sudo -u pagure HOME=/srv/git gitolite compile
real    1m0.603s
user    0m59.528s
sys 0m1.070s
pkgs02 ~][PROD]# time sudo -u pagure HOME=/srv/git gitolite compile
real    1m1.635s
user    1m0.310s
sys 0m1.280s

I think the last thing we can do is get ride of all the tests-* repo/namespace

Metadata Update from @pingou:
- Issue assigned to pingou

I think we optimized things as much as currently possible, here are the last entries:

[2017-09-05 07:34:00,247: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[a632cdb0-8afd-4189-8c0c-c88d7fa924f5] succeeded in 44.630052877s: None
[2017-09-05 07:01:24,077: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[7780c551-59c2-4ae0-a807-dc9a4c0d2b38] succeeded in 81.653864675s: None
[2017-09-05 07:00:02,421: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[6fdcb320-0d84-48c2-ad05-ded78d529345] succeeded in 32.850191s: None
[2017-09-05 06:59:29,568: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[27c51e25-6612-46a6-a517-ede09156091a] succeeded in 156.979562691s: None
[2017-09-05 06:05:15,671: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[91ff1d49-22af-4a49-9830-c31844dfa0b4] succeeded in 36.627623749s: None
[2017-09-05 06:04:39,041: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[d487cacb-68ab-450b-a814-1d1972ff9d4d] succeeded in 268.136146245s: None
[2017-09-04 20:03:29,647: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[25d592d6-f8e5-4c9c-9f34-d20b13312457] succeeded in 34.59132456s: None
[2017-09-04 20:02:55,053: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[89d500f4-6de9-4a4b-b466-0c3ee092af02] succeeded in 34.144023939s: None
[2017-09-04 20:02:20,908: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[febf3eed-f9d6-4512-913d-72489b51d024] succeeded in 33.700446798s: None
[2017-09-04 20:01:47,206: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[9d63c077-1824-4376-98db-d5a9110ce1c7] succeeded in 34.826500553s: None
[2017-09-04 19:38:28,582: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[b9573c7f-c068-4483-b357-5eec8ab26c03] succeeded in 34.391764589s: None
[2017-09-04 19:12:58,621: INFO/MainProcess] Task pagure.lib.tasks.generate_gitolite_acls[f675d881-6ec4-40cb-874b-8b663cf5de70] succeeded in 31.78510089s: None

There is still a little variability but most often it compiles in ~ 40 seconds.

I am going to close this ticket as fixed for now and I'll see if I can discuss with gitolite upstream about some more optimizations.

Metadata Update from @pingou:
- Issue close_status updated to: Fixed

Metadata