Genesys not able to cti control 8845 SIP phones.

[sacanand]

Issue  :Genesys not able to cti control 8845 SIP phones.

8845 phones are new

Firmware version: sip8845_65.10-3-2-16

Cisco CallManager Publisher – System version: 8.6.2.24107-1

8945 SIP phones are working fine.

Error received: Invalid login/ Out of service Media error 58.

Troubleshooting done:

Restarted CTI service

Un-associate and re-associate from the application user.

Cluster reboot was performed after device pack install recently.

Collected CTI logs and analysis show same details for both working and non working phone.

Please let us know if there is any bug on 8845 or advice next step.

Trace file with detail attached.

Non Working

11:19:06.866 |CTIDeviceLineCache::GetDeviceStaticInfo- success=1 model=36224 prod=36677 Proto=11 DevTypeName=Cisco 8845 RIS=1 SupFeature=31|0,0,0,0.0^*^*
11:19:06.866 |DbAccess::ReadDeviceInfoByDeviceNameOrPkid - GetDeviceStaticInfo success=1 model=36224 prod=36677 Proto=2 DevTypeName=Cisco 8845 RIS=1 SupFeature=31|0,0,0,0.0^*^*
11:19:06.866 |CTILocaleUtil::GetAltScriptFromLocale FOUND Locale=1 AltScript=|0,0,0,0.0^*^*
11:19:06.866 |DbAccess::ReadDevicePoolInfo|0,0,0,0.0^*^*
11:19:06.866 |JEBA DbAccess::ReadDevicePoolInfo device pkid found pkid=cc99fba5-7d81-c045-091f-801c9bb9b83b|0,0,0,0.0^*^*
11:19:06.866 |CTIDeviceLineCache::GetDeviceInfo devPkid=cc99fba5-7d81-c045-091f-801c9bb9b83b|0,0,0,0.0^*^*
11:19:06.866 |CTIDevicePoolCache::GetServerAndNodeFromDevicePool devPoolPkid=dca8cdf6-6796-4552-8f03-ed2099cabde2|0,0,0,0.0^*^*
11:19:06.866 |     JEBA DbAccess::Iterating Device=SEP0057D2C17969 Pkid=cc99fba5-7d81-c045-091f-801c9bb9b83b NodeId3,0,0,0,0|0,0,0,0.0^*^*
11:19:06.866 |     JEBA CTIDbAccess DevicePoolFetchReq Device=SEP0057D2C17969 NodeId3,0,0,0,0 bResult=1|0,0,0,0.0^*^*
11:19:06.866 |ready_CtiDevicePoolFetchReq Query Success Device=SEP0057D2C17969|0,0,0,0.0^*^*

000013464 |2016/06/16 11:19:06.898 |200 |SdlSig    |CtiGetDeviceAndLineInfoReq             |ready                          |CTIDbAccess(3,200,26,1)          |CTIDeviceLineMgr(3,200,25,1)     |3,200,21,1.271^*^*                       |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] AsyncResponse=315 DeviceNameSEP0057D2C17969
000013465 |2016/06/16 11:19:06.898 |200 |SdlSig    |CtiGetDeviceAndLineInfoRes             |ready                          |CTIDeviceLineMgr(3,200,25,1)     |CTIDbAccess(3,200,26,1)          |3,200,21,1.271^*^*                       |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] AsyncResponse=315 Result=0x0 deviceName=SEP0057D2C17969 EventContent=10 DeviceConfigInfo= Locale=1 AltScrpt= DNDOption=0 ConfigIpAddrMode=2 Hotelling=T Restricted=F OutboundRO=0 BIB=T DNDStatus=F LoginStatus=0 TotalLines=1 LineCount=1 MoreLines=F DN = 12025 Part = BUPA_Internal PkGpDN =  PkGpPart =
000013466 |2016/06/16 11:19:06.898 |200 |AppInfo   |||CTIDeviceLineMgr(3,200,25,1)|||[CTI-INFO] [DeviceEventRouter(SEP0057D2C17969)::getDeviceAndLineInfoRes]     deviceName=SEP0057D2C17969 (mState=2)
000013467 |2016/06/16 11:19:06.898 |200 |AppInfo   |||CTIDeviceLineMgr(3,200,25,1)|||[DeviceEventRouter::saveAndGenerateResponseToApps]  [CTI-APP]     (Signal=CtiDeviceAndLineInfoMsg DeviceName=SEP0057D2C17969
000013468 |2016/06/16 11:19:06.898 |200 |AppInfo   |||CTIDeviceLineMgr(3,200,25,1)|||[CTI-INFO] [DeviceEventRouter(SEP0057D2C17969)::saveAndGenerateResponseToApps]     RegStatus =2 ReqType =1
000013469 |2016/06/16 11:19:06.898 |200 |AppInfo   |||CTIDeviceLineMgr(3,200,25,1)|||[CTI-INFO] [DeviceEventRouter(SEP0057D2C17969)::cleanupOutStandingRequest]     deviceName=SEP0057D2C17969 Stoping timer for SyncId 315
000013470 |2016/06/16 11:19:06.898 |200 |SdlSig    |CtiDeviceLineInfoNotify                |ready                          |CTIHandler(3,200,22,2)           |CTIDeviceLineMgr(3,200,25,1)     |3,200,21,1.271^*^*                       |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0]  ReqType=0RequestId=125 EvStatusCode=0 deviceName=SEP0057D2C17969 EventContent=10 DeviceConfigInfo= Locale=1 AltScrpt= DNDOption=0 ConfigIpAddrMode=2 Hotelling=T Restricted=F OutboundRO=0 BIB=T DNDStatus=F LoginStatus=0 TotalLines=1 LineCount=1 MoreLines=F DN = 12025 Part = BUPA_Internal PkGpDN =  PkGpPart =
000013471 |2016/06/16 11:19:06.898 |200 |AppInfo   |||CTIHandler(3,200,22,2)|||[CTI-INFO] [CTIHandler::appDeviceInfoUpdateHotelingData]     deviceName=SEP0057D2C17969 deviceType=36224 dbDeviceId=202 bInControlList=1 mbUserLoggedIn=0 bHotelingAllowed=1 LoginUserId= bJustAcquired=0
000013472 |2016/06/16 11:19:06.898 |200 |AppInfo   |||CTIHandler(3,200,22,2)|||[CTI-APP] [CTIHandler::OutputCtiMessage      ]     CTI   ProviderDeviceLineInfoEvent    (  DName=SEP0057D2C17969 CtrlBits=1)
000013473 |2016/06/16 11:19:06.898 |200 |SdlSig    |CtiProviderGetSingleDeviceAndLinesResponse |ready                          |CTIHandler(3,200,22,2)           |CTIDeviceLineMgr(3,200,25,1)     |3,200,21,1.271^*^*                       |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0]  ReqId=125 ReqType=0

Working

10:57:07.915 |CTIDeviceLineCache::GetDeviceStaticInfo- success=1 model=585 prod=472 Proto=11 DevTypeName=Cisco 8945 RIS=1 SupFeature=15|0,0,0,0.0^*^*
10:57:07.915 |DbAccess::ReadDeviceInfoByDeviceNameOrPkid - GetDeviceStaticInfo success=1 model=585 prod=472 Proto=2 DevTypeName=Cisco 8945 RIS=1 SupFeature=15|0,0,0,0.0^*^*
10:57:07.915 |CTILocaleUtil::GetAltScriptFromLocale FOUND Locale=1 AltScript=|0,0,0,0.0^*^*
10:57:07.916 |DbAccess::ReadDevicePoolInfo|0,0,0,0.0^*^*
10:57:07.916 |JEBA DbAccess::ReadDevicePoolInfo device pkid found pkid=0d6996fd-c71a-6bef-04b9-2ee2d3651939|0,0,0,0.0^*^*
10:57:07.916 |CTIDeviceLineCache::GetDeviceInfo devPkid=0d6996fd-c71a-6bef-04b9-2ee2d3651939|0,0,0,0.0^*^*
10:57:07.916 |CTIDevicePoolCache::GetServerAndNodeFromDevicePool devPoolPkid=48c7aafa-e6c7-4bbe-99a7-ff8062d20b78|0,0,0,0.0^*^*
10:57:07.916 |     JEBA DbAccess::Iterating Device=SEPE0D173E119B3 Pkid=0d6996fd-c71a-6bef-04b9-2ee2d3651939 NodeId1,3,0,0,0|0,0,0,0.0^*^*
10:57:07.916 |     JEBA CTIDbAccess DevicePoolFetchReq Device=SEPE0D173E119B3 NodeId1,3,0,0,0 bResult=1|0,0,0,0.0^*^*
10:57:07.916 |ready_CtiDevicePoolFetchReq Query Success Device=SEPE0D173E119B3|0,0,0,0.0^*^*

000013388 |2016/06/16 10:57:07.921 |200 |SdlSig-O  |CtiGetDeviceAndLineInfoReq             |NA RemoteSignal                |UnknownProcessName(1,100,65,7)   |CTIDeviceLineMgr(1,200,25,1)     |1,200,21,1.211^*^*                       |AsyncResponse=303 DeviceNameSEPE0D173E119B3
000013389 |2016/06/16 10:57:07.921 |200 |SdlSig-I  |CtiGetDeviceAndLineInfoRes             |ready                          |CTIDeviceLineMgr(1,200,25,1)     |SIPStationD(1,100,65,7)          |1,200,21,1.211^*^*                       |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] AsyncResponse=303 Result=0x0 deviceName=SEPE0D173E119B3 EventContent=14 DeviceConfigInfo= Locale=1 AltScrpt= DNDOption=0 ConfigIpAddrMode=3 Hotelling=T Restricted=F OutboundRO=0 BIB=F DNDStatus=F LoginStatus=2 DeviceRegistrationInfo= TerminateMedia=5 ActiveIPAddrMode=0 IPv4=572016138 IPv6= LoginUser= ProfilePkid= Encoding=3 CtiControllable=1 AppCapability=60 UserCapability=40 TotalLines=1 LineCount=1 MoreLines=F DN = 12023 Part = BUPA_Internal PkGpDN =  PkGpPart =
000013390 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIDeviceLineMgr(1,200,25,1)|||[CTI-INFO] [DeviceEventRouter(SEPE0D173E119B3)::getDeviceAndLineInfoRes]     deviceName=SEPE0D173E119B3 (mState=2)
000013391 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIDeviceLineMgr(1,200,25,1)|||[DeviceEventRouter::saveAndGenerateResponseToApps]  [CTI-APP]     (Signal=CtiDeviceAndLineInfoMsg DeviceName=SEPE0D173E119B3
000013392 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIDeviceLineMgr(1,200,25,1)|||[CTI-INFO] [DeviceEventRouter(SEPE0D173E119B3)::saveAndGenerateResponseToApps]     RegStatus =1 ReqType =2
000013393 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIDeviceLineMgr(1,200,25,1)|||[CTI-INFO] [DeviceEventRouter(SEPE0D173E119B3)::cleanupOutStandingRequest]     deviceName=SEPE0D173E119B3 Stoping timer for SyncId 303
000013394 |2016/06/16 10:57:07.921 |200 |SdlSig    |CtiDeviceLineInfoNotify                |ready                          |CTIHandler(1,200,22,2)           |CTIDeviceLineMgr(1,200,25,1)     |1,200,21,1.211^*^*                       |[R:N-H:0,N:1,L:0,V:0,Z:0,D:0]  ReqType=0RequestId=107 EvStatusCode=0 deviceName=SEPE0D173E119B3 EventContent=14 DeviceConfigInfo= Locale=1 AltScrpt= DNDOption=0 ConfigIpAddrMode=2 Hotelling=T Restricted=F OutboundRO=0 BIB=F DNDStatus=F LoginStatus=2 DeviceRegistrationInfo= TerminateMedia=5 ActiveIPAddrMode=0 IPv4=572016138 IPv6= LoginUser= ProfilePkid= Encoding=3 CtiControllable=1 AppCapability=60 UserCapability=40 TotalLines=1 LineCount=1 MoreLines=F DN = 12023 Part = BUPA_Internal PkGpDN =  PkGpPart =
000013395 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIHandler(1,200,22,2)|||[CTI-INFO] [CTIHandler::appDeviceInfoUpdateDeviceState]     deviceName=SEPE0D173E119B3 state=1
000013396 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIHandler(1,200,22,2)|||[CTI-INFO] [CTIHandler::appDeviceInfoUpdateHotelingData]     deviceName=SEPE0D173E119B3 deviceType=585 dbDeviceId=207 bInControlList=1 mbUserLoggedIn=0 bHotelingAllowed=1 LoginUserId= bJustAcquired=0
000013397 |2016/06/16 10:57:07.921 |200 |AppInfo   |||CTIHandler(1,200,22,2)|||[CTI-APP] [CTIHandler::OutputCtiMessage      ]     CTI   ProviderDeviceLineInfoEvent    (  DName=SEPE0D173E119B3 CtrlBits=1)
000013398 |2016/06/16 10:57:07.921 |200 |SdlSig    |CtiProviderGetSingleDeviceAndLinesResponse |ready                          |CTIHandler(1,200,22,2)           |CTIDeviceLineMgr(1,200,25,1)     |1,200,21,1.211^*^*                       |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0]  ReqId=107 ReqType=0

[Deepak Mehta]

Have you tried deleting and recreating the phones.?

I haven't seen any bug for this however other theads does talk about the same issue with genesys.

[sacanand]

Yes  we have deleted and recreated phone/ Associated and unassociated phone with application user/ Restarted CTI manager/ Reset Phone.

"Standard CTI Allow control of all devices" and "Standard CTI Enabled" permission are added to user.

Same configuration works for 8945 phones however fails for 8845

[Jonathan Schulenberg · Accepted solution]

Have you added Standard CTI Allow Control of Phones supporting Connected Xfer and conf to the app user as well?

[jip]

I encountered the same issue and after adding this role to the JTAPI users, it works with 8851 SIP Phones.

Yes, your answer is correct.

[Leszek Wojnarski · Accepted solution]

I've checked the logs and what I can see is that when you login using you application user. Device is not even on the list of devices associated to the user. And that is even before it checks the registration status or tries to control those devices. It's simple not in DB of the associated devices from some reason. This is in most cases configuration issue with the configuration. But might be some DB issue as well, hard to say for now. Can you try to point your application to CTI Manager service running on Publisher instead of the one running on Sub? And make sure all devices are assosisted to TSERVER_JTAPI_LAB.

SEP0057D2C17969 - working

SEPE0D173E119B3 - Not Working - not on the list of phones associated to TSERVER_JTAPI_LAB user.

|CTIHandler(1,200,22,1) |1,200,21,1.2^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SubType=1 CTIHandlerPid=(1,200,22,1) LoginUserId=TSERVER_JTAPI_LAB
000000087 |2016/06/16 10:44:25.613 |200 |AppInfo |||CTIDeviceRegManager(1,200,24,1)||| TrackApplication - Adding first time CTIHandler=(1,200,22,1)
000000088 |2016/06/16 10:44:25.613 |200 |SdlSig |ProviderSubscriptionRegNotify |ready |CTIDbAccess(1,200,26,1) |CTIHandler(1,200,22,1) |1,200,21,1.2^*^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] userId=0x09eea464
000000089 |2016/06/16 10:44:25.613 |200 |SdlSig |CtiDeviceListWithDPFetchReq |ready |CTIDbAccess(1,200,26,1) |CTIDeviceRegManager(1,200,24,1) |1,200,21,1.2^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] Enum=1 User=TSERVER_JTAPI_LAB
000000090 |2016/06/16 10:44:25.614 |200 |SdlSig |CtiDeviceListWithDPFetchRes |ready |CTIDeviceRegManager(1,200,24,1) |CTIDbAccess(1,200,26,1) |1,200,21,1.2^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] EnumHandle=1 NumDevices=43 Total=43 mbMore=0 :31004:50000:SEP001B2A8958FC:30014:12796:12802:71006:31005:31002:30012:31006:31007:37850:31008:31009:SEP001B535D3884:SEP001B535C7858:SEP001BD58468B5:SEP001BD52D239C:SEP001B53B95E77:SEP0057D2C17969:37900:SEP8478ACED9621:SEP001B535C78F3:SEP20BBC0DEFC78:12791:SEP001B535C7700:SEP001B535CC073:31001:30000:SEP001B5413C430:SEP001B53B8A7EB:SEP001B2A89C8F3:30011:30013:SEP001B2A89A505:SEP002497AB2CD6:12803:30010:SEP001B535CC746:12805:31003:37470

Leszek