Skip to content

Commit

Permalink
cmd: log less on info level
Browse files Browse the repository at this point in the history
Currently, virter logs the same 8 (ish) lines every time a VM is
started, and another few when it is removed.

This is redundant information in almost all cases, so it really belongs
in the Debug level.
  • Loading branch information
chrboe committed Dec 20, 2023
1 parent a0bf17c commit 697988e
Show file tree
Hide file tree
Showing 3 changed files with 18 additions and 18 deletions.
2 changes: 1 addition & 1 deletion cmd/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,7 @@ func initConfig() {
if newPath == "" {
newPath = filepath.Join(configPath(), "virter.toml")
}
log.Print("Config file does not exist, creating default: ", newPath)
log.Info("Config file does not exist, creating default: ", newPath)

err := writeDefaultConfig(newPath)
if err != nil {
Expand Down
4 changes: 2 additions & 2 deletions internal/virter/dhcp.go
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ func (v *Virter) AddDHCPHost(mac string, id uint) error {
return fmt.Errorf("failed to compute IP for network: %w", err)
}

log.Printf("Add DHCP entry from %v to %v", mac, ip)
log.WithField("from", mac).WithField("to", ip).Debug("Add DHCP entry")
err = v.patchedNetworkUpdate(
v.provisionNetwork,
libvirt.NetworkUpdateCommandAddLast,
Expand Down Expand Up @@ -213,7 +213,7 @@ func (v *Virter) removeDomainDHCP(domain libvirt.Domain, removeDHCPEntries bool)

func (v *Virter) removeDHCPEntries(network libvirt.Network, mac string, ips []string) error {
for _, ip := range ips {
log.Printf("Remove DHCP entry from %v to %v", mac, ip)
log.WithField("from", mac).WithField("to", ip).Debug("Remove DHCP entry")
err := v.patchedNetworkUpdate(
network,
libvirt.NetworkUpdateCommandDelete,
Expand Down
30 changes: 15 additions & 15 deletions internal/virter/vm.go
Original file line number Diff line number Diff line change
Expand Up @@ -130,7 +130,7 @@ func (v *Virter) VMRun(vmConfig VMConfig) error {
}
// end checks

log.Print("Create host key")
log.Debug("Create host key")
hostkey, err := sshkeys.NewRSAHostKey()
if err != nil {
return fmt.Errorf("could not create new host key: %w", err)
Expand All @@ -148,26 +148,26 @@ func (v *Virter) VMRun(vmConfig VMConfig) error {

log.Debugf("Using domain XML: %s", vmXML)

log.Print("Define VM")
log.Debug("Define VM")
d, err := v.libvirt.DomainDefineXML(vmXML)
if err != nil {
return fmt.Errorf("could not define domain: %w", err)
}

log.Print("Create boot volume")
log.Debug("Create boot volume")
_, err = v.ImageSpawn(vmConfig.Name, v.provisionStoragePool, vmConfig.Image, vmConfig.BootCapacityKiB)
if err != nil {
return err
}

log.Print("Create cloud-init volume")
log.Debug("Create cloud-init volume")
_, err = v.createCIData(vmConfig, hostkey)
if err != nil {
return err
}

for _, d := range vmConfig.Disks {
log.Printf("Create volume '%s'", d.GetName())
log.WithField("name", d.GetName()).Debug("Create volume")
pool, err := v.lookupPool(d.GetPool())
if err != nil {
return fmt.Errorf("failed to lookup libvirt pool %s: %w", d.GetPool(), err)
Expand All @@ -188,7 +188,7 @@ func (v *Virter) VMRun(vmConfig VMConfig) error {
}
}

log.Print("Start VM")
log.Debug("Start VM")
err = v.libvirt.DomainCreate(d)
if err != nil {
return fmt.Errorf("could not create (start) domain: %w", err)
Expand Down Expand Up @@ -245,7 +245,7 @@ func (v *Virter) WaitVmReady(ctx context.Context, shellClientBuilder ShellClient
return nil
}

log.Print("Wait for VM to get ready")
log.Debug("Wait for VM to get ready")

// Using ActualTime breaks the expectation of the unit tests
// that this code does not sleep, but we work around that by
Expand All @@ -254,7 +254,7 @@ func (v *Virter) WaitVmReady(ctx context.Context, shellClientBuilder ShellClient
return fmt.Errorf("VM not ready: %w", err)
}

log.Print("Successfully connected to ready VM")
log.Debug("Successfully connected to ready VM")
return nil
}

Expand Down Expand Up @@ -283,7 +283,7 @@ func (v *Virter) VMRm(vmName string, removeDHCPEntries bool, removeBoot bool) er
// it is active (running). And only if it is persistent, otherwise the
// domain is gone and we cannot query what resources it depended on.
if active > 0 && persistent > 0 {
log.Print("Stop VM")
log.Debug("Stop VM")
err = v.libvirt.DomainDestroy(domain)
if err != nil {
return fmt.Errorf("could not destroy domain: %w", err)
Expand Down Expand Up @@ -318,14 +318,14 @@ func (v *Virter) VMRm(vmName string, removeDHCPEntries bool, removeBoot bool) er
}

if persistent > 0 {
log.Print("Undefine VM")
log.Debug("Undefine VM")
err = v.libvirt.DomainUndefineFlags(domain, libvirt.DomainUndefineNvram)
if err != nil {
return fmt.Errorf("could not undefine domain: %w", err)
}
} else if active > 0 {
// Stop the VM if we did not stop it previously.
log.Print("Stop VM")
log.Debug("Stop VM")
err = v.libvirt.DomainDestroy(domain)
if err != nil {
return fmt.Errorf("could not destroy domain: %w", err)
Expand Down Expand Up @@ -370,7 +370,7 @@ func (v *Virter) rmSnapshots(domain libvirt.Domain) error {
}

for _, snapshot := range snapshots {
log.Printf("Delete snapshot %v", snapshot.Name)
log.WithField("name", snapshot.Name).Debug("Delete snapshot")
err = v.libvirt.DomainSnapshotDelete(snapshot, 0)
if err != nil {
return fmt.Errorf("could not delete snapshot: %w", err)
Expand Down Expand Up @@ -443,14 +443,14 @@ func (v *Virter) vmShutdown(ctx context.Context, afterNotifier AfterNotifier, sh
}

if active != 0 {
log.Printf("Shut down VM")
log.Debug("Shut down VM")

err = v.libvirt.DomainShutdown(domain)
if err != nil {
return fmt.Errorf("could not shut down domain: %w", err)
}

log.Printf("Wait for VM to stop")
log.Debug("Wait for VM to stop")
}

timeout := afterNotifier.After(shutdownTimeout)
Expand Down Expand Up @@ -703,7 +703,7 @@ func (v *Virter) VMExecRsync(ctx context.Context, copier netcopy.NetworkCopier,
g, ctx := errgroup.WithContext(ctx)
for _, vmName := range vmNames {
vmName := vmName
log.Printf(`Copying files via rsync: %s to %s on %s`, rsyncStep.Source, rsyncStep.Dest, vmName)
log.Debugf(`Copying files via rsync: %s to %s on %s`, rsyncStep.Source, rsyncStep.Dest, vmName)
g.Go(func() error {
dest := fmt.Sprintf("%s:%s", vmName, rsyncStep.Dest)
return v.VMExecCopy(ctx, copier, files, dest)
Expand Down

0 comments on commit 697988e

Please sign in to comment.