perf: Capture InstanceTypeFilterErrors in error structs and don't print them until the end #1948

jonathan-innis · 2025-01-31T22:47:55Z

Fixes #N/A

Description

This change ensures that we don't perform expensive operations that show-up in the CPU profile and show-up in our heap analysis to print the nodeClaimRequirements and performing resources.Merge.

These changes were executed against the scheduling benchmark (which showed negligible performance changes) and a live test that deploys 20,000 pods to the cluster and generates 10,000 nodes (with two pods per node constrained by the size of the instance types on NodePools). Prior to the change, this test took 31m49s. After the change, the same test case takes 26m34s (a 5m15s improvement).

Before PR

Scheduling Benchmark

=== RUN   TestSchedulingProfile
scheduled 40151 against 8031 nodes in total in 59.198867831s 678.2393223232317 pods/sec
400 instances 1 pods      1 nodes     183.666µs per scheduling      183.666µs per pod
400 instances 50 pods     10 nodes    42.342407ms per scheduling    846.848µs per pod
400 instances 100 pods    20 nodes    86.044652ms per scheduling    860.446µs per pod
400 instances 500 pods    100 nodes   408.015194ms per scheduling   816.03µs per pod
400 instances 1000 pods   200 nodes   803.296687ms per scheduling   803.296µs per pod
400 instances 1500 pods   300 nodes   1.23015975s per scheduling    820.106µs per pod
400 instances 2000 pods   400 nodes   1.744999875s per scheduling   872.499µs per pod
400 instances 5000 pods   1000 nodes  5.008729875s per scheduling   1.001745ms per pod
400 instances 10000 pods  2000 nodes  12.685723333s per scheduling  1.268572ms per pod
400 instances 20000 pods  4000 nodes  35.421737833s per scheduling  1.771086ms per pod
--- PASS: TestSchedulingProfile (67.02s)
PASS

Live Test

Scheduling Time: 31m49s

