enhancement(kubernetes source): Kubernetes partial message merge #2134

MOZGIII · 2020-03-24T23:22:40Z

This PR adds support for partial events merging at kubernetes.

Closes #1718.
Ref fluent/fluent-bit#337.

To do:

add the ability to opt-out of automatic merging
validate that the integration test is adequate (cc @ktff)
make integration test pass
user-facing documentation
correct the feature separation-related errors
implement support for CRI log format

MOZGIII · 2020-03-24T23:55:53Z

Apparently, the kubernetes source is not at https://github.com/timberio/vector/blob/master/.github/semantic.yml

Signed-off-by: MOZGIII <[email protected]>

…filters Signed-off-by: MOZGIII <[email protected]>

ktff · 2020-03-25T09:25:28Z

The kube test is sufficient, although I am curious if it's passing with Docker runtime and non Docker runtime.

@MOZGIII Have you perhaps tested them on both?

MOZGIII · 2020-03-25T13:12:43Z

I wasn't able to successfully run the integration test locally. Docker tests that we have are hard to use for me, and it also got no success with my live k8s cluster.
Any hints on what I should run to invoke the integration tests properly without running the whole test suite?

I have doubts about the test procedure I added - I suspect echoing 64k of data won't work if it's passed as an argument. So, I'd really like to test it.

binarylogic · 2020-03-25T13:50:02Z

@LucioFranco @ktff mind helping or considering ways we can improve isolate these tests?

LucioFranco · 2020-03-25T14:56:28Z

@MOZGIII cargo test --features kubernetes kubernetes should work, as long as you have a valid kube config file. I use minikube locally and it should just work.

MOZGIII · 2020-03-25T16:55:57Z

@MOZGIII cargo test --features kubernetes kubernetes should work, as long as you have a valid kube config file. I use minikube locally and it should just work.

I tried this command:

cargo test --package vector --features kubernetes-integration-tests --lib --  --nocapture sources::kubernetes::test::kube_partial

But I get "no such file or dir" errors...

It seems like tests (and vector) need access to the cluster filesystem. This doesn't work with minikube since it's in a VM, and my "local" cluster is also remote to my workstation system...

Maybe I'm just doing something wrong.

LucioFranco · 2020-03-25T17:12:48Z

@MOZGIII I just tested locally with minikube with the kvm driver and it seems to work, the test ends up hanging looks like its just making a lot of 200ok requests.

In the past I ran our tests via virtualbox and it worked fine. So not sure what is happening.

MOZGIII · 2020-03-25T17:49:18Z

RUST_BACKTRACE=1 cargo test --package vector --features kubernetes-integration-tests --lib --  --nocapture sources::kubernetes::test::kube_partial
    Finished test [unoptimized + debuginfo] target(s) in 0.46s
     Running target/debug/deps/vector-672836462b12273f

running 1 test
thread 'sources::kubernetes::test::kube_partial' panicked at 'failed to load kubeconfig: Error { inner: Os { code: 2, kind: NotFound, message: "No such file or directory" }

stack backtrace:
   0: failure::backtrace::internal::InternalBacktrace::new
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/backtrace/internal.rs:46
   1: failure::backtrace::Backtrace::new
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/backtrace/mod.rs:121
   2: <failure::error::error_impl::ErrorImpl as core::convert::From<F>>::from
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/error/error_impl.rs:19
   3: <failure::error::Error as core::convert::From<F>>::from
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/error/mod.rs:36
   4: <T as core::convert::Into<U>>::into
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libcore/convert/mod.rs:558
   5: failure::context::Context<D>::with_err
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/context.rs:105
   6: failure::Fail::context
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/lib.rs:160
   7: <core::result::Result<T,E> as failure::result_ext::ResultExt<T,E>>::context::{{closure}}
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/result_ext.rs:164
   8: core::result::Result<T,E>::map_err
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libcore/result.rs:604
   9: <core::result::Result<T,E> as failure::result_ext::ResultExt<T,E>>::context
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/failure-0.1.6/src/result_ext.rs:164
  10: kube::config::apis::Config::load_config
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/kube-0.16.1/src/config/apis.rs:136
  11: kube::config::kube_config::KubeConfigLoader::load
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/kube-0.16.1/src/config/kube_config.rs:26
  12: kube::config::load_kube_config_with
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/kube-0.16.1/src/config/mod.rs:73
  13: kube::config::load_kube_config
             at /home/mozgiii/.cargo/registry/src/github.com-1ecc6299db9ec823/kube-0.16.1/src/config/mod.rs:47
  14: vector::sources::kubernetes::test::Kube::new
             at src/sources/kubernetes/test.rs:172
  15: vector::sources::kubernetes::test::kube_partial
             at src/sources/kubernetes/test.rs:651
  16: vector::sources::kubernetes::test::kube_partial::{{closure}}
             at src/sources/kubernetes/test.rs:646
  17: core::ops::function::FnOnce::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libcore/ops/function.rs:232
  18: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/liballoc/boxed.rs:1015
  19: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  20: std::panicking::try
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panicking.rs:281
      std::panic::catch_unwind
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panic.rs:394
      test::run_test_in_process
             at src/libtest/lib.rs:539
      test::run_test::run_test_inner::{{closure}}
             at src/libtest/lib.rs:452
  21: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/sys_common/backtrace.rs:129
  22: std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/thread/mod.rs:475
      <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panic.rs:318
      std::panicking::try::do_call
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panicking.rs:305
  23: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  24: std::panicking::try
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panicking.rs:281
      std::panic::catch_unwind
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panic.rs:394
      std::thread::Builder::spawn_unchecked::{{closure}}
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/thread/mod.rs:474
      core::ops::function::FnOnce::call_once{{vtable.shim}}
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libcore/ops/function.rs:232
  25: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/liballoc/boxed.rs:1015
  26: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/liballoc/boxed.rs:1015
      std::sys_common::thread::start_thread
             at src/libstd/sys_common/thread.rs:13
      std::sys::unix::thread::Thread::new::thread_start
             at src/libstd/sys/unix/thread.rs:80
  27: start_thread
  28: __clone


Error loading kube config: Unable to open config file }', src/sources/kubernetes/test.rs:172:22
stack backtrace:
   0: backtrace::backtrace::libunwind::trace
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
   1: backtrace::backtrace::trace_unsynchronized
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
   2: std::sys_common::backtrace::_print_fmt
             at src/libstd/sys_common/backtrace.rs:77
   3: <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt
             at src/libstd/sys_common/backtrace.rs:59
   4: core::fmt::write
             at src/libcore/fmt/mod.rs:1052
   5: std::io::Write::write_fmt
             at src/libstd/io/mod.rs:1426
   6: std::sys_common::backtrace::_print
             at src/libstd/sys_common/backtrace.rs:62
   7: std::sys_common::backtrace::print
             at src/libstd/sys_common/backtrace.rs:49
   8: std::panicking::default_hook::{{closure}}
             at src/libstd/panicking.rs:204
   9: std::panicking::default_hook
             at src/libstd/panicking.rs:224
  10: std::panicking::rust_panic_with_hook
             at src/libstd/panicking.rs:472
  11: rust_begin_unwind
             at src/libstd/panicking.rs:380
  12: core::panicking::panic_fmt
             at src/libcore/panicking.rs:85
  13: core::option::expect_none_failed
             at src/libcore/option.rs:1199
  14: core::result::Result<T,E>::expect
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libcore/result.rs:991
  15: vector::sources::kubernetes::test::Kube::new
             at src/sources/kubernetes/test.rs:172
  16: vector::sources::kubernetes::test::kube_partial
             at src/sources/kubernetes/test.rs:651
  17: vector::sources::kubernetes::test::kube_partial::{{closure}}
             at src/sources/kubernetes/test.rs:646
  18: core::ops::function::FnOnce::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libcore/ops/function.rs:232
  19: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/liballoc/boxed.rs:1015
  20: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  21: std::panicking::try
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panicking.rs:281
  22: std::panic::catch_unwind
             at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/libstd/panic.rs:394
  23: test::run_test_in_process
             at src/libtest/lib.rs:539
  24: test::run_test::run_test_inner::{{closure}}
             at src/libtest/lib.rs:452
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
test sources::kubernetes::test::kube_partial ... FAILED

failures:

failures:
    sources::kubernetes::test::kube_partial

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 607 filtered out

