Uploaded image for project: 'Qt'
  1. Qt
  2. QTBUG-21369

serious bug: pipelined requests are given the data of the next request instead of their own

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: P1: Critical
    • Resolution: Done
    • Affects Version/s: 4.7.4
    • Fix Version/s: 4.8.0, 5.0.0
    • Component/s: Network
    • Labels:
      None
    • Environment:
    • Commits:
      4.8: ec6d7694f72498d1b156bb0ae8d305e01931f7b2 , 5.0: 20f80d06f7027e8cefe288f60953109c3e333e81

      Description

      It seems that commit 145fecc833926c307819752912e6833169799a53 introduced a serious problem that was quite challenging to debug..., but it boils down to the fact that a request can be written to the socket but not flushed yet, which then can be "overwritten by/lost due to" the second of a series of pipelined requests, resulting in all of these/remaining requests receiving the 'wrong' reply data, i.e. the data that belongs to the request just after it; this gets triggered only when the number of parallel channels all are handling a request and additional requests come in and therefore are pipelined, which probably explains why it seems to have gone unnoticed for quite some time; the attached very simple example qml shows the problem by loading a set of images.

      Commenting in the socket->flush() call (see attached patch

      @@ -221,7 +221,7 @@ bool QHttpNetworkConnectionChannel::sendRequest()
       #endif
               socket->write(header);
               // flushing is dangerous (QSslSocket calls transmit which might read or error)
      -//        socket->flush();
      +        socket->flush();
               QNonContiguousByteDevice* uploadByteDevice = request.uploadByteDevice();
               if (uploadByteDevice) {
                   // connect the signals so this function gets called again
      

      ) makes the problem disappear in our setup, but obviously given the comment in the code, this most likely is not the optimum solution.


      Details of our reproducible example:

      The problem is already on the level of sent-out requests, so it should not matter what http server I used, but as the easiest reproducible example which I could describe fully step-by-step I used web2py and its built-in python web server. I did the following:

      • I downloaded fresh web2py from http://www.web2py.com/examples/static/nightly/web2py_src.zip and unzipped it;
      • I put 10 images parcel01.jpg...parcel10.jpg into web2py/applications/welcome/static/. The images contain (on the image) numbers 01...10 matching file names.
      • I started "python web2py.py" and clicked on "start server"
      • I created qml which uses above images (see attachment):
        • there are just four rows of 10 images; you would expect to get what's on the attached screenshot 110909-missing_requests-correct.png
        • to make sure that separate requests are made, I've added to each source unique parameter "?xyy" (which is ignored by the server; x is row number, yy image number; thus parcel07.jpg in the third row has source "http://127.0.0.1:8000/welcome/static/parcel07.jpg?307")

      But in fact if you run this qml (e.g. using qmlviewer from Qt) instead of 110909-missing_requests-correct.png you will get 110908-missing_requests-QT_BUG.png => four places (2nd row: 4th and 9th img; 3rd row 5th img; and 4th row 1st img) show wrong images .

      Now, after adding a bit of debug to qt, I can say the following:
      The requests for different images are handled by a number of QHttpNetworkConnectionChannel-s. Most of them never use pipeline (alreadyPipelinedRequests list is empty, socket->write() is called only from sendRequest() and not from pipelineInto()). In my case, pipelining is used for exactly one channel. And these are the
      images which are fetched in a wrong way. If I debug the places just before socket->write() I get for this channel the following (this + _FUNCTION_ + request.url()):

      Debug of socket->write()
      QHttpNetworkConnectionChannel(0x6e1e38) sendRequest http://127.0.0.1:8000/welcome/static/parcel01.jpg?101
      QHttpNetworkConnectionChannel(0x6e1e38) sendRequest http://127.0.0.1:8000/welcome/static/parcel01.jpg?201
      QHttpNetworkConnectionChannel(0x6e1e38) pipelineInto http://127.0.0.1:8000/welcome/static/parcel04.jpg?204
      QHttpNetworkConnectionChannel(0x6e1e38) pipelineInto http://127.0.0.1:8000/welcome/static/parcel09.jpg?209
      QHttpNetworkConnectionChannel(0x6e1e38) pipelineInto http://127.0.0.1:8000/welcome/static/parcel05.jpg?305
      QHttpNetworkConnectionChannel(0x6e1e38) pipelineInto http://127.0.0.1:8000/welcome/static/parcel01.jpg?401
      QHttpNetworkConnectionChannel(0x6e1e38) pipelineInto http://127.0.0.1:8000/welcome/static/parcel07.jpg?407
      ...long delay...
      QHttpNetworkConnectionChannel(0x6e1e38) sendRequest http://127.0.0.1:8000/welcome/static/parcel07.jpg?407
      

      Now, as you can see on the attached snapshot (110908-missing_requests-QT_BUG.png):

      Result on the screen
      image with source parcel01.jpg?101	is correct
      image with source parcel01.jpg?201	is correct
      image with source parcel04.jpg?204	shows 209 (it's the 4th image in the 2nd row, but it shows "09")
      image with source parcel09.jpg?209	shows 305
      image with source parcel05.jpg?305	shows 401
      image with source parcel01.jpg?401	shows 407
      image with source parcel07.jpg?407	shows nothing; only after a long delay the request is repeated (see debug above) and then:
      image with source parcel07.jpg?407	is correct (from the later, separate sendRequest)
      

      Now, I did the same with a tcp_dump watching the outgoing requests: it turns out that even though debug of socket->write() shows that GET request for "parcel04.jpg?204" was written to the socket, tcp_dump cannot see any such request! So the situation is that Qt writes to the socket requests for 101, 201, 204, 209, 305, 401, 407 and in the case of piped requests expects replies in the same order; BUT in fact sent out requests are: 101, 201, 209, 305, 401, 407 (note that 204 is missing). When replies come back, for the third request server (correctly) replies with image 09, but Qt thinks that the third request was "204" => so the 4th image in the 2nd row shows an image "09" which in fact comes from the next request (209)! And so on:

      • image with source "209" shows image from request "305"
      • image with source "305" shows image from request "401"
      • image with source "401" shows image from request "407"
      • image with source "407" never gets any image based on the original requests, and only after timeout when the request gets resend it gets correct image.

      This leads to the situation shown on the screenshot 110908-missing_requests-QT_BUG.png. After applying the attached patch, we get the correct/expected screenshot 110909-missing_requests-correct.png.

        Attachments

        1. 110908-missing_requests-QT_BUG.png
          110908-missing_requests-QT_BUG.png
          52 kB
        2. 110909-comment_flush_back_in.patch
          0.7 kB
        3. 110909-missing_requests-correct.png
          110909-missing_requests-correct.png
          53 kB
        4. example.qml
          5 kB
        5. patch2.diff
          0.6 kB
        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

            People

            Assignee:
            phartman Peter Hartmann (closed Nokia identity) (Inactive)
            Reporter:
            wiecko Marek Wieckowski
            Votes:
            3 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Gerrit Reviews

                There are no open Gerrit changes