Python Connector protocol client sends Message before Notify?

[slfritchie]

Is this a bug, feature request, or feedback?

Bug

What is the current behavior?

ConnectorError: Bad stream_id 15678928204669818676

What is the expected behavior?

The Python Connector client should always send a Notify message for any given stream ID before sending a Message message that uses that stream ID.

What OS and version of Wallaroo are you using?

Ubuntu Xenial/16.04 LTS + aloc-tee-source+new-passthrough branch @ commit bf5ec10

Steps to reproduce?

$ cd /top/of/wallaroo/repo
$ git checkout -f 7ab14750cd ; echo We need the passthrough app from another branch
$ mv examples/pony/passthrough 
$ git checkout -f COMMIT-ABOVE
$ mv passthrough examples/pony
$ dd if=testing/data/market_spread/nbbo/r3k-symbols_nbbo-fixish.msg bs=1000000 count=4 | od -x | sed 's/^/T/' > /tmp/input-file.txt
$ cd testing/correctness/scripts/effectively-once
$ make -C ../../../.. PONYCFLAGS="--verbose=1 -d -Dresilience -Dtrace -Dcheckpoint_trace -Didentify_routing_ids" build-examples-pony-passthrough build-testing-tools-external_sender     build-utils-cluster_shrinker

$ ./master-crasher.sh 2 crash1 crash-sink
$ tail -n 3 /tmp/wallaroo.*

... then wait for intermittent error in /tmp/sender.out:

2019-09-20 05:09:29,288 ERROR    [__init__.py:693] handle_close
2019-09-20 05:09:29,289 DEBUG    [__init__.py:245] _stop_asyncore_loop
2019-09-20 05:09:29,289 DEBUG    [__init__.py:654] Removing socket from asyncore map
2019-09-20 05:09:29,289 DEBUG    [__init__.py:660] Closing socket 3
2019-09-20 05:09:29,289 DEBUG    [connectors.py:442] MultiSourceConnector closed Stream(id=15678928204669818676L, name='/tmp/input-file.txt', point_of_ref=132986, is_open=False)
2019-09-20 05:09:29,390 DEBUG    [__init__.py:676] _reconnect_common: top
2019-09-20 05:09:29,391 DEBUG    [__init__.py:384] Now connected on socket 3
2019-09-20 05:09:29,391 DEBUG    [__init__.py:415] Socket 3 now ready
2019-09-20 05:09:29,392 DEBUG    [connectors.py:412] MultiSourceConnector added Stream(id=15678928204669818676L, name='/tmp/input-file.txt', point_of_ref=132986, is_open=False)
2019-09-20 05:09:29,392 DEBUG    [connectors.py:184] resetting FramedFileReader(filename: /tmp/input-file.txt, closed: False, point_of_ref: 423801) from 423801 to position 132986
2019-09-20 05:09:29,393 ERROR    [__init__.py:720] Closing the connection after encountering an error:
Traceback (most recent call last):
  File "/usr/lib/python2.7/asyncore.py", line 83, in read
    obj.handle_read_event()
  File "/usr/lib/python2.7/asyncore.py", line 449, in handle_read_event
    self.handle_read()
  File "/usr/lib/python2.7/asynchat.py", line 147, in handle_read
    self.found_terminator()
  File "/home/vagrant/wallaroo/machida/lib/wallaroo/experimental/__init__.py", line 283, in found_terminator
    self._handle_frame(frame)
  File "/home/vagrant/wallaroo/machida/lib/wallaroo/experimental/__init__.py", line 297, in _handle_frame
    raise ConnectorError(msg.message)
ConnectorError: Bad stream_id 15678928204669818676