problem: zbroker (gossip) sometimes asserts in connect

[rpedde]

Error in test "/home/rpedde/working/work/python-zbroker/scripts/simple_writer.yml"

Host "writer" (airbook.local)

Post started at: 14-08-06 15:19:19
Running tasks: 1

Test script

sleep 1
timeout 5000
open pipe1 write
write pipe1 abc
close pipe1 write

Script Log

14-08-06 15:19:20 Set prefix to 1
14-08-06 15:19:20 Set broker to 1-0
14-08-06 15:19:20 Sleeping for 1 seconds
14-08-06 15:19:21 Set timeout to 5000
14-08-06 15:19:21 Opening descriptor "1-0|>1-pipe1"
14-08-06 15:19:21 Opened pipe "pipe1" for write
14-08-06 15:19:21 Writing "abc" to pipe "pipe1"
14-08-06 15:19:26 Unexpected exception: timeouterror
14-08-06 15:19:26 Test failed

Broker Log

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-06 15:19:19 starting zpipes broker using config in '/tmp/tmpwKj2xz/zbroker.cfg'
N: 14-08-06 15:19:19 starting zpipes service
I: 14-08-06 15:19:19 using TCP gossip discovery service
I: 14-08-06 15:19:19 gossip service connect to tcp://airbook.local:5672
I: 14-08-06 15:19:19 Zyre node endpoint=tcp://*:49152 announce=tcp://airbook.internal.pedde.com:49152
I: 14-08-06 15:19:19 joining cluster as broker-1-0
I: 14-08-06 15:19:19 ZPIPES server appeared at broker-1-0
I: 14-08-06 15:19:19 ZPIPES server appeared at B08C5A
I: 14-08-06 15:19:19 ZPIPES server appeared at broker-1-0
I: 14-08-06 15:19:19 ZPIPES server appeared at broker-1-1
I: 14-08-06 15:19:20 ZPIPES server vanished from 
I: 14-08-06 15:19:20 ZPIPES server vanished from 
D: 14-08-06 15:19:21    934:                                : start:
D: 14-08-06 15:19:21    934:                                :     OUTPUT
D: 14-08-06 15:19:21    934:                                :         $ lookup or create pipe
D: 14-08-06 15:19:21    934:1-pipe1                         :         $ open pipe writer
I: 14-08-06 15:19:21 1-pipe1: attach local writer
I: 14-08-06 15:19:21 1-pipe1: broadcast we are now writer
I: 14-08-06 15:19:21 open local writer
D: 14-08-06 15:19:21    934:1-pipe1                         :         > before writing
D: 14-08-06 15:19:21    934:1-pipe1                         : before writing:
D: 14-08-06 15:19:21    934:1-pipe1                         :     ok
D: 14-08-06 15:19:21    934:1-pipe1                         :         $ send OUTPUT_OK
D: 14-08-06 15:19:21    934:1-pipe1                         :         > writing
D: 14-08-06 15:19:21    934:1-pipe1                         : writing:
D: 14-08-06 15:19:21    934:1-pipe1                         :     WRITE
D: 14-08-06 15:19:21    934:1-pipe1                         :         $ process write request
D: 14-08-06 15:19:21    934:1-pipe1                         :         > processing write
I: 14-08-06 15:19:24 ZPIPES server vanished from broker-1-1
I: 14-08-06 15:19:24 ZPIPES server vanished from broker-1-0
I: 14-08-06 15:19:24 ZPIPES server vanished from B08C5A
D: 14-08-06 15:19:26    934:1-pipe1                         : processing write:
D: 14-08-06 15:19:26    934:1-pipe1                         :     wakeup
D: 14-08-06 15:19:26    934:1-pipe1                         :         $ send WRITE_TIMEOUT
D: 14-08-06 15:19:26    934:1-pipe1                         :         > writing
interrupted
N: 14-08-06 15:19:27 terminating zpipes service

Host "reader" (airbook.local)

Post started at: 14-08-06 15:19:19
Running tasks: 1

Test script

sleep 1
timeout 5000
open pipe1 read
read pipe1 3 abc
close pipe1 read

Script Log

