tosc-rs / mnemos

An Operating System for Building Small Computers
https://mnemos.dev
Apache License 2.0
253 stars 18 forks source link

feat(kernel): improve `registry` tracing #266

Closed hawkw closed 1 year ago

hawkw commented 1 year ago

The registry emits a bunch of tracing diagnostics, but they're not that helpful in most cases. In particular, when we get a service, we log its UUID, but this isn't super readable for someone consuming the logs --- you have to then take that UUID and look it up against the table of potential UUIDs to figure out which service was being looked up. Also, some of the errors introduced in #258 look pretty lousy in fmt::Debug output.

This branch fixes both of those issues. I've changing the logs emitted by the registry to also include the type name of the service, which makes it easier to tell what's going on without having to cross-reference UUIDs against the actual source code. Furthermore, I've improved the readability of some of the error types.

Example log output:

Before ```rust running 1 test INFO registry::tests::user_connect Registry::register{uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635}: kernel::registry: Registered uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635 service_id=0 INFO registry::tests::user_connect kernel::comms::bbq: Creating new mpsc BBQueue channel capacity=256 INFO registry::tests::user_connect kernel::comms::bbq: Channel created successfully INFO registry::tests::user_connect user_connect{hello=TestMessage(1)}:Registry::connect_userspace_with_hello{user_hello=[1] uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635}: kernel::registry: Got KernelHandle from Registry uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635 service_id=0 client_id=1 INFO registry::tests::user_connect user_request{req=TestMessage(1)}: kernel::registry::tests: sending user request req=TestMessage(1) INFO registry::tests::user_connect kernel::registry::tests: received request val=1 INFO registry::tests::user_connect user_request{req=TestMessage(1)}: kernel::registry::tests: return=Ok(TestMessage(2)) ERROR registry::tests::user_connect user_connect{hello=TestMessage(2)}: kernel::registry::tests: error=UserConnectError::Connect(ConnectError::::Rejected(TestMessage(666))) INFO registry::tests::user_connect user_connect{hello=TestMessage(1)}:Registry::connect_userspace_with_hello{user_hello=[1] uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635}: kernel::registry: Got KernelHandle from Registry uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635 service_id=0 client_id=2 INFO registry::tests::user_connect user_request{req=TestMessage(2)}: kernel::registry::tests: sending user request req=TestMessage(2) INFO registry::tests::user_connect kernel::registry::tests: received request val=2 INFO registry::tests::user_connect user_request{req=TestMessage(2)}: kernel::registry::tests: return=Ok(TestMessage(3)) INFO registry::tests::user_connect user_request{req=TestMessage(3)}: kernel::registry::tests: sending user request req=TestMessage(3) INFO registry::tests::user_connect kernel::registry::tests: received request val=3 INFO registry::tests::user_connect user_request{req=TestMessage(3)}: kernel::registry::tests: return=Ok(TestMessage(4)) test registry::tests::user_connect ... ok ```
After ```rust running 1 test INFO registry::tests::user_connect Registry::register{svc=kernel::registry::tests::TestService}: kernel::registry: Registered svc=kernel::registry::tests::TestService uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635 service_id=0 INFO registry::tests::user_connect kernel::comms::bbq: Creating new mpsc BBQueue channel capacity=256 INFO registry::tests::user_connect kernel::comms::bbq: Channel created successfully INFO registry::tests::user_connect user_connect{hello=TestMessage(1)}:Registry::connect_userspace_with_hello{user_hello=[1] svc=kernel::registry::tests::TestService}: kernel::registry: Got KernelHandle from Registry svc=kernel::registry::tests::TestService uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635 service_id=0 client_id=1 INFO registry::tests::user_connect user_request{req=TestMessage(1)}: kernel::registry::tests: sending user request req=TestMessage(1) INFO registry::tests::user_connect kernel::registry::tests: received request val=1 INFO registry::tests::user_connect user_request{req=TestMessage(1)}: kernel::registry::tests: return=Ok(TestMessage(2)) ERROR registry::tests::user_connect user_connect{hello=TestMessage(2)}: kernel::registry::tests: error=Connect(Rejected { error: TestMessage(666), svc: kernel::registry::tests::TestService }) INFO registry::tests::user_connect user_connect{hello=TestMessage(1)}:Registry::connect_userspace_with_hello{user_hello=[1] svc=kernel::registry::tests::TestService}: kernel::registry: Got KernelHandle from Registry svc=kernel::registry::tests::TestService uuid=05bcd4b7-dd81-434a-a958-f18ee84f8635 service_id=0 client_id=2 INFO registry::tests::user_connect user_request{req=TestMessage(2)}: kernel::registry::tests: sending user request req=TestMessage(2) INFO registry::tests::user_connect kernel::registry::tests: received request val=2 INFO registry::tests::user_connect user_request{req=TestMessage(2)}: kernel::registry::tests: return=Ok(TestMessage(3)) INFO registry::tests::user_connect user_request{req=TestMessage(3)}: kernel::registry::tests: sending user request req=TestMessage(3) INFO registry::tests::user_connect kernel::registry::tests: received request val=3 INFO registry::tests::user_connect user_request{req=TestMessage(3)}: kernel::registry::tests: return=Ok(TestMessage(4)) test registry::tests::user_connect ... ok ````