cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
673
Views
1
Helpful
14
Replies

SIP REGISTER fails with 580 but server has no logs

r0nh
Level 1
Level 1

I am trying to send a SIP REGISTER and it fails with 580.

I cannot find out how to determine what is being denied. ie: what i am sending wrong that could result in a 580

is there a way in CUCM to find in a  log file somewhere what might be wrong with the packet.

Thanks for anyone reading this.

 

REGISTER sip:192.168.30.220 SIP/2.0
Via: SIP/2.0/TCP 192.168.208.157:63047;branch=95a1b2a72b10418a3f3f
Contact: <sip:44d955db-d9d4-f630-fe5e-01686318fe2d@192.168.208.157:63047;transport=tcp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-A45630BB643A>";+u.sip!devicename.ccm.cisco.com="SEPA45630BB643A";+u.sip!model.ccm.cisco.com="436"
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-6.0.0,X-cisco-xsi-8.5.1
Max-Forwards: 70
Expires: 120
Mime-Version: 1.0
Reason: SIP;cause=200;text="cisco-alarm:23 Name=SEPA45630BB643A Load=SIP45.9-4-2SR4-3S Last=reset-restart"
Content-Type: multipart/mixed; boundary=uniqueBoundary
To: <sip:1247@192.168.30.220>
From: <sip:1247@192.168.30.220>;tag=00007ff77ba8d355
Call-ID: 44d955db-d9d4-f630-fe5e-01686318fe2d@192.168.208.157
CSeq: 2999 REGISTER
Date: Fri, 15 Mar 2024 02:29:31 GMT
User-Agent: Cisco-CP7965G//9.4.2
Content-Length: 1356

--uniqueBoundary
Content-Type: application/x-cisco-remotecc-request+xml
Content-Disposition: session;handling=optional

<?xml version="1.0" encoding="UTF-8"?>
<x-cisco-remotecc-request>
<bulkregisterreq>
<contact all="true">
<register></register>
</contact>
</bulkregisterreq>
</x-cisco-remotecc-request>

--uniqueBoundary
Content-Type: application /x-cisco-remotecc-request + xml
Content-Disposition: session; handling = optional

<?xml version="1.0" encoding="UTF-8"?>
<x-cisco-remotecc-request>
<optionsind>
<combine max="6">
<remotecc>
<status></status>
</remotecc>
<service-control></service-control>
</combine>
<dialog usage="hook status">
<unot></unot>
<sub></sub>
</dialog>
<dialog usage="shared line">
<unot></unot>
<sub></sub>
</dialog>
<presence usage = "blf speed dial">
<unot></unot>
<sub></sub>
</presence>
<joinreq></joinreq>
<cfwdall-anyline>No</cfwdall-anyline>
<coaching></coaching>
<oosalarm></oosalarm>
<rpid-orig-called>
</rpid-orig-called>
</optionsind>
</x-cisco-remotecc-request>

--uniqueBoundary--

 

14 Replies 14

A 580 is a "precondition failure" meaning CUCM could not service some aspect of the registration message. (Super helpful, eh?) It could be model, MAC, firmware, or a host of other things. Can you post the 500 error message? That might have more information.

Maren

Here is a doc describing troubleshooting phone registration in CUCM. Much of it is easy stuff, but the doc does describe what logs to collect and how to do that:

Troubleshoot IP Phone Unregistration Issues in CUCM - https://www.cisco.com/c/en/us/support/docs/unified-communications/unified-communications-manager-version-115/220670-troubleshoot-ip-phone-unregistration-iss.html 

Maren

Thank you we have tried almost all of these solutions in the documentation. Nothing showed even a trace of the device showing up as being rejected. But we do get response from the server (as posted above) but none of these logs even show the rejection. I have tried the event logs as well. I see other devices registering but nothing about the rejection. or 580 error indicating anything that might be wrong. And i have tried everything like using the IP address instead of the host. various changes in the supports User-Agent etc. but i am just guessing.

The above looks like the REGISTER message coming from the phone and not the 580 response from the server. Am I missing something?

