Ssh

格式化 SFTP 日誌以在每個條目上都有使用者名

  • February 16, 2022

我正在執行一個生產伺服器(Debian 10,標準 OpenSSH 包),它執行 Pure-FTPD 用於傳統連接,SFTP 用於我們目前的所有連接。SFTP 伺服器設置有 chroot 監獄,該監獄通過使用者 chroot 監獄中的綁定設備進行登錄。這由 rsyslog 獲取並發送到 /var/log/sftp.log,之後我使用 logstash 解析該文件並將所有內容轉發到我們的超級使用者的視覺化伺服器。超級使用者登錄視覺化以在一處查看所有 SFTP 和 FTP/FTPS 日誌。

pure-ftpd 日誌以我們的超級使用者喜歡的方式格式化:

pure-ftpd: (testuser@hostname) [NOTICE] /home/ftpusers/testuser//outbound/testfile.pdf downloaded  (1765060 bytes, 5989.55KB/sec)

這很棒,因為它在一行中顯示了他們上傳或下載的確切使用者和確切文件。但是,對於 SFTP,情況就不是那麼好了:

internal-sftp[8848]: session opened for local user testuser from [{ip_address}]
internal-sftp[8848]: opendir "/inbound"
internal-sftp[8848]: realpath "/inbound/."
internal-sftp[8848]: open "/inbound/testfile.pdf" flags WRITE,CREATE,TRUNCATE mode 0666
internal-sftp[8848]: close "/inbound/testfile.pdf" bytes read 0 written 1734445

在這種情況下,日誌很容易跟踪。testuser登錄,寫入文件,完成。但是我們有很多使用者同時登錄,並且來自多個 internal-sftp 實例的日誌可以同時出現。如果發生這種情況,跟踪使用者活動的唯一方法是搜尋使用者名testuser,找到記錄的程序 ID(8848在上面的範例中),然後查找具有該程序 ID 的任何消息。許多使用者通過 cronjob 登錄,所以這種情況每 2 分鐘左右發生一次……當我們有 300 個使用者定期登錄時,您可以想像通過這麼多程序 ID 進行搜尋會很痛苦。

我的問題

***有沒有辦法在 sftp-internal 的每條日誌消息前面加上生成日誌的使用者名?這必須在 chroot 監獄中工作。***我找不到任何關於如何修改 rsyslog 生成的消息以包含使用者名的資訊。

我想從我的 SFTP 日誌中看到類似的內容:

internal-sftp[8848]: (testuser) open "/inbound/testfile.pdf" flags WRITE,CREATE,TRUNCATE mode 0666
internal-sftp[8848]: (testuser) close "/inbound/testfile.pdf" bytes read 0 written 1734445

目前配置狀態

我的流程鍊是:

ssh -> sftp-internal -> rsyslog (on local3.*) -> 文件 /var/log/sftp.log -> logstash -> 導出到視覺化伺服器

摘自我在 /etc/ssh/sshd_config 中的 chroot 組

Match Group sftpusers 
       ChrootDirectory %h
       AuthorizedKeysFile %h/.ssh/authorized_keys
       ForceCommand internal-sftp -f local3 -l INFO
       # ForceCommand internal-sftp -l VERBOSE
       AllowTcpForwarding no
       X11Forwarding no

和我的 /etc/rsyslog.d/sftp.conf

local3.*        -/var/log/sftp.log

類似問題:

這個問題是關於 SFTP 日誌記錄到單獨的文件,但它提到了一篇舊文章的這個waybackmachine 條目,其中包括漂亮格式化的 SFTP 日誌條目,看起來像標準 xferlogs。這篇文章提到了一個 Perl 腳本(聖杯),它會為你格式化,但是很可惜,這個連結已經失效了。我可以編寫一個 Python 或 Perl 腳本來查找傳輸的特定消息,獲取程序 ID,並反向搜尋以找到使用者,然後將帶有使用者名的重新格式化的 xfer 消息列印到文件中。但是肯定有人以前解決過這個問題並且有更好的解決方案。

感謝您的任何幫助。

我能夠使用 Python 和 systemd 建構解決方案。這是非常快速和骯髒的,但適用於我的目的。我接收一個 sftp 內部日誌文件並將其轉儲到重新格式化的文件中。如果此格式化程序出錯,我不會修改原始文件。

Python 腳本

這將註銷到 rsyslog 以進行監視並從 systemd 響應 SEGINT。是的,這應該使用比列表更好的東西,但是 python 沒有內置的環形緩衝區或正式的排隊系統(如果我遺漏了一些東西,請給我留言)。不管怎樣……這不是C!

#!/usr/bin/python3

import logging
import re
import sys
import time


