After upgrade to 8.1.1 enabling apps take down owncloud

[kalletabur]

Steps to reproduce

1. Have 8.0.2 owncloud with encryption
2. Upgrade to 8.1.1 (enable memcache, migrate keys etc) so everything works (tested most ordinary stuff, also tested Federated Cloud ID)
3. Go to Apps -> Productivity enable Documents app + enable News app

Expected behaviour

Documents apps should be working, News app should be working as normal

Actual behaviour

After enabling Documents app I wanted to verify that app is enabled (on 8.0.4 Documents app was impossible to enable), going to Enabled tab show empty page. Going to another App/Conf page (Files app, Admin page) triggers some new update - User is thrown out and Owncloud Update page is shown. When "Update" is finished and user is let in. Now after going to enable News app owncloud is unresponsible - pages are empty even when going to URL with an another browser

Reloading services or system reboot don't fix

News app wasn't actually important. I just wanted to test whether owncloud starts again updating process - it didn't .. instead disabled owncloud. Maybe installing other apps don't disable owncloud or maybe they do.

Server configuration

Operating system:
Debian 7.8

Web server:
NGINX 1.2.1-2.2+wheezy3

Database:
MySQL 5.5.44-0+deb7u1

PHP version:
PHP 5.4.41-0+deb7u1

