Uploaded image for project: 'ActiveMQ Classic'
  1. ActiveMQ Classic
  2. AMQ-5486

Thread synchronization overhead is unexpectedly high

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • 5.9.1
    • 5.14.0
    • Broker
    • None
    • UbuntuServer 12.04 x86_64, Linux Kernel 3.20.23, OpenJDK 1.7.0_51 64-Bit Server VM, Xms 2G, Xms 8G, CPU: E5-2620 v2 X 2, 64 GB RAM

    Description

      There's about 20 topics with virtual topic enabled, hundreds of comsumers/producers connected to MQ on NIO transport connector. During the run there're about 12000 msg flow in per second, not a very high rate, but ActiveMQ consumes a lot of CPU resource (about 600%~1000%). To find out what's the most CPU consuming code path, I use JProfiler to dig into the process.

      Among all the NIO worker threads, most of them were frequently blocked and did a little job between the 'unblocked' time. While they're expected spend most of their time slices on waiting for work item and processed them.

      After reviewing the monitor usage history and stats, I think these NIO workers were competing fiercely with each other on executing a synchronized method (DestinationMap::get), which is also the most hot spot in the program . I also notice that the caller AbstractRegion::getDestinations acquires a read lock before calling it, so I guess this could be a left out, read lock is the actual lock type required here.

      It's too difficult for me to list all critical sections between NIO workers, or between NIO workers and BrokerService which adds up to the overall synchronize overhead. So I attach the relevant info, with the hope of finding a complete solution to this.

      Attachments

        1. tunable_threadpool_options.patch
          6 kB
          Benjamin Huang
        2. Monitor_Usage_Statistics.html
          88 kB
          Benjamin Huang
        3. Monitor_History.zip
          1.16 MB
          Benjamin Huang
        4. Method_Statistics.html
          515 kB
          Benjamin Huang
        5. monitor_usage_stats.png
          347 kB
          Benjamin Huang
        6. nio_worker_blocked_frequently.png
          396 kB
          Benjamin Huang
        7. nio_worker_blocked_2.png
          405 kB
          Benjamin Huang
        8. nio_worker_blocked_1.png
          409 kB
          Benjamin Huang

        Issue Links

          Activity

            People

              Unassigned Unassigned
              benjaminhuang Benjamin Huang
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: