You are viewing a plain text version of this content. The canonical link for it is here.
Posted to proton@qpid.apache.org by Phil Harvey <ph...@philharveyonline.com> on 2012/11/28 18:26:46 UTC

Unexpected behaviour in test ssl.py - possible bug?

Hi,

We've been working on the Java SSL implementation and are seeing a test
fail against proton-c but that works against proton-j.  We're not sure if
the problem is in proton-c, or in our modified test, and are hoping someone
who knows about proton-c's SSL implementation can give a view on this
before we raise a Jira.

One of the scenarios we wanted to cover in our testing was the case where
the Transport input method leaves "left-overs", e.g. when you call
server.input() with 100 bytes of input, but it only accepts 20, as
indicated by its return value.

For example, we expect this to happen if the preceding client.output() call
is told to write to a buffer sized such that its output contains a trailing
*fragment* of an SSL packet, which input() won't be able to decipher.

We therefore modified the pump method in proton/tests/proton_tests/ssl.py
to handle this case.  In its loop, it now captures the bytes "left over"
after calling input(), and prepends them to the input() invocation in the
next iteration.  The buffer size is now a parameter so individual tests can
exercise the packet fragmenting behaviour described above.

We made the following change:

-------
diff --git a/tests/proton_tests/ssl.py b/tests/proton_tests/ssl.py
index 8567b1b..237c3da 100644
--- a/tests/proton_tests/ssl.py
+++ b/tests/proton_tests/ssl.py
@@ -43,13 +43,32 @@ class SslTest(common.Test):
         self.t_client = None
         self.t_server = None

-    def _pump(self):
+    def _pump(self, buffer_size=1024):
+        """
+        Make the transport send up to buffer_size bytes (this will be the
AMQP
+        header and open frame) returning a buffer containing the bytes
+        sent.  Transport is stateful so this will return 0 when it has
+        no more frames to send.
+        TODO this function is duplicated in sasl.py. Should be moved to a
common place.
+        """
+        out_client_leftover_by_server = ""
+        out_server_leftover_by_client = ""
+        i=0
         while True:
-            out_client = self.t_client.output(1024)
-            out_server = self.t_server.output(1024)
-            if out_client: self.t_server.input(out_client)
-            if out_server: self.t_client.input(out_server)
+
+            out_client = out_client_leftover_by_server +
self.t_client.output(buffer_size)
+            out_server = out_server_leftover_by_client +
self.t_server.output(buffer_size)
+
+            if out_client:
+                number_server_consumed = self.t_server.input(out_client)
+                out_client_leftover_by_server =
out_client[number_server_consumed:] # if it consumed everything then this
is empty
+
+            if out_server:
+                number_client_consumed = self.t_client.input(out_server)
+                out_server_leftover_by_client =
out_server[number_client_consumed:] # if it consumed everything then this
is empty
+
             if not out_client and not out_server: break
