alt-orchestra/talos
1
0
Fork 0
Code Issues Pull Requests Actions 27 Packages Projects Releases Wiki Activity

fix: proper logging in machined on startup

Browse Source 
Move `setupLogging` inside the controller, so that logger is set up
correctly before Talos starts printing first messages.

This fixes an inconsistency that first messages are printed using
"default" logger, while after that the proper logger is set up, and
format of the messages matches kernel log.

Also move `waitForUSBDelay` into the sequencer after `udevd` was
started (this is when blockdevices including USB ones are discovered).

Signed-off-by: Andrey Smirnov <andrey.smirnov@siderolabs.com>
This commit is contained in:
Andrey Smirnov 2023-11-07 16:33:18 +04:00
parent a54da5f641
commit 87c40da6cc
No known key found for this signature in database
GPG Key ID: FE042E3D4085A811
3 changed files with 73 additions and 83 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

91
internal/app/machined/pkg/runtime/v1alpha1/v1alpha1_controller.go
View File

@ -8,22 +8,24 @@ import (
"context"
"errors"
"fmt"
"io"
"log"
"os"
"os/signal"
"strconv"
"strings"
"syscall"
"time"
"github.com/siderolabs/go-kmsg"
"golang.org/x/sync/errgroup"
"github.com/siderolabs/talos/internal/app/machined/pkg/runtime"
"github.com/siderolabs/talos/internal/app/machined/pkg/runtime/logging"
"github.com/siderolabs/talos/internal/app/machined/pkg/runtime/v1alpha1/acpi"
"github.com/siderolabs/talos/internal/app/machined/pkg/runtime/v1alpha2"
krnl "github.com/siderolabs/talos/pkg/kernel"
"github.com/siderolabs/talos/pkg/machinery/api/common"
"github.com/siderolabs/talos/pkg/machinery/api/machine"
"github.com/siderolabs/talos/pkg/machinery/kernel"
)
// Controller represents the controller responsible for managing the execution
@ -38,14 +40,6 @@ type Controller struct {
// NewController intializes and returns a controller.
func NewController() (*Controller, error) {
// Wait for USB storage in the case that the install disk is supplied over
// USB. If we don't wait, there is the chance that we will fail to detect the
// install disk.
err := waitForUSBDelay()
if err != nil {
return nil, err
}
s, err := NewState()
if err != nil {
return nil, err
@ -67,9 +61,47 @@ func NewController() (*Controller, error) {
return nil, err
}
if err := ctlr.setupLogging(); err != nil {
return nil, err
}
return ctlr, nil
}
func (c *Controller) setupLogging() error {
machinedLog, err := c.r.Logging().ServiceLog("machined").Writer()
if err != nil {
return err
}
if c.r.State().Platform().Mode() == runtime.ModeContainer {
// send all the logs to machinedLog as well, but skip /dev/kmsg logging
log.SetOutput(io.MultiWriter(log.Writer(), machinedLog))
log.SetPrefix("[talos] ")
return nil
}
// disable ratelimiting for kmsg, otherwise logs might be not visible.
// this should be set via kernel arg, but in case it's not set, try to force it.
if err = krnl.WriteParam(&kernel.Param{
Key: "proc.sys.kernel.printk_devkmsg",
Value: "on\n",
}); err != nil {
var serr syscall.Errno
if !(errors.As(err, &serr) && serr == syscall.EINVAL) { // ignore EINVAL which is returned when kernel arg is set
log.Printf("failed setting kernel.printk_devkmsg: %s, error ignored", err)
}
}
if err = kmsg.SetupLogger(nil, "[talos]", machinedLog); err != nil {
return fmt.Errorf("failed to setup logging: %w", err)
}
return nil
}
// Run executes all phases known to the controller in serial. `Controller`
// aborts immediately if any phase fails.
func (c *Controller) Run(ctx context.Context, seq runtime.Sequence, data interface{}, setters ...runtime.LockOption) error {
@ -385,42 +417,3 @@ func (c *Controller) phases(seq runtime.Sequence, data interface{}) ([]runtime.P
return phases, nil
}
func waitForUSBDelay() (err error) {
wait := true
file := "/sys/module/usb_storage/parameters/delay_use"
_, err = os.Stat(file)
if err != nil {
if os.IsNotExist(err) {
wait = false
} else {
return err
}
}
if wait {
var b []byte
b, err = os.ReadFile(file)
if err != nil {
return err
}
val := strings.TrimSuffix(string(b), "\n")
var i int
i, err = strconv.Atoi(val)
if err != nil {
return err
}
log.Printf("waiting %d second(s) for USB storage", i)
time.Sleep(time.Duration(i) * time.Second)
}
return nil
}

9
internal/app/machined/pkg/runtime/v1alpha1/v1alpha1_sequencer.go
View File

@ -70,9 +70,6 @@ func (*Sequencer) Initialize(r runtime.Runtime) []runtime.Phase {
switch r.State().Platform().Mode() { //nolint:exhaustive
case runtime.ModeContainer:
phases = phases.Append(
"logger",
SetupLogger,
).Append(
"systemRequirements",
SetupSystemDirectory,
).Append(
@ -89,9 +86,6 @@ func (*Sequencer) Initialize(r runtime.Runtime) []runtime.Phase {
)
default:
phases = phases.Append(
"logger",
SetupLogger,
).Append(
"systemRequirements",
EnforceKSPPRequirements,
SetupSystemDirectory,
@ -111,6 +105,9 @@ func (*Sequencer) Initialize(r runtime.Runtime) []runtime.Phase {
"earlyServices",
StartUdevd,
StartMachined,
).Append(
"usb",
WaitForUSB,
).Append(
"meta",
ReloadMeta,

56
internal/app/machined/pkg/runtime/v1alpha1/v1alpha1_sequencer_tasks.go
View File

@ -16,6 +16,7 @@ import (
"os"
"path/filepath"
"slices"
"strconv"
"strings"
"syscall"
"time"
@ -35,7 +36,6 @@ import (
"github.com/siderolabs/go-blockdevice/blockdevice/util"
"github.com/siderolabs/go-cmd/pkg/cmd"
"github.com/siderolabs/go-cmd/pkg/cmd/proc"
"github.com/siderolabs/go-kmsg"
"github.com/siderolabs/go-pointer"
"github.com/siderolabs/go-procfs/procfs"
"github.com/siderolabs/go-retry/retry"
@ -63,7 +63,6 @@ import (
"github.com/siderolabs/talos/internal/pkg/secureboot/tpm2"
"github.com/siderolabs/talos/pkg/conditions"
"github.com/siderolabs/talos/pkg/images"
krnl "github.com/siderolabs/talos/pkg/kernel"
"github.com/siderolabs/talos/pkg/kernel/kspp"
"github.com/siderolabs/talos/pkg/kubernetes"
machineapi "github.com/siderolabs/talos/pkg/machinery/api/machine"
@ -71,7 +70,6 @@ import (
"github.com/siderolabs/talos/pkg/machinery/config/machine"
"github.com/siderolabs/talos/pkg/machinery/config/types/v1alpha1"
"github.com/siderolabs/talos/pkg/machinery/constants"
"github.com/siderolabs/talos/pkg/machinery/kernel"
metamachinery "github.com/siderolabs/talos/pkg/machinery/meta"
resourcefiles "github.com/siderolabs/talos/pkg/machinery/resources/files"
"github.com/siderolabs/talos/pkg/machinery/resources/k8s"
@ -81,41 +79,43 @@ import (
"github.com/siderolabs/talos/pkg/version"
)
// SetupLogger represents the SetupLogger task.
func SetupLogger(runtime.Sequence, any) (runtime.TaskExecutionFunc, string) {
return func(ctx context.Context, logger *log.Logger, r runtime.Runtime) (err error) {
machinedLog, err := r.Logging().ServiceLog("machined").Writer()
// WaitForUSB represents the WaitForUSB task.
func WaitForUSB(runtime.Sequence, any) (runtime.TaskExecutionFunc, string) {
return func(ctx context.Context, logger *log.Logger, r runtime.Runtime) error {
// Wait for USB storage in the case that the install disk is supplied over
// USB. If we don't wait, there is the chance that we will fail to detect the
// install disk.
file := "/sys/module/usb_storage/parameters/delay_use"
_, err := os.Stat(file)
if err != nil {
if os.IsNotExist(err) {
return nil
}
return err
}
b, err := os.ReadFile(file)
if err != nil {
return err
}
if r.State().Platform().Mode() == runtime.ModeContainer {
// send all the logs to machinedLog as well, but skip /dev/kmsg logging
log.SetOutput(io.MultiWriter(log.Writer(), machinedLog))
log.SetPrefix("[talos] ")
val := strings.TrimSuffix(string(b), "\n")
return nil
var i int
i, err = strconv.Atoi(val)
if err != nil {
return err
}
// disable ratelimiting for kmsg, otherwise logs might be not visible.
// this should be set via kernel arg, but in case it's not set, try to force it.
if err = krnl.WriteParam(&kernel.Param{
Key: "proc.sys.kernel.printk_devkmsg",
Value: "on\n",
}); err != nil {
var serr syscall.Errno
logger.Printf("waiting %d second(s) for USB storage", i)
if !(errors.As(err, &serr) && serr == syscall.EINVAL) { // ignore EINVAL which is returned when kernel arg is set
log.Printf("failed setting kernel.printk_devkmsg: %s, error ignored", err)
}
}
if err = kmsg.SetupLogger(nil, "[talos]", machinedLog); err != nil {
return fmt.Errorf("failed to setup logging: %w", err)
}
time.Sleep(time.Duration(i) * time.Second)
return nil
}, "setupLogger"
}, "waitForUSB"
}
// EnforceKSPPRequirements represents the EnforceKSPPRequirements task.