search

php-memcached-dev / php-memcached

memcached extension based on libmemcached library
Other
991 stars 323 forks source link

Session lock record with PHP 7.0.9 #269

Open CassianoCarraro opened 8 years ago

CassianoCarraro commented 8 years ago

I'm using a Memcached session handler normally in PHP 5.6. But with PHP 7 session don't retrieved properly and the follow warning message was triggered in PHP error log: PHP Warning: session_start(): Unable to clear session lock record.

Any suggestion?

datasage commented 8 years ago

Session settings have changed quite a bit for php 7 version of the extension, you will probably need to tweak your settings a bit to get it to behave as it did in PHP 5.6

sodabrew commented 8 years ago

Please state the version of php-memcached that you are using (or the git revision if you're building from source).

CassianoCarraro commented 8 years ago

I tried to use repository and build php7 source branch, but in both case i have the same problem. The versions is as follows:

From repository Memcached version: 3.0.0-dev libmemcached version: 1.0.16

From php7 branch: Memcached version: 3.0.0b1 libmemcached version: 1.0.18

beniamin commented 8 years ago

I had same problem and I resolved the issue by disabling session.lazy_write in php.ini

arisro commented 8 years ago

Hey guys,

You can set memcached.sess_lock_expire to your max_execution_time value to avoid that bug from #266. This way the extension won't fall back to the max_execution_time value - which it reads incorrectly.

CassianoCarraro commented 8 years ago

I disabled session.lazy_write and set memcached.sess_lock_expire according my max_execution_time, but the problem persists. I found that this problem occurs when many requests is sent in a short time to session_start() with a same session id. This can be simulated with a code that call session_start() and then add a sleep executing this script many times will throw this error. I think that have a problem to unlock session or another configuration is causing the problem.

arisro commented 8 years ago

@CassianoCarraro

In the case you describe, the error is normal. Example:

  1. See this: https://bugs.php.net/bug.php?id=72345. The maximum execution time is not affected by system calls, stream operations etc. So the time you wait for session_start() doesn't add to the execution time.
  2. You have max_execution_time = memcached.sess_lock_expire = 30s
  3. You fire a request that keeps the session locked 3s let's say. If you fire 11 requests, they are serialized by the session lock. Your requests will go through 1 by 1.
  4. The first request goes in immediately and locks the session for 3s. The seconds request waits 3s then he locks it for another 3s. The third request will wait in total 6s, then lock for 3s, and so on.
  5. The 11th request has to wait 30s. Since session_start() doesn't add to the exection time, you won't get a max execution time error. You will get instead a warning, because of the session locking timeouts (which you can control with memcached.sess_lock_retries, memcached.sess_lock_wait_min/max). Once this timeout happens, your request will go through and be executed - ignoring the lock so to say.

So this is another problem, and is not actually an issue cause by this extension. The issue #266 consists in the session lock being permanently set (with 0 TTL) so you reach the timeout limit on any request - and the lock is not removed even after the timeout, when the request is processed.

beniamin commented 8 years ago

My problem is with parallel requests. If I have an ajax request running and I send another request, both requests are stopped and receive 500 with error from first post.
I tried to set max_execution_time = memcached.sess_lock_expire, but didn't solve my problem. Only disabling session.lazy_write solved my problem.

idmssvep commented 8 years ago

I have the same issue, i run a lot of paralell requests and i have repeating "Unable to clear session lock record" fatals. I disabled lazy write and tried following memcached config:

memcached.sess_lock_expire 7200
memcached.sess_lock_max_wait not set memcached.sess_lock_retries 5 memcached.sess_lock_wait not set memcached.sess_lock_wait_max 120000 memcached.sess_lock_wait_min 0 memcached.sess_locking 1

with: Version 3.0.0-dev libmemcached version 1.0.16

With older versions on php 5.4 base i have absolutely no issues. It gives me a feeling that on PHP7 they are processed much faster and due to this fact create more blocking requests. One question: Is this issue fixed to PHP 7.0.9, so a up or downgrade could help?

arielkung commented 8 years ago

Confirming here in php 7.0.12 if you set a fixed value for memcached.sess_lock_expire the issue goes away. Message "PHP Warning: session_start(): Unable to clear session lock record." will appear anyway if your session is locked more than the time you set of course.

bzabos commented 7 years ago

Please read up on how these values are consumed: https://github.com/php-memcached-dev/php-memcached/blob/master/memcached.ini

Increasing sess_lock_wait_max is only increasing the maximum seconds to which php will perform its exponential back off routine for retries. Increasing this value does nothing when sess_lock_wait_min is left untouched. If we want php to continue retrying at an acceptable interval, I don't believe these are the keys we should be adjusting. Lowering sess_lock_expire is just highjacking the session from other, long running, requests — is that the desired behaviour? Disabling lazy_write also seems like a bad idea.

Can anyone see why the solution wouldn't be to simply increase sess_lock_retries to a number that would result in an acceptable wait time for your specific scenario?

Eg. Where default sess_lock_wait_min=1000 and default sess_lock_wait_max=2000 and increased sess_lock_retries=10, our retry wait will accumulate as 1s+2s+2s+... Ns, giving us a total wait of 19 seconds of waiting and retrying for session lock to be released by other requests; logically, it makes sense to formulate rough equality with your max_execution_time.

woolardfa commented 7 years ago

For our Moodle site, we use memcached for PHP sessions. Because of the way Moodle uses the session handler in its AJAX calls (several issued before main page request finishes) we often get blocked session_start() calls. See this bug and this bug for details.

To get the new version to behave like the old one, we set the lock_wait_min and _max to the same reduced value of 150. This makes the spin lock retry 150 msec, as was the default in 2.2.x. Moodle config default is to wait a max of 120 secs to attain a session lock, so we set the retry count to 800 (120 / .15).

One or two seconds seems to be much to long to wait between attempts; much better to make several frequent attempts waiting (sleeping) only 150 msec at a time.

sodabrew commented 7 years ago

I've read through this ticket and I'm not sure what problem or change request is still outstanding.

andrerom commented 7 years ago

Well somwhow it seems session locking might be broken with php7, similar issue here.

sodabrew commented 7 years ago

@andrerom As I wrote, I don't fully understand the specific problem(s?) that people are having in this thread. If the problem(s?) is also affecting you, can you help to explain what would resolve it?

woolardfa commented 7 years ago

I believe the session locking problem isn't so much an issue with the php_memcached as it is with PHP (all versions). See https://bugs.php.net/bug.php?id=71962.

The messages having to do with failure to clear lock records come about because competing processes using the same session (i.e. main page request, and any number of AJAX calls associated it), are all working with the same memcached item--the first to finish removes the lock item, and the rest all report they were unable to do so simply because it wasn't there any longer.

sodabrew commented 7 years ago

I still don't understand if there is something that needs to be fixed or changed or better documented.

@woolardfa The bug you linked is specific to the memcached extension, it just happens to be filed in the PHP bug tracker, and I don't see in what way the PHP version affects the bug.

woolardfa commented 7 years ago

@sodabrew, you are correct. As I said in previous message, the issue is not in php_memcached.

idmssvep commented 7 years ago

With the explanation from woolardfa i could successfully resolve the issue from my application. Thanks!

idmssvep commented 7 years ago

Can the ini file description be updated please:

https://github.com/php-memcached-dev/php-memcached/blob/master/memcached.ini

Section: ; The time, in seconds, before a lock should release itself. ; Setting to 0 results in the default behaviour, which is to ; use the memcached.sess_lock_max_wait setting. If that is ; also 0, max_execution_time will be used. memcached.sess_lock_expire = 0;

"memcached.sess_lock_max_wait" is deprecated, i assume that "memcached.sess_lock_wait_max" will be i place but i´d like to know.

mikealmond commented 7 years ago

Any update on this?

nitinsbuzz commented 7 years ago

Any chance queing requests on the server side can solve this problem?

nitinsbuzz commented 7 years ago

If this is an issue regarding only ajax requests, how about session_write_close() a.s.ap. after the ajax call? Any experience with this option? Will it remove the lock?

http://php.net/manual/en/function.session-write-close.php http://php.net/manual/en/function.session-write-close.php#63970

woolardfa commented 7 years ago

session_write_close will end up clobbering the session data. session_abort() is the way to leave it alone.

nitinsbuzz commented 7 years ago

@woolardfa would session_abort() has also work immediatly after session_write_close() in case session data needs update on ajax call?

woolardfa commented 7 years ago

No. Use one or the other. The point is that you have to detect whether or not PHP/session/memcached was truly successful in establishing the lock entry (semaphore), and thus acquiring the right to update the session content, OR whether it just gave up after trying the specified number of times (timed out), and returned a True (the bug in session_start()) anyway. In this latter case, the session content given to the usurping process will be empty... and when session_write_close is called, or the page is allowed to end normally, that bogus (empty) session data will be written back clobbering the valid data. Calling session_abort will prevent that.

nitinsbuzz commented 7 years ago

I think the problem is with async requests (using a service worker). Only if memcached can handle async requests would it solve the problem or move long processes to the background to make sure sync requests do not get blocked.

tvlooy commented 7 years ago

For people that don't completely understand what this locking is, I recommend this article: https://ma.ttias.be/php-session-locking-prevent-sessions-blocking-in-requests/

In my opinion the default sess_lock_wait_min and sess_lock_wait_max are too high and the sess_lock_retries too low. If I set the sess_lock_wait_min and sess_lock_wait_max to 150 and increase the sess_lock_retries to match the current PHP max_execution_time, that seems to work for me.

If I look at the code, this is actually how it worked in the old PHP 5.x extension.

nitinsbuzz commented 7 years ago

How about moving the session files to memory for faster and multi access or creating virtual readonly files so that reading does not lock the file? Is this possible for memcached?

jaccoTopVintage commented 7 years ago

@sodabrew , while I'm not entirely sure about the cause of the issue, the issue is quite serious: it effectively disqualifies the use of memcached as a session save handler for PHP >= v7.0.

Our logfiles are rapidly accumulating these errors, even for just staging (=internal testing) traffic.

[Tue Jun 13 09:59:34.545330 2017] [:error] [pid 863] [client 172.31.47.37:62727] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:02:35.437714 2017] [:error] [pid 1420] [client 172.31.17.123:2875] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:07:36.574186 2017] [:error] [pid 770] [client 172.31.4.11:13979] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:08:12.651084 2017] [:error] [pid 23486] [client 172.31.47.37:33523] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:11:28.548426 2017] [:error] [pid 1573] [client 172.31.4.11:33060] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:11:37.436829 2017] [:error] [pid 23723] [client 172.31.4.11:3833] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:14:17.058926 2017] [:error] [pid 23717] [client 172.31.4.11:4263] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:15:10.176169 2017] [:error] [pid 1104] [client 172.31.47.37:19174] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:16:32.894139 2017] [:error] [pid 23813] [client 172.31.17.123:58336] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:17:15.524989 2017] [:error] [pid 1111] [client 172.31.4.11:15525] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:22:59.417394 2017] [:error] [pid 1906] [client 172.31.17.123:6021] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:22:59.432654 2017] [:error] [pid 1816] [client 172.31.47.37:2256] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:23:08.161788 2017] [:error] [pid 1787] [client 172.31.17.123:6025] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:23:16.484796 2017] [:error] [pid 24015] [client 172.31.17.123:59396] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:23:24.383012 2017] [:error] [pid 2140] [client 172.31.47.37:2320] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:23:43.852884 2017] [:error] [pid 1816] [client 172.31.47.37:2338] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:24:25.161398 2017] [:error] [pid 24203] [client 172.31.47.37:35983] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:03.566216 2017] [:error] [pid 1458] [client 172.31.17.123:24316] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:27.959560 2017] [:error] [pid 1496] [client 172.31.17.123:24374] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:28.079258 2017] [:error] [pid 24287] [client 172.31.17.123:60018] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:28.271585 2017] [:error] [pid 24290] [client 172.31.17.123:60046] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:28.613682 2017] [:error] [pid 2199] [client 172.31.17.123:6733] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:28.663198 2017] [:error] [pid 1343] [client 172.31.17.123:24390] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:28.970449 2017] [:error] [pid 1496] [client 172.31.17.123:24374] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:29.490061 2017] [:error] [pid 24290] [client 172.31.17.123:60046] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:27:29.857074 2017] [:error] [pid 2199] [client 172.31.17.123:6733] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:28:46.994038 2017] [:error] [pid 2335] [client 172.31.47.37:3174] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:29:00.161461 2017] [:error] [pid 2335] [client 172.31.47.37:3174] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:29:20.098777 2017] [:error] [pid 1787] [client 172.31.4.11:35818] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:32:59.001278 2017] [:error] [pid 2195] [client 172.31.17.123:7623] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:33:45.308154 2017] [:error] [pid 24287] [client 172.31.4.11:7269] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:38:55.447610 2017] [:error] [pid 1823] [client 172.31.47.37:22896] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:39:56.155497 2017] [:error] [pid 24238] [client 172.31.4.11:8209] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:40:07.865303 2017] [:error] [pid 1967] [client 172.31.4.11:19039] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:40:12.868631 2017] [:error] [pid 2609] [client 172.31.17.123:8763] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:40:19.048030 2017] [:error] [pid 1855] [client 172.31.17.123:26476] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:40:25.111417 2017] [:error] [pid 1998] [client 172.31.17.123:26432] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:42:25.782704 2017] [:error] [pid 24824] [client 172.31.17.123:62482] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:42:30.814022 2017] [:error] [pid 2092] [client 172.31.17.123:26826] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:43:04.932733 2017] [:error] [pid 1998] [client 172.31.4.11:19519] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:43:45.679325 2017] [:error] [pid 2795] [client 172.31.4.11:38020] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:44:45.618017 2017] [:error] [pid 24853] [client 172.31.4.11:8963] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:44:46.826418 2017] [:error] [pid 2865] [client 172.31.4.11:38170] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:45:20.161990 2017] [:error] [pid 2095] [client 172.31.17.123:27296] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:45:41.488957 2017] [:error] [pid 2795] [client 172.31.17.123:9643] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:47:00.471857 2017] [:error] [pid 3022] [client 172.31.4.11:38542] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:50:18.691312 2017] [:error] [pid 2957] [client 172.31.4.11:39036] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:50:18.752100 2017] [:error] [pid 2323] [client 172.31.4.11:20717] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:50:20.614374 2017] [:error] [pid 3008] [client 172.31.17.123:10439] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:51:26.870465 2017] [:error] [pid 2437] [client 172.31.17.123:28202] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:51:50.680096 2017] [:error] [pid 3135] [client 172.31.17.123:10619] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:52:51.911556 2017] [:error] [pid 3053] [client 172.31.4.11:39432] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:52:53.204019 2017] [:error] [pid 2415] [client 172.31.4.11:21093] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:53:17.773753 2017] [:error] [pid 2465] [client 172.31.47.37:25128] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:53:51.918845 2017] [:error] [pid 25093] [client 172.31.17.123:64284] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:54:47.174806 2017] [:error] [pid 25181] [client 172.31.17.123:64438] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:56:19.245320 2017] [:error] [pid 3020] [client 172.31.4.11:40018] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:57:38.188590 2017] [:error] [pid 2704] [client 172.31.17.123:29226] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 10:58:47.985600 2017] [:error] [pid 25400] [client 172.31.47.37:41417] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:02:28.356013 2017] [:error] [pid 25398] [client 172.31.4.11:11795] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:03:42.262363 2017] [:error] [pid 25596] [client 172.31.4.11:11971] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:09:05.051044 2017] [:error] [pid 25729] [client 172.31.17.123:2581] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:09:05.305337 2017] [:error] [pid 25667] [client 172.31.17.123:2575] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:09:52.250367 2017] [:error] [pid 25729] [client 172.31.4.11:12935] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:12:07.299454 2017] [:error] [pid 3157] [client 172.31.17.123:31354] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:12:59.271920 2017] [:error] [pid 3666] [client 172.31.47.37:9914] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:13:26.276822 2017] [:error] [pid 25868] [client 172.31.47.37:43489] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:13:46.663606 2017] [:error] [pid 25922] [client 172.31.17.123:3295] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:13:54.835686 2017] [:error] [pid 3742] [client 172.31.47.37:10016] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Tue Jun 13 11:15:42.915935 2017] [:error] [pid 2904] [client 172.31.4.11:24571] PHP Warning: session_start(): Unable to clear session lock record in (...)

