logstash-plugins/logstash-output-http

java.net.SocketException: Broken pipe (Write failed) when trying to post 150K+ json payload

dclain opened this issue · 2 comments

I'm having issues trying to POST "relatively big" json payloads (150K+) using the output http plugin.

I've tried to increase automatic_retries , connect_timeout, request_timeout, socket_timeout and decrease validate_after_inactivity properties with no success.

I've validated I can post the same payload via Postman or via curl within the logstash instance.
My current workaround is to save the event in a json file using the file output plugin and post it
via curl using the exec output plugin.
But obviously that's not ideal.

I've enabled debugging on http-output plugin and some apache packages (wire and retryExec) (c.f stacktrace below)

It works fine w/ smaller payloads but seems to always fail for anything slightly bigger than 100K or so.
Is this a known issue or is there any limit on the payload size for this plugin?

  • Version: logstash 5.1.1, http-output-plugin 3.1.1 running in a container
  • Operating System: ubuntu 14.04.1
  • config file:
input {
    beats {
        port => 5044
        ssl => true
        ssl_certificate => "/etc/logstash/my.logstash.crt"
        ssl_key => "/etc/logstash/my.logstash.key"
    }
}

filter {
    if [type] == "inventory"  {
        json {
            source => "message"
            remove_field => ["message"]
        }
    }
}

output {
    if [type] == "inventory" {
        http {
            url => "xxxxx/inventory"
            headers => {
                "Content-Type" => "application/json"
            }
            http_method => "post"
            codec => "json"
            automatic_retries => 5
            id => "http_inventory"
            socket_timeout => 1000
            request_timeout => 1000
            validate_after_inactivity => 0
            retry_non_idempotent => true
    }
}

stacktrace:

?21:27:54.670 [pool-186-thread-1] INFO  org.apache.http.impl.execchain.RetryExec - Retrying request to {s}->https://xxxxx:443
?21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "POST /inventory HTTP/1.1[\r][\n]"
{21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "Content-Type: application/json[\r][\n]"
s21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "Connection: Keep-Alive[\r][\n]"
s21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "Content-Length: 183475[\r][\n]"
w21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "Host: xxxxxxx[\r][\n]"
x21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "User-Agent: Manticore 0.6.0[\r][\n]"
z21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "Accept-Encoding: gzip,deflate[\r][\n]"
]21:27:54.706 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "[\r][\n]"
21:27:55.074 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "--- here there's the json payload that i can't really post ---
?21:27:55.103 [pool-186-thread-1] DEBUG org.apache.http.wire - http-outgoing-54 >> "[write] I/O error: Broken pipe (Write failed)"
?21:27:55.104 [pool-186-thread-1] INFO  org.apache.http.impl.execchain.RetryExec - I/O exception (java.net.SocketException) caught when processing request to {s}->https://xxxxx:443: Broken pipe (Write failed)
m21:27:55.104 [pool-186-thread-1] DEBUG org.apache.http.impl.execchain.RetryExec - Broken pipe (Write failed)
5java.net.SocketException: Broken pipe (Write failed)
K	at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:1.8.0_111]
X	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) ~[?:1.8.0_111]
R	at java.net.SocketOutputStream.write(SocketOutputStream.java:153) ~[?:1.8.0_111]
T	at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:431) ~[?:1.8.0_111]
N	at sun.security.ssl.OutputRecord.write(OutputRecord.java:417) ~[?:1.8.0_111]
^	at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:876) ~[?:1.8.0_111]
V	at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:847) ~[?:1.8.0_111]
T	at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:123) ~[?:1.8.0_111]
s	at org.apache.http.impl.conn.LoggingOutputStream.write(LoggingOutputStream.java:77) ~[httpclient-4.5.2.jar:4.5.2]
~	at org.apache.http.impl.io.SessionOutputBufferImpl.streamWrite(SessionOutputBufferImpl.java:126) ~[httpcore-4.4.4.jar:4.4.4]
x	at org.apache.http.impl.io.SessionOutputBufferImpl.write(SessionOutputBufferImpl.java:162) ~[httpcore-4.4.4.jar:4.4.4]
|	at org.apache.http.impl.io.ContentLengthOutputStream.write(ContentLengthOutputStream.java:115) ~[httpcore-4.4.4.jar:4.4.4]
|	at org.apache.http.impl.io.ContentLengthOutputStream.write(ContentLengthOutputStream.java:122) ~[httpcore-4.4.4.jar:4.4.4]
c	at org.apache.http.entity.StringEntity.writeTo(StringEntity.java:169) ~[httpcore-4.4.4.jar:4.4.4]
?	at org.apache.http.impl.DefaultBHttpClientConnection.sendRequestEntity(DefaultBHttpClientConnection.java:158) ~[httpcore-4.4.4.jar:4.4.4]
n	at org.apache.http.impl.conn.CPoolProxy.sendRequestEntity(CPoolProxy.java:162) ~[httpclient-4.5.2.jar:4.5.2]
y	at org.apache.http.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:237) ~[httpcore-4.4.4.jar:4.4.4]
s	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:122) ~[httpcore-4.4.4.jar:4.4.4]
q	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271) ~[httpclient-4.5.2.jar:4.5.2]
m	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184) ~[httpclient-4.5.2.jar:4.5.2]
e	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88) [httpclient-4.5.2.jar:4.5.2]
l	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) [httpclient-4.5.2.jar:4.5.2]
w	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) [httpclient-4.5.2.jar:4.5.2]
v	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:71) [httpclient-4.5.2.jar:4.5.2]
w	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:220) [httpclient-4.5.2.jar:4.5.2]
w	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:164) [httpclient-4.5.2.jar:4.5.2]
H	at sun.reflect.GeneratedMethodAccessor50.invoke(Unknown Source) ~[?:?]
i	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_111]
D	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_111]
b	at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:481) [?:?]
M	at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:336) [?:?]
\	at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:68) [?:?]
T	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:236) [?:?]
?	at rubyjit.Manticore::Response$$call_28e9faa42def46f7b7c11e2eb043499f7b09a0a21173230247.chained_0_rescue_1$RUBY$SYNTHETIC__file__(/usr/share/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.6.0-java/lib/manticore/response.rb:50) [?:?]
?	at rubyjit.Manticore::Response$$call_28e9faa42def46f7b7c11e2eb043499f7b09a0a21173230247.__file__(/usr/share/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.6.0-java/lib/manticore/response.rb:49) [?:?]
?	at rubyjit.Manticore::Response$$call_28e9faa42def46f7b7c11e2eb043499f7b09a0a21173230247.__file__(/usr/share/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.6.0-java/lib/manticore/response.rb) [?:?]
?	at rubyjit.Manticore::Response$$call_28e9faa42def46f7b7c11e2eb043499f7b09a0a21173230247.__file__(/usr/share/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.6.0-java/lib/manticore/response.rb) [?:?]
V	at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:101) [?:?]
S	at Manticore$$Response_875930374.call(Manticore$$Response_875930374.gen:13) [?:?]
K	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_111]
b	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_111]
b	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_111]
8	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_111]

@dclain there's no known issue here. We use Apache HC for the connection, which is ubiquitous, so I doubt the bug is there. Can you try this against another backend server to see if you still get the broken pipe error?

jsvd commented

closing due to idleness + lack of new information