Edgewall Software
Modify

Opened 5 years ago

Closed 5 years ago

#8623 closed defect (fixed)

env.config.save() may destroy trac.ini

Reported by: eblot Owned by: rblank
Priority: highest Milestone: 0.11.7
Component: general Version: 0.12dev
Severity: normal Keywords: config
Cc: osimons, ryano@…, mikael@…
Release Notes:
API Changes:

Description

Trac:	0.12dev-r8263
Python:	2.5.4 (r254:67916, Feb 17 2009, 20:36:34) [GCC 4.3.3]
setuptools:	0.6c9
psycopg2:	2.0.9
Genshi:	0.6dev-r1052
Babel:	-
mod_wsgi:	2.5
Pygments:	1.0
Bitten:	0.6dev-r0
Subversion:	1.6.4 (r38063)
RPC:	1.0.6
jQuery:	1.3.2

If a plugin (namely: CustomFieldAdminPlugin) provides invalid data to the Configuration module, Trac raises an error while updating the configuration file.

The net result is a partially written trac.ini which early terminates right after the last valid processed option.

I know the first culprit is the plugin which should not provide invalid data to Trac, however the issue here is not a recoverable: the trac.ini file is simply destroyed, and it seems Trac does not attempt to keep a backup configuration file.

It would be better and more realiable to:

  1. create a new temporary file with the new configuration, then
  2. replace the existing configuration file once the new one has been successfully created
2009-09-01 10:33:40,326 Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "/local/engine/trac/trac/web/main.py", line 464, in _dispatch_request
    dispatcher.dispatch(req)
  File "/local/engine/trac/trac/web/main.py", line 212, in dispatch
    resp = chosen_handler.process_request(req)
  File "/local/engine/trac/trac/admin/web_ui.py", line 114, in process_request
    path_info)
  File "build/bdist.linux-i686/egg/customfieldadmin/customfieldadmin.py", line 72, in render_admin_panel
    cfapi.update_custom_field(self.env, cfdict, create=True)
  File "build/bdist.linux-i686/egg/customfieldadmin/api.py", line 99, in update_custom_field
    self.create_custom_field(env, customfield)
  File "build/bdist.linux-i686/egg/customfieldadmin/api.py", line 92, in create_custom_field
    env.config.save()
  File "/local/engine/trac/trac/config.py", line 198, in save
    val.encode('utf-8')))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3 in position 6: ordinal not in range(128)

The error does not end up right here.
Once Trac has self-destroyed its own configuration file, it starts reporting a funny error:

2009-09-01 10:33:45,403 Trac[env] ERROR: Exception caught while checking for upgrade: 
Traceback (most recent call last):
  File "/local/engine/trac/trac/env.py", line 590, in open_environment
    needs_upgrade = env.needs_upgrade()
  File "/local/engine/trac/trac/env.py", line 429, in needs_upgrade
    db = self.get_db_cnx()
  File "/local/engine/trac/trac/env.py", line 275, in get_db_cnx
    return DatabaseManager(self).get_connection()
  File "/local/engine/trac/trac/db/api.py", line 88, in get_connection
    return self._cnx_pool.get_cnx(self.timeout or None)
  File "/local/engine/trac/trac/db/pool.py", line 176, in get_cnx
    return _backend.get_cnx(self._connector, self._kwargs, timeout)
  File "/local/engine/trac/trac/db/pool.py", line 109, in get_cnx
    cnx = connector.get_connection(**kwargs)
  File "/local/engine/trac/trac/db/sqlite_backend.py", line 127, in get_connection
    return SQLiteConnection(path, params, log)
  File "/local/engine/trac/trac/db/sqlite_backend.py", line 173, in __init__
    raise TracError(_('Database "%(path)s" not found.', path=path))
TracError: Database "/local/var/trac/projects/conax/db/trac.db" not found.

I'm not sure how/why Trac wants to find a trac.db file, it is likely that it falls back to SQLite when it cannot find the DB connection string, but the message for the admin is hard to understand: Trac fails to connect to a DB which has never existed, because the connection string does not exist anymore in the configuration file. It would be better to report a missing connection string here.

It seems that this error does not stop Trac from accessing the DB. So the final error is