{"level":"INFO","time":"2025-02-02T06:45:17.502Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":3563,"pods-remaining":16437,"duration":"1m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:46:17.563Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":5017,"pods-remaining":14983,"duration":"2m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:47:17.663Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":6127,"pods-remaining":13873,"duration":"3m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:48:17.718Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":7071,"pods-remaining":12929,"duration":"4m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:49:17.873Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":7911,"pods-remaining":12089,"duration":"5m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:50:18.015Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":8671,"pods-remaining":11329,"duration":"6m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:51:18.075Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":9367,"pods-remaining":10633,"duration":"7m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:52:18.319Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":10017,"pods-remaining":9983,"duration":"8m0s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:53:18.497Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":10627,"pods-remaining":9373,"duration":"9m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:54:18.551Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":11205,"pods-remaining":8795,"duration":"10m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:55:18.745Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":11755,"pods-remaining":8245,"duration":"11m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:56:18.965Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":12283,"pods-remaining":7717,"duration":"12m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:57:19.157Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":12787,"pods-remaining":7213,"duration":"13m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:58:19.252Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":13273,"pods-remaining":6727,"duration":"14m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T06:59:19.280Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":13743,"pods-remaining":6257,"duration":"15m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:00:19.325Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":14195,"pods-remaining":5805,"duration":"16m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:01:19.376Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":14635,"pods-remaining":5365,"duration":"17m1s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:02:19.579Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":15063,"pods-remaining":4937,"duration":"18m2s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:03:19.664Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":15479,"pods-remaining":4521,"duration":"19m2s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:04:19.813Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":15885,"pods-remaining":4115,"duration":"20m2s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:05:20.038Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":16281,"pods-remaining":3719,"duration":"21m2s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:06:20.256Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":16663,"pods-remaining":3337,"duration":"22m2s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:07:20.293Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":17035,"pods-remaining":2965,"duration":"23m2s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:08:20.542Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":17407,"pods-remaining":2593,"duration":"24m3s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:09:20.691Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":17763,"pods-remaining":2237,"duration":"25m3s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:10:20.868Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":18117,"pods-remaining":1883,"duration":"26m3s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:11:20.904Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":18463,"pods-remaining":1537,"duration":"27m3s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:12:21.082Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":18795,"pods-remaining":1205,"duration":"28m3s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:13:21.410Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":19123,"pods-remaining":877,"duration":"29m3s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:14:21.578Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":19447,"pods-remaining":553,"duration":"30m4s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:15:21.892Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","pods-scheduled":19767,"pods-remaining":233,"duration":"31m4s","scheduling-id":"cbdf5dcc-94c3-4371-b0a6-f8574137b2af"}
{"level":"INFO","time":"2025-02-02T07:16:06.064Z","logger":"controller","caller":"provisioning/provisioner.go:129","message":"found provisionable pod(s)","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","Pods":"default/test-51, default/test-123, default/test-31, default/test-181, default/test-19 and 19995 other(s)","duration":"31m49.389166009s"}
{"level":"INFO","time":"2025-02-02T07:16:06.094Z","logger":"controller","caller":"provisioning/provisioner.go:350","message":"computed new nodeclaim(s) to fit pod(s)","commit":"16dfcb0-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"c3bd7c1f-4074-4d75-83e3-22c046e7efe6","nodeclaims":10000,"pods":20000}

Heap Profile

After PR

Scheduling Benchmark

=== RUN   TestSchedulingProfile
scheduled 40151 against 8031 nodes in total in 59.329537061s 676.7455468044276 pods/sec
400 instances 1 pods      1 nodes     199.111µs per scheduling      199.111µs per pod
400 instances 50 pods     10 nodes    42.671329ms per scheduling    853.426µs per pod
400 instances 100 pods    20 nodes    110.710599ms per scheduling   1.107105ms per pod
400 instances 500 pods    100 nodes   432.48425ms per scheduling    864.968µs per pod
400 instances 1000 pods   200 nodes   1.021048083s per scheduling   1.021048ms per pod
400 instances 1500 pods   300 nodes   1.41967825s per scheduling    946.452µs per pod
400 instances 2000 pods   400 nodes   1.755113042s per scheduling   877.556µs per pod
400 instances 5000 pods   1000 nodes  5.021272375s per scheduling   1.004254ms per pod
400 instances 10000 pods  2000 nodes  12.540354458s per scheduling  1.254035ms per pod
400 instances 20000 pods  4000 nodes  35.597483625s per scheduling  1.779874ms per pod
--- PASS: TestSchedulingProfile (66.63s)
PASS

Live Test

Scheduling Time: 26m34s

{"level":"INFO","time":"2025-02-02T06:14:35.499Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":3993,"pods-remaining":16007,"duration":"1m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:15:35.613Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":5631,"pods-remaining":14369,"duration":"2m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:16:35.706Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":6837,"pods-remaining":13163,"duration":"3m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:17:35.835Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":7859,"pods-remaining":12141,"duration":"4m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:18:35.920Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":8763,"pods-remaining":11237,"duration":"5m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:19:36.030Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":9581,"pods-remaining":10419,"duration":"6m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:20:36.137Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":10337,"pods-remaining":9663,"duration":"7m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:21:36.266Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":11037,"pods-remaining":8963,"duration":"8m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:22:36.288Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":11685,"pods-remaining":8315,"duration":"9m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:23:36.336Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":12307,"pods-remaining":7693,"duration":"10m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:24:36.356Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":12901,"pods-remaining":7099,"duration":"11m0s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:25:36.485Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":13467,"pods-remaining":6533,"duration":"12m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:26:36.632Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":14011,"pods-remaining":5989,"duration":"13m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:27:36.802Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":14539,"pods-remaining":5461,"duration":"14m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:28:37.000Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":15051,"pods-remaining":4949,"duration":"15m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:29:37.161Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":15545,"pods-remaining":4455,"duration":"16m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:30:37.245Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":16023,"pods-remaining":3977,"duration":"17m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:31:37.392Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":16485,"pods-remaining":3515,"duration":"18m1s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:32:37.534Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":16935,"pods-remaining":3065,"duration":"19m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:33:37.625Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":17375,"pods-remaining":2625,"duration":"20m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:34:37.690Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":17803,"pods-remaining":2197,"duration":"21m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:35:37.839Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":18217,"pods-remaining":1783,"duration":"22m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:36:37.930Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":18623,"pods-remaining":1377,"duration":"23m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:37:38.041Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":19023,"pods-remaining":977,"duration":"24m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:38:38.068Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":19415,"pods-remaining":585,"duration":"25m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:39:38.221Z","logger":"controller","caller":"provisioning/provisioner.go:343","message":"computing pod scheduling...","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","pods-scheduled":19801,"pods-remaining":199,"duration":"26m2s","scheduling-id":"7045ca91-106e-453a-8921-3cd9b2719ba1"}
{"level":"INFO","time":"2025-02-02T06:40:09.404Z","logger":"controller","caller":"provisioning/provisioner.go:129","message":"found provisionable pod(s)","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","Pods":"default/test-51, default/test-123, default/test-31, default/test-181, default/test-19 and 19995 other(s)","duration":"26m34.756538567s"}
{"level":"INFO","time":"2025-02-02T06:40:09.435Z","logger":"controller","caller":"provisioning/provisioner.go:350","message":"computed new nodeclaim(s) to fit pod(s)","commit":"0edfada-dirty","controller":"provisioner","namespace":"","name":"","reconcileID":"aea398a8-2f52-4a1d-9250-70b4a268231e","nodeclaims":10000,"pods":20000}

Heap Profile

How was this change tested?

make presubmit

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

k8s-ci-robot · 2025-01-31T22:47:58Z

Skipping CI for Draft Pull Request.
If you want CI signal for your change, please convert it to an actual PR.
You can still manually trigger a test run with /test all

coveralls · 2025-01-31T23:09:47Z

Pull Request Test Coverage Report for Build 13082607588

Details

44 of 54 (81.48%) changed or added relevant lines in 2 files are covered.
4 unchanged lines in 1 file lost coverage.
Overall coverage increased (+0.04%) to 81.268%

Changes Missing Coverage	Covered Lines	Changed/Added Lines	%
pkg/controllers/provisioning/scheduling/nodeclaim.go	43	53	81.13%

Files with Coverage Reduction	New Missed Lines	%
pkg/controllers/provisioning/scheduling/nodeclaim.go	4	88.78%

Totals
Change from base Build 13082187201:	0.04%
Covered Lines:	9098
Relevant Lines:	11195

💛 - Coveralls

…m until the end

rschalo · 2025-02-04T15:38:24Z

pkg/controllers/provisioning/scheduling/nodeclaim.go

-	if !r.requirementsMet && !r.fits && !r.hasOffering {
-		return "no instance type met the scheduling requirements or had enough resources or had a required offering"
+	if !e.requirementsMet && !e.fits && !e.hasOffering {
+		return fmt.Sprintf("no instance type met the scheduling requirements or had enough resources or had a required offering, requirements=%s, resources=%s", e.requirements, resources.String(resources.Merge(e.daemonRequests, e.podRequests)))


Does the improvement require that e.requirements, resources.String(resources.Merge(e.daemonRequests, e.podRequests) be called in every branch as opposed to once at the top of .Error()?

No, it doesn't -- I was going back and forth on whether to add the code duplication or not -- it seemed fine to me to do it this way for the short-circuiting and error returns -- otherwise, I have to create a string and then append to it

rschalo · 2025-02-04T18:31:16Z

/lgtm

k8s-ci-robot · 2025-02-04T18:31:32Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: jonathan-innis, rschalo

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [jonathan-innis]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

k8s-ci-robot added the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Jan 31, 2025

k8s-ci-robot added the cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. label Jan 31, 2025

k8s-ci-robot requested review from jackfrancis and tallaxes January 31, 2025 22:48

k8s-ci-robot added approved Indicates a PR has been approved by an approver from all required OWNERS files. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Jan 31, 2025

k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jan 31, 2025

jonathan-innis force-pushed the remove-print-requirements branch from ecce7df to 0edfada Compare January 31, 2025 23:40

k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jan 31, 2025

jonathan-innis force-pushed the remove-print-requirements branch from 0edfada to 06f044f Compare February 2, 2025 06:41

jonathan-innis marked this pull request as ready for review February 2, 2025 07:18

k8s-ci-robot removed the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Feb 2, 2025

k8s-ci-robot requested review from engedaam and jmdeal February 2, 2025 07:19

Capture InstanceTypeFilterErrors in error structs and don't print the…

f91a411

…m until the end

jonathan-innis force-pushed the remove-print-requirements branch from 06f044f to f91a411 Compare February 2, 2025 07:20

rschalo reviewed Feb 4, 2025

View reviewed changes

k8s-ci-robot assigned rschalo Feb 4, 2025

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Feb 4, 2025

rschalo approved these changes Feb 4, 2025

View reviewed changes

k8s-ci-robot merged commit 9740cc2 into kubernetes-sigs:main Feb 4, 2025
13 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

perf: Capture InstanceTypeFilterErrors in error structs and don't print them until the end #1948

perf: Capture InstanceTypeFilterErrors in error structs and don't print them until the end #1948

jonathan-innis commented Jan 31, 2025 •

edited

Loading

k8s-ci-robot commented Jan 31, 2025

coveralls commented Jan 31, 2025 •

edited

Loading

rschalo Feb 4, 2025

jonathan-innis Feb 4, 2025

rschalo commented Feb 4, 2025

k8s-ci-robot commented Feb 4, 2025

perf: Capture InstanceTypeFilterErrors in error structs and don't print them until the end #1948

perf: Capture InstanceTypeFilterErrors in error structs and don't print them until the end #1948

Conversation

jonathan-innis commented Jan 31, 2025 • edited Loading

Before PR

Scheduling Benchmark

Live Test

Heap Profile

After PR

Scheduling Benchmark

Live Test

Heap Profile

k8s-ci-robot commented Jan 31, 2025

coveralls commented Jan 31, 2025 • edited Loading

Pull Request Test Coverage Report for Build 13082607588

Details

💛 - Coveralls

rschalo Feb 4, 2025

Choose a reason for hiding this comment

jonathan-innis Feb 4, 2025

Choose a reason for hiding this comment

rschalo commented Feb 4, 2025

k8s-ci-robot commented Feb 4, 2025

jonathan-innis commented Jan 31, 2025 •

edited

Loading

coveralls commented Jan 31, 2025 •

edited

Loading