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

Debug log with concatenated string #128

Merged
merged 1 commit into from
Feb 23, 2018
Merged
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
44 changes: 22 additions & 22 deletions middleware.go
Original file line number Diff line number Diff line change
Expand Up @@ -201,18 +201,18 @@ func addCredentials(c *Client, r *Request) error {
func requestLogger(c *Client, r *Request) error {
if c.Debug {
rr := r.RawRequest
c.Log.Println()
c.disableLogPrefix()
c.Log.Println("---------------------- REQUEST LOG -----------------------")
c.Log.Printf("%s %s %s\n", r.Method, rr.URL.RequestURI(), rr.Proto)
c.Log.Printf("HOST : %s", rr.URL.Host)
c.Log.Println("HEADERS:")
reqLog := "\n---------------------- REQUEST LOG -----------------------\n" +
fmt.Sprintf("%s %s %s\n", r.Method, rr.URL.RequestURI(), rr.Proto) +
fmt.Sprintf("HOST : %s\n", rr.URL.Host) +
fmt.Sprintf("HEADERS:\n")

for h, v := range rr.Header {
c.Log.Printf("%25s: %v", h, strings.Join(v, ", "))
reqLog += fmt.Sprintf("%25s: %v\n", h, strings.Join(v, ", "))
}
c.Log.Printf("BODY :\n%v", r.fmtBodyString())
c.Log.Println("----------------------------------------------------------")
c.enableLogPrefix()
reqLog += fmt.Sprintf("BODY :\n%v\n", r.fmtBodyString()) +
"----------------------------------------------------------\n"

c.Log.Print(reqLog)
Copy link
Member

Choose a reason for hiding this comment

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

@sudo-suhas Please update your code to

c.disableLogPrefix()
c.Log.Print(reqLog)
c.enableLogPrefix()

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Could you tell me why you are requesting this change? The output seems correct with the current state from what I can tell. If I do the suggested change, because of concurrent execution, sometimes the prefix is present even though we disabled in the previous line:

debug logs
λ go run concurrent_resty.go

---------------------- REQUEST LOG -----------------------
GET  /posts/5  HTTP/1.1
HOST   : jsonplaceholder.typicode.com
HEADERS:
                   Accept: application/json; charset=utf-8
             Content-Type: application/json; charset=utf-8
               User-Agent: go-resty v1.2 - https://github.com/go-resty/resty
BODY   :
***** NO CONTENT *****
----------------------------------------------------------
RESTY 2018/02/23 08:50:24
---------------------- REQUEST LOG -----------------------
GET  /posts/3  HTTP/1.1
HOST   : jsonplaceholder.typicode.com
HEADERS:
                   Accept: application/json; charset=utf-8
             Content-Type: application/json; charset=utf-8
               User-Agent: go-resty v1.2 - https://github.com/go-resty/resty
BODY   :
***** NO CONTENT *****
----------------------------------------------------------
RESTY 2018/02/23 08:50:24
---------------------- REQUEST LOG -----------------------
GET  /posts/2  HTTP/1.1
HOST   : jsonplaceholder.typicode.com
HEADERS:
             Content-Type: application/json; charset=utf-8
               User-Agent: go-resty v1.2 - https://github.com/go-resty/resty
                   Accept: application/json; charset=utf-8
BODY   :
***** NO CONTENT *****
----------------------------------------------------------
RESTY 2018/02/23 08:50:24
---------------------- REQUEST LOG -----------------------
GET  /posts/4  HTTP/1.1
HOST   : jsonplaceholder.typicode.com
HEADERS:
               User-Agent: go-resty v1.2 - https://github.com/go-resty/resty
                   Accept: application/json; charset=utf-8
             Content-Type: application/json; charset=utf-8
BODY   :
***** NO CONTENT *****
----------------------------------------------------------

---------------------- REQUEST LOG -----------------------
GET  /posts/1  HTTP/1.1
HOST   : jsonplaceholder.typicode.com
HEADERS:
                   Accept: application/json; charset=utf-8
             Content-Type: application/json; charset=utf-8
               User-Agent: go-resty v1.2 - https://github.com/go-resty/resty
BODY   :
***** NO CONTENT *****
----------------------------------------------------------

---------------------- RESPONSE LOG -----------------------
STATUS          : 200 OK
RECEIVED AT     : 2018-02-23T08:50:24.247412+05:30
RESPONSE TIME   : 216.1499ms
HEADERS:
                       Expires: Fri, 23 Feb 2018 07:20:23 GMT
                  Content-Type: application/json; charset=utf-8
                  X-Powered-By: Express
                        Pragma: no-cache
                           Via: 1.1 vegur
                        Server: cloudflare
                        Cf-Ray: 3f170c8dbdaf31c2-SIN
                    Set-Cookie: __cfduid=d8df9daebb9cc67d01d2dd80f101254771519356023; expires=Sat, 23-Feb-19 03:20:23 GMT; path=/; domain=.typicode.com; HttpOnly
Access-Control-Allow-Credentials: true
                 Cache-Control: public, max-age=14400
        X-Content-Type-Options: nosniff
                     Expect-Ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
                          Date: Fri, 23 Feb 2018 03:20:23 GMT
                          Vary: Origin, Accept-Encoding
                          Etag: W/"124-yiKdLzqO5gfBrJFrcdJ8Yq0LGnU"
               Cf-Cache-Status: HIT
BODY   :
{
   "userId": 1,
   "id": 1,
   "title": "sunt aut facere repellat provident occaecati excepturi optio reprehenderit",
   "body": "quia et suscipit\nsuscipit recusandae consequuntur expedita et cum\nreprehenderit molestiae ut ut quas totam\nnostrum rerum est autem sunt rem eveniet architecto"
}
----------------------------------------------------------
RESTY 2018/02/23 08:50:24
---------------------- RESPONSE LOG -----------------------
STATUS          : 200 OK
RECEIVED AT     : 2018-02-23T08:50:24.247412+05:30
RESPONSE TIME   : 225.1572ms
HEADERS:
                          Date: Fri, 23 Feb 2018 03:20:23 GMT
               Cf-Cache-Status: HIT
                  X-Powered-By: Express
                 Cache-Control: public, max-age=14400
                        Pragma: no-cache
                          Etag: W/"11b-USacuIw5a/iXAGdNKBvqr/TbMTc"
                     Expect-Ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
                    Set-Cookie: __cfduid=d8df9daebb9cc67d01d2dd80f101254771519356023; expires=Sat, 23-Feb-19 03:20:23 GMT; path=/; domain=.typicode.com; HttpOnly
                          Vary: Origin, Accept-Encoding
Access-Control-Allow-Credentials: true
                           Via: 1.1 vegur
                        Server: cloudflare
                        Cf-Ray: 3f170c8dbdac31c2-SIN
                  Content-Type: application/json; charset=utf-8
                       Expires: Fri, 23 Feb 2018 07:20:23 GMT
        X-Content-Type-Options: nosniff
BODY   :
{
   "userId": 1,
   "id": 3,
   "title": "ea molestias quasi exercitationem repellat qui ipsa sit aut",
   "body": "et iusto sed quo iure\nvoluptatem occaecati omnis eligendi aut ad\nvoluptatem doloribus vel accusantium quis pariatur\nmolestiae porro eius odio et labore et velit aut"
}
----------------------------------------------------------

---------------------- RESPONSE LOG -----------------------
STATUS          : 200 OK
RECEIVED AT     : 2018-02-23T08:50:24.247412+05:30
RESPONSE TIME   : 223.1548ms
HEADERS:
Access-Control-Allow-Credentials: true
                 Cache-Control: public, max-age=14400
                          Vary: Origin, Accept-Encoding
                  X-Powered-By: Express
                        Pragma: no-cache
                          Etag: W/"116-jnDuMpjju89+9j7e0BqkdFsVRjs"
               Cf-Cache-Status: HIT
                     Expect-Ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
                    Set-Cookie: __cfduid=d8df9daebb9cc67d01d2dd80f101254771519356023; expires=Sat, 23-Feb-19 03:20:23 GMT; path=/; domain=.typicode.com; HttpOnly
                        Cf-Ray: 3f170c8dbdb331c2-SIN
                           Via: 1.1 vegur
                  Content-Type: application/json; charset=utf-8
                       Expires: Fri, 23 Feb 2018 07:20:23 GMT
        X-Content-Type-Options: nosniff
                        Server: cloudflare
                          Date: Fri, 23 Feb 2018 03:20:23 GMT
BODY   :
{
   "userId": 1,
   "id": 2,
   "title": "qui est esse",
   "body": "est rerum tempore vitae\nsequi sint nihil reprehenderit dolor beatae ea dolores neque\nfugiat blanditiis voluptate porro vel nihil molestiae ut reiciendis\nqui aperiam non debitis possimus qui neque nisi nulla"
}
----------------------------------------------------------

---------------------- RESPONSE LOG -----------------------
STATUS          : 200 OK
RECEIVED AT     : 2018-02-23T08:50:24.7007314+05:30
RESPONSE TIME   : 671.4715ms
HEADERS:
                  X-Powered-By: Express
Access-Control-Allow-Credentials: true
                        Pragma: no-cache
                          Etag: W/"10e-HqG77o1RAmatkSwR36f4+Io6g1E"
                           Via: 1.1 vegur
               Cf-Cache-Status: REVALIDATED
                     Expect-Ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
                        Server: cloudflare
                          Date: Fri, 23 Feb 2018 03:20:24 GMT
                 Cache-Control: public, max-age=14400
                       Expires: Fri, 23 Feb 2018 07:20:24 GMT
        X-Content-Type-Options: nosniff
                  Content-Type: application/json; charset=utf-8
                    Set-Cookie: __cfduid=d8df9daebb9cc67d01d2dd80f101254771519356023; expires=Sat, 23-Feb-19 03:20:23 GMT; path=/; domain=.typicode.com; HttpOnly
                          Vary: Origin, Accept-Encoding
                        Cf-Ray: 3f170c8dbdb131c2-SIN
BODY   :
{
   "userId": 1,
   "id": 4,
   "title": "eum et est occaecati",
   "body": "ullam et saepe reiciendis voluptatem adipisci\nsit amet autem assumenda provident rerum culpa\nquis hic commodi nesciunt rem tenetur doloremque ipsam iure\nquis sunt voluptatem rerum illo velit"
}
----------------------------------------------------------

---------------------- RESPONSE LOG -----------------------
STATUS          : 200 OK
RECEIVED AT     : 2018-02-23T08:50:24.8098105+05:30
RESPONSE TIME   : 790.564ms
HEADERS:
                          Vary: Origin, Accept-Encoding
Access-Control-Allow-Credentials: true
                           Via: 1.1 vegur
                     Expect-Ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
                  Content-Type: application/json; charset=utf-8
                  X-Powered-By: Express
                        Pragma: no-cache
                        Cf-Ray: 3f170c8dbdad31c2-SIN
                          Date: Fri, 23 Feb 2018 03:20:24 GMT
                    Set-Cookie: __cfduid=d8df9daebb9cc67d01d2dd80f101254771519356023; expires=Sat, 23-Feb-19 03:20:23 GMT; path=/; domain=.typicode.com; HttpOnly
                 Cache-Control: public, max-age=14400
        X-Content-Type-Options: nosniff
                        Server: cloudflare
                       Expires: Fri, 23 Feb 2018 07:20:24 GMT
                          Etag: W/"e1-IivojO0CtPZmcMK0iydTbsfG7Wc"
               Cf-Cache-Status: REVALIDATED
BODY   :
{
   "userId": 1,
   "id": 5,
   "title": "nesciunt quas odio",
   "body": "repudiandae veniam quaerat sunt sed\nalias aut fugiat sit autem sed est\nvoluptatem omnis possimus esse voluptatibus quis\nest aut tenetur dolor neque"
}
----------------------------------------------------------

Copy link
Member

Choose a reason for hiding this comment

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

@sudo-suhas Okay, I see the prefix is printed in some of the log. Thanks for sharing sample log. This change is not needed. I will look into it later on.

}

return nil
Expand All @@ -224,23 +224,23 @@ func requestLogger(c *Client, r *Request) error {

func responseLogger(c *Client, res *Response) error {
if c.Debug {
c.Log.Println()
c.disableLogPrefix()
c.Log.Println("---------------------- RESPONSE LOG -----------------------")
c.Log.Printf("STATUS : %s", res.Status())
c.Log.Printf("RECEIVED AT : %v", res.ReceivedAt().Format(time.RFC3339Nano))
c.Log.Printf("RESPONSE TIME : %v", res.Time())
c.Log.Println("HEADERS:")
resLog := "\n---------------------- RESPONSE LOG -----------------------\n" +
fmt.Sprintf("STATUS : %s\n", res.Status()) +
fmt.Sprintf("RECEIVED AT : %v\n", res.ReceivedAt().Format(time.RFC3339Nano)) +
fmt.Sprintf("RESPONSE TIME : %v\n", res.Time()) +
"HEADERS:\n"

for h, v := range res.Header() {
c.Log.Printf("%30s: %v", h, strings.Join(v, ", "))
resLog += fmt.Sprintf("%30s: %v\n", h, strings.Join(v, ", "))
}
if res.Request.isSaveResponse {
c.Log.Printf("BODY :\n***** RESPONSE WRITTEN INTO FILE *****")
resLog += fmt.Sprintf("BODY :\n***** RESPONSE WRITTEN INTO FILE *****\n")
} else {
c.Log.Printf("BODY :\n%v", res.fmtBodyString(c.debugBodySizeLimit))
resLog += fmt.Sprintf("BODY :\n%v\n", res.fmtBodyString(c.debugBodySizeLimit))
}
c.Log.Println("----------------------------------------------------------")
c.enableLogPrefix()
resLog += "----------------------------------------------------------\n"

c.Log.Print(resLog)
Copy link
Member

Choose a reason for hiding this comment

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

@sudo-suhas Please update your code to

c.disableLogPrefix()
c.Log.Print(resLog)
c.enableLogPrefix()

}

return nil
Expand Down