From 58b3c520f7a45e4e181bc1f0ea9c2eca102c72ed Mon Sep 17 00:00:00 2001 From: Razvan Barbascu Date: Tue, 14 May 2024 03:57:33 -0700 Subject: [PATCH] fix(forknet) Set log rotation policy (#11283) Set the file size to 100Mb, set max log size to 100GB. All logs will be written to logs.txt. Rotated files will be renamed with the time of rotation. Rotation logic is: copy, then truncate the current file. If logs go over the 100GB limit, oldest log file (lexicographically) will be removed until the logs size is under the limit. The log rotation trigger will be called in the main loop of `neard_runner.py`. Example output of `ls neard-logs`: ``` total 342M drwxrwxr-x 2 ubuntu ubuntu 4.0K May 13 10:23 . drwxr-xr-x 8 ubuntu ubuntu 4.0K May 13 10:13 .. -rw-rw-r-- 1 ubuntu ubuntu 83 May 13 10:23 .logrotate_status -rw-rw-r-- 1 ubuntu ubuntu 664 May 13 10:13 .neard_logrotate_policy -rw-rw-r-- 1 ubuntu ubuntu 6.2M May 10 11:09 initlog.txt -rw-rw-r-- 1 ubuntu ubuntu 28M May 13 10:23 logs.txt -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:11 logs.txt-2024-05-13-10-11-10 -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:16 logs.txt-2024-05-13-10-16-21 -rw-rw-r-- 1 ubuntu ubuntu 104M May 13 10:21 logs.txt-2024-05-13-10-21-41 ``` ``` cat neard-logs/.neard_logrotate_policy /home/ubuntu/neard-logs/logs.txt { su ubuntu ubuntu size 100M rotate 99 copytruncate missingok notifempty dateext dateformat -%Y-%m-%d-%H-%M-%S create 0644 ubuntu ubuntu prerotate total_size=$(du -sb /home/ubuntu/neard-logs/logs.txt* | awk '{total+=$1}END{print total}') while [ $total_size -gt 100000000000 ]; do # get the oldest file alphabetically oldest_file=$(ls -1 /home/ubuntu/neard-logs/logs.txt-* | head -n1) rm -f "$oldest_file" total_size=$(du -sb /home/ubuntu/neard-logs/logs.txt* | awk '{total+=$1}END{print total}') done endscript } ``` Tested by decreasing the max_size to 300MB then triggered the next rotation to happen. ``` # trigger the rotation ubuntu:~$ dump >> neard-logs/logs.txt 102+0 records in 102+0 records out 106954752 bytes (107 MB, 102 MiB) copied, 0.304547 s, 351 MB/s # list logs pre rotation ubuntu:~$ ls -lah neard-logs/logs.txt* -rw-rw-r-- 1 ubuntu ubuntu 138M May 13 10:38 neard-logs/logs.txt -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:36 neard-logs/logs.txt-2024-05-13-10-32-12 -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:36 neard-logs/logs.txt-2024-05-13-10-32-32 -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:37 neard-logs/logs.txt-2024-05-13-10-32-52 -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:36 neard-logs/logs.txt-2024-05-13-10-33-02 -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:37 neard-logs/logs.txt-2024-05-13-10-33-12 -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:37 neard-logs/logs.txt-2024-05-13-10-33-22 # logs after rotation ubuntu:~$ ls -lah neard-logs/logs.txt* -rw-rw-r-- 1 ubuntu ubuntu 563K May 13 10:38 neard-logs/logs.txt -rw-rw-r-- 1 ubuntu ubuntu 102M May 13 10:37 neard-logs/logs.txt-2024-05-13-10-33-22 -rw-rw-r-- 1 ubuntu ubuntu 138M May 13 10:38 neard-logs/logs.txt-2024-05-13-10-38-43 ``` It can be observed that all the files were removed except for the last 2 rotated ones and the active file. Ideally, we want to only use the `rotate 99` directive. --- pytest/tests/mocknet/helpers/neard_runner.py | 84 +++++++++++++++++--- 1 file changed, 71 insertions(+), 13 deletions(-) diff --git a/pytest/tests/mocknet/helpers/neard_runner.py b/pytest/tests/mocknet/helpers/neard_runner.py index 3c152841744..210953f95ea 100644 --- a/pytest/tests/mocknet/helpers/neard_runner.py +++ b/pytest/tests/mocknet/helpers/neard_runner.py @@ -109,6 +109,32 @@ class TestState(Enum): backup_id_pattern = re.compile(r'^[0-9a-zA-Z.][0-9a-zA-Z_\-.]+$') +# Rotate the logs if they get larger than __neard_logs_file_size__ +# Remove old files if the number of files is __neard_logs_max_file_count__ +# Remove old files if all the logs are past __neard_logs_max_size__ +# The prerotate logic serves us in case neard_runner is not running for a while +# and we end up with a file larger than the estimated size. +LOGROTATE_TEMPLATE = """__neard_logs_dir__/__neard_logs_file_name__ { + su ubuntu ubuntu + size __neard_logs_file_size__ + rotate __neard_logs_max_file_count__ + copytruncate + missingok + notifempty + dateext + dateformat -%Y-%m-%d-%H-%M-%S + create 0644 ubuntu ubuntu + prerotate + total_size=$(du -sb __neard_logs_dir__/__neard_logs_file_name__* | awk '{total+=$1}END{print total}') + while [ $total_size -gt __neard_logs_max_size__ ]; do + # get the oldest file alphabetically + oldest_file=$(ls -1 __neard_logs_dir__/__neard_logs_file_name__-* | head -n1) + rm -f "$oldest_file" + total_size=$(du -sb __neard_logs_dir__/__neard_logs_file_name__* | awk '{total+=$1}END{print total}') + done + endscript +}""" + class NeardRunner: @@ -116,10 +142,8 @@ def __init__(self, args): self.home = args.home self.neard_home = args.neard_home self.neard_logs_dir = args.neard_logs_dir - try: - os.mkdir(self.neard_logs_dir) - except FileExistsError: - pass + self.neard_logs_file_name = 'logs.txt' + self._configure_neard_logs() with open(self.home_path('config.json'), 'r') as f: self.config = json.load(f) self.neard = None @@ -150,6 +174,46 @@ def __init__(self, args): # is no need to block reading that when inside the update_binaries rpc for example self.lock = threading.Lock() + def _configure_neard_logs(self): + try: + os.mkdir(self.neard_logs_dir) + except FileExistsError: + pass + + variables = { + '__neard_logs_dir__': f'{self.neard_logs_dir}', + '__neard_logs_file_name__': f'{self.neard_logs_file_name}', + '__neard_logs_file_size__': '100M', + '__neard_logs_max_file_count__': '900', + '__neard_logs_max_size__': '100000000000', # 100G + } + logrotate_config = LOGROTATE_TEMPLATE + # Replace variables in the template + for var, value in variables.items(): + logrotate_config = re.sub(re.escape(var), value, logrotate_config) + self.logrotate_config_path = f'{self.neard_logs_dir}/.neard_logrotate_policy' + logging.info( + f'Setting log rotation policy in {self.logrotate_config_path}') + with open(self.logrotate_config_path, 'w') as config_file: + config_file.write(logrotate_config) + self.logrotate_binary_path = shutil.which('logrotate') + if self.logrotate_binary_path is None: + logging.error('The logrotate tool was not found on this system.') + + # Try to rotate the logs based on the policy defined here: self.logrotate_config_path. + def run_logrotate(self): + run_logrotate_cmd = [ + self.logrotate_binary_path, '-s', + f'{self.neard_logs_dir}/.logrotate_status', + self.logrotate_config_path + ] + subprocess.Popen( + run_logrotate_cmd, + stdin=subprocess.DEVNULL, + stdout=subprocess.DEVNULL, + stderr=subprocess.DEVNULL, + ) + def is_legacy(self): if os.path.exists(os.path.join( self.neard_home, 'setup', 'records.json')) and os.path.exists( @@ -749,15 +813,8 @@ def source_near_home_path(self): # If this is a regular node, starts neard run. If it's a traffic generator, starts neard mirror run def start_neard(self, batch_interval_millis=None): - for i in range(20, -1, -1): - old_log = os.path.join(self.neard_logs_dir, f'log-{i}.txt') - new_log = os.path.join(self.neard_logs_dir, f'log-{i+1}.txt') - try: - os.rename(old_log, new_log) - except FileNotFoundError: - pass - - with open(os.path.join(self.neard_logs_dir, 'log-0.txt'), 'ab') as out: + with open(os.path.join(self.neard_logs_dir, self.neard_logs_file_name), + 'ab') as out: if self.is_traffic_generator(): cmd = [ self.data['current_neard_path'], @@ -1158,6 +1215,7 @@ def main_loop(self): self.reset_near_home() elif state == TestState.MAKING_BACKUP: self.make_backup() + self.run_logrotate() time.sleep(10) def serve(self, port):