Edgewall Software
Modify

Opened 13 years ago

Last modified 11 months ago

#7820 new defect

[PATCH] Syslog Logging Not Working on FreeBSD

Reported by: david@… Owned by:
Priority: normal Milestone: next-dev-1.7.x
Component: general Version: none
Severity: normal Keywords: patch syslog freebsd bitesized logging
Cc: packet@… Branch:
Release Notes:

The logger can be configured using a Configuration File.

API Changes:
Internal Changes:

Description

FreeBSD's syslog doesn't listen on /dev/log. It uses /var/run/log. Attached is a patch that allows you to specify the path to the UNIX socket instead of hardcoding it. It basically uses the logfile parameter, if it's None use /dev/log otherwise use it.

This bug affects all versions of Trac since about 0.7 it looks like.

Attachments (5)

syslog-path.patch (662 bytes ) - added by david@… 13 years ago.
Patch for 0.10-stable and trunk. Overrides handling of UNIX socket path via logfile parameter.
syslog-removepath.patch (543 bytes ) - added by david@… 13 years ago.
It's also possible to just remove the explicit path, and everything Just Works(tm) (at least on Python 2.5.2).
logging_config.patch (7.5 KB ) - added by Sebastian Klemke <packet@…> 6 years ago.
Updated logging config patch. Adds the path, basename, project log format substitutions.
logging.ini (342 bytes ) - added by Sebastian Klemke <packet@…> 6 years ago.
Logging config ini file to log to syslog on FreeBSD
logging_config_adminpanel.patch (3.9 KB ) - added by Sebastian Klemke <packet@…> 6 years ago.
Patch to the admin panel to add log_config support.

Download all attachments as: .zip

Change History (29)

by david@…, 13 years ago

Attachment: syslog-path.patch added

Patch for 0.10-stable and trunk. Overrides handling of UNIX socket path via logfile parameter.

by david@…, 13 years ago

Attachment: syslog-removepath.patch added

It's also possible to just remove the explicit path, and everything Just Works(tm) (at least on Python 2.5.2).

comment:1 by Christian Boos, 13 years ago

Milestone: 0.13

My preference goes to attachment:syslog-removepath.patch.

Moving to 0.13 so that we don't have to bother with Python 2.3.

Should be verified for 2.4 as well, and on other platforms if needed (MacOS X?)

comment:2 by george@…, 12 years ago

Yes, this works for OS 10.6 with the built-in Python 2.6.

comment:3 by Remy Blank, 11 years ago

Cc: bitesized added

According to the Python documentation:

  • Passing no argument to SysLogHandler connects to the syslog via UDP port 514 on localhost.
  • Specifying a string argument to SysLogHandler is only documented since 2.5, but is actually supported earlier (2.3 is the oldest I checked), and connects to a UNIX socket.

Considering this, we could support both variants, which comes closer to the first patch:

  • Add a new parameter logdest.
  • If logdest starts with UDP:, we pass the remaining string as a hostname and log via UDP to that host (which could be localhost). This would also allow logging remotely.
  • Otherwise, logdest is passed as a string and we log to a UNIX socket.

Re-using logfile for this purpose is probably a bad idea, as the default value is trac.log.

comment:4 by Remy Blank, 11 years ago

Cc: bitesized removed
Keywords: bitesized added

Oops, wrong field :)

comment:5 by Ryan J Ollos, 6 years ago

#11216 closed as a duplicate, additionally requesting the ability to set the syslog facility. ticket:11216:logging_config.patch adds a log_config option which points to a dedicated logging configuration file.

by Sebastian Klemke <packet@…>, 6 years ago

Attachment: logging_config.patch added

Updated logging config patch. Adds the path, basename, project log format substitutions.

by Sebastian Klemke <packet@…>, 6 years ago

Attachment: logging.ini added

Logging config ini file to log to syslog on FreeBSD

comment:6 by Sebastian Klemke <packet@…>, 6 years ago

Cc: packet@… added

by Sebastian Klemke <packet@…>, 6 years ago

Patch to the admin panel to add log_config support.

