VVX300/400 FTP Provisioning Issue

[Anonymous]

Hello,

My company has been using Polycom Soundpoint IP 330/450/550 phones which are provisioned via an FTP server. There are no issues with these phones and the provisioning is working fine. We recently purchase a VVX300 and a VVX 400 to test on our systems as a new possible standard model going forward. If I either configure these to connect to our sip server via the web portal, or upload a config file via the web portal for the phones, they work fine. However, when I attempt to have these phones get their config files from the FTP server it fails to do so. I consistently see the following error in the app logs on the phone:

000101.877|cfg  |4|00|Prov|Download of master configuration file failed

I have a config file created with the phone's MAC address to use as its configuration but it does not seem to be grabbing it. The phone can ping the boot server and the server can ping the phone successfully. Where should I be looking to narrow down the cause of this issue? Below is the phone information. 

Phone Information

Phone Model VVX 300

Part Number 3111-46135-002 Rev:A

UC Software Version 4.1.7.1428

Updater Version 5.1.7.1368

[SteffenBaierUK]

Hello caboose877,

welcome to the Polycom Community.

Are these manually configured to get a boot server or are you using a DHCP Option?

If DHCP Option what actual Option ? 66, 160 or 161 ?

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

[Anonymous]

Hello,

These are manually configured to get to the boot server. 

[SteffenBaierUK]

Hello caboose877,

On the Phone:

Settings > Logging > Global Settings > Global Log Level Limit > Debug
Settings > Logging > Global Settings > Global Log Level Limit > Log File Size (Kbytes) > VVX = 180 or Trio 512
Settings > Logging > Module Log Level Limits > CURL > Debug

Then get the logs:

Diagnostics > View & Download Logs > UCS Application > Export
Diagnostics > View & Download Logs > System Log > Export

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

[Anonymous]

Hello,

Attached is the app log. It looks like we are getting more information with the new logging settings. The new error is:

530 User cannot log in, home directory inaccessible.

Which seems to indicate a permissions issue on the FTP server. I have reset the password for both the phone provisioning user on the server and the password entered on the phone with no change. 

[Anonymous]

Sorry, it looks like attachments to outside sites are disabled on our network. I will post the log with some sanitization of identifying information.

000208.543|app1 |5|00|Manual Reboot
000208.697|ldap |4|00|ldapXfer::start:xferStart failed cState=-1
000208.697|app1 |*|00|AppC::appReboot corp dir shutdown complete
000209.086|so |*|00|SoNcasC::procMsg: Client service shutdown complete
000224.086|wdog |*|00|Watchdog Expired: tSupObjs, 8
000224.086|log |*|00|---------- Final log entry ----------
000016.976|log |*|00|---------- Initial log entry ----------
000009.720|wdog |*|00|Initial log entry. Current logging level 4
000016.588|rdisk|*|00|Initial log entry. Current logging level 4
000016.594|rdisk|*|00|RAM disk created and mounted at "/rfs0"
000016.595|rdisk|*|00|RAM disk created, size: 16,777,216 bytes
000016.948|so |*|00|Platform: Model=VVX 300, Assembly=3111-46135-002 Rev=A Region=0
000016.951|so |*|00|Platform: Interface eth0 MAC=64167f91aa2c
000016.955|so |*|00|Platform: BootBlock=3.0.4.0028 (46135-002) 30-Jan-13 18:00
000016.956|so |*|00|Platform: BootL1=1.0.0.0009 (46135-002) 11-Jan-13 14:23
000016.965|so |*|00|Platform: Updater=5.1.7.1368 13-Apr-16 18:59
000016.965|so |*|00|Application, main: Label=SIP, Version=PrairieDog 4.1.7.1428 13-Apr-16 18:22
000016.965|so |*|00|Application, main: P/N=3150-11530-417
000016.965|rdisk|*|00|RAM disk created, size: 16,777,216 bytes
000016.970|ocsp |*|00|O.C.S.P. Enabled = 0
000016.986|log |4|00|UtilLogC:: Invalid Server Address.
000017.027|tls |*|00|Initial log entry. Current logging level 4
000017.078|pmt |*|00|Initial log entry. Current logging level 4
000017.081|wdog |*|00|Initial log entry. Current logging level 4
000017.083|ethf |*|00|Initial log entry. Current logging level 4
000017.084|hw |*|00|Initial log entry. Current logging level 4
000017.089|ares |*|00|Initial log entry. Current logging level 4
000017.091|dns |*|00|Initial log entry. Current logging level 4
000017.091|cfg |*|00|Initial log entry. Current logging level 4
000017.092|cfg |*|00|Prm|cfgParamBaseProfileUpdate: Using Base Profile Generic
000017.107|dot1x|*|00|Initial log entry. Current logging level 4
000017.126|ethf |4|00|utilEthFilterInit: VLAN Filter enabled, Storm Filter enabled
000017.311|lic |*|00|Initial log entry. Current logging level 4
000017.331|lic |5|00|cfgCfsFlashKeyScratchLoad: could not load flash len 976
000017.465|curl |*|00|Initial log entry. Current logging level 0
000017.465|utilm|*|00|Initial log entry. Current logging level 4
000017.467|copy |*|00|Initial log entry. Current logging level 4
000017.469|rtos |*|00|Initial log entry. Current logging level 4
000017.473|sec |*|00|Initial log entry. Current logging level 4
000017.504|so |*|00|Configuration files:
000017.519|log |*|00|Log render level set to 0
000017.532|pcap |*|00|On-Phone Packet Capture enabled
000017.537|srtp |*|00|Initial log entry. Current logging level 4
000017.550|cfg |5|00|Prm|Parameter 0 is out of range
000017.559|res |*|00|Initial log entry. Current logging level 4
000017.561|httpa|*|00|Initial log entry. Current logging level 4
000017.561|lldp |*|00|Initial log entry. Current logging level 4
000017.561|cdp |*|00|Initial log entry. Current logging level 4
000017.564|pcd |*|00|Initial log entry. Current logging level 4
000017.588|tickt|*|00|Initial log entry. Current logging level 4
000017.616|utilm|4|00|uBLFUnCompressed: File /ffs0/Config/Local/WebTicket/0/sip.usr doesn't exist or is empty
000017.622|tickt|4|00|soWebTicketCertMove: Could not copy key to new slot
000017.626|tickt|4|00|soWebTicketCertMove: Could not copy cert to new slot
000017.626|tickt|4|00|soWebTicketCertMove: Could not copy SIP user to new slot
000017.627|tickt|4|00|soWebTicketCertMove: Could not copy SIP uuid to new slot
000017.627|tickt|4|00|soWebTicketCertMove: Could not copy server to new slot
000017.633|loc |*|00|Initial log entry. Current logging level 4
000017.650|ssps |*|00|Initial log entry. Current logging level 4
000017.662|ssps |5|00|Allocated 36992 bytes for SspsHdiMemBase=0xb651b0
000017.666|ssps |4|00|sspsDspLoad: found Maroo 23.
000018.135|so |*|00|System Info Reports:
000018.135|so |*|00| Cpu is ARMv6-compatible processor rev 7 (v6l), ID: 0x111700b0, running at 300MHz.
000018.135|so |*|00| Board is identified as PolycomVVX-VVX_300.
000018.135|so |*|00| DRAM_SIZE: 128 MB
000018.135|so |*|00| NAND flash detected is 20
000018.137|key |*|00|Initial log entry. Current logging level 4
000018.185|httpd|*|00|Initial log entry. Current logging level 4
000018.194|poll |*|00|Initial log entry. Current logging level 4
000018.195|push |*|00|Initial log entry. Current logging level 4
000018.196|poll |*|00|Initial log entry. Current logging level 4
000018.198|poll |*|00|Initial log entry. Current logging level 4
000018.201|poll |*|00|Initial log entry. Current logging level 4
000018.201|poll |*|00|Initial log entry. Current logging level 4
000018.202|poll |*|00|Initial log entry. Current logging level 4
000018.204|ht |*|00|Initial log entry. Current logging level 4
000018.208|dbuf |*|00|Initial log entry. Current logging level 4
000018.215|ssps |*|00|sspsMain: Set HDI mem to be 0, was 0
000018.235|ssps |*|00|Application, comp. 1: Label=PolyDSP Vino BCM11195 Mem1 FS1, Version=7.7.2.7243 03-Oct-2013 18:31
000018.235|ssps |*|00|Application, comp. 1: P/N=3150-11580-772.
000018.235|ice |*|00|Initial log entry. Current logging level 4
000018.238|pps |*|00|Initial log entry. Current logging level 4
000018.240|sip |*|00|Initial log entry. Current logging level 4
000018.244|sipt |*|00|Initial log entry. Current logging level 4
000018.244|sipp |*|00|Initial log entry. Current logging level 4
000018.250|ptt |*|00|Initial log entry. Current logging level 4
000019.387|pwrsv|*|00|Initial log entry. Current logging level 4
000019.396|so |*|00|Using TCP IP Media Port, configured initial RTP port 2222
000019.423|cfg |5|00|Prm|Parameter dialplan.impossibleMatchHandling requested type 2 but is of type 0
000019.473|sshc |*|00|Initial log entry. Current logging level 4
000019.475|app1 |*|00|Initial log entry. Current logging level 4
000019.510|app1 |*|00|AppPhoneC::AppPhoneC() Number Of Line Keys = 48
000019.510|app1 |*|00|AppPhoneC::AppPhoneC() - new AppRegLineC, Default user
000019.590|ldap |*|00|Initial log entry. Current logging level 4
000019.590|ldap |4|00|cDynamicData::cDynamicData:cDynamicData:Failed
000019.764|efk |*|00|Initial log entry. Current logging level 4
000019.764|efk |4|00|EFK not enabled.
000019.764|efk |4|00|EFK param failed to initialize.
000019.764|efk |4|00|EFK feature is disabled.
000019.835|lic |4|00|License: feature Nuance XT9 is not available
000019.837|cfg |4|00|Dir|regAppCb set
000019.847|app1 |4|00|getCfgParams
000019.849|cmp |*|00|Initial log entry. Current logging level 4
000019.855|wmgr |*|00|Initial log entry. Current logging level 4
000019.871|slog |*|00|Initial log entry. Current logging level 3
000019.960|so |4|00|SoKeyC::procMsg unexpected message 4099
000024.630|pgui |*|00|Initial log entry. Current logging level 4
000032.354|dhcpc|*|00|Initial log entry. Current logging level 4
000032.650|cfg |4|00|RT|voIpProt.server.dhcp.option is not specified in config
000036.584|cfg |4|00|RT|DHCP CfgRtMsgDhcpUp is received.
000036.585|cfg |*|00|RT|Do not do DHCP VLAN Discovery.
000036.585|cfg |*|00|RT| Phone IP address is #.#.#.255.
000036.586|cfg |*|00|RT| Subnet mask is 255.255.254.0.
000036.586|cfg |*|00|RT| Gateway address is #.#.#.1.
000036.586|cfg |*|00|RT| DNS server is #.#.#.35.
000036.586|cfg |*|00|RT| DNS alternate server is #.#.#.42.
000036.586|cfg |*|00|RT| DNS domain is domainname.local.
000036.589|dns |*|00|DNS resolver servers are '#.#.#.35' '#.#.#.42'
000036.589|dns |*|00|DNS resolver search domain is 'domainname.local'
000036.593|cfg |*|00|RT|Primary IP: #.#.#.255 subnet mask 255.255.254.0
000036.654|so |*|00|Network initialized. Starting network tasks.
000036.658|ice |5|00|Network ICE stack failed to initialize in 5000 ms
000036.659|log |*|00|Install file upload callback for 'so'
000036.668|so |4|00|Could not find IP address for SNTP server. DnsRetryPeriod 86400
000036.685|sip |5|00|Bind Successful
000036.689|sip |5|00|Starting Accept Task
000057.291|pgui |*|00|Qt Mouse driver created.
000059.540|em |*|00|Initial log entry. Current logging level 4
000059.594|dbs |*|00|Initial log entry. Current logging level 4
000059.617|osd |*|00|Initial log entry. Current logging level 4
000100.018|clist|*|00|Initial log entry. Current logging level 4
000100.064|app1 |5|00|[connectToDatabase]: dbDirSet activated
000101.145|curl |3|00|timeout on name lookup is not supported
000101.147|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000101.147|curl |3|00| Trying #.#.#.36...
000101.149|curl |3|00|the local port callback returned 0
000101.149|curl |3|00|Local port: 16869
000101.153|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000101.158|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000101.160|curl |1|00|HEADER_OUT: USER vvx300
000101.161|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000101.162|curl |1|00|HEADER_OUT: PASS XXXX
000101.163|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000101.164|curl |3|00|Access denied: 530
000101.164|curl |3|00|Closing connection #0
000101.193|clist|4|00|dbIO::processResult:copy error
000101.194|clist|4|00|dbSet::srv2mem:transfer failed, trying to get local file
000101.200|curl |3|00|timeout on name lookup is not supported
000101.201|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000101.201|curl |3|00| Trying #.#.#.36...
000101.203|curl |3|00|the local port callback returned 0
000101.203|curl |3|00|Local port: 17433
000101.205|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000101.206|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000101.207|curl |1|00|HEADER_OUT: USER vvx300
000101.208|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000101.210|curl |1|00|HEADER_OUT: PASS XXXX
000101.211|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000101.211|curl |3|00|Access denied: 530
000101.212|curl |3|00|Closing connection #0
000101.233|clist|4|00|dbIO::processResult:copy error
000101.234|clist|4|00|dbSet::srv2mem:transfer failed, trying to get local file
000101.345|clist|4|00|dbSet::load:cleared load error state m_sync=<0x40>
000101.351|curl |3|00|timeout on name lookup is not supported
000101.358|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000101.359|curl |3|00| Trying #.#.#.36...
000101.360|curl |3|00|the local port callback returned 0
000101.361|curl |3|00|Local port: 16624
000101.363|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000101.365|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000101.366|curl |1|00|HEADER_OUT: USER vvx300
000101.367|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000101.368|curl |1|00|HEADER_OUT: PASS XXXX
000101.369|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000101.370|curl |3|00|Access denied: 530
000101.370|curl |3|00|Closing connection #0
000101.393|clist|4|00|dbIO::processResult:copy error
000101.393|clist|4|00|dbSet::srv2mem:transfer failed, trying to get local file
000101.882|sip |*|00|Sip Register Usr:VVX300 Dsp:VVX 300 Auth:'' Inx:0
000101.916|sip |*|00|Fast Boot Measurement Point: Ready for Call, uptime: 61.916 sec.
000101.955|curl |3|00|timeout on name lookup is not supported
000101.956|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000101.956|curl |3|00| Trying #.#.#.36...
000101.956|curl |3|00|the local port callback returned 0
000101.956|curl |3|00|Local port: 36573
000101.960|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000101.960|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000101.961|curl |1|00|HEADER_OUT: USER vvx300
000101.963|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000101.963|curl |1|00|HEADER_OUT: PASS XXXX
000101.965|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000101.965|curl |3|00|Access denied: 530
000101.965|curl |3|00|Closing connection #0
000101.969|curl |3|00|timeout on name lookup is not supported
000101.969|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000101.969|curl |3|00| Trying #.#.#.36...
000101.970|curl |3|00|the local port callback returned 0
000101.970|curl |3|00|Local port: 47952
000101.975|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000101.976|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000101.976|curl |1|00|HEADER_OUT: USER vvx300
000101.978|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000101.978|curl |1|00|HEADER_OUT: PASS XXXX
000101.979|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000101.980|curl |3|00|Access denied: 530
000101.980|curl |3|00|Closing connection #0
000101.981|cfg |4|00|Prov|Download of master configuration file failed
000101.981|cfg |4|00|Prov|Trying to boot from existing configuration
000101.981|cfg |4|00|Prov|Provisioning failed
000101.985|cfg |*|00|Prov|Finished updating configuration
000101.994|curl |3|00|timeout on name lookup is not supported
000101.994|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000101.995|curl |3|00| Trying #.#.#.36...
000101.996|curl |3|00|the local port callback returned 0
000101.996|curl |3|00|Local port: 60764
000101.998|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000101.999|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000101.999|curl |1|00|HEADER_OUT: USER vvx300
000102.000|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000102.001|curl |1|00|HEADER_OUT: PASS XXXX
000102.002|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000102.002|curl |3|00|Access denied: 530
000102.002|curl |3|00|Closing connection #0
000102.003|log |4|00|UtilLogServerC::uploadFifoLog: upload error. protocol 0 result = -1
000102.004|log |4|00|Failed to upload boot log on start up.
000102.010|curl |3|00|timeout on name lookup is not supported
000102.010|curl |3|00|About to connect() to ftpboot.domainname.local port 21 (#0)
000102.010|curl |3|00| Trying #.#.#.36...
000102.011|curl |3|00|the local port callback returned 0
000102.011|curl |3|00|Local port: 46152
000102.013|curl |3|00|Connected to ftpboot.domainname.local (#.#.#.36) port 21 (#0)
000102.013|curl |1|00|HEADER_IN : 220 Microsoft FTP Service
000102.014|curl |1|00|HEADER_OUT: USER vvx300
000102.015|curl |1|00|HEADER_IN : 331 Password required for vvx300.
000102.015|curl |1|00|HEADER_OUT: PASS XXXX
000102.016|curl |1|00|HEADER_IN : 530 User cannot log in, home directory inaccessible.
000102.017|curl |3|00|Access denied: 530
000102.017|curl |3|00|Closing connection #0
000102.017|log |4|00|UtilLogServerC::uploadFifoLog: upload error. protocol 0 result = -1
000103.556|brow |*|00|Initial log entry. Current logging level 4