Plantronics + Polycom. Now together as Poly Logo

VVX410 Reboot Loop

SOLVED
Advisor

VVX410 Reboot Loop

Hi,

We have an FTP provisioning deployed and we are successfully pushing firmware (5.4.2.2834) and our configuration to VVX500s successfully.  I have a test environment setup identical to my clients.  I can image 410s, 500s, 600s and trio 8800s without issue.

 

At my client we have successfully imaged about (10) VVX500s, the pull the firmware and configuration perfectly at site 1 and site 2.  I'm working with one of the administrators at Site 2 and he is trying to manually point (3) 410's at our provisioning server in site 1.  It apperas the 410's pull the firmware down fine and load the configuration and successfully boot up and sign in to SFB.  After about 5 minutes the phones reboot and seem to start the process over again.  This process will continually repeat.  If we factory reset, it will just do it again all the time.  It doesnt seem to be an isoloated issue because all (3) 410's are experiencing this behavior.  VVX500's at the same site do not exibit this behavior.  I am having someone at site 1 test a VVX410 to see if it's related to the site.  The client is using an Avaya switch. LLDP is turned on for those ports and PoE is limited to 16 watts.

 

I tried to review the boot log for one of the 410s and I don't have a good understanding how to read these logs but to me it looks like the phone is trying to hit one of our Lync 2013 front end servers and maybe pull an older update?

 

Anyone have any ideas? Here's the bootlog for the phone.

000018.783|dhcpc|*|01|Initial log entry. Current logging level 2
000018.785|dhcpc|3|01|dhcAddIf v4 succeeds: eth0.
000018.790|dhcpc|3|01|dhcRebind v4: Will wait until sync rebind completes.
000019.445|dhcpc|3|01|dhcListener: Read succeeds: state:
.
000019.449|dhcpc|3|01|relLease(0) v4: Succeeded to fork dhclient to terminate.
000020.106|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: PREINIT
.
000020.107|dhcpc|4|01|DhcpClient::processLine: no callback for state 1 if eth0
000021.323|dhcpc|3|01|dhcListener: Read succeeds: eth0 ip: 10.110.33.56
.
000021.324|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: subnet-mask 255.255.255.0
.
000021.326|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: routers 10.110.33.1
.
000021.327|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name-servers 10.110.188.60 10.110.188.61
.
000021.329|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 86400
.
000021.331|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-server-identifier 10.110.188.60
.
000021.336|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: broadcast-address 10.110.33.255
.
000021.341|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 86400
.
000021.342|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-message-type 5
.
000021.344|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-renewal-time 43200
.
000021.346|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp_rebinding_time 75600
.
000021.358|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: o-128 Nortel-i2004-B, s1ip=10.110.100.50;p1=4100;a1=1;r1=7; s2ip=10.120.100.50;p2=4100;a2=1;r2=7;vq=y,vlanf=n,bt=y.
.
000021.369|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: o-191 VLAN-A:133
.
000021.383|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: BOUND
.
000021.383|dhcpc|4|01|DhcpClient::processLine: no callback for state 2 if eth0
000021.384|dhcpc|3|01|dhcRebind v4: Sync rebind succeeds.
000021.385|dhcpc|3|01|Program eth0 to use subnet mask 255.255.255.0, result -1.
000021.385|dhcpc|3|01|Program eth0 to use ip address 10.110.33.56, result 0.
000021.386|dhcpc|3|01|Program eth0 to use router 10.110.33.1, result 0.
000021.403|dhcpc|3|01|getLease v4: Succeeded to fork dhclient for interface eth0.
000022.395|ares |*|01|Initial log entry. Current logging level 3
000022.397|dns |*|01|DNS resolver servers are '10.110.188.60' '10.110.188.61'
000022.397|dns |*|01|DNS resolver search domain is ''
000022.397|app1 |3|01|DNS resolver servers are '10.110.188.60' '10.110.188.61'
000022.397|app1 |3|01|DNS resolver search domain is ''
000022.435|app1 |3|01|DHCP returned result 0x187 from server 10.110.188.60.
000022.435|app1 |3|01| Phone IPv4 address is 10.110.33.56.
000022.438|app1 |3|01| Subnet mask is 255.255.255.0.
000022.438|app1 |3|01| Gateway address is 10.110.33.1.
000022.438|app1 |3|01| DNS server is 10.110.188.60
000022.438|app1 |3|01| DNS alternate server is 10.110.188.61.
000022.468|cfg |*|01|Prov|Starting to update
000022.506|copy |3|01|'http://PlcmSpIp:****@lync2013.domain.com/RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/3111-46162-001.CPE.nbt' from 'lync2013.domain.com(10.110.186.20)'
0427100238|app1 |3|01|Time has been set from pool.ntp.org (70.33.56.18).
0427100238|app1 |3|01| 1461751358: 2016-4-27, 10:2:38, DST off
0427100238|copy |3|01|Download of 'RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/3111-46162-001.CPE.nbt' FAILED on attempt 1 (addr 1 of 1)
0427100238|copy |*|01|Server 'lync2013.domain.com' said 'RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/3111-46162-001.CPE.nbt' is not present
0427100238|cfg |3|01|Could not get all 512 bytes of the header
0427100238|app1 |4|01|Error downloading
0427100238|cfg |*|01|Prov|Starting to update
0427100238|copy |3|01|'http://PlcmSpIp:****@lync2013.domain.com/RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/CPE.nbt' from 'lync2013.domain.com(10.110.186.20)'
0427100238|cfg |3|01|New load header information:
0427100238|cfg |3|01|Code length: 0x025FE030
0427100238|cfg |3|01|Code Checksum: 0x38A19233
0427100238|cfg |3|01|Options: 0x00000080
0427100238|cfg |3|01|Recognized container image
0427100238|cfg |3|01|New load header information:
0427100238|cfg |3|01|Code length: 0x01F1FC9C
0427100238|cfg |3|01|Code Checksum: 0xF805D40A
0427100238|cfg |3|01|Options: 0x00000002
0427100238|cfg |3|01|Could not open application file for checking
0427100238|cfg |3|01|Application in container image 1 is different
0427100238|cfg |3|01|New load header information:
0427100238|cfg |3|01|Code length: 0x006DDA94
0427100238|cfg |3|01|Code Checksum: 0x38A0F38E
0427100238|cfg |3|01|Options: 0x00000010
0427100238|cfg |3|01|Updater is already present
0427100238|cfg |3|01|Updater in container image 2 is not different
0427100238|cfg |3|01|Using application
0427100238|cfg |*|01|Prov|Updating the Application
0427100238|cfg |3|01|Using compatible image 0
0427100453|copy |3|01|buffered_write: transfer terminated
0427100453|copy |3|01|Download of 'RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/CPE.nbt' succeeded on attempt 1 (addr 1 of 1)
0427100454|sig |*|01|Initial log entry. Current logging level 3
0427100454|sig |3|01|hwSigParseRemove: found key Sig_3.
0427100456|cfg |3|01|Good image signature
0427100457|cfg |3|01|Programming 32636632 bytes into tffs in 4K blocks
0427100500|cfg |3|01|Extracting application files
0427100500|cfg |3|01|New load header information:
0427100500|cfg |3|01|Code length: 0x01F1FC9C
0427100500|cfg |3|01|Code Checksum: 0xF805D40A
0427100500|cfg |3|01|Options: 0x00000002
0427100713|cfg |3|01|Finished extracting application files (OK)
0427100729|cfg |3|01|File system is synchronized
0427100730|cfg |*|01|Prov|Succeeded updating file http://lync2013.domain.com/RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/CPE.nbt
0427100730|cfg |*|01|Prov|Image has been changed
0427100730|copy |3|01|'ftp://PlcmSpIp:****@netmon.domain.com/0004f28c756f.cfg' from 'netmon.domain.com(10.255.50.21)'
0427100730|copy |3|01|Download of '0004f28c756f.cfg' FAILED on attempt 1 (addr 1 of 1)
0427100730|copy |3|01|transport res: 78 respCode 550. transport error: Remote file not found. transport error buffer: Remote file not found.
0427100730|copy |3|01|Update of '/ffs0/newinit.mac' failed, leaving local copy intact
0427100730|copy |3|01|'ftp://PlcmSpIp:****@netmon.domain.com/000000000000.cfg' from 'netmon.domain.com(10.255.50.21)'
0427100730|copy |3|01|Download of '000000000000.cfg' succeeded on attempt 1 (addr 1 of 1)
0427100730|cfg |3|01|Prov|Provisioning succeeded
0427100730|app1 |3|01|Application, load: Type=SIP, Version=5.2.0.8330 25-Sep-14 18:53
0427100730|cfg |*|01|Prov|Finished updating configuration
0427100730|boot |*|01|Using TFFS for flash load
0427100730|boot |*|01|Code length: 0x01F1FC9C
0427100730|boot |*|01|Code checksum: 0xF805D40A
0427100730|app1 |4|01|Loaded application software/release/sip.ld from local system successfully.
0427100730|app1 |6|01|Uploading boot log, time is Wed Apr 27 10:07:31 2016
0427100730|copy |3|01|'ftp://PlcmSpIp:****@netmon.domain.com/logs/0004f28c756f-boot.log' to 'netmon.domain.com(10.255.50.21)'
0427100733|copy |3|01|Upload of 'logs/0004f28c756f-boot.log' succeeded on attempt 1 (addr 1 of 1)
0427100734|dhcpc|3|01|relLease(0) v4: Succeeded to fork dhclient to terminate.
0427100758|cfg |3|01|Prov|Shutting down
000009.066|so |*|01|---------- Initial log entry ----------
000009.066|so |*|01|+++ Note that Updater log times are in GMT +++
000009.066|boot |*|01|Initial log entry. Current logging level 3
000009.067|copy |*|01|Initial log entry. Current logging level 3
000009.067|utilm|*|01|Initial log entry. Current logging level 4
000009.067|hw |*|01|Initial log entry. Current logging level 4
000009.067|ethf |*|01|Initial log entry. Current logging level 4
000009.067|dns |*|01|Initial log entry. Current logging level 3
000009.067|curl |*|01|Initial log entry. Current logging level 3
000009.067|sec |*|01|Initial log entry. Current logging level 4
000009.088|wdog |*|01|Initial log entry. Current logging level 4
000009.088|lldp |*|01|Initial log entry. Current logging level 3
000009.088|cdp |*|01|Initial log entry. Current logging level 3
000009.088|key |*|01|Initial log entry. Current logging level 4
000009.089|so |3|01|SoKeyC::keyboardSetup(): Assigning virtual key: hwId 45 soKeyConcordVirtualTab[i].function 53
000009.111|so |3|01|Platform: Model=VVX 410, Assembly=3111-46162-001 Rev=A Region=0
000009.111|so |3|01|Platform: Board=3111-46162-001 2 0
000009.112|so |3|01|Platform: MAC=0004f28c756f
000009.113|so |3|01|Platform: BootBlock=3.0.4.0146 (46162-001) 10-Jan-13 20:21
000009.114|so |*|01|Platform: BootL1=1.0.0.0041 (46162-001) 10-Jan-13 20:16
000009.114|so |3|01|Application, main: Label=Updater, Version=Albite 5.4.0.8782 25-Sep-14 18:22
000009.114|so |3|01|Application, main: P/N=3150-11069-540
000009.114|log |*|01|Install file upload callback for 'Updater'
000009.115|app1 |*|01|Initial log entry. Current logging level 3
000009.159|cfg |*|01|Initial log entry. Current logging level 2
000009.178|dot1x|*|01|Initial log entry. Current logging level 3
000009.178|app1 |3|01|Starting provisioning because of the start type.
000009.402|tls |*|01|Initial log entry. Current logging level 4
000010.086|so |3|01|Link status is Net up Speed 1000 full Duplex, PC down.
000015.481|lldp |3|01|LLDP received a response from a switch. LLDP enabled.
000015.664|dhcpc|*|01|Initial log entry. Current logging level 2
000015.666|dhcpc|3|01|dhcAddIf v4 succeeds: eth0.
000015.672|dhcpc|3|01|dhcRebind v4: Will wait until sync rebind completes.
000016.322|dhcpc|3|01|dhcListener: Read succeeds: state:
.
000016.326|dhcpc|3|01|relLease(0) v4: Succeeded to fork dhclient to terminate.
000016.978|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: PREINIT
.
000016.979|dhcpc|4|01|DhcpClient::processLine: no callback for state 1 if eth0
000018.181|dhcpc|3|01|dhcListener: Read succeeds: eth0 ip: 10.110.33.56
.
000018.183|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: subnet-mask 255.255.255.0
.
000018.184|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: routers 10.110.33.1
.
000018.186|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name-servers 10.110.188.60 10.110.188.61
.
000018.188|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 86400
.
000018.189|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-server-identifier 10.110.188.60
.
000018.194|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: broadcast-address 10.110.33.255
.
000018.199|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 86400
.
000018.201|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-message-type 5
.
000018.203|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-renewal-time 43200
.
000018.204|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp_rebinding_time 75600
.
000018.216|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: o-128 Nortel-i2004-B, s1ip=10.110.100.50;p1=4100;a1=1;r1=7; s2ip=10.120.100.50;p2=4100;a2=1;r2=7;vq=y,vlanf=n,bt=y.
.
000018.228|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: o-191 VLAN-A:133
.
000018.242|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: BOUND
.

 

Message 1 of 5
4 REPLIES 4
Highlighted
Polycom Employee & Community Manager

Re: VVX410 Reboot Loop

Hello medlhuber,

welcome back to the Polycom Community.

looking at your log:

 

0427100453|copy |3|01|Download of 'RequestHandler/Files/3PIP/POLYCOM/VVX410/Rev-A/ENU/5.2.0.8330/CPE/CPE.nbt' succeeded on attempt 1 (addr 1 of 1)

You stated above that you are running 5.4.2

 

As you can see in the above snippet the phone tries to downgrade via the LYNC Server to software 5.2.0.8330

 

It then tries again:

 

0427100730|app1 |4|01|Loaded application software/release/sip.ld from local system successfully.

Not knowing to much about your setup I assume this is your local path to the software.

 

The FAQ therefore contains this post here:

 

Feb 02, 2016 Question:How can I prevent a Polycom VVX Business Media Phone to be downgraded / upgraded automatically via Skype for Business and/or Office365?

Resolution:Download, unpack and import the attached lyncDeviceUpdateEnabledOFF.zip

 

Or simply decide if you want the LYNC server to host the firmware or a local FTP server instead.

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 5
Advisor

Re: VVX410 Reboot Loop

Thanks for the response Steffen.  We definitely want to push firmware from the provisioning server, not the Lync server.

 

There is some old firmware updates out there on the Lync server that is being advertised, as you stated that is our problem, we have updates avaliable in both locations.  Can that firmware on the Lync server be safely deleted without impacting any phones that are not currently configured to use the provisioning server for configuration and updates?  We are still testing phones by manually pointing them to our provisioning server, but soon we plan to update DHCP and reconfigure all currently deployed phones.

 

Otherwise I am more curious about this statement below.  Where do I download this?

 

Resolution:Download, unpack and import the attached lyncDeviceUpdateEnabledOFF.zip

 

Is that related to these 2 parameters?  Can I set these to 0 to block the updates?  I tried adding these configurations to my lab environment and even after factoring resetting my phone it seems like it's trying to use both my provisioning server and the Lync server for updates.

 

device.prov.lyncDeviceUpdateEnabled="1" device.prov.lyncDeviceUpdateEnabled.set="1"  

 

Thanks

-Matt

 

Message 3 of 5
Advisor

Re: VVX410 Reboot Loop

I think I figured it out with the help of Jeff's blog.  Enable (1) the set command but disable (0) the update command.

 

http://blog.schertz.name/2013/10/updating-polycom-vvx-phones/

 

For example, to disable the Lync Device Update capability on the devices import the following sample configuration file into the phone.  In order to modify any individual device parameters it is required that the device.set and device.<parameterName>.set parameters are set to ‘1’ at the same time, otherwise the phone will ignore the configuration change.

<?xml version="1.0" encoding="utf-8"?>
<Lync device.set="1" device.prov.lyncDeviceUpdateEnabled.set="1"device.prov.lyncDeviceUpdateEnabled="0" />

Message 4 of 5
Polycom Employee & Community Manager

Re: VVX410 Reboot Loop

Hello medlhuber,

the referred zip file is attached to the Skype for Business FAQ within this section.

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 5