Slow queries from Zebra_Session

[oevna]

The server has 16G of memory and a quad core Xeon @ 3.20GHz.

Our MySQL slowqueries.log is full of things like this now, even with a server load of 0.42:

Query_time: 34.210791 Lock_time: 0.000077 Rows_sent: 0 Rows_examined: 0 SET timestamp=1500342862; INSERT INTO session_data ( session_id, hash, session_data, session_expire ) VALUES ( "l99gu2r3t6tto9bhpf4r9fhec3", "06dfe788b292aaf30b1e048300bc99cf", "www.example.com |O:17:\"Authentication\":10:{s:9:\"auth_type\";N;s:6:\"status\";N;s:14:\"login_function\";s:8:\"Login\";s:14:\"login_callback\";N;s:22:\"login_failure_callback\";N;s:15:\"logout_callback\";N;s:26:\"provider_mismatch_callb ack\";s:19:\"ProviderMismatch\";s:27:\"\0RB_Authentication\0identity\";N;s:29:\"\0Authentication\0csrf_token\";s:60:\"xxx\";s:24:\"password_change_callback\";s:17:\ "PasswordChange\";}", "1502762028" ) ON DUPLICATE KEY UPDATE session_data = "www.example.com |O:17:\"Authentication\":10:{s:9:\"auth_type\";N;s:6:\"status\";N;s:14:\"login_function\";s:8:\"Login\";s:14:\"login_callback\";N;s:22:\"login_failure_callback\";N;s:15:\"logout_callback\";N;s:26:\"provider_mismatch_callb ack\";s:19:\"ProviderMismatch\";s:27:\"\0Authentication\0identity\";N;s:29:\"\0Authentication\0csrf_token\";s:60:\"xxxxxxxxx\";s:24:\"password_change_callback\";s:17:\ "PasswordChange\";}", session_expire = "1502762028";

And these (more numerous):

Query_time: 11.333438 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 SET timestamp=1500408648; SELECT GET_LOCK("session_2e70si6agkejccs7ptd71n3i24", 60);

I'm using the schema specified in the install/session_data.sql.

[stefangabos]

The SET timestamp query is not from Zebra_Session. Other than that, the queries look fine to me but they take too long...Is there a HUGE amount of rows in the session table? (although, that shouldn't lead to this behaviour).

If you say that there are more GET_LOCK statements it may be that they are failing; replace the die statement in line 470 with error_log to see if that is the case; if this is indeed the problem then it is because you or your users are authenticated, in the same browser, with the same account, multiple times and doing things that take a lot of time to complete; during this time the row is locked and other sessions (same accounts, different tabs) will be unable to get these locks and will hang.

that's all I can come up with, for now.

[oevna]

SET timestamp I'm assuming is from MySQL internals for slowquery.log, so I think we can ignore that. There are currently 6,465 rows in session_data. I'll try your suggestions first.

[oevna]

I'm now using error_log('Zebra_Session: Could not obtain session lock!', 1, '/path/to/zebra_log'); (given Apache write access)

And I've also tried error_log('Zebra_Session: Could not obtain session lock!');

And neither the error_log nor zebra_log ever have any data written to them. Yet I still do see the entries in the mysqld slowqueries.log.

I've tried logging into the app myself and opening many different tabs to try to reproduce the problem, but I've never seen it myself as a result of anything I can do.

There aren't many other slow queries that show up in that log other than the ones produced by the session library, and the load is low enough that something like high processor or memory usage would cause them.

Any other suggestions?

[dnanusevski]

I have a system that will be used with similar/same browsers and same accounts.

Will there be problems ?

[stefangabos]

This is most likely because of #16 and therefore should now be fixed