VVX 501/601 - Incorrect Time offset from DHCP [5.4.3.2036]

[Sean.Stanley66]

I'm testing the VVX 501 and 601 models for use in production.  I have noticed that the phones are not applying the time offset correctly when DHCP option 002 is set to -5, 0xFFFFB9B0.  The phones are using GMT without any offset.

All other phone models, VVX 400, 401, 410, 411, 600, work fine and apply their respective offset received from DHCP.

I have tested the 501/601 with other time offsets and the time adjusts correctly.  (I've tested +8, and -8)

Recently released software, 5.5.1 Rev Q(5.5.1.15937), works fine with all time offsets.

We have over 2000 phones running in production without issue, is there a known bug with the VVX 501/601 when it comes to time offset and EST?

I do see the 501/601 getting -18000 for a time offset in their logs.

Software: 5.4.3.2036

Thanks

Sean

[SteffenBaierUK]

Please open a ticket via the known channels

Replied via a mobile device

[eandron]

I am running into a similair issue. When trying to log into Skype for Business from the web interface it just hangs there for a very long time until I cancel. Version and Logs below. I have been going back and forth with settings and NTP and DHCP settings. Still unable to figure out the issue. I think there is an issue with DNS but according to Office365 all records are correct. Please help if you can.

Phone Information
Phone Model    VVX 601
Part Number    3111-48600-001 Rev:A
IP Mode    IPv4
IP Address    10.11.165.70
UC Software Version    5.5.1.15937
Updater Version    5.7.1.17460

001300.145|cfg  |4|00|Prov|CfgDhcpInformControl::ExtractOptions: DHCP ACK message failed initial validation. Skipping parsing of DHCP options.
001308.145|cfg  |4|00|Prov|CfgDhcpInformControl::ExtractOptions: DHCP ACK message failed initial validation. Skipping parsing of DHCP options.
001311.177|sip  |4|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList 'ecaplp.com' found no records
001311.273|sip  |4|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList 'ecaplp.com' found no records
001311.534|sip  |4|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList 'ecaplp.com' found no records
001311.534|sip  |4|00|doDnsListLookup(tls): doDnsSrvLookupForARecordList 'sipinternal.ecaplp.com' found no records
001313.064|sip  |4|00|CTcpSocket::Abandon - TLS Listen Thread has exited. Process further to abandon this socket
001313.064|sip  |4|00|CTcpSocket::Abandon connected socket. Send Message 0xb62c17c8
001313.150|sip  |4|00|SSL_get_error Error code=5,rc(0)
001313.150|sip  |4|00|TLS Listen Thread Exit
001313.655|utilm|4|00|uBLFUnCompressed: File /ffs0/Config/Local/WebTicket/0/private.key doesn't exist or is empty
001313.655|sip  |*|00|Sending User Cert fetch Request: OnlyTlsDsk[1]
001313.665|AuthS|2|00|Request(-1)AuthSvc,(102)AuthServiceUCMsgKey,(-1)pps,(14),(Expiry,TransactionId,Time,Type):(-1,-1,1514271949,0)IndicationLevel:(200)
001313.665|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(102)AuthServiceUCMsgKey:(205)AuthSvcAOServiceRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(-1)
001313.665|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(102)AuthServiceUCMsgKey:(208)AuthSvcAODBAddKey
Caller Service(-1):IndicationCode(0)
,TransactionID(-1)
001313.665|AuthS|2|00|Silent Add Notifier, CallerService(AuthServiceCallerSnooper)
001313.665|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(102)AuthServiceUCMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(101)AuthServiceWTMsgKey:(208)AuthSvcAODBAddKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Silent Add Notifier, CallerService(AuthServiceCallerSnooper)
001313.666|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(102)AuthServiceUCMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(145)AuthServiceCallerSnooper:IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Reqponse(-1)AuthSvc,(102)AuthServiceUCMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1694001916,1514271949,1)IndicationCode:(0)
001313.666|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(101)AuthServiceWTMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(105)AuthServiceUTMsgKey:(208)AuthSvcAODBAddKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Silent Add Notifier, CallerService(AuthServiceCallerSnooper)
001313.666|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(101)AuthServiceWTMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(145)AuthServiceCallerSnooper:IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Reqponse(-1)AuthSvc,(101)AuthServiceWTMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1694001916,1514271949,1)IndicationCode:(0)
001313.666|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(105)AuthServiceUTMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(105)AuthServiceUTMsgKey:(214)AuthSvcAOFsmRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((359),(1)kBaseEventInit,Ticks(0))
001313.666|AuthS|2|00|S/E(sSAuthSvcUTS0,kBaseEventInit),rO(305)
001313.666|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((340),(1)kBaseEventInit,Ticks(0))
001313.666|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((340),(1)kBaseEventInit,Ticks(0))
001313.666|AuthS|2|00|[prepareAndSendRequest]:[4283]:[1]:[https://webdirGB1.online.lync.com:443/CertProv/CertProvisioningService.svc/mex]
001313.666|cfg  |5|00|Prm|Parameter feature.validate.peer.cert requested type 0 but is of type 7
001313.666|AuthS|2|00|S/E(sSAuthSvcGetServers,kBaseEventInit),rO(5)
001313.666|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((340),(5),Ticks(0))
001313.666|AuthS|2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
001313.666|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(105)AuthServiceUTMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(145)AuthServiceCallerSnooper:IndicationCode(0)
,TransactionID(1694001916)
001313.666|AuthS|2|00|Reqponse(-1)AuthSvc,(105)AuthServiceUTMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1694001916,1514271949,1)IndicationCode:(0)
001313.667|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(105)AuthServiceUTMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(145)AuthServiceCallerSnooper:IndicationCode(100)SM Started
,TransactionID(1694001916)
001313.667|AuthS|2|00|Reqponse(-1)AuthSvc,(105)AuthServiceUTMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1694001916,1514271949,1)IndicationCode:(100)SM Started
001314.146|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((340),(301)kEAuthOnRecvDataResponse,Ticks(0))
001314.150|AuthS|2|00|m_RetVal[0] eReqRspID[1] curlReturn[0] HttpRspCode[200] messageLen[13455]
001314.150|AuthS|2|00|S/E(sSAuthSvcGetServers,kEAuthOnRecvDataResponse),rO(3)
001314.150|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((343),(1)kBaseEventInit,Ticks(0))
001314.150|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((343),(1)kBaseEventInit,Ticks(0))
001314.150|AuthS|2|00|[prepareAndSendRequest]:[4283]:[3]:[https://webdirgb1.online.lync.com/WebTicket/WebTicketService.svc/mex]
001314.150|cfg  |5|00|Prm|Parameter feature.validate.peer.cert requested type 0 but is of type 7
001314.150|AuthS|2|00|S/E(sSAuthSvcGetTokenProvider,kBaseEventInit),rO(5)
001314.150|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((343),(5),Ticks(0))
001314.661|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((343),(301)kEAuthOnRecvDataResponse,Ticks(0))
001314.664|AuthS|2|00|m_RetVal[0] eReqRspID[3] curlReturn[0] HttpRspCode[200] messageLen[13132]
001314.664|AuthS|2|00|S/E(sSAuthSvcGetTokenProvider,kEAuthOnRecvDataResponse),rO(3)
001314.664|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(1)kBaseEventInit,Ticks(0))
001314.664|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(1)kBaseEventInit,Ticks(0))
001314.664|AuthS|2|00|S/E(sSAuthSvcUTEnd,kBaseEventInit),rO(3)
001314.664|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(3),Ticks(0))
001314.664|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(3),Ticks(0))
001314.664|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(-1),Ticks(0))
001314.664|AuthS|2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(105)AuthServiceUTMsgKey:(215)AuthSvcAOFsmReplyKey
Caller Service(-1):IndicationCode(200)Got User Type
,TransactionID(1694001916)
001314.664|AuthS|2|00|Silent Indication, CallerService(AuthServiceCallerSnooper)
001314.665|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(105)AuthServiceUTMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(200)Got User Type
,TransactionID(1694001916)
001314.665|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(101)AuthServiceWTMsgKey:(211)AuthSvcAODBIEIndKey
Caller Service(-1):IndicationCode(200)Got User Type
,TransactionID(1694001916)
001314.665|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(106)AuthServiceOAuthMsgKey:(208)AuthSvcAODBAddKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001314.665|AuthS|2|00|Silent Add Notifier, CallerService(AuthServiceCallerSnooper)
001314.665|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(105)AuthServiceUTMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(145)AuthServiceCallerSnooper:IndicationCode(200)Got User Type
,TransactionID(1694001916)
001314.666|AuthS|2|00|Reqponse(-1)AuthSvc,(105)AuthServiceUTMsgKey,(-1)lyncStatus,(14),(Expiry,TransactionId,Time,Type):(-1,1694001916,1514271950,1)IndicationCode:(200)Got User Type
001314.666|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(106)AuthServiceOAuthMsgKey:(212)AuthSvcAODBDBIndKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001314.666|AuthS|2|00|Policy Dest:(203)AuthServicePolicyFsmKey:(106)AuthServiceOAuthMsgKey:(214)AuthSvcAOFsmRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(1694001916)
001314.666|AuthS|2|00|<SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((501),(1)kBaseEventInit,Ticks(0))
001314.666|AuthS|2|00|S/E(sSOAuth2S0,kBaseEventInit),rO(5)
001314.666|AuthS|2|00|<\SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((501),(5),Ticks(0))
001314.666|AuthS|2|00|<SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((501),(501)kEOAuth2OAuth2Start,Ticks(0))
001314.666|AuthS|2|00|S/E(sSOAuth2S0,kEOAuth2OAuth2Start),rO(503)
001314.666|AuthS|2|00|<\SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((502),(1)kBaseEventInit,Ticks(0))
001314.666|AuthS|2|00|<SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((502),(1)kBaseEventInit,Ticks(0))
001314.666|AuthS|2|00|S/E(sTSOAuth2CheckOAuthTokenProvider,kBaseEventInit),rO(3)
001314.666|AuthS|2|00|<\SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((503),(1)kBaseEventInit,Ticks(0))
001314.666|AuthS|2|00|<SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((503),(1)kBaseEventInit,Ticks(0))

001330.072|app1 |5|00|AppPhoneLockC::Init - bPhoneLockState [0]
001330.078|sip  |*|00|Sip UnRegister Usr:eandron@domain.na Dsp:jeisenstat Auth:'' Inx:0
001330.078|sip  |*|00|SipUserRemove: user 0 being removed.
001330.078|WADSe|2|00|Request(-1)WADService,(778)WADServiceReqMsgKey,(-1)pps,(-1),(Expiry,TransactionId,Time,Type):(0,-1,1514271965,0)IndicationLevel:(200)
001330.078|AuthS|2|00|Request(-1)AuthSvc,(104)AuthServiceGeneralMsgKey,(-1)pps,(18),(Expiry,TransactionId,Time,Type):(0,-1,1514271965,0)IndicationLevel:(200)
001330.079|proxy|2|00|CProxyService:: General Msg, Expiry(0)
001330.079|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(104)AuthServiceGeneralMsgKey:(205)AuthSvcAOServiceRequestKey
Caller Service(-1):IndicationCode(0)
,TransactionID(17770444)
001330.079|AuthS|2|00|Policy Dest:(202)AuthServicePolicyDBKey:(-1):(209)AuthSvcAODBRemoveKey
Caller Service(-1):IndicationCode(0)
,TransactionID(17770444)
001330.079|AuthS|2|00|<SM>(333)AuthServiceWTUsingOAuthStateMachine(0xb57b8c08):Ctx((362),(7)kBaseEventStop,Ticks(0))
001330.079|AuthS|2|00|<\SM>(333)AuthServiceWTUsingOAuthStateMachine(0xb57b8c08):Ctx((362),(-1),Ticks(0))
001330.079|AuthS|2|00|<SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(7)kBaseEventStop,Ticks(0))
001330.079|AuthS|2|00|<\SM>(329)AuthServiceUTStateMachine(0xb57b1ad0):Ctx((370),(-1),Ticks(0))
001330.081|sip  |*|00|Sip Register Usr:VVX601 Dsp:VVX 601 Auth:'Using Login Cred' Inx:0
001330.100|utilm|4|00|uBLFUnCompressed: File /ffs0/Config/Local/WebTicket/0/sip.usr doesn't exist or is empty
001330.101|AuthS|2|00|<SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((511),(7)kBaseEventStop,Ticks(0))
001330.101|AuthS|2|00|<\SM>(330)AuthServiceOAuthStateMachine(0xb57b7458):Ctx((511),(-1),Ticks(0))
001330.101|AuthS|2|00|Policy Dest:(201)AuthServicePolicyServiceKey:(104)AuthServiceGeneralMsgKey:(206)AuthSvcAOServiceReplyKey
Caller Service(-1):IndicationCode(302)Resource Removed Permanently
,TransactionID(17770444)
001330.102|AuthS|2|00|Reqponse(-1)AuthSvc,(-1),(-1),(-1),(Expiry,TransactionId,Time,Type):(-1,17770444,1514271965,1)IndicationCode:(302)Resource Removed Permanently
001330.102|AuthS|2|00|Number Of Controllers=0
001334.886|sip  |*|00|User removed
001335.076|copy |4|00|Configuration of URL failed
001335.076|cfg  |4|00|Prov|Could not download file 64167f03c2e4-web.cfg
001335.076|cfg  |4|00|Prov|Uploading phoneWeb.cfg failed
001335.076|cfg  |4|00|Prov|Update configuration failed

[SteffenBaierUK]

Hello @eandron,

welcome to the Polycom Community.

A couple of things:

1. First of all your reply has nothing to do with the original posters as they complained about an offset issue and this is not the case in your post.
   
   
2. You are missing an NTP server highlighted in your log in red. Without NTP the phone cannot validate any certificate.
   
   
3. Your DNS is not setup correctly.
   
   
4. Your VVX601 is not a Skype for Business SKU as explained in detail => here <=

The community's Skype for Business FAQ contains this post here:

Jan 17, 2017 Question:How can I troubleshoot simple Skype for Business, LYNC or Office365 issues?

Resolution: Have a look => 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

[eandron]

thank you for responding.

Please explain what is missing with the NTP. Our DHCP by default is giving out NTP. Is the DNS you are speaking about the domain name that is being used to login into Office365/Skype for business? if so are we supposed to add a record in the domain name records? sorry for being confused on this but i am a bit confused.. According to Microsoft Office 365 all DNS records are correct for lync.

As far as "Your VVX601 is not a Skype for Business SKU as explained in detail" does this mean the phone cant be used? please explain.

thanks in advance.

[SteffenBaierUK]

Hello @eandron,

I already replied with an FAQ that you can utilize to troubleshoot your NTP issue. In addition your DNS Setup should not cause any error messages.