I'm not sure exactly what causes the issue, but we confirmed that it is caused by PHP7: an otherwise identical PHP 5.6.30 setup the issue does not show up.

We've tried a whole lot of changes in the settings, but so far, we can't get the issue resolved. Current settings:

ini_set('session.lazy_write', 0);
ini_set('memcached.sess_lock_wait_min', 150);
ini_set('memcached.sess_lock_wait_max', 150);
ini_set('memcached.sess_lock_retries', 15);
ini_set('memcached.sess_lock_expire', ini_get('max_execution_time'));
ini_set('memcached.sess_consistent_hash', 1);
ini_set('memcached.sess_binary_protocol', 0);
session_start();

We also tried directly editing the php.ini files, but (as expected) it does not make any difference.

memcached version       3.0.0-dev
libmemcached version    1.0.16

I would be happy to assist in finding the cause of the issue, if that would help speed up a fixing it.

tvlooy commented 7 years ago

@jaccoTopVintage try this: ini_set('memcached.sess_lock_wait_min', 150); ini_set('memcached.sess_lock_wait_max', 150); ini_set('memcached.sess_lock_retries', ini_get('max_execution_time') * 1000 / 150); remove all your other ini_sets (including session.lazy_write)

This is the fix that I suggested here https://github.com/php-memcached-dev/php-memcached/pull/350 and we are running a high traffic (~140 cmd/s) site in production with these settings (we use both sessions and user cache) without any issues so far. /cc @sodabrew