error: test failed, to rerun pass '-p vector --lib'

This is an error sample.
I'm also using kvm driver, but the error looks different.

LucioFranco · 2020-03-25T17:51:32Z

@MOZGIII where are you running this test and where does your kube config file live? Does kubectl work for you? If kubectl works, vector should too.

Because I am 100% not running into that error I can actually reach kube. I just ran minikube start and the same cargo command and it worked.

MOZGIII · 2020-03-25T18:00:41Z

kubectl works as expected.

$ kubectl get node
NAME   STATUS   ROLES    AGE   VERSION
m01    Ready    master   18h   v1.17.3

I have the KUBE_CONFIG variable set, and it's pointing to multiple files since I have a number of clusters to work with, so that might be what's causing issues. Our tooling might not be updated to support this yet. I'll investigate...

Thanks for bringing this up the kubeconfig file location, I forgot this could be a problem!

LucioFranco · 2020-03-25T18:01:38Z

@MOZGIII oh that looks like something that is missing from kubers?

MOZGIII · 2020-03-25T18:03:09Z

@LucioFranco might be on their end, but idk yet.

MOZGIII · 2020-03-26T19:36:33Z

Checked out kube code, turns out it's a problem on their end: https://github.com/clux/kube-rs/blob/22c13c34bd56a4323eab0e5b923e7cb9b03e54ef/kube/src/config/kube_config.rs#L35

~~Crated kube-rs/kube#198~~ See kube-rs/kube#132

I'm using a workaround, thx everyone for the help!

Signed-off-by: MOZGIII <[email protected]>

MOZGIII · 2020-03-26T20:48:10Z

I can't make the integration test pass, but I assume this is ok cause there's this comment: https://github.com/timberio/vector/blob/f22d088230024cce7493f0ac9258baadfd76b4ff/src/sources/kubernetes/test.rs#L78
Looks like I wasn't even testing my branch this whole time 😄

@ktff what should I do?

Signed-off-by: MOZGIII <[email protected]>

ktff · 2020-03-27T10:18:06Z

@MOZGIII

Looks like I wasn't even testing my branch this whole time

Yea, it happens.

Two options:

Wait for chore(tests): Enable Kubernetes tests #1970 to be merged. I'll push it to be merged by the end of the week.
Create your own account on dockerhub, build the image with vector locally and push it to the repository. And finally change the used image in https://github.com/timberio/vector/blob/f22d088230024cce7493f0ac9258baadfd76b4ff/src/sources/kubernetes/test.rs#L116.
This is sufficient for the dockerfile

FROM buildpack-deps:18.04-curl
COPY ./vector /usr/local/bin
ENTRYPOINT ["/usr/local/bin/vector"]

MOZGIII · 2020-03-27T16:20:54Z

@ktff thx! I'll just wait for #1970.

Signed-off-by: MOZGIII <[email protected]>

MOZGIII · 2020-03-31T05:15:50Z

I have troubles when running new cd tests; make test-kubernetes utility.
CI also doesn't seem to work.

Was able to test via RUST_BACKTRACE=1 KUBE_TEST_IMAGE="mozgiii/vector-test:kubernetes-partial-message-merge" cargo test --package vector --features kubernetes-integration-tests --lib -- --nocapture sources::kubernetes::test::kube_partial.
Found one bug, fixed it, now should be ready to merge.

Waiting on review!

ktff · 2020-03-31T08:05:37Z

I have troubles when running new cd tests; make test-kubernetes utility.

What kind of troubles? If it's relevant, could you post some last 100 lines of the log output here #1635, or open a new issue with it, so I can take a look.

MOZGIII · 2020-04-01T00:44:27Z

@ktff created #2193, hope it helps

ktff

As noted in the comment about CRI, the detection of partial message in case of a CRI runtime needs to be changed. This is made more complex by not knowing in what runtime we are until the first message. Check this function to see how we are detecting that. Maybe we could add a field to signal if we are in the Docker or CRI runtime.

ktff · 2020-04-01T08:49:39Z

.meta/sources/kubernetes.toml.bak

