[zeromq-dev] zauth failure

Sun Jan 10 08:54:44 CET 2016

Took me a while to get that script working. :)

Next time, to help us get a grip on things faster, be explicit about
the code you are testing, and how to reproduce the problem. E.g.: "I'm
using CZMQ master. If I run czmq_selftest -v -t zauth in a loop, every
now and then it freezes partway through".

I've run the code for a while and it doesn't crash. OK, it's a timing
issue. Let's provoke that. I start a compile job in another window.
Boom! It freezes. Ctrl-C, and it restarts the test loop... another
compile job, Boom! It freezes again.

So we have a simple way to reproduce.

It should not freeze. If any given step times-out, it should assert.
So let's see exactly where it's waiting. Time to insert printfs and
trace it. Wow... printfs really do change behavior. Now it only
freezes every five or so runs. Still, caught it, line 462:

    zstr_send (*server, "Hello, World");

Ah, looking again at the man page for ZMQ_PUSH and I wonder how this
could ever work.

The server is a PUSH socket and will only accept a message if there's
a peer. So I'd expect sending to block *every time* we have an
authentication failure.

Hypothesis: after 'connect' and during the security handshake with the
peer, for a small window, the socket accepts messages. The test case
depended on this always working. If the send doesn't happen just fast
enough, it'll block forever (the symptom we're seeing).

Let's check this analysis... add a 200 msec pause after zsock_connect
on line 459. Now it should block every time. Bingo! We have a
winner...!

Now, to fix that. Send on PUSH or DEALER is by default blocking. We
could do the sleep, followed by a non-blocking send. Or, we could set
a send timeout on the socket, which seems cleaner.

Which works.

Adding these two lines before the zstr_send makes the problem happen
systematically, and then fixes it:

    zclock_sleep (200);
    zsock_set_sndtimeo (*server, 200);

I'll make a PR with this patch.

-Pieter