jaccoTopVintage commented 7 years ago

@tvlooy thanks for the comment!

I take it
ini_set('memcached.sess_lock_expire', ini_get('max_execution_time'));
can/should also stay, because it seems to work in union with: ini_set('memcached.sess_lock_retries', ini_get('max_execution_time') * 1000 / 150);
?

sodabrew commented 7 years ago

To everyone who commented on this issue: Please look at PR #350 and test out those values. If they work for most people, then I will accept them as the new defaults in the next version of this extension.

woolardfa commented 7 years ago

We've been using 150/150 and 800 ... this mimics the spin lock behavior of the previous strategy, and the overall timeout (give up time) is 120 secs... which is what Moodle (the app we're running) defaulted to in its configs.

tvlooy commented 7 years ago

@jaccoTopVintage can you confirm the new values work for you? sess_lock_expire is not used by the 7.x extension and thus has no effect

jaccoTopVintage commented 7 years ago

@tvlooy I will confirm tomorrow, when I can monitor the results during the day.

jaccoTopVintage commented 7 years ago

If sess_lock_expire is not used the php 7.x extension, then why is it still listed in the memcached.ini file?

; The time, in seconds, before a lock should release itself.
; Setting to 0 results in the default behaviour, which is to
; use the memcached.sess_lock_max_wait setting. If that is
; also 0, max_execution_time will be used.
memcached.sess_lock_expire = 0;

