host-ctr: exposes error level log messages to console

[etungsten]

Issue #, if available: Fixes #477

Description of changes:
Splits logrus logs to different output with LogSplit logrus hook.
Error, fatal, panic levels goes to standard error and all other log levels go to stdout

Testing:

Locally ran host-ctr with an invalid image repository:

$ sudo ./host-ctr -containerd-socket /run/containerd/containerd.sock -pull-image-only -source 328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2 > >(tee -a stdout.log) 2> >(tee -a stderr.log >&2)
time="2019-10-29T15:33:25-07:00" level=warning msg="Failed to pull image. Waiting 4.273s before retrying..." error="failed to resolve reference \"328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2\": failed to do request: Head \"https://328549459982.dkr.ecrus-west-2.amazonaws.com/v2/thar-admin/manifests/0.2\": dial tcp: lookup 328549459982.dkr.ecrus-west-2.amazonaws.com on 127.0.1.1:53: no such host"
SNIP
time="2019-10-29T15:34:16-07:00" level=error msg="retries exhausted: failed to resolve reference \"328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2\": failed to do request: Head \"https://328549459982.dkr.ecrus-west-2.amazonaws.com/v2/thar-admin/manifests/0.2\": dial tcp: lookup 328549459982.dkr.ecrus-west-2.amazonaws.com on 127.0.1.1:53: no such host" ref="328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2"

Then with valid image repository:

$ sudo ./host-ctr -containerd-socket /run/containerd/containerd.sock -pull-image-only -source 328549459982.dkr.ecr.us-west-2.amazonaws.com/thar-admin:v0.2 > >(tee -a stdout.log) 2> >(tee -a stderr.log >&2)
time="2019-10-29T16:06:17-07:00" level=info msg="Pulling with Amazon ECR Resolver" ref="ecr.aws/arn:aws:ecr:us-west-2:328549459982:repository/thar-admin:v0.2"
time="2019-10-29T16:06:20-07:00" level=info msg="Pulled successfully" img="ecr.aws/arn:aws:ecr:us-west-2:328549459982:repository/thar-admin:v0.2"
time="2019-10-29T16:06:20-07:00" level=info msg=Unpacking... img="ecr.aws/arn:aws:ecr:us-west-2:328549459982:repository/thar-admin:v0.2"
time="2019-10-29T16:06:20-07:00" level=info msg="Tagging image" imageName="328549459982.dkr.ecr.us-west-2.amazonaws.com/thar-admin:v0.2"

Verified that errors get written to stderr and everything else to stdout:

$ cat stderr.log 
time="2019-10-29T15:34:16-07:00" level=error msg="retries exhausted: failed to resolve reference \"328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2\": failed to do request: Head \"https://328549459982.dkr.ecrus-west-2.amazonaws.com/v2/thar-admin/manifests/0.2\": dial tcp: lookup 328549459982.dkr.ecrus-west-2.amazonaws.com on 127.0.1.1:53: no such host" ref="328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2"
$ cat stdout.log 
time="2019-10-29T15:33:25-07:00" level=warning msg="Failed to pull image. Waiting 4.273s before retrying..." error="failed to resolve reference \"328549459982.dkr.ecrus-west-2.amazonaws.com/thar-admin:0.2\": failed to do request: Head \"https://328549459982.dkr.ecrus-west-2.amazonaws.com/v2/thar-admin/manifests/0.2\": dial tcp: lookup 328549459982.dkr.ecrus-west-2.amazonaws.com on 127.0.1.1:53: no such host"
SNIP
time="2019-10-29T16:06:17-07:00" level=info msg="Pulling with Amazon ECR Resolver" ref="ecr.aws/arn:aws:ecr:us-west-2:328549459982:repository/thar-admin:v0.2"
time="2019-10-29T16:06:20-07:00" level=info msg="Pulled successfully" img="ecr.aws/arn:aws:ecr:us-west-2:328549459982:repository/thar-admin:v0.2"
time="2019-10-29T16:06:20-07:00" level=info msg=Unpacking... img="ecr.aws/arn:aws:ecr:us-west-2:328549459982:repository/thar-admin:v0.2"
time="2019-10-29T16:06:20-07:00" level=info msg="Tagging image" imageName="328549459982.dkr.ecr.us-west-2.amazonaws.com/thar-admin:v0.2"

On a Thar instance with the following in userdata:

[settings.host-containers.control]
enabled = true
source = "totallyvalidimagerepo.org/foo:bar"

[email protected] outputs error messages to the console:

[   59.623035] host-ctr[2621]: time="2019-10-29T23:19:00Z" level=error msg="retries exhausted: failed to resolve reference \"gibberishadmincontainer.org/foo:bar\": failed to do request: Head https://gibberishadmincontainer.org/v2/foo/manifests/bar: dial tcp: lookup gibberishadmincontainer.org on 192.168.0.2:53: no such host" ref="gibberishadmincontainer.org/foo:bar"
[   60.681191] host-ctr[2672]: time="2019-10-29T23:19:01Z" level=error msg="retries exhausted: failed to resolve reference \"totallyvalidimagerepo.org/foo:bar\": failed to do request: Head https://totallyvalidimagerepo.org/v2/foo/manifests/bar: dial tcp: lookup totallyvalidimagerepo.org on 192.168.0.2:53: no such host" ref="totallyvalidimagerepo.org/foo:bar"
[  156.734936] host-ctr[4049]: time="2019-10-29T23:20:37Z" level=error msg="retries exhausted: failed to resolve reference \"totallyvalidimagerepo.org/foo:bar\": failed to do request: Head https://totallyvalidimagerepo.org/v2/foo/manifests/bar: dial tcp: lookup totallyvalidimagerepo.org on 192.168.0.2:53: no such host" ref="totallyvalidimagerepo.org/foo:bar"
[  156.826145] host-ctr[4011]: time="2019-10-29T23:20:38Z" level=error msg="retries exhausted: failed to resolve reference \"gibberishadmincontainer.org/foo:bar\": failed to do request: Head https://gibberishadmincontainer.org/v2/foo/manifests/bar: dial tcp: lookup gibberishadmincontainer.org on 192.168.0.2:53: no such host" ref="gibberishadmincontainer.org/foo:bar"

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

[etungsten]

Addresses @jahkeup 's comment.
Sets up the logger during init(), tested and things still work.

[jahkeup]

🖱️ 🚢 💻