How to enable logging when using the instance "run" command?

Hey Folks,

We are rewriting some scripts to stop using clock server and start using crontab.

To be simple, I wrote a simple script to call the already existent view with crontab:

# -*- coding: utf-8 -*-
"""scripts/call_view.py"""
from plone import api

import sys
import transaction


portal = api.portal.get()
view_name = sys.argv[-1]
api.content.get_view(name=view_name, context=portal, request=app.REQUEST)()
transaction.commit()

And add the call of this script at our buildout with crontab:

#example_buildout.cfg
[buildout]
parts +=
    process-analytics
    process-feeds
    process-cma

[process-analytics]
recipe = z3c.recipe.usercrontab
times = 0 */2 * * *
command = ${buildout:bin-directory}/instance -O Plone run ${buildout:directory}/scripts/call-view.py process-analytics

[process-feeds]
recipe = z3c.recipe.usercrontab
times = 20 * * * *
command = ${buildout:bin-directory}/instance -O Plone run ${buildout:directory}/scripts/call-view.py process-all-feeds

[process-cma]
recipe = z3c.recipe.usercrontab
times = 40 */4 * * *
command = ${buildout:bin-directory}/instance -O Plone run ${buildout:directory}/scripts/call-view.py process-cma

Like this scripts are running fine, but the logger inside the views are not.

Can someone guide me on how to make logger work again?

1 Like

Hi man!

Does not it just work with "import logging" or like here https://docs.plone.org/4/en/develop/plone/misc/commandline.html#spoofing-http-request?

  1.  # -*- coding: utf-8 -*-
    
  2. """scripts/call_view.py"""
    
  3. from plone import api
    
  4. import sys, **logging**
    
  5. import transaction
    
  6. **logger = logging.getLogger('My Magic Script')**
    
  7. portal = api.portal.get()
    
  8. view_name = sys.argv[-1]
    
  9. api.content.get_view(name=view_name, context=portal, request=app.REQUEST)()
    
  10. **logger.info('Yes we can!')**
    
  11. transaction.commit()

If you are looking for persistent per-object logging then check out zopyx.plone.persistenlogger.

Thanks for the answer!

I tried something like what you said, but the messages is not getting into var/log/instance.log when I use instance run

Also, my view already has the logger, it worked fine with clock server, so my script don't need to add a new logger.

It is just not working when I execute this way for some reason..

Thank you for the link, but that's not what I need..

We had a similar issue and ended creating a specific logger in the script
that logged to a specific log file instead of to instance.log

nice @erral! I tried something like this yesterday without success.. is it possible to share this code?

Would https://github.com/collective/collective.fingerpointing/blob/b9ce87a411de9bf81acbda9b7e4b03807578ffa7/src/collective/fingerpointing/logger.py be a start for you creating a custom logger for your package @rodfersou ?

The real question here is: does anybody knows why the instance logger doesn't work when using the "run" command?

As @rodfersou mentioned we are using code with logger.info() calls that normally are dumped to an instance.log file then the instance is running using instance start. But those same calls don't log anything when the code is called using instance run.

I made a test and I noticed that only WARN level is shown in the display even when have configured the access log at INFO level.

Is there a way to change this behavior?

3 Likes

We agree with you, the suggestion was a last case scenario. Don't know if it's really necessary, but did you try to spoof the REQUEST and see if it works? Or add a new handler to the log like it's shown in the spoof REQUEST code snippet?

It's something like this

import logging
import sys
import os

# Force application logging level to INFO and log output to stdout for all loggers
root_logger = logging.getLogger()
root_logger.setLevel(logging.INFO)

handler = logging.StreamHandler(sys.stdout)
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
handler.setFormatter(formatter)
root_logger.addHandler(handler)
dir_path = os.path.dirname(os.path.realpath(os.path.realpath(sys.argv[-1])))
fh = logging.FileHandler('{}/var/log/directory_full_import.log'.format(dir_path))
fh.setLevel(logging.INFO)
fh.setFormatter(formatter)
root_logger.addHandler(fh)

from logging import getLogger
log = getLogger('directory_full_import')
1 Like

OMG.. too much code for something that should just work in first place..

Can someone point out if is it possible to fix in the core?

We always use messages on the WARN level in run scripts - even so this is annoying. We had a look into the code but there seems no easy way to change this behaviour. A ticket in the Zope issue tracker would be nice.

1 Like

done: https://github.com/zopefoundation/Zope/issues/161

1 Like