From 7c88f02d6a2a367b3ac6b84366d07b9d6de1869d Mon Sep 17 00:00:00 2001
From: John Johansen <john.johansen@canonical.com>
Date: Sat, 28 Nov 2020 04:48:47 -0800
Subject: [PATCH] aa-notify: don't crash if the logfile is not present due to
 rotation

If aa-notify races file rotation it may crash with a trace back to
the log file being removed before the new one is moved into place.

    Traceback (most recent call last):
       File "/usr/sbin/aa-notify", line 570, in <module>
         main()
       File "/usr/sbin/aa-notify", line 533, in main
          for message in notify_about_new_entries(logfile, args.wait):
       File "/usr/sbin/aa-notify", line 145, in notify_about_new_entries
         for event in follow_apparmor_events(logfile, wait):
       File "/usr/sbin/aa-notify", line 236, in follow_apparmor_events
         if os.stat(logfile).st_ino != log_inode:
    FileNotFoundError: [Errno 2] No such file or directory: '/var/log/audit/audit.log'

If we hit this situation sleep and then retry opening the logfile.

Fixes: https://gitlab.com/apparmor/apparmor/-/issues/130
MR: https://gitlab.com/apparmor/apparmor/-/merge_requests/688
Signed-off-by: John Johansen <john.johansen@canonical.com>
Acked-by: Christian Boltz <apparmor@cboltz.de>
---
 utils/aa-notify | 39 ++++++++++++++++++++++++++++-----------
 1 file changed, 28 insertions(+), 11 deletions(-)

diff --git a/utils/aa-notify b/utils/aa-notify
index 72d72be79..160e2650b 100755
--- a/utils/aa-notify
+++ b/utils/aa-notify
@@ -232,6 +232,27 @@ def follow_apparmor_events(logfile, wait=0):
                 format(int(time.time()) - start_time)
             )
 
+            (logdata, log_inode, log_size) = reopen_logfile_if_needed(logfile, logdata, log_inode, log_size)
+
+            for event in parse_logdata(logdata):
+                # @TODO Alternatively use os.times()
+                if int(time.time()) - start_time < wait:
+                    debug_logger.debug('Omitted an event seen during wait time')
+                    continue
+                yield event
+
+            if debug_logger.debugging and debug_logger.debug_level <= 10 and int(time.time()) - start_time > 100:
+                debug_logger.debug('Debug mode detected: aborting notification emitter after 100 seconds.')
+                sys.exit(0)
+
+            time.sleep(1)
+
+
+def reopen_logfile_if_needed(logfile, logdata, log_inode, log_size):
+    retry = True
+
+    while retry:
+        try:
             # Reopen file if inode has chaneged, e.g. rename by logrotate
             if os.stat(logfile).st_ino != log_inode:
                 debug_logger.debug('Logfile was renamed, reload to read the new file.')
@@ -249,18 +270,14 @@ def follow_apparmor_events(logfile, wait=0):
             if os.stat(logfile).st_size > log_size:
                 log_size = os.stat(logfile).st_size
 
-            for event in parse_logdata(logdata):
-                # @TODO Alternatively use os.times()
-                if int(time.time()) - start_time < wait:
-                    debug_logger.debug('Omitted an event seen during wait time')
-                    continue
-                yield event
-
-            if debug_logger.debugging and debug_logger.debug_level <= 10 and int(time.time()) - start_time > 100:
-                debug_logger.debug('Debug mode detected: aborting notification emitter after 100 seconds.')
-                sys.exit(0)
-
+            retry = False
+        except FileNotFoundError:
+            # @TODO: switch to epoll/inotify/
+            debug_logger.debug('Logfile not found, retrying.')
             time.sleep(1)
+            # @TODO: send notification if reopening the log fails too many times
+
+    return (logdata, log_inode, log_size)
 
 
 def get_apparmor_events(logfile, since=0):