tracker issue : CF-4205489

select a category, or use search below
(searches all categories and all time range)
Title:

Potential for thousands of Redis calls every 5 seconds when monitoring sessions with PMT

| View in Tracker

Status/Resolution/Reason: To Fix//Investigate

Reporter/Name(from Bugbase): Michael F. / ()

Created: 10/21/2019

Components: PMT, Non-Request Metrics

Versions: 2018

Failure Type: Performance Issue

Found In Build/Fixed In Build: Update 5 /

Priority/Frequency: Normal / All users will encounter

Locale/System: English / Linux

Vote Count: 1

Problem Description: 

With FusionReactor, you have the ability to track Jedis. This is the library used to create and manage session storage in ColdFusion if you have Redis session management configured, rather than in Memory sessions.

You see that with FusionReactor, there appears to be a function that makes one Redis call for every single session in Redis. This occurs every 5 seconds.

If PMT is removed these Redis calls stop occuring.

With a single session you see there is one redis call every 5 seconds - https://drive.google.com/open?id=10DchQuEN2OqfPBvYeBFU-I0UEjT4PvMl

with 1000 active sessions there are 2000 redis calls every 5 seconds - https://drive.google.com/open?id=14chGbcpok27Bx4ZeUbmfkuEsVPEtNNqe

As soon as sessions expire the redis calls stop - https://drive.google.com/open?id=1NYVRjLTj6pnVsPWhhVRYb_z_w8yUsUrJ

These are the redis calls being made - https://drive.google.com/open?id=1aWqZ9hbv-i-a6kxUwntEhhKT4AMeBgMq

Steps to Reproduce:
1. Configure CF 2018 with redis sessions
2. Add FR onto the CF 2018 (optional to give you easy visibility of the Redis calls)
3. Add the CF 2018 to PMT
4. Use Apache benchmark, Apache Jmeter or any other load simulation tool to push a given number of requests that create sessions into CF
5. Observer the active Redis queries

If you require any assistance on FR config email support@fusion-reactor.com or me personally (I am the technical support engineer for FusionReactor).

Actual Result:
There is a potential for hundreds of thousands of calls to Redis every 5 seconds.
This has the potential to have a big impact on system performance as the number of sessions grows.

Expected Result:
There should not be this many calls to Redis every 5 seconds

Any Workarounds:
None

Attachments:

Comments:

Michael, Do you happen to have thread dumps of the CF server, from when you simulated that behavior. That would make it easier to check the part of the code from where those calls are generating, in case one of those calls is captured in the dump.
Comment by Piyush K.
31808 | November 11, 2019 03:31:55 PM GMT
Hi, See Selection_577 this shows the profiler in an older version of FusionReactor where we call the Monitor class to retrieve the active session count. You can see that we make a reflection call to coldfusion.monitor.inmemory.InMemoryMonitoringServiceImpl.getActiveSessionCount() so we can gather the session metrics. In the profile if you follow the profile tree is the full profile you can see coldfusion.monitor.inmemory.InMemoryMonitoringServiceImpl.getActiveSessionCount() calls coldfusion.runtime.SessionTracker.getActiveSessionCount() which makes Jedis calls to Redis. This is the method call we can see makes one Redis call per active session. In a later version of FusionReactor, where we stopped calling the Monitor.getActiveSessionCount() so we were not making any calls to Redis, we took a stack trce of all threads and see the stack trace: "java.net.SocketOutputStream.socketWrite0(Native Method) java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) java.net.SocketOutputStream.write(SocketOutputStream.java:155) redis.clients.util.RedisOutputStream.flushBuffer(RedisOutputStream.java:52) redis.clients.util.RedisOutputStream.flush(RedisOutputStream.java:216) redis.clients.jedis.Connection.flush(Connection.java:331) redis.clients.jedis.Connection.getBinaryMultiBulkReply(Connection.java:274) redis.clients.jedis.BinaryJedis.hgetAll(BinaryJedis.java:1028) coldfusion.runtime.session.external.RedisSessionStorage.getSessionCount(RedisSessionStorage.java:430) coldfusion.runtime.SessionTracker.getSessionCount(SessionTracker.java:796) coldfusion.monitor.scheduler.NonRequestTask.updateSessionData(NonRequestTask.java:176) coldfusion.monitor.scheduler.NonRequestTask.collectNonRequestMetrics(NonRequestTask.java:120) coldfusion.monitor.scheduler.NonRequestTask.run(NonRequestTask.java:101) java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) java.lang.Thread.run(Thread.java:844)" Please let me know if there is anything else you need.
Comment by Michael F.
31809 | November 11, 2019 04:47:54 PM GMT
Any word on this, Adobe folks?
Vote by Charlie A.
31890 | November 27, 2019 09:03:09 PM GMT
Hi All, We are looking into this issue. Thanks, Mayur Jain
Comment by Mayur J.
31889 | November 28, 2019 07:45:00 AM GMT