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

Convert to logxi #1755

Merged
merged 1 commit into from Aug 21, 2016
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.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
3 changes: 1 addition & 2 deletions builtin/credential/approle/path_tidy_user_id.go
Expand Up @@ -5,7 +5,6 @@ import (
"sync/atomic"
"time"

"github.com/hashicorp/errwrap"
"github.com/hashicorp/go-multierror"
"github.com/hashicorp/vault/logical"
"github.com/hashicorp/vault/logical/framework"
Expand Down Expand Up @@ -59,7 +58,7 @@ func (b *backend) tidySecretID(s logical.Storage) error {
}

if secretIDEntry == nil {
result = multierror.Append(result, errwrap.Wrapf("[ERR] {{err}}", fmt.Errorf("entry for SecretID %s is nil", secretIDHMAC)))
result = multierror.Append(result, fmt.Errorf("entry for SecretID %s is nil", secretIDHMAC))
lock.Unlock()
continue
}
Expand Down
6 changes: 3 additions & 3 deletions builtin/credential/cert/path_login.go
Expand Up @@ -218,18 +218,18 @@ func (b *backend) loadTrustedCerts(store logical.Storage) (pool *x509.CertPool,
trustedNonCAs = make([]*ParsedCert, 0)
names, err := store.List("cert/")
if err != nil {
b.Logger().Printf("[ERR] cert: failed to list trusted certs: %v", err)
b.Logger().Error("cert: failed to list trusted certs", "error", err)
return
}
for _, name := range names {
entry, err := b.Cert(store, strings.TrimPrefix(name, "cert/"))
if err != nil {
b.Logger().Printf("[ERR] cert: failed to load trusted certs '%s': %v", name, err)
b.Logger().Error("cert: failed to load trusted cert", "name", name, "error", err)
continue
}
parsed := parsePEM([]byte(entry.Certificate))
if len(parsed) == 0 {
b.Logger().Printf("[ERR] cert: failed to parse certificate for '%s'", name)
b.Logger().Error("cert: failed to parse certificate", "name", name)
continue
}
if !parsed[0].IsCA {
Expand Down
2 changes: 1 addition & 1 deletion builtin/credential/github/path_login.go
Expand Up @@ -48,7 +48,7 @@ func (b *backend) pathLogin(

ttl, _, err := b.SanitizeTTLStr(config.TTL.String(), config.MaxTTL.String())
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("[ERR]:%s", err)), nil
return logical.ErrorResponse(fmt.Sprintf("error sanitizing TTLs: %s", err)), nil
}

return &logical.Response{
Expand Down
32 changes: 23 additions & 9 deletions builtin/credential/ldap/backend.go
Expand Up @@ -105,7 +105,9 @@ func (b *backend) Login(req *logical.Request, username string, password string)
return nil, logical.ErrorResponse(err.Error()), nil
}

b.Logger().Printf("[DEBUG] auth/ldap: BindDN for %s is %s", username, bindDN)
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: BindDN fetched", "username", username, "binddn", bindDN)
}

// Try to bind as the login user. This is where the actual authentication takes place.
if err = c.Bind(bindDN, password); err != nil {
Expand All @@ -121,7 +123,9 @@ func (b *backend) Login(req *logical.Request, username string, password string)
if err != nil {
return nil, logical.ErrorResponse(err.Error()), nil
}
b.Logger().Printf("[DEBUG] auth/ldap: Server returned %d groups: %v", len(ldapGroups), ldapGroups)
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: Groups fetched from server", "num_server_groups", len(ldapGroups), "server_groups", ldapGroups)
}

ldapResponse := &logical.Response{
Data: map[string]interface{}{},
Expand All @@ -137,7 +141,9 @@ func (b *backend) Login(req *logical.Request, username string, password string)
// Import the custom added groups from ldap backend
user, err := b.User(req.Storage, username)
if err == nil && user != nil && user.Groups != nil {
b.Logger().Printf("[DEBUG] auth/ldap: adding %d local groups: %v\n", len(user.Groups), user.Groups)
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: adding local groups", "num_local_groups", len(user.Groups), "local_groups", user.Groups)
}
allGroups = append(allGroups, user.Groups...)
}
// Merge local and LDAP groups
Expand Down Expand Up @@ -207,7 +213,9 @@ func (b *backend) getBindDN(cfg *ConfigEntry, c *ldap.Conn, username string) (st
}

filter := fmt.Sprintf("(%s=%s)", cfg.UserAttr, ldap.EscapeFilter(username))
b.Logger().Printf("[DEBUG] auth/ldap: Discovering user, BaseDN=%s, Filter=%s", cfg.UserDN, filter)
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: Discovering user", "userdn", cfg.UserDN, "filter", filter)
}
result, err := c.Search(&ldap.SearchRequest{
BaseDN: cfg.UserDN,
Scope: 2, // subtree
Expand Down Expand Up @@ -239,7 +247,9 @@ func (b *backend) getUserDN(cfg *ConfigEntry, c *ldap.Conn, bindDN string) (stri
if cfg.UPNDomain != "" {
// Find the distinguished name for the user if userPrincipalName used for login
filter := fmt.Sprintf("(userPrincipalName=%s)", ldap.EscapeFilter(bindDN))
b.Logger().Printf("[DEBUG] auth/ldap: Searching UPN, BaseDN=%s, Filter=%s", cfg.UserDN, filter)
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: Searching UPN", "userdn", cfg.UserDN, "filter", filter)
}
result, err := c.Search(&ldap.SearchRequest{
BaseDN: cfg.UserDN,
Scope: 2, // subtree
Expand Down Expand Up @@ -281,18 +291,20 @@ func (b *backend) getLdapGroups(cfg *ConfigEntry, c *ldap.Conn, userDN string, u
ldapMap := make(map[string]bool)

if cfg.GroupFilter == "" {
b.Logger().Printf("[WARN] auth/ldap: GroupFilter is empty, will not query server")
b.Logger().Warn("auth/ldap: GroupFilter is empty, will not query server")
Copy link
Member

Choose a reason for hiding this comment

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

IsWarn check is missing here and in the next log message as well.

As a general comment, it is a real pain to check IsDebug or IsWarn before printing anything.

Is it not possible that the Logger().Debug() will only print if Debug is enabled. So we can conveniently skip the check.

Copy link
Member Author

Choose a reason for hiding this comment

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

return make([]string, 0), nil
}

if cfg.GroupDN == "" {
b.Logger().Printf("[WARN] auth/ldap: GroupDN is empty, will not query server")
b.Logger().Warn("auth/ldap: GroupDN is empty, will not query server")
return make([]string, 0), nil
}

// If groupfilter was defined, resolve it as a Go template and use the query for
// returning the user's groups
b.Logger().Printf("[DEBUG] auth/ldap: Compiling group filter %s", cfg.GroupFilter)
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: Compiling group filter", "group_filter", cfg.GroupFilter)
}

// Parse the configuration as a template.
// Example template "(&(objectClass=group)(member:1.2.840.113556.1.4.1941:={{.UserDN}}))"
Expand All @@ -313,7 +325,9 @@ func (b *backend) getLdapGroups(cfg *ConfigEntry, c *ldap.Conn, userDN string, u
var renderedQuery bytes.Buffer
t.Execute(&renderedQuery, context)

b.Logger().Printf("[DEBUG] auth/ldap: Searching GroupDN=%s, query=%s", cfg.GroupDN, renderedQuery.String())
if b.Logger().IsDebug() {
b.Logger().Debug("auth/ldap: Searching", "groupdn", cfg.GroupDN, "rendered_query", renderedQuery.String())
}

result, err := c.Search(&ldap.SearchRequest{
BaseDN: cfg.GroupDN,
Expand Down
2 changes: 1 addition & 1 deletion builtin/logical/mongodb/backend_test.go
Expand Up @@ -7,12 +7,12 @@ import (
"strings"
"sync"
"testing"
"time"

"github.com/hashicorp/vault/logical"
logicaltest "github.com/hashicorp/vault/logical/testing"
"github.com/mitchellh/mapstructure"
"github.com/ory-am/dockertest"
"time"
)

var (
Expand Down
4 changes: 3 additions & 1 deletion builtin/logical/pki/path_fetch.go
Expand Up @@ -191,7 +191,9 @@ reply:
logical.HTTPRawBody: certificate,
}}
if retErr != nil {
b.Logger().Printf("Possible error, but cannot return in raw response: %s. Note that an empty CA probably means none was configured, and an empty CRL is quite possibly correct", retErr)
if b.Logger().IsWarn() {
b.Logger().Warn("Possible error, but cannot return in raw response. Note that an empty CA probably means none was configured, and an empty CRL is possibly correct", "error", retErr)
}
}
retErr = nil
response.Data[logical.HTTPStatusCode] = 200
Expand Down
14 changes: 8 additions & 6 deletions builtin/logical/postgresql/backend.go
Expand Up @@ -3,10 +3,11 @@ package postgresql
import (
"database/sql"
"fmt"
"log"
"strings"
"sync"

log "github.com/mgutz/logxi/v1"

"github.com/hashicorp/vault/logical"
"github.com/hashicorp/vault/logical/framework"
)
Expand Down Expand Up @@ -45,13 +46,14 @@ type backend struct {
db *sql.DB
lock sync.Mutex

logger *log.Logger
logger log.Logger
}

// DB returns the database connection.
func (b *backend) DB(s logical.Storage) (*sql.DB, error) {
b.logger.Println("[TRACE] postgres/db: enter")
defer b.logger.Println("[TRACE] postgres/db: exit")
b.logger.Trace("postgres/db: enter")
defer b.logger.Trace("postgres/db: exit")

b.lock.Lock()
defer b.lock.Unlock()

Expand Down Expand Up @@ -111,8 +113,8 @@ func (b *backend) DB(s logical.Storage) (*sql.DB, error) {

// ResetDB forces a connection next time DB() is called.
func (b *backend) ResetDB() {
b.logger.Println("[TRACE] postgres/resetdb: enter")
defer b.logger.Println("[TRACE] postgres/resetdb: exit")
b.logger.Trace("postgres/resetdb: enter")
defer b.logger.Trace("postgres/resetdb: exit")

b.lock.Lock()
defer b.lock.Unlock()
Expand Down
23 changes: 12 additions & 11 deletions builtin/logical/postgresql/path_role_create.go
Expand Up @@ -33,12 +33,13 @@ func pathRoleCreate(b *backend) *framework.Path {

func (b *backend) pathRoleCreateRead(
req *logical.Request, data *framework.FieldData) (*logical.Response, error) {
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: enter")
defer b.logger.Println("[TRACE] postgres/pathRoleCreateRead: exit")
b.logger.Trace("postgres/pathRoleCreateRead: enter")
defer b.logger.Trace("postgres/pathRoleCreateRead: exit")

name := data.Get("name").(string)

// Get the role
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: getting role")
b.logger.Trace("postgres/pathRoleCreateRead: getting role")
role, err := b.Role(req.Storage, name)
if err != nil {
return nil, err
Expand All @@ -48,7 +49,7 @@ func (b *backend) pathRoleCreateRead(
}

// Determine if we have a lease
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: getting lease")
b.logger.Trace("postgres/pathRoleCreateRead: getting lease")
lease, err := b.Lease(req.Storage)
if err != nil {
return nil, err
Expand Down Expand Up @@ -84,20 +85,20 @@ func (b *backend) pathRoleCreateRead(
Format("2006-01-02 15:04:05-0700")

// Get our handle
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: getting database handle")
b.logger.Trace("postgres/pathRoleCreateRead: getting database handle")
db, err := b.DB(req.Storage)
if err != nil {
return nil, err
}

// Start a transaction
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: starting transaction")
b.logger.Trace("postgres/pathRoleCreateRead: starting transaction")
tx, err := db.Begin()
if err != nil {
return nil, err
}
defer func() {
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: rolling back transaction")
b.logger.Trace("postgres/pathRoleCreateRead: rolling back transaction")
tx.Rollback()
}()

Expand All @@ -108,7 +109,7 @@ func (b *backend) pathRoleCreateRead(
continue
}

b.logger.Println("[TRACE] postgres/pathRoleCreateRead: preparing statement")
b.logger.Trace("postgres/pathRoleCreateRead: preparing statement")
stmt, err := tx.Prepare(Query(query, map[string]string{
"name": username,
"password": password,
Expand All @@ -118,22 +119,22 @@ func (b *backend) pathRoleCreateRead(
return nil, err
}
defer stmt.Close()
b.logger.Println("[TRACE] postgres/pathRoleCreateRead: executing statement")
b.logger.Trace("postgres/pathRoleCreateRead: executing statement")
if _, err := stmt.Exec(); err != nil {
return nil, err
}
}

// Commit the transaction

b.logger.Println("[TRACE] postgres/pathRoleCreateRead: committing transaction")
b.logger.Trace("postgres/pathRoleCreateRead: committing transaction")
if err := tx.Commit(); err != nil {
return nil, err
}

// Return the secret

b.logger.Println("[TRACE] postgres/pathRoleCreateRead: generating secret")
b.logger.Trace("postgres/pathRoleCreateRead: generating secret")
resp := b.Secret(SecretCredsType).Response(map[string]interface{}{
"username": username,
"password": password,
Expand Down
1 change: 0 additions & 1 deletion builtin/logical/rabbitmq/path_roles_test.go

This file was deleted.

21 changes: 13 additions & 8 deletions builtin/logical/ssh/communicator.go
Expand Up @@ -7,11 +7,12 @@ import (
"fmt"
"io"
"io/ioutil"
"log"
"net"
"os"
"path/filepath"

log "github.com/mgutz/logxi/v1"

"golang.org/x/crypto/ssh"
"golang.org/x/crypto/ssh/agent"
)
Expand All @@ -38,6 +39,9 @@ type SSHCommConfig struct {

// DisableAgent, if true, will not forward the SSH agent.
DisableAgent bool

// Logger for output
Logger log.Logger
}

// Creates a new communicator implementation over SSH. This takes
Expand Down Expand Up @@ -92,8 +96,9 @@ func (c *comm) NewSession() (session *ssh.Session, err error) {
}

if err != nil {
log.Printf("ssh session open error: '%s', attempting reconnect", err)
c.config.Logger.Error("ssh session open error, attempting reconnect", "error", err)
if err := c.reconnect(); err != nil {
c.config.Logger.Error("reconnect attempt failed", "error", err)
return nil, err
}

Expand All @@ -119,13 +124,13 @@ func (c *comm) reconnect() error {
//
// http://golang.org/doc/faq#nil_error
c.conn = nil
log.Printf("reconnection error: %s", err)
c.config.Logger.Error("reconnection error", "error", err)
return err
}

sshConn, sshChan, req, err := ssh.NewClientConn(c.conn, c.address, c.config.SSHConfig)
if err != nil {
log.Printf("handshake error: %s", err)
c.config.Logger.Error("handshake error", "error", err)
c.Close()
return err
}
Expand Down Expand Up @@ -153,15 +158,15 @@ func (c *comm) connectToAgent() {
}
agentConn, err := net.Dial("unix", socketLocation)
if err != nil {
log.Printf("[ERROR] could not connect to local agent socket: %s", socketLocation)
c.config.Logger.Error("could not connect to local agent socket", "socket_path", socketLocation)
return
}
defer agentConn.Close()

// create agent and add in auth
forwardingAgent := agent.NewClient(agentConn)
if forwardingAgent == nil {
log.Printf("[ERROR] Could not create agent client")
c.config.Logger.Error("could not create agent client")
return
}

Expand All @@ -180,7 +185,7 @@ func (c *comm) connectToAgent() {

err = agent.RequestAgentForwarding(session)
if err != nil {
log.Printf("[ERROR] RequestAgentForwarding: %#v", err)
c.config.Logger.Error("error requesting agent forwarding", "error", err)
return
}
return
Expand Down Expand Up @@ -243,7 +248,7 @@ func (c *comm) scpSession(scpCommand string, f func(io.Writer, *bufio.Reader) er
if exitErr, ok := err.(*ssh.ExitError); ok {
// Otherwise, we have an ExitErorr, meaning we can just read
// the exit status
log.Printf("non-zero exit status: %d", exitErr.ExitStatus())
c.config.Logger.Error("got non-zero exit status", "exit_status", exitErr.ExitStatus())

// If we exited with status 127, it means SCP isn't available.
// Return a more descriptive error for that.
Expand Down