MQTT Last Will not retaining messages

[devops-github]

Hello, first of all thanks for maintaining such a great tool to all the people involved in the project. I've been using it for a while and has helped a lot in my previous projects.

I believe I found an issue with the MQTT adapter's ability to retain Last Will messages. What I am trying to achieve is a "last_status" channel for IoT. Devices post an "Online" message whenever they connect including some useful info, with retained=True, and they set an "Offline" Last Will in case they disconnect, also with retained=True.

I haven't been able to make that work. I've went through RabbitMQ config, I've made queues durable, went through MQTT adapter config, and it never happened. Only the published messages with retain=True are retained, but not last wills with retain=True.

I then tried with another MQTT broker and it worked. Here are the steps to reproduce the bug. I am using Python with PAHO MQTT client.

import paho.mqtt.client as mqtt

TOPIC = 'device/status'
BROKER = 'my.own.broker.url'

client = mqtt.Client(
    client_id="TestPublisher",
    clean_session=False,
    protocol=mqtt.MQTTv311,
)
client.will_set(TOPIC, 'Offline', qos=1, retain=True)
client.connect(host=BROKER, port=8883)
client.publish(TOPIC, str("Online"), retain=True)

This works properly, and first sends the "Online" message, and afterwards the "Offline" message. In another listener I see this messages:

Received message on topic device/status: "Online"
Received message on topic device/status: "Offline"

When I restart the listener, I receive the following retained message:

Received message on topic device/status: "Online"

If I change the broker to a sample broker from Eclipse:

import paho.mqtt.client as mqtt

TOPIC = 'device/status'
BROKER = "iot.eclipse.org"

client = mqtt.Client(
    client_id="TestPublisher",
    clean_session=False,
    protocol=mqtt.MQTTv311,
)
client.will_set(TOPIC, 'Offline', qos=1, retain=True)
client.connect(host=BROKER, port=1883)
client.publish(TOPIC, str("Online"), retain=True)

The next time I restart the listener I receive:

Received message on topic device/status: "Offline"

Any ideas of what can be wrong in my setup? Or is it definitely a bug?

Thanks in advance,
Chesco.

[michaelklishin]

What version of RabbitMQ is used? What's in log files?

[francisco-elements]

RabbitMQ status:

[{pid,8952},
 {running_applications,
     [{rabbitmq_auth_backend_http,"RabbitMQ HTTP Authentication Backend",[]},
      {mochiweb,"MochiMedia Web Server","2.13.0"},
      {rabbitmq_mqtt,"RabbitMQ MQTT Adapter","3.6.1"},
      {rabbit,"RabbitMQ","3.6.1"},
      {os_mon,"CPO  CXC 138 46","2.2.14"},
      {amqp_client,"RabbitMQ AMQP Client","3.6.1"},
      {rabbit_common,[],"3.6.1"},
      {mnesia,"MNESIA  CXC 138 12","4.11"},
      {inets,"INETS  CXC 138 49","5.9.7"},
      {ranch,"Socket acceptor pool for TCP protocols.","1.2.1"},
      {compiler,"ERTS  CXC 138 10","4.9.4"},
      {syntax_tools,"Syntax tools","1.6.12"},
      {ssl,"Erlang/OTP SSL application","5.3.2"},
      {public_key,"Public key infrastructure","0.21"},
      {asn1,"The Erlang ASN1 compiler version 2.0.4","2.0.4"},
      {crypto,"CRYPTO version 2","3.2"},
      {xmerl,"XML parser","1.3.5"},
      {sasl,"SASL  CXC 138 11","2.3.4"},
      {stdlib,"ERTS  CXC 138 10","1.19.4"},
      {kernel,"ERTS  CXC 138 10","2.16.4"}]},
 {os,{unix,linux}},
 {erlang_version,
     "Erlang R16B03 (erts-5.10.4) [source] [64-bit] [async-threads:64] [kernel-poll:true]\n"},
 {memory,
     [{total,83784024},
      {connection_readers,0},
      {connection_writers,0},
      {connection_channels,0},
      {connection_other,579984},
      {queue_procs,401216},
      {queue_slave_procs,0},
      {plugins,60688},
      {other_proc,16762816},
      {mnesia,109144},
      {mgmt_db,0},
      {msg_index,1914560},
      {other_ets,4574008},
      {binary,28459768},
      {code,25795277},
      {atom,891825},
      {other_system,4234738}]},
 {alarms,[]},
 {listeners,[{clustering,25672,"::"},{amqp,5672,"::"},{mqtt,1883,"::"}]},
 {vm_memory_high_watermark,0.4},
 {vm_memory_limit,416286310},
 {disk_free_limit,50000000},
 {disk_free,6851149824},
 {file_descriptors,
     [{total_limit,924},{total_used,7},{sockets_limit,829},{sockets_used,5}]},
 {processes,[{limit,1048576},{used,285}]},
 {run_queue,0},
 {uptime,1188899},
 {kernel,{net_ticktime,60}}]

Logs show nothing too interesting I guess:

=INFO REPORT==== 5-Apr-2016::11:37:19 ===
accepting MQTT connection <0.23672.89> (X.Y.Z.9:39612 -> X.Y.Z.20.92:1883)

=INFO REPORT==== 5-Apr-2016::11:37:20 ===
MQTT detected network error for "X.Y.Z.21.9:39612 -> X.Y.Z.20.92:1883": peer closed TCP connection

[michaelklishin]

OK, that's enough information to investigate, thanks for the code sample.

[michaelklishin]

There is another log, rabbitmq-sasl.log. Is there anything?

[francisco-elements]

Nope, I checked and there were no updates at all when interacting with it during the tests. If you need anything else just say. Cheers!

[francisco-elements]

Hey @michaelklishin any news about the status of this ticket? Thanks

[michaelklishin]

@francisco-elements no update. This issue is not a high priority at the moment.

[francisco-elements]

Ok @michaelklishin thanks for the response, we'll keep on waiting until that moment arrives while it's not a blocking issue for us. Please keep us updated if there are any news about this.

[pavi32]

HI @francisco-elements i am getting same issue, how to fix this issue

[francisco-elements]

Hey @pavi32 we're still waiting... for now we set up a continuous listener all the time and an API call that returns the last known status of the machines. We're still hoping this will get attention as it is definitely a bug in the platform.

[simondkim]

+1 Same for me. I wasn't able to get retain working for the will message. Any update on this? @michaelklishin By the way, thanks for the great work with RabbitMQ and especially with the MQTT plugin. We're loving it so far.

[FrankAdesys]

Hi, I'm also faced with his issue.
I don't know if it helps, but I did some digging around in the code and might have found what the problem is. However, I'm not familiar with Erlang, so please ignore this post if it doesn't make sense...

What I found was that with a regular published message, a retained message is send to the retainer in "rabbit_mqtt_processor.erl" on lines 190-193:

190:    case Retain of
191:      false -> ok;
192:      true  -> hand_off_to_retainer(RPid, Topic, Msg)
193:    end,

However, when a LWT is published, the "retained" flag is not checked and will not be stored to the retainer. So hopefully adding the above 4 lines around line 458 of "rabbit_mqtt_processor.erl" will solve the problem.

Again, not familiar with Erlang, just trying to speed up solving this issue.

[michaelklishin]

@FrankAdesys thanks. It does make sense (at least without looking at the code) :)

[acogoluegnes]

@devops-github Would you be interested in running your test against a patched version of RabbitMQ that contains the fix for the retained last will (using RabbitMQ generic Unix package)?

[chescales]

@acogoluegnes yes sure I'd be glad to try it! How can I get it?

Edit: it was me who posted under the devops-github account ;)

[acogoluegnes]

Here it is: https://drive.google.com/file/d/0B7BDFc9o83HmMFNxSDJQUm91ZFU/view?usp=sharing

[michaelklishin]

@chescales you can get 3.6.7 Milestone 2 binary builds from GitHub.

[chescales]

@michaelklishin @acogoluegnes works like a charm, thanks! Do you know when approximately could 3.6.7 be released?

[michaelklishin]

@chescales should be this month.

[chescales]

Ok awesome, again thanks for the great work.