Mantis - Resin
Viewing Issue Advanced Details
1648 minor always 03-15-07 07:18 03-15-07 15:12
sam  
ferg  
urgent  
closed 3.0.22  
fixed  
none    
none 3.1.1  
0001648: Expect: 100-continue with LoadBalanceServlet
(rep by A Balandran)

We are trying to move from apache to resin standalone. During this process we have noticed that when we use the LoadBalanceServlet and the header contains an Expect: 100-continue the request fails on the LoadBalanceServlet server. This causes the client to resend the data and the backend server will receive double requests. The log contains an error

[19:20:11.059] [default->foocity:16] hmux protocol error at f

We can verify this problem by removing the Expect: 100-Continue from the
request header and then everything works fine.

Here is an example log of a series of requests from a client that shows once the Expect header

[19:20:10.688] [hogwarts, 5] POST /cwsreq HTTP/1.1
[19:20:10.688] [hogwarts, 5] Remote-IP: 172.30.50.143:4425
[19:20:10.688] [hogwarts, 5] Host: ssl.4yyy.com
[19:20:10.688] [hogwarts, 5] Accept: */*
[19:20:10.688] [hogwarts, 5] Cookie: JSESSIONID=abc5bfwAjDv6NaE0Spofr
[19:20:10.688] [hogwarts, 5] Content-type: text/xml
[19:20:10.688] [hogwarts, 5] Content-Length: 82
[19:20:10.688] load balance [default->gryffindor:16] URL /cwsreq
[19:20:10.688] load balance [default->gryffindor:16] Host: ssl.4yyy.com
[19:20:10.688] load balance [default->gryffindor:16] Accept: */*
[19:20:10.688] load balance [default->gryffindor:16] Cookie: JSESSIONID=abc5bfwAjDv6NaE0Spofr
[19:20:10.688] load balance [default->gryffindor:16] Content-type: text/xml
[19:20:10.688] load balance [default->gryffindor:16] Content-Length: 82
[19:20:10.697] load balance [default->gryffindor:16] 200 OK
[19:20:10.697] load balance [default->gryffindor:16] Q (keepalive)
[19:20:10.697] [hogwarts, 5] HTTP/1.1 200 OK
[19:20:10.697] [hogwarts, 5] Content-Length: 108
[19:20:10.697] [5] chunk: 108
[19:20:10.697] [hogwarts, 5] keepalive
[19:20:11.035] [hogwarts, 5] POST /cwsreq HTTP/1.1
[19:20:11.035] [hogwarts, 5] Remote-IP: 172.30.50.143:4425
[19:20:11.035] [hogwarts, 5] Host: ssl.4yyy.com
[19:20:11.035] [hogwarts, 5] Accept: */*
[19:20:11.035] [hogwarts, 5] Cookie: JSESSIONID=abc5bfwAjDv6NaE0Spofr
[19:20:11.035] [hogwarts, 5] Content-type: text/xml
[19:20:11.035] [hogwarts, 5] Content-Length: 3561
[19:20:11.035] [hogwarts, 5] Expect: 100-continue
[19:20:11.056] load balance [default->gryffindor:16] URL /cwsreq
[19:20:11.056] load balance [default->gryffindor:16] Host: ssl.4yyy.com
[19:20:11.056] load balance [default->gryffindor:16] Accept: */*
[19:20:11.056] load balance [default->gryffindor:16] Cookie: JSESSIONID=abc5bfwAjDv6NaE0Spofr
[19:20:11.057] load balance [default->gryffindor:16] Content-type: text/xml
[19:20:11.057] load balance [default->gryffindor:16] Content-Length: 3561
[19:20:11.057] load balance [default->gryffindor:16] Expect: 100-continue
[19:20:11.059] [default->gryffindor:16] hmux protocol error at f
[19:20:11.059] [hogwarts, 5] HTTP/1.1 503 Service Temporarily Unavailable
[19:20:11.059] [hogwarts, 5] Content-Type: text/html
[19:20:11.059] [hogwarts, 5] Transfer-Encoding: chunked
[19:20:11.059] [5] write-chunk(7)
[19:20:11.059] ClusterClient[ClusterServer[id=gryffindor index=0 address=192.168.60.85:6880 cluster=xxx4]] busy
[19:20:11.059] close com.caucho.server.cluster.ClusterStream@ab7165
[19:20:11.059] load-balance for session abc5bfwAjDv6NaE0Spofr primary default->gryffindor connection failed.
[19:20:11.059] connect com.caucho.server.cluster.ClusterStream@1a1c42f
[19:20:11.060] load balance [default->gryffindor:17] URL /cwsreq
[19:20:11.060] load balance [default->gryffindor:17] Host: ssl.4yyy.com
[19:20:11.060] load balance [default->gryffindor:17] Accept: */*
[19:20:11.060] load balance [default->gryffindor:17] Cookie: JSESSIONID=abc5bfwAjDv6NaE0Spofr
[19:20:11.060] load balance [default->gryffindor:17] Content-type: text/xml
[19:20:11.060] load balance [default->gryffindor:17] Content-Length: 3561
[19:20:11.060] load balance [default->gryffindor:17] Expect: 100-continue
[19:20:11.062] [default->gryffindor:17] hmux protocol error at f
[19:20:11.062] close com.caucho.server.cluster.ClusterStream@1a1c42f
[19:20:11.062] java.lang.IllegalStateException: sendError() forbidden after buffer has been committed.
[19:20:11.062] at com.caucho.server.connection.AbstractHttpResponse.sendError(AbstractHttpResponse.java:453)
[19:20:11.062] at com.caucho.server.connection.AbstractHttpResponse.sendError(AbstractHttpResponse.java:440)

Notes
(0001773)
ferg   
03-15-07 15:12   
server/269n