comment:7 by Ryan J Ollos, 6 years ago

The patch looks pretty good. The biggest thing that will delay getting this committed is the lack of unit tests. If some unit tests were added this could be included in milestone:1.2.

comment:8 by Ryan J Ollos, 6 years ago

See also #11874. The proposed changes in that ticket would be a good follow-on to this ticket.

comment:9 by Ryan J Ollos, 6 years ago

Keywords: logging added
Milestone: next-major-releases1.2

comment:10 by Ryan J Ollos, 6 years ago

Owner: set to Ryan J Ollos
Status: newassigned

comment:11 by Ryan J Ollos, 6 years ago

Minor refactorings in [14333:14336].

Revised changes in log:rjollos.git:t7820_logging_config. The revised changes avoid API changes that were present in attachment:logging_config.patch. Some of those changes have been deferred to #11874 (comment:10:ticket:11874).

I'll do more testing and add unit tests.

Last edited 6 years ago by Ryan J Ollos (previous) (diff)

comment:12 by Ryan J Ollos, 6 years ago

TODO Add documentation to TracLogging.

comment:13 by Jun Omae, 6 years ago

At least, we should use disable_existing_loggers=False for the logging.config.fileConfig(). I guess that call of the fileConfig() would stop loggers of other environments with multiple projects.

See:

Last edited 6 years ago by Ryan J Ollos (previous) (diff)

comment:14 by Ryan J Ollos, 6 years ago

Release Notes: modified (diff)

comment:15 by figaro, 6 years ago

Keywords: patch added

comment:16 by Ryan J Ollos, 6 years ago

Milestone: 1.21.3.1

comment:17 by Ryan J Ollos, 5 years ago

comment:18 by Jun Omae, 5 years ago

The resource of the logging handler isn't closed even though calling Environment.shutdown().

logging.ini has the following.

[formatters]
keys=form01

[logger_root]
level=NOTSET
handlers=hand01

[handler_hand01]
class=FileHandler
level=NOTSET
formatter=form01
args=('/tmp/trac.log',)

[formatter_form01]
class=logging.Formatter
format=Trac %(asctime)s %(levelname)s %(message)s

After constructing Environment object, the logger is initialized and the /tmp/trac.log is opened.

>>> from trac.env import Environment
>>> env = Environment('/home/jun66j5/var/trac/1.3dev-sqlite')
>>> import os
>>> os.getpid()
4625
>>> os.system('lsof -p 4625 | tail -4')
python  4625 jun66j5    0u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    1u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    2u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    3w   REG    8,1    14517  268820 /tmp/trac.log
0

However, the /tmp/trac.log is still opened after call of Environment.shutdown(). No way to close the resource.

>>> env.shutdown()
>>> os.system('lsof -p 4625 | tail -4')
python  4625 jun66j5    0u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    1u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    2u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    3w   REG    8,1    14517  268820 /tmp/trac.log
0
>>> del env
>>> env
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
NameError: name 'env' is not defined
>>> import gc
>>> gc.collect()
732
>>> gc.collect()
0
>>> os.system('lsof -p 4625 | tail -4')
python  4625 jun66j5    0u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    1u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    2u   CHR  136,0      0t0       3 /dev/pts/0
python  4625 jun66j5    3w   REG    8,1    14517  268820 /tmp/trac.log
0

in reply to:  18 comment:19 by Ryan J Ollos, 5 years ago

Replying to Jun Omae:

The resource of the logging handler isn't closed even though calling Environment.shutdown().

Thanks for noticing. I have a possible solution for that issue, but there are a few related issues to work through. Handling multiple environments, each with their own logger, may be tricky. I'll post some more changes and comments soon.

comment:20 by Ryan J Ollos, 5 years ago