I'm not contradicting you, just curious if the .ini file is up to date or not?

tvlooy commented 7 years ago

@jaccoTopVintage my bad. You are right it is in use. I grepped the code and couldn't find it and saw that it was removed in dc5b22a8dace7373c1ef9d2946e89a660ed35b20 but I didn't see that it got replaced with the MEMC_SESSION_INI_ENTRY macro so I had to grep for lock_expire. But: the default value is 0 and then it automatically defaults to the max_execution_time. So no need to change it I think

jaccoTopVintage commented 7 years ago

We gave the new settings a try. Our latest edition of the setting are:

ini_set('memcached.sess_lock_wait_min', 150); // milliseconds
ini_set('memcached.sess_lock_wait_max', 150); // milliseconds
ini_set('memcached.sess_lock_retries', ini_get('max_execution_time') * 1000 / 150); // keep trying for the full duration of 'max_execution_time'
ini_set('memcached.sess_lock_expire', ini_get('max_execution_time')); // seconds
ini_set('memcached.sess_consistent_hash', 1); // boolean

At first, the results looked promissing. There was only a single session-related error in our log files:

[Wed Jun 14 07:41:10.994489 2017] [:error] [pid 2439] [client 172.31.17.123:5283] PHP Fatal error: session_start(): Failed to create session ID: memcached (path: hostname_of_memcached_server_instance:11211) in (...)

