Log output review

[phuonghuynh]

Sample log messages for one SQS like bellow, INFO level is enabled by default
Which log entries are redundant?

Aug 10, 2017 12:27:59 PM [log] 
INFO: [c.r.j.p.a.SQSTrigger][thread-0000B1] [job-testjenkins-pipeline] Parse and do match against events, message: {
  "Type" : "Notification",
  "MessageId" : "179b21d9-b49d-5d3d-9d22-73dc458228b2",
  "TopicArn" : "arn:aws:sns:us-west-2:239062223385:testjenkins-topic",
  "Subject" : "UPDATE: AWS CodeCommit us-west-2 push: testjenkins2",
  "Message" : "{\"Records\":[{\"awsRegion\":\"us-west-2\",\"codecommit\":{\"references\":[{\"commit\":\"95a0dc394aa840c441d0734fb6f0307e42ebebec\",\"ref\":\"refs/heads/master\"}]},\"eventId\":\"c0646674-cd6a-4095-baea-5888c6a4d829\",\"eventName\":\"ReferenceChanges\",\"eventPartNumber\":1,\"eventSource\":\"aws:codecommit\",\"eventSourceARN\":\"arn:aws:codecommit:us-west-2:239062223385:testjenkins2\",\"eventTime\":\"2017-08-10T05:27:59.217+0000\",\"eventTotalParts\":1,\"eventTriggerConfigId\":\"98c0360d-86ef-495d-a91b-21f6f5294ff7\",\"eventTriggerName\":\"All\",\"eventVersion\":\"1.0\",\"userIdentityARN\":\"arn:aws:iam::239062223385:user/ext-phuong-huynh\"}]}",
  "Timestamp" : "2017-08-10T05:27:59.274Z",
  "SignatureVersion" : "1",
  "Signature" : "DzYsyV6BHaQZei0jJzrCMq4zwAWIjbY3x7qGSSzEm+UiRItMR+fw3nOxkIyvj4zOUyD3HRrydz2SA1DGaOvAoyQKtF3xwEBD/S8QZe/ZcgQ0zkcoNNBOevzRHCPVNCqqcq9XADHys0whrOr7Vl78Pt/hqMd4XxsGP9UFj/GK5TgiQ0BYU6pF21ylsBl7b6k9Sk2k7BKhRVYb33rTY9MGQzZrJmTmrW3ysWUiDvpHz2yvA/l3adATOzboyn+Kxltepn40Yn4HE7ic7/JhaMyhaxIMnuUUhsINbLX6oe5QM6hXL9QlPouIm1mR89DH7i0dDMvm0qMGZlTxnzHFCMSOvw==",
  "SigningCertURL" : "https://sns.us-west-2.amazonaws.com/SimpleNotificationService-b95095beb82e8f6a046b3aafc7f4149a.pem",
  "UnsubscribeURL" : "https://sns.us-west-2.amazonaws.com/?Action=Unsubscribe&SubscriptionArn=arn:aws:sns:us-west-2:239062223385:testjenkins-topic:cbae7177-c37e-411e-a5e8-ee9a4b871ff8"
}
Aug 10, 2017 12:27:59 PM [log] 
INFO: [c.r.j.p.a.m.i.ScmJobEventTriggerMatcher][thread-0000B1] [job-testjenkins-pipeline] Hurray! Event arn:aws:codecommit:us-west-2:239062223385:testjenkins2 matched SCM git https://git-codecommit.us-west-2.amazonaws.com/v1/repos/testjenkins2
Aug 10, 2017 12:27:59 PM [log] 
INFO: [c.r.j.p.a.m.i.SubscribeBranchEventTriggerMatcher][thread-0000B1] [job-testjenkins-pipeline] Hurray! Event arn:aws:codecommit:us-west-2:239062223385:testjenkins2 matched branch master
Aug 10, 2017 12:27:59 PM [log] 
INFO: [c.r.j.p.a.m.AndEventTriggerMatcher][thread-0000B1] OK! At least one event matched
Aug 10, 2017 12:27:59 PM [log] 
INFO: [c.r.j.p.a.m.EventTriggerMatcherImpl][thread-0000B1] [job-testjenkins-pipeline] Finally, events match status is true
Aug 10, 2017 12:27:59 PM [log] 
INFO: [c.r.j.p.a.SQSTrigger][thread-0000B1] [job-testjenkins-pipeline] Hurray! Execute it
Aug 10, 2017 12:27:59 PM [log] 
INFO: Try to trigger the build for message: 179b21d9-b49d-5d3d-9d22-73dc458228b2
Aug 10, 2017 12:28:00 PM [log] 
INFO: [c.r.j.p.a.n.SQSChannelImpl][thread-0000B1] Delete 1 message(s) (0 failed) from https://sqs.us-west-2.amazonaws.com/239062223385/testjenkinssqs
Aug 10, 2017 12:28:02 PM [log] 
INFO: Any code changes found in SCM? true
Aug 10, 2017 12:28:02 PM [log] 
INFO: Finally! The build is scheduled? true

[ronaldtse]

Some log entires should be shown only once per message, and some per-repo for matching:

Only show once per message in the beginning (not per repo):

Aug 10, 2017 12:27:59 PM [log]
INFO: [c.r.j.p.a.SQSTrigger][thread-0000B1] [job-testjenkins-pipeline] Parse and do match against events, message: {
"Type" : "Notification",
"MessageId" : "179b21d9-b49d-5d3d-9d22-73dc458228b2",
"TopicArn" : "arn:aws:sns:us-west-2:239062223385:testjenkins-topic",
"Subject" : "UPDATE: AWS CodeCommit us-west-2 push: testjenkins2",
"Message" : "{"Records":[{"awsRegion":"us-west-2","codecommit":{"references":[{"commit":"95a0dc394aa840c441d0734fb6f0307e42ebebec","ref":"refs/heads/master"}]},"eventId":"c0646674-cd6a-4095-baea-5888c6a4d829","eventName":"ReferenceChanges","eventPartNumber":1,"eventSource":"aws:codecommit","eventSourceARN":"arn:aws:codecommit:us-west-2:239062223385:testjenkins2","eventTime":"2017-08-10T05:27:59.217+0000","eventTotalParts":1,"eventTriggerConfigId":"98c0360d-86ef-495d-a91b-21f6f5294ff7","eventTriggerName":"All","eventVersion":"1.0","userIdentityARN":"arn:aws:iam::239062223385:user/ext-phuong-huynh"}]}",
"Timestamp" : "2017-08-10T05:27:59.274Z",
"SignatureVersion" : "1",
"Signature" : "DzYsyV6BHaQZei0jJzrCMq4zwAWIjbY3x7qGSSzEm+UiRItMR+fw3nOxkIyvj4zOUyD3HRrydz2SA1DGaOvAoyQKtF3xwEBD/S8QZe/ZcgQ0zkcoNNBOevzRHCPVNCqqcq9XADHys0whrOr7Vl78Pt/hqMd4XxsGP9UFj/GK5TgiQ0BYU6pF21ylsBl7b6k9Sk2k7BKhRVYb33rTY9MGQzZrJmTmrW3ysWUiDvpHz2yvA/l3adATOzboyn+Kxltepn40Yn4HE7ic7/JhaMyhaxIMnuUUhsINbLX6oe5QM6hXL9QlPouIm1mR89DH7i0dDMvm0qMGZlTxnzHFCMSOvw==",
"SigningCertURL" : "https://sns.us-west-2.amazonaws.com/SimpleNotificationService-b95095beb82e8f6a046b3aafc7f4149a.pem",
"UnsubscribeURL" : "https://sns.us-west-2.amazonaws.com/?Action=Unsubscribe&SubscriptionArn=arn:aws:sns:us-west-2:239062223385:testjenkins-topic:cbae7177-c37e-411e-a5e8-ee9a4b871ff8"
}

Per repo:

Aug 10, 2017 12:27:59 PM [log]
INFO: [c.r.j.p.a.m.i.ScmJobEventTriggerMatcher][thread-0000B1] [job-testjenkins-pipeline] Hurray! Event arn:aws:codecommit:us-west-2:239062223385:testjenkins2 matched SCM git https://git-codecommit.us-west-2.amazonaws.com/v1/repos/testjenkins2

Per repo:

Aug 10, 2017 12:27:59 PM [log]
INFO: [c.r.j.p.a.m.i.SubscribeBranchEventTriggerMatcher][thread-0000B1] [job-testjenkins-pipeline] Hurray! Event arn:aws:codecommit:us-west-2:239062223385:testjenkins2 matched branch master

Per repo:

Aug 10, 2017 12:27:59 PM [log]
INFO: [c.r.j.p.a.m.AndEventTriggerMatcher][thread-0000B1] OK! At least one event matched

Do we need this?

Aug 10, 2017 12:27:59 PM [log]
INFO: [c.r.j.p.a.m.EventTriggerMatcherImpl][thread-0000B1] [job-testjenkins-pipeline] Finally, events match status is true

Once per triggered repo:
Aug 10, 2017 12:27:59 PM [log]
INFO: [c.r.j.p.a.SQSTrigger][thread-0000B1] [job-testjenkins-pipeline] Hurray! Execute it

Once per triggered repo:

Aug 10, 2017 12:27:59 PM [log]
INFO: Try to trigger the build for message: 179b21d9-b49d-5d3d-9d22-73dc458228b2

Once per message:
Aug 10, 2017 12:28:00 PM [log]

INFO: [c.r.j.p.a.n.SQSChannelImpl][thread-0000B1] Delete 1 message(s) (0 failed) from https://sqs.us-west-2.amazonaws.com/239062223385/testjenkinssqs

Per triggered repo:

Aug 10, 2017 12:28:02 PM [log]
INFO: Any code changes found in SCM? true

Per repo to build:

Aug 10, 2017 12:28:02 PM [log]
INFO: Finally! The build is scheduled? true

[ronaldtse]

In case of failure, this message is shown, but should not be shown:

[c.r.j.p.a.SQSTrigger][thread-000093] [job-indigo-app-wiki-44] Parse and do match against events, message: {
"Type" : "Notification",
"MessageId" : "47653dec-7b46-583e-9846-6fe9a5c7d646",
...

[phuonghuynh]

In case of failure, this message is shown, but should not be shown:

@ronaldtse we should show message body for failure case?

[ronaldtse]

As long as we have shown the full SNS message once, it is good enough -- we don't need to show the same message for every single job, right?