Mailing-List: contact dev-help@couchdb.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@couchdb.apache.org
Received-SPF: pass (nike.apache.org: domain of antony.blakey@gmail.com
 designates 209.85.220.163 as permitted sender)
DomainKey-Signature: a=rsa-sha1; c=nofws;
        d=gmail.com; s=gamma;
        h=message-id:from:to:in-reply-to:content-type
         :content-transfer-encoding:mime-version:subject:date:references
         :x-mailer;
        b=ti1KQLwUJpHU24VkYRHQ1lHRibbwnEpGRL0n4gbRux15hbwjZJRFzot7oKvMbDKYe8
         h/OOwlxGy8qa9PMA1ocFohFeg7QkLKiyDN8I3/CWre53bC/HkZTBtUJ7DtK76x01jc0j
         /QkDs6DceL99fW/v41ABJad157RkFAiB6gvpU=
Message-Id: <48E6A852-8FF2-4EDB-B776-94D350928E18@gmail.com>
From: Antony Blakey <antony.blakey@gmail.com>
To: dev@couchdb.apache.org
In-Reply-To: <CFCC2390-68D7-482F-8331-F3EC9D6B8451@apache.org>
Content-Type: text/plain; charset=US-ASCII; format=flowed; delsp=yes
Content-Transfer-Encoding: 7bit
Mime-Version: 1.0 (Apple Message framework v930.4)
Subject: Re: Attachment Replication Problem - Bug Found
Date: Fri, 29 May 2009 12:38:32 +0930
References: <E787EF52-E1DF-4112-8DD6-1C6ABE2266FA@gmail.com>
 <12669510-BD0F-45F3-8AC6-19872DF9071D@gmail.com>
 <e282921e0905151727y5fbca6acqb191a92138336bf2@mail.gmail.com>
 <25F55CAE-C44E-4416-AF39-C9037BA099FE@gmail.com>
 <E40771FC-817D-432D-A8C2-FB321EC97B14@gmail.com>
 <9F12A09E-64D7-4703-A295-81B205655300@gmail.com>
 <CFCC2390-68D7-482F-8331-F3EC9D6B8451@apache.org>

Further to this issue, using trunk my repeatable error hangs  
replication. I get a result like this:

------------------------------------------------------------------------------------------
[debug] [<0.125.0>] Attachment URL http://localhost:5985/acumen-curricula/3861b6572b83310c8d1bd4af19c24960/generated_learning_guide.pdf?rev=12-3009421878
[debug] [<0.125.0>] streaming attachment Status "200" Headers  
[{"Transfer-Encoding","chunked"},
                                            {"Server",
                                             "CouchDB/0.10.0a (Erlang  
OTP/R13B)"},
                                             
{"ETag","\"12-3009421878\""},
                                            {"Date",
                                             "Fri, 29 May 2009  
02:29:05 GMT"},
                                            {"Content- 
Type","application/pdf"},
                                            {"Cache-Control",
                                             "must-revalidate"}]
[debug] [<0.125.0>] REPLICATOR: about to update_docs
[debug] [<0.125.0>] REPLICATOR: in update_docs
[debug] [<0.125.0>] REPLICATOR: about to write_and_commit
[debug] [<0.125.0>] REPLICATOR: about to doc_flush_binaries
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for Learning  
Guide.odt
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for Pre-Service  
Lesson Planning Guide.doc
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for Trainers  
Guide.odt
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for New  
Mindmap.png
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for Presentation  
Guide.odp
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for mpabroa.mm
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for New Mindmap.mm
[debug] [<0.125.0>] REPLICATOR: about to flush_binary for  
generated_learning_guide.pdf
[debug] [<0.125.0>] write_streamed_attachment has written too much  
expected: 81912 got: 81913 tail: <<"\r">>
------------------------------------------------------------------------------------------

And it's all over for that couchdb. Restart is required to continue.

I've set the ibrowse # of sessions and pipeline to 1 to try and remove  
the pipelining and concurrent connections from the mix, but still it  
happens - then again it seems I'm not being entirely successful in  
that regard because ...

When I turn ibrowse tracing on (in make_attachment_receiver) like this:

     ...
     {ok, Conn} = ibrowse:spawn_link_worker_process(Host, Port),
     Conn ! {trace, true},
     ...

then I see this result:

------------------------------------------------------------------------------------------
2009-5-28_23:18:25:922 -- (localhost:5985) - Recvd more data: size:  
69. NeedBytes: 62
2009-5-28_23:18:25:922 -- (localhost:5985) - Recvd another chunk...
2009-5-28_23:18:25:922 -- (localhost:5985) - RemData -> "\r\n0\r\n\r\n"
2009-5-28_23:18:25:925 -- (localhost:5985) - Determined chunk size: 0.  
Already recvd: 2
2009-5-28_23:18:25:925 -- (localhost:5985) - Detected end of chunked  
transfer...
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Presentation  
Guide.odp
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for New Mindmap.mm
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Mathematics  
2 Application of Subtraction.odt
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for  
generated_learning_guide.pdf
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Learning  
Guide.odt
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Pre-Service  
Lesson Planning Guide.doc
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Trainers  
Guide.odt
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Presentation  
Guide.odp
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for New Mindmap.mm
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for  
generated_learning_guide.pdf
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Learning  
Guide.odt
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Trainers  
Guide.odt
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Pre-Service  
Lesson Planning Guide.doc
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Gases.png
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Behaviour of  
Gases1.odt
[debug] [<0.120.0>] REPLICATOR: about to flush_binary for Science 9 -  
Behaviour of Gases.pdf
[debug] [<0.120.0>] write_streamed_attachment has written too much  
expected: 383360 got: 383361 tail: <<"\r">>
2009-5-28_23:18:51:418 -- (localhost:5985) - TCP connection closed by  
peer!
2009-5-28_23:18:51:637 -- (localhost:5985) - TCP connection closed by  
peer!
2009-5-28_23:18:51:678 -- (localhost:5985) - TCP connection closed by  
peer!
2009-5-28_23:18:51:932 -- (localhost:5985) - TCP connection closed by  
peer!
2009-5-28_23:18:52:75 -- (localhost:5985) - TCP connection closed by  
peer!
------------------------------------------------------------------------------------------

And once again, all over. I initially suspected that the ibrowse error  
was terminating the stream readers without sending the failure  
response, but I'm not really sure.

I suspect from the ibrowse tracing showing interleaved data response  
(and those 5 connection close messages) that I haven't succeeded in  
make ibrowse linear-one-request, which I need to do to find this  
problem in ibrowse.

Any hints on how to truly make ibrowse single-connection without  
pipelining?

Antony Blakey
-------------
CTO, Linkuistics Pty Ltd
Ph: 0438 840 787

Some defeats are instalments to victory.
   -- Jacob Riis