6 Replies Latest reply on Mar 31, 2004 8:06 AM by Joerg Thoennes

    Comparison of UIL2, OIL2 and OIL

    lucasfowler Newbie

      We have an application running at a constant 50 messages/second, running on Linux

      We had this application running in 3.0.8 using OIL and it was fine.
      When we moved to 3.2.3 we also moved to using UIL2 and suddenly
      the whole thing was using 100% CPU for the same 50 messages.
      So I did some tests, basically the difference was in the Context changes
      which linux required for this:

      UIL2: ~12500/s
      OIL2: ~5000/s
      OIL: ~2500/s

      We don't need the special features of UIL2 because there are no firewall
      issues. So I guess we'll use OIL.

      Can anyone give me some reasons why not?
      Is there a plan to deprecate OIL with OIL2?

        • 1. Re: Comparison of UIL2, OIL2 and OIL
          Scott Stark Master

          OIL2 has never been a recommended protocol and will be dropped in the future. Post more details about the OS, VM and app as I have not seen this type of cpu utilization with UIL2.

          • 2. Re: Comparison of UIL2, OIL2 and OIL
            lucasfowler Newbie

            Thanks for the prompt reply Scott.

            1. So what is the roadmap for the protocols in 3.2.3, can we assume OIL and UIL2?

            2. We're running Linux 2.4.18-smp with 2 1.4 GHz Pentium III

            Java version 1.4.1_01 command line

            java -DJBOSS=505 -server -server -Xms4m -Xmx256m -Dprogram.name=run.sh -classpath JBossTomcat/bin/run.jar:/opt2/JavaCentral/linux/j2sdk1.4.1_01/lib/tools.jar org.jboss.Main

            We are using a topic without message persistence.

            Here is a cut of the UIL2 trace, if you want more I can send you directly,
            I guess that I wont make any friends if I post the whole thing here:

            [2004-03-27 17:39:20,377] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 13
            [2004-03-27 17:39:20,377] [INFO ] [ResponseStreamServlet] sending to TrendClient: SubscribeEndResponse[ MarketOverview;s=queue/macd/Gateway:Exchange:swx:TsxReceiver:-;t=queue/macd/Gateway:TrendServer:trprvdm:0567563C46F29693A55C7BF579474400;-----E;25074;363084;#0;status(0;;);[ null;null;null;null;null;null;null;false;null;null;null;null;null;null;null;null;null;null;0;null;false;null;null;null]]
            [2004-03-27 17:39:20,378] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 1
            [2004-03-27 17:39:20,378] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : receive
            [2004-03-27 17:39:20,378] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : acknowledge
            [2004-03-27 17:39:20,378] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 13
            [2004-03-27 17:39:20,378] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : receive
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : 10000
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:2/d861c65a3f793124a1a55df717b6d6af subId=-2147483648
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : 10000
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
            Principal: Roles(members:guest)
            ;principal=null;roles=Roles(members:guest) for rolePrincipals [guest]
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:4/b6c32f83fab56332da3a9ce1303fe839 subId=-2147483648
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : receive
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
            Principal: guest
            Principal: Roles(members:guest)
            ;principal=null;roles=Roles(members:guest) for rolePrincipals [guest]
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 13
            [2004-03-27 17:39:20,379] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : receive
            [2004-03-27 17:39:20,380] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 13
            [2004-03-27 17:39:20,380] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : AcknowledgementRequest:ACK,TOPIC.responseStream,ID:1-108040556036222250
            [2004-03-27 17:39:20,380] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 2
            [2004-03-27 17:39:20,380] [TRACE] [org.jboss.mq.server.MessageCache] remove lock aquire message 47814 msg=22249 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=31557867 clear=true reset=true
            [2004-03-27 17:39:20,380] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 47814 msg=22249 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=31557867 clear= true reset=true
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] remove lock release lrucache 47814 msg=22249 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=31557867 clear= true reset=true
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
            Header {
            jmsDestination : TOPIC.responseStream
            jmsDeliveryMode : 2
            jmsExpiration : 0
            jmsPriority : 4
            jmsMessageID : ID:1-108040556037922251
            jmsTimeStamp : 1080405560379
            jmsCorrelationID: null
            jmsReplyTo : null
            jmsType : null
            jmsRedelivered : false
            jmsProperties : {}
            jmsPropertiesReadWrite:true
            msgReadOnly : false
            producerClientId: ID:1
            }
            }
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageReference] clear lock aquire 47814 msg=22249 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=31557867
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageReference] clear lock relased 47814 msg=22249 hard REMOVED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=31557867
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
            Principal: Roles(members:guest)
            ;principal=null;roles=Roles(members:guest) for rolePrincipals [guest]
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=31557867 clear= true reset=true
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : acknowledge
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] add lock aquire message 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] add lock aquire lruCache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] add locks release47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
            [2004-03-27 17:39:20,381] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,382] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 13
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 1
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : receive
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : 10000
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:3/866562762198cee89472fdfba750df77 subId=-2147483648
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 wasHard=true
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
            Principal: Roles(members:guest)
            ;principal=null;roles=Roles(members:guest) for rolePrincipals [guest]
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,383] [TRACE] [org.jboss.mq.server.MessageCache] add lock aquire message 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageCache] add lock aquire lruCache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageCache] add locks release47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.il.uil2.UILClientILService] Begin handleMsg, msgType: 25
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.il.uil2.UILClientILService] End handleMsg
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 1
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : acknowledge
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : AcknowledgementRequest:ACK,TOPIC.responseStream,ID:1-108040556037922251
            [2004-03-27 17:39:20,384] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,385] [TRACE] [org.jboss.mq.server.MessageCache] add lock aquire message 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,386] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,386] [TRACE] [org.jboss.mq.server.MessageCache] add lock aquire lruCache 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,386] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,386] [TRACE] [org.jboss.mq.server.MessageCache] add locks release47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,386] [TRACE] [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
            [2004-03-27 17:39:20,386] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 wasHard=true
            [2004-03-27 17:39:20,404] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.il.uil2.UILClientILService] Begin handleMsg, msgType: 25
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 2
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.server.MessageCache] remove lock aquire message 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 clear=true reset=true
            [2004-03-27 17:39:20,405] [TRACE] [org.jboss.mq.il.uil2.UILClientILService] End handleMsg
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 clear= true reset=true
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.MessageCache] remove lock release lrucache 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108 clear= true reset=true
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 1
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.MessageReference] clear lock aquire 47815 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : acknowledge
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.MessageReference] clear lock relased 47815 msg=22250 hard REMOVED PERSISTENT queue=TOPIC.responseStream.ID:2.-2147483648 priority=4 hashCode=25688108
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : AcknowledgementRequest:ACK,TOPIC.responseStream,ID:1-108040556037922251
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,406] [TRACE] [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=25688108 clear= true reset=true
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageCache] remove lock aquire message 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 clear=true reset=true
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : acknowledge
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 clear= true reset=true
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 1
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageCache] remove lock release lrucache 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799 clear= true reset=true
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageReference] clear lock aquire 47816 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,407] [TRACE] [org.jboss.mq.server.MessageReference] clear lock relased 47816 msg=22250 hard REMOVED PERSISTENT queue=TOPIC.responseStream.ID:4.-2147483648 priority=4 hashCode=28720799
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=28720799 clear= true reset=true
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : acknowledge
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 1
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock aquire 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878 wasHard=true
            [2004-03-27 17:39:20,408] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 13
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.server.TracingInterceptor] CALLED : receive
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.server.TracingInterceptor] ARG : 10000
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:2/d861c65a3f793124a1a55df717b6d6af subId=-2147483648
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
            Principal: Roles(members:guest)
            ;principal=null;roles=Roles(members:guest) for rolePrincipals [guest]
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : receive
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 13
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.server.MessageReference] getMessage lock released 47817 msg=22250 hard NOT_STORED PERSISTENT queue=TOPIC.responseStream.ID:3.-2147483648 priority=4 hashCode=29978878
            [2004-03-27 17:39:20,409] [TRACE] [org.jboss.mq.server.TracingInterceptor] RETURN : receive
            [2004-03-27 17:39:20,409] [INFO ] [ResponseStreamServlet] sending to TrendClient: SubscribeEndResponse[ MarketOverview;s=queue/macd/Gateway:Exchange:swx:TsxReceiver:-;t=queue/macd/Gateway:TrendServer:trprvdm:0567563C46F29693A55C7BF579474400;-----E;25075;363089;#0;status(0;;);[ null;null;null;null;null;null;null;false;null;null;null;null;null;null;null;null;null;null;0;null;false;null;null;null]]

            • 3. Re: Comparison of UIL2, OIL2 and OIL
              Adrian Brock Master

              No OIL is going away. OIL has some bad synchronization problems.
              UIL2 is designed to be concurrent.

              I don't recognise your CPU problems. Are you using Redhat9?
              Try setting
              export LD_ASSUME_KERNEL=2.4.1
              to turn off Redhat's buggy backport of NPTL

              I have also started to do some work on the server concurrency in 3.2.4RC1
              If you are interested, there is also an improved persistence manager
              called JDBC3PersistenceManager in examples/jms
              which fixes some scalability problems with topics.

              Regards,
              Adrian

              • 4. Re: Comparison of UIL2, OIL2 and OIL
                Joerg Thoennes Newbie

                Adrian,

                I am a collegue of Lucas:

                Ad 1) We need to use the IL which is fast enough for our purposes
                (UIL2 currently isn't as fast as OIL in our specific application)

                Ad 2)
                We are using Debian Linux, so the hint with Red Hat does not
                apply for us.

                With our type of application, we have seen a much higher CPU
                utilzation. Finally, we found that simply changing the used
                invocation layer gives us different figures in the number of context
                switches while performing the same actions in our application.

                The IL with the most context switches (UIL2) also uses up the
                most CPU time for doing the same stuff. If we enable tracing, we
                see a lot of lock aquire and release (about 2 pages per message).
                Cf. Lucas' posting above.

                So we did conclude that there may be a concurrency issue, e.g.
                some sort of contention. So if you currently do some work in that
                area (server concurrency) this may fit our needs quite well.

                Ad 3)
                We currently do not use JDBC for JMS and actually do not need
                any persistence. In JBoss 3.2.4, we will probably use the
                persistence manager which does not do any persistence (forgot
                the exact name).

                If you could provide us with further information on your work on
                server concurrency, this would be very helpful for us. Do you need
                any extra input from our side?

                Cheers, Joerg

                • 5. Re: Comparison of UIL2, OIL2 and OIL
                  Adrian Brock Master

                  1) In my measurements UIL2 is faster than OIL
                  (except for the time required to connect on a local machine which takes longer
                  because of thread pool construction). It is on my list to improve the thread pooling
                  generally in jbossmq. See the development forums.

                  2) UIL2 does less synchronization so what you are probably seeing is more
                  concurrency allowed in the server leading to more contention.
                  One of the ways it does this is to pass off requests to a threadpool so
                  it can process the next request immediately.
                  See my previous comment where I mention I made improvements in 3.2.4RC1
                  to parts of the server.
                  Try 3.2.4RC1 to see if you have the same problem.
                  The JDBC3 persistence manager will scale better (even if you are not
                  persisting) because it does less cloning of the messages for topics.

                  3) Yes 3.2.4RC1 contains configration for dummy persistence/caching
                  in docs/examples/jms
                  This has less overhead at the expense that your memory is not protected if the
                  messages do not fit in memory.

                  If you have a profiler, list the points where you are seeing contention.

                  You might also try a 2.6 kernel which has a working implementation of NPTL.
                  It handles thread scheduling much more efficiently.
                  I'm not convinced 2.6 is production ready as yet though.

                  Regards,
                  Adrian

                  • 6. Re: Comparison of UIL2, OIL2 and OIL
                    Joerg Thoennes Newbie

                     

                    "adrian@jboss.org" wrote:
                    No OIL is going away. OIL has some bad synchronization problems.
                    UIL2 is designed to be concurrent.


                    Adrian,

                    does message of the sort

                    [org.jboss.mq.SpyMessageConsumer] WARNING: NACK issued. The message consumer was not waiting for a message.
                    ...repeated multiple times...
                    [org.jboss.mq.il.oil.OILClientILService] Closing receiver connections on port: 39371
                    


                    indicate such synchronization problems?

                    Remember: We use JBoss 3.2.3 where the ping deadlock leads to a read timeout on the socket.

                    Cheers, Joerg