Are you saying that the CallManager trace file does not have this REGISTER message in it? If it does include it, can you post (as an attachment to your reply) the trace file so we can see what's going on in CUCM that would generate a 580?

Maren

I do not have any logs on the server side. I did look at them but i cannot find any rejection or anything with this device or any type of error message for this device in the logs. The only reason i know it is a 580 is my wireshark trace.  

Can you please share a screenshot of the trace settings you have for the call manager service? If you don’t have any SDL logs at all then likely you might have deselected all options and unchecked that logs are enabled. If that’s the case you may want to use the option to reset it to default values and then select to set that on all the nodes in the cluster. But before you do that please take a screenshot of this page and share it here.



Response Signature


Here are my settings. 

It does download the cnf.xml file and then sends the sip REGISTER

so i know it is actually connecting to the backend. I 

Ok so we set everything and I found this

00758914.036 |14:21:29.832 |AppInfo |//SIP/Stack/States/0x0xe39f8778/sipSPIChangeState: 0xe39f8778 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_INCOMING_REGISTER, SUBSTATE_NONE)
00758917.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPTcp(1,100,191,1) |SIPHandler(1,100,183,1) |1,100,251,393.2^192.168.208.157^* |*TraceFlagOverrode
00758917.001 |14:21:29.832 |AppInfo |SIPTcp - Did not find table entry in Send Msg, Index = 387
00758917.002 |14:21:29.832 |AppInfo |SIPTcp - Notify SIP Stack table(0xe85c0030) invalid connection (387) with socket error!
00758918.000 |14:21:29.832 |SdlSig |SIPRegisterInd |wait |SIPStationInit(1,100,190,1) |SIPHandler(1,100,183,1) |1,100,251,393.2^192.168.208.157^* |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0] ccbID= 23253 --TransType=1 --TransSecurity=0 PeerAddr = 192.168.208.157:62466 MAC = DeviceName = X509SubjectName = SubjectAltname = UserId =
00758918.001 |14:21:29.832 |AppInfo |SIPStationInit: connId=387, SEP796579651111, bf4cb718-8b89-559b-d5fb-3553d12bf1fc@192.168.208.157:62465, New [dynamic] device registering over TCP transport
00758918.002 |14:21:29.832 |AppInfo |SIPStationInit: Txs handleCiscoReg inbound [connID=387, dev=SEP796579651111, instance=796579651111, contact=192.168.208.157:62465] gracefulReg 0 foundDev 0 expiresIsZero 0
00758918.003 |14:21:29.832 |AppInfo |SIPRegistrationTable::addToConnectionIndexTableInternal: Adding SEP796579651111 to connectionIndexTable
00758918.004 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, New targetEntry created
00758918.005 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, (RegTrace 0xe39e16a8) Enqueuing register for ccbID 23253
00758918.006 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, REGISTER Queued
00758918.007 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, DevStat-InitState: NEW --> ON_NEWREG_QUEUE
00758919.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758919.001 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 58 (SIPSPI_EV_SOCKET_ERROR)
00758919.002 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWSocketException: context=(nil)
00758919.003 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessSocketExceptions: gConnTab=0xe85c0030, addr=192.168.208.157, port=62466, connid=387, transpo
00758919.004 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0/sipConnectionManagerProcessSocketExceptions: Handling TCP reset for all contexts on connection
00758919.005 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0xe77c0768/sipConnectionManagerNotifyReset: Found gcbs on connection waitq
00758919.006 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportPostCloseConnection: Posting TCP conn close for addr=192.168.208.157, port=62466, connid=387
00758919.007 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipDeleteConnInstance: Deleted conn=0xe77c0768, connid=387, addr=192.168.208.157, port=62466, transport=TCP
00758920.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPTcp(1,100,191,1) |SIPHandler(1,100,183,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758920.001 |14:21:29.832 |AppInfo |SIPTcp - Did not find table entry in Close Msg,Index = 387
00758921.000 |14:21:29.832 |SdlSig |SIPConnControlInd |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.3^*^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] controlOperation=1 IP=192.168.208.157 connIndex=387
00758921.001 |14:21:29.832 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/getRemoteAddrInfo: RemoteAddrInfo = 192.168.208.157:62466
00758922.000 |14:21:29.832 |SdlSig |SIPConnControlInd |wait |SIPStationInit(1,100,190,1) |SIPHandler(1,100,183,1) |1,100,251,393.3^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] controlOperation=1 IP=192.168.208.157 connIndex=387
00758922.001 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, Received SIPConnControlInd on a non-shared connection
00758922.002 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, DevStat-InitState: ON_NEWREG_QUEUE --> CONN_CONTROL_RCVD
00758922.003 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, processSIPConnControlInd: No Dpid assigned, removing entry e39e16a8
00758922.004 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, (RegTrace 0xe39e16a8) Rejecting register for ccbID 23253
00758922.005 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, Removing targetEntry
00758922.006 |14:21:29.832 |AppInfo |SIPRegistrationTable::remove: Removing SEP796579651111 from connectionIndexTable
00758922.007 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, Dropping the connection
00758922.008 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, DevStat-InitState: CONN_CONTROL_RCVD --> DELETING
00758923.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.2^192.168.208.157^* |*TraceFlagOverrode
00758923.001 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 58 (SIPSPI_EV_SOCKET_ERROR)
00758923.002 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWSocketException: context=0xe85c0030
00758923.003 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessSocketExceptions: gConnTab=0xe85c0030, addr=192.168.208.157, port=62466, connid=387, transpo
00758923.004 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessSocketExceptions: Could not find connection for addr=192.168.208.157, port=62466
00758924.000 |14:21:29.833 |SdlSig |SIPRegisterResp |wait |SIPHandler(1,100,183,1) |SIPStationInit(1,100,190,1) |1,100,251,393.3^*^* |[T:N-H:0,N:0,L:0,V:0,Z:1,D:0] ccbID= 23253 --TransType=1 --TransSecurity=0 PeerAddr= 192.168.208.157:62465 respCode= 580 action= 2 device=
00758924.001 |14:21:29.833 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPRegisterResp: ++++++ Decrememted gSipNewRegPendingNum to 0
00758924.002 |14:21:29.833 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 43 (SIPSPI_EV_REGISTER_RESP)
00758924.003 |14:21:29.833 |AppInfo |//SIP/Stack/Info/0x0xe39f8778/sipSPISendResponse: Associated container=0xe3e3f730 to REGISTER Response 580
00758924.004 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipSPISendResponse: Sending REGISTER Response to the transport layer
00758924.005 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipSPITransportSendMessage: msg=0xe9825910, addr=192.168.208.157, port=62466, sentBy_port=62465, is_req=0, tran
00758924.006 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerGetConnectionIfExists: Connection not found for addr=192.168.208.157, port=62466
00758924.007 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipTransportLogicSendMsg: Cannot locate same connection as we received request on for
00758924.008 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportPostRequestConnection: Posting TCP conn create request for addr=192.168.208.157, port=62465, conte
00758924.009 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportSetConnWaitTimer: Wait timer set for connection=0xe74c00b8,addr=192.168.208.157, port=62465
00758924.010 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
00758924.011 |14:21:29.833 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: timerContext=0xe74c0104 type=SIP_TIMER_WAIT_CONNECT value=5000 retries=0
00758924.012 |14:21:29.833 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: timerContext=0xe74c0104 type=SIP_TIMER_WAIT_CONNECT value=5000 retries=0
00758924.013 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipCreateConnInstance: Created new initiated conn=0xe74c00b8, connid=-1, addr=192.168.208.157, port=62465, transport=
00758924.014 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceGetConnectionId: Registering gcb=0xe39f8778 with connection=0xe74c00b8
00758924.015 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipTransportLogicSendMsg: Waiting for Connection for sending msg=0xe9825910
00758924.016 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipSPITransportSendMessage: Deferred sending msg=0xe9825910
00758925.000 |14:21:29.833 |SdlSig |SIPSPISignal |wait |SIPTcp(1,100,191,1) |SIPHandler(1,100,183,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758925.001 |14:21:29.833 |AppInfo |SIPTcp - SIPSPI_EV_CREATE_CONNECTION: Addr=192.168.208.157, Port=62465, globalTCPInst=0xe85c0030
00758926.000 |14:21:29.833 |SdlSig |SdlConnectReq |started |SdlTCPService(1,100,254,1) |SIPTcp(1,100,191,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758926.001 |14:21:29.833 |Created | | |SdlTCPConnector(1,100,252,117) |SdlTCPService(1,100,254,1) | |NumOfCurrentInstances: 1
00758927.000 |14:21:29.833 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758927.001 |14:21:29.833 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 59 (SIPSPI_EV_CONNECTION_CREATED)
00758927.002 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessConnCreated: gConnTab=0xe85c0030, addr=192.168.208.157, port=62465, connid=388, transport=TCP
00758927.003 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceHandleConnectionCreated: Moving connection=0xe74c00b8, connid=388state to pending
00758928.000 |14:21:29.833 |SdlSig |SIPConnControlReq |wait |SIPHandler(1,100,183,1) |SIPStationInit(1,100,190,1) |1,100,251,393.3^*^* |[T:Z-H:0,N:0,L:0,V:0,Z:0,D:0] controlOperation=1 transport=2 connIndex=387 listenerPort=0 remoteAddr Type=0
00758929.000 |14:21:29.833 |SdlSig |SIPConnControlReq |wait |SIPTcp(1,100,191,1) |SIPHandler(1,100,183,1) |1,100,251,393.3^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] controlOperation=1 transport=2 connIndex=387 listenerPort=0 remoteAddr Type=0
00758929.001 |14:21:29.833 |AppInfo |SIPTcp - Did not find table entry in connControlReq Index = 387
00758930.000 |14:21:29.908 |Created | | |SdlTCPConnection(1,100,251,394) |SdlTCPConnector(1,100,252,117) | |NumOfCurrentInstances: 11
00758931.000 |14:21:29.908 |Stopping | | |SdlTCPConnector(1,100,252,117) |SdlTCPConnector(1,100,252,117) | |NumOfCurrentInstances: 1
00758932.000 |14:21:29.908 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,252,117.1^*^* |*TraceFlagOverrode
00758932.001 |14:21:29.908 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 59 (SIPSPI_EV_CONNECTION_CREATED)
00758932.002 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessConnCreated: gConnTab=0xe85c0030, addr=192.168.208.157, port=62465, connid=388, transport=TCP
00758932.003 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportStopConnWaitTimer: Wait timer stopped for connection=0xe74c00b8,addr=192.168.208.157, port=62465
00758932.004 |14:21:29.908 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer: timerContext=0xe74c0104 type=SIP_TIMER_WAIT_CONNECT value=5000 retries=0
00758932.005 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0/sipInstanceHandleConnectionCreated: Moving connection=0xe74c00b8, connid=388state to established
00758932.006 |14:21:29.908 |AppInfo |//SIP/Stack/Error/0x0/sipInstanceHandleConnectionCreated: Notify gcb=0xe39f8778 that connection is available
00758932.007 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipTransportPostInternalMsg: Posting Internal Msg type=0
00758933.000 |14:21:29.908 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPHandler(1,100,183,1) |1,100,252,117.1^*^* |*TraceFlagOverrode
00758933.001 |14:21:29.908 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 64 (SIPSPI_EV_INTERNAL_MSG)
00758933.002 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipTransportPostSendMessage: Posting send for msg=0xe9825910, addr=192.168.208.157, port=62465, connId=388 for
00758933.003 |14:21:29.908 |AppInfo |//SIP/Stack/Info/0x0xe39f8778/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to b
00758933.004 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0xe85c0030, addr=192.168.208.157, port=62465, unregistering c
00758933.005 |14:21:29.908 |AppInfo |//SIP/Stack/Info/0x0xe39f8778/sipSPIUfreeOneCCB: Freeing ccb e39f8778
00758933.006 |14:21:29.908 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessInternalMsg: GCB has cleanedup, aborting send operation
00758934.000 |14:21:29.908 |SdlSig |SIPSPISignal |wait |SIPTcp(1,100,191,1) |SIPHandler(1,100,183,1) |1,100,252,117.1^*^* |*TraceFlagOverrode
00758934.001 |14:21:29.908 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.208.157 on port 62465 index 388
[49057,NET]
SIP/2.0 580 Precondition Failed
Via: SIP/2.0/TCP 192.168.208.157:62465;branch=49c30fb086802e6a6a5e
From: <sip:1247@hq-ucm125pub.corp.ipblue.com>;tag=5b810b2615301416
To: <sip:1247@hq-ucm125pub.corp.ipblue.com>;tag=1233128092
Date: Fri, 15 Mar 2024 18:21:29 GMT
Call-ID: bf4cb718-8b89-559b-d5fb-3553d12bf1fc@,68b52667562e06b4
CSeq: 18566 REGISTER
Content-Length: 0

 

Those are not the default values. I would recommend you to use the option to set the default values and set that to be used on all nodes. The second picture looks very odd as it’s set to show TFTP service, but the options shown are for the call manager service.



Response Signature


Thank you we changed the server settings and got some valuable information. i see the following do you know what this means. I am trying to figure out what might be wrong but you can see it decided  the 508. Hopefully it shows something.

 

00758918.001 |14:21:29.832 |AppInfo |SIPStationInit: connId=387, SEP796579651111, bf4cb718-8b89-559b-d5fb-3553d12bf1fc@192.168.208.157:62465, New [dynamic] device registering over TCP transport
00758918.002 |14:21:29.832 |AppInfo |SIPStationInit: Txs handleCiscoReg inbound [connID=387, dev=SEP796579651111, instance=796579651111, contact=192.168.208.157:62465] gracefulReg 0 foundDev 0 expiresIsZero 0
00758918.003 |14:21:29.832 |AppInfo |SIPRegistrationTable::addToConnectionIndexTableInternal: Adding SEP796579651111 to connectionIndexTable
00758918.004 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, New targetEntry created
00758918.005 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, (RegTrace 0xe39e16a8) Enqueuing register for ccbID 23253
00758918.006 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, REGISTER Queued
00758918.007 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, DevStat-InitState: NEW --> ON_NEWREG_QUEUE
00758919.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758919.001 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 58 (SIPSPI_EV_SOCKET_ERROR)
00758919.002 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWSocketException: context=(nil)
00758919.003 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessSocketExceptions: gConnTab=0xe85c0030, addr=192.168.208.157, port=62466, connid=387, transpo
00758919.004 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0/sipConnectionManagerProcessSocketExceptions: Handling TCP reset for all contexts on connection
00758919.005 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0xe77c0768/sipConnectionManagerNotifyReset: Found gcbs on connection waitq
00758919.006 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportPostCloseConnection: Posting TCP conn close for addr=192.168.208.157, port=62466, connid=387
00758919.007 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipDeleteConnInstance: Deleted conn=0xe77c0768, connid=387, addr=192.168.208.157, port=62466, transport=TCP
00758920.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPTcp(1,100,191,1) |SIPHandler(1,100,183,1) |1,100,251,393.3^*^* |*TraceFlagOverrode
00758920.001 |14:21:29.832 |AppInfo |SIPTcp - Did not find table entry in Close Msg,Index = 387
00758921.000 |14:21:29.832 |SdlSig |SIPConnControlInd |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.3^*^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] controlOperation=1 IP=192.168.208.157 connIndex=387
00758921.001 |14:21:29.832 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/getRemoteAddrInfo: RemoteAddrInfo = 192.168.208.157:62466
00758922.000 |14:21:29.832 |SdlSig |SIPConnControlInd |wait |SIPStationInit(1,100,190,1) |SIPHandler(1,100,183,1) |1,100,251,393.3^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] controlOperation=1 IP=192.168.208.157 connIndex=387
00758922.001 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, Received SIPConnControlInd on a non-shared connection
00758922.002 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, DevStat-InitState: ON_NEWREG_QUEUE --> CONN_CONTROL_RCVD
00758922.003 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, processSIPConnControlInd: No Dpid assigned, removing entry e39e16a8
00758922.004 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, (RegTrace 0xe39e16a8) Rejecting register for ccbID 23253
00758922.005 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, Removing targetEntry
00758922.006 |14:21:29.832 |AppInfo |SIPRegistrationTable::remove: Removing SEP796579651111 from connectionIndexTable
00758922.007 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, Dropping the connection
00758922.008 |14:21:29.832 |AppInfo |SIPStationInit: connID=387, SEP796579651111, 192.168.208.157:62465, DevStat-InitState: CONN_CONTROL_RCVD --> DELETING
00758923.000 |14:21:29.832 |SdlSig |SIPSPISignal |wait |SIPHandler(1,100,183,1) |SIPTcp(1,100,191,1) |1,100,251,393.2^192.168.208.157^* |*TraceFlagOverrode
00758923.001 |14:21:29.832 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 (SIP_NETWORK_MSG), for event 58 (SIPSPI_EV_SOCKET_ERROR)
00758923.002 |14:21:29.832 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportProcessNWSocketException: context=0xe85c0030
00758923.003 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessSocketExceptions: gConnTab=0xe85c0030, addr=192.168.208.157, port=62466, connid=387, transpo
00758923.004 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerProcessSocketExceptions: Could not find connection for addr=192.168.208.157, port=62466
00758924.000 |14:21:29.833 |SdlSig |SIPRegisterResp |wait |SIPHandler(1,100,183,1) |SIPStationInit(1,100,190,1) |1,100,251,393.3^*^* |[T:N-H:0,N:0,L:0,V:0,Z:1,D:0] ccbID= 23253 --TransType=1 --TransSecurity=0 PeerAddr= 192.168.208.157:62465 respCode= 580 action= 2 device=
00758924.001 |14:21:29.833 |AppInfo |//SIP/SIPHandler/ccbId=0/scbId=0/wait_SIPRegisterResp: ++++++ Decrememted gSipNewRegPendingNum to 0
00758924.002 |14:21:29.833 |AppInfo |//SIP/Stack/Info/0x0/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 (SIP_APPLICATION_MSG), for event 43 (SIPSPI_EV_REGISTER_RESP)
00758924.003 |14:21:29.833 |AppInfo |//SIP/Stack/Info/0x0xe39f8778/sipSPISendResponse: Associated container=0xe3e3f730 to REGISTER Response 580
00758924.004 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipSPISendResponse: Sending REGISTER Response to the transport layer
00758924.005 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipSPITransportSendMessage: msg=0xe9825910, addr=192.168.208.157, port=62466, sentBy_port=62465, is_req=0, tran
00758924.006 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipConnectionManagerGetConnectionIfExists: Connection not found for addr=192.168.208.157, port=62466
00758924.007 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0xe39f8778/sipTransportLogicSendMsg: Cannot locate same connection as we received request on for
00758924.008 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportPostRequestConnection: Posting TCP conn create request for addr=192.168.208.157, port=62465, conte
00758924.009 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportSetConnWaitTimer: Wait timer set for connection=0xe74c00b8,addr=192.168.208.157, port=62465
00758924.010 |14:21:29.833 |AppInfo |//SIP/Stack/Transport/0x0/sipTransportSetConnWaitTimer:
Wait Conn Ti

 

 

Also if you would, please pretty please, put your configs and/or debugs in a text file and attach them to a post (rather than pasting your output into the post itself). It makes things much easier for us to look at. Thank you.

Maren

r0nh
Level 1
Level 1

i am still unable to figure out why i cannot register.  Hopefully someone will see this . 

There is something funky going on with the ports. The initial request comes in on port 62465, but it's almost like the phone is using that port for communication but embedding 62466 inside the communications. Because of the conflict (if I'm reading this right) CUCM cannot establish communications.

Is this phone behind NAT? Or is there a firewall between the phone and CUCM?

Maren