+            i=i+1

     def _testpath(self, file):
         """ Set the full path to the certificate,keyfile, etc. for the
test.
-------

Several ssl tests now fail when run against proton-c, all with the same
error.  This surprised us because we hadn't started playing with the buffer
size yet - we were still using the default of 1024.

For example, test_server_authentication gives this output:

proton_tests.ssl.SslTest.test_server_authentication
.........................................................................[0xa2ca208:0]
ERROR[-2] SSL Failure: error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record mac
 fail
Error during test:  Traceback (most recent call last):
    File "./tests/proton-test", line 331, in run
      phase()
    File "/home/phil/dev/proton/tests/proton_tests/ssl.py", line 166, in
test_server_authentication
      self._pump()
    File "/home/phil/dev/proton/tests/proton_tests/ssl.py", line 63, in
_pump
      number_server_consumed = self.t_server.input(out_client)
    File "/home/phil/dev/proton/proton-c/bindings/python/proton.py", line
2141, in input
      return self._check(n)
    File "/home/phil/dev/proton/proton-c/bindings/python/proton.py", line
2115, in _check
      raise exc("[%s]: %s" % (err,
pn_error_text(pn_transport_error(self._trans))))
  TransportException: [-2]: SSL Failure: error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record mac
Totals: 1 tests, 0 passed, 0 skipped, 0 ignored, 1 failed

The first pump() call in this test works fine; the failure we see is when
it's invoked again after closing the connection.

The problem is that the previous t_server.input call didn't accept *any* of
the bytes given to it.  On the next t_server.input call, these bytes are
prepended to the newly-produced ones from t_client.output, which seems
reasonable to us, but this produces the error above.

We were going to raise a Jira but want to get some initial feedback first,
in case we're just misunderstanding how this API is meant to be used.

Thanks
Phil

Re: Unexpected behaviour in test ssl.py - possible bug?

Posted by Phil Harvey <ph...@philharveyonline.com>.
Hi Ken,

Thanks for looking into it. I've raised
https://issues.apache.org/jira/browse/PROTON-171 and assigned it to you.

Phil
On Nov 28, 2012 6:19 PM, "Ken Giusti" <kg...@redhat.com> wrote:

> Hi Phil,
>
> I think you've uncovered a bug - definitely raise a jira and assign it to
> me.
>
> Now that you mention it, I'm surprised that the original version of pump()
> worked properly - seems like it would risk discarding any output not
> consumed by the input handler.    Your changes to pump() should be an
> improvement.
>
> -K
>
> ----- Original Message -----
> > Hi,
> >
> > We've been working on the Java SSL implementation and are seeing a
> > test
> > fail against proton-c but that works against proton-j.  We're not
> > sure if
> > the problem is in proton-c, or in our modified test, and are hoping
> > someone
> > who knows about proton-c's SSL implementation can give a view on this
> > before we raise a Jira.
> >
> > One of the scenarios we wanted to cover in our testing was the case
> > where
> > the Transport input method leaves "left-overs", e.g. when you call
> > server.input() with 100 bytes of input, but it only accepts 20, as
> > indicated by its return value.
> >
> > For example, we expect this to happen if the preceding
> > client.output() call
> > is told to write to a buffer sized such that its output contains a
> > trailing
> > *fragment* of an SSL packet, which input() won't be able to decipher.
> >
> > We therefore modified the pump method in
> > proton/tests/proton_tests/ssl.py
> > to handle this case.  In its loop, it now captures the bytes "left
> > over"
> > after calling input(), and prepends them to the input() invocation in
> > the
> > next iteration.  The buffer size is now a parameter so individual
> > tests can
> > exercise the packet fragmenting behaviour described above.
> >
> > We made the following change:
> >
> > -------
> > diff --git a/tests/proton_tests/ssl.py b/tests/proton_tests/ssl.py
> > index 8567b1b..237c3da 100644
> > --- a/tests/proton_tests/ssl.py
> > +++ b/tests/proton_tests/ssl.py
> > @@ -43,13 +43,32 @@ class SslTest(common.Test):
> >          self.t_client = None
> >          self.t_server = None
> >
> > -    def _pump(self):
> > +    def _pump(self, buffer_size=1024):
> > +        """
> > +        Make the transport send up to buffer_size bytes (this will
> > be the
> > AMQP
> > +        header and open frame) returning a buffer containing the
> > bytes
> > +        sent.  Transport is stateful so this will return 0 when it
> > has
> > +        no more frames to send.
> > +        TODO this function is duplicated in sasl.py. Should be moved
> > to a
> > common place.
> > +        """
> > +        out_client_leftover_by_server = ""
> > +        out_server_leftover_by_client = ""
> > +        i=0
> >          while True:
> > -            out_client = self.t_client.output(1024)
> > -            out_server = self.t_server.output(1024)
> > -            if out_client: self.t_server.input(out_client)
> > -            if out_server: self.t_client.input(out_server)
> > +
> > +            out_client = out_client_leftover_by_server +
> > self.t_client.output(buffer_size)
> > +            out_server = out_server_leftover_by_client +
> > self.t_server.output(buffer_size)
> > +
> > +            if out_client:
> > +                number_server_consumed =
> > self.t_server.input(out_client)
> > +                out_client_leftover_by_server =
> > out_client[number_server_consumed:] # if it consumed everything then
> > this
> > is empty
> > +
> > +            if out_server:
> > +                number_client_consumed =
> > self.t_client.input(out_server)
> > +                out_server_leftover_by_client =
> > out_server[number_client_consumed:] # if it consumed everything then
> > this
> > is empty
> > +
> >              if not out_client and not out_server: break
> > +            i=i+1
> >
> >      def _testpath(self, file):
> >          """ Set the full path to the certificate,keyfile, etc. for
> >          the
> > test.
> > -------
> >
> > Several ssl tests now fail when run against proton-c, all with the
> > same
> > error.  This surprised us because we hadn't started playing with the
> > buffer
> > size yet - we were still using the default of 1024.
> >
> > For example, test_server_authentication gives this output:
> >
> > proton_tests.ssl.SslTest.test_server_authentication
> >
> .........................................................................[0xa2ca208:0]
> > ERROR[-2] SSL Failure: error:1408F119:SSL
> > routines:SSL3_GET_RECORD:decryption failed or bad record mac
> >  fail
> > Error during test:  Traceback (most recent call last):
> >     File "./tests/proton-test", line 331, in run
> >       phase()
> >     File "/home/phil/dev/proton/tests/proton_tests/ssl.py", line 166,
> >     in
> > test_server_authentication
> >       self._pump()
> >     File "/home/phil/dev/proton/tests/proton_tests/ssl.py", line 63,
> >     in
> > _pump
> >       number_server_consumed = self.t_server.input(out_client)
> >     File "/home/phil/dev/proton/proton-c/bindings/python/proton.py",
> >     line
> > 2141, in input
> >       return self._check(n)
> >     File "/home/phil/dev/proton/proton-c/bindings/python/proton.py",
> >     line
> > 2115, in _check
> >       raise exc("[%s]: %s" % (err,
> > pn_error_text(pn_transport_error(self._trans))))
> >   TransportException: [-2]: SSL Failure: error:1408F119:SSL
> > routines:SSL3_GET_RECORD:decryption failed or bad record mac
> > Totals: 1 tests, 0 passed, 0 skipped, 0 ignored, 1 failed
> >
> > The first pump() call in this test works fine; the failure we see is
> > when
> > it's invoked again after closing the connection.
> >
> > The problem is that the previous t_server.input call didn't accept
> > *any* of
> > the bytes given to it.  On the next t_server.input call, these bytes
> > are
> > prepended to the newly-produced ones from t_client.output, which
> > seems
> > reasonable to us, but this produces the error above.
> >
> > We were going to raise a Jira but want to get some initial feedback
> > first,
> > in case we're just misunderstanding how this API is meant to be used.
> >
> > Thanks
> > Phil
> >
>

