tetragon: Debug output fixes #334
Conversation
Adding debug option that enabled debug output from logger, like: # go test -count=1 -run . ./pkg/sensors/tracing/ -test.v -debug Suggested-by: Kornilios Kourtis <[email protected]> Signed-off-by: Jiri Olsa <[email protected]>
| @@ -115,6 +116,9 @@ func tetragonExecute() error { | |||
| log.Fatal(err) | |||
| } | |||
|
|
|||
| // enable extra programs/maps loading debug output | |||
| program.KeepCollection = option.Config.Debug | |||
|
|
|||
There was a problem hiding this comment.
@tixxdz hm, but this one is just global bool to get the debug messages,
plus option.Config.Debug bool enables debug output in above statement
There was a problem hiding this comment.
Ah yes, debug can also be set by log-level=debug where option.Config.Debug is just an alias to: log-level=debug... this was done to not break old tetragon helm charts and follow cilium IIRC
So since this touch main tetragon, please check here: https://github.com/cilium/tetragon/blob/main/cmd/tetragon/main.go#L114 we setup logging, so probably you should do something like that helper to get if loglevel is debug or above after we setup that logging... hope it makes sense.
I think we may add a comment to note that option.Config.Debug is just an alias and we should go GetLogLevel() ?
There was a problem hiding this comment.
Ah yes, debug can also be set by log-level=debug where option.Config.Debug is just an alias to: log-level=debug... this was done to not break old tetragon helm charts and follow cilium IIRC
So since this touch main tetragon, please check here: https://github.com/cilium/tetragon/blob/main/cmd/tetragon/main.go#L114 we setup logging, so probably you should do something like that helper to get if loglevel is debug or above after we setup that logging... hope it makes sense.
hum, not sure I follow.. the logger.SetupLogging sets debug level based
on the option.Config.Debug value, all this change does is to enable
additional debug output if option.Config.Debug value is true
maybe I can make it more explicit? with:
// enable extra programs/maps loading debug output
if option.Config.Debug {
program.KeepCollection = true
}
There was a problem hiding this comment.
Hmm The logger.SetupLogging() is based on option.Config.Debug and also --log-level argument too.
If we run this with --log-level=debug or --log-level=trace without passing --debug, should we expect to see this same behavior ? I suspect yes but maybe I'm missing something... !
There was a problem hiding this comment.
ah ok there's --log-level option, I see your point.. how about this then:
// enable extra programs/maps loading debug output
if logger.DefaultLogger.IsLevelEnabled(logrus.DebugLevel) {
program.KeepCollection = true
}
There was a problem hiding this comment.
@olsajiri perfect ;-) thank you!
Enabling the extra output for debug mode. It shows details about loaded programs and maps, like: time="2022-08-18T10:22:40+02:00" level=debug msg="Programs (bpf/objs/bpf_generic_kprobe_v53.o):" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1975: generic_kprobe_process_event0 - [3128 3125 3014 3126 3015 3037 3127 3036 3033]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1980: generic_kprobe_event - [3128 3036]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1981: generic_kprobe_filter_arg1 - [3128 3124 3014 3126 3015 3125 3033 3036 3037 3122 3017]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1982: generic_kprobe_process_event2 - [3014 3126 3015 3128 3125 3037 3033 3127 3036]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1974: generic_kprobe_filter_arg3 - [3128 3124 3014 3126 3015 3125 3033 3036 3037 3122 3017]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1972: generic_kprobe_process_event1 - [3014 3126 3015 3128 3125 3037 3033 3127 3036]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1973: generic_kprobe_process_filter - [3128 3014 3126 3015 3124 3036]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1976: generic_kprobe_process_event4 - [3014 3126 3015 3128 3125 3037 3033 3127 3036]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1977: generic_kprobe_filter_arg5 - [3128 3124 3014 3126 3015 3125 3033 3036 3037 3122 3017]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1978: generic_kprobe_filter_arg2 - [3128 3124 3014 3126 3015 3125 3033 3036 3037 3122 3017]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1979: generic_kprobe_filter_arg4 - [3128 3124 3014 3126 3015 3125 3033 3036 3037 3122 3017]" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 1971: generic_kprobe_process_event3 - [3014 3126 3015 3128 3125 3037 3033 3127 3036]" time="2022-08-18T10:22:40+02:00" level=debug msg="Maps (bpf/objs/bpf_generic_kprobe_v53.o):" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3017: tcpmon_map" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3033: fdinstall_map" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3036: kprobe_calls" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3037: retprobe_map" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3124: filter_map" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3125: config_map" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3128: process_call_heap" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3014: execve_map" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3015: execve_map_stats" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3122: override_tasks" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3126: execve_val" time="2022-08-18T10:22:40+02:00" level=debug msg=" - 3127: buffer_heap_map" Signed-off-by: Jiri Olsa <[email protected]>
Moving some extra Info/Warn messages to Debug lovel. Also adjusting a bit Programs/Maps loading messages to make it more readable. Signed-off-by: Jiri Olsa <[email protected]>
|
Treating @tixxdz's comment:
As an implicit ✅, merging. |
Adding -debug option to sensor tests and moving some of the loading messages to debug level.
Signed-off-by: Jiri Olsa [email protected]