There are numerous issues that need to be worked out, the first of which is for the Environment to get the name of the logger to use, as pointed out in comment:18. I considered a few ways to approach this:

  • Add a [logging] configuration option, logger_name. This seems like a redundant specification since the logger name is specified in the logging.ini file, but it could be useful in the case that logging.ini defined loggers for several environments, and each environment pointed to the same logging.ini (which itself presents issues, to be discussed).
  • Parse logging.ini to get the logger name before calling fileConfig. An imposed constraint would be that logging.ini can only contain the configuration for single logger, and possibly the root logger as well. Python 3.4 allows an instance derived from RawConfigParser to be passed as fname, which would fit this pattern.
  • Reimplement fileConfig in trac.log, returning the name of the logger. The constraint of one logger per configuration file (not including root), would need to be imposed.

I'm inclined to go with the last solution because the implementation of fileConfig has several issues that could be solved with a rewrite.

  • fileConfig calls _install_loggers, which removes all handlers for the root logger. With multiple environments we might want to use the root logger to share configuration across all the environments, but we don't want the root logger to be reset each time an environment reads its logging.ini.
  • The internal list of handlers is cleared each time a logging config file is read. fileConfig doesn't support incremental configuration. DictConfig does support incremental configuration, but I'm not sure the implementation is quite what we want.

The way fileConfig is implemented, I'm inclined to think that the expected use would be to load logging.ini at application scope, then have a logger_name configuration option so that each Environment knows which logger to use. However, Trac doesn't have an application scope configuration whereby we could load the logging configuration at application startup. Or, maybe I'm wrong about this, and Trac's means of application-scope configuration is to use environment variables, which might work in this case.

Side note: the Python documentation recommends using dictConfig rather than fileConfig, but I think fileConfig is pretty close to what we want with Trac since we already use the ini file format for trac.ini. I've studied the source code for logging.config and there are other warts, which I won't go into because I think I see a path to a reasonable solution.

I don't want to overcomplicate the implementation prior to getting feedback on use cases, so I'm suggesting the following constraints:

  • Each environment should have its own logging.ini file and that file should define the name of a single logger that is used only by that environment.
  • To share a configuration among multiple environments (e.g. have them all log to the same file), the root logger should be configured.

The re-implementation of fileConfig will return the name of the logger that has been read from logging.ini and the Trac environment will clean up the handlers for its loggers on shutdown.

I'm not quite sure how to handle configuring the root logger in a multi-environment configuration. If the root logger is configured in logging.ini for every environment, then it will be recreated when each Environment is created. It's also not clear to me which Environment should be responsible for cleaning up the handlers for the root logger. Maybe that would be accomplished by a shutdown function called by atexit.

On the other hand, if we make a single environment responsible for configuration and cleaning up the root logger, then we need to make sure that environment is started first.

I'm considering something like the following as a solution. Store the logger config in its own file, or use a prefix like file:// (inspired by cfg://), to point to the root config file from every logging.ini. With the logging config in its own file, we could store the timestamp of that file and only reload the root configuration file when the timestamp has changed. I'm assuming we could use a class or module scope variable to store the timestamp so that the timestamp would be seen by all environments running in the same process. However, it's possible I don't understand all the possible runtime configurations that need to be accounted for. I'm assuming that under any configuration, we only need to account for multiple environments running in the same process, and that the state of class or module scope variables will be shared across all environments running in the same process, but no environments running outside the process. I'm also assuming we may need to put a lock on any such variables since they could be written to from multiple threads running in the process.

Another possible solution, mentioned earlier, would be to configure the root logger at application scope.

comment:21 by Christian Boos, 5 years ago

Milestone: 1.3.1next-dev-1.3.x

Moving to some later 1.3.x version.

comment:22 by Ryan J Ollos, 2 years ago

Milestone: next-dev-1.3.xnext-dev-1.5.x

Milestone renamed

comment:23 by Ryan J Ollos, 2 years ago

Owner: Ryan J Ollos removed
Status: assignednew

comment:24 by Ryan J Ollos, 11 months ago

Milestone: next-dev-1.5.xnext-dev-1.7.x

Milestone renamed

Modify Ticket

Change Properties
Set your email in Preferences
Action
as new The ticket will remain with no owner.
The ticket will be disowned.
as The resolution will be set. Next status will be 'closed'.
The owner will be changed from (none) to anonymous. Next status will be 'assigned'.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.