search

plone / Products.CMFPlone

The core of the Plone content management system
https://plone.org
GNU General Public License v2.0
254 stars 191 forks source link

Plone 5 upgrade fails without pre-warning when email addresses are not unique. #1387

Closed abadger1406 closed 8 years ago

abadger1406 commented 8 years ago

I trying to upgrade a site with about 300G of filesystem data:-

root@big /home/Plone # du -s -h zeocluster/var/*
224M    zeocluster/var/backups
208G    zeocluster/var/blobstorage
18G zeocluster/var/blobstoragebackups
4.0K    zeocluster/var/blobstoragesnapshots
1.2G    zeocluster/var/b.tar.gz
16G zeocluster/var/client1
9.6M    zeocluster/var/client2
113G    zeocluster/var/filestorage
4.0K    zeocluster/var/README.txt
4.0K    zeocluster/var/snapshotbackups
600K    zeocluster/var/zeoserver

I have copied across var directories, and then click the Upgrade button

Current active configuration
    4207
Latest available configuration
    5011

The upgrade appears to start .. python starts running at 100% ....

24687 plone_d+ 20 0 956520 593232 14072 S 79.1 0.9 9:37.40 python2.7

This carries on for a few minutes

I then get 504 Gateway timeout message on web page.

Have tried to look at the process which is still running

root@big /home/Plone5/zeocluster/var # strace -p 24687
Process 24687 attached
select(12, [4 11], [], [4 11], {6, 315078}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {6, 70295}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {6, 69508}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {6, 9476}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 956137}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 914628}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 863763}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 717528}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 716070}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 502826}) = ? ERESTARTNOHAND (To be restarted if no handler)
select(12, [4 11], [], [4 11], {5, 491363}) = ? ERESTARTNOHAND (To be restarted if no handler)
^CProcess 24687 detached
 <detached ...>
root@big /home/Plone5/zeocluster/var # ps -ef | grep 24687
root     23001 16765  0 16:24 pts/4    00:00:00 grep --color=auto 24687
plone_d+ 24687 24685  0 Feb15 ?        00:12:45 /home/Plone5/zeocluster/bin/python2.7 /home/Plone5/zeocluster/parts/client1/bin/interpreter /home/Plone5/buildout-cache/eggs/Zope2-2.13.23-py2.7.egg/Zope2/Startup/run.py -C /home/Plone5/zeocluster/parts/client1/etc/zope.conf

Is there a better way to migrate such a large data set ?

pbauer commented 8 years ago

The timeout comes from your webserver not from Plone. Try to access it directly. Also you should monitor the log with tail -f unless you run the instance in the foreground. Your migration might have succeeded despite the timeout.

abadger1406 commented 8 years ago 
root@big /home/Plone5/zeocluster # tail -f ./var/client1/event.log
2016-02-16T16:33:23 ERROR plone.app.upgrade The upgrade path did NOT reach current version
------
2016-02-16T16:33:23 ERROR plone.app.upgrade Migration has failed
------
2016-02-16T16:33:23 INFO plone.app.upgrade Dry run selected, transaction aborted
------
2016-02-16T16:33:34 INFO plone.app.theming.policy initializing local cache on thread 140030111594240 for https://big4.netfm.org/d2s::barceloneta
------
2016-02-16T16:34:58 ERROR PortalTransforms Cannot register transform lynx_dump, using BrokenTransform: Error
 Unable to find binary "lynx" in /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games

Ok .. will try installing lynx

abadger1406 commented 8 years ago 
tail -f ./var/client1/event.log
...
...

2016-02-16T16:51:37 INFO GenericSetup.archetypetool Archetype tool imported.
------
2016-02-16T16:51:37 ERROR GenericSetup Step languagetool has an invalid import handler
------
2016-02-16T16:51:37 ERROR GenericSetup Step passwordstrength has an invalid import handler
------
2016-02-16T16:51:37 INFO plone.app.upgrade Ran upgrade step: Miscellaneous
------
2016-02-16T16:51:37 INFO Products.GenericSetup.tool Importing profile profile-plone.app.upgrade.v42:to425 with dependency strategy upgrade.
------
2016-02-16T16:51:37 INFO Products.GenericSetup.tool Applying main profile profile-plone.app.upgrade.v42:to425
------
2016-02-16T16:51:37 INFO GenericSetup.rolemap Role / permission map imported.
------
2016-02-16T16:51:37 ERROR GenericSetup Step loginlockout has an invalid import handler
------
2016-02-16T16:51:37 INFO GenericSetup.archetypetool Archetype tool imported.
------
2016-02-16T16:51:37 ERROR GenericSetup Step languagetool has an invalid import handler
------
2016-02-16T16:51:37 ERROR GenericSetup Step passwordstrength has an invalid import handler
------
2016-02-16T16:51:37 INFO plone.app.upgrade Ran upgrade step: Miscellaneous
------
2016-02-16T16:51:37 INFO plone.app.upgrade Ran upgrade step: Miscellaneous
------
2016-02-16T16:51:37 INFO plone.app.upgrade Ran upgrade step: Miscellaneous
------
2016-02-16T16:51:37 INFO Products.GenericSetup.tool Importing profile profile-plone.app.upgrade.v43:to43alpha1 with dependency strategy upgrade.
------
2016-02-16T16:51:37 INFO Products.GenericSetup.tool Applying main profile profile-plone.app.upgrade.v43:to43alpha1
------
2016-02-16T16:51:37 INFO GenericSetup.rolemap Role / permission map imported.
------
2016-02-16T16:51:37 ERROR GenericSetup Step loginlockout has an invalid import handler
------
2016-02-16T16:51:38 INFO GenericSetup.skins Skins tool imported.
------
2016-02-16T16:51:38 INFO GenericSetup.archetypetool Archetype tool imported.
------
2016-02-16T16:51:38 INFO GenericSetup.propertiestool Properties tool imported.
------
2016-02-16T16:51:38 ERROR GenericSetup Step languagetool has an invalid import handler
------
2016-02-16T16:51:38 INFO GenericSetup.catalog Catalog imported.
------
2016-02-16T16:51:38 ERROR GenericSetup Step passwordstrength has an invalid import handler
------
2016-02-16T16:51:38 INFO plone.app.upgrade Analyzing sortable_title index
------
2016-02-16T16:51:38 INFO ProgressHandler Process started (4012 objects to go)
------
2016-02-16T16:52:15 INFO ProgressHandler Process terminated. Duration: 36.99 seconds
------
2016-02-16T16:52:15 INFO plone.app.upgrade Updating sortable_title index
------
2016-02-16T16:52:15 INFO ProgressHandler Process started (1283 objects to go)

And still appears to be running okay....

2016-02-16T16:54:26 ERROR GenericSetup Step passwordstrength has an invalid import handler
------
2016-02-16T16:54:26 INFO plone.app.upgrade Ran upgrade step: Upgrade Profiles for 4.3a2
------
2016-02-16T16:54:26 INFO plone.app.upgrade Migrating syndication tool
------
2016-02-16T16:55:14 INFO plone.app.upgrade Ran upgrade step: Upgrade syndication
------
2016-02-16T16:55:14 INFO plone.app.upgrade Cleaned up the toolset registry.
------
2016-02-16T16:55:14 INFO plone.app.upgrade Ran upgrade step: Uninstall KSS
------
2016-02-16T16:55:14 INFO plone.app.upgrade Ran upgrade step: Upgrade TinyMCE
------
2016-02-16T16:55:14 INFO Products.GenericSetup.tool Importing profile profile-plone.app.upgrade.v43:to43beta2 with dependency strategy upgrade.
------
2016-02-16T16:55:14 INFO Products.GenericSetup.tool Applying main profile profile-plone.app.upgrade.v43:to43beta2
------
2016-02-16T16:55:14 INFO GenericSetup.rolemap Role / permission map imported.
------
2016-02-16T16:55:14 ERROR GenericSetup Step loginlockout has an invalid import handler
------
2016-02-16T16:55:14 INFO GenericSetup.archetypetool Archetype tool imported.
------
2016-02-16T16:55:14 ERROR GenericSetup Step languagetool has an invalid import handler
------
2016-02-16T16:55:14 ERROR GenericSetup Step passwordstrength has an invalid import handler
------
2016-02-16T16:55:14 INFO plone.app.upgrade Ran upgrade step: Upgrade plone.app.discussion
------
2016-02-16T16:55:14 INFO plone.app.upgrade Ran upgrade step: Upgrade plonetheme.sunburst
------
2016-02-16T16:55:14 INFO Products.GenericSetup.tool Importing profile profile-plone.app.upgrade.v43:to43rc1 with dependency strategy upgrade.
------
2016-02-16T16:55:14 INFO Products.GenericSetup.tool Applying main profile profile-plone.app.upgrade.v43:to43rc1
------
2016-02-16T16:55:14 INFO GenericSetup.rolemap Role / permission map imported.
------
2016-02-16T16:55:14 ERROR GenericSetup Step loginlockout has an invalid import handler
------
2016-02-16T16:55:14 INFO GenericSetup.archetypetool Archetype tool imported.
------
2016-02-16T16:55:14 ERROR GenericSetup Step languagetool has an invalid import handler
------
2016-02-16T16:55:14 INFO GenericSetup.catalog Catalog imported.
------
2016-02-16T16:55:14 ERROR GenericSetup Step passwordstrength has an invalid import handler
------
2016-02-16T16:55:14 INFO plone.app.upgrade Reindex Title index with I18N Case Normalizer

...
...

------
2016-02-16T16:57:02 INFO plone.app.upgrade Reindex Description index with I18N Case Normalizer
------

2016-02-16T17:00:20 INFO plone.app.upgrade Email is used as login, setting PAS login_transform to 'lower'.
------
2016-02-16T17:00:20 ERROR PluggableAuthService User id ian.johns@cari.com: login name 'ian.johns@cari.com' already taken.
------
2016-02-16T17:00:20 ERROR PluggableAuthService There were 1 errors when updating login names. quit_on_first_error was True
------
2016-02-16T17:00:20 ERROR plone.app.upgrade Upgrade aborted. Error:
Traceback (most recent call last):
  File "/home/Plone5/buildout-cache/eggs/Products.CMFPlone-5.0-py2.7.egg/Products/CMFPlone/MigrationTool.py", line 257, in upgrade
    step['step'].doStep(setup)
  File "/home/Plone5/buildout-cache/eggs/Products.GenericSetup-1.8.0-py2.7.egg/Products/GenericSetup/upgrade.py", line 166, in doStep
    self.handler(tool)
  File "/home/Plone5/buildout-cache/eggs/plone.app.upgrade-1.3.18-py2.7.egg/plone/app/upgrade/v50/alphas.py", line 79, in lowercase_email_login
    pas.manage_changeProperties(login_transform='lower')
  File "/home/Plone5/buildout-cache/eggs/Zope2-2.13.23-py2.7.egg/OFS/PropertyManager.py", line 332, in manage_changeProperties
    self._updateProperty(name, value)
  File "/home/Plone5/buildout-cache/eggs/Zope2-2.13.23-py2.7.egg/OFS/PropertyManager.py", line 210, in _updateProperty
    self._setPropValue(id, value)
  File "/home/Plone5/buildout-cache/eggs/Products.PluggableAuthService-1.10.0-py2.7.egg/Products/PluggableAuthService/PluggableAuthService.py", line 1115, in _setPropValue
    self.updateAllLoginNames()
  File "/home/Plone5/buildout-cache/eggs/Products.PluggableAuthService-1.10.0-py2.7.egg/Products/PluggableAuthService/PluggableAuthService.py", line 1347, in updateAllLoginNames
    quit_on_first_error=quit_on_first_error)
  File "/home/Plone5/buildout-cache/eggs/Products.PluggableAuthService-1.10.0-py2.7.egg/Products/PluggableAuthService/plugins/ZODBUserManager.py", line 376, in updateEveryLoginName
    ', '.join(errors))
ValueError: Transformed login names are not unique: ian.johns@cari.com.
------
2016-02-16T17:00:20 INFO plone.app.upgrade Starting upgrade of core addons.
------
2016-02-16T17:00:20 INFO Products.GenericSetup.tool No upgrades available for profile Products.CMFEditions:CMFEditions. Profile stays at version ('4',).
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile Products.CMFPlacefulWorkflow:CMFPlacefulWorkflow is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.contenttypes:default is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.dexterity:default is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 INFO Products.GenericSetup.tool No upgrades available for profile plone.app.discussion:default. Profile stays at version ('102',).
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.event:default is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.iterate:plone.app.iterate is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.multilingual:default is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.querystring:default is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 INFO Products.GenericSetup.tool No upgrades available for profile plone.app.theming:default. Profile stays at version ('1001',).
------
2016-02-16T17:00:20 WARNING Products.GenericSetup.tool Version of profile plone.app.users:default is unknown, refusing to upgrade.
------
2016-02-16T17:00:20 INFO plone.app.upgrade Done upgrading core addons.
------
2016-02-16T17:00:20 INFO plone.app.upgrade End of upgrade path, migration has finished
------
2016-02-16T17:00:20 ERROR plone.app.upgrade The upgrade path did NOT reach current version
------
2016-02-16T17:00:20 ERROR plone.app.upgrade Migration has failed

2016-02-16T16:57:58 INFO plone.app.upgrade Reindex SearchableText index with I18N Case Normalizer

Ok... so duplicate name is my issue .. will remove this

pbauer commented 8 years ago

@abadger1406 Great that you found the error. I formatted your tracebacks to make them readable (three `'s before and after)

jensens commented 8 years ago

if solved please close issue

djay commented 8 years ago

Since the upgrade requires email addresses to be unique it would be a much nicer user experience if there was a check very early in the upgrade process so this was displayed on screen to the user rather than finding it in the logs. I'll update the title to reflect this instead of creating a new ticket

jensens commented 8 years ago

+1

mauritsvanrees commented 8 years ago

It only requires unique email addresses when you are using emails as login names.

In Plone 4 you can add collective.emaillogin4 to the eggs and use the @@migrate-to-emaillogin page to look for duplicates. See https://pypi.python.org/pypi/collective.emaillogin4 This page is also available in Plone 5 (which integrates the fixes from this package) but likely the page will give errors simply because any page will give errors before you have completed the migration.

It is part of the upgrade from Plone 4.3 to Plone 5.0 (v50/alphas.py) so I guess it is hard to show it earlier. We don't really have a place to show warnings about things that you need to do manually first.

jensens commented 8 years ago

IMO possible problem with possible solutions should be added to the migration guide.