Re: Unexpected behaviour in test ssl.py - possible bug?

Posted by Ken Giusti <kg...@redhat.com>.
Hi Phil,

I think you've uncovered a bug - definitely raise a jira and assign it to me.

Now that you mention it, I'm surprised that the original version of pump() worked properly - seems like it would risk discarding any output not consumed by the input handler.    Your changes to pump() should be an improvement. 

-K

----- Original Message -----
> Hi,
> 
> We've been working on the Java SSL implementation and are seeing a
> test
> fail against proton-c but that works against proton-j.  We're not
> sure if
> the problem is in proton-c, or in our modified test, and are hoping
> someone
> who knows about proton-c's SSL implementation can give a view on this
> before we raise a Jira.
> 
> One of the scenarios we wanted to cover in our testing was the case
> where
> the Transport input method leaves "left-overs", e.g. when you call
> server.input() with 100 bytes of input, but it only accepts 20, as
> indicated by its return value.
> 
> For example, we expect this to happen if the preceding
> client.output() call
> is told to write to a buffer sized such that its output contains a
> trailing
> *fragment* of an SSL packet, which input() won't be able to decipher.
> 
> We therefore modified the pump method in
> proton/tests/proton_tests/ssl.py
> to handle this case.  In its loop, it now captures the bytes "left
> over"
> after calling input(), and prepends them to the input() invocation in
> the
> next iteration.  The buffer size is now a parameter so individual
> tests can
> exercise the packet fragmenting behaviour described above.
> 
> We made the following change:
> 
> -------
> diff --git a/tests/proton_tests/ssl.py b/tests/proton_tests/ssl.py
> index 8567b1b..237c3da 100644
> --- a/tests/proton_tests/ssl.py
> +++ b/tests/proton_tests/ssl.py
> @@ -43,13 +43,32 @@ class SslTest(common.Test):
>          self.t_client = None
>          self.t_server = None
> 
> -    def _pump(self):
> +    def _pump(self, buffer_size=1024):
> +        """
> +        Make the transport send up to buffer_size bytes (this will
> be the
> AMQP
> +        header and open frame) returning a buffer containing the
> bytes
> +        sent.  Transport is stateful so this will return 0 when it
> has
> +        no more frames to send.
> +        TODO this function is duplicated in sasl.py. Should be moved
> to a
> common place.
> +        """
> +        out_client_leftover_by_server = ""
> +        out_server_leftover_by_client = ""
> +        i=0
>          while True:
> -            out_client = self.t_client.output(1024)
> -            out_server = self.t_server.output(1024)
> -            if out_client: self.t_server.input(out_client)
> -            if out_server: self.t_client.input(out_server)
> +
> +            out_client = out_client_leftover_by_server +
> self.t_client.output(buffer_size)
> +            out_server = out_server_leftover_by_client +
> self.t_server.output(buffer_size)
> +
> +            if out_client:
> +                number_server_consumed =
> self.t_server.input(out_client)
> +                out_client_leftover_by_server =
> out_client[number_server_consumed:] # if it consumed everything then
> this
> is empty
> +
> +            if out_server:
> +                number_client_consumed =
> self.t_client.input(out_server)
> +                out_server_leftover_by_client =
> out_server[number_client_consumed:] # if it consumed everything then
> this
> is empty
> +
>              if not out_client and not out_server: break
> +            i=i+1
> 
>      def _testpath(self, file):
>          """ Set the full path to the certificate,keyfile, etc. for
>          the
> test.
> -------
> 
> Several ssl tests now fail when run against proton-c, all with the
> same
> error.  This surprised us because we hadn't started playing with the
> buffer
> size yet - we were still using the default of 1024.
> 
> For example, test_server_authentication gives this output:
> 
> proton_tests.ssl.SslTest.test_server_authentication
> .........................................................................[0xa2ca208:0]
> ERROR[-2] SSL Failure: error:1408F119:SSL
> routines:SSL3_GET_RECORD:decryption failed or bad record mac
>  fail
> Error during test:  Traceback (most recent call last):
>     File "./tests/proton-test", line 331, in run
>       phase()
>     File "/home/phil/dev/proton/tests/proton_tests/ssl.py", line 166,
>     in
> test_server_authentication
>       self._pump()
>     File "/home/phil/dev/proton/tests/proton_tests/ssl.py", line 63,
>     in
> _pump
>       number_server_consumed = self.t_server.input(out_client)
>     File "/home/phil/dev/proton/proton-c/bindings/python/proton.py",
>     line
> 2141, in input
>       return self._check(n)
>     File "/home/phil/dev/proton/proton-c/bindings/python/proton.py",
>     line
> 2115, in _check
>       raise exc("[%s]: %s" % (err,
> pn_error_text(pn_transport_error(self._trans))))
>   TransportException: [-2]: SSL Failure: error:1408F119:SSL
> routines:SSL3_GET_RECORD:decryption failed or bad record mac
> Totals: 1 tests, 0 passed, 0 skipped, 0 ignored, 1 failed
> 
> The first pump() call in this test works fine; the failure we see is
> when
> it's invoked again after closing the connection.
> 
> The problem is that the previous t_server.input call didn't accept
> *any* of
> the bytes given to it.  On the next t_server.input call, these bytes
> are
> prepended to the newly-produced ones from t_client.output, which
> seems
> reasonable to us, but this produces the error above.
> 
> We were going to raise a Jira but want to get some initial feedback
> first,
> in case we're just misunderstanding how this API is meant to be used.
> 
> Thanks
> Phil
>