tkrs / poston Goto Github PK

View Code? Open in Web Editor NEW

6.0 3.0 0.0 230 KB

Yet another Fluentd logger for Rust 💎

License: MIT License

Rust 100.00%

fluentd-logger fluentd

poston's Introduction

poston

Yet another fluentd logger for Rust

Usage

See examples

poston's People

Contributors

Stargazers

Watchers

poston's Issues

Many ACKs and chunks do not match

Once the incorrect ack comes back, many same errors occur after that.

[2019-02-26T17:37:53Z WARN  poston::emitter] Did not match ack and chunk. ack: MDc0M2FhNmEtMDI5NS00NmQ4LTk5ZTQtNDViZDcxZTU1NDcy, chunk: ZDQ1YzhhMzQtYWE4Zi00ZTI3LTk4ZTItMmNiNTQwMzMyYjg4.
[2019-02-26T17:37:55Z WARN  poston::emitter] Did not match ack and chunk. ack: ZDQ1YzhhMzQtYWE4Zi00ZTI3LTk4ZTItMmNiNTQwMzMyYjg4, chunk: YjRlYzY3OWItMzRiMy00MDI3LWFiMTItNTc0OTM5YzZiY2I4.
[2019-02-26T17:37:55Z WARN  poston::emitter] Did not match ack and chunk. ack: YjRlYzY3OWItMzRiMy00MDI3LWFiMTItNTc0OTM5YzZiY2I4, chunk: MDllNWE5NWYtYWYyZS00NzU5LThiMmQtMTJkOWI1YmE2OTZm.
[2019-02-26T17:37:56Z WARN  poston::emitter] Did not match ack and chunk. ack: MDllNWE5NWYtYWYyZS00NzU5LThiMmQtMTJkOWI1YmE2OTZm, chunk: NTJlM2VhY2QtN2JjNC00YzQxLTk5NmEtYjc2M2JmMjE1YTE1.
[2019-02-26T17:37:57Z WARN  poston::emitter] Did not match ack and chunk. ack: NTJlM2VhY2QtN2JjNC00YzQxLTk5NmEtYjc2M2JmMjE1YTE1, chunk: NGMwZjIxM2YtMGU0Ny00Mzk2LTkxMWItYTgwYzExOGNhMTli.
[2019-02-26T17:37:58Z WARN  poston::emitter] Did not match ack and chunk. ack: NGMwZjIxM2YtMGU0Ny00Mzk2LTkxMWItYTgwYzExOGNhMTli, chunk: OTEwZGM3YzctODMyOC00ZTlkLTg4ZWItZjZmMWY0N2FlNjA2.
[2019-02-26T17:37:58Z WARN  poston::emitter] Did not match ack and chunk. ack: OTEwZGM3YzctODMyOC00ZTlkLTg4ZWItZjZmMWY0N2FlNjA2, chunk: YjkzNzc1MGYtM2MwNi00MTI4LTk1MjItOWYyNjkyYmUzOWFh.
[2019-02-26T17:37:59Z WARN  poston::emitter] Did not match ack and chunk. ack: YjkzNzc1MGYtM2MwNi00MTI4LTk1MjItOWYyNjkyYmUzOWFh, chunk: ZWEzNmZmYzQtMDhiMC00N2IwLThiOTktNzliYzg1ODQ1YjU1.
[2019-02-26T17:38:00Z WARN  poston::emitter] Did not match ack and chunk. ack: ZWEzNmZmYzQtMDhiMC00N2IwLThiOTktNzliYzg1ODQ1YjU1, chunk: NGE1YzdkMjktZTQ3Zi00YTMxLWFkNmYtYzdiYTc2NWQ1MmJk.
[2019-02-26T17:38:01Z WARN  poston::emitter] Did not match ack and chunk. ack: NGE1YzdkMjktZTQ3Zi00YTMxLWFkNmYtYzdiYTc2NWQ1MmJk, chunk: NjM0MWVkYjUtODhjNC00OGQ1LWE3MjYtY2M1MzZjNjFlNzhm.
[2019-02-26T17:38:01Z WARN  poston::emitter] Did not match ack and chunk. ack: NjM0MWVkYjUtODhjNC00OGQ1LWE3MjYtY2M1MzZjNjFlNzhm, chunk: ZDYxMTMzOGMtMWU4NS00Yjc3LWFiODAtNjQxZDhkYzAyYWYz.
[2019-02-26T17:38:03Z WARN  poston::emitter] Did not match ack and chunk. ack: ZDYxMTMzOGMtMWU4NS00Yjc3LWFiODAtNjQxZDhkYzAyYWYz, chunk: NDZhNGE4ZDItN2M3OC00YmVhLTgyYjQtZmM1MWJkNzgyYzc4.
[2019-02-26T17:38:03Z WARN  poston::emitter] Did not match ack and chunk. ack: NDZhNGE4ZDItN2M3OC00YmVhLTgyYjQtZmM1MWJkNzgyYzc4, chunk: YzhhZDJlMzYtMjhjOC00ZWU5LWJhYTAtZjcxZWJiMzcxYjA4.
[2019-02-26T17:38:03Z WARN  poston::emitter] Did not match ack and chunk. ack: YzhhZDJlMzYtMjhjOC00ZWU5LWJhYTAtZjcxZWJiMzcxYjA4, chunk: ZGQ2Mzg0OTktNWFiZC00ODQ2LTliYjktYjdhNjVkYzU1NzA4.

