Zenn
Open10

sshログイン試行されたときにチャットツールに通知を受け取りたい

shell
SSH
Mattermost
logrotate
horoniumhoronium

背景

現在個人利用しているサーバに、AWS上のEC2インスタンスと、自宅の物理サーバがあります。
AWS上のサーバで作業をするときは、AWS Systems Managerのセッションマネージャーでアクセスしているため、ssh用にポートは特に開けていません。
自宅の物理サーバにはそんなものはないので、インターネットからアクセスするためにssh接続が必要です。
（AWSのサーバ経由でsshする運用にする手もありますが、sshポートフォワーディングをしたかったりなど他にも色々都合がありssh解放したい）

そのため気持ち程度のセキュリティ対策としてポート番号変更・rootのsshログイン制限をして、自宅のルータでポート開放して数日使用していたのですが、後日確認するとポート開放した翌日には変更したポートに対してsshのログイン試行がされていることに気付きました。（以下がその時のログをkibanaで集計したものです）

正直ポート番号もxxx22のようなポート番号にしていたので、狙いやすいポートだったのかもしれませんが、ポート開放した翌日にはそのようなことになっていることに思ったより衝撃を受け、sshのポート開放するのであればちゃんと監視・通知をしようと思いました。
ただ、まだZabbixやPrometheusなどの監視サーバを用意していないため、今から監視サーバ構築と設定の勉強するとだいぶ時間かかるしなーと思い、それよりスクリプト自作してサービス登録とかの方が先が見えていた（つもりだった）ので、監視・通知するスクリプトを作成しようと思い作成しました。

horoniumhoronium

要件

  • /var/log/audit/audit.logでsshログイン失敗のイベントを監視
  • 同じIPアドレスから複数回（適当に5,50, 500回とか）ログイン失敗のイベントを検知したら、そのIPアドレスを個人で使用しているチャットツール（Mattermost）に通知する
    • 検知したらログイン試行の実施具合を見て対応を検討する（あまりにしつこいようだったらsshdやfirewalldでIP制限するのかな？と想定しているが詳細未定）
  • 自作したスクリプトはサービスとして登録する
    • 日次で監視・通知サービスが落ちてないか、別サーバ（AWX）で確認させるplaybookを作成する
  • イベント検知の回数をカウントするため、別途ログファイルにログイン失敗したイベントを書き出す。ログでディスク逼迫させないためにログローテの設定をする
horoniumhoronium

スクリプト

スクリプト内容

#!/bin/sh
TARGET_LOG="/var/log/audit/audit.log"
IDS_LOG="/opt/service/log/ids-audit.log"

_error_conditions="^type=USER_LOGIN.*failed.*$"

hitAction() {
        while read i
        do
                line=$(echo $i | grep "${_error_conditions}" | cut -d" " -f12)
                if [ -n "$line" ];then
                        echo $line >> ${IDS_LOG}
                        num=$(grep -F "$line" ${IDS_LOG} | wc -l | cut -d" " -f1)
                        if [ $num = 5 ];then
                                notifyMattermost "5回ログイン試行あり : $line"
                        elif [ $num = 50 ];then
                                notifyMattermost "50回ログイン試行あり : $line"
                        elif [ $num = 500 ];then
                                notifyMattermost "500回ログイン試行あり : $line"
                        fi
                elif [ $? = 0 ];then
                        notifyMattermost "$0：失敗"
                fi
        done
}

notifyMattermost() {
        url="<MattermostのURL>/api/v4/posts"
        token="<Mattermostで作成したBotアカウントのトークン>"
        postChannelId="<投稿したいチャンネルのID>"
        # post mattermost
        curl -s $url \
        -H "Authorization: Bearer $token" \
        -H "Content-Type: application/json; charset=utf-8" \
        -d @- <<-EOS
        {
                "channel_id": "$postChannelId",
                "message": "$1"
        }
        EOS
}

tail -n 0 --follow=name --retry $TARGET_LOG | hitAction

スクリプト説明

type=USER_LOGIN msg=audit(1670764245.399:3634): pid=2458284 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login acct="(unknown)" exe="/usr/sbin/sshd" hostname=? addr=192.168.0.10 terminal=ssh res=failed'UID="root" AUID="unset"
  • ざっくり処理の流れとしては以下
    • tailで監視し、ログファイルに書き込みが行われたらパイプラインで処理に流す
    • grepで検知したいイベントを検索&IPアドレスの列を取り出す
    • grepに引っかかったら、IPアドレスをログファイルに書き出す
    • 書き出したIPアドレスが5/50/500回以上ログに書き出されていたらMattermostに通知する関数をキック

スクリプト作成中の個人的な気づき

  • Mattermostに通知する関数を作成する際、curlのオプション-dでインデントを揃えるためにはヒアドキュメントにハイフンを付与して<<-とする必要があることを初めて知った
  • tail -n 0やtail -fでは複数パイプラインを繋げようとするとうまく処理されなかった。そのためgrepを複数パイプしたAND検索が出来ず、正規表現で監視するイベントを指定する必要がありそう。
  • 最初IPアドレス以外の列の情報も通知文に入れようかなーと思っていたのですが、Mattermostに通知する関数のmessageに入れると文字コード関連のエラーが出てきてしまった。すぐに解決できずおとなしくIPアドレスのみにした
horoniumhoronium

サービス設定

以下ファイルを作成。auditのログを読み込むのでAfterでauditdを指定してみた。
Typeについてはこちらの記事を参考にさせていただき、コマンドを実行して終了するスクリプトではforkingを指定する必要があるのかな、と認識しました。そのため上記スクリプトはtailが動き続けるのでsimpleでよいかと。

/usr/lib/systemd/system/ids-audit.service
[Unit]
Description=intrusion detection system (original scripts)
After=auditd.service

[Service]
ExecStart=/opt/service/bin/ids-audit.sh
Type=simple

[Install]
WantedBy=multi-user.target

設定コマンド

systemctl daemon-reload
systemctl start ids-audit
systemctl enable ids-audit
horoniumhoronium

ログローテ設定中（1日様子見したがローテせず）

ログローテ設定ファイル

/etc/logrotate.d/ids-audit
/opt/service/log/ids-audit.log {
    missingok #ログファイルが存在しなくてもエラーを出力しない
    notifempty #ログの中身が空ならローテーションしない
    copytruncate #コピーでローテした後、元のログファイルの中身を削除
    rotate 30 #30世代保管（適当）
    daily #日次
    nocompress #圧縮しない
    olddir /opt/service/log/rotate #ローテされたログ格納先
}

上記ファイル作成後、logrotate -d /etc/logrotate.d/ids-au で特にエラーが出てないことを確認し、またlogrotateのサービス再起動も実行しました。

設定した翌日に確認すると、、、

  • ログローテされておらず
  • 試しにlogrotate -f ～～で強制的に実行してみると問題なくローテーションされた

エラー確認

  • ジャーナルログを確認すると以下エラーが
12月 12 00:00:05 xxxxxxx logrotate[2489253]: error: error opening /opt/service/log/ids-audit.log: 許可がありません
  • audit.logに以下メッセージが
type=AVC msg=audit(1670770805.459:3685): avc:  denied  { write } for  pid=2489253 comm="logrotate" name="ids-audit.log" dev="dm-0" ino=101168988 scontext=system_u:system_r:logrotate_t:s0 tcontext=unconfined_u:object_r:usr_t:s0 tclass=file permissive=0

調べてみると、、、

  • SELinuxが悪さシステムを守ってくれているらしい
    • SELinuxを全然理解していなかったのですが、プロセスがアクセスするリソースとかを制限しているらしい
    • プロセスが脆弱性などをつかれて乗っ取られて権限昇格などされても、関係ないリソースを操作できないように守ってくれている
  • 今回のケース（audit.logより）ではusr_tタイプのリソース（ログファイル）がlogrotate_tタイプの書き込みを拒否したとなっているらしい
  • RedHat公式ナレッジ： https://access.redhat.com/documentation/ja-jp/red_hat_enterprise_linux/6/html/security-enhanced_linux/sect-security-enhanced_linux-working_with_selinux-selinux_contexts_labeling_files
    • ls -Zで現在どういったタイプなど設定されているか確認可能
    • ログローテはコピーにしており、ログファイルが書き換わらない想定のため、ログファイルのタイプを一時的な変更のchconで試してみる
