Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add more helpful message on plugin setup failure #223

Merged
merged 8 commits into from
Dec 5, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
79 changes: 74 additions & 5 deletions client.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,9 @@ import (
"crypto/subtle"
"crypto/tls"
"crypto/x509"
"debug/elf"
"debug/macho"
"debug/pe"
"encoding/base64"
"errors"
"fmt"
Expand All @@ -15,17 +18,28 @@ import (
"net"
"os"
"os/exec"
"os/user"
"path/filepath"
"runtime"
"strconv"
"strings"
"sync"
"sync/atomic"
"syscall"
"time"

"github.com/hashicorp/go-hclog"
"google.golang.org/grpc"
)

const unrecognizedRemotePluginMessage = `Unrecognized remote plugin message: %s
This usually means
the plugin was not compiled for this architecture,
the plugin is missing dynamic-link libraries necessary to run,
the plugin is not executable by this process due to file permissions, or
the plugin failed to negotiate the initial go-plugin protocol handshake
%s`

// If this is 1, then we've called CleanupClients. This can be used
// by plugin RPC implementations to change error behavior since you
// can expected network connection errors at this point. This should be
Expand Down Expand Up @@ -473,7 +487,65 @@ func (c *Client) Kill() {
c.l.Unlock()
}

// Starts the underlying subprocess, communicating with it to negotiate
// peTypes is a list of Portable Executable (PE) machine types from https://learn.microsoft.com/en-us/windows/win32/debug/pe-format
// mapped to GOARCH types. It is not comprehensive, and only includes machine types that Go supports.
var peTypes = map[uint16]string{
0x14c: "386",
0x1c0: "arm",
0x6264: "loong64",
0x8664: "amd64",
0xaa64: "arm64",
}

// additionalNotesAboutCommand tries to get additional information about a command that might help diagnose
// why it won't run correctly. It runs as a best effort only.
func additionalNotesAboutCommand(path string) string {
notes := ""
stat, err := os.Stat(path)
if err != nil {
return notes
}

notes += "\nAdditional notes about plugin:\n"
notes += fmt.Sprintf(" Path: %s\n", path)
notes += fmt.Sprintf(" Mode: %s\n", stat.Mode())
tomhjp marked this conversation as resolved.
Show resolved Hide resolved
statT, ok := stat.Sys().(*syscall.Stat_t)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi,

this does not compile on Windows:

Error: C:\Users\runneradmin\go\pkg\mod\github.com\hashicorp\[email protected]\client.go:512:36: undefined: syscall.Stat_t

https://github.com/drakkan/sftpgo/actions/runs/3641265803/jobs/6146996350

if ok {
currentUsername := "?"
if u, err := user.LookupId(strconv.FormatUint(uint64(os.Getuid()), 10)); err == nil {
currentUsername = u.Username
}
currentGroup := "?"
if g, err := user.LookupGroupId(strconv.FormatUint(uint64(os.Getgid()), 10)); err == nil {
currentGroup = g.Name
}
username := "?"
if u, err := user.LookupId(strconv.FormatUint(uint64(statT.Uid), 10)); err == nil {
username = u.Username
}
group := "?"
if g, err := user.LookupGroupId(strconv.FormatUint(uint64(statT.Gid), 10)); err == nil {
group = g.Name
}
notes += fmt.Sprintf(" Owner: %d [%s] (current: %d [%s])\n", statT.Uid, username, os.Getuid(), currentUsername)
notes += fmt.Sprintf(" Group: %d [%s] (current: %d [%s])\n", statT.Gid, group, os.Getgid(), currentGroup)
}

if elfFile, err := elf.Open(path); err == nil {
notes += fmt.Sprintf(" ELF architecture: %s (current architecture: %s)\n", elfFile.Machine, runtime.GOARCH)
} else if machoFile, err := macho.Open(path); err == nil {
notes += fmt.Sprintf(" MachO architecture: %s (current architecture: %s)\n", machoFile.Cpu, runtime.GOARCH)
} else if peFile, err := pe.Open(path); err == nil {
machine, ok := peTypes[peFile.Machine]
if !ok {
machine = "unknown"
}
notes += fmt.Sprintf(" PE architecture: %s (current architecture: %s)\n", machine, runtime.GOARCH)
}
return notes
}

// Start the underlying subprocess, communicating with it to negotiate
// a port for RPC connections, and returning the address to connect via RPC.
//
// This method is safe to call multiple times. Subsequent calls have no effect.
Expand Down Expand Up @@ -697,10 +769,7 @@ func (c *Client) Start() (addr net.Addr, err error) {
line = strings.TrimSpace(line)
parts := strings.SplitN(line, "|", 6)
if len(parts) < 4 {
err = fmt.Errorf(
"Unrecognized remote plugin message: %s\n\n"+
"This usually means that the plugin is either invalid or simply\n"+
"needs to be recompiled to support the latest protocol.", line)
err = fmt.Errorf(unrecognizedRemotePluginMessage, line, additionalNotesAboutCommand(cmd.Path))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Open question: Given the scope of usage of this library, and the fact we have a levelled logger available, would it potentially make sense to log the additional notes to debug level instead, and include a note about the availability of debug logs in the error message? I can definitely see the appeal of just having all the information available right there in the error message, and I can also see the possibility for grumbles about verboseness (which I personally don't sympathise with too much), so I'm genuinely undecided.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think by returning an error message, we give the caller the option to log and at what level. They certainly might perform an action based on the remote plugin message in the first line. I think I prefer it as is.

return
}

Expand Down
42 changes: 41 additions & 1 deletion client_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,13 +10,14 @@ import (
"net"
"os"
"os/exec"
"path"
"path/filepath"
"strings"
"sync"
"testing"
"time"

hclog "github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-hclog"
)

func TestClient(t *testing.T) {
Expand Down Expand Up @@ -1395,3 +1396,42 @@ this line is short
t.Fatalf("\nexpected output: %q\ngot output: %q", msg, read)
}
}

func TestAdditionalNotesAboutCommand(t *testing.T) {
files := []string{
"windows-amd64.exe",
"windows-386.exe",
"linux-amd64",
"darwin-amd64",
"darwin-arm64",
}
for _, file := range files {
fullFile := path.Join("testdata", file)
if _, err := os.Stat(fullFile); os.IsNotExist(err) {
t.Skipf("testdata executables not present; please run 'make' in testdata/ directory for this test")
}

notes := additionalNotesAboutCommand(fullFile)
if strings.Contains(file, "windows") && !strings.Contains(notes, "PE") {
t.Errorf("Expected notes to contain Windows information:\n%s", notes)
}
if strings.Contains(file, "linux") && !strings.Contains(notes, "ELF") {
t.Errorf("Expected notes to contain Linux information:\n%s", notes)
}
if strings.Contains(file, "darwin") && !strings.Contains(notes, "MachO") {
t.Errorf("Expected notes to contain macOS information:\n%s", notes)
}

if strings.Contains(file, "amd64") && !(strings.Contains(notes, "amd64") || strings.Contains(notes, "EM_X86_64") || strings.Contains(notes, "CpuAmd64")) {
t.Errorf("Expected notes to contain amd64 information:\n%s", notes)
}

if strings.Contains(file, "arm64") && !strings.Contains(notes, "CpuArm64") {
t.Errorf("Expected notes to contain arm64 information:\n%s", notes)
}
if strings.Contains(file, "386") && !strings.Contains(notes, "386") {
t.Errorf("Expected notes to contain 386 information:\n%s", notes)
}

}
}
2 changes: 1 addition & 1 deletion plugin_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@ import (
"time"

"github.com/golang/protobuf/ptypes/empty"
hclog "github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-hclog"
grpctest "github.com/hashicorp/go-plugin/test/grpc"
"golang.org/x/net/context"
"google.golang.org/grpc"
Expand Down
5 changes: 5 additions & 0 deletions testdata/.gitignore
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
windows-amd64.exe
windows-386.exe
linux-amd64
darwin-amd64
darwin-arm64
29 changes: 29 additions & 0 deletions testdata/Makefile
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
default: all
.PHONY: default

.PHONY: clean
clean:
rm -f windows-amd64.exe windows-386.exe linux-amd64 darwin-amd64 darwin-arm64

.PHONY: all
all: windows-amd64.exe windows-386.exe linux-amd64 darwin-amd64 darwin-arm64

.PHONY: windows-amd64.exe
windows-amd64.exe:
GOOS=windows GOARCH=amd64 go build -o $@

.PHONY: windows-386.exe
windows-386.exe:
GOOS=windows GOARCH=386 go build -o $@

.PHONY: linux-amd64
linux-amd64:
GOOS=linux GOARCH=amd64 go build -o $@

.PHONY: darwin-amd64
darwin-amd64:
GOOS=darwin GOARCH=amd64 go build -o $@

.PHONY: darwin-arm64
darwin-arm64:
GOOS=darwin GOARCH=arm64 go build -o $@
1 change: 1 addition & 0 deletions testdata/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
This folder contains a minimal Go program so that we can obtain example binaries of programs for various architectures for use in tests.
3 changes: 3 additions & 0 deletions testdata/go.mod
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
module example.com/testdata

go 1.19
Empty file added testdata/go.sum
Empty file.
4 changes: 4 additions & 0 deletions testdata/minimal.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
package main

func main() {
}