Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Action runs much slower than compiling a full project #147

Open
GnomedDev opened this issue Mar 26, 2023 · 5 comments · May be fixed by #174
Open

Action runs much slower than compiling a full project #147

GnomedDev opened this issue Mar 26, 2023 · 5 comments · May be fixed by #174
Assignees
Labels
bug Something isn't working

Comments

@GnomedDev
Copy link

This action seems to run slower on https://github.com/stblr/mkw-sp than our build action does, significantly. I theorize this is because https://github.com/jidicula/clang-format-action/blob/main/check.sh#L23-L28 is starting a new docker container per file? at least that is what it looks like to me.

@jidicula jidicula self-assigned this Mar 26, 2023
@jidicula jidicula added the bug Something isn't working label Mar 26, 2023
@jidicula
Copy link
Owner

Thanks for submitting an issue! Could you include a link to a workflow run showing this so I can peruse the logs?

@GnomedDev
Copy link
Author

Looking at the numbers, it seems it doesn't take as long as I thought, but is still longer than build time by a significant margin. An example workflow run is https://github.com/stblr/mkw-sp/actions/runs/4526224913

@echoix
Copy link

echoix commented Nov 18, 2023

If you want to see a potential use case, look at any clang-format run in the OSGeo/grass repo: https://github.com/OSGeo/grass/actions/workflows/clang-format-check.yml
CI is often long before starting with the 20 available runners, since it is shared with other big projects in the geospatial field, like PROJ and GDAL.

