PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'D:\\Data\\XYZ\\applications\\MyApp\\private\\app.log'

[Davidiam]

We have activated logging in our applications and have defined 2 back-ups for the rotation.

We often get errors when running web2py shell scripts because I think that the the web2py web application and the web2py shell script are both trying to access the log file.  It looks like it is trying to perform a rotation at the moment of the error.

Can anyone give me an idea on how we can resolve with this conflict without disabling rotation?

Here is the full output:

--- Logging error ---
Traceback (most recent call last):
  File "D:\Python\Miniconda3\envs\web2py_XYZ\lib\logging\handlers.py", line 74, in emit
    self.doRollover()
  File "D:\Python\Miniconda3\envs\web2py_XYZ\lib\logging\handlers.py", line 177, in doRollover
    self.rotate(self.baseFilename, dfn)
  File "D:\Python\Miniconda3\envs\web2py_XYZ\lib\logging\handlers.py", line 115, in rotate
    os.rename(source, dest)
PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'D:\\Data\\XYZ\\applications\\MyApp\\private\\app.log' -> 'D:\\Data\\XYZ\\applications\\MyApp\\private\\app.log.1'
Call stack:
  File "D:\Data\XYZ\web2py.py", line 58, in <module>
    gluon.widget.start()
  File "D:\Data\XYZ\gluon\widget.py", line 746, in start
    run(options.shell, plain=options.plain, bpython=options.bpython,
  File "D:\Data\XYZ\gluon\shell.py", line 280, in run
    _env = env(a, c=c, f=f, import_models=import_models, extra_request=extra_request)
  File "D:\Data\XYZ\gluon\shell.py", line 181, in env
    run_models_in(environment)
  File "D:\Data\XYZ\gluon\compileapp.py", line 563, in run_models_in
    restricted(ccode, environment, layer=model)
  File "D:\Data\XYZ\gluon\restricted.py", line 219, in restricted
    exec(ccode, environment)
  File "applications\MyApp\models\b_console.py", line 153, in <module>
    console.log(source='b_console.py', message=str(console), add_timestamp=True)
  File "applications\MyApp\models\b_console.py", line 147, in log
    logger.debug(msg=out_log)

Thanks in advance,

David

[Dave S]

On Wednesday, August 23, 2023 at 9:55:49 PM UTC-7 david....@gmail.com wrote:

We have activated logging in our applications and have defined 2 back-ups for the rotation.

We often get errors when running web2py shell scripts because I think that the the web2py web application and the web2py shell script are both trying to access the log file.  It looks like it is trying to perform a rotation at the moment of the error.

It's not clear to me whether the application or the shell script is getting this error.    What gets logged when running the scripts?  Does this happen when loading the script?  What is b_console.py doing?  Generally, models don't contain procedural code, except for things like custom validators, and in web2py models get loaded on every hit (http requests or shell start ups if you use -M).

That said, I haven't had issues with log rotation, even on a production application (running on Amazon Linux).  My non-production apps, of course, don't have a lot of traffic, and my big WinError issue is not with logging, but writing a  temporary file and then renaming it; sometimes the OS hasn't finished its background work from the close before the rename is attempted.  

My non-production apps use SQLite3, so there are some "database locked" conflicts occasionally.

Can anyone give me an idea on how we can resolve with this conflict without disabling rotation?

Well, using a hammer where screwdriver is needed, you might have the shell script check the size of the log file, and bail out if the size is too near the rotation threshold. 

Good luck!

/dps