debug_output.txt

[88396] 2016/12/30 10:36:39.184894 [DBG] 127.0.0.1:49506 - cid:73 - Client connection created
[88396] 2016/12/30 10:36:39.185146 [TRC] 127.0.0.1:49506 - cid:73 - ->> [CONNECT {"version":"1.3","verbose":true,"protocol":1,"pedantic":false,"lang":"elixir"}]
[88396] 2016/12/30 10:36:39.185191 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:39.185439 [TRC] 127.0.0.1:49506 - cid:73 - ->> [SUB one_off.c4b487b4 c4b487b4]
[88396] 2016/12/30 10:36:39.185464 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:39.185622 [TRC] 127.0.0.1:49506 - cid:73 - ->> [UNSUB c4b487b4 1]
[88396] 2016/12/30 10:36:39.185634 [DBG] 127.0.0.1:49506 - cid:73 - Deferring actual UNSUB(one_off.c4b487b4): 1 max, 0 received
[88396] 2016/12/30 10:36:39.185640 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:39.185801 [TRC] 127.0.0.1:49506 - cid:73 - ->> [PUB _STAN.discover.test-cluster one_off.c4b487b4 28]
[88396] 2016/12/30 10:36:39.185812 [TRC] 127.0.0.1:49506 - cid:73 - ->> MSG_PAYLOAD: [
nats_streaming_exheartin]
[88396] 2016/12/30 10:36:39.185818 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:39.185827 [TRC] 127.0.0.1:51366 - cid:2 - <<- [MSG _STAN.discover.test-cluster 2 one_off.c4b487b4 28]
[88396] 2016/12/30 10:36:39.186017 [TRC] 127.0.0.1:51366 - cid:2 - ->> [PUB one_off.c4b487b4 179]
[88396] 2016/12/30 10:36:39.186041 [TRC] 127.0.0.1:51366 - cid:2 - ->> MSG_PAYLOAD: [
 _STAN.pub.j2UwoevbQUieAvFAEeDG3d _STAN.sub.j2UwoevbQUieAvFAEeDG8r"_STAN.unsub.j2UwoevbQUieAvFAEeDGJJ""_STAN.close.j2UwoevbQUieAvFAEeDGOX2%_STAN.subclose.j2UwoevbQUieAvFAEeDGE5]
[88396] 2016/12/30 10:36:39.186053 [DBG] 127.0.0.1:51366 - cid:2 - Auto-unsubscribe limit of 1 reached for sid 'c4b487b4'
[88396] 2016/12/30 10:36:39.186107 [TRC] 127.0.0.1:49506 - cid:73 - <<- [MSG one_off.c4b487b4 c4b487b4 179]
[88396] 2016/12/30 10:36:39.186139 [TRC] 127.0.0.1:49506 - cid:73 - <-> [DELSUB c4b487b4]
[88396] 2016/12/30 10:36:42.097439 [TRC] 127.0.0.1:49506 - cid:73 - ->> [SUB fooinbox 130ed5d1]
[88396] 2016/12/30 10:36:42.097470 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:42.097728 [TRC] 127.0.0.1:49506 - cid:73 - ->> [SUB heartin a1a5ed78]
[88396] 2016/12/30 10:36:42.097752 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:42.098007 [TRC] 127.0.0.1:49506 - cid:73 - ->> [SUB one_off.6af3af24 6af3af24]
[88396] 2016/12/30 10:36:42.098026 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:42.098138 [TRC] 127.0.0.1:49506 - cid:73 - ->> [UNSUB 6af3af24 1]
[88396] 2016/12/30 10:36:42.098151 [DBG] 127.0.0.1:49506 - cid:73 - Deferring actual UNSUB(one_off.6af3af24): 1 max, 0 received
[88396] 2016/12/30 10:36:42.098157 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:42.098274 [TRC] 127.0.0.1:49506 - cid:73 - ->> [PUB _STAN.sub.j2UwoevbQUieAvFAEeDG8r one_off.6af3af24 39]
[88396] 2016/12/30 10:36:42.098286 [TRC] 127.0.0.1:49506 - cid:73 - ->> MSG_PAYLOAD: [
nats_streaming_exfoofooinbox0�P]
[88396] 2016/12/30 10:36:42.098291 [TRC] 127.0.0.1:49506 - cid:73 - <<- [OK]
[88396] 2016/12/30 10:36:42.098300 [TRC] 127.0.0.1:51366 - cid:2 - <<- [MSG _STAN.sub.j2UwoevbQUieAvFAEeDG8r 4 one_off.6af3af24 39]
[88396] 2016/12/30 10:36:42.098456 [TRC] 127.0.0.1:51366 - cid:2 - ->> [SUB _INBOX.j2UwoevbQUieAvFAEeDUTF  172]
[88396] 2016/12/30 10:36:42.098474 [TRC] 127.0.0.1:51366 - cid:2 - ->> [PING]
[88396] 2016/12/30 10:36:42.098479 [TRC] 127.0.0.1:51366 - cid:2 - <<- [PONG]
[88396] 2016/12/30 10:36:42.098593 [TRC] 127.0.0.1:51365 - cid:1 - ->> [PUB one_off.6af3af24 31]
[88396] 2016/12/30 10:36:42.098604 [TRC] 127.0.0.1:51365 - cid:1 - ->> MSG_PAYLOAD: [_INBOX.j2UwoevbQUieAvFAEeDUTF]
[88396] 2016/12/30 10:36:42.098615 [DBG] 127.0.0.1:51365 - cid:1 - Auto-unsubscribe limit of 1 reached for sid '6af3af24'
[88396] 2016/12/30 10:36:42.098621 [TRC] 127.0.0.1:49506 - cid:73 - <<- [MSG one_off.6af3af24 6af3af24 31]
[88396] 2016/12/30 10:36:42.098627 [TRC] 127.0.0.1:49506 - cid:73 - <-> [DELSUB 6af3af24]

From the trace, it looks like the Streaming server is correctly sending the message to "fooinbox". The "Stalled" debug statement indicates that the MaxInflight was set to 1. If you did not do that, I would recommend double-checking the serialization of the SubscriptionRequest protocol.

Actually, re-run with both -SDV -DV to get streaming and nats debug/trace in the same log.

Ok, I think that the issue is that you set the MaxInflight to 0, which prevents the first message to even be sent. I think we should fix that in the server to reject MaxInflight value <= 0.