I cannot help you setting up your network in regards of DNS and I can only point you to the FAQ posts that describe how to troubleshoot NTP issues.

You clearly do not have an NTP server setup for this subnet or the log time would show MMDDHHMMSS.

In regards of the Phone SKU you have not purchased a phone that entitles you to be used for Skype for Business so you need to purchase an additional Polycom per phone license.

Redington Distri Pte Ltd sold this phone back in 29/05/2017 so you can work with them.

In order to raise a support ticket you need to work with Redington Distri Pte Ltd as they need to do this for you.

End Customers are unable to open a ticket directly with Polycom support.

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

[eandron]

 I really do appreciate the response.

What i dont understand is the DNS that you are referring to.

doDnsListLookup(tcp): doDnsSrvLookupForARecordList 'ecaplp.com' found no records
001311.273|sip  |4|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList 'ecaplp.com' found no records
001311.534|sip  |4|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList 'ecaplp.com' found no records
001311.534|sip  |4|00|doDnsListLookup(tls): doDnsSrvLookupForARecordList 'sipinternal.ecaplp.com' found no records

The DNS records for the domain are according to Microsoft setup correctly. Records below.  That being said what are the above records looking for if the records for Lync are set correctly.

_____________________________________

Type

Priority

Host name

Points to address or value

TTL

CNAME

-

sip

sipdir.online.lync.com

1 Hour

CNAME

-

lyncdiscover

webdir.online.lync.com

1 Hour

Type

Service

Protocol

Port

Weight

Priority

TTL

Name

Target

SRV

_sip

_tls

443

1

100

1 Hour

@

sipdir.online.lync.com

SRV

_sipfederationtls

_tcp

5061

1

100

1 Hour

@

sipfed.online.lync.com

___________________________________

[SteffenBaierUK]

Hello @eandron,

our phone does not just print these errors in the log. It simply does not get a response from your DNS server for these.

The FAQ explains how to take a wireshark trace remotely so in doing this prior to signing in it may help you identify these.

Our internal records show that back in November someone attempted to open a ticket with Polycom support in regards of a changed Internet provider, This does not match with the details you provided here.

Again please ensure you have the relevant Polycom per phone licenses required when using a non Skype SKU for all the phones you are utilizing.

I also provided you with the details who to contact if you need further support.

Other Polycom members can try and help you of course in their own convenience. 

Best Regards

Steffen Baier

Polycom Global Services

[eandron]

yes please provide a contact person to speak with.

I still do not understand the DNS response. The DNS local to the phone is using google DNS. My question is why does the phone need any other records besides the ones i pasted in my previous post and confirmed to be correct . If its looking to the external DNS for the domain name in quesiton then what additional records "could" it possibly need. Any that being said everything else works with all other DNS records. this is why im confused by the DNS response.

[SteffenBaierUK]

Hello @eandron,

not knowing the history or who you purchased these phones originally from I can only suggest you utilize an Internet search engine if the person who sold you the units is unable to help you.

All I know is that the internal Polycom ticket was opened on something completely different as what you now describe.

In regards for your DNS issue it is looking up the 

ecaplp.com

Domain.

I do not know what or who your organisation is or what Email credentials you use so please work with Microsoft and/or your reseller who sold you these units.

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