Collecting security logs on Mac OS X: OpenBSM and real-time monitoring

こんにちは！わたしです！

直近、お仕事ではリモートワークが中心になってきているのでエンドポイントのログ取得・監視を強化したいですねってことでmacOSでログをどう取れば調べてはC++でごりごりと実装するということをしています。（お仕事では今はmacOSでパケットキャプチャして遊んでいます）

本日ひとりカレンダー4日目は、OpenBSMというBSDのシステム監査の仕組みを利用してプロセスの挙動を監視してみたいと思います。

OpenBSM and praudit

OpenBSMはBSDのシステム監査の仕組みなんですが、これをmacOSに移植したのはMcAfeeらしいですね。なんにせよ、Windowsの監査ログのようなログがmacOSでも取れるようになるのでありがたい仕組みです。

OpenBSMで現在の取得しているログの設定は /etc/security/audit_control で確認できます。

$ sudo cat /etc/security/audit_control
#
# $P4: //depot/projects/trustedbsd/openbsm/etc/audit_control#8 $
#
dir:/var/audit
flags:lo,aa
minfree:5
naflags:lo,aa
policy:cnt,argv
filesz:2M
expire-after:10M
superuser-set-sflags-mask:has_authenticated,has_console_access
superuser-clear-sflags-mask:has_authenticated,has_console_access
member-set-sflags-mask:
member-clear-sflags-mask:has_authenticated

ファイルサイズやexpirationはまあどうでもいいですね。flagsの意味は /etc/security/audit_class をみて確認しましょう。

$ sudo cat /etc/security/audit_class
#
# $P4: //depot/projects/trustedbsd/openbsm/etc/audit_class#6 $
#
0x00000000:no:invalid class
0x00000001:fr:file read
0x00000002:fw:file write
0x00000004:fa:file attribute access
0x00000008:fm:file attribute modify
0x00000010:fc:file create
0x00000020:fd:file delete
0x00000040:cl:file close
0x00000080:pc:process
0x00000100:nt:network
0x00000200:ip:ipc
0x00000400:na:non attributable
0x00000800:ad:administrative
0x00001000:lo:login_logout
0x00002000:aa:authentication and authorization
0x00004000:ap:application
0x10000000:res:reserved for internal use
0x20000000:io:ioctl
0x40000000:ex:exec
0x80000000:ot:miscellaneous
0xffffffff:all:all flags set

loはlogin_logout, aaは authentication and authorizationですから、デフォルトの設定ではログインや認証まわりのログだけ取っていることがわかります。 /etc/security/audit_control で dir が /var/audit に設定されていましたが、これらのログは /var/audit/ の下に <開始日時>.<終了日時> というファイル名で保存されています。

$ sudo ls /var/audit/
20170824072304.crash_recovery 20170826065614.crash_recovery 20171031025009.crash_recovery 20181020065446.crash_recovery 20190130140354.crash_recovery 20190423214535.20190611234937 20201203134532.not_terminated
20170824104555.crash_recovery 20170826072207.crash_recovery 20171120043953.crash_recovery 20181102112013.crash_recovery 20190224002124.crash_recovery 20190611234937.20190806161628 current
20170824104813.crash_recovery 20171026191401.crash_recovery 20180411125651.crash_recovery 20181201055850.crash_recovery 20190423164549.crash_recovery 20190806161628.crash_recovery
20170824112617.crash_recovery 20171030023220.20171031024907 20180411132356.crash_recovery 20181230171426.crash_recovery 20190423172528.crash_recovery 20200323090933.crash_recovery
20170824194116.crash_recovery 20171031024907.20171031024937 20180715130243.crash_recovery 20190101000032.crash_recovery 20190423205812.crash_recovery 20200412040713.crash_recovery
20170825120532.crash_recovery 20171031024937.20171031025009 20181018160014.crash_recovery 20190101000200.crash_recovery 20190423214014.crash_recovery 20201203122231.crash_recovery

途中でクラッシュした場合は終了日時が crash_recovery になっています。最新のログは current です。

これらのログは praudit コマンドで読み取ることができます。 -x オプションでXMLとして出力してくれるので、適当に sudo praudit /var/audit/current > /tmp/audit.xml とかやってみて、XMLをエディタで開いて眺めてみると良いでしょう。

そのままだと読みにくいので xmllint — format で整形してvimで眺めてみます。確かにログインや認証のログが残っていることがわかりますね。

これもこれで有用な情報なんですが、今回は /etc/security/audit_control に pc (process) のフラグを立ててプロセスの情報を取得し、 /var/audit に保存済みの過去のログを読むのではなく、リアルタイムにプロセスの挙動の情報を取得してみたいと思います。

Real-time process auditing through auditpipe

幸いなことにauditpipeというリアルタイムにBSMの監査データを取得できる擬似デバイスがあります。

$ ls -l /dev | grep audit
crw-------  1 root  wheel           10,   0 12  3 22:45 auditpipe
crw-r--r--  1 root  wheel            9,   2 12  3 22:45 auditsessions

auditsessionsは知らない子ですが、auditpipeはman pageもあるのでよく知っている子です。man pageには、アプリケーションがリアルタイムモニタリングの目的でBSMのlive audit dataにアクセスするためのfacilityとかいろいろ書いてありますね。 /dev/auditpipe という擬似デバイスを通して discrete BSM audit records を読み取れるということで、prauditコマンドを使って普通に読み取れます。

/etc/security/audit_control のflags, naflagsに pc (process) フラグを立てて再起動し、 sudo praudit /dev/auditpipe を実行すると、何か動いているプロセスがあると恐ろしい勢いでログが流れていきます。

cURLで https://www.apple.com にGETを投げたときはこんなログがえられました。

header,236,11,execve(2),0,Fri Dec  4 22:00:12 2020, + 952 msec
exec arg,curl,https://www.apple.com
path,/usr/bin/curl
path,/usr/bin/curl
attribute,100755,root,wheel,16777220,914,0
arbitrary,hex,byte,20, 9e 98 b8 58 63 b5 74 d 30 c2 53 c3 9c 9a b1 c8 f0 5c 17 91
subject,yu,yu,staff,yu,staff,1295,100006,50331650,0.0.0.0
return,success,0
...
header,126,11,exit(2),0,Fri Dec  4 22:00:13 2020, + 65 msec
exit,Error 0,0
subject,yu,yu,staff,yu,staff,1295,100006,50331650,0.0.0.0
return,success,0
identity,1,com.apple.curl,complete,,complete,0x9e98b85863b5740d30c253c39c9ab1c8f05c1791
trailer,126

このままだと辛いので、XMLで出力して整形してあげると、何が起こっているかわかりやすくなるかもしれません。

具体例としてXMLで出力した結果を少しだけみてみます。

<record version="11" event="fork(2)" modifier="0" time="Fri Dec  4 22:04:50 2020" msec=" + 520 msec">
  <argument arg-num="0" value="0x51c" desc="child PID"/>
  <subject audit-uid="yu" uid="yu" gid="staff" ruid="yu" rgid="staff" pid="806" sid="100006" tid="50331650 0.0.0.0"/>
  <return errval="success" retval="1308"/>
  <identity signer-type="1" signing-id="com.apple.bash" signing-id-truncated="no" team-id="" team-id-truncated="no" cdhash="0x508595e78370793873b546fdc6ed6b32422627eb"/>
</record>
...
<record version="11" event="setpgrp(2)" modifier="0" time="Fri Dec  4 22:04:50 2020" msec=" + 520 msec">
  <subject audit-uid="yu" uid="yu" gid="staff" ruid="yu" rgid="staff" pid="1308" sid="100006" tid="50331650 0.0.0.0"/>
  <return errval="success" retval="0"/>
  <identity signer-type="1" signing-id="com.apple.bash" signing-id-truncated="no" team-id="" team-id-truncated="no" cdhash="0x508595e78370793873b546fdc6ed6b32422627eb"/>
</record>
...
<record version="11" event="execve(2)" modifier="0" time="Fri Dec  4 22:04:50 2020" msec=" + 522 msec">
  <exec_args>
   <arg>tail</arg>
   <arg>-f</arg>
   <arg>process.xml</arg>
  </exec_args>
  <path>/usr/bin/tail</path>
  <path>/usr/bin/tail</path>
  <attribute mode="100755" uid="root" gid="wheel" fsid="16777220" nodeid="813" device="0"/>
  <arbitrary print="hex" type="1" count="20"> 87 75 ec c5 1d 8e 33 6d e4 45 40 57 45 c8 f6 a d7 4d ec 38</arbitrary>
  <subject audit-uid="yu" uid="yu" gid="staff" ruid="yu" rgid="staff" pid="1308" sid="100006" tid="50331650 0.0.0.0"/>
  <return errval="success" retval="0"/>
  <identity signer-type="1" signing-id="com.apple.bash" signing-id-truncated="no" team-id="" team-id-truncated="no" cdhash="0x508595e78370793873b546fdc6ed6b32422627eb"/>
</record>
...
<record version="11" event="wait4(2)" modifier="0" time="Fri Dec  4 22:04:52 2020" msec=" + 8 msec">
  <argument arg-num="0" value="0xffffffff" desc="pid"/>
  <subject audit-uid="yu" uid="yu" gid="staff" ruid="yu" rgid="staff" pid="806" sid="100006" tid="50331650 0.0.0.0"/>
  <return errval="success" retval="1308"/>
  <identity signer-type="1" signing-id="com.apple.bash" signing-id-truncated="no" team-id="" team-id-truncated="no" cdhash="0x508595e78370793873b546fdc6ed6b32422627eb"/>
</record>

fork, setpgrp, execve, waitなどが、引数とステータス、実行したユーザー、引数などとともに出力されているのがわかると思います。

forkも見えるので、丁寧にpidを紐づけていけばプロセスの親子関係もわかりますし、引数が見えますので怪しいコマンドを叩いているとかもわかります。

Let’s call it a day

今日はここまでにしましょう！一行でもいいから何らか情報を発信する目標を4日連続達成なので褒めてほしい。

さて、昨日、一昨日はシステムのロギングの仕組みがsyslogからApple Unified Logに変わっていることと、liveでログを取得するためには log stream コマンドが使えること、ログインの情報やsudoの情報、その他 kext のロードなどセキュリティの観点でリアルタイムにモニタリングしたいイベントが取得できることを紹介しました。

本日は、 log stream では多分取れないプロセスの挙動を知るための情報jはOpenBSMで記録されており、リアルタイムに取得するには /dev/auditpipe を praudit で読めば良さそうなことを紹介しました。

processのほか network のフラグも立てることで、プロセスの親子関係やコマンドの引数、実行したユーザーの情報のほか、通信と通信を出したプロセスを紐づけることも可能となります。

ここまでできれば、あとはログを整形していらない情報落としてLog Aggregator (logstash, fluentdなど) に投げる仕組みと Aggregator + ElasticSearchのサーバーでも適当に立てれば、簡易EDRまではあと一歩って感じですね。

明日何の話をするかはまだ未定です。思いついたら適当に何か書きますー。それではまた明日。

Supplementary Info: policy flags and prefixes for success/failure

/etc/security/audit_control にpolicyってキーもあったと思いますが、 man audit_control すればわかりますがmacOS (Darwin) ではほぼ実装されていないのでデフォルトの設定よりいい設定はないでしょう…（悲しいね）

Windowsの監査ログでは「成功を記録する」「失敗を記録する」にチェックをつけて成功のみ記録したり失敗のみ記録したりできますが、OpenBSMも同様にflags, naflagsのそれぞれのフラグの前にprefixをつけることで成功のみや失敗のみを記録できます。

(none) Record both successful and failed events.
+ Record successful events.
- Record failed events.
^ Record neither successful nor failed events.
^+ Do not record successful events.
^- Do not record failed events.

例えばログインの失敗のみを記録するならフラグは lo ではなく +lo になります。