Fix null pointer exception in user_ldap #25062

Merged
merged 1 commit into from Jun 21, 2016

Projects

None yet

4 participants

@butonic
Member
butonic commented Jun 10, 2016 edited

This will prevent upgrade experiences like this:

I tried to prepare our next upgrade from 8.2.5 to 9.0.2. The occ-script 
is throwing an error: 

[root@owncloud owncloud_9.0.2]# php55 occ -vvv upgrade 
--skip-migration-test 
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 
2016-06-06T11:20:43+02:00 Set log level to debug 
2016-06-06T11:20:43+02:00 Turned on maintenance mode 
2016-06-06T11:20:43+02:00 Repair step: Repair MySQL database engine 
2016-06-06T11:20:43+02:00 Repair step: Repair MySQL collation 
2016-06-06T11:20:43+02:00 Repair step: Repair SQLite autoincrement 
2016-06-06T11:20:43+02:00 Repair step: Repair duplicate entries in 
oc_lucene_status 
2016-06-06T11:20:43+02:00 Repair info: lucene_status table does not 
exist -> nothing to do 
2016-06-06T11:20:43+02:00 Updating database schema 
2016-06-06T11:20:44+02:00 Updated database 
2016-06-06T11:20:44+02:00 Disabled 3rd-party app: files_videoviewer 
2016-06-06T11:20:44+02:00 Disabled 3rd-party app: updater 
2016-06-06T11:20:44+02:00 Updating <files_pdfviewer> ... 
2016-06-06T11:20:44+02:00 Updated <files_pdfviewer> to 0.8.1 
2016-06-06T11:20:44+02:00 Updating <files_texteditor> ... 
2016-06-06T11:20:44+02:00 Updated <files_texteditor> to 2.1 
2016-06-06T11:20:44+02:00 Updating <gallery> ... 
2016-06-06T11:20:44+02:00 Updated <gallery> to 14.5.0 
2016-06-06T11:20:44+02:00 Updating <user_ldap> ... 
2016-06-06T11:20:44+02:00 Updated <user_ldap> to 0.8.0 
2016-06-06T11:20:44+02:00 Updating <files> ... 
2016-06-06T11:20:44+02:00 Updated <files> to 1.4.4 
2016-06-06T11:20:44+02:00 Updating <activity> ... 
2016-06-06T11:20:44+02:00 Updated <activity> to 2.2.1 
2016-06-06T11:20:44+02:00 Updating <files_sharing> ... 
2016-06-06T11:20:44+02:00 Updated <files_sharing> to 0.9.1 
2016-06-06T11:20:44+02:00 Updating <files_trashbin> ... 
2016-06-06T11:20:44+02:00 Updated <files_trashbin> to 0.8.0 
2016-06-06T11:20:44+02:00 Updating <files_versions> ... 
2016-06-06T11:20:44+02:00 Updated <files_versions> to 1.2.0 
2016-06-06T11:20:44+02:00 Updating <firewall> ... 
2016-06-06T11:20:44+02:00 Updated <firewall> to 2.3.0 
2016-06-06T11:20:44+02:00 Updating <notifications> ... 
2016-06-06T11:20:44+02:00 Updated <notifications> to 0.2.3 
2016-06-06T11:20:44+02:00 Updating <provisioning_api> ... 
2016-06-06T11:20:44+02:00 Updated <provisioning_api> to 0.4.1 
2016-06-06T11:20:44+02:00 Updating <admin_audit> ... 
2016-06-06T11:20:44+02:00 Updated <admin_audit> to 0.7 
PHP Fatal error: Call to a member function processAttributes() on a 
non-object in 
/var/www/html/owncloud_9.0.2/apps/user_ldap/lib/access.php 
on line 733 
[root@owncloud owncloud_9.0.2]# 

Leaves the qestion why do we get null from the ldap user manager ...

00005599

@DeepDiver1975 DeepDiver1975 added this to the 9.1-current milestone Jun 10, 2016
@PVince81
Collaborator

@butonic can you rerun it on the failed environment ? For which user did it return null ? Maybe it was a disabled/obsoleted/stray user ?

