Empty logfiles after logrotating with logrotated

[Édouard Thuleau]

I use the following logrotate script to archive the Glance logfiles:

$ cat /etc/logrotate.d/glance
/var/log/glance/glance.log {
    daily
    missingok
}

Problem is, that Glance doesn't write logdata after rotating the logfiles.
A restart of the service is required.

host:/var/log/glance$ ls -lh
total 15M
-rw-r--r-- 1 glance root 0 2011-04-28 08:00 glance.log
-rw-r--r-- 1 glance root 15M 2011-04-28 15:46 glance.log.1

This bug was fixed in Nova (cf. https://bugs.launchpad.net/nova/+bug/721141)

[Jay Pipes (jaypipes)]

Heh, I even made a note to myself to address this when I did logging...and subsequently ignored my own note :(

I'll get working on this shortly.

Cheers,
jay

[Jay Pipes (jaypipes)]

ping. hi, Edouard. Would you mind posting the contents of your current glance-api.conf (and glance-registry.conf).

I need to figure out if this is something we can solve with the logging configuration file, or something we need to change in the code.

Thanks!
-jay

[Édouard Thuleau (ethuleau)]

API:

[DEFAULT]
# Show more verbose log output (sets INFO log level output)
verbose = True

# Show debugging output in logs (sets DEBUG log level output)
debug = True

# Which backend store should Glance use by default is not specified
# in a request to add a new image to Glance? Default: 'file'
# Available choices are 'file', 'swift', and 's3'
default_store = file

# Address to bind the API server
bind_host = 0.0.0.0

# Port the bind the API server to
bind_port = 9292

# Address to find the registry server
registry_host = 0.0.0.0

# Port the registry server is listening on
registry_port = 9191

# Log to this file. Make sure you do not set the same log
# file for both the API and registry servers!
log_file = /var/log/glance/api.log

# ============ Filesystem Store Options ========================

# Directory that the Filesystem backend store
# writes image data to
filesystem_store_datadir = /media/nas/OpenStack/Glance/

# ============ Swift Store Options =============================

# Address where the Swift authentication service lives
swift_store_auth_address = 127.0.0.1:8080/v1.0/

# User to authenticate against the Swift authentication service
swift_store_user = jdoe

# Auth key for the user authenticating against the
# Swift authentication service
swift_store_key = a86850deb2742ec3cb41518e26aa2d89

# Container within the account that the account should use
# for storing images in Swift
swift_store_container = glance

# Do we create the container if it does not exist?
swift_store_create_container_on_put = False

[pipeline:glance-api]
pipeline = versionnegotiation apiv1app

[pipeline:versions]
pipeline = versionsapp

[app:versionsapp]
paste.app_factory = glance.api.versions:app_factory

[app:apiv1app]
paste.app_factory = glance.api.v1:app_factory

[filter:versionnegotiation]
paste.filter_factory = glance.api.middleware.version_negotiation:filter_factory

#####################################################
#####################################################
#####################################################

REGISTRY:

[DEFAULT]
# Show more verbose log output (sets INFO log level output)
verbose = True

# Show debugging output in logs (sets DEBUG log level output)
debug = True

# Address to bind the registry server
bind_host = 0.0.0.0

# Port the bind the registry server to
bind_port = 9191

# Log to this file. Make sure you do not set the same log
# file for both the API and registry servers!
log_file = /var/log/glance/registry.log

# SQLAlchemy connection string for the reference implementation
# registry server. Any valid SQLAlchemy connection string is fine.
# See: http://www.sqlalchemy.org/docs/05/reference/sqlalchemy/connections.html#sqlalchemy.create_engine
sql_connection=mysql://root:nova@127.0.0.1/glance

# Period in seconds after which SQLAlchemy should reestablish its connection
# to the database.
#
# MySQL uses a default `wait_timeout` of 8 hours, after which it will drop
# idle connections. This can result in 'MySQL Gone Away' exceptions. If you
# notice this, you can lower this value to ensure that SQLAlchemy reconnects
# before MySQL can drop the connection.
sql_idle_timeout = 3600

[app:glance-registry]
paste.app_f...

[Mark McLoughlin (markmc)]

We just need to change from FileHandler to WatchedFileHandler

Will submit a patch with test case to gerrit

[Mark McLoughlin (markmc)]

Here's the gerrit submission:

  https://review.openstack.org/340

Not convinced I fully understand the process yet :-)

[Jay Pipes (jaypipes)]

You did just fine! :) Thanks, Marc!

[Openstack Gerrit (openstack-gerrit)]

Reviewed: https://review.openstack.org/340
Committed: http://github.com/openstack/glance/commit/ecbcc09ce5c337a84d8adf19f957529c4f76a075
Submitter: Jenkins
Branch: master

 status fixcommitted
 done

commit ecbcc09ce5c337a84d8adf19f957529c4f76a075
Author: Mark McLoughlin <email address hidden>
Date: Thu Aug 25 12:20:51 2011 +0100

    Switch file based logging to WatchedFileHandler for logrotate

    Fixes lp:772397

    FileHandler opens the logfile at startup, keeps the stream open and
    continues to log to it forever.

    If logrotate decides to rotate the file, it will rename the original
    file and a new file is created with the same attributes as the original
    file.

    The problem is that the process is still writing to the original file,
    not the newly created file. Traditionally, system daemons respond to
    a SIGHUP by re-opening log files and logrotate can be configured to
    deliver this signal on rotation.

    However, python has an elegant solution. WatchedFileHandler monitors
    the inode for the specified log file name and, if that ever changes,
    it re-opens the stream.

    Nova already uses WatchedFileHandler to good effect. See:

      https://code.launchpad.net/~soren/nova/logrotate/+merge/50292

    Change-Id: I7f693f133d230d65d7c94ebf3a2ec0c8b362f993

[Openstack Gerrit (openstack-gerrit)]

Reviewed: https://review.openstack.org/348
Committed: http://github.com/openstack/glance/commit/20f09f6bd589613043e5b1eba70aa38bb63746b4
Submitter: Jenkins
Branch: milestone-proposed

 status fixcommitted
 done

commit 20f09f6bd589613043e5b1eba70aa38bb63746b4
Author: Mark McLoughlin <email address hidden>
Date: Thu Aug 25 12:20:51 2011 +0100

    Switch file based logging to WatchedFileHandler for logrotate

    Fixes lp:772397

    FileHandler opens the logfile at startup, keeps the stream open and
    continues to log to it forever.

    If logrotate decides to rotate the file, it will rename the original
    file and a new file is created with the same attributes as the original
    file.

    The problem is that the process is still writing to the original file,
    not the newly created file. Traditionally, system daemons respond to
    a SIGHUP by re-opening log files and logrotate can be configured to
    deliver this signal on rotation.

    However, python has an elegant solution. WatchedFileHandler monitors
    the inode for the specified log file name and, if that ever changes,
    it re-opens the stream.

    Nova already uses WatchedFileHandler to good effect. See:

      https://code.launchpad.net/~soren/nova/logrotate/+merge/50292

    Change-Id: I7f693f133d230d65d7c94ebf3a2ec0c8b362f993