zalando-stups / mint-worker

The secret rotator and distributor for the STUPS ecosystem
http://stups.readthedocs.org/en/latest/components/mint.html
Other
9 stars 3 forks source link

No HTTP timeouts configured anywhere #32

Closed ChristianLohmann closed 7 years ago

ChristianLohmann commented 8 years ago

This is an abstract of a memory dump:

pool-3-thread-1" #30 prio=5 os_prio=0 tid=0x00007ffc0c5c3000 nid=0x26 runnable [0x00007ffbe0337000] java.lang.Thread.State: RUNNABLE java.net.SocketInputStream.socketRead0(Native Method) java.net.SocketInputStream.socketRead(SocketInputStream.java:116) java.net.SocketInputStream.read(SocketInputStream.java:170) java.net.SocketInputStream.read(SocketInputStream.java:141) sun.security.ssl.InputRecord.readFully(InputRecord.java:465) sun.security.ssl.InputRecord.read(InputRecord.java:503) sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973) locked <0x00000007089d55e0> (a java.lang.Object) sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375) locked <0x00000007089d5708> (a java.lang.Object) sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403) sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387) org.apache.http.conn.ssl.SSLSocketFactory.connectSocket(SSLSocketFactory.java:543) org.apache.http.conn.ssl.SSLSocketFactory.connectSocket(SSLSocketFactory.java:409) org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:177) org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:304) org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:611) org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:446) org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) clj_http.core$request.invoke(core.clj:298) clojure.lang.Var.invoke(Var.java:379) clj_http.client$wrap_request_timing$fn__2908.invoke(client.clj:796) clj_http.headers$wrap_header_map$fn__983.invoke(headers.clj:143) clj_http.client$wrap_query_params$fn__2821.invoke(client.clj:624) clj_http.client$wrap_basic_auth$fn__2828.invoke(client.clj:640) clj_http.client$wrap_oauth$fn__2832.invoke(client.clj:647) clj_http.client$wrap_user_info$fn__2837.invoke(client.clj:663) clj_http.client$wrap_url$fn__2894.invoke(client.clj:762) clj_http.client$wrap_redirects$fn__2649.invoke(client.clj:237) clj_http.client$wrap_decompression$fn__2668.invoke(client.clj:309) clj_http.client$wrap_input_coercion$fn__2760.invoke(client.clj:460) clj_http.client$wrap_additional_header_parsing$fn__2781.invoke(client.clj:522) clj_http.client$wrap_output_coercion$fn__2751.invoke(client.clj:438) clj_http.client$wrap_exceptions$fn__2635.invoke(client.clj:189) clj_http.client$wrap_accept$fn__2795.invoke(client.clj:565) clj_http.client$wrap_accept_encoding$fn__2801.invoke(client.clj:579) clj_http.client$wrap_content_type$fn__2790.invoke(client.clj:554) clj_http.client$wrap_form_params$fn__2872.invoke(client.clj:722) clj_http.client$wrap_nested_params$fn__2889.invoke(client.clj:755) clj_http.client$wrap_method$fn__2842.invoke(client.clj:670) clj_http.cookies$wrap_cookies$fn__266.invoke(cookies.clj:124) clj_http.links$wrap_links$fn__1167.invoke(links.clj:51) clj_http.client$wrap_unknown_host$fn__2898.invoke(client.clj:771) clj_http.client$post.doInvoke(client.clj:886) clojure.lang.RestFn.invoke(RestFn.java:423) org.zalando.stups.mint.worker.external.services$generate_new_password.invoke(services.clj:36) org.zalando.stups.mint.worker.job.sync_password$sync_password.invoke(sync_password.clj:26) org.zalando.stups.mint.worker.job.sync_app$sync_app.invoke(sync_app.clj:38) org.zalando.stups.mint.worker.job.run$run_sync$fn__6870.invoke(run.clj:48) org.zalando.stups.mint.worker.job.run$run_sync.invoke(run.clj:47) org.zalando.stups.mint.worker.job.run.Jobs$fn__6917$fn__6918$fn__6919.invoke(run.clj:85) clojure.lang.AFn.call(AFn.java:18) org.zalando.stups.txdemarcator.Transactions.runAsBackgroundTransaction(Transactions.java:55) org.zalando.stups.mint.worker.job.run.Jobs$fn__6917$fn__6918.invoke(run.clj:85) org.zalando.stups.friboo.system.cron.NewRelicTracer.callWithTrace(cron.clj:54) sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source) sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) java.lang.reflect.Method.invoke(Method.java:497) clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:93) clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:28) org.zalando.stups.mint.worker.job.run.Jobs$fn__6917.invoke(run.clj:85) clojure.lang.AFn.run(AFn.java:22) java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java) java.lang.Thread.run(Thread.java:745)

at org.zalando.stups.mint.worker.external.services$generate_new_password.invoke(services.clj:36) it seems to hang.

There should be some timeout setting for these cases

prayerslayer commented 8 years ago

I thought this is covered by Hystrix :/

hjacobs commented 8 years ago

@prayerslayer where do you see Hystrix in the stack trace :smirk: ?

hjacobs commented 7 years ago

We need to configure HTTP timeouts for all HTTP calls like here: https://github.com/dakrone/clj-http#post

Recently had the same issue with GCS:


Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: "pool-3-thread-1" #30 prio=5 os_prio=0 tid=0x00007f06fccca800 nid=0x25 runnable [0x00007f06c7ffd000]
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]:    java.lang.Thread.State: RUNNABLE
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at java.net.SocketInputStream.socketRead0(Native Method)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at java.net.SocketInputStream.read(SocketInputStream.java:170)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at java.net.SocketInputStream.read(SocketInputStream.java:141)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at sun.security.ssl.InputRecord.read(InputRecord.java:503)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011- locked <0x00000007466ef6d0> (a java.lang.Object)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011- locked <0x00000007466f1808> (a sun.security.ssl.AppInputStream)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.core$request.invokeStatic(core.clj:298)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.core$request.invoke(core.clj:208)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clojure.lang.Var.invoke(Var.java:379)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_request_timing$fn__4696.invoke(client.clj:796)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.headers$wrap_header_map$fn__3561.invoke(headers.clj:143)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_query_params$fn__4609.invoke(client.clj:624)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_basic_auth$fn__4616.invoke(client.clj:640)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_oauth$fn__4620.invoke(client.clj:647)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_user_info$fn__4625.invoke(client.clj:663)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_url$fn__4682.invoke(client.clj:762)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_redirects$fn__4437.invoke(client.clj:237)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_decompression$fn__4456.invoke(client.clj:309)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_input_coercion$fn__4548.invoke(client.clj:460)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_additional_header_parsing$fn__4569.invoke(client.clj:522)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_output_coercion$fn__4539.invoke(client.clj:438)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_exceptions$fn__4423.invoke(client.clj:189)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_accept$fn__4583.invoke(client.clj:565)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_accept_encoding$fn__4589.invoke(client.clj:579)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_content_type$fn__4578.invoke(client.clj:554)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_form_params$fn__4660.invoke(client.clj:722)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_nested_params$fn__4677.invoke(client.clj:755)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_method$fn__4630.invoke(client.clj:670)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.cookies$wrap_cookies$fn__2845.invoke(cookies.clj:124)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.links$wrap_links$fn__3745.invoke(links.clj:51)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$wrap_unknown_host$fn__4686.invoke(client.clj:771)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$post.invokeStatic(client.clj:886)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clj_http.client$post.doInvoke(client.clj:882)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clojure.lang.RestFn.invoke(RestFn.java:423)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.zalando.stups.mint.worker.external.gcs$post_object.invokeStatic(gcs.clj:16)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.zalando.stups.mint.worker.external.gcs$post_object.invoke(gcs.clj:13)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.zalando.stups.mint.worker.external.gcs$fn__6380.invokeStatic(gcs.clj:28)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.zalando.stups.mint.worker.external.gcs$fn__6380.invoke(gcs.clj:22)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at clojure.lang.MultiFn.invoke(MultiFn.java:243)
Jan  9 11:24:40 ip-172-31-147-108 docker/ec5222c7e0c8[817]: #011at org.zalando.stups.mint.worker.job.sync_app$sync_app$fn__6070.invoke(sync_app.clj:23)
jbellmann commented 7 years ago

Hi, please also have a look at the version used. We had the same in tokens and 'timeouts' were set. There is/was a bug in 'http-components' that make 'timeouts' useless.

Jörg