ownCloud version: (see ownCloud admin page)
8.1.1-1 (this is Debian package version .. cause web interface isn't responding)
8.1.1.3 (version from config.php)

Updated from an older ownCloud or fresh install:
8.0.2

List of activated apps:
Activity, Deleted files, External storage support, First Run Wizard, LDAP user and group backend, Mail Template Editor, PDF Viewer, Pictures, Server-side Encryption, Share Files, Text Editor, Versions, Video Viewer (taken from earlier issue - web interface is not responding and occ script not working)

Running occ scripts (app:list, config:list,occ ldap:show-config) throws exception:
sudo -u www-data php occ app:list

An unhandled exception has been thrown:
OC\HintException: [0]: Missing memcache class \OC\Memcache\APC for local cache (Is the matching PHP module installed and enabled ?)

The content of config/config.php:

<?php
$CONFIG = array (
  'instanceid' => '01010101010101',
  'passwordsalt' => '01010101010101',
  'trusted_domains' => 
  array (
    0 => 'oc.example.net',
    1 => '101.101.101.101',
  ),
  'datadirectory' => '/var/ocdatafolder/',
  'dbtype' => 'mysql',
  'version' => '8.1.1.3',
  'dbname' => 'ocdb',
  'dbhost' => 'localhost',
  'dbtableprefix' => 'ocdb_',
  'dbuser' => 'ocuser',
  'dbpassword' => '01010101010101',
  'installed' => true,
  'forcessl' => true,
  'loglevel' => '0',
  'mail_smtpmode' => 'smtp',
  'mail_smtphost' => 'oc.example.net',
  'mail_smtpport' => 25,
  'ldapIgnoreNamingRules' => false,
  'theme' => '',
  'maintenance' => false,
  'secret' => '01010101010101',
  'memcache.local' => '\OC\Memcache\APC',
);

Are you using external storage, if yes which one: local/smb/sftp/...
No

Are you using encryption:
yes

Are you using an external user-backend, if yes which one: LDAP/ActiveDirectory/Webdav/...

LDAP configuration (delete this part if not used)

|appid|configkey|configvalue|
|user_ldap|cleanUpJobOffset|600|
|user_ldap|enabled|yes|
|user_ldap|has_memberof_filter_support|1|
|user_ldap|home_folder_naming_rule||
|user_ldap|installed_version|0.5.0|
|user_ldap|last_jpegPhoto_lookup|0|
|user_ldap|ldap_agent_password||
|user_ldap|ldap_attributes_for_group_search||
|user_ldap|ldap_attributes_for_user_search||
|user_ldap|ldap_backup_host||
|user_ldap|ldap_backup_port||
|user_ldap|ldap_base|DC=example,DC=local|
|user_ldap|ldap_base_groups|DC=example,DC=local|
|user_ldap|ldap_base_users|DC=example,DC=local|
|user_ldap|ldap_cache_ttl|600|
|user_ldap|ldap_configuration_active|1|
|user_ldap|ldap_display_name|displayname|
|user_ldap|ldap_dn|CN=Comp-Ownc,OU=COM,OU=Company,DC=example,DC=local|
|user_ldap|ldap_email_attr|mail|
|user_ldap|ldap_experienced_admin|0|
|user_ldap|ldap_expert_username_attr|sAMAccountName|
|user_ldap|ldap_expert_uuid_group_attr||
|user_ldap|ldap_expert_uuid_user_attr||
|user_ldap|ldap_group_display_name|cn|
|user_ldap|ldap_group_filter|(&(|(objectclass=group))(|(cn=Dev)(CN=Comp-Ownc)(cn=Comp-admis)))|
|user_ldap|ldap_group_filter_mode|0|
|user_ldap|ldap_group_member_assoc_attribute|member|
|user_ldap|ldap_groupfilter_groups|Comp-DevComp-Owncloud Comp-admis|
|user_ldap|ldap_groupfilter_objectclass|group|
|user_ldap|ldap_host|dc300|
|user_ldap|ldap_login_filter|(&(&(|(objectclass=person))(|(memberof=CN=Comp-Ownc,OU=DL,OU=Company,DC=example,DC=local)(memberof=CN=Comp-Dev,OU=DL,OU=Company,DC=example,DC=local)(memberof=CN=Comp-admis,OU=DL,OU=Company,DC=example,DC=local)))(samaccountname=%uid))|
|user_ldap|ldap_login_filter_mode|0|
|user_ldap|ldap_loginfilter_attributes||
|user_ldap|ldap_loginfilter_email|0|
|user_ldap|ldap_loginfilter_username|1|
|user_ldap|ldap_nested_groups|0|
|user_ldap|ldap_nocase|1|
|user_ldap|ldap_override_main_server|0|
|user_ldap|ldap_paging_size|500|
|user_ldap|ldap_port|389|
|user_ldap|ldap_quota_attr||
|user_ldap|ldap_quota_def||
|user_ldap|ldap_tls|0|
|user_ldap|ldap_turn_off_cert_check|1|
|user_ldap|ldap_user_filter_mode|1|
|user_ldap|ldap_userfilter_groups||
|user_ldap|ldap_userfilter_objectclass||
|user_ldap|ldap_userlist_filter|(&(|(objectclass=person))(|(memberof=CN=Comp-Ownc,OU=DL,OU=Company,DC=example,DC=local)(memberof=CN=Comp-Dev,OU=DL,OU=Company,DC=example,DC=local)(memberof=CN=Comp-SystemAdministrators,OU=DL,OU=Company,DC=example,DC=local)))|
|user_ldap|ocsid|166061|
|user_ldap|types|authentication|

Client configuration

Browser:
Chrome, FF

Operating system:
Ubuntu 14

Logs

Web server error log

error.log
2015/08/14 10:12:55 [error] 8191#0: *351 access forbidden by rule, client: 101.101.101.101, server: oc.example.net, request: "GET /data/htaccesstest.txt HTTP/1.1", host: "oc.example.net"
2015/08/14 10:16:25 [error] 8191#0: *389 FastCGI sent in stderr: "PHP message: PHP Parse error:  syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /var/www/owncloud/apps/news/appinfo/application.php on line 51" while reading response header from upstream, client: 192.168.1.4, server: oc.example.net, request: "GET /index.php/settings/ajax/navigationdetect.php?app=168040 HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "oc.example.net", referrer: "https://oc.example.net/index.php/settings/apps"

access.log
192.168.1.4 - - [14/Aug/2015:12:35:19 +0000] "GET / HTTP/1.1" 500 5 "-" "Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:40.0) Gecko/20100101 Firefox/40.0"

ownCloud log (data/owncloud.log)

Going to Apps app

enable documents app

Upgrade

{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"core","message":"starting upgrade from 8.1.1.3 to 8.1.1.3","level":0,"time":"2015-08-14T10:12:33+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}
{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"PHP","message":"Cannot modify header information - headers already sent by (output started at \/var\/www\/owncloud\/lib\/private\/eventsource.php:99) at \/var\/www\/owncloud\/lib\/private\/user\/session.php#306","level":3,"time":"2015-08-14T10:12:37+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}
{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"PHP","message":"Cannot modify header information - headers already sent by (output started at \/var\/www\/owncloud\/lib\/private\/eventsource.php:99) at \/var\/www\/owncloud\/lib\/private\/user\/session.php#307","level":3,"time":"2015-08-14T10:12:37+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}
{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"PHP","message":"Cannot modify header information - headers already sent by (output started at \/var\/www\/owncloud\/lib\/private\/eventsource.php:99) at \/var\/www\/owncloud\/lib\/private\/user\/session.php#308","level":3,"time":"2015-08-14T10:12:37+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}
{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"PHP","message":"Cannot modify header information - headers already sent by (output started at \/var\/www\/owncloud\/lib\/private\/eventsource.php:99) at \/var\/www\/owncloud\/lib\/private\/user\/session.php#311","level":3,"time":"2015-08-14T10:12:37+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}
{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"PHP","message":"Cannot modify header information - headers already sent by (output started at \/var\/www\/owncloud\/lib\/private\/eventsource.php:99) at \/var\/www\/owncloud\/lib\/private\/user\/session.php#312","level":3,"time":"2015-08-14T10:12:37+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}
{"reqId":"zF4ay1CAKcOrp0yKkE+x","remoteAddr":"192.168.1.4","app":"PHP","message":"Cannot modify header information - headers already sent by (output started at \/var\/www\/owncloud\/lib\/private\/eventsource.php:99) at \/var\/www\/owncloud\/lib\/private\/user\/session.php#313","level":3,"time":"2015-08-14T10:12:37+00:00","method":"GET","url":"\/core\/ajax\/update.php?requesttoken=01010101010101"}



After upgrade is finished

{"reqId":"Z\/ooh7DELn3cf1nNUPHH","remoteAddr":"192.168.1.4","app":"PHP","message":"Declaration of OCA\\Files_Sharing\\External\\Scanner::scanFile() should be compatible with OC\\Files\\Cache\\Scanner::scanFile($file, $reuseExisting = 0, $parentId = -1, $cacheData = NULL, $lock = true) at \/var\/www\/owncloud\/apps\/files_sharing\/lib\/external\/scanner.php#121","level":3,"time":"2015-08-14T10:12:53+00:00","method":"PROPFIND","url":"\/remote.php\/webdav"}
{"reqId":"Z\/ooh7DELn3cf1nNUPHH","remoteAddr":"192.168.1.4","app":"files_external","message":"Unauthorized","level":3,"time":"2015-08-14T10:12:53+00:00","method":"PROPFIND","url":"\/remote.php\/webdav"}
{"reqId":"Z\/ooh7DELn3cf1nNUPHH","remoteAddr":"192.168.1.4","app":"files_external","message":"Unauthorized","level":3,"time":"2015-08-14T10:12:54+00:00","method":"PROPFIND","url":"\/remote.php\/webdav"}
{"reqId":"Z\/ooh7DELn3cf1nNUPHH","remoteAddr":"192.168.1.4","app":"files_external","message":"Unauthorized","level":3,"time":"2015-08-14T10:12:54+00:00","method":"PROPFIND","url":"\/remote.php\/webdav"}
{"reqId":"Z\/ooh7DELn3cf1nNUPHH","remoteAddr":"192.168.1.4","app":"files_external","message":"Unauthorized","level":3,"time":"2015-08-14T10:12:54+00:00","method":"PROPFIND","url":"\/remote.php\/webdav"}
{"reqId":"Z\/ooh7DELn3cf1nNUPHH","remoteAddr":"192.168.1.4","app":"files_external","message":"Unauthorized","level":3,"time":"2015-08-14T10:12:55+00:00","method":"PROPFIND","url":"\/remote.php\/webdav"}
{"reqId":"YZcdD9hwZyKsXkDrBL8P","remoteAddr":"192.168.1.4","app":"PHP","message":"Declaration of OCA\\Files_Sharing\\External\\Scanner::scanFile() should be compatible with OC\\Files\\Cache\\Scanner::scanFile($file, $reuseExisting = 0, $parentId = -1, $cacheData = NULL, $lock = true) at \/var\/www\/owncloud\/lib\/autoloader.php#133","level":3,"time":"2015-08-14T10:13:16+00:00","method":"GET","url":"\/index.php\/apps\/files\/ajax\/scan.php?force=false&dir=&requesttoken=01010101010101"}
{"reqId":"l2NX8n6418UrTX1e\/JfH","remoteAddr":"192.168.1.4","app":"core","message":"Exception while scanning storage \"webdav::user1@oc.example.net\/\/remote.php\/webdav\/testisiinmidagi\/\": Sabre\\HTTP\\ClientHttpException: Not Found","level":3,"time":"2015-08-14T10:13:16+00:00","method":"GET","url":"\/index.php\/apps\/files\/ajax\/list.php?dir=%2F&sort=name&sortdirection=asc"}



going to Apps app

{"reqId":"+TGW\/miud\/8\/sTLvPWit","remoteAddr":"192.168.1.4","app":"core","message":"No update found at the ownCloud appstore for app 166056","level":1,"time":"2015-08-14T13:17:36+03:00","method":"GET","url":"\/index.php\/settings\/apps\/list?category=0&includeUpdateInfo=1"}
{"reqId":"+TGW\/miud\/8\/sTLvPWit","remoteAddr":"192.168.1.4","app":"core","message":"No update found at the ownCloud appstore for app 166051","level":1,"time":"2015-08-14T13:17:37+03:00","method":"GET","url":"\/index.php\/settings\/apps\/list?category=0&includeUpdateInfo=1"}
{"reqId":"+TGW\/miud\/8\/sTLvPWit","remoteAddr":"192.168.1.4","app":"core","message":"No update found at the ownCloud appstore for app 166055","level":1,"time":"2015-08-14T13:17:37+03:00","method":"GET","url":"\/index.php\/settings\/apps\/list?category=0&includeUpdateInfo=1"}
{"reqId":"+TGW\/miud\/8\/sTLvPWit","remoteAddr":"192.168.1.4","app":"core","message":"No update found at the ownCloud appstore for app 166049","level":1,"time":"2015-08-14T13:17:37+03:00","method":"GET","url":"\/index.php\/settings\/apps\/list?category=0&includeUpdateInfo=1"}


enable news app


{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder\/news\/vendor\/bin): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#466","level":3,"time":"2015-08-14T13:18:21+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder\/news\/vendor): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#466","level":3,"time":"2015-08-14T13:18:21+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder\/\/news): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#472","level":3,"time":"2015-08-14T13:18:21+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"unlink(): No such file or directory at \/var\/www\/owncloud\/lib\/private\/helper.php#468","level":3,"time":"2015-08-14T13:18:22+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder\/news\/vendor\/bin): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#466","level":3,"time":"2015-08-14T13:18:22+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder\/news\/vendor): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#466","level":3,"time":"2015-08-14T13:18:22+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder\/news): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#466","level":3,"time":"2015-08-14T13:18:22+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"\/fHE6qHLAGQI\/dL5Q2PX","remoteAddr":"192.168.1.4","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_6KZ57e-folder): Directory not empty at \/var\/www\/owncloud\/lib\/private\/helper.php#472","level":3,"time":"2015-08-14T13:18:22+03:00","method":"POST","url":"\/index.php\/settings\/ajax\/enableapp.php"}
{"reqId":"EBE22M6eP1gmvWVG+757","remoteAddr":"192.168.1.4","app":"user_ldap","message":"Turned off SSL certificate validation successfully.","level":0,"time":"2015-08-14T13:18:22+03:00","method":"GET","url":"\/index.php\/settings\/ajax\/navigationdetect.php?app=168040"}
{"reqId":"EBE22M6eP1gmvWVG+757","remoteAddr":"192.168.1.4","app":"user_ldap","message":"initializing paged search for  Filter objectClass=* base Array\n(\n    [0] => cn=user1,ou=example,dc=local\n)\n attr Array\n(\n    [0] => \n)\n limit 500 offset 0","level":0,"time":"2015-08-14T13:18:22+03:00","method":"GET","url":"\/index.php\/settings\/ajax\/navigationdetect.php?app=168040"}
{"reqId":"EBE22M6eP1gmvWVG+757","remoteAddr":"192.168.1.4","app":"user_ldap","message":"Ready for a paged search","level":0,"time":"2015-08-14T13:18:22+03:00","method":"GET","url":"\/index.php\/settings\/ajax\/navigationdetect.php?app=168040"}
{"reqId":"EBE22M6eP1gmvWVG+757","remoteAddr":"192.168.1.4","app":"user_ldap","message":"readAttribute: cn=user1,ou=example,dc=local found","level":0,"time":"2015-08-14T13:18:22+03:00","method":"GET","url":"\/index.php\/settings\/ajax\/navigationdetect.php?app=168040"}
{"reqId":"EBE22M6eP1gmvWVG+757","remoteAddr":"192.168.1.4","app":"PHP","message":"syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' at \/var\/www\/owncloud\/apps\/news\/appinfo\/application.php#51","level":3,"time":"2015-08-14T13:18:22+03:00","method":"GET","url":"\/index.php\/settings\/ajax\/navigationdetect.php?app=168040"}


go to enable tab -> screen empty

{"reqId":"xvrTmzMnA5AqAK4X8YR5","remoteAddr":"192.168.1.4","app":"PHP","message":"syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' at \/var\/www\/owncloud\/apps\/news\/appinfo\/application.php#51","level":3,"time":"2015-08-14T13:18:39+03:00","method":"GET","url":"\/index.php\/settings\/apps\/list?category=0&includeUpdateInfo=0"}
{"reqId":"5ndD5HGBr4xmqV4XuJTs","remoteAddr":"192.168.1.4","app":"PHP","message":"syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' at \/var\/www\/owncloud\/apps\/news\/appinfo\/application.php#51","level":3,"time":"2015-08-14T13:18:39+03:00","method":"GET","url":"\/index.php\/settings\/apps\/list?category=0&includeUpdateInfo=1"}


go to files app -> screen empty

going to new browser

{"reqId":"d23zVZs3llFIuSdJzOAi","remoteAddr":"192.168.1.4","app":"PHP","message":"syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' at \/var\/www\/owncloud\/apps\/news\/appinfo\/application.php#51","level":3,"time":"2015-08-14T13:21:21+03:00","method":"GET","url":"\/favicon.ico"}

Screenshots

[MorrisJobke]

Related to #18224

@LukasReschke You worked on the app management code recently. Can we combine re-activation and upgrade of an app in app management?

[MorrisJobke]

cc @DeepDiver1975

[BernhardPosselt]

My guess is that the app.php gets loaded after an app update even if the requirements in the info.xml are not met

[BernhardPosselt]

Linking relevant issue owncloud-archive/news#838

[tflidd]

I have seen the same problem on my test-machine (Debian 7/Apache/PHP 5.4.x/MySQL), upgrade to 8.1.1 (from 8.1.0) via SuSE-repo, that was ok. Owncloud broke after upgrade of News app to latest version.
So news-app requires php 5.5 but for some reason, the php version is not checked before installing this app.

Disabling via occ-command (sudo -u www-data....) fails as well:
PHP Parse error: syntax error, unexpected 'class' (T_CLASS), expecting identifier (T_STRING) or variable (T_VARIABLE) or '{' or '$' in /var/www/owncloud/apps/news/appinfo/application.php on line 51
That is really a very bad user experience. I needed to disable the news-app in the database:
UPDATE owncloud.appconfigSETconfigvalue= 'no' WHEREappconfig.appid= 'news' ANDappconfig.configkey = 'enabled';

[tflidd]

A small follow up: there is still the background-job in the database causing errors when executing the cron.
The apps-menu is not really consistent. In the section non-activated apps, news is listed with a warning of the php version:

I would expect a similar warning in the multimedia section but there is no warning at all:

[MorrisJobke]

cc @LukasReschke

[kalletabur]

As I see it might be related to News 6.0.0 breaks owncloud. Ok but how should I now disable News (or any app) if it breaks owncloud?

[BernhardPosselt]

@kalletabur according to @PVince81 this should work in the top owncloud directory:

./occ app:disable news