In this repo, we have about 22 minutes to run clang-format.
In order to check if the time spent was spent doing tasks, I used runforesight/workflow-telemetry-action@v1 to check CPU usage. I also compared to another action that uses a python runner instead (it's not simply python that should make the difference, but the way clang-format is called) : DoozyX/clang-format-lint-action@v0.16.2.

It is possible to collect all the files path/exclusions in a kind of list and then pass it all at once to clang-format. Even if it is a bit more complicated, super-linter (which uses shell scripts) uses this: https://github.com/super-linter/super-linter/blob/f3279a4414f050cf9dbb2b56db7eae31a9c8ee35/lib/functions/buildFileList.sh#L151-L193

Current action clang-format (~22 min for clang-format)

Workflow Telemetry - ClangFormat Check / Formatting Check

Workflow telemetry for commit 839680e69e88ad6bb79279adee67c38e6c371444
You can access workflow job details here

Step Trace

gantt
	title Formatting Check
	dateFormat x
	axisFormat %H:%M:%S
	Set up job : milestone, 1700341492000, 1700341493000
	Collect Workflow Telemetry : 1700341493000, 1700341494000
	Run actions/checkout@8ade135a41bc03ea155e62e844d188df1ea18608 : 1700341494000, 1700341500000
	Run clang-format style check for C/C++/Protobuf programs. : 1700341500000, 1700342834000
	Post Run actions/checkout@8ade135a41bc03ea155e62e844d188df1ea18608 : 1700342834000, 1700342834000

CPU Metrics

68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f737461636b65642d617265612f74696d652f63686172745f737461636b65645f617265615f74696d655f65326434313138342d363631332d343433342d613235612d3435373863

Memory Metrics

68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f737461636b65642d617265612f74696d652f63686172745f737461636b65645f617265615f74696d655f66373163633462642d653762382d343530642d623836332d3531396264

IO Metrics

Read Write
Network I/O 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f34623764656131632d663237312d343034352d626631302d396333383661656663653266 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f61383264343536652d663730382d346237652d393530312d336566343037616530323530
Disk I/O 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f35643965663538322d343465662d343838352d393136362d366534336138666639383331 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f65653765326632372d383932302d346532322d386466632d356130383765663165643165

Process Trace

Top 100 processes with highest duration

gantt
	title Formatting Check
	dateFormat x
	axisFormat %H:%M:%S
	node (checkout) : 1700341494031, 1700341500222
	git : 1700341494293, 1700341499411
	git : 1700341494296, 1700341499155
	git-remote-http : 1700341494298, 1700341499155
	git : 1700341497285, 1700341499399
	git : 1700341499414, 1700341500206
	bash : 1700341500280, 1700342834759
	check.sh : 1700341500282, 1700342834758
	bash : 1700341500282, 1700342834758
	docker : 1700341500318, 1700341505529
	docker : 1700341506736, 1700341507173
	docker : 1700341576924, 1700341577368
	docker : 1700341601245, 1700341601677
	docker : 1700341612338, 1700341612780
	docker : 1700341617968, 1700341618398
	docker : 1700341635297, 1700341635728
	docker : 1700341638114, 1700341638557
	docker : 1700341640501, 1700341641130
	docker : 1700341642316, 1700341643285
	docker : 1700341644061, 1700341644492
	docker : 1700341681129, 1700341681569
	docker : 1700341683889, 1700341684334
	docker : 1700341684741, 1700341685230
	docker : 1700341685234, 1700341685668
	docker : 1700341702724, 1700341703170
	docker : 1700341704345, 1700341704833
	docker : 1700341713141, 1700341713598
	docker : 1700341717528, 1700341717961
	docker : 1700341723568, 1700341724004
	docker : 1700341734412, 1700341734893
	docker : 1700341744392, 1700341744829
	docker : 1700341777768, 1700341778206
	docker : 1700341789957, 1700341790390
	docker : 1700341798644, 1700341799110
	docker : 1700341803069, 1700341803520
	docker : 1700341803523, 1700341803966
	docker : 1700341805161, 1700341805594
	docker : 1700341808818, 1700341809284
	docker : 1700341838615, 1700341839053
	docker : 1700341846244, 1700341846676
	docker : 1700341851378, 1700341851881
	docker : 1700341852712, 1700341853145
	docker : 1700341873992, 1700341874430
	docker : 1700341890052, 1700341890497
	docker : 1700341908661, 1700341909166
	docker : 1700341911844, 1700341912285
	docker : 1700341934051, 1700341934521
	docker : 1700341978757, 1700341979198
	docker : 1700342068588, 1700342069038
	docker : 1700342103426, 1700342104179
	docker : 1700342106153, 1700342106588
	docker : 1700342118617, 1700342119047
	docker : 1700342122929, 1700342123405
	docker : 1700342127422, 1700342127852
	docker : 1700342203474, 1700342203926
	docker : 1700342207502, 1700342207933
	docker : 1700342209092, 1700342209531
	docker : 1700342214630, 1700342215061
	docker : 1700342218602, 1700342219059
	docker : 1700342241387, 1700342241858
	docker : 1700342246286, 1700342246716
	docker : 1700342247845, 1700342248278
	docker : 1700342251824, 1700342252254
	docker : 1700342275121, 1700342275558
	docker : 1700342290457, 1700342291238
	docker : 1700342304149, 1700342304598
	docker : 1700342308937, 1700342309374
	docker : 1700342343789, 1700342344230
	docker : 1700342346998, 1700342347434
	docker : 1700342382540, 1700342383105
	docker : 1700342383109, 1700342383545
	docker : 1700342419022, 1700342419459
	docker : 1700342423378, 1700342423810
	docker : 1700342428493, 1700342428925
	docker : 1700342433989, 1700342434435
	docker : 1700342439989, 1700342440430
	docker : 1700342445189, 1700342445624
	docker : 1700342450029, 1700342450476
	docker : 1700342452423, 1700342453229
	docker : 1700342453232, 1700342453665
	docker : 1700342464009, 1700342464761
	docker : 1700342478961, 1700342479394
	docker : 1700342485376, 1700342485807
	docker : 1700342519129, 1700342519570
	docker : 1700342529498, 1700342529944
	docker : 1700342538739, 1700342539181
	docker : 1700342548254, 1700342548687
	docker : 1700342585718, 1700342586154
	docker : 1700342656476, 1700342656918
	docker : 1700342691073, 1700342691504
	docker : 1700342708154, 1700342708721
	docker : 1700342757171, 1700342757653
	docker : 1700342758051, 1700342758588
	docker : 1700342775511, 1700342775955
	docker : 1700342776336, 1700342776780
	docker : 1700342782728, 1700342783159
	docker : 1700342787481, 1700342787913
	docker : 1700342789916, 1700342790370
	docker : 1700342815887, 1700342816320
	docker : 1700342823727, 1700342824163

Faster clang-format (~31 secs for clang-format)

Workflow Telemetry - ClangFormat Check / Formatting Check

Workflow telemetry for commit 66f6736f1bb0aff522a5c6dd529775191c3ac7e5
You can access workflow job details here

Step Trace

gantt
	title Formatting Check
	dateFormat x
	axisFormat %H:%M:%S
	Set up job : milestone, 1700341522000, 1700341527000
	Build DoozyX/clang-format-lint-action@v0.16.2 : 1700341527000, 1700341533000
	Collect Workflow Telemetry : 1700341533000, 1700341533000
	Run actions/checkout@8ade135a41bc03ea155e62e844d188df1ea18608 : 1700341533000, 1700341540000
	Run DoozyX/clang-format-lint-action@v0.16.2 : 1700341540000, 1700341556000
	Verify Changed files : 1700341556000, 1700341557000
	List all changed files tracked and untracked files : 1700341557000, 1700341557000
	Run actions/upload-artifact@v3 : 1700341557000, 1700341557000
	Post Verify Changed files : 1700341557000, 1700341557000

CPU Metrics

68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f737461636b65642d617265612f74696d652f63686172745f737461636b65645f617265615f74696d655f30376438313836632d626635632d346462652d613034372d6537663033

Memory Metrics

68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f737461636b65642d617265612f74696d652f63686172745f737461636b65645f617265615f74696d655f33373165316236652d636130652d343064342d383033392d3065326162

IO Metrics

Read Write
Network I/O 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f36316235356638392d383863352d343231302d383836392d343966313235663733623435 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f61313830613635352d316364382d346661622d616439642d613366396238333965653565
Disk I/O 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f61643230636365612d376133342d346130632d383562352d373462393039393436653235 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f6c696e652f74696d652f63686172745f6c696e655f74696d655f32303430393734392d356666352d343836382d386461322d343234316264353061366462

Process Trace

Top 100 processes with highest duration

gantt
	title Formatting Check
	dateFormat x
	axisFormat %H:%M:%S
	node (checkout) : 1700341533443, 1700341540649
	git : 1700341533580, 1700341533581
	git : 1700341533588, 1700341533589
	git : 1700341533592, 1700341533598
	git : 1700341533600, 1700341533601
	git : 1700341533604, 1700341533605
	git : crit, 1700341533607, 1700341533608
	git : 1700341533611, 1700341533639
	git-submodule : 1700341533613, 1700341533638
	git : 1700341533616, 1700341533619
	gettext : 1700341533623, 1700341533623
	git : 1700341533627, 1700341533628
	git : 1700341533630, 1700341533631
	git : 1700341533631, 1700341533632
	git : 1700341533633, 1700341533634
	git : 1700341533634, 1700341533635
	git : 1700341533638, 1700341533639
	git : crit, 1700341533641, 1700341533642
	git : 1700341533643, 1700341533664
	git-submodule : 1700341533645, 1700341533665
	git : 1700341533647, 1700341533647
	gettext : 1700341533651, 1700341533651
	git : 1700341533655, 1700341533656
	git : 1700341533657, 1700341533658
	git : 1700341533658, 1700341533659
	git : 1700341533659, 1700341533660
	git : 1700341533661, 1700341533662
	git : 1700341533664, 1700341533665
	git : 1700341533667, 1700341533668
	git : 1700341533673, 1700341539839
	git : 1700341533675, 1700341539613
	git-remote-http : 1700341533677, 1700341539613
	git : 1700341537275, 1700341539828
	git : 1700341539829, 1700341539836
	git : 1700341539839, 1700341539840
	git : 1700341539843, 1700341540634
	git : 1700341540636, 1700341540637
	git : 1700341540640, 1700341540641
	docker : 1700341540688, 1700341556577
	bash : 1700341556637, 1700341557591
	bash : 1700341556639, 1700341557591
	git : 1700341556640, 1700341557085
	git : 1700341557088, 1700341557564
	git : 1700341557566, 1700341557581
	sort : 1700341557585, 1700341557586
	bash : 1700341557613, 1700341557614
	node (upload-artifact) : 1700341557621, 1700341557902
	node (checkout) : 1700341557919, 1700341558068
	git : 1700341557992, 1700341557993
	git : 1700341558000, 1700341558001
	git : crit, 1700341558004, 1700341558005
	git : 1700341558007, 1700341558031
	git-submodule : 1700341558009, 1700341558031
	git : 1700341558012, 1700341558012
	gettext : 1700341558016, 1700341558016
	git : 1700341558019, 1700341558020
	git : 1700341558021, 1700341558022
	git : 1700341558022, 1700341558023
	git : 1700341558024, 1700341558025
	git : 1700341558025, 1700341558026
	git : 1700341558029, 1700341558031
	git : 1700341558033, 1700341558034
	git : 1700341558036, 1700341558037
	git : 1700341558039, 1700341558062
	git-submodule : 1700341558041, 1700341558062
	git : 1700341558043, 1700341558043
	gettext : 1700341558047, 1700341558047
	git : 1700341558051, 1700341558052
	git : 1700341558052, 1700341558053
	git : 1700341558054, 1700341558055
	git : 1700341558056, 1700341558057
	git : 1700341558057, 1700341558058
	git : 1700341558060, 1700341558062

The most interesting thing to look at here is the difference between the CPU usage graphs:

Current action Other faster action
68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f737461636b65642d617265612f74696d652f63686172745f737461636b65645f617265615f74696d655f65326434313138342d363631332d343433342d613235612d3435373863 68747470733a2f2f6170692e676c6f62616467652e636f6d2f76312f636861727467656e2f737461636b65642d617265612f74696d652f63686172745f737461636b65645f617265615f74696d655f30376438313836632d626635632d346462652d613034372d6537663033

Take note that the metrics were only fetched each 5 secs, so the one running only a minute is not as nice to see. So, even with a two core runner (that is what github gives us right?), about half of one core is used, with half of it being system time. So I think its fair to think starting a docker container for the 3357 files takes some amount of time.

I'm not knowledgable enough about bash to be able to suggest the syntax to place the results of the find into whatever variable it takes to give it to the command (inside docker). But it seems its possible to have an exclude regex in the find too, https://stackoverflow.com/questions/6745401/regular-expression-to-exclude-filetypes-from-find. So all could be made in one pass. Last thing: are they some limits on how long the file list can be to be passed sucessfully? If yes, then a batching of a couple thousands should be fine, since 3357 files divided in three "jobs" was able to be run. (The other one uses multiprocessing to launch more than one). Thus, I expect a runtime of maybe 1min30 or less to be perfectly possible if only one docker invocation is used with one process, and no other optimization.

@jidicula
Copy link
Owner

@echoix Thanks for sharing this example! I'm trying some stuff out in #174 - I'll open up a draft PR against your repo pointing to that branch once I think I have a satisfactory solution, and I'll ping you to allow CI runs on it so we can see what the perf looks like.

@echoix
Copy link

echoix commented Dec 24, 2023

You can directly fork https://github.com/OSGeo/grass, it's an open source project. They aim to replace the functionality of this to use pre-commit.ci soon, solving this and other checks altogether.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants