0001648: Expect: 100-continue with LoadBalanceServlet

Viewing Issue Simple Details [ Jump to Notes ]

[ View Advanced ] [ Issue History ] [ Print ]

Category

Severity

Reproducibility

Date Submitted

Last Update

0001648

[Resin]

minor

always

03-15-07 07:18

03-15-07 15:12

Reporter

sam

View Status

public

Assigned To

ferg

Priority

urgent

Resolution

fixed

Status

closed

Product Version

3.0.22

Summary

0001648: Expect: 100-continue with LoadBalanceServlet

Description

(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)

Additional Information

Attached Files

Relationships

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

Issue History
Date Modified	Username	Field	Change
03-15-07 07:18	sam	New Issue
03-15-07 15:12	ferg	Note Added: 0001773
03-15-07 15:12	ferg	Assigned To	=> ferg
03-15-07 15:12	ferg	Status	new => closed
03-15-07 15:12	ferg	Resolution	open => fixed
03-15-07 15:12	ferg	Fixed in Version	=> 3.1.1

Mantis 1.0.0rc3[^]

29 total queries executed.
26 unique queries executed.