René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"RotatingFileHandler fails when logs are stored in a non-posix file system docker-mounted in Linux-OS","articleBody":"# Bug report\n\n### Bug description:\n\n### Issue description\n\nThe `RotatingFileHandler `fails to execute the method `self.shouldRollover()` because of an `OSError: [Errno 9] Bad file descriptor`. \n\nBackground info: The issue appears in an application running in Docker on Debian. I use Windows Server 2016 as my main file server, so I usually want all my logs stored over there.\n\nI really do not want to provide any misleading information but to me, it looks like the issue started appearing with python 3.12.\nI've been using the python logging module for years now within a lot of different projects, all running in docker and always storing the log files over to my Windows file server through this “double mounting” technique (more about this down below).\n\nI started seeing the issues when I first deployed an app with python 3.12. This was a new project, which never ran under previous python versions. However, I have a couple of other projects which shares the same code and the same logging technique but still run previous python versions (nothing ancient, \u003e=3.9). This issue never came up there.\n\nMy guess is that python threats the directory as posix-complient as it detects a Linux-OS, although this is not the case as the directory lives on a NTFS file system on Windows. May this be the case?\n\n**Strange fact 😵**: My app runs 24/7. It runs the whole week no problem, writes a lot of log entries like a charme. But when I come back after the weekend, I find it “stuck” on this error. As if the shouldRollover() method somehow gets called at specific interval or day-of-week? I observed this behavior 3 weeks in a row. Could it be?\n\n### To reproduce:\n\n**Host OS**: Debian 12 Bookworm \n**Host Kernel**: Linux debjm02 6.1.0-21-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.90-1 (2024-05-03) x86_64 GNU/Linux\n**Docker version**: 26.1.1, build 4cf5afa\n**Docker image**: python:3.12-slim-bookworm\n\n#### Mounting \"technique\":\n\n- Windows-based NTFS share is mounted on Debian `via cifs and /etc/fstab` under `/mnt/servers/`\n- Subdirectory `/mnt/servers/myapp/logs/` is then mounted into container under `/logs/` (via docker volumes)\n\n### Creation of Logger with rotating log file\n\n```python\npylogger = logging.getLogger( self.__name__ )\nrotating_file_handler = logging.handlers.RotatingFileHandler(\n    filename='/logs/myapp.log', \n    maxBytes=5_000_000, \n    backupCount=5,\n    encoding='utf-8')\nformatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s')\nrotating_file_handler.setFormatter(formatter)\npylogger.addHandler(rotating_file_handler)\n```\n\n### Error and Stacktrace\n```\nTraceback (most recent call last):\n  File \"/usr/local/lib/python3.12/logging/handlers.py\", line 73, in emit\n      if self.shouldRollover(record):\n             ^^^^^^^^^^^^^^^^^^^^^^^^^^^\n         File \"/usr/local/lib/python3.12/logging/handlers.py\", line 197, in shouldRollover\n      self.stream.seek(0, 2)  #due to non-posix-compliant Windows feature\n        ^^^^^^^^^^^^^^^^^^^^^^\n    OSError: [Errno 9] Bad file descriptor\nCall stack:\n  File \"/app/__main__.py\", line 213, in \u003cmodule\u003e\n      main()\n      File \"/app/__main__.py\", line 127, in main\n      file_count: int = run_task(task)\n      File \"/app/__main__.py\", line 44, in run_task\n      log.info(f\"{task.name}: Stopping processing for current poll, as poll_max_files have been reached\")\n      File \"/usr/local/lib/python3.12/site-packages/meethpycommons/logger.py\", line 220, in info\n      target.info(obj)\n    Message: 'Auftragsbestätigungen: Stopping processing for current poll, as poll_max_files have been reached'\nArguments: ()\n2024-05-21 09:18:31 [WRN] Auftragsbestätigungen: 30 file/s processed [success/error: 0/30]\n```\n\n### CPython versions tested on:\n\n3.12\n\n### Operating systems tested on:\n\nLinux","author":{"url":"https://github.com/lollo0296","@type":"Person","name":"lollo0296"},"datePublished":"2024-06-17T15:13:46.000Z","interactionStatistic":{"@type":"InteractionCounter","interactionType":"https://schema.org/CommentAction","userInteractionCount":4},"url":"https://github.com/120647/cpython/issues/120647"}