cancelar
Mostrar resultados para 
Pesquisar em vez de 
Queria dizer: 
cancel
979
Apresentações
54
Útil
3
Respostas

Analise de Log Call Manager

rodrigosenador
Level 1
Level 1

Boa noite a todos

O motivo desta discusão e para falar e ajudar a analisar logs de erros no calllmanager e como não achei muita coisa sobre o assunto estou colocando minha duvida aqui

Sr(a)s

Segue um trecho do log emitido:

10:20:50.977 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[350]: [sip_display:3726]  state = 9  event = 12  cause = 12 lineID = 1   

10:20:50.992 : 192.168.102.87 : Usr Level :INFO    : voip_task[350]: [sip_post_process_event:4442] Received Event(id-12):Unknown, line->num=0, ^M

10:20:51.023 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[350]: [sip_display:3726]  state = 8  event = 28  cause = 12 lineID = 1   

10:20:51.055 : 192.168.102.87 : Usr Level :INFO    : voip_task[350]: [sip_post_process_event:4442] Received Event(id-28):Unknown, line->num=0, ^M

10:20:51.086 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[350]: [sip_display:3726]  state = 0  event = 29  cause = 12 lineID = 1   

10:20:51.117 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 9

10:20:51.133 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 0

10:20:51.164 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:20:51.195 : 192.168.102.87 : Usr Level :INFO    : voip_task[350]: [sip_post_process_event:4442] Received Event(id-29):Unknown, line->num=0, ^M

10:20:51.226 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:21:06.701 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 2 (4).

10:21:06.733 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [acl_pfn_state_changed_ev_handler:7649] Registration successed. starting registration timer with normal timeout.

10:21:06.764 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 5 (0).

10:21:06.795 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5376] Line 0 registed success.

10:21:06.826 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 20

10:21:06.857 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5401] Line 0 registered successfully.

10:21:06.873 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:22:25.918 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 2 (4).

10:22:25.965 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [acl_pfn_state_changed_ev_handler:7649] Registration successed. starting registration timer with normal timeout.

10:22:25.996 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 5 (0).

10:22:26.027 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5376] Line 0 registed success.

10:22:26.059 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 20

10:22:26.074 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5401] Line 0 registered successfully.

10:22:26.105 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:20:50.977 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[350]: [sip_display:3726]  state = 9  event = 12  cause = 12 lineID = 1   

10:20:50.992 : 192.168.102.87 : Usr Level :INFO    : voip_task[350]: [sip_post_process_event:4442] Received Event(id-12):Unknown, line->num=0, ^M

10:20:51.023 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[350]: [sip_display:3726]  state = 8  event = 28  cause = 12 lineID = 1   

10:20:51.055 : 192.168.102.87 : Usr Level :INFO    : voip_task[350]: [sip_post_process_event:4442] Received Event(id-28):Unknown, line->num=0, ^M

10:20:51.086 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[350]: [sip_display:3726]  state = 0  event = 29  cause = 12 lineID = 1   

10:20:51.117 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 9

10:20:51.133 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 0

10:20:51.164 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:20:51.195 : 192.168.102.87 : Usr Level :INFO    : voip_task[350]: [sip_post_process_event:4442] Received Event(id-29):Unknown, line->num=0, ^M

10:20:51.226 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:21:06.701 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 2 (4).

10:21:06.733 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [acl_pfn_state_changed_ev_handler:7649] Registration successed. starting registration timer with normal timeout.

10:21:06.764 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 5 (0).

10:21:06.795 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5376] Line 0 registed success.

10:21:06.826 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 20

10:21:06.857 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5401] Line 0 registered successfully.

10:21:06.873 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

10:22:25.918 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 2 (4).

10:22:25.965 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [acl_pfn_state_changed_ev_handler:7649] Registration successed. starting registration timer with normal timeout.

10:22:25.996 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5353] sip_pre_reg_client_state_changed - Line 0 (5076) ==> State 5 (0).

10:22:26.027 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5376] Line 0 registed success.

10:22:26.059 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [display_update_cb:3871] update display status to 20

10:22:26.074 : 192.168.102.87 : Usr Level :NOTICE  : voip_task[350]: [sip_pre_reg_client_state_changed:5401] Line 0 registered successfully.

10:22:26.105 : 192.168.102.87 : Usr Level :DEBUG   : voip_task[355]: [messageQ_receiver: 225] received msg: type=1, id=110

Agora minha duvida

o que seria o State = 01 o que significa ?

e o Cause = 12 ?

existe uma tabela para decifrar estes codigos

se alguem puder me ajudar agradeço.

Atenciosamente,

Rodrigo Prado.

3 RESPOSTAS 3

Opa Rodrigo, sinceramente já vi muitos traces do CUCM para troubleshooting em roteamento da chamada mas nunca vi este dai não. Parece ser de algum serviço especifico.

Quando habilitamos os traces da pra especificar N "subserviço", tais como Enable SIP Stack Trace, Enable Music On Hold Trace, etc etc.....e eu até hoje só habilitei algum especifico quando engenheiros do tac solicitavam. Acredito que este log ai seja relacionado ao Serviço CallManager e "subserviço" SIP Stack.... mas fica dificil interpretar um trace sem saber o porque dele ter sido coletado.

Achei esse doc aqui que pode te auxiliar: http://www.cisco.com/en/US/docs/voice_ip_comm/cucm/service/9_0/admin/CUCM_BK_C136FE37_00_cisco-unified-serviceability-administration-guide_chapter_011.html

E infelizmente eu desconheço alguma tabela para decifrar os codigos exibidos nos traces. Mas tem boas almas que ajudam criando documentações que auxiliam nas nossas análise. veja este exemplo:

https://supportforums.cisco.com/docs/DOC-11779

Espero ter ajudado,

Leonardo Oliveira
www.avvid.net

Leonardo Oliveira

Bruno Rangel
Spotlight
Spotlight

Olá Rodrigo apenas para completar a otima resposta do Leonardo (+5 stars)...

E infelizmente eu desconheço alguma tabela para decifrar os codigos  exibidos nos traces. Mas tem boas almas que ajudam criando documentações  que auxiliam nas nossas análise. veja este exemplo:

https://supportforums.cisco.com/docs/DOC-11779


Essse mesmo documento foi traduzido pela Michelle Jardim na CSC Portugues, veja:

Rastreando chamadas H323 em CCM SDI traces

Cheers
Bruno Rangel

"Se você quiser alguém em quem confiar, confie em si mesmo. Quem acredita sempre alcança"
Renato Russo

Cheers
Bruno Rangel
Please remember to rate helpful responses using the star bellow and identify helpful or correct answers

Ola pessoal,

Apenas uma informação complementar. Vocês podem usar a ferramenta abaixo para analisar os logs de chamadas:

Voce coleta o CCM SDI traces e abre com a ferramenta. Ela te proporciona filtros que vão facilitar bastante seu troubleshooting.

http://translatorx.cisco.com/

Attn,

Daniel

Daniel Sobrinho