14-08-06 15:19:20 Set prefix to 1
14-08-06 15:19:20 Set broker to 1-1
14-08-06 15:19:20 Sleeping for 1 seconds
14-08-06 15:19:21 Set timeout to 5000
14-08-06 15:19:21 Opening descriptor "1-1|1-pipe1"

Broker Log

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-06 15:19:19 starting zpipes broker using config in '/tmp/tmpEa58uZ/zbroker.cfg'
N: 14-08-06 15:19:19 starting zpipes service
I: 14-08-06 15:19:19 using TCP gossip discovery service
I: 14-08-06 15:19:19 gossip service connect to tcp://airbook.local:5672
I: 14-08-06 15:19:19 Zyre node endpoint=tcp://*:49153 announce=tcp://airbook.internal.pedde.com:49153
I: 14-08-06 15:19:19 joining cluster as broker-1-1
I: 14-08-06 15:19:19 ZPIPES server appeared at broker-1-1
I: 14-08-06 15:19:19 ZPIPES server appeared at broker-1-0
I: 14-08-06 15:19:19 ZPIPES server appeared at B08C5A
I: 14-08-06 15:19:19 ZPIPES server vanished from broker-1-1
zbroker: zyre_peer.c:138: zyre_peer_connect: Assertion `rc == 0' failed.

Additionally, I was running a hub at tcp://*:5672

strangely, it doesn't show connect messages. This log excerpt from the preceeding run:

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-06 15:18:37 starting zpipes broker using config in './zbroker.cfg'
N: 14-08-06 15:18:37 starting zpipes service
N: 14-08-06 15:18:37 binding zpipes service to 'ipc://@/zpipes/local'
I: 14-08-06 15:18:37 using TCP gossip discovery service
I: 14-08-06 15:18:37 Zyre node endpoint=tcp://eth1:5671
I: 14-08-06 15:18:37 Zyre node announce=tcp://localhost:5671
I: 14-08-06 15:18:37 gossip service bind to tcp://eth1:5672
I: 14-08-06 15:18:37 joining cluster as B08C5A
I: 14-08-06 15:18:38 ZPIPES server vanished from 
I: 14-08-06 15:19:08 ZPIPES server vanished from 
I: 14-08-06 15:19:08 ZPIPES server vanished from 
I: 14-08-06 15:19:20 ZPIPES server vanished from 
I: 14-08-06 15:19:20 ZPIPES server vanished from 

[hintjens]

I've added a trace to zyre_peer_connect so we can see what the invalid endpoint is.

[rpedde]

I still don't see it from latest master:

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-13 14:41:53 starting zpipes broker using config in '/tmp/tmpGweFjT/zbroker.cfg'
N: 14-08-13 14:41:53 starting zpipes service
I: 14-08-13 14:41:53 using TCP gossip discovery service
I: 14-08-13 14:43:25 ZPIPES server appeared at 2BB83B
I: 14-08-13 14:43:25 ZPIPES server appeared at 3C482C
I: 14-08-13 14:43:25 ZPIPES server appeared at 5D975D
I: 14-08-13 14:43:25 ZPIPES server vanished from 3C482C
zbroker: zyre_peer.c:138: zyre_peer_connect: Assertion `rc == 0' failed.

[hintjens]

:-( I forgot to create the pull request to Zyre. Did that now, sorry for
the misstep.

zeromq/zyre#226

On Wed, Aug 13, 2014 at 9:45 PM, Ron Pedde notifications@github.com wrote:

I still don't see it from latest master:

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-13 14:41:53 starting zpipes broker using config in '/tmp/tmpGweFjT/zbroker.cfg'
N: 14-08-13 14:41:53 starting zpipes service
I: 14-08-13 14:41:53 using TCP gossip discovery service
I: 14-08-13 14:43:25 ZPIPES server appeared at 2BB83B
I: 14-08-13 14:43:25 ZPIPES server appeared at 3C482C
I: 14-08-13 14:43:25 ZPIPES server appeared at 5D975D
I: 14-08-13 14:43:25 ZPIPES server vanished from 3C482C
zbroker: zyre_peer.c:138: zyre_peer_connect: Assertion `rc == 0' failed.

—
Reply to this email directly or view it on GitHub
#101 (comment).

[rpedde]

Error in test "/home/rpedde/working/work/python-zbroker/scripts/simple_writer.yml"

Host "writer" (airbook.local)

Post started at: 14-08-19 10:56:37
Running tasks: 1

Test script

sleep 1
timeout 5000
open pipe1 write
write pipe1 abc
close pipe1 write

Script Log

14-08-19 10:56:38 Set prefix to 1
14-08-19 10:56:38 Set broker to 1-0
14-08-19 10:56:38 Sleeping for 1 seconds
14-08-19 10:56:39 Set timeout to 5000
14-08-19 10:56:39 Opening descriptor "1-0|>1-pipe1"

Broker Log

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-19 10:56:37 starting zpipes broker using config in '/tmp/tmp8tsaH4/zbroker.cfg'
N: 14-08-19 10:56:37 starting zpipes service
I: 14-08-19 10:56:37 using TCP gossip discovery service
I: 14-08-19 10:56:37 gossip service connect to tcp://airbook.local:5672
I: 14-08-19 10:56:37 Zyre node endpoint=tcp://*:49153 announce=tcp://airbook.internal.pedde.com:49153
I: 14-08-19 10:56:37 joining cluster as F0EA32
I: 14-08-19 10:56:37 ZPIPES server appeared at A80B9D
I: 14-08-19 10:56:37 ZPIPES server appeared at F0EA32
I: 14-08-19 10:56:37 ZPIPES server appeared at 245A6C
I: 14-08-19 10:56:37 ZPIPES server vanished from F0EA32
E: 14-08-19 10:56:37 (F0EA32) cannot connect to endpoint=tcp://*:49153
zbroker: zyre_peer.c:143: zyre_peer_connect: Assertion `0' failed.

Host "reader" (airbook.local)

Post started at: 14-08-19 10:56:37
Running tasks: 1

Test script

sleep 1
timeout 5000
open pipe1 read
read pipe1 3 abc
close pipe1 read

Script Log

14-08-19 10:56:38 Set prefix to 1
14-08-19 10:56:38 Set broker to 1-1
14-08-19 10:56:38 Sleeping for 1 seconds
14-08-19 10:56:39 Set timeout to 5000
14-08-19 10:56:39 Opening descriptor "1-1|1-pipe1"
14-08-19 10:56:39 Opened pipe "pipe1" for read
14-08-19 10:56:39 Reading 3 bytes from pipe "pipe1"
14-08-19 10:56:44 Unexpected exception: timeouterror
14-08-19 10:56:44 Test failed

Broker Log

zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-19 10:56:37 starting zpipes broker using config in '/tmp/tmp6f94UO/zbroker.cfg'
N: 14-08-19 10:56:37 starting zpipes service
I: 14-08-19 10:56:37 using TCP gossip discovery service
I: 14-08-19 10:56:37 gossip service connect to tcp://airbook.local:5672
I: 14-08-19 10:56:37 Zyre node endpoint=tcp://*:49152 announce=tcp://airbook.internal.pedde.com:49152
I: 14-08-19 10:56:37 joining cluster as A80B9D
I: 14-08-19 10:56:37 ZPIPES server appeared at A80B9D
I: 14-08-19 10:56:37 ZPIPES server appeared at 245A6C
I: 14-08-19 10:56:38 ZPIPES server vanished from 
I: 14-08-19 10:56:38 ZPIPES server vanished from 
I: 14-08-19 10:56:38 ZPIPES server vanished from 
I: 14-08-19 10:56:38 ZPIPES server vanished from 
I: 14-08-19 10:56:38 ZPIPES server vanished from 
D: 14-08-19 10:56:39    653:                                : start:
D: 14-08-19 10:56:39    653:                                :     INPUT
D: 14-08-19 10:56:39    653:                                :         $ lookup or create pipe
D: 14-08-19 10:56:39    653:1-pipe1                         :         $ open pipe reader
I: 14-08-19 10:56:39 1-pipe1: attach local reader
I: 14-08-19 10:56:39 1-pipe1: broadcast we are now reader
I: 14-08-19 10:56:39 open local reader
D: 14-08-19 10:56:39    653:1-pipe1                         :         > before reading
D: 14-08-19 10:56:39    653:1-pipe1                         : before reading:
D: 14-08-19 10:56:39    653:1-pipe1                         :     ok
D: 14-08-19 10:56:39    653:1-pipe1                         :         $ send INPUT_OK
D: 14-08-19 10:56:39    653:1-pipe1                         :         > reading
D: 14-08-19 10:56:39    653:1-pipe1                         : reading:
D: 14-08-19 10:56:39    653:1-pipe1                         :     READ
D: 14-08-19 10:56:39    653:1-pipe1                         :         $ process read request
D: 14-08-19 10:56:39    653:1-pipe1                         :         > processing read
I: 14-08-19 10:56:42 ZPIPES server vanished from A80B9D
D: 14-08-19 10:56:44    653:1-pipe1                         : processing read:
D: 14-08-19 10:56:44    653:1-pipe1                         :     wakeup
D: 14-08-19 10:56:44    653:1-pipe1                         :         $ send READ_TIMEOUT
D: 14-08-19 10:56:44    653:1-pipe1                         :         > reading
interrupted
N: 14-08-19 10:56:45 terminating zpipes service

[hintjens]

@rpedde in general, if you get an assert, can you try to get a stack backtrace? I've got the cause of this issue now, though it's unclear exactly how the call flow is happening.

[hintjens]

Fixed by zeromq/zyre#228 (I think).

[rpedde]

Still seems to be happening.

Error in test "/home/rpedde/working/work/python-zbroker/scripts/simple_writer.yml"

Host "writer" (airbook.local)

Post started at: 14-08-20 12:04:45
Running tasks: 1

Test script

sleep 1
timeout 5000
open pipe1 write
write pipe1 abc
close pipe1 write

Script Log

14-08-20 12:04:46 Set prefix to 1
14-08-20 12:04:46 Set broker to 1-0
14-08-20 12:04:46 Sleeping for 1 seconds
14-08-20 12:04:47 Set timeout to 5000
14-08-20 12:04:47 Opening descriptor "1-0|>1-pipe1"

Broker Log

GNU gdb (GDB) 7.4.1-debian
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker...done.
(gdb) (gdb) (gdb) Starting program: /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker /tmp/tmpsezeZj/zbroker.cfg
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7ffff7ffa000
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-20 12:04:46 starting zpipes broker using config in '/tmp/tmpsezeZj/zbroker.cfg'
N: 14-08-20 12:04:46 starting zpipes service
I: 14-08-20 12:04:46 using TCP gossip discovery service
I: 14-08-20 12:04:46 gossip service connect to tcp://airbook.local:5672
[New Thread 0x7ffff65b0700 (LWP 22539)]
[New Thread 0x7ffff5daf700 (LWP 22540)]
[New Thread 0x7ffff55ae700 (LWP 22542)]
[New Thread 0x7ffff4dad700 (LWP 22543)]
[New Thread 0x7ffff45ac700 (LWP 22544)]
I: 14-08-20 12:04:46 Zyre node endpoint=tcp://*:49153 announce=tcp://airbook.internal.pedde.com:49153
I: 14-08-20 12:04:46 joining cluster as 76F912
I: 14-08-20 12:04:46 ZPIPES server appeared at 76F912
I: 14-08-20 12:04:46 ZPIPES server appeared at E64CC4
I: 14-08-20 12:04:46 ZPIPES server appeared at 76F912
I: 14-08-20 12:04:46 ZPIPES server appeared at 8F8E50
I: 14-08-20 12:04:46 ZPIPES server vanished from 76F912
E: 14-08-20 12:04:46 (76F912) cannot connect to endpoint=tcp://*:49153
zbroker: zyre_peer.c:143: zyre_peer_connect: Assertion `0' failed.

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff4dad700 (LWP 22543)]
0x00007ffff71a6475 in *__GI_raise (sig=<optimized out>)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
64  ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) #0  0x00007ffff71a6475 in *__GI_raise (sig=<optimized out>)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x00007ffff71a96f0 in *__GI_abort () at abort.c:92
#2  0x00007ffff719f621 in *__GI___assert_fail (assertion=0x7ffff79bec6b "0", 
    file=<optimized out>, line=143, 
    function=0x7ffff79bf070 "zyre_peer_connect") at assert.c:81
#3  0x00007ffff79b8a73 in zyre_peer_connect ()
   from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#4  0x00007ffff79baba6 in zyre_node_require_peer ()
   from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#5  0x00007ffff79bb17f in zyre_node_recv_peer ()
   from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#6  0x00007ffff79bbba2 in zyre_node_actor ()
   from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#7  0x00007ffff776225d in s_thread_shim (args=0x612940) at zactor.c:67
#8  0x00007ffff6cdcb50 in start_thread (arg=<optimized out>)
    at pthread_create.c:304
#9  0x00007ffff72500ed in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#10 0x0000000000000000 in ?? ()
(gdb) A debugging session is active.

    Inferior 1 [process 22522] will be killed.

Quit anyway? (y or n) [answered Y; input not from terminal]

Host "reader" (airbook.local)

Post started at: 14-08-20 12:04:45
Running tasks: 1

Test script

sleep 1
timeout 5000
open pipe1 read
read pipe1 3 abc
close pipe1 read

Script Log

14-08-20 12:04:46 Set prefix to 1
14-08-20 12:04:46 Set broker to 1-1
14-08-20 12:04:46 Sleeping for 1 seconds
14-08-20 12:04:47 Set timeout to 5000
14-08-20 12:04:47 Opening descriptor "1-1|1-pipe1"
14-08-20 12:04:47 Opened pipe "pipe1" for read
14-08-20 12:04:47 Reading 3 bytes from pipe "pipe1"
14-08-20 12:04:52 Unexpected exception: timeouterror
14-08-20 12:04:52 Test failed

Broker Log

GNU gdb (GDB) 7.4.1-debian
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker...done.
(gdb) (gdb) (gdb) Starting program: /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker /tmp/tmpO00ITV/zbroker.cfg
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7ffff7ffa000
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-20 12:04:46 starting zpipes broker using config in '/tmp/tmpO00ITV/zbroker.cfg'
N: 14-08-20 12:04:46 starting zpipes service
I: 14-08-20 12:04:46 using TCP gossip discovery service
I: 14-08-20 12:04:46 gossip service connect to tcp://airbook.local:5672
[New Thread 0x7ffff65b0700 (LWP 22532)]
[New Thread 0x7ffff5daf700 (LWP 22533)]
[New Thread 0x7ffff55ae700 (LWP 22534)]
[New Thread 0x7ffff4dad700 (LWP 22536)]
[New Thread 0x7ffff45ac700 (LWP 22538)]
I: 14-08-20 12:04:46 Zyre node endpoint=tcp://*:49152 announce=tcp://airbook.internal.pedde.com:49152
I: 14-08-20 12:04:46 joining cluster as 8F8E50
I: 14-08-20 12:04:46 ZPIPES server appeared at 8F8E50
I: 14-08-20 12:04:46 ZPIPES server appeared at E64CC4
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
I: 14-08-20 12:04:47 ZPIPES server vanished from 
D: 14-08-20 12:04:47    499:                                : start:
D: 14-08-20 12:04:47    499:                                :     INPUT
D: 14-08-20 12:04:47    499:                                :         $ lookup or create pipe
D: 14-08-20 12:04:47    499:1-pipe1                         :         $ open pipe reader
I: 14-08-20 12:04:47 1-pipe1: attach local reader
I: 14-08-20 12:04:47 1-pipe1: broadcast we are now reader
I: 14-08-20 12:04:47 open local reader
D: 14-08-20 12:04:47    499:1-pipe1                         :         > before reading
D: 14-08-20 12:04:47    499:1-pipe1                         : before reading:
D: 14-08-20 12:04:47    499:1-pipe1                         :     ok
D: 14-08-20 12:04:47    499:1-pipe1                         :         $ send INPUT_OK
D: 14-08-20 12:04:47    499:1-pipe1                         :         > reading
D: 14-08-20 12:04:47    499:1-pipe1                         : reading:
D: 14-08-20 12:04:47    499:1-pipe1                         :     READ
D: 14-08-20 12:04:47    499:1-pipe1                         :         $ process read request
D: 14-08-20 12:04:47    499:1-pipe1                         :         > processing read
I: 14-08-20 12:04:52 ZPIPES server vanished from 8F8E50
D: 14-08-20 12:04:52    499:1-pipe1                         : processing read:
D: 14-08-20 12:04:52    499:1-pipe1                         :     wakeup
D: 14-08-20 12:04:52    499:1-pipe1                         :         $ send READ_TIMEOUT
D: 14-08-20 12:04:52    499:1-pipe1                         :         > reading

[hintjens]

I'll add an extra log to make sure this is the latest version...
On Aug 20, 2014 7:17 PM, "Ron Pedde" notifications@github.com wrote:

Still seems to be happening.

Error in test
"/home/rpedde/working/work/python-zbroker/scripts/simple_writer.yml"
Host "writer" (airbook.local)

Post started at: 14-08-20 12:04:45
Running tasks: 1
Test script

sleep 1
timeout 5000
open pipe1 write
write pipe1 abc
close pipe1 write

Script Log

14-08-20 12:04:46 Set prefix to 1
14-08-20 12:04:46 Set broker to 1-0
14-08-20 12:04:46 Sleeping for 1 seconds
14-08-20 12:04:47 Set timeout to 5000
14-08-20 12:04:47 Opening descriptor "1-0|>1-pipe1"

Broker Log

GNU gdb (GDB) 7.4.1-debian
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker...done.
(gdb) (gdb) (gdb) Starting program: /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker /tmp/tmpsezeZj/zbroker.cfg
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7ffff7ffa000
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-20 12:04:46 starting zpipes broker using config in '/tmp/tmpsezeZj/zbroker.cfg'
N: 14-08-20 12:04:46 starting zpipes service
I: 14-08-20 12:04:46 using TCP gossip discovery service
I: 14-08-20 12:04:46 gossip service connect to tcp://airbook.local:5672
[New Thread 0x7ffff65b0700 (LWP 22539)]
[New Thread 0x7ffff5daf700 (LWP 22540)]
[New Thread 0x7ffff55ae700 (LWP 22542)]
[New Thread 0x7ffff4dad700 (LWP 22543)]
[New Thread 0x7ffff45ac700 (LWP 22544)]
I: 14-08-20 12:04:46 Zyre node endpoint=tcp://:49153 announce=tcp://airbook.internal.pedde.com:49153
I: 14-08-20 12:04:46 joining cluster as 76F912
I: 14-08-20 12:04:46 ZPIPES server appeared at 76F912
I: 14-08-20 12:04:46 ZPIPES server appeared at E64CC4
I: 14-08-20 12:04:46 ZPIPES server appeared at 76F912
I: 14-08-20 12:04:46 ZPIPES server appeared at 8F8E50
I: 14-08-20 12:04:46 ZPIPES server vanished from 76F912
E: 14-08-20 12:04:46 (76F912) cannot connect to endpoint=tcp://:49153
zbroker: zyre_peer.c:143: zyre_peer_connect: Assertion `0' failed.

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff4dad700 (LWP 22543)]
0x00007ffff71a6475 in *__GI_raise (sig=)
at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
64 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) #0 0x00007ffff71a6475 in *__GI_raise (sig=)
at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1 0x00007ffff71a96f0 in *__GI_abort () at abort.c:92
#2 0x00007ffff719f621 in *__GI___assert_fail (assertion=0x7ffff79bec6b "0",
file=, line=143,
function=0x7ffff79bf070 "zyre_peer_connect") at assert.c:81
#3 0x00007ffff79b8a73 in zyre_peer_connect ()
from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#4 0x00007ffff79baba6 in zyre_node_require_peer ()
from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#5 0x00007ffff79bb17f in zyre_node_recv_peer ()
from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#6 0x00007ffff79bbba2 in zyre_node_actor ()
from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/lib/libzyre.so.1
#7 0x00007ffff776225d in s_thread_shim (args=0x612940) at zactor.c:67
#8 0x00007ffff6cdcb50 in start_thread (arg=)
at pthread_create.c:304
#9 0x00007ffff72500ed in clone ()
at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#10 0x0000000000000000 in ?? ()
(gdb) A debugging session is active.

