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

Add more logging to mark-scan #4569

Merged
merged 19 commits into from
Feb 20, 2024
Merged

Add more logging to mark-scan #4569

merged 19 commits into from
Feb 20, 2024

Conversation

kshen0
Copy link
Contributor

@kshen0 kshen0 commented Feb 2, 2024

Overview

#3983

  • Adds logging to mark-scan frontend, backend, and daemons
  • Migrates PAT input daemon from C to Rust to converge on Rust logging library

Demo Video or Screenshot

N/A

Testing Plan

  • Add automated tests

Checklist

  • I have added logging where appropriate to any new user actions, system updates such as file reads or storage writes, or errors introduced.

await logger.log(
LogEventId.PollWorkerConfirmedBallotRemoval,
'poll_worker'
);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Most behavior requiring logs is common to VxMark or covered in the backend

@kshen0 kshen0 mentioned this pull request Feb 5, 2024
1 task
Base automatically changed from kevin/logging-type-gen to main February 7, 2024 20:23
@kshen0 kshen0 force-pushed the kevin/mark-scan-logging-2 branch from bcbd640 to 3831e82 Compare February 9, 2024 00:56
@CLAassistant
Copy link

CLAassistant commented Feb 13, 2024

CLA assistant check
All committers have signed the CLA.

@kshen0 kshen0 force-pushed the kevin/mark-scan-logging-2 branch from 442fc43 to ad771f1 Compare February 13, 2024 22:19
@kshen0 kshen0 marked this pull request as ready for review February 14, 2024 00:31
Copy link
Collaborator

@eventualbuddha eventualbuddha left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Needs CircleCI config updates.

