Plantronics + Polycom. Now together as Poly Logo

Decoding VVX500 Log file

Occasional Visitor

Decoding VVX500 Log file

Hi everyone,

 

I'm trying to get PIN authentication working on a range of Polycom devices for a new SfB 2015 on prem setup. We used to have Lync 2013 standard edition and the handsets worked for PIN auth fine. However we have replaced (migrated) to SfB 2015 with ENTERPRISE POOLS.

 

We are using ARR as our load balancers (for HTTP/S), and DNS Round Robin for the SIP/FE stuff.

 

Now we have moved to this new config, CX and VVX devices simply don't work with PIN auth. We are using 5.4.3.1014 on the VVX 500 I'm using for testing.

 

Can someone assist with the log files? Appears to be getting the DHCP options fine (I'm sure the DHCP is working without any issues), but failing further down...! Any help greatly appreciated!

 

0509165501|so   |4|00|[soRegistrationC] Login Credentials valid causing SoRegEventLine Changed
0509165501|ec   |4|00|Removing web ticket service
0509165501|ec   |4|00|Removed web ticket service
0509165504|sip  |*|00|dhcpOption120LyncQuery numList [1]
0509165505|tickt|4|00|[soWebTicketPinAuthGetRootCertChain]:[9412]  soRootCertGet returned Failure
0509165505|tickt|*|00|*********************Start [webTicketPrintAll]*****************
0509165505|tickt|*|00|uiSlot [0]
0509165505|tickt|*|00|m_pcSipUser [NULL]
0509165505|tickt|*|00|m_pcSipUuid [bffeaf91-4463-560e-8365-1ed6ad2baf1b]
0509165505|tickt|*|00|m_pcNtlmUser [NULL]
0509165505|tickt|*|00|m_pcNtlmDomain [NULL]
0509165505|tickt|*|00|m_pcStsUri [https://bur-skype-webint.domain.com:443/CertProv/CertProvisioningService.svc]
0509165505|tickt|*|00|m_validUntil [0]
0509165505|tickt|*|00|m_validityDuration [0]
0509165505|tickt|*|00|m_bCertExists [0]
0509165505|tickt|*|00|m_bCertExpired [1]
0509165505|tickt|*|00|m_eCredentialType [3]
0509165505|tickt|*|00|m_bForCedReSign [1]
0509165505|tickt|*|00|m_pcExt [7676]
0509165505|tickt|*|00|m_eLyncEnvironment [0]
0509165505|tickt|*|00|m_bLyncO365Enabled [0]
0509165505|tickt|*|00|m_eErrorCode [9]
0509165505|tickt|*|00|m_enInputEvent [23]
0509165505|tickt|*|00|m_csCertProvSvcUrl [https://bur-skype-webint.domain.com:443/CertProv/CertProvisioningService.svc]
0509165505|tickt|*|00|m_csWebTicketSvcUrl [https://bur-skype-webint.domain.com/WebTicket/WebTicketService.svc]
0509165505|tickt|*|00|m_csWebTicketProofUrl [https://bur-skype-webint.domain.com/CertProv/CertProvisioningService.svc/WebTicket_Proof_SHA1]
0509165505|tickt|*|00|m_csRootCertChainUrl [http://bur-skype-webint.domain.com/CertProv/CertProvisioningService.svc/anon]
0509165505|tickt|*|00|m_csFedDataMexUrl []
0509165505|tickt|*|00|m_csWebTicketServerPinAuth []
0509165505|tickt|*|00|m_csWebTicketServerCertAuth []
0509165505|tickt|*|00|m_csOrgIDAuthEndPointUrl []
0509165505|tickt|*|00|m_csOrgIDAuthEndPointBaseUrl []
0509165505|tickt|*|00|m_eLyncOnlineUserType [0]
0509165505|tickt|*|00|csTimeCreatedVal [NULL]
0509165505|tickt|*|00|csTimeExpVal [NULL]
0509165505|tickt|*|00|*********************End [webTicketPrintAll]*****************
0509165505|cfg  |5|00|Prm|Parameter device.lync.timeZone requested type 7 but is of type 1
0509165505|cfg  |5|00|Prm|Parameter device.lync.timeZone requested type 7 but is of type 1
0509165506|app1 |*|00|SoRegistrationEventLineChanged - success lineIndex 0 RegListSize 0
0509165506|app1 |*|00|SoRegistrationEventLast - new AppRegLineC, Default user
0509165506|so   |4|00|[SoNcasC]: appncascontext termination:1
0509165506|so   |4|00|[SoNcasC]: Case Handling termination:1
0509165506|sip  |*|00|Sip Register Usr:VVX500 Dsp:VVX 500 Auth:'Using Login Cred' Inx:0
0509165506|utilm|4|00|uBLFUnCompressed: File /ffs0/Config/Local/WebTicket/0/fedContactUrl.dom doesn't exist or is empty
0509165506|cfg  |5|00|Prm|Parameter attendant.reg requested type 2 but is of type 0
0509165506|app1 |4|00|MWI information : new message count is '0'
0509165506|ec   |4|00|Removing web ticket service
0509165506|ec   |4|00|Removed web ticket service
0509165506|ec   |4|00|Removing web ticket service
0509165506|ec   |4|00|Removed web ticket service
0509165506|app1 |4|00|MWI information : new message count is '0'
Message 1 of 9
8 REPLIES 8
Polycom Employee & Community Manager

Re: Decoding VVX500 Log file

Hello stevehoot,

welcome to the Polycom Community.

0509165505|tickt|4|00|[soWebTicketPinAuthGetRootCertChain]:[9412]  soRootCertGet returned Failure

 

You seem to have some issues and we would need CFG logging at event 2 and Tickt at Debug and overall logging at debug.

 

Please work with your Polycom reseller on this or check the FAQ.


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

Best Regards

Steffen Baier

Polycom Global Services




<======== Signature / Disclaimer ========>
Please be aware:For questions about the type of support to expect please check here

Please also ensure you always check the VoIP , Video Endpoint , Skype for Business , PSTN or RPM FAQ's

Please remember, if you see a post that helped you , and it answers your question, please mark it as an "Accept as Solution".

The title Polycom Employee & Community Manager is an automatic setting within the community and any forum reply or post is based upon my personal experience and does not reflect the opinion or view of my employer.
Poly employee participation within this community is not mandatory and any post or FAQ article provided by myself is done either during my working hours or outside working hours, in my private time, and maybe answered on weekends, bank holidays or personal holidays.
Message 2 of 9
Regular Advisor

Re: Decoding VVX500 Log file

Steve,

 

Check to make sure you can browse to the certificate service with /mex at the end you should get some XML as a response.   Is that host your new SfB pool?

https://bur-skype-webint.domain.com:443/CertProv/CertProvisioningService.svc/mex

 

Message 3 of 9
Occasional Visitor

Re: Decoding VVX500 Log file

Hi James,

 

Thanks for getting back to me.

 

Yep - if I browse to the path in IE it works fine, no cert errors from a domain joined Windows 7 laptop.

 

We have three FE servers with internal certs on them, but use ARR as a web reverse proxy / load balancer. The ARR server has a public CA wildcard on it, which I believe is fully supported using the latest firmware on the VVX devices. All other endpoints work fine (including mobility, Windows Store, Exchange intergration and the standard SfB 2015 client).

 

The error seems to point to the root certificate not being acquired, but the entire chain is installed correctly on the ARR server, so I'm unusure why this is happening. With ARR doing SSH proxying (again, this is supported in SfB 2015) surely the ARR that hands the certificates out and the entire chain...?

 

Does SfB itself hand out the certificate and chain? If so how does this fit in with using a reverse proxy that does SSH proxying?

 

Thanks again for your help,

 

Steve

Message 4 of 9
Polycom Employee & Community Manager

Re: Decoding VVX500 Log file

Hello stevehoot,

in my initial reply I had already outlined that we require different log's.

 

Also the VoIP FAQ contains:

 

Mar 04, 2016 Question:Do Polycom phones support wildcard certificates?

Resolution: Please check this post => here <=


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

Best Regards

Steffen Baier

Polycom Global Services




<======== Signature / Disclaimer ========>
Please be aware:For questions about the type of support to expect please check here

Please also ensure you always check the VoIP , Video Endpoint , Skype for Business , PSTN or RPM FAQ's

Please remember, if you see a post that helped you , and it answers your question, please mark it as an "Accept as Solution".

The title Polycom Employee & Community Manager is an automatic setting within the community and any forum reply or post is based upon my personal experience and does not reflect the opinion or view of my employer.
Poly employee participation within this community is not mandatory and any post or FAQ article provided by myself is done either during my working hours or outside working hours, in my private time, and maybe answered on weekends, bank holidays or personal holidays.
Message 5 of 9
Occasional Visitor

Re: Decoding VVX500 Log file

Hi Steffen,

 

Thanks. I'm a SfB administrator at heart - I don't usually do a great deal with endpoints usually so I needed to have a play with the device to work out how to modify the logging settings!

 

After changing the settings as you advised, I'm getting much more verbose information.

 

My understanding is that the VVX is attempting to download the root chain via the CertProv service on the FE servers, proxied via the ARR server. The traffic is hitting the right location (DHCP is working fine), and it returns the right URL's - even a HTTP 200 to confirm a web socket is made OK - but then when it attempts to perform "ACT_FetchRootCertChainPinAuth", which leads to a number of soWebTicketPinauthGetRootCertChain entries. These are below:

 

0510142207|tickt|2|00|soWebTicketPinauthGetRootCertChain: SpecialInterop_Lync2010 detected
0510142207|tickt|2|00|soWebTicketPinauthGetRootCertChain: autoProvision location is 6
0510142207|tickt|2|00|soWebTicketPinauthGetRootCertChain: Cert is not available at 6
0510142208|tickt|2|00|doXmlParsingForErrorCode: ErrorCode is:28100

 

Usefully, I get a full response back from ARR/SfB which states that that we are not authorised. Standard HTTP 401 (access denied due to invalid credentials):

 

0510142208|tickt|1|00|[soRootCertGetForPinAuth]:[9302] curlReturn [0] resCode[401] serErrorCode[28100] pResponse[HTTP/1.1 401 Unauthorized

 

The logging has helped confirm a few things, however it hasn't reallly pin-pointed the issue. (Pun intended!)

 

So all I can really sumise so far is that when the VVX is performing the tickt soWebTicketPinAuthGetRootCertChain step we get a failure back. The error appears to be invalid credentials, however I am confident that the extension and PIN are accurate. (I've created a new account with a new PIN just for this purpose).

 

I was under the impression that the root chain certificates should be downloaded without authentication...? Seems odd that I can sign in using username and password, but not PIN. What's differerent or special about certificates for PIN auth vs. normal auth? Is there anything special relating to using reverse proxies?

 

I've attached the full log if that's any help at all?!

 

Thanks - Steve

 

Message 6 of 9
Regular Advisor

Re: Decoding VVX500 Log file

Steve,

 

NTLM will not work with PIN auth.  Do you have a non-domain joined computer or a browser like Firefox that doesn't use WNA to test that URL with?  It looks like Anonymous authentication is not being allowed by the ARR/IIS server.

 

You said CX phones are not able to do PIN auth as well?   Have you also posted this in any Lync/SfB support forums?

 

 

Message 7 of 9
Occasional Visitor

Re: Decoding VVX500 Log file

Hi James.

 

Thanks - I've just tried this with firefox and to the /mex URL it works fine. Get nicely formatted XML that all seems fine... Hence why I'm so confused!

 

I've raised it with the SfB forums: https://social.technet.microsoft.com/Forums/windows/en-US/c3089028-94b1-4e0b-9d2d-c0890af0eb71/sfb-s...

 

The CX devices have the same issue.

 

Thanks - Steve

 

Message 8 of 9
Regular Advisor

Re: Decoding VVX500 Log file

Steve,

 

Have you tried using the STS-URI Override setting on a VVX phone to point it directly at one of your Front Ends?  See if you get different behavior going around the ARR. 

 

By any chance is there a PaloAlto firewall between your phones and the ARR?

Message 9 of 9