Polycom PNP issue over HTTP v3.3.0.3165

[Carl Johnson]

As requested a new thread.

 

We are having issues with 3.3.0.3165 HTTP provisioning.

 

1) The Polycom phone is setup to use the HTTP, ext user, ext web pass (tested this via web interface .. all works)

2) The Polycom contacts the server but cannot pull the PNP files as the URL it tries to use DOES not EXIST

 

0219185255|copy |3|00|'http://180%40rcp.local:****@IP/0004f210d648.cfg' from 'DMZIP'

0219185300|copy |4|00|Download of '0004f210d648.cfg' FAILED on attempt 1 (addr 1 of 1)

 

3) I can manually get the PNP files if I specify this URL and the same user/pass .. but this is not the URL the phones will request ..

 

http://DMZIP/provisioning/0004f210d648.cfg

 

4) That is NOT the URL being requested by the phone .. why is this broken as the WIKI PNP says it that should all work .. please fix for 3.3.1.

[Carl Johnson]

PBXNSIP .. anything .. it would be great to have this issue resolved ASAP?

[Vodia PBX]

PBXNSIP .. anything .. it would be great to have this issue resolved ASAP?

 

Just tried it here... It worked... I even tried over the Internet. It also worked...

 

Both provisioning over the Internet and provisioning in the LAN. Using version 3.1.2 on the phone (bootloader 4.1.2.0037). All phones firmware files are in the tftp directory.

 

Do you have a pnp.xml file in your html directory? If that should be so, consider moving it away and restart the service.

 

I attached the log file from the phone for reference.

 

0324204419|log |*|02|Initial log entry. Current logging level 4

0324204419|so |*|02|Initial log entry. Current logging level 3

0324204419|so |*|02|---------- Initial log entry ----------

0324204419|so |*|02|Platform: Model=SoundPoint IP 550, Assembly=2345-12500-001 Rev=A

0324204419|so |*|02|Platform: MAC=0004f214058e, IP=192.168.178.21, Subnet Mask=255.255.255.0

0324204419|so |*|02|Platform: BootBlock=2.7.0 (12500_001) 18-Jan-07 13:27

0324204419|so |*|02|Platform: Bootrom=4.1.2.0037 11-Aug-08 16:16

0324204419|so |*|02|Application, main: Label=SIP, Version=3.1.2.0392 07-Jan-09 13:08

0324204419|so |*|02|Application, main: P/N=3150-11530-312

0324204419|so |3|02|Platform: Flash detected is 9 which is different than expected.

0324204419|wdog |*|02|Initial log entry. Current logging level 4

0324204419|ethf |*|02|Initial log entry. Current logging level 4

0324204419|so |5|02|utilCertificateInit failed.

0324204419|hw |*|02|Initial log entry. Current logging level 4

0324204419|ares |*|02|Initial log entry. Current logging level 4

0324204419|dns |*|02|Initial log entry. Current logging level 3

0324204419|cfg |*|02|Initial log entry. Current logging level 3

0324204419|cfg |3|02|RT|Checking DHCP option 160 type string

0324204419|cfg |3|02|RT|Runtime basic IP parameters updated.

0324204419|cfg |3|02|RT|Runtime SNTP parameters updated.

0324204419|dns |*|02|DNS resolver servers are '192.168.178.1' '0.0.0.0'

0324204419|dns |*|02|DNS resolver search domain is ''

0324204419|so |4|02|[soFontsC]: Font item (2)(2) is NULL.

0324204419|curl |*|02|Initial log entry. Current logging level 3

0324204419|utilm|*|02|Initial log entry. Current logging level 4

0324204419|copy |*|02|Initial log entry. Current logging level 3

0324204419|rtos |*|02|Initial log entry. Current logging level 4

0324204419|sec |*|02|Initial log entry. Current logging level 4

0324204419|cfg |3|02|Prm|Beginning to provision phone

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20/2345-12500-001.bootrom.ld' from '192.168.178.20'

0324204419|cfg |3|02|Prm|Image 2345-12500-001.bootrom.ld has not changed

0324204419|copy |3|02|buffered_write: transfer Terminated on entry. Return 0

0324204419|copy |3|02|Download of '2345-12500-001.bootrom.ld' succeeded on attempt 1 (addr 1 of 1)

0324204419|cfg |3|02|Prm|Downloaded bootROM is identical to current version 4.1.2

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20/0004f214058e.cfg' from '192.168.178.20'

0324204419|copy |3|02|Download of '0004f214058e.cfg' succeeded on attempt 1 (addr 1 of 1)

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20/2345-12500-001.sip.ld' from '192.168.178.20'

0324204419|copy |4|02|Download of '2345-12500-001.sip.ld' FAILED on attempt 1 (addr 1 of 1)

0324204419|copy |4|02|Server '192.168.178.20' said '2345-12500-001.sip.ld' is not present

0324204419|cfg |4|02|Prm|Could not get all 512 bytes of the header

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20/sip.ld' from '192.168.178.20'

0324204419|cfg |3|02|Prm|Image sip.ld has not changed

0324204419|copy |3|02|buffered_write: transfer Terminated on entry. Return 0

0324204419|copy |3|02|Download of 'sip.ld' succeeded on attempt 1 (addr 1 of 1)

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20:80/provisioning/polycom_phone.cfg' from '192.168.178.20'

0324204419|copy |3|02|Download of 'provisioning/polycom_phone.cfg' succeeded on attempt 1 (addr 1 of 1)

0324204419|cfg |3|02|Prm|Updated http://192.168.178.20:80/provisioning/polycom_phone.cfg

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20:80/provisioning/polycom_sip.cfg' from '192.168.178.20'

0324204419|copy |3|02|Download of 'provisioning/polycom_sip.cfg' succeeded on attempt 1 (addr 1 of 1)

0324204419|cfg |3|02|Prm|Updated http://192.168.178.20:80/provisioning/polycom_sip.cfg

0324204419|cfg |3|02|Prm|Check of configuration files suceeded

0324204419|cfg |3|02|Prm|Phone successfully provisioned

0324204419|cfg |*|02|Prm|Configuration file "polycom_phone.cfg" is from template Unknown, revision Unknown

0324204419|cfg |*|02|Prm|Configuration file "polycom_phone.cfg" SHA1 digest: 87F30DB8EBF7457481EE3F197F6EB5BD0F5F1CCA

0324204419|cfg |*|02|Prm|Configuration file "polycom_sip.cfg" is from template Unknown, revision Unknown

0324204419|cfg |*|02|Prm|Configuration file "polycom_sip.cfg" SHA1 digest: CE500E55FED94E2E0EDC4E34221C147AB86290A0

0324204419|so |3|02|Success provisioning.

0324204419|so |*|02|Configuration files: http://192.168.178.20:80/provisioning/polycom_phone.cfg, http://192.168.178.20:80/provisioning/polycom_sip.cfg

0324204419|copy |3|02|'http://44%40localhost:****@192.168.178.20/0004f214058e-phone.cfg' from '192.168.178.20'

0324204419|copy |4|02|Download of '0004f214058e-phone.cfg' FAILED on attempt 1 (addr 1 of 1)

0324204419|copy |4|02|Server '192.168.178.20' said '0004f214058e-phone.cfg' is not present

0324204419|utilm|4|02|uBLFCompressed: File /ffs0/local/0004f214058e-phone_cfg.zzz does not exist or is empty

0324204419|sec |4|02|utilCryptoConfigFileEncrypted: Could not read file /ffs0/local/0004f214058e-phone_cfg.zzz.

0324204419|cfg |3|02|Edit|Local cfg not found: /ffs0/local/0004f214058e-phone_cfg.zzz

0324204419|cfg |3|02|Edit|Loaded local file: /ffs0/local/0004f214058e-phone_cfg.zzz

0324204419|cfg |4|02|Edit|Error 0x380003 attempting stat of /ffs0/local/0004f214058e-phone_cfg.zzz

