Getting Zope code to output to event.log
To debug my code in my Zope/Plone site, I sometimes need to put logger lines into Zope/Plone code, in order to trace my way through an error traceback. I can do this easily with Plone code in the Plone Products folder: Just put in the logger line, restart Zope, run my tests, and the output appears in the Zope event.log. But when I try the same thing with native Zope code (for example, in the OFS directory), the output doesn't show up in event.log. I figure these modules have to be reinstalled or re-somethinged to get my changes activated, but I don't know how to do this. Can you help? ~ TIA ~ Ken
+-------[ Ken Winter ]---------------------- | To debug my code in my Zope/Plone site, I sometimes need to put logger lines | into Zope/Plone code, in order to trace my way through an error traceback. | | | | I can do this easily with Plone code in the Plone Products folder: Just put in | the logger line, restart Zope, run my tests, and the output appears in the Zope | event.log. But when I try the same thing with native Zope code (for example, | in the OFS directory), the output doesn?t show up in event.log. | | | | I figure these modules have to be reinstalled or re-somethinged to get my | changes activated, but I don?t know how to do this. Can you help? [this assumes the code is actually being called] You are probably logging at a level below the level that will be output into the log. LOG.info() is about the lowest level that will go out by default. Without seeing any examples from you it's hard to tell. -- Andrew Milton akm@theinternet.com.au
-----Original Message----- From: Andrew Milton [mailto:akm@theinternet.com.au] Sent: Wednesday, August 05, 2009 3:49 PM To: Ken Winter Cc: 'Zope List' Subject: Re: [Zope] Getting Zope code to output to event.log
+-------[ Ken Winter ]---------------------- | To debug my code in my Zope/Plone site, I sometimes need to put logger lines | into Zope/Plone code, in order to trace my way through an error traceback. | | | | I can do this easily with Plone code in the Plone Products folder: Just put in | the logger line, restart Zope, run my tests, and the output appears in the Zope | event.log. But when I try the same thing with native Zope code (for example, | in the OFS directory), the output doesn?t show up in event.log. | | | | I figure these modules have to be reinstalled or re-somethinged to get my | changes activated, but I don?t know how to do this. Can you help?
[this assumes the code is actually being called]
You are probably logging at a level below the level that will be output into the log.
LOG.info() is about the lowest level that will go out by default.
Without seeing any examples from you it's hard to tell.
Here's an example of the traceback from the error I'm trying to debug. I assume the fact that a module appears in the traceback proves that it is being called. 2009-08-05T15:11:20 ERROR Zope.SiteErrorLog http://instance3.dhat.webfactional.com/groups/Popper 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 Shared.DC.Scripts.Bindings, line 348, in _bindAndExec Module Products.PythonScripts.PythonScript, line 326, in _exec Module None, line 19, in Popper - <PythonScript at /groups/Popper> - Line 19 Module Products.Groups.standard_tree, line 131, in populateStandardTrees Module Products.Groups.standard_tree, line 189, in populateStandardTree Module Products.CMFCore.PortalFolder, line 414, in invokeFactory Module Products.CMFCore.TypesTool, line 937, in constructContent Module Products.CMFCore.TypesTool, line 345, in constructInstance Module Products.CMFCore.TypesTool, line 359, in _finishConstruction Module Products.CMFCore.CMFCatalogAware, line 145, in notifyWorkflowCreated Module Products.CMFCore.WorkflowTool, line 409, in notifyCreated Module Products.CMFCore.WorkflowTool, line 760, in _reindexWorkflowVariables Module Products.Archetypes.CatalogMultiplex, line 108, in reindexObjectSecurity Module Products.ZCatalog.CatalogBrains, line 52, in _unrestrictedGetObject Module OFS.Traversable, line 187, in unrestrictedTraverse - __traceback_info__: (['event', 'base-events'], 'practical-matters') Module Products.Five.traversable, line 143, in __bobo_traverse__ AttributeError: practical-matters Here's a snippet from the unrestrictedTraverse() method of instance3/Zope-2.9.8-final/lib/python/OFS/Traversable.py: ... try: obj = self while path: name = path_pop() logger.info("unrestrictedTraverse(): " "\n\t path = %r\n\t name = %r" % (path, name)) __traceback_info__ = path, name if name[0] == '_': # Never allowed in a URL. raise NotFound, name if name == '..': next = aq_parent(obj) if next is not _none: if restricted and not securityManager.validate( obj, obj,name, next): raise Unauthorized, name obj = next continue bobo_traverse = _getattr(obj, '__bobo_traverse__', _none) logger.info("unrestrictedTraverse(): before bobo_traverse") if bobo_traverse is not _none: ... The only thing I've changed in this snippet is to add the two logger lines. I also had to add these lines at the top of the Traversable.py module: import logging logger = logging.getLogger('OFS/Traversable.py:') ~ HTH ~ Ken
+-------[ Ken Winter ]---------------------- | | > -----Original Message----- | > From: Andrew Milton [mailto:akm@theinternet.com.au] | > Sent: Wednesday, August 05, 2009 3:49 PM | > To: Ken Winter | > Cc: 'Zope List' | > Subject: Re: [Zope] Getting Zope code to output to event.log | > | > +-------[ Ken Winter ]---------------------- | > | | > | I figure these modules have to be reinstalled or re-somethinged to get | > my | > | changes activated, but I don?t know how to do this. Can you help? | > | > [this assumes the code is actually being called] | > | > You are probably logging at a level below the level that will be output | > into the log. | > | > LOG.info() is about the lowest level that will go out by default. | > | > Without seeing any examples from you it's hard to tell. | | Here's an example of the traceback from the error I'm trying to debug. I | assume the fact that a module appears in the traceback proves that it is | being called. And you have your logging level set to what? Look in your zope.conf for <eventlog> it should be similar to; <eventlog> level INFO <logfile> path $INSTANCE/log/event.log </logfile> </eventlog> You can also try changing logger.info to logger.warn or logger.error -- Andrew Milton akm@theinternet.com.au
Andrew & Chris ~ Thanks, but it still doesn't work for me. See details of what happened when I tried each of your suggestions below. ~ Ken
-----Original Message----- From: Andrew Milton [mailto:akm@theinternet.com.au] Sent: Wednesday, August 05, 2009 6:47 PM To: Ken Winter Cc: 'Andrew Milton'; 'Zope List' Subject: Re: [Zope] Getting Zope code to output to event.log
+-------[ Ken Winter ]---------------------- | | > -----Original Message----- | > From: Andrew Milton [mailto:akm@theinternet.com.au] | > Sent: Wednesday, August 05, 2009 3:49 PM | > To: Ken Winter | > Cc: 'Zope List' | > Subject: Re: [Zope] Getting Zope code to output to event.log | > | > +-------[ Ken Winter ]---------------------- | > | | > | I figure these modules have to be reinstalled or re-somethinged to get | > my | > | changes activated, but I don?t know how to do this. Can you help? | > | > [this assumes the code is actually being called] | > | > You are probably logging at a level below the level that will be output | > into the log. | > | > LOG.info() is about the lowest level that will go out by default. | > | > Without seeing any examples from you it's hard to tell. | | Here's an example of the traceback from the error I'm trying to debug. I | assume the fact that a module appears in the traceback proves that it is | being called.
And you have your logging level set to what?
Look in your zope.conf for <eventlog> it should be similar to;
<eventlog> level INFO <logfile> path $INSTANCE/log/event.log </logfile> </eventlog>
My event.log setting is... <eventlog> level all <logfile> path /home/dhat/webapps/instance3/Zope-2.9.8-final.instance/log/event.log level info </logfile> </eventlog> ...which seems even more permissive than your example. However, I also noticed this... <logger access> level warn <logfile> path /home/dhat/logs/user/Z2_zope_instance3.log format %(message)s </logfile> </logger> ...which may mean that the logger tool is not being called for levels less than WARN. So I changed that line to "level info", and restarted Zope. No change.
You can also try changing logger.info to logger.warn or logger.error
Next, I tried logger.warn, and restarted Zope. No change. Then I tried Chris Withers' suggestion: "Try changing logger = logging.getLogger('OFS/Traversable.py:') to: logger = logging.getLogger('event.OFS/Traversable.py:')" No change.
+-------[ Ken Winter ]---------------------- | Andrew & Chris ~ | | Thanks, but it still doesn't work for me. See details of what happened when | I tried each of your suggestions below. [snip] | > | > You can also try changing logger.info to logger.warn or logger.error | > | | Next, I tried logger.warn, and restarted Zope. | | No change. I would suggest then that your zope user does not have write access to the OFS directory (or the files), and cannot create new .pyc files and is using the existing ones (without the logging). Or that you are not changing the code that is being executed... -- Andrew Milton akm@theinternet.com.au
I do have write access to the Zope files I'm =editing, as I can see the updated timestamp change when I save them. However, I do notice that there are NO .pyc files in the directories that contain the files that I am editing. I'm way out of my depth here: Does the lack of .pyc files mean that the .py files here are not the ones being compiled/executed? ~ Tx Ken
-----Original Message----- From: Andrew Milton [mailto:akm@theinternet.com.au] Sent: Monday, August 10, 2009 1:09 PM To: Ken Winter Cc: 'Zope List' Subject: Re: [Zope] Getting Zope code to output to event.log
+-------[ Ken Winter ]---------------------- | Andrew & Chris ~ | | Thanks, but it still doesn't work for me. See details of what happened when | I tried each of your suggestions below.
[snip]
| > | > You can also try changing logger.info to logger.warn or logger.error | > | | Next, I tried logger.warn, and restarted Zope. | | No change.
I would suggest then that your zope user does not have write access to the OFS directory (or the files), and cannot create new .pyc files and is using the existing ones (without the logging).
Or that you are not changing the code that is being executed...
-- Andrew Milton akm@theinternet.com.au
+-------[ Ken Winter ]---------------------- | I do have write access to the Zope files I'm =editing, as I can see the | updated timestamp change when I save them. But Zope might not... | | However, I do notice that there are NO .pyc files in the directories that | contain the files that I am editing. I'm way out of my depth here: Does the | lack of .pyc files mean that the .py files here are not the ones being | compiled/executed? It's odd that there are no .pyc files, at a minimum the install normally byte-compiles them as part of the install. Perhaps you are editing the unpacked source, instead of the installed Zope code. Check your zopectl or runzope script and see what ZOPE_HOME is set to. The that *should* be the root of your installed zope. -- Andrew Milton akm@theinternet.com.au
Eureka! Yes, I was editing the unpacked source, which is in a directory named: /home/dhat/webapps/instance3/Zope-2.9.8-final.install At your suggestion, I found this in zopectl: @set ZOPE_HOME=/home/dhat/webapps/instance3/Zope-2.9.8-final.install @set INSTANCE_HOME=/home/dhat/webapps/instance3/Zope-2.9.8-final.instance And as soon as I started putting logger lines into the ZOPE_HOME code, they came out fine! ~ Thanks so much! ~ Ken
-----Original Message----- From: Andrew Milton [mailto:akm@theinternet.com.au] Sent: Monday, August 10, 2009 1:34 PM To: Ken Winter Cc: 'Andrew Milton'; 'Zope List' Subject: Re: [Zope] Getting Zope code to output to event.log
...
Perhaps you are editing the unpacked source, instead of the installed Zope code.
Check your zopectl or runzope script and see what ZOPE_HOME is set to. The that *should* be the root of your installed zope.
-- Andrew Milton akm@theinternet.com.au
Ken Winter wrote:
import logging logger = logging.getLogger('OFS/Traversable.py:')
Try changing this to: logger = logging.getLogger('event.OFS/Traversable.py:') cheers, Chris -- Simplistix - Content Management, Batch Processing & Python Consulting - http://www.simplistix.co.uk
participants (3)
-
Andrew Milton -
Chris Withers -
Ken Winter