[1.10] Add log-level option to conmon and crio.conf #1692

umohnani8 · 2018-07-11T16:56:24Z

conmon now has a --log-level flag that changes
the verbosity of the logs based on the value it
is set to. From logrus, panic(0), fatal(1), error(2) tells
conmon to print all pexit and nexit logs (this
is the default). warn(3) adds the nwarn logs, info(4)
adds the ninfo logs, and finally debug(5) adds the ndebug
logs as well.

Adds a log_level field in the crio.conf that can have the
following options: panic, fatal, error, warn, info, and debug.
Changes default from info to error.

Signed-off-by: umohnani8 umohnani@redhat.com

umohnani8 · 2018-07-11T16:56:34Z

@mrunalp @runcom PTAL

mrunalp · 2018-07-11T17:03:52Z

/test all

mrunalp · 2018-07-11T17:25:25Z

@umohnani8 Let us also port this to master and release-1.11. Thank!

mheon · 2018-07-11T17:33:10Z

Can we get a flag to optionally keep this? It seems valuable for debugging Podman.

umohnani8 · 2018-07-11T17:46:55Z

@mrunalp should I go ahead and add a flag? If so, what do we want to call the flag.

rhatdan · 2018-07-11T17:56:30Z

Can you just make it debug versus info?

mrunalp · 2018-07-11T19:56:40Z

@rhatdan The debug change doesn't work as it just changes what gets printed in the logs. We would need to add a flag to control it.

umohnani8 · 2018-07-11T20:29:33Z

Added debug flag. @mrunalp @mheon @rhatdan PTAL

mheon · 2018-07-11T20:35:56Z

conmon/conmon.c

@@ -80,6 +80,18 @@
 		syslog(LOG_INFO, "conmon <ninfo>: " fmt " \n", ##__VA_ARGS__); \
 	} while (0)

+#define ndebug(s)                                             \
+	do {                                                 \


Might be better to include the if(opt_debug) in the macros so all debug prints will only happen if debug is set.

runcom · 2018-07-12T06:43:14Z

Why do you need this for debugging @mheon? Do you have or had any use case that helps you debug with this information? If this is successful the pid is sent back to golang where if in not wrong is printed somewhere, if not, we can add it there.

mheon · 2018-07-12T11:46:10Z

Our most successful debug strategy for conmon problems now is to have people copy the command line libpod would use to launch it and then run it themselves and see what happens. It lets us get output more reliably than forwarding to Go with the added benefit that we can easily stick strace on there if needed to get a better picture of where it's failing. Having the container pid actually printed is useful there.

…

On Thu, Jul 12, 2018, 02:43 Antonio Murdaca ***@***.***> wrote: Why do you need this for debugging @mheon <https://github.com/mheon>? Do you have or had any use case that helps you debug with this information? If this is successful the pid is sent back to golang where if in not wrong is printed somewhere, if not, we can add it there. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1692 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AHYHCLt_N4yQmZRq3n7VmzOWFsM0Z-N-ks5uFvAEgaJpZM4VLgF0> .

runcom · 2018-07-12T12:02:41Z

Our most successful debug strategy for conmon problems now is to have
people copy the command line libpod would use to launch it and then run it
themselves and see what happens. It lets us get output more reliably than
forwarding to Go with the added benefit that we can easily stick strace on
there if needed to get a better picture of where it's failing.

yeah that's exactly what we do as well to debug conmon, I still can't see how the pid printed after conmon starts is useful, but ok.

umohnani8 · 2018-07-12T15:21:11Z

/test all

mrunalp · 2018-07-12T18:14:06Z

We decided to add support for log-level instead.

umohnani8 · 2018-07-19T13:55:49Z

Added --log-level to conmon and changed when the logs are printed based on the level. Also added log_level to the crio.conf file.
@mrunalp @runcom PTAL.
Once this gets approved, I will pull in the same thing to master and 1.11.

TomSweeneyRedHat

Changes LGTM, any man page adjustments needed?

umohnani8 · 2018-07-19T14:58:59Z

/test all

umohnani8 · 2018-07-19T15:03:26Z

@TomSweeneyRedHat thanks! Added doc changes.

umohnani8 · 2018-07-19T15:14:46Z

/test all

TomSweeneyRedHat · 2018-07-19T15:30:35Z

tutorial.md

@@ -163,7 +163,7 @@ Description=OCI-based implementation of Kubernetes Container Runtime Interface
 Documentation=https://github.com/kubernetes-incubator/cri-o

 [Service]
-ExecStart=/usr/local/bin/crio --log-level debug
+ExecStart=/usr/local/bin/crio


It would be nice to show an example in crio.conf how to set up the debug level. Also based on the registry.conf discussions this morning, does the registries option at line 150 still hold?

That is fine, for 1.10 and below we need to add the default registries in /etc/crio/crio.conf.
Added an "optional" to show how we can change the log_level in crio.conf.

rhatdan · 2018-07-19T15:38:36Z

Kata does not work on 1.10, so we can ignore that I believe.

umohnani8 · 2018-07-19T18:28:51Z

/test e2e_rhel

mrunalp · 2018-07-19T21:14:18Z

conmon/conmon.c

@@ -171,6 +196,7 @@ static GOptionEntry opt_entries[] =
  { "log-size-max", 0, 0, G_OPTION_ARG_INT64, &opt_log_size_max, "Maximum size of log file", NULL },
  { "socket-dir-path", 0, 0, G_OPTION_ARG_STRING, &opt_socket_path, "Location of container attach sockets", NULL },
  { "version", 0, 0, G_OPTION_ARG_NONE, &opt_version, "Print the version and exit", NULL },
+  { "log-level", 0, 0, G_OPTION_ARG_INT, &opt_log_level, "Print debug logs based on log level", NULL },


We should read this as ARG_STRING and map it to int for log_level.

But then logrus already maps the levels to int, so isn't it better to use that instead of creating a new string to int map of the levels in conmon?

Fixed. Reading as ARG_STRING and mapping to an int. Not the most high tech way, but it is the simplest solution I could think of. @mrunalp @runcom PTAL.

mrunalp · 2018-07-23T21:53:14Z

conmon/conmon.c

+	}
+
+#define ndebug(s)                                                     \
+	if (parse_level(opt_log_level) > 2) {                                      \


2 doesn't match the enum values you have defined below. We should use the enum constants instead of number in this comparison.

umohnani8 · 2018-07-25T14:45:41Z

/test all

umohnani8 · 2018-07-25T17:58:01Z

/test e2e_rhel

umohnani8 · 2018-07-27T14:58:50Z

/test e2e_rhel

conmon now has a --log-level flag that changes the verbosity of the logs based on the value it is set to. From logrus, panic(0), fatal(1), error(2) tells conmon to print all pexit and nexit logs (this is the default). warn(3) adds the nwarn logs, info(4) adds the ninfo logs, and finally debug(5) adds the ndebug logs as well. Adds a log_level field in the crio.conf that can have the following options: panic, fatal, error, warn, info, and debug. Changes default from info to error. Signed-off-by: umohnani8 <umohnani@redhat.com>

umohnani8 · 2018-07-27T19:09:41Z

/test all

umohnani8 · 2018-07-30T14:03:57Z

tests finally pass. @mrunalp @runcom PTAL

runcom · 2018-07-30T14:40:20Z

cmd/crio/main.go

@@ -229,9 +232,9 @@ func main() {
 		},
 		cli.StringFlag{
 			Name:  "log-level",
-			Usage: "log messages above specified level: debug, info (default), warn, error, fatal or panic",
+			Value: "error",


are we sure about this default? what was before this change overall?

it was info. We want the logs to be as minimal as possible by default so error seems like the best choice. When we change this in crio.conf the logs get more verbose for both cri-o and conmon.

awesome, we're good then (error's super fine!)

rhatdan · 2018-07-30T16:50:02Z

LGTM

umohnani8 requested review from mrunalp and runcom as code owners July 11, 2018 16:56

k8s-ci-robot added cncf-cla: yes size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Jul 11, 2018

runcom approved these changes Jul 11, 2018

View reviewed changes

umohnani8 changed the title ~~Remove "container PID" logs from conmon~~ [1.10] Remove "container PID" logs from conmon Jul 11, 2018

umohnani8 force-pushed the 1.10 branch from 6cc816e to e3155e0 Compare July 11, 2018 20:26

k8s-ci-robot added size/S Denotes a PR that changes 10-29 lines, ignoring generated files. and removed size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Jul 11, 2018

umohnani8 force-pushed the 1.10 branch from e3155e0 to 9e3e66a Compare July 11, 2018 20:34

mheon reviewed Jul 11, 2018

View reviewed changes

umohnani8 force-pushed the 1.10 branch 4 times, most recently from 93b9213 to a362df2 Compare July 12, 2018 14:49

umohnani8 force-pushed the 1.10 branch from a362df2 to e366f43 Compare July 19, 2018 13:49

k8s-ci-robot removed the size/S Denotes a PR that changes 10-29 lines, ignoring generated files. label Jul 19, 2018

umohnani8 force-pushed the 1.10 branch from e366f43 to 7664f9e Compare July 19, 2018 13:53

TomSweeneyRedHat reviewed Jul 19, 2018

View reviewed changes

umohnani8 force-pushed the 1.10 branch from 7664f9e to 9cdadd2 Compare July 19, 2018 14:42

umohnani8 force-pushed the 1.10 branch from 9cdadd2 to 87f0a59 Compare July 19, 2018 15:03

k8s-ci-robot added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Jul 19, 2018

TomSweeneyRedHat reviewed Jul 19, 2018

View reviewed changes

umohnani8 force-pushed the 1.10 branch 2 times, most recently from c455fa4 to 3e02a0b Compare July 19, 2018 18:54

mrunalp reviewed Jul 19, 2018

View reviewed changes

umohnani8 force-pushed the 1.10 branch 2 times, most recently from b3d45c4 to d4c0fb9 Compare July 23, 2018 19:27

mrunalp reviewed Jul 23, 2018

View reviewed changes

umohnani8 force-pushed the 1.10 branch from d4c0fb9 to b4f6b4d Compare July 24, 2018 17:23

umohnani8 force-pushed the 1.10 branch from b4f6b4d to 1691b67 Compare July 27, 2018 18:27

runcom reviewed Jul 30, 2018

View reviewed changes

rhatdan merged commit 7cc47d7 into cri-o:release-1.10 Jul 30, 2018

[1.10] Add log-level option to conmon and crio.conf #1692

[1.10] Add log-level option to conmon and crio.conf #1692

Conversation

umohnani8 commented Jul 11, 2018 • edited

umohnani8 commented Jul 11, 2018

mrunalp commented Jul 11, 2018

mrunalp commented Jul 11, 2018

mheon commented Jul 11, 2018

umohnani8 commented Jul 11, 2018

rhatdan commented Jul 11, 2018

mrunalp commented Jul 11, 2018

umohnani8 commented Jul 11, 2018

Choose a reason for hiding this comment

runcom commented Jul 12, 2018

mheon commented Jul 12, 2018 via email

runcom commented Jul 12, 2018

umohnani8 commented Jul 12, 2018

mrunalp commented Jul 12, 2018

umohnani8 commented Jul 19, 2018

TomSweeneyRedHat left a comment

Choose a reason for hiding this comment

umohnani8 commented Jul 19, 2018

umohnani8 commented Jul 19, 2018

umohnani8 commented Jul 19, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rhatdan commented Jul 19, 2018

umohnani8 commented Jul 19, 2018

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

umohnani8 commented Jul 25, 2018

umohnani8 commented Jul 25, 2018

umohnani8 commented Jul 27, 2018

umohnani8 commented Jul 27, 2018

umohnani8 commented Jul 30, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rhatdan commented Jul 30, 2018

umohnani8 commented Jul 11, 2018 •

edited