Sommario

Introduzione

Prerequisiti

Requisiti

Componenti usati

Premesse

Problema

Problemi più comuni

Supporti eliminati

Potatura per età

Esempio di analisi del log per la traccia della registrazione Eliminazione per età

Eliminazione dello spazio

Eliminazione prima dell'archiviazione

Errore di negoziazione codec da CUCM

Registri MS

Registri CUCM

Codec comuni

Introduzione

Questo documento descrive i problemi comuni rilevati in MediaSense (MS) che causano la perdita o l'impossibilità di riprodurre le registrazioni sul server.

Prerequisiti

Requisiti

Cisco raccomanda la conoscenza dei seguenti argomenti:

- Cisco MS

- Cisco Unified Contact Center Express (UCCX)

- Cisco Unified Communications Manager (CUCM)

Componenti usati

Le informazioni fornite in questo documento si basano sulle seguenti versioni software e hardware:

- MS 10.5 e successivi

- Call Manager 11.0

Le informazioni discusse in questo documento fanno riferimento a dispositivi usati in uno specifico ambiente di produzione. Su tutti i dispositivi menzionati nel documento la configurazione è stata ripristinata ai valori predefiniti. Se la rete è operativa, valutare attentamente eventuali conseguenze derivanti dall'uso dei comandi.

Premesse

Uno dei problemi più comuni riscontrati in MS è l'impossibilità di accedere alle registrazioni perché il supporto viene rimosso da MS. Questo documento spiega come risolvere meglio questi tipi di scenari per comprendere perché i supporti registrati non sono su MS.

Problema

Non è possibile riprodurre le registrazioni da MS Search and Play. Le dimensioni del brano corrispondono a 00:00:00 e a sinistra della registrazione è presente un punto esclamativo giallo che indica l'assenza di supporti, come mostrato nell'immagine.

Problemi più comuni

Supporti eliminati

La configurazione di eliminazione in MS consente di eliminare le registrazioni se hanno superato una determinata età o se è necessario più spazio su disco per le registrazioni più recenti.

Le impostazioni di eliminazione si trovano in: Cisco MediaSense Administration > Administration > Prune Policy Configuration. Se l'impostazione Non rimuovere automaticamente i dati associati e i file multimediali convertiti è selezionata, quando le registrazioni vengono eliminate dal server, i relativi metadati rimangono e viene visualizzato un punto esclamativo giallo con un errore "Record Canceled" o "Zero Size Tracks" come mostrato nell'immagine.

Il modo più rapido per verificarlo è tramite groom.log generato dal servizio Media.

Potatura per età

È possibile raccogliere il file groom.log e/o orapurges.log dalla raccolta dei log del servizio multimediale da Real Time Monitoring Tool (RTMT) oppure utilizzare rapidamente l'interfaccia della riga di comando (CLI):

Nota: il log di groom mostra il file SMD non elaborato, associato all'ID sessione dal database MySQL del servizio multimediale. L'acquisizione di un ID di sessione da un file SMD è un'operazione complessa, in quanto richiede l'accesso root al server. Questi registri sono utili solo per comprendere l'età delle registrazioni potate.

Ad esempio, questi log mostrano che le registrazioni del 4 gennaio 2017 vengono eliminate:

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

orapurges.logmostrare un po' più di dettaglio quando vengono presentati l'ID sessione e i numeri di traccia:

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

Esempio di analisi del log per la traccia della registrazione Eliminazione per età

In questo esempio, le registrazioni sono state eliminate molto più rapidamente delle 90 impostazioni di prugna.

Nei registri ORA-ora è possibile vedere che la registrazione con ID sessione 56e5159848cca971 è stata eseguita correttamente in MS ed è stata chiusa con uno stato CLOSED_NORMAL.

La registrazione è iniziata alle ore 1483987536761, che è 'Lun Gen 9 13:45:36 2017 GMT-5:00'.

Anche l'URL del supporto qui, che mostra una registrazione salvata.

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"}

Questa registrazione viene eliminata nel file orapurges.log. Track1 e Track0 sono destinati alle parti separate nella registrazione:

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.

I log ORA-ora mostrano le sessioni eliminate, che includono la sessione mostrata in precedenza:

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

Qui vengono mostrate le 6 sessioni eliminate:

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

Eliminazione dello spazio

È inoltre possibile vedere quando le registrazioni vengono eliminate per liberare spazio su disco per le nuove registrazioni. Quando un MS raggiunge la condizione critica della partizione /registeredMedia raggiungendo il 90%, le registrazioni più vecchie (anche se più giovani della soglia di età) vengono potate per fare spazio a quelle nuove. MS elimina i batch di 200 registrazioni fino a quando lo spazio su disco non è pari o inferiore all'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

Eliminazione prima dell'archiviazione

L'archiviazione della registrazione su un server SFTP è stata introdotta in MS 10.5. In alcuni casi, è possibile eliminare i supporti prima di procedere all'archiviazione. Un problema comune è che la connettività al server SFTP si interrompe, e mentre la registrazione è stata archiviata con molto tempo di anticipo, MS non può farlo a causa di problemi di connessione con il server SFTP. MediaSense tenta ripetutamente di archiviare una registrazione se il tentativo di archiviazione non riesce.

Di seguito è riportato un esempio di quanto è possibile visualizzare nel file /var/log/active/ora/logs/storagemanagement/ORA-storagemanagementagent.YYY-MM-DDTHH-MM-SS.sss.log:

admin: visualizzazione file activelog /ora/logs/media/storagemanagement/ORA-storagemanagementagent.YYY-MM-GGTHH-MM-SS.sss.log

ID sessione archiviata: ebcf45708f010bc1

IP server SFTP: 10.75.41.225

MS converte la registrazione in MP4 per l'archiviazione:

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}]]:

MS elabora una richiesta di trasferimento della registrazione:

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

MS tenta di connettersi al server SFTP, ma non riesce con un'eccezione JSch (Java Secure Channel). JSch è un'implementazione Java di SSHv2 che MS utilizza per il proprio client 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

Errore di negoziazione codec da CUCM

Questo esempio si riferisce alla registrazione con BiB (Built-in-Bridge). Nel vocabolario CUCM/MS, il dispositivo near-end è il dispositivo che trasmette l'audio a MS, questo è un telefono CUCM nel caso del telefono configurato con registrazione BiB. Il dispositivo più lontano è il dispositivo che trasmette i supporti al dispositivo registrato. Nella maggior parte dei casi, si tratta di un trunk SIP CUCM, ovvero il dispositivo da cui proviene la segnalazione SIP di un telefono PSTN. Analogamente, è possibile pensare che il segnale near-end venga trasmesso dal dispositivo registrato e che il segnale far-end venga ricevuto dal dispositivo registrato.

In questo esempio, queste sono le informazioni sulle chiamate che è possibile visualizzare da MS Search and Play:

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

È probabile che si sia verificato un errore di negoziazione del codec nella chiamata near-end dal telefono CUCM al trunk SIP MS. Gli xrefCI visualizzati sono gli CI CUCM per la chiamata effettiva e non per la chiamata registrata da 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

Nei log CUCM, questi sono gli CI trovati per la chiamata da registrare sono:

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

Registri MS

Chiamata near-end:

First Invite MS riceve: Call-ID: 50459200-8261109d-125c82-2080fe0a@10.1.1.60 dal dispositivo near-end.

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

MS invia un segnale acustico a 180 squilli.

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

MS invia 200 OK con 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

Si riceve un ACK da CUCM per questa chiamata senza SDP, il che significa che non è stato scelto un codec da 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

La chiamata è terminata.

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

Chiamata remota:

Second Invite MS riceve: Call-ID: 50459200-8261109d-125c83-2080fe0a@10.1.1.60 dal dispositivo più lontano.

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

MS invia 180 squilli per la seconda chiamata.

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

MS invia 200 OK con 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 invia ACK con SDP. Per questo segmento di chiamata, viene scelto G729 poiché entrambi i server supportano questa opzione dall'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

La chiamata è terminata.

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

MS Registra la chiamata come errore.

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]

Il file JSON viene creato e salvato in 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

Registri CUCM

Ecco l'analisi delle cifre per il BiB del telefono CUCM che chiama il modello di composizione MS. b0042422044001 è il DN BiB.

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

risposta CUCM all'analisi delle cifre. Ecco il CI della chiamata: 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 da BiB 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)

Questo CI è impostato con CI 71233612. CI per la connessione trunk SIP CUCM-MS. Questi due CI formano l'ID chiamata SIP.

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}

Invito rivolto a MS per questa chiamata con Call-ID 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

Chiamata non riuscita a negoziare un codec.

Passiamo a MS 200 OK con SDP e scopriamo perché non è stato possibile impostare un codec.

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

Richiesta di connessione supporti per i due CI. ID MediaManager: 847431. Seguire questo ID per scoprire perché non è stato possibile configurare il supporto.

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

La relazione di regione richiede che tra queste regioni vi sia una velocità di trasmissione audio massima di 8 kbps.

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 proviene dalla regione di Las Vegas ed è impostato per (4,20)=G711 ulaw. (Telefono agente).

Pty2 proviene da SignalHill_Region e dispone di 8 funzionalità. (Si tratta del trunk SIP 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

Poiché G711 ulaw utilizza una velocità di trasmissione di 64 kbps, CUCM tenta di richiamare un transcodificatore. La correzione delle relazioni di area elimina il problema.

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

Per risolvere questo problema, è necessario correggere la relazione di regione su CUCM per consentire una velocità in bit massima maggiore tra le regioni (almeno 64 kbps). Si consiglia di creare una nuova regione per MS. Configuratela in modo che sia esattamente la stessa regione della vecchia, con la differenza che dovete aumentare la velocità bit massima ad almeno 64 kbps e assicuratevi che le regioni che utilizzano l'impostazione di sistema predefinita per la velocità bit massima siano aumentate ad almeno 64 kbps. Copiare il set di pool di dispositivi nel trunk MS SIP, assegnare la nuova area al pool di dispositivi, assegnare il pool di dispositivi al trunk MS SIP, reimpostare il trunk MS SIP.

Codec comuni

In CUCM, i codec sono elencati nel formato (Cap,ptime), dove Cap = funzionalità = codex e ptime = tempo di pacchettizzazione. Di seguito è riportato un elenco di codec importanti che è possibile visualizzare nel campo 'Cap':

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