You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@nifi.apache.org by GitBox <gi...@apache.org> on 2019/04/04 12:34:29 UTC
[GitHub] [nifi] kourge-ch commented on issue #3276: NIFI-5953 Manage GetTwitter connection retries on '420 Enhance Your C…
kourge-ch commented on issue #3276: NIFI-5953 Manage GetTwitter connection retries on '420 Enhance Your C…
URL: https://github.com/apache/nifi/pull/3276#issuecomment-479878565
hello @ijokarumawak,
I have run some tests with the `GetTwitter` processor before and after the change.
First; before the change, a test was run with `GetTwitter` processor in version `1.7.1`. Here `client.reconnect()` is called after each `HTTP_ERROR` (including 420 errors). The default number of retries before stopping is 5.
On `HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm` messages, the client will try to reconnect after 5s, 10s, 20s, 40s and 1m20s, and then stops with `STOPPED_BY_ERROR: Retries exhausted`.
detailed log here for test 1:
```
2019-04-04 08:27:07,198 INFO [NiFi Web Server-1427] o.a.n.c.s.StandardProcessScheduler Starting GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814]
2019-04-04 08:27:07,271 INFO [Timer-Driven Process Thread-8] com.twitter.hbc.httpclient.BasicClient New connection executed: GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814], endpoint: /1.1/statuses/filter.json?delimited=length&stall_warnings=true
2019-04-04 08:27:07,274 INFO [Timer-Driven Process Thread-8] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] to run with 1 threads
2019-04-04 08:27:07,303 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Establishing a connection
2019-04-04 08:27:07,546 INFO [Flow Service Tasks Thread-1] o.a.nifi.controller.StandardFlowService Saved flow controller org.apache.nifi.controller.FlowController@6b8c9cdb // Another save pending = false
2019-04-04 08:27:08,028 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 08:27:09,276 ERROR [Timer-Driven Process Thread-3] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 08:27:13,029 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Done processing, preparing to close connection
2019-04-04 08:27:13,032 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Establishing a connection
2019-04-04 08:27:13,669 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 08:27:14,277 ERROR [Timer-Driven Process Thread-3] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 08:27:23,670 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Done processing, preparing to close connection
2019-04-04 08:27:23,672 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Establishing a connection
2019-04-04 08:27:24,347 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 08:27:25,280 ERROR [Timer-Driven Process Thread-3] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 08:27:44,347 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Done processing, preparing to close connection
2019-04-04 08:27:44,349 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Establishing a connection
2019-04-04 08:27:44,994 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 08:27:46,286 ERROR [Timer-Driven Process Thread-8] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 08:28:24,994 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Done processing, preparing to close connection
2019-04-04 08:28:24,996 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Establishing a connection
2019-04-04 08:28:25,778 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 08:28:25,789 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 69 milliseconds (Stop-the-world time = 16 milliseconds, Clear Edit Logs time = 32 millis), max Transaction ID 368
2019-04-04 08:28:26,297 ERROR [Timer-Driven Process Thread-4] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 08:29:03,473 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 08:29:03,473 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 08:29:45,778 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Done processing, preparing to close connection
2019-04-04 08:29:45,781 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Establishing a connection
2019-04-04 08:29:46,495 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 08:29:46,495 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] exit event - Retries exhausted
2019-04-04 08:29:46,495 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Done processing, preparing to close connection
2019-04-04 08:29:46,496 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Shutting down httpclient connection manager
2019-04-04 08:29:47,316 ERROR [Timer-Driven Process Thread-9] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 08:29:48,316 ERROR [Timer-Driven Process Thread-9] o.a.nifi.processors.twitter.GetTwitter GetTwitter[id=e7733d6d-0169-1000-c703-fe76dd72b814] Received error STOPPED_BY_ERROR: Retries exhausted due to null. Will not attempt to reconnect
```
Then another test was done after the change. Here `client.reconnect()` is not called after `HTTP_ERROR`. The number of retries have been made configurable (new property `MAX_CONNECTION_RETRIES`). I set its value to 10.
So there, on `HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm` messages, the client will try to reconnect after 5s, 10s, 20s, 40s, 1m20s, 2m40s, 5m20s, 5m20s, 5m20s, 5m20s and then stops with `STOPPED_BY_ERROR: Retries exhausted`.
Retry delay will not exceet 320s (5m20s) because of the `BasicReconnectionManager` configuration:
https://github.com/twitter/hbc/blob/hbc-2.2.0/hbc-core/src/main/java/com/twitter/hbc/BasicReconnectionManager.java#L25-L29
INITIAL_EXPONENTIAL_BACKOFF_MILLIS = 5000;
MAX_EXPONENTIAL_BACKOFF_MILLIS = 320000;
This page https://developer.twitter.com/en/docs/basics/rate-limiting.html ("Exponential back-off pattern for streaming" section) explains that the client should implement an exponential back-off pattern in subsequent reconnection attempts (e.g. wait 1 second, then 2 seconds, then 4, 8, 16, etc), with some reasonable upper limit.
detailed log here for test 2:
```
2019-04-04 09:01:07,753 INFO [NiFi Web Server-1485] o.a.n.c.s.StandardProcessScheduler Starting GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97]
2019-04-04 09:01:07,762 INFO [Timer-Driven Process Thread-3] com.twitter.hbc.httpclient.BasicClient New connection executed: GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97], endpoint: /1.1/statuses/filter.json?delimited=length&stall_warnings=true
2019-04-04 09:01:07,762 INFO [Timer-Driven Process Thread-3] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] to run with 1 threads
2019-04-04 09:01:07,763 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:01:08,149 INFO [Flow Service Tasks Thread-1] o.a.nifi.controller.StandardFlowService Saved flow controller org.apache.nifi.controller.FlowController@6b8c9cdb // Another save pending = false
2019-04-04 09:01:08,671 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_xU89nE0M8Mz5TpWr2r1VmQ=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:08 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:08 GMT
2019-04-04 09:01:08,671 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436846837841547; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:08 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:08 GMT
2019-04-04 09:01:08,672 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:01:09,763 WARN [Timer-Driven Process Thread-2] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:01:13,672 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:01:13,674 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:01:14,346 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_1hs/vwq7sNKfxwcbVtlNvw=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:14 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:14 GMT
2019-04-04 09:01:14,346 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436847426116500; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:14 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:14 GMT
2019-04-04 09:01:14,346 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:01:14,764 WARN [Timer-Driven Process Thread-2] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:01:24,346 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:01:24,348 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:01:25,055 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_Pilx2VwmvihGb5oFZXwgOg=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:24 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:24 GMT
2019-04-04 09:01:25,055 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436848497343578; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:24 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:24 GMT
2019-04-04 09:01:25,056 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:01:25,767 WARN [Timer-Driven Process Thread-2] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:01:45,056 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:01:45,058 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:01:45,808 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_Ey60FJtWi/9F4KYZcauKTA=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:45 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:45 GMT
2019-04-04 09:01:45,808 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436850572032044; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:01:45 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:01:45 GMT
2019-04-04 09:01:45,808 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:01:46,770 WARN [Timer-Driven Process Thread-10] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:02:25,808 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:02:25,812 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:02:26,493 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_aAXwjWrLTjl2Um1oQGhauA=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:02:26 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:02:26 GMT
2019-04-04 09:02:26,494 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436854640535136; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:02:26 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:02:26 GMT
2019-04-04 09:02:26,494 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:02:27,779 WARN [Timer-Driven Process Thread-1] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:02:27,823 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 141 milliseconds (Stop-the-world time = 38 milliseconds, Clear Edit Logs time = 62 millis), max Transaction ID 368
2019-04-04 09:03:03,480 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:03:03,480 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:03:46,494 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:03:46,495 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:03:47,175 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_bOan2LuB0JBy1cdcyZhKUA=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:03:47 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:03:47 GMT
2019-04-04 09:03:47,175 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436862708757316; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:03:47 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:03:47 GMT
2019-04-04 09:03:47,177 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:03:47,794 WARN [Timer-Driven Process Thread-3] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:04:27,973 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 150 milliseconds (Stop-the-world time = 39 milliseconds, Clear Edit Logs time = 71 millis), max Transaction ID 368
2019-04-04 09:05:03,480 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:05:03,480 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:06:27,177 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:06:27,179 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:06:27,979 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_36C0ZoMLl4HypSarWK218g=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:06:27 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:06:27 GMT
2019-04-04 09:06:27,980 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436878782160931; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:06:27 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:06:27 GMT
2019-04-04 09:06:27,980 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:06:28,114 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 140 milliseconds (Stop-the-world time = 43 milliseconds, Clear Edit Logs time = 60 millis), max Transaction ID 368
2019-04-04 09:06:28,831 WARN [Timer-Driven Process Thread-7] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:07:03,480 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:07:03,480 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:08:28,253 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 139 milliseconds (Stop-the-world time = 42 milliseconds, Clear Edit Logs time = 61 millis), max Transaction ID 368
2019-04-04 09:09:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:09:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:10:28,363 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 109 milliseconds (Stop-the-world time = 27 milliseconds, Clear Edit Logs time = 52 millis), max Transaction ID 368
2019-04-04 09:11:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:11:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:11:47,980 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:11:47,981 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:11:48,687 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_CC7NhkL4Gq8eskK9WPbVww=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:11:48 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:11:48 GMT
2019-04-04 09:11:48,687 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436910860432095; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:11:48 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:11:48 GMT
2019-04-04 09:11:48,687 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:11:49,886 WARN [Timer-Driven Process Thread-1] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:12:28,490 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 126 milliseconds (Stop-the-world time = 31 milliseconds, Clear Edit Logs time = 60 millis), max Transaction ID 368
2019-04-04 09:13:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:13:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:14:28,636 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 146 milliseconds (Stop-the-world time = 46 milliseconds, Clear Edit Logs time = 60 millis), max Transaction ID 368
2019-04-04 09:15:03,481 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:15:03,482 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:16:28,767 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 130 milliseconds (Stop-the-world time = 42 milliseconds, Clear Edit Logs time = 46 millis), max Transaction ID 368
2019-04-04 09:17:03,482 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:17:03,482 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:17:08,687 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:17:08,689 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:17:09,401 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_Li+Nhhl+Rn+wkrOZpcClwA=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:17:09 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:17:09 GMT
2019-04-04 09:17:09,401 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436942931889047; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:17:09 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:17:09 GMT
2019-04-04 09:17:09,402 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:17:09,961 WARN [Timer-Driven Process Thread-1] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:18:28,899 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 131 milliseconds (Stop-the-world time = 38 milliseconds, Clear Edit Logs time = 56 millis), max Transaction ID 368
2019-04-04 09:19:03,482 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:19:03,482 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:20:29,039 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 139 milliseconds (Stop-the-world time = 39 milliseconds, Clear Edit Logs time = 60 millis), max Transaction ID 368
2019-04-04 09:21:03,482 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:21:03,483 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:22:29,110 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 70 milliseconds (Stop-the-world time = 19 milliseconds, Clear Edit Logs time = 31 millis), max Transaction ID 368
2019-04-04 09:22:29,402 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:22:29,403 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:22:30,136 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_GSOJTjaLu+KDqTCUzcmRMA=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:22:30 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:22:30 GMT
2019-04-04 09:22:30,137 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155436975004499201; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:22:30 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:22:30 GMT
2019-04-04 09:22:30,137 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:22:31,035 WARN [Timer-Driven Process Thread-10] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:23:03,483 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:23:03,483 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:24:29,252 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 142 milliseconds (Stop-the-world time = 42 milliseconds, Clear Edit Logs time = 61 millis), max Transaction ID 368
2019-04-04 09:25:03,483 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:25:03,483 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:26:29,415 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@409b1740 checkpointed with 123 Records and 0 Swap Files in 162 milliseconds (Stop-the-world time = 47 milliseconds, Clear Edit Logs time = 63 millis), max Transaction ID 368
2019-04-04 09:27:03,484 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2019-04-04 09:27:03,484 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 122 records in 0 milliseconds
2019-04-04 09:27:50,137 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:27:50,138 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Establishing a connection
2019-04-04 09:27:50,872 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: personalization_id="v1_MsclDUT7MiCO2xfoPHoR2g=="; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:27:50 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:27:50 GMT
2019-04-04 09:27:50,872 WARN [hosebird-client-io-thread-0] o.a.h.c.protocol.ResponseProcessCookies Invalid cookie header: "set-cookie: guest_id=v1%3A155437007078273225; Max-Age=63072000; Expires=Sat, 3 Apr 2021 09:27:50 GMT; Path=/; Domain=.twitter.com". Invalid 'expires' attribute: Sat, 3 Apr 2021 09:27:50 GMT
2019-04-04 09:27:50,872 WARN [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Error connecting w/ status code - 420, reason - Enhance Your Calm
2019-04-04 09:27:50,872 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] exit event - Retries exhausted
2019-04-04 09:27:50,872 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Done processing, preparing to close connection
2019-04-04 09:27:50,872 INFO [hosebird-client-io-thread-0] com.twitter.hbc.httpclient.ClientBase GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Shutting down httpclient connection manager
2019-04-04 09:27:52,093 WARN [Timer-Driven Process Thread-1] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error HTTP_ERROR: HTTP/1.1 420 Enhance Your Calm. Will attempt to reconnect
2019-04-04 09:27:53,094 ERROR [Timer-Driven Process Thread-1] c.k.nifi.processors.wiip.GetTwitter GetTwitter[id=69741800-9749-3439-9f3c-43b640162b97] Received error STOPPED_BY_ERROR: Retries exhausted due to null. Will not attempt to reconnect
```
So in conclusion the new property introduced to make the number of reties configurable is needed to let a chance to the client to get the connection to Twitter API up and running. With only 5 retries, in my experience I often reach the timeout and lost the connection. In my past test made a few weeks ago I got to the conclusion that I need at least 7 retries. I now set the value to 10 in my configurations.
And after running my last test I also conclude that removing `client.reconnect()` on `HTTP_ERROR` does not change the behavior. So, this part of the merge may be left behind if the risk of regression is too high.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services