VVX 401 MFA Failed to Sign-In

[JoshuaHasson]

---------------Phone Information---------------
Phone Model VVX 401
Part Number 3111-48400-001 Rev:A
MAC Address 64:16:7F:44:E6:DA
IP Mode IPv4
IP Address 10.1.9.52
UCS Version 6.0.0.4796
Updater Version 6.0.0.4604

---------------Connected Devices---------------
Windows 10 Pro - LAN Connected

Microsoft Office 365 ProPlus -en-us

Skype for Business for Office 365 MSO (16.0.10730.20344) 64-bit

Additional Polycom Infrastructure: Polycom BToE 3.9.0.0

--------------------Issue------------------------
Recently configured Multi-Factor Authentication in Office 365. Users are unable to connect to Skype For Business and cannot Sign-In, BToE is paired, Phone has DHCP address and is Web UI Accessible. This has worked without MFA enabled.

- Issue is not Day 1, phone has been upgaded from 5.9.2.3446 for testing, same symptoms.
- Failed to Fetch Certificate after Authenticating with SfB Password Pop-up
- Skype for Business Sign In has failed.

Sign-In Method from Phone is Web Sign-In (Aka.ms/sphone)

---------------------LOG-------------------------

0529130716|auth |2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(106)AuthServiceOAuthMsgKey:(214)AuthSvcAOFsmRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1323034982)
0529130716|auth |2|00|SM Module: SM created Ref(12860)
0529130716|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((501),(1)kBaseEventInit,Ticks(0))
0529130716|auth |2|00|S/E(sSOAuth2S0,kBaseEventInit),rO(5)
0529130716|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((501),(5),Ticks(0))
0529130716|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((501),(501)kEOAuth2OAuth2Start,Ticks(0))
0529130716|auth |2|00|S/E(sSOAuth2S0,kEOAuth2OAuth2Start),rO(503)
0529130716|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((502),(1)kBaseEventInit,Ticks(0))
0529130716|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((502),(1)kBaseEventInit,Ticks(0))
0529130716|auth |2|00|S/E(sTSOAuth2CheckOAuthTokenProvider,kBaseEventInit),rO(3)
0529130716|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((503),(1)kBaseEventInit,Ticks(0))
0529130716|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((503),(1)kBaseEventInit,Ticks(0))
0529130716|auth |2|00|[OAuth2PrepareAndSendRequest]:[1379]:[1]:[https://login.windows.net/common/UserRealm/jfigueroa@conferencetech.com?api-version=1.0]
0529130716|nisvc|2|00|Request(-1)nisvc,(701)NIServiceNiReqMsgKey,(-1)auth,(702)NIServiceNiResMsgKey,(Expiry,TransactionId,Time,Type):(-1,-1,1559153236,0)IndicationLevel:(200)
0529130716|auth |2|00|S/E(sSOAuth2IdentifyOnlineUserType,kBaseEventInit),rO(5)
0529130716|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((503),(5),Ticks(0))
0529130716|auth |2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
0529130716|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529130716|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(106)AuthServiceOAuthMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(0)
,TransactionID(1323034982)
0529130716|auth |2|00|Response(-1)auth,(106)AuthServiceOAuthMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1323034982,1559153236,1)IndicationCode:(0)
0529130716|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(106)AuthServiceOAuthMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(100)SM Started
,TransactionID(1323034982)
0529130716|auth |2|00|Response(-1)auth,(106)AuthServiceOAuthMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1323034982,1559153236,1)IndicationCode:(100)SM Started
0529130716|log |5|00|Skipped uploading of failed log file because no of failures are > 4 or last upload failed time is < 60 seconds.
0529130717|nisvc|2|00|

****************************HTTP SEND**************************

0529130717|nisvc|2|00|HTTP SEND:: DestUrl(https://login.windows.net/common/UserRealm/jfigueroa@conferencetech.com?api-version=1.0), HttpResCode(200), curlRetCode(0) retVal(0)
0529130717|nisvc|2|00|ErrorBuffer::
0529130717|nisvc|2|00|

****************************HTTP SEND**************************

0529130717|nisvc|2|00|<\ni03:1,time taken(55)>
0529130717|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((503),(301)kEAuthOnRecvDataResponse,Ticks(0))
0529130717|auth |2|00|[OAuth2ParseAndSaveRequiredInfo]:[1535] eReqRspID[1] m_RetVal[0] curlReturn[0] HttpRspCode[200] csStrippedResponse[{"ver":"1.0","account_type":"Managed","domain_name":"conferencetech.com","cloud_instance_name":"microsoftonline.com","cloud_audience_urn":"urn:federation:MicrosoftOnline"}]
0529130717|auth |2|00|S/E(sSOAuth2IdentifyOnlineUserType,kEAuthOnRecvDataResponse),rO(3)
0529130717|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((504),(1)kBaseEventInit,Ticks(0))
0529130717|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((504),(1)kBaseEventInit,Ticks(0))
0529130717|auth |2|00|S/E(sTSOAuth2CheckOnlineUserType,kBaseEventInit),rO(505)
0529130717|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((505),(1)kBaseEventInit,Ticks(0))
0529130717|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((505),(1)kBaseEventInit,Ticks(0))
0529130717|auth |4|00|This request is blocked
0529130717|auth |2|00|[OAuth2PrepareAndSendRequest]:[1379]:[2]:[https://login.windows.net/common/oauth2/token]
0529130717|nisvc|2|00|Request(-1)nisvc,(701)NIServiceNiReqMsgKey,(-1)auth,(702)NIServiceNiResMsgKey,(Expiry,TransactionId,Time,Type):(-1,-1,1559153237,0)IndicationLevel:(200)
0529130717|auth |2|00|S/E(sSOAuth2FetchOAuth2ManagedToken,kBaseEventInit),rO(5)
0529130717|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((505),(5),Ticks(0))
0529130717|nisvc|4|00|Ni is blocked for username jfigueroa@conferencetech.com
0529130717|nisvc|2|00|<\ni00:1,time taken(0)>
0529130717|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((505),(301)kEAuthOnRecvDataResponse,Ticks(0))
0529130717|auth |2|00|[OAuth2ParseAndSaveRequiredInfo]:[1535] eReqRspID[2] m_RetVal[-1] curlReturn[0] HttpRspCode[401] csStrippedResponse[]
0529130717|auth |2|00|AuthSvc SOAuth2FetchOAuth2ManagedToken-Not received the Token
0529130717|auth |2|00|S/E(sSOAuth2FetchOAuth2ManagedToken,kEAuthOnRecvDataResponse),rO(4)
0529130717|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((513),(1)kBaseEventInit,Ticks(0))
0529130717|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((513),(1)kBaseEventInit,Ticks(0))
0529130717|auth |4|00|Auth state mechine module description pHD(-1)
https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc
https://webdir4a.online.lync.com/CertProv/CertProvisioningService.svc/WebTicket_Proof_SHA1

https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc/cert



https://login.windows.net/common/oauth2/authorize
https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc/OAuth
https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc
https://login.windows.net/common/oauth2/au
0529130717|auth |4|00|Auth state mechine module parameters, AuthSvc SOAuth2Error, BaseEventInit restart[0] SfbTokenFetchMethod[3] 
0529130717|auth |2|00|AuthSvc SOAuth2Error, BaseEventInit 401
0529130717|auth |2|00|S/E(sSOAuth2Error,kBaseEventInit),rO(4)
0529130717|auth |3|00|kEAuthOnRecvDataResponse:Event(4) not found in Transition Table for state sSOAuth2Error
0529130717|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((513),(4),Ticks(0))
0529130717|auth |2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(106)AuthServiceOAuthMsgKey:(215)AuthSvcAOFsmReplyKey
Caller Service(-1):IndicationCode(401)Failed to Get oAuth Token
,TransactionID(1323034982)
0529130717|auth |2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
0529130717|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529130717|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(106)AuthServiceOAuthMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(401)Failed to Get oAuth Token
,TransactionID(1323034982)
0529130717|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((513),(7)kBaseEventStop,Ticks(0))
0529130717|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x1ae67f8):Ctx((513),(-1),Ticks(0))
0529130717|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529130717|auth |2|00|<SM>(304)AuthServiceUTStateMachine(0x1af7d48):Ctx((345),(7)kBaseEventStop,Ticks(0))
0529130717|auth |2|00|<\SM>(304)AuthServiceUTStateMachine(0x1af7d48):Ctx((345),(-1),Ticks(0))
0529130717|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529130717|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(101)AuthServiceWTMsgKey:(211)AuthSvcAODBIEIndKey
Caller Service(-1):IndicationCode(401)Failed to Get oAuth Token
,TransactionID(1323034982)
0529130717|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529130717|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(102)AuthServiceUCMsgKey:(211)AuthSvcAODBIEIndKey
Caller Service(-1):IndicationCode(401)Failed to Get oAuth Token
,TransactionID(1323034982)
0529130717|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529130717|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(102)AuthServiceUCMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(-1):IndicationCode(401)Failed to Get oAuth Token
,TransactionID(1323034982)
0529130717|auth |2|00|Response(-1)auth,(102)AuthServiceUCMsgKey,(-1)pps,(14),(Expiry,TransactionId,Time,Type):(-1,1323034982,1559153237,1)IndicationCode:(401)Failed to Get oAuth Token
0529130717|pps |4|00|CSeGetUCRsp::execute: Entered Invalid Credentials 
0529130717|cfg |4|00|RT|SIP is setting Login Credentials to invalid for Reason[1]
0529130717|nisvc|2|00|Request(-1)nisvc,(4)ServiceSetMsgKey,(-1),(-1),(Expiry,TransactionId,Time,Type):(-1,-1,1559153237,0)IndicationLevel:(200)
0529130717|so |4|00|[soRegistrationC] Login Credentials invalid causing SoRegEventLine Deleted
0529130717|btoe |4|00|Resp to PBC: <Signin> <Failed>
0529130717|app1 |4|00|AppBrowserUiC::updateConfiguration(): calling startBrowserUI()
0529130717|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(106)AuthServiceOAuthMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(401)Failed to Get oAuth Token
,TransactionID(1323034982)
0529130717|auth |2|00|Response(-1)auth,(106)AuthServiceOAuthMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1323034982,1559153237,1)IndicationCode:(401)Failed to Get oAuth Token
0529130717|nisvc|2|00|NI Module received cred.change
0529130717|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Enter

0529130717|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Default

0529130717|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Exit

0529130719|so |4|00|[SoNcasC]: appncascontext termination:1
0529130719|so |4|00|[SoNcasC]: Case Handling termination:1
0529130719|app1 |*|00|SoRegistrationEventLineDeleted - new AppRegLineC, Default user
0529130719|so |4|00|[SoNcasC]: appncascontext termination:1
0529130719|app1 |5|00|AppPhoneLockC::Init - bPhoneLockState [0]
0529130719|sip |*|00|Sip Unregistering user:jfigueroa@conferencetech.com display name:jfigueroa authorizing user name:'' index value:0
0529130719|sip |4|00|SipRemoveMonitoredUser : CSTA Line Not Found 
0529130719|sip |*|00|SipUserRemove: user 0 being removed.
0529130724|so |4|00|[SoNcasC]: Case Handling termination:1
0529130724|sip |*|00|Sip registering user:VVX401 display name:VVX 401 authorizing user name:'Using Login Cred' index value:0
0529130724|utilm|4|00|uBLFUnCompressed: File /ffs0/Config/Local/WebTicket/0/sip.usr doesn't exist or is empty
0529130724|sip |*|00|User removed
0529130738|nisvc|2|00|Request(-1)nisvc,(3)ServiceTimerMsgKey,(-1),(-1),(Expiry,TransactionId,Time,Type):(-1,-1,1559153258,0)IndicationLevel:(200)
0529130738|nisvc|2|00|TimerId:(WPADStateMachineModule,CbData,ModuleP,MMS,State),(0x19bb338,0x19bbfd8,60000,4)
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((654),(2),Ticks(0))
0529130738|nisvc|2|00|S/E(sSWPADRetry,),rO(3)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|S/E(sSWPADMode,kBaseEventInit),rO(1552)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((646),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((646),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|S/E(sSWPADConfigDiscovery,kBaseEventInit),rO(4)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|S/E(sSWPADMode,kBaseEventInit),rO(1553)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((647),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((647),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|DHCP 252 Opt Value: 
0529130738|nisvc|2|00|S/E(sSWPADDHCPDiscovery,kBaseEventInit),rO(4)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|S/E(sSWPADMode,kBaseEventInit),rO(1554)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((648),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((648),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|DNS Domain() DomainIdx(0)
0529130738|nisvc|2|00|S/E(sSWPADDnsADiscovery,kBaseEventInit),rO(4)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((645),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|S/E(sSWPADMode,kBaseEventInit),rO(4)
0529130738|nisvc|2|00|<\SM>(301)WPADStateMachineModule(0x19bb338):Ctx((652),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|2|00|<SM>(301)WPADStateMachineModule(0x19bb338):Ctx((652),(1)kBaseEventInit,Ticks(0))
0529130738|nisvc|4|00|Renew(0) Pac Fetch Failed, SMCtx:
ProxyData:UserName Valid,Password Valid,nAddrs:0
Type/Address:
DHCPCurl:
HttpCode:0 CurlCode:0 DiagErrCode:842346809
Retry:0 Failed:1 Renew:0 Expiry:0 Domain: Domain Tokens(0)
Domain Idx:-1 

[JoshuaHasson]

This also fails with Polycom Better Together over Ethernet Connector (BToE) Application 4.0.0.0

-- Behavior now is authenticating and Fetching, never says it fails. See log. 

0529144828|log  |5|00|Skipped uploading of failed log file because no of failures are > 4 or last upload failed time is < 60 seconds.
0529144828|nisvc|2|00|

****************************HTTP SEND**************************

0529144828|nisvc|2|00|HTTP SEND:: DestUrl(https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc/mex), HttpResCode(200), curlRetCode(0) retVal(0)
0529144828|nisvc|2|00|ErrorBuffer::
0529144828|nisvc|2|00|

****************************HTTP SEND**************************

0529144828|nisvc|2|00|<\ni00:1,time taken(62)>
0529144828|auth |2|00|<SM>(304)AuthServiceUTStateMachine(0x43f24838):Ctx((318),(301)kEAuthOnRecvDataResponse,Ticks(0))
0529144828|auth |2|00|m_RetVal[0] eReqRspID[3] curlReturn[0] HttpRspCode[200] messageLen[13120]
0529144828|auth |2|00|S/E(sSAuthSvcGetTokenProvider,kEAuthOnRecvDataResponse),rO(3)
0529144828|auth |2|00|<\SM>(304)AuthServiceUTStateMachine(0x43f24838):Ctx((345),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|<SM>(304)AuthServiceUTStateMachine(0x43f24838):Ctx((345),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|S/E(sSAuthSvcUTEnd,kBaseEventInit),rO(3)
0529144828|auth |2|00|<\SM>(304)AuthServiceUTStateMachine(0x43f24838):Ctx((345),(3),Ticks(0))
0529144828|auth |2|00|<SM>(304)AuthServiceUTStateMachine(0x43f24838):Ctx((345),(3),Ticks(0))
0529144828|auth |2|00|<\SM>(304)AuthServiceUTStateMachine(0x43f24838):Ctx((345),(-1),Ticks(0))
0529144828|auth |2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(105)AuthServiceUTMsgKey:(215)AuthSvcAOFsmReplyKey
Caller Service(-1):IndicationCode(200)Got User Type
,TransactionID(727687822)
0529144828|auth |2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
0529144828|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529144828|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(105)AuthServiceUTMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(200)Got User Type
,TransactionID(727687822)
0529144828|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(101)AuthServiceWTMsgKey:(211)AuthSvcAODBIEIndKey
Caller Service(-1):IndicationCode(200)Got User Type
,TransactionID(727687822)
0529144828|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(106)AuthServiceOAuthMsgKey:(208)AuthSvcAODBAddKey
Caller Service(-1):IndicationCode(0)
,TransactionID(727687822)
0529144828|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False] DB will be update when User Mode = 0
0529144828|auth |2|00|Silent Add Notifier, CallerService(AuthServiceCallerSnooper)
0529144828|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(105)AuthServiceUTMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(200)Got User Type
,TransactionID(727687822)
0529144828|auth |2|00|Response(-1)auth,(105)AuthServiceUTMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,727687822,1559159308,1)IndicationCode:(200)Got User Type
0529144828|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(106)AuthServiceOAuthMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(0)
,TransactionID(727687822)
0529144828|auth |2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(106)AuthServiceOAuthMsgKey:(214)AuthSvcAOFsmRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(727687822)
0529144828|auth |2|00|SM Module: SM created Ref(35788)
0529144828|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((501),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|S/E(sSOAuth2S0,kBaseEventInit),rO(5)
0529144828|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((501),(5),Ticks(0))
0529144828|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((501),(501)kEOAuth2OAuth2Start,Ticks(0))
0529144828|auth |2|00|S/E(sSOAuth2S0,kEOAuth2OAuth2Start),rO(6)
0529144828|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((511),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((511),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|OAuth2 SOAuth2RenewAccessToken, Device Pairing Detected, Fetch using Refresh Token
0529144828|auth |2|00|S/E(sSOAuth2RenewAccessToken,kBaseEventInit),rO(511)
0529144828|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((512),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((512),(1)kBaseEventInit,Ticks(0))
0529144828|auth |2|00|OAuth2 SOAuth2RenewAccessTokenWithRefreshToken, fetching access token using refresh token
0529144828|auth |2|00|prepareOAuth2TokenRefreshReqBody: ClientID:131c22db-3591-4fc8-a305-55444fa5ccd3
0529144828|auth |2|00|[OAuth2PrepareAndSendRequest]:[1379]:[6]:[https://login.windows.net/common/oauth2/token]
0529144828|nisvc|2|00|Request(-1)nisvc,(701)NIServiceNiReqMsgKey,(-1)auth,(702)NIServiceNiResMsgKey,(Expiry,TransactionId,Time,Type):(-1,-1,1559159308,0)IndicationLevel:(200)
0529144828|auth |2|00|S/E(sSOAuth2RenewAccessTokenWithRefreshToken,kBaseEventInit),rO(5)
0529144828|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((512),(5),Ticks(0))
0529144828|auth |2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
0529144828|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529144828|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(106)AuthServiceOAuthMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(0)
,TransactionID(727687822)
0529144828|auth |2|00|Response(-1)auth,(106)AuthServiceOAuthMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,727687822,1559159308,1)IndicationCode:(0)
0529144828|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(106)AuthServiceOAuthMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(100)SM Started
,TransactionID(727687822)
0529144828|auth |2|00|Response(-1)auth,(106)AuthServiceOAuthMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,727687822,1559159308,1)IndicationCode:(100)SM Started
0529144829|nisvc|2|00|

****************************HTTP SEND**************************

0529144829|nisvc|2|00|HTTP SEND:: DestUrl(https://login.windows.net/common/oauth2/token), HttpResCode(200), curlRetCode(0) retVal(0)
0529144829|nisvc|2|00|ErrorBuffer::
0529144829|nisvc|2|00|

****************************HTTP SEND**************************

0529144829|nisvc|2|00|<\ni01:1,time taken(66)>
0529144829|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((512),(301)kEAuthOnRecvDataResponse,Ticks(0))
0529144829|auth |2|00|[OAuth2ParseAndSaveRequiredInfo]:[1535] eReqRspID[6] m_RetVal[0] curlReturn[0] HttpRspCode[200] csStrippedResponse[{"token_type":"Bearer","scope":"user_impersonation","expires_in":"3600","ext_expires_in":"3600","expires_on":"1559162910","not_before":"1559159010","resource":"https://webdir4a.online.lync.com","access_token":"eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6IkhCeGw5bUFlNmd4YXZDa2NvT1UyVEhzRE5hMCIsImtpZCI6IkhCeGw5bUFlNmd4YXZDa2NvT1UyVEhzRE5hMCJ9.eyJhdWQiOiJodHRwczovL3dlYmRpcjRhLm9ubGluZS5seW5jLmNvb
0529144829|auth |2|00|OAuth2 SOAuth2RenewAccessTokenWithRefreshToken, EAuthOnRecvDataResponse : access token (and refresh token) are received and updated
0529144829|auth |2|00|S/E(sSOAuth2RenewAccessTokenWithRefreshToken,kEAuthOnRecvDataResponse),rO(3)
0529144829|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((510),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((510),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|S/E(sSOAuth2End,kBaseEventInit),rO(3)
0529144829|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((511),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|<SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((511),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|OAuth2 SOAuth2RenewAccessToken, starting the timer to refresh the access token
0529144829|auth |3|00|auth's Ticked,Reason(Internal),Count/Size(1/1),Stop? (No)
0529144829|auth |3|00|auth's Timer,Running(1),Start(2700000)
0529144829|auth |2|00|S/E(sSOAuth2RenewAccessToken,kBaseEventInit),rO(5)
0529144829|auth |2|00|<\SM>(305)AuthServiceOAuthStateMachine(0x43f25540):Ctx((511),(5),Ticks(0))
0529144829|auth |2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(106)AuthServiceOAuthMsgKey:(215)AuthSvcAOFsmReplyKey
Caller Service(-1):IndicationCode(200)Got OAUTH2 Token
,TransactionID(727687822)
0529144829|auth |2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
0529144829|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529144829|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(106)AuthServiceOAuthMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(200)Got OAUTH2 Token
,TransactionID(727687822)
0529144829|auth |2|00|Policy Dest:(202)AuthServicePolicyDBKey:(101)AuthServiceWTMsgKey:(211)AuthSvcAODBIEIndKey
Caller Service(-1):IndicationCode(200)Got OAUTH2 Token
,TransactionID(727687822)
0529144829|auth |2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(101)AuthServiceWTMsgKey:(214)AuthSvcAOFsmRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(727687822)
0529144829|cfg  |5|00|RT|cfgRtUpdateLoginCredentials: executing.
0529144829|cfg  |5|00|RT|cfgRtUpdateLoginCredentials: mode = Host.
0529144829|cfg  |5|00|RT|cfgRtUpdateLoginCredentials: flash LoginCredentials Empty
0529144829|nisvc|2|00|Request(-1)nisvc,(4)ServiceSetMsgKey,(-1),(-1),(Expiry,TransactionId,Time,Type):(-1,-1,1559159309,0)IndicationLevel:(200)
0529144829|so   |4|00|[soRegistrationC] Login Credentials empty causing SoRegEventLine Deleted
0529144829|cfg  |5|00|RT|cfgRtUpdateLoginCredentials: executing.
0529144829|cfg  |5|00|RT|cfgRtUpdateLoginCredentials: mode = Host.
0529144829|cfg  |5|00|RT|cfgRtUpdateLoginCredentials: flash LoginCredentials Empty
0529144829|nisvc|2|00|Request(-1)nisvc,(4)ServiceSetMsgKey,(-1),(-1),(Expiry,TransactionId,Time,Type):(-1,-1,1559159309,0)IndicationLevel:(200)
0529144829|so   |4|00|[soRegistrationC] Login Credentials empty causing SoRegEventLine Deleted
0529144829|cfg  |5|00|Prm|Parameter device.lync.timeZone requested type 7 but is of type 1
0529144829|cfg  |5|00|Prm|Parameter device.lync.timeZone requested type 7 but is of type 1
0529144829|app1 |4|00|AppBrowserUiC::updateConfiguration(): calling startBrowserUI()
0529144829|app1 |4|00|AppBrowserUiC::updateConfiguration(): calling startBrowserUI()
0529144829|auth |2|00|SM Module: SM created Ref(35869)
0529144829|auth |2|00|<SM>(308)AuthServiceWTUsingOAuthStateMachine(0x43f23310):Ctx((336),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|S/E(sSAuthSvcWTS0,kBaseEventInit),rO(316)
0529144829|auth |2|00|<\SM>(308)AuthServiceWTUsingOAuthStateMachine(0x43f23310):Ctx((337),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|<SM>(308)AuthServiceWTUsingOAuthStateMachine(0x43f23310):Ctx((337),(1)kBaseEventInit,Ticks(0))
0529144829|auth |2|00|[prepareAndSendRequest]:[4355]:[17]:[https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc/OAuth]
0529144829|cfg  |5|00|Prm|Parameter feature.validate.peer.cert requested type 0 but is of type 7
0529144829|nisvc|2|00|Request(-1)nisvc,(701)NIServiceNiReqMsgKey,(-1)auth,(702)NIServiceNiResMsgKey,(Expiry,TransactionId,Time,Type):(-1,-1,1559159309,0)IndicationLevel:(200)
0529144829|auth |2|00|S/E(sSAuthSvcGetWTUsingOAuthToken,kBaseEventInit),rO(5)
0529144829|auth |2|00|<\SM>(308)AuthServiceWTUsingOAuthStateMachine(0x43f23310):Ctx((337),(5),Ticks(0))
0529144829|auth |2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
0529144829|auth |2|00|CAuthSvcUpdateTokenNotifier:: UserMode = [False]
0529144829|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(106)AuthServiceOAuthMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(200)Got OAUTH2 Token
,TransactionID(727687822)
0529144829|auth |2|00|Response(-1)auth,(106)AuthServiceOAuthMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,727687822,1559159309,1)IndicationCode:(200)Got OAUTH2 Token
0529144829|auth |2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(101)AuthServiceWTMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(144)AuthServiceCallerSnooper:IndicationCode(100)SM Started
,TransactionID(727687822)
0529144829|auth |2|00|Response(-1)auth,(101)AuthServiceWTMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,727687822,1559159309,1)IndicationCode:(100)SM Started
0529144829|nisvc|2|00|NI Module received cred.change
0529144829|nisvc|2|00|NI Module received cred.change
0529144830|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Enter

0529144830|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Default

0529144830|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Exit

0529144830|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Enter

0529144830|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Default

0529144830|brow |4|00|CWebLayoutMgr::handleProxyConfiguration Exit

0529144830|nisvc|2|00|

****************************HTTP SEND**************************

0529144830|nisvc|2|00|HTTP SEND:: DestUrl(https://webdir4a.online.lync.com/WebTicket/WebTicketService.svc/OAuth), HttpResCode(200), curlRetCode(0) retVal(0)
0529144830|nisvc|2|00|ErrorBuffer::
0529144830|nisvc|2|00|

[SteffenBaierUK]

Hello @JoshuaHasson 

Just like this user => here <= please be aware of the following when utilizing UCS 4.1.0 or later:

The use of Polycom UC Software versions 4.1.X (“Software”) requires the purchase of a separate Software license for every device that will use the Software in a LYNC / Skype for Business environment. You may not install, access, or use the Software in a LYNC / Skype for Business environment on more devices than are listed on your license until additional licenses have been purchased and authorized by Polycom. These licenses should be purchased from the same company from which you purchased the devices. You may operate devices against a LYNC / Skype for Business server for trial purposes for up to 30 days without purchasing a license. Use of the Software is subject to the terms and conditions of the End User License Agreement.

Polycom reserves the right to audit your deployment to verify that you have sufficient licenses to match the number of devices being used.

Information in regards to License Part Numbers can be found here

The serial 64167F44E6DA is a VVX401 2200-48400-025 aka not a -019 SKU and was sold via SCANSOURCE INC back in 14/08/2018.

Do you have the relevant Skype for Business per Phone licenses for all the phones you are using within your organisation?

In relation to MFA / Failed to fetch the user certificate the community search finds many similar posts but you need to clarify your licensing situation before moving forward.

Once this has been established you can open a ticket via Scansource and we are happy to help you.

Best Regards

Steffen Baier

[JoshuaHasson]

All employees are E5 Licensed in Office 365 and have a Domestic Calling Plan. 

As stated in the issue above, all users could connect to SfB on 5.9.2 UCS of the VVX401 and BToE 3.9. However after implementing MFA, the phone will not fully sign-in. 

[SteffenBaierUK]

Hello @JoshuaHasson 

We are not talking about a Skype License, we are talking about a Polycom per device license in order to utilize Skype for Business with a Polycom phone which was not purchased as a -018 or -019 SKU

5150-49252-001	SW,LIC,LYNC ENTERPRISE IND PHONE
5150-49253-001	SW,LIC,LYNC ENTERPRISE SITE (5 UNITS)
5150-49254-001	SW,LIC,LYNC ENTERPRISE SITE (10 UNITS)
5150-49255-001	SW,LIC,LYNC ENTERPRISE SITE (100 UNITS)
5150-49256-001	SW,LIC,LYNC ENTERPRISE SITE (1000 UNITS)
5150-49257-001	SW,LIC,LYNC ENTERPRISE SITE (10000 UNITS)

The above licenses need to be either purchased or you need proof of purchase of these via purchase order.

Please ensure to provide some feedback if this reply has helped you so other users can profit from your experience.

Best Regards

Steffen Baier