DevOps NetworkDevOpsNetwork
Join Free
Practical infra coding

Find the file handle leak in a log scanner

mediumDebug and review code

Problem statement

A monitoring job counts ERROR lines across every log file on a host, and the counts on the dashboard look too low. The function is about to be moved into a long-running agent, where leaked file handles eventually end in OSError: [Errno 24] Too many open files. Review it, list the bugs, and fix it.

count_errors.py (broken)

Python
def count_errors(paths):
total = 0
for p in paths:
try:
f = open(p)
for line in f:
if line.startswith("FATAL"):
return total # nothing useful after a fatal
if line.startswith("ERROR"):
total += 1
except:
pass
return total

The intended behaviour: count lines starting with ERROR in every file; within one file, stop at a FATAL line (anything after it is noise from the crash); report files that cannot be read instead of hiding them.

Test data (c.log is in the list but does not exist):

TEXT
a.log: INFO start / ERROR disk full / FATAL giving up / ERROR after fatal
b.log: ERROR timeout / INFO ok
c.log: (missing)
d.log: ERROR one / ERROR two

The expected count is 4: one in a.log before the FATAL, one in b.log, two in d.log. A test harness records ResourceWarnings, which Python emits when a file object is garbage-collected while still open. That makes the leak visible even on a small test.

Symptom (actual output of the broken version):

TEXT
ERROR lines counted: 1
files left open: ['a.log']

Examples

Example 1

Input: The same harness with the fixed `count_errors`

Output: warning: skipped c.log: No such file or directory ERROR lines counted: 4 files left open: none

Hints

Approach

Optimal

Bug 1: the file is never closed. f = open(p) has no matching close(). In CPython the file is usually closed when the variable is rebound or the function returns, because its reference count drops to zero, and that is why this code "works" in small tests. But nothing guarantees it: if a reference survives (a traceback kept in a log handler, a generator, a different Python implementation), handles pile up until the process hits its open-file limit. The harness makes the leak visible: ResourceWarning: unclosed file fires for a.log, the file that was open when return ran. Fix: with open(...) as f: closes the file on every exit path, including break, return and exceptions.

Bug 2: return instead of break. A FATAL line was meant to stop scanning that file. return stops scanning all files, so b.log and d.log are never read and the count is 1 instead of 4. That explains the low dashboard numbers.

Bug 3: bare except: pass. It hides the missing c.log, and it would equally hide a NameError in the loop, a KeyboardInterrupt, or a UnicodeDecodeError, producing a silently wrong total. Fix: catch OSError only, and print which file was skipped and why.

Bug 4: no encoding. open(p) uses the platform's default encoding. A UTF-8 log with one non-ASCII character can then raise UnicodeDecodeError on some systems (and bug 3 would hide it). Fix: encoding="utf-8", errors="replace", so an odd byte never stops the scan.

The fixed version prints the skipped file, counts 4, and leaves no files open.

ComplexityTime O(total lines)Space O(1)
Python
import os
def count_errors(paths):
total = 0
for p in paths:
try:
with open(p, encoding="utf-8", errors="replace") as f:
for line in f:
if line.startswith("FATAL"):
break # stop this file, keep scanning the others
if line.startswith("ERROR"):
total += 1
except OSError as e:
print(f"warning: skipped {os.path.basename(p)}: {e.strerror}")
return total
# ---- test harness: sample logs, and catch "unclosed file" warnings ----
import gc
import os
import tempfile
import warnings
LOGS = {
"a.log": "INFO start\nERROR disk full\nFATAL giving up\nERROR after fatal\n",
"b.log": "ERROR timeout\nINFO ok\n",
"c.log": None, # listed but missing
"d.log": "ERROR one\nERROR two\n",
}
with tempfile.TemporaryDirectory() as d:
paths = []
for name, text in LOGS.items():
p = os.path.join(d, name)
paths.append(p)
if text is not None:
with open(p, "w", encoding="utf-8") as f:
f.write(text)
with warnings.catch_warnings(record=True) as caught:
warnings.simplefilter("always", ResourceWarning)
total = count_errors(paths)
gc.collect()
leaked = sorted(os.path.basename(str(w.message).split("name='")[1].split("'")[0])
for w in caught if issubclass(w.category, ResourceWarning))
print(f"ERROR lines counted: {total}")
print(f"files left open: {leaked if leaked else 'none'}")

Follow-up questions

  • Also read .gz rotated logs with gzip.open, still inside a with block.
  • Process the files in parallel with a thread pool. What limits the number of open files now?
  • Return per-file counts as well as the total, so the dashboard can show which log is noisy.

Frequently asked questions

Long-running agents and cron jobs that scan many files are exactly where leaked handles turn into Too many open files, often weeks after the code shipped. Reviewers are expected to spot a missing with block and an over-broad except on sight.

Yes. Relying on garbage collection makes closing depend on details you do not control: whether anything else holds a reference, whether the code runs on PyPy, and when the collector runs. with makes it deterministic, and it also flushes and closes files you write, which matters for data integrity, not just handle counts.

Count the open handles: ls /proc/<pid>/fd | wc -l or lsof -p <pid> on Linux, and watch it grow over time. In tests, run with python -X dev or -W error::ResourceWarning so unclosed files are reported or become errors.