Update logging to print json as per mint log format #812

nitisht · 2017-09-07T13:53:49Z

ebozduman · 2017-09-07T22:34:29Z

functional_tests.go

-	if err = c.MakeBucket(bucketName, "eu-central-1"); err == nil {
-		logger().Fatal("Error: make bucket should should fail for", bucketName)
+	if err = c.MakeBucket(bucketName, region); err == nil {
+		failureLog(function, args, startTime, "", "Same bucket created twice", err).Fatal()


"Same bucket created twice" message sounds like as if the bucket is successfully created twice.
I think the message should simply say "Bucket already exists!"

ebozduman · 2017-09-07T23:02:20Z

functional_tests.go

@@ -283,57 +367,70 @@ func testPutObjectReadAt() {



args["reader"] needs to be populated with reader value, since reader is one of the parameters for PutObject function.

ebozduman · 2017-09-07T23:03:20Z

functional_tests.go

@@ -283,57 +367,70 @@ func testPutObjectReadAt() {

 	// Save the data
 	objectName := randString(60, rand.NewSource(time.Now().UnixNano()), "")
+	args["objectName"] = objectName
+
 	// Object content type
 	objectContentType := "binary/octet-stream"



args["objectContentType"] needs to be populated with objectContentType value, since objectContentType is one of the parameters for PutObject function.

ebozduman · 2017-09-07T23:15:36Z

functional_tests.go

 	}
 	if st.Size != int64(sixtyFiveMiB) {
-		logger().Fatalf("Error: number of bytes in stat does not match, want %v, got %v\n",
-			sixtyFiveMiB, st.Size)
+		failureLog(function, args, startTime, "", "Number of bytes returned by PutObject does not match, want "+string(sixtyFiveMiB)+" got "+string(st.Size), err).Fatal()


"Number of bytes returned by PutObject does not match, want ... => "Number of bytes returned by PutObject does not match GetObject. Expected ...

ebozduman · 2017-09-07T23:19:38Z

functional_tests.go

 	}
 	if st.ContentType != customContentType {
-		logger().Fatalf("Error: Expected and found content types do not match, want %v, got %v\n",
-			customContentType, st.ContentType)
+		failureLog(function, args, startTime, "", "ContentType does not match, want "+customContentType+" got "+st.ContentType, err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-07T23:30:27Z

functional_tests.go

 	}
 	if err := r.Close(); err == nil {
-		logger().Fatal("Error: object is already closed, should return error")
+		failureLog(function, args, startTime, "", "Object already closed, should respond with error", err).Fatal()


err here is nil. So, there is no point of printing it in the failure log.
failureLog(function, args, startTime, "", "Object already closed, should respond with error"~~, err~~).Fatal()

This comment has not been an answered yet.

ebozduman · 2017-09-08T00:30:31Z

functional_tests.go

 	_, err = c.PutObject(bucketName, objectName, reader, "application/octet-stream")
 	if err == nil {
-		logger().Fatal("Error: PutObject should fail.")
+		failureLog(function, args, startTime, "", "PutObject should fail", err).Fatal()


err is nil. No point in logging it in.
failureLog(function, args, startTime, "", "PutObject should fail"~~, err~~).Fatal()

This comment has not been answered yet.

ebozduman · 2017-09-08T00:33:33Z

functional_tests.go

 	}
 	if !strings.Contains(err.Error(), "proactively closed to be verified later") {
-		logger().Fatal("Error:", err)
+		failureLog(function, args, startTime, "", "Error string not found in PutObject output", err).Fatal()


No need to say Error. It is fatal log and it is obvious that there is a problem:
failureLog(function, args, startTime, "", "~~Error s~~String not found in PutObject output", err).Fatal()

ebozduman · 2017-09-08T00:45:15Z

functional_tests.go

-	logger().Info()
+	// initialize logging params
+	startTime := time.Now()
+	function := "PutObject(bucketName, objectName, reader, contentType)"


We test ListPartiallyUploaded functionality here. So, the function should be set to ListIncompleteUploads(bucketName, objectName, isRecursive, doneCh)

ebozduman · 2017-09-08T01:00:22Z

functional_tests.go

 	}
 	if st.Size != int64(bufSize) {
-		logger().Fatalf("Error: number of bytes in stat does not match, want %v, got %v\n",
-			bufSize, st.Size)
+		failureLog(function, args, startTime, "", "Number of bytes read does not match, want "+string(int64(bufSize))+" got "+string(st.Size), err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-08T01:10:43Z

functional_tests.go

 	}

 	st, err := r.Stat()
 	if err != nil {
-		logger().Fatal("Error:", err, bucketName, objectName)
+		failureLog(function, args, startTime, "", "GetObject failed", err).Fatal()


"GetObject failed" => "Stat failed"

ebozduman · 2017-09-08T03:00:57Z

functional_tests.go

 	}
 	if st.Size != int64(bufSize) {
-		logger().Fatalf("Error: number of bytes in stat does not match, want %v, got %v\n",
-			bufSize, st.Size)
+		failureLog(function, args, startTime, "", "Number of bytes in stat does not match, want "+string(int64(bufSize))+", got "+string(st.Size), err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-08T03:01:13Z

functional_tests.go

 	}
 	if m != len(buf2) {
-		logger().Fatalf("Error: ReadAt read shorter bytes before reaching EOF, want %v, got %v\n", m, len(buf2))
+		failureLog(function, args, startTime, "", "ReadAt read shorter bytes before reaching EOF, want "+string(len(buf2))+", got "+string(m), err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-08T03:04:38Z

functional_tests.go

 	}
 	if m != len(buf3) {
-		logger().Fatalf("Error: ReadAt read shorter bytes before reaching EOF, want %v, got %v\n", m, len(buf3))
+		failureLog(function, args, startTime, "", "ReadAt read shorter bytes before reaching EOF, want "+string(len(buf3))+", got "+string(m), err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-08T03:04:51Z

functional_tests.go

 	}
 	if m != len(buf4) {
-		logger().Fatalf("Error: ReadAt read shorter bytes before reaching EOF, want %v, got %v\n", m, len(buf4))
+		failureLog(function, args, startTime, "", "ReadAt read shorter bytes before reaching EOF, want "+string(len(buf4))+", got "+string(m), err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-08T03:05:02Z

functional_tests.go

 		}
 	}
 	if m != len(buf5) {
-		logger().Fatalf("Error: ReadAt read shorter bytes before reaching EOF, want %v, got %v\n", m, len(buf5))
+		failureLog(function, args, startTime, "", "ReadAt read shorter bytes before reaching EOF, want "+string(len(buf5))+", got "+string(m), err).Fatal()


... match, want ... => ... match. Expected ...

ebozduman · 2017-09-08T19:17:47Z

functional_tests.go

 	}

 	policy := minio.NewPostPolicy()

 	if err := policy.SetBucket(""); err == nil {
-		logger().Fatalf("Error: %s", err)
+		failureLog(function, args, startTime, "", "SetBucket failed", err).Fatal()


The error message is wrong. SetBucket is supposed to fail, but it did not return with an error message. So, this is a negative testing and "SetBucket failed" message here is misleading. The failureLog is supposed to be something like:
failureLog(function, args, startTime, "", "SetBucket did not fail for invalid bucket name").Fatal()

The same comment is also valid for the following line numbers:
1714, 1717, 1720, 1723, 1726, 1832, 1836, 1840, 1844, 1849, 1907, 2687, 2944, 3723, 3727, 3731, 3735, and 3797

ebozduman · 2017-09-08T19:24:34Z

functional_tests.go

 	}
 	if err = c.MakeBucket(bucketName, "eu-west-1"); err == nil {
-		logger().Fatal("Error: make bucket should should fail for", bucketName)
+		failureLog(function, args, startTime, "", "Make bucket should should fail", err).Fatal()


Typo:
should should => should
But it is better to modify the error message since this is negative testing, probably like:
failureLog(function, args, startTime, "", "Bucket already exists").Fatal()

ebozduman · 2017-09-08T21:06:42Z

functional_tests.go

 	}
 	if err := r.Close(); err == nil {
-		logger().Fatal("Error: object is already closed, should return error")
+		failureLog(function, args, startTime, "", "Object is already closed, should return error", err).Fatal()


No point of logging nill error message, err:
failureLog(function, args, startTime, "", "Object is already closed, should return error"~~, err~~).Fatal()

ebozduman · 2017-09-08T21:08:02Z

functional_tests.go

 	_, err = c.PutObject(bucketName, objectName, reader, "application/octet-stream")
 	if err == nil {
-		logger().Fatal("Error: PutObject should fail.")
+		failureLog(function, args, startTime, "", "PutObject should fail", err).Fatal()


No point of logging nill error message, err:
failureLog(function, args, startTime, "", "PutObject should fail"~~, err~~).Fatal()

ebozduman · 2017-09-08T21:10:33Z

functional_tests.go

 	}
 	_, err = r.Seek(offset, 2)
 	if err == nil {
-		logger().Fatal("Error: seek on positive offset for whence '2' should error out")
+		failureLog(function, args, startTime, "", "Seek on positive offset for whence '2' should error out", err).Fatal()


No point of logging nill error message, err:
failureLog(function, args, startTime, "", "Seek on positive offset for whence '2' should error out"~~, err~~).Fatal()

ebozduman · 2017-09-08T21:14:14Z

functional_tests.go

 	}

 	if err := c.ComposeObject(dst, srcSlice); err == nil {
-		logger().Fatal("Error was expected.")
+		failureLog(function, args, startTime, "", "Expected error in ComposeObject", err).Fatal()


No point of logging nill error message, err:
failureLog(function, args, startTime, "", "Expected error in ComposeObject"~~, err~~).Fatal()

ebozduman · 2017-09-08T21:14:58Z

functional_tests.go

 	}
 	// 3. ComposeObject call should fail.
 	if err := c.ComposeObject(dst, []minio.SourceInfo{badSrc}); err == nil {
-		logger().Fatal("Error was expected.")
+		failureLog(function, args, startTime, "", "ComposeObject expected to fail", err).Fatal()


No point of logging nill error message, err:
failureLog(function, args, startTime, "", "ComposeObject expected to fail"~~, err~~).Fatal()

ebozduman · 2017-09-08T21:15:38Z

functional_tests.go

 	}
 	err = c.RemoveBucket(bucketName)
 	if err == nil {
-		logger().Fatal("Error:")
+		failureLog(function, args, startTime, "", "RemoveBucket should fail as bucket does not exist", err).Fatal()


No point of logging nill error message, err:
failureLog(function, args, startTime, "", "RemoveBucket should fail as bucket does not exist"~~, err~~).Fatal()

ebozduman · 2017-09-08T21:21:48Z

functional_tests.go

 	}
 	if err := r.Close(); err == nil {
-		logger().Fatal("Error: object is already closed, should return error")
+		failureLog(function, args, startTime, "", "Already closed object. No error returned", err).Fatal()


err is nil. No point in logging it in.
failureLog(function, args, startTime, "", "Supposed to error out for the already closed object"~~, err~~).Fatal()

This comment has not been answered yet.

ebozduman · 2017-09-08T21:23:47Z

functional_tests.go

 	_, err = c.PutObject(bucketName, objectName, reader, "application/octet-stream")
 	if err == nil {
-		logger().Fatal("Error: PutObject should fail.")
+		failureLog(function, args, startTime, "", "PutObject should fail", err).Fatal()


err is nil. No point in logging it in.
failureLog(function, args, startTime, "", "PutObject was supposed to fail"~~, err~~).Fatal()

This comment has not been answered yet.

nitisht · 2017-09-09T08:21:53Z

@ebozduman updated the PR with correct error messages for negative test cases. For cases related to your comment

No point of logging nill error message, err:
failureLog(function, args, startTime, "", "RemoveBucket should fail as bucket does not exist", err).Fatal()

I have updated the logging function to not log error if its nil. Ref:
https://github.com/minio/minio-go/pull/812/files#diff-2b25d2aeef5dac13377316ffcd8ce169R102

ebozduman · 2017-09-12T16:22:02Z

functional_tests.go

 	}
 	if err := r.Close(); err == nil {
-		logger().Fatal("Error: object is already closed, should return error")
+		failureLog(function, args, startTime, "", "Object already closed, should respond with error", err).Fatal()


This comment has not been an answered yet.

ebozduman · 2017-09-12T16:24:45Z

functional_tests.go

 	_, err = c.PutObject(bucketName, objectName, reader, "application/octet-stream")
 	if err == nil {
-		logger().Fatal("Error: PutObject should fail.")
+		failureLog(function, args, startTime, "", "PutObject should fail", err).Fatal()


This comment has not been answered yet.

ebozduman · 2017-09-12T16:26:28Z

functional_tests.go

 	}
 	if err := r.Close(); err == nil {
-		logger().Fatal("Error: object is already closed, should return error")
+		failureLog(function, args, startTime, "", "Already closed object. No error returned", err).Fatal()


This comment has not been answered yet.

ebozduman · 2017-09-12T16:27:22Z

functional_tests.go

 	_, err = c.PutObject(bucketName, objectName, reader, "application/octet-stream")
 	if err == nil {
-		logger().Fatal("Error: PutObject should fail.")
+		failureLog(function, args, startTime, "", "PutObject should fail", err).Fatal()


This comment has not been answered yet.

ebozduman · 2017-09-12T16:36:10Z

functional_tests.go

 	}

 	policy := minio.NewPostPolicy()

 	if err := policy.SetBucket(""); err == nil {
-		logger().Fatalf("Error: %s", err)
+		failureLog(function, args, startTime, "", "SetBucket did not fail for invalid conditions", err).Fatal()


How about these negative tests between lines 1711~1723?
The same err == nil comment also applies here.

nitisht and others added 2 commits September 7, 2017 19:15

Update logging to print json as per mint log format

c28dec4

Fixes minio#779

Merge branch 'master' into mint-json

f6d4e10

nitisht requested review from harshavardhana and ebozduman September 7, 2017 13:56

ebozduman requested changes Sep 7, 2017

View reviewed changes

ebozduman requested changes Sep 8, 2017

View reviewed changes

nitisht and others added 6 commits September 8, 2017 13:06

Fix error messages for logs and update args for API calls

3816567

Fix error messages for logging

44866ea

Remove nil error reports from logging

208474b

Merge branch 'master' into mint-json

82a5bd8

Fix build failure

7d14ebe

Fix build failure

41ce9b1

ebozduman requested changes Sep 8, 2017

View reviewed changes

Update megative case error messages to indicate correct problem

310b053

nitisht mentioned this pull request Sep 12, 2017

[mint-json] Release minio-go with json changes minio/mint#131

Closed

ebozduman requested changes Sep 12, 2017

View reviewed changes

ebozduman approved these changes Sep 12, 2017

View reviewed changes

harshavardhana approved these changes Sep 12, 2017

View reviewed changes

deekoder merged commit a0478d7 into minio:master Sep 12, 2017

nitisht mentioned this pull request Sep 14, 2017

Update minio-go to output new mint log format #779

Closed

Update logging to print json as per mint log format #812

Update logging to print json as per mint log format #812

Conversation

nitisht commented Sep 7, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ebozduman Sep 7, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

nitisht commented Sep 9, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ebozduman Sep 7, 2017 •

edited

Loading