[Zope3-dev] How one Zope 3 bug was fixed
Steve Alexander
steve@cat-box.net
Wed, 11 Jun 2003 12:08:43 +0300
When I logged onto irc this morning, I noticed that Adam Da had found a
problem with the security pages in Zope 3.
Adam offered to help fix the bug, and the conversation turned to exactly
how one tracks down and fixes such a bug.
Perhaps some members of this mailing list will find it interesting or
informative. Here's the transcript. It is 241 lines long.
----
<Da> Using the ZMI, if I go to Grant->Grant Permissions to roles I get
an error:Request URL http://demo:8081/@@AllRolePermissions.html
<Da> Request URL http://demo:8081/@@AllRolePermissions.html ....
Exception Value (<zope.tales.tales.Iterator object at 0x88b12ec>, 'index')
<Da> Is there another way to grant permissions? What would I have to do
to fix this code?
<srichter> via ZCML
<srichter> I dunno how broken the grants views are though
<Da> I'd be happy to do it, but would need someone to point me in the
right direction...:)
<srichter> Da: you must wait until Jim or Steve are awake :-)
<-- srichter has quit (Read error: 60 (Operation timed out))
--- You are now known as SteveA
<SteveA> Da: the problem is that the TALES repeat/varname/index is broken
<SteveA> A deeper problem is that index is not defined in ITALESIterator
<SteveA> Should TALES iterators have an index?
<SteveA> probably they should
<SteveA> I'll check the spec
<SteveA> right, the spec says it has an index
<Da> I thought it would :)
<SteveA> I'll go ahead and fix this.
<SteveA> does anyone have Zope 2 to hand?
<Da> Thanks - If you would like, I could do it - but I would need you to
check/guide - which would probably be slower for you, but at least you
get another person workign on zope3 :)
<SteveA> I need to find out what repeat/var/number and repeat/var/index
do if the iterator hasn't been used yet
<SteveA> Da: ok. First, I'll explain how I tracked down the problem
<SteveA> I reproduced the problem you reported, by doing a cvs up,
checking there was no C to recompile, starting up Zope, and going to the
page you mentioned.
<SteveA> I saw the error, and saw the traceback on my console. The
traceback would also be available in the site error reporting service.
<SteveA> The problem is to do with the page that is accessed through the
browser as @@AllRolePermissions.html
<SteveA> The easiest way (for now) of finding the code and templates for
that page is to look through configure.zcml files for that name, without
the leading @@ characters.
<SteveA> find -name "*.zcml" | xargs grep AllRolePermissions.html
<SteveA> So, I find the answer in
src/zope/app/browser/security/grants/configure.zcml
<SteveA> Looking in that file, I find this zcml:
<SteveA> <browser:pages
<SteveA> for="zope.app.interfaces.annotation.IAnnotatable"
<SteveA> permission="zope.Security"
<SteveA> class=".rolepermissionview.RolePermissionView">
<SteveA> <browser:page name="AllRolePermissions.html"
<SteveA> attribute="index" />
<SteveA>
<SteveA>
<SteveA> and it continues.
<SteveA> So, the page isn't given directly as a page template. It is the
"index" attribute of the .rolepermissionview.RolePermissionView class
<SteveA> the leading dot means "relative the zcml file's package"
<Da> uhuh.,... so far ok...
<SteveA> there is no package="..." attribute at the top of the zcml
file, so it is the package the zcml is actually in.
<SteveA> In this case, zope.app.browser.security.grants
<SteveA> So, I look at the module in
src/zope/app/browser/secuirty/grants/rolepermissionview.py
<SteveA> Here, we see the class RolePermissionView
<SteveA> its index attribut is given by
<SteveA> index = ViewPageTemplateFile('manage_access.pt')
<SteveA> So, I look in
src/zope/app/browser/secuirty/grants/manage_access.pt
<SteveA> this is the template where the problem occurs
<SteveA> I know from the traceback that the problem is due to trying to
use the name "index", so I look in the file for all occurances of 'index'
<SteveA> There are four, in TALES path expressions embedded in string:
expressions
<SteveA> To check that this is truely the cause of the problem, I remove
the '$' character from the path expressions in string expressions that
contain 'index'
<SteveA> and refresh my browser
<SteveA> the page renders without error
<SteveA> So, I know that the problem is related to tales expressions
with repeat/variable/index
<SteveA> Next, I have to find the class that implements this, to find
out what the problem is.
<SteveA> Possible causes of the problems are:
<SteveA> * The security checker is incorrectly defined for the iterator,
so it doesn't include an 'index' name
<SteveA> * The class doesn't support the 'index' name
<SteveA> either case, or both, would produce the problem
<SteveA> for example, if the interface doesn't include the name, but the
class does, then all unit tests would pass, but we'd still see the same
problem.
<SteveA> Still following ok ?
<Da> yeah, I'm still with you :) Just sometimes a little behind...
<SteveA> Great. So, next we need to find a way to stop the python
interpreter, and inspect the object from which we cannot get 'index'
<Da> In this case its the latter?
<SteveA> We'll find out in a minute. Looking back at the traceback, the
error is raised in src/zope/app/traversing/adapters.py, line 60, method
'traverse'
<SteveA> (actually, it was line 59... I have inserted another line)
<SteveA> The lines leading up to raising the exception at line 59 look
like this:
<SteveA> if hasattr(subject, '__getitem__'):
<SteveA> # Let exceptions propagate.
<SteveA> return subject[name]
<SteveA> else:
<SteveA> raise NotFoundError(subject, name)
<SteveA> So, the problem is that 'index' is not found as an item of
whatever 'subject' is
<SteveA> actually, in the traceback, I can see that 'subject' is a
zope.tales.tales.Iterator object
<SteveA> NotFoundError: (<zope.tales.tales.Iterator object at
0x90552b4>, 'index')
<SteveA> so, that's a good start.
<SteveA> But, I want to probe this object a bit.
<SteveA> Just before the 'raise' statement, at the same level of
indentation, I insert a call to the debugger to give me an interactive
debugging session
<SteveA> if hasattr(subject, '__getitem__'):
<SteveA> # Let exceptions propagate.
<SteveA> return subject[name]
<SteveA> else:
<SteveA> import pdb; pdb.set_trace()
<SteveA> raise NotFoundError(subject, name)
<SteveA> So, here's what happened when I restarted Zope, restored the
tales in the page, and refreshed the browser:
<SteveA>
<SteveA> --Return--
<SteveA> > /usr/lib/python2.2/pdb.py(926)set_trace()->None
<SteveA> -> Pdb().set_trace()
<SteveA> (Pdb) s
<SteveA> >
/home/steve/coding/zope3/Zope3/src/zope/app/traversing/adapters.py(60)traverse()
<SteveA> -> raise NotFoundError(subject, name)
<SteveA> (Pdb) l
<SteveA> 55 if hasattr(subject, '__getitem__'):
<SteveA> 56 # Let exceptions propagate.
<SteveA> 57 return subject[name]
<SteveA> 58 else:
<SteveA> 59 import pdb; pdb.set_trace()
<SteveA> 60 -> raise NotFoundError(subject, name)
<SteveA> 61
<SteveA> 62 class ObjectName(object):
<SteveA> 63
<SteveA> 64 implements(IObjectName)
<SteveA> 65
<SteveA> (Pdb) subject
<SteveA> <zope.tales.tales.Iterator object at 0x9020c94>
<SteveA> (Pdb) subject.index
<SteveA> *** ForbiddenAttribute: index
<SteveA> (Pdb) subject.number
<SteveA> <bound method Iterator.number of <zope.tales.tales.Iterator
object at 0x9020c94>>
<SteveA>
<SteveA> The initial 's' is to get out of the call to the debugger. You
always need to do an 's' when you drop into the debugger like this.
<SteveA> The 'l' means "list the lines around where I am in the code"
<SteveA> we can see that it is just about to raise an exception
<SteveA> I type in 'subject' to see how the variable subject is represented
<SteveA> Actually, I should have said "p subject" meaning "print subject"
<SteveA> you need to do this if you want to inspect any variables that
are also pdb commands
<SteveA> 'index' is a forbidden attribute. That means the security
checker doesn't allowed it to be accessed.
<SteveA> At this point, I could have used the security API to remove the
security proxy from 'subject', and see if it as an 'index' attribute.
<Da> OK..
<SteveA> that would help me see what the problem is
<SteveA> I verify that it has a 'number' attribute anyway. Actually,
'number' is a method.
<SteveA> I press 'q' (not shown) to exit the debugger.
<SteveA> Next, I decide to look at the code to Iterator
<SteveA> it is in src/zope/tales/tales.py
<SteveA> the name 'index' appears in this file, but only as a local
variable in a method
<SteveA> There is no sign of any base-class that could provide an
'index' variable
<SteveA> One thing to notice about the Iterator class: its unit tests
are in its docstrings as DocTests.
<SteveA> These are executed as part of the unit test.
<Da> uhuh
<SteveA> So, what's needed is to add an index() method, like the number
method.
<SteveA> Notice that Iterator implements ITALESIterator
<SteveA> (there's an 'if' there, but that's just to reduce dependencies
<SteveA> )
<SteveA> So, we should see if ITALESIterator defines 'index'
<SteveA> Turns out that it doesn't.
<SteveA> So, we need to do that.
<SteveA> This is the point where I checked the spec to see if index
really should be there.
<SteveA> Turns out it should.
<SteveA> http://www.zope.org/Wikis/DevSite/Projects/ZPT/RepeatVariable
<SteveA> I also checked that all the other variables in the spec are in
the interface
<SteveA> they are
<SteveA> but curiously, there are a couple of extra names in the interface
<SteveA> there's Roman and roman, like letter and Letter
<SteveA> there's also 'item'
<SteveA> and the documentation of 'item' in the interface doesn't make
sense as English language
<SteveA> So, I add an 'index' above "number()" saying basically the same
thing,
<SteveA> but "starting with 0" rather than "starting with 1"
<SteveA> Looking back at the iterator code, it is clear from the item()
method's test that it returns the current item of the iteration
<SteveA> So, I can correct that docstring in the interface.
<SteveA> Back in the code, I can add an index() method like the number()
method, with a doctest
<SteveA> but wait... there's a problem
<SteveA> the doctest for number() doesn't say what the result should be
if number is called before the first value is obtained from the iterator
<SteveA> should it be '0'?
<SteveA> should it raise an exception?
<SteveA> The interface doesn't say.
<SteveA> For our 'index' method, what should this do?
<SteveA> Should it return -1?
<SteveA> should it raise an exception?
<SteveA> In general, it is as great a problem to over-specify an
interface as to underspecify it.
<SteveA> In many cases, leaving an interface underspecified is better.
<SteveA> It should be as specified as it needs to be.
<SteveA> In practical terms, it doesn't matter what the iterator returns
for index() and number(), and the rest of the methods, when the iterator
hasn't given up its first item
<SteveA> because it will never be used that way from TALES
<Da> In this case shouldn't we see what item number does?
<Da> ok
<SteveA> Sure. I read the code, and it looks like it will return 0
<SteveA> we can test that too, though.
<SteveA> Got a python interpreter handy?
<Da> sure :)
<SteveA> >>> from zope.tales.tales import Iterator
<SteveA> hmm... what next
<SteveA> the Iterator constructor requires four arguments
<SteveA> we have the doctest, so we can just do what that does
<SteveA> >>> context = Context(ExpressionEngine(), {})
<SteveA> >>> it = Iterator('foo', ("apple", "pear", "orange"), context)
<SteveA> That's what the doctest says
<SteveA> however, these names will be from the current module, so we
need to import them first
<SteveA> >>> from zope.tales.tales import Iterator, Context
<SteveA> >>> from zope.tales.tales import Iterator, Context,
ExpressionEngine
<SteveA> >>> context = Context(ExpressionEngine(), {})
<SteveA> >>> it = Iterator('foo', range(5), context)
<SteveA> >>>
<SteveA> >>> it.number()
<SteveA> 0
<SteveA> >>> it.roman()
<SteveA> ''
<SteveA> >>> it.letter()
<SteveA> Traceback (most recent call last):
<SteveA> File "<stdin>", line 1, in ?
<SteveA> File
"/home/steve/coding/zope3/Zope3/src/zope/tales/tales.py", line 252, in
letter
<SteveA> raise TypeError("No iteration position")
<SteveA> TypeError: No iteration position
<SteveA> aha
<Da> voila
<SteveA> >>> it.item()
<SteveA> Traceback (most recent call last):
<SteveA> File "<stdin>", line 1, in ?
<SteveA> File
"/home/steve/coding/zope3/Zope3/src/zope/tales/tales.py", line 409, in item
<SteveA> return self._item
<SteveA> AttributeError: 'Iterator' object has no attribute '_item'
<SteveA> that's not so good
<SteveA> it looks ugly
<SteveA> it looks to me like the TypeError has been thought about, and
raised on purpose
<SteveA> and the AttributeError is an accident
<SteveA> I think it.item() should raise a TypeError too in this case
<SteveA> I'll add that to the interface
<SteveA> The Roman behaviour is reasonable. The roman numeral for 0 is ''
<SteveA> but it still looks like more of an accident than anything else
<SteveA> it certainly isn't tested as such
<Da> Should they all raise exceptions?
<SteveA> perhaps
<SteveA> but, that's a lot of overhead if you use these things on each
iteration, for no real reason
<SteveA> I think I would do it for item, because its error is so ugly
<SteveA> and I'd do it for index, because I don't like having an index of -1
<Da> OK.
<SteveA> and I'd document in the interface that the behaviour for
calling anything before the first iteration is undefined
<SteveA> and essentially meaningless
<SteveA> (except length, that is)
<SteveA> O
<SteveA> I'd say that in the ITALESIterator interface docstring, rather
than in each method
<SteveA> Da: can you commit to CVS?
<Da> OK.
<Da> I can't I only use anon CVS co
<SteveA> ah, ok
<SteveA> Then, I need to do the work.
<SteveA> If you had checkin privs. then you could do it and check it in.
<SteveA> but, I hope this "tour of fixing a zope3 bug" has been helpful
<SteveA> you can get checkin privs, if you like
<Da> How do you get checking privs?
<SteveA> although it involves sending a small amount of paperwork to ZC
<Da> (I was just looking on wiki to find out)
<SteveA> http://dev.zope.org/CVS/ContributorIntroduction
<Da> Thanks a lot Steve - you've made the process a lot clearer!
<SteveA> great.
<SteveA> before I check in, i'll need to cvs up again, to make sure
no-one else has changed things in the repository while I've been working,
<SteveA> and then run all the unit tests and functional tests, and
ensure that they pass.
<SteveA> and, preferably start up zope to check it still runs correctly.
<SteveA> Of course, I should also check that the bug I'm fixing is fixed :)
<Da> Heh, for me to send the form to Fredirkburg is going to take a
while - I'm in Kuala Lumpur
--
Steve Alexander