Bug 798731 - clustered brokers rewrite timestamps in messages
Summary: clustered brokers rewrite timestamps in messages
Keywords:
Status: NEW
Alias: None
Product: Red Hat Enterprise MRG
Classification: Red Hat
Component: qpid-cpp
Version: Development
Hardware: Unspecified
OS: Unspecified
low
medium
Target Milestone: ---
: ---
Assignee: Ken Giusti
QA Contact: Messaging QE
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-02-29 17:04 UTC by Leonid Zhaldybin
Modified: 2022-04-23 08:28 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Leonid Zhaldybin 2012-02-29 17:04:47 UTC
Description of problem:
The new feature was introduced in qpid 0.14 - "Support for timestamping messages on arrival at the broker." A broker can be configured to add a timestamp to the message it receives from a client.
The problem is that when a broker which is part of a cluster, receives a message from another broker, and this message has a timestamp in it already, this timestamp gets rewritten. This leads to an inconsistency in cluster.

For example, I have a cluster consisting of just two brokers. They are both running:
[root@lzhaldyb-rhel62i ~]# qpid-cluster
  Cluster Name: lzhaldyb-cluster
Cluster Status: ACTIVE
  Cluster Size: 2
       Members: ID=192.168.62.1:1984 URL=amqp:tcp:10.34.33.227:5672,tcp:192.168.62.1:5672
              : ID=192.168.62.2:3691 URL=amqp:tcp:10.34.33.226:5672,tcp:192.168.62.2:5672

Step 1: send two messages to one of the brokers.
[root@lzhaldyb-rhel62i ~]# ./spout -c 1 -i message_$(date +%s) test_cluster_timestamps && sleep 8 && ./spout -c 1 -i message_$(date +%s) test_cluster_timestamps
Both brokers have both messages with identical timestamps after this step:
[root@lzhaldyb-rhel62i ~]# ./drain -c 0 'test_cluster_timestamps; {mode: browse}'
Message(properties={spout-id:message_1330528317:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528317}, content='')
Message(properties={spout-id:message_1330528325:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528325}, content='')
[root@lzhaldyb-rhel62x ~]# ./drain -c 0 'test_cluster_timestamps; {mode: browse}'
Message(properties={spout-id:message_1330528317:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528317}, content='')
Message(properties={spout-id:message_1330528325:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528325}, content='')

Step 2: turn off one of the brokers and send two more messages to the active one.
[root@lzhaldyb-rhel62x ~]# service qpidd stop
Stopping Qpid AMQP daemon:                                 [  OK  ]
[root@lzhaldyb-rhel62i ~]# qpid-cluster
  Cluster Name: lzhaldyb-cluster
Cluster Status: ACTIVE
  Cluster Size: 1
       Members: ID=192.168.62.1:2296 URL=amqp:tcp:10.34.33.227:5672,tcp:192.168.62.1:5672
[root@lzhaldyb-rhel62i ~]# ./drain -c 0 'test_cluster_timestamps; {mode: browse}'
Message(properties={spout-id:message_1330528317:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528317}, content='')
Message(properties={spout-id:message_1330528325:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528325}, content='')
Message(properties={spout-id:message_1330528499:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528499}, content='')
Message(properties={spout-id:message_1330528507:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528507}, content='')

Step 3: turn the second broker back on.
On this step, the first broker sends the messages to the second one, which sets the timestamps to the current value:
[root@lzhaldyb-rhel62x ~]# service qpidd start
Starting Qpid AMQP daemon:                                 [  OK  ]
[root@lzhaldyb-rhel62x ~]# ./drain -c 0 'test_cluster_timestamps; {mode: browse}'
Message(properties={spout-id:message_1330528317:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330532153}, content='')
Message(properties={spout-id:message_1330528325:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330532153}, content='')
Message(properties={spout-id:message_1330528499:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330532153}, content='')
Message(properties={spout-id:message_1330528507:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330532153}, content='')
whereas the timestamps on the first broker remain the same:
[root@lzhaldyb-rhel62i ~]# ./drain -c 0 'test_cluster_timestamps; {mode: browse}'
Message(properties={spout-id:message_1330528317:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528317}, content='')
Message(properties={spout-id:message_1330528325:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528325}, content='')
Message(properties={spout-id:message_1330528499:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528499}, content='')
Message(properties={spout-id:message_1330528507:0, x-amqp-0-10.routing-key:test_cluster_timestamps, x-amqp-0-10.timestamp:1330528507}, content='')

As a result we have a cluster with two brokers, each of which has the exact same messages, but timestamps of these messages differ among brokers.

Version-Release number of selected component (if applicable):
qpid-cpp-client-0.14-7.el6.i686
qpid-cpp-client-devel-0.14-7.el6.i686
qpid-cpp-client-ssl-0.14-7.el6.i686
qpid-cpp-server-0.14-7.el6.i686
qpid-cpp-server-cluster-0.14-7.el6.i686
qpid-cpp-server-devel-0.14-7.el6.i686
qpid-cpp-server-ssl-0.14-7.el6.i686
qpid-cpp-server-store-0.14-7.el6.i686
qpid-cpp-server-xml-0.14-7.el6.i686


How reproducible:
always

Steps to Reproduce:
1. Configure cluster, turn one of the clustered brokers off.
2. Send a few messages to the currently active broker.
3. Turn the broker from Step 1 back on.
4. Compare timestamps of the messages on the newly started broker and the one they were initially sent to by the client.
  
Actual results:
The timestamps of the same message differ on different brokers.

Expected results:
Timestamps are consistent throughout the broker.

Additional info:


Note You need to log in before you can comment on or make changes to this bug.