0324204419|utilm|4|02|uBLFCompressed: File /ffs0/local/0004f214058e-phone_cfg.zzz does not exist or is empty

0324204419|cfg |5|02|Prm|Error when decompressing config file /ffs0/local/0004f214058e-phone_cfg.zzz

0324204419|cfg |3|02|RT|Checking DHCP option 160 type string

0324204419|cfg |3|02|RT|Runtime SNTP parameters updated.

0324204419|so |3|02|Using time offset 3600 seconds.

0324204419|so |3|02|SNTP: sync with server '192.168.178.1' 1 of 1 OK on try 1 of 2 timeout 500 of total 0 ticks (0 sec)

0324204419|so |3|02|Setting daylight savings string to "TIMEZONE=UTC::-60:::".

0324214508|log |*|02|Log render level set to 1

0324214508|lic |*|02|Initial log entry. Current logging level 4

0324214508|copy |3|02|'http://44%40localhost:****@192.168.178.20/000000000000-license.cfg' from '192.168.178.20'

0324214508|copy |4|02|Download of '000000000000-license.cfg' FAILED on attempt 1 (addr 1 of 1)

0324214508|copy |3|02|transport res: 28 respCode 0

0324214508|copy |3|02|transport error: a timeout was reached.

0324214508|copy |3|02|transport error buffer: connect() timed out!.

0324214508|copy |3|02|Making further download attempts for '000000000000-license.cfg'

0324214508|copy |3|02|'http://44%40localhost:****@192.168.178.20/000000000000-license.cfg' from '192.168.178.20'

0324214508|copy |4|02|Download of '000000000000-license.cfg' FAILED on attempt 2 (addr 1 of 1)

0324214508|copy |4|02|Server '192.168.178.20' said '000000000000-license.cfg' is not present

0324214508|copy |3|02|'http://44%40localhost:****@192.168.178.20/0004f214058e-license.cfg' from '192.168.178.20'

0324214508|copy |4|02|Download of '0004f214058e-license.cfg' FAILED on attempt 1 (addr 1 of 1)

0324214508|copy |4|02|Server '192.168.178.20' said '0004f214058e-license.cfg' is not present

0324214508|lic |4|02|cfgCfsFlashKeyScratchLoad: key is blank

0324214508|srtp |*|02|Initial log entry. Current logging level 4

0324214508|rdisk|*|02|Initial log entry. Current logging level 4

0324214508|rdisk|*|02|RAM disk created, size: 4,194,304 bytes

0324214508|res |*|02|Initial log entry. Current logging level 4

0324214508|httpa|*|02|Initial log entry. Current logging level 4

0324214508|cdp |*|02|Initial log entry. Current logging level 4

0324214508|cdp |*|02|CDP is DISABLED. CDP not detected at boot.

0324214508|sys |*|02|Initial log entry. Current logging level 4

0324214508|copy |3|02|'http://44%40localhost:****@192.168.178.20/0004f214058e-directory.xml' from '192.168.178.20'

0324214508|copy |3|02|Download of '0004f214058e-directory.xml' succeeded on attempt 1 (addr 1 of 1)

0324214508|cfg |4|02|Edit|Local file compressed: /ffs0/local/local-directory_xml.zzz

0324214508|ssps |*|02|Initial log entry. Current logging level 4

0324214508|dbuf |*|02|Initial log entry. Current logging level 4

0324214508|so |*|02|System Info Reports:

0324214508|so |*|02|.CPU is TNETV1055/C55x, rev 2 running at 125MHz with memory at 125MHz.

0324214508|so |*|02|.Board is identified as PolycomSoundPointIP-SPIP_550.

0324214508|so |*|02|.DRAM_LO: 0x94000000. DRAM_SIZE: 32 MB

0324214508|so |*|02|.Clocks are VBUSP: 125MHz, USB: 25MHz, LCD: 31MHz, DSP: 100MHz.

0324214508|key |*|02|Initial log entry. Current logging level 4

0324214508|ht |*|02|Initial log entry. Current logging level 4

0324214508|httpd|*|02|Initial log entry. Current logging level 4

0324214508|ssps |*|02|Application, comp. 1: Label=PolyDSP Titan Mem1 FS3 (G.729), Version=3.1.2.0022 08-Dec-08 10:52

0324214508|ssps |*|02|Application, comp. 1: P/N=3150-11580-312.

0324214508|pps |*|02|Initial log entry. Current logging level 4

0324214508|sip |*|02|Initial log entry. Current logging level 4

0324214508|copy |3|02|'http://44%40localhost:****@192.168.178.20/SoundPointIPWelcome.wav' from '192.168.178.20'

0324214508|cfg |4|02|Edit|Error 0x380003 attempting stat of /ffs0/local/0004f214058e-phone_cfg.zzz

0324214508|cfg |4|02|Edit|Error 0x380003 attempting stat of /ffs0/local/0004f214058e-phone_cfg.zzz

0324214508|lic |4|02|License: feature VoiceQualityMetrics is not available

0324214508|so |4|02|No license for voice quality monitoring.

0324214508|so |4|02|All voice quality monitoring features disabled.

[Carl Johnson]

We removed the pnp.xml file and restarted the service, still no luck, the phone cannot get the MAC config file from the service? This is from a real-world IP to our DMZ real-world IP which should provision using the SIP rewrite, correct?

 

* changed the realworld IP to the word IP *

 

0219185249|cfg |3|00|Beginning to provision phone

0219185249|copy |3|00|'http://180%40rcp.local:****@IP/2345-11402-001.bootrom.ld' from IP

0219185249|cfg |3|00|Image 2345-11402-001.bootrom.ld has not changed

0219185249|copy |3|00|buffered_write: transfer Terminated on entry. Return 0

0219185249|copy |3|00|Download of '2345-11402-001.bootrom.ld' succeeded on attempt 1 (addr 1 of 1)

0219185249|cfg |3|00|Downloaded bootROM is identical to current version 4.1.2

0219185249|copy |3|00|'http://180%40rcp.local:****@IP/0004f210d648.cfg' from IP

0219185254|copy |4|00|Download of '0004f210d648.cfg' FAILED on attempt 1 (addr 1 of 1)

[Vodia PBX]

We removed the pnp.xml file and restarted the service, still no luck, the phone cannot get the MAC config file from the service? This is from a real-world IP to our DMZ real-world IP which should provision using the SIP rewrite, correct?

 

When you provision outside of the LAN, then the MAC plays no role any more; you better remove it. The PBX identifies the account only by the authentication info that you provide.

[Carl Johnson]

We removed the pnp.xml file and restarted the service, still no luck, the phone cannot get the MAC config file from the service? This is from a real-world IP to our DMZ real-world IP which should provision using the SIP rewrite, correct?

 

* changed the realworld IP to the word IP *

 

0219185249|cfg |3|00|Beginning to provision phone

0219185249|copy |3|00|'http://180%40rcp.local:****@IP/2345-11402-001.bootrom.ld' from IP

0219185249|cfg |3|00|Image 2345-11402-001.bootrom.ld has not changed

0219185249|copy |3|00|buffered_write: transfer Terminated on entry. Return 0

0219185249|copy |3|00|Download of '2345-11402-001.bootrom.ld' succeeded on attempt 1 (addr 1 of 1)

0219185249|cfg |3|00|Downloaded bootROM is identical to current version 4.1.2

0219185249|copy |3|00|'http://180%40rcp.local:****@IP/0004f210d648.cfg' from IP

0219185254|copy |4|00|Download of '0004f210d648.cfg' FAILED on attempt 1 (addr 1 of 1)

 

I tested this further and it appears to provision properly on the INSIDE, so I would guess this is related to the sip IP rewrite rule change in this version?

[Vodia PBX]

I tested this further and it appears to provision properly on the INSIDE, so I would guess this is related to the sip IP rewrite rule change in this version?

 

No, there is also a change regarding the identification of the device that is being provisioned.

 

If the ARP cache contains the IP address of the device and it also matches a known MAC address, then the PBX trusts that MAC address (can be disabled).

 

Otherwise, it will always use HTTP authentication.

[Carl Johnson]

Ok .. disabled PNP trust MAC and now the internal phone will not provision over HTTP using a proper user/pass that tests good. Seems something is broken here?

 

* Replaced actual private IP with LANIP *

 

0326163952|copy |3|00|'http://111%40rcp.local:****@LANIP/0004f20457d6.cfg' from LANIP

0326163959|copy |4|00|Download of '0004f20457d6.cfg' FAILED on attempt 1 (addr 1 of 1)

0326163959|copy |3|00|transport res: 22 respCode 401

0326163959|copy |3|00|transport error: Curl Error strings have been compiled out.

0326163959|copy |3|00|transport error buffer: The requested URL returned error: 401.

[Vodia PBX]

Ok .. disabled PNP trust MAC and now the internal phone will not provision over HTTP using a proper user/pass that tests good. Seems something is broken here?

 

* Replaced actual private IP with LANIP *

 

0326163952|copy |3|00|'http://111%40rcp.local:****@LANIP/0004f20457d6.cfg' from LANIP

0326163959|copy |4|00|Download of '0004f20457d6.cfg' FAILED on attempt 1 (addr 1 of 1)

0326163959|copy |3|00|transport res: 22 respCode 401

0326163959|copy |3|00|transport error: Curl Error strings have been compiled out.

0326163959|copy |3|00|transport error buffer: The requested URL returned error: 401.

 

401 means that the authentication did not work. Are you sure that you have chosen the right password (the web password)?

 

It does not matter if you disable the MAC trust or not. If you are not in the LAN than that flag has no effect.

 

I tried it again from here. It worked if the phone uses a standard port (80). Using a non-standard port did not work.

[Carl Johnson]

That is all good in assumption but as noted using the URL with /provisioning and exact password/username works but using the URL without the word provisoning as shown in the log will not WORK at all and does NOT prompt for a user/pass .. sounds like a PBX issue. Please contact offline to start a WEBEX so you can see the issue at hand.

[Carl Johnson]

That is all good in assumption but as noted using the URL with /provisioning and exact password/username works but using the URL without the word provisoning as shown in the log will not WORK at all and does NOT prompt for a user/pass .. sounds like a PBX issue. Please contact offline to start a WEBEX so you can see the issue at hand.

 

Also, after changing back to PNP trust MAC .. it is OK .. and the internal phone will provsion (same LAN).

 

0326234909|cfg |3|00|Downloaded bootROM is identical to current version 4.1.2

0326234909|copy |3|00|'http://111%40rcp.local:****@192.168.40.223/0004f20457d6.cfg' from '192.168.40.223'

0326234909|copy |3|00|Download of '0004f20457d6.cfg' succeeded on attempt 1 (addr 1 of 1)

0326234909|copy |3|00|'http://111%40rcp.local:****@192.168.40.223/2345-11500-040.sip.ld'

[Carl Johnson]

Okay .. so I have come up with what the EXACT issue is here.

 

On the phone it will provision properly IF the phone has been provisioned ONE time internally inside the network. Otherwise if it is blank file system it will not work as the BOOTROM tries to provision from the URL

 

http://180@rcp.local:xxxx@X.X.X.X/provisio...004f210d2d7.cfg

 

and this will not work as the BOOTROM cannot authenticate?? But the SIP app can and does auth properly so it can reprovision the config on a ALREADY working phone correctly but not on a virgin.

 

** PLEASE REPAIR THE PBX TO WORK **

 

Steps to replicate issue.

 

1) Wipe phone

2) setup the phone to provision via HTTP with proper user/pass

3) Phone cannot contact boot server, will fail (pcap shows the GET request from the phone and the pbx returns a 404)

 

Steps for the phone to provision ..

 

1) Provision phone INTERNALLY via TFTP

2) Change the provisioning on the phone to HTTP with proper user/pass