apps/mark-scan/accessible-controller/src/controllerd.rs Outdated Show resolved Hide resolved
@@ -29,6 +32,7 @@ function renderWithAuthAndBallotContext(
): VxRenderResult {
return render(
<BallotInvalidatedPage
logger={logger}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Feels like we need a useLogger hook.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In line with discussion in #4592 (comment), 579f510 moves logging to the backend

apps/mark-scan/pat-device-input/src/patinputd.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/patinputd.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/patinputd.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/patinputd.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/patinputd.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/patinputd.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/pin.rs Outdated Show resolved Hide resolved
apps/mark-scan/pat-device-input/src/pin.rs Outdated Show resolved Hide resolved
kshen0 and others added 5 commits February 14, 2024 17:10
Clean up unnecessary multiline calls to `log!` and use shorthand where possible

Co-authored-by: Brian Donovan <[email protected]>
Don't crash on pin read errors and simplify pin value comparison

Co-authored-by: Brian Donovan <[email protected]>
@kshen0 kshen0 force-pushed the kevin/mark-scan-logging-2 branch from 2a314ae to 43ef878 Compare February 15, 2024 02:43
@kshen0
Copy link
Contributor Author

kshen0 commented Feb 15, 2024

Needs CircleCI config updates.

Do you mind if I do this in a follow up PR? I didn't realize circleci.yml is autogenerated. From a quick look, the generation script only handles pnpm packages atm and needs to be extended to handle Rust crates.

Rust tests pass here but validate monorepo failed.

);
Ok(size) => match handle_command(&serial_buf[..size]) {
Ok(key_option) => {
if key_option.is_some() {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Refactored handle_command to avoid passing the device, which is cumbersome to create in CI because it requires special permissions. This seemed easier than configuring udev rules for CI.

The downside is I introduced this nested conditioning to handle when the command should no-op ie. when the controller indicates one of its buttons was released. We only want to send keyboard events when the button is depressed.

To support this, handle_command returns Some(keyboard::Key) on controller button press, and None(keyboard::Key) on button release.

Open to feedback on how to handle these checks more cleanly/inline.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This can be improved by being more specific about the types you're looking for in your match arms:

                        Ok(Some(key)) => {
                            if let Err(err) = send_key(&mut device, key) {
                                log!(EventId::UnknownError, "Error sending key: {err}");
                            }
                        }
                        Ok(None) => {}

In general, you don't want to use is_some() or is_ok() et al when you want the value being wrapped. Use match/if let/let/else destructuring

Comment on lines 466 to 468
// In prod we wait 1s for the device to register.
// We can afford to be riskier to speed up tests.
thread::sleep(DEVICE_WAIT_DURATION);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This isn't needed, right?

Comment on lines 479 to 481
let key_option = handle_command(&data).unwrap();
assert!(key_option.is_some());
assert_eq!(key_option.unwrap(), keyboard::Key::R);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I recommend this:

Suggested change
let key_option = handle_command(&data).unwrap();
assert!(key_option.is_some());
assert_eq!(key_option.unwrap(), keyboard::Key::R);
assert_eq!(handle_command(&data).unwrap().unwrap(), keyboard::Key::R);

In tests, unwrapping Option and Result generally provides more useful error messages than assert!(key_option.is_some()) or assert!(result.is_ok()). For example:

called `Result::unwrap()` on an `Err` value: UnexpectedDataLength(258)

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Rebase weirdness?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Somewhere along the way this code path was reported as uncovered so I added this test.

@kshen0 kshen0 force-pushed the kevin/mark-scan-logging-2 branch from ad796d2 to 74cb5de Compare February 15, 2024 18:57
@kshen0 kshen0 mentioned this pull request Feb 16, 2024
3 tasks
Copy link
Collaborator

@eventualbuddha eventualbuddha left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A couple minor things, but LGTM!

Comment on lines 85 to 91
set_up_pins().unwrap_or_else(|error| {
log!(
event_id: EventId::ConnectToPatInputComplete,
disposition: Disposition::Failure,
message: format!("An error occurred during GPIO pin connection: {error}")
);
});
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When you're not using the value it seems a little weird to use unwrap_or_else. Maybe do this?

Suggested change
set_up_pins().unwrap_or_else(|error| {
log!(
event_id: EventId::ConnectToPatInputComplete,
disposition: Disposition::Failure,
message: format!("An error occurred during GPIO pin connection: {error}")
);
});
if let Err(error) = set_up_pins() {
log!(
event_id: EventId::ConnectToPatInputComplete,
disposition: Disposition::Failure,
message: format!("An error occurred during GPIO pin connection: {error}")
);
}

Also, do we want to continue after this?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

5171668
good catch, thank you

apps/mark-scan/pat-device-input/src/pin.rs Show resolved Hide resolved
@@ -0,0 +1,138 @@
use pin::Pin;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Write a //! module-level doc comment? I know a fair amount of the existing Rust code doesn't do this, but I'm trying to encourage better habits here.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

a75cf84

doc comments added to both daemons and Pin struct

/// Makes the pin accessible from userspace. If the pin is already set up due to
/// a previous `set_up` call, or from other callers of the sysfs interface, `set_up`
/// will tear down the pin and attempt one more time to set up. This may cause
/// interruption to other processes attempting to read the pin value.
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This brings up the question of whether we should just continue when we see the pin is already exported. IMO since we expect this daemon to be the only exporter it should never rely on the unexpected state of the pin already being exported. ie. it should always be exercising the path to export the pin.

@@ -51,6 +72,9 @@ impl Pin {
self.set_direction_in()
}

/// Reads the pin value and returns the boolean inverse of the pin's raw value.
/// # Example
/// When the pin's value is b'0', `is_active` returns true.
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I believe this convention is specific to VSAP's implementation, so it could arguably live in the daemon code. But since we have no planned use for this module outside the PAT integration it feels cleaner to leave this translation in the pin module.

@kshen0 kshen0 merged commit 3712d34 into main Feb 20, 2024
52 checks passed
@kshen0 kshen0 deleted the kevin/mark-scan-logging-2 branch February 20, 2024 21:33
@kshen0 kshen0 changed the title Kevin/mark scan logging 2 Add more logging to mark-scan Feb 29, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants