[AMQ-3299] Prioritizing of messages isn't applied to all messages during test.

• Type: Bug
• Status: Closed
• Priority: Trivial
• Resolution: Not A Problem
• Affects Version/s: 5.4.2
• Component/s: Broker

Environment

Operating System = Windows XP version 5.1 running on x86
Java; VM; Vendor = 1.6.0_23
Runtime = Java HotSpot(TM) Client VM 19.0-b09

• Assignee: Unassigned
• Reporter: Robert Liguori
• Created: 27/Apr/11 14:06
• Updated: 01/Jul/11 19:16
• Resolved: 01/Jul/11 19:16

Description

Considering this link: http://activemq.apache.org/activemq-performance-module-users-manual.html and sample test performance benchmarks of 1 million messages every 5 mins, I created and ran a priority test with 333 messages being sent every second.

Problem: It appears as if the priority algorithm is not being applied (or even attempted) to many of the messages in the middle of the run. Consider this output and examine the message order. Note: the number following the #s represent the message and order-number sent by the producer. In this piece of the consumer log, these numbers are sequentially ordered meaning that the producer did not order them (based on priority) before sending them out:

...
09:59:58 INFO MESSAGE PRI-4 #20951 Count-19953
09:59:58 INFO MESSAGE PRI-9 #20952 Count-19954
09:59:58 INFO MESSAGE PRI-2 #20953 Count-19955
09:59:58 INFO MESSAGE PRI-5 #20954 Count-19956
09:59:58 INFO MESSAGE PRI-5 #20955 Count-19957
09:59:58 INFO MESSAGE PRI-9 #20956 Count-19958
09:59:58 INFO MESSAGE PRI-7 #20957 Count-19959
09:59:58 INFO MESSAGE PRI-0 #10648 Count-19960
09:59:58 INFO MESSAGE PRI-3 #20959 Count-19961
09:59:58 INFO MESSAGE PRI-2 #20960 Count-19962
09:59:58 INFO MESSAGE PRI-8 #20961 Count-19963
09:59:58 INFO MESSAGE PRI-4 #20962 Count-19964
09:59:58 INFO MESSAGE PRI-7 #20963 Count-19965
09:59:58 INFO MESSAGE PRI-3 #20964 Count-19966
09:59:58 INFO MESSAGE PRI-9 #20965 Count-19967
09:59:58 INFO MESSAGE PRI-3 #20966 Count-19968
09:59:58 INFO MESSAGE PRI-7 #20967 Count-19969
09:59:58 INFO MESSAGE PRI-1 #20968 Count-19970
09:59:58 INFO MESSAGE PRI-8 #20969 Count-19971
09:59:58 INFO MESSAGE PRI-1 #20970 Count-19972
09:59:58 INFO MESSAGE PRI-8 #20971 Count-19973
09:59:58 INFO MESSAGE PRI-9 #20972 Count-19974
09:59:58 INFO MESSAGE PRI-2 #20973 Count-19975
09:59:58 INFO MESSAGE PRI-4 #20974 Count-19976
09:59:58 INFO MESSAGE PRI-6 #20975 Count-19977
09:59:58 INFO MESSAGE PRI-8 #20976 Count-19978
09:59:58 INFO MESSAGE PRI-2 #20977 Count-19979
09:59:58 INFO MESSAGE PRI-5 #20978 Count-19980
09:59:58 INFO MESSAGE PRI-6 #20979 Count-19981
09:59:58 INFO MESSAGE PRI-5 #20980 Count-19982
09:59:58 INFO MESSAGE PRI-1 #20981 Count-19983
09:59:58 INFO MESSAGE PRI-4 #20982 Count-19984
09:59:58 INFO MESSAGE PRI-5 #20983 Count-19985
09:59:58 INFO MESSAGE PRI-2 #20984 Count-19986
09:59:58 INFO MESSAGE PRI-6 #20985 Count-19987
09:59:58 INFO MESSAGE PRI-8 #20986 Count-19988
09:59:58 INFO MESSAGE PRI-7 #20987 Count-19989
09:59:58 INFO MESSAGE PRI-3 #20988 Count-19990
09:59:58 INFO MESSAGE PRI-7 #20989 Count-19991
09:59:58 INFO MESSAGE PRI-3 #20990 Count-19992
09:59:58 INFO MESSAGE PRI-4 #20991 Count-19993
09:59:58 INFO MESSAGE PRI-5 #20992 Count-19994
09:59:58 INFO MESSAGE PRI-6 #20993 Count-19995
09:59:58 INFO MESSAGE PRI-1 #20994 Count-19996
09:59:58 INFO MESSAGE PRI-0 #10667 Count-19997
09:59:58 INFO MESSAGE PRI-7 #20996 Count-19998
09:59:58 INFO MESSAGE PRI-3 #20997 Count-19999
09:59:58 INFO MESSAGE PRI-8 #20998 Count-20000
09:59:58 INFO MESSAGE PRI-8 #20999 Count-20001
...

I am separately attaching fuller consumer and producer logs. Clear ordering of messages is noticeable at the beginning and end of the test in the consumer log. Actually, there appears to the sending the high priority messages, followed by the sending of expedited messages intermixed with aged normal priority messages, followed by no ordering, followed by low priority messages with the value of '0'. The question is... why did the message ordering stop?