Append chunked body responses invoked as part of _build_request

[foobargeez]

This patch ensures that the AE's http_request chunked response is honored and appended to the response content. Also, ensures that the event loop does not end prematurely.

[hexfusion]

Hi @foobargeez thanks for the PR. Could you take a minute and explain the reason for this change and give an example of a problem you are trying to solve? Some example code would be great.

[hexfusion]

This will need some tests as well so perhaps you can answer all the above with a test.

[foobargeez]

Scenario:

Created the below etcd keys:

etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:sgdfgasgdfgasgdfgasgdfgasgdfgasgdfgasgdfgasgdfgasgdfgasgdfgasgdfgasgdfga 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:fgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsdfgyhsd 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:ghhdfaghhdfaghhdfaghhdfaghhdfaghhdfaghhdfaghhdfaghhdfaghhdfaghhdfaghhdfa 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:dgkeigdgkeigdgkeigdgkeigdgkeigdgkeigdgkeigdgkeigdgkeigdgkeigdgkeigdgkeig 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:dkgbegdkgbegdkgbegdkgbegdkgbegdkgbegdkgbegdkgbegdkgbegdkgbegdkgbegdkgbeg 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:kgjeigkgjeigkgjeigkgjeigkgjeigkgjeigkgjeigkgjeigkgjeigkgjeigkgjeigkgjeig 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:kdrgbakdrgbakdrgbakdrgbakdrgbakdrgbakdrgbakdrgbakdrgbakdrgbakdrgbakdrgba 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:dfgjbddfgjbddfgjbddfgjbddfgjbddfgjbddfgjbddfgjbddfgjbddfgjbddfgjbddfgjbd 1; etcdctl --endpoints=etcd-dev.test.com:2379 put etcd_chunk_test:fdgdgafdgdgafdgdgafdgdgafdgdgafdgdgafdgdgafdgdgafdgdgafdgdgafdgdgafdgdga 1

Ran the following script:

use AnyEvent;
use AnyEvent::HTTP;

my $cv = AnyEvent->condvar;

$cv->begin;

http_request(
    'POST',
    'http://etcd-dev.test.com:2379/v3alpha/kv/range',
    body => '{"key":"ZXRjZF9jaHVua190ZXN0","range_end":"ZXRjZF9jaHVua190ZXN1"}',
    on_body => sub {
        my ($body, $hdr) = @_;
        print "-->" . $body . "<--\n";
        #$cv->end;
    },
    sub {
        my (undef, $hdr) = @_;
        $cv->end;
    }
);

$cv->recv;

The output is as below:

-->{"header":{"cluster_id":"219392735742827174","member_id":"8078686634843474950","revision":"34791","raft_term":"27"},"kvs":[{"key":"ZXRjZF9jaHVua190ZXN0OmRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZGRmZ2piZA==","create_revision":"34790","mod_revision":"34790","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmRna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZ2Rna2VpZw==","create_revision":"34786","mod_revision":"34786","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmRrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZ2RrZ2JlZw==","create_revision":"34787","mod_revision":"34787","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYWZkZ2RnYQ==","create_revision":"34791","mod_revision":"34791","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZGZneWhzZA==","create_revision":"34784","mod_revision":"34784","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYWdoaGRmYQ==","create_revision":"34785","mod_revision":"34785","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYWtkcmdiYQ==","create_revision":"34789","mod_revision":"34789","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OmtnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZ2tnamVpZw==","create_revision":"34788","mod_revision":"34788","version":"1","value":"MQ=="},{"key":"ZXRjZF9jaHVua190ZXN0OnNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZnYXNnZGZn<--
-->YQ==","create_revision":"34783","mod_revision":"34783","version":"1","value":"MQ=="}],"count":"9"}<--

Per the above output, the output is split into two chunks. The current code in etcd is exiting the event loop right after receiving the first chunk. The patch now appends all chunks and ends the event loop only on connection disconnect.

Please note that I am not sure what is special about the keys I quoted above -- the issue happens with 9 keys (not 10 or 8) and have no clue why the data gets split into chunks only with the above similar 9 keys. The key length too is important as it doesn't happen with small key lengths. Overall, a weird scenario, but nevertheless, the patch handles chunked responses by appending the output.

Regarding a test case, I am not exactly sure how to come up with one and importantly a generic one. If you have any ideas, let me know and I am happy to.

[hexfusion]

@foobargeez, thanks so lets say using the keys you added above, what code are you using with Net::Etcd to reproduce the issue? Just a simple script will be fine. Will be easier for me to review and test.

[foobargeez]

Just a simple script will be fine

I already added the code to my above comment. Let me know if that didn't work for you.

[foobargeez]

To clarify further, the code I used in my comment above is the same code that I copied from Net::Etcd's Action.pm and from _build_request. Hope it helps!

[hexfusion]

@foobargeez I understand that your using the code from the Net::Etcd source and that is useful example. But since you are making the issue against the module itself I am curious how you are using Net::Etcd. Are you doing range, watch etc? Your update breaks the Watch test. So although it solves one problem it creates others. So to clarify can you show with Net::Etcd use Net::Etcd in a Perl script against the keys above what will generate the result that is not as expected. Does that make sense?

[foobargeez]

Sure, that's the easy part! I got to the bottom of the issue, so started the issue from there :-/

use Net::Etcd;
use Data::Dumper;

$ENV{ETCDCTL_API} = 3;

$etcd = Net::Etcd->new({
    host => "etcd-dev.test.com",
    port => 2379,
    ssl => 0
});

$range = $etcd->range({ key => 'etcd_chunk_test', range_end => 'etcd_chunk_tesu' });

my @all = $range->all;
print Dumper(@all), "\n";

Output:

unexpected end of string while parsing JSON string, at character offset 1919 (before "(end of string)") at /usr/local/perls/perl-5.26.1/lib/site_perl/5.26.1/JSON.pm line 187.

[foobargeez]

Your update breaks the Watch test. So although it solves one problem it creates others.

Checking ... sorry :(

[foobargeez]

Your update breaks the Watch test. So although it solves one problem it creates others.

I reverted my changes and ran the test and it's still failing. Looks like some other changes are causing the issue. Let me know if you need a hand digging this.

[hexfusion]

@foobargeez can you show the output of your test failure and what version of etcd your using. I just ran the test a number of times against master without failure.

[samb@ob1 perl-net-etcd]$ etcd --version
etcd Version: 3.3.0+git
Git SHA: 729eab92b
Go Version: go1.9.2
Go OS/Arch: linux/amd64

[foobargeez]

$>etcd --version
etcd Version: 3.2.5
Git SHA: d0d1a87
Go Version: go1.8.3
Go OS/Arch: linux/amd64

The test fails while creating watch create:

$> perl 06-watch.t
1..8
<gets stuck>

[hexfusion]

@foobargeez with your change Watch blocks, without it does not. Am I missing something?

commit 83a30188fda137a83d299b14b0e7275b037963e3 (HEAD -> master, origin/master, origin/HEAD)
Author: Sam Batschelet <sbatschelet@mac.com>
Date:   Mon Jan 29 09:27:20 2018 -0500

    testing: Bump travis to latest etcd. (#39)
[..]

$ git log

I add your change

$ git diff
diff --git a/lib/Net/Etcd/Role/Actions.pm b/lib/Net/Etcd/Role/Actions.pm
index 422ee40..197c739 100644
--- a/lib/Net/Etcd/Role/Actions.pm
+++ b/lib/Net/Etcd/Role/Actions.pm
@@ -171,11 +171,10 @@ sub _build_request {
         },
         on_body   => sub {
             my ($data, $hdr) = @_;
-            $self->{response}{content} = $data;
+            $self->{response}{content} .= $data;
             $cb->($data, $hdr) if $cb;
             my $status = $hdr->{Status};
             $self->check_hdr($status);
-            $cv->end;
             1
         },
         sub {

async watch call blocks

$ perl t/06-watch.t
1..8

remove your change back to master

$ git checkout  lib/Net/Etcd/Role/Actions.pm

pass

[samb@ob1 perl-net-etcd]$ perl t/06-watch.t
1..8
ok 1 - watch create
ok 2 - kv put
ok 3 - kv put success
ok 4 - kv range
ok 5 - kv range success
ok 6 - number of async events stored. (create_watch, create key)
ok 7 - kv range_delete
ok 8 - kv delete success

So please before we spend anymore time in this I need Perl code using the Net::Etcd module showing unexpected output. From there we can look at a solution.

[hexfusion]

I see your code above now nevermind. Will test and let you know, thanks.

[hexfusion]

@foobargeez so the bug is in how we handle all. So if you change your script above and do the following.

print Dumper($range->{response}{content});

You will see that all the data is already returned correctly. So we just need to make sure all and get_value can handle that properly. See what you can do with that 👍 .

[hexfusion]

Ugh brother ok I guess I need to slow down I am going to review this more.

[hexfusion]

@foobargeez OK so we have an issue with chunked data as you noted. But we also need to handle async streams such as Watch so they don't block.

[foobargeez]

But we also need to handle async streams such as Watch so they don't block.

Yep -- sorry, I overlooked that :-/

Per the documentation of AnyEvent::HTTP, it sounds like we should start looking into want_body_handle:

want_body_handle:
...
This is useful with some push-type services, where, after the initial headers, an interactive protocol is used (typical example would be the push-style twitter API which starts a JSON/XML stream).
...

I will look into it sometime next week.

[hexfusion]

I will look into it sometime next week.

Thanks, checkout Miyagawa's module if you haven't, might be useful.

https://github.com/miyagawa/AnyEvent-Twitter-Stream/blob/master/lib/AnyEvent/Twitter/Stream.pm#L165

[foobargeez]

I did :-) I noted that line as well ... grr ...

[foobargeez]

I figured I would finish it while I have the context -- please review and let me know if something is unclear.

[hexfusion]

lgtm, thanks @foobargeez

[hexfusion]

@foobargeez I cut a new release v0.019 is on it's way to CPAN, 👍