Skip to content

Housekeeping: Logged messages now follow a given standard#167

Merged
tolik518 merged 14 commits intomasterfrom
log-format
Apr 7, 2025
Merged

Housekeeping: Logged messages now follow a given standard#167
tolik518 merged 14 commits intomasterfrom
log-format

Conversation

@tolik518
Copy link
Owner

@tolik518 tolik518 commented Apr 5, 2025

Factorion will now write logs in a standardized format. This is part of the preparations for introducing the ELK stack (or some other centralized logging) to my server.

before

InfluxDB client configured. Metrics will be logged.
Fetched new token. Will expire: 2025-04-06T20:05:02Z
Now: 2025-04-05T20:05:02.375087177Z | Expiration time: 2025-04-06T20:05:02Z
Found comment_ids in the file
2025-04-05 - 20:05:02.509432674 | Polling Reddit for new comments...
2025-04-05 - 20:05:07.223019465 | Polling Reddit for new comments...
2025-04-05 - 20:05:10.775219833 | Polling Reddit for new comments...

after

INFO | factorion_bot | 2025-04-05T18:56:32Z | InfluxDB client configured. Metrics will be logged.
INFO | factorion_bot | 2025-04-05T18:56:38Z | Fetched new token. Will expire: 2025-04-06T18:56:38Z
INFO | factorion_bot | 2025-04-05T18:56:38Z | Found comment_ids in the file
INFO | factorion_bot | 2025-04-05T18:56:38Z | Polling Reddit for new comments...
INFO | factorion_bot | 2025-04-05T18:56:50Z | Polling Reddit for new comments...
ERROR | factorion_bot | 2025-04-05T18:57:12Z | Thread panicked at src/main.rs:141 with message: attempt to calculate the remainder with a divisor of zero

@tolik518
Copy link
Owner Author

tolik518 commented Apr 5, 2025

I'm not sure if the panic hook is good practice, but I haven't found a better way to forward the panic messages to the logger

@tolik518 tolik518 changed the title Logged messages now follow a given standard Housekeeping: Logged messages now follow a given standard Apr 5, 2025
@tolik518 tolik518 requested a review from Copilot April 5, 2025 21:27
Copy link

Copilot AI left a comment

Choose a reason for hiding this comment

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

Copilot reviewed 6 out of 6 changed files in this pull request and generated no comments.

Comments suppressed due to low confidence (1)

src/reddit_api.rs:233

  • [nitpick] Consider aligning the logging level for 'Missing ratelimit' messages across the codebase. In src/reddit_api.rs the message uses warn! while in src/main.rs a similar situation uses error!; review and adjust the severity to ensure consistent behavior.
warn!("Missing ratelimit")

@tolik518 tolik518 requested a review from Copilot April 5, 2025 21:31
Copy link

Copilot AI left a comment

Choose a reason for hiding this comment

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

Copilot reviewed 8 out of 8 changed files in this pull request and generated no comments.

Comments suppressed due to low confidence (1)

src/main.rs:271

  • If the intention is to clear the file contents before writing new comment IDs, consider using '.truncate(true)' to avoid leaving stale data from previous runs.
.truncate(false)

@tolik518
Copy link
Owner Author

tolik518 commented Apr 5, 2025

The first copilot comment was actually unexpectedly helpful

match self {
CalculationResult::Exact(n) => write!(f, "Exact({})", truncate(n)),
CalculationResult::Approximate(of, int) => {
write!(f, "Approximate({:?}, {})", of, truncate(int))
Copy link
Collaborator

Choose a reason for hiding this comment

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

That's going to be really long, a 3.4 would be displayed as OrdFloat { inner: 3.399999999999999911182158029987476766109466552734375000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 } (More than 25 digits every time). Would maybe make more sense to do, what we do for formatting them and .as_float().to_f64().

Otherwise, at least truncate it (though we really don't need to have it tell us it's an OrdFloat).

Copy link
Owner Author

Choose a reason for hiding this comment

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

That's a very good point, didn't think of long Floats

Copy link
Owner Author

Choose a reason for hiding this comment

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

Truncation now displays as following (3.4 on my machine is also a bit different):

INFO | factorion-bot | 2025-04-06T20:49:45Z | Comment -> RedditComment { id: "t1_mlramm9", calculation_list: [Calculation { value: 3.400000000000000000..., steps: [(1, 0)], result: Float(10.13610185115513210...) }], author: "tolik518", notify: None, subreddit: "test", status: Status { already_replied_or_rejected: false, not_replied: true, number_too_big_to_calculate: false, no_factorial: false, reply_would_be_too_long: false, factorials_found: true }, commands: Commands { shorten: false, steps: false, termial: false, no_note: false, post_only: false } }

@Aras14HD
Copy link
Collaborator

Aras14HD commented Apr 6, 2025

Don't know if you want to do that in a separate pull, but I have some proposals for debug/trace logs:

  • What we're getting (if check_posts/check_mentions is true), like Getting comments, posts, inbox
  • How many comments total were returned by the api (comments.len())
  • How long we sleep for (reply and polling)
  • What the current ratelimit values are, like 504s till reset, 783 requests remaining
  • the current last_ids values, like Last ids were t1_msu372s (comments) t3_msu42sa (posts) t1_ue14n2s (inbox)

In general, I would use debug for data useful while developing/debugging (duh), logged once a loop or reply at most. And trace could be used for stuff that happens every gotten comment, though I have no ideas, what could be useful there.

@tolik518
Copy link
Owner Author

tolik518 commented Apr 6, 2025

All those logs would make sense. I'm not sure how I'd differentiate trace and debug tbh.

Not sure if I'll implement the proposed logs in that pr, or create a separate one. I'll take a look at it in the evening.

@tolik518 tolik518 mentioned this pull request Apr 6, 2025
@tolik518 tolik518 requested review from Aras14HD and Copilot April 6, 2025 20:57
Copy link

Copilot AI left a comment

Choose a reason for hiding this comment

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

Copilot reviewed 8 out of 8 changed files in this pull request and generated no comments.

Copy link
Collaborator

@Aras14HD Aras14HD left a comment

Choose a reason for hiding this comment

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

Other than the one instance of code duplication, everything looks good now.

Comment on lines +60 to +67
fn truncate<T: fmt::Debug>(val: &T) -> String {
let s = format!("{:?}", val);
if s.len() > 25 {
format!("{}...", &s[..20])
} else {
s
}
}
Copy link
Collaborator

Choose a reason for hiding this comment

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

While this one duplication is not much of a problem, if it becomes more, you really should just move it outside. Would make it easier to for example change the length of the truncation.

Copy link
Owner Author

Choose a reason for hiding this comment

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

Yeah you're right, I was just struggling to find a fitting place for the function

@tolik518 tolik518 merged commit 34e813b into master Apr 7, 2025
5 checks passed
@tolik518 tolik518 deleted the log-format branch April 7, 2025 19:52
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