shell operator failing when using klog in the hook

[ayushtiku5]

I am using golang executable as a hook for the shell-operator. I am using klog for logging from inside the hook but the shell operator pod fails with the following logs:

time="2022-03-15T07:02:21Z" level=info msg="shell-operator main-69abe104-2022.03.10_12:35:21"
time="2022-03-15T07:02:21Z" level=info msg="Listen on 0.0.0.0:9115"
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_live_ticks" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_tasks_queue_action_duration_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric gauge shell_operator_tasks_queue_length" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric gauge shell_operator_kube_snapshot_objects" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric gauge shell_operator_kube_snapshot_bytes" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_kube_jq_filter_duration_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_kube_event_duration_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric gauge shell_operator_hook_enable_kubernetes_bindings_seconds" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_hook_enable_kubernetes_bindings_errors_total" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric gauge shell_operator_hook_enable_kubernetes_bindings_success" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_hook_run_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_hook_run_user_cpu_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_hook_run_sys_cpu_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric gauge shell_operator_hook_run_max_rss_bytes" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_hook_run_errors_total" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_hook_run_allowed_errors_total" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_hook_run_success_total" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_task_wait_in_queue_seconds_total" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=debug msg="MAIN Init"
time="2022-03-15T07:02:21Z" level=info msg="Hooks dir: /hooks"
time="2022-03-15T07:02:21Z" level=info msg="Use temporary dir: /tmp/shell-operator"
time="2022-03-15T07:02:21Z" level=info msg="Debug endpoint listen on /var/run/shell-operator/debug.socket"
time="2022-03-15T07:02:21Z" level=info msg="Create metric histogram shell_operator_kubernetes_client_request_latency_seconds" operator.component=metricsStorage
time="2022-03-15T07:02:21Z" level=info msg="Create metric counter shell_operator_kubernetes_client_request_result_total" operator.component=metricStorage
time="2022-03-15T07:02:21Z" level=info msg="Kubernetes client is configured successfully with 'out-of-cluster' config" operator.component=KubernetesAPIClient
time="2022-03-15T07:02:21Z" level=info msg="Kubernetes client is configured successfully with 'out-of-cluster' config" operator.component=KubernetesAPIClient
time="2022-03-15T07:02:21Z" level=info msg="Initialize hooks manager. Search for and load all hooks."
time="2022-03-15T07:02:21Z" level=debug msg="  Search hooks in this paths: [/hooks/hook]"
time="2022-03-15T07:02:21Z" level=info msg="Load config from '/hooks/hook'" hook=hook phase=config
time="2022-03-15T07:02:21Z" level=debug msg="Executing hook in /hooks" cmd="/hooks/hook --config" hook=hook
time="2022-03-15T07:02:21Z" level=debug msg="Executing command '/hooks/hook --config' in '/hooks' dir"
time="2022-03-15T07:02:21Z" level=error msg="Hook config output:\n" hook=hook phase=config
time="2022-03-15T07:02:21Z" level=error msg="MAIN Fatal: initialize hook manager: cannot get config for hook '/hooks/hook': fork/exec /hooks/hook: no such file or directory\n"
time="2022-03-15T07:02:21Z" level=error msg="INIT HookManager failed: cannot get config for hook '/hooks/hook': fork/exec /hooks/hook: no such file or directory"

The /hooks/hook executable does exist.
Following is the go code of the hook:

package main

import (
	"flag"
	"fmt"

	"k8s.io/klog/v2"
)

func main() {
	klog.InitFlags(nil)
	klog.LogToStderr(true)
	defer klog.Flush()

	var config bool
	flag.BoolVar(&config, "config", false, "")
	flag.Parse()


	if config {
		yaml :=
`configVersion: v1
kubernetes:
- apiVersion: v1
  kind: ConfigMap
  executeHookOnEvent: ["Added", "Modified", "Deleted"]
  nameSelector:
   matchNames:
    - test_cm
  namespace:
   nameSelector:
    matchNames: ["test_ns"]`
		fmt.Println(yaml)
	} else {
		klog.Info("hello world")
	}
}

Note that this doesn't fail if I use logrus library (github.com/sirupsen/logrus) instead of klog

[diafour]

fork/exec /hooks/hook: no such file or directory is actualy a message about missing dynamic library. You can check libraries with ldd /hooks/hook. You've built binary on system with glibc, but shell-operator image is based on apline which uses musl. As the simplest solution try to disable CGO: CGO_ENABLED=0 go build ... .

[ayushtiku5]

Thanks @diafour . This worked