Timeout causes PHP execution to hang

[araines]

Hi

I'm having intermittent trouble with our system which I believe I have managed to trace back to memcached. Following the troubleshooting guide on the memcached timeouts wiki, I'm now coming to the conclusion there is some form of problem with the PHP client.

System info:

PHP 7.0.19-1+deb.sury.org~trusty+1 (fpm-fcgi) (built: May 11 2017 14:25:46)
Linux qa1-api-01 3.13.0-117-generic #164-Ubuntu SMP Fri Apr 7 11:05:26 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

# php-fpm7.0 -i | grep memcached
/etc/php/7.0/fpm/conf.d/25-memcached.ini
memcached
memcached support => enabled
libmemcached version => 1.0.18
memcached.compression_factor => 1.3 => 1.3
memcached.compression_threshold => 2000 => 2000
memcached.compression_type => fastlz => fastlz
memcached.default_binary_protocol => 0 => 0
memcached.default_connect_timeout => 0 => 0
memcached.default_consistent_hash => 0 => 0
memcached.serializer => php => php
memcached.sess_binary_protocol => 1 => 1
memcached.sess_connect_timeout => 0 => 0
memcached.sess_consistent_hash => 1 => 1
memcached.sess_lock_expire => 0 => 0
memcached.sess_lock_max_wait => not set => not set
memcached.sess_lock_retries => 5 => 5
memcached.sess_lock_wait => not set => not set
memcached.sess_lock_wait_max => 2000 => 2000
memcached.sess_lock_wait_min => 1000 => 1000
memcached.sess_locking => 1 => 1
memcached.sess_number_of_replicas => 0 => 0
memcached.sess_persistent => 0 => 0
memcached.sess_prefix => memc.sess. => memc.sess.
memcached.sess_randomize_replica_read => 0 => 0
memcached.sess_remove_failed_servers => 0 => 0
memcached.sess_sasl_password => no value => no value
memcached.sess_sasl_username => no value => no value
memcached.sess_server_failure_limit => 0 => 0
memcached.store_retry_count => 2 => 2
Registered save handlers => files user memcached

The symptoms are that our PHP-FPM processes hang - apparently doing nothing (our app stops logging) but using as much CPU as they can - until the PHP execution timeout is reached. At that stage we get an error in our syslog:

ool www: PHP Fatal error:  Maximum execution time of 300 seconds exceeded in /vol/api/releases/8245f9086e24fafa1fe6281032007ec31f188ca6/vendor/doctrine/cache/lib/Doctrine/Common/Cache/MemcachedCache.php on line 109

The line in this example corresponds with a SET operation.

I've used strace to track what is happening and these are the last lines we see before the PHP process hangs:

gettimeofday({1494600712, 434076}, NULL) = 0
sendto(10, "set 8245f9086e24fafa1fe628103200"..., 571, MSG_NOSIGNAL, NULL, 0) = 571
recvfrom(10, "END\r\n", 8196, MSG_NOSIGNAL, NULL, NULL) = 5
recvfrom(10, 0x7f432c435cd8, 8196, 16384, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=10, events=POLLIN}], 1, 2000) = 1 ([{fd=10, revents=POLLIN}])
recvfrom(10, "STORED\r\n", 8196, MSG_NOSIGNAL, NULL, NULL) = 8
recvfrom(10, 0x7f432c435cd8, 8196, 16384, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=10, events=POLLIN}], 1, 2000) = 0 (Timeout)
shutdown(10, SHUT_RDWR)                 = 0
close(10)                               = 0

Where the file descriptor 10 is our connection to the memcached server.

At the same time as this issue occurred, I was running the mc_conn_tester.pl script (5000 cycles) and saw no issues reported from there. This leads me to believe it is not a networking issue.

I'm not sure where to go from here - any and all help appreciated.

[sodabrew]

Are you sometimes creating keys with non-ascii-printable values (e.g. special characters or whitespace) ?

[araines]

Thanks for the pointer - it looks possible that we are getting that situation. Whitespace, UTF8 character sets etc. We also potentially have some very long keys.

I've since altered our key generation so that it always performs an md5 as the very last step to avoid lengthy keys and non-alphanumeric characters. This appears to have resolved the problem - although as it's an intermittent issue I'm not 100% sure it has resolved it. Also I don't believe we ever experienced this problem until upgrading from PHP5.6 to PHP7.0, although again I don't have much hard evidence to support that - just anecdotal evidence.

I couldn't see anything in the documentation relating to reserved characters or other restrictions around keys. Nor does the library throw any errors for misuse. If there are genuine restrictions on keys, I'd strongly suggest it is made very clear in the documentation and ideally have the library deal with it too.

Thanks again for the help

[sodabrew]

Great! I'll mark this a duplicate of #339 for now - the memcached client should be proactive about checking for invalid keys and throwing an exception rather than sending to the server a request that cannot be parsed by the server.