[AMQ-5925] Excessive CPU and Slow Throughput When Using Shiro Encrypted Passwords

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Abandoned
• Affects Version/s: 5.11.1, 5.11.2, 5.12.0
• Component/s: Broker, Security/JAAS
• Assignee: Unassigned
• Reporter: Justin Reock
• Created: 12/Aug/15 17:30
• Updated: 13/Mar/22 14:16
• Resolved: 13/Mar/22 14:16

Description

When using encrypted passwords with the Shiro plugin, the broker uses excessive CPU and message throughput is greatly reduced.

CPU Sampling in JVisualVM shows the majority of the CPU utilization going to the org.apache.shiro.crypto.hash.SimpleHash.hash() thread. You can see the thread sampling screenshot in the attached PDF.

This is easy to recreate. I used a Camel DataSet load test (attached as camel.xml) and ran it against the broker with and without Shiro password encryption turned on.

Please find attached an activemq.xml with the Shiro plugin enabled and using an encrypted password (clear text password is commented out).

I performed this test in 5.10, 5.11.0, 5.11.1, 5.11.2 and 5.12.0

Results with encryption in 5.12.0:

INFO | Apache Camel 2.15.2 (CamelContext: camel) started in 0.556 seconds
INFO | Sent: 1000 messages so far. Last group took: 222743 millis which is: 4.489 messages per second. average: 4.489
INFO | Sent: 2000 messages so far. Last group took: 220536 millis which is: 4.534 messages per second. average: 4.512
INFO | Sent: 3000 messages so far. Last group took: 220147 millis which is: 4.542 messages per second. average: 4.522

Results with encryption turned off:

INFO | Sent: 1000 messages so far. Last group took: 2288 millis which is: 437.063 messages per second. average: 437.063
INFO | Sent: 2000 messages so far. Last group took: 1551 millis which is: 644.745 messages per second. average: 520.969
INFO | Sent: 3000 messages so far. Last group took: 1291 millis which is: 774.593 messages per second. average: 584.795
INFO | Sent: 4000 messages so far. Last group took: 1361 millis which is: 734.754 messages per second. average: 616.238
INFO | Sent: 5000 messages so far. Last group took: 1216 millis which is: 822.368 messages per second. average: 648.761
INFO | Sent: 6000 messages so far. Last group took: 1176 millis which is: 850.34 messages per second. average: 675.447
INFO | Sent: 7000 messages so far. Last group took: 1188 millis which is: 841.751 messages per second. average: 695.065
INFO | Sent: 8000 messages so far. Last group took: 1380 millis which is: 724.638 messages per second. average: 698.629
INFO | Sent: 9000 messages so far. Last group took: 1435 millis which is: 696.864 messages per second. average: 698.432
INFO | Sent: 10000 messages so far. Last group took: 1525 millis which is: 655.738 messages per second. average: 693.914
INFO | Sent: 11000 messages so far. Last group took: 1480 millis which is: 675.676 messages per second. average: 692.216
INFO | Sent: 12000 messages so far. Last group took: 1283 millis which is: 779.423 messages per second. average: 698.731
INFO | Sent: 13000 messages so far. Last group took: 1129 millis which is: 885.74 messages per second. average: 710.266
INFO | Sent: 14000 messages so far. Last group took: 1167 millis which is: 856.898 messages per second. average: 719.055

My thinking is that this is happening because of the use of the raw SimpleHash object instead of using a Shiro CacheManager to hold the decrypted credentials.