Índice

Introdução

Pré-requisitos

Requisitos

Componentes Utilizados

Informações de Apoio

Problema

A maioria de problemas comuns

Media podados

Poda para a idade

Análise do log do exemplo para a gravação de seguimento que poda pela idade

Poda para o espaço

Poda antes de arquivístico

Falha da negociação codec de CUCM

Logs MS

Logs CUCM

Codecs comuns

Introdução

Este original descreve os problemas comuns considerados em MediaSense (MS) que causam gravações perdidas ou unplayable no server.

Pré-requisitos

Requisitos

Cisco recomenda-o tem o conhecimento nestes assuntos:

- Cisco MS

- Cisco Unified Contact Center Express (UCCX)

- Gerente das comunicações unificadas de Cisco (CUCM)

Componentes Utilizados

As informações neste documento são baseadas nestas versões de software e hardware:

- MS 10.5 e últimos

- Gerenciador de chamada 11.0

A informação neste documento foi criada dos dispositivos em um ambiente de produção específico. Todos os dispositivos utilizados neste documento foram iniciados com uma configuração (padrão) inicial. Se sua rede está viva, assegure-se de que você compreenda o impacto potencial do comando any.

Informações de Apoio

Um da maioria de problemas comuns encontrados no MS é que não pode alcançar gravações porque o media é removido do MS. Este original explica como pesquisar defeitos melhor estes tipos de encenações a fim ajudar a compreender porque o media gravado não está no MS.

Problema

Você é incapaz de jogar gravações da busca e do jogo MS. O tamanho da trilha mostra que 00:00:00 e lá são um ponto de exclamação amarelo à esquerda da gravação que indica que não há nenhum media segundo as indicações da imagem.

A maioria de problemas comuns

Media podados

A configuração de poda no MS pode podar gravações se passaram uma determinada idade ou se mais espaço de disco está precisado para umas gravações mais novas.

Você pode encontrar seus ajustes de poda neste lugar: A administração de Cisco MediaSense > a administração > configuração das normas da ameixa seca. Se não remova automaticamente os dados associados e o ajuste convertido dos arquivos de media está selecionado, a seguir quando as gravações forem podadas do server, seu meta - os dados permanecem, e um ponto de exclamação amarelo com um erro do “trilhas canceladas” ou “zero registro do tamanho” é indicado segundo as indicações da imagem.

A maneira a mais rápida de verificar isto é com groom.log gerou pelo serviço de media.

Poda para a idade

Você pode recolher groom.log e/ou orapurge.log da coleção do log de serviço dos media da ferramenta do monitoramento em tempo real (RTMT), ou você pode rapidamente usar o comando line interface(cli):

Note: O log do noivo mostra o arquivo cru SMD, que é associado com o ID de sessão do base de dados de MySQL de serviço de media. É incômodo a fim obter um ID de sessão de um arquivo SMD porque toma o acesso raiz ao server. Estes logs são somente bons a fim compreender da idade das gravações podadas.

Por exemplo, estes logs mostram que as gravações desde o 4 de janeiro, 2017, obtêm podadas:

admin:file view activelog /ora/logs/media/groom.log

|2017-01-05 15:04:37.169| 10093: RUNNING min 86400 secs max 1 days evtmax 1 days

|2017-01-05 15:04:37.169| RETENTION groom /recordedMedia/10093/20170104/586d4513.smd

|2017-01-05 15:04:37.172| RETENTION groom /recordedMedia/10093/20170104/586d463f.smd

|2017-01-05 15:04:37.190| PRUNED DB config before Wed Jan 4 16:11:49 2017

|2017-01-05 15:04:37.252| 10198: RUNNING min 86400 secs max 1 days evtmax 1 days

|2017-01-05 15:04:37.252| RETENTION groom /recordedMedia/10198/20170104/586d45e8.smd

|2017-01-05 15:04:37.272| PRUNED DB config before Wed Jan 4 16:07:41 2017

|2017-01-05 15:04:37.291| 10055: RUNNING min 86400 secs max 1 days evtmax 1 days

|2017-01-05 15:04:37.291| RETENTION groom /recordedMedia/10055/20170104/586d4632.smd

|2017-01-05 15:04:37.311| PRUNED DB config before Wed Jan 4 16:10:05 2017

orapurge.logshow um pouco de mais detalhe como os números do ID de sessão e da trilha são apresentados:

admin: file view activelog /ora/logs/media/orapurge.log

2017-01-10 14:50:26.551 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:71> ] OraSessionPurge purging begins...

2017-01-10 14:50:27.189 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:106> ] Recording id 10000 first time 1483988829 (5873df5d)

2017-01-10 14:50:27.190 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:114> ] Found 0 clips below requested time

2017-01-10 14:50:27.190 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:106> ] Recording id 10001 first time 1483993518 (5873f1ae)

2017-01-10 14:50:27.191 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:114> ] Found 1 clips below requested time

2017-01-10 14:50:27.193 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:142> ] ORA session 56e21598489cf631-TRACK0 has been groomed and is now removed

Análise do log do exemplo para a gravação de seguimento que poda pela idade

Neste exemplo, você vê gravações ter sido podado muito mais rapidamente do que os 90 ajustes da ameixa seca.

Nos logs de ORA-ora, você vê que gravando com ID de sessão 56e5159848cca971, entrou a multa MS apenas e se fechou com um estado CLOSED_NORMAL.

A gravação começou no tempo 1483987536761 da época, que é “segunda-feira o 9 de janeiro 13:45:36 2017 GMT-5:00”.

Você vê que o media URL dentro aqui também, que mostra uma gravação salvar.

0005394466: 10.45.2.17: Jan 10 2017 14:58:09.955 -0400: %CCBU_API-7-TRACE: {Thrd=AMS-pool-1-thread-8} Result from the command -

{"responseMessage":"Success: Your request was successfully completed.","responseCode":2000,"responseBody":... (removed for brevity)

{"sessionState":"CLOSED_NORMAL","callControllerType":"Cisco-CUCM","sessionId":"56e5159848cca971","urls":{"httpUrl":"https://10.45.2.17:8446/recordedMedia/oramedia/mp4/56e5159848cca971.mp4","rtspUrl":"rtsp://10.45.2.17/archive/56e5159848cca971","mp4Url":"https://10.45.2.17:8446/recordedMedia/oramedia/mp4/56e5159848cca971.mp4","wavUrl":"https://10.45.2.17:8446/recordedMedia/oramedia/wav/56e5159848cca971.wav"},"sessionStartDate":1483987536761,"tracks":[{"trackStartDate":1483987536761,"trackDuration":166256,"codec":"PCMU","downloadUrl":"https://10.45.2.17:8446/mma/ExportRaw?recording=56e5159848cca971-TRACK1","trackNumber":1,"trackMediaType":"AUDIO","participants":[{"participantStartDate":1483987536761,"deviceRef":"7876050871","isConference":false,"xRefCi":"40461072","participantDuration":166256,"deviceId":"DOM-WAN-RT1"}]},{"trackStartDate":1483987536761,"trackDuration":166256,"codec":"PCMU","downloadUrl":"https://10.45.2.17:8446/mma/ExportRaw?recording=56e5159848cca971-TRACK0","trackNumber":0,"trackMediaType":"AUDIO","participants":[{"participantStartDate":1483987536761,"deviceRef":"3204","lineDisplayName":"SIN ASIGNAR AREA CAJA","isConference":false,"xRefCi":"18891730","participantDuration":166256,"deviceId":"SEP00CCFC16F00D"}]}],"sessionDuration":166256,"callControllerIP":"10.64.0.12"}

Você vê que esta gravação obtém removida em orapurge.log. Track1 e Track0 são para os partidos separados na gravação:

2017-01-10 15:00:26.539 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:71> ] OraSessionPurge purging begins...

2017-01-10 15:00:27.205 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:106> ] Recording id 10000 first time 1483988829 (5873df5d)

2017-01-10 15:00:27.205 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:114> ] Found 0 clips below requested time

2017-01-10 15:00:27.206 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:106> ] Recording id 10001 first time 1483993518 (5873f1ae)

...

2017-01-10 15:00:27.239 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:106> ] Recording id 10043 first time 1483994599 (5873f5e7)

2017-01-10 15:00:27.239 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:114> ] Found 1 clips below requested time

2017-01-10 15:00:27.242 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurge.cpp:142> ] ORA session 56e5159848cca971-TRACK1 has been groomed and is now removed

...

2017-01-10 15:00:27.464 [ OraSessionPurge(19409) ORA_PURGE=1 <OraSessionPurgep.cpp:193> ] OraSessionPurge purging completes.

Os logs de ORA-ora mostram-nos as sessões que são podadas, ele incluem a sessão mostrada previamente:

0005395238: 10.45.2.17: Jan 10 2017 15:02:47.745 -0400: %CCBU_API-6-PRUNE_SESSIONS_COMMAND: {Thrd=AMS-pool-1-thread-10} %[message=(Prune id = ORA.11.0.1.10000-103.ReplyTo.1.MMA.MMA1-1484074962694-1, # sessions = 6)]: Response to Prune Sessions Command

0005395239: 10.45.2.17: Jan 10 2017 15:02:47.746 -0400: %CCBU_API-7-TRACE: {Thrd=AMS-pool-1-thread-10} deletePrunedSessions(Operation Id: 1386, # sessions: 6) begin transaction duration : 0

0005395240: 10.45.2.17: Jan 10 2017 15:02:47.813 -0400: %CCBU_API-7-TRACE: {Thrd=AMS-pool-1-thread-10} deletePrunedSessions(Operation Id: 1386, # sessions: 6) commit duration : 37

0005395241: 10.45.2.17: Jan 10 2017 15:02:47.813 -0400: %CCBU_API-7-TRACE: {Thrd=AMS-pool-1-thread-10} deletePrunedSessions(Operation Id: 1386, # sessions: 6) transaction duration : 66

0005395242: 10.45.2.17: Jan 10 2017 15:02:47.813 -0400: %CCBU_API-7-TRACE: {Thrd=AMS-pool-1-thread-10} deletePrunedSessions(Operation Id: 1386, # sessions: 6) method duration : 67

0005395243: 10.45.2.17: Jan 10 2017 15:02:47.813 -0400: %CCBU_API-7-TRACE: {Thrd=AMS-pool-1-thread-10} deletePrunedSessions(Operation Id: 1386, # sessions: 6) deletable sessions: 6, deleted sessions: 6

Isto mostra as sessões podadas 6:

0005395244: 10.45.2.17: Jan 10 2017 15:02:47.813 -0400: %CCBU_API-6-PRUNE_SESSIONS_RESPONSE: {Thrd=AMS-pool-1-thread-10} %[message=PruneSessionsResponse[Response,prune.id=ORA.11.0.1.10000-103.ReplyTo.1.MMA.MMA1-1484074962694-1,status=SUCCESS,sessions(6)=[56e5159848cca971, 56e6159848cedb61, 56e7159848ddf241, 56e8159848de26c1, 56e91598490f5bd1, 56ea1598493582c1],seqnum=2780,header=MessageHeader[jmsType=ORA.AMS.PruneSessionsResponse,id=null,corrId=null,ssId=API1,ssType=API,dest=ORA.11.0.1.10000-103.ReplyTo.1.MMA.MMA1,replyTo=null,kind=RESPONSE,reqId=MMA.MMA1.1484074967738.1654,reqTimeout=180000,alwaysDeliverResponses=true,msgVersion=[1, 1, 1],timestamps={created=1484074967813}],state=CREATED,sequenced=false,msg={null}]]: Response to Prune Sessions Response

Poda para o espaço

Você pode igualmente ver quando as gravações são podadas para recuperar o espaço de disco para gravações novas. Quando um MS alcança a condição crítica da separação de /recordedMedia que alcança 90 por cento, umas gravações mais velhas (mesmo se mais novo do que o ponto inicial da idade) estão podadas para fazer a sala para novos. O MS poda os grupos de 200 gravações até que o espaço de disco esteja em ou mais baixa de 86%.

admin:file view activelog /ora/logs/media/groom.log

|2016-10-03 16:09:51.669| Volume /recordedMedia OVERSUBSCRIBED at 87%, need to get to 86%

|2016-10-03 16:09:51.669| Attempting 0 of max attempts[ 20 ]

|2016-10-03 16:09:54.729| OVERSUBSCRIPTION groom /recordedMedia/10054/20160902/57c9d313.smd

|2016-10-03 16:09:54.730| OVERSUBSCRIPTION groom /recordedMedia/10068/20160902/57c9d313.smd

|2016-10-03 16:09:54.734| OVERSUBSCRIPTION groom /recordedMedia/10073/20160902/57c9d314.smd

|2016-10-03 16:09:54.734| OVERSUBSCRIPTION groom /recordedMedia/10092/20160902/57c9d314.smd

Poda antes de arquivístico

Gravar arquivística a um servidor SFTP foi introduzida em MS 10.5. Em alguns casos, você possa ter media podado antes que arquivístico pode ocorrer. Um problema comum é que a Conectividade ao servidor SFTP vai para baixo, e quando a gravação for arquivada um muito tempo adiantado, o MS não pode fazer tão devido às questões de conexão com o servidor SFTP. MediaSense tenta repetidamente arquivar uma gravação se a tentativa de arquivar falha.

Está aqui um exemplo do que você veria em /var/log/active/ora/logs/storagemanagement/ORA-storagemanagementagent.YYY-MM-DDTHH-MM-SS.sss.log:

admin: activelog /ora/logs/media/storagemanagement/ORA-storagemanagementagent.YYY-MM-DDTHH-MM-SS.sss.log da opinião do arquivo

ID de sessão arquivado: ebcf45708f010bc1

IP do servidor SFTP: 10.75.41.225

O MS converte a gravação a MP4 para arquivístico:

0010755845: 10.75.41.210: Sep 08 2016 20:33:09.068 -0500: %CCBU_MMA-6-CONVERT_SESSION_REQUEST: {Thrd=pool-14-thread-107845}

%[message_string=ConvertSessionTask-185682: Sending response ConvertSessionResponse[Response,session=ebcf45708f010bc1,

status=SUCCESS,url=http://10.75.41.210:8081/recordedMedia/oramedia/mp4/ebcf45708f010bc1.mp4,details=Success,seqnum=1528709,

header=MessageHeader[jmsType=ORA.MMA.ConvertSessionResponse,id=null,corrId=null,ssId=MMA1,

ssType=MMA,dest=ORA.10.5.1.10000-23.ReplyTo.1.AMS.API1,replyTo=null,kind=RESPONSE,reqId=API.API1.1473384786428.476820,

reqTimeout=7200000,alwaysDeliverResponses=false,msgVersion=[1, 1, 1],timestamps={created=1473384789060}],

state=CREATED,sequenced=false,msg={null}]]:

O MS processa um pedido transferir a gravação:

0010755846: 10.75.41.210: Sep 08 2016 20:33:09.073 -0500: %CCBU_MMA-6-MSG_INCOMING_FROM_BUS: {Thrd=ActiveMQ Session Task-2315}

%[correlation_id=null][mid=ID:TacMS-60118-1471342398443-3:3:2:1:477533][msg_kind=ActiveMQMapMessage][

msg_type=ORA.MMA.TransferSessionRequest]: A message has been received by the message bus

0010755847: 10.75.41.210: Sep 08 2016 20:33:09.074 -0500: %CCBU_MMA-6-TRANSFER_SESSION_EVENT_INFO: {

Thrd=pool-1-thread-20-MMA1-1409831} %[event.type=Adding to execute TransferSessionTask-291323, sessionName=ebcf45708f010bc1: ]

[message=]: TransferSession

O MS tenta conectar ao servidor SFTP, mas falha com uma exceção do canal seguro das Javas (JSch). JSch é uma aplicação das Javas de SSHv2 que o MS usa para seu cliente SSH:

0010755848: 10.75.41.210: Sep 08 2016 20:33:09.074 -0500: %CCBU_MMA-6-TRANSFER_SESSION_EVENT_INFO: {Thrd=pool-1-thread-8-MMA1-1409832}

%[event.type=SFTP Trace Level (1) - Connecting to 10.75.41.225 port 22][message=]: TransferSession

0010755849: 10.75.41.210: Sep 08 2016 20:33:09.076 -0500: %CCBU_MMA-3-CONVERT_SESSION_ERROR:

{Thrd=pool-1-thread-8-MMA1-1409832} %[exception=][message=TransferSessionTask-291323, sessionName=ebcf45708f010bc1:

Exception][message_string=com.jcraft.jsch.JSchException: java.net.ConnectException: Connection refused]:

0010755850: 10.75.41.210: Sep 08 2016 20:33:09.076 -0500: %CCBU_MMA-3-EXCEPTION_INFO: {Thrd=pool-1-thread-8-MMA1-1409832}

%[build_date=Jan 16, 1970 11:38 PM][build_type=rel][exception=com.jcraft.jsch.JSchException:

java.net.ConnectException: Connection refused

at com.jcraft.jsch.Util.createSocket(Util.java:349)

at com.jcraft.jsch.Session.connect(Session.java:215)

at com.jcraft.jsch.Session.connect(Session.java:183)

at com.cisco.ora.mediamanageragent.msgs.TransferSessionTask.createSftpSession(TransferSessionTask.java:479)

at com.cisco.ora.mediamanageragent.msgs.TransferSessionTask.fileExists(TransferSessionTask.java:417)

at com.cisco.ora.mediamanageragent.msgs.TransferSessionTask.getAction(TransferSessionTask.java:121)

at com.cisco.ora.mediamanageragent.msgs.TransferSessionTask.run(TransferSessionTask.java:203)

at com.cisco.ccbu.infra.threads.InstrumentedRunnable.run(InstrumentedRunnable.java:92)

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

at java.lang.Thread.run(Thread.java:662)

at com.cisco.ccbu.infra.threads.ThreadPoolThread.run(ThreadPoolThread.java:164)

Caused by: java.net.ConnectException: Connection refused

at java.net.PlainSocketImpl.socketConnect(Native Method)

at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)

at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)

at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)

at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)

at java.net.Socket.connect(Socket.java:529)

at java.net.Socket.connect(Socket.java:478)

at java.net.Socket.<init>(Socket.java:375)

at java.net.Socket.<init>(Socket.java:189)

at com.jcraft.jsch.Util.createSocket(Util.java:343)

... 11 more

Falha da negociação codec de CUCM

Este exemplo é com gravação da Construir-em-ponte (babador). No vocabulário CUCM/MS, o dispositivo da extremidade próxima é o dispositivo que transmite o áudio ao MS, isto é um telefone CUCM no caso do telefone configurado com gravação do babador. O dispositivo de extremidade oposta é o media transmissor do dispositivo ao dispositivo gravado. Na maioria de caso, este é um tronco do SORVO CUCM, que seja o dispositivo de que a sinalização do SORVO de um telefone PSTN vem. Equivalentemente, você pode pensar da sinalização da extremidade próxima é transmitido pelo dispositivo gravado e pela sinalização da ponta oposta que estão sendo recebidos do dispositivo gravado.

Neste exemplo, esta é a informação de chamada que você pode ver da busca MS e jogar:

Session ID: 745a15454b0e7f62

ERROR: Record Response Fail 11/11/2016 10:40 GMT-08:00

Calling: 5255553333 xrefCI: 71234316   Codec Listed: G729

Called : 555666       xrefCI: 71233302   Codec Listed: none

Você vê que havia provável uma falha da negociação codec no atendimento da extremidade próxima do telefone CUCM ao tronco do SORVO MS. os xrefCIs considerados são os CUCM CI para o atendimento real e não para o atendimento gravado pelo MS.

These two CIs comprises one SIP Call-ID for the audio call between the two phones.

DN: 5255553333 <-- CI: 71234316 --> CUCM <-- CI: 71233302 --> DN: 555666

Em logs CUCM, estes são os CI encontrados para que o atendimento seja gravado são:

These two CIs comprise one SIP Call-ID for the near-end recorded call.

DN: 555666 <-- CI: 71233611 --> CUCM <-- CI: 71233612 --> MS SIP Trunk 'DN': 4321

These two CIs comprise one SIP Call-ID for the far-end recorded call.

DN: 5255553333 <-- CI: 71233614 --> CUCM <-- CI: 71233615 --> MS SIP Trunk 'DN': 4321

Logs MS

Atendimento da extremidade próxima:

Convide primeiramente o MS recebe: Identidade da chamada: 50459200-8261109d-125c82-2080fe0a@10.1.1.60 do dispositivo da extremidade próxima.

0000724480: 10.55.100.23: Nov 11 2016 12:40:29.637 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=Pool-sip-thread-17475} %[message_string=process new Invitation: SipCall-17502, INBOUND_RECORDING, null, State=ALERTED: , processing=7

INVITE sip:4321@10.55.100.23:5060 SIP/2.0

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee04b9db528

Max-Forwards: 69

To: <sip:4321@10.55.100.23>

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

CSeq: 101 INVITE

Content-Length: 0

Date: Fri, 11 Nov 2016 18:40:29 GMT

Supported: timer,resource-priority,replaces

Supported: X-cisco-srtp-fallback

Supported: Geolocation

Min-SE: 1800

User-Agent: Cisco-CUCM11.0

Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY

Expires: 180

Allow-Events: presence, kpml

Call-Info: <sip:10.1.1.60:5060>;method="NOTIFY;Event=telephone-event;Duration=500"

Session-ID: 00000000000000000000000000000000;remote=00000000000000000000000000000000

Cisco-Guid: 1346736640-0000065536-0000177089-0545324554

Session-Expires: 1800

P-Asserted-Identity: "(Operator) Jared TAC" <sip:555666@10.1.1.60>

Remote-Party-ID: "(Operator) Jared TAC" <sip:555666@10.1.1.60>;party=calling;screen=yes;privacy=off

Contact: <sip:555666@10.1.1.60:5060;transport=tcp>;isfocus

O MS envia 180 que soam.

0000724487: 10.55.100.23: Nov 11 2016 12:40:29.638 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=Pool-sip-thread-17475} %[message_string=postProcessInvitation SipCall-17502, INBOUND_RECORDING, NEAR_END, State=ALERTED: sending response

SIP/2.0 180 Ringing

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee04b9db528

To: <sip:4321@10.55.100.23>;tag=ds23933dcf

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

CSeq: 101 INVITE

Content-Length: 0

Contact: <sip:4321@10.55.100.23:5060;transport=tcp>

Allow: INVITE, BYE, CANCEL, ACK, NOTIFY, INFO, UPDATE

Server: MediaSense/10.x

O MS envia a APROVAÇÃO 200 com SDP.

0000724519: 10.55.100.23: Nov 11 2016 12:40:29.801 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=Pool-capture-thread-15474} %[message_string=SipCall-17502, INBOUND_RECORDING, NEAR_END, State=ALERTED send 200 Ok:

SIP/2.0 200 Ok

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee04b9db528

To: <sip:4321@10.55.100.23>;tag=ds23933dcf

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

CSeq: 101 INVITE

Content-Length: 309

Contact: <sip:4321@10.55.100.23:5060;transport=tcp>

Content-Type: application/sdp

Allow: INVITE, BYE, CANCEL, ACK, NOTIFY, INFO, UPDATE

Server: MediaSense/10.x

v=0

o=CiscoORA 2153 1 IN IP4 10.55.100.23

s=SIP Call

c=IN IP4 10.55.100.23

t=0 0

m=audio 34370 RTP/AVP 102 0 8 9 18

a=rtpmap:102 MP4A-LATM/90000

a=fmtp:102 profile-level-id=24;object=23;bitrate=64000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:9 G722/8000

a=rtpmap:18 G729/8000

a=recvonly

]: Border Message

Você obtém um ACK de CUCM para este atendimento sem SDP, assim que significa que um codec não esteve escolhido por CUCM.

0000724529: 10.55.100.23: Nov 11 2016 12:40:29.868 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=DIALOG_CALLBACK.6} %[message_string=SipCall-17502, INBOUND_RECORDING, NEAR_END, State=ALERTED process ACK, hasBody=false

ACK sip:4321@10.55.100.23:5060;transport=tcp SIP/2.0

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee4766a922

Max-Forwards: 69

To: <sip:4321@10.55.100.23>;tag=ds23933dcf

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

CSeq: 101 ACK

Content-Length: 0

Date: Fri, 11 Nov 2016 18:40:29 GMT

User-Agent: Cisco-CUCM11.0

Allow-Events: presence, kpml

Session-ID: 00000000000000000000000000000000;remote=59bbdbcfa64352fa65ba535ab3695142

]: Border Message

0000724530: 10.55.100.23: Nov 11 2016 12:40:29.868 -0600: %CCBU_CALL_CONTROL-7-TRACE: {Thrd=DIALOG_CALLBACK.11} -SdpParser: created AUDIO-MediaParameters: host=10.15.255.254, port=4000, RtpAttributes=[ payloadType=18 G729/8000 ], SENDONLY, pTime=20

0000724531: 10.55.100.23: Nov 11 2016 12:40:29.868 -0600: %CCBU_CALL_CONTROL-4-WARN_MESSAGE: {Thrd=DIALOG_CALLBACK.6} %[message_string=SipCall-17502, INBOUND_RECORDING, NEAR_END, State=ALERTED invalid codec or does not have SDP body in Ack

CUCM termina o atendimento.

0000724562: 10.55.100.23: Nov 11 2016 12:40:29.871 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=DIALOG_CALLBACK.6} %[message_string=SipCall-17502, INBOUND_RECORDING, NEAR_END, State=DISCONNECTED sendBye, reason=reject sending

BYE sip:555666@10.1.1.60:5060;transport=tcp SIP/2.0

Max-Forwards: 70

To: <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

From: <sip:4321@10.55.100.23>;tag=ds23933dcf

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

CSeq: 1 BYE

Content-Length: 0

]: Border Message

Atendimento da ponta oposta:

Convide em segundo o MS recebe: Identidade da chamada: 50459200-8261109d-125c83-2080fe0a@10.1.1.60 do dispositivo de extremidade oposta.

INVITE sip:4321@10.55.100.23:5060;transport=TCP SIP/2.0

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee255dcfc0

Max-Forwards: 69

To: <sip:4321@10.254.128.36>

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-farend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695143~47718da5-fef5-1f81-1709-6f389f40258a-71233615

Call-ID: 50459200-8261109d-125c83-2080fe0a@10.1.1.60

CSeq: 102 INVITE

Content-Length: 0

Date: Fri, 11 Nov 2016 18:40:29 GMT

Supported: timer,resource-priority,replaces

Supported: X-cisco-srtp-fallback

Supported: Geolocation

Min-SE: 1800

User-Agent: Cisco-CUCM11.0

Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY

Expires: 180

Allow-Events: presence, kpml

Call-Info: <sip:10.1.1.60:5060>;method="NOTIFY;Event=telephone-event;Duration=500"

Session-ID: 00000000000000000000000000000000;remote=00000000000000000000000000000000

Cisco-Guid: 1346736640-0000065536-0000177090-0545324554

Session-Expires: 1800

P-Asserted-Identity: "(Operator) Jared TAC" <sip:555666@10.1.1.60>

Remote-Party-ID: "(Operator) Jared TAC" <sip:555666@10.1.1.60>;party=calling;screen=yes;privacy=off

Contact: <sip:555666@10.1.1.60:5060;transport=tcp>;isfocus

O MS envia 180 que soam para a segunda chamada.

0000724502: 10.55.100.23: Nov 11 2016 12:40:29.683 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=Pool-sip-thread-17476} %[message_string=postProcessInvitation SipCall-17503, INBOUND_RECORDING, NEAR_END, State=ALERTED: sending response

SIP/2.0 180 Ringing

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee255dcfc0

To: <sip:4321@10.254.128.36>;tag=dsb56a3dfc

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-farend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695143~47718da5-fef5-1f81-1709-6f389f40258a-71233615

Call-ID: 50459200-8261109d-125c83-2080fe0a@10.1.1.60

CSeq: 102 INVITE

Content-Length: 0

Contact: <sip:4321@10.55.100.23:5060;transport=tcp>

Allow: INVITE, BYE, CANCEL, ACK, NOTIFY, INFO, UPDATE

Server: MediaSense/10.x

O MS envia a APROVAÇÃO 200 com SDP.

0000724516: 10.55.100.23: Nov 11 2016 12:40:29.800 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=Pool-capture-thread-15474} %[message_string=SipCall-17503, INBOUND_RECORDING, FAR_END, State=ALERTED send 200 Ok:

SIP/2.0 200 Ok

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee255dcfc0

To: <sip:4321@10.254.128.36>;tag=dsb56a3dfc

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-farend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695143~47718da5-fef5-1f81-1709-6f389f40258a-71233615

Call-ID: 50459200-8261109d-125c83-2080fe0a@10.1.1.60

CSeq: 102 INVITE

Content-Length: 309

Contact: <sip:4321@10.55.100.23:5060;transport=tcp>

Content-Type: application/sdp

Allow: INVITE, BYE, CANCEL, ACK, NOTIFY, INFO, UPDATE

Server: MediaSense/10.x

v=0

o=CiscoORA 2152 1 IN IP4 10.55.100.23

s=SIP Call

c=IN IP4 10.55.100.23

t=0 0

m=audio 53368 RTP/AVP 102 0 8 9 18

a=rtpmap:102 MP4A-LATM/90000

a=fmtp:102 profile-level-id=24;object=23;bitrate=64000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:9 G722/8000

a=rtpmap:18 G729/8000

a=recvonly

]: Border Message

CUCM envia o ACK com SDP. Para este trecho de chamada, o G729 é escolhido desde que ambos os server apoiam este do SDP.

0000724521: 10.55.100.23: Nov 11 2016 12:40:29.866 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=DIALOG_CALLBACK.11} %[message_string=SipCall-17503, INBOUND_RECORDING, FAR_END, State=ALERTED process ACK, hasBody=true

ACK sip:4321@10.55.100.23:5060;transport=tcp SIP/2.0

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee3220aa67f

Max-Forwards: 69

To: <sip:4321@10.254.128.36>;tag=dsb56a3dfc

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-farend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695143~47718da5-fef5-1f81-1709-6f389f40258a-71233615

Call-ID: 50459200-8261109d-125c83-2080fe0a@10.1.1.60

CSeq: 102 ACK

Content-Length: 259

Date: Fri, 11 Nov 2016 18:40:29 GMT

User-Agent: Cisco-CUCM11.0

Allow-Events: presence, kpml

Session-ID: 00000000000000000000000000000000;remote=59bbdbcfa64352fa65ba535ab3695143

Content-Type: application/sdp

v=0

o=CiscoSystemsCCM-SIP 3695143 1 IN IP4 10.1.1.60

s=SIP Call

c=IN IP4 10.15.255.254

b=TIAS:8000

b=CT:8

b=AS:8

t=0 0

m=audio 4000 RTP/AVP 18 101

a=ptime:20

a=rtpmap:18 G729/8000

a=sendonly

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

]: Border Message

CUCM termina o atendimento.

0000724546: 10.55.100.23: Nov 11 2016 12:40:29.869 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=DIALOG_CALLBACK.6} %[message_string=SipCall-17503, INBOUND_RECORDING, FAR_END, State=ACTIVE sendBye, reason=local disconnect sending

BYE sip:555666@10.1.1.60:5060;transport=tcp SIP/2.0

Max-Forwards: 70

To: <sip:555666@10.1.1.60;x-farend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695143~47718da5-fef5-1f81-1709-6f389f40258a-71233615

From: <sip:4321@10.254.128.36>;tag=dsb56a3dfc

Call-ID: 50459200-8261109d-125c83-2080fe0a@10.1.1.60

CSeq: 1 BYE

Content-Length: 0

O MS grava o atendimento como uma falha.

0000724557: 10.55.100.23: Nov 11 2016 12:40:29.871 -0600: %CCBU_CALL_CONTROL-7-TRACE: {Thrd=DIALOG_CALLBACK.6} -InMemoryDataBaseAdapter: processing UpdateLocalDB

Session: 745a15454b0e7f62, ERROR, MEDIA_SERVER_ERROR, sipServer=10.55.100.23, version=9, lastNotifiedVersion=9, fromDN=null, toDN=null, audioChannels=2, videoChannels=0, started: Fri Nov 11 12:40:29 CST 2016, ended: Fri Nov 11 12:40:29 CST 2016, duration=0sec, recordingServer=10.55.100.23, ccId=null, ccIp=10.1.1.60, type=PHONE, appType=null, ErrorDetail =MEDIA_SERVER_ERROR

CallEndPoint: type=NEAR_END, dn=555666, displayName=(Operator) Jared TAC, xRefci=71233302, device=SEP002497A964CF, conf=false, {SipCall-17502, INBOUND_RECORDING, NEAR_END, State=DISCONNECTED, CallId: 50459200-8261109d-125c82-2080fe0a@10.1.1.60}, Tracks=[TrackInfo: type=AUDIO, port=34370, trackNumber=0, repository=/recordedMedia, size=-1, state=ACTIVE, stateChanged=false, codec=null]

CallEndPoint: type=FAR_END, dn=5255553333, xRefci=71234316, device=10.15.255.254, conf=false, {SipCall-17503, INBOUND_RECORDING, FAR_END, State=DISCONNECTED, CallId: 50459200-8261109d-125c83-2080fe0a@10.1.1.60}, Tracks=[TrackInfo: type=AUDIO, port=53368, trackNumber=1, repository=/recordedMedia, size=-1, state=ACTIVE, stateChanged=false, codec=G729]

O arquivo JSON é criado e salvar no MS.

0000724560: 10.55.100.23: Nov 11 2016 12:40:29.871 -0600: %CCBU_CALL_CONTROL-6-BORDER_MESSAGE: {Thrd=Pool-ams-thread-9738} %[message_string=HttpPostClient-9738: executing POST http://10.55.100.23:8640/ora/SipAdaptorService/SipAdaptor/addOrUpdateSession HTTP/1.1

{"sessionData": {

"callControllerIP": "10.1.1.60",

"callControllerType": "Cisco-CUCM",

"endDate": 1478889629869,

"endPoints": [

{

"clusterid": "TACOp",

"conference": false,

"device": "SEP002497A964CF",

"displayName": "(Operator) Jared TAC",

"dn": "555666",

"startDate": 1478889629868,

"tracks": [{

"location": "/recordedMedia",

"mediaState": "ACTIVE",

"startDate": 1478889629868,

"track": 0,

"type": "AUDIO"

}],

"type": "NEAR_END",

"xRefci": "71233302"

},

{

"clusterid": "TACOp",

"conference": false,

"device": "10.15.255.254",

"dn": "5255553333",

"startDate": 1478889629868,

"tracks": [{

"codec": "G729",

"location": "/recordedMedia",

"mediaState": "ACTIVE",

"startDate": 1478889629868,

"track": 1,

"type": "AUDIO"

}],

"type": "FAR_END",

"xRefci": "71234316"

}

],

"errorDetail": "MEDIA_SERVER_ERROR",

"operationType": "ADD",

"recordingServer": "10.55.100.23",

"sessionName": "745a15454b0e7f62",

"sipServer": "10.55.100.23",

"startDate": 1478889629868,

"state": "ERROR",

"version": 9

}}]: Border Message

Logs CUCM

Está aqui a análise de dígitos para o babador do telefone CUCM que chama o teste padrão do seletor MS. b0042422044001 é o babador DN.

47540157.011 |10:40:29.606 |AppInfo |Digit analysis: match(pi="1", fqcn="", cn="b0042422044001",plv="5", pss="Directory URI:Internal_pt:Voicemail_PT:UCCX_pt:SAT-TX-8-5-PT:SAT-TX-OffHrs-PT", TodFilteredPss="Directory URI:Internal_pt:Voicemail_PT:UCCX_pt:SAT-TX-8-5-PT", dd="4321",dac="0")

47540157.012 |10:40:29.606 |AppInfo |Digit analysis: analysis results

47540157.013 |10:40:29.606 |AppInfo ||PretransformCallingPartyNumber=b0042422044001

|CallingPartyNumber=b0042422044001

|DialingPartition=Internal_pt

|DialingPattern=4321

Resposta de CUCMs à análise de dígitos. Está aqui o CI para o atendimento: 71233611.

47540163.000 |10:40:29.606 |SdlSig |DmPidRes |wait |Da(4,100,214,1) |DeviceManager(4,100,208,1) |4,100,14,574746.28^10.1.1.60^Port 32978 |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] Cepn=c0132a35-e434-e61d-ddda-af59c7a2ce1d Id=3812252328 ccmType=3 DeviceName=MediaSense_RL Pid=4,100,90,41,

CI do babador a CUCM: 71233611.

47540163.001 |10:40:29.606 |AppInfo |Digit analysis: wait_DmPidRes- Partition=[d15d1a00-02a2-34a7-e0d9-7d653b500c6d] Pattern=[4321] Where=[],cmDeviceType=[AccessDevice], OutsideDialtone =[0], DeviceOverride=[0], PID=RouteListControl(4,100,90,41),CI=[71233611],Sender=Cdcc(4,100,222,745108)

Este CI estabelece-se com CI 71233612. Este é o CI para a conexão de tronco do SORVO CUCM-MS. Estes dois CI formam a identidade da chamada do SORVO.

47540171.000 |10:40:29.606 |SdlSig |CcSetupReq |idle |RouteListControl(4,100,90,41) |Cdcc(4,100,222,745108) |4,100,14,574746.28^10.1.1.60^Port 32978 |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] CI=71233612 CI.branch=0 sBPL.plid=65 sBPL.l=0 sBPL.pl=5 sBPL.msd=0 FDataType=0 opId=0 ssType=0 SsKey=0 invokeId=0 resultExp=F bpda=F pi.piid=30 pi.l=0 pi2.piid=30 pi2.l=0 pi3.piid=30 pi3.l=0 FQCGPN=pi=0si1 preXCgpn=tn=0npi=0ti=1nd=b0042422044001pi=0si1 cgPart= cgPat=b0042422044001 cgpn=tn=0npi=0ti=1nd=8980pi=0si3 cgpnVM= unXCgpn=tn=0npi=0ti=1nd=b0042422044001pi=0si1 cName=locale: 1 Name: (Operator) Jared TAC UnicodeName: (Operator) Jared TAC pi: 0 DD=ti=1nd=4321pi=0si1 origDD=ti=1nd=4321pi=0si1 preXCdpn=tn=0npi=0ti=1nd=4321pi=0si0 preXTagsList=SUBSCRIBER preXPosMatchList=4321 cdPart=d15d1a00-02a2-34a7-e0d9-7d653b500c6d cdPat=4321 cdpn=tn=0npi=0ti=1nd=4321pi=0si1 cdpnVMbox= localPatternUsage=5 connectedPatternUsage=0 itrPart= itrPat= LRPart= LRPat= LR=tn=0npi=0ti=1pi=0si1 LRVM= LRName=locale: 1 Name: Call Manager UnicodeName: pi: 0 FQOCpdn=ti=1nd=4321pi=0si1 fFQLRNum=pi=0si1 oPart=d15d1a00-02a2-34a7-e0d9-7d653b500c6d oPat=4321 oCpdn=tn=0npi=0ti=1nd=4321pi=0si1 oCdpnVM= oRFR=354 oName=locale: 1 Name: UnicodeName: pi: 0 ts=SUBSCRIBER posMatches=4321 withTags= withValues= rdn.l=0IpAddrMode=0 ipAddrType=0 ipv4=10.15.3.60:0 region=LasVegas_Region capCount=1 ctiActive=F ctiFarEndDev=1 ctiCCMId=4 cgPtyDev=SEP002497A964CF callInst=0 confCallInst=0 OLF=1Supp DTMF=3DTMF Cfg=1DTMF Payload=0isOffNetDev=F bc.l=0 bc.itr=0 bc.itc=0 bc.trm=0 bc.tm=0 maxForwards=70 cgpnMaskedByRedirect=T callingDP= featCallType=0 callingUserId= UnicodeName: muteEnabled=0 associatedCallCI=0 featurePriority=1 nonTargetPolicy=0 unconsumedDigits= suppressMOH=T numPlanPkid =47120c78-3381-7a76-dc37-fc87210358cb networkDomain= bitMask=0 SetupReason=0 routeClass=1 sideACmDeviceType=1 protected=1 ControlProcessType=0 tokens=0 isPresent=F transitCount=0 geolocInfo=null locPkid= locName= deductBW=F fateShareId= videoTrafficClass=Unspecified oFromAnalogDvc=F bridgeParticipantID= callingUsr= remoteClusterID= isEMCCDevice=F lHPMemCEPN= cHPMemCEPN= isParamSet=FTransparentData=null CanSupportSIPTandN=false TransId=0 AllowBitMask=0x0 UserAgentOrServer= OrigDDName=locale: 1 Name: UnicodeName: pi: 0 mCallerId= mCallerName=LatentCaps=null icidVal= icidGenAddr= oioi= tioi= ptParams= receivedPAID= routeHdr= routeCepn= requestURI= PCVFlag=F originallyHadISUP=F isIMSFinalRoute=F IMSMode=0 SideABibEnabled= 0 isCgpnNonPreemptable=F isCdpnNonPreemptable=F origDP= lastRedirectingDP= originalLRG= lastRedirectingLRG= nwLoc=0 rstr= FarEndDeviceName= ReferredByUri= Session-ID: ;remote= hdrMOH=0 CAL={v=ffffffff, m=ffffffff, tDev=F, res=F, devType=0}

Está aqui o convite ao MS para este atendimento com identidade da chamada 50459200-8261109d-125c82-2080fe0a.

47540202.001 |10:40:29.610 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 10.55.100.23 on port 5060 index 95625

[12124747,NET]

INVITE sip:4321@10.55.100.23:5060 SIP/2.0

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee04b9db528

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

To: <sip:4321@10.55.100.23>

Date: Fri, 11 Nov 2016 18:40:29 GMT

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

Supported: timer,resource-priority,replaces

Min-SE: 1800

User-Agent: Cisco-CUCM11.0

Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY

CSeq: 101 INVITE

Expires: 180

Allow-Events: presence, kpml

Supported: X-cisco-srtp-fallback

Supported: Geolocation

Call-Info: <sip:10.1.1.60:5060>;method="NOTIFY;Event=telephone-event;Duration=500"

Session-ID: 00000000000000000000000000000000;remote=00000000000000000000000000000000

Cisco-Guid: 1346736640-0000065536-0000177089-0545324554

Session-Expires: 1800

P-Asserted-Identity: "(Operator) Jared TAC" <sip:555666@10.1.1.60>

Remote-Party-ID: "(Operator) Jared TAC" <sip:555666@10.1.1.60>;party=calling;screen=yes;privacy=off

Contact: <sip:555666@10.1.1.60:5060;transport=tcp>;isFocus

Max-Forwards: 70

Content-Length: 0

Este é o atendimento que não negociou um codec.

Deixe-nos saltar à APROVAÇÃO MS 200 com SDP e figurar para fora porque um codec não poderia ser ajustado.

47540802.002 |10:40:29.819 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 10.55.100.23 on port 5060 index 95625 with 1024 bytes:

[12124760,NET]

SIP/2.0 200 Ok

Via: SIP/2.0/TCP 10.1.1.60:5060;branch=z9hG4bK201ee04b9db528

To: <sip:4321@10.55.100.23>;tag=ds23933dcf

From: "(Operator) Jared TAC" <sip:555666@10.1.1.60;x-nearend;x-refci=71233302;x-nearendclusterid=TACOp;x-nearenddevice=SEP002497A964CF;x-nearendaddr=555666;x-farendrefci=71234316;x-farendclusterid=TACOp;x-farenddevice=10.15.255.254;x-farendaddr=5255553333>;tag=3695142~47718da5-fef5-1f81-1709-6f389f40258a-71233612

Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60

CSeq: 101 INVITE

Content-Length: 309

Contact: <sip:4321@10.55.100.23:5060;transport=tcp>

Content-Type: application/sdp

Allow: INVITE, BYE, CANCEL, ACK, NOTIFY, INFO, UPDATE

Server: MediaSense/10.x

v=0

o=CiscoORA 2153 1 IN IP4 10.55.100.23

s=SIP Call

c=IN IP4 10.55.100.23

t=0 0

m=audio 34370 RTP/AVP 102 0 8 9 18

a=rtpmap:102 MP4A-LATM/90000

a=fmtp:102 profile-level-id=24;object=23;bitrate=64000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:9 G722/8000

a=rtpmap:18 G729/8000

a=recvonly

Requisição de conexão dos media para os dois CI. MediaManager ID: 847431. Siga este ID para ver porque você não poderia estabelecer media.

47540844.001 |10:40:29.825 |AppInfo |ARBTRY-ConnectionManager-wait_MediaConnectRequest(71233611,71233612)

47540850.001 |10:40:29.826 |AppInfo |SIG-MediaManager-(847431)::wait_MediaConnectRequest, CI(71233611,71233612), capCount(1,8), mcNodeId(0,0), xferMode(8,16), reConnectType(0), mrid (0, 0) IFCreated(0 0) proIns(0 0), AC(0,0), party1DTMF(1 3 0 0 0) party2DTMF(1 0 0 1 1),reConnFlag=0, connType(2,3), IFHand(0,0),MTP(0,0),MRGL(3cf3871c-f9ac-1a4b-9261-105cb3c6cb79,17b41810-a72d-d2e0-be30-8dffe05ce048) videoCap(0 0), mmCallType(0),FS(0,0), IpAddrMode(0 0) aPid(4, 242, 2044), bPid(4, 83, 215774) EOType(0 0) () honorCodec(0 0)

47540874.000 |10:40:29.829 |SdlSig |CACInfoRes |waitCACInfoRes |MediaManager(4,100,142,847431) |ReservationMgr(4,100,111,1) |4,100,14,460202.37477^10.55.100.23^* |[R:N-H:0,N:3,L:0,V:0,Z:0,D:0] CI= 0 aCI=71233611 bCI=71233612 pol=0 rsvpStatus=1 aVideoTrafficClass=0 bVideoTrafficClass=0 sessJoined=F staIdx_no_agent=0 locationstatus=( AudioBWReserved) eoSent=F aAgent: confID =0 ci =0 capCt =0 reg= mtpType =2 agentCt =0 mmCapSet=0 agentAllo =0 RemoAgent=F DevCap=0 ipAddrMode=0 bAgent: confID =0 ci =0 capCt =0 reg= mtpType =2 agentCt =0 mmCapSet=0 agentAllo =0 RemoAgent=F DevCap=0 ipAddrMode=0 aPort: NumPort =0 bPort: NumPort =0 otherAgentPort: NumPort =0

47540874.001 |10:40:29.829 |AppInfo |DET-MediaManager-(847431) - waitCACInfoRes_CACInfoRes- qosType=0 videoEsc=0 mNoVideoResvAttempted=1 VideoCall=0

O relacionamento da região dita que há uma taxa de bits audio máxima de 8kbps entre estas regiões.

47540874.002 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::waitCACInfoRes_CACInfoRes, rsvp(0,0), E2E RegionBwKbps[ A=8 V = 384 I = 2000000000 ] ,deviceAcaps(0) deviceBCaps(0),noVideoResv(1), mmAllowedCallType(0x00000000)

47540874.003 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::mapCapabilitiesToMMCallType - Call is set to Audio Only - vidCall = 0)

47540874.004 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::buildMtpXcoderAllocList, savedConnectionCount=0, QosType=0

47540874.005 |10:40:29.829 |AppInfo |DET-RegionsServer::matchCapabilities-- savedOption=3, PREF_NONE, regionA=(null) regionB=(null) latentCaps(A=0, B=0) kbps=8, capACount=1, capBCount=8

47540874.006 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::checkAudioPassThru, param(bPostMTPAllocation=0,chkTrp=1), capCount(1,8), mtpPT=1, aPT=2

Pty1 está vindo do LasVegas_Region e está sendo ajustado para (ulaw 4,20)=G711. (Este é o telefone do agente).

Pty2 está vindo do SignalHill_Region e tem 8 capacidades. (Este é o tronco do SORVO MS).

47540874.007 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::preCheckCapabilities, region1=LasVegas_Region, region2=SignalHill_Region, Pty1 capCount=1 (Cap,ptime)= (4,20), Pty2 capCount=8 (Cap,ptime)= (44,0) (4,20) (2,20) (6,20) (11,20) (12,20) (15,20) (16,20)

47540874.008 |10:40:29.829 |AppInfo |DET-RegionsServer::matchCapabilities-- savedOption=0, PREF_NONE, regionA=(null) regionB=(null) latentCaps(A=0, B=0) kbps=8, capACount=1, capBCount=8

47540874.009 |10:40:29.829 |AppInfo |RegionsServer: applyCodecFilterIfNeeded - no codecs remained after filtering so restored original 0 caps

Há uma má combinação das capacidades desde que o ulaw G711 usa uma taxa de bits 64kbps, assim que CUCM tenta invocar um transcodificador. Corrigir os relacionamentos da região elimina a edição.

47540874.010 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::preCheckCapabilities, caps mismatch! Xcoder Reqd. kbps(8), filtered A[capCount=0 (Cap,ptime)=], B[capCount=4 (Cap,ptime)= (11,20) (12,20) (15,20) (16,20)] allowMTP=0 numXcoderRequired=1 xcodingSide=1

47540874.011 |10:40:29.829 |AppInfo |DET-MediaManager-(847431)::prepareInitialConnectionList, Party1CapCount=1 Party2CapCount=8 XcoderRequired=1 xcodingSide=1 allowMTP=0

Para resolver isto, você deve corrigir o relacionamento da região em CUCM para reservar uma taxa de bits máxima maior entre regiões - pelo menos 64 kbps. Recomenda-se lhe cria uma região nova para a Senhora configurar-la para ser o exato mesmos que a região velha salvo que você deve aumentar a taxa de bits máxima pelo menos a 64 kbps, e assegura-se de que todas as regiões que se usarem o padrão de sistema para a taxa de bits máxima deva ser aumentado pelo menos a 64 kbps. Copie o grupo de pool de dispositivos no tronco do SORVO MS, atribua a região nova a este pool de dispositivos, atribua o pool de dispositivos ao tronco do SORVO MS, restaure o tronco do SORVO MS.

Codecs comuns

Em CUCM, os codecs são alistados no formulário (tampão, ptime), onde tampão = capacidade = tempo do códice e do ptime = do empacotamento. Está aqui uma lista de codecs que importantes você pode ver no campo do “tampão”:

G711 Alaw with 64 kbps bit rate = 2

G711 Ulaw with 64 kbps bit rate = 4

G722 with 64 kbps bit rate      = 6

G722 with 56 kbps bit rate      = 7

G722 with 48k kbps bit rate     = 8

G728                            = 10

G729                            = 11

G729 Annex A                    = 12

G729 Annex B                    = 15