Problem when specifying pod/container/pid arguments but not when specifying host/pid arguments

[03k64]

Hi, I'm having an issue when specifying a combination of pod/container/pid arguments, the issue does not occur when I run against a combination of only host/pid arguments. For example, if I ssh onto a Kubernetes worker node and docker inspect... to find the PID of a running container, then I can run the following command and see output as below in response to curl commands that cause the service to make onward requests:

➜ kubectl trace run worker.node --tracer bcc --program gethostlatency \
   -a -n example_namespace --args "-p 3439256"
Got 23 pods, 23 non-terminal podstrace a7e3cf5c-a1e9-4405-a303-7951589e45a0 created
TIME      PID     COMM                  LATms HOST
14:51:56  3439256 node                   0.24 foo.example.com
14:51:57  3439256 node                   0.13 bar.example.com
14:51:58  3439256 node                   0.15 baz.example.com

However, if I attempt the same command against the pod/container/pid I see only the header output as below no matter how many subsequent curl commands I make against the service:

➜ kubectl trace run pod/example-pod -c example_container --tracer bcc --program gethostlatency \
  -a -n example_namespace --args "-p 1"         
Got 23 pods, 23 non-terminal podstrace 2a20a6d9-f644-419f-a3cd-44dcabc775f3 created
TIME      PID     COMM                  LATms HOST

I've also tried specifying --process-selector "pid=1" instead of/in addition to --args "-p 1" without success. I've also followed the steps in the README and repeated the above after creating a ServiceAccount, PodSecurityPolicy, ClusterRole and ClusterRoleBinding in case that was the issue, but I still saw only the headers output as above. I've confirmed the container-relative PID of 1 by inspecting /proc/1/cmdline to ensure it is the application command that is being run under PID 1.

I am running using the latest commit compiled from source per the README and the cluster is running v1.19.14 of Kubernetes. If you can suggest anything to try and debug what the issue might be then I am happy to provide further information, thanks in advance :)

[dalehamel]

Try specifying the pid with $container_pid per the docs, it will get replaced by the pid that the selector matches

[dalehamel]

@03k64 sorry was typing from my phone yesterday so couldn't give a complete explanation, but I think what you need in order to correctly match this process is an invocation like this:

kubectl trace run pod/example-pod -c example_container --process-selector "pid=1" --tracer bcc --program gethostlatency \
  -a -n example_namespace --args "-p $container_pid"         

The process selector will match a process relative to the container namespace using the criteria specified (FYI you can also go by exe name, rather than having to hardcode the PID).

Regardless of whether you use a process selector or not, the target process ID is available to the trace program via the magic value $container_pid, which is substituted for either the process ID of the container (if no process selector is specified) or the selected process (if a process selector is specified, and matches).

Please give this a try.

[03k64]

Hi @dalehamel and thanks for getting back to me. Sorry for my own delay in replying, I'm currently only working part-time on a Monday while studying.

I tried the format of command you suggested without success. I tried specifying --process-selector "pid=1", --process-selector "exe=node" and --process-selector "cmdline=node" after looking through the source code (I would have tried matching on --process-selector "comm=?" also but I couldn't see any comm file in /proc/1 in the container).

With each invocation using process-selector and $container_pid I get no output beyond a message about the trace being created, when I describe the job it appears that $container_pid is set to an empty string, for example:

➜ kubectl trace run pod/example-pod -c example-container --process-selector "pid=1" --tracer bcc \
  --program gethostlatency -a -n example-namespace --args "-p $container_pid"
Got 13 pods, 13 non-terminal podstrace 237228b9-7f44-4b2a-89ae-ff82ddbbaa3f created

➜ kubectl get job -n playground -o yaml kubectl-trace-237228b9-7f44-4b2a-89ae-ff82ddbbaa3f
... elided output ...
      containers:
      - command:
        - /bin/timeout
        - --preserve-status
        - --signal
        - INT
        - "3600"
        - /bin/trace-runner
        - --tracer=bcc
        - --pod-uid=c0c344cb-afdf-462c-b262-0dc14c462edf
        - --container-id=e2344912be637a2a8d1dd035b3c2d4cd60bb0798e317f02fc8aebaac47f0cc58
        - --process-selector=pid=1
        - --output=stdout
        - --program=gethostlatency
        - '--args=-p '
... elided output ...

The job itself is in a Failed state insofar as it has no completions and a Failed condition is present. By contrast, when I run the trace for the specific container as I outlined in my original comment, I see the following which shows the correct arguments being passed to /bin/trace-runner despite the absence of output beyond column headers:

➜ kubectl trace run pod/example-pod -c example_container --tracer bcc --program gethostlatency \
  -a -n example_namespace --args "-p 1"         
Got 23 pods, 23 non-terminal podstrace 2a20a6d9-f644-419f-a3cd-44dcabc775f3 created
TIME      PID     COMM                  LATms HOST

➜ kubectl get job -n playground -o yaml kubectl-trace-8c8b1b96-a0b6-4558-b5f3-1315d33aa877
... elided output ...
      containers:
      - command:
        - /bin/timeout
        - --preserve-status
        - --signal
        - INT
        - "3600"
        - /bin/trace-runner
        - --tracer=bcc
        - --pod-uid=9ccb5a4b-5cd1-4344-b426-485271813696
        - --container-id=1bc3f2d13512c2f3f036d13aa640fcc32806b22a5640e7915e05aa8d1fa87cb8
        - --process-selector=
        - --output=stdout
        - --program=gethostlatency
        - --args=-p 1
... elided output ...

In this instance, the job is in an active state and has no failure conditions attached. The only thing that struck me as odd about this was that --process-selector= line, it struck me as odd that it would still be present if not specified when running the trace?

[03k64]

As an additional question (and I can raise a new issue for this if desired), is there any plan to have the --tracer bcc option allow for custom bcc programs to be provided using the -f flag? Currently when I try this I receive the following Error: the bpftrace programm cannot be empty