Como posso registrar totalmente todas as ações de scripts bash?

Eu geralmente coloco algo semelhante ao seguinte no início de cada script (especialmente se ele for executado como um daemon):

#!/bin/bash
exec 3>&1 4>&2
trap 'exec 2>&4 1>&3' 0 1 2 3
exec 1>log.out 2>&1
# Everything below will go to the file 'log.out':

Explicação:

1. exec 3>&1 4>&2

   Salva descritores de arquivo para que possam ser restaurados para o que eram antes do redirecionamento ou usados ​​para produzir o que eram antes do redirecionamento a seguir.

2. trap 'exec 2>&4 1>&3' 0 1 2 3

   Restaurar descritores de arquivo para sinais específicos. Geralmente não é necessário, pois eles devem ser restaurados quando o sub-shell sair.

3. exec 1>log.out 2>&1

   Redirecione stdoutpara o arquivo log.oute depois redirecione stderrpara stdout. Observe que a ordem é importante quando você deseja que eles vão para o mesmo arquivo. stdout deve ser redirecionado antes stderrde ser redirecionado para stdout.

A partir de então, para ver a saída no console (talvez), você pode simplesmente redirecionar para &3. Por exemplo,

echo "$(date) : part 1 - start" >&3

irá para onde stdoutfoi direcionado, presumivelmente o console, antes de executar a linha 3 acima.

Enquanto leio sua pergunta, você não deseja registrar a saída, mas toda a sequência de comandos; nesse caso, as outras respostas não o ajudarão.

Invoque scripts de shell com -x para produzir tudo:

sh -x foo.sh

Faça login no arquivo desejado com:

sh -x foo.sh >> /home/scripts/cron/logs

para obter a saída ssh para seu arquivo de log, você deve redirecionar stderrpara stdout. você pode fazer isso anexando 2>&1após seu script bash.

deve ficar assim:

#!/bin/bash
(
...
) 2>&1 | tee ...

quando isso não exibir as mensagens na ordem correta, tente adicionar outro subshell:

#!/bin/bash
((
...
) 2>&1) | tee ...

No bash, você pode colocar set -xe imprimir todos os comandos que executa (e as variáveis ​​do bash) depois disso. Você pode desativá-lo com set +x.

Se você quer ser paranóico, você pode colocar set -o errexitem seu script. Isso significa que o script falhará e será interrompido se um comando retornar um código de saída diferente de zero, que é a maneira padrão do unix de sinalizar que algo deu errado.

Se você quiser obter logs melhores, você deve olhar no tspacote moreutilsdebian/ubuntu. Ele irá prefixar cada linha com um carimbo de data/hora e imprimi-lo. Então você pode ver quando as coisas estavam acontecendo.

Seguindo o que outros disseram, o manual do conjunto é um bom recurso. Eu coloco:

#!/usr/bin/env bash
exec 1> command.log 2>&1
set -x

No topo dos scripts, desejo continuar, ou set -exse deve sair em caso de erro.

Descobri que a resposta @nicerobot ( Como posso registrar totalmente todas as ações de scripts bash? ) pode não ser suficiente para redirecionar completamente toda a saída para o console. Alguma saída ainda pode ser perdida.

O redirecionamento completo fica assim:

#!/bin/bash

# some basic initialization steps including `NEST_LVL` and `SCRIPTS_LOGS_ROOT variables...
source ".../__myinit__.sh"

# no local logging if nested call
(( ! IMPL_MODE && ! NEST_LVL )) && {
  export IMPL_MODE=1
  exec 3>&1 4>&2
  trap 'exec 2>&4 1>&3' EXIT HUP INT QUIT RETURN

  [[ ! -e "${SCRIPTS_LOGS_ROOT}/.log" ]] && mkdir "${SCRIPTS_LOGS_ROOT}/.log"

  # RANDOM instead of milliseconds
  case $BASH_VERSION in
    # < 4.2
    [123].* | 4.[01] | 4.0* | 4.1[^0-9]*)
      LOG_FILE_NAME_SUFFIX=$(date "+%Y'%m'%d_%H'%M'%S''")$(( RANDOM % 1000 ))
      ;;
    # >= 4.2
    *)
      printf -v LOG_FILE_NAME_SUFFIX "%(%Y'%m'%d_%H'%M'%S'')T$(( RANDOM % 1000 ))" -1
      ;;
  esac

  (
  (
    myfoo1
    #...
    myfooN

    # self script reentrance...
    exec $0 "$@"
  ) | tee -a "${SCRIPTS_LOGS_ROOT}/.log/${LOG_FILE_NAME_SUFFIX}.myscript.log" 2>&1
  ) 1>&3 2>&4

  exit $?
}

