.Net RabbitMQ Client Library Fails Consistently on Ubuntu

[Richard Tasker]

Hi All,

I have a .net hello world application which is developed on osx and ran on linux (ubuntu 16.04 atm). Our application works fine in development on our macs but as soon as we run it in a docker container on our ubuntu testing vm the RMQ connection fails.

We use the RawRabbit library to talk to RMQ, but the exception we see are from the RabbitMQ.Client library.

I have attached the logs for you to see. I have put the application container on docker hub for you to use. it is available via,

docker pull vqcomms/rabbitfailure

In the container example RMQ and the app are in separate containers, but the failure can also be seen when RMQ and the app are in the same container. I have also attached a docker compose file for you to run. Download the attached file in a new folder and run the following command in the same folder.

docker-compose up

Here is the code that is being executed in the app.

using System;

using System.Threading;

using System.Threading.Tasks;

using RawRabbit.Configuration;

using RawRabbit.vNext;

using RMQ.Core.Messaging;

namespace RMQ.Consumer

{

class Program

{

static void Main(string[] args)

{

Thread.Sleep(10000); // Wait for RMQ container to start

var budClient = BusClientFactory.CreateDefault(new RawRabbitConfiguration { Hostnames = { "rmq" } });

Console.WriteLine("Consumer - Subscribing to Ping Messages");

budClient.SubscribeAsync<PongMessage>((msg, context) =>

{

Console.WriteLine($"Consumer - Received Ping: {msg.Message} : {DateTime.Now.ToString("HH:mm:ss:fff")}");

return Task.CompletedTask;

});

Console.ReadLine();

}

}

}

Please let me know if you require more info.

Regards,

Rich

[Michael Klishin]

According to the logs, RabbitMQ accepts a connection and then the client closes TCP connection,

and something (RawRabbit? your code?) reports that a connection has timed out.

We only support RabbitMQ .NET client versions starting with 4.0 on non-Windows platforms and only on .NET Core.

Is that what your example is running? I don't know what .NET client version RawRabbit uses but it seems to put a bunch of opinionated stuff on top (channel scaling? I don't know what that is).

Lastly, taking a traffic capture may reveal what is really going on. As far as I can tell with the amount of information provided in the logs,

at some point a read operation on a TCP connection to RabbitMQ node times out and it is detected