On Sun, Jan 10, 2016 at 12:59 AM, Robert Johnston <robert at layer2.com> wrote:
> Hi Pieter,
>
> Thanks for staying with me on this!
>
> OK:
>
> I built using the instructions from http://hintjens.com/blog:49 - this guy really knows his stuff ;-).
>
> And yes, they included libsodium.
>
> I wasn't running from Eclipse: I used Eclipse to try do debug it.  But it runs fine in the debugger.
>
> The attached screen shot shows it running on the command line using a bash script that runs it over and over in a while loop.  I needed the script because the failure is intermittent (remember I said "mostly works").
>
> I REALLY hate these kinds of problems.  If I enter printf statements, the problem goes away; if I try to use a debugger, the problem goes away.  It is down to deducing possible causes from a knowledge of the code.  Except I don't know much about the code!  I guess it is time to learn.  Ye Gods!!!
>
> Put the attached very sophisticated script into your czmq directory and run for a while.  You might not see it: the time, the tide, and phase of the moon will be different.
>
> Thanks for your patience.
>
> Robert
>
>
>
> -----Original Message-----
> From: pieterh at gmail.com [mailto:pieterh at gmail.com] On Behalf Of Pieter Hintjens
> Sent: Friday, January 08, 2016 11:52 PM
> To: robert at layer2.com
> Cc: ZeroMQ development list <zeromq-dev at lists.zeromq.org>
> Subject: Re: [zeromq-dev] zauth failure
>
> "Running under Eclipse" :)
>
> We normally build and test from the command line. You can run the zauth test by itself using: src/czmq_selftest -v -t zauth.
>
> Which shows the same output as you're getting, except it continues with the CURVE tests (and your case seems to stop there).
>
> How exactly did you build CZMQ? Are you using libsodium?
>
> -Pieter
>
>
> On Sat, Jan 9, 2016 at 12:32 AM, Robert Johnston <robert at layer2.com> wrote:
>> I am using CZMQ.  I am curious: what seems to indicate that I am not?  Maybe I am missing something important.
>>
>> Thanks
>>
>> -----Original Message-----
>> From: pieterh at gmail.com [mailto:pieterh at gmail.com] On Behalf Of Pieter
>> Hintjens
>> Sent: Friday, January 08, 2016 3:24 PM
>> To: robert at layer2.com
>> Cc: ZeroMQ development list <zeromq-dev at lists.zeromq.org>
>> Subject: Re: [zeromq-dev] zauth failure
>>
>> OK, I'm sorry, didn't read your first email properly.
>>
>> Are you using the jzmq zauth class? Or JeroMQ? (I thought you were using CZMQ at first).
>>
>> Authentication is failing with a 400 "no access" error code. You can debug the zap handler in zauth to see what is going on.
>>
>> -Pieter
>>
>> On Sat, Jan 9, 2016 at 12:11 AM, Robert Johnston <robert at layer2.com> wrote:
>>> The problem is happening in my application using CURVE.  I only went to the test to see what I was doing wrong.  When I found the same failure in the test it gave me a way to show you the problem.
>>>
>>> Right now, I can ignore it.  "Working mostly" allows me to keep developing.  Soon either you will fix it or I will try.
>>>
>>> Thanks for all you have done.
>>>
>>> Robert
>>>
>>> -----Original Message-----
>>> From: pieterh at gmail.com [mailto:pieterh at gmail.com] On Behalf Of
>>> Pieter Hintjens
>>> Sent: Friday, January 08, 2016 1:49 PM
>>> To: robert at layer2.com
>>> Cc: ZeroMQ development list <zeromq-dev at lists.zeromq.org>
>>> Subject: Re: [zeromq-dev] zauth failure
>>>
>>> Sounds like a timing issue.
>>>
>>> You can simply comment out that test step, or ignore the test failure.
>>> It's not significant and we can fix it independently of you trying out the auth stuff.
>>>
>>>
>>> On Fri, Jan 8, 2016 at 9:02 PM, Robert Johnston <robert at layer2.com> wrote:
>>>> Now I am.  And still occasionally stops at same place.  Note: after
>>>> I posted yesterday I tried to debug using Eclipse.  But the failure
>>>> doesn't occur.  So the debugger changes something (timing?)
>>>>
>>>> -----Original Message-----
>>>> From: pieterh at gmail.com [mailto:pieterh at gmail.com] On Behalf Of
>>>> Pieter Hintjens
>>>> Sent: Friday, January 08, 2016 11:22 AM
>>>> To: robert at layer2.com; ZeroMQ development list
>>>> <zeromq-dev at lists.zeromq.org>
>>>> Subject: Re: [zeromq-dev] zauth failure
>>>>
>>>> Robert, are you using CZMQ and libzmq from github master?
>>>>
>>>> On Fri, Jan 8, 2016 at 12:36 AM, Robert Johnston <robert at layer2.com> wrote:
>>>>> Hi,
>>>>>
>>>>>
>>>>>
>>>>> I am adding authorization to one of our projects.  It works – mostly.
>>>>> Sometimes it freezes – quietly: no crash, assert, etc.
>>>>>
>>>>>
>>>>>
>>>>> To see what I was doing wrong I tried running your zauth_test.  It
>>>>> works too
>>>>> - mostly. And it too sometimes freezes – quietly: no crash, assert, etc.
>>>>>
>>>>>
>>>>>
>>>>> * zauth:
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: ZAP request mechanism=NULL
>>>>> ipaddress=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: - allowed (NULL)
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: - ZAP reply status_code=200
>>>>> status_text=OK
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: API command=DENY
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: - blacklisting ipaddress=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: ZAP request mechanism=NULL
>>>>> ipaddress=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: - denied (blacklist) address=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:46 zauth: - ZAP reply status_code=400
>>>>> status_text=No access
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: API command=ALLOW
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: - whitelisting ipaddress=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: ZAP request mechanism=NULL
>>>>> ipaddress=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: - passed (whitelist) address=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: - ZAP reply status_code=200
>>>>> status_text=OK
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: ZAP request mechanism=PLAIN
>>>>> ipaddress=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: - passed (whitelist) address=127.0.0.1
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: - denied (PLAIN) no password file
>>>>> defined
>>>>>
>>>>> I: 16-01-07 15:10:47 zauth: - ZAP reply status_code=400
>>>>> status_text=No access
>>>>>
>>>>>
>>>>>
>>>>> That’s all folks!!!
>>>>>
>>>>>
>>>>>
>>>>> Apparently it is waiting for Godot.
>>>>>
>>>>>
>>>>>
>>>>> As usual, any and all comments, suggestions, praise, or blame
>>>>> gratefully accepted.
>>>>>
>>>>>
>>>>>
>>>>> Robert Johnston
>>>>>
>>>>> robert at layer2.com
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> zeromq-dev mailing list
>>>>> zeromq-dev at lists.zeromq.org
>>>>> http://lists.zeromq.org/mailman/listinfo/zeromq-dev
>>>>>
>>>>
>>>
>>