Problem Calling UM voice mail at 8400 uc

Felipe.Herrera · Post by **Felipe.Herrera** » 22 Jan 2012 00:11

Hello please can support me with the following question on sip 486 busy message seen in the call flow from a central Oxe to the number of voice mail directory on the server type UM 8400. Excuseme my english
The configuration to be performed step by step verified that Voice mail service directory numbe are registered in the Oxe.
On the server shows that UC is registered in Oxe and sip media server, msa, rsm is OK but the service rs is NOK.
In Oxe shows that the number of directory voice mail UM is properly registered.

The server logs and traces are UC
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:37 udp_recv fd:10
13:12:37 udp_recv fd:10 iBytesRead:442 message:SIP/2.0 200 OK
Contact: <sip:8097@192.168.30.170:5070;transport=UDP>;expires=14400
To: sip:8097@192.168.30.31;tag=efa68634eae8f11921baf8e5f679417b
From: sip:8097@192.168.30.31;tag=f051bc956f83e397d20d4ed8ed074828
Call-ID: db79ed0d34d0bae6aa87d1d89b616fe1@ucv.vivienda.gob.pe
CSeq: 2082276973 REGISTER
Via: SIP/2.0/UDP ucv.vivienda.gob.pe:5070;received=192.168.30.170;branch=z9hG4bKfbf3769cbec8b2f41a56ed98c5196877
Content-Length: 0

13:12:37 UdpInputProc iSock:10 iBytesRead:442 Host:192.168.30.31 Port:5060
13:12:37 [CTransportUdp::receiveMessage] from 192.168.30.31:5060 rc:442
13:12:37 [CTransport::findConnection] pConnection = f001 remoteHost=192.168.30.31, remotePort=5060
13:12:37 f001 [CConnection::dOSTest](192.168.30.31,5060,0) MaxNbMsgByPeriod:40 Period:3
13:12:37 f001 [CConnection::dOSTest](192.168.30.31,5060,0) NbMsg:4 < seuil
13:12:37 f001 [CConnection::resetConnectionTimer] Creating the activity timer
13:12:37 RECEIVE MESSAGE FROM NETWORK (192.168.30.31:5060 [UDP])
----------------------utf8-----------------------
SIP/2.0 200 OK
Contact: <sip:8097@192.168.30.170:5070;transport=UDP>;expires=14400
To: sip:8097@192.168.30.31;tag=efa68634eae8f11921baf8e5f679417b
From: sip:8097@192.168.30.31;tag=f051bc956f83e397d20d4ed8ed074828
Call-ID: db79ed0d34d0bae6aa87d1d89b616fe1@ucv.vivienda.gob.pe
CSeq: 2082276973 REGISTER
Via: SIP/2.0/UDP ucv.vivienda.gob.pe:5070;received=192.168.30.170;branch=z9hG4bKfbf3769cbec8b2f41a56ed98c5196877
Content-Length: 0

-------------------------------------------------

13:12:37 RECEIVE (192.168.30.31:5060 [UDP]) SIP/2.0 200 OK
13:12:37 5 [CResponse::CResponse] Creation of a response (RECEIVED FROM NETWORK)
13:12:37 [CDispatcher::onIncomingResponse]
13:12:37 [CDispatcher::processResponseFromManagerIndex] start at index 0
13:12:37 101 [CCallManager::onIncomingResponse]
13:12:37 1105 [CCall::receiveResponse] 200
13:12:37 1105 [CCall::receiveResponse]Trying to find the right dialog
13:12:37 1105 [CCall::receiveResponse]One dialog found
13:12:37 1505 [CDialog::receiveResponse]
13:12:37 2105 [CTransTryingState::receiveResponse] Final : Transaction changes to Completed state
13:12:37 1505 [CDialog::onTransactionState(pTrans = 2105, previousState = Trying, currentState = Completed, reason = Final resp reception]
13:12:37 ========> [CSipTcCall::onReceiveResponse] response = 200
13:12:37 ========> [CSipTcCall::onReceiveResponse] receive OK response
13:12:37 ========> [CSipTcCall::onReceiveResponse] receive OK on IN_PROGRESS_REGISTER State
13:12:37 CPI_GMsg::SetVerb ok
13:12:37 append attr : Reason-Code: 200
13:12:37 8776 [CSipAddrSpec::getAddrSpecAsString]
13:12:37 append attr : Destination: sip:8097@192.168.30.31
13:12:37 877a [CSipAddrSpec::getAddrSpecAsString]
13:12:37 append attr : Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:12:37 append attr : TimeToLive: 14400
13:12:37 us_rcve: protocol:0, leg_id:4
13:12:37 <- PORTCONF-CLOSING 8
13:12:37 <- Reason-Code: 200
13:12:37 <- Destination: sip:8097@192.168.30.31
13:12:37 <- Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:12:37 <- TimeToLive: 14400
13:12:37 ~CPI_GMsg refcount=2
13:12:37 us-handle sip 4 PORTCONF-CLOSING
13:12:37 PORTCONF trt PORTCONF-CLOSING 8 Reason-Code: 200 Destination: sip:8097@192.168.30.31 Transport-Address: {sip:8097@192.168.30.170:5070;transport=UDP} TimeToLive: 14400
13:12:37 PORTCONF trt 0
13:12:37 unix-send: on channel sock13 (toward MS 192.168.30.170)
13:12:37 -> PORTCONF 11
13:12:37 -> Reason-Code: 200
13:12:37 -> Destination: sip:8097@192.168.30.31
13:12:37 -> Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:12:37 -> TimeToLive: 14400
13:12:37 -> Leg-Id: 1007
13:12:37 CPUUsed size=0
13:12:37 RedMsg size=0
13:12:37 req size=0
13:12:37 proto size=5
13:12:37 proto (1001006)=us
13:12:37 proto (1001007)=us
13:12:37 proto (1001003)=us
13:12:37 proto (1001004)=us
13:12:37 proto (1001005)=us
13:12:37 reverse size=0
13:12:37 state size=0
13:12:37 rep_notif size=0
13:12:37 registrar size=5
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:37 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:12:37 <- PORTCONF-CLOSING 0
13:12:37 <- Leg-Id: 1003
13:12:37 us-handle us 1001003 PORTCONF-CLOSING
13:12:37 CPUUsed size=0
13:12:37 RedMsg size=0
13:12:37 req size=0
13:12:37 proto size=4
13:12:37 proto (1001006)=us
13:12:37 proto (1001007)=us
13:12:37 proto (1001004)=us
13:12:37 proto (1001005)=us
13:12:37 reverse size=0
13:12:37 state size=0
13:12:37 rep_notif size=0
13:12:37 registrar size=5
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:37 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:12:37 <- PORTCONF-CLOSING 0
13:12:37 <- Leg-Id: 1004
13:12:37 us-handle us 1001004 PORTCONF-CLOSING
13:12:37 CPUUsed size=0
13:12:37 RedMsg size=0
13:12:37 req size=0
13:12:37 proto size=3
13:12:37 proto (1001006)=us
13:12:37 proto (1001007)=us
13:12:37 proto (1001005)=us
13:12:37 reverse size=0
13:12:37 state size=0
13:12:37 rep_notif size=0
13:12:37 registrar size=5
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:37 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:12:37 <- PORTCONF-CLOSING 0
13:12:37 <- Leg-Id: 1005
13:12:37 us-handle us 1001005 PORTCONF-CLOSING
13:12:37 CPUUsed size=0
13:12:37 RedMsg size=0
13:12:37 req size=0
13:12:37 proto size=2
13:12:37 proto (1001006)=us
13:12:37 proto (1001007)=us
13:12:37 reverse size=0
13:12:37 state size=0
13:12:37 rep_notif size=0
13:12:37 registrar size=5
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:37 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:12:37 <- PORTCONF-CLOSING 0
13:12:37 <- Leg-Id: 1006
13:12:37 us-handle us 1001006 PORTCONF-CLOSING
13:12:37 CPUUsed size=0
13:12:37 RedMsg size=0
13:12:37 req size=0
13:12:37 proto size=1
13:12:37 proto (1001007)=us
13:12:37 reverse size=0
13:12:37 state size=0
13:12:37 rep_notif size=0
13:12:37 registrar size=5
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:37 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:12:37 <- PORTCONF-CLOSING 0
13:12:37 <- Leg-Id: 1007
13:12:37 us-handle us 1001007 PORTCONF-CLOSING
13:12:37 CPUUsed size=0
13:12:37 RedMsg size=0
13:12:37 req size=0
13:12:37 proto size=0
13:12:37 reverse size=0
13:12:37 state size=0
13:12:37 rep_notif size=0
13:12:37 registrar size=5
13:12:37 registrar (sip:8091)=us:127.0.0.1 14400
13:12:37 registrar (sip:8092)=us:127.0.0.1 14400
13:12:37 registrar (sip:8097)=us:127.0.0.1 14400
13:12:37 registrar (sip:8093)=us:127.0.0.1 14400
13:12:37 registrar (sip:8090)=us:127.0.0.1 14400
13:12:42 2101 [CTransCompletedState::timerFires] Timer K : Transaction changes to Terminated state
13:12:42 2102 [CTransCompletedState::timerFires] Timer K : Transaction changes to Terminated state
13:12:42 2103 [CTransCompletedState::timerFires] Timer K : Transaction changes to Terminated state
13:12:42 2104 [CTransCompletedState::timerFires] Timer K : Transaction changes to Terminated state
13:12:42 2105 [CTransCompletedState::timerFires] Timer K : Transaction changes to Terminated state
13:12:42 1501 [CDialog::onTransactionState(pTrans = 2101, previousState = null, currentState = Terminated, reason = Timer K fires]
13:12:42 1101 [CCall::onDialogClosed]
13:12:42 1101 [CCall::onDialogClosed] only initial *********
13:12:42 1101 [CCall] closed
13:12:42 101 [CCallManager::onCallClosed]
13:12:42 101 [CCallManager::onCallClosed()] Call 1101 closed. Removing call 154789440 from the maps
13:12:42 2101 [~CTransaction] transaction 172175035 REGISTER
13:12:42 1 [~CResponse] resp(200) d0910fa75e2f8d9ce086bd74c96978c2@ucv.vivienda.gob.pe 172175035 REGISTER
13:12:42 1502 [CDialog::onTransactionState(pTrans = 2102, previousState = null, currentState = Terminated, reason = Timer K fires]
13:12:42 1102 [CCall::onDialogClosed]
13:12:42 1102 [CCall::onDialogClosed] only initial *********
13:12:42 1102 [CCall] closed
13:12:42 101 [CCallManager::onCallClosed]
13:12:42 101 [CCallManager::onCallClosed()] Call 1102 closed. Removing call 155536744 from the maps
13:12:42 2102 [~CTransaction] transaction 1895868346 REGISTER
13:12:42 2 [~CResponse] resp(200) 4aad8fd8aa3f30e700aef5139086b336@ucv.vivienda.gob.pe 1895868346 REGISTER
13:12:42 1503 [CDialog::onTransactionState(pTrans = 2103, previousState = null, currentState = Terminated, reason = Timer K fires]
13:12:42 1103 [CCall::onDialogClosed]
13:12:42 1103 [CCall::onDialogClosed] only initial *********
13:12:42 1103 [CCall] closed
13:12:42 101 [CCallManager::onCallClosed]
13:12:42 101 [CCallManager::onCallClosed()] Call 1103 closed. Removing call 154943984 from the maps
13:12:42 2103 [~CTransaction] transaction 71072531 REGISTER
13:12:42 3 [~CResponse] resp(200) 6a7d1a332ddb5037ddf69a56664d2a6c@ucv.vivienda.gob.pe 71072531 REGISTER
13:12:42 1504 [CDialog::onTransactionState(pTrans = 2104, previousState = null, currentState = Terminated, reason = Timer K fires]
13:12:42 1104 [CCall::onDialogClosed]
13:12:42 1104 [CCall::onDialogClosed] only initial *********
13:12:42 1104 [CCall] closed
13:12:42 101 [CCallManager::onCallClosed]
13:12:42 101 [CCallManager::onCallClosed()] Call 1104 closed. Removing call 156519432 from the maps
13:12:42 2104 [~CTransaction] transaction 2092214177 REGISTER
13:12:42 4 [~CResponse] resp(200) c7adef23c2b97a2ffd8430c7fee1e517@ucv.vivienda.gob.pe 2092214177 REGISTER
13:12:42 1505 [CDialog::onTransactionState(pTrans = 2105, previousState = null, currentState = Terminated, reason = Timer K fires]
13:12:42 1105 [CCall::onDialogClosed]
13:12:42 1105 [CCall::onDialogClosed] only initial *********
13:12:42 1105 [CCall] closed
13:12:42 101 [CCallManager::onCallClosed]
13:12:42 101 [CCallManager::onCallClosed()] Call 1105 closed. Removing call 156524976 from the maps
13:12:42 2105 [~CTransaction] transaction 2082276973 REGISTER
13:12:42 5 [~CResponse] resp(200) db79ed0d34d0bae6aa87d1d89b616fe1@ucv.vivienda.gob.pe 2082276973 REGISTER
13:12:44 101 [CCallManager::removeGarbage] at index i = 4
13:12:44 ========> [CSipTcCall::~CSipTcCall] unregister the legId on US
13:12:44 1105 [CCall::~CCall]
13:12:44 1505 [CDialog::~CDialog]
13:12:44 5 [~CRequest] req db79ed0d34d0bae6aa87d1d89b616fe1@ucv.vivienda.gob.pe 2082276973 REGISTER
13:12:44 101 [CCallManager::removeGarbage] at index i = 3
13:12:44 ========> [CSipTcCall::~CSipTcCall] unregister the legId on US
13:12:44 1104 [CCall::~CCall]
13:12:44 1504 [CDialog::~CDialog]
13:12:44 4 [~CRequest] req c7adef23c2b97a2ffd8430c7fee1e517@ucv.vivienda.gob.pe 2092214177 REGISTER
13:12:44 101 [CCallManager::removeGarbage] at index i = 2
13:12:44 ========> [CSipTcCall::~CSipTcCall] unregister the legId on US
13:12:44 1103 [CCall::~CCall]
13:12:44 1503 [CDialog::~CDialog]
13:12:44 3 [~CRequest] req 6a7d1a332ddb5037ddf69a56664d2a6c@ucv.vivienda.gob.pe 71072531 REGISTER
13:12:44 101 [CCallManager::removeGarbage] at index i = 1
13:12:44 ========> [CSipTcCall::~CSipTcCall] unregister the legId on US
13:12:44 1102 [CCall::~CCall]
13:12:44 1502 [CDialog::~CDialog]
13:12:44 2 [~CRequest] req 4aad8fd8aa3f30e700aef5139086b336@ucv.vivienda.gob.pe 1895868346 REGISTER
13:12:44 101 [CCallManager::removeGarbage] at index i = 0
13:12:44 ========> [CSipTcCall::~CSipTcCall] unregister the legId on US
13:12:44 1101 [CCall::~CCall]
13:12:44 1501 [CDialog::~CDialog]
13:12:44 1 [~CRequest] req d0910fa75e2f8d9ce086bd74c96978c2@ucv.vivienda.gob.pe 172175035 REGISTER
13:12:53 udp_recv fd:10
13:12:53 udp_recv fd:10 iBytesRead:1075 message:INVITE sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE, INFO
Supported: replaces,timer,histinfo
User-Agent: OmniPCX Enterprise R10.0 j1.410.34
Session-Expires: 1800;refresher=uac
Min-SE: 900
P-Alcatel-CSBU: categparty=internal;call_condition=localdirect
Content-Type: application/sdp
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=9c530a074a0a1b56d1b759fbcb98cd83
Contact: <sip:3333@192.168.30.31;transport=UDP>
Call-ID: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
CSeq: 680582418 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bK8255fcedf137ec0b8d4fd446e607bccf
Max-Forwards: 70
Content-Length: 290

v=0
o=OXE 1326996797 1326996797 IN IP4 192.168.30.31
s=abs
c=IN IP4 192.168.30.33
t=0 0
m=audio 32736 RTP/AVP 18 8 97
a=sendrecv
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=maxptime:40
a=rtpmap:8 PCMA/8000
a=ptime:20
a=maxptime:30
a=rtpmap:97 telephone-event/8000

13:12:53 UdpInputProc iSock:10 iBytesRead:1075 Host:192.168.30.31 Port:5060
13:12:53 [CTransportUdp::receiveMessage] from 192.168.30.31:5060 rc:1075
13:12:53 [CTransport::findConnection] pConnection = f001 remoteHost=192.168.30.31, remotePort=5060
13:12:53 f001 [CConnection::dOSTest](192.168.30.31,5060,0) MaxNbMsgByPeriod:40 Period:3
13:12:53 f001 [CConnection::dOSTest](192.168.30.31,5060,0) NbMsg:5 < seuil
13:12:53 f001 [CConnection::resetConnectionTimer] Creating the activity timer
13:12:53 RECEIVE MESSAGE FROM NETWORK (192.168.30.31:5060 [UDP])
----------------------utf8-----------------------
INVITE sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE, INFO
Supported: replaces,timer,histinfo
User-Agent: OmniPCX Enterprise R10.0 j1.410.34
Session-Expires: 1800;refresher=uac
Min-SE: 900
P-Alcatel-CSBU: categparty=internal;call_condition=localdirect
Content-Type: application/sdp
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=9c530a074a0a1b56d1b759fbcb98cd83
Contact: <sip:3333@192.168.30.31;transport=UDP>
Call-ID: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
CSeq: 680582418 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bK8255fcedf137ec0b8d4fd446e607bccf
Max-Forwards: 70
Content-Length: 290

v=0
o=OXE 1326996797 1326996797 IN IP4 192.168.30.31
s=abs
c=IN IP4 192.168.30.33
t=0 0
m=audio 32736 RTP/AVP 18 8 97
a=sendrecv
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=maxptime:40
a=rtpmap:8 PCMA/8000
a=ptime:20
a=maxptime:30
a=rtpmap:97 telephone-event/8000
-------------------------------------------------

13:12:53 RECEIVE (192.168.30.31:5060 [UDP]) INVITE sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
13:12:53 6 [CRequest::CRequest] Creation of a request (RECEIVED FROM NETWORK)
13:12:53 [CAdnsMngt::checkHostInBlackList] host=192.168.30.31 alcResult= 0
13:12:53 [CAdnsMngt::checkHostInBlackList] host=192.168.30.31 alcResult= 0
13:12:53 [CDispatcher::onIncomingRequest()]
13:12:53 [CDispatcher::processRequestFromManagerIndex()] start at index 0
13:12:53 101 [CCallManager::onIncomingRequest()]
13:12:53 101 [CCallManager::onIncomingRequest()] creates a new Call if this request doesn't refer to any old call
13:12:53 ========> [CSipTcCall::CSipTcCall]
13:12:53 ========> [CSipTcCall::CSipTcCall] LegId=0
13:12:53 ========> [CSipTcCallManager::callFactory] CSiptTcCall created
13:12:53 1106 [CCall::receiveRequest] INVITE
13:12:53 1506 [CDialog::receiveRequest]
13:12:53 1506 [CDialog::receiveInviteRequest]
13:12:53 1506 [CDialog::onTransactionState(pTrans = 2106, previousState = Terminated, currentState = Initial, reason = None]
13:12:53 2106 [CTransInitialState::receiveRequest] Transaction changes to Proceeding state
13:12:53 1506 [CDialog::onTransactionState(pTrans = 2106, previousState = Initial, currentState = Proceeding, reason = Request reception]
13:12:53 6 [CResponse::CResponse] Creation of a response
13:12:53 6 [CResponse::create] RESPONSE CREATION
13:12:53 6 [CResponse::checkStatusLine] Create StatusLine from code given as parameter
13:12:53 6 [CResponse::createViaHeaders] Copy Via headers from previous request (number : 1)
13:12:53 6 [CMessage::getHeaderAtIndexFromSipMessage(Timestamp, 0)] sip_getHeaderAtIndex FAILED => HSS ERROR No exist
13:12:53 6 [CResponse::create] Initialize context (Local = To & Remote = From)
13:12:53 6 [CMessage::send] sip_sendMessage (192.168.30.31:5060)
13:12:53 SEND MESSAGE TO NETWORK (192.168.30.31:5060 [UDP]) (BUFF LEN = 338)
----------------------utf8-----------------------
SIP/2.0 100 Trying
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=9c530a074a0a1b56d1b759fbcb98cd83
Call-ID: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
CSeq: 680582418 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bK8255fcedf137ec0b8d4fd446e607bccf
Content-Length: 0

-------------------------------------------------
13:12:53 SEND (192.168.30.31:5060 [UDP] SIP/2.0 100 Trying
13:12:53 [CTransport::findConnection] pConnection = f001 remoteHost=192.168.30.31, remotePort=5060
13:12:53 [CTransport::getConnection] RemoteHost=(192.168.30.31 5060) already exist, using connection f001
13:12:53 udp_send fd:10
13:12:53 udp_send fd:10 port 5060 iBytesSend:338 message:SIP/2.0 100 Trying
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=9c530a074a0a1b56d1b759fbcb98cd83
Call-ID: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
CSeq: 680582418 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bK8255fcedf137ec0b8d4fd446e607bccf
Content-Length: 0

13:12:53 f001 [CConnection::resetConnectionTimer] Creating the activity timer
13:12:53 [sip_freeEventContext]
13:12:53 1506 [CDialog::receiveInviteRequest] a new Server INVITE transaction is in progress
13:12:53 [CSessionTimerContext::CSessionTimerContext] New CSessionTimerContext from request (Server, UA)
13:12:53 [CSessionTimerContext::updateAfterRefreshReception] Update CSessionTimerContext (refresh reception)
13:12:53 [CSessionTimerContext::updateSupported] Request timer supported
13:12:53 [CSessionTimerContext::updateMinSE] Min-SE updated : 900
13:12:53 [CSessionTimerContext::updateSessionExpires] header value : 1800
13:12:53 [CSessionTimerContext::updateSessionExpires] updated
13:12:53 [CSessionTimerContext::updateSessionExpires] Refresher updated : r
13:12:53 [CSessionTimerContext::updateSessionExpires] Session-Expires updated : 1800
13:12:53 [CSessionTimerContext::setRefreshMethod] Allow refreshMethod=UPDATE
13:12:53 1506 [CDialog::addTransaction] added transaction 2106 with branch z9hG4bK8255fcedf137ec0b8d4fd446e607bccf, with CSeq 680582418
13:12:53 1106 [CCall::checkAuthentication] INVITE
13:12:53 ========> [CSipTcCall::onReceiveRequest]
13:12:53 ========> [CSipTcCall::checkRequireHeaders]
13:12:53 ========> [CSipTcCall::onReceiveRequest] receive INVITE method
13:12:53 ========> [CSipTcCall::onReceiveRequest] INVITE case
13:12:53 ========> [CSipTcCall::onReceiveRequest] call sipToUsNotification with RING verb
13:12:53 ========> [CSipTcCall::SipToUsNotification]
13:12:53 CPI_GMsg::SetVerb ok
13:12:53 [CSipMediaDescription::parseFormatString] Got 3 format(s) from string 18 8 97
13:12:53 append attr : Media: audio/192.168.30.33:32736
13:12:53 append attr : Codecs: audio/g729,audio/g711Alaw64k,audio/telephone-event/8000:97
13:12:53 877c [CSipAddrSpec::getAddrSpecAsString]
13:12:53 ========> [CSipTcCall::SipToUsNotification] To (escaped)=sip:8097@node001001;user=phone
13:12:53 ========> [CSipTcCall::SipToUsNotification] To (unescaped)=sip:8097@node001001;user=phone
13:12:53 append attr : Destination: sip:8097@node001001;user=phone
13:12:53 6 [CMessage::getAssertedIdCount] need to create the wrapper
13:12:53 6 [CMessage::createAssertedIdWrapperFromMessage]
13:12:53 6 [CMessage::createAssertedIdWrapperFromMessage] there is 0 P-Asserted-Identity header in the message
13:12:53 877b [CSipAddrSpec::getAddrSpecAsString]
13:12:53 ========> [CSipTcCall::SipToUsNotification] From (escaped)=sip:3333@192.168.30.31;user=phone
13:12:53 ========> [CSipTcCall::SipToUsNotification] From (unescaped)=sip:3333@192.168.30.31;user=phone
13:12:53 append attr : Caller: sip:3333@192.168.30.31;user=phone
13:12:53 append attr : Caller-Name: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>
13:12:53 append attr : Call-Ref-Number: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
13:12:53 877f [CSipAddrSpec::getAddrSpecAsString]
13:12:53 append attr : Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:12:53 append attr : Leg-Id: 0
13:12:53 ========> [CSipTcCall::sipToUsNotification] find P-Alcatel-CSBU = categparty=internal;call_condition=localdirect
13:12:53 append attr : Alcatel-Attr-Supp: categparty=internal;call_condition=localdirect
13:12:53 append attr : User-Information: OmniPCX Enterprise R10.0 j1.410.34
13:12:53 append attr : Accept-Language: en
13:12:53 ========> [CSipTcCall::sipToUsNotification] send message to us
13:12:53 us_rcve: protocol:0, leg_id:0
13:12:53 <- RING 0
13:12:53 <- Media: audio/192.168.30.33:32736
13:12:53 <- Codecs: audio/g729,audio/g711Alaw64k,audio/telephone-event/8000:97
13:12:53 <- Destination: sip:8097@node001001;user=phone
13:12:53 <- Caller: sip:3333@192.168.30.31;user=phone
13:12:53 <- Caller-Name: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>
13:12:53 <- Call-Ref-Number: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
13:12:53 <- Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:12:53 <- Leg-Id: 0
13:12:53 <- Alcatel-Attr-Supp: categparty=internal;call_condition=localdirect
13:12:53 <- User-Information: OmniPCX Enterprise R10.0 j1.410.34
13:12:53 <- Accept-Language: en
13:12:53 ~CPI_GMsg refcount=2
13:12:53 us-handle sip 0 RING
13:12:53 registration to 'sip:8097' expired
13:12:53 unix-send: on channel sock13 (toward MS 192.168.30.170)
13:12:53 -> CALL 12
13:12:53 -> Media: audio/192.168.30.33:32736
13:12:53 -> Codecs: audio/g729,audio/g711Alaw64k,audio/telephone-event/8000:97
13:12:53 -> Destination: sip:8097@node001001;user=phone
13:12:53 -> Caller: sip:3333@192.168.30.31;user=phone
13:12:53 -> Caller-Name: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>
13:12:53 -> Call-Ref-Number: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
13:12:53 -> Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:12:53 -> Alcatel-Attr-Supp: categparty=internal;call_condition=localdirect
13:12:53 -> User-Information: OmniPCX Enterprise R10.0 j1.410.34
13:12:53 -> Accept-Language: en
13:12:53 CPUUsed size=1
13:12:53 CPUUsed (0)=A
13:12:53 RedMsg size=0
13:12:53 req size=1
13:12:53 req (12)=0
13:12:53 proto size=1
13:12:53 proto (0)=sip
13:12:53 reverse size=0
13:12:53 state size=1
13:12:53 state (0)=arriving
13:12:53 rep_notif size=0
13:12:53 registrar size=5
13:12:53 registrar (sip:8091)=us:127.0.0.1 14400
13:12:53 registrar (sip:8092)=us:127.0.0.1 14400
13:12:53 registrar (sip:8097)=us:127.0.0.1 14400
13:12:53 registrar (sip:8093)=us:127.0.0.1 14400
13:12:53 registrar (sip:8090)=us:127.0.0.1 14400
13:12:53 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:12:53 <- BUSY 12
13:12:53 us-handle us -1 BUSY
13:12:53 BUSY (MAKECALL context)
13:12:53 us_send: protocol:0, leg_id:0
13:12:53 -> HANGUP 13
13:12:53 -> Leg-Id: 0
13:12:53 -> Reason: Busy
13:12:53 ========> [CSipTcCallManager::siptc] receive message from us
13:12:53 CPI_GMsg list refcount:3 internal list :
13:12:53 HANGUP 13
13:12:53 Leg-Id: 0
13:12:53 Reason: Busy
13:12:53 ========> [CSipTcCallManager::onReceiveUSRequest]
13:12:53 ========> [CSipTcCall::onReceiveUS]
13:12:53 CPI_GMsg list refcount:4 internal list :
13:12:53 HANGUP 13
13:12:53 Leg-Id: 0
13:12:53 Reason: Busy
13:12:53 ========> [CSipTcCall::onReceiveUS] receive a request=7
13:12:53 ========> [CSipTcCall::onReceiveUS] receive HANGUP on state = 1
13:12:53 ========> [CSipTcCall::onReceiveUS] rec HANGUP on IN_PROGRESS_INVITE state, send 486 or 480
13:12:53 1106 [CCall::makeGenericResponse] 486
13:12:53 1506 [CDialog::createResponse] 486
13:12:53 7 [CResponse::CResponse] Creation of a response
13:12:53 7 [CResponse::create] RESPONSE CREATION
13:12:53 7 [CResponse::checkStatusLine] Create StatusLine from code given as parameter
13:12:53 7 [CResponse::createToHeader] Initialize To TAG from context
13:12:53 7 [CResponse::createToHeader] Creation a tag for To header
13:12:53 7 [CResponse::createViaHeaders] Copy Via headers from previous request (number : 1)
13:12:53 7 [CResponse::create] Initialize context (Local = To & Remote = From)
13:12:53 7 [CMessage::send] sip_sendMessage (192.168.30.31:5060)
13:12:53 SEND MESSAGE TO NETWORK (192.168.30.31:5060 [UDP]) (BUFF LEN = 378)
----------------------utf8-----------------------
SIP/2.0 486 Busy Here
To: <sip:8097@node001001;user=phone>;tag=57edb2688989e8b04cf22c1601175e99
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=9c530a074a0a1b56d1b759fbcb98cd83
Call-ID: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
CSeq: 680582418 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bK8255fcedf137ec0b8d4fd446e607bccf
Content-Length: 0

-------------------------------------------------
13:12:53 SEND (192.168.30.31:5060 [UDP] SIP/2.0 486 Busy Here
13:12:53 [CTransport::findConnection] pConnection = f001 remoteHost=192.168.30.31, remotePort=5060
13:12:53 [CTransport::getConnection] RemoteHost=(192.168.30.31 5060) already exist, using connection f001
13:12:53 udp_send fd:10
13:12:53 udp_send fd:10 port 5060 iBytesSend:378 message:SIP/2.0 486 Busy Here
To: <sip:8097@node001001;user=phone>;tag=57edb2688989e8b04cf22c1601175e99
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=9c530a074a0a1b56d1b759fbcb98cd83
Call-ID: 168b64c21fe5927052a6986c20b56b7b@192.168.30.31
CSeq: 680582418 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bK8255fcedf137ec0b8d4fd446e607bccf
Content-Length: 0

13:12:53 f001 [CConnection::resetConnectionTimer] Creating the activity timer
13:12:53 [sip_freeEventContext]
13:12:53 6 [~CResponse] resp(100) 168b64c21fe5927052a6986c20b56b7b@192.168.30.31 680582418 INVITE
13:12:53 2106 [CTransProceedingState::createResponse] Final : Transaction changes to Completed state
13:12:53 1506 [CDialog::onTransactionState(pTrans = 2106, previousState = Proceeding, currentState = Completed, reason = Final resp creation]
13:12:53 1506 [CDialog::updateRouteSet] there are 0 record-route headers
13:12:53 ========> [CSipTcCall::sendUsReply] send to us the reply 71
13:12:53 CPI_GMsg::SetVerb ok
13:12:53 append attr : Leg-Id: 0
13:12:53 us_rcve: protocol:0, leg_id:0
13:12:53 <- OK 13
13:12:53 <- Leg-Id: 0
13:12:53 ~CPI_GMsg refcount=2
13:12:53 CPI_GMsg::SetVerb ok
13:12:53 append attr : Leg-Id: 0
13:12:53 us_rcve: protocol:0, leg_id:0
13:12:53 <- DROPPED 1
13:12:53 <- Leg-Id: 0
13:12:53 ~CPI_GMsg refcount=2
13:12:53 ~CPI_GMsg refcount=4
13:12:53 ~CPI_GMsg refcount=3
13:12:53 clean-leg 0

In the central Oxe shows the following logs and traces
(672620:000046) event_init_screen_mem : line 1 tscreen '8097 '
(672620:000047) MEVO : sauve_num_in_bis numero_demande 8097
(672620:000048) depart_t2_ok(90,0) : monlap 11
(672620:000049) depart_t2_ok On est la .....
(672620:000050) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000051) depart_t2_ok result=1
(672620:000052) depart_t2_ok(90,63) : monlap 10
(672620:000053) depart_t2_ok On est la .....
(672620:000054) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000055) depart_t2_ok result=1
(672620:000056) depart_t2_ok(90,0) : monlap 11
(672620:000057) depart_t2_ok On est la .....
(672620:000058) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000059) depart_t2_ok result=1
(672620:000060) depart_t2_ok(90,63) : monlap 10
(672620:000061) depart_t2_ok On est la .....
(672620:000062) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000063) depart_t2_ok result=1
(672620:000064) depart_t2_ok(90,0) : monlap 11
(672620:000065) depart_t2_ok On est la .....
(672620:000066) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000067) depart_t2_ok result=1
(672620:000068) depart_t2_ok(90,63) : monlap 10
(672620:000069) depart_t2_ok On est la .....
(672620:000070) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000071) depart_t2_ok result=1
(672620:000072) depart_t2_ok(90,0) : monlap 11
(672620:000073) depart_t2_ok On est la .....
(672620:000074) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000075) depart_t2_ok result=1
(672620:000076) modifIfRemoteExtGhostZ-->neqt1=375
(672620:000077) depart_t2_ok(90,63) : monlap 10
(672620:000078) depart_t2_ok On est la .....
(672620:000079) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(672620:000080) depart_t2_ok result=1
(672620:000081) ---> ptdemi->neqt 375
(672620:000082) ---> with_terminaison->dtyterm 13
(672620:000083) MEVO : get_typ_mevo typmevo VMS_NETWORK
(672620:000084) MEVO : init_feature_2_id option1 1 ,2 1, rvext = 0
(672620:000085) MEVO : option1 1 ,2 1 rv_loc_op 0
(672620:000086) INIT MEVO : uti_inidcom init mevo neqt 1676
(672620:000087) SIP : besoin_et_echec_alloc_comp -> faisceau SIP ou ABCIP
(672620:000088) SIP : besoin_et_echec_alloc_comp -> prisedep
(672620:000089) SIP : besoin_et_echec_alloc_comp -> egzis_li OK
(672620:000090) recup_dom_recherche cr_plus_proche = 2
(672620:000091) SIP mise_a_jour_des_canaux ind=0 neqt=1676 allocation=1
(672620:000092) SIP mise_a_jour_des_canaux state=0
(672620:000093) emis_setup-->neqt_pttrav=375 neqt_ptdemi=1676 payload=97
(672620:000094) sendipns :envoi de ei_sending_complete dans le setup
(672620:000095) SIP SIP_remp_channel etat_t2 = 1
(672620:000096) SIP : remp_specific_classmarks-->ptdemi->nummcdu=375
(672620:000097) MEVO : VMS_NETWORK
(672620:000098) SIP : copy_rtp_data_for_sip_use : local or distant : 1 sens : 0
(672620:000099) SIP : copy_rtp_data_for_sip_use : carte_fille_lio=0
(672620:000100) Enter remp_ip_payloads-->nummcdu=375
(672620:000101) Il_y_a_de_l_ABC_IP 6 result=0
(672620:000102) Il_y_a_du_SIP 1 neqt 1676 remote_device 0
(672620:000103) Il_y_a_du_SIP 3 result=1
(672620:000104) SIP : recupere_compression_type(1676) : DEFAULT_COMPRESSION G711
(672620:000105) Il_y_a_du_SIP 1 neqt 1676 remote_device 0
(672620:000106) Il_y_a_du_SIP 3 result=1
(672620:000107) EI_RTP_INFO 5: payload=97
(672620:000108) sip_behind_rex dcom -- start
(672620:000109) get_sip_dcom_behind_rex : nummcdu = 375
(672620:000110) get_sip_dcom_behind_rex : neqt_rem = 375
(672620:000111) get_sip_dcom_behind_rex : neqt_rem = 375
(672620:000112) chgt_local_rtp_info ptdemi->info.hinfo=0 ptdemi->neqt=1676
(672620:000113) INIT MEVO : uti_inidcom init mevo neqt 1612
(672620:000114) ctrl_party_cat ptdemi->abonne_reseau = 1
(672620:000115) SIP_ctrl_ip_payloads ptdemi->payloads_recu[0]=17
(672620:000116) SIP_ctrl_ip_payloads ptdemi->payloads_recu[1]=0
(672620:000117) SIP : copy_rtp_data_for_sip_use : local or distant : 1 sens : 1
(672620:000118) SIP : copy_rtp_data_for_sip_use : carte_fille_lio=0
(672620:000119) liste_des_services_sip: Result=1
(672620:000120) envoi du code secret 0
(672620:000121) MEVO : option 1 1
(672620:000122) MEVO : j 0 contenu 192
(672620:000123) MEVO : j 1 contenu 32
(672620:000124) MEVO : j 2 contenu 0
(672620:000125) MEVO : j 3 contenu 94
(672620:000126) MEVO : octet 0 0xc0 lect_t2 0xc0
(672620:000127) MEVO : option 1 1
(672620:000128) CAC_SIP : arr_ipns : on va rentrer dans setup_received, neqt : 1612
(672620:000129) setup_received-->Marhaban bikom dans le monde SIP : message de 1612
(672620:000130) SIP SIP_remp_channel etat_t2 = 6
(672620:000131) setup_received-->remote_oeration_value = -1
(672620:000132) setup_received-->prise_channel = 1
(672620:000133) appel Telephonique
(672620:000134) Case1
(672620:000135) operations_vers_sip_autorise : gf = 1
(672620:000136) result of operations_vers_sip_autorises = 1
(672620:000137) setup_received_without_transfer_setup
(672620:000138) MEVO : rend_indice_mevo indice 2 numero 8097 trouve 1
(672620:000139) get_extension_nulog-->ext mevo=1001
(672620:000140) called entity 1000
(672620:000141) build_called_to_sip internal sip user
(672620:000142) SIP : portal_data_invite nulo_final = 65535
(672620:000143) IN build_calling_to_sip len=4
(672620:000144) build_calling_to_sip , octet3: unknown ou private : OK
(672620:000145) build_calling_to_sip private : sip_dico : NOK
(672620:000146) B
(672620:000147) E
(672620:000148) L
(672620:000149) I
(672620:000150) S
(672620:000151) S
(672620:000152) A
(672620:000153)
(672620:000154)
(672620:000155) L
(672620:000156) E
(672620:000157) Z
(672620:000158) A
(672620:000159) M
(672620:000160) A
(672620:000161) SIP : text_to_url_display : avant : BELISSA LEZAMA
(672620:000162) SIP : text_to_url_display : apres : BELISSA LEZAMA
(672620:000163) build_calling_to_sip from_hostname=192.168.30.31
(672620:000164) build_calling_to_sip from_username=1441
(672620:000165) build_calling_to_sip from_display_name=BELISSA LEZAMA
(672620:000166) get_dom_jct_ip_sip_2 dom_nb 16384
(672620:000167) send_only_one_algo neqt 1612 explmevo 1 nulo_final 65535
(672620:000168) send_only_one_algo FALSE
(672620:000169) SIP : reservation_cac_ok : hostname : vivienda.gob.pe
(672620:000170) SIP : reservation_cac_ok domaineFrom(16384) domaineTo(1000)
(672620:000171) is_ice_ext_gw-->ext_gw=1000,Result=FALSE
(672620:000172) remp_SDP_as_INVITE 1612
(672620:000173) remp_SDP_as_INVITE extGw 1000
(672620:000174) send_sip--->ptdemi->nulo_final=65535,neqt_en_face=1676
(672620:000175) send_sip ---> call_type:0
(672620:000176) SIP : [send_to_motor] ipcSend resultat : 0 sur eqt : 1612
(672620:000177) SIP : [ipc_send] envoi du message : 10752.
(672620:000178) +------------------------------------------------------------+
(672620:000179) | Message sent UA (neqt : 1612-0) ----> SIP
(672620:000180) | INVITE : 8097@vivienda.gob.pe:5060 ; user=phone
(672620:000181) | From : <BELISSA LEZAMA> 1441@192.168.30.31:5060 ; user=phone
(672620:000182) | To : <> 8097@vivienda.gob.pe:5060 ; user=phone
(672620:000183) +------------------------------------------------------------+
(672620:000184) | SDP :
(672620:000185) | @IP:port = 192.168.30.33:32592
(672620:000186) | ALGOS :
(672620:000187) | G729
(672620:000188) | PCMA
(672620:000189) | DTMF : 97
(672620:000190) | DIRECTION : SEND & RECEIVE
(672620:000191) | cac : false
(672620:000192) | -->Portal
(672620:000193) | Coming from an extension
(672620:000194) | Transfer allowed
(672620:000195) | Language : 0
(672620:000196) | call_condition : 13
(672620:000197) | autoAnswer : false
(672620:000198) +------------------------------------------------------------+
(672620:000199) send_mess_etab sur SIP no=7 neqt=1612
(672620:000200) neqt(1612) PROCEDURE send_etab_tab_mess() no_tmp_etab=7
(672620:000201) (1612) CPU_CPU_SAVE_SIP 25322904
(672620:000202) event_init_screen_mem : line 1 tscreen '8097 '
(672620:000203) MEVO : rend_categorie_mevo cat=1, option1 1 ,2 1
(672620:000204) SIP : Global_get_mcdu, in dico
(672620:000205) SIP : Global_get_mcdu, in dico
(

Post by **cavagnaro** » 23 Jan 2012 08:58

Says:

Reason: Busy

Can you post the result of "sipregister -l"?

Felipe.Herrera · Post by **Felipe.Herrera** » 23 Jan 2012 11:40

Dump local registrar base
-------------------------------------------------
Address of record : 8097
contact : sip:8097@192.168.30.170:5070, UDP, 8647 s
-------------------------------------------------
Address of record : 8093
contact : sip:8093@192.168.30.170:5070, UDP, 8647 s
-------------------------------------------------
Address of record : 8098
contact : sip:8098@192.168.28.170:51506, udp, 3155 s
-------------------------------------------------
Address of record : 8090
contact : sip:8090@192.168.30.170:5070, UDP, 8647 s
-------------------------------------------------
Address of record : 8091
contact : sip:8091@192.168.30.170:5070, UDP, 8647 s
-------------------------------------------------
Address of record : 8092
contact : sip:8092@192.168.30.170:5070, UDP, 8647 s
*************************************************
****** registred user number : 6
*************************************************

Post by **cavagnaro** » 23 Jan 2012 12:00

You say:

On the server shows that UC is registered in Oxe and sip media server, msa, rsm is OK but the service rs is NOK.

So can you please do the following:

1. Stop ICS services
2. Clean logs
3. Start ICS services
4. Do a call
5. Collect and post OXE SIP logs
6. Collect and post ICS (MS) logs
7. A print screen of your ICS services
8. ICS WebAdmin configuration screenshots if you can too

Regards

Felipe.Herrera · Post by **Felipe.Herrera** » 23 Jan 2012 12:26

thanks Cavagnaro, for answer.

This moment post logs

Felipe.Herrera · Post by **Felipe.Herrera** » 23 Jan 2012 13:37

hi cavagnaro.
Sending of logs

OXE SIP
--------------------------------------------------------------------------
(783980:000643) MEVO : update_type_of_set neqt 621
(783980:000644) INIT MEVO : uti_inidcom init mevo neqt 621
(783980:000645) INIT MEVO : uti_inidcom init mevo neqt 597
(783980:000646) event_init_screen_mem : line 1 tscreen '8097 '
(783980:000647) MEVO : sauve_num_in_bis numero_demande 8097
(783980:000648) depart_t2_ok(90,0) : monlap 11
(783980:000649) depart_t2_ok On est la .....
(783980:000650) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000651) depart_t2_ok result=1
(783980:000652) depart_t2_ok(90,63) : monlap 10
(783980:000653) depart_t2_ok On est la .....
(783980:000654) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000655) depart_t2_ok result=1
(783980:000656) depart_t2_ok(90,0) : monlap 11
(783980:000657) depart_t2_ok On est la .....
(783980:000658) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000659) depart_t2_ok result=1
(783980:000660) depart_t2_ok(90,63) : monlap 10
(783980:000661) depart_t2_ok On est la .....
(783980:000662) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000663) depart_t2_ok result=1
(783980:000664) depart_t2_ok(90,0) : monlap 11
(783980:000665) depart_t2_ok On est la .....
(783980:000666) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000667) depart_t2_ok result=1
(783980:000668) depart_t2_ok(90,63) : monlap 10
(783980:000669) depart_t2_ok On est la .....
(783980:000670) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000671) depart_t2_ok result=1
(783980:000672) depart_t2_ok(90,0) : monlap 11
(783980:000673) depart_t2_ok On est la .....
(783980:000674) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000675) depart_t2_ok result=1
(783980:000676) modifIfRemoteExtGhostZ-->neqt1=384
(783980:000677) depart_t2_ok(90,63) : monlap 10
(783980:000678) depart_t2_ok On est la .....
(783980:000679) depart_t2_ok pour SIP (faisceau 90) -> Result avant 1 etat2 4 en_service 1
(783980:000680) depart_t2_ok result=1
(783980:000681) ---> ptdemi->neqt 384
(783980:000682) ---> with_terminaison->dtyterm 13
(783980:000683) ..reptrad.Status = 13, OK_Tsled_Number = 13
(783980:000684) ..reptrad.Application = 0, Tsl_Com_Apl = 0
(783980:000685) ..reptrad.Type.Com = 8, Tsl_Network_Member_Pfx = 6
(783980:000686) ..reptrad.Network_Cat = 0, Tsl_Net_SIP_Extension = 12
(783980:000687) ..is_a_network_set_like_sip_extension (8097) : 0
(783980:000688) MEVO : init_feature_2_id option1 1 ,2 1, rvext = 0
(783980:000689) MEVO : option1 1 ,2 1 rv_loc_op 0
(783980:000690) ..reptrad.Status = 13, OK_Tsled_Number = 13
(783980:000691) ..reptrad.Application = 0, Tsl_Com_Apl = 0
(783980:000692) ..reptrad.Type.Com = 8, Tsl_Network_Member_Pfx = 6
(783980:000693) ..reptrad.Network_Cat = 0, Tsl_Net_SIP_Extension = 12
(783980:000694) ..is_a_network_set_like_sip_extension (8097) : 0
(783980:000695) INIT MEVO : uti_inidcom init mevo neqt 1676
(783980:000696) neqttouc neqt=1676 nekip=384 toucacod=1
(783980:000697) neqttouc result=1000180 en Hexa !!!
(783980:000698) ..reptrad.Status = 13, OK_Tsled_Number = 13
(783980:000699) ..reptrad.Application = 0, Tsl_Com_Apl = 0
(783980:000700) ..reptrad.Type.Com = 8, Tsl_Network_Member_Pfx = 6
(783980:000701) ..reptrad.Network_Cat = 0, Tsl_Net_SIP_Extension = 12
(783980:000702) ..is_a_network_set_like_sip_extension (8097) : 0
(783980:000703) ..must_put_rtp_in_abcip with JONCTEUR_POSTE & is_a_sip : 0
(783980:000704) SIP : besoin_et_echec_alloc_comp -> faisceau SIP ou ABCIP
(783980:000705) SIP : besoin_et_echec_alloc_comp -> prisedep
(783980:000706) SIP : besoin_et_echec_alloc_comp -> egzis_li OK
(783980:000707) recup_dom_recherche cr_plus_proche = 2
(783980:000708) SIP mise_a_jour_des_canaux ind=0 neqt=1676 allocation=1
(783980:000709) SIP mise_a_jour_des_canaux state=0
(783980:000710) ..reptrad.Status = 13, OK_Tsled_Number = 13
(783980:000711) ..reptrad.Application = 0, Tsl_Com_Apl = 0
(783980:000712) ..reptrad.Type.Com = 8, Tsl_Network_Member_Pfx = 6
(783980:000713) ..reptrad.Network_Cat = 0, Tsl_Net_SIP_Extension = 12
(783980:000714) ..is_a_network_set_like_sip_extension (8097) : 0
(783980:000715) ..must_put_rtp_in_abcip with JONCTEUR_POSTE & is_a_sip : 0
(783980:000716) neqttouc neqt=1676 nekip=384 toucacod=1
(783980:000717) neqttouc result=1000180 en Hexa !!!
(783980:000718) emis_setup-->neqt_pttrav=384 neqt_ptdemi=1676 payload=97
(783980:000719) sendipns :envoi de ei_sending_complete dans le setup
(783980:000720) SIP SIP_remp_channel etat_t2 = 1
(783980:000721) SIP : remp_specific_classmarks-->ptdemi->nummcdu=16777600
(783980:000722) MEVO : VMS_NETWORK
(783980:000723) SIP : copy_rtp_data_for_sip_use : local or distant : 1 sens : 0
(783980:000724) SIP : copy_rtp_data_for_sip_use : carte_fille_lio=0
(783980:000725) Enter remp_ip_payloads-->nummcdu=16777600
(783980:000726) Il_y_a_de_l_ABC_IP 6 result=0
(783980:000727) Il_y_a_du_SIP 1 neqt 1676 remote_device 0
(783980:000728) Il_y_a_du_SIP 3 result=1
(783980:000729) SIP : recupere_compression_type(1676) : DEFAULT_COMPRESSION G711
(783980:000730) Il_y_a_du_SIP 1 neqt 1676 remote_device 0
(783980:000731) Il_y_a_du_SIP 3 result=1
(783980:000732) EI_RTP_INFO 5: payload=97
(783980:000733) sip_behind_rex dcom -- start
(783980:000734) get_sip_dcom_behind_rex : nummcdu = 16777600
(783980:000735) get_sip_dcom_behind_rex : neqt_rem = 384
(783980:000736) get_sip_dcom_behind_rex : neqt_rem = 384
(783980:000737) chgt_local_rtp_info ptdemi->info.hinfo=0 ptdemi->neqt=1676
(783980:000738) INIT MEVO : uti_inidcom init mevo neqt 1612
(783980:000739) ..reptrad.Status = 2, OK_Tsled_Number = 13
(783980:000740) ..reptrad.Application = 2, Tsl_Com_Apl = 0
(783980:000741) ..reptrad.Type.Com = 1, Tsl_Network_Member_Pfx = 6
(783980:000742) ..reptrad.Network_Cat = 0, Tsl_Net_SIP_Extension = 12
(783980:000743) ..is_a_network_set_like_sip_extension () : 0
(783980:000744) ..must_put_rtp_in_abcip with JONCTEUR_POSTE & is_a_sip : 0
(783980:000745) ctrl_party_cat ptdemi->abonne_reseau = 1
(783980:000746) SIP_ctrl_ip_payloads ptdemi->payloads_recu[0]=17
(783980:000747) SIP_ctrl_ip_payloads ptdemi->payloads_recu[1]=0
(783980:000748) SIP : copy_rtp_data_for_sip_use : local or distant : 1 sens : 1
(783980:000749) SIP : copy_rtp_data_for_sip_use : carte_fille_lio=0
(783980:000750) liste_des_services_sip: Result=1
(783980:000751) envoi du code secret 0
(783980:000752) MEVO : option 1 1
(783980:000753) MEVO : j 0 contenu 192
(783980:000754) MEVO : j 1 contenu 32
(783980:000755) MEVO : j 2 contenu 0
(783980:000756) MEVO : j 3 contenu 94
(783980:000757) MEVO : octet 0 0xc0 lect_t2 0xc0
(783980:000758) MEVO : option 1 1
(783980:000759) CAC_SIP : arr_ipns : on va rentrer dans setup_received, neqt : 1612
(783980:000760) setup_received-->Marhaban bikom dans le monde SIP : message de 1612
(783980:000761) SIP SIP_remp_channel etat_t2 = 6
(783980:000762) setup_received-->remote_oeration_value = -1
(783980:000763) setup_received-->prise_channel = 1
(783980:000764) appel Telephonique
(783980:000765) Case1
(783980:000766) operations_vers_sip_autorise : gf = 1
(783980:000767) result of operations_vers_sip_autorises = 1
(783980:000768) setup_received_without_transfer_setup
(783980:000769) MEVO : rend_indice_mevo indice 2 numero 8097 trouve 1
(783980:000770) get_extension_nulog-->ext mevo=1001
(783980:000771) called entity 1000
(783980:000772) build_called_to_sip internal sip user
(783980:000773) SIP : portal_data_invite nulo_final = 65535
(783980:000774) IN build_calling_to_sip len=4
(783980:000775) build_calling_to_sip , octet3: unknown ou private : OK
(783980:000776) build_calling_to_sip private : sip_dico : NOK
(783980:000777) R
(783980:000778) E
(783980:000779) Y
(783980:000780) N
(783980:000781) A
(783980:000782) L
(783980:000783) D
(783980:000784) O
(783980:000785)
(783980:000786)
(783980:000787) G
(783980:000788) I
(783980:000789) R
(783980:000790) A
(783980:000791) L
(783980:000792) D
(783980:000793) SIP : text_to_url_display : avant : REYNALDO GIRALD
(783980:000794) SIP : text_to_url_display : apres : REYNALDO GIRALD
(783980:000795) build_calling_to_sip from_hostname=192.168.30.31
(783980:000796) build_calling_to_sip from_username=3333
(783980:000797) build_calling_to_sip from_display_name=REYNALDO GIRALD
(783980:000798) get_dom_jct_ip_sip_2 dom_nb 16384
(783980:000799) send_only_one_algo neqt 1612 explmevo 1 nulo_final 65535
(783980:000800) send_only_one_algo FALSE
(783980:000801) SIP : reservation_cac_ok : hostname : node001001
(783980:000802) SIP : reservation_cac_ok domaineFrom(16384) domaineTo(1000)
(783980:000803) is_ice_ext_gw-->ext_gw=1000,Result=FALSE
(783980:000804) remp_SDP_as_INVITE 1612
(783980:000805) remp_SDP_as_INVITE extGw 1000
(783980:000806) send_sip--->ptdemi->nulo_final=65535,neqt_en_face=1676
(783980:000807) send_sip ---> call_type:0
(783980:000808) SIP : [send_to_motor] ipcSend resultat : 0 sur eqt : 1612
(783980:000809) SIP : [ipc_send] envoi du message : 10752.
(783980:000810) +------------------------------------------------------------+
(783980:000811) | Message sent UA (neqt : 1612-0) ----> SIP
(783980:000812) | INVITE : 8097@node001001:5060 ; user=phone
(783980:000813) | From : <REYNALDO GIRALD> 3333@192.168.30.31:5060 ; user=phone
(783980:000814) | To : <> 8097@node001001:5060 ; user=phone
(783980:000815) +------------------------------------------------------------+
(783980:000816) | SDP :
(783980:000817) | @IP:port = 192.168.30.33:32656
(783980:000818) | ALGOS :
(783980:000819) | G729
(783980:000820) | PCMA
(783980:000821) | DTMF : 97
(783980:000822) | DIRECTION : SEND & RECEIVE
(783980:000823) | cac : false
(783980:000824) | -->Portal
(783980:000825) | Coming from an extension
(783980:000826) | Transfer allowed
(783980:000827) | Language : 0
(783980:000828) | call_condition : 13
(783980:000829) | autoAnswer : false
(783980:000830) +------------------------------------------------------------+
(783980:000831) send_mess_etab sur SIP no=3 neqt=1612
(783980:000832) neqt(1612) PROCEDURE send_etab_tab_mess() no_tmp_etab=3
(783980:000833) (1612) CPU_CPU_SAVE_SIP 25191832
(783980:000834) event_init_screen_mem : line 1 tscreen '8097 '
(783980:000835) MEVO : rend_categorie_mevo cat=1, option1 1 ,2 1
(783980:000836) SIP : Global_get_mcdu, in dico
(783980:000837) SIP : Global_get_mcdu, in dico
(783981:000838) SIP : request_failure_for_invite : SIP_REQ_FAILURE 10767
(783981:000839) SIP : traitement_4_5_6_xx : categorie 10767
(783981:000840) SIP : ctrl_sip evt : 10767.
(783981:000841) +------------------------------------------------------------+
(783981:000842) | Message received SIP ----> UA (neqt : 1612)
(783981:000843) | Request Failure 486
(783981:000844) | RELATIVE REQUEST : INVITE
(783981:000845) +------------------------------------------------------------+
(783981:000846) MEVO : init_feature_2_id option1 1 ,2 1, rvext = 1
(783981:000847) CCBS_CCNR false
(783981:000848) 125542 : equiv_err_sip_q931 : sip response : 486
(783981:000849) 125542 :equiv_err_sip_q931 Index : 22
(783981:000850) 125542 : equiv_err_sip_q931 : sip response : 486 ch_cause : 17
(783981:000851) SIP : traitement_4_5_6_xx-->etat_t2=9
(783981:000852) SIP : traitement_4_5_6_xx : xx 86
(783981:000853) SIP : traitement_4_5_6_xx : cause 17
(783981:000854) SIP : remp_specific_classmarks-->SIP_remp_specific_classmarks
(783981:000855) SIP_remp_specific_classmarks-->etat_t2=9
(783981:000856) SIP_remp_specific_classmarks cnip_received
(783981:000857) SIP : ptdemi->init_party_nr 2 : 1
(783981:000858) event_init_screen_mem : line 1 tscreen '8097 '
(783981:000859) quel_service the value of sauve_1 is 0
(783981:000860) SIP : ctrl_sip evt : 2.
(783981:000861) +------------------------------------------------------------+
(783981:000862) | Message received SIP ----> UA (neqt : 1612-8)
(783981:000863) +------------------------------------------------------------+
(783981:000864) SIP : [send_to_motor_eqt_release] ipcSend resultat : 0 sur eqt : 1612
(783981:000865) SIP : [ipc_send] envoi eqt release 1612
(783981:000866) dec_verrou_before_dispo_t2 lib_messa_etab no=3 neqt=1612
(783981:000867) neqt(1612) PROCEDURE send_lib_tab_mess() lien=0:MOI
(783981:000868) nu_tmp=3
(783981:000869) (1612) CPU_CPU_SAVE_SIP 25192984
(783981:000870) SIP mise_a_jour_des_canaux ind=63 neqt=1612 allocation=0
(783981:000871) envoijustif : ptdemi->neqt=1676
(783981:000872) SIP mise_a_jour_des_canaux ind=0 neqt=1676 allocation=0
(783981:000873) SIP mise_a_jour_des_canaux ind=0 neqt=1676 allocation=0

---------------------------------------------------------------------------------

UCV LOgs

[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/SipServer/sip-log.txt
13:16:03 proto size=0
13:16:03 reverse size=0
13:16:03 state size=0
13:16:03 rep_notif size=0
13:16:03 registrar size=5
13:16:03 registrar (sip:8091)=us:127.0.0.1 14400
13:16:03 registrar (sip:8092)=us:127.0.0.1 14400
13:16:03 registrar (sip:8097)=us:127.0.0.1 14400
13:16:03 registrar (sip:8093)=us:127.0.0.1 14400
13:16:03 registrar (sip:8090)=us:127.0.0.1 14400
13:16:43 HTTP: http operation : GET /trace/status?MS_ADDRESS=192.168.30.170 HTTP/1.1
13:16:43 HTTP: on socket: sock14
13:16:43 unix-send: on channel sock13 (toward MS 192.168.30.170)
13:16:43 -> TRACE 64
13:16:43 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:16:43 <- TRACED 64
13:16:43 <- AlComp:
13:16:43 <- AlLevel:
13:16:43 <- RsLevel:
13:16:43 <- BrowserLevel:
13:16:43 <- AlStatus: OK
13:16:43 <- RsStatus: NOK
13:16:43 <- AlNbSessions: 0
13:16:43 <- AlNbTrfSessions: 0
13:16:43 <- RsNbSessions:
13:16:43 <- AlTraceUrl: http://192.168.30.170:8015/MediaServer/AL/al-log.txt
13:16:43 <- AlEvtUrl: http://192.168.30.170:8015/MediaServer/AL/al-alarm.txt
13:16:43 <- AlExcUrl: http://192.168.30.170:8015/MediaServer/AL/al-err.txt
13:16:43 <- RmsConfUrl: http://192.168.30.170:8015/ecc.cfg
13:16:43 <- ServicesUrl: http://192.168.30.170:8015/services
13:16:43 <- RsTraceUrl:
13:16:43 <- BrowserUrl: http://192.168.30.170:8015/browser
13:16:43 <- ReadMeUrl: http://192.168.30.170:8015/README.txt
13:16:43 us-handle us -1 TRACED
13:16:43 message recu: TRACED 64 AlComp: {} AlLevel: {} RsLevel: {} BrowserLevel: {} AlStatus: OK RsStatus: NOK AlNbSessions: 0 AlNbTrfSessions: 0 RsNbSessions: {} AlTraceUrl: http://192.168.30.170:8015/MediaServer/AL/al-log.txt AlEvtUrl: http://192.168.30.170:8015/MediaServer/AL/al-alarm.txt AlExcUrl: http://192.168.30.170:8015/MediaServer/AL/al-err.txt RmsConfUrl: http://192.168.30.170:8015/ecc.cfg ServicesUrl: http://192.168.30.170:8015/services RsTraceUrl: {} BrowserUrl: http://192.168.30.170:8015/browser ReadMeUrl: http://192.168.30.170:8015/README.txt
13:16:43 CPUUsed size=0
13:16:43 RedMsg size=0
13:16:43 req size=0
13:16:43 proto size=0
13:16:43 reverse size=0
13:16:43 state size=0
13:16:43 rep_notif size=0
13:16:43 registrar size=5
13:16:43 registrar (sip:8091)=us:127.0.0.1 14400
13:16:43 registrar (sip:8092)=us:127.0.0.1 14400
13:16:43 registrar (sip:8097)=us:127.0.0.1 14400
13:16:43 registrar (sip:8093)=us:127.0.0.1 14400
13:16:43 registrar (sip:8090)=us:127.0.0.1 14400
13:17:03 udp_recv fd:10
13:17:03 udp_recv fd:10 iBytesRead:1074 message:INVITE sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE, INFO
Supported: replaces,timer,histinfo
User-Agent: OmniPCX Enterprise R10.0 j1.410.34
Session-Expires: 1800;refresher=uac
Min-SE: 900
P-Alcatel-CSBU: categparty=internal;call_condition=localdirect
Content-Type: application/sdp
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
Contact: <sip:3333@192.168.30.31;transport=UDP>
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
CSeq: 31090765 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
Max-Forwards: 70
Content-Length: 290

v=0
o=OXE 1327342659 1327342659 IN IP4 192.168.30.31
s=abs
c=IN IP4 192.168.30.33
t=0 0
m=audio 32656 RTP/AVP 18 8 97
a=sendrecv
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=maxptime:40
a=rtpmap:8 PCMA/8000
a=ptime:20
a=maxptime:30
a=rtpmap:97 telephone-event/8000

13:17:03 UdpInputProc iSock:10 iBytesRead:1074 Host:192.168.30.31 Port:5060
13:17:03 [CTransportUdp::receiveMessage] from 192.168.30.31:5060 rc:1074
13:17:03 [CTransport::findConnection] pConnection = 0 remoteHost=192.168.30.31, remotePort=5060
13:17:03 f003 [CConnection::resetConnectionTimer] Creating the activity timer
13:17:03 [CTransport::addConnection] Insert connection f003 with key = 192.168.30.31|5060
13:17:03 RECEIVE MESSAGE FROM NETWORK (192.168.30.31:5060 [UDP])
----------------------utf8-----------------------
INVITE sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, PRACK, NOTIFY, REFER, SUBSCRIBE, OPTIONS, UPDATE, INFO
Supported: replaces,timer,histinfo
User-Agent: OmniPCX Enterprise R10.0 j1.410.34
Session-Expires: 1800;refresher=uac
Min-SE: 900
P-Alcatel-CSBU: categparty=internal;call_condition=localdirect
Content-Type: application/sdp
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
Contact: <sip:3333@192.168.30.31;transport=UDP>
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
CSeq: 31090765 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
Max-Forwards: 70
Content-Length: 290

v=0
o=OXE 1327342659 1327342659 IN IP4 192.168.30.31
s=abs
c=IN IP4 192.168.30.33
t=0 0
m=audio 32656 RTP/AVP 18 8 97
a=sendrecv
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=maxptime:40
a=rtpmap:8 PCMA/8000
a=ptime:20
a=maxptime:30
a=rtpmap:97 telephone-event/8000
-------------------------------------------------

13:17:03 RECEIVE (192.168.30.31:5060 [UDP]) INVITE sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
13:17:03 1A [CRequest::CRequest] Creation of a request (RECEIVED FROM NETWORK)
13:17:03 [CAdnsMngt::checkHostInBlackList] host=192.168.30.31 alcResult= 0
13:17:03 [CAdnsMngt::checkHostInBlackList] host=192.168.30.31 alcResult= 0
13:17:03 [CDispatcher::onIncomingRequest()]
13:17:03 [CDispatcher::processRequestFromManagerIndex()] start at index 0
13:17:03 101 [CCallManager::onIncomingRequest()]
13:17:03 101 [CCallManager::onIncomingRequest()] creates a new Call if this request doesn't refer to any old call
13:17:03 ========> [CSipTcCall::CSipTcCall]
13:17:03 ========> [CSipTcCall::CSipTcCall] LegId=0
13:17:03 ========> [CSipTcCallManager::callFactory] CSiptTcCall created
13:17:03 1110 [CCall::receiveRequest] INVITE
13:17:03 1510 [CDialog::receiveRequest]
13:17:03 1510 [CDialog::receiveInviteRequest]
13:17:03 1510 [CDialog::onTransactionState(pTrans = 2110, previousState = Terminated, currentState = Initial, reason = None]
13:17:03 2110 [CTransInitialState::receiveRequest] Transaction changes to Proceeding state
13:17:03 1510 [CDialog::onTransactionState(pTrans = 2110, previousState = Initial, currentState = Proceeding, reason = Request reception]
13:17:03 1A [CResponse::CResponse] Creation of a response
13:17:03 1A [CResponse::create] RESPONSE CREATION
13:17:03 1A [CResponse::checkStatusLine] Create StatusLine from code given as parameter
13:17:03 1A [CResponse::createViaHeaders] Copy Via headers from previous request (number : 1)
13:17:03 1A [CMessage::getHeaderAtIndexFromSipMessage(Timestamp, 0)] sip_getHeaderAtIndex FAILED => HSS ERROR No exist
13:17:03 1A [CResponse::create] Initialize context (Local = To & Remote = From)
13:17:03 1A [CMessage::send] sip_sendMessage (192.168.30.31:5060)
13:17:03 SEND MESSAGE TO NETWORK (192.168.30.31:5060 [UDP]) (BUFF LEN = 337)
----------------------utf8-----------------------
SIP/2.0 100 Trying
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
CSeq: 31090765 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
Content-Length: 0

-------------------------------------------------
13:17:03 SEND (192.168.30.31:5060 [UDP] SIP/2.0 100 Trying
13:17:03 [CTransport::findConnection] pConnection = f003 remoteHost=192.168.30.31, remotePort=5060
13:17:03 [CTransport::getConnection] RemoteHost=(192.168.30.31 5060) already exist, using connection f003
13:17:03 Tcl_OpenUdpClient (192.168.30.31,5060)
13:17:03 Tcl_OpenUdpClient reuse existing socket=10
13:17:03 udp_send fd:10
13:17:03 udp_send fd:10 port 5060 iBytesSend:337 message:SIP/2.0 100 Trying
To: <sip:8097@node001001;user=phone>
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
CSeq: 31090765 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
Content-Length: 0

13:17:03 f003 [CConnection::resetConnectionTimer] Creating the activity timer
13:17:03 [sip_freeEventContext]
13:17:03 1510 [CDialog::receiveInviteRequest] a new Server INVITE transaction is in progress
13:17:03 [CSessionTimerContext::CSessionTimerContext] New CSessionTimerContext from request (Server, UA)
13:17:03 [CSessionTimerContext::updateAfterRefreshReception] Update CSessionTimerContext (refresh reception)
13:17:03 [CSessionTimerContext::updateSupported] Request timer supported
13:17:03 [CSessionTimerContext::updateMinSE] Min-SE updated : 900
13:17:03 [CSessionTimerContext::updateSessionExpires] header value : 1800
13:17:03 [CSessionTimerContext::updateSessionExpires] updated
13:17:03 [CSessionTimerContext::updateSessionExpires] Refresher updated : r
13:17:03 [CSessionTimerContext::updateSessionExpires] Session-Expires updated : 1800
13:17:03 [CSessionTimerContext::setRefreshMethod] Allow refreshMethod=UPDATE
13:17:03 1510 [CDialog::addTransaction] added transaction 2110 with branch z9hG4bKb5958c23d3c3fb341351f94a8826b2a8, with CSeq 31090765
13:17:03 1110 [CCall::checkAuthentication] INVITE
13:17:03 ========> [CSipTcCall::onReceiveRequest]
13:17:03 ========> [CSipTcCall::checkRequireHeaders]
13:17:03 ========> [CSipTcCall::onReceiveRequest] receive INVITE method
13:17:03 ========> [CSipTcCall::onReceiveRequest] INVITE case
13:17:03 ========> [CSipTcCall::onReceiveRequest] call sipToUsNotification with RING verb
13:17:03 ========> [CSipTcCall::SipToUsNotification]
13:17:03 CPI_GMsg::SetVerb ok
13:17:03 [CSipMediaDescription::parseFormatString] Got 3 format(s) from string 18 8 97
13:17:03 append attr : Media: audio/192.168.30.33:32656
13:17:03 append attr : Codecs: audio/g729,audio/g711Alaw64k,audio/telephone-event/8000:97
13:17:03 87ef [CSipAddrSpec::getAddrSpecAsString]
13:17:03 ========> [CSipTcCall::SipToUsNotification] To (escaped)=sip:8097@node001001;user=phone
13:17:03 ========> [CSipTcCall::SipToUsNotification] To (unescaped)=sip:8097@node001001;user=phone
13:17:03 append attr : Destination: sip:8097@node001001;user=phone
13:17:03 1A [CMessage::getAssertedIdCount] need to create the wrapper
13:17:03 1A [CMessage::createAssertedIdWrapperFromMessage]
13:17:03 1A [CMessage::createAssertedIdWrapperFromMessage] there is 0 P-Asserted-Identity header in the message
13:17:03 87ee [CSipAddrSpec::getAddrSpecAsString]
13:17:03 ========> [CSipTcCall::SipToUsNotification] From (escaped)=sip:3333@192.168.30.31;user=phone
13:17:03 ========> [CSipTcCall::SipToUsNotification] From (unescaped)=sip:3333@192.168.30.31;user=phone
13:17:03 append attr : Caller: sip:3333@192.168.30.31;user=phone
13:17:03 append attr : Caller-Name: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>
13:17:03 append attr : Call-Ref-Number: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
13:17:03 87f2 [CSipAddrSpec::getAddrSpecAsString]
13:17:03 append attr : Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:17:03 append attr : Leg-Id: 0
13:17:03 ========> [CSipTcCall::sipToUsNotification] find P-Alcatel-CSBU = categparty=internal;call_condition=localdirect
13:17:03 append attr : Alcatel-Attr-Supp: categparty=internal;call_condition=localdirect
13:17:03 append attr : User-Information: OmniPCX Enterprise R10.0 j1.410.34
13:17:03 append attr : Accept-Language: en
13:17:03 ========> [CSipTcCall::sipToUsNotification] send message to us
13:17:03 us_rcve: protocol:0, leg_id:0
13:17:03 <- RING 20
13:17:03 <- Media: audio/192.168.30.33:32656
13:17:03 <- Codecs: audio/g729,audio/g711Alaw64k,audio/telephone-event/8000:97
13:17:03 <- Destination: sip:8097@node001001;user=phone
13:17:03 <- Caller: sip:3333@192.168.30.31;user=phone
13:17:03 <- Caller-Name: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>
13:17:03 <- Call-Ref-Number: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
13:17:03 <- Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:17:03 <- Leg-Id: 0
13:17:03 <- Alcatel-Attr-Supp: categparty=internal;call_condition=localdirect
13:17:03 <- User-Information: OmniPCX Enterprise R10.0 j1.410.34
13:17:03 <- Accept-Language: en
13:17:03 ~CPI_GMsg refcount=2
13:17:03 us-handle sip 0 RING
13:17:03 registration to 'sip:8097' expired
13:17:03 unix-send: on channel sock13 (toward MS 192.168.30.170)
13:17:03 -> CALL 65
13:17:03 -> Media: audio/192.168.30.33:32656
13:17:03 -> Codecs: audio/g729,audio/g711Alaw64k,audio/telephone-event/8000:97
13:17:03 -> Destination: sip:8097@node001001;user=phone
13:17:03 -> Caller: sip:3333@192.168.30.31;user=phone
13:17:03 -> Caller-Name: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>
13:17:03 -> Call-Ref-Number: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
13:17:03 -> Transport-Address: sip:8097@192.168.30.170:5070;transport=UDP
13:17:03 -> Alcatel-Attr-Supp: categparty=internal;call_condition=localdirect
13:17:03 -> User-Information: OmniPCX Enterprise R10.0 j1.410.34
13:17:03 -> Accept-Language: en
13:17:03 CPUUsed size=1
13:17:03 CPUUsed (0)=A
13:17:03 RedMsg size=0
13:17:03 req size=1
13:17:03 req (65)=0
13:17:03 proto size=1
13:17:03 proto (0)=sip
13:17:03 reverse size=0
13:17:03 state size=1
13:17:03 state (0)=arriving
13:17:03 rep_notif size=0
13:17:03 registrar size=5
13:17:03 registrar (sip:8091)=us:127.0.0.1 14400
13:17:03 registrar (sip:8092)=us:127.0.0.1 14400
13:17:03 registrar (sip:8097)=us:127.0.0.1 14400
13:17:03 registrar (sip:8093)=us:127.0.0.1 14400
13:17:03 registrar (sip:8090)=us:127.0.0.1 14400
13:17:03 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:17:03 <- BUSY 65
13:17:03 us-handle us -1 BUSY
13:17:03 BUSY (MAKECALL context)
13:17:03 us_send: protocol:0, leg_id:0
13:17:03 -> HANGUP 66
13:17:03 -> Leg-Id: 0
13:17:03 -> Reason: Busy
13:17:03 ========> [CSipTcCallManager::siptc] receive message from us
13:17:03 CPI_GMsg list refcount:3 internal list :
13:17:03 HANGUP 66
13:17:03 Leg-Id: 0
13:17:03 Reason: Busy
13:17:03 ========> [CSipTcCallManager::onReceiveUSRequest]
13:17:03 ========> [CSipTcCall::onReceiveUS]
13:17:03 CPI_GMsg list refcount:4 internal list :
13:17:03 HANGUP 66
13:17:03 Leg-Id: 0
13:17:03 Reason: Busy
13:17:03 ========> [CSipTcCall::onReceiveUS] receive a request=7
13:17:03 ========> [CSipTcCall::onReceiveUS] receive HANGUP on state = 1
13:17:03 ========> [CSipTcCall::onReceiveUS] rec HANGUP on IN_PROGRESS_INVITE state, send 486 or 480
13:17:03 1110 [CCall::makeGenericResponse] 486
13:17:03 1510 [CDialog::createResponse] 486
13:17:03 1B [CResponse::CResponse] Creation of a response
13:17:03 1B [CResponse::create] RESPONSE CREATION
13:17:03 1B [CResponse::checkStatusLine] Create StatusLine from code given as parameter
13:17:03 1B [CResponse::createToHeader] Initialize To TAG from context
13:17:03 1B [CResponse::createToHeader] Creation a tag for To header
13:17:03 1B [CResponse::createViaHeaders] Copy Via headers from previous request (number : 1)
13:17:03 1B [CResponse::create] Initialize context (Local = To & Remote = From)
13:17:03 1B [CMessage::send] sip_sendMessage (192.168.30.31:5060)
13:17:03 SEND MESSAGE TO NETWORK (192.168.30.31:5060 [UDP]) (BUFF LEN = 377)
----------------------utf8-----------------------
SIP/2.0 486 Busy Here
To: <sip:8097@node001001;user=phone>;tag=42c49f15bfd84d2bf08ce8eed2e1050f
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
CSeq: 31090765 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
Content-Length: 0

-------------------------------------------------
13:17:03 SEND (192.168.30.31:5060 [UDP] SIP/2.0 486 Busy Here
13:17:03 [CTransport::findConnection] pConnection = f003 remoteHost=192.168.30.31, remotePort=5060
13:17:03 [CTransport::getConnection] RemoteHost=(192.168.30.31 5060) already exist, using connection f003
13:17:03 udp_send fd:10
13:17:03 udp_send fd:10 port 5060 iBytesSend:377 message:SIP/2.0 486 Busy Here
To: <sip:8097@node001001;user=phone>;tag=42c49f15bfd84d2bf08ce8eed2e1050f
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
CSeq: 31090765 INVITE
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
Content-Length: 0

13:17:03 f003 [CConnection::resetConnectionTimer] Creating the activity timer
13:17:03 [sip_freeEventContext]
13:17:03 1A [~CResponse] resp(100) 94b73e204302cf0795bfefa6054ddec3@192.168.30.31 31090765 INVITE
13:17:03 2110 [CTransProceedingState::createResponse] Final : Transaction changes to Completed state
13:17:03 1510 [CDialog::onTransactionState(pTrans = 2110, previousState = Proceeding, currentState = Completed, reason = Final resp creation]
13:17:03 1510 [CDialog::updateRouteSet] there are 0 record-route headers
13:17:03 ========> [CSipTcCall::sendUsReply] send to us the reply 71
13:17:03 CPI_GMsg::SetVerb ok
13:17:03 append attr : Leg-Id: 0
13:17:03 us_rcve: protocol:0, leg_id:0
13:17:03 <- OK 66
13:17:03 <- Leg-Id: 0
13:17:03 ~CPI_GMsg refcount=2
13:17:03 CPI_GMsg::SetVerb ok
13:17:03 append attr : Leg-Id: 0
13:17:03 us_rcve: protocol:0, leg_id:0
13:17:03 <- DROPPED 21
13:17:03 <- Leg-Id: 0
13:17:03 ~CPI_GMsg refcount=2
13:17:03 ~CPI_GMsg refcount=4
13:17:03 ~CPI_GMsg refcount=3
13:17:03 clean-leg 0
13:17:03 CPUUsed size=0
13:17:03 RedMsg size=0
13:17:03 req size=0
13:17:03 proto size=0
13:17:03 reverse size=0
13:17:03 state size=0
13:17:03 rep_notif size=0
13:17:03 registrar size=5
13:17:03 registrar (sip:8091)=us:127.0.0.1 14400
13:17:03 registrar (sip:8092)=us:127.0.0.1 14400
13:17:03 registrar (sip:8097)=us:127.0.0.1 14400
13:17:03 registrar (sip:8093)=us:127.0.0.1 14400
13:17:03 registrar (sip:8090)=us:127.0.0.1 14400
13:17:03 udp_recv fd:10
13:17:03 udp_recv fd:10 iBytesRead:407 message:ACK sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
To: <sip:8097@node001001;user=phone>;tag=42c49f15bfd84d2bf08ce8eed2e1050f
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
CSeq: 31090765 ACK
Content-Length: 0

13:17:03 UdpInputProc iSock:10 iBytesRead:407 Host:192.168.30.31 Port:5060
13:17:03 [CTransportUdp::receiveMessage] from 192.168.30.31:5060 rc:407
13:17:03 [CTransport::findConnection] pConnection = f003 remoteHost=192.168.30.31, remotePort=5060
13:17:03 f003 [CConnection::dOSTest](192.168.30.31,5060,0) MaxNbMsgByPeriod:40 Period:3
13:17:03 f003 [CConnection::dOSTest](192.168.30.31,5060,0) NbMsg:1 < seuil
13:17:03 f003 [CConnection::resetConnectionTimer] Creating the activity timer
13:17:03 RECEIVE MESSAGE FROM NETWORK (192.168.30.31:5060 [UDP])
----------------------utf8-----------------------
ACK sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
Call-ID: 94b73e204302cf0795bfefa6054ddec3@192.168.30.31
From: "REYNALDO GIRALD" <sip:3333@192.168.30.31;user=phone>;tag=a19e34235859a09dd72addc2a13f9591
To: <sip:8097@node001001;user=phone>;tag=42c49f15bfd84d2bf08ce8eed2e1050f
Via: SIP/2.0/UDP 192.168.30.31;branch=z9hG4bKb5958c23d3c3fb341351f94a8826b2a8
CSeq: 31090765 ACK
Content-Length: 0

-------------------------------------------------

13:17:03 RECEIVE (192.168.30.31:5060 [UDP]) ACK sip:8097@192.168.30.170:5070;transport=UDP SIP/2.0
13:17:03 1B [CRequest::CRequest] Creation of a request (RECEIVED FROM NETWORK)
13:17:03 [CAdnsMngt::checkHostInBlackList] host=192.168.30.31 alcResult= 0
13:17:03 [CAdnsMngt::checkHostInBlackList] host=192.168.30.31 alcResult= 0
13:17:03 [CDispatcher::onIncomingRequest()]
13:17:03 [CDispatcher::processRequestFromManagerIndex()] start at index 0
13:17:03 101 [CCallManager::onIncomingRequest()]
13:17:03 1110 [CCall::receiveRequest] ACK
13:17:03 1510 [CDialog::receiveRequest]
13:17:03 1510 [CDialog::receiveAckRequest]
13:17:03 2110 [CTransCompletedState::receiveRequest] ACK(UDP) : Transaction changes to Confirmed state
13:17:03 1510 [CDialog::onTransactionState(pTrans = 2110, previousState = Completed, currentState = Confirmed, reason = Request reception]
13:17:03 1510 [CDialog::receiveAckRequest] receiving an ACK on a previously rejected INVITE
13:17:03 1110 [CCall::checkAuthentication] ACK
13:17:03 ========> [CSipTcCall::onReceiveRequest]
13:17:03 ========> [CSipTcCall::checkRequireHeaders]
13:17:03 ========> [CSipTcCall::onReceiveRequest] receive ACK method
13:17:03 ========> [CSipTcCall::onReceiveRequest] receive ACK on bad state SipTcCall
13:17:03 us-handle sip 0 OK
13:17:03 CPUUsed size=0
13:17:03 RedMsg size=0
13:17:03 req size=0
13:17:03 proto size=0
13:17:03 reverse size=0
13:17:03 state size=0
13:17:03 rep_notif size=0
13:17:03 registrar size=5
13:17:03 registrar (sip:8091)=us:127.0.0.1 14400
13:17:03 registrar (sip:8092)=us:127.0.0.1 14400
13:17:03 registrar (sip:8097)=us:127.0.0.1 14400
13:17:03 registrar (sip:8093)=us:127.0.0.1 14400
13:17:03 registrar (sip:8090)=us:127.0.0.1 14400
13:17:03 us-handle sip 0 DROPPED
13:17:03 CPUUsed size=0
13:17:03 RedMsg size=0
13:17:03 req size=0
13:17:03 proto size=0
13:17:03 reverse size=0
13:17:03 state size=0
13:17:03 rep_notif size=0
13:17:03 registrar size=5
13:17:03 registrar (sip:8091)=us:127.0.0.1 14400
13:17:03 registrar (sip:8092)=us:127.0.0.1 14400
13:17:03 registrar (sip:8097)=us:127.0.0.1 14400
13:17:03 registrar (sip:8093)=us:127.0.0.1 14400
13:17:03 registrar (sip:8090)=us:127.0.0.1 14400
13:17:03 unix-rcve: on channel sock13 (from MS 192.168.30.170)
13:17:03 <- LOGIN 0
13:17:03 <- Leg-Id: 1001
13:17:03 us-handle us 1001001 LOGIN
13:17:03 unix-send: on channel sock13 (toward MS 192.168.30.170)
13:17:03 -> READY 67
13:17:03 -> Leg-Id: 1001
13:17:03 clean-leg 1001001
13:17:03 CPUUsed size=0
13:17:03 RedMsg size=0
13:17:03 req size=0
13:17:03 proto size=0
13:17:03 reverse size=0
13:17:03 state size=0
13:17:03 rep_notif size=0
13:17:03 registrar size=5
13:17:03 registrar (sip:8091)=us:127.0.0.1 14400
13:17:03 registrar (sip:8092)=us:127.0.0.1 14400
13:17:03 registrar (sip:8097)=us:127.0.0.1 14400
13:17:03 registrar (sip:8093)=us:127.0.0.1 14400
13:17:03 registrar (sip:8090)=us:127.0.0.1 14400
13:17:08 2110 [CTransConfirmedState::timerFires] TimerI : Transaction changes to Terminated state
13:17:08 1510 [CDialog::onTransactionState(pTrans = 2110, previousState = null, currentState = Terminated, reason = Timer I fires]
13:17:08 1110 [CCall::onDialogClosed]
13:17:08 1110 [CCall::onDialogClosed] only initial *********
13:17:08 1110 [CCall] closed
13:17:08 101 [CCallManager::onCallClosed]
13:17:08 101 [CCallManager::onCallClosed()] Call 1110 closed. Removing call 169188152 from the maps
13:17:08 2110 [~CTransaction] transaction 31090765 INVITE
13:17:08 1B [~CRequest] req 94b73e204302cf0795bfefa6054ddec3@192.168.30.31 31090765 ACK
13:17:08 101 [CCallManager::removeGarbage] at index i = 0
13:17:08 ========> [CSipTcCall::~CSipTcCall] unregister the legId on US
13:17:08 1110 [CCall::~CCall]
13:17:08 1510 [CDialog::~CDialog]
13:17:08 [CSessionTimerContext::~CSessionTimerContext] Free CSessionTimerContext
13:17:08 1B [~CResponse] resp(486) 94b73e204302cf0795bfefa6054ddec3@192.168.30.31 31090765 INVITE
13:17:08 1A [~CRequest] req 94b73e204302cf0795bfefa6054ddec3@192.168.30.31 31090765 INVITE

Media Server global status
global information
number of connected RMS : 1
OXE (main): 192.168.30.31
registered services : 8097 8093 8090 8091 8092
connected modules status
MS module 192.168.30.170 (Primary) : NOK - (SIP server : OK/0 - RMS : OK/0 - RS : NOK)
Media Server global status : NOK
Notes:
Only local SIP server is seen. In case of redundant SIP server configuration, you must connect to the other one to know its status.
Only connected MS modules could be seen through this page.
MSA state is not indicated here.

[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/AL/
al-alarm.txt al-err.old al-err.old-1 al-err.txt al-obs.txt al-stderr.txt rms.lock
[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/AL/
al-alarm.txt al-err.old al-err.old-1 al-err.txt al-obs.txt al-stderr.txt rms.lock
[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/AL/al-alarm.txt
23 Jan 2012 12:59:03,924 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1468) | SIP service registration request : Service 8090
23 Jan 2012 12:59:03,926 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1468) | SIP service registration request : Service 8093
23 Jan 2012 12:59:03,928 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1468) | SIP service registration request : Service 8091
23 Jan 2012 12:59:03,929 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1468) | SIP service registration request : Service 8092
23 Jan 2012 12:59:03,931 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1468) | SIP service registration request : Service 8097
23 Jan 2012 12:59:03,932 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1345) | SIP service registration : Service 8090 is registered for 14400(14400) seconds
23 Jan 2012 12:59:03,978 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1345) | SIP service registration : Service 8093 is registered for 14400(14400) seconds
23 Jan 2012 12:59:03,979 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1345) | SIP service registration : Service 8091 is registered for 14400(14400) seconds
23 Jan 2012 12:59:03,981 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1345) | SIP service registration : Service 8092 is registered for 14400(14400) seconds
23 Jan 2012 12:59:03,982 ALL [[Session Manager]] - alarms.mediaServer.al (ApSessionMgr.java:1345) | SIP service registration : Service 8097 is registered for 14400(14400) seconds

root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/
tail: error reading `/opt/Alcatel-Lucent/logs/MediaServer/MSAccess/': Is a directory
tail: /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/: cannot follow end of this type of file; giving up on this name
tail: no files remaining
[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/msa
msa-alarm.txt msa.log msa-stderr.txt
[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/msa.log
16 Jan 2012 20:11:20,630 ERROR [RMI TCP Connection(3)-192.168.30.170] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
17 Jan 2012 10:55:20,667 ERROR [main] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
17 Jan 2012 11:19:02,772 ERROR [main] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
17 Jan 2012 11:25:05,273 ERROR [RMI TCP Connection(3)-192.168.30.170] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
20 Jan 2012 17:14:04,364 ERROR [RMI TCP Connection(3)-192.168.30.170] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
20 Jan 2012 17:16:33,536 ERROR [main] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
20 Jan 2012 17:20:04,183 ERROR [main] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
20 Jan 2012 17:42:24,581 ERROR [main] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
20 Jan 2012 19:56:46,001 ERROR [main] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001
20 Jan 2012 21:02:45,387 ERROR [RMI TCP Connection(3)-192.168.30.170] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001

root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/msa
msa-alarm.txt msa.log msa-stderr.txt
[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/msa-alarm.txt
23 Jan 2012 12:56:28,195 ALL [Thread-4] - alarms.mediaServer.msa (?:?) | SIP Server bad status - reason : [SIP:NOK;]
23 Jan 2012 12:57:04,974 ALL [main] - alarms.mediaServer.msa (?:?) | DataAccess link ready
23 Jan 2012 12:57:05,793 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access starting
23 Jan 2012 12:57:05,813 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access started
23 Jan 2012 12:58:47,282 ALL [RMI TCP Connection(2)-192.168.30.170] - alarms.mediaServer.msa (?:?) | Administration notification received
23 Jan 2012 12:58:47,289 ALL [RMI TCP Connection(2)-192.168.30.170] - alarms.mediaServer.msa (?:?) | DataAccess link ready
23 Jan 2012 12:58:56,919 ALL [main] - alarms.mediaServer.msa (?:?) | DataAccess link ready
23 Jan 2012 12:58:57,762 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access starting
23 Jan 2012 12:58:57,774 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access started
23 Jan 2012 13:03:57,873 ALL [Thread-4] - alarms.mediaServer.msa (?:?) | Resource Server bad status - reason : [SIP:OK;AL:OK;RS:NOK;]

[root@ucv ~]# tail -f /opt/Alcatel-Lucent/logs/MediaServer/MSAccess/msa-alarm.txt
23 Jan 2012 12:56:28,195 ALL [Thread-4] - alarms.mediaServer.msa (?:?) | SIP Server bad status - reason : [SIP:NOK;]
23 Jan 2012 12:57:04,974 ALL [main] - alarms.mediaServer.msa (?:?) | DataAccess link ready
23 Jan 2012 12:57:05,793 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access starting
23 Jan 2012 12:57:05,813 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access started
23 Jan 2012 12:58:47,282 ALL [RMI TCP Connection(2)-192.168.30.170] - alarms.mediaServer.msa (?:?) | Administration notification received
23 Jan 2012 12:58:47,289 ALL [RMI TCP Connection(2)-192.168.30.170] - alarms.mediaServer.msa (?:?) | DataAccess link ready
23 Jan 2012 12:58:56,919 ALL [main] - alarms.mediaServer.msa (?:?) | DataAccess link ready
23 Jan 2012 12:58:57,762 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access starting
23 Jan 2012 12:58:57,774 ALL [main] - alarms.mediaServer.msa (?:?) | MS Access started
23 Jan 2012 13:03:57,873 ALL [Thread-4] - alarms.mediaServer.msa (?:?) | Resource Server bad status - reason : [SIP:OK;AL:OK;RS:NOK;]

Post by **cavagnaro** » 24 Jan 2012 09:19

Ok,
So we can establish that SIP layer is ok, what is wrong is MS one...
Check this error:

20 Jan 2012 21:02:45,387 ERROR [RMI TCP Connection(3)-192.168.30.170] (?:?) - EXCEPTION in MsDataAccess/getIPAddress: java.net.UnknownHostException: node001001

So please double check your configuration and name resolution
Also, you have already installed TTS engine and language packages...right?

Felipe.Herrera · Post by **Felipe.Herrera** » 24 Jan 2012 11:19

thanks, Cavagnaro.
Over engine TTS is not installed. In the CD installer for TTS no find el file rs-api-4.0-8.i386.rpm

Good Bless

Post by **cavagnaro** » 24 Jan 2012 12:01

It is another disk, or download it from BPWS

Felipe.Herrera · Post by **Felipe.Herrera** » 24 Jan 2012 12:20

Thanks. Cavagnaro.
already resolved this problem. Download the files for TTS API from BPWS
The Media Server is OK.

global information
number of connected RMS : 1
OXE (main): 192.168.30.31
registered services : 8097 8093 8090 8091 8092

connected modules status
MS module 192.168.30.170 (Primary) : OK - (SIP server : OK/0 - RMS : OK/0 - RS : OK/0)

Media Server global status : OK

The call establish with the directory numver UM successfull.

Very Thanks

Alcatel Unleashed

Problem Calling UM voice mail at 8400 uc

Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc

Re: Problem Calling UM voice mail at 8400 uc