3) reboot, phone will provide cannot contact boot server but continues to boot

4) new ext shows and registers

[Vodia PBX]

and this will not work as the BOOTROM cannot authenticate?? But the SIP app can and does auth properly so it can reprovision the config on a ALREADY working phone correctly but not on a virgin.

 

Whow... I can't try this out right now... That would explain the problems. Does that apply only to "older" bootloaders or also the the latest and greatest? Can someone verify?

[Carl Johnson]

This is v4.1.12.0037 boottom and v3.1.1 SIP

[Carl Johnson]

Pbxnsip .. I really need resolve on this .. please help!!

[Vodia PBX]

This is v4.1.12.0037 boottom and v3.1.1 SIP

 

Okay, this is what I did: I nuked the phone several times with a factory reset, and settings reset. After that, set it up for PnP with HTTP, and username/password set appropriately. It works.

 

I did not try to downgrade the bootloader. Maybe the older bootloader has the problem that authentication is not supported yet.

[hosted]

what a pain this is.

 

got a polycom phone I wiped all the settings. provisioned it for http and I kept getting 401 errors. arrgh

changed the setting to tftp with the same auth (101@domain1) same password and it worked!

 

I pulled the tftp manually and it just references URL's so I assume the auth is still used as it should however it seems the initial file request is BAD.

 

db

[Vodia PBX]

what a pain this is.

 

got a polycom phone I wiped all the settings. provisioned it for http and I kept getting 401 errors. arrgh

changed the setting to tftp with the same auth (101@domain1) same password and it worked!

 

I pulled the tftp manually and it just references URL's so I assume the auth is still used as it should however it seems the initial file request is BAD.

 

Maybe send me a PM with the provisioning info and we'll give it a try from here. If you have Remote Desktop or at least a HTTP login we could even try to get it working. Seems this is a problem of the test environment.

[Carl Johnson]

Okay, this is what I did: I nuked the phone several times with a factory reset, and settings reset. After that, set it up for PnP with HTTP, and username/password set appropriately. It works.

 

I did not try to downgrade the bootloader. Maybe the older bootloader has the problem that authentication is not supported yet.

 

 

What bootloader?

[hosted]

Maybe send me a PM with the provisioning info and we'll give it a try from here. If you have Remote Desktop or at least a HTTP login we could even try to get it working. Seems this is a problem of the test environment.

 

We have only rolled out 1 customer on it.

 

I also rolled out a CS410 with a private IP. I used http login and that went without any issue.

 

I think the problem is the phone is not asking for http://ip/provisioning/mac.cnf I can call that URL from offsite and login and see the proper login information. again when i use tftp is works fine. but thats becasue it is trivial and hands out the http page, which then works.

 

If this is not the issue, I will PM the login info.

[Carl Johnson]

We have only rolled out 1 customer on it.

 

I also rolled out a CS410 with a private IP. I used http login and that went without any issue.

 

I think the problem is the phone is not asking for http://ip/provisioning/mac.cnf I can call that URL from offsite and login and see the proper login information. again when i use tftp is works fine. but thats becasue it is trivial and hands out the http page, which then works.

 

If this is not the issue, I will PM the login info.

 

By default, with using just an IP/host when provisioning the Polycom will look for http://IP/mac.cfg .. we had to type in via the keypad the URL http://IP/provisioning and then it at least worked on the applicaiton side .. but not the bootloader as it appears the boot loader will not authenticate when asked.

[hosted]

the bootloader asked for the tftp just fine, so technically it worked.

[Carl Johnson]

the bootloader asked for the tftp just fine, so technically it worked.

 

TFTP and HTTP are two different animals and my preference is not to allow TFTP from the real world .. you know?

[hosted]

true but until https works

[hosted]

when is this going to get fixed? 3.3.1.3177 still same issue.

 

if phone asks for http://IP/0004f210afff.cfg which doesnt work.

 

pbxnsip is expecting http://IP/provisioning/0004f210afff.cfg which the phone never asks for.