structured logs and logfile rollover features

[sparrc]

Summary

Addresses part of #2284

1. Removes deprecated seelog "ForModule" loggers
2. Adds ability to have logfiles rollover based on size rather than hourly (both agent and audit logs)
3. Changes the default agent log format to logfmt (agent logs only)
4. Adds support for JSON log format (agent logs only)
5. Updates revision of seelog library to fix bug where the 'current' logfile had a rollover suffix added to it
6. consolidates logging code into fewer .go files

Example logfmt log:

level=info time=2019-12-18T19:50:28Z msg="waiting for event for task" module=task_manager.go taskARN=arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a taskFamily=hello-world-service taskVersion=14
level=info time=2019-12-18T19:50:28Z msg="got container change event [event type: ContainerStatusChangeEvent, event container status: RUNNING, docker ID: 68ae7e2a956c91974ec978dc4fadae9c09268e075ebe4c5410eed7b9c1cc752f] for container [~internal~ecs~pause]" module=task_manager.go taskARN=arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a taskFamily=hello-world-service taskVersion=14
level=info time=2019-12-18T19:50:28Z msg="redundant container state change. ~internal~ecs~pause to RUNNING, but already RESOURCES_PROVISIONED" module=task_manager.go taskARN=arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a taskFamily=hello-world-service taskVersion=14
level=info time=2019-12-18T19:50:28Z msg="task at steady state: RUNNING" module=task_manager.go taskARN=arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a taskFamily=hello-world-service taskVersion=14
level=info time=2019-12-18T19:50:28Z msg="waiting for event for task" module=task_manager.go taskARN=arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a taskFamily=hello-world-service taskVersion=14

Example json log:

{"level": "info", "time": "2019-12-18T01:00:30Z", "msg": "redundant container state change. ~internal~ecs~pause to RUNNING, but already RESOURCES_PROVISIONED", "module": "task_manager.go", "taskARN": "arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a", "taskFamily": "hello-world-service", "taskVersion": "14"}
{"level": "info", "time": "2019-12-18T01:00:30Z", "msg": "task at steady state: RUNNING", "module": "task_manager.go", "taskARN": "arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a", "taskFamily": "hello-world-service", "taskVersion": "14"}
{"level": "info", "time": "2019-12-18T01:00:30Z", "msg": "waiting for event for task", "module": "task_manager.go", "taskFamily": "hello-world-service", "taskVersion": "14", "taskARN": "arn:aws:ecs:us-west-2:039193556298:task/auto-robc/33d755ba06e94b3594ba9c2da95a6f4a"}
{"level": "info", "time": "2019-12-18T01:03:14Z", "msg": "TCS Websocket connection closed for a valid reason", "module": "handler.go"}
{"level": "info", "time": "2019-12-18T01:03:14Z", "msg": "Establishing a Websocket connection to https://ecs-t-1.us-west-2.amazonaws.com/ws?agentHash=a1bdebca&agentVersion=1.34.0&cluster=auto-robc&containerInstance=arn%3Aaws%3Aecs%3Aus-west-2%3A039193556298%3Acontainer-instance%2Fauto-robc%2F3330a8a91d15464ea30662d5840164cd&dockerVersion=18.06.1-ce", "module": "client.go"}
{"level": "info", "time": "2019-12-18T01:03:14Z", "msg": "Connected to TCS endpoint", "module": "handler.go"}
{"level": "info", "time": "2019-12-18T01:05:11Z", "msg": "Saving state!", "module": "state_manager.go"}

Implementation details

We are using seelog's custom formatters to write our own logfmt and json formatters, and then adding configuration variables to switch between these.

Testing

This is being tested as part of a broader logging refactor project.

Description for the changelog

Enhancement - structured logs and logfile rollover features

Licensing

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

[fierlion]

Looks good.

[yumex93]

Can we add a piece of example log file in the pr description? It will be more straightforward for us to know what the log look like now.

[sparrc]

sure!

[yumex93]

Isn't read lock good enough here since we are just reading here?

[sparrc]

yes but I am using just a plain sync.Mutex....a RWMutex seemed like overkill given the low-throughput expectation here

[yumex93]

If the rollover type and output format are not supported, what will happen? Will it fail some time? Or agent may just run with malformat log?

[sparrc]

seelog should fail the create the logger, which means it would fallback to the default seelog logger and log an error

[yumex93]

Any test we can add to double check the log is generated as we expected or maybe unit test to make sure the functions in the file work as expected?

[sparrc]

I can try to write some unit tests for the seelog formatter funcs

[sparrc]

done

[petderek]

When you rebase, can you have the list of logging changes available in the commit message itself?