Inferior 1 [process 22522] will be killed.

Quit anyway? (y or n) [answered Y; input not from terminal]

Host "reader" (airbook.local)

Post started at: 14-08-20 12:04:45
Running tasks: 1
Test script

sleep 1
timeout 5000
open pipe1 read
read pipe1 3 abc
close pipe1 read

Script Log

14-08-20 12:04:46 Set prefix to 1
14-08-20 12:04:46 Set broker to 1-1
14-08-20 12:04:46 Sleeping for 1 seconds
14-08-20 12:04:47 Set timeout to 5000
14-08-20 12:04:47 Opening descriptor "1-1|1-pipe1"
14-08-20 12:04:47 Opened pipe "pipe1" for read
14-08-20 12:04:47 Reading 3 bytes from pipe "pipe1"
14-08-20 12:04:52 Unexpected exception: timeouterror
14-08-20 12:04:52 Test failed

Broker Log

GNU gdb (GDB) 7.4.1-debian
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker...done.
(gdb) (gdb) (gdb) Starting program: /opt/bundler/zvm2-zpipes/zvm2-zpipes-00008/bin/zbroker /tmp/tmpO00ITV/zbroker.cfg
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7ffff7ffa000
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
zbroker service/0.0.2
Copyright (c) 2014 the Contributors
This Software is provided under the MPLv2 License on an "as is" basis,
without warranty of any kind, either expressed, implied, or statutory.

