flask-apscheduler scheduled job only logs the first time of execution

[bowenli86]

Hi Vinicius,

I configured a test cron job and logging in Flask. That job has logging inside it. I observed that job only logs the first time of execution to file, and all following loggings are missing.

Here's my code:

# module: mymodule
import logging
logger = logging.getLogger('myapp')

def job(a, b):
    print("Start test job")
    logger.info("Start test job")

class ScheduledJobConfigs(object):
    JOBS = [
        {
            'id': 'test',
            'func': 'mymodule:job',
            'args': (0, 1),
            'trigger': 'cron',
            'second': '*/5'
        },
    ]

    SCHEDULER_API_ENABLED = True

app = Flask('myapp')

if __name__ == '__main__':
    # Setup logging
    handler = RotatingFileHandler('myapp.log', maxBytes=10000, backupCount=1)
    handler.setLevel(logging.INFO)
    handler.setFormatter(logging.Formatter(
        '%(asctime)s %(levelname)s: %(message)s '
        '[in %(module)s.%(filename)s:%(lineno)d]'))
    app.logger.addHandler(handler)
    app.logger.setLevel(logging.INFO)

    # Setup APScheduler
    app.config.from_object(ScheduledJobConfigs())
    scheduler = APScheduler()
    scheduler.api_enabled = True
    scheduler.init_app(app)
    scheduler.start()

    app.run()

Since 'job' is configured to run every 5 sec, I expect to see "Start test job" from both console and myapp.log file every 5 sec. But the reality is, I saw new "Start test job" from console every 5 sec, but "Start test job" only shows once in myapp.log.

This seems to be not specific to cron triggered job. I tested interval triggered job and it has the same problem. Is this a bug, or I didn't configure logging correctly for APScheduler?

Thanks,
Bowen

[bowenli86]

Intesting - if I remove print("Start test job") from code, the logging shows as expected. So apparently console print somehow disrupts file logging of scheduled job.

[viniciuschiele]

Hi @bowenli86

Thanks for providing a full example.

I ran your example here and it worked well even with print.

Are you using only one .py file that contains the app initialization and the job method? If so, it causes weird things because the module is loaded twice (one by python and another time by APScheduler).
I would recommend you to use at least two files, one with your job method (jobs.py) and another one with the Flask/APscheduler intialization (app.py)

If that is not your case, it should work well, I don't see how a print could break the logging file.

Are you using Python 3?

[bowenli86]

Hi @viniciuschiele

I have three files as shown above.

I'm using Python3. Could that be a problem?

[viniciuschiele]

I'm using Python 3.5.2 and it works well, not sure what is the problem.

[viniciuschiele]

Feel free to reopen it again if you need it.