(( NEST_LVL++ ))

# usual script body goes here...

Explicação :

1. Não há o suficiente para redirecionar a saída porque você ainda precisa redirecionar as echochamadas internas para o console e para o arquivo, portanto, o pipe-plus-tee é a única maneira de dividir o fluxo de saída.
2. Temos que usar o (...)operador para redirecionar cada fluxo para um arquivo autônomo ou para restaurar todos os fluxos de volta ao original por etapas separadas. A segunda razão porque myfooas chamadas antes da auto-reentrada precisam funcionar como estão, sem nenhum redirecionamento adicional.
3. Como o script pode ser chamado a partir de um script aninhado, precisamos redirecionar a saída em um arquivo apenas uma vez em uma chamada de nível superior. Então usamos NEST_LVLvariável para indicar o nível de chamada do ninho.
4. Como o redirecionamento pode ser executado externamente independentemente do script, temos que habilitar explicitamente o redirecionamento interno pela IMPL_MODEvariável.
5. Temos que usar valores de data e hora para criar automaticamente um novo arquivo de log exclusivo em cada execução de script.

TL;DR - Ontem escrevi um conjunto de ferramentas para registrar execuções e sessões de programas.

Atualmente disponível em https://github.com/wwalker/quick-log

Como administrador, estou sempre querendo registrar a saída de algum comando, geralmente não um script. Para resolver esse problema, escrevi algumas coisas. O mais fácil é usar o programa "script" como mencionou xX0v0Xx. Descobri que chamar script (sem argumentos) muitas vezes resultaria em substituir a saída de um script anterior. Então eu criei este alias. Tudo o que faz é evitar a substituição. Você precisa de um diretório ~/tmp.

$ alias scr='script ~/tmp/typescript-$(date +%FT%T)'
$ scr
Script started, file is /home/wwalker/tmp/typescript-2019-12-05T18:56:31
$

Isso é ótimo quando quero pegar uma sessão interativa.

Quando quero registrar a saída de um comando (script ou binário), quero a saída exata ou quero a saída com timestamps na frente de cada linha. Então eu escrevi essas duas funções bash:

alias iso8601="date +%Y-%m-%dT%H:%M:%S"

justlog(){
  name=$(basename "$1")
  log=~/logs/${name}-$(iso8601)
  "$@" > "$log" 2>&1
}

timelog(){
  name=$(basename "$1")
  log=~/logs/${name}-$(iso8601)
  # https://github.com/wwalker/ilts
  # You could replace ilts with ts
  # /usr/bin/ts %FT%H:%M:%.S
  "$@" |& ilts -S -E > "$log" 2>&1
}

Basta executar seu comando como faria normalmente:

justlog run rcn rcn-work\\\\\* 'ps -ef -o lstart,cmd | grep [s]upervisor'

ou

timelog run rcn rcn-work\\\\\* 'ps -ef -o lstart,cmd | grep [s]upervisor'

Isso acabou de criar 2 arquivo chamado:

wwalker@polonium:~ ✓ $ ls -l ~/logs/run*
-rw-r--r-- 1 wwalker wwalker 10495 2019-12-05 18:21:14.985 /home/wwalker/logs/run-2019-12-05T18:21:13
-rw-r--r-- 1 wwalker wwalker  1694 2019-12-05 18:24:02.878 /home/wwalker/logs/run-2019-12-05T18:24:01
-rw-r--r-- 1 wwalker wwalker  7623 2019-12-05 18:25:07.873 /home/wwalker/logs/run-2019-12-05T18:25:06
-rw-r--r-- 1 wwalker wwalker 10296 2019-12-05 18:34:59.546 /home/wwalker/logs/run-2019-12-05T18:34:57

Mas, espere que tem mais!!

Eu não queria ter que fazer um ls para encontrar o nome do arquivo de log que justlog ou timelog acabou de criar para mim. Então, eu adicionei mais 3 funções:

newestlog(){
  name=$(basename "$1")
  ls  ~/logs/"${name}"* | tail -1
}

viewlog(){
  name=$(basename "$1")
  view $( newestlog "$name" )
}

lesslog(){
  name=$(basename "$1")
  less $( newestlog "$name" )
}

Então, você executa seu comando com justlog (ou timelog) e, em seguida, basta usar lesslog ou viewlog (provavelmente criarei um log do emacs para essas pessoas):

justlog run rcn rcn-work\\\\\* 'ps -ef -o lstart,cmd | grep [s]upervisor'
lesslog run

É isso, não ls ~/tmp, não há jogos de conclusão de guias para encontrar o nome do arquivo. Basta executar lesslog (ou viewlog se você gosta de usar o vim para ver os logs).

Mas espere! Tem mais!

"Eu uso grep o tempo todo em meus arquivos de log" - E a resposta é, você adivinhou,greplog

Primeiro, obtenha o texto de todos os arquivos /etc/cron.d/atop do servidor 800 que estão quebrados:

justlog fordcrun 'cat /etc/cron.d/atop; md5dum /etc/cron.d/atop'

Em seguida, obtenha os nomes de host (na linha acima da saída no arquivo :-) ) com greplog:

wwalker@polonium:~ ✓ $ greplog fordcrun  -B1 -F "0 0 * * root"
int-salt-01:
    0 0 * * root systemctl restart atop
--
rcn-pg-01:
    0 0 * * root systemctl restart atop
rcn-pg-02:
    0 0 * * root systemctl restart atop
rcn-pg-03:
    0 0 * * root systemctl restart atop

Você pode simplesmente usar "script".

man scriptpara detalhes.

Exemplo:

script -a -e -c "set -x; echo this is logging ..; <your script can be called here>" mylogfile.log

Então, aqui está uma opção que usei e considero um pouco mais amigável. Essencialmente, defina uma função de tarefa na parte superior de seu script e defina todas as suas seções com suas próprias funções para serem passadas para chamadas da função de tarefa. Ele também pode ser estendido para adicionar alguns sinalizadores específicos de INFO, WARN, DEBUG e ERROR para seus logs. Elas seriam simplesmente funções que usam um echo para encapsular sua mensagem de maneira consistente, já que todas as saídas vão para o seu log de qualquer maneira.

Ficaria algo assim:

# Append a timestamp and always write a new file
#LOGFILE=/var/log/my_setup_log_file.$(date +%Y%h%d_%H.%M).log
# Same log, growing and appending - make sure its a one time deal or that you have a log rotating utility running.
LOGFILE=/var/log/my_setup_log_file.log
touch "${LOGFILE}"
TAIL_PID=$!
# [Un]comment the following line to control display of this script for the tty in real time.  All other commands should be passed to task.
tail -f "${LOGFILE}" &
# logging function - called task to make main section more readable...prepend it to commands, or group commands in a function and prepend the call.
task() {
    echo "===================================================================================================="
    echo "$(date):$(printf ' %q' "$@")"
    echo "===================================================================================================="
    start=$(date +%s)
    "$@" 2>&1
    end=$(date +%s)
    runtime=$((end-start))
    echo "Elapsed time for command was $runtime seconds."
    echo ""
} >> "${LOGFILE}"

### FUNCTION DEFS...

### Main exectuion

task my_operational_step_1
task my_operational_step_2
kill ${TAIL_PID}
exit 0

LIMITAÇÕES e CUIDADO :

1. Na minha primeira iteração, optei por usar o comando tee no modo de acréscimo para todas as gravações de log, o que requer o uso de um pipe. Isso elimina a capacidade de usar variáveis ​​de escopo global entre funções, porque cada função é efetivamente executada em seu próprio subshell, devido ao pipe. Argh.
2. Abordando o problema 1, mudei para a abordagem de usar o tail -f como uma tarefa gerada no início (~ linha 7). Isso permite que a função de tarefa coloque toda a saída no log, mas ainda seja capaz de ver o que está acontecendo em tempo real.
3. Observe que você precisa capturar o PID do tail para matá-lo mais tarde, como você pode ver na linha 8, e depois o kill no final do script.
4. Um corolário para o item 3 é que se seu script sair mais cedo, o tail continua rodando em segundo plano... Provavelmente vale a pena escrever algumas armadilhas para lidar com isso... Eu não me incomodei com isso, dado o escopo do que eu ' estou fazendo.
5. Eu não usei isso extensivamente, então você pode se deparar com problemas nos quais não pensei.
6. É possível ter coisas que não são registradas usando essa abordagem, portanto, não é uma resposta perfeita para a pergunta do OP.