
On 2021-12-06 at 02:15:36 +1100, Chris Angelico <rosuav@gmail.com> wrote:
On Mon, Dec 6, 2021 at 1:48 AM <2QdxY4RzWzUUiLuE@potatochowder.com> wrote:
On 2021-12-05 at 20:30:53 +1100, Chris Angelico <rosuav@gmail.com> wrote:
[...]
I agree. *Not* conflating timestamps and event IDs is a good thing! APIs and libraries like that are making my point: the very notion of "overriding the current time" is a bad one. The notion of "defaulting to the current time" might be okay, in some systems, until it isn't.
Time-based OTPs are using timestamps. That's what they do. Defaulting to the current time is *precisely* how most 2FA systems work. Being able to override the time is useful primarily for testing. So for the TOTP case, I would say that "timestamp=>time.time()" is the perfect way to spell it.
If time-based OTPs use timestamps, then why is there a timestamp parameter at all? "Current time" is part of the function, not part of the API. Testing functions like that is another problem; adding parameters to the API does not solve it. IMO, a better solution is a test harness that can provide a known "current time" value. [...]
I don't know why you'd have something in a logger that lets you configure the time, but my guess would be that it's the same thing: you can unit-test the logger with consistent inputs. For instance:
def format_log_line(event, time=>current_time(), host=>get_host()): return ...
It's not a question of configuring *the* time, it's a question of recognizing that there's more than one time: the time the event occurred is different from the time the event is logged. Yes, in many cases in many systems, it's a difference without a distinction. In other systems, timestamps added by loggers are wholly irrelevant. Out of curiosity, why did you make host a late-binding parameter?
# shorthand, obv you'd be using a proper testing framework assert format_log_line({...}, time=1638717131, host="example") == "..."
TBH, I think that defaulting to "event happened right now" is about as good a default as you'll ever get. In some situations you'll know when the event happened... but honestly, I'd rather know when the log line happened too. So if I have an event with an inbuilt timestamp, I'll incorporate that into the *body* of the log line, and still have the logger add its own timestamp.
But maybe I've spent too much time rummaging through logs from buggy systems.
In time-critical code, I'm not going to waste resources (time, memory, CPU cycles) formatting a log entry. The event occurred and has a timestamp; formatting and logging will happen in a whole different context (another thread? another CPU? another OS? the O&M system at the time the user asks to look at the logs?). I'm not denying that there are times you want both timestamps; I'm denying that you can always conflate them without losing important information. I'm sticking to my story, which is no doubt a product of the sorts of systems I've built (and debugged, and not built): the apparent use case of "defaulting to a value that changes, like the current time or a function-generated ID" is conflating the logic of the function with that function's API.