My two web-apps are being used a lot more this past month, which is good. However, as a result I noticed in the PythonAnywhere Dashboard that my file-storage had reached 98% of my allowance, so on Friday (22 June 2022 at about 11pm), I increased the allowance so that it was at 80% of capacity. (I know I should have kept an eye on the storage usage and increased it sooner).
However, since that file-storage allowance increase, I've noticed the apps sometimes are slow to respond, and there are many thousands of on-going "Logging error ..." messages in my server logs (eg: "/var/log/www.madapps.uk.server.log", etc), so that the recent server log files are 320 Mbytes, 515 Mbytes, and 850Mbytes (whereas in the past these logs were up to a hundred Kbytes at most).
However, in my error log files (eg: "/var/log/www.madapps.uk.error.log"), the last message was "2022-06-23 18:58" (which was after I increased my storage allowance):
2022-06-23 18:58:26,935: File "/home/sbridgett/madapps/webedit/views_editor.py", line 108, in <module>
2022-06-23 18:58:26,935: from webedit.views_teamup import get_teamup_events
I know there should have been several messages written to these error logs since.
I haven't made significant changes to my scripts, and my scripts still run on my localhost at home okay, and I've also disabled some logging messages, but I haven't been able to fix this problem so far.
I think that when my app does produce an uncaught exception error, or an imported module logs to the error log, then it can't currently write to the error log, so instead the system recursively writes thousands of lines to the server log about "Traceback,.... OSError: [Errno 9] Bad file descriptor, ... etc", as shown below. (I assume the "Bad file descriptor," refers to the error log file), as it tries to write to error log, which raises another exception, which tries again to write to the error log file, etc:
"2022-06-27 16:29:25 ('web_error:', '.............')
2022-06-27 16:29:30 --- Logging error ---
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
2022-06-27 16:29:30 #012During handling of the above exception, another exception occurred:
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
2022-06-27 16:29:30 #012During handling of the above exception, another exception occurred:
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
2022-06-27 16:29:30 #012During handling of the above exception, another exception occurred:
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
2022-06-27 16:29:30 #012During handling of the above exception, another exception occurred:
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
2022-06-27 16:29:30 #012During handling of the above exception, another exception occurred:
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
2022-06-27 16:29:30 #012During handling of the above exception, another exception occurred:
2022-06-27 16:29:30 Traceback (most recent call last):
2022-06-27 16:29:30 File "/usr/local/lib/python3.7/logging/handlers.py", line 940, in emit#012 self.socket.sendto(msg, self.address)
2022-06-27 16:29:30 OSError: [Errno 9] Bad file descriptor
etc....."
Until it finally stops writing to the log when it reaches max recursion depth:
2022-06-27 04:34:04 File "/usr/local/lib/python3.7/logging/__init__.py", line 1451, in findCaller#012 f = currentframe()
2022-06-27 04:34:04 RecursionError: maximum recursion depth exceeded
For example, here are counts of the numbers of messages written to the server log counted by time:
cut -f1,2 -d' ' /var/log/www.madapps.uk.server.log | uniq -c
.....
4 2022-06-27 16:29:25
83 2022-06-27 16:29:30
914 2022-06-27 16:29:31
10082 2022-06-27 16:29:32
13600 2022-06-27 16:29:33
10945 2022-06-27 16:29:34
13750 2022-06-27 16:29:35
5653 2022-06-27 16:29:36
2 2022-06-27 16:30:50
3 2022-06-27 16:30:51
4 2022-06-27 16:30:52
4 2022-06-27 16:34:12
.....etc
I've restarted the apps four times, and have further increased my file storage allowance, and deleted some old unused files, and added more exception catches to the scripts, but still haven't managed to stop this happening :(