by .NET itself, not heartbeats (http://rabbitmq.com/heartbeats.html). Which is not an indication of a problem in any of the libraries

involved.

We have seen obscure Linux-specific issues around networking (well, TLS) even on .NET Core in the past.

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

MK

Staff Software Engineer, Pivotal/RabbitMQ

[Michael Klishin]

More stuff that is confusing:

consumer_1  | [10:22:59] [$3] [INFO] [TopologyProvider]: Disposing topology channel (if exists).

consumer_1  | [11:23:03] [$8] [DEBUG] [EventingRawConsumer]: The consumer with tag 'amq.ctag-pTNDUydHsfR4XHuvxGm6VA' has been cancelled.

I have no idea why would a consumer be cancelled if there's a network connection problem. Consumers are cancelled either explicitly

in application code or when their queue is deleted (https://www.rabbitmq.com/consumer-cancel.html). This sounds like a yet another

couple of features specific to RawRabbit.

I highly recommend porting your code to the .NET client 4.x on .NET Core to compare and taking a traffic capture with tcpdump/Wireshark.

To post to this group, send email to rabbitm...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

MK

Staff Software Engineer, Pivotal/RabbitMQ

[Jonathan Channon]

This docker container contains a .net core self contained app. RawRabbit depends on RabbitMQ.Client (>= 4.1.0) 

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-user...@googlegroups.com.

To post to this group, send email to rabbitm...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

MK

Staff Software Engineer, Pivotal/RabbitMQ

[Pär Dahlman]

The application runs version 1.10.3 of RawRabbit that was released 4 months ago. It has about 10k downloads, which isn't a lot, but enough to make me think that we would have heard about this issue before if it was related to RawRabbit. We have been running 1.10.3 since it was released (under Windows, though) and none of our 30+ services have the same experience. I also understand that the applications that Richard refers to runs under OS X without any problems.

The logs you refer to comes from two different threads, $3, the TopologyProvider, has a dedicated channel for creating queues and exchanges as well as binding queues to exchanges. The consumer from $8 has a dedicated channel that only handles that consumer.

The way I see it, the interesting part of the stack trace is the following

consumer_1  | [10:23:06] [$8] [INFO] [EventingRawConsumer]: Consumer amq.ctag-pTNDUydHsfR4XHuvxGm6VA has been shut down.
consumer_1  |   Reason: System.Net.Sockets.SocketException: Connection timed out
consumer_1  |    at RabbitMQ.Client.Impl.Frame.ReadFrom(NetworkBinaryReader reader)
consumer_1  |    at RabbitMQ.Client.Impl.SocketFrameHandler.ReadFrame()
consumer_1  |    at RabbitMQ.Client.Framing.Impl.Connection.MainLoopIteration()
consumer_1  |    at RabbitMQ.Client.Framing.Impl.Connection.MainLoop()
consumer_1  |   Initiator: Library
consumer_1  |   Reply Text: Unexpected Exception

It comes from here https://github.com/pardahlman/RawRabbit/blob/stable/src/RawRabbit/Consumer/Eventing/EventingRawConsumer.cs#L27. The way I read it, there is SocketException. Also initiator (which is the ShutdownInitiator) is Library, which I think refers to the RabbitMQ.Client, right? (Application would be application or RawRabbit, Peer would be Broker right?).

To summarize:
1. The app works in OsX, and I'm 99.999999999% sure it would work under Windows
2. There Library initiates the shutdown

To me that sounds like one of the obscure Linux issues?

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-user...@googlegroups.com.

To post to this group, send email to rabbitm...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

MK

Staff Software Engineer, Pivotal/RabbitMQ

[Michael Klishin]

Initiator of "application" means the user chose to close a connection by explicitly invoking IConnection#Close or similar.

Staff Software Engineer, Pivotal/RabbitMQ

[Pär Dahlman]

An initiator of "Library" (as in this case) would be the RabbitMQ.Client?

[Richard Tasker]

Michael,

To make sure the issue is not within RawRabbit I have rewritten the hello world app just using the RabbitMQ.Client package (4.1.3).

The SecketException is still being thrown. I have attached the code and logs for you to look over. Again this version of the app is able to connect to the bus on OSX but has trouble connecting on linux.

Regards,

Rich 

[Richard Tasker]

I have just removed any possible networking issues introduced by docker by installing rabbitmq on the ubuntu server and running the app. It still throws the exception.

./publish/RMQ.Consumer
Declaring exchange 'rmq.core.messaging'.
Declaring queue 'pongmessage_/app/rmq_consumer'.
Binding queue 'pongmessage_/app/rmq_consumer' to exchange 'rmq.core.messaging' with routing key 'pongmessage.#'
Setting QoS
  Prefetch Size: 0
  Prefetch Count: 50
  global: false
Setting up a consumer on channel 1 for queue pongmessage with NoAck set to False.
The consumer with tag 'amq.ctag-EuoX4zeqBV0T_drIXmMe6w' has been cancelled.
Consumer amq.ctag-EuoX4zeqBV0T_drIXmMe6w has been shut down.

  Reason: System.Net.Sockets.SocketException: Connection timed out

   at RabbitMQ.Client.Impl.Frame.ReadFrom(NetworkBinaryReader reader)
   at RabbitMQ.Client.Impl.SocketFrameHandler.ReadFrame()
   at RabbitMQ.Client.Framing.Impl.Connection.MainLoopIteration()
   at RabbitMQ.Client.Framing.Impl.Connection.MainLoop()
  Initiator: Library
  Reply Text: Unexpected Exception

-- Rich

[Chris McKee]

Hi,

  I changed the example code you provided to include auth as its mandatory and the user needs access to do the setup so my user has 

/

.*

.*

.*

 

var factory = new ConnectionFactory() { HostName = "127.0.0.1", Password="admin", UserName="admin" };

Is there anything else I need to do to make it crash?

Without the auth it crashes out as it lacks permissions; but it will do that in windows as well as linux and probably anything else.

[Jonathan Channon]

Diff seems to be auth and a not a self contained app ie/you execute it with dotnet tooling whereas a self contained app you just execute the published binary and don't need dotnet tooling installed. 

[Chris McKee]

Same result in self contained (runs fine), with auth of course. I am running 5.0.0-pre4 ; need to retry with stable.

[Michael Klishin]

Is it just my email client rendering it that way or the vhost below is "/_", not "/"?

Authentication and vhost permission (authorization) errors are logged and should be quite visible.

I cannot check them right now but IIRC one of the original logs provided earlier has *successful* connections

logged and then the client closes TCP connection abruptly. So the client reports a TCP socket read timeout

and the server reports an abruptly closed TCP connection from the client. Something doesn't add up

and containers definitely add complexity to the picture.

That's why I asked for a traffic dump.

[Chris McKee]

Retried with stable (current) nuget version of RMQ client on a clean ubuntu 16 lts machine connecting to a rabbit instance in another vm; using self-contained (had to install apt-get install libunwind8) to get it to run. Still runs fine.

Built/published in VS 2017 / windows 10. Zipped up solution and build files here https://cp.sync.com/dl/b6f36ee40#fb2fizun-zar9dhpt-tn5ttqre-5q7buik5

@Michael its / .* .* .*  Google groups copied the formatting from the admin client which is probably skewing it.

[Chris McKee]

Can someone attach the built packaged files + sln that fails; be interesting to see the difference between whats generated.

It's bloody weird.

[Michael Klishin]

Chris,

Thank you for spending your time on this.

[Michael Klishin]

FWIW our CI pipeline for RabbitMQ .NET client uses .NET Core on Linux in a container. And yes, everything is passes

(over 200 tests, mostly integration, taking some 10 minutes total).

On 21 Apr 2017, at 00:38, Chris McKee <pcde...@gmail.com> wrote:

[Chris McKee]

Closest I could get error wise was by running the self-contained program on a separate vm and resetting rmq app on the other vm which caused...

Which I'd expect.

This is my sln https://cp.sync.com/dl/b6f36ee40#fb2fizun-zar9dhpt-tn5ttqre-5q7buik5

This is my compiled for ubuntu published self-contained build, pointing at local host using admin/admin creds with https://cp.sync.com/dl/09bc0c160#dgymhuf8-7pf7yh5f-bmas7wh4-maf3qgy7

I reset rabbit using

sudo rabbitmqctl stop_app

sudo rabbitmqctl force_reset

sudo rabbitmqctl start_app

sudo rabbitmqctl change_password guest 1234567

sudo rabbitmqctl add_user admin admin

sudo rabbitmqctl set_user_tags admin administrator

sudo rabbitmqctl list_users

sudo rabbitmqctl set_permissions -p / admin ".*" ".*" ".*"

I assumed the creds were removed from the examples and that you're not using another of the auth mechanisms; also that your rabbit.config is default (none).

I'm at a bit of an impasse as I can't make it fail. If you can have a go in your VM with the above prebuilt binary we may be able to narrow it down; and maybe built on another mac to discount any core library pollution?

Ta

Chris

[Michael Klishin]

You can also cut inbound traffic on the app's VM using iptables.

It should have a similar effect (not necessarily a socket timeout

detected by the OS/.NET, though, could be that the heartbeat mechanism detects it first — and that's why it exists).

[Jonathan Channon]

The whole codebase is here https://github.com/VQComms/RMQDemo/tree/rmqclient

To build you can do

./build.sh ubuntu.16.04-x64

You may want to remove the docker build lines in that file also but the RMQ.Consumer standalone app will be put in a publish folder in the root of the repo.

I will take Chris' app and try it on our Ubuntu box

Cheers

[Jonathan Channon]

Just ran Chris' binary after creating the admin/admin user in RMQ and I get the same errors:

[192.168.1.183] ➜  chris ./RMQFubar

Declaring exchange 'rmq.core.messaging'.
Declaring queue 'pongmessage_/app/rmq_consumer'.
Binding queue 'pongmessage_/app/rmq_consumer' to exchange 'rmq.core.messaging' with routing key 'pongmessage.#'
Setting QoS
  Prefetch Size: 0
  Prefetch Count: 50
  global: false
Setting up a consumer on channel 1 for queue pongmessage with NoAck set to False.

The consumer with tag 'amq.ctag-ljFuznO2LU2wEXR__VdDOQ' has been cancelled.
Consumer amq.ctag-ljFuznO2LU2wEXR__VdDOQ has been shut down.

  Reason: System.Net.Sockets.SocketException: Connection timed out
   at RabbitMQ.Client.Impl.Frame.ReadFrom(NetworkBinaryReader reader)
   at RabbitMQ.Client.Impl.SocketFrameHandler.ReadFrame()
   at RabbitMQ.Client.Framing.Impl.Connection.MainLoopIteration()
   at RabbitMQ.Client.Framing.Impl.Connection.MainLoop()
  Initiator: Library
  Reply Text: Unexpected Exception

I'll try and get some traffic dump. Any suggestions on best tool that you would like to see the output from?

[Jonathan Channon]

RMQ Logs are:

=INFO REPORT==== 21-Apr-2017::09:37:52 ===
Creating user 'admin'


=INFO REPORT==== 21-Apr-2017::09:37:52 ===
Setting user tags for user 'admin' to [administrator]


=INFO REPORT==== 21-Apr-2017::09:38:17 ===
Setting permissions for 'admin' in '/' to '.*', '.*', '.*'


=INFO REPORT==== 21-Apr-2017::09:38:40 ===
accepting AMQP connection <0.542.0> (127.0.0.1:48518 -> 127.0.0.1:5672)


=INFO REPORT==== 21-Apr-2017::09:38:40 ===
connection <0.542.0> (127.0.0.1:48518 -> 127.0.0.1:5672): user 'admin' authenticated and granted access to vhost '/'


=WARNING REPORT==== 21-Apr-2017::09:39:06 ===
closing AMQP connection <0.542.0> (127.0.0.1:48518 -> 127.0.0.1:5672):
client unexpectedly closed TCP connection

[Karl Nilsson]

Wireshark would be best but isn't always practical in a server setting - tcpdump would be probably be sufficient to get some idea what is going on.

See: https://www.wireshark.org/docs/wsug_html_chunked/AppToolstcpdump.html

So to sum up - this error happens when RabbitMQ 3.6.6 is installed directly on a ubuntu machine and the client program is run on a different machine or the same? As Michael mentioned our CI runs on completely on linux in a container setting. That said the tests only connect to localhost so there may be other things going on when the server is running remotely.

Cheers

Karl

--

You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Staff Software Engineer, Pivotal/RabbitMQ

[Jonathan Channon]

Currently the test is RMQ on Ubuntu 16.04 x64 and the client .netcore standalone app executing on the same machine. Docker has been removed and so has RawRabbit.

After executing 

sudo tcpdump port 5672 -w mycap.pcap

Then running the netcore app from Chris, the app fell over and attached is the mycap.pcap file. I think its pretty much empty.

If you'd like me to run a specific command of tcpdump, please let me know

Thanks

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-user...@googlegroups.com.
To post to this group, send email to rabbitm...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[Karl Nilsson]

Are you sure you are listening on the right interface? You normally have to specify the -i flag.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Karl Nilsson]

Best to try it without the -w flag to ensure you actually see traffic. You can list interfaces available with tcpdump -D

--

Karl Nilsson

Pivotal/RabbitMQ

--

Karl Nilsson

Pivotal/RabbitMQ

[Chris McKee]

I've set up an image in DO and copied my binary over; only thing I had to install was rabbitmq & libunwind8; I'll skype you the private key as the servers disposable. 

Seems ok though :| 

[Jonathan Channon]

Running the below whilst the app crashed, I can run again if you want the binary file?

sudo tcpdump -i any port 5672

tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked), capture size 262144 bytes
10:26:27.032963 IP localhost.56676 > localhost.amqp: Flags [S], seq 2709637204, win 43690, options [mss 65495,sackOK,TS val 228586385 ecr 0,nop,wscale 7], length 0
10:26:27.032989 IP localhost.amqp > localhost.56676: Flags [S.], seq 3112145387, ack 2709637205, win 43690, options [mss 65495,sackOK,TS val 228586385 ecr 228586385,nop,wscale 7], length 0
10:26:27.033004 IP localhost.56676 > localhost.amqp: Flags [.], ack 1, win 342, options [nop,nop,TS val 228586385 ecr 228586385], length 0
10:26:27.114881 IP localhost.56676 > localhost.amqp: Flags [P.], seq 1:9, ack 1, win 342, options [nop,nop,TS val 228586405 ecr 228586385], length 8
10:26:27.114897 IP localhost.amqp > localhost.56676: Flags [.], ack 9, win 342, options [nop,nop,TS val 228586405 ecr 228586405], length 0
10:26:27.115459 IP localhost.amqp > localhost.56676: Flags [P.], seq 1:496, ack 9, win 342, options [nop,nop,TS val 228586405 ecr 228586405], length 495
10:26:27.115474 IP localhost.56676 > localhost.amqp: Flags [.], ack 496, win 350, options [nop,nop,TS val 228586405 ecr 228586405], length 0
10:26:27.156673 IP localhost.56676 > localhost.amqp: Flags [P.], seq 9:418, ack 496, win 350, options [nop,nop,TS val 228586416 ecr 228586405], length 409
10:26:27.156969 IP localhost.amqp > localhost.56676: Flags [P.], seq 496:516, ack 418, win 350, options [nop,nop,TS val 228586416 ecr 228586416], length 20
10:26:27.156985 IP localhost.56676 > localhost.amqp: Flags [.], ack 516, win 350, options [nop,nop,TS val 228586416 ecr 228586416], length 0
10:26:27.160600 IP localhost.56676 > localhost.amqp: Flags [P.], seq 418:438, ack 516, win 350, options [nop,nop,TS val 228586417 ecr 228586416], length 20
10:26:27.163056 IP localhost.56676 > localhost.amqp: Flags [P.], seq 438:454, ack 516, win 350, options [nop,nop,TS val 228586417 ecr 228586416], length 16
10:26:27.163093 IP localhost.amqp > localhost.56676: Flags [.], ack 454, win 350, options [nop,nop,TS val 228586417 ecr 228586417], length 0
10:26:27.163161 IP localhost.amqp > localhost.56676: Flags [P.], seq 516:529, ack 454, win 350, options [nop,nop,TS val 228586417 ecr 228586417], length 13
10:26:27.168445 IP localhost.56676 > localhost.amqp: Flags [P.], seq 454:467, ack 529, win 350, options [nop,nop,TS val 228586419 ecr 228586417], length 13
10:26:27.168897 IP localhost.amqp > localhost.56676: Flags [P.], seq 529:545, ack 467, win 350, options [nop,nop,TS val 228586419 ecr 228586419], length 16
10:26:27.183147 IP localhost.56676 > localhost.amqp: Flags [P.], seq 467:511, ack 545, win 350, options [nop,nop,TS val 228586422 ecr 228586419], length 44
10:26:27.183298 IP localhost.amqp > localhost.56676: Flags [P.], seq 545:557, ack 511, win 350, options [nop,nop,TS val 228586422 ecr 228586422], length 12
10:26:27.184980 IP localhost.56676 > localhost.amqp: Flags [P.], seq 511:560, ack 557, win 350, options [nop,nop,TS val 228586423 ecr 228586422], length 49
10:26:27.185139 IP localhost.amqp > localhost.56676: Flags [P.], seq 557:607, ack 560, win 350, options [nop,nop,TS val 228586423 ecr 228586423], length 50
10:26:27.186907 IP localhost.56676 > localhost.amqp: Flags [P.], seq 560:642, ack 607, win 350, options [nop,nop,TS val 228586423 ecr 228586423], length 82
10:26:27.187356 IP localhost.amqp > localhost.56676: Flags [P.], seq 607:619, ack 642, win 350, options [nop,nop,TS val 228586423 ecr 228586423], length 12
10:26:27.188325 IP localhost.56676 > localhost.amqp: Flags [P.], seq 642:661, ack 619, win 350, options [nop,nop,TS val 228586423 ecr 228586423], length 19
10:26:27.188423 IP localhost.amqp > localhost.56676: Flags [P.], seq 619:631, ack 661, win 350, options [nop,nop,TS val 228586424 ecr 228586423], length 12
10:26:27.191732 IP localhost.56676 > localhost.amqp: Flags [P.], seq 661:687, ack 631, win 350, options [nop,nop,TS val 228586424 ecr 228586424], length 26
10:26:27.191869 IP localhost.amqp > localhost.56676: Flags [P.], seq 631:643, ack 687, win 350, options [nop,nop,TS val 228586424 ecr 228586424], length 12
10:26:27.199887 IP localhost.56676 > localhost.amqp: Flags [P.], seq 687:700, ack 643, win 350, options [nop,nop,TS val 228586426 ecr 228586424], length 13
10:26:27.200257 IP localhost.amqp > localhost.56676: Flags [P.], seq 643:659, ack 700, win 350, options [nop,nop,TS val 228586426 ecr 228586426], length 16
10:26:27.204504 IP localhost.56676 > localhost.amqp: Flags [P.], seq 700:750, ack 659, win 350, options [nop,nop,TS val 228586428 ecr 228586426], length 50
10:26:27.204728 IP localhost.amqp > localhost.56676: Flags [P.], seq 659:703, ack 750, win 350, options [nop,nop,TS val 228586428 ecr 228586428], length 44
10:26:27.244386 IP localhost.56676 > localhost.amqp: Flags [.], ack 703, win 350, options [nop,nop,TS val 228586438 ecr 228586428], length 0
10:26:27.362859 IP localhost.56676 > localhost.amqp: Flags [P.], seq 750:758, ack 703, win 350, options [nop,nop,TS val 228586467 ecr 228586428], length 8
10:26:27.400394 IP localhost.amqp > localhost.56676: Flags [.], ack 758, win 350, options [nop,nop,TS val 228586477 ecr 228586467], length 0
10:26:42.362039 IP localhost.56676 > localhost.amqp: Flags [P.], seq 758:766, ack 703, win 350, options [nop,nop,TS val 228590217 ecr 228586477], length 8
10:26:42.362060 IP localhost.amqp > localhost.56676: Flags [.], ack 766, win 350, options [nop,nop,TS val 228590217 ecr 228590217], length 0
10:26:57.362736 IP localhost.56676 > localhost.amqp: Flags [P.], seq 766:774, ack 703, win 350, options [nop,nop,TS val 228593967 ecr 228590217], length 8
10:26:57.362757 IP localhost.amqp > localhost.56676: Flags [.], ack 774, win 350, options [nop,nop,TS val 228593967 ecr 228593967], length 0
10:27:06.887953 IP localhost.56676 > localhost.amqp: Flags [F.], seq 774, ack 703, win 350, options [nop,nop,TS val 228596348 ecr 228593967], length 0
10:27:06.888120 IP localhost.amqp > localhost.56676: Flags [R.], seq 703, ack 775, win 350, options [nop,nop,TS val 228596348 ecr 228596348], length 0

[Jonathan Channon]

On Friday, 21 April 2017 10:28:33 UTC+1, Jonathan Channon wrote:

Running the below whilst the app crashed, I can run again if you want the binary file?

sudo tcpdump -i any port 5672

tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked), capture size 262144 bytes
10:26:27.032963 IP localhost.56676 > localhost.amqp: Flags [S], seq 2709637204, win 43690, options [mss 65495,sackOK,TS val 228586385 ecr 0,nop,wscale 7], length 0
10:26:27.032989 IP localhost.amqp > localhost.56676: Flags [S.], seq 3112145387, ack 2709637205, win 43690, options [mss 65495,sackOK,TS val 228586385 ecr 228586385,nop,wscale 7], length 0
10:26:27.033004 IP localhost.56676 > localhost.amqp: Flags [.], ack 1, win 342, options [nop,nop,TS val 228586385 ecr 228586385], length 0
10:26:27.114881 IP localhost.56676 > localhost.amqp: Flags [P.], seq 1:9, ack 1, win 342, options [nop,nop,TS val 228586405 ecr 228586385], length 8
10:26:27.114897 IP localhost.amqp > localhost.56676: Flags [.], ack 9, win 342, options [nop,nop,TS val 228586405 ecr 228586405], length 0
10:26:27.115459 IP localhost.amqp > localhost.56676: Flags [P.], seq 1:496, ack 9, win 342, options [nop,nop,TS val 228586405 ecr 228586405], length 495
10:26:27.115474 IP localhost.56676 > localhost.amqp: Flags [.], ack 496, win 350, options [nop,nop,TS val 228586405 ecr 228586405], length 0
10:26:27.156673 IP localhost.56676 > localhost.amqp: Flags [P.], seq 9:418, ack 496, win 350, options [nop,nop,TS val 228586416 ecr 228586405], length 409
10:26:27.156969 IP localhost.amqp > localhost.56676: Flags [P.], seq 496:516, ack 418, win 350, options [nop,nop,TS val 228586416 ecr 228586416], length 20
10:26:27.156985 IP localhost.56676 > localhost.amqp: Flags [.], ack 516, win 350, options [nop,nop,TS val 228586416 ecr 228586416], length 0
10:26:27.160600 IP localhost.56676 > localhost.amqp: Flags [P.], seq 418:438, ack 516, win 350, options [nop,nop,TS val 228586417 ecr 228586416], length 20
10:26:27.163056 IP localhost.56676 > localhost.amqp: Flags [P.], seq 438:454, ack 516, win 350, options [nop,nop,TS val 228586417 ecr 228586416], length 16
10:26:27.163093 IP localhost.amqp > localhost.56676: Flags [.], ack 454, win 350, options [nop,nop,TS val 228586417 ecr 228586417], length 0

10:26:27.163161 IP localhost.amqp > localhost.56676: Flags [P.], seq 516:529, ack 454,<span st

[Chris McKee]

TCPDump on the DigitalOcean server i threw up;  tcpdump port 5672 -w mycap.pcap -i lo

I didnt kill the process while this was running -

reading from file mycap.pcap, link-type EN10MB (Ethernet)

09:28:42.145612 IP localhost.50862 > localhost.amqp: Flags [S], seq 929520256, win 43690, options [mss 65495,sackOK,TS val 193506 ecr 0,nop,wscale 6], length 0

09:28:42.145633 IP localhost.amqp > localhost.50862: Flags [S.], seq 3736223313, ack 929520257, win 43690, options [mss 65495,sackOK,TS val 193506 ecr 193506,nop,wscale 6], length 0

09:28:42.145650 IP localhost.50862 > localhost.amqp: Flags [.], ack 1, win 683, options [nop,nop,TS val 193506 ecr 193506], length 0

09:28:42.265588 IP localhost.50862 > localhost.amqp: Flags [P.], seq 1:9, ack 1, win 683, options [nop,nop,TS val 193536 ecr 193506], length 8

09:28:42.265617 IP localhost.amqp > localhost.50862: Flags [.], ack 9, win 683, options [nop,nop,TS val 193536 ecr 193536], length 0

09:28:42.267378 IP localhost.amqp > localhost.50862: Flags [P.], seq 1:502, ack 9, win 683, options [nop,nop,TS val 193537 ecr 193536], length 501

09:28:42.267433 IP localhost.50862 > localhost.amqp: Flags [.], ack 502, win 700, options [nop,nop,TS val 193537 ecr 193537], length 0

09:28:42.330555 IP localhost.50862 > localhost.amqp: Flags [P.], seq 9:418, ack 502, win 700, options [nop,nop,TS val 193552 ecr 193537], length 409

09:28:42.331205 IP localhost.amqp > localhost.50862: Flags [P.], seq 502:522, ack 418, win 700, options [nop,nop,TS val 193553 ecr 193552], length 20

09:28:42.331225 IP localhost.50862 > localhost.amqp: Flags [.], ack 522, win 700, options [nop,nop,TS val 193553 ecr 193553], length 0

09:28:42.336998 IP localhost.50862 > localhost.amqp: Flags [P.], seq 418:438, ack 522, win 700, options [nop,nop,TS val 193554 ecr 193553], length 20

09:28:42.341117 IP localhost.50862 > localhost.amqp: Flags [P.], seq 438:454, ack 522, win 700, options [nop,nop,TS val 193555 ecr 193553], length 16

09:28:42.341158 IP localhost.amqp > localhost.50862: Flags [.], ack 454, win 700, options [nop,nop,TS val 193555 ecr 193554], length 0

09:28:42.341299 IP localhost.amqp > localhost.50862: Flags [P.], seq 522:535, ack 454, win 700, options [nop,nop,TS val 193555 ecr 193554], length 13

09:28:42.349466 IP localhost.50862 > localhost.amqp: Flags [P.], seq 454:467, ack 535, win 700, options [nop,nop,TS val 193557 ecr 193555], length 13

09:28:42.350666 IP localhost.amqp > localhost.50862: Flags [P.], seq 535:551, ack 467, win 700, options [nop,nop,TS val 193557 ecr 193557], length 16

09:28:42.370182 IP localhost.50862 > localhost.amqp: Flags [P.], seq 467:511, ack 551, win 700, options [nop,nop,TS val 193562 ecr 193557], length 44

09:28:42.370734 IP localhost.amqp > localhost.50862: Flags [P.], seq 551:563, ack 511, win 700, options [nop,nop,TS val 193563 ecr 193562], length 12

09:28:42.373220 IP localhost.50862 > localhost.amqp: Flags [P.], seq 511:560, ack 563, win 700, options [nop,nop,TS val 193563 ecr 193563], length 49

09:28:42.373609 IP localhost.amqp > localhost.50862: Flags [P.], seq 563:613, ack 560, win 700, options [nop,nop,TS val 193563 ecr 193563], length 50

09:28:42.376346 IP localhost.50862 > localhost.amqp: Flags [P.], seq 560:642, ack 613, win 700, options [nop,nop,TS val 193564 ecr 193563], length 82

09:28:42.377256 IP localhost.amqp > localhost.50862: Flags [P.], seq 613:625, ack 642, win 700, options [nop,nop,TS val 193564 ecr 193564], length 12

09:28:42.378950 IP localhost.50862 > localhost.amqp: Flags [P.], seq 642:661, ack 625, win 700, options [nop,nop,TS val 193565 ecr 193564], length 19

09:28:42.379051 IP localhost.amqp > localhost.50862: Flags [P.], seq 625:637, ack 661, win 700, options [nop,nop,TS val 193565 ecr 193565], length 12

09:28:42.383719 IP localhost.50862 > localhost.amqp: Flags [P.], seq 661:687, ack 637, win 700, options [nop,nop,TS val 193566 ecr 193565], length 26

09:28:42.384006 IP localhost.amqp > localhost.50862: Flags [P.], seq 637:649, ack 687, win 700, options [nop,nop,TS val 193566 ecr 193566], length 12

09:28:42.396074 IP localhost.50862 > localhost.amqp: Flags [P.], seq 687:700, ack 649, win 700, options [nop,nop,TS val 193569 ecr 193566], length 13

09:28:42.396931 IP localhost.amqp > localhost.50862: Flags [P.], seq 649:665, ack 700, win 700, options [nop,nop,TS val 193569 ecr 193569], length 16

09:28:42.402869 IP localhost.50862 > localhost.amqp: Flags [P.], seq 700:750, ack 665, win 700, options [nop,nop,TS val 193571 ecr 193569], length 50

09:28:42.403405 IP localhost.amqp > localhost.50862: Flags [P.], seq 665:709, ack 750, win 700, options [nop,nop,TS val 193571 ecr 193571], length 44

09:28:42.442704 IP localhost.50862 > localhost.amqp: Flags [.], ack 709, win 700, options [nop,nop,TS val 193581 ecr 193571], length 0

09:28:42.543582 IP localhost.50862 > localhost.amqp: Flags [P.], seq 750:758, ack 709, win 700, options [nop,nop,TS val 193606 ecr 193571], length 8

09:28:42.582701 IP localhost.amqp > localhost.50862: Flags [.], ack 758, win 700, options [nop,nop,TS val 193616 ecr 193606], length 0

09:28:57.542057 IP localhost.50862 > localhost.amqp: Flags [P.], seq 758:766, ack 709, win 700, options [nop,nop,TS val 197355 ecr 193616], length 8

09:28:57.542081 IP localhost.amqp > localhost.50862: Flags [.], ack 766, win 700, options [nop,nop,TS val 197355 ecr 197355], length 0

09:29:12.543916 IP localhost.50862 > localhost.amqp: Flags [P.], seq 766:774, ack 709, win 700, options [nop,nop,TS val 201106 ecr 197355], length 8

09:29:12.543937 IP localhost.amqp > localhost.50862: Flags [.], ack 774, win 700, options [nop,nop,TS val 201106 ecr 201106], length 0

09:29:27.544067 IP localhost.50862 > localhost.amqp: Flags [P.], seq 774:782, ack 709, win 700, options [nop,nop,TS val 204856 ecr 201106], length 8

09:29:27.544099 IP localhost.amqp > localhost.50862: Flags [.], ack 782, win 700, options [nop,nop,TS val 204856 ecr 204856], length 0

On Friday, 21 April 2017 10:22:22 UTC+1, Chris McKee wrote:

[Karl Nilsson]

yes please the binary file would be great thanks.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Jonathan Channon]

See attached:

[Chris McKee]

If you open in wireshark and follow the tcp stream of the last message you see

basic.nackt..consumer_cancel_notifyt..connection.blockedt..authentication_failure_closet..connection_nameV.PLAIN.....admin.admin.en_US..

On Friday, 21 April 2017 10:41:52 UTC+1, Jonathan Channon wrote:

See attached:

[Chris McKee]

That might be unrelated as mine continues to run; even though

AMQP.. .........

.

. .....capabilitiesF.....publisher_confirmst..exchange_exchange_bindingst.

basic.nackt..consumer_cancel_notifyt..connection.blockedt..consumer_prioritiest..authentication_failure_closet..per_consumer_qost..direct_reply_tot..cluster_nameS....rabbit@rmq-temp.localdomain copyrightS....Copyright (C) 2007-2016 Pivotal Software, Inc..informationS...5Licensed under the MPL. See http://www.rabbitmq.com/.platformS...

Erlang/OTP.productS....RabbitMQ.versionS....3.6.9....AMQPLAIN PLAIN....en_US.........

.....m.productS....RabbitMQ.versionS....0.0.0.0.platformS.....NET copyrightS....Copyright (c) 2007-2016 Pivotal Software, Inc..informationS...5Licensed under the MPL. See http://www.rabbitmq.com/.capabilitiesF.....publisher_confirmst..exchange_exchange_bindingst.

basic.nackt..consumer_cancel_notifyt..connection.blockedt..authentication_failure_closet..connection_nameV.PLAIN.....admin.admin.en_US.........

.........<.........

.........<.........

.(./...........

.)............

........................$.(.

...rmq.core.messaging.topic..............(.........).2.

...pongmessage_/app/rmq_consumer............*.2...pongmessage_/app/rmq_consumer...............J.2.....pongmessage_/app/rmq_consumer.rmq.core.messaging

pongmessage.#..............2...........<.

.....2..........<.............(...Goodbye...............)...........

........................*.<.....pongmessage_/app/rmq_consumer.............$.<...amq.ctag-U0AGEqsEYgN6OkI_hvhe4Q.................................

My working pcap is attached for comparison.

[Karl Nilsson]

Those are capabilities reported by the broker. If there was a genuine auth failure it would not proceed beyond the connection frames.

Instead it appears that the client is sending a FIN packet after just over 14 seconds of socket inactivity. Does this tally with experience? 

The client, however sets the default socket timeout to 30s so unless you are tinkering with the timeout values I am not sure what is going on there. Could be netcore bug perhaps?

https://github.com/rabbitmq/rabbitmq-dotnet-client/blob/59919d314575ef7b92dcbbcb5bfd582b91f55e5f/projects/client/RabbitMQ.Client/src/client/api/ConnectionFactory.cs#L112

Jonathan/Richard - you could try experimenting by lowering the requested heartbeat interval on the ConnectionFactory to see if this makes a difference. Also you could try increasing the SocketReadTimeout.

Cheers

Karl

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Jonathan Channon]

I've tried my app on Chris VM and all OK, also replicated on a VM in scaleaway.com and also all ok.

Have changed the code slightly on our ubuntu machine to be:

var factory = new ConnectionFactory() { HostName = "localhost", UserName = "admin", Password = "admin", SocketReadTimeout = 10000, RequestedHeartbeat = 5 };

Still fell over, please see attached dump file from that code change.

On Friday, 21 April 2017 11:18:22 UTC+1, Karl Nilsson wrote:

Those are capabilities reported by the broker. If there was a genuine auth failure it would not proceed beyond the connection frames.

Instead it appears that the client is sending a FIN packet after just over 14 seconds of socket inactivity. Does this tally with experience? 

The client, however sets the default socket timeout to 30s so unless you are tinkering with the timeout values I am not sure what is going on there. Could be netcore bug perhaps?

https://github.com/rabbitmq/rabbitmq-dotnet-client/blob/59919d314575ef7b92dcbbcb5bfd582b91f55e5f/projects/client/RabbitMQ.Client/src/client/api/ConnectionFactory.cs#L112

Jonathan/Richard - you could try experimenting by lowering the requested heartbeat interval on the ConnectionFactory to see if this makes a difference. Also you could try increasing the SocketReadTimeout.

Cheers

Karl

On 21 April 2017 at 10:55, Chris McKee <pcde...@gmail.com> wrote:

If you open in wireshark and follow the tcp stream of the last message you see

basic.nackt..consumer_cancel_notifyt..connection.blockedt..authentication_failure_closet..connection_nameV.PLAIN.....admin.admin.en_US..

On Friday, 21 April 2017 10:41:52 UTC+1, Jonathan Channon wrote:

See attached:

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-user...@googlegroups.com.
To post to this group, send email to rabbitm...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Karl Nilsson]

Thanks, very odd, the client still initiates the close even though a heartbeat was read from the socket recently. So am I right to assume this issue is only reproducible on your ubuntu infrastructure?

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Jonathan Channon]

Afraid so :(

[Karl Nilsson]

Have you only got a single ubuntu box or have you got several? If the latter do they all exhibit the same issue?

Has you rabbit server tcp keepalives enabled? See: https://www.rabbitmq.com/networking.html

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Yantrio]

Hi Karl, Jonathan and myself have tried with the following configuration file, and the problem still exists

[

{rabbit, [

{tcp_listen_options, [{keepalive,true}]}

]}

].

I don't think this made any changes :(

[Karl Nilsson]

As it only happens on this single machine it is very likely to be an environmental issue. I'm not sure what else to suggest at this point. Perhaps there are some funky tcp kernel parameters in place or something. 

To determine if it is an issue with the client could you write a similar client application using another rabbitmq client library, perhaps the python or ruby ones and see if that also fails?

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Jonathan Channon]

A colleague last week wrote a python app from here and put that in a container and rmq in the same container and all was well.

[Yantrio]

I've enabled some event tracing on the dotnet side and got the attached logs as a result, I can't glean too much information from this, but maybe it will help someone.

[Karl Nilsson]

Thanks - it does confirm it is receive timeout and not something else. As you've confirmed other clients have been seen to work and it works in other environments I am leaning towards either a bug in .NET core for your particular linux configuration or possibly a bug in the client but without a means for reproduction I am not sure how to proceed looking at that.

have you got any other linux environment at hand you can test in?

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Jonathan Channon]

We can have whatever environment needs be to test this however we can reproduce this in Docker as shown in one of the original messages in this thread so I'm not sure if that is doable for you?  We are going to create a new VM for where we originally saw this issue in our integration testing and see if that resolves it however if it does its slightly concerning.  If it doesn't solve it we are happy to provide whatever you need and pay for support to solve the issue.

[Jonathan Channon]

So we've managed to find the image that causes the problem and have uploaded that image here - https://drive.google.com/drive/folders/0B3sp1P5dyJIsT0E1OWN0OUF0REk?usp=sharing

To confirm on a clean download of Ubuntu the app works fine.

In the above image we have installed Docker, htop, ohmyzsh, iTerm, VMWare Tools and that's about it.

Last week we tried updating Docker versions on that image as its behind what is released today. Doing it incrementally made no difference. Our thinking was maybe it was altering the network stack somehow and resulting in the exception we see but it didn't seem to solve it.

Would you mind investigating using this image? RabbitMQ is installed cleanly with a user with password admin/admin and the app is in ~/app. Simply run ./RMQ.Consumer to start it and wait for it to fall over which it does quite quickly.  It's baffling as there is very little installed on the image compared to a standard download off Ubuntu download page.

Thanks

[Karl Nilsson]

Thanks, I will try to get it running and have a look around.

Cheers

Karl

--

You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ

[Jonathan Channon]

Thanks, much appreciated

[Karl Nilsson]

I wasn't able to the get 6.4GB (!) vm disk to attach and run properly. I've tried to reproduce with an ubuntu 16.04 vm but no luck there either. I also tried the docker-compose file above and the subscriber is still sitting there after nearly an hour, no crash in sight.

Any chance you could just re-build your linux infra and see if that fixes it?

Cheers

Karl

On 25 April 2017 at 11:59, Jonathan Channon <jonathan...@gmail.com> wrote:

Thanks, much appreciated

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Karl Nilsson

Pivotal/RabbitMQ