Repository: snowflakedb/gosnowflake
Pull request #362 (2020-12-22 04:31:49)

SNOW-239637 Logging with context
### Description
Add WithContext support for logging to record context fields. Add session ID in context.

### Checklist
- [x] Code compiles correctly
- [x] Run ``make fmt`` to fix inconsistent formats
- [x] Run ``make lint`` to get lint errors and fix all of them
- [ ] Created tests which fail without the change (if possible)
- [x] All tests passing
- [ ] Extended the README / documentation, if necessary


sfc-gh-stakeda: Overall looks good to me. This PR reminds me that the importance of log with context. Other drivers can follow to have more meaning information, session id, request id, query id, for better diagnosis.

Patch:
diff --git a/auth.go b/auth.go
index cb74339..39d9bfd 100644
--- a/auth.go
+++ b/auth.go
@@ -344,7 +344,7 @@ func authenticate(
 		return
 	}
 
-	logger.Infof("PARAMS for Auth: %v, %v, %v, %v, %v, %v",
+	logger.WithContext(sc.ctx).Infof("PARAMS for Auth: %v, %v, %v, %v, %v, %v",
 		params, sc.rest.Protocol, sc.rest.Host, sc.rest.Port, sc.rest.LoginTimeout, sc.cfg.Authenticator.String())
 
 	respd, err := sc.rest.FuncPostAuth(ctx, sc.rest, params, headers, jsonBody, sc.rest.LoginTimeout)
diff --git a/authexternalbrowser.go b/authexternalbrowser.go
index 0fef7e2..6533efe 100644
--- a/authexternalbrowser.go
+++ b/authexternalbrowser.go
@@ -115,7 +115,7 @@ func getIdpURLProofKey(
 
 	jsonBody, err := json.Marshal(authRequest)
 	if err != nil {
-		logger.Errorf("failed to serialize json. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to serialize json. err: %v", err)
 		return "", "", err
 	}
 
@@ -196,7 +196,7 @@ func authenticateByExternalBrowser(
 	var errFromGoroutine error
 	conn, err := l.Accept()
 	if err != nil {
-		logger.Errorf("unable to accept connection. err: %v", err)
+		logger.WithContext(ctx).Errorf("unable to accept connection. err: %v", err)
 		log.Fatal(err)
 	}
 	go func(c net.Conn) {
@@ -247,7 +247,7 @@ func authenticateByExternalBrowser(
 
 	escapedSamlResponse, err := url.QueryUnescape(encodedSamlResponse)
 	if err != nil {
-		logger.Errorf("unable to unescape saml response. err: %v", err)
+		logger.WithContext(ctx).Errorf("unable to unescape saml response. err: %v", err)
 		return nil, nil, err
 	}
 	return []byte(escapedSamlResponse), []byte(proofKey), nil
diff --git a/authokta.go b/authokta.go
index 6478ff0..bd59239 100644
--- a/authokta.go
+++ b/authokta.go
@@ -57,7 +57,7 @@ func authenticateBySAML(
 	user string,
 	password string,
 ) (samlResponse []byte, err error) {
-	logger.Info("step 1: query GS to obtain IDP token and SSO url")
+	logger.WithContext(ctx).Info("step 1: query GS to obtain IDP token and SSO url")
 	headers := make(map[string]string)
 	headers["Content-Type"] = headerContentTypeApplicationJSON
 	headers["accept"] = headerContentTypeApplicationJSON
@@ -83,7 +83,7 @@ func authenticateBySAML(
 	if err != nil {
 		return nil, err
 	}
-	logger.Infof("PARAMS for Auth: %v, %v", params, sr)
+	logger.WithContext(ctx).Infof("PARAMS for Auth: %v, %v", params, sr)
 	respd, err := sr.FuncPostAuthSAML(ctx, sr, headers, jsonBody, sr.LoginTimeout)
 	if err != nil {
 		return nil, err
@@ -104,7 +104,7 @@ func authenticateBySAML(
 			Message:  respd.Message,
 		}
 	}
-	logger.Info("step 2: validate Token and SSO URL has the same prefix as oktaURL")
+	logger.WithContext(ctx).Info("step 2: validate Token and SSO URL has the same prefix as oktaURL")
 	var tokenURL *url.URL
 	var ssoURL *url.URL
 	if tokenURL, err = url.Parse(respd.Data.TokenURL); err != nil {
@@ -121,7 +121,7 @@ func authenticateBySAML(
 			MessageArgs: []interface{}{oktaURL, respd.Data.TokenURL, respd.Data.SSOURL},
 		}
 	}
-	logger.Info("step 3: query IDP token url to authenticate and retrieve access token")
+	logger.WithContext(ctx).Info("step 3: query IDP token url to authenticate and retrieve access token")
 	jsonBody, err = json.Marshal(authOKTARequest{
 		Username: user,
 		Password: password,
@@ -134,7 +134,7 @@ func authenticateBySAML(
 		return nil, err
 	}
 
-	logger.Info("step 4: query IDP URL snowflake app to get SAML response")
+	logger.WithContext(ctx).Info("step 4: query IDP URL snowflake app to get SAML response")
 	params = &url.Values{}
 	params.Add("RelayState", "/some/deep/link")
 	params.Add("onetimetoken", respa.CookieToken)
@@ -145,14 +145,14 @@ func authenticateBySAML(
 	if err != nil {
 		return nil, err
 	}
-	logger.Info("step 5: validate post_back_url matches Snowflake URL")
+	logger.WithContext(ctx).Info("step 5: validate post_back_url matches Snowflake URL")
 	tgtURL, err := postBackURL(bd)
 	if err != nil {
 		return nil, err
 	}
 
 	fullURL := sr.getURL()
-	logger.Infof("tgtURL: %v, origURL: %v", tgtURL, fullURL)
+	logger.WithContext(ctx).Infof("tgtURL: %v, origURL: %v", tgtURL, fullURL)
 	if !isPrefixEqual(tgtURL, fullURL) {
 		return nil, &SnowflakeError{
 			Number:      ErrCodeSSOURLNotMatch,
@@ -218,7 +218,7 @@ func postAuthSAML(
 		var respd authResponse
 		err = json.NewDecoder(resp.Body).Decode(&respd)
 		if err != nil {
-			logger.Errorf("failed to decode JSON. err: %v", err)
+			logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 			return nil, err
 		}
 		return &respd, nil
@@ -243,7 +243,7 @@ func postAuthSAML(
 	}
 	_, err = ioutil.ReadAll(resp.Body)
 	if err != nil {
-		logger.Errorf("failed to extract HTTP response body. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to extract HTTP response body. err: %v", err)
 		return nil, err
 	}
 	return nil, &SnowflakeError{
@@ -276,7 +276,7 @@ func postAuthOKTA(
 		var respd authOKTAResponse
 		err = json.NewDecoder(resp.Body).Decode(&respd)
 		if err != nil {
-			logger.Errorf("failed to decode JSON. err: %v", err)
+			logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 			return nil, err
 		}
 		return &respd, nil
@@ -286,8 +286,8 @@ func postAuthOKTA(
 		logger.Errorf("failed to extract HTTP response body. err: %v", err)
 		return nil, err
 	}
-	logger.Infof("HTTP: %v, URL: %v", resp.StatusCode, fullURL)
-	logger.Infof("Header: %v", resp.Header)
+	logger.WithContext(ctx).Infof("HTTP: %v, URL: %v", resp.StatusCode, fullURL)
+	logger.WithContext(ctx).Infof("Header: %v", resp.Header)
 	return nil, &SnowflakeError{
 		Number:      ErrFailedToAuthOKTA,
 		SQLState:    SQLStateConnectionRejected,
@@ -309,7 +309,7 @@ func getSSO(
 		return nil, err
 	}
 	fullURL.RawQuery = params.Encode()
-	logger.Infof("fullURL: %v", fullURL)
+	logger.WithContext(ctx).Infof("fullURL: %v", fullURL)
 	resp, err := sr.FuncGet(ctx, sr, fullURL, headers, timeout)
 	if err != nil {
 		return nil, err
@@ -317,14 +317,14 @@ func getSSO(
 	defer resp.Body.Close()
 	b, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
-		logger.Errorf("failed to extract HTTP response body. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to extract HTTP response body. err: %v", err)
 		return nil, err
 	}
 	if resp.StatusCode == http.StatusOK {
 		return b, nil
 	}
-	logger.Infof("HTTP: %v, URL: %v ", resp.StatusCode, fullURL)
-	logger.Infof("Header: %v", resp.Header)
+	logger.WithContext(ctx).Infof("HTTP: %v, URL: %v ", resp.StatusCode, fullURL)
+	logger.WithContext(ctx).Infof("Header: %v", resp.Header)
 	return nil, &SnowflakeError{
 		Number:      ErrFailedToGetSSO,
 		SQLState:    SQLStateConnectionRejected,
diff --git a/chunk_arrow.go b/chunk_arrow.go
index c000055..190c748 100644
--- a/chunk_arrow.go
+++ b/chunk_arrow.go
@@ -18,7 +18,7 @@ type arrowResultChunk struct {
 }
 
 func (arc *arrowResultChunk) decodeArrowChunk(rowType []execResponseRowType) ([]chunkRowType, error) {
-	logger.Info("Arrow Decoder")
+	logger.Debug("Arrow Decoder")
 
 	var chunkRows []chunkRowType
 
diff --git a/cmd/logger/logger.go b/cmd/logger/logger.go
index cfdfa5a..82ee3f0 100644
--- a/cmd/logger/logger.go
+++ b/cmd/logger/logger.go
@@ -21,43 +21,48 @@ func (log *testLogger) SetLogLevel(level string) error {
 	return nil
 }
 
-func getLogger() *testLogger {
+func createTestLogger() testLogger {
 	var logging = testLogger{*rlog.New()}
 	var formatter = rlog.JSONFormatter{CallerPrettyfier: sf.SFCallerPrettyfier}
 	logging.SetReportCaller(true)
 	logging.SetFormatter(&formatter)
-	return &logging
+	return logging
 }
 
 func main() {
 	buf := &bytes.Buffer{}
 	buf2 := &bytes.Buffer{}
 
-	sf.GetLogger().SetOutput(buf)
-	sf.GetLogger().Info("Hello I am default")
-	sf.GetLogger().Info("Hello II amm default")
-	sf.GetLogger().Debug("Default I am debug NOT SHOWN")
-	sf.GetLogger().SetLogLevel("debug")
-	sf.GetLogger().Debug("Default II amm debug TO SHOW")
+	var mylog = sf.GetLogger()
+	mylog.SetOutput(buf)
+	mylog.Info("Hello I am default")
+	mylog.Info("Hello II amm default")
+	mylog.Debug("Default I am debug NOT SHOWN")
+	mylog.SetLogLevel("debug")
+	mylog.Debug("Default II amm debug TO SHOW")
 
-	var testlg = getLogger()
-	testlg.SetLogLevel("debug")
-	testlg.SetOutput(buf2)
-	sf.SetLogger(testlg)
-	sf.GetLogger().Debug("test debug log is shown")
-	sf.GetLogger().SetLogLevel("info")
-	sf.GetLogger().Debug("test debug log is not shownII")
+	var testlog = sf.CreateDefaultLogger()
+	testlog.SetLogLevel("debug")
+	testlog.SetOutput(buf)
+	testlog.SetOutput(buf2)
+	sf.SetLogger(&testlog)
+
+	var mylog2 = (sf.GetLogger()).(sf.SFLogger)
+	mylog2.Debug("test debug log is shown")
+	mylog2.SetLogLevel("info")
+	mylog2.Debug("test debug log is not shownII")
 	log.Print("Expect all true values:")
 
 	// verify logger switch
-	log.Printf("%t:%t:%t:%t", strings.Contains(buf.String(), "I am default"),
-		strings.Contains(buf.String(), "II amm default"),
-		!strings.Contains(buf.String(), "test debug log is shown"),
+	var strbuf = buf.String()
+	log.Printf("%t:%t:%t:%t", strings.Contains(strbuf, "I am default"),
+		strings.Contains(strbuf, "II amm default"),
+		!strings.Contains(strbuf, "test debug log is shown"),
 		strings.Contains(buf2.String(), "test debug log is shown"))
 
 	// verify log level switch
-	log.Printf("%t:%t:%t:%t", !strings.Contains(buf.String(), "Default I am debug NOT SHOWN"),
-		strings.Contains(buf.String(), "Default II amm debug TO SHOW"),
+	log.Printf("%t:%t:%t:%t", !strings.Contains(strbuf, "Default I am debug NOT SHOWN"),
+		strings.Contains(strbuf, "Default II amm debug TO SHOW"),
 		strings.Contains(buf2.String(), "test debug log is shown"),
 		!strings.Contains(buf2.String(), "test debug log is not shownII"))
 
diff --git a/connection.go b/connection.go
index 8d53b5b..78b19f8 100644
--- a/connection.go
+++ b/connection.go
@@ -35,6 +35,7 @@ const (
 )
 
 type snowflakeConn struct {
+	ctx             context.Context
 	cfg             *Config
 	rest            *snowflakeRestful
 	SequenceCounter uint64
@@ -81,7 +82,7 @@ func (sc *snowflakeConn) exec(
 		req.Bindings = make(map[string]execBindParameter, len(bindings))
 		for i, n := 0, len(bindings); i < n; i++ {
 			t := goTypeToSnowflake(bindings[i].Value, tsmode)
-			logger.Infof("tmode: %v\n", t)
+			logger.WithContext(ctx).Debugf("tmode: %v\n", t)
 			if t == "CHANGE_TYPE" {
 				tsmode, err = dataTypeMode(bindings[i].Value)
 				if err != nil {
@@ -109,8 +110,8 @@ func (sc *snowflakeConn) exec(
 	if multiCount != nil {
 		req.Parameters = map[string]interface{}{string(MultiStatementCount): multiCount}
 	}
-	logger.Infof("bindings: %v", req.Bindings)
-	logger.Infof("parameters: %v", req.Parameters)
+	logger.WithContext(ctx).Infof("bindings: %v", req.Bindings)
+	logger.WithContext(ctx).Infof("parameters: %v", req.Parameters)
 
 	headers := make(map[string]string)
 	headers["Content-Type"] = headerContentTypeApplicationJSON
@@ -142,7 +143,7 @@ func (sc *snowflakeConn) exec(
 	} else {
 		code = -1
 	}
-	logger.Infof("Success: %v, Code: %v", data.Success, code)
+	logger.WithContext(ctx).Infof("Success: %v, Code: %v", data.Success, code)
 	if !data.Success {
 		return nil, &SnowflakeError{
 			Number:   code,
@@ -151,7 +152,7 @@ func (sc *snowflakeConn) exec(
 			QueryID:  data.Data.QueryID,
 		}
 	}
-	logger.Info("Exec/Query SUCCESS")
+	logger.WithContext(ctx).Info("Exec/Query SUCCESS")
 	sc.cfg.Database = data.Data.FinalDatabaseName
 	sc.cfg.Schema = data.Data.FinalSchemaName
 	sc.cfg.Role = data.Data.FinalRoleName
@@ -163,11 +164,11 @@ func (sc *snowflakeConn) exec(
 }
 
 func (sc *snowflakeConn) Begin() (driver.Tx, error) {
-	return sc.BeginTx(context.TODO(), driver.TxOptions{})
+	return sc.BeginTx(sc.ctx, driver.TxOptions{})
 }
 
 func (sc *snowflakeConn) BeginTx(ctx context.Context, opts driver.TxOptions) (driver.Tx, error) {
-	logger.Info("BeginTx")
+	logger.WithContext(ctx).Info("BeginTx")
 	if opts.ReadOnly {
 		return nil, &SnowflakeError{
 			Number:   ErrNoReadOnlyTransaction,
@@ -199,10 +200,10 @@ func (sc *snowflakeConn) cleanup() {
 }
 
 func (sc *snowflakeConn) Close() (err error) {
-	logger.Infoln("Close")
+	logger.WithContext(sc.ctx).Infoln("Close")
 	sc.stopHeartBeat()
 
-	err = sc.rest.FuncCloseSession(context.TODO(), sc.rest, sc.rest.RequestTimeout)
+	err = sc.rest.FuncCloseSession(sc.ctx, sc.rest, sc.rest.RequestTimeout)
 	if err != nil {
 		logger.Error(err)
 	}
@@ -211,7 +212,7 @@ func (sc *snowflakeConn) Close() (err error) {
 }
 
 func (sc *snowflakeConn) PrepareContext(ctx context.Context, query string) (driver.Stmt, error) {
-	logger.Infoln("Prepare")
+	logger.WithContext(sc.ctx).Infoln("Prepare")
 	if sc.rest == nil {
 		return nil, driver.ErrBadConn
 	}
@@ -223,18 +224,18 @@ func (sc *snowflakeConn) PrepareContext(ctx context.Context, query string) (driv
 }
 
 func (sc *snowflakeConn) Prepare(query string) (driver.Stmt, error) {
-	return sc.PrepareContext(context.TODO(), query)
+	return sc.PrepareContext(sc.ctx, query)
 }
 
 func (sc *snowflakeConn) ExecContext(ctx context.Context, query string, args []driver.NamedValue) (driver.Result, error) {
-	logger.Infof("Exec: %#v, %v", query, args)
+	logger.WithContext(ctx).Infof("Exec: %#v, %v", query, args)
 	if sc.rest == nil {
 		return nil, driver.ErrBadConn
 	}
 	// TODO: handle noResult and isInternal
 	data, err := sc.exec(ctx, query, false, false, args)
 	if err != nil {
-		logger.Infof("error: %v", err)
+		logger.WithContext(ctx).Infof("error: %v", err)
 		if data != nil {
 			code, err := strconv.Atoi(data.Code)
 			if err != nil {
@@ -256,7 +257,7 @@ func (sc *snowflakeConn) ExecContext(ctx context.Context, query string, args []d
 		if err != nil {
 			return nil, err
 		}
-		logger.Infof("number of updated rows: %#v", updatedRows)
+		logger.WithContext(ctx).Debugf("number of updated rows: %#v", updatedRows)
 		return &snowflakeResult{
 			affectedRows: updatedRows,
 			insertID:     -1,
@@ -285,7 +286,7 @@ func (sc *snowflakeConn) ExecContext(ctx context.Context, query string, args []d
 			if sc.isDml(childData.Data.StatementTypeID) {
 				count, err := updateRows(childData.Data)
 				if err != nil {
-					logger.Errorf("error: %v", err)
+					logger.WithContext(ctx).Errorf("error: %v", err)
 					if childData != nil {
 						code, err := strconv.Atoi(childData.Code)
 						if err != nil {
@@ -302,26 +303,26 @@ func (sc *snowflakeConn) ExecContext(ctx context.Context, query string, args []d
 				updatedRows += count
 			}
 		}
-		logger.Infof("number of updated rows: %#v", updatedRows)
+		logger.WithContext(ctx).Infof("number of updated rows: %#v", updatedRows)
 		return &snowflakeResult{
 			affectedRows: updatedRows,
 			insertID:     -1,
 			queryID:      sc.QueryID,
 		}, nil
 	}
-	logger.Info("DDL")
+	logger.Debug("DDL")
 	return driver.ResultNoRows, nil
 }
 
 func (sc *snowflakeConn) QueryContext(ctx context.Context, query string, args []driver.NamedValue) (driver.Rows, error) {
-	logger.Infof("Query: %#v, %v", query, args)
+	logger.WithContext(ctx).Infof("Query: %#v, %v", query, args)
 	if sc.rest == nil {
 		return nil, driver.ErrBadConn
 	}
 	// TODO: handle noResult and isInternal
 	data, err := sc.exec(ctx, query, false, false, args)
 	if err != nil {
-		logger.Errorf("error: %v", err)
+		logger.WithContext(ctx).Errorf("error: %v", err)
 		if data != nil {
 			code, err := strconv.Atoi(data.Code)
 			if err != nil {
@@ -369,7 +370,7 @@ func (sc *snowflakeConn) QueryContext(ctx context.Context, query string, args []
 			resultPath := fmt.Sprintf("/queries/%s/result", child.id)
 			childData, err := sc.getQueryResult(ctx, resultPath)
 			if err != nil {
-				logger.Errorf("error: %v", err)
+				logger.WithContext(ctx).Errorf("error: %v", err)
 				if childData != nil {
 					code, err := strconv.Atoi(childData.Code)
 					if err != nil {
@@ -403,18 +404,18 @@ func (sc *snowflakeConn) Exec(
 	query string,
 	args []driver.Value) (
 	driver.Result, error) {
-	return sc.ExecContext(context.TODO(), query, toNamedValues(args))
+	return sc.ExecContext(sc.ctx, query, toNamedValues(args))
 }
 
 func (sc *snowflakeConn) Query(
 	query string,
 	args []driver.Value) (
 	driver.Rows, error) {
-	return sc.QueryContext(context.TODO(), query, toNamedValues(args))
+	return sc.QueryContext(sc.ctx, query, toNamedValues(args))
 }
 
 func (sc *snowflakeConn) Ping(ctx context.Context) error {
-	logger.Infoln("Ping")
+	logger.WithContext(ctx).Infoln("Ping")
 	if sc.rest == nil {
 		return driver.ErrBadConn
 	}
@@ -435,7 +436,7 @@ func (sc *snowflakeConn) CheckNamedValue(nv *driver.NamedValue) error {
 
 func (sc *snowflakeConn) populateSessionParameters(parameters []nameValueParameter) {
 	// other session parameters (not all)
-	logger.Infof("params: %#v", parameters)
+	logger.WithContext(sc.ctx).Infof("params: %#v", parameters)
 	for _, param := range parameters {
 		v := ""
 		switch param.Value.(type) {
@@ -534,13 +535,13 @@ func (sc *snowflakeConn) getQueryResult(ctx context.Context, resultPath string)
 	url := sc.rest.getFullURL(resultPath, &param)
 	res, err := sc.rest.FuncGet(ctx, sc.rest, url, headers, sc.rest.RequestTimeout)
 	if err != nil {
-		logger.Errorf("failed to get response. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to get response. err: %v", err)
 		return nil, err
 	}
 	var respd *execResponse
 	err = json.NewDecoder(res.Body).Decode(&respd)
 	if err != nil {
-		logger.Errorf("failed to decode JSON. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 		return nil, err
 	}
 	return respd, nil
diff --git a/driver.go b/driver.go
index 155961c..e77f6cd 100644
--- a/driver.go
+++ b/driver.go
@@ -20,8 +20,9 @@ func (d SnowflakeDriver) Open(dsn string) (driver.Conn, error) {
 	var err error
 	sc := &snowflakeConn{
 		SequenceCounter: 0,
+		ctx:             context.TODO(),
 	}
-	ctx := context.TODO()
+
 	sc.cfg, err = ParseDSN(dsn)
 	if err != nil {
 		sc.cleanup()
@@ -69,7 +70,7 @@ func (d SnowflakeDriver) Open(dsn string) (driver.Conn, error) {
 	switch sc.cfg.Authenticator {
 	case AuthTypeExternalBrowser:
 		samlResponse, proofKey, err = authenticateByExternalBrowser(
-			ctx,
+			sc.ctx,
 			sc.rest,
 			sc.cfg.Authenticator.String(),
 			sc.cfg.Application,
@@ -82,7 +83,7 @@ func (d SnowflakeDriver) Open(dsn string) (driver.Conn, error) {
 		}
 	case AuthTypeOkta:
 		samlResponse, err = authenticateBySAML(
-			ctx,
+			sc.ctx,
 			sc.rest,
 			sc.cfg.OktaURL,
 			sc.cfg.Application,
@@ -95,7 +96,7 @@ func (d SnowflakeDriver) Open(dsn string) (driver.Conn, error) {
 		}
 	}
 	authData, err = authenticate(
-		ctx,
+		sc.ctx,
 		sc,
 		samlResponse,
 		proofKey)
@@ -105,21 +106,12 @@ func (d SnowflakeDriver) Open(dsn string) (driver.Conn, error) {
 	}
 
 	sc.populateSessionParameters(authData.Parameters)
+	sc.ctx = context.WithValue(sc.ctx, SFSessionIDKey, authData.SessionID)
 	sc.startHeartBeat()
 	return sc, nil
 }
 
-var logger = DefaultLogger()
-
-// SetLogger set a new logger of SFLogger interface for gosnowflake
-func SetLogger(inLogger SFLogger) {
-	logger = inLogger
-}
-
-// GetLogger return logger that is not public
-func GetLogger() SFLogger {
-	return logger
-}
+var logger = CreateDefaultLogger()
 
 func init() {
 	sql.Register("snowflake", &SnowflakeDriver{})
diff --git a/location.go b/location.go
index 6e90ec6..58c8547 100644
--- a/location.go
+++ b/location.go
@@ -83,7 +83,7 @@ func init() {
 	timezones = make(map[int]*time.Location, 48)
 	// pre-generate all common timezones
 	for i := -720; i <= 720; i += 30 {
-		logger.Infof("offset: %v", i)
+		logger.Debugf("offset: %v", i)
 		timezones[i] = genTimezone(i)
 	}
 }
diff --git a/log.go b/log.go
index 59dfc0f..948610b 100644
--- a/log.go
+++ b/log.go
@@ -1,43 +1,312 @@
 package gosnowflake
 
 import (
+	"context"
 	"fmt"
 	rlog "github.com/sirupsen/logrus"
 	"io"
 	"path"
 	"runtime"
+	"time"
 )
 
-// SFLogger Snowflake logger wrapper interface to expose the same interface as FieldLogger defined in logrus
+//SFSessionIDKey is context key of session id
+const SFSessionIDKey contextKey = "LOG_SESSION_ID"
+
+//SFSessionUserKey is context key of  user id of a session
+const SFSessionUserKey contextKey = "LOG_USER"
+
+//LogKeys these keys in context should be included in logging messages when using logger.WithContext
+var LogKeys = [...]contextKey{SFSessionIDKey, SFSessionUserKey}
+
+//SFLogger Snowflake logger interface to expose FieldLogger defined in logrus
 type SFLogger interface {
-	rlog.FieldLogger
-	SetOutput(output io.Writer)
+	rlog.Ext1FieldLogger
 	SetLogLevel(level string) error
+	WithContext(ctx context.Context) *rlog.Entry
+	SetOutput(output io.Writer)
 }
 
-// SFCallerPrettyfier to provide base file name and function name from calling frame used in SFLogger
+//SFCallerPrettyfier to provide base file name and function name from calling frame used in SFLogger
 func SFCallerPrettyfier(frame *runtime.Frame) (string, string) {
 	return path.Base(frame.Function), fmt.Sprintf("%s:%d", path.Base(frame.File), frame.Line)
 }
 
 type defaultLogger struct {
-	*rlog.Logger
+	inner *rlog.Logger
 }
 
+//SetLogLevel set logging level for calling defaultLogger
 func (log *defaultLogger) SetLogLevel(level string) error {
 	actualLevel, err := rlog.ParseLevel(level)
 	if err != nil {
 		return err
 	}
-	log.Level = actualLevel
+	log.inner.SetLevel(actualLevel)
 	return nil
 }
 
-// DefaultLogger return a new instance of SFLogger with default config
-func DefaultLogger() SFLogger {
+//WithContext return Entry to include fields in context
+func (log *defaultLogger) WithContext(ctx context.Context) *rlog.Entry {
+	fields := context2Fields(ctx)
+	return log.inner.WithFields(*fields)
+}
+
+//CreateDefaultLogger return a new instance of SFLogger with default config
+func CreateDefaultLogger() SFLogger {
 	var rLogger = rlog.New()
 	var formatter = rlog.TextFormatter{CallerPrettyfier: SFCallerPrettyfier}
 	rLogger.SetReportCaller(true)
 	rLogger.SetFormatter(&formatter)
-	return &defaultLogger{Logger: rLogger}
+	var ret = defaultLogger{inner: rLogger}
+	return &ret //(&ret).(*SFLogger)
+}
+
+// WithField allocates a new entry and adds a field to it.
+// Debug, Print, Info, Warn, Error, Fatal or Panic must be then applied to
+// this new returned entry.
+// If you want multiple fields, use `WithFields`.
+func (log *defaultLogger) WithField(key string, value interface{}) *rlog.Entry {
+	return log.inner.WithField(key, value)
+
+}
+
+// Adds a struct of fields to the log entry. All it does is call `WithField` for
+// each `Field`.
+func (log *defaultLogger) WithFields(fields rlog.Fields) *rlog.Entry {
+	return log.inner.WithFields(fields)
+}
+
+// Add an error as single field to the log entry.  All it does is call
+// `WithError` for the given `error`.
+func (log *defaultLogger) WithError(err error) *rlog.Entry {
+	return log.inner.WithError(err)
+}
+
+// Overrides the time of the log entry.
+func (log *defaultLogger) WithTime(t time.Time) *rlog.Entry {
+	return log.inner.WithTime(t)
+}
+
+func (log *defaultLogger) Logf(level rlog.Level, format string, args ...interface{}) {
+	log.inner.Logf(level, format, args...)
+}
+
+func (log *defaultLogger) Tracef(format string, args ...interface{}) {
+	log.inner.Tracef(format, args...)
+}
+
+func (log *defaultLogger) Debugf(format string, args ...interface{}) {
+	log.inner.Debugf(format, args...)
+}
+
+func (log *defaultLogger) Infof(format string, args ...interface{}) {
+	log.inner.Infof(format, args...)
+}
+
+func (log *defaultLogger) Printf(format string, args ...interface{}) {
+	log.inner.Printf(format, args...)
+}
+
+func (log *defaultLogger) Warnf(format string, args ...interface{}) {
+	log.inner.Warnf(format, args...)
+}
+
+func (log *defaultLogger) Warningf(format string, args ...interface{}) {
+	log.inner.Warningf(format, args...)
+}
+
+func (log *defaultLogger) Errorf(format string, args ...interface{}) {
+	log.inner.Errorf(format, args...)
+}
+
+func (log *defaultLogger) Fatalf(format string, args ...interface{}) {
+	log.inner.Fatalf(format, args...)
+}
+
+func (log *defaultLogger) Panicf(format string, args ...interface{}) {
+	log.inner.Panicf(format, args...)
+}
+
+func (log *defaultLogger) Log(level rlog.Level, args ...interface{}) {
+	log.inner.Log(level, args...)
+}
+
+func (log *defaultLogger) LogFn(level rlog.Level, fn rlog.LogFunction) {
+	log.inner.LogFn(level, fn)
+}
+
+func (log *defaultLogger) Trace(args ...interface{}) {
+	log.inner.Trace(args...)
+}
+
+func (log *defaultLogger) Debug(args ...interface{}) {
+	log.inner.Debug(args...)
+}
+
+func (log *defaultLogger) Info(args ...interface{}) {
+	log.inner.Info(args...)
+}
+
+func (log *defaultLogger) Print(args ...interface{}) {
+	log.inner.Print(args...)
+}
+
+func (log *defaultLogger) Warn(args ...interface{}) {
+	log.inner.Warn(args...)
+}
+
+func (log *defaultLogger) Warning(args ...interface{}) {
+	log.inner.Warning(args...)
+}
+
+func (log *defaultLogger) Error(args ...interface{}) {
+	log.inner.Error(args...)
+}
+
+func (log *defaultLogger) Fatal(args ...interface{}) {
+	log.inner.Fatal(args...)
+}
+
+func (log *defaultLogger) Panic(args ...interface{}) {
+	log.inner.Panic(args...)
+}
+
+func (log *defaultLogger) TraceFn(fn rlog.LogFunction) {
+	log.inner.TraceFn(fn)
+}
+
+func (log *defaultLogger) DebugFn(fn rlog.LogFunction) {
+	log.inner.DebugFn(fn)
+}
+
+func (log *defaultLogger) InfoFn(fn rlog.LogFunction) {
+	log.inner.InfoFn(fn)
+}
+
+func (log *defaultLogger) PrintFn(fn rlog.LogFunction) {
+	log.inner.PrintFn(fn)
+}
+
+func (log *defaultLogger) WarnFn(fn rlog.LogFunction) {
+	log.inner.PrintFn(fn)
+}
+
+func (log *defaultLogger) WarningFn(fn rlog.LogFunction) {
+	log.inner.WarningFn(fn)
+}
+
+func (log *defaultLogger) ErrorFn(fn rlog.LogFunction) {
+	log.inner.ErrorFn(fn)
+}
+
+func (log *defaultLogger) FatalFn(fn rlog.LogFunction) {
+	log.inner.FatalFn(fn)
+}
+
+func (log *defaultLogger) PanicFn(fn rlog.LogFunction) {
+	log.inner.PanicFn(fn)
+}
+
+func (log *defaultLogger) Logln(level rlog.Level, args ...interface{}) {
+	log.inner.Logln(level, args...)
+}
+
+func (log *defaultLogger) Traceln(args ...interface{}) {
+	log.inner.Traceln(args...)
+}
+
+func (log *defaultLogger) Debugln(args ...interface{}) {
+	log.inner.Debugln(args...)
+}
+
+func (log *defaultLogger) Infoln(args ...interface{}) {
+	log.inner.Infoln(args...)
+}
+
+func (log *defaultLogger) Println(args ...interface{}) {
+	log.inner.Println(args...)
+}
+
+func (log *defaultLogger) Warnln(args ...interface{}) {
+	log.inner.Warnln(args...)
+}
+
+func (log *defaultLogger) Warningln(args ...interface{}) {
+	log.inner.Warningln(args...)
+}
+
+func (log *defaultLogger) Errorln(args ...interface{}) {
+	log.inner.Errorln(args...)
+}
+
+func (log *defaultLogger) Fatalln(args ...interface{}) {
+	log.inner.Fatalln(args...)
+}
+
+func (log *defaultLogger) Panicln(args ...interface{}) {
+	log.inner.Panicln(args...)
+}
+
+func (log *defaultLogger) Exit(code int) {
+	log.inner.Exit(code)
+}
+
+// SetLevel sets the logger level.
+func (log *defaultLogger) SetLevel(level rlog.Level) {
+	log.inner.SetLevel(level)
+}
+
+// GetLevel returns the logger level.
+func (log *defaultLogger) GetLevel() rlog.Level {
+	return log.inner.GetLevel()
+}
+
+// AddHook adds a hook to the logger hooks.
+func (log *defaultLogger) AddHook(hook rlog.Hook) {
+	log.inner.AddHook(hook)
+
+}
+
+// IsLevelEnabled checks if the log level of the logger is greater than the level param
+func (log *defaultLogger) IsLevelEnabled(level rlog.Level) bool {
+	return log.inner.IsLevelEnabled(level)
+}
+
+// SetFormatter sets the logger formatter.
+func (log *defaultLogger) SetFormatter(formatter rlog.Formatter) {
+	log.inner.SetFormatter(formatter)
+}
+
+// SetOutput sets the logger output.
+func (log *defaultLogger) SetOutput(output io.Writer) {
+	log.inner.SetOutput(output)
+}
+
+func (log *defaultLogger) SetReportCaller(reportCaller bool) {
+	log.inner.SetReportCaller(reportCaller)
+}
+
+// SetLogger set a new logger of SFLogger interface for gosnowflake
+func SetLogger(inLogger *SFLogger) {
+	logger = *inLogger //.(*defaultLogger)
+}
+
+// GetLogger return logger that is not public
+func GetLogger() SFLogger {
+	return logger
+}
+
+func context2Fields(ctx context.Context) *rlog.Fields {
+	var fields = rlog.Fields{}
+	if ctx == nil {
+		return &fields
+	}
+
+	for i := 0; i < len(LogKeys); i++ {
+		if ctx.Value(LogKeys[i]) != nil {
+			fields[string(LogKeys[i])] = ctx.Value(LogKeys[i])
+		}
+	}
+	return &fields
 }
diff --git a/ocsp.go b/ocsp.go
index 76ea2c4..aa150ae 100644
--- a/ocsp.go
+++ b/ocsp.go
@@ -371,14 +371,14 @@ func checkOCSPCacheServer(
 		}
 	}
 	defer res.Body.Close()
-	logger.Infof("StatusCode from OCSP Cache Server: %v\n", res.StatusCode)
+	logger.Debugf("StatusCode from OCSP Cache Server: %v\n", res.StatusCode)
 	if res.StatusCode != http.StatusOK {
 		return nil, &ocspStatus{
 			code: ocspFailedResponse,
 			err:  fmt.Errorf("HTTP code is not OK. %v: %v", res.StatusCode, res.Status),
 		}
 	}
-	logger.Info("reading contents")
+	logger.Debugf("reading contents")
 
 	dec := json.NewDecoder(res.Body)
 	for {
@@ -425,14 +425,14 @@ func retryOCSP(
 		}
 	}
 	defer res.Body.Close()
-	logger.Infof("StatusCode from OCSP Server: %v\n", res.StatusCode)
+	logger.Debugf("StatusCode from OCSP Server: %v\n", res.StatusCode)
 	if res.StatusCode != http.StatusOK {
 		return ocspRes, ocspResBytes, &ocspStatus{
 			code: ocspFailedResponse,
 			err:  fmt.Errorf("HTTP code is not OK. %v: %v", res.StatusCode, res.Status),
 		}
 	}
-	logger.Info("reading contents")
+	logger.Debug("reading contents")
 	ocspResBytes, err = ioutil.ReadAll(res.Body)
 	if err != nil {
 		return ocspRes, ocspResBytes, &ocspStatus{
@@ -440,7 +440,7 @@ func retryOCSP(
 			err:  err,
 		}
 	}
-	logger.Info("parsing OCSP response")
+	logger.Debug("parsing OCSP response")
 	ocspRes, err = ocsp.ParseResponse(ocspResBytes, issuer)
 	if err != nil {
 		return ocspRes, ocspResBytes, &ocspStatus{
diff --git a/restful.go b/restful.go
index d03740d..eae316a 100644
--- a/restful.go
+++ b/restful.go
@@ -182,11 +182,11 @@ func postRestfulQueryHelper(
 	}
 	defer resp.Body.Close()
 	if resp.StatusCode == http.StatusOK {
-		logger.Infof("postQuery: resp: %v", resp)
+		logger.WithContext(ctx).Infof("postQuery: resp: %v", resp)
 		var respd execResponse
 		err = json.NewDecoder(resp.Body).Decode(&respd)
 		if err != nil {
-			logger.Errorf("failed to decode JSON. err: %v", err)
+			logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 			return nil, err
 		}
 		if respd.Code == sessionExpiredCode {
@@ -212,14 +212,14 @@ func postRestfulQueryHelper(
 
 			resp, err = sr.FuncGet(ctx, sr, fullURL, headers, timeout)
 			if err != nil {
-				logger.Errorf("failed to get response. err: %v", err)
+				logger.WithContext(ctx).Errorf("failed to get response. err: %v", err)
 				return nil, err
 			}
 			respd = execResponse{} // reset the response
 			err = json.NewDecoder(resp.Body).Decode(&respd)
 			resp.Body.Close()
 			if err != nil {
-				logger.Errorf("failed to decode JSON. err: %v", err)
+				logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 				return nil, err
 			}
 			if respd.Code == sessionExpiredCode {
@@ -236,11 +236,11 @@ func postRestfulQueryHelper(
 	}
 	b, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
-		logger.Errorf("failed to extract HTTP response body. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to extract HTTP response body. err: %v", err)
 		return nil, err
 	}
-	logger.Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
-	logger.Infof("Header: %v", resp.Header)
+	logger.WithContext(ctx).Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
+	logger.WithContext(ctx).Infof("Header: %v", resp.Header)
 	return nil, &SnowflakeError{
 		Number:      ErrFailedToPostQuery,
 		SQLState:    SQLStateConnectionFailure,
@@ -250,7 +250,7 @@ func postRestfulQueryHelper(
 }
 
 func closeSession(ctx context.Context, sr *snowflakeRestful, timeout time.Duration) error {
-	logger.Info("close session")
+	logger.WithContext(ctx).Info("close session")
 	params := &url.Values{}
 	params.Add("delete", "true")
 	params.Add(requestIDKey, getOrGenerateRequestIDFromContext(ctx))
@@ -272,7 +272,7 @@ func closeSession(ctx context.Context, sr *snowflakeRestful, timeout time.Durati
 		var respd renewSessionResponse
 		err = json.NewDecoder(resp.Body).Decode(&respd)
 		if err != nil {
-			logger.Errorf("failed to decode JSON. err: %v", err)
+			logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 			return err
 		}
 		if !respd.Success && respd.Code != sessionExpiredCode {
@@ -289,11 +289,11 @@ func closeSession(ctx context.Context, sr *snowflakeRestful, timeout time.Durati
 	}
 	b, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
-		logger.Errorf("failed to extract HTTP response body. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to extract HTTP response body. err: %v", err)
 		return err
 	}
-	logger.Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
-	logger.Infof("Header: %v", resp.Header)
+	logger.WithContext(ctx).Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
+	logger.WithContext(ctx).Infof("Header: %v", resp.Header)
 	return &SnowflakeError{
 		Number:      ErrFailedToCloseSession,
 		SQLState:    SQLStateConnectionFailure,
@@ -303,7 +303,7 @@ func closeSession(ctx context.Context, sr *snowflakeRestful, timeout time.Durati
 }
 
 func renewRestfulSession(ctx context.Context, sr *snowflakeRestful, timeout time.Duration) error {
-	logger.Info("start renew session")
+	logger.WithContext(ctx).Info("start renew session")
 	params := &url.Values{}
 	params.Add(requestIDKey, getOrGenerateRequestIDFromContext(ctx))
 	params.Add(requestGUIDKey, uuid.New().String())
@@ -334,7 +334,7 @@ func renewRestfulSession(ctx context.Context, sr *snowflakeRestful, timeout time
 		var respd renewSessionResponse
 		err = json.NewDecoder(resp.Body).Decode(&respd)
 		if err != nil {
-			logger.Errorf("failed to decode JSON. err: %v", err)
+			logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 			return err
 		}
 		if !respd.Success {
@@ -353,11 +353,11 @@ func renewRestfulSession(ctx context.Context, sr *snowflakeRestful, timeout time
 	}
 	b, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
-		logger.Errorf("failed to extract HTTP response body. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to extract HTTP response body. err: %v", err)
 		return err
 	}
-	logger.Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
-	logger.Infof("Header: %v", resp.Header)
+	logger.WithContext(ctx).Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
+	logger.WithContext(ctx).Infof("Header: %v", resp.Header)
 	return &SnowflakeError{
 		Number:      ErrFailedToRenewSession,
 		SQLState:    SQLStateConnectionFailure,
@@ -367,7 +367,7 @@ func renewRestfulSession(ctx context.Context, sr *snowflakeRestful, timeout time
 }
 
 func cancelQuery(ctx context.Context, sr *snowflakeRestful, requestID string, timeout time.Duration) error {
-	logger.Info("cancel query")
+	logger.WithContext(ctx).Info("cancel query")
 	params := &url.Values{}
 	params.Add(requestIDKey, getOrGenerateRequestIDFromContext(ctx))
 	params.Add(requestGUIDKey, uuid.New().String())
@@ -397,7 +397,7 @@ func cancelQuery(ctx context.Context, sr *snowflakeRestful, requestID string, ti
 		var respd cancelQueryResponse
 		err = json.NewDecoder(resp.Body).Decode(&respd)
 		if err != nil {
-			logger.Errorf("failed to decode JSON. err: %v", err)
+			logger.WithContext(ctx).Errorf("failed to decode JSON. err: %v", err)
 			return err
 		}
 		if !respd.Success && respd.Code == sessionExpiredCode {
@@ -421,11 +421,11 @@ func cancelQuery(ctx context.Context, sr *snowflakeRestful, requestID string, ti
 	}
 	b, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
-		logger.Errorf("failed to extract HTTP response body. err: %v", err)
+		logger.WithContext(ctx).Errorf("failed to extract HTTP response body. err: %v", err)
 		return err
 	}
-	logger.Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
-	logger.Infof("Header: %v", resp.Header)
+	logger.WithContext(ctx).Infof("HTTP: %v, URL: %v, Body: %v", resp.StatusCode, fullURL, b)
+	logger.WithContext(ctx).Infof("Header: %v", resp.Header)
 	return &SnowflakeError{
 		Number:      ErrFailedToCancelQuery,
 		SQLState:    SQLStateConnectionFailure,
diff --git a/retry.go b/retry.go
index 69246d3..1c42801 100644
--- a/retry.go
+++ b/retry.go
@@ -210,7 +210,7 @@ func (r *retryHTTP) setBody(body []byte) *retryHTTP {
 
 func (r *retryHTTP) execute() (res *http.Response, err error) {
 	totalTimeout := r.timeout
-	logger.Infof("retryHTTP.totalTimeout: %v", totalTimeout)
+	logger.WithContext(r.ctx).Infof("retryHTTP.totalTimeout: %v", totalTimeout)
 	retryCounter := 0
 	sleepTime := time.Duration(0)
 
@@ -237,7 +237,7 @@ func (r *retryHTTP) execute() (res *http.Response, err error) {
 				return res, err
 			}
 			// cannot just return 4xx and 5xx status as the error can be sporadic. run often helps.
-			logger.Warningf(
+			logger.WithContext(r.ctx).Warningf(
 				"failed http connection. no response is returned. err: %v. retrying...\n", err)
 		} else {
 			if res.StatusCode == http.StatusOK || r.raise4XX && res != nil && res.StatusCode >= 400 && res.StatusCode < 500 {
@@ -247,7 +247,7 @@ func (r *retryHTTP) execute() (res *http.Response, err error) {
 				// This is currently used for Snowflake login. The caller must generate an error object based on HTTP status.
 				break
 			}
-			logger.Warningf(
+			logger.WithContext(r.ctx).Warningf(
 				"failed http connection. HTTP Status: %v. retrying...\n", res.StatusCode)
 			res.Body.Close()
 		}
@@ -255,7 +255,7 @@ func (r *retryHTTP) execute() (res *http.Response, err error) {
 		sleepTime = defaultWaitAlgo.decorr(retryCounter, sleepTime)
 
 		if totalTimeout > 0 {
-			logger.Infof("to timeout: %v", totalTimeout)
+			logger.WithContext(r.ctx).Infof("to timeout: %v", totalTimeout)
 			// if any timeout is set
 			totalTimeout -= sleepTime
 			if totalTimeout <= 0 {
@@ -277,7 +277,7 @@ func (r *retryHTTP) execute() (res *http.Response, err error) {
 			rUpdater = newRetryUpdate(r.fullURL)
 		}
 		r.fullURL = rUpdater.replaceOrAdd(retryCounter)
-		logger.Infof("sleeping %v. to timeout: %v. retrying", sleepTime, totalTimeout)
+		logger.WithContext(r.ctx).Infof("sleeping %v. to timeout: %v. retrying", sleepTime, totalTimeout)
 
 		await := time.NewTimer(sleepTime)
 		select {
diff --git a/rows.go b/rows.go
index bf00ed9..f38e267 100644
--- a/rows.go
+++ b/rows.go
@@ -46,7 +46,7 @@ type snowflakeRows struct {
 }
 
 func (rows *snowflakeRows) Close() (err error) {
-	logger.Infoln("Rows.Close")
+	logger.WithContext(rows.sc.ctx).Debugln("Rows.Close")
 	return nil
 }
 
@@ -239,8 +239,8 @@ func (scd *snowflakeChunkDownloader) start() error {
 	// start downloading chunks if exists
 	chunkMetaLen := len(scd.ChunkMetas)
 	if chunkMetaLen > 0 {
-		logger.Infof("MaxChunkDownloadWorkers: %v", MaxChunkDownloadWorkers)
-		logger.Infof("chunks: %v, total bytes: %d", chunkMetaLen, scd.totalUncompressedSize())
+		logger.Debugf("MaxChunkDownloadWorkers: %v", MaxChunkDownloadWorkers)
+		logger.Debugf("chunks: %v, total bytes: %d", chunkMetaLen, scd.totalUncompressedSize())
 		scd.ChunksMutex = &sync.Mutex{}
 		scd.DoneDownloadCond = sync.NewCond(scd.ChunksMutex)
 		scd.Chunks = make(map[int][]chunkRowType)
@@ -305,7 +305,7 @@ func (scd *snowflakeChunkDownloader) Next() (chunkRowType, error) {
 		}
 
 		for scd.Chunks[scd.CurrentChunkIndex] == nil {
-			logger.Infof("waiting for chunk idx: %v/%v",
+			logger.Debugf("waiting for chunk idx: %v/%v",
 				scd.CurrentChunkIndex+1, len(scd.ChunkMetas))
 
 			err := scd.checkErrorRetry()
@@ -318,7 +318,7 @@ func (scd *snowflakeChunkDownloader) Next() (chunkRowType, error) {
 			// 1) one chunk download finishes or 2) an error occurs.
 			scd.DoneDownloadCond.Wait()
 		}
-		logger.Infof("ready: chunk %v", scd.CurrentChunkIndex+1)
+		logger.Debugf("ready: chunk %v", scd.CurrentChunkIndex+1)
 		scd.CurrentChunk = scd.Chunks[scd.CurrentChunkIndex]
 		scd.ChunksMutex.Unlock()
 		scd.CurrentChunkSize = len(scd.CurrentChunk)
@@ -327,7 +327,7 @@ func (scd *snowflakeChunkDownloader) Next() (chunkRowType, error) {
 		scd.schedule()
 	}
 
-	logger.Infof("no more data")
+	logger.Debugf("no more data")
 	if len(scd.ChunkMetas) > 0 {
 		close(scd.ChunksError)
 		close(scd.ChunksChan)
@@ -398,7 +398,7 @@ func downloadChunk(ctx context.Context, scd *snowflakeChunkDownloader, idx int)
 func downloadChunkHelper(ctx context.Context, scd *snowflakeChunkDownloader, idx int) error {
 	headers := make(map[string]string)
 	if len(scd.ChunkHeader) > 0 {
-		logger.Info("chunk header is provided.")
+		logger.Debug("chunk header is provided.")
 		for k, v := range scd.ChunkHeader {
 			headers[k] = v
 		}
@@ -489,7 +489,7 @@ func decodeChunk(scd *snowflakeChunkDownloader, idx int, bufStream *bufio.Reader
 			return err
 		}
 	}
-	logger.Infof(
+	logger.Debugf(
 		"decoded %d rows w/ %d bytes in %s (chunk %v)",
 		scd.ChunkMetas[idx].RowCount,
 		scd.ChunkMetas[idx].UncompressedSize,
diff --git a/statement.go b/statement.go
index 99c3bdb..224ea6c 100644
--- a/statement.go
+++ b/statement.go
@@ -20,34 +20,34 @@ type snowflakeStmt struct {
 }
 
 func (stmt *snowflakeStmt) Close() error {
-	logger.Infoln("Stmt.Close")
+	logger.WithContext(stmt.sc.ctx).Infoln("Stmt.Close")
 	// noop
 	return nil
 }
 
 func (stmt *snowflakeStmt) NumInput() int {
-	logger.Infoln("Stmt.NumInput")
+	logger.WithContext(stmt.sc.ctx).Infoln("Stmt.NumInput")
 	// Go Snowflake doesn't know the number of binding parameters.
 	return -1
 }
 
 func (stmt *snowflakeStmt) ExecContext(ctx context.Context, args []driver.NamedValue) (driver.Result, error) {
-	logger.Infoln("Stmt.ExecContext")
+	logger.WithContext(stmt.sc.ctx).Infoln("Stmt.ExecContext")
 	return stmt.sc.ExecContext(ctx, stmt.query, args)
 }
 
 func (stmt *snowflakeStmt) QueryContext(ctx context.Context, args []driver.NamedValue) (driver.Rows, error) {
-	logger.Infoln("Stmt.QueryContext")
+	logger.WithContext(stmt.sc.ctx).Infoln("Stmt.QueryContext")
 	return stmt.sc.QueryContext(ctx, stmt.query, args)
 }
 
 func (stmt *snowflakeStmt) Exec(args []driver.Value) (driver.Result, error) {
-	logger.Infoln("Stmt.Exec")
+	logger.WithContext(stmt.sc.ctx).Infoln("Stmt.Exec")
 	return stmt.sc.Exec(stmt.query, args)
 }
 
 func (stmt *snowflakeStmt) Query(args []driver.Value) (driver.Rows, error) {
-	logger.Infoln("Stmt.Query")
+	logger.WithContext(stmt.sc.ctx).Infoln("Stmt.Query")
 	return stmt.sc.Query(stmt.query, args)
 }
 
diff --git a/transaction.go b/transaction.go
index 8fa09f5..298347b 100644
--- a/transaction.go
+++ b/transaction.go
@@ -3,7 +3,6 @@
 package gosnowflake
 
 import (
-	"context"
 	"database/sql/driver"
 )
 
@@ -15,7 +14,7 @@ func (tx *snowflakeTx) Commit() (err error) {
 	if tx.sc == nil || tx.sc.rest == nil {
 		return driver.ErrBadConn
 	}
-	_, err = tx.sc.exec(context.TODO(), "COMMIT", false, false, nil)
+	_, err = tx.sc.exec(tx.sc.ctx, "COMMIT", false, false, nil)
 	if err != nil {
 		return
 	}
@@ -27,7 +26,7 @@ func (tx *snowflakeTx) Rollback() (err error) {
 	if tx.sc == nil || tx.sc.rest == nil {
 		return driver.ErrBadConn
 	}
-	_, err = tx.sc.exec(context.TODO(), "ROLLBACK", false, false, nil)
+	_, err = tx.sc.exec(tx.sc.ctx, "ROLLBACK", false, false, nil)
 	if err != nil {
 		return
 	}


Test patch:
diff --git a/ctx_test.go b/ctx_test.go
new file mode 100644
index 0000000..384a8b1
--- /dev/null
+++ b/ctx_test.go
@@ -0,0 +1,47 @@
+package gosnowflake
+
+import (
+	"context"
+	"fmt"
+	"testing"
+)
+
+func TestCtxVal(t *testing.T) {
+	type favContextKey string
+
+	f := func(ctx context.Context, k favContextKey) {
+		if v := ctx.Value(k); v != nil {
+			fmt.Println("found value:", v)
+			return
+		}
+		fmt.Println("key not found:", k)
+	}
+
+	k := favContextKey("language")
+	ctx := context.WithValue(context.Background(), k, "Go")
+
+	k2 := favContextKey("data")
+	ctx2 := context.WithValue(ctx, k2, "Snowflake")
+	f(ctx, k)
+	f(ctx, favContextKey("color"))
+
+	f(ctx2, k)
+	f(ctx2, k2)
+}
+
+func TestLogEntryCtx(t *testing.T) {
+	var log = logger
+	var ctx1 = context.WithValue(context.TODO(), SFSessionIDKey, "sessID1")
+	var ctx2 = context.WithValue(context.TODO(), SFSessionUserKey, "admin")
+
+	fs1 := context2Fields(ctx1)
+	fs2 := context2Fields(ctx2)
+	l1 := log.WithFields(*fs1)
+	l2 := log.WithFields(*fs2)
+	l1.Info("Hello 1")
+	l2.Warning("Hello 2")
+
+	//log.WithContext(ctx).Info("new log text 1")
+	//log.WithContext(ctx2).Info("new log text 2")
+
+}