I: 14-08-20 12:04:46 starting zpipes broker using config in '/tmp/tmpO00ITV/zbroker.cfg'
N: 14-08-20 12:04:46 starting zpipes service
I: 14-08-20 12:04:46 using TCP gossip discovery service
I: 14-08-20 12:04:46 gossip service connect to tcp://airbook.local:5672
[New Thread 0x7ffff65b0700 (LWP 22532)]
[New Thread 0x7ffff5daf700 (LWP 22533)]
[New Thread 0x7ffff55ae700 (LWP 22534)]
[New Thread 0x7ffff4dad700 (LWP 22536)]
[New Thread 0x7ffff45ac700 (LWP 22538)]
I: 14-08-20 12:04:46 Zyre node endpoint=tcp://*:49152 announce=tcp://airbook.internal.pedde.com:49152
I: 14-08-20 12:04:46 joining cluster as 8F8E50
I: 14-08-20 12:04:46 ZPIPES server appeared at 8F8E50
I: 14-08-20 12:04:46 ZPIPES server appeared at E64CC4
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
I: 14-08-20 12:04:47 ZPIPES server vanished from
D: 14-08-20 12:04:47 499: : start:
D: 14-08-20 12:04:47 499: : INPUT
D: 14-08-20 12:04:47 499: : $ lookup or create pipe
D: 14-08-20 12:04:47 499:1-pipe1 : $ open pipe reader
I: 14-08-20 12:04:47 1-pipe1: attach local reader
I: 14-08-20 12:04:47 1-pipe1: broadcast we are now reader
I: 14-08-20 12:04:47 open local reader
D: 14-08-20 12:04:47 499:1-pipe1 : > before reading
D: 14-08-20 12:04:47 499:1-pipe1 : before reading:
D: 14-08-20 12:04:47 499:1-pipe1 : ok
D: 14-08-20 12:04:47 499:1-pipe1 : $ send INPUT_OK
D: 14-08-20 12:04:47 499:1-pipe1 : > reading
D: 14-08-20 12:04:47 499:1-pipe1 : reading:
D: 14-08-20 12:04:47 499:1-pipe1 : READ
D: 14-08-20 12:04:47 499:1-pipe1 : $ process read request
D: 14-08-20 12:04:47 499:1-pipe1 : > processing read
I: 14-08-20 12:04:52 ZPIPES server vanished from 8F8E50
D: 14-08-20 12:04:52 499:1-pipe1 : processing read:
D: 14-08-20 12:04:52 499:1-pipe1 : wakeup
D: 14-08-20 12:04:52 499:1-pipe1 : $ send READ_TIMEOUT
D: 14-08-20 12:04:52 499:1-pipe1 : > reading

—
Reply to this email directly or view it on GitHub
#101 (comment).

[hintjens]

OK, you're definitely still running the previous version, this log line isn't in the source any more:

Zyre node endpoint=tcp://*:49153 announce=tcp://airbook.internal.pedde.com:49153

[rpedde]

ah gack. i had it pinned to before the printf format change and forgot to unpin it when it got fixed. Will try again. Sorry.

[rpedde]

believe this to be fixed.