monitor plugin std outputs for unexpected data
Once a plugin process is started, go-plugin will redirect the stdout and stderr stream through a grpc service and provide those streams to the client. This is rarely used, as it is prone to failing with races because those same file descriptors are needed for the initial handshake and logging setup, but data may be accidentally sent to these nonetheless. The usual culprits are stray `fmt.Print` usage where logging was intended, or the configuration of a logger after the os.Stderr file descriptor was replaced by go-plugin. These situations are very hard for provider developers to debug since the data is discarded entirely. While there may be improvements to be made in the go-plugin package to configure this behavior, in the meantime we can add a simple monitoring io.Writer to the streams which will surface th data as warnings in the logs instead of writing it to `io.Discard`
This commit is contained in:
parent
ef88c54604
commit
feb7622846
|
@ -351,6 +351,8 @@ func providerFactory(meta *providercache.CachedProvider) providers.Factory {
|
|||
Cmd: exec.Command(execFile),
|
||||
AutoMTLS: enableProviderAutoMTLS,
|
||||
VersionedPlugins: tfplugin.VersionedPlugins,
|
||||
SyncStdout: logging.PluginOutputMonitor(fmt.Sprintf("%s:stdout", meta.Provider)),
|
||||
SyncStderr: logging.PluginOutputMonitor(fmt.Sprintf("%s:stderr", meta.Provider)),
|
||||
}
|
||||
|
||||
client := plugin.NewClient(config)
|
||||
|
@ -406,6 +408,8 @@ func unmanagedProviderFactory(provider addrs.Provider, reattach *plugin.Reattach
|
|||
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
|
||||
Managed: false,
|
||||
Reattach: reattach,
|
||||
SyncStdout: logging.PluginOutputMonitor(fmt.Sprintf("%s:stdout", provider)),
|
||||
SyncStderr: logging.PluginOutputMonitor(fmt.Sprintf("%s:stderr", provider)),
|
||||
}
|
||||
// TODO: we probably shouldn't hardcode the protocol version
|
||||
// here, but it'll do for now, because only one protocol
|
||||
|
|
|
@ -163,6 +163,8 @@ func provisionerFactory(meta discovery.PluginMeta) provisioners.Factory {
|
|||
Logger: logging.NewLogger("provisioner"),
|
||||
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
|
||||
AutoMTLS: enableProviderAutoMTLS,
|
||||
SyncStdout: logging.PluginOutputMonitor(fmt.Sprintf("%s:stdout", meta.Name)),
|
||||
SyncStderr: logging.PluginOutputMonitor(fmt.Sprintf("%s:stderr", meta.Name)),
|
||||
}
|
||||
client := plugin.NewClient(cfg)
|
||||
return newProvisionerClient(client)
|
||||
|
|
|
@ -187,3 +187,35 @@ func isValidLogLevel(level string) bool {
|
|||
|
||||
return false
|
||||
}
|
||||
|
||||
// PluginOutputMonitor creates an io.Writer that will warn about any writes in
|
||||
// the default logger. This is used to catch unexpected output from plugins,
|
||||
// notifying them about the problem as well as surfacing the lost data for
|
||||
// context.
|
||||
func PluginOutputMonitor(source string) io.Writer {
|
||||
return pluginOutputMonitor{
|
||||
source: source,
|
||||
log: logger,
|
||||
}
|
||||
}
|
||||
|
||||
// pluginOutputMonitor is an io.Writer that logs all writes as
|
||||
// "unexpected data" with the source name.
|
||||
type pluginOutputMonitor struct {
|
||||
source string
|
||||
log hclog.Logger
|
||||
}
|
||||
|
||||
func (w pluginOutputMonitor) Write(d []byte) (int, error) {
|
||||
// Limit the write size to 1024 bytes We're not expecting any data to come
|
||||
// through this channel, so accidental writes will usually be stray fmt
|
||||
// debugging statements and the like, but we want to provide context to the
|
||||
// provider to indicate what the unexpected data might be.
|
||||
n := len(d)
|
||||
if n > 1024 {
|
||||
d = append(d[:1024], '.', '.', '.')
|
||||
}
|
||||
|
||||
w.log.Warn("unexpected data", w.source, strings.TrimSpace(string(d)))
|
||||
return n, nil
|
||||
}
|
||||
|
|
Loading…
Reference in New Issue