[PATCH] trac becomes unusable after entering a log file path without proper permissions

[bernardfrancois]

If you enter a log file path without proper permissions, trac totally breaks. You get an 'Internal Server Error' message on every page.

The only remedy I found is by changing the path again in the trac.ini file.

I reported this bug in the ubuntu launchpad:

​https://bugs.launchpad.net/ubuntu/+source/trac/+bug/469641

[anonymous]

Note: for example, enter '/trac.log' as log file path, and see what happens…

[anonymous]

I second that bug. I'm using Trac 0.11.5 under Ubuntu 9.10.

With:

[logging]
log_type = file
log_level = DEBUG 
lof_file = /some/path/trac/doesnt/have/permission/to

gives:

Internal Server Error

TracError: IOError: (13, 'Permission denied')

IMHO, Trac should be more forgiving in this case of misconfiguration.

[martin@…]

comment:2 is me, forgot my email address.

[Tim Hatch]

Eli, we should make a test for this.

[Carsten Klein <carsten.klein@…>]

I believe that the main problem lies in log.FileHandler#_open, which uncoditionally tries to open the file.

However, I'd rather display a more detailed error message to the user than simply ignoring the fact that logging was disabled.

So, basically in trac.web.main#_dispatch_request(…)

    try:
        if not env and env_error:
            raise HTTPInternalError(env_error)

The error should be made more clear to the user.

Don't know if this would require additional work on env.Environment#setup_log() where it will create the log file.

[Thijs Triemstra]

patch against 0.12-stable r10370

[Thijs Triemstra]

Attached a patch that prints a more descriptive error when a log file can't be saved:

Error

TracError: Permissions error for Trac log file. Unable to write: /etc/trac.log

[Remy Blank]

That's a first step. However, your access constant is wrong, I believe. The correct test would be:

if not os.access(logfile, os.F_OK | os.W_OK):

I wonder if it would be worth allowing the environment to work even without a log file. That is, instead of raising an exception, create a null handler instead of the FileHandler. Bonus points if all web accesses by a TRAC_ADMIN then display a warning explaining the issue, and the same with trac-admin calls.

Putting on my todo list to already apply the simple solution.

[Remy Blank]

There's another issue with this patch: it doesn't allow the initial creation of the log file.

[anonymous]

Backlink to #9914: A wrong path because of using slash instead backslash makes trac unusable until the admin fixes the path in trac.ini. The webinterface input handler must be robust enough to stand such misconfiguration.

[Remy Blank]

This shouldn't block 0.12.2. We can move it back when the patch is updated.

[Mikhail Terekhov <termim@…>]

another patch against trunk r10771

[Mikhail Terekhov <termim@…>]

Somewhat simpler variant of this simple patch against current trunk (r10771).

Could we please move it to 0.13?

[Christian Boos]

I wouldn't use i18n here, it's too low-level. Also, in case of such a failure we should try to setup a fallback logger on stderr.

[Christian Boos]

What about this?

trac/env.py

@@ -636 +636 @@
                      .replace('%(path)s', self.path) \
                      .replace('%(basename)s', os.path.basename(self.path)) \
                      .replace('%(project)s', self.project_name)
-        self.log, self._log_handler = logger_handler_factory(
-            logtype, logfile, self.log_level, logid, format=format)
+        try:
+            log_and_handler = logger_handler_factory(
+                logtype, logfile, self.log_level, logid, format=format)
+        except Exception, e:
+            log_and_handler = logger_handler_factory(
+                'stderr', '', self.log_level, logid, format=format)
+            log_and_handler[0].error("Error creating the %s log handler (%s), "
+                                     "falling back to stderr",
+                                     logtype, exception_to_unicode(e))
+            self.config.set('logging', 'log_type', 'stderr')
+        self.log, self._log_handler = log_and_handler
         from trac import core, __version__ as VERSION
         self.log.info('-' * 32 + ' environment startup [Trac %s] ' + '-' * 32,
                       get_pkginfo(core).get('version', VERSION))

[Ryan J Ollos]

The patch in comment:15 looks okay to me. We might consider being more specific about the exceptions we trap though.

[Ryan J Ollos]

With this ticket having been open for so long, I'm going to take the approach that an imperfect solution is better than no solution. The behavior can always be further improved later on.

Proposed change in [93c1700f/rjollos.git]. Most of all, I just want to make sure that a configuration change through the Admin Logging page does not make the Trac instance unusable. I think that's unacceptable behavior.

Additionally, I considered showing the exception as a warning for admin users:

trac/env.py

@@ -236 +236 @@
         self.path = os.path.normpath(os.path.normcase(path))
         self.log = None
         self.config = None
+        self.logger_exception = None
 
         if create:
             self.create(options)
@@ -630 +631 @@
         except Exception as e:
             self.log = create_logger('stderr')
             self.log.error("Logger configuration error: %s", e)
+            self.logger_exception = e
         self.log.info('-' * 32 + ' environment startup [Trac %s] ' + '-' * 32,
                       self.trac_version)
 

trac/web/main.py

@@ -190 +190 @@
         self.log.debug('Dispatching %r', req)
         chrome = Chrome(self.env)
 
+        if self.env.logger_exception and 'TRAC_ADMIN' in req.perm:
+            add_warning(req, _("Logger configuration error: %(error)s",
+                               error=self.env.logger_exception))
+
         try:
             # Select the component that should handle the request
             chosen_handler = None

Alternatively, we could only show the error when the path is /admin/general/logging. We could also print the warning when trac-admin is called. Is it worth the extra complexity?

At a minimum, I just want to get a fix committed so that the Trac instance can't be made unusable by a configuration change from the Logging Admin page. Particularly since I will propose changes for #7820 soon, and without the fix there will be more options that can lead to a mis-configured logger that can make the Trac instance unusable.

[Ryan J Ollos]

I gave it some more thought. If you edit trac.ini, then your configuration is applied and you can fix it by editing trac.ini. However, if you make changes from the admin panel, we first test whether those changes are a valid configuration before allowing the changes to be applied. This prevents the Trac instance from being made unreachable by the configuration changes: [88a7ebde8/rjollos.git]. I'll add more tests before committing.

[Ryan J Ollos]

Committed to 1.2-stable in r15783, merged to trunk in r15784.

[Jun Omae]

In [15783#file2], it seems that log_format = format.replace(...) should be log_format = log_format.replace(...). format is a built-in function.

        if log_format:
            log_format = format.replace('$(', '%(') \
                               .replace('%(path)s', self.path) \

[Ryan J Ollos]

Thanks for spotting the incomplete variable rename. I added a test and will commit shortly when the CI tests pass.

[Ryan J Ollos]

Fixed on 1.2-stable in r15785, merged to trunk in r15786.

[Jun Omae]

After [15783], trac.log and trac.log.1 files are created by make unit-test.

[Ryan J Ollos]

Thanks for spotting.

Unrelated, the call to create_logger in trac/admin/web_ui.py registers a handler if it succeeds. I wasn't worried about that because the environment is shutdown after a configuration change, destroying the logger. However I think it would be better to avoid adding the handler to the logger and to close the handler immediately after it's created. Possible fix: [efb1399d/rjollos.git].

[Ryan J Ollos]

comment:30 change committed to 1.2-stable in r15819, merged to trunk in r15820.