Wednesday, January 4, 2012

Logging Shell Commands in Linux

If you own/administer a Linux machine or server which is being used by multiple users, at some time you must have felt the need to log and record the commands being run in the shell by the users. This can be useful for auditing, tracking and saving the commands being used.

Now the problem is that the built-in logging mechanism in bash i.e. .bash_history file (or the "history" command) is not reliable. First, the command is not logged immediately it is entered into the shell, 2nd and most importantly if the bash session is terminated or gets disconnected abnormally, all the commands for that session would be lost.
 This means that if the linux system crashes, you will never see the commands that were last run in the active bash sessions when the system crashed. Well in bash's defence this feature is never intended to be used for tracking or auditing, it is just command history keeper that keeps track of you last executed commands in case you press the up-arrow-key or use reverse command search (ctrl + r).

There are many methods to log shell commands, some involve recompiling bash and others involve installing third party key logging software. Both of these options are discouraged and are risky especially on production servers.

Recently I discovered a very quick, safe, neat and efficient way of logging bash commands. I am using it on many production machines and it is doing its job well.


Step 1:
Use your favourite text editor to open /etc/bashrc and append the following line at the end:
export PROMPT_COMMAND='RETRN_VAL=$?;logger -p local6.debug "$(whoami) [$$]: $(history 1 | sed "s/^[ ]*[0-9]\+[ ]*//" ) [$RETRN_VAL]"'

Step 2:
Set the syslogger to trap local6 to a log file by adding this line in the /etc/syslog.conf file:
local6.*                /var/log/cmdlog.log
and restart
service syslog restart
THATS ALL!

Logging bash commands is this easy! Just logoff and log back in and all your commands will be logged in /var/log/cmdlog.log from now on. It is easily customizable what you want to log. Let me first explain how this works

How it works

Well the crucial key behind this logging mechanism is the "PROMPT_COMMAND" variable in bash. According to the bash manual:
If set, the value is executed as a command prior to issuing each primary prompt.
In easy words(tldp):

Bash provides an environment variable called PROMPT_COMMAND. The contents of this variable are executed as a regular Bash command just before Bash displays a prompt.
So once we know that bash will execute the content of this variable, we can do any thing (limited to your imagintion). For logging this is what I am doing:
RETRN_VAL=$?
i.e, save the return code in a variable (before it is lost ;))
logger -p local6.debug "$(whoami) [$$]: $(history 1 | sed "s/^[ ]*[0-9]\+[ ]*//" ) [$RETRN_VAL]"
next I am logging the following (using the logger command):
$(whoami) => Current user name
[$$] => PID of current Shell (helps differentiate b/w multiple sessions by the same user)
$(history 1 | sed "s/^[ ]*[0-9]\+[ ]*//" ) => Last executed command, sed is used to remove the command index number and the whitespaces outputted by the history command
[$RETRN_VAL] => Add the return code at the end in square brackets

Sample Logs:
Jan  2 15:20:01 testdb1 oratest: oratest [5583]: cd /testdata [0]
Jan  2 15:20:02 testdb1 oratest: oratest [5583]: ls -ltr [0]
Jan  2 15:20:15 testdb1 oratest: oratest [5583]: du -sh * [0]
Jan  2 15:21:56 testdb1 oratest: oratest [5583]: clear [0]
Jan  2 15:21:59 testdb1 oratest: oratest [5583]: df -h  [0]
Jan  2 15:28:00 testdb1 oratest: oratest [5583]: uptime [0]
Jan  2 15:28:09 testdb1 oratest: oratest [5583]: top c [0]
Jan  3 10:57:18 testdb1 khizer: khizer [22493]: su - [0]
Jan  3 10:57:26 testdb1 khizer: khizer [22493]: su - [1]
Jan  3 10:57:31 testdb1 khizer: root [22646]: ulimit -c [0]
Jan  3 11:20:49 testdb1 khizer: khizer [808]: ping 10.105.22.71 [0]
Jan  3 11:29:57 testdb1 khizer: root [22646]: crontab -e [0]
Jan  3 11:30:01 testdb1 khizer: root [22646]: service crond relaod [1]
Jan  3 11:30:05 testdb1 khizer: root [22646]: service crond reload [0]
Jan  3 11:30:20 testdb1 khizer: khizer [808]: wq [127]
Jan  3 11:30:43 testdb1 khizer: khizer [808]: q [127]
Jan  3 11:37:13 testdb1 khizer: khizer [808]: date [0]
Jan  3 12:00:05 testdb1 khizer: root [22646]: crontab -e [0]
Jan  3 12:00:06 testdb1 khizer: root [22646]: service crond reload [0]
Jan  4 10:42:10 testdb1 oratest: oratest [23732]: rm -rf p_HPUX-IA64.zip rda p11812741_423_HPUX-IA64.zip readme.txt 6249879 [0]
Jan  4 10:42:12 testdb1 oratest: oratest [23732]: ls -ltr  [0]
Jan  4 10:42:17 testdb1 oratest: oratest [23732]: mkdir TEST [0]
Jan  4 10:42:18 testdb1 oratest: oratest [23732]: pwd [0]
Jan  4 10:43:56 testdb1 oratest: oratest [23732]: vi backup.sql [0]
Jan  4 10:44:02 testdb1 oratest: oratest [23732]: vi backup.sql [1]



29 comments:

  1. Hi!

    just one small problem:

    if you hit the "enter" key without a command, the last command is being logged again and again...

    ReplyDelete
  2. Yeah it is like that. Normally sys-log would combine the similar outputs to say "Last Message repeated N times" instead of logging thing again and again.

    ReplyDelete
  3. Thank you. This will really help me to monitor the DBA/APPs Guys what they are doing in our server.

    ReplyDelete
  4. Thank you for your resolution. But, how to logging csh, sh...shel commands ? Please help me!

    ReplyDelete
  5. Hello,

    How can i make mapping between PID of current Shell and ip address associated with this.

    ReplyDelete
  6. I can add $SSH_CLIENT into /etc/bashrc and is ok for the curent user login. But if the user became root via sudo, in the next log the ip address no longer exist.

    Any idea?

    ReplyDelete
    Replies
    1. That is because when a shell user switches to another user it gets a new shell session along with new shell variables. I can't seem to find a easy way to pass along a variable to the newly spawned shells (via su or sudo). A very quick way of solving this problem would be to keep track of TTY session (which will be consistent through all the sub-shell sessions) and $SSH_CLIENT variable in a file. Here is how I did it:

      #> mkdir -p /var/run/cmd_log
      #> touch /var/run/cmd_log/_dev_pts_{0..100}
      #> chmod -R 777 /var/run/cmd_log

      Set the COMMAND_PROMPT variable in /etc/bashrc something like this:

      export PROMPT_COMMAND='RETRN_VAL=$?;TTY_SESSION=$(tty | tr '/' '_');test -n "$SSH_CLIENT" -a ! -s /var/run/cmd_log/$TTY_SESSION && echo $SSH_CLIENT > /var/run/cmd_log/$TTY_SESSION; printf "\033]0;%s@%s:%s\007" "${USER}" "${HOSTNAME%%.*}" "${PWD/#$HOME/~}";logger -p local6.debug "$(whoami) [$$]: $(history 1 | sed "s/^[ ]*[0-9]\+[ ]*//" ) [$RETRN_VAL] [[$(cat /var/run/cmd_log/$TTY_SESSION)]]"'

      I am sure there must be better ways of doing this! If you figure out a better way, do let me know :)

      I hope this helps.

      Delete
  7. ¿Does this affects the value of $? ? if you need to use it after a command it is preserved or is the value of the PROMPT_COMMAND?

    ReplyDelete
    Replies
    1. Good question. No this doesn't affect the value of $? variable.

      Delete
  8. Not working for me on centos 5.6. even the log file is not getting created

    ReplyDelete
  9. kill -9 $$ and you log nothing :) solve this one ;)

    ReplyDelete
    Replies
    1. You are right. This script has many more limitations than just that. Just unset the PROMPT_COMMAND variable and it will stop working. This script is just to keep a good time based record of the commands you or your fellow users run on the shell. This script doesn't promise to help you track users with bad intentions.

      Delete
  10. "service syslog restart" this command needs to be run after the config changes. Missing in the steps above

    ReplyDelete
    Replies
    1. Yes, thanks for pointing that out. I'll add it in the steps.

      Delete
  11. Hi Khizer! great tutorial. Just one thing (i don't know if i'm doing this right) with this procedure i only get root user bash logs. I mean, with sudo su will log messages, but if i'm not root, it won't. Is this ok? if it is, how can i add all users bash logs?
    Thanks!!

    ReplyDelete
    Replies
    1. As long as you stay in the bash shell, no matter what user you switch to, it should log the commands. I use this extensively in production (mainly on RHEL 5/6). How ever, if the user you are switching to from root has its default shell other than bash, like csh or ksh, it will stop working. (you can check the default shell of the users in /etc/passwd)

      Delete
  12. lets say an oracle user changes his shell and gets into the sql prompt, is ther a way to track down/log the sql commands the user ran ?

    ReplyDelete
    Replies
    1. No any thing outside bash won't be logged. Just the command you enter in the bash shell

      Delete
    2. Depending on your db you can monitor sql commands with builtin auditing for oracle, sybase or write a trigger that would save all needed data in table for postgres, mysql

      Delete
  13. Is there a way you know I could monitor the commands that are typed on runtime. Lets say I want to monitor my own commands and have the terminal prompt me if I typed "find" instead of "find -name ". So i'd like to stop the execution of the command and prompt back saying "hey you typed this command, please type this and that to execute it" sorts.
    Thanks for any help in the direction. I've been trying to get info on how to do this but haven't been successful yet.

    ReplyDelete
  14. Great tutorial and thank you! I've set this up on multiple rhel servers but would like to have all instances of /var/log/cmdlog.log files written to a single file on one server. Can you assist?

    ReplyDelete
  15. hi,

    I am facing one problem with this .The history 1 command executes when the user login initially and takes the last command executed .

    For example a normal user executed init 6 ( which will fail since it i not root ) and logs init 6 command with return code 1 ( This is fine for me ) and lets consider user logged off for the day.
    Next day when user logging in the last command will be init 6 in history and it logs as init 6 with a return code 0 ( Infact on this day user was not tried the init 6 command ) . But the log says user executed init 6 command and it was a success .

    Could you please help on this ?
    On the next day

    ReplyDelete
  16. You could use two alternative options to achieve similar result:
    - auditd, if your kernel/distro supports it, targeted more at real auditing, or
    - Snoopy Logger (https://github.com/a2o/snoopy/ ), lightweight(-er) solution, if you trust your users and just need a log of commands).

    Disclosure: Snoopy maintainer here.

    ReplyDelete
  17. đồng tâm
    game mu
    cho thuê nhà trọ
    cho thuê phòng trọ
    nhac san cuc manh
    số điện thoại tư vấn pháp luật miễn phí
    văn phòng luật
    tổng đài tư vấn pháp luật
    dịch vụ thành lập công ty trọn gói
    nước cờ trên bàn thương lượng
    mbp
    erg
    nghịch lý
    chi square test
    nghệ thuật nói chuyện
    coase
    thuyết kỳ vọng
    chiến thắng con quỷ trong bạn
    cân bằng nash

    Nhanh như vậy đã thành lập công ty?

    Suy nghĩ đến tình hình hiện nay, Triệu Quốc Đống gật đầu. Hắn biết Thái Chánh Dương đang khó xử vì việc này. Hắn mới là phó phòng, đến Sở Giao thông đã là quá chói mắt. Mục đích của công ty khai thác đường cao tốc là gì thì ai cũng biết. Không nói là đơn vị cấp huyện, dù là cấp phó huyện cũng đủ làm bao người thèm muốn.

    Không phải người của Thái Chánh Dương không thể ngồi vào vị trí giám đốc công ty. Nhưng mà người của Thái Chánh Dương chưa chắc đã có thể ngồi ổn ở vị trí này. Trong đó dính dáng quá nhiều lợi ích, công ty khai thác đường cao tốc về sau liên lụy tới khối lượng công trình quá lớn.

    - Chú làm thì anh rất yên tâm, nhưng kinh nghiệm và cấp bậc hành chính của chú lại thấp. Công ty khai thác đường cao tốc không chỉ phụ trách thủ tục khai thác, còn dính dáng tới nhiều việc khác nữa. Cho nên hôm nay Chủ tịch Tần cùng anh nói chuyện chính là việc này.
    Thái Chánh Dương trầm ngâm một chút rồi nói.

    - Thái ca, em không thích hợp với công ty khai thác đường cao tốc. Kinh nghiệm, tuổi của em đều không thích hợp. Hơn nữa em không thích việc kinh doanh.
    Triệu Quốc Đống nói:
    - Thái ca không cần suy nghĩ cho em. Em vào sở được lên cấp Trưởng phòng đã làm bao người đỏ mắt. Nếu làm em tới làm phó giám đốc công ty khai thác đường cao tốc thì có lẽ sẽ có người nảy lầu mất.

    - Công ty khai thác đường cao tốc không phải một hai ngày có thể thành lập, anh đoán có lẽ năm sau mới chính thức xác định Cao tốc An Du, An Quế thì mới thành lập. Hòa Hoàng coi như quyết định vào Cao tốc An Quế, hơn nữa Tân Gia Pha và Tân Thế Giới cũng sẽ liên doanh xây dựng Cao tốc An Du, công lao này của chú thì trên tỉnh không thể không thấy. Phá cách đề bạt làm phó giám đốc cũng không phải không thể. Anh chỉ là thấy chú quen chủ trì công việc ở Phòng cao tốc, lần này nếu chú mà đến làm phó thì sợ không quen.

    ReplyDelete
  18. This comment has been removed by the author.

    ReplyDelete
  19. Thank you very much, It is very useful for me..............

    ReplyDelete
  20. gracias, me sirvio y tomare en cuenta los comenarios de los demas

    ReplyDelete
  21. This works for me also... Thank you very much.....

    ReplyDelete
  22. Very good TutoriaL........

    ReplyDelete