@@ -38,6 +38,14 @@ of `kube-system`. Which is by default excluded, \
 unless there are any non empty `include` options.\
 """

+[sources.kubernetes.options.auto_partial_merge]
+type = "bool"
+common = true


Majority of the logs won't be separated, so I wouldn't consider it common.

This is how it is in docker source, but I don't mind changing this.
@binarylogic what do you think?

Agree that this should be false. I don't think this is a common option that users should be changing.

ktff · 2020-04-01T13:56:10Z

src/sources/kubernetes/mod.rs

+            .filter_map(move |event| now.filter(event));
+
+        let stream: Box<dyn Stream<Item = Event, Error = _> + Send> = if self.auto_partial_merge {
+            let mut transform_merge_partial_events = transform_merge_partial_events();


This approach to merging won't work with CRI runtimes. Implementations of it usually leave newline from the ~~stdin~~ stdout, and don't put it if the log was broken in multiple parts, instead they add a tag which we extract here to a field multiline_tag.

This is evident if you test it against Kubernetes cluster with CRI runtime, for example microk8s.

Good catch! Thanks for pointing this out. Indeed, we can't merge before this is corrected.

lukesteensen · 2020-04-14T18:24:04Z

@MOZGIII could you re-request review once this is ready to go? I'm going to remove the review requests for now so we stop getting reminded.

MOZGIII · 2020-05-20T06:28:50Z

Closing this in favor of a k8s rework as part of the #2222.

MOZGIII requested review from lukesteensen, binarylogic and ktff March 24, 2020 23:22

MOZGIII force-pushed the kubernetes-partial-message-merge branch 2 times, most recently from 2e33b06 to 9310817 Compare March 24, 2020 23:30

MOZGIII added 9 commits March 25, 2020 02:59

Generalize merge transform around log event normalizer

3b562ed

Signed-off-by: MOZGIII <[email protected]>

Add TrailingNewlineNormalizer

3c97d45

Signed-off-by: MOZGIII <[email protected]>

Move src/transforms/merge.rs to src/transforms/merge/mod.rs

5b04af2

Signed-off-by: MOZGIII <[email protected]>

Split normalizers into a normalizer mod

960be0a

Signed-off-by: MOZGIII <[email protected]>

Add normalizer tests

1ae3037

Signed-off-by: MOZGIII <[email protected]>

Add support for partial events merging at kubernetes source

f7a6ec3

Signed-off-by: MOZGIII <[email protected]>

Add an integration test for partial message merging at kubernetes

bed4c6e

Signed-off-by: MOZGIII <[email protected]>

Add the ability to opt-out from automatic partial events merging

dd009a8

Signed-off-by: MOZGIII <[email protected]>

Use defaults at sources::kubernetes::file_source_builder::tests::all_…

24fcf58

…filters Signed-off-by: MOZGIII <[email protected]>

MOZGIII force-pushed the kubernetes-partial-message-merge branch from 99982c3 to 24fcf58 Compare March 24, 2020 23:59

Hoverbear assigned MOZGIII Mar 25, 2020

Hoverbear mentioned this pull request Mar 25, 2020

Missing kubernetes labels on GH issues #2151

Closed

MOZGIII added 2 commits March 26, 2020 23:17

Make the partial test easier for human to check

f22d088

Signed-off-by: MOZGIII <[email protected]>

Add special test case for bare newline

0b79d1c

Signed-off-by: MOZGIII <[email protected]>

MOZGIII added 2 commits March 26, 2020 23:49

Fix feature flags

89e2799

Signed-off-by: MOZGIII <[email protected]>

Add documentation

bd206e1

Signed-off-by: MOZGIII <[email protected]>

MOZGIII added 2 commits March 31, 2020 05:31

Merge branch 'master' into kubernetes-partial-message-merge

3a0793b

Signed-off-by: MOZGIII <[email protected]>

Correct the default value for auto_partial_merge

f3e4b2e

Signed-off-by: MOZGIII <[email protected]>

MOZGIII mentioned this pull request Apr 1, 2020

Kubernetes tests don't work locally #2193

Closed

ktff suggested changes Apr 1, 2020

View reviewed changes

ktff mentioned this pull request Apr 3, 2020

fix(kubernetes source)!: Use Pod's UID to exclude Vector's logs #2188

Closed

lukesteensen removed request for lukesteensen and binarylogic April 14, 2020 18:24

MOZGIII mentioned this pull request Apr 22, 2020

chore: Kubernetes Integration RFC #2222

Merged

MOZGIII closed this May 20, 2020

binarylogic deleted the kubernetes-partial-message-merge branch July 23, 2020 17:30

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

enhancement(kubernetes source): Kubernetes partial message merge #2134

enhancement(kubernetes source): Kubernetes partial message merge #2134

MOZGIII commented Mar 24, 2020 •

edited

Loading

MOZGIII commented Mar 24, 2020 •

edited

Loading

ktff commented Mar 25, 2020

MOZGIII commented Mar 25, 2020 •

edited

Loading

binarylogic commented Mar 25, 2020

LucioFranco commented Mar 25, 2020

MOZGIII commented Mar 25, 2020

LucioFranco commented Mar 25, 2020

MOZGIII commented Mar 25, 2020 •

edited

Loading

LucioFranco commented Mar 25, 2020 •

edited

Loading

MOZGIII commented Mar 25, 2020

LucioFranco commented Mar 25, 2020

MOZGIII commented Mar 25, 2020

MOZGIII commented Mar 26, 2020 •

edited

Loading

MOZGIII commented Mar 26, 2020 •

edited

Loading

ktff commented Mar 27, 2020 •

edited

Loading

MOZGIII commented Mar 27, 2020

MOZGIII commented Mar 31, 2020 •

edited

Loading

ktff commented Mar 31, 2020

MOZGIII commented Apr 1, 2020

ktff left a comment

ktff Apr 1, 2020

MOZGIII Apr 21, 2020

binarylogic Apr 21, 2020

ktff Apr 1, 2020 •

edited

Loading

MOZGIII Apr 7, 2020

lukesteensen commented Apr 14, 2020

MOZGIII commented May 20, 2020

enhancement(kubernetes source): Kubernetes partial message merge #2134

enhancement(kubernetes source): Kubernetes partial message merge #2134

Conversation

MOZGIII commented Mar 24, 2020 • edited Loading

MOZGIII commented Mar 24, 2020 • edited Loading

ktff commented Mar 25, 2020

MOZGIII commented Mar 25, 2020 • edited Loading

binarylogic commented Mar 25, 2020

LucioFranco commented Mar 25, 2020

MOZGIII commented Mar 25, 2020

LucioFranco commented Mar 25, 2020

MOZGIII commented Mar 25, 2020 • edited Loading

LucioFranco commented Mar 25, 2020 • edited Loading

MOZGIII commented Mar 25, 2020

LucioFranco commented Mar 25, 2020

MOZGIII commented Mar 25, 2020

MOZGIII commented Mar 26, 2020 • edited Loading

MOZGIII commented Mar 26, 2020 • edited Loading

ktff commented Mar 27, 2020 • edited Loading

MOZGIII commented Mar 27, 2020

MOZGIII commented Mar 31, 2020 • edited Loading

ktff commented Mar 31, 2020

MOZGIII commented Apr 1, 2020

ktff left a comment

Choose a reason for hiding this comment

ktff Apr 1, 2020

Choose a reason for hiding this comment

MOZGIII Apr 21, 2020

Choose a reason for hiding this comment

binarylogic Apr 21, 2020

Choose a reason for hiding this comment

ktff Apr 1, 2020 • edited Loading

Choose a reason for hiding this comment

MOZGIII Apr 7, 2020

Choose a reason for hiding this comment

lukesteensen commented Apr 14, 2020

MOZGIII commented May 20, 2020

MOZGIII commented Mar 24, 2020 •

edited

Loading

MOZGIII commented Mar 24, 2020 •

edited

Loading

MOZGIII commented Mar 25, 2020 •

edited

Loading

MOZGIII commented Mar 25, 2020 •

edited

Loading

LucioFranco commented Mar 25, 2020 •

edited

Loading

MOZGIII commented Mar 26, 2020 •

edited

Loading

MOZGIII commented Mar 26, 2020 •

edited

Loading

ktff commented Mar 27, 2020 •

edited

Loading

MOZGIII commented Mar 31, 2020 •

edited

Loading

ktff Apr 1, 2020 •

edited

Loading