class SFTPLogFormatter:

   def __init__(self, infile: str, outfile: str):
       self.logger = logging.getLogger(__name__)
       self.logger.setLevel(logging.DEBUG)
       stdout_handler = logging.StreamHandler()
       stdout_handler.setLevel(logging.DEBUG)
       stdout_handler.setFormatter(logging.Formatter('%(levelname)8s | %(message)s'))
       self.logger.addHandler(stdout_handler)

       self.infile = open(infile, 'r')

       # append to file and keep only 1 lines in a write buffer (write almost
       # immediately)
       self.outfile = open(outfile, 'a', 1)

   def start(self):
       try:
           self.logger.info('starting formatter')
           self.run()
       except KeyboardInterrupt:
           self.logger.warning('SIGINT received, gracefully exiting')
           self.stop()

   @staticmethod
   def tail_file(file_obj):
       while True:
           line = file_obj.readline()
           # sleep if file hasn't been updated
           if not line:
               time.sleep(1)
               continue

           yield line

   def run(self):
       self.infile.seek(0, 2)  # jump to end of file for `tail -f` type behavior
       lines_read = []
       for line in self.tail_file(self.infile): # tail a file like `tail -f`
           lines_read.insert(0, line) # treat the list like a stack
           lines_read = lines_read[:2000] # trim stack since python does not have ring buffers

           modifyline_match = re.match(r'(.*)\[(\d+)\]: (open|close|remove name) (.*)', line) 
           if not modifyline_match:
               self.logger.info(line)
               self.outfile.write(line)
               continue

           modify_line_procid = modifyline_match.group(2)

           self.logger.debug(f'searching for session open statement for open|close file match string: \"{modifyline_match.group(0)}\"')
           open_session_regex = rf'.*\[{modify_line_procid}\]: session opened for local user (.*) from.*'
           open_session_match = None
           for prevline in lines_read[1:]:
               open_session_match = re.match(open_session_regex, prevline)
               if open_session_match:
                   self.logger.debug(f'found session open string: \"{open_session_match.group(0)}\"')
                   break
           else:
               # we found nothing
               self.logger.debug('could not find open session string for: \"{modifyline_match.group(0)}\"')
               continue

           modify_line_start = modifyline_match.group(1)
           modify_line_operator = modifyline_match.group(3)
           modify_line_details = modifyline_match.group(4)

           username = open_session_match.group(1)

           log_str = f'{modify_line_start}[{modify_line_procid}]: (user={username}) {modify_line_operator} {modify_line_details}\n'
           self.logger.info(log_str)
           self.outfile.write(log_str)

   def stop(self):
       self.logger.info('cleaning up')
       try:
           self.infile.close()
       except Exception as e:
           self.logger.error(f'failure while closing infile: {e}')

       try:
           self.outfile.close()
       except Exception as e:
           self.logger.error(f'failure while closing outfile: {e}')

       self.logger.info('exit')
       sys.exit(0)


if __name__ == '__main__':
   infile = sys.argv[1]
   outfile = sys.argv[2]
   service = SFTPLogFormatter(infile, outfile)
   service.start()

服務文件

在 systemd 中創建並啟用了以下服務文件。

[Unit]
Description=Format log messages from sftp to have the username on any file reads, writes, and deletes, making multi-user logs much easier to read.
After=network.target

[Service]
User=root
Type=simple
ExecStart=/usr/bin/python3 /home/admin/services/format_sftp_logs_with_username.py /var/log/sftp.log /var/log/sftp_with_usernames.log
KillSignal=SIGINT

[Install]
WantedBy=multi-user.target

結果

這會導致以下日誌消息。注意 (user=XYZ) 添加。

Feb 11 21:22:01 ip-10-20-0-96 internal-sftp[18241]: session opened for local user testuser from [127.0.0.1]
Feb 11 21:22:02 ip-10-20-0-96 internal-sftp[18241]: opendir "/"
Feb 11 21:22:02 ip-10-20-0-96 internal-sftp[18241]: closedir "/"
Feb 11 21:22:05 ip-10-20-0-96 internal-sftp[18241]: opendir "/inbound"
Feb 11 21:22:05 ip-10-20-0-96 internal-sftp[18241]: closedir "/inbound"
Feb 11 21:22:10 ip-10-20-0-96 internal-sftp[18241]: opendir "/inbound/"
Feb 11 21:22:10 ip-10-20-0-96 internal-sftp[18241]: closedir "/inbound/"
Feb 11 21:22:12 ip-10-20-0-96 internal-sftp[18241]: (user=testuser) open "/inbound/mailhog-deployment.yaml" flags READ mode 0666
Feb 11 21:22:12 ip-10-20-0-96 internal-sftp[18241]: (user=testuser) close "/inbound/mailhog-deployment.yaml" bytes read 815 written 0
Feb 11 21:22:13 ip-10-20-0-96 internal-sftp[18241]: opendir "/inbound/"
Feb 11 21:22:13 ip-10-20-0-96 internal-sftp[18241]: closedir "/inbound/"
Feb 11 21:22:14 ip-10-20-0-96 internal-sftp[18241]: opendir "/inbound/"
Feb 11 21:22:14 ip-10-20-0-96 internal-sftp[18241]: closedir "/inbound/"
Feb 11 21:22:14 ip-10-20-0-96 internal-sftp[18241]: (user=testuser) remove name "/inbound/mailhog-deployment.yaml"
Feb 11 21:22:18 ip-10-20-0-96 internal-sftp[18241]: (user=testuser) open "/inbound/mailhog-deployment.yaml" flags WRITE,CREATE,TRUNCATE mode 0644
Feb 11 21:22:18 ip-10-20-0-96 internal-sftp[18241]: (user=testuser) close "/inbound/mailhog-deployment.yaml" bytes read 0 written 815
Feb 11 21:22:19 ip-10-20-0-96 internal-sftp[18241]: session closed for local user testuser from [127.0.0.1]

限制

緩衝區有 2000 行後視來尋找程序 ID。如果您在給定的時刻有數十或數百名使用者登錄,請提高它。否則,這應該可以滿足大多數伺服器的需求。

引用自:https://serverfault.com/questions/1093393