But, the we got quite some occurrences of session-related warnings/errors that appear to come in groups; below is a single such group:

[Wed Jun 14 08:47:41.684568 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.684837 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.685067 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.685304 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.685522 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.685736 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.685946 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.686173 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.686392 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.686602 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.686815 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.687061 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.687277 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.687542 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.687752 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.687975 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.688194 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.688402 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.688614 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.688829 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.689040 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.689238 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.689475 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.689719 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.689928 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.690135 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.690343 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.690561 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.690790 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.691001 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.691209 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.691421 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.691629 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.691849 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.692058 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.692286 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.692496 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.692702 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.692912 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.693116 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.693328 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.693533 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.693738 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.694031 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.694243 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.694452 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.694659 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.694865 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.695072 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.695282 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.695487 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.695692 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.695897 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.696100 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.696332 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.696546 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.696748 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.696954 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.697161 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.697380 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.697601 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.697808 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.698021 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.698227 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.698448 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.698654 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.698865 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.699070 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.699274 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.699480 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.699690 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.699899 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.700102 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.700335 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.700542 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.700778 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.700988 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.701199 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.701403 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.701605 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.701814 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.702019 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.702223 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.702431 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.702639 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.702876 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.703080 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.703282 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.703492 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.703696 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.703923 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.704147 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.704357 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.704562 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.704765 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.704981 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.705226 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.705441 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.705647 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.705857 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.706070 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.706284 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.706489 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.706693 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.706898 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.707102 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.707316 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.707531 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.707745 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.707952 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.708198 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.708442 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.708690 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.708948 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.709273 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.709531 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.709793 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.710053 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.710316 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.710581 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.710841 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.711107 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.711371 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.711643 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.711900 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.712180 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.712439 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.712696 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.712958 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.713219 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.713475 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.713730 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.713991 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.714262 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.714521 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.714785 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.715048 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.715328 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.715599 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.715856 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.716110 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.716399 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.716655 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.716911 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.717177 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.717441 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.717715 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.717981 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.718244 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.718508 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.718766 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.719021 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.719308 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.719573 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.719836 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.720100 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.720392 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.720630 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.720859 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.721101 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.721351 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.721574 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.721835 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.722098 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.722362 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.722607 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.722874 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Failed to write session lock: SERVER HAS FAILED AND IS DISABLED UNTIL TIMED RETRY in (...)
[Wed Jun 14 08:47:41.723128 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_start(): Unable to clear session lock record in ...
[Wed Jun 14 08:47:42.129742 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_regenerate_id(): Session write failed. ID: memcached (hostname_of_memcached_server_instance) in ...
[Wed Jun 14 08:47:42.289705 2017] [:error] [pid 27036] [client 172.31.4.11:16071] PHP Warning: session_write_close(): Failed to write session data (memcached). Please verify that the current setting of session.save_path is correct (:11211) in Unknown on line 0

(The in Unknown on line 0 in the last log line is because session_write_close() is registered as a shutdown function and, as a result, does not have __FILE__ and __LINE__ information anymore, when it triggers the E_WARNING; the lack of context is normal in this situation.)

In addition to this, I still see frequent occurrences of:

[Wed Jun 14 09:02:32.985122 2017] [:error] [pid 4781] [client 172.31.4.11:29183] PHP Warning: session_start(): Unable to clear session lock record in (...)
[Wed Jun 14 09:06:41.328233 2017] [:error] [pid 27657] [client 172.31.4.11:19093] PHP Fatal error: session_start(): Failed to create session ID: memcached (path: hostname_of_memcached_server_instance:11211) in (...)

So, I don't think the issue has been solved (yet) by changing the settings.

tvlooy commented 7 years ago

Yes but "the server has failed" comes from libmemcached. I think at that point you are killing the server where you are running your memcached on and the problem lies there, not in the php-memcached extension.

jaccoTopVintage commented 7 years ago

Well, the proposed default settings are, without question, a huge improvement to the current default settings. So, I support the idea of merging Please look at PR https://github.com/php-memcached-dev/php-memcached/pull/350.

I fear however, that there is (also) a deeper underlying problem, because we never had any noteworthy issues with memcached backed session with out PHP 5 servers.

jaccoTopVintage commented 7 years ago

@tvlooy , What are the Memcached settings you use, for your high traffic production site?

More specifically, what is are numbers your production environment uses for the limit of simultaneous incoming connections (-c flag) and the memory cap (-m flag)?

tvlooy commented 7 years ago

@jaccoTopVintage -c 8192, -m 128. That is for sessions only (so was the ~140 cmd/s). We run a separate instance for user cache with -c 8192, -m 1536 that is doing ~718000 cmd/s.

tvlooy commented 7 years ago

@CassianoCarraro what was your status with this issue? Can you verifiy the solution above?

jaccoTopVintage commented 7 years ago

We finally fixed the issues we had with the memcached backed PHP sessions. The 'solution' for us was to set:

ini_set('session.lazy-write', 0); // Mimic PHP5 behaviour

This is, of course, not a solution, but rather a workaround. I'm guessing that the lazy-write option somehow walks a code path that triggers errors, or at least, incompatibilities with the memcached server. My C skill are way too rusty to find the issue myself, but I'm hoping this information can at least help someone else find out the root cause of the issue.

CassianoCarraro commented 7 years ago

@tvlooy I updated my PHP and memcached lib. Now I'm working with: PHP: 7.0.20 Memcached version: 3.0.3 libmemcached version: 1.0.18

I did some tests in my environment with default config's and all is working fine now. In addition, I performed some tests delaying the requests to simulate the problem. In this case I did some adjustments in configuration vars memcached.sess_lock_expire and memcached.sess_lock_wait_max as the @idmssvep indicated and work fine too.

tvlooy commented 7 years ago

Thanks! Anyone else that is following this report? Please test and report your findings.

nadalizadeh commented 7 years ago

My warnings disappeared with the following configuration as @tvlooy suggested.

; Wait for 150 ms initially
memcached.sess_lock_wait_min = 150
; Wait for 500 ms in the next retries
memcached.sess_lock_wait_max = 500
; Retry for 60 times overally (max time would be 60 x 500 ms)
memcached.sess_lock_retries = 60
; Total time that a lock exists is 40 seconds which is equal to my max_execution_time
memcached.sess_lock_expire = 40

-> Upgrading to the latest php-memcached from git repository didn't help without the configuration above.

baurmatt commented 7 years ago

Still happening to us even thought we have set the recommended memcached config options :(

tvlooy commented 7 years ago

we are stull running fine in production without issues when using those values