horoniumhoronium

ログファイルのSELinuxコンテキスト（タイプ）変更

では、いざ変更しようと思ったら許可がないと表示されました。
rootで操作していたので、おそらくSELinuxを有効化しているのが原因と推測。
そのため一時的にSELinuxを無効化→SELinuxコンテキスト変更→SELinux有効化の手順で実施しました。

[root@<hostname>log]# ls -Z ids-audit.log
unconfined_u:object_r:usr_t:s0 ids-audit.log
[root@<hostname>log]# chcon -t logrotate_t ids-audit.log
chcon: 'ids-audit.log' のコンテキストを `unconfined_u:object_r:logrotate_t:s0' に変更できません: 許可がありません
[root@<hostname>log]# setenforce 0
[root@<hostname>log]# getenforce
Permissive
[root@<hostname>log]# chcon -t logrotate_t ids-audit.log
[root@<hostname>log]# ls -Z ids-audit.log
unconfined_u:object_r:logrotate_t:s0 ids-audit.log
[root@<hostname>log]# setenforce 1
[root@<hostname>log]# getenforce
Enforcing

ということで、これでログローテされるか1日様子見します。
これでローテーションされ、またSELinuxコンテキストも変更されていないか確認できれば一通り完了の予定です。

horoniumhoronium

ログローテ再失敗

ログローテに失敗してましたのでエラー内容確認です。

----
time->Tue Dec 13 00:00:06 2022
type=PROCTITLE msg=audit(1670857206.359:4200): proctitle=2F7573722F7362696E2F6C6F67726F74617465002F6574632F6C6F67726F746174652E636F6E66
type=SYSCALL msg=audit(1670857206.359:4200): arch=c000003e syscall=257 success=no exit=-13 a0=ffffff9c a1=55fb521216d0 a2=200c1 a3=180 items=0 ppid=1 pid=2897936 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="logrotate" exe="/usr/sbin/logrotate" subj=system_u:system_r:logrotate_t:s0 key=(null)
type=AVC msg=audit(1670857206.359:4200): avc:  denied  { write } for  pid=2897936 comm="logrotate" name="rotate" dev="dm-0" ino=1696358 scontext=system_u:system_r:logrotate_t:s0 tcontext=unconfined_u:object_r:usr_t:s0 tclass=dir permissive=0
  • /var/log/message確認
Dec 13 00:00:06 <hostname> logrotate[2897936]: error: error creating output file /opt/service/log/rotate/ids-audit.log-20221213: 許可がありません
Dec 13 00:00:06 <hostname> systemd[1]: logrotate.service: Main process exited, code=exited, status=1/FAILURE
Dec 13 00:00:06 <hostname> systemd[1]: logrotate.service: Failed with result 'exit-code'.

今度はローテーション後のファイルが作成に許可がされてないように、のように読めますね。
これはフォルダの設定すればいいのかな？と思い、フォルダのSELinuxコンテキストを変更してみます。

[root@<hostname> log]# ls -dZ rotate/
unconfined_u:object_r:usr_t:s0 rotate/
[root@<hostname> log]# setenforce 0
[root@<hostname> log]# chcon -t logrotate_t rotate
[root@<hostname> log]# ls -dZ rotate/
unconfined_u:object_r:logrotate_t:s0 rotate/
[root@<hostname> log]# setenforce 1
[root@<hostname> log]# getenforce
Enforcing
horoniumhoronium

上記の後ログローテをデバックモードで実行したら思ったより画面に色々表示され（ログに残し忘れた、、、）、またすぐに挙動を確認しようとログローテを一時的にhourlyに変更して確認してみたらまだエラーが。

Dec 13 11:03:42 docker logrotate[3085550]: error: error creating output file /opt/service/log/rotate/ids-audit.log-2022121311: 許可がありません

----
time->Tue Dec 13 11:03:42 2022
type=PROCTITLE msg=audit(1670897022.518:4445): proctitle=2F7573722F7362696E2F6C6F67726F74617465002F6574632F6C6F67726F746174652E636F6E66
type=SYSCALL msg=audit(1670897022.518:4445): arch=c000003e syscall=257 success=no exit=-13 a0=ffffff9c a1=5559849cb6d0 a2=200c1 a3=180 items=0 ppid=1 pid=3085550 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="logrotate" exe="/usr/sbin/logrotate" subj=system_u:system_r:logrotate_t:s0 key=(null)
type=AVC msg=audit(1670897022.518:4445): avc:  denied  { write } for  pid=3085550 comm="logrotate" name="rotate" dev="dm-0" ino=1696358 scontext=system_u:system_r:logrotate_t:s0 tcontext=unconfined_u:object_r:logrotate_t:s0 tclass=dir permissive=0

ログローテの挙動が自身無いのですが、現在1回強制実行したログローテ後のファイルがrotate/ids-audit.log.1として残っています。
これをリネームしようとしてる？と考えて試しにこのログもSELinuxコンテキストを変更し、手動でログローテさせてみたところ、やはりログローテしたファイルをさらにリネームしようとしていました。

# logrotate /etc/logrotate.d/ids-audit
error: error renaming /opt/service/log/rotate/ids-audit.log.1 to /opt/service/log/rotate/ids-audit.log.2: 許可がありません

エラーに出ているファイル名ids-audit.log-2022121311なのはちょっと理解できてないですが、とりあえず今サフィックスをリネームしていく方式ではダメそうです。
そのため試しにサフィックスを日付などで固定するため、logrotateファイルにdateextを追記して再度手動実行してみましたが、結局ファイルが作成できないエラーとなりました。

# logrotate /etc/logrotate.d/ids-audit
error: error creating output file /opt/service/log/rotate/ids-audit.log-2022121311: 許可がありません

ここでなんでだ～、と思いながらもaudit.logを改めて確認したら、logrotateの実行SELinuxコンテキストがunconfined_tに変わっていました。

type=AVC msg=audit(1670899070.175:4457): avc:  denied  { write } for  pid=3095251 comm="logrotate" name="rotate" dev="dm-0" ino=1696358 scontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:logrotate_t:s0 tclass=dir permissive=0

簡単に調べてみると、これはrootユーザがbashなどにいるときのタイプらしく、rootユーザによって実行されているからタイプが違うよ、と怒られてると思われます。そのため手動実行ではなく、おとなしく次回実行されるのを待つことにします。

horoniumhoronium

logrotateをhourlyに変更したが、1時間ごとに実行されないので調べてみるとlogrotateがデフォルトだと日次で実行されているため設定が必要とのこと。
しかしちょっと調べた感じでは/etc/corn.hourlyにあるlogrotateをhourlyのフォルダにコピーする手段が出てくるが、自分の環境ではそんなファイルがない。
そのためもう少し調べてみると、新しいOSではcronではなくsystemd-timerで管理するようになっているらしい。
https://qiita.com/opuntia/items/cfae86f40f4a959113b5

別に変更してもいいが、急ぎでもないためいったん日次でローテーションされるか様子を見る。

horoniumhoronium

ログローテ失敗：続

変わらずログローテされていませんでした。
以下ログを確認するとタイプはちゃんとlogrotate_tになっているのですが、なぜでしょう。。。

type=AVC msg=audit(1670943602.454:4492): avc:  denied  { write } for  pid=3303451 comm="logrotate" name="rotate" dev="dm-0" ino=1696358 scontext=system_u:system_r:logrotate_t:s0 tcontext=unconfined_u:object_r:logrotate_t:s0 tclass=dir permissive=0

Dec 14 00:00:02 docker logrotate[3303451]: error: error creating output file /opt/service/log/rotate/ids-audit.log-20221214: 許可がありません

現在の選択肢として、

  • 一時的な設定ではなく永続設定semanage fcontextをフォルダに対して試してみる
  • 引き続き原因調査
  • 敗戦処理としてsemanage permissive -a logrotate_tでログローテはSELinuxの対象外とする

とかでしょうか。ちょっと検討中。