Solved: Re: CIPCs not registering from the network

Scuromano · ‎02-05-2018

I have a situation where new CIPCs are set to auto-register but are not registering on the network. Hardware phones auto-register fine. This is one MAC address 18DBF2536950. This is the output of the TFTP traces for the phone. What does "No OffClusters found. Hence returning NOTFOUND to request" mean in terms of not registering? Or, "FindMatching(18DBF2536950), Not Found" I was told that previously, all CIPCs auto-registered with no problems. Of couse, nothing changed. Any help on this?

|RequestPoller::pollForRequest(30), fd(53) Read Ready
00046989.000 |15:03:04.873 |AppInfo |-->TID[d8a18b70] HTTPEngine::acceptConnect(), [0xf533c570], socket(53)
00046990.000 |15:03:04.873 |AppInfo |   TID[d8a18b70] HTTPEngine::acceptConnect(), [0xf533c570], socket(53) accept() success, Socket(10), RemoteIP(10.1.1.18), Port(49809)
00046991.000 |15:03:04.873 |AppInfo |<--TID[d8a18b70] HTTPEngine::acceptConnect(), [0xf533c570], socket(53)
00046992.000 |15:03:04.873 |AppInfo |   TID[d8a18b70] TFTPServer::waitForHTTPConnection[0x88ca238]() sockets:53 count(00000), connect(0xf533c570)
00046993.000 |15:03:04.873 |AppInfo |   TID[d8a18b70] TFTPServer::waitForHTTPConnection[0x88ca238]() sockets:53 HTTP Connection count(1)
00046994.000 |15:03:04.873 |AppInfo |TID[d8a18b70] CReqProcessThreads::processHttpReq(push CReqContext[0xf533c570])
00046995.000 |15:03:04.873 |AppInfo |CReqContext::CReqContext(0xf533cf50)
00046996.000 |15:03:04.873 |AppInfo |-->TID[e3429b70] CReqContext::HTTPProxyRun(), [0xf533c570~50~10.1.1.18~49809]
00046997.000 |15:03:04.873 |AppInfo |-->TID[e3429b70] HTTPEngine::getRequest(), [0xf533c570~50~10.1.1.18~49809]
00046998.000 |15:03:04.873 |AppInfo |pollFor(1), Time(5), poll(10) Read Ready
00046999.000 |15:03:04.873 |AppInfo |TID[e3429b70] HTTPEngine::readRequest(), [0xf533c570~50~10.1.1.18~49809], socket(10), received size[144]
00047000.000 |15:03:04.873 |AppInfo |   TID[e3429b70] HTTPEngine::getRequest(), [0xf533c570~50~10.1.1.18~49809] socket(10), ReqTimeout[60], Request[GET /CTLSEP18DBF2536950.tlv HTTP/1.1
Accept: */*
User-Agent: CIPC
Host: 10.1.31.234:6970
Connection: Keep-Alive
Cache-Control: no-cache]
00047001.000 |15:03:04.873 |AppInfo |   TID[e3429b70] HTTPEngine::getRequest(), [0xf533c570~50~10.1.1.18~49809] File Requested CTLSEP18DBF2536950.tlv
00047002.000 |15:03:04.873 |AppInfo |<--TID[e3429b70] HTTPEngine::getRequest(), [0xf533c570~50~10.1.1.18~49809]
00047003.000 |15:03:04.873 |AppInfo |-->CReqContext::tftp[0xf533c570~50~10.1.1.18~49809]
00047004.000 |15:03:04.873 |AppInfo |CReqContext::CheckAndSetIsStatic(ctlsep18dbf2536950.tlv) is (Not a Static) File
00047005.000 |15:03:04.873 |AppInfo |CReqContext::isCTLCAPFRequest[CTLSEP18DBF2536950.tlv] Not a CTLCAPF File
00047006.000 |15:03:04.873 |AppInfo |   CReqContext::tftp[0xf533c570~50~10.1.1.18~49809] HandleCTL: [CTLSEP18DBF2536950.tlv] is CTLSEPMac.tlv file, Searching[18DBF2536950]
00047007.000 |15:03:04.873 |AppInfo |TFTPCache::FindMatching(18DBF2536950), Not Found
00047008.000 |15:03:04.873 |AppInfo |   CReqContext::tftp[0xf533c570~50~10.1.1.18~49809] HandleCTL: Match[18DBF2536950] Not found locally
00047009.000 |15:03:04.873 |AppInfo |CReqContext::checkAndHandleDiagReq[0xf533c570~50~10.1.1.18~49809], File[CTLSEP18DBF2536950.tlv]
00047010.000 |15:03:04.873 |AppInfo |   CReqContext::tftp[0xf533c570~50~10.1.1.18~49809] No OffClusters found. Hence returning NOTFOUND to request.
00047011.000 |15:03:04.873 |AppInfo |-->HTTPEngine::sendNak[0xf533c570~50~10.1.1.18~49809][1]
00047012.000 |15:03:04.873 |AppInfo |   HTTPEngine::sendNak[0xf533c570~50~10.1.1.18~49809][1] FileName[CTLSEP18DBF2536950.tlv], Version[HTTP/1.1]
00047013.000 |15:03:04.873 |AppInfo |   HTTPEngine::sendNak[0xf533c570~50~10.1.1.18~49809][1] [64][HTTP/1.1 404 Not Found
Content-length: 0
Content-type: */*

]
00047014.000 |15:03:04.873 |AppInfo |-->HTTPEngine::sendMessage[0xf533c570~50~10.1.1.18~49809]
00047015.000 |15:03:04.873 |AppInfo |   HTTPEngine::sendMessage[0xf533c570~50~10.1.1.18~49809] Socket[10], Length[64]
00047016.000 |15:03:04.873 |AppInfo |   HTTPEngine::sendMessage[0xf533c570~50~10.1.1.18~49809] Send Complete, Size[64], Sent[64]
00047017.000 |15:03:04.873 |AppInfo |<--HTTPEngine::sendMessage[0xf533c570~50~10.1.1.18~49809]
00047018.000 |15:03:04.873 |AppInfo |<--HTTPEngine::sendNak[0xf533c570~50~10.1.1.18~49809][1]
00047019.000 |15:03:04.873 |AppInfo |<--CReqContext::tftp[0xf533c570~50~10.1.1.18~49809]
00047020.000 |15:03:04.873 |AppInfo |TID[e3429b70] HTTPEngine::startAsyncIO[0xf533c570~50~10.1.1.18~49809]() Socket[10] Registered for callback successfully
00047021.000 |15:03:04.873 |AppInfo |<--TID[e3429b70] CReqContext::HTTPProxyRun(), [0xf533c570~50~10.1.1.18~49809]
00047022.000 |15:03:06.365 |AppInfo |HTTPEngine::ProcessAsyncIO[0xf533c570~50~10.1.1.18~49809], Socket[10]
00047023.000 |15:03:06.365 |AppInfo |-->TID[dc61eb70] CReqContext::HTTPProxyRun(), [0xf533c570~50~10.1.1.18~49809]
00047024.000 |15:03:06.365 |AppInfo |-->TID[dc61eb70] HTTPEngine::getRequest(), [0xf533c570~50~10.1.1.18~49809]
00047025.000 |15:03:06.365 |AppInfo |pollFor(1), Time(60), poll(10) Read Ready
00047026.000 |15:03:06.365 |AppInfo |TID[dc61eb70] HTTPEngine::readRequest(), [0xf533c570~50~10.1.1.18~49809], socket(10), received size[-1]
00047027.000 |15:03:06.365 |AppInfo |TID[dc61eb70] HTTPEngine::readRequest() error in connection, [0xf533c570~50~10.1.1.18~49809], socket(10), error(104) in recv
00047028.000 |15:03:06.365 |AppInfo |<--TID[dc61eb70] HTTPEngine::getRequest(), [0xf533c570~50~10.1.1.18~49809]
00047029.000 |15:03:06.365 |AppInfo |   TID[dc61eb70] CReqContext::HTTPProxyRun(), [0xf533c570~50~10.1.1.18~49809] Failed to Read, Status[-1]
00047030.000 |15:03:06.365 |AppInfo |<--TID[dc61eb70] CReqContext::HTTPProxyRun(), [0xf533c570~50~10.1.1.18~49809]
00047031.000 |15:03:06.365 |AppInfo |CReqContext::CleanupTxnMap() - transaction ID [0] associated with cReq[0xf533c570~50~10.1.1.18~49809], MapSize[0]
00047032.000 |15:03:06.365 |AppInfo |TID[dc61eb70] HTTPEngine::stopAsyncIO[0xf533c570~50~10.1.1.18~49809] Socket[10] Queued for cleanup
00047033.000 |15:03:06.365 |AppInfo |TID[dd01fb70] NetworkService::cleanupThread() Socket[10], CReqContext[0xf533c570~50~10.1.1.18~49809]
00047034.000 |15:03:06.365 |AppInfo |TID[dd01fb70] CReqContext::~CReqContext[0xf533c570~50~10.1.1.18~49809]
00047035.000 |15:03:14.107 |AppInfo |   TID[045c4b70] CServiceModule::TimerThread() signal reRead config[666539]
00047036.000 |15:03:14.107 |SdlStat |Period: 12s #Lines: 54 #Bytes: 6595 Total Number of Buffers: 2000 Free LWM: 1985 Free LWM(total): 1926
00047037.000 |15:03:14.107 |AppInfo |-->CServiceModule::BuildDefaultXML()
00047038.000 |15:03:14.107 |AppInfo |-->CXMLDefault::BuildFromDatabase
00047039.000 |15:03:14.107 |AppInfo |

Scuromano · ‎02-13-2018

Update to the post: the issue was that the CallManager Group had been changed (they insisted that no changes were made) and the first server in the group had auto-registration turned off. Once the order in the group was changed, the phones auto-registered. Thanks for your responses.

View solution in original post

Andrew West · ‎02-05-2018

If you statically assign the device name at both the CUCM and IPC level does it register then?

Scuromano · ‎02-07-2018

We tried this. At first, it said "rejected" in CUCM. Then, they opened up CIPC on the PC to try ot delete the ITL file but it registered then, the rejected went away. It works normally now. There is just some issue with the auto-registration.

Rajan · ‎02-05-2018

What is the CUCM version and whether its a secure cluster ?

Scuromano · ‎02-07-2018

CIPC version is 8.6.6.0.

CUCM version is 10.5.2.12901-1

Not sure if it's a secure cluster or not. Where do you find that out?

We deleted the CTL files but it didn't help.

Scuromano · ‎02-13-2018

Update to the post: the issue was that the CallManager Group had been changed (they insisted that no changes were made) and the first server in the group had auto-registration turned off. Once the order in the group was changed, the phones auto-registered. Thanks for your responses.