REGRESSION: Cf_client_data not deleting in 5.3.6.61

This seems like a regression issue.

Lucee 5.3.6.61
Apache Tomcat/9.0.31
11.0.6 (AdoptOpenJDK) 64bit
CentOS Linux 7.8.2003

Recently updated from Lucee 5.2.8.50 to 5.3.6.61 because a production web server started to crash for unknown reasons. Upgrade went smooth. However, about a month later started to have performance problems related to cf_client_data.

Clustered setup with 2 web servers / 2 db servers (one for data - one for session)

The performance problem was isolated to the session database. In AWS CloudWatch, I could see the Average Queue Length growing - and spiking every 61 minutes. I traced those queries and it was:

Time: 200805 16:59:00

Query_time: 239.316670 Lock_time: 0.000045 Rows_sent: 7465744 Rows_examined: 7565860

SET timestamp=1596661140;
SELECT cfid, name FROM cf_client_data WHERE expires <= ‘1596660900852’;

Looks like I was missing a vital index - which has been added using:

CREATE UNIQUE INDEX ix_cf_client_data ON cf_client_data(cfid, name, expires)

QUESTION: Why wasn’t this a problem in 5.2.8.50???

The index was missing then too. Everything else is 100% same. No changes in user volumes.

We failed back to 5.2.8.50 last night. I trucated the cf_client_data tables for both versions. This morning the 5.2.8.50 is an expected size. The 5.3.6.61 cf_client_data table is growing again.

Is this a possible bug in 5.3.6.61? cf_client_data is not deleting? I see delete statements running every 61 minutes - such as this:

DELETE FROM cf_client_data WHERE cfid=‘cab5cb06-1f5f-47cd-95e3-c49a4072c43b’ and name=‘APP20180723’

— but why would the record count have grown so dramatically over a month. It was up to over 7,000,000 records in cf_client_data when it finally crashed last night… Again, none of this was happening in 5.2.8.50 with the EXACT same hardware / application set up. Again, this seems like a regression issue.

Quick follow up - I’ve been watching the roughly hourly deletes of client scope data in our database, and it looks like both of our Production Lucee servers are sending the same DELETE request:

4602673 root ip-10-0-3-162.ec2.internal:50148 cf_client_vars_lucee_5_1 Query 0 query end DELETE FROM cf_client_data WHERE cfid=‘5b22622e-a553-43cb-ad67-a7d4ba9b65bd’ and name=’’
4602668 root ip-10-0-1-213.ec2.internal:55970 cf_client_vars_lucee_5_1 Query 0 query end DELETE FROM cf_client_data WHERE cfid=‘5b22622e-a553-43cb-ad67-a7d4ba9b65bd’ and name=’’

Notice the CFID is the same on both delete statements originating from different IP addresses (web servers).

Does anyone know if this is expected behavior?

application.cfm config - as I understood that to be relevant.

CFAPPLICATION NAME=“APP20180723” CLIENTMANAGEMENT=“Yes” SETCLIENTCOOKIES=“Yes” CLIENTSTORAGE= “cf_client_vars_lucee_5_1” sessionmanagement=“yes” clientCluster=“true” setdomaincookies=“Yes”

Thanks in advance for any thoughts you have! I greatly appreciate this group!

Hi,

let me allow one question. In your first post, there is an name=‘APP20180723’ in the DELETE SQL statement, whereas the name=’’ in your second post is empty.
Are the two SQL statements from the same Lucee-version?

Michael

Hi Michael

Thanks for the response. We did have two versions at one point. I believe we are now only on the same version for this session table. We turned off the 5.3.6.61 and are now running on a cluster of 4 x 5.2.8.50 lucee servers. I have been trying to figure out where those null application names are coming from.

Still seeing null entries for Application Name in the CF_CLIENT_DATA table. Seems like a duplicate entry for many CFID’s. However, they seem to stop at some point in the table.

Why would there be null Application Names?

Why would there be duplicate CFIDs?

Thx

Probably it is related to this issue https://luceeserver.atlassian.net/browse/LDEV-3001 and Application Names are missing in general.

See comment here https://luceeserver.atlassian.net/browse/LDEV-2990

1 Like

Thanks. I will jump over there and share my logs.

Notice the duplicate CFIDs - only for 5.3.6.61….

Any thoughts on this?

Also - I came by this in the logs today (we are still on the old version 5.2.8.50

“ERROR”,“http-nio-8888-exec-23”,“09/16/2020”,“12:44:26”,“scope-context”,"Duplicate entry ‘93cba7cf-3d80-40f9-9a71-c9510204d320-MAR20180723-1600281866592’ for key ‘ix_cf_client_data’
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry ‘93cba7cf-3d80-40f9-9a71-c9510204d320-MAR20180723-1600281866592’ for key ‘ix_cf_client_data’