Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8209178

Proxied HttpsURLConnection doesn't send BODY when retrying POST request

    XMLWordPrintable

Details

    • b17
    • x86_64
    • windows_7

    Backports

      Description

        ADDITIONAL SYSTEM INFORMATION :
        Reproduced on Windows 7
        but also occurs on linux servers

        Reproduced with :
        - Oracle JDK 1.8.0_172
        - OpenJDK 10.0.2

        A DESCRIPTION OF THE PROBLEM :
        As described here : https://bugs.java.com/bugdatabase/view_bug.do?bug_id=6382788, the JDK is able to retry http/https requests when the server doesn't respond with a correct HTTP response.

        When it occurs on a POST request : the body of the POST is lost during the retry process. Only the request headers are sent, leaving the remote server waiting for the body.

        This bug is linked to this former bug, when it was the request header that was lost :
        https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8025710

        Please note that the JDK handles this kind of retries in a least two places :
        - sun.net.www.http.HttpClient#parseHTTP
        - sun.net.www.http.HttpClient#parseHTTPHeader


        In my case, the cause of the retry is a very specific timeout behaviour on a cached TLS connection :
        I described it in another bug report : internal review ID : 9056455

        STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
        The testcase I described in the bug report "internal review ID : 9056455" is able to reproduced the behaviour reliably.

        But I guess it is possible to simulate the problem more easily
        ( I don't know if the problem is specific to HTTPS, but ssl debug are valuable to observe the problem )
        - set up an HTTPS server responding to POST requests but which close abrutly the connection without any response one out of two times
        - Set up a forward proxy usable for calling the previous server
        - make a HTTPS POST call (with a body) with HttpsURLConnection to the previous server through the proxy (at the moment where the request will first be closed abrutly by the server)

        EXPECTED VERSUS ACTUAL BEHAVIOR :
        EXPECTED -
        Transparent retry of the POST will work and the server will correctly received the body on the second try

        JDK logs on sun.net.www. and ssl debug logs shows that two TLS connection was made and that the body was sent in each case.
        ACTUAL -
        The JDK tries to make a transparent retry of the POST but only send the headers and not the body on this retry :
        The server wait for the body (as the requet contains a non-null Content-Length) and the client call eventually fail with a read timeout

        JDK logs on sun.net.www. and ssl debug logs shows that two TLS connection was made but that the body was not sent on the second call


        During the retry we have :
        (...)
        main, WRITE: TLSv1.2 Alert, length = 26
        [Raw write]: length = 31
        0000: 15 03 03 00 1A 00 00 00 00 00 00 00 05 AE EA C8 ................
        0010: 41 BB E8 1A 3A 64 08 8D 57 4A 3D 63 0A 34 A9 A...:d..WJ=c.4.
        main, called closeSocket(false)
        main, called close()
        main, called closeInternal(true)
        août 03, 2018 7:49:47 PM sun.net.www.protocol.http.HttpURLConnection sendCONNECTRequest
        PRÉCIS: www.MessageHeader@14fc5f045'>sun.net.www.MessageHeader@14fc5f045 pairs: {CONNECT xxxxxxxx.com:443 HTTP/1.1: null}{User-Agent: Java/1.8.0_172}{Host: api.orange.com}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Proxy-Connection: keep-alive}
        août 03, 2018 7:49:47 PM sun.net.www.protocol.http.HttpURLConnection doTunneling
        PRÉCIS: www.MessageHeader@6e2829c71'>sun.net.www.MessageHeader@6e2829c71 pairs: {null: HTTP/1.1 200 Connection established}
        Allow unsafe renegotiation: false
        Allow legacy hello messages: true
        (...)

        Here the stack from the timeout :
        (...)
        Padded plaintext before ENCRYPTION: len = 399
        0000: 50 4F 53 54 20 2F 6F 70 65 6E 69 64 63 6F 6E 6E POST /openidconn
        0010: 65 63 74 2F 66 72 2F 76 31 2F 74 6F 6B 65 6E 20 ect/fr/v1/token
        0020: 48 54 54 50 2F 31 2E 31 0D 0A 43 6F 6E 74 65 6E HTTP/1.1..Conten
        0030: 74 2D 54 79 70 65 3A 20 61 70 70 6C 69 63 61 74 t-Type: applicat
        0040: 69 6F 6E 2F 78 2D 77 77 77 2D 66 6F 72 6D 2D 75 ion/x-www-form-u
        0050: 72 6C 65 6E 63 6F 64 65 64 0D 0A 63 68 61 72 73 rlencoded..chars
        0060: 65 74 3A 20 75 74 66 2D 38 0D 0A 41 75 74 68 6F et: utf-8..Autho
        0070: 72 69 7A 61 74 69 6F 6E 3A 20 42 61 73 69 63 20 rization: Basic
           (deleted)
        00C0: 53 77 3D 3D 0D 0A 43 61 63 68 65 2D 43 6F 6E 74 xxxx..Cache-Cont
        00D0: 72 6F 6C 3A 20 6E 6F 2D 63 61 63 68 65 0D 0A 50 rol: no-cache..P
        00E0: 72 61 67 6D 61 3A 20 6E 6F 2D 63 61 63 68 65 0D ragma: no-cache.
        00F0: 0A 55 73 65 72 2D 41 67 65 6E 74 3A 20 4A 61 76 .User-Agent: Jav
        0100: 61 2F 31 2E 38 2E 30 5F 31 37 32 0D 0A 48 6F 73 a/1.8.0_172..Hos
        0110: 74 3A (deleted) 63 6F t: api.xxxxxx.co
        0120: 6D 0D 0A 41 63 63 65 70 74 3A 20 74 65 78 74 2F m..Accept: text/
        0130: 68 74 6D 6C 2C 20 69 6D 61 67 65 2F 67 69 66 2C html, image/gif,
        0140: 20 69 6D 61 67 65 2F 6A 70 65 67 2C 20 2A 3B 20 image/jpeg, *;
        0150: 71 3D 2E 32 2C 20 2A 2F 2A 3B 20 71 3D 2E 32 0D q=.2, */*; q=.2.
        0160: 0A 43 6F 6E 6E 65 63 74 69 6F 6E 3A 20 6B 65 65 .Connection: kee
        0170: 70 2D 61 6C 69 76 65 0D 0A 43 6F 6E 74 65 6E 74 p-alive..Content
        0180: 2D 4C 65 6E 67 74 68 3A 20 36 35 0D 0A 0D 0A -Length: 65....
        main, WRITE: TLSv1.2 Application Data, length = 423
        [Raw write]: length = 428
        0000: 17 03 03 01 A7 00 00 00 00 00 00 00 01 54 A3 9B .............T..
        0010: 86 64 95 19 C0 EA 32 A4 6E DA 58 DA C8 5C 3C 35 .d....2.n.X..\<5
        0020: D3 4E FC D8 D4 60 9E 9F A7 BC B4 10 74 9F A4 12 .N...`......t...
        0030: 10 EF 3F C4 C9 5C 3B 82 A1 AA E4 FC D7 11 72 59 ..?..\;.......rY
        0040: 35 91 17 5C D5 A9 6A FC 88 DA C7 18 51 F9 82 0A 5..\..j.....Q...
        0050: 50 26 EC 57 E0 B1 6B 4B BA FB DC 25 CA 30 35 8C P&.W..kK...%.05.
        0060: FC 5D 4B 6B 62 7A 74 86 20 97 D6 74 7D 1A DC 17 .]Kkbzt. ..t....
        0070: A9 F2 DE B7 3D 3C 07 93 A8 8F CB 85 03 2F 5F 3C ....=<......./_<
        0080: 31 1A 74 82 9E D0 52 81 2E FB 90 AD 36 B1 DC 66 1.t...R.....6..f
        0090: EA 4E 83 B5 B8 93 2F D6 4E A1 42 81 40 65 72 BD .N..../.N.B.@er.
        00A0: 5B 30 27 CB 3B C8 33 9A 00 84 A5 68 A6 13 32 C3 [0'.;.3....h..2.
        00B0: 21 F5 72 2B EB B2 B2 CB 5D 17 DD 08 49 8A C1 FD !.r+....]...I...
        00C0: 0E 09 70 D0 26 F8 8C 9A 45 CF 55 99 7A 92 F3 A3 ..p.&...E.U.z...
        00D0: DB CC E9 80 F8 A6 76 46 C8 DA 33 A9 3E A3 6B A9 ......vF..3.>.k.
        00E0: 65 18 BA D9 DD 25 BC AE 21 F2 2B 6A 9F CE 68 45 e....%..!.+j..hE
        00F0: 61 D1 04 6B 77 10 BE 40 55 31 7D D1 6E E1 02 E2 a..kw..@U1..n...
        0100: EF 61 61 02 FF 8D A3 CB 72 E1 18 98 0F A9 81 57 .aa.....r......W
        0110: 7F 61 AC 5B A1 71 BC B0 D8 D7 39 78 D4 AF 98 C1 .a.[.q....9x....
        0120: 39 CE D0 7B FE 75 E6 6F 3C 64 E1 13 19 89 01 1E 9....u.o<d......
        0130: 08 B8 A9 E7 79 54 EA BB 32 88 EB 2D 9E B3 3E 4D ....yT..2..-..>M
        0140: FA 2C 0B 00 84 7D 3C 04 6A CB 91 4E 43 C3 A5 83 .,....<.j..NC...
        0150: 81 8F D6 AC 45 6F BB 53 91 A7 D5 AF 80 FB 65 0E ....Eo.S......e.
        0160: 5C 4D DB BF 95 FA C4 98 9F 95 6B 4C D6 3E 8A E1 \M........kL.>..
        0170: F5 72 23 FC 15 36 39 E1 DF EF A2 7C E5 58 71 80 .r#..69......Xq.
        0180: 84 26 39 93 C9 5B A7 FF 80 9F 4B 64 3C A0 60 48 .&9..[....Kd<.`H
        0190: 8D 4C 29 A1 9B 33 29 7F 78 58 B0 46 A3 2D 47 DC .L)..3).xX.F.-G.
        01A0: 4A F7 74 4C C5 28 CD 5A F7 3C 96 4F J.tL.(.Z.<.O
        main, handling exception: java.net.SocketTimeoutException: Read timed out
        main, called close()
        main, called closeInternal(true)
        main, SEND TLSv1.2 ALERT: warning, description = close_notify
        Padded plaintext before ENCRYPTION: len = 2
        0000: 01 00 ..
        main, WRITE: TLSv1.2 Alert, length = 26
        [Raw write]: length = 31
        0000: 15 03 03 00 1A 00 00 00 00 00 00 00 02 8A 6C 98 ..............l.
        0010: 8F 35 34 06 0F 52 77 F6 08 9B 36 DF 46 B4 F3 .54..Rw...6.F..
        main, called closeSocket(true)
        main, called close()
        main, called closeInternal(true)

        java.net.SocketTimeoutException: Read timed out

        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
        at sun.security.ssl.InputRecord.read(InputRecord.java:503)
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:983)
        at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:940)
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
        at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
        at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
        at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:848)
        at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1587)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1492)
        at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
        at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:347)
        at TestCase.testCaseMethod

        ---------- BEGIN SOURCE ----------
        Here the test case from bug report "internal review ID : 9056455"

        It make two request, but depending on the test setup, one request may be sufficient to reproduce (cf Steps to Reproduce)

        package testcase;

        import org.apache.commons.io.IOUtils;
        import org.junit.Test;

        import javax.net.ssl.HttpsURLConnection;
        import java.io.InputStream;
        import java.io.OutputStream;
        import java.net.InetSocketAddress;
        import java.net.Proxy;
        import java.net.SocketAddress;
        import java.net.URL;
        import java.nio.charset.StandardCharsets;

        public class TestCaseHttpsURLConnection {

        @Test
        public void testCaseMethod() throws Exception {

        URL url = new URL( "https://some.tls.server/xxx/yyy");

        SocketAddress sa = new InetSocketAddress("some.corporate.proxy",8080);
        Proxy proxy = new Proxy(Proxy.Type.HTTP,sa);

        int nb = 0;
        while(++nb <= 2) {
        try {

        System.out.println("*********** REQUEST n° " + nb + " ******************");

        HttpsURLConnection urlConnection = (HttpsURLConnection) url.openConnection(proxy);

        urlConnection.setConnectTimeout(1000);
        urlConnection.setReadTimeout(15000);
        urlConnection.setDoInput(true);
        urlConnection.setDoOutput(true);
        urlConnection.setRequestMethod("POST");
        urlConnection.setUseCaches(false);

        urlConnection.setRequestProperty( "Content-Type", "application/x-www-form-urlencoded");
        urlConnection.setRequestProperty( "charset", "utf-8");
        urlConnection.setRequestProperty("Authorization", "Basic xxxxxxxxxx==");

        urlConnection.setRequestProperty("Connection", "keep-alive");

        String urlParameters = "param1=a&param2=b&param3=c";
        byte[] postData = urlParameters.getBytes( StandardCharsets.UTF_8 );

        OutputStream outputStream = urlConnection.getOutputStream();
        outputStream.write(postData);
        outputStream.close();

        int responseCode = urlConnection.getResponseCode();

        System.out.printf("UrlConnection - ResponseCode : %s%n",responseCode);

        String output;
        InputStream inputStream;
        if(responseCode < 400) {
        inputStream = urlConnection.getInputStream();
        } else {
        inputStream = urlConnection.getErrorStream();
        }
        output = IOUtils.toString(inputStream); // consumint the inputstream is also important to make the httpsclient cacheable
        inputStream.close(); // Important to make the client httpscacheable
        // urlConnection.disconnect(); // NO ...

        System.out.printf("Response body : %s%n",output);

        } finally {
        try {
        Thread.sleep(35000);
        } catch (InterruptedException e) {
        e.printStackTrace();
        }
        }
        }
        }

        }

        ---------- END SOURCE ----------

        CUSTOMER SUBMITTED WORKAROUND :
        In my case : disable keepalive connection which triggered the retry condition too often
        Other workaround : disable retries on POST with proprety sun.net.http.retryPost to have a fail fast behaviour (but losing retries capability)

        FREQUENCY : always


        Attachments

          Issue Links

            Activity

              People

                jboes Julia Boes (Inactive)
                webbuggrp Webbug Group
                Votes:
                0 Vote for this issue
                Watchers:
                10 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved: