Need help on migration from OC 8.2.10 to NC 9.0.56

stannum · February 16, 2017, 10:43am

Faced with weird problem during upgrade/migration from Owncloud installation to Nextcloud. All done according admin manual, but after > sudo -s www-data php ./occ updgrade
got stuck:

Nextcloud 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)
Checked database schema update
Checking updates of apps
Checking whether the database schema for <activity> can be updated (this can take a long time depending on the database size)
Checking whether the database schema for <files_sharing> can be updated (this can take a long time depending on the database size)
Checking whether the database schema for <files_trashbin> can be updated (this can take a long time depending on the database size)
Checking whether the database schema for <user_ldap> can be updated (this can take a long time depending on the database size)
Checked database schema update for apps
Updating database schema
Updated database
Disabled 3rd-party app: calendar
Disabled 3rd-party app: contacts
Disabled 3rd-party app: files_videoviewer
Updating <files_pdfviewer> ...
Updated <files_pdfviewer> to 0.8.1
Updating <files_texteditor> ...
Updated <files_texteditor> to 2.1
Updating <gallery> ...
Updated <gallery> to 14.5.0
Updating <user_ldap> ...
Updated <user_ldap> to 0.8.0
Updating <files> ...
Updated <files> to 1.4.4
Updating <activity> ...
Updated <activity> to 2.2.1
Updating <files_sharing> ...
Updated <files_sharing> to 0.9.1
Updating <files_trashbin> ...
Updated <files_trashbin> to 0.8.0
Updating <files_versions> ...
Updated <files_versions> to 1.2.0
Updating <provisioning_api> ...
Updated <provisioning_api> to 0.4.1
Update 3rd-party app: calendar
Update 3rd-party app: contacts

this is what in data/owncloud.log

{"reqId":"Iv2KTKXlMkUG1m8Q9JO4","remoteAddr":"","app":"core","message":"starting upgrade from 8.2.10.2 to 9.0.56.2","level":0,"time":"2017-02-16T13:17:48+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"Iv2KTKXlMkUG1m8Q9JO4","remoteAddr":"","app":"core","message":"No update found at the Nextcloud appstore for app 166054","level":0,"time":"2017-02-16T13:18:19+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"Iv2KTKXlMkUG1m8Q9JO4","remoteAddr":"","app":"user_ldap","message":"getUsers: Options: search  limit 500 offset 0 Filter: (&(&(objectCategory=person)(mail=*)(objectClass=user))(displayname=*)(displayname=*))","level":0,"time":"2017-02-16T13:18:20+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}

Since my installation is on VMware VM I took snaphot before whole process and so I can do any of steps anytime, And I have already tried many times but always get the same result, even tried to run occ upgrade for 12 hours - no luck - process never ends succeessful, it simply NEVER ends…

System/Soft versions:
OS: Debian Jessie 8
PHP 5.6
Apache 2.2
MariaDB 10.0.29

stannum · February 16, 2017, 11:53am

Ok. Now I’ve tried to do same thing but after disconnecting virtual “patch-cord” from vnic and prceed all from VM Console and now it seems to completed but now it shows me message about integrity problem.

stannum · February 16, 2017, 11:58am

Integrity problem is bug?
When run

sudo -u www-data php /var/www/nextcloud/occ integrity:check-core
      - INVALID_HASH:
        - .htaccess:
          - expected: 4a97aae4d05df89a28bf2e63fe2a31cdf2afe74d3c9f622afb581d6b0f1f4e001639c7c3a31d7aaa793c00d5f355e0bfaad62ec45507245de441cfc552115cd7
          - current: 280a3be281226943d26139fab2602eb6d9e59c6fef6c921ab071890e0de1f1bfe51b572db366f0c6017286dfe4d45aea45296583567c4246c868f6f2d2a7ae62

So I definitely tuned my .htaccess accordingly to options described in config.sample.php but why it reports me error about IT?

stannum · February 16, 2017, 12:04pm

Finally I think I found what causes to STUCK upgrade/migration process - occ making huge amount of LDAP queries because of my LDAP/AD directory contains something about 80000 users an it query each of them with portions of 500 each single moment.

I found this during upgrade from NC 9.0.56 to CC 10 and occ there has nice TUI that show whole process very clear:

Nextcloud 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
Turned on maintenance mode
Checking whether the database schema can be updated (this can take a long time depending on the database size)
 Done
 27/27 [============================] 100%
Checked database schema update
Checking updates of apps
Checking whether the database schema for <activity> can be updated (this can take a long time depending on the database size)
 Done
 2/2 [============================] 100%
Checking whether the database schema for <dav> can be updated (this can take a long time depending on the database size)
 Done
 10/10 [============================] 100%
Checking whether the database schema for <federatedfilesharing> can be updated (this can take a long time depending on the database size)
 Done
 1/1 [============================] 100%
Checking whether the database schema for <federation> can be updated (this can take a long time depending on the database size)
 Done
 1/1 [============================] 100%
Checking whether the database schema for <files_sharing> can be updated (this can take a long time depending on the database size)
 Done
 1/1 [============================] 100%
Checking whether the database schema for <files_trashbin> can be updated (this can take a long time depending on the database size)
 Done
 1/1 [============================] 100%
Checking whether the database schema for <notifications> can be updated (this can take a long time depending on the database size)
 Done
 1/1 [============================] 100%
Checking whether the database schema for <user_ldap> can be updated (this can take a long time depending on the database size)
 Done
 3/3 [============================] 100%
Checked database schema update for apps
Updating database schema
Updated database
Updating <federatedfilesharing> ...
Updated <federatedfilesharing> to 1.0.1
Updating <gallery> ...
Updated <gallery> to 15.0.1
Updating <provisioning_api> ...
Updated <provisioning_api> to 1.0.0
Updating <updatenotification> ...
Updated <updatenotification> to 1.0.1
Updating <federation> ...
Updated <federation> to 1.0.1
Updating <user_ldap> ...
Updated <user_ldap> to 1.0.1
Updating <files> ...
Updated <files> to 1.5.2
Updating <activity> ...
Updated <activity> to 2.3.2
Updating <dav> ...
Fix classification for calendar objects
 Дети Казань-Купцов Даниил Евгеньевич 
 10002/0 [------>---------------------]   0%

So the last line still growing (16502/0) and percents are still show me 0%, so I will keep eye on and will write final solution if I reach some milestone…

stannum · February 16, 2017, 1:42pm

Just posting the update, so now that step was completed in 2 hours:

<....>  < ===== look above
Updating <dav> ...
Fix classification for calendar objects
 РЦМП (кв)-ВысокаяГора Доп РЦМП
 Done                                                                                                                                                                   
 58276/58276 [============================] 100%
Updated <dav> to 1.0.1
Updating <files_sharing> ...

Updated <files_sharing> to 1.0.0
Updating <files_trashbin> ...
Updated <files_trashbin> to 1.0.0
Updating <files_versions> ...
Updated <files_versions> to 1.3.0
Updating <comments> ...
Updated <comments> to 1.0.0
Updating <notifications> ...
Updated <notifications> to 0.3.0
Updating <systemtags> ...
Updated <systemtags> to 1.0.2
Updating <theming> ...
Updated <theming> to 1.0.1
Drop old database tables
 Done                                                                                                                                                                   
 31/31 [============================] 100%                                                                                                                              
Remove old (< 9.0) calendar/contact shares
 Done                                                                                                                                                                   
 4/4 [============================] 100%                                                                                                                                
Fix permissions so avatars can be stored again
 Done                                                                                                                                                                   
 2/2 [============================] 100%                                                                                                                                
Repair unmerged shares
 Starting ...                                                                                                                                                           
  3502/58276 [=>--------------------------]   6%

So now it seams will take another 2 hours to complete next step (“Repair unmerged shares”)

stannum · February 16, 2017, 2:08pm

Finallly I found where it stucked.
Last thing that written on screen is

Repair unmerged shares
 Starting ...                                                                                                                                                           
  3502/58276 [=>--------------------------]   6%

After that it do nothing. I look with top command and from VMware Client performance tab - VM is do NOTHING it simply stuck, but not OS itself just ./occ upgrade script - the system is totally responsive and even another site in same apache2 instance is working ok

stannum · February 17, 2017, 7:58am

Just updating situation on migration/upgrate.
My investigations of my problem revealed to me a reason why any update from 8.2.x is failing again and again.
In short words, something was changed in ‘./occ upgrade’ script and now in 9.x+ versions of OwnCloud and NextCloud this script performing some kind of work with LDAP-user accounts and upgrade stucks in one of the steps. Not sure what step actually lead to stuck whole upgrade but think this happens on processing shared files(folders)

Repair unmerged shares

Starting …
3502/58276 [=>--------------------------] 6%

Workaround:
Before upgrade from 8.2.x to next Major Release you need to disable user_ldap app with CLI command

sudo -u www-data php nextcloud/occ app:disable user_ldap

I will test it further if there are some kind issues after upgrading with disabled LDAP-accounts, how it influences to user shares. But disabling user_ldap app is only way to get updated at this moment.
And all written above is applied to any further updates after 9.x. So to update from 9.x to next stable I need to disable user_ldap again, and from 10 to 11 too.

tflidd · February 17, 2017, 8:12am

@nickvergessen @LukasReschke can you help here?

nickvergessen · February 20, 2017, 10:02am

@rullzer any known issues with the “merge shares” migration/repair step?

rullzer · February 20, 2017, 10:15am

Not as far as I’m aware.

stannum · February 20, 2017, 11:09am

My installation is on Virtual Infrastructure so I have no problem to repeat whole process again until get needed results.

Now I have my installation upgraded to latest Nextcloud 11.0.1 (production) and at this moment saving snapshot at current stage for testing purpose. and then will revert to stage where I have had OwnCloud 8.2.10 then I will try again to update to NextCloud 9.0.56.

stannum · February 20, 2017, 12:01pm

Lets start!
Just for your information:
OS: Debian GNU/Linux 8.7 (jessie)
SOFT: PHP 5.6, Mariadb 10.0.29, Apache2 2.4.10
Installed: OwnCloud 8.2.10.2 from packages
User backend: LDAP/MS Acive Directory 58000+ users (not all user are active but they CAN login and HAVE access)

saved config/config.php, data/ directory is outside of /var/www/
removed distributive packages of owncloud 8.2.10.2
unpacked nextcloud-9.0.56.tar.bz2 contents to /var/www/
chowned to www-data:www-data
run upgrade with: sudo -u www-data php nextcloud/occ upgrade

Now on screen with ./occ upgrade I got this:

sudo -u www-data php nextcloud/occ upgrade
Nextcloud 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
Turned on maintenance mode
Checking whether the database schema can be updated (this can take a long time depending on the database size)
Checked database schema update
Checking updates of apps
Checking whether the database schema for <activity> can be updated (this can take a long time depending on the database size)
Checking whether the database schema for <files_sharing> can be updated (this can take a long time depending on the database size)
Checking whether the database schema for <files_trashbin> can be updated (this can take a long time depending on the database size)
Checking whether the database schema for <user_ldap> can be updated (this can take a long time depending on the database size)
Checked database schema update for apps
Updating database schema
Updated database
Disabled 3rd-party app: calendar
Disabled 3rd-party app: contacts
Disabled 3rd-party app: files_videoviewer
Updating <files_pdfviewer> ...
Updated <files_pdfviewer> to 0.8.1
Updating <files_texteditor> ...
Updated <files_texteditor> to 2.1
Updating <gallery> ...
Updated <gallery> to 14.5.0
Updating <user_ldap> ...
Updated <user_ldap> to 0.8.0
Updating <files> ...
Updated <files> to 1.4.4
Updating <activity> ...
Updated <activity> to 2.2.1
Updating <files_sharing> ...
Updated <files_sharing> to 0.9.1
Updating <files_trashbin> ...
Updated <files_trashbin> to 0.8.0
Updating <files_versions> ...
Updated <files_versions> to 1.2.0
Updating <provisioning_api> ...
Updated <provisioning_api> to 0.4.1
Update 3rd-party app: calendar
Update 3rd-party app: contacts

data/owncloud.log - is growing
and there are many line like this:

{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"initializing paged search for  Filter objectClass=* base Array\n(\n    [0] => cn=\u0443\u0438\u043f-\u0445\u0443\u0441\u043d\u0443\u0442\u0434\u0438\u043d\u043e\u0432\u0430 \u044d\u043b\u044c\u0432\u0438\u0440\u0430 \u0440\u0430\u043c\u0438\u043b\u0435\u0432\u043d\u0430,ou=users,ou=\u0443\u0438\u043f,ou=organizations,dc=gov,dc=tatar,dc=ru\n)\n attr Array\n(\n    [0] => objectguid\n)\n limit 500 offset 0","level":0,"time":"2017-02-20T14:52:30+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"Ready for a paged search","level":0,"time":"2017-02-20T14:52:30+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"initializing paged search for  Filter objectClass=* base Array\n(\n    [0] => cn=\u0443\u0438\u043f-\u0445\u0443\u0441\u043d\u0443\u0442\u0434\u0438\u043d\u043e\u0432\u0430 \u044d\u043b\u044c\u0432\u0438\u0440\u0430 \u0440\u0430\u043c\u0438\u043b\u0435\u0432\u043d\u0430,ou=users,ou=\u0443\u0438\u043f,ou=organizations,dc=gov,dc=tatar,dc=ru\n)\n attr Array\n(\n    [0] => displayname\n)\n limit 500 offset 0","level":0,"time":"2017-02-20T14:52:30+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"Ready for a paged search","level":0,"time":"2017-02-20T14:52:30+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"No DN found for 1094104A-AE13-4591-AFFF-29AA4A208BD2 on ldap:\/\/gov.tatar.ru","level":0,"time":"2017-02-20T14:52:30+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"getUsers: 500 Users found","level":0,"time":"2017-02-20T14:52:32+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"getUsers: Options: search  limit 500 offset 38000 Filter: (&(&(objectCategory=person)(mail=*)(objectClass=user))(displayname=*)(displayname=*))","level":0,"time":"2017-02-20T14:52:32+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"initializing paged search for  Filter (&(&(objectCategory=person)(mail=*)(objectClass=user))(displayname=*)(displayname=*)) base Array\n(\n    [0] => OU=Organizations,DC=gov,DC=tatar,DC=ru\n)\n attr Array\n(\n    [0] => dn\n    [1] => uid\n    [2] => samaccountname\n    [3] => memberof\n    [4] => \n    [5] => mail\n    [6] => displayname\n    [7] => \n)\n limit 500 offset 38000","level":0,"time":"2017-02-20T14:52:32+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"Looking for cookie L\/O 500\/37500","level":1,"time":"2017-02-20T14:52:32+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}

stannum · February 20, 2017, 12:38pm

That’s it!
Update process stopped (I think), because data/owncloud.log - stopped growing and CPU usage dropped to near 0%
last log lines are:

"time":"2017-02-20T15:20:32+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"Ready for a paged search","level":0,"time":"2017-02-20T15:20:32+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"getUsers: 500 Users found","level":0,"time":"2017-02-20T15:20:40+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"getUsers: Options: search  limit 500 offset 40000 Filter: (&(&(objectCategory=person)(mail=*)(objectClass=user))(displayname=*)(displayname=*))","level":0,"time":"2017-02-20T15:20:40+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"initializing paged search for  Filter (&(&(objectCategory=person)(mail=*)(objectClass=user))(displayname=*)(displayname=*)) base Array\n(\n    [0] => OU=Organizations,DC=gov,DC=tatar,DC=ru\n)\n attr Array\n(\n    [0] => dn\n    [1] => uid\n    [2] => samaccountname\n    [3] => memberof\n    [4] => \n    [5] => mail\n    [6] => displayname\n    [7] => \n)\n limit 500 offset 40000","level":0,"time":"2017-02-20T15:20:40+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}
{"reqId":"V\/6L7\/g1VPPXqpska+ql","remoteAddr":"","app":"user_ldap","message":"Ready for a paged search","level":0,"time":"2017-02-20T15:20:40+03:00","method":"--","url":"--","user":"--","version":"8.2.10.2"}

./occ upgrade screen still shows the same, so “upgrade is processing”, and php is still running:

$ ps ax | grep occ
18422 pts/0    S+     0:00 sudo -u www-data php nextcloud/occ upgrade
18423 pts/0    S+    11:45 php nextcloud/occ upgrade

Now need your advices, dear comrades, because upgrade is totally stuck, I’ve checked this previously.

@rullzer, @nickvergessen
So I have calculated time that ./occ upgrade had run normally, it is around 1 hour (+/-) 2 min, before stuck.
So may be this problem related to some kind of request TTL (“reqId”:“V/6L7/g1VPPXqpska+ql”) or something like that?

tflidd · March 27, 2017, 10:42am

Can you check your timeout settings of your database and also php<->database?