Memcache error when update to 9.1.0 #25692

Closed
insertjokehere opened this Issue Aug 2, 2016 · 16 comments

Projects

None yet

5 participants

@insertjokehere

After installing the packages for Owncloud 9.1.0 over 9.0.4, I cannot complete the occ upgrade step because of an Error 21 interacting with memcached : SERVER END message

Steps to reproduce

  1. Install 9.0.4
  2. apt-get upgrade to 9.1.0
  3. occ upgrade

Expected behaviour

The upgrade should complete so I can use my instance

Actual behaviour

The upgrade fails. Output looks like:

ownCloud or one of the apps require upgrade - only a limited number of commands are available  
You may use your browser or the occ upgrade command to do the upgrade  
Set log level to debug  
Checking whether the database schema can be updated (this can take a long time depending on the database size)  
 Done                                       
 24/24 [============================] 100%  
Checked database schema update  
Checking updates of apps  
Checked database schema update for apps  
Updating database schema  
Updated database  
Drop old database tables  
 Done                                              
 28/28 [============================] 100%         
Remove old (< 9.0) calendar/contact shares  
 Done                                              
 4/4 [============================] 100%           
Fix permissions so avatars can be stored again  
 Done                                              
 2/2 [============================] 100%           
Starting code integrity check...  
Exception: Error 21 interacting with memcached : SERVER END  
Update failed  
Maintenance mode is kept active  
Reset log level  

Server configuration

Operating system: Ubuntu 14.04

Web server: nginx

Database: Postgresql 9.3

PHP version: 5.5.9

ownCloud version: 9.1.0

Updated from an older ownCloud or fresh install: 9.0.4

Where did you install ownCloud from: http://download.owncloud.org/download/repositories/stable/Ubuntu_14.04/

@ghost
ghost commented Aug 3, 2016

@insertjokehere If you don't have multiple oC instances connecting to the same memcached a quick workaround would be to use APCu as recommended here:

https://doc.owncloud.org/server/9.1/admin_manual/configuration_server/caching_configuration.html#recommendations-based-on-type-of-deployment

@tflidd
Contributor
tflidd commented Aug 3, 2016

Or just disable all caching modules during upgrade.

@PVince81
Collaborator

If disabling memcache is the only solution then maybe OC could try and detect that it's enabled and refuse to upgrade before it isn't ?

@tomascohen

The point of having an upgrade script with sanity checks reporting eveltual problems (+1) is that you can detect what's going on.
-1 for OC not reporting the problem to the end user (yield in a void in which it cannot complete the upgrade and the last resort is to google for the message).
-1 for OC, if there's a production OC, successfully having Memcached set, why does the upgrade fail? Is this a bug on the upgrade process checks? A bug in the configuration? Which?

This is not an enhacement issue, it is a bug.

I work for another FLOSS project and I know it is hard to cope with all the things people report. But I think this kind of issues should have higher priority, as they are BLOCKERS for normal users.

@PVince81 PVince81 added bug and removed enhancement labels Dec 7, 2016
@PVince81
Collaborator
PVince81 commented Dec 7, 2016

What are the steps to reproduce the issue ?
Setup memcache then simply upgrade ?
Is this happening with any kind of memcache server ?

@tomascohen
  • Have an up-to-date Ubuntu 14.04.5 LTS (amd64)
  • Have memcached installed and running
  • Have owncloud-files installed
  • Have memcached enabled on the config file:
    'memcache.local' => '\\OC\\Memcache\\APCu', 'memcache.distributed' => '\\OC\\Memcache\\Memcached', 'memcached_servers' => array ( 0 => array ( 0 => 'localhost', 1 => 11211, ), ),
  • upgrade using plain apt update ; apt upgrade
  • perform the needed occ upgrade step:
    $ cd /var/www/owncloud ; sudo -u www-data php occ upgrade
    => FAIL: You get Exception: Error 21 interacting with memcached : SERVER END
  • Remove the memcache.* entries
  • perform the needed occ upgrade step:
    $ cd /var/www/owncloud ; sudo -u www-data php occ upgrade
    => SUCCESS: Upgrade completes correctly
  • Put the memcached config back
  • The UI doesn't show any problems:

image

CONCLUSION: Either the upgrade checks are wrong or the production UI is wrongly hidding real problems with memcache.

@PVince81
Collaborator
PVince81 commented Dec 8, 2016

@VicDeo can you have a look ?

@VicDeo VicDeo was assigned by PVince81 Dec 8, 2016
@PVince81 PVince81 added the sev2-high label Dec 8, 2016
@PVince81 PVince81 added this to the 10.0 milestone Dec 8, 2016
@VicDeo
Member
VicDeo commented Dec 8, 2016

@tomascohen

-1 for OC not reporting the problem to the end user (yield in a void in which it cannot complete the upgrade and the last resort is to google for the message).

Googling is better than tail data/owncloud.log? why?

@VicDeo
Member
VicDeo commented Dec 8, 2016 edited

Got the trace

{
"reqId":"X+XiCPNQz\/++UpHvwjJo","remoteAddr":"","app":"core","message":"Exception: {"Exception":"Exception","Message":"Error 21 interacting with memcached : SERVER END","Code":0,"Trace":"
#0 /opt/owncloud/lib/private/Memcache/Memcached.php(112): OC\Memcache\Memcached->verifyReturnCode()
#1 /opt/owncloud/lib/private/IntegrityCheck/Checker.php(449): OC\Memcache\Memcached->set('oc.integrityche...', '[]')
#2 /opt/owncloud/lib/private/IntegrityCheck/Checker.php(511): OC\IntegrityCheck\Checker->storeResults('comments', Array)
#3 /opt/owncloud/lib/private/IntegrityCheck/Checker.php(586): OC\IntegrityCheck\Checker->verifyAppSignature('comments')
#4 /opt/owncloud/lib/private/Updater.php(275): OC\IntegrityCheck\Checker->runInstanceVerification()
#5 /opt/owncloud/lib/private/Updater.php(150): OC\Updater->doUpgrade('9.1.2.5', '9.1.1.3')
#6 /opt/owncloud/core/Command/Upgrade.php(290): OC\Updater->upgrade()
#7 /opt/owncloud/3rdparty/symfony/console/Command/Command.php(259): OC\Core\Command\Upgrade->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /opt/owncloud/3rdparty/symfony/console/Application.php(844): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#9 /opt/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OC\Core\Command\Upgrade), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#10 /opt/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#11 /opt/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(NULL, NULL)\
#12 /opt/owncloud/console.php(102): OC\Console\Application->run()
#13 /opt/owncloud/occ(11): require_once('/opt/owncloud/c...')
#14 {main}","File":"/opt/owncloud/lib/private/Memcache/Memcached.php","Line":219}","level":3,"time":"2016-12-08T21:44:14+00:00","method":"--","url":"--","user":"--"
}

Might be related to the fact that APCu extension is not enabled for php-cli by default.

@VicDeo
Member
VicDeo commented Dec 8, 2016 edited

@PVince81 No need to fire an update. Reproducible by running an integrity check from CLI with enabled memcached.
Because integrity check uses cache to store results.

I'm not an memcached expert, but it looks like a bug in validation:

  1. http://php.net/manual/en/memcached.set.php
    Returns TRUE on success or FALSE on failure. Use Memcached::getResultCode() if necessary.

We always do Memcached::getResultCode():

	public function set($key, $value, $ttl = 0) {
		if ($ttl > 0) {
			$result =  self::$cache->set($this->getNamespace() . $key, $value, $ttl);
		} else {
			$result = self::$cache->set($this->getNamespace() . $key, $value);
		}
		$this->verifyReturnCode();
		return $result;
	}
        ...
	private function verifyReturnCode() {
		$code = self::$cache->getResultCode();
		if ($code === \Memcached::RES_SUCCESS) {
			return;
		}
		$message = self::$cache->getResultMessage();
		throw new \Exception("Error $code interacting with memcached : $message");
	}
  1. and here comes another part of the show. Our default options:
			$defaultOptions = [
				\Memcached::OPT_CONNECT_TIMEOUT => 50,
                                ...
				// Enable Binary Protocol
				\Memcached::OPT_BINARY_PROTOCOL =>      true,
			];

apparently \Memcached::OPT_BINARY_PROTOCOL => true,

as per http://php.net/manual/en/memcached.cas.php#97603
MEMCACHED_END (code 21) is a valid response for binary mode

but this is for Memcached::cas and I'm unsure about Memcached::set

as a workaround
\Memcached::OPT_BINARY_PROTOCOL => true,
can be changed
\Memcached::OPT_BINARY_PROTOCOL => false,

@PVince81
Collaborator
PVince81 commented Dec 9, 2016

I also heard somone say that the APCu cache for CLI and web server are completely separate. So maybe when upgrading we should just disable APCu completely as it is unlikely to be useful at all as it has no access to the stuff cached by the web server ?

@PVince81
Collaborator
PVince81 commented Dec 9, 2016

actually we could even disable APCu for ALL commands:

  • occ upgrade
  • integrity check
  • cron (well, unless there bkg jobs cache stuff that they could reuse through the next runs)
@ghost
ghost commented Dec 9, 2016

Side-note: This issue here is about Memcached as the cache.

For Memcached and Redis it makes sense to keep it for all commands as this cache is shared between cli and webserver.

@VicDeo
Member
VicDeo commented Dec 9, 2016

@RealRancor By any chance do you have an idea why this could happen?
This is being logged on a failure:

<28 SET 3cd763eff299c60562737c6f40cbb0af/oc.integritycheck.checkeroc.integritycheck.checker Value len is 530
>28 Writing bin response:
>28   0x81 0x01 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x06
<28 Read binary protocol data:
<28    0x80 0x07 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
>28 Writing bin response:
>28   0x81 0x07 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
>28   0x00 0x00 0x00 0x00
Failed to write, and not due to blocking: Broken pipe

It seems to me that php-memcached unexpectedly closes a connection to the memcached server.

@VicDeo
Member
VicDeo commented Dec 9, 2016

ok.

<28 Read binary protocol data:
<28    0x80 0x07 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00
<28    0x00 0x00 0x00 0x00

is a quit command. https://github.com/memcached/memcached/wiki/BinaryProtocolRevamped#command-opcodes. So memcached server is obeying to it.

@ghost
ghost commented Dec 10, 2016

@VicDeo Sorry, don't have any experience with memcached.

@butonic butonic closed this in #26816 Dec 15, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment