Descrição

Este artigo descreve como solucionar problemas e realizar análise de causa raiz quando um CVM (VM controlador) é reinicializado repentinamente.

Logs para procurar dentro da CVM:

 dmesg /var/log/messages /home/log/messages (terá os logs detalhados do kernel no momento da reinicialização.)

Registros a serem procurados no host AHV:

 /tmp/NTNX.serial.out.0 /var/tmp/NTNX.serial.out.0 /var/log/libvirt/qemu/NTNX-
  
  -
   
  
   -CVM.log
   
  
  
  
 

Logs a serem procurados dentro do ESXi:

 /vmfs/volumes/NTNX-local-ds-
  
  -
   
  
   /ServiceVM_Centos/ServiceVM_Centos.0.out /vmfs/volumes/NTNX-local-ds-
    
   
    -
     
    
     /ServiceVM_Centos/vmware.log /var/log/vmksummary.log
     
    
    
    
   
   
   
  
  
  
 

Para revisar a latência de memória/uso da CPU/disco do CVM no momento da reinicialização, os logs sysstats em /home/nutanix/data/logs/sysstats podem ser revisados. Observe que os logs estão no carimbo de data/hora UTC.

 /home/nutanix/data/logs/sysstats/meminfo.INFO
/home/nutanix/data/logs/sysstats/mpstat.INFO
/home/nutanix/data/logs/sysstats/iostat.INFO

Solução

Exemplos

1. Última reinicialização do comando CVM:

    nutanix@cvm$ última reinicialização
   reinicie a inicialização do sistema 2.6.32-279.9.1.e Seg, 23 de dezembro 09:40 - 12:16 (02:36)

2. Logs na CVM /var/log/messages e kern.log :

    23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Aguardando a criação de /dev/fct0
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: sondado fct0
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: sector_size=512
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: O dispositivo está operando como um dispositivo de bloco.
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: configurando dados de intervalo de canal para [2 .. 2047]
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: *** desligamento impuro detectado, verificando novamente o log. ***
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: *** isso pode levar vários minutos.              ***
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: ************************ ***************************
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: Powercut detectado
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365 GB 0000:03:00.0: Reconectado com sucesso após desligamento impróprio.  (AP: 1942+228114432)
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioinf Fusion-io ioDrive2 365GB 0000:03:00.0: Criando dispositivo de bloco fioa: principal: 252 menor: 0 tamanho do setor: 512...
   23 de dezembro 09:40:06 Kernel NTNX-CVM-A: fioa: fioa1

3. Logs ESXi /vmfs/volumes/xxxxxxxx-xxxxxxxx-xxxx-xxxxxxxxxxxx/ServiceVM*/vmware.log :

    2013-12-23T17:35:25.959Z| vcpu-0| I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-2| I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-7| I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-1 | I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-5| I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-4| I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-3| I120: Reinicialização da CPU: suave (modo 1)
   2013-12-23T17:35:25.960Z| vcpu-6| I120: Reinicialização da CPU: suave (modo 1)

   
   "Reiniciar sistema operacional convidado" no CVM iniciado a partir do vCentre resulta na seguinte assinatura no vmware.log do cvm
   (Observe que esta entrada não ocorre no vmware.log se o CVM tiver sido reiniciado normalmente de dentro do Cluster Nutanix por meio do AOS Upgrade ou do comando cvm_shutdown)

    2022-03-01T23:24:30.638Z| vmx| I125: Ferramentas: enviando solicitação de alteração de estado 'OS_Reboot' (estado = 2)
   

   
   "Shutdown Guest OS" no CVM iniciado a partir do vCentre resulta na seguinte assinatura no vmware.log do cvm
   (Observe que esta entrada não ocorre no vmware.log se o CVM tiver sido desligado normalmente de dentro do Cluster Nutanix por meio do AOS Upgrade ou do comando cvm_shutdown)

    2022-03-02T00:22:15.448Z| vmx| I125: Ferramentas: enviando solicitação de mudança de estado 'OS_Halt' (estado = 1)
   

   
   Outro exemplo de vmware.log (baseado no bug VMware nº 676321):

    17-07-2013T22:35:53.907Z| vcpu-0| W110: PÂNICO DO MONITOR: vcpu-7:ASSERT vmcore/exts/hv/vt/hv-vt.c:1933 bugNr=676321
   17-07-2013T22:35:53.907Z| vcpu-0| I120: Core dump com build build-838463
   17-07-2013T22:35:53.907Z| vcpu-6| I120: Saindo do vcpu-6
   17-07-2013T22:35:53.907Z| vcpu-4| I120: Saindo do vcpu-7
   17-07-2013T22:35:53.907Z| vcpu-0| W110: Gravando arquivo principal do monitor "/vmfs/volumes/50630639-74fa7b98-830d-0025904c8605/ServiceVM-1.24_Ubuntu/vmmcores.gz"
   

   
   Outro vmware.log (configuração incorreta do EPT - VMware KB 1036775 ):

    03-05-2013T17:27:43.262Z| vcpu-1| MONITOR PANIC: vcpu-0:Configuração incorreta do EPT: PA b49b405b0
   03-05-2013T17:27:43.262Z| vcpu-1| Core dump com build build-623860
   03-05-2013T17:27:43.262Z| vcpu-1| Gravando o arquivo principal do monitor "/vmfs/volumes/51548019-3efd569e-d4d8-002590840e37/ServiceVM/vmmcores.gz"
   03-05-2013T17:27:43.262Z| vcpu-6| Saindo do vcpu-6
   

4. Os logs ESXi /vmfs/volumes/xxxxxxxx-xxxxxxxx-xxxx-xxxxxxxxxxxx/ServiceVM*/ServiceVM.out.0 mostram o problema driver jbd2/fio neste exemplo:

    último arquivo sysfs: /sys/devices/pci0000:00/0000:00:10.0/host2/target2:0:2/2:0:2:0/block/sdb/queue/scheduler CPU 0 Módulos vinculados em: be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4 cxgb3i libcxgbi cxgb3 mdio ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr i Pid: 3403, comm: jbd2/fioa1-8 Tainted: P --------------- 2.6.32 -279.9.1.el6.nutanix.x86_64 #1 VMware, Inc. VMware Virtual Platform/440BX Desktop RIP: 0010:[
       
       ] [
        
       
        ] jbd2_journal_commit_transaction + 0x120c/0x14b0 [jbd2] RSP: 0018:ffff880431113d30 EFLAGS: 00010246 RAX: 0000000000000008 RBX: ffff8804330d9800 RCX: 000000000 RDX: ffff8804060ff000 RSI: 0000000000000286 RDI: ffff8804330d9800 RBP: ffff880431113e60 R08: ffff880028216e90 R09: ffff880028216f00 : 000000000000018 R11: 000000000000000 R12: 0000000000000000 R13: ffff8804330d9800 R14: ffff8804220a4ae0 R15: ffff8804330d9898 FS: 0000000000000000(0000) 00) knlGS:000000000000000 CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b CR2: 00007fbeca8a4916 CR3: 0000000378ef3000 CR4 : : 000000000000000 DR1: 000000000000000 DR2: 000000000000000 DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 Processo jbd2/fioa 1-8 (pid: 3403, threadinfo ffff880431112000, tarefa ffff8804220a4ae0) Pilha:
        
       
       
       
      

5. Para qualquer falha recente no disco rígido, verifique o log hades.out.

   Se o SSD for a unidade de metadados, o AOS forçará a reinicialização do CVM. Além disso, se o AOS tiver problemas para remover um HDD e uma remoção forçada for acionada por hades, um CVM será reinicializado.

   A saída de ServiceVM.out.0 ( Bug 735768 ):

    BUG do kernel em fs/jbd2/commit.c:353! código de operação inválido: 0000 [#1] último arquivo sysfs do SMP: /sys/devices/pci0000:00/0000:00:15.0/0000:03:00.0/host2/port-2:2/end_device-2:2/target2: 0:2/2:0:2:0/bloco/sdc/dev CPU 1

   
   ESXi vmksummary para ver se o host ESXi foi reinicializado:

    [root@esxi]# grep -i bootstop /var/log/vmksummary.log 2015-02-07T02:54:17Z bootstop: Host está desligando 2015-02-07T08:43:04Z bootstop: Host foi inicializado

   
   AHV:

    Logs de inicialização do sistema a partir de logs de auditoria no hipervisor
   
    11277 type=SYSTEM_BOOT msg=audit(1556350213.112:4): pid=4405 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='init exe="/sbin/telinit" hostname=? endereço=? terminal=console res=sucesso'
   11278 type=SYSTEM_RUNLEVEL msg=audit(1556350213.112:5): pid=4405 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='old-level=N new-level=3 exe=" /sbin/telinit" hostname=? endereço=? terminal=console res=sucesso'
   

   
   CVM:

    nutanix@cvm$ sudo grep -i "kmsg iniciado" /home/log/messages 2015-01-30T10:59:39.957663-08:00 Kernel NTNX-A-CVM: imklog 5.8.10, fonte de log = /proc/kmsg iniciado. 2015-02-07T00:46:55.164530-08:00 Kernel NTNX-A-CVM: imklog 5.8.10, fonte de log = /proc/kmsg iniciado.

   
   Role algumas linhas acima para obter mais informações:

    nutanix@cvm$ sudo grep -i -B 5 "kmsg iniciado" /home/log/messages 2015-02-06T18:00:02.539862-08:00 NTNX-C-CVM audispd: node=NTNX-C-CVM type= EOE msg=auditoria(1423274402.537:7498): 2015-02-06T18:00:02.578946-08:00 NTNX-C-CVM audispd: node=NTNX-C-CVM type=SYSCALL msg=audit(1423274402.577:7499): arch = c000003e syscall = 90 sucesso = sim saída = 0 a0 = 251b700 a1 = 1ed a2 = 7f1ddb485a08 a3 = 7fff69bbdf30 itens = 1 ppid = 8586 pid = 9025 auid = 1000 uid = 1000 gid = 1000 euid = 1000 suid = 1000 fsuid = 1000 egid=1000 sgid=1000 fsgid=1000 tty=(nenhum) ses=150912 comm="python" exe="/usr/bin/python" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=" perm_mod" 2015-02-06T18:00:02.585360-08:00 NTNX-C-CVM audispd: node=NTNX-C-CVM type=SYSCALL msg=audit(1423274402.584:7500): arch=c000003e syscall=90 sucesso=yes saída = 0 a0 = 2894550 a1 = 1ed a2 = 7f1e2b955a08 a3 = 7fff0e433a48 itens = 1 ppid = 8570 pid = 9026 auid = 1000 uid = 1000 gid = 1000 euid = 1000 suid = 1000 fsuid = 1000 egid = 1000 1000 fsgid = 1000 tty=(nenhum) ses=150897 comm="python" exe="/usr/bin/python" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key="perm_mod" 2015-02-06T18: 00:02.585392-08:00 NTNX-C-CVM audispd: node=NTNX-C-CVM type=PATH msg=audit(1423274402.584:7500): item=0 name="/home/nutanix/.python-eggs/simplejson -3.4.1-py2.6-linux-x86_64.egg-tmp/simplejson/tmp0cHe62.$extract" inode=365 dev=09:02 modo=0100600 ouid=1000 ogid=1000 rdev=00:00 obj=unconfined_u: object_r:user_home_t:s0 nametype=NORMAL

Para versões mais recentes do CVM, pode ser necessário usar o grep para "rsyslogd.*start" em vez de "kmsg iniciado":

 nutanix@cvm$ sudo grep -i "rsyslogd.*start" /var/log/messages 2018-03-06T03:28:13.648673-07:00 NTNX-C-CVM rsyslogd: [software de origem = "rsyslogd" swVersion = " 7.4.7" x-pid="1273" x-info="http:// www .rsyslog.com"] início 2018-03-06T03:28:13.647853-07:00 NTNX-C-CVM rsyslogd-2307: aviso: ~ a ação está obsoleta, considere usar a instrução 'stop' [tente http:// www .rsyslog.com/e/2307 ] 2018-03-06T03:28:13.651494-07:00 NTNX-C-CVM systemd [1]: Serviço de registro do sistema iniciado.

Informações adicionais

• Nutanix KB 1252 - Documento original no Portal Nutanix
• Página de destino da Nutanix
• Plano de suporte Lenovo ISG - ThinkAgile HX Appliance e Lenovo Converged HX Series