feat: add a message journal #116
Conversation
DuckBoss
force-pushed
the
jajerome/message-journal
branch
2 times, most recently
from
d4398a1 to
cb26a4d
Compare
DuckBoss
force-pushed
the
jajerome/message-journal
branch
2 times, most recently
from
31eb3da to
82a9b6d
Compare
There was a problem hiding this comment.
Overall, this is a great start. I'm focusing a lot of my review on the D-Bus method definition for now, since that's where the real API boundary exists. I do have some reservations about using an in-memory slice to store all the messages; that could grow significantly over the course of a long-running process like yggd, so we might need to reconsider the implementation of the journal.
cmd/yggctl/main.go
Outdated
| &cli.StringFlag{ | ||
| Name: "truncate-message", | ||
| Aliases: []string{"t"}, | ||
| Usage: "Truncates worker event messages if they exceed the specified character count (10 by default).", |
There was a problem hiding this comment.
A default value can automatically be included in the help output by using the Value field of a Flag. That sets the default value returned by c.String("truncate-message") as well, so you don't need to check the flag value later.
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
82a9b6d to
97fd6e2
Compare
DuckBoss
force-pushed
the
jajerome/message-journal
branch
2 times, most recently
from
da86f9d to
240abe7
Compare
Summary of changes made since last review:
Changes based on feedback:[subpop feedback]
[jirihnidek feedback]
Other:
|
DuckBoss
force-pushed
the
jajerome/message-journal
branch
2 times, most recently
from
6269089 to
8c916ea
Compare
internal/work/dispatcher.go
Outdated
| continue | ||
| } | ||
| event.Message = eventMessage | ||
| workerMessageID = eventId | ||
| case ipc.WorkerEventNameBegin: | ||
| eventID, ok := s.Body[1].(string) |
There was a problem hiding this comment.
This is not correct. You are trying to access s.Body[1] without checking the length of s.Body first. You can shoot down yggd, when you sent following command over MQTT:
go run ./cmd/yggctl generate data-message --directive echo "hello" | pub -broker tcp://localhost:1883 -topic yggdrasil/$(hostname)/data/inWhen I run testing echo worker, then I'm getting following "traceback" on terminal with yggd:
[jhnidek@thinkpad-p1 yggdrasil]$ go run ./cmd/yggd --server tcp://localhost:1883 --log-level trace --client-id $(hostname)
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/cmd/yggd/main.go:192: starting yggd version
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:68: connecting to session bus for worker IPC: unix:path=/run/user/1000/bus
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:95: exported /com/redhat/Yggdrasil1/Dispatcher1 on bus
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/cmd/yggd/client.go:150: connecting to session bus: unix:path=/run/user/1000/bus
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/cmd/yggd/client.go:175: exported /com/redhat/Yggdrasil1 on bus
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:51: connected to broker: tcp://localhost:1883
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/cmd/yggd/main.go:267: no TLSconfig, disabling TLS watcher update.
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:73: subscribed to topic: yggdrasil/thinkpad-p1/data/in
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:86: subscribed to topic: yggdrasil/thinkpad-p1/control/in
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:174: published message to topic yggdrasil/thinkpad-p1/control/out
[yggd] 2023/05/29 09:47:00 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:175: message: {"type":"connection-status","message_id":"6a5cc967-6b61-497a-8a66-9e95eaf32147","response_to":"","version":1,"sent":"2023-05-29T09:47:00.442261841+02:00","content":{"canonical_facts":null,"dispatchers":{},"state":"online"}}
[yggd] 2023/05/29 09:47:05 /home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:244: send message ddd96e7e-daaa-4cf6-8e36-852bacd0fc84 to worker echo
[yggd] 2023/05/29 09:47:05 /home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:113: received signal: &dbus.Signal{Sender:":1.433", Path:"/com/redhat/Yggdrasil1/Worker1/echo", Name:"com.redhat.Yggdrasil1.Worker1.Event", Body:[]interface {}{0x1}, Sequence:0x8}
[yggd] 2023/05/29 09:47:05 /home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:271: cannot add journal entry: message journal not enabled
[yggd] 2023/05/29 09:47:05 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:174: published message to topic yggdrasil/thinkpad-p1/control/out
[yggd] 2023/05/29 09:47:05 /home/jhnidek/github/redhat-insights/yggdrasil/internal/transport/mqtt.go:175: message: {"type":"connection-status","message_id":"0f0cdcbf-2fa1-4e6d-9116-411dac290912","response_to":"","version":1,"sent":"2023-05-29T09:47:05.940491216+02:00","content":{"canonical_facts":null,"dispatchers":{"echo":{"DispatchedAt":"","Version":"1"}},"state":"online"}}
panic: runtime error: index out of range [1] with length 1
goroutine 53 [running]:
github.com/redhatinsights/yggdrasil/internal/work.(*Dispatcher).Connect.func1()
/home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:157 +0xaa5
created by github.com/redhatinsights/yggdrasil/internal/work.(*Dispatcher).Connect
/home/jhnidek/github/redhat-insights/yggdrasil/internal/work/dispatcher.go:111 +0x64a
exit status 2
There was a problem hiding this comment.
This is correct; the "message" field of an Event is nullable. It's not clearly
annotated as such in the Interface specification, but perhaps it should be.
Event:
@name: Name of the event.
@message: Optional message included with the event.
f850a14 to
5208d8b
Compare
I think my reasoning was to maintain simplicity down the line if EDIT: After further experimentation, I decided to just merge the runtime/persistent tables into a single table. It didn't make much sense to turn off persistent journal entries specifically when the message journal is enabled especially since yggdrasil doesn't have any logic to clear tables on exit -- only on start up. |
DuckBoss
force-pushed
the
jajerome/message-journal
branch
5 times, most recently
from
020e642 to
78c3b88
Compare
dbus/com.redhat.Yggdrasil1.xml
Outdated
| <arg type="s" name="message_id" direction="in" /> | ||
| <arg type="s" name="worker" direction="in" /> | ||
| <arg type="s" name="from" direction="in" /> | ||
| <arg type="s" name="to" direction="in" /> |
There was a problem hiding this comment.
"from-time" "to-time" ?
There was a problem hiding this comment.
Yes, 'from' and 'to' should be clarified. I like from-time and to-time. Another option is the English words "since" and "until". Those have a similar "from time" and "to time" association, respectively.
There was a problem hiding this comment.
I think I would prefer since/until too.. it's less jarring to read in the --help output.
| "worker_event": ipc.WorkerEventName(workerEvent).String(), | ||
| "worker_message": workerEventMessage, | ||
| } | ||
| entries = append(entries, newMessage) |
There was a problem hiding this comment.
It could be very slow, when there will be thousands of entries. Have you tested this case?
There was a problem hiding this comment.
Yes it could slow down with thousands of entries, but I was hoping the addition of filters would prevent a case where thousands of events would have to be retrieved at a single time (specifically the message-id or to/sent filters).
I'm not sure, is there an alternative way to handle this that you think would work well? 🤔
There was a problem hiding this comment.
I was thinking about this. I wonder if there's a way to defer some of the
aggregation of this function further up the call stack. Maybe instead of
appending each entry to a slice within GetEntries and returning it at the end,
GetEntries could accept a callback function that gets called on each entry as
its read from the database. That passes the responsibility of aggregating the
results (or not) to the caller. I don't know what advantage that really brings
though, since eventually, this map gets serialized into a D-Bus message and
passed back across the D-Bus broker.
| @@ -0,0 +1 @@ | |||
| DROP TABLE IF EXISTS journal; | |||
There was a problem hiding this comment.
There is no empty line at the end of the file. Is it expected?
There was a problem hiding this comment.
I haven't seen any functional difference and my editor hasn't complained about it. I can't find any styling guidelines around this case either...maybe just leave it as it is and not add anything extra to migration scripts 🤷
| @@ -0,0 +1,9 @@ | |||
| CREATE TABLE IF NOT EXISTS journal ( | |||
| id INTEGER NOT NULL PRIMARY KEY, | |||
| message_id VARCHAR(36) NOT NULL, | |||
There was a problem hiding this comment.
SQLite has a more simple than SQL standard type system:
https://sqlite.org/datatype3.html. It all basically resolves to five types:
TEXT, NUMERIC, INTEGER, REAL, BLOB. You can probably simplify this CREATE
statement to using the SQLite type affinities instead.
CREATE TABLE IF NOT EXISTS journal (
id INTEGER NOT NULL PRIMARY KEY,
message_id TEXT NOT NULL,
sent INTEGER NOT NULL,
worker_name TEXT NOT NULL,
response_to TEXT,
worker_event INTEGER,
worker_message TEXT,
);|
|
||
| const messageJournalTableName string = "journal" | ||
|
|
||
| //go:embed migrations/*.sql |
| // New initializes a message journal sqlite database consisting | ||
| // of a runtime table that gets cleared on every session start | ||
| // and a persistent table that maintains journal entries across sessions. |
There was a problem hiding this comment.
This comment is no longer accurate, given the change in design.
| return nil | ||
| } | ||
|
|
||
| // AddEntry adds a new message journal entry to both the temporary runtime table |
There was a problem hiding this comment.
This comment is no longer accurate, given the design changes.
cmd/yggctl/main.go
Outdated
| &cli.StringFlag{ | ||
| Name: "from", | ||
| Aliases: []string{}, | ||
| Usage: "Only display worker messages and emitted events sent starting from the timestamp provided.", |
There was a problem hiding this comment.
The cli package does have a TimestampFlag. That might help enforce the
proper data type for this flag.
cmd/yggctl/main.go
Outdated
| &cli.BoolFlag{ | ||
| Name: "persistent", | ||
| Aliases: []string{"p"}, | ||
| Usage: "Display worker messages and emitted events gathered across multiple sessions from persistent storage.", |
There was a problem hiding this comment.
Nit-pick: Usage strings don't end with periods. They don't need to be complete
sentences. They can be short, descriptive fragments.
cmd/yggctl/main.go
Outdated
| Name: "message-journal", | ||
| Usage: "Display a list of all worker messages and emitted events", | ||
| UsageText: "yggctl message-journal", | ||
| Description: "The message-journal command sends a dbus call to yggdrasil to retrieve a message journal containing all worker messages and emitted events.", |
There was a problem hiding this comment.
D-Bus is an irrelevant implementation detail from the user's perspective. Since
these strings are meant to be user-facing, this description should tell the user
what the operation will/should do, not necessarily how it accomplishes that
operation.
| Description: "The message-journal command sends a dbus call to yggdrasil to retrieve a message journal containing all worker messages and emitted events.", | |
| Description: "The message-journal command retrieves a message list containing all worker messages and emitted events.", |
cmd/yggctl/main.go
Outdated
| &cli.UintFlag{ | ||
| Name: "truncate-message", | ||
| Aliases: []string{"t"}, | ||
| Usage: "Truncates worker event messages if they exceed the specified character count.", |
There was a problem hiding this comment.
Try to use the BACKTICK notation in Usage text if possible. It helps to
clarify the data types expected in the flag.
cmd/yggctl/actions.go
Outdated
| if len(journalEntries) == 0 { | ||
| fmt.Println("No journal entries found.") | ||
| return nil | ||
| } |
There was a problem hiding this comment.
Hm. I think there is value to printing a message if no records are retrieved. If
we don't, we'd either print a single line with the table headers or we'd print
nothing at all. In either case, the user would be left wondering if the command
worked correctly. Reporting an error to the user in the case of zero records
avoids that case.
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
e21aa18 to
176be8c
Compare
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
176be8c to
95b9d67
Compare
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
95b9d67 to
2fb6938
Compare
Summary of Changes... there's a bunch..Changes since optional data handling rework:
Changes since last review (before optional data handling rework):The changes made here have all been squashed into [0efddca] and were made before the implementation Based on older feedback [commits squashed to 0efddca]:
Other changes [commits squashed to 0efddca]: |
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
1791ed7 to
90f2fb3
Compare
subpop
force-pushed
the
jajerome/message-journal
branch
from
90f2fb3 to
f617b60
Compare
There was a problem hiding this comment.
A few small changes here and there; mostly around string content. But great work! I tested the functionality and it works out. I'm going to try and stress test it with some looping message transmission, but I figured I'd get this review back to you to clear up the little bits here and there.
| @@ -88,4 +88,4 @@ | |||
| <arg name="out" direction="out" type="s" /> | |||
| </method> | |||
| </interface> | |||
| </node> | |||
| </node> | |||
There was a problem hiding this comment.
There's an editor conflict going on. This file's trailing newline got removed.
This change is superfluous and shouldn't be committed.
There was a problem hiding this comment.
This change hasn't been dropped from the PR yet.
dbus/com.redhat.Yggdrasil1.xml
Outdated
| <arg type="s" name="worker" direction="in" /> | ||
| <arg type="s" name="since" direction="in" /> | ||
| <arg type="s" name="until" direction="in" /> | ||
| <arg type="s" name="persistent" direction="in" /> |
There was a problem hiding this comment.
persistent is a bool type, not a string type.
| <arg type="s" name="persistent" direction="in" /> | |
| <arg type="b" name="persistent" direction="in" /> |
| } | ||
|
|
||
| type errorJournal struct { | ||
| err interface{} |
There was a problem hiding this comment.
Interesting design choice. Why is err an interface{} type instead of an
error type?
There was a problem hiding this comment.
Being unfamiliar with this, I think I looked to how errors were tested in other parts of the code and used this as a basis:
yggdrasil/internal/tags/tags.go
Lines 15 to 25 in 5130298
But you're right, using an error type and then checking for errors in tests like -
wantError: &errorJournal{fmt.Errorf("my error message")} would also work.
| values (?,?,?,?,?,?)` | ||
|
|
||
| insertAction, err := j.database.Prepare( | ||
| fmt.Sprintf(insertEntryTemplate, messageJournalTableName), |
There was a problem hiding this comment.
Why is the table name a static string and printed into the SQL template? This
could be simplified, couldn't it? Is this left over from the previous design
where there were two tables?
There was a problem hiding this comment.
Ah good point, this was left over from the previous design.
| // buildDynamicGetEntriesQuery is a utility method that builds the dynamic sql query | ||
| // required to filter journal entry messages from the message journal database | ||
| // when they are retrieved in the 'GetEntries' method. | ||
| func (j *MessageJournal) buildDynamicGetEntriesQuery(filter Filter) (string, error) { |
There was a problem hiding this comment.
This is the kind of function that I would like to see coupled with some unit
tests. It's currently declared as a method on MessageJournal, but only because
it uses the initializedAt member field. Adding initializedAt as a function
parameter means you can drop the method to a standalone function. This would
make it more straight forward to write a series of tests, as it becomes a basic
input/output transformation function.
| func (j *MessageJournal) buildDynamicGetEntriesQuery(filter Filter) (string, error) { | |
| func buildDynamicGetEntriesQuery(filter Filter, initializedAt time.Time) (string, error) { |
cmd/yggctl/main.go
Outdated
| &cli.StringFlag{ | ||
| Name: "worker", | ||
| Aliases: []string{"w"}, | ||
| Usage: "Only display worker messages and emitted events for the specified worker `NAME`", |
There was a problem hiding this comment.
| Usage: "Only display worker messages and emitted events for the specified worker `NAME`", | |
| Usage: "Include only events emitted by `WORKER`", |
cmd/yggctl/main.go
Outdated
| &cli.StringFlag{ | ||
| Name: "message-id", | ||
| Aliases: []string{"m"}, | ||
| Usage: "Only display worker messages and emitted events for the entries with the specified message id `STRING`", |
There was a problem hiding this comment.
| Usage: "Only display worker messages and emitted events for the entries with the specified message id `STRING`", | |
| Usage: "Include only events emitted for message ID `STRING`", |
cmd/yggctl/main.go
Outdated
| &cli.StringFlag{ | ||
| Name: "since", | ||
| Aliases: []string{"s"}, | ||
| Usage: "Only display worker messages and emitted events sent starting from the provided `TIMESTAMP` (YYYY-MM-DD HH:MM:SS)", |
There was a problem hiding this comment.
| Usage: "Only display worker messages and emitted events sent starting from the provided `TIMESTAMP` (YYYY-MM-DD HH:MM:SS)", | |
| Usage: "Include only events emitted after `TIMESTAMP` (YYYY-MM-DD HH:MM:SS)", |
cmd/yggctl/main.go
Outdated
| &cli.StringFlag{ | ||
| Name: "until", | ||
| Aliases: []string{"u"}, | ||
| Usage: "Only display worker messages and emitted events sent up to the provided `TIMESTAMP` (YYYY-MM-DD HH:MM:SS)", |
There was a problem hiding this comment.
| Usage: "Only display worker messages and emitted events sent up to the provided `TIMESTAMP` (YYYY-MM-DD HH:MM:SS)", | |
| Usage: "Include only events emitted before `TIMESTAMP` (YYYY-MM-DD HH:MM:SS)", |
cmd/yggctl/main.go
Outdated
| Aliases: []string{"f"}, | ||
| Usage: "Print output in `FORMAT` (json, table or text)", | ||
| Value: "table", | ||
| DefaultText: "table", |
There was a problem hiding this comment.
Is DefaultText required with Value too? What does DefaultText do?
There was a problem hiding this comment.
The DefaultText is not strictly required, but it specifies what is selected by default in the --help output:
--format FORMAT, -f FORMAT Print output in Format (json, table or text) (default: table)
Although it's generally used for when a default value for a flag is computed, I think this is still a good idea to add to any flags that have non-computed default values in yggctl.
Doc reference: https://cli.urfave.org/v2/examples/flags/#default-values-for-help-output
There was a problem hiding this comment.
Oh, interesting. What happens if DefaultText is omitted, but Value is set to a string like "table". Doesn't it use that value as the default in the help text? I interpreted DefaultText as being an option to override the default value's string formatted value in cases like the example when the default is randomized.
There was a problem hiding this comment.
Ah I see.. I checked this again and it looks like that's the case. It looks like it's fine to remove DefaultText then.
There was a problem hiding this comment.
A few small changes here and there; mostly around string content. But great work! I tested the functionality and it works out. I'm going to try and stress test it with some looping message transmission, but I figured I'd get this review back to you to clear up the little bits here and there.
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
84d59dc to
e47d50e
Compare
Changes since last review [10/11/2023]yggctl:
yggd journal:
|
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
e47d50e to
58cc14a
Compare
cmd/yggd/main.go
Outdated
| func setupMessageJournal(client *Client) error { | ||
| messageJournalPath := config.DefaultConfig.MessageJournal | ||
| if messageJournalPath != "" { | ||
| journalFilePath := filepath.Join(messageJournalPath) |
There was a problem hiding this comment.
What is the intention of this statement? Calling filepath.Join with one
element seems superfluous. If you want to clean the file path, I concur, but
filepath.Clean might be more appropriate in that case.
There was a problem hiding this comment.
Honestly, not sure why the filepath.Join is still there. It must be another remnant from the previous two-database design. Thanks for catching that.
| @@ -88,4 +88,4 @@ | |||
| <arg name="out" direction="out" type="s" /> | |||
| </method> | |||
| </interface> | |||
| </node> | |||
| </node> | |||
There was a problem hiding this comment.
This change hasn't been dropped from the PR yet.
|
I hate to ask, but when was the last time you rebased this onto |
|
OK. I looped messages at it and it did great. I'm all good with this after it gets a rebase onto |
I rebased it somewhat recently (I think it's been 3 weeks?) so it should be mostly caught up. I'll rebase it again after I make the final adjustments. |
DuckBoss
force-pushed
the
jajerome/message-journal
branch
3 times, most recently
from
edbe6f0 to
05e0093
Compare
|
@jirihnidek are your changes addressed? The PR is waiting on your approval, since you made a change request in a previous review. |
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
05e0093 to
17f20cb
Compare
This feature adds a message journal that tracks dispatched messages and worker events. This will be useful for diagnostic purposes. The message journal can be filtered by the message id or the worker name and worker messages can be truncated by a user specified length. Signed-off-by: Jason Jerome <jajerome@redhat.com>
DuckBoss
force-pushed
the
jajerome/message-journal
branch
from
17f20cb to
5b88bbf
Compare
This feature adds a message journal that tracks dispatched messages and worker events.
The
yggctlcommand added to enable the retrieval of the message journal can also be filteredby the message id or the worker name, and optional data can be truncated by a user specified length.
Note: Do not merge this before the following blocking PRs:
Features:
yggctlcomand:message-journal$ yggctl message-journal <opts>--message-id <my_message_id>: Only displays journal entries that have the specified message id.--worker <my_worker>: Only displays journal entries that have the specified worker.--since <utc timestamp>: Only displays journal entries of events created after the specified timestamp.--until <utc timestamp>: Only displays journal entries of events created up until the specified timestamp.--persistent: Displays journal entries from the current and all previous yggdrasil sessions. By default, the message journal only shows entries from the active session.Example Usage:
Input:
yggctl message-journalOutput: