(taken from https://github.com/openstax/cnx/issues/757)
The servers running legacy are prod04 and prod05. This can be found on cnx-deploy:
[zclient:children]
prod04
prod05
From the first screenshot, you can see the url https://legacy.cnx.org/Members/mcantrall, so I would look for /Members/mcantrall
in the logs.
Legacy logs are in /var/lib/cnx/cnx-buildout/var/log/
. ssh
into prod04 and prod05 and look for the error.
I use less
and search within the file.
I suggest going to the bottom of the file (less shortcut: G
) and then do a reverse search (less shortcut: ?
)
and I found this:
2019-11-06T10:27:01 ERROR Zope.SiteErrorLog https://legacy.cnx.org/Members/mcantrall/workspace_contents
Traceback (innermost last):
Module ZPublisher.Publish, line 115, in publish
Module ZPublisher.mapply, line 88, in mapply
Module ZPublisher.Publish, line 41, in call_object
Module Shared.DC.Scripts.Bindings, line 311, in __call__
Module Products.PloneHotfix20110531, line 106, in _patched_bindAndExec
Module Products.PloneHotfix20130618.spamProtect, line 35, in _patched_bindAndExec
Module Products.PloneHotfix20121106.python_scripts, line 63, in _patched_bindAndExec
Module Shared.DC.Scripts.Bindings, line 348, in _bindAndExec
Module Products.CMFCore.FSPageTemplate, line 195, in _exec
Module Products.CacheSetup.patch_cmf, line 29, in FSPT_pt_render
Module Products.CacheSetup.patch_utils, line 9, in call_pattern
Module Products.CMFCore.FSPageTemplate, line 134, in pt_render
Module Products.CacheSetup.patch_cmf, line 77, in PT_pt_render
Module Products.CacheSetup.patch_utils, line 9, in call_pattern
Module Products.PageTemplates.PageTemplate, line 104, in pt_render
- <FSPageTemplate at /plone/workspace_contents used for /plone/Members/mcantrall>
Module TAL.TALInterpreter, line 238, in __call__
Module TAL.TALInterpreter, line 281, in interpret
Module TAL.TALInterpreter, line 749, in do_useMacro
Module TAL.TALInterpreter, line 281, in interpret
Module TAL.TALInterpreter, line 457, in do_optTag_tal
Module TAL.TALInterpreter, line 442, in do_optTag
Module TAL.TALInterpreter, line 437, in no_tag
Module TAL.TALInterpreter, line 281, in interpret
Module TAL.TALInterpreter, line 780, in do_defineSlot
Module TAL.TALInterpreter, line 281, in interpret
Module TAL.TALInterpreter, line 457, in do_optTag_tal
Module TAL.TALInterpreter, line 442, in do_optTag
Module TAL.TALInterpreter, line 437, in no_tag
...
Module TAL.TALInterpreter, line 281, in interpret
Module TAL.TALInterpreter, line 507, in do_setLocal_tal
Module Products.PageTemplates.TALES, line 221, in evaluate
- URL: file:RhaptosSite/skins/rhaptos_site/workspace_contents.pt
- Line 282, Column 20
- Expression: standard:'item/getObject | nothing'
- Names:
{'container': <PloneSite at /plone>,
'context': <PloneFolder at /plone/Members/mcantrall>,
'default': <Products.PageTemplates.TALES.Default instance at 0x7f2e235b5cf8>,
'here': <PloneFolder at /plone/Members/mcantrall>,
'loop': <Products.PageTemplates.TALES.SafeMapping object at 0x7f2e0e9b0e60>,
'modules': <Products.PageTemplates.ZRPythonExpr._SecureModuleImporter instance at 0x7f2e235b8488>,
'nothing': None,
'options': {'args': ()},
'repeat': <Products.PageTemplates.TALES.SafeMapping object at 0x7f2e0e9b0e60>,
'request': <HTTPRequest, URL=https://legacy.cnx.org/Members/mcantrall/workspace_contents>,
'root': <Application at >,
'template': <FSPageTemplate at /plone/workspace_contents used for /plone/Members/mcantrall>,
'traverse_subpath': [],
'user': <PloneUser 'sanura'>}
Module Products.PageTemplates.Expressions, line 185, in __call__
Module Products.PageTemplates.Expressions, line 180, in _eval
Module Products.PageTemplates.Expressions, line 85, in render
Module Products.ZCatalog.CatalogBrains, line 86, in getObject
Module OFS.Traversable, line 250, in restrictedTraverse
Module OFS.Traversable, line 187, in unrestrictedTraverse
- __traceback_info__: ([], '2019-11-04.8137449132')
Module Products.Five.traversable, line 126, in __bobo_traverse__
AttributeError: 2019-11-04.8137449132
This bit in the traceback gives you the filename:
- URL: file:RhaptosSite/skins/rhaptos_site/workspace_contents.pt
- Line 282, Column 20
- Expression: standard:'item/getObject | nothing'
In the /var/lib/cnx/cnx-buildout
, do
find -name workspace_contents.pt
You'd get something like this:
./eggs/Products.RhaptosSite-1.47-py2.4.egg/Products/RhaptosSite/skins/rhaptos_site/workspace_contents.pt
./eggs/Products.RhaptosSite-1.49-py2.4.egg/Products/RhaptosSite/skins/rhaptos_site/workspace_contents.pt
./eggs/Products.RhaptosSite-1.46-py2.4.egg/Products/RhaptosSite/skins/rhaptos_site/workspace_contents.pt
./eggs/Products.RhaptosSite-1.48-py2.4.egg/Products/RhaptosSite/skins/rhaptos_site/workspace_contents.pt
Older eggs are often not deleted, the file we need is the latest one
./eggs/Products.RhaptosSite-1.49-py2.4.egg/Products/RhaptosSite/skins/rhaptos_site/workspace_contents.pt
I'm not sure what the line number in the traceback (Line 282, Column 20
)
refers to because the file only has 200 lines.
But we can look for the expression item/getObject
, and it's on line 149:
<metal:item_slot metal:fill-slot="item_display" i18n:domain="plone"
tal:define="obj item/getObject | nothing">
This is the current plone documentation for the zope page template language: https://docs.plone.org/adapt-and-extend/theming/templates_css/template_basics.html
Plone uses Zope Page Templates, consisting of the three related standards:
- Template Attribute Language (TAL)
- TAL Expression Syntax (TALES)
- Macro Expansion TAL (METAL).
Note: we are using plone version 2.5, and the current version of plone at the time of writing is 5.2, so a lot of the documentation probably doesn't apply.
tal:define=obj item/getObject | nothing
means something like:
try:
obj = item.getObject() # or item.getObject
except:
obj = None
But item
isn't actually defined in this file.
Look further up the file, you'll see on line 127:
<metal:contentsmacro use-macro="context/folder_contents/macros/contents">
This means use the macro called "contents" in a file called folder_contents.*
.
find -name 'folder_contents.*'
./parts/plone/GroupUserFolder/doc/folder_contents.png
./parts/plone/CMFPlone/skins/plone_templates/folder_contents.pt.metadata
./parts/plone/CMFPlone/skins/plone_templates/folder_contents.pt
./parts/plone/CMFDefault/skins/generic/folder_contents.dtml
./parts/plone/CMFDefault/skins/zpt_generic/folder_contents.py
./eggs/Products.RhaptosSite-1.47-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt.metadata
./eggs/Products.RhaptosSite-1.47-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt
./eggs/Products.RhaptosSite-1.49-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt.metadata
./eggs/Products.RhaptosSite-1.49-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt
./eggs/Products.RhaptosSite-1.46-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt.metadata
./eggs/Products.RhaptosSite-1.46-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt
./eggs/Products.RhaptosSite-1.48-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt.metadata
./eggs/Products.RhaptosSite-1.48-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt
This time there are results from parts/
, it contains some plone and zope
packages and some third party packages. Our packages are in eggs/
, but there
are other third party packages in eggs/
as well.
Since Products.RhaptosSite
is one of our packages, it's most likely to be
overriding the default zope and plone ones.
So open ./eggs/Products.RhaptosSite-1.49-py2.4.egg/Products/RhaptosSite/skins/rhaptos_overrides/folder_contents.pt
.
Searching for item
, I found on line 241:
<tal:items tal:repeat="item batch">
This is like:
for item in batch:
Next, we need to look for the definition of batch
, on line 46 - 54:
<metal:contentsmacro define-macro="contents"
tal:define="standalone python:1;
contentTypes here/getAllowedTypes;
contentFilter contentFilter|request/contentFilter|nothing;
b_size b_size|request/b_size|python:100;
view_title view_title|request/view_title|string:;
contentsMethod python:test(here.portal_type=='Topic', here.queryCatalog, here.getFolderContents);
batch batch|python:contentsMethod(contentFilter,batch=True, b_size=b_size);
full_view full_view|request/full_view|python:True;">
batch
is contentsMethod(contentFilter, batch=True, b_size=b_size)
,
contentsMethod
is here.queryCatalog if here.portal_type == 'Topic' else here.getFolderContents
.
contentFilter
is None
unless there is a post or get request parameter called contentFilter
,
b_size
is 100
unless there is a post or get request parameter called b_size
.
Next, it's time to get a python shell with the zope application:
./bin/instance debug
The first line (among lots of warnings) is:
Starting debugger (the name "app" is bound to the top-level Zope object)
You can see it by doing:
>>> app
<Application at >
ZODB (Zope Object Database) is an object oriented database for storing python objects.
For example, you can use objectValues()
to find all the child objects of app
.
>>> app.objectValues()
[<ApplicationManager at /Control_Panel>, <DTMLMethod at /standard_html_header>, <DTMLMethod at /standard_html_footer>, <DTMLMethod at /standard_error_message>, <Folder at /QuickStart>, <VirtualHostMonster at /risaRemap>, <Folder at /developers>, <ZSyncer at /broken>, <Image at /favicon.ico>, <DTMLMethod at /index_html>, <BrowserIdManager at /browser_id_manager>, <SessionDataManager at /session_data_manager>, <Folder at /Examples>, <SiteErrorLog at /error_log>, <ZopePageTemplate at /standard_template.pt>, <Connection at /devrep>, <PythonScript at /convertUsers>, <SQL at /sqlListUsers>, <PythonScript at /usListUsers>, <Folder at /tmp>, <PloneSite at /plone>, <PythonScript at /migrate_contents>, <PythonScript at /migrate_workgroups>, <ExternalMethod at /loggit>, <LocalFS at /logs>, <LocalFS at /oldlogs>, <PythonScript at /request>, <ExternalMethod at /html2cnxml>, <LocalFS at /rerunlogs>, <LocalFS at /stats>, <SimpleTemporaryContainer at /temp_folder>, <PluggableAuthService at /acl_users>, <File at /robots.txt>]
The url that had the error is /plone/Members/mcantrall
, which can be accessed
by doing app.plone.Members.mcantrall
.
>>> app.plone.Members.mcantrall
<PloneFolder at /plone/Members/mcantrall>
>>> app.plone.Members.mcantrall.objectIds()
['col28320', 'Module.2019-11-01.2903', 'm79822', 'm79926', 'Module.2019-11-01.3346', 'Module.2019-11-01.3513', 'Module.2019-11-01.5839', 'Module.2019-11-01.0059', 'Module.2019-11-01.0304', 'Module.2019-11-01.0503', 'Module.2019-11-01.0645', 'Module.2019-11-01.0840', 'Module.2019-11-04.5029', 'Module.2019-11-04.5400', 'Module.2019-11-04.5609', 'Module.2019-11-04.5759', 'Module.2019-11-04.0035', 'Module.2019-11-04.0237', 'Module.2019-11-04.0350', 'Module.2019-11-04.4815']
>>> app.plone.Members.mcantrall.portal_type
'Workspace'
To reproduce the error when the user goes to their workspace, we follow the paths that the code took:
getFolderContents
:
karen@qa00:/var/lib/cnx/cnx-buildout$ find -name 'getFolderContents.*'
./parts/plone/CMFPlone/skins/plone_scripts/getFolderContents.py
contents = context.portal_catalog.queryCatalog(contentFilter, show_all=1,
queryCatalog
:
karen@qa00:/var/lib/cnx/cnx-buildout$ find -name 'queryCatalog.*'
./parts/plone/CMFPlone/skins/plone_scripts/queryCatalog.py
./eggs/Products.PloneHotfix20121106-1.2-py2.4.egg/Products/PloneHotfix20121106/queryCatalog.pyo
./eggs/Products.PloneHotfix20121106-1.2-py2.4.egg/Products/PloneHotfix20121106/queryCatalog.pyc
./eggs/Products.PloneHotfix20121106-1.2-py2.4.egg/Products/PloneHotfix20121106/queryCatalog.py
results = catalog(**query)
The query includes the location to search from, which is the current path
/plone/Members/mcantrall
. By default, the portal catalog only returns
objects that can be viewed by the current user. Since we are not logged in in
the python shell, we need to use unrestrictedSearchResults
in order to see
what the user is seeing:
>>> app.plone.portal_catalog.unrestrictedSearchResults({'path': {'query': '/plone/Members/mcantrall', 'depth': 1}})
[<Products.ZCatalog.Catalog.mybrains object at 0x7123a48>, <Products.ZCatalog.Catalog.mybrains object at 0x7123c58>, <Products.ZCatalog.Catalog.mybrains object at 0x7123cb0>, <Products.ZCatalog.Catalog.mybrains object at 0x750e050>, <Products.ZCatalog.Catalog.mybrains object at 0x750e8e8>, <Products.ZCatalog.Catalog.mybrains object at 0x753d310>, <Products.ZCatalog.Catalog.mybrains object at 0x753d998>, <Products.ZCatalog.Catalog.mybrains object at 0x7557310>, <Products.ZCatalog.Catalog.mybrains object at 0x7557998>, <Products.ZCatalog.Catalog.mybrains object at 0x7557b50>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf0a8>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf100>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf158>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf260>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf2b8>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf310>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf680>, <Products.ZCatalog.Catalog.mybrains object at 0x78cf8e8>, <Products.ZCatalog.Catalog.mybrains object at 0x78cfa48>, <Products.ZCatalog.Catalog.mybrains object at 0x78cfec0>, <Products.ZCatalog.Catalog.mybrains object at 0x7a1e730>, <Products.ZCatalog.Catalog.mybrains object at 0x7a1ef18>]
The portal catalog returns these objects called brain
s, they contain some
basic information about the objects like id
and path
, but doesn't contain
everything. To get the object, we can call .getObject()
.
>>> items = app.plone.portal_catalog.unrestrictedSearchResults({'path': {'query': '/plone/Members/mcantrall', 'depth': 1}})
>>> [i.getObject() for i in items]
Traceback (most recent call last):
File "<stdin>", line 1, in ?
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/Products/ZCatalog/CatalogBrains.py", line 86, in getObject
target = parent.restrictedTraverse(path[-1])
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/OFS/Traversable.py", line 250, in restrictedTraverse
return self.unrestrictedTraverse(path, default, restricted=1)
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/OFS/Traversable.py", line 187, in unrestrictedTraverse
next = bobo_traverse(REQUEST, name)
File "/var/lib/cnx/cnx-buildout/eggs/Products.Five-1.4.5_rhaptosdev_r32037-py2.4.egg/Products/Five/traversable.py", line 126, in __bobo_traverse__
return getattr(self, name)
AttributeError: 2019-11-04.0519911123
This is exactly the kind of error we are seeing in the traceback!
>>> brains = set([i.getId for i in items])
>>> objects = set(app.plone.Members.mcantrall.objectIds())
>>> brains.difference(objects)
set(['2019-11-04.8137449132', '2019-11-04.0519911123'])
There is a difference between the objects in the database and the brains returned by the portal catalog.
Probably some objects didn't create or delete cleanly, causing the objects to be indexed but do not actually exist in the database.
Next, try to unindex the object so the portal catalog doesn't return the object:
>>> app.plone.portal_catalog.unindexObject(app.plone.Members.mcantrall['2019-11-04.8137449132']
... )
Traceback (most recent call last):
File "<stdin>", line 1, in ?
File "/var/lib/cnx/cnx-buildout/eggs/Products.PloneHotfix20130618-1.1-py2.4.egg/Products/PloneHotfix20130618/get.py", line 38, in __getitem__
raise KeyError, key
KeyError: '2019-11-04.8137449132'
>>> app.plone.portal_catalog.unindexObject.func_code
<code object unindexObject at 0x7f7d12eb49d0, file "/var/lib/cnx/cnx-buildout/parts/plone/CMFCore/CatalogTool.py", line 368>
>>> app.plone.portal_catalog.uncatalog_object('/plone/Members/mcantrall/2019-11-04.8137449132')
Traceback (most recent call last):
File "<stdin>", line 1, in ?
File "/var/lib/cnx/cnx-buildout/eggs/Products.CacheSetup-1.2.1-py2.4.egg/Products/CacheSetup/patch.py", line 109, in uncatalog_object
return call(self, 'uncatalog_object', uid)
File "/var/lib/cnx/cnx-buildout/eggs/Products.CacheSetup-1.2.1-py2.4.egg/Products/CacheSetup/patch_utils.py", line 6, in call
return getattr(self, PATTERN % __name__)(*args, **kw)
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/Products/ZCatalog/ZCatalog.py", line 599, in uncatalog_object
self._catalog.uncatalogObject(uid)
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/Products/ZCatalog/Catalog.py", line 389, in uncatalogObject
x.unindex_object(rid)
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/Products/PluginIndexes/DateRangeIndex/DateRangeIndex.py", line 192, in unindex_object
self._removeForwardIndexEntry( since, until, documentId )
File "/var/lib/cnx/cnx-buildout/parts/zope2/lib/python/Products/PluginIndexes/DateRangeIndex/DateRangeIndex.py", line 384, in _removeForwardIndexEntry
set.remove( documentId )
KeyError: -1455954524
Unindexing the object returned a KeyError
returned by a DateRangeIndex
.
Let's have a look at the indexes available:
>>> app.plone.portal_catalog.index_objects()
[<DateIndex at created>, <FieldIndex at orig_id>, <FieldIndex at Creator>, <DateIndex at modified>, <DateRangeIndex at effectiveRange>, <FieldIndex at sortable_title>, <KeywordIndex at allowedRolesAndUsers>, <FieldIndex at getObjPositionInParent>, <DateIndex at Date>, <ExtendedPathIndex at path>, <FieldIndex at review_state>, <FieldIndex at portal_type>]
The only DateRangeIndex
is effectiveRange
so that's where the problem is.
I've written a script to fix this problem: https://github.com/openstax/devops/blob/master/scripts/legacy/fix_legacy_user_workspace.py
Usage: fix_legacy_user_workspace.py [username] ...
Usage: fix_legacy_user_workspace.py --test | --help | --fix-all
Attempts to fix the AttributeError raised when a user goes to their workspace.
Options:
--fix-all fix all broken workspaces
--commit commit transaction (save all changes)
--test run unit tests
-h, --help display help message and exit
I tested this on staging and it appears to work for user davidnvn
(because mcantrall
's workspace wasn't broken). On production, I expect the script to be run like this:
./fix_legacy_user_workspace.py mcantrall
-
Download the script:
wget -O fix_legacy_user_workspace.py 'https://raw.githubusercontent.com/openstax/devops/master/scripts/legacy/fix_legacy_user_workspace.py?token=AABFOCPNDDG4X77UDQ2AEVK54TORK' chmod +x fix_legacy_user_workspace.py
-
Run the script:
./fix_legacy_user_workspace.py --commit mcantrall