Vector: Crash on rate limiting in S3 sink

[anton-ryzhov]

Version: vector 0.7.0 (v0.7.0 x86_64-unknown-linux-musl 2020-01-22)

Config:

[sources.infile]
  type = "file"
  include = ["100mb.log"]

[sinks.aws_s3]
  type = "aws_s3"
  inputs = ["infile"]

  region = "region"
  bucket = "bucket"

  encoding = "ndjson"
  compression = "none"

  [sinks.aws_s3.batch]
    max_size = 102400

  [sinks.aws_s3.request]
    in_flight_limit = 1000000   # Very big number
    rate_limit_num = 1000000    # Very big number

max_size = 102400 is set to small value for generating more concurrent requests.
I create this 100mb.log file and then run vector — everything works fine.

But when I put in_flight_limit = 1 with RUST_BACKTRACE=full I'm getting this exception:

Jan 22 16:21:31.336  INFO source{name=infile type=file}:file_server: file_source::file_server: Found file to watch. path="100mb.log" file_position=0
thread 'tokio-runtime-worker-0' panicked at 'max requests in-flight; poll_ready must be called first', /opt/rust/registry/src/github.com-1ecc6299db9ec823/tower-limit-0.1.1/src/concurrency/service.rs:78:13
stack backtrace:
   0:           0xc1170a - <unknown>
   1:           0x7086cc - <unknown>
   2:           0xc10ea6 - <unknown>
   3:           0xc10af3 - <unknown>
   4:           0xc10185 - <unknown>
   5:          0x1695524 - <unknown>
   6:          0x10c79cb - <unknown>
   7:           0xf4339f - <unknown>
   8:          0x113e749 - <unknown>
   9:          0x159b0f2 - <unknown>
  10:          0x159769a - <unknown>
  11:          0x10b0a44 - <unknown>
  12:          0x10b0496 - <unknown>
  13:          0x1124dbe - <unknown>
  14:          0x15c504b - <unknown>
  15:          0x100abf0 - <unknown>
  16:           0xc6d839 - <unknown>
  17:           0xc697c6 - <unknown>
  18:           0xc68d77 - <unknown>
  19:           0xc4099f - <unknown>
  20:           0xc439de - <unknown>
  21:           0xc6633b - <unknown>
  22:           0xc66c4a - <unknown>
  23:           0xc24def - <unknown>
  24:           0xc274e0 - <unknown>
Jan 22 16:21:31.362 ERROR vector::topology: Unhandled error
Jan 22 16:21:31.362  INFO vector: Shutting down.
Jan 22 16:21:31.363 ERROR source{name=infile type=file}: vector::buffers: sender error: SendError("...")
Jan 22 16:21:31.363 ERROR vector::topology: Unhandled error
Jan 22 16:21:31.363 ERROR source{name=infile type=file}: vector::sources::file: e=send failed because receiver is gone

Same for rate_limit_num = 1, it fails with another trace:

Jan 22 16:21:35.610  INFO source{name=infile type=file}:file_server: file_source::file_server: Found file to watch. path="100mb.log" file_position=0
Jan 22 16:21:35.617 TRACE sink{name=aws_s3 type=aws_s3}: tower_limit::rate::service: rate limit exceeded, disabling service
thread 'tokio-runtime-worker-2' panicked at 'service not ready; poll_ready must be called first', /opt/rust/registry/src/github.com-1ecc6299db9ec823/tower-limit-0.1.1/src/rate/service.rs:107:35
stack backtrace:
   0:           0xc1170a - <unknown>
   1:           0x7086cc - <unknown>
   2:           0xc10ea6 - <unknown>
   3:           0xc10af3 - <unknown>
   4:           0xc10185 - <unknown>
   5:          0x1695524 - <unknown>
   6:          0x13d7333 - <unknown>
   7:          0x10c7960 - <unknown>
   8:           0xf4339f - <unknown>
   9:          0x113e749 - <unknown>
  10:          0x159b0f2 - <unknown>
  11:          0x159769a - <unknown>
  12:          0x10b0a44 - <unknown>
  13:          0x10b0496 - <unknown>
  14:          0x1124dbe - <unknown>
  15:          0x15c504b - <unknown>
  16:          0x100abf0 - <unknown>
  17:           0xc6d839 - <unknown>
  18:           0xc697c6 - <unknown>
  19:           0xc68d77 - <unknown>
  20:           0xc4099f - <unknown>
  21:           0xc439de - <unknown>
  22:           0xc6633b - <unknown>
  23:           0xc66c4a - <unknown>
  24:           0xc24def - <unknown>
  25:           0xc274e0 - <unknown>
Jan 22 16:21:35.634 ERROR vector::topology: Unhandled error
Jan 22 16:21:35.634  INFO vector: Shutting down.
Jan 22 16:21:35.635 ERROR source{name=infile type=file}: vector::buffers: sender error: SendError("...")
Jan 22 16:21:35.635 ERROR vector::topology: Unhandled error

I also tested same way rate limiting with http sink — it works fine.

[lukesteensen]

Thanks for reporting this @anton-ryzhov! I apologize for the trouble. We'll start digging into this right away.

[LucioFranco]

Yup, there was a small bug in our Map service implementation, here is the fix PR https://github.com/timberio/vector/pull/1569

[anton-ryzhov]

That was fast!

[lukesteensen]

Great bug reports really help! Thanks again @anton-ryzhov