On 3/6/08, Tres Seaver <tseaver@palladion.com> wrote:

Ryan Smith wrote:

...

Posted this to the Plone Mailing-list, but this is more of a problem I am having with Zope. There will be additional information here -

http://www.nabble.com/Indexing-Bug---Index-changes-and-is-not-always-correct...

...

Basically the problem I am having is that I create an index, but sometimes this index changes and is incorrect.

To test this I would constantly click the 'Clear and Rebuild' button under the Advanced Tab. Then I would browse my index under the Indexes tab.

After repeating this many many times, I would get 2 different results for my index (1 correct, the other completely wrong). I didn't change anything else, I just kept clicking rebuild.

We need more information:

- What kind of index?

- What objects are you indexing?

- What kind of query are you making against the index?

- What does "completely wrong" mean?

Here are the 2 word answers, I go into more detail below. - What kind of index? FieldIndex on an attribute I created called 'access'. Access is a list of accesses a user has. - What objects are you indexing? Any object with the 'access' attribute - What kind of query are you making against the index? I noticed the problem when doing a folder listing in my Plone Site. - What does "completely wrong" mean? The index is missing objects that have the 'access' attribute. If an object's 'access' attribute is B it may be mapped in the index to A. Here is some background on what I am doing - For a plone site, I needed a way to allow a user to only see objects if they had a certain set of roles. I can't use the default security policy because we may want an object to require the roles Alpha AND Beta, but by default if a user has Alpha OR Beta they can see the object. When creating an object, it is possible to specify and 'access' attribute that will require special accesses to view the object. I handle if a user can view an object by dynamically adding them to a group, via a Group Plugin. Problem was this didn't effect if the object showed up in a search result, like a folder listing. Plone calls ZCatalog.searchResults() to get the metadata for all the objects in a folder. I grab these results and remove objects that shouldn't be listed to a specific user. To check if a user is allowed to view it, I check in the metadata, if my attribute is there I compare it to the users roles and remove it if needed This all works most of the time. But sometimes the index changes and the results I filter out will be wrong.

...

I noticed something interesting in my debugging window. All rebuilds that resulted in a correct index had this - DEBUG txn.-1223402608 commit <Connection at 0b5a01ec> All rebuilds that resulted in an incorrect index had this - DEBUG txn.-1244382320 commit <Connection at 0965020c>

Something different is being done, I'm just not sure what or why.

Any suggestions as to why this is happening or where I should look to fix this would be greatly appreciated.

The two log messages you post are effectively identical: some get served from different ZODB connections, but that shouldn't cause any difference in behavior. If you have one connection with "stale" data for some objects (that would be a bug somewhere), then restarting Zope might make the problem disappear, although we still wouldn't know how that connection got into that state.

The point I was trying to make with this was that if I reindex 100 times. I will get "DEBUG txn.-1223402608 commit <Connection at 0b5a01ec>" 80 times and "DEBUG txn.-1244382320 commit <Connection at 0965020c>" 20 times. I realize they are nearly the same, but I get 2 distinct values every time. So if I dont restart Zope, it will always be one of these 2, nothing else. And the re-indexes that are wrong always share the same value.

Tres, let me start by saying thanks for helping me look into this.

Note that a FieldIndex is likely not to do what you want for multi-valued attributes, such as lists or tuples: you probably want a KeywordIndex, which allows you do supply operators such as 'and' and 'or'.

I considered a KeywordIndex at first. It can't do what I want though, I would need to mix and, or's and not's to do what I need to do.

That isn't enough information: we really need to see the arguments being passed to the catalog's 'search' or 'searchResults' methods.

You need to show the filter you are using, because nothing in stock Zope / CMF / Plone works the way you describe.

In Products.CMFPlone.CatalogTool.py In the function searchResults has this at the bottom - return ZCatalog.searchResults(self, REQUEST, **kw) I added the following code to the bottom of this function results = ZCatalog.searchResults(self, REQUEST, **kw) usrAccesses = getUserAccesses(user) for index in reversed(range(len(results))): if results[index].getAccess: reqAccesses = results[index].getAccess for access in usrAccesses : if access in reqAccesses : reqAccesses.remove(access) if len(reqAccesses): del results[index] return results --------------------------------------------------------------------------- This code does what I need it to do. The problem is reqAccesses = results[index].getAccess Sometimes has the wrong accesses.

I think you need to give us a script to reproduce the behavior you are seeing, e.g.:

I will set up and run the script you sent. The thing is, more than likely it will produce the expected results. I don't always see the behavior. Before setting up your test cases, here are the actual results from one of our test servers. The Index created is called 'getAccess', the metadata field created is 'getAccess' Created the following objects. The suffix on each file name desicribes what I set the access attribute is. (a==alpha, b==beta, g==gamma, n==none of them) /Plone/test-area/filen /Plone/test-area/filea /Plone/test-area/fileab /Plone/test-area/fileabg /Plone/test-area/fileag /Plone/test-area/fileg In the ZMI under portal_catalog, Advanced tab, I click "Update Catalog". In a seperate window I refresh portal_catalog->Indexes->getAccess->Browse ---------------------------------------------------------------------- Now sometimes the getAccess Index has the following which is correct - [''] /Plone/test-area/filen ['alpha', ''] /Plone/test-area/filea ['alpha', 'beta', ''] /Plone/test-area/fileab ['alpha', 'beta', 'gamma', ''] /Plone/test-area/fileabg ['alpha', 'gamma', ''] /Plone/test-area/fileag ['gamma', ''] /Plone/test-area/fileg ----------------------------------------------------- Other times it has this, which is incorrect - ['alpha'] /Plone/test-area/filea /Plone/test-area/fileag ['alpha', 'beta', ''] /Plone/test-area/fileab ['alpha', 'beta', 'gamma', ''] /Plone/test-area/fileabg ['gamma', ''] /Plone/test-area/fileg ----------------------------------------------------------------- As you can see the one that is wrong changed ['alpha', ''] to ['alpha'] which caused it to grab more than it should of And it is missing [''] and ['alpha', 'gamma'] -----------------------------------------------------------------------------------------

The two "values" you are seeing (I'm willing to bet money that the transaction ID isn't the same) are two different ZODB connections: some requests get one connection from the pool, while others get another.

If this is the case could there be a reason why one of the connections from the pool always results in something different? - Ryan

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Ryan Smith wrote:

Tried running your script, but I think I'm missing something (I usually dont dive this far into the ZMI). When I run it, searchResults does not return anything. I dont think the problem is with searching though. The problem is for some reason my indexes get re-indexed (not sure when this usually happens). When there is a re-index though, sometimes the index is not properly indexed. This causes unexpected results to be returned when I do a search.

...

6. Run the script, then tell us what you see, versus what you expected to see, when you run the script. When I run it using a Keyword index and that query, I get the following, which is exactly what I expect::

Here is my output - Querying value for access: baz

Querying value for access: ('baz',)

Querying value for access: ('bam', 'baz')

Querying value for access: ('bar', 'baz')

It does have the following values in my index though ('bam', 'baz') /Plone/test/qux

('bar', 'baz') /Plone/test/splift

('baz',) /Plone/test/foo

...

Querying value for access: baz /scratch/foo /scratch/qux /scratch/splift

Querying value for access: ('baz',) /scratch/foo /scratch/qux /scratch/splift

Querying value for access: ('bam', 'baz') /scratch/qux

Querying value for access: ('bar', 'baz') /scratch/splift

My output was using a KeywordIndex, with 'and' as the operator. I noted when reading your earlier description that your code was testing the value of the 'getAccess' entry in the *metadata*, not in the index: in fact, you don't need an index at all to do the filtering in that code. Can you check on the "Catalog" tab that the metadata for your indexed objects has the correct 'getAccess' values? Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFH0GGY+gerLs4ltQ4RAluoAKCWLq9YozOzKpL7O1dCPqfgCKyU+QCfUS6d oi0KKIqF6toGV96NAQm3whg= =gEB/ -----END PGP SIGNATURE-----

Tres - I am 98% sure I found the source of my problem. I thought I was getting a copy of something back, when really I was getting a pointer to it. So I was changing the catalog. I am still slightly confused as to how it fixed itself (probably was due to data being cached). In my code I have - reqAccesses = results[index].getAccess for access in usrAccesses : if access in reqAccesses : reqAccesses.remove(access) I am getting a reference though, so when I do remove() I am changing the actual catalog values. It looks like it is fixed by doing reqAccesses = results[index].getAccess.copy() I would like to thank you though for helping me deal with my stupidity. This one was really stumping me since it seemed as though my code wasn't always involved. On 3/7/08, Ryan Smith <rsmith985@gmail.com> wrote:

...

My output was using a KeywordIndex, with 'and' as the operator.

I noted when reading your earlier description that your code was testing the value of the 'getAccess' entry in the *metadata*, not in the index: in fact, you don't need an index at all to do the filtering in that code. Can you check on the "Catalog" tab that the metadata for your indexed objects has the correct 'getAccess' values?

To answer your question. For something lets say fileab (which should have 'alpha' and 'beta'): If the index is correct: I went to catalog, then clicked fileab, then checked the getAccess key and it was correct, ['alpha', 'beta', '']. If the index is wrong: Doing the same the the getAccess key is wrong, ['beta']. ----------------------------------- I realized something this morning. The bug is only reproducable, if there are concurrent connections. Someone else mentioned that concurrent connections resulted in wrong catalog entries. At first I thought this wasn't always the case for me, but it is.

If I log in as an admin and I continuously refresh the catalog, it looks like it will always be correct.

If, though, I open a second browser and log in as a normal user, I am able to cause the problem to happen fairly often by updating the catalog.

- Ryan

-- Ryan Smith 859-338-4713 (c) rsmith985@gmail.com