Mailing-List: contact user-help@couchdb.apache.org; run by ezmlm
Precedence: bulk
Reply-To: user@couchdb.apache.org
Date: Tue, 20 Jun 2017 21:55:53 -0400 (EDT)
From: Joan Touzet <wohali@apache.org>
Reply-To: Joan Touzet <wohali@apache.org>
To: user@couchdb.apache.org
Message-ID: <1830441581.2326.1498010152432.JavaMail.Joan@RITA>
In-Reply-To: <4F709517-AFCF-44A2-9290-FF7C4928FDD0@calftrail.com>
References: <4F709517-AFCF-44A2-9290-FF7C4928FDD0@calftrail.com>
Subject: Re: Extra 500 reply added to list function response when accessed
 through rewrite
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit
Thread-Topic: Extra 500 reply added to list function response when accessed through rewrite
Thread-Index: UEYVv91TfylwzNTznhn8/dHpsYmVgQ==
archived-at: Wed, 21 Jun 2017 01:56:09 -0000

Hi Nate,

We've moved to GitHub Issues. A 500 with a stack trace is definitely evidence of a bug,
we shouldn't ever return a 500 -- though I admit this is a bit of a corner case.

https://github.com/apache/couchdb/issues

I'm not able to dig in on your specific bug right now, but perhaps someone else can
shed some light?

Thanks,
Joan

----- Original Message -----
From: "Nathan Vander Wilt" <nate-lists@calftrail.com>
To: user@couchdb.apache.org
Sent: Tuesday, 20 June, 2017 7:04:05 PM
Subject: Extra 500 reply added to list function response when accessed through rewrite

I am getting strange responses from CouchDB 2.0.0 when accessing a list handler through a rewrite. The result to my single request is two responses: the expected one, plus an extra "unknown_error" 500 response. Over HTTP/1.1 this issue is masked because the extra response is not properly chunked, but over HTTP/1.0 the two responses appear as a single body before the connection is closed. So in local development the problem isn't seen in the browser, but when hosted behind an HTTP/1.0 proxy like nginx in production all clients will see the extra content appended to the intended HTML.

Regardless of the HTTP version of the request, the behavior is accompanied in the console logs by:

    [error] 2017-06-20T20:54:43.637726Z couchdb@localhost <0.23057.8> 4d6c7d7e8f req_err(2053811356) unknown_error : undef
        [<<"lacc:get/2">>,<<"chttpd:split_response/1 L343">>,<<"chttpd:handle_request_int/1 L234">>,<<"chttpd:process_request/1 L293">>,<<"chttpd:handle_request_int/1 L229">>,<<"mochiweb_http:headers/6 L122">>,<<"proc_lib:init_p_do_apply/3 L247">>]
    [notice] 2017-06-20T20:54:43.637979Z couchdb@localhost <0.23057.8> 4d6c7d7e8f undefined 127.0.0.1 undefined GET /test/_design/glob/_rewrite/2015/04/f1040_spreadsheet 500 ok 22


Note there is no separate log for the initial "200" response, just the second "500" one.

Turns out if I call `getRows()` an extra times in the list function (or if there are no matching rows), the extra 500 response does not happen. Also if I bypass the rewrite and query the list function directly, I do not see an extra response.

So it seems there might be a bug, maybe something like "the rewrite handler generates an extra, broken response if a list function doesn't consume beyond all the available rows".

Is this something I should file in JIRA, or have I made a mistake somewhere? Details below. (The original code can be seen at https://github.com/natevw/glob but I've simplified things down in my notes above and still seeing the issue.)

thanks,
-natevw


---


The rewrite used looks like

  "rewrites": [{
      "from": "/:path1/:path2/:path3",
      "to": "_list/posts/by_path",
      "query": {
          "include_docs": "true",
          "key": [":path1",":path2",":path3"]
      }
  }]

And the list function can be as simple as

    function() {
      return "[LIST FN OUTPUT]";
    }

When I query this such that "key" ends up matching a row from a simple "by_path" view, I get an extra garbage response when I access the rewrite:

    $ telnet localhost 5984
    GET /test/_design/glob/_rewrite/2015/04/f1040_spreadsheet

    HTTP/1.1 200 OK
    Connection: close
    Content-Type: application/json
    Date: Tue, 20 Jun 2017 20:34:49 GMT
    Server: CouchDB/2.0.0 (Erlang OTP/19)

    [LIST FN OUTPUT]HTTP/1.1 500 Internal Server Error
    Cache-Control: must-revalidate
    Connection: close
    Content-Length: 60
    Content-Type: application/json
    Date: Tue, 20 Jun 2017 20:34:49 GMT
    Server: CouchDB/2.0.0 (Erlang OTP/19)
    X-Couch-Request-ID: 5e0e7f467b
    X-Couch-Stack-Hash: 2053811356
    X-CouchDB-Body-Time: 0

    {"error":"unknown_error","reason":"undef","ref":2053811356}
    Connection closed by foreign host.


This does not happen with a direct request to the list, bypassing the rewrite:

    GET /test/_design/glob/_list/posts/by_path?include_docs=true&key=["2015","04","f1040_spreadsheet"]

    HTTP/1.1 200 OK
    Connection: close
    Content-Type: application/json
    Date: Tue, 20 Jun 2017 20:38:08 GMT
    Server: CouchDB/2.0.0 (Erlang OTP/19)

    [LIST FN OUTPUT]Connection closed by foreign host.


Nor does it happen if I make a request through the rewrite targeting a "missing key", i.e. one that was not emitted by the view:

    GET /test/_design/glob/_rewrite/2020/13/not_exist

    HTTP/1.1 200 OK
    Connection: close
    Content-Type: application/json
    Date: Tue, 20 Jun 2017 20:40:29 GMT
    Server: CouchDB/2.0.0 (Erlang OTP/19)

    [LIST FN OUTPUT]Connection closed by foreign host.


If I change my list function to

    function() {
      getRow();
      getRow();
      return "[LIST FN OUTPUT]";
    }

then the problem goes away even when accessed via the rewrite. With just a single call to `getRow()` the extra response persists.


Also note that the chunked responses of HTTP/1.1 mask this "double response" issue, so you'll see it in telnet or if CouchDB is behind nginx, but not in a browser or similar: 


    GET /test/_design/glob/_rewrite/2015/04/f1040_spreadsheet HTTP/1.1
    
    HTTP/1.1 200 OK
    Content-Type: application/json
    Date: Tue, 20 Jun 2017 20:50:12 GMT
    Server: CouchDB/2.0.0 (Erlang OTP/19)
    Transfer-Encoding: chunked
    
    d
    [LIST FN OUTPUT]
    0
    
    HTTP/1.1 500 Internal Server Error
    Cache-Control: must-revalidate
    Content-Length: 60
    Content-Type: application/json
    Date: Tue, 20 Jun 2017 20:50:12 GMT
    Server: CouchDB/2.0.0 (Erlang OTP/19)
    X-Couch-Request-ID: 524b67d8db
    X-Couch-Stack-Hash: 2053811356
    X-CouchDB-Body-Time: 0
    
    {"error":"unknown_error","reason":"undef","ref":2053811356}