How are connections counted for QS_SrvMinDataRate

[Simon Studer]

How are connections counted for QS_SrvMinDataRate?

We noticed that the minimum data rate is enforced even though there are not many busy connections (these two log entries were logged practically at the same time):

MaxRequestWorkers 3072
QS_SrvMinDataRate 120 5120 750

mod_qos(200): { "scoreboard": { "open": 195904, "waiting": 518, "read": 103, "write": 79, "keepalive": 0, "start": 0, "log": 3, "dns": 0, "closing": 1, "finishing": 0, "idle": 0 }, "maxclients": { "max": 3072, "busy": 185 }, "clientContentTypes": { **** } }

mod_qos(034): access denied, QS_SrvMinDataRate rule (in:0): min=871, this connection=0, c=****

Also, is it normal that there are so many open connections?

[Pascal Buchbinder]

May I ask which version of mod_qos and which Apache MPM you use?

[Simon Studer]

We are using mod_qos 11.63 with event MPM.

[Pascal Buchbinder]

mod_qos counts the number of open connection records/structures which are created by Apache when opening a new connection (increment) and which is destroyed (decrement) when the connection gets closed and the memory freed.
The number of connections mod_qos "sees" could be logged by adding %{QS_AllConn}e to your transfer/custom log (see http://mod-qos.sourceforge.net/#QS_AllConn).

The value shown by QS_AllConn can be different than the "busy" entry in the status log (higher or lower - as they are not calculated at the very same time and as they use different sources).
Example (status logged by mod_qos 11.64, Apache 2.4.41 MPM event, 30 test clients without keepalive and 10ms "think time" between each request, document size 159 bytes):

[Wed Dec 11 22:44:00.425296 2019] [qos:notice] [pid 5182:tid 139889139828480] mod_qos(200): { "scoreboard": { "open": 130997, "waiting": 68, "read": 2, "write": 5, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 0, "finishing": 0, "idle": 0 }, "maxclients": { "max": 150, "busy": 7, "QS_AllConn": 15 } }
[Wed Dec 11 22:45:00.653599 2019] [qos:notice] [pid 5182:tid 139889139828480] mod_qos(200): { "scoreboard": { "open": 130997, "waiting": 56, "read": 4, "write": 7, "keepalive": 0, "start": 0, "log": 5, "dns": 0, "closing": 3, "finishing": 0, "idle": 0 }, "maxclients": { "max": 150, "busy": 16, "QS_AllConn": 7 } }
[Wed Dec 11 22:46:00.868205 2019] [qos:notice] [pid 5182:tid 139889139828480] mod_qos(200): { "scoreboard": { "open": 130997, "waiting": 64, "read": 7, "write": 3, "keepalive": 0, "start": 0, "log": 1, "dns": 0, "closing": 0, "finishing": 0, "idle": 0 }, "maxclients": { "max": 150, "busy": 11, "QS_AllConn": 20 } }

The question is: Does the number of connection shown by QS_AllConn always stays higher than expected?

[Pascal Buchbinder]

same test with MPM worker more clients (200)

[Sat Dec 14 21:09:00.698250 2019] [qos:notice] [pid 7980:tid 140185512986368] mod_qos(200): { "scoreboard": { "open": 130672, "waiting": 54, "read": 170, "write": 2, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 174, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 172, "QS_AllConn": 170 } }
[Sat Dec 14 21:10:01.051849 2019] [qos:notice] [pid 8260:tid 140185512986368] mod_qos(200): { "scoreboard": { "open": 130672, "waiting": 65, "read": 170, "write": 1, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 164, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 171, "QS_AllConn": 169 } }

moving the "think time" when sending the request header (results in more threads in the read state):

[Sat Dec 14 21:12:00.606173 2019] [qos:notice] [pid 8258:tid 140185512986368] mod_qos(200): { "scoreboard": { "open": 130622, "waiting": 51, "read": 193, "write": 8, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 198, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 201, "QS_AllConn": 205 } }
[Sat Dec 14 21:13:00.366358 2019] [qos:notice] [pid 9777:tid 140185383728896] mod_qos(200): { "scoreboard": { "open": 130622, "waiting": 36, "read": 198, "write": 2, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 214, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 200, "QS_AllConn": 213 } }
[Sat Dec 14 21:14:00.551823 2019] [qos:notice] [pid 9742:tid 140185512986368] mod_qos(200): { "scoreboard": { "open": 130622, "waiting": 38, "read": 199, "write": 3, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 210, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 202, "QS_AllConn": 206 } }

and with MPM event

[Sat Dec 14 21:16:00.870301 2019] [qos:notice] [pid 11523:tid 139957759432448] mod_qos(200): { "scoreboard": { "open": 130272, "waiting": 498, "read": 199, "write": 1, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 102, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 200, "QS_AllConn": 201 } }
[Sat Dec 14 21:17:00.273620 2019] [qos:notice] [pid 12144:tid 139957759432448] mod_qos(200): { "scoreboard": { "open": 130272, "waiting": 516, "read": 193, "write": 0, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 91, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 193, "QS_AllConn": 215 } }
[Sat Dec 14 21:18:00.274059 2019] [qos:notice] [pid 11525:tid 139957759432448] mod_qos(200): { "scoreboard": { "open": 130272, "waiting": 505, "read": 199, "write": 0, "keepalive": 0, "start": 0, "log": 0, "dns": 0, "closing": 96, "finishing": 0, "idle": 0 }, "maxclients": { "max": 525, "busy": 199, "QS_AllConn": 187 } }

the results using Apache 2.4.41 MPM event look pretty good

[Simon Studer]

I will have to check how it behaves exactly by logging the two values together. There was around a second between the log entries I posted above.

How did you log the QS_AllConn variable in the scoreboard, did you have to modify the source code or is there an option for showing this information? It would be useful to have it there.

[Pascal Buchbinder]

Logging QS_AllConn for every request will help you to see the maximum and minimum number of connections your server has (which is better than only one sample per minute as you won't see any peaks).