Skip Menu |

Preferred bug tracker

Please visit the preferred bug tracker to report your issue.

This queue is for tickets about the POE-Component-MessageQueue CPAN distribution.

Report information
The Basics
Id: 49666
Status: resolved
Priority: 0/
Queue: POE-Component-MessageQueue

People
Owner: Nobody in particular
Requestors: IRONCAMEL [...] cpan.org
Cc:
AdminCc:

Bug Information
Severity: Important
Broken in: 0.2.6
Fixed in: (no value)



Subject: Messages in queue are out of order.
I have a simple script that produces 10 messages. When I consume them, the messages are out of order. If I uncomment the sleep 1, then it works correctly. Shouldn't order be guaranteed since this is a queue? What am I not understanding? I have started mq.pl with no arguments. Here is the relevant section of my producer code: my $stomp = Net::Stomp->new({ hostname => 'localhost', port => 61613 }); $stomp->connect(); for (1 .. $numMessages) { print "$_ adding $qpath: $message\n"; $stomp->send({ destination => "$qpath", body => "$message$_", persistent => 'true', }); #sleep 1; }
The MQ attempts to deliver messages in order, but puts performance above order. Specifically, there is one performance optimization which works as follows: - At the time a message is received, if there is a non-busy subscriber an that queue, simply deliver the message right away. So, lets say this happens: (1) Message 1 is sent and the subscriber isn't busy, so the message is delivered right away. (2) Message 2 comes in, but the subscriber is still busy with message 1, so its stored to be delivered later. (3) Message 3 comes in right when the subscriber finishes with message 1, but before message 2 can be taken out of storage, so message 3 is delivered. I can't be sure that this is what is happening in your case. The log files would help. However, if order is absolutely important to your application, this optimization would need to be "turned off" however there isn't a convenient way to do this now. Patches would be welcome! On Nie. 13 Wrz. 2009, 02:52:25, IRONCAMEL wrote: Show quoted text
> I have a simple script that produces 10 messages. When I consume them, > the messages are out of order. If I uncomment the sleep 1, then it > works correctly. Shouldn't order be guaranteed since this is a queue? > What am I not understanding? > > I have started mq.pl with no arguments. > > Here is the relevant section of my producer code: > > my $stomp = Net::Stomp->new({ > hostname => 'localhost', > port => 61613 > }); > $stomp->connect(); > > for (1 .. $numMessages) > { > print "$_ adding $qpath: $message\n"; > $stomp->send({ > destination => "$qpath", > body => "$message$_", > persistent => 'true', > }); > #sleep 1; > }
Subject: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Sun, 13 Sep 2009 04:00:30 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
Yes, order is very important in our application. I am attaching the log output in case it may help you confirm that the problem is what you suspected. I have the producer sending 10 messages while one consumer was listening. I would be happy to work on a patch, if you could point me in the right direction. RECV (14): CONNECT : RECV (14): SEND message 174 (1 bytes) to /queue/test (persistent: 1) QUEUE: Message 174 claimed by 13 during send STORE: COMPLEX: FRONT: Added 174 Dispatching message 174 to client 13 RECV (14): SEND message 175 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 175 RECV (14): SEND message 176 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 176 RECV (14): SEND message 177 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 177 RECV (14): SEND message 178 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 178 RECV (14): SEND message 179 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 179 RECV (14): SEND message 180 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 180 RECV (14): SEND message 181 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 181 RECV (14): SEND message 182 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 182 RECV (14): SEND message 183 (2 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 183 RECV (14): DISCONNECT MASTER: Removing client 14 RECV (13): ACK - message 174 STORE: COMPLEX: FRONT: Message 177 claimed by client 13 Dispatching message 177 to client 13 RECV (13): ACK - message 177 STORE: COMPLEX: FRONT: Message 176 claimed by client 13 Dispatching message 176 to client 13 RECV (13): ACK - message 176 STORE: COMPLEX: FRONT: Message 175 claimed by client 13 Dispatching message 175 to client 13 RECV (13): ACK - message 175 STORE: COMPLEX: FRONT: Message 180 claimed by client 13 Dispatching message 180 to client 13 RECV (13): ACK - message 180 STORE: COMPLEX: FRONT: Message 179 claimed by client 13 Dispatching message 179 to client 13 RECV (13): ACK - message 179 STORE: COMPLEX: FRONT: Message 178 claimed by client 13 Dispatching message 178 to client 13 RECV (13): ACK - message 178 STORE: COMPLEX: FRONT: Message 183 claimed by client 13 Dispatching message 183 to client 13 RECV (13): ACK - message 183 STORE: COMPLEX: FRONT: Message 182 claimed by client 13 Dispatching message 182 to client 13 RECV (13): ACK - message 182 STORE: COMPLEX: FRONT: Message 181 claimed by client 13 Dispatching message 181 to client 13 RECV (13): ACK - message 181 Regards, Naveed On Sun, Sep 13, 2009 at 3:28 AM, David Snopek via RT <bug-POE-Component-MessageQueue@rt.cpan.org> wrote: Show quoted text
> <URL: https://rt.cpan.org/Ticket/Display.html?id=49666 > > > > The MQ attempts to deliver messages in order, but puts performance above > order. > > Specifically, there is one performance optimization which works as follows: > >  - At the time a message is received, if there is a non-busy subscriber > an that queue, simply deliver the message right away. > > So, lets say this happens: > >  (1) Message 1 is sent and the subscriber isn't busy, so the message is > delivered right away. >  (2) Message 2 comes in, but the subscriber is still busy with message > 1, so its stored to be delivered later. >  (3) Message 3 comes in right when the subscriber finishes with message > 1, but before message 2 can be taken out of storage, so message 3 is > delivered. > > I can't be sure that this is what is happening in your case.  The log > files would help.  However, if order is absolutely important to your > application, this optimization would need to be "turned off" however > there isn't a convenient way to do this now.  Patches would be welcome! > > On Nie. 13 Wrz. 2009, 02:52:25, IRONCAMEL wrote:
>> I have a simple script that produces 10 messages.  When I consume them, >> the messages are out of order.  If I uncomment the sleep 1, then it >> works correctly.  Shouldn't order be guaranteed since this is a queue? >> What am I not understanding? >> >> I have started mq.pl with no arguments. >> >> Here is the relevant section of my producer code: >> >> my $stomp = Net::Stomp->new({ >>     hostname => 'localhost', >>     port     => 61613 >> }); >> $stomp->connect(); >> >> for (1 .. $numMessages) >> { >>     print "$_ adding $qpath: $message\n"; >>     $stomp->send({ >>         destination => "$qpath", >>         body        => "$message$_", >>         persistent  => 'true', >>     }); >>     #sleep 1; >> }
> > > >
Actually, my suspicion was not on at all (although, what I described could genuinely affect order of message delivery). It appears whats going on here, is that the front store (PoCo::MQ::Storage::BigMemory, assuming you are using the default configuration) is delivering the messages out-of-order which shouldn't happen. Can you try running the unit tests? Specifically t/05_storage_api.t and watch for tests 27 - 42. Those tests depend on BigMemory returning the results in order. Also, you could try running mq.pl (if you are, in fact, using mq.pl) with the option "--front-store memory". That will cause it to use the much slower PoCo::MQ::Storage::Memory, but then we can atleast try and isolate the bug to BigMemory. And one last thing! Are you using perl 5.8 or 5.10? There are some issues with 5.10 that haven't yet been fully explored. Hopefully, we can get to the bottom of this. On Nie. 13 Wrz. 2009, 01:01:12, naveedm9@gmail.com wrote: Show quoted text
> Yes, order is very important in our application. I am attaching the > log output in case it may help you confirm that the problem is what > you suspected. I have the producer sending 10 messages while one > consumer was listening. > > I would be happy to work on a patch, if you could point me in the > right direction. > > > RECV (14): CONNECT : > RECV (14): SEND message 174 (1 bytes) to /queue/test (persistent: 1) > QUEUE: Message 174 claimed by 13 during send > STORE: COMPLEX: FRONT: Added 174 > Dispatching message 174 to client 13 > RECV (14): SEND message 175 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 175 > RECV (14): SEND message 176 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 176 > RECV (14): SEND message 177 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 177 > RECV (14): SEND message 178 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 178 > RECV (14): SEND message 179 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 179 > RECV (14): SEND message 180 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 180 > RECV (14): SEND message 181 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 181 > RECV (14): SEND message 182 (1 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 182 > RECV (14): SEND message 183 (2 bytes) to /queue/test (persistent: 1) > STORE: COMPLEX: FRONT: Added 183 > RECV (14): DISCONNECT > MASTER: Removing client 14 > RECV (13): ACK - message 174 > STORE: COMPLEX: FRONT: Message 177 claimed by client 13 > Dispatching message 177 to client 13 > RECV (13): ACK - message 177 > STORE: COMPLEX: FRONT: Message 176 claimed by client 13 > Dispatching message 176 to client 13 > RECV (13): ACK - message 176 > STORE: COMPLEX: FRONT: Message 175 claimed by client 13 > Dispatching message 175 to client 13 > RECV (13): ACK - message 175 > STORE: COMPLEX: FRONT: Message 180 claimed by client 13 > Dispatching message 180 to client 13 > RECV (13): ACK - message 180 > STORE: COMPLEX: FRONT: Message 179 claimed by client 13 > Dispatching message 179 to client 13 > RECV (13): ACK - message 179 > STORE: COMPLEX: FRONT: Message 178 claimed by client 13 > Dispatching message 178 to client 13 > RECV (13): ACK - message 178 > STORE: COMPLEX: FRONT: Message 183 claimed by client 13 > Dispatching message 183 to client 13 > RECV (13): ACK - message 183 > STORE: COMPLEX: FRONT: Message 182 claimed by client 13 > Dispatching message 182 to client 13 > RECV (13): ACK - message 182 > STORE: COMPLEX: FRONT: Message 181 claimed by client 13 > Dispatching message 181 to client 13 > RECV (13): ACK - message 181 > > Regards, > Naveed > > On Sun, Sep 13, 2009 at 3:28 AM, David Snopek via RT > <bug-POE-Component-MessageQueue@rt.cpan.org> wrote:
> > <URL: https://rt.cpan.org/Ticket/Display.html?id=49666 > > > > > > > The MQ attempts to deliver messages in order, but puts performance
> above
> > order. > > > > Specifically, there is one performance optimization which works as
> follows:
> > > >  - At the time a message is received, if there is a non-busy
> subscriber
> > an that queue, simply deliver the message right away. > > > > So, lets say this happens: > > > >  (1) Message 1 is sent and the subscriber isn't busy, so the message
> is
> > delivered right away. > >  (2) Message 2 comes in, but the subscriber is still busy with
> message
> > 1, so its stored to be delivered later. > >  (3) Message 3 comes in right when the subscriber finishes with
> message
> > 1, but before message 2 can be taken out of storage, so message 3 is > > delivered. > > > > I can't be sure that this is what is happening in your case.  The
> log
> > files would help.  However, if order is absolutely important to your > > application, this optimization would need to be "turned off" however > > there isn't a convenient way to do this now.  Patches would be
> welcome!
> > > > On Nie. 13 Wrz. 2009, 02:52:25, IRONCAMEL wrote:
> >> I have a simple script that produces 10 messages.  When I consume
> them,
> >> the messages are out of order.  If I uncomment the sleep 1, then it > >> works correctly.  Shouldn't order be guaranteed since this is a
> queue?
> >> What am I not understanding? > >> > >> I have started mq.pl with no arguments. > >> > >> Here is the relevant section of my producer code: > >> > >> my $stomp = Net::Stomp->new({ > >>     hostname => 'localhost', > >>     port     => 61613 > >> }); > >> $stomp->connect(); > >> > >> for (1 .. $numMessages) > >> { > >>     print "$_ adding $qpath: $message\n"; > >>     $stomp->send({ > >>         destination => "$qpath", > >>         body        => "$message$_", > >>         persistent  => 'true', > >>     }); > >>     #sleep 1; > >> }
> > > > > > > >
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Sun, 13 Sep 2009 21:52:42 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
On Sun, Sep 13, 2009 at 9:09 AM, David Snopek via RT <bug-POE-Component-MessageQueue@rt.cpan.org> wrote: Show quoted text
> > Actually, my suspicion was not on at all (although, what I described > could genuinely affect order of message delivery). > > It appears whats going on here, is that the front store > (PoCo::MQ::Storage::BigMemory, assuming you are using the default > configuration) is delivering the messages out-of-order which shouldn't > happen.
I was using the default configuration. I had simply run: mq.pl --nouuids Show quoted text
> Can you try running the unit tests?  Specifically t/05_storage_api.t and > watch for tests 27 - 42.  Those tests depend on BigMemory returning the > results in order.
All the unit tests pass. Show quoted text
> Also, you could try running mq.pl (if you are, in fact, using mq.pl) > with the option "--front-store memory".  That will cause it to use the > much slower PoCo::MQ::Storage::Memory, but then we can atleast try and > isolate the bug to BigMemory.
Using the --front-store memory option didn't make a difference. The messages were still out of order. Show quoted text
> And one last thing!  Are you using perl 5.8 or 5.10?  There are some > issues with 5.10 that haven't yet been fully explored.
I am using perl 5.8. Show quoted text
> Hopefully, we can get to the bottom of this.
Agreed :) Naveed
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Sun, 13 Sep 2009 22:18:24 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
I am providing logs of another run. As before, I run the producer script to produce 10 messages, using the script I posted earlier. This time the consumer wasn't running. Then I turn on the consumer. This way the log lines for the producer and consumer are not overlapping, so it may be easier to figure out what is going on. I started the broker with "sudo mq.pl --nouuids". The lines starting with "STORE: COMPLEX: FRONT: Added" show that the messages are arriving in the correct order (254 .. 263). The final order of the messages when they are consumed are: (254, 257, 256, 255, 260, 259, 258, 263, 262, 261) Here is the log. *** Start log. First I produce 10 messages: MASTER: Removing client 12 RECV (13): CONNECT : RECV (13): SEND message 254 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 254 RECV (13): SEND message 255 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 255 RECV (13): SEND message 256 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 256 RECV (13): SEND message 257 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 257 RECV (13): SEND message 258 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 258 RECV (13): SEND message 259 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 259 RECV (13): SEND message 260 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 260 RECV (13): SEND message 261 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 261 RECV (13): SEND message 262 (1 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 262 RECV (13): SEND message 263 (2 bytes) to /queue/test (persistent: 1) STORE: COMPLEX: FRONT: Added 263 RECV (13): DISCONNECT MASTER: Removing client 13 STORE: COMPLEX: Pushing expired messages (254, 256, 255) to backstore. STORE: COMPLEX: BACK: THROTTLED: Added 256. STORE: COMPLEX: BACK: Sending throttled message 256 (0 left) STORE: COMPLEX: Pushing expired messages (261, 259, 263, 262, 258, 260, 257) to backstore. STORE: COMPLEX: BACK: THROTTLED: Added 259. STORE: COMPLEX: BACK: THROTTLED: Added 260. STORE: COMPLEX: BACK: THROTTLED: Added 261. STORE: COMPLEX: BACK: THROTTLED: Added 262. STORE: COMPLEX: BACK: THROTTLED: Added 263. STORE: COMPLEX: BACK: Sending throttled message 259 (4 left) STORE: COMPLEX: BACK: Sending throttled message 260 (3 left) STORE: COMPLEX: BACK: Sending throttled message 263 (2 left) STORE: COMPLEX: BACK: Sending throttled message 262 (1 left) STORE: COMPLEX: BACK: Sending throttled message 261 (0 left) *** Now starting the consumer: RECV (14): CONNECT : RECV (14): SUBSCRIBE /queue/test (ack: client) STORE: COMPLEX: FRONT: Message 254 claimed by client 14 Dispatching message 254 to client 14 RECV (14): ACK - message 254 STORE: COMPLEX: FRONT: Message 257 claimed by client 14 Dispatching message 257 to client 14 RECV (14): ACK - message 257 STORE: COMPLEX: FRONT: Message 256 claimed by client 14 Dispatching message 256 to client 14 RECV (14): ACK - message 256 STORE: COMPLEX: FRONT: Message 255 claimed by client 14 Dispatching message 255 to client 14 RECV (14): ACK - message 255 STORE: COMPLEX: FRONT: Message 260 claimed by client 14 Dispatching message 260 to client 14 RECV (14): ACK - message 260 STORE: COMPLEX: FRONT: Message 259 claimed by client 14 Dispatching message 259 to client 14 RECV (14): ACK - message 259 STORE: COMPLEX: FRONT: Message 258 claimed by client 14 Dispatching message 258 to client 14 RECV (14): ACK - message 258 STORE: COMPLEX: FRONT: Message 263 claimed by client 14 Dispatching message 263 to client 14 RECV (14): ACK - message 263 STORE: COMPLEX: FRONT: Message 262 claimed by client 14 Dispatching message 262 to client 14 RECV (14): ACK - message 262 STORE: COMPLEX: FRONT: Message 261 claimed by client 14 Dispatching message 261 to client 14 RECV (14): ACK - message 261 *** End log Naveed
Hrm.. Let's try an other test.. Do the same thing you did here, where you do the producer first but instead of running the consumer afterwards, stop the MQ and open the backstore database with sqlite (on my Debian system, its called "sqlite3"). Note: you have to wait until all the messages move into the back store before stopping the MQ, so watch the logs. Here I did the same test on my machine: dsnopek@skystudio:~/prj/perl_mq/devel.mainline$ sqlite3 /var/lib/perl_mq/mq.db SQLite version 3.5.9 Enter ".help" for instructions Show quoted text
sqlite> SELECT * FROM messages ORDER BY timestamp;
1|/queue/monkey_bin|1|||1252909883.39394|6| 2|/queue/monkey_bin|1|||1252909883.39896|6| 3|/queue/monkey_bin|1|||1252909883.40001|6| 4|/queue/monkey_bin|1|||1252909883.40083|6| 5|/queue/monkey_bin|1|||1252909883.40159|6| 6|/queue/monkey_bin|1|||1252909883.40236|6| 7|/queue/monkey_bin|1|||1252909883.40315|6| 8|/queue/monkey_bin|1|||1252909883.40394|6| 9|/queue/monkey_bin|1|||1252909883.40471|6| 10|/queue/monkey_bin|1|||1252909883.40549|6| Show quoted text
sqlite>
It shows that when ordered by timestamp, the messages go in the correct order. If both Memory and BigMemory are getting it wrong, the only thing I can think of, is that somehow on your system the timestamps are not getting set right or are getting set without enough precision. This should show that if its the case. Although, I still am confused about how the tests could pass if the storage engines are returning messages out of order, so it could be something else entirely. But lets check out this possibility first.
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Mon, 14 Sep 2009 03:01:49 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
I think you are on to something. The timestamps look fishy: Show quoted text
sqlite> select * from messages order by timestamp;
294|/queue/test|1|||1252911075.89115|5| 295|/queue/test|1|||1252911075.89515|5| 296|/queue/test|1|||1252911075.89915|5| 297|/queue/test|1|||1252911075.89915|5| 298|/queue/test|1|||1252911075.89915|5| 301|/queue/test|1|||1252911075.90315|5| 300|/queue/test|1|||1252911075.90315|5| 299|/queue/test|1|||1252911075.90315|5| 303|/queue/test|1|||1252911075.90715|6| 302|/queue/test|1|||1252911075.90715|5| The timestamps are equal for multiple messages. I believe that the reason for this might have to do with these 2 lines from the log: STORE: COMPLEX: Pushing expired messages (294) to backstore. STORE: COMPLEX: Pushing expired messages (298, 303, 295, 299, 302, 296, 297, 300, 301) to backstore. Seems like when messages expire from the front-store, they get pushed to the back-store all at once. The original order is not maintained. Right? Naveed
On Pon. 14 Wrz. 2009, 03:02:30, naveedm9@gmail.com wrote: Show quoted text
> I think you are on to something. The timestamps look fishy: >
> sqlite> select * from messages order by timestamp;
> 294|/queue/test|1|||1252911075.89115|5| > 295|/queue/test|1|||1252911075.89515|5| > 296|/queue/test|1|||1252911075.89915|5| > 297|/queue/test|1|||1252911075.89915|5| > 298|/queue/test|1|||1252911075.89915|5| > 301|/queue/test|1|||1252911075.90315|5| > 300|/queue/test|1|||1252911075.90315|5| > 299|/queue/test|1|||1252911075.90315|5| > 303|/queue/test|1|||1252911075.90715|6| > 302|/queue/test|1|||1252911075.90715|5|
Ah ha! Show quoted text
> The timestamps are equal for multiple messages. I believe that the > reason for this might have to do with these 2 lines from the log: > > STORE: COMPLEX: Pushing expired messages (294) to backstore. > STORE: COMPLEX: Pushing expired messages (298, 303, 295, 299, 302, > 296, 297, 300, 301) to backstore. > > Seems like when messages expire from the front-store, they get pushed > to the back-store all at once. The original order is not maintained. > Right?
Actually, no. The timestamp is set on the message object as soon as the message is received. This is a little tricky to see in the code because its Moose-ified, but look at MessageQueue/Message.pm lines 80-84: has 'timestamp' => ( is => 'ro', isa => 'Num', default => sub { time() }, ); When the message object is created, it calls "time()" to set the timestamp. The fact that all those are moved to the backstore at once is because the timestamp is the same, so they would expire at the same time. So! Either time() isn't being precise enough, or somehow all those messages are being created within the same fraction of a second. Try installing Time::HighRes and see if that helps.
On Pon. 14 Wrz. 2009, 03:12:03, DSNOPEK wrote: Show quoted text
> > Try installing Time::HighRes and see if that helps.
Er, sorry! I made a type-o. I meant to say install Time::HiRes
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Mon, 14 Sep 2009 04:28:28 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
I installed Time::HiRes and that did not solve the problem. So I did a little investigating. I added a print statement inside the loop of my producer script. use Time::HiRes qw(time); for (1 .. $numMessages) { print time . " $_: adding $qpath: $message$_\n"; $stomp->send({ destination => "$qpath", body => "$message$_", persistent => 'true', }); } Here is the output: $ ./pro.pl -queue=test -count=10 asdf connecting to host: localhost 1252915736.00148 1: adding /queue/test: asdf1 1252915736.00148 2: adding /queue/test: asdf2 1252915736.00148 3: adding /queue/test: asdf3 1252915736.00148 4: adding /queue/test: asdf4 1252915736.00148 5: adding /queue/test: asdf5 1252915736.00148 6: adding /queue/test: asdf6 1252915736.00148 7: adding /queue/test: asdf7 1252915736.00148 8: adding /queue/test: asdf8 1252915736.00148 9: adding /queue/test: asdf9 1252915736.00148 10: adding /queue/test: asdf10 Seems like everything happened at 1252915736.00148 o'clock. So then I tried running this from the shell: $ perl -MTime::HiRes -le 'use Time::HiRes q(time); print time for (1..10)' 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 1252916393.97498 This is on a centos 5 machine, which is running in the cloud, which the mq.pl broker is running on. I tested the same commanded on my personal ubuntu machine and got this: $ perl -MTime::HiRes -le 'use Time::HiRes q(time); print time for (1..10)' 1252915576.46853 1252915576.46869 1252915576.46875 1252915576.46881 1252915576.46887 1252915576.46893 1252915576.46898 1252915576.46904 1252915576.4691 1252915576.46916 So it seems like it is a timestamp issue. I'm not sure if the centos server is incorrect or if it is just super fast. Do you have any ideas?
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Mon, 14 Sep 2009 04:34:45 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
Here is something that is interesting. On the server that mq.pl is running on, I ran this: $ perl -MTime::HiRes -le 'use Time::HiRes q(time); print time for (1..1000)' | uniq 1252917001.29759 1252917001.30159 Note that I am piping the results of the perl command into uniq. And there were only 2 lines in the result. So the time seems to jump from 1252917001.29759 to 1252917001.30159.
On Pon. 14 Wrz. 2009, 04:29:11, naveedm9@gmail.com wrote: Show quoted text
> > So it seems like it is a timestamp issue. I'm not sure if the centos > server is incorrect or if it is just super fast. Do you have any > ideas?
Hrm. This is most likely a problem with the timer functionality on the CentOS server, particularly since its running in the cloud, the virtual OS probably doesn't have access to hardware functionality that would help the timer.. There is probably a way to make a work around for this but I can't think of an easy one right now, for example: (1) We could add something to the timestamp, but that gets dangerous too, because when do we reset it, how do we make sure it doesn't go too far ahead. (2) We could replace the timestamp with a simple counter which increments for each message, but that will have problems between MQ shutdown/startup (and theoretic problems for the unfinished clustering code). (3) An option to use the message id for order (in the case of --nouuids) but this would require changes to every storage engine, some more serious than others. I don't have a good answer right now...
On Mon Sep 14 04:43:37 2009, DSNOPEK wrote: Show quoted text
> On Pon. 14 Wrz. 2009, 04:29:11, naveedm9@gmail.com wrote:
> > > > So it seems like it is a timestamp issue. I'm not sure if the > > centos server is incorrect or if it is just super fast. Do you > > have any ideas?
> > Hrm. This is most likely a problem with the timer functionality > on the CentOS server, particularly since its running in the cloud, > the virtual OS probably doesn't have access to hardware > functionality that would help the timer.. > > There is probably a way to make a work around for this but I can't > think of an easy one right now, for example: > > (1) We could add something to the timestamp, but that gets > dangerous too, because when do we reset it, how do we make sure > it doesn't go too far ahead. > > (2) We could replace the timestamp with a simple counter which > increments for each message, but that will have problems between > MQ shutdown/startup (and theoretic problems for the unfinished > clustering code). > > (3) An option to use the message id for order (in the case of > --nouuids) but this would require changes to every storage > engine, some more serious than others. > > I don't have a good answer right now...
http://pastie.org/616357 Add an ordinal field to messages. It resets every time there's a new timestamp. Then, you can break timestamp ties with it. The above pastie is just pseudocode, it'd go somewhere in Message.pm (probably want to use BUILD instead of the inline builder on the timestamp attribute). Any of the storage engines that sort would need to be updated to break timestamp ties with ordinal, and the db schema would have to change to include the ordinal field. Grep the codebase for any other sorts, and that should fix you right up. This is a nontrivial amount of hacking, and this bug isn't a problem for me right now, so I'm not going to spend any time on it. Should be a clear path to solving your problem if you've got the programmer time though. :)
On Pon. 14 Wrz. 2009, 12:56:44, frodwith wrote: Show quoted text
> http://pastie.org/616357 > > Add an ordinal field to messages. It resets every time there's a > new timestamp. Then, you can break timestamp ties with it. > > The above pastie is just pseudocode, it'd go somewhere in Message.pm > (probably want to use BUILD instead of the inline builder on the > timestamp attribute). > > Any of the storage engines that sort would need to be updated to > break timestamp ties with ordinal, and the db schema would have to > change to include the ordinal field. Grep the codebase for any > other sorts, and that should fix you right up. > > This is a nontrivial amount of hacking, and this bug isn't a problem > for me right now, so I'm not going to spend any time on it. Should > be a clear path to solving your problem if you've got the programmer > time though. :)
I just want to add that frodwith's solution looks good and a patch that implemented this would very likely be accepted (after review, of course!). Additionally, a unit test that would fail on systems with timers that perform like shown in the rest of the ticket would be very welcome, even without a fix for the problem.
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Mon, 14 Sep 2009 17:00:00 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
On Mon, Sep 14, 2009 at 1:06 PM, David Snopek via RT<bug-POE-Component-MessageQueue@rt.cpan.org> wrote: Show quoted text
> > I just want to add that frodwith's solution looks good and a patch that > implemented this would very likely be accepted (after review, of course!). > > Additionally, a unit test that would fail on systems with timers that > perform like shown in the rest of the ticket would be very welcome, even > without a fix for the problem.
I would like to take a shot at it. Is there a version control system for this project, or should I just download the latest source code from cpan and hack away at that?
On Mon Sep 14 17:00:41 2009, naveedm9@gmail.com wrote: Show quoted text
> > I would like to take a shot at it. Is there a version control system > for this project, or should I just download the latest source code > from cpan and hack away at that?
We use Bazaar as described (very shorty) in the POD docs: http://search.cpan.org/~dsnopek/POE-Component-MessageQueue-0.2.6/lib/POE/Component/MessageQueue.pm#DEVELOPMENT The ideal way to contribute is to make a branch of the main branch and publish it somewhere. Then there is a back and forth during review, where we'll suggest or make changes, and ultimately the branch is merged into the main branch and released. Contributing with patches rather than Bazaar is also acceptable, it just creates a little extra work, especially if we need to go back and forth during review a few times. Also, we do most of our development discussions on the Google Group: http://groups.google.com/group/pocomq You can search around there for examples of how contributions have gone in the past. Thanks for taking the time to hack on this!
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Wed, 16 Sep 2009 11:33:56 -0400
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
On Mon, Sep 14, 2009 at 12:56 PM, Paul Driver via RT <bug-POE-Component-MessageQueue@rt.cpan.org> wrote: Show quoted text
> <URL: https://rt.cpan.org/Ticket/Display.html?id=49666 > > > On Mon Sep 14 04:43:37 2009, DSNOPEK wrote:
>> On Pon. 14 Wrz. 2009, 04:29:11, naveedm9@gmail.com wrote:
>> > >> > So it seems like it is a timestamp issue.  I'm not sure if the >> > centos server is incorrect or if it is just super fast.  Do you >> > have any ideas?
>> >> Hrm.  This is most likely a problem with the timer functionality >> on the CentOS server, particularly since its running in the cloud, >> the virtual OS probably doesn't have access to hardware >> functionality that would help the timer.. >> >> There is probably a way to make a work around for this but I can't >> think of an easy one right now, for example: >> >>  (1) We could add something to the timestamp, but that gets >>  dangerous too, because when do we reset it, how do we make sure >>  it doesn't go too far ahead. >> >>  (2) We could replace the timestamp with a simple counter which >>  increments for each message, but that will have problems between >>  MQ shutdown/startup (and theoretic problems for the unfinished >>  clustering code). >> >>  (3) An option to use the message id for order (in the case of >>  --nouuids) but this would require changes to every storage >>  engine, some more serious than others. >> >> I don't have a good answer right now...
> > http://pastie.org/616357 > > Add an ordinal field to messages.  It resets every time there's a > new timestamp.  Then, you can break timestamp ties with it. > > The above pastie is just pseudocode, it'd go somewhere in Message.pm > (probably want to use BUILD instead of the inline builder on the > timestamp attribute). > > Any of the storage engines that sort would need to be updated to > break timestamp ties with ordinal, and the db schema would have to > change to include the ordinal field.  Grep the codebase for any > other sorts, and that should fix you right up. > > This is a nontrivial amount of hacking, and this bug isn't a problem > for me right now, so I'm not going to spend any time on it.  Should > be a clear path to solving your problem if you've got the programmer > time though.  :) >
Just want to point out that this could be a problem for you even if your broker is not on a cloud server. If order matters to you. And in general, if you are using a queue data structure, then you probably care about order. On my puny desktop, I ran the following. $ perl -MTime::HiRes -le 'use Time::HiRes q(time); print time for (1..10)' 1253115071.29503 1253115071.2951 1253115071.2951 1253115071.29511 1253115071.29512 1253115071.29513 1253115071.29513 1253115071.29514 1253115071.29514 1253115071.29515 You see that the second and third prints both happened at 1253115071.2951.
On Pt 02 Apr 2010, 03:24:37, IRONCAMEL wrote: Show quoted text
> I have a patch that fixes this issue: > > http://github.com/ironcamel/POE--Component-- > MessageQueue/commit/09ffbd01a711cd4536ac0b6f01fb832939944b96
I haven't had time to do a full review of the changes or any testing yet, but I like what you're doing here. Unlike Paul's proposed fix, this doesn't require adding an additional field or DB column, so its fully compatible with what already exists. Also, I did a little research on the speed of time() vs. Time::HiRes::time(). Attached is a benchmarking script. It appears that time() is about 4-6% faster than Time::HiRes::time(). While that isn't much, since we don't really *need* the accuracy of Time::HiRes, I think this is an argument in favor of your approach. So, I still have to do full review and some testing but right now I think that this patch will be accepted. Thanks so much for hacking on this! David Snopek.
Subject: benchmark-time.pl
use Time::HiRes; use Benchmark qw(:all) ; cmpthese(-10, { 'Time::HiRes' => sub { my $t0 = Time::HiRes::time(); }, 'builtin time()' => sub { my $t0 = time(); }, });
On Pt 02 Apr 2010, 03:24:37, IRONCAMEL wrote: Show quoted text
> I have a patch that fixes this issue: > > http://github.com/ironcamel/POE--Component-- > MessageQueue/commit/09ffbd01a711cd4536ac0b6f01fb832939944b96
So, I have been thinking about what datatype this should be in the database. In your patch, you set it to REAL (which really doesn't matter too much for sqlite anyway) but I'm not 100% sure that's what we should do. Floating point values can sometimes be bad representations of decimal numbers and this patch is very decimal (appends .00001, .00002, etc to the number). But switching to a string could slow things down on databases like MySQL. I'm not sure either of these is really a worry (more research necessary!) but if they are, a fixed-point number represented as an integer seems the most logical. But that would break the ease with which we can query the database and see whats going on... This needs more thought.
On Wt 06 Apr 2010, 08:28:09, DSNOPEK wrote: Show quoted text
> > On Pt 02 Apr 2010, 03:24:37, IRONCAMEL wrote:
> > I have a patch that fixes this issue: > > > > http://github.com/ironcamel/POE--Component-- > > MessageQueue/commit/09ffbd01a711cd4536ac0b6f01fb832939944b96
> > So, I have been thinking about what datatype this should be in the > database. In your patch, you set it to REAL (which really doesn't > matter too much for sqlite anyway) but I'm not 100% sure that's what we > should do. > > Floating point values can sometimes be bad representations of decimal > numbers and this patch is very decimal (appends .00001, .00002, etc to > the number). But switching to a string could slow things down on > databases like MySQL. I'm not sure either of these is really a worry > (more research necessary!) but if they are, a fixed-point number > represented as an integer seems the most logical. But that would break > the ease with which we can query the database and see whats going on... > > This needs more thought.
I'm thinking that DECIMAL(15,5) would be a good type. For MySQL >5.0.3 it should work without floating-point problems and a number with these dimensions (15 significant digits, 5 of which are fractional) should work with SQLite3's storage engine correctly (it will try to store it as a float, but convert to text if it isn't *exact* to 15 significant digits). I'll start making up the schemas and what not.
The patch and some other house keeping for the new version and schemas is now in the mainline Bazaar branch and its Git mirror. Please test, this will become the next release.
Subject: Re: [rt.cpan.org #49666] Messages in queue are out of order.
Date: Wed, 7 Apr 2010 04:57:29 +0100
To: bug-POE-Component-MessageQueue [...] rt.cpan.org
From: Naveed Massjouni <naveedm9 [...] gmail.com>
On Tue, Apr 6, 2010 at 2:41 PM, David Snopek via RT <bug-POE-Component-MessageQueue@rt.cpan.org> wrote: Show quoted text
> <URL: https://rt.cpan.org/Ticket/Display.html?id=49666 > > > > The patch and some other house keeping for the new version and schemas > is now in the mainline Bazaar branch and its Git mirror.  Please test, > this will become the next release.
Thanks David. Please hold off on the release until I get a chance to test this on my cloud servers. I will try to do this very soon. Naveed
On Tue Apr 06 23:58:04 2010, naveedm9@gmail.com wrote: Show quoted text
> On Tue, Apr 6, 2010 at 2:41 PM, David Snopek via RT > <bug-POE-Component-MessageQueue@rt.cpan.org> wrote:
> > <URL: https://rt.cpan.org/Ticket/Display.html?id=49666 > > > > > > > The patch and some other house keeping for the new version and
schemas Show quoted text
> > is now in the mainline Bazaar branch and its Git mirror.  Please
test, Show quoted text
> > this will become the next release.
> > Thanks David. Please hold off on the release until I get a chance to > test this on my cloud servers. I will try to do this very soon. > > Naveed
I just installed the latest version from github and ran some tests on my boxes and everything seems to be working good. All messages were in order. Great idea using DECIMAL instead of REAL to store the value. I just learned that the decimal type is "used to store values for which it is important to preserve exact precision, for example with monetary data". Which is what we want here.