Hi Andre,
I've create the issue
https://java.net/jira/browse/GRIZZLY-1578
and we have the fix already commited to 2.3.x branch. It will be
available in Grizzly 2.3.6.
For now you can use 2.3.6-SNAPSHOT.
Thank you.
WBR,
Alexey.
On 20.08.13 01:58, André Wallat wrote:
> Hi Alexey,
>
> the bug seems to be fixed! Are you going to commit this workaround fix
> or will there be a fix on the jersey side, where the root of the
> problem seems to be?
>
> Cheers and thanks for finding a fix,
> André
>
>
>
> On Tue, Aug 20, 2013 at 2:00 AM, Oleksiy Stashok
> <oleksiy.stashok_at_oracle.com <mailto:oleksiy.stashok_at_oracle.com>> wrote:
>
> Hi Andre,
>
> looks like it's a bug in Jersey [2], but we can work it around by
> propagating InputStream mark/reset mechanism to servlet layer.
> Pls. try the patch [1] and let me know if it fixes the problem.
>
> Thank you.
>
> WBR,
> Alexey.
>
> [1]
> https://dl.dropboxusercontent.com/u/7319744/params/grizzly-http-servlet-2.3.4.jar
> [2] org.glassfish.jersey.message.internal.EntityInputStream.java:172
>
> /**
> * Check if the underlying entity stream is empty.
> * <p>
> * Note that the operation may need to block until a first byte (or EOF) is available in the stream.
> * </p>
> *
> * @return {_at_code true} if the entity stream is empty, {_at_code false} otherwise.
> */
> public boolean isEmpty() {
> ensureNotClosed();
>
> if (input == null) {
> return true;
> }
>
> try {
> if (input.available() > 0) {
> return false;
> } else if (input.markSupported()) {
> input.mark(1);
> int i = input.read();
> input.reset();
> return i == -1;
> } else {
> int b = input.read();
> if (b == -1) {
> return true;
> }
>
> PushbackInputStream pbis;
> if (input instanceof PushbackInputStream) {
> pbis = (PushbackInputStream) input;
> } else {
> pbis = new PushbackInputStream(input, 1);
> input = pbis;
> }
> pbis.unread(b);
>
> return false;
> }
> } catch (IOException ex) {
> throw new ProcessingException(ex);
> }
> }
>
>
>
>
> On 19.08.13 16:07, André Wallat wrote:
>>
>> So ... I attached a part of the log file to this email. Logging
>> level set to FINEST for the InputBuffer.
>>
>> Am 20.08.2013 00:15 schrieb "Oleksiy Stashok"
>> <oleksiy.stashok_at_oracle.com <mailto:oleksiy.stashok_at_oracle.com>>:
>>
>> Hi Andre,
>>
>> I think we're very close to resolve the issue, can you pls.
>> enable FINEST logging on
>> org.glassfish.grizzly.http.io.InputBuffer.
>> Looks like if the payload comes in separate chunk somebody
>> calls readByte().
>>
>>
>> Aug 19, 2013 11:42:37 PM
>> org.glassfish.grizzly.http.io.InputBuffer log
>> INFO: InputBuffer
>> org.glassfish.grizzly.http.io.InputBuffer_at_58365946 readByte.
>> Ready content: ByteBufferWrapper (1478438888)
>> [visible=[java.nio.HeapByteBufferR[pos=0 lim=0 cap=0]]]
>>
>> So I wonder where it called from.
>>
>> Thank you.
>>
>> WBR,
>> Alexey.
>>
>> On 19.08.13 14:56, André Wallat wrote:
>>> Hi Alexey,
>>>
>>> yeah, I know how this game is played :)
>>> Here comes the interesting part of the log. The first part
>>> shows a successful login and the last part hopefully gives
>>> the detail where it's going wrong:
>>>
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_2a5a6254
>>> initialize with ready content: HeapBuffer (334335621)
>>> [pos=0 lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_2a5a6254
>>> fillFully, len: 33. Ready content: HeapBuffer
>>> (334335621) [pos=0 lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_2a5a6254
>>> getBuffer. Ready content: HeapBuffer (334335621) [pos=0
>>> lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.util.Parameters processParameters
>>> INFO: process parameters. Buffer: HeapBuffer (125283488)
>>> [pos=0 lim=33 cap=33] start=0 len=33 firstbyte=j
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.util.Parameters processParameters
>>> INFO: Adding param. name=j_username value=admin
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.util.Parameters processParameters
>>> INFO: Adding param. name=j_password value=admin
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_2a5a6254 skip
>>> 33 bytes. Ready content: HeapBuffer (334335621) [pos=0
>>> lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_58365946
>>> initialize with ready content: ByteBufferWrapper
>>> (1478438888) [visible=[java.nio.HeapByteBufferR[pos=0
>>> lim=0 cap=0]]]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_58365946
>>> readByte. Ready content: ByteBufferWrapper (1478438888)
>>> [visible=[java.nio.HeapByteBufferR[pos=0 lim=0 cap=0]]]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_58365946
>>> fillFully, len: 33. Ready content: HeapBuffer
>>> (234235343) [pos=1 lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_58365946
>>> getBuffer. Ready content: HeapBuffer (234235343) [pos=1
>>> lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.util.Parameters processParameters
>>> INFO: process parameters. Buffer: HeapBuffer (888646187)
>>> [pos=1 lim=33 cap=33] start=1 len=32 firstbyte=_
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.util.Parameters processParameters
>>> INFO: Adding param. name=_username value=admin
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.util.Parameters processParameters
>>> INFO: Adding param. name=j_password value=admin
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.io.InputBuffer log
>>> INFO: InputBuffer
>>> org.glassfish.grizzly.http.io.InputBuffer_at_58365946 skip
>>> 32 bytes. Ready content: HeapBuffer (234235343) [pos=1
>>> lim=33 cap=33]
>>> Aug 19, 2013 11:42:37 PM
>>> org.glassfish.grizzly.http.server.NetworkListener
>>> shutdownNow
>>> INFO: Stopped listener bound to [0.0.0.0:9998
>>> <http://0.0.0.0:9998>]
>>>
>>>
>>> In the whole log the ByteBufferWrapper is only used when the
>>> error occurs, so maybe something is going wrong in there!?
>>>
>>> Cheers,
>>> André
>>>
>>>
>>>
>>>
>>> On Mon, Aug 19, 2013 at 9:06 PM, Oleksiy Stashok
>>> <oleksiy.stashok_at_oracle.com
>>> <mailto:oleksiy.stashok_at_oracle.com>> wrote:
>>>
>>> Hi Andre,
>>>
>>> it looks like 1 byte has been read off the payload
>>> before it got parsed as parameters.
>>> I prepared a new patch here [1] with more logging. It
>>> will help to track if somebody read 1 byte before
>>> parsing parameters.
>>>
>>> You can use the patch as it is - it will notify us about
>>> all the buffer reads, or you can set
>>> org.glassfish.grizzly.http.io.InputBuffer logging level
>>> to Level.FINEST to see the reads stacktraces as well.
>>>
>>> Thank you for help.
>>>
>>>
>>> WBR,
>>> Alexey.
>>>
>>> [1]
>>> https://dl.dropboxusercontent.com/u/7319744/params/grizzly-http-2.3.4.jar
>>>
>>> On 18.08.13 09:29, André Wallat wrote:
>>>> Hi Alexey,
>>>>
>>>> here's a part from the log. I wrote a simple test to
>>>> send POST-requests all the time and stop if the server
>>>> responds with a 403-error.
>>>>
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: process parameters. Buffer: HeapBuffer
>>>> (418015750) [pos=0 lim=33 cap=33] start=0 len=33
>>>> firstbyte=j
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: Adding param. name=j_username value=admin
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: Adding param. name=j_password value=admin
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: process parameters. Buffer: HeapBuffer
>>>> (1654094979) [pos=0 lim=33 cap=33] start=0 len=33
>>>> firstbyte=j
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: Adding param. name=j_username value=admin
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: Adding param. name=j_password value=admin
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: process parameters. Buffer: HeapBuffer
>>>> (1271617369) [pos=1 lim=33 cap=33] start=1 len=32
>>>> firstbyte=_
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: Adding param. name=_username value=admin
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.util.Parameters
>>>> processParameters
>>>> INFO: Adding param. name=j_password value=admin
>>>> Aug 18, 2013 6:21:15 PM
>>>> org.glassfish.grizzly.http.server.NetworkListener
>>>> shutdownNow
>>>> INFO: Stopped listener bound to [0.0.0.0:9998
>>>> <http://0.0.0.0:9998>]
>>>>
>>>> Hope this helps,
>>>> André
>>>>
>>>>
>>>>
>>>> On Sun, Aug 18, 2013 at 5:27 PM, Oleksiy Stashok
>>>> <oleksiy.stashok_at_oracle.com
>>>> <mailto:oleksiy.stashok_at_oracle.com>> wrote:
>>>>
>>>> Hi Andre,
>>>>
>>>> unfortunately the log you sent looks fine.
>>>> Here I prepared the same patch for Grizzly 2.3.4
>>>> [1], there is no need to change the logging level,
>>>> because the logs I'm interested in should be logged
>>>> using Level.INFO.
>>>>
>>>> Thanks a lot.
>>>>
>>>> WBR,
>>>> Alexey.
>>>>
>>>> [1]
>>>> https://dl.dropboxusercontent.com/u/7319744/params/grizzly-http-2.3.4.jar
>>>>
>>>>
>>>>
>>>> On 18.08.13 06:36, André Wallat wrote:
>>>>> Hi Alexey,
>>>>>
>>>>> I tried the patched library but wasn't able to
>>>>> reproduce it unfortunately. With version 2.3.4 and
>>>>> logging level set to FINE I could get the error
>>>>> (see attached file). The finer I set the logging
>>>>> level the less the error occurs. But maybe the
>>>>> exception shown in the attached log file already
>>>>> helps to figure out the problem!?
>>>>>
>>>>> I will try some more tests ...
>>>>>
>>>>> Cheers,
>>>>> André
>>>>>
>>>>>
>>>>>
>>>>> On Sat, Aug 17, 2013 at 10:36 PM, Oleksiy Stashok
>>>>> <oleksiy.stashok_at_oracle.com
>>>>> <mailto:oleksiy.stashok_at_oracle.com>> wrote:
>>>>>
>>>>> Hi Andre,
>>>>>
>>>>> I tried the same request, but still can't
>>>>> reproduce the issue.
>>>>> Can you pls. try this patch [1], which extends
>>>>> Grizzly parameters parsing logging. Once the
>>>>> issue is reproduced - pls. send us the server
>>>>> logging.
>>>>>
>>>>> Thank you.
>>>>>
>>>>> WBR,
>>>>> Alexey.
>>>>>
>>>>> [1]
>>>>> https://dl.dropboxusercontent.com/u/7319744/params/grizzly-http-2.3.5.jar
>>>>>
>>>>>
>>>>>
>>>>> On 17.08.13 04:48, André Wallat wrote:
>>>>>> Hi everyone,
>>>>>>
>>>>>> I was able to take a snapshot showing the
>>>>>> data that lead to the error.
>>>>>>
>>>>>> * at packet no. 40 you can see a successful
>>>>>> login with the response in no. 43
>>>>>> * at packet no. 204 you can see another
>>>>>> login (with same form parameters) with a
>>>>>> denied error sent in no. 206
>>>>>>
>>>>>> I hope you can find out what's going wrong now :)
>>>>>> I was using an iPod touch and even on a
>>>>>> Safari desktop browser the problem occurred,
>>>>>> however not that often!
>>>>>>
>>>>>> Cheers,
>>>>>> André
>>>>>>
>>>>>>
>>>>>> On Sat, Aug 17, 2013 at 4:52 AM, gajanan
>>>>>> x.kulkarni <gajanan.x.kulkarni_at_oracle.com
>>>>>> <mailto:gajanan.x.kulkarni_at_oracle.com>> wrote:
>>>>>>
>>>>>> ok lets wait on wireshark data from the André
>>>>>>
>>>>>> Thanks
>>>>>> Gajanan.
>>>>>>
>>>>>> On 8/17/2013 6:42 AM, Oleksiy Stashok wrote:
>>>>>>
>>>>>> I tried sending a request
>>>>>> byte-by-byte, but still can't
>>>>>> reproduce the problem :(
>>>>>>
>>>>>>
>>>>>>
>>>>>> On 16.08.13 17:18, Gajanan wrote:
>>>>>>
>>>>>> Reason could be that request is
>>>>>> coming in smaller chunks and
>>>>>> grizzly misses a char while
>>>>>> joining the chunks seen similare
>>>>>> issue on sailfin in the fast. To
>>>>>> reproduce u need simple code
>>>>>> which writes request in small chunks.
>>>>>>
>>>>>> Sent from my Xperia™ smartphone
>>>>>>
>>>>>> André Wallat
>>>>>> <andre.wallat_at_gmail.com
>>>>>> <mailto:andre.wallat_at_gmail.com>>
>>>>>> wrote:
>>>>>>
>>>>>> Hello,
>>>>>>
>>>>>> I came across a strange error
>>>>>> when I access my server from the
>>>>>> iPad browser Safari. Most of the
>>>>>> times the first character of the
>>>>>> first form parameter is removed,
>>>>>> so instead of "username" the
>>>>>> parameter "sername" is received
>>>>>> in my ContainerRequestFilter. All
>>>>>> the other parameters are fine.
>>>>>> Other browsers like Chrome,
>>>>>> Firefox and even Android worked okay.
>>>>>>
>>>>>> Any ideas? Maybe someone can open
>>>>>> up an issue for this?
>>>>>>
>>>>>> Here a bit more detailed scenario:
>>>>>> I send a post request with jQuery
>>>>>> (v1.10.2) to my server after I
>>>>>> access my website the first time.
>>>>>> I think here it even works to
>>>>>> transmit/convert the form
>>>>>> parameter correctly, but when I
>>>>>> submit the data a second time,
>>>>>> then the first form parameter is
>>>>>> losing its first character. My
>>>>>> website is a single-page-app
>>>>>> created with AngularJS.
>>>>>> With firefox light I could check
>>>>>> the POST-request and the
>>>>>> submitted parameters were
>>>>>> correct. So it has to be an error
>>>>>> in grizzly!?
>>>>>>
>>>>>> My workaround so far is to add a
>>>>>> dummy-Parameter as the first
>>>>>> parameter, so that the other
>>>>>> parameters stay okay.
>>>>>>
>>>>>> Client: Safari iOS iPad 6.1.3
>>>>>> Server: Grizzly 2.3.5
>>>>>>
>>>>>> Cheers,
>>>>>> André
>>>>>>
>>>>>>
>>>>>>
>>>>>> --
>>>>>> "I say the glass is always full- half
>>>>>> with air, half with water!" - Modi
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>>>
>>>
>>>
>>
>
>