feat: Logging license type usage - #268
dominicprice-lowrisc wants to merge 6 commits into
Conversation
Signed-off-by: Dominic Price <dominic.price@lowrisc.org>
Signed-off-by: Dominic Price <dominic.price@lowrisc.org>
Signed-off-by: Dominic Price <dominic.price@lowrisc.org>
Signed-off-by: Dominic Price <dominic.price@lowrisc.org>
Signed-off-by: Dominic Price <dominic.price@lowrisc.org>
1f66ad8 to
b6114ba
Compare
dominicprice-lowrisc
changed the title
Signed-off-by: Dominic Price <dominic.price@lowrisc.org>
There was a problem hiding this comment.
Thanks for the work on this @dominicprice-lowrisc, the overall approach LGTM.
I've left a lot of comments but most are very nitpicky, and hopefully quite easy to address or defer. The important comments are those on OpenTitan's commit guidelines and about handling resources vs. tools in the ResourceManager.
| if log.isEnabledFor(log.DEBUG) and self._resources: | ||
| self.add_job_status_change_callback( | ||
| lambda spec, old, new, resources=self._resources: | ||
| lambda spec, old, new, resources=self._resources: ( |
There was a problem hiding this comment.
Nit: For OpenTitan & related projects, the contribution guidelines recommends that commits are made atomic, without a series of fixups.
Can you squash this down so that each commit is independently passing CI / formatting etc. in isolation? It could all be in 1 commit, or maybe you could make 3 commits with e.g. (a) add license type usage logging, (b) add a test and (c) improve the logging? The change to the tool_meta_factory could also reasonably be its own commit: it's up to you :)
| self._on_kill_signal: list[OnSchedulerKillCb] = [] | ||
|
|
||
| # Register callbacks for debug logging | ||
| if log.isEnabledFor(log.DEBUG) and self._resources: |
There was a problem hiding this comment.
I'm still not 100% sure if this is best to exist here as a "native" concept in the Scheduler / ResourceManager, or if it should be a separate ResourceInstrumentation that hooks in.
I think that in reality this kind of resource logging probably better fits as an instrumentation hook, so that it can easily be enabled/disabled on the command line rather than being hid behind behind a logging level. But at the same time the resources are already tracked in the ResourceManager which is a first-class concept since it limits parallelism, so it also makes sense to have the logging here.
I think for now this approach makes good sense, though if we end up needing to expand this in the future it might be a good idea to revisit this. From my perspective, in an ideal world there would be some API via which an external observer could query the running dvsim process, and this would probably hook into the instrumentation -- rather than needing to parse log strings directly.
| if log.isEnabledFor(log.DEBUG) and self._resources: | ||
| self.add_job_status_change_callback( | ||
| lambda spec, old, new, resources=self._resources: ( | ||
| resources.update_job_status_count_per_tool(spec, old, new) | ||
| ) | ||
| ) | ||
| self.add_job_status_change_callback( | ||
| lambda _spec, _old, _new, resources=self._resources: ( | ||
| resources.log_job_status_count_per_tool() | ||
| ) | ||
| ) |
There was a problem hiding this comment.
Nit: I would combine these into one callback -- in practice the callbacks should be handled sequentially in terms of the order registered, however this is not explicitly defined anywhere and we should not make this assumption (even internally 😅)
I would also probably move all of this under log.VERBOSE instead of log.DEBUG: if we need to, we can hide this logging behind a CLI option.
| self._provider = provider | ||
| self._missing_policy = missing_policy | ||
| self._usage = defaultdict(int) | ||
| self._job_status_count_per_tool: dict[str, dict[JobStatus, int]] = {} |
There was a problem hiding this comment.
I would use a more strong
| self._job_status_count_per_tool: dict[str, dict[JobStatus, int]] = {} | |
| self._job_status_count_per_tool = defaultdict(lambda: defaultdict(int)) |
And then log an error in ResourceManager.update_job_status_count_per_tool if we didn't see the tool during initialization. Or do you see a problem with this approach?
|
|
||
| spec: JobSpec | ||
| backend_key: str # either spec.backend, or the default backend if not given | ||
| tool: str |
There was a problem hiding this comment.
I think this might be left-over code? Given that all the accesses that I can see just go through JobHandle.spec.tool?
| self, spec: JobSpec, old: JobStatus, new: JobStatus | ||
| ) -> None: | ||
| """Update the index that tracks job status counts per resource.""" | ||
| if status_counts := self._job_status_count_per_tool.get(spec.tool.name): |
There was a problem hiding this comment.
Since this is native to the ResourceManager, it should be able to abstract generic resources (and generic amounts of resources) instead of just tool names.
spec.resources is an optional mapping of resource name -> resource amount, so it allows jobs to define arbitrary amounts of resources. So while this is currently used for simulation tools, it could also denote physical resources, requirements for multiple simultaneous licenses (e.g. VCS & Z01X), etc. Then future job types just need to implement the resources that they need, and users can customize their resource availability on the command-line to limit parallelism.
I would probably initialize the index with the sum of the total resource usage, following the same approach as you currently have -- and then track this iterating over the resources of each job.
| """Initialise an index tracking the number of jobs with each status, per tool.""" | ||
| for job in jobs: | ||
| tool = job.tool.name | ||
| if job_status_counts := self._job_status_count_per_tool.get(tool, None): |
There was a problem hiding this comment.
Nit: redundant None
| if job_status_counts := self._job_status_count_per_tool.get(tool, None): | |
| if job_status_counts := self._job_status_count_per_tool.get(tool): |
| return ToolMeta(name=name, version=version) | ||
| if name: | ||
| return ToolMeta(name=name, version=version) | ||
| # Do not need cryptographically secure PRNG for generating values to test on. |
There was a problem hiding this comment.
Nit: I would just drop this comment, I think it's understandable from the noqa.
| assert_that(proc.exitcode, equal_to(0)) | ||
|
|
||
|
|
||
| class TestLogging: |
There was a problem hiding this comment.
Nit: can you give this a quick docstring? Something like
"""Unit tests for the logging functionality of the scheduler."""| @staticmethod | ||
| @pytest.mark.asyncio | ||
| @pytest.mark.timeout(DEFAULT_TIMEOUT) | ||
| async def test_blocked_weight_starvation_logs( |
There was a problem hiding this comment.
It's fine to base this test on test_blocked_weight_starvation, but I would suggest the name is more clear about what is actually being tested. Maybe something like:
| async def test_blocked_weight_starvation_logs( | |
| async def test_resource_logging( |
This branch has not been deployed
2 participants
Description
This PR addresses #267 by adding additional logging at the debug level. There is already logging for when a job has changed status (e.g. from scheduled to queued), and now a table is also logged showing per tool, the number of jobs with each status. I have attached an image and text copy of how these logs look when run in the OpenTitan repository. I have also added a test case to intercept the logs and check that each of the simulation tools is present in the logs at the debug level.
The way I implemented this was to create an index in the
ResourceManagerto track job statuses per tool, and register callbacks in theSchedulerto log this information whenever a job changes status. I also modifiedtool_meta_factoryin the tests file to randomly select real simulation tools names, rather than just using"test_tool"by default.(The exact command I used to generate the attached screenshot was
uv run --no-sync dvsim hw/top_earlgrey/dv/top_earlgrey_sim_cfgs.hjson -i smoke --scratch ~/scratch --fixed-seed 1 --verbose=debug --cov -R A=20, with my fork of DVSim installed).