@butonic
Member
butonic commented Jun 10, 2016

It is a test environment. Will see what we can find out...

@PVince81
Collaborator
PVince81 commented Jun 10, 2016 edited

So far I'm worried that we might be skipping legitimate users. But if those are broken/deleted users then your PR would be fine.

@PVince81
Collaborator
@michaelstingl

@butonic A user applied the patch and provided feedback: 00005599

@butonic
Member
butonic commented Jun 13, 2016

with the new patch the update completes fine. asked them to classify the users that are logged with this PR

@PVince81
Collaborator

@michaelstingl mind posting the (anonymized) feedback here, if possible ?

@michaelstingl

@PVince81 As @butonic described, after he patched the patch, the upgrade worked fine.

@michaelstingl

@butonic I've got the log from the latest upgrade:
s3.owncloud.com_owncloud/Shared/owncloud/support/github-issues/core/25062/owncloud.log.zip

Could you check for disabled/obsoleted/stray users?

@PVince81
Collaborator

This PR could also help with #24733 (non-update case)

@DeepDiver1975
Member

squashed and rebased

@DeepDiver1975
Member

πŸ‘

@DeepDiver1975 DeepDiver1975 commented on an outdated diff Jun 21, 2016
apps/user_ldap/lib/Access.php
@@ -732,7 +732,14 @@ public function batchApplyUserAttributes(array $ldapRecords){
$user->unmark();
$user = $this->userManager->get($ocName);
}
- $user->processAttributes($userRecord);
+ if ($user !== null) {
+ $user->processAttributes($userRecord);
+ } else {
+ \OC::$server->getLogger()->debug(
+ "The ldap user manager retured null for $ocName",
@butonic @DeepDiver1975 butonic Fix null pointer exception in user_ldap
c0bbbd6
@PVince81
Collaborator

πŸ‘ I agree to merge. Better be more robust here and log errors in case they can help debugging.

@DeepDiver1975 DeepDiver1975 merged commit 704a993 into master Jun 21, 2016

20 of 22 checks passed

server-master-linux-externals-ci/database=sqlite,external=swift-ceph,label=SLAVE Build #11259 found unstable in 8 min 25 sec
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=test_shareLink,mirallBranch=v2.0.2,slave=SMASH Build #15573 in progress...
Details
Scrutinizer 8 new issues
Details
cla-bot-core Build #4931 succeeded in 21 sec
Details
continuous-integration/php-5.4 Build #5137 succeeded in 6 min 12 sec
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
core-ci-linux-jsunit/database=sqlite,label=SLAVE Build #63020 succeeded in 50 sec
Details
core-ci-linux/database=mysql,label=SLAVE Build #31934 succeeded in 17 min
Details
core-ci-linux/database=oci,label=SLAVE Build #31934 succeeded in 54 min
Details
core-ci-linux/database=pgsql,label=SLAVE Build #31934 succeeded in 16 min
Details
core-ci-linux/database=sqlite,label=SLAVE Build #31934 succeeded in 7 min 22 sec
Details
ocs-api-integration-tests-ci Build #11754 succeeded in 11 min
Details
server-master-linux-externals-ci/database=sqlite,external=smb-silvershell,label=SLAVE Build #11259 succeeded in 2 min 51 sec
Details
server-master-linux-externals-ci/database=sqlite,external=webdav-ownCloud,label=SLAVE Build #11259 succeeded in 12 min
Details
server-master-linux-externals-smb-windows-ext-ci/database=sqlite,external=smb-windows,label=master Build #22460 succeeded in 2 min 45 sec
Details
server-master-linux-php7-ci/database=sqlite,label=SLAVE Build #40251 succeeded in 3 min 23 sec
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=litmus,mirallBranch=v2.0.2,slave=SMASH Build #15573 succeeded in 9 min 22 sec
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=test_basicSync@0,mirallBranch=v2.0.2,slave=SMASH Build #15573 succeeded in 1 hr 47 min
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=test_basicSync@1,mirallBranch=v2.0.2,slave=SMASH Build #15573 succeeded in 1 hr 44 min
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=test_sharePermissions,mirallBranch=v2.0.2,slave=SMASH Build #15573 succeeded in 1 hr 40 min
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=test_sharePropagationGroups,mirallBranch=v2.0.2,slave=SMASH Build #15573 succeeded in 1 hr 15 min
Details
smashbox-on-docker-ci/DOCKER_IMAGE=ubuntu_oc_lamp-git,TEST_NAME=test_sharePropagationInsideGroups,mirallBranch=v2.0.2,slave=SMASH Build #15573 succeeded in 1 hr 22 min
Details
@DeepDiver1975 DeepDiver1975 deleted the fix-npe-in-user-ldap branch Jun 21, 2016
@michaelstingl

Could you check for disabled/obsoleted/stray users?

@butonic Have you seen something in their logs that needs to be fixed on their side?

@butonic
Member
butonic commented Jun 29, 2016

The log shows 144 occurrences where the ldap user manager returns null for a userid. @michaelstingl can they try to check if the uids exist in the oc_ldap_user_mapping table in the owncloud_name column, eg:

SELECT * FROM oc_ldap_user_mapping WHERE owncloud_name IN ('foo@bar.com', 'baz@bar.com', ...)
@butonic
Member
butonic commented Jun 29, 2016

Other than this I see a lot of

{"reqId":"o\/lf1DbXqp3ThGA8Ont3",
"remoteAddr":"",
"app":"no app in context",
"message":"
Exception: {\"Exception\":\"InvalidArgumentException\",
\"Message\":\"Card does not exists: LDAP:foo@bar.com.vcf\",
\"Code\":0,
\"Trace\":\"#0 /var/www/html/owncloud_9.0.2/apps/dav/lib/carddav/carddavbackend.php(884): OCA\DAV\CardDAV\CardDavBackend->getCardId('5', 'LDAP:foo@bar...')
#1 /var/www/html/owncloud_9.0.2/apps/dav/lib/carddav/carddavbackend.php(499): OCA\DAV\CardDAV\CardDavBackend->updateProperties('5', 'LDAP:foo@bar...', 'BEGIN:VCARD\r\\nVE...')
#2 /var/www/html/owncloud_9.0.2/apps/dav/lib/carddav/syncservice.php(225): OCA\DAV\CardDAV\CardDavBackend->createCard('5', 'LDAP:foo@bar...', 'BEGIN:VCARD\r\\nVE...')
#3 /var/www/html/owncloud_9.0.2/apps/dav/lib/hookmanager.php(99): OCA\DAV\CardDAV\SyncService->updateUser(Object(OC\User\User))
#4 [internal function]: OCA\DAV\HookManager->changeUser(Array)
#5 /var/www/html/owncloud_9.0.2/lib/private/hook.php(105): call_user_func(Array, Array)
#6 /var/www/html/owncloud_9.0.2/lib/private/server.php(244): OC_Hook::emit('OC_User', 'changeUser', Array)
#7 [internal function]: OC\Server->OC\{closure}(Object(OC\User\User), 'quota', '30 GB')
#8 /var/www/html/owncloud_9.0.2/lib/private/hooks/emittertrait.php(98): call_user_func_array(Object(Closure), Array)
#9 /var/www/html/owncloud_9.0.2/lib/private/hooks/publicemitter.php(32): OC\Hooks\BasicEmitter->emit('\\OC\\User', 'changeUser', Array)
#10 /var/www/html/owncloud_9.0.2/lib/private/user/user.php(417): OC\Hooks\PublicEmitter->emit('\\OC\\User', 'changeUser', Array)
#11 /var/www/html/owncloud_9.0.2/lib/private/user/user.php(364): OC\User\User->triggerChange('quota', '30 GB')
#12 /var/www/html/owncloud_9.0.2/apps/user_ldap/lib/user/user.php(465): OC\User\User->setQuota('30 GB')
#13 /var/www/html/owncloud_9.0.2/apps/user_ldap/lib/user/user.php(160): OCA\user_ldap\lib\user\User->updateQuota('30 GB')
#14 /var/www/html/owncloud_9.0.2/apps/user_ldap/lib/access.php(734): OCA\user_ldap\lib\user\User->processAttributes(Array)
#15 /var/www/html/owncloud_9.0.2/apps/user_ldap/lib/access.php(706): OCA\user_ldap\lib\Access->batchApplyUserAttributes(Array)
#16 /var/www/html/owncloud_9.0.2/apps/user_ldap/user_ldap.php(192): OCA\user_ldap\lib\Access->fetchListOfUsers('(&(|(objectclas...', Array, 500, 500)
#17 /var/www/html/owncloud_9.0.2/lib/private/user/manager.php(337): OCA\user_ldap\USER_LDAP->getUsers('', 500, 500)
#18 /var/www/html/owncloud_9.0.2/apps/dav/lib/carddav/syncservice.php(269): OC\User\Manager->callForAllUsers(Object(Closure))
#19 /var/www/html/owncloud_9.0.2/apps/dav/lib/carddav/syncjob.php(38): OCA\DAV\CardDAV\SyncService->syncInstance()
#20 /var/www/html/owncloud_9.0.2/lib/private/backgroundjob/job.php(52): OCA\DAV\CardDAV\SyncJob->run(NULL)
#21 /var/www/html/owncloud_9.0.2/lib/private/backgroundjob/timedjob.php(53): OC\BackgroundJob\Job->execute(Object(OC\BackgroundJob\JobList), Object(OC\Log))
#22 /var/www/html/owncloud_9.0.2/cron.php(145): OC\BackgroundJob\TimedJob->execute(Object(OC\BackgroundJob\JobList), Object(OC\Log))
#23 {main}\",\"File\":\"/var/www/html/owncloud_9.0.2/apps/dav/lib/carddav/carddavbackend.php\",
\"Line\":961}",
"level":3,
"time":"2016-06-13T12:04:17+00:00",
"method":"--",
"url":"--",
"user":"--"}

@DeepDiver1975 this happens during the migration ... critical or can be ignored?

@butonic
Member
butonic commented Jun 29, 2016 edited

also:

{"reqId":"...","remoteAddr":"128.176.190.117","app":"PHP","message":"hash_file(\/var\/www\/html\/owncloud_9.0.2\/apps\/user_ldap\/lib\/access.php.orig): failed to open stream: Permission denied at \/var\/www\/html\/owncloud_9.0.2\/lib\/private\/integritycheck\/checker.php#224","level":3,"time":"2016-06-13T12:01:24+00:00","method":"GET","url":"\/settings\/integrity\/rescan?requesttoken=...","user":"adminUser"}

indicates a patched 9.0.2 was used. the error will go away with 9.0.3.

@DeepDiver1975
Member

@DeepDiver1975 this happens during the migration ... critical or can be ignored?

worth a look - I'll take care

@DeepDiver1975
Member

@butonic @michaelstingl which dbms is used there?

@butonic
Member
butonic commented Jun 29, 2016

@DeepDiver1975 they use a galera cluster

@DeepDiver1975
Member

@DeepDiver1975 they use a galera cluster

hmmm .... this might explain why the card cannot be selected from the db after insert?

@michaelstingl
michaelstingl commented Jun 30, 2016 edited

@butonic @DeepDiver1975 Here is a investigation about the LDAP users that caused the trouble:
/Shared/owncloud/support/github-issues/core/25062/ldap-user-investigation.txt

This shows nothing unexpected.

What next?

@butonic
Member
butonic commented Jul 1, 2016

@michaelstingl do we have the results of #25062 (comment)

@michaelstingl

@butonic No, but I will ask…

@michaelstingl
michaelstingl commented Jul 1, 2016 edited

@michaelstingl do we have the results of #25062 (comment)

Here is the output:
Shared/owncloud/support/github-issues/core/25062/oc_ldap_user_mapping.txt

I think, this all looks good. Doesn't it?

@butonic
Member
butonic commented Jul 1, 2016

The mappings are all there ... looks fine.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment