Suggerimenti per la risoluzione dei problemi relativi ai supporti registrati mancanti in MediaSense
Sommario
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):
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
Feedback