Didn't retry after the reconnect was successful.

poston/src/connect.rs

Line 160 in 9f68ddc

| io::ErrorKind::ConnectionAborted => self.reconnect(),

v0.7.5 was broken

Run the example:

 cargo run --example main
    Finished dev [unoptimized + debuginfo] target(s) in 0.05s
     Running `target/debug/examples/main`
 INFO  poston::client > Worker creating...
 DEBUG poston::connect > Start connect to "127.0.0.1:24224"
 INFO  poston::client  > Sending terminate message to worker.
 DEBUG poston::connect > Failed to read response, chunk: QHgESbRQQ0KnfDEFqWsYJQ==, cause: Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" }
 WARN  poston::connect > Failed to read response, chunk: QHgESbRQQ0KnfDEFqWsYJQ==, cause: Transient(Network("Resource temporarily unavailable (os error 11)"))
 ERROR poston::queue   > Tag 'test.human.age.67' unexpected error occurred during emitting message, cause: 'Network("Resource temporarily unavailable (os error 11)")'

it is probably caused by updating base64.

https://github.com/tkrs/poston/releases/tag/v0.7.5

Need the client closing manually

Because it is cannot drop when the WorkerPool created as the static lifetime.

Consider allocation size of entries

poston/src/emitter.rs

Lines 39 to 41 in 96d9e63

 let size = size.unwrap_or_else(|| queue.len()); 

 let mut entries = Vec::with_capacity(size); 

 queue.take(&mut entries);

Here, wasteful capacity was allocated when the queue length is smaller than size of args.

Should sleep before the reconnect

It does not make sense to reconnect immediately as soon as Fluentd starts reloading.

Single event writing should be supported

Unrecognized option: 'write-mode' on nightly build

https://circleci.com/gh/tkrs/poston/126?utm_campaign=vcs-integration-link&utm_medium=referral&utm_source=github-build-link

Returns an error instead of panic if the connection can't be opened

It would be nice if an error could be sent back when we create the workerPool and the connection can't be opened. For now, it panics and it is not user-friendly. I would like to be able to handle those errors.

Does it make sense to you ?

Replace standard-version with release-please

https://github.com/googleapis/release-please

Heartbeat

Failover for connection

I want to switch to file output when TCP connection fails to some extent.

Rename RetryableConnect with ReconnectableWrite

It would be better.

Test fails on Windows

https://docs.microsoft.com/en-us/windows/desktop/api/minwinbase/ns-minwinbase-filetime

Contains a 64-bit value representing the number of 100-nanosecond intervals since January 1, 1601 (UTC).

Should re-write with re-connect when the write_all returned NotConnected Error

Consider log-level

Move examples here

https://github.com/tkrs/rust-sandbox/tree/master/fluent-main

An empty response continues

❯ cargo run --example main
   Compiling poston v0.3.1 (/Users/tkrs/code/github.com/tkrs/poston)
    Finished dev [unoptimized + debuginfo] target(s) in 5.20s
     Running `target/debug/examples/main`
 INFO  main > Start.
 INFO  main > Start sending messages. No 0.
 INFO  main > Start sending messages. No 1.
 INFO  main > Start sending messages. No 2.
 INFO  main > Start sending messages. No 3.
 INFO  main > Start sending messages. No 5.
 INFO  main > Start sending messages. No 8.
 INFO  main > Start sending messages. No 6.
 INFO  main > Start sending messages. No 9.
 DEBUG poston::client > Worker 0 creating...
 DEBUG poston::connect > Start connect to "127.0.0.1:24224".
 INFO  main            > Start sending messages. No 4.
 INFO  main > Start sending messages. No 7.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.
 WARN  poston::emitter > Failed to received ack response. chunk: ZjkxNjQ3YTgtOWNkMS00ZDJmLThmMDktODA0YjI1NzVkNjA3.

No need for multiple run workers

Client SHOULD retry to send events later when ...

https://github.com/fluent/fluentd/wiki/Forward-Protocol-Specification-v1#response

Did not match ack and chunk

Once Failed to read response, many same errors and twice write occur after that. Here are logs:

2020-09-15T13:25:54.035897792+00:00 - [fluent-worker-pool][WARN] - Failed to read response, chunk: OTk3ZDcxNTktNjUzMC00NTZmLTljN2UtODliMzhkODE1NmUx, cause: Transient(NetworkError("Resource temporarily unavailable (os error 11)"))
2020-09-15T13:26:04.591909981+00:00 - [fluent-worker-pool][WARN] - Failed to read response, chunk: OTk3ZDcxNTktNjUzMC00NTZmLTljN2UtODliMzhkODE1NmUx, cause: Transient(NetworkError("Resource temporarily unavailable (os error 11)"))
2020-09-15T13:26:06.540205861+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: OTk3ZDcxNTktNjUzMC00NTZmLTljN2UtODliMzhkODE1NmUx, chunk: YzAyZTVhYjgtYjRmNS00Y2JmLWEwMzYtMGQ1YzRkZGU1NWNl
2020-09-15T13:26:09.714639498+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: NDNhNjFhY2MtZTlhMC00NWQ0LThkNGYtOWVmZTkyY2UyM2Q0, chunk: ZGEwNzMwZjktZTVmMC00ZDE5LWFmMmMtMzY1NWJkZTZhOGEx
2020-09-15T13:26:13.858623537+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: ODAzYzA4ODQtMjdjYS00NTU2LTk2ZTgtZGZiYTE0OGU1YWIz, chunk: ZWI1YmU4NzItYTNlNS00ZDE5LTlkMTQtMjUxMGY3MWQ0MGIw
2020-09-15T13:26:14.173476908+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: ZTBhODZmYjItOGE3NC00MjA0LTkwMzAtYzBkZTY5YTExMDYz, chunk: MDhmNzI1NWUtNmY0YS00MzU1LTk3ZDUtOTBmY2NmNDI4MTBi
2020-09-15T13:26:14.298042783+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: MDhmNzI1NWUtNmY0YS00MzU1LTk3ZDUtOTBmY2NmNDI4MTBi, chunk: MjU0NTA1MTctMDA4Ny00NjRjLTkzM2QtNGUzOWUzNzBkMjU4
2020-09-15T13:26:14.438972065+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: MjU0NTA1MTctMDA4Ny00NjRjLTkzM2QtNGUzOWUzNzBkMjU4, chunk: YmRjZjM3OGUtOWJkYi00NWI5LWJlMjYtNmNiNDI0MDYwZmEw
2020-09-15T13:26:14.656711886+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: YmRjZjM3OGUtOWJkYi00NWI5LWJlMjYtNmNiNDI0MDYwZmEw, chunk: OGQzNDkyNjMtNmQ2Yy00OTc0LWIzZjItZTg3NzU3OTJlNDUx
2020-09-15T13:26:14.810611582+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: OGQzNDkyNjMtNmQ2Yy00OTc0LWIzZjItZTg3NzU3OTJlNDUx, chunk: ZjYxMjIyMjctZTUyOC00MjUzLThjZmEtNGZlNDRlYzc2MGQy
2020-09-15T13:26:14.894403624+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: ZjYxMjIyMjctZTUyOC00MjUzLThjZmEtNGZlNDRlYzc2MGQy, chunk: MzNhYWMzMDktMGU3OC00Y2Q3LThkOGEtNGM0MmVlNDZmZDM0
2020-09-15T13:26:15.301887782+00:00 - [fluent-worker-pool][WARN] - Did not match ack and chunk, ack: NzVkY2M1ZTYtMDMyNC00NTk0LThmNDItYjliMmJlYmJiNzRh, chunk: MzdjZTM5ZmYtOWZmNi00MTZmLTkxY2YtMWE3ODQxNWVhMmYz

There are 2 bugs.

The error "Resource temporarily unavailable (os error 11)" should be handled differently, or should be ignored. It means we will receive the response, but with a delay.
After this case all messages are sent several times. It depends on the settings write_retry_timeout and read_retry_timeout
by default write_retry_timeout is 30 secs, read_retry_timeout 10 secs. Messages are sent twice for these settings.
I see nested closure with backoff pattern in the method
fn write_and_read(&mut self, buf: &[u8], chunk: &str) -> Result<(), Error>, file https://github.com/tkrs/poston/blob/master/src/connect.rs.
External closure with write works successfully once, and nested read_backoff is failed after 10 secs. It means that external backoff also is failed, but writes to socket. So it will write again the same message on next backoff step because it has a 30 secs timeout. I thinк write_retry_timeout should be less or equal than read_retry_timeout.
Anyway the nested backoff is hard to understand and the kind of anti pattern. May be needs refactoring write_and_read function.

Thanks

No longer needs borrowing channel receiver

In #93, the number of workers is reduced to 1, so borrowing by Arc and Mutex is no longer necessary.

Adopt ihrwein/backoff for the retry handle

https://github.com/ihrwein/backoff

	let size = size.unwrap_or_else(\|\| queue.len());
	let mut entries = Vec::with_capacity(size);
	queue.take(&mut entries);