feat(machine-logs): add server side of journal logs (#282)

* Add server side of journal logs

This add the server side and grpc methods to get a journal logs from a
machine. It repurposes ServiceLogEntry for these logs to keep the
changes somewhat to a minimum. And it lets us re-use the merging of the
various logs. In the protobufs ContainerLog has been renamed to just Log
and LogEntry, as these are now also used for journal logs.

It does api.LogOptions in more places to reduce the various logOpts that
were used.

It does not yet plumb it through to the uc client, that needs a follow
up pr. Following logs is also not yet implemented.

Signed-off-by: Miek Gieben <miek@miek.nl>

* Fix test too

Signed-off-by: Miek Gieben <miek@miek.nl>

* remove entire comment

Signed-off-by: Miek Gieben <miek@miek.nl>

* Implement the follow option, untested mind you

Signed-off-by: Miek Gieben <miek@miek.nl>

* update debug line

Signed-off-by: Miek Gieben <miek@miek.nl>

* internal/jounal: First batch of PR comments

Signed-off-by: Miek Gieben <miek@miek.nl>

* internal/journal: code review comments

Signed-off-by: Miek Gieben <miek@miek.nl>

* Manually apply suggestion

Signed-off-by: Miek Gieben <miek@miek.nl>

* apply comment manually

Signed-off-by: Miek Gieben <miek@miek.nl>

* internal/journal: add unit test

Signed-off-by: Miek Gieben <miek@miek.nl>

* Use testify

Signed-off-by: Miek Gieben <miek@miek.nl>

* -amFix scanner.Err checking

Signed-off-by: Miek Gieben <miek@miek.nl>

* Implement code review comments

Signed-off-by: Miek Gieben <miek@miek.nl>

---------

Signed-off-by: Miek Gieben <miek@miek.nl>
This commit is contained in:
Miek Gieben
2026-04-08 18:51:52 +10:00
committed by GitHub
parent 4b34c42b76
commit cef047221c
19 changed files with 1204 additions and 862 deletions
+94
View File
@@ -14,12 +14,15 @@ import (
"slices"
"strconv"
"sync"
"time"
"github.com/containerd/errdefs"
"github.com/docker/docker/client"
"github.com/docker/go-connections/sockets"
"github.com/psviderski/uncloud/internal/corrosion"
"github.com/psviderski/uncloud/internal/docker"
"github.com/psviderski/uncloud/internal/fs"
"github.com/psviderski/uncloud/internal/journal"
"github.com/psviderski/uncloud/internal/machine/api/pb"
apiproxy "github.com/psviderski/uncloud/internal/machine/api/proxy"
"github.com/psviderski/uncloud/internal/machine/caddyconfig"
@@ -30,6 +33,7 @@ import (
machinedocker "github.com/psviderski/uncloud/internal/machine/docker"
"github.com/psviderski/uncloud/internal/machine/network"
"github.com/psviderski/uncloud/internal/machine/store"
"github.com/psviderski/uncloud/pkg/api"
"github.com/psviderski/unregistry"
"github.com/siderolabs/grpc-proxy/proxy"
"golang.org/x/sync/errgroup"
@@ -1073,3 +1077,93 @@ func (m *Machine) InspectService(
}
return &pb.InspectServiceResponse{Service: svc}, nil
}
// logsHeartbeatInterval is the interval at which heartbeat entries are sent when there are no logs to stream.
const logsHeartbeatInterval = 200 * time.Millisecond
// MachineLogs streams logs from a systemd service.
func (s *Machine) MachineLogs(
req *pb.LogsRequest, stream grpc.ServerStreamingServer[pb.LogEntry],
) error {
// TODO(miek): almost duplicate of docker/server.ContainerLogs
ctx := stream.Context()
opts := api.ServiceLogsOptions{
Follow: req.Follow,
Tail: int(req.Tail),
Since: req.Since,
Until: req.Until,
}
logsCh, err := journal.Logs(ctx, req.Id, opts)
if err != nil {
if errdefs.IsNotFound(err) {
return status.Error(codes.NotFound, err.Error())
}
return status.Errorf(codes.Internal, "get journal logs: %v", err)
}
log := slog.With("unit", req.Id, "stream_id", fmt.Sprintf("%p", stream)[2:])
log.Debug("Starting systemd service logs streaming.",
"follow", req.Follow, "tail", req.Tail, "since", req.Since, "until", req.Until)
// Heartbeats are needed only when following logs to let the client know when there are no new log entries
// to allow it to advance the watermark of last received log timestamp.
var heartbeatCh <-chan time.Time
if req.Follow {
heartbeatTicker := time.NewTicker(logsHeartbeatInterval)
defer heartbeatTicker.Stop()
heartbeatCh = heartbeatTicker.C
}
started := time.Now()
lastSent := time.Time{}
for {
select {
case entry, ok := <-logsCh:
if !ok {
// Channel closed, no more log entries.
return nil
}
if entry.Err != nil {
return status.Error(codes.Internal, entry.Err.Error())
}
pbEntry := &pb.LogEntry{
Stream: api.LogStreamTypeToProto(entry.Stream),
Timestamp: timestamppb.New(entry.Timestamp),
Message: entry.Message,
}
if err = stream.Send(pbEntry); err != nil {
return status.Errorf(codes.Internal, "send log entry: %v", err)
}
lastSent = entry.Timestamp
case now := <-heartbeatCh:
// Only send heartbeat if no log entries have been sent since the last heartbeat interval or
// if no log entries have been sent at all for at least a heartbeat interval since starting.
if now.Sub(lastSent) < logsHeartbeatInterval ||
(lastSent.IsZero() && now.Sub(started) < logsHeartbeatInterval) {
continue
}
// Use the timestamp one heartbeat in the past to be conservative. This reduces the chance of sending
// a timestamp that is greater than a log entry currently being parsed but not yet sent, which would
// cause the client to incorrectly believe it has received all logs up to that point.
heartbeat := &pb.LogEntry{
Stream: pb.LogEntry_HEARTBEAT,
Timestamp: timestamppb.New(now.Add(-logsHeartbeatInterval)),
}
if err = stream.Send(heartbeat); err != nil {
return status.Errorf(codes.Internal, "send log stream heartbeat: %v", err)
}
lastSent = heartbeat.Timestamp.AsTime()
log.Debug("Sent log stream heartbeat.", "timestamp", lastSent)
case <-ctx.Done():
return status.Error(codes.Canceled, ctx.Err().Error())
}
}
}