Re: Error in Form-Parameter conversion

  • From: Oleksiy Stashok <oleksiy.stashok@...>
  • To: users@...
  • Subject: Re: Error in Form-Parameter conversion
  • Date: Tue, 20 Aug 2013 12:18:07 -0700

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@... <mailto:oleksiy.stashok@...>> 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 {@code true} if the entity stream is empty, {@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@... <mailto:oleksiy.stashok@...>>:

        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@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@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@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@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@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@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@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@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@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@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@...
        <mailto:oleksiy.stashok@...>> 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@...
            <mailto:oleksiy.stashok@...>> 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@...
                <mailto:oleksiy.stashok@...>> 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@...
                    <mailto:gajanan.x.kulkarni@...>> 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@...
                                <mailto:andre.wallat@...>>
                                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














Re: Error in Form-Parameter conversion

(continued)

Re: Error in Form-Parameter conversion

Oleksiy Stashok 08/17/2013

Re: Error in Form-Parameter conversion

André Wallat 08/18/2013

Re: Error in Form-Parameter conversion

Oleksiy Stashok 08/18/2013

Re: Error in Form-Parameter conversion

André Wallat 08/18/2013

Re: Error in Form-Parameter conversion

Oleksiy Stashok 08/19/2013

Re: Error in Form-Parameter conversion

André Wallat 08/19/2013

Re: Error in Form-Parameter conversion

Oleksiy Stashok 08/19/2013

Re: Error in Form-Parameter conversion

André Wallat 08/19/2013

Re: Error in Form-Parameter conversion

Oleksiy Stashok 08/20/2013

Re: Error in Form-Parameter conversion

André Wallat 08/20/2013

Re: Error in Form-Parameter conversion

Oleksiy Stashok 08/20/2013
Terms of Use; Privacy Policy; Copyright ©2013-2015 (revision 20150626.29986a4)
 
 
Close
loading
Please Confirm
Close