Skip to content
This repository has been archived by the owner on May 12, 2021. It is now read-only.

tracing: Add OpenTracing support #415

Merged
merged 10 commits into from
Mar 14, 2019

Conversation

jodh-intel
Copy link
Contributor

Add OpenTracing [1] support using Jaeger [2]. Full details are provided
in TRACING.md.

Fixes #322.

[1] - https://opentracing.io
[2] - https://jaegertracing.io

Signed-off-by: James O. D. Hunt james.o.hunt@intel.com

@jodh-intel
Copy link
Contributor Author

Related: #328.

@jodh-intel
Copy link
Contributor Author

I should point out that this PR removes the original grpcTracer() function (which logged gRPC calls) as this now seems superfluous given this PR provides real tracing. Additionally, retaining it is going to be awkward since although it will be trivial to work it into the "isolated" trace mode, it will be less easy to deal with "collated" mode (see TRACING.md for details of trace modes).

@jodh-intel
Copy link
Contributor Author

Hi @klynnrif - ptal.

@jodh-intel jodh-intel force-pushed the support-opentracing branch 3 times, most recently from 90091c8 to dd40de0 Compare November 16, 2018 15:34
Copy link

@klynnrif klynnrif left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Scrubbed for grammar, structure, and flow. Here's to hoping I didn't change meanings :) Thanks!

README.md Outdated

## Developer mode

Adding `agent.devmode` to the guest kernel command line will enable [debug mode](#debug-mode) and also allow the agent process to coredump (disabled by default).

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested rewrite: Add agent.devmode to the guest kernel command line to enable debug mode and allow the agent process to coredump (disabled by default).

TRACING.md Outdated

# OpenTracing summary

An OpenTracing enabled application creates trace "spans". A span must contain

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Adding hyphen: An OpenTracing-enabled application ....

TRACING.md Outdated
An OpenTracing enabled application creates trace "spans". A span must contain
the following attributes:

- A name.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Lines 31 - 33 suggest removing the periods at the end of each bullet since they are not complete sentences.

TRACING.md Outdated
[golang client package](https://github.com/jaegertracing/jaeger-client-go/).

The Jaeger architecture means that the Jaeger client code running in the
application reports all span information to a Jaeger agent. This agent then

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggest removing "then": This agent forwards the information on to...

TRACING.md Outdated
is not desirable to run a `jaeger-agent` process inside the VM:

- Adding extra binaries and an extra service to run the Jaeger agent inside
the VM would increase the size of the guest OS image used to

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested rewrite to stay active: the VM increases the size of the guest OS image used to

TRACING.md Outdated
- The image configured in the `kata-runtime` `configuration.toml` file must
be specified using `image=` (`initrd=` is not supported).

This is due to having to run additional systemd services inside the VM

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested rewrite: This is because, currently, additional systemd services have to run inside the VM in order to proxy the Jaeger trace flows...

TRACING.md Outdated
[Guest to Host communication using VSOCK](#guest-to-host-communication-using-vsock)
section for further details.

- Tracing is only finalised when the workload has exited

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

finalised => finalized

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've gone for "completed" here instead:

  • for consistency with that is already written.
  • to remove the contention ;)

TRACING.md Outdated

- Tracing is only finalised when the workload has exited

Although trace *can* be inspected before the workload exits, it will be

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested rewrite to stay active: Although trace can be inspected before the workload exits, it is incomplete.

TRACING.md Outdated

# Appendix: Setting up a tracing development environment

If you wish to debug, further develop or test tracing, follow the steps below

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Add series comma, wish=>want, and below=>following:

If you want to debug, further develop, or test tracing, use the following steps...

TRACING.md Outdated
## Guest journal redirector

Since agent tracing requires VSOCK, and enabling VSOCK in `configuration.toml`
disables the `kata-proxy` (since it is not required), the Kata Container has

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Lines 291-294 suggested rewrite: disables the 'kata-proxy' (not required), the Kata Container has no way to display the guest OS journal messages, which are normally redirected through the proxy. This makes debugging difficult. To overcome this issue, create another pair of ...

@sboeuf
Copy link

sboeuf commented Nov 16, 2018

@jodh-intel oh nice you finally got the PR ready!!! Yay!
How many days do I need to plan to review this properly :p

agent.go Outdated
@@ -352,13 +425,22 @@ func (s *sandbox) getContainer(id string) (*container, error) {
return ctr, nil
}

func (s *sandbox) setContainer(id string, ctr *container) {
func (s *sandbox) setContainer(ctx context.Context, id string, ctr *container) {
span, _ := trace(ctx, "sandbox", "setContainer")
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

other functions use s.trace, why don't use it here?

@@ -224,6 +255,19 @@ func (c *container) getProcess(execID string) (*process, error) {
return proc, nil
}

func (s *sandbox) trace(name string) (opentracing.Span, context.Context) {
if s.ctx == nil {
agentLog.WithField("type", "bug").Error("trace called before context set")
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

might be this function should be a singleton, hence log an error is not needed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I added this for consistency with the approach used in the runtime. If you look at agent.go, you'll see that there is a "gap" between creating the sandbox and having s.ctx set. That is unfortunately required since:

  • the context can only be set after tracing has been setup.
  • the sandbox needs to be created before tracing has been setup.

We could use a new context when creating the sandbox and then reset it to the correct context containing the trace metadata but this approach is simpler I think.

@devimc
Copy link

devimc commented Nov 16, 2018

nice job James! 😄

@jshachm
Copy link
Member

jshachm commented Nov 19, 2018

Nice job @jodh-intel

Beyond this, will we have a chance to support this in initrd model

@jodh-intel
Copy link
Contributor Author

Thanks @klynnrif, @devimc - branch updated.

@sboeuf - hahaaa! It's not as bad as it might appear in terms of LOC. But it is a little subtle in places, hence the big TRACING.md.

@jodh-intel
Copy link
Contributor Author

I recommend testing this PR using:

@jodh-intel
Copy link
Contributor Author

Note that the horrid hex strings in the scripts and Jaeger systemd services are going to be architecture-dependent. That's not a problem today but probably will be once os390x support lands. It's unclear how best to handle this. A reliable mechanism would be to provide a C program to generate the output as @mcastelino does on https://gist.github.com/mcastelino/9a57d00ccf245b98de2129f0efe39857#using-specific-ports, but the ideal would be to not require users to build and run a C program simply to get tracing working on big endian systems.

Copy link

@klynnrif klynnrif left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lgtm - thanks!

Copy link

@sboeuf sboeuf left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jodh-intel I didn't finish the review because I realized that you were explaining the way a container exit was working and I didn't agree with it. But this led me to try to reproduce the behavior that you were seeing on my machine and I understand now why you thought DestroySandbox() is not called in case of simple container process termination.
Please refer to moby/moby#38233 and kata-containers/runtime#926
I think the problem comes from your environment running docker 18.09 with the wrong version of containerd.
This generates some errors in the cleanup path, and the delete never gets called, which means we never end up calling into DestroySandbox().

But if you can confirm that this behavior is fixed by updating containerd and making sure the containerd service runs the right binary, I think the whole part of the documentation where you say that you cannot stop the tracing in DestroySandbox() could be avoided and your code could be modified accordingly.

Please try to confirm the behavior here, I'd really like to make sure we're all on the same page with the code flow.

Makefile Show resolved Hide resolved
Makefile Outdated
@@ -25,9 +25,17 @@ ifeq ($(TRACE),yes)
endif
endif

# If "yes", install additional services to redirect guest OS journal messages
# to the host using VHOST.
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

s/VHOST/VSOCK/

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed.

Gopkg.toml Outdated

[[constraint]]
name = "github.com/uber/jaeger-client-go"
version = "2.15.0"
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please add this constraint after the last constraint that is already in this file. This way it remains clear that we have constraint first, then the override, and at the end the special prune case.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That was auto-added by dep, but I agree it makes sense so fixed.

TRACING.md Outdated
- A pair of timestamps (recording the start time and end time of some operation)
- A reference to the span's parent span

All spans need to be "finished", or completed, to allow the OpenTracing
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Don't you want to use italic for finished and completed words here?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point - fixed.

TRACING.md Show resolved Hide resolved
TRACING.md Outdated

# VM shutdown

Assume a user has run the following to create a Kata Container:
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would say Kata Containers container or Kata container.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed - fixed.

TRACING.md Outdated
The user exits the primary workload shell by typing `exit`.

This results in the `kata-agent` process detecting that the primary workload
process has exited, and then exits itself. This, in turn, causes the VM to shut down.
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I thought we changed the kata-agent service so that it won't shutdown the VM when terminating. The reason was to make sure the shutdown of the VM was coming only from the runtime, preventing from any conflict with a VM that would have been already shutdown because the agent exited.

Similarly to the case you describe as container manager requested, because the container representing the sandbox terminates, the shim will terminate and the container manager will issue a container delete, leading to the gRPC call destroySandbox.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did indeed do this in testing but due I suspect to the containerd issue, that change wasn't required.

This will no doubt need updating as you suggest but let me go and look at the containerd version...

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Picking this up again...

We don't want to stop the kata agent service stopping the VM - it's the other way around for tracing scenarios:

  • If the user types exit:

    • The workload shell exits
    • The agent detects this and stops tracing itself.
    • The agent exits.
    • The agent service detects this and performs a controlled VM shutdown.
  • If the user types docker stop, the same thing has to happen - the VM needs to shut itself down and the runtime should not call the QMP QUIT command as that will kill the VM before the agent has finished stopping tracing itself.

That does mean I'll have to tweak the runtime "somehow" to stop it calling QUIT. I can't see currently how to make that change "clean" - currently, you enable agent trace by modifying hypervisor.qemu.kernel_params directly. The best I can think of right now is to add a runtime.enable_agent_tracing which will:

  • Disable the QUIT.
  • Add the trace arguments to hypervisor.qemu.kernel_params (yuck).

Any other ideas?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't get what's wrong with the gRPC call DestroySandbox(). This function is always called in every situation (now that we fixed Docker 18.09), meaning the agent is always around, even when the container workload exited.
In both cases (container workload exit, and forced kill), the runtime will at some point communicate with the agent the need to terminate through agent.stopSandbox() which will send the gRPC call DestroySandbox().

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes - DestroySandbox() is always called, but it doesn't appear to be possible to shut down the gRPC server by triggering the server to end from DestroySandbox(). I need to debug further but I think this is the same problem I hit a while back with gRPC internal locks and waitgroups. It's sounding like you cannot shut down the server on the same goroutine that's it's running in. However, if you try to stop the server in WaitProcess(), all works as expected.

TRACING.md Outdated

- The `kata-agent` `DestroySandbox` gRPC API is called.
- The runtime sends a [QMP](https://wiki.qemu.org/Documentation/QMP) `quit`
command to the VM to ensure it is stopped.
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not to ensure, but to shut it down.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed.

TRACING.md Outdated
The crucial difference between the two shutdown methods explained in the [VM
shutdown](#vm-shutdown) section is that the user-initiated shutdown does not
explicitly destroy the sandbox using the `DestroySandbox` gRPC API: the
sandbox is "destroyed" by the agent shutting down the VM.
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's not explicitly done the same way, but when the management layer realizes the shim is not there anymore, it sends a kata-runtime delete and eventually this calls into DestroySandbox.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Again, this relates to the issue I seem to have been having with containerd so I'll come back to this one...

@jodh-intel jodh-intel force-pushed the support-opentracing branch 2 times, most recently from 6a1761c to f8eae56 Compare November 22, 2018 15:21
@grahamwhaley
Copy link
Contributor

@sboeuf - this probably needs your re-review now when you find a slot.

Copy link
Contributor

@grahamwhaley grahamwhaley left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A few doc notes... nothing major, but a couple of fixes required.

TRACING.md Outdated
* [Host environment](#host-environment)
* [Guest environment](#guest-environment)
* [Limitations](#limitations)
* [Appendix: Setting up a tracing development environment](#appendix:-setting-up-a-tracing-development-environment)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The appendix link does not hot-render. I think it needs the ref modding to (that is, drop the stray :) :

#appendix-setting-up-a-tracing-development-environment

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed.

TRACING.md Outdated
following:

| Trace type | Trace setting | Description | Use-case | Notes |
|-|-|-|-|
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This table is not rendering for me - I suspect you are missing one set of | - | in the second line.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Weirdly it rendered for me in both github and atom. What are you using ooi?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was just looking in the 'view file' on the github PR - so, dunno why that was different from your github view...

TRACING.md Show resolved Hide resolved
1. Build a custom non-initrd image using
[osbuilder](https://github.com/kata-containers/osbuilder).

- The image **must** include:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How does one achieve this? I think you added the ability to osbuilder to do this for you?, in which case we can note the method (TRACE=true or somesuch) here?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

See kata-containers/osbuilder#200 :)

It's a bit circular. Once the osbuilder PR has landed, this can be simplified.

I did toy with the idea of creating a small .md doc here and having osbuilder execute it, but discarded the idea since that script needs to know things like $ROOTFS directories and those are a purely osbuilder concern so it would have been "the wrong way round".

TRACING.md Show resolved Hide resolved
@jodh-intel jodh-intel force-pushed the support-opentracing branch 2 times, most recently from e38e2f0 to 8524e85 Compare November 26, 2018 17:02
@jodh-intel
Copy link
Contributor Author

@sboeuf - I think we just need you ack to allow us break out the champagne... 😄

@jodh-intel
Copy link
Contributor Author

Gah - I'm starting to go off this browser with it's aggressive caching and page unloading - I'd missed @sboeuf's ack.

/me looks at test carnage...

@jodh-intel
Copy link
Contributor Author

/retest

@jodh-intel
Copy link
Contributor Author

16.04 metrics CI timed out @grahamwhaley:

Build timed out (after 10 minutes). Marking the build as aborted.
14:01:43 density/docker_memory_usage.sh: line 190: 29584 Terminated              docker rm -f ${containers[@]}

@grahamwhaley
Copy link
Contributor

@jodh-intel - that metrics CI timeout looks like docker/kata got stuck trying to delete the containers after the test had been run. It looks like @amshinde also saw a 'failed to delete container' on another CI before on this PR? That makes me wonder if we have some inherent rm/delete hangup hiding in here somewhere?
I'll re-trigger the CI (and I've tried to adjust the bounds, so the metrics CI has a chance of passing...)

@jodh-intel
Copy link
Contributor Author

Nooo - I've already re-triggered :)

Yes, there may be an issue but I was hoping to get a fresh set of CI logs as cannot recreate locally.

Sebastien Boeuf and others added 9 commits March 13, 2019 14:50
This commit attempts to close cleanly the gRPC server so that tracing
will be ended properly.

Fixes kata-containers#445

Signed-off-by: Sebastien Boeuf <sebastien.boeuf@intel.com>
The semantic around the agent is that it should be a passive
component, hence it should not implicitly shut down the VM.

Instead, we expect the kata-runtime to be responsible for this,
using the appropriate VM interface to stop it.

Fixes kata-containers#449

Depends-on: github.com/kata-containers/tests#1101

Signed-off-by: Sebastien Boeuf <sebastien.boeuf@intel.com>
Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
Tabs should only be used in rules.

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
Reformat an `ifeq` test for clarity.

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
Detected by the CI's static analysis:

```
api.go:38:2:warning: unused variable or constant exitSuccess (varcheck)
api.go:39:2:warning: unused variable or constant exitFailure (varcheck)
api.go:38:2:warning: const exitSuccess is unused (U1000) (unused)
api.go:39:2:warning: const exitFailure is unused (U1000) (unused)
```

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
This seems to be an erroneous / outdated entry as it's hiding
files below `vendor/`!

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
Firm up the language used in the README.

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
Explain how to enable debug.

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
Update the README to show how to enable developer mode.

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
@jodh-intel
Copy link
Contributor Author

/retest

Add OpenTracing [1] support using Jaeger [2]. Introduces two new gRPC
API calls to enable and disable tracing dynamically: `StartTracing()`
and `StopTracing()`.

Full details of this feature are provided in `TRACING.md`.

Updated vendoring for github.com/mdlayher/vsock to resolve hangs using a
vsock socket with `grpcServer.Serve()`. Changes:

    498f144 Handle return result in Accept test
    fda437e Fix unblocking after closing listener
    4b12813 Add go.mod
    ce2ff06 vsock: factor out newConn function on Linux
    d8b0f13 vsock: adjust listener test for nonblocking
    7a158c6 vsock: enable timeouts also on listener connections
    f68ad55 vsock: allow timeouts with Go 1.11
    d0067a6 vsock/conn: don't use struct embedding

Note: the agent **must** be built with golang 1.11* or newer to ensure
correct behaviour.

Fixes kata-containers#322.

[1] - https://opentracing.io
[2] - https://jaegertracing.io

Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>
@jodh-intel
Copy link
Contributor Author

/retest

@jodh-intel
Copy link
Contributor Author

@nitkon - It looks like the ppc64 CI isn't actually running tests for PRs?:

Building remotely on Power8_slave01 (power8-ubuntu-1604 power8_node) in workspace /home/jenkins/workspace/kata-containers-agent-Power8-ubuntu-16-04-PR-initrd
[WS-CLEANUP] Deleting project workspace...

@jodh-intel
Copy link
Contributor Author

Branch updated.

@mcastelino - ftr, I removed the unused gRPC stream interceptor function.

@sboeuf
Copy link

sboeuf commented Mar 13, 2019

@mcastelino if you agree, let's merge this PR :)

@mcastelino
Copy link
Contributor

LGTM @sboeuf please merge this so that we can switch to a custom exporter quickly

@sboeuf
Copy link

sboeuf commented Mar 14, 2019

@jodh-intel that's it you're done, you can go to the beach for a year now 🌴 🌞

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

9 participants