2009-09-01 10:33:45,489 Trac[main] ERROR: Exception caught while post-processing request: 
Traceback (most recent call last):
  File "/local/engine/trac/trac/web/main.py", line 246, in dispatch
    self._post_process_request(req)
  File "/local/engine/trac/trac/web/main.py", line 332, in _post_process_request
    f.post_process_request(req, *(None,)*extra_arg_count)
  File "build/bdist.linux-i686/egg/revtree/web_ui.py", line 224, in post_process_request
    if req.perm.has_permission('REVTREE_VIEW'):
  File "/local/engine/trac/trac/perm.py", line 526, in has_permission
    return self._has_permission(action, resource)
  File "/local/engine/trac/trac/perm.py", line 540, in _has_permission
    check_permission(action, perm.username, resource, perm)
  File "/local/engine/trac/trac/perm.py", line 427, in check_permission
    perm)
  File "/local/engine/trac/trac/perm.py", line 284, in check_permission
    get_user_permissions(username)
  File "/local/engine/trac/trac/perm.py", line 359, in get_user_permissions
    for perm in self.store.get_user_permissions(username):
  File "/local/engine/trac/trac/perm.py", line 175, in get_user_permissions
    db = self.env.get_db_cnx()
  File "/local/engine/trac/trac/env.py", line 275, in get_db_cnx
    return DatabaseManager(self).get_connection()
  File "/local/engine/trac/trac/db/api.py", line 88, in get_connection
    return self._cnx_pool.get_cnx(self.timeout or None)
  File "/local/engine/trac/trac/db/pool.py", line 176, in get_cnx
    return _backend.get_cnx(self._connector, self._kwargs, timeout)
  File "/local/engine/trac/trac/db/pool.py", line 109, in get_cnx
    cnx = connector.get_connection(**kwargs)
  File "/local/engine/trac/trac/db/sqlite_backend.py", line 127, in get_connection
    return SQLiteConnection(path, params, log)
  File "/local/engine/trac/trac/db/sqlite_backend.py", line 173, in __init__
    raise TracError(_('Database "%(path)s" not found.', path=path))
TracError: Database "/local/var/trac/projects/conax/db/trac.db" not found.
2009-09-01 10:33:45,489 Trac[main] WARNING: HTTPInternalError: 500 Trac Error (Database "/local/var/trac/projects/conax/db/trac.db" not found.)

Attachments (3)

8623-atomic-config-updates-r8625.patch (6.6 KB) - added by rblank 5 years ago.
Patch adding atomic config updates.
8623-atomic-config-updates-r8631.patch (8.8 KB) - added by rblank 5 years ago.
A better implementation of atomic file updates. Some parts untested.
8623-atomic-config-updates-r8631.2.patch (8.9 KB) - added by rblank 5 years ago.
Fixed fallback rename when destination doesn't exist.

Download all attachments as: .zip

Change History (33)

comment:1 follow-up: Changed 5 years ago by eblot

comment:2 in reply to: ↑ 1 ; follow-up: Changed 5 years ago by osimons

Replying to eblot:

See ticket:8623

Correct reference should be th:ticket:5760. That said, I see no issues with latest plugin using 0.11.6dev and not quite sure what (if anything) may be different in trunk. We'll follow up the plugin-specific details there.

Keeping this ticket open though as safer writing of trac.ini is a good idea, and incomplete ini files can lead to many serious issues when custom configurations are replaced with defaults from options registry - like for instance missing custom security policies.

comment:3 Changed 5 years ago by cboos

  • Keywords config added
  • Milestone set to 0.11.6

Now that I think about it, even when the write operation is progressing successfully, nothing prevents Trac to read the partially written trac.ini file either.

We should write the configuration to a temporary file, then rename it to trac.ini.

On Windows, the rename would fail if trac.ini is currently being read, so we could add a retry in this case.

comment:4 in reply to: ↑ 2 ; follow-up: Changed 5 years ago by eblot

Replying to osimons:

Replying to eblot:

See ticket:8623

Correct reference should be th:ticket:5760. That said, I see no issues with latest plugin using 0.11.6dev and not quite sure what (if anything) may be different in trunk. We'll follow up the plugin-specific details there.

How do you know which version of the plugin is actually run, as setup.py seems to be out of sync?

Keeping this ticket open though as safer writing of trac.ini is a good idea, and incomplete ini files can lead to many serious issues when custom configurations are replaced with defaults from options registry - like for instance missing custom security policies.

Not mentioning the loss of important data as the trac.ini file may not have been backed up since the latest modifications.

comment:5 in reply to: ↑ 4 Changed 5 years ago by osimons

Replying to eblot:

How do you know which version of the plugin is actually run, as setup.py seems to be out of sync?

I'll bump version for you and add information to 'About Trac' just to make sure - see #5710. BTW, you seem to be running the plugin out of a build directory (build/bdist.linux-i686/egg/customfieldadmin/) - that is intentional?

comment:6 Changed 5 years ago by osimons

Oops - forget the link to local ticket 5710… Irrelevant of course, and just clumsy fingers when trying to reference th:ticket:5760 again getting both link-style and ticket number wrong :-)

comment:7 Changed 5 years ago by Ryan Ollos <ryano@…>

  • Cc ryano@… added

comment:8 Changed 5 years ago by rblank

  • Owner set to rblank

Looking into that.

Changed 5 years ago by rblank

Patch adding atomic config updates.

comment:9 Changed 5 years ago by rblank

The patch above updates the config file atomically by writing to a temporary file in the same directory, then renaming over trac.ini. As suggested in comment:3, it retries for two seconds on windows if the rename raises a WindowsError.

Feedback welcome.

comment:10 follow-up: Changed 5 years ago by osimons

Nice. Looks good. And thanks for making the supporting util methods - I needed the same for another file I write as part of my custom Trac setup :-) I'll try to give it a spin and migrate my custom code too. Patch is for 0.11-stable, right?

comment:11 in reply to: ↑ 10 Changed 5 years ago by rblank

Replying to osimons:

Patch is for 0.11-stable, right?

Correct.

comment:12 follow-up: Changed 5 years ago by osimons

Looking at the code, I kind of feel the API would be cleaner if we also made a replace_file(filename, data) that abstracted away the temporary file in the same directory + the attributes/perm preservation? Or even changed the current method to create_or_replace_file()?

Also, a question: What is the probability of two threads/processes writing and renaming at the same time? With 2 second delay on Windows, could the situation arise where suddenly both start renaming? Would some sort of locking be needed as well?

comment:13 in reply to: ↑ 12 ; follow-up: Changed 5 years ago by rblank

Replying to osimons:

Looking at the code, I kind of feel the API would be cleaner if we also made a replace_file(filename, data) that abstracted away the temporary file in the same directory + the attributes/perm preservation?

Interesting. That would require writing the whole file content to a StringIO first, so that it can be passed to replace_file(). Actually, I'm pretty sure that I have seen such a function before. Probably in Mercurial.

Also, a question: What is the probability of two threads/processes writing and renaming at the same time? With 2 second delay on Windows, could the situation arise where suddenly both start renaming? Would some sort of locking be needed as well?

The file update is atomic, so one of the processes is going to win, and the changes from the other one will be lost. While still not quite ideal, it's already much better than a corrupt file. The temporary file will be different for each thread/process, so there's no race condition there. Changes to trac.ini should be relatively rare anyway, and I don't think we can do much better (with reasonable effort).

Looking at the Mercurial code, they have an interesting way of renaming over an open file. They rename the destination file to a temporary, unlink it, then rename the source to the destination. I'll try that as well.

Oh, there it is: atomictempfile. I'll have to understand that first :)

comment:14 in reply to: ↑ 13 Changed 5 years ago by cboos

Replying to rblank:

Oh, there it is: atomictempfile. I'll have to understand that first :)

Once you do, please pass on the explanation :-) For me at least (Vista with UAC), that method doesn't work.

Changed 5 years ago by rblank

A better implementation of atomic file updates. Some parts untested.

comment:15 Changed 5 years ago by rblank

The patch above implements a nicer API for atomic file updates, through an AtomicFile object that can be either committed, or rolled back.

The update is atomic on Unix, and tries to be on Windows. It uses one of the following methods to rename the temporary file to the final name, in order of preference:

  • MoveFileTransacted(): available since Windows Vista. This rename is specified to be atomic. I haven't been able to test it, though, as I don't have a Vista machine.
  • MovefileEx(): not truly atomic, but quite close. Tested on Windows XP.
  • os.rename(): not atomic. This is what Mercurial implements, and as noted in comment:14, it doesn't actually work if the file is open. We could add the retry functionality.

The first two options require ctypes. Now I wonder if this added complexity is really worth it, or if we should just keep the third option (with the retry).

Testing of the first option on Vista would be welcome.

Changed 5 years ago by rblank

Fixed fallback rename when destination doesn't exist.

comment:16 Changed 5 years ago by rblank

The patch above is an update to make the fallback rename solution work in the case where the destination file doesn't exist already.

In the current state, the config file update has the following properties:

  • On Unix, the update will always succeed and be atomic. If there are concurrent updates, the last one will win and updates from previous ones will be lost. This is unavoidable unless we put the config into the database.
  • On Windows Vista and later, with ctypes installed (or Python ≥2.5), the same properties hold.
  • On Windows XP and lower, or without ctypes, the rename will not be atomic and may fail, due to concurrent updates or if the config file is open for reading. In the former case, the worst that can happen is that a temporary file could be left in the conf directory. In the latter case, the update will simply fail, and the user will be alerted. Both cases should be rare enough.

All cases are much better than the current solution, where the config file can be corrupted. I wouldn't complicate the logic with retries on Windows, as the config file should only rarely be open (only during an environment reload).

I'm still looking for a volunteer to test the atomic solution on Windows Vista.

comment:17 Changed 5 years ago by cboos

Ah… finally! I can stop my digging through the recent tickets :-)

I tested the rename function under Vista sp2 this morning, Python 2.6.1, ctypes 1.1.0. It works, I can rename(src,dst) even when dst is actually opened, impressive!

I had to change:

MoveFileTransacted = ctypes.kernel32.MoveFileTransactedA 

to:

MoveFileTransacted = ctypes.windll.kernel32.MoveFileTransactedA 

Also, the following:

                      if not MoveFileTransacted(src, dst, None, None, 
                          MOVEFILE_REPLACE_EXISTING 
                          | MOVEFILE_WRITE_THROUGH, ta): 
                                raise ctypes.WinError() 
                            if not CommitTransaction(ta): 
                                raise ctypes.WinError() 

could be rewritten:

                      if MoveFileTransacted(src, dst, None, None, 
                          MOVEFILE_REPLACE_EXISTING 
                          | MOVEFILE_WRITE_THROUGH, ta) and \
                         CommitTransaction(ta): 
                          return
                      raise ctypes.WinError() 

comment:18 Changed 5 years ago by rblank

  • Resolution set to fixed
  • Status changed from new to closed

Thanks for testing! Patch (with improvements) applied in [8635].

comment:19 Changed 5 years ago by osimons

Thanks - works great! Also when reused for my custom management plugin :-)

comment:20 Changed 5 years ago by rblank

Testing on Vista has shown that the variant with MoveFileTransacted() can actually rename an open file, so the corresponding unit test has been set to run in that case in [8655].

comment:21 Changed 5 years ago by mrelbe

  • Resolution fixed deleted
  • Status changed from closed to reopened

Using WinXP Pro and Trac 0.11.6, I get exception ctype.WinError() when the trachacks:AccountManagerPlugin operates on the svnserve password store. For more info, please see trachacks:ticket:6356.

I would suspect the problem belongs to Trac, and not the plugin…

comment:22 Changed 5 years ago by Mikael Relbe <mikael@…>

  • Cc mikael@… added
  • Milestone 0.11.6 deleted

Milestone 0.11.6 does not seem reasonable… clearing it to allow this ticket to be triaged (I am new here, please correct me if I am doing something bad).

comment:23 follow-up: Changed 5 years ago by rblank

Could you please post the whole traceback, including the error message?

comment:24 in reply to: ↑ 23 ; follow-up: Changed 5 years ago by mrelbe

Replying to rblank:

Could you please post the whole traceback, including the error message?

Python traceback:

2009-12-21 17:21:05,733 Trac[main] DEBUG: Dispatching <Request "POST u'/admin/accounts/users'">
2009-12-21 17:21:05,765 Trac[session] DEBUG: Retrieving session for ID u'Mikael'
2009-12-21 17:21:05,780 Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "C:\Python26\lib\site-packages\trac-0.11.6-py2.6.egg\trac\web\main.py", line 450, in _dispatch_request
    dispatcher.dispatch(req)
  File "C:\Python26\lib\site-packages\trac-0.11.6-py2.6.egg\trac\web\main.py", line 206, in dispatch
    resp = chosen_handler.process_request(req)
  File "C:\Python26\lib\site-packages\trac-0.11.6-py2.6.egg\trac\admin\web_ui.py", line 114, in process_request
    path_info)
  File "build\bdist.win32\egg\acct_mgr\admin.py", line 117, in render_admin_panel
    return self._do_users(req)
  File "build\bdist.win32\egg\acct_mgr\admin.py", line 185, in _do_users
    _create_user(req, self.env, check_permissions=False)
  File "build\bdist.win32\egg\acct_mgr\web_ui.py", line 71, in _create_user
    mgr.set_password(user, password)
  File "build\bdist.win32\egg\acct_mgr\api.py", line 128, in set_password
    if store.set_password(user, password):
  File "build\bdist.win32\egg\acct_mgr\svnserve.py", line 60, in set_password
    cfg.save()
  File "C:\Python26\lib\site-packages\trac-0.11.6-py2.6.egg\trac\config.py", line 225, in save
    fileobj.close()
  File "C:\Python26\lib\site-packages\trac-0.11.6-py2.6.egg\trac\util\__init__.py", line 178, in commit
    rename(self._temp, self._path)
  File "C:\Python26\lib\site-packages\trac-0.11.6-py2.6.egg\trac\util\__init__.py", line 120, in rename
    raise ctypes.WinError()
WindowsError: (2, 'Det g\xe5r inte att hitta filen.')
2009-12-21 17:21:05,842 Trac[chrome] DEBUG: Prepare chrome data for request

The WindowsError message states "File not found" (in Swedish).

System Information::

User AgentMozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.2b5) Gecko/20091204 Firefox/3.6b5 (.NET CLR 3.5.30729)
Trac0.11.6 r8866
Python2.6.4 (r264:75708, Oct 26 2009, 08:23:19) [MSC v.1500 32 bit (Intel)]
setuptools0.6c11
SQLite3.5.9
pysqlite2.4.1
Genshi0.6dev-r1092
Pygments1.1.1
Subversion1.6.6 (r40053)
jQuery1.2.6
AccountManagerPlugin 0.11 r7163

Hope this is to some help for tracking the problem.

comment:25 in reply to: ↑ 24 Changed 5 years ago by mrelbe

Replying to mrelbe:

Python traceback:

Sorry, forgot to mention what caused the error: I simply tried to add a new user using the AccountManagerPlugin which is setup to use svn's password file. When that file is to be updated by config.py of Trac, the exception occurs as stated above.

(I am a total newbie to Python, I am not capable to elaborate further on this…)

comment:26 follow-up: Changed 5 years ago by rblank

  • Milestone set to 0.12

I should re-check this before 0.12.

comment:27 in reply to: ↑ 26 Changed 5 years ago by mrelbe <mikael@…>

Replying to rblank:

I should re-check this before 0.12.

Thank you! Please also check trachacks:ticket:6356#comment:2 (and please ignore comment 3 :)

Merry Christmas!

comment:28 Changed 5 years ago by rblank

It seems that MoveFileEx() is failing, which can be the case if the destination file is open. But I don't understand how it could fail with "File not found" (which I assume means that the source file cannot be found). And even worse, how replacing MoveFileEx() with os.remove() + os.rename() can solve the issue.

comment:29 Changed 5 years ago by rblank

  • Milestone changed from 0.12 to 0.11.7

This is related to #8913, and both should be fixed for 0.11.7.

comment:30 Changed 5 years ago by rblank

  • Resolution set to fixed
  • Status changed from reopened to closed

The issue with th:AccountManagerPlugin was due to its using Unicode paths, which were not supported. This has been fixed in [8994] by using the wide Windows API for renaming.

Add Comment

Modify Ticket

Change Properties
<Author field>
Action
as closed The owner will remain rblank.
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from rblank to the specified user.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.