Solved: boot.log dhcp information

Squigley · ‎02-04-2015

Hi Steffen,

In previous versions of the bootrom (along with application < 5.1.2), the boot.log would include useful information about DHCP, DNS, and provisioning such as the following:

000007.321|so   |3|01|Platform: Model=VVX 500, Assembly=3111-44500-001 Rev=A Region=0
000007.321|so   |3|01|Platform: Board=3111-44500-001 7 0
000007.321|so   |3|01|Platform: MAC=[redacted]
000007.322|so   |3|01|Platform: BootBlock=3.0.3.0013 (44500-001) 07-Oct-11 08:34
000007.322|so   |*|01|Platform: BootL1=1.0.0.0018 (44500-001) 06-Oct-11 17:01
000007.322|so   |3|01|Application, main: Label=Updater, Version=Hornblende 5.2.1.3271 10-Oct-13 05:41
000007.322|so   |3|01|Application, main: P/N=3150-11069-521
000008.188|so   |3|01|Link status is Net up Speed 1000 full Duplex, PC down.
000016.567|lldp |3|01|LLDP did not receive a response from a switch. Disabling LLDP.
000016.590|cdp  |3|01|CDP is disabled.
000016.714|dhcpc|3|01|dhcAddIf v4 succeeds: eth0.
000020.775|dns  |*|01|DNS resolver servers are '192.168.0.2' ''
000020.775|dns  |*|01|DNS resolver search domain is 'gateway.2wire.net'
000020.775|app1 |3|01|DNS resolver server is '192.168.0.2'
000020.775|app1 |3|01|DNS resolver search domain is 'gateway.2wire.net'
000020.823|app1 |3|01|DHCP returned result 0x287 from server 192.168.0.2.
000020.824|app1 |3|01|   Phone IPv4 address is 192.168.0.200.
000020.824|app1 |3|01|   Subnet mask is 255.255.255.0.
000020.824|app1 |3|01|   Gateway address is 192.168.0.2.
000020.824|app1 |3|01|   DNS server is 192.168.0.2
000020.824|app1 |3|01|   DNS domain is gateway.2wire.net.
0802055818|app1 |3|01|Time has been set from time.versature.com (198.41.28.69).
0802055818|app1 |3|01|   1406959098: 2014-8-2, 5:58:18, DST off

In the more recent versions of the bootrom, none of the DHCP, DNS, or provisioning details are included, eg:

000007.381|so   |3|01|Platform: Model=VVX 500, Assembly=3111-44500-001 Rev=A Region=0
000007.381|so   |3|01|Platform: Board=3111-44500-001 7 0
000007.381|so   |3|01|Platform: MAC=[redacted]
000007.382|so   |3|01|Platform: BootBlock=3.0.3.0013 (44500-001) 07-Oct-11 08:34
000007.383|so   |*|01|Platform: BootL1=1.0.0.0018 (44500-001) 06-Oct-11 17:01
000007.383|so   |3|01|Application, main: Label=Updater, Version=Citrine 5.3.2.1761 20-Aug-14 14:38
000007.383|so   |3|01|Application, main: P/N=3150-11069-532
000007.417|app1 |3|01|Application, load: Type=SIP, Version=5.1.2.1801 20-Aug-14 14:49
000008.261|so   |3|01|Link status is Net up Speed 1000 full Duplex, PC down.

Is there a way to increase the logging level of some of the applications/processes that run during the bootrom stage so that we're able to see the local DHCP/DNS parameters that were received by the phone, and the result of it's provisioning attempt(s)?

Thanks.

Squigley · ‎03-09-2015

OK, I worked this out.

It seems that the VVX phones default to syslog level 4 for most modules, and the information I was looking for is a syslog level 3 message.

By adding some settings to the phone's config such as:

log.level.change.boot="3"
log.level.change.cdp="3"
log.level.change.copy="3"
log.level.change.curl="3"
log.level.change.dhcpc="3"
log.level.change.dot1x="3"
log.level.change.lldp="3"

I was then able to see the information I was looking for.

View solution in original post

SteffenBaierUK · ‎02-04-2015

Hello squigley,

I cant verify this on my end.

UC Software 5.0.2.2756

000011.295|dhcpc|3|01|dhcAddIf v4 succeeds: eth0.
000011.299|dhcpc|3|01|dhcRebind v4: Will wait until sync rebind completes.
000011.887|dhcpc|3|01|dhcListener: Read succeeds: state:
.
000011.889|dhcpc|3|01|relLease(0) v4: Succeeded to fork dhclient to terminate.
000012.481|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: PREINIT
.
000014.660|dhcpc|3|01|dhcListener: Read succeeds: eth0 ip: 10.252.149.108
.
000014.661|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: subnet-mask 255.255.255.0
.
000014.662|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: routers 10.252.149.1
.
000014.663|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name-servers 172.27.1.16 172.27.1.21
.
000014.664|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name polycom.com
.
000014.665|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 604800
.
000014.666|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-server-identifier 10.252.149.1
.
000014.669|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: broadcast-address 10.252.149.255
.
000014.672|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 604800
.
000014.673|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-message-type 5
.
000014.674|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-renewal-time 302400
.
000014.675|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp_rebinding_time 529200
.
000014.696|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: BOUND
.
000014.696|dhcpc|3|01|dhcRebind v4: Sync rebind succeeds.
000014.697|dhcpc|3|01|Program eth0 to use subnet mask 255.255.255.0, result -1.
000014.697|dhcpc|3|01|Program eth0 to use ip address 10.252.149.108, result 0.
000014.697|dhcpc|3|01|Program eth0 to use router 10.252.149.1, result 0.
000014.708|dhcpc|3|01|getLease v4: Succeeded to fork dhclient.
000043.260|ares |*|01|Initial log entry. Current logging level 3
000043.261|dns  |*|01|DNS resolver servers are '172.27.1.16' '172.27.1.21'
000043.261|dns  |*|01|DNS resolver search domain is 'polycom.com'
000043.261|app1 |3|01|DNS resolver servers are '172.27.1.16' '172.27.1.21'
000043.261|app1 |3|01|DNS resolver search domain is 'polycom.com'
000043.261|app1 |5|01|Could not get an address(Boot Server) for .
000043.263|app1 |3|01|DHCP returned result 0x387 from server 10.252.149.1.
000043.263|app1 |3|01|   Phone IPv4 address is 10.252.149.108.
000043.263|app1 |3|01|   Subnet mask is 255.255.255.0.
000043.263|app1 |3|01|   Gateway address is 10.252.149.1.
000043.263|app1 |3|01|   DNS server is 172.27.1.16
000043.263|app1 |3|01|   DNS alternate server is 172.27.1.21.
000043.263|app1 |3|01|   DNS domain is polycom.com.

UC Software 5.1.2.1801

000021.833|dhcpc|3|01|dhcAddIf v4 succeeds: eth0.
000021.836|dhcpc|3|01|dhcRebind v4: Will wait until sync rebind completes.
000022.423|dhcpc|3|01|dhcListener: Read succeeds: state:
.
000022.426|dhcpc|3|01|relLease(0) v4: Succeeded to fork dhclient to terminate.
000023.022|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: PREINIT
.
000023.023|dhcpc|4|01|DhcpClient::processLine: no callback for state 1 if eth0
000024.160|dhcpc|3|01|dhcListener: Read succeeds: eth0 ip: 10.252.149.103
.
000024.162|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: subnet-mask 255.255.255.0
.
000024.162|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: routers 10.252.149.1
.
000024.163|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name-servers 10.252.122.120 10.252.130.10
.
000024.164|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name t3voipuk.lab
.
000024.165|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 691200
.
000024.166|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-server-identifier 10.252.149.249
.
000024.167|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: ntp-servers 10.252.122.120
.
000024.167|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: time-servers 10.252.122.120
.
000024.170|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: broadcast-address 10.252.149.255
.
000024.173|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 691200
.
000024.174|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-message-type 5
.
000024.175|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-renewal-time 345600
.
000024.176|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp_rebinding_time 604800
.
000024.197|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: BOUND
.
000024.197|dhcpc|4|01|DhcpClient::processLine: no callback for state 2 if eth0
000024.198|dhcpc|3|01|dhcRebind v4: Sync rebind succeeds.
000024.198|dhcpc|3|01|Program eth0 to use subnet mask 255.255.255.0, result -1.
000024.199|dhcpc|3|01|Program eth0 to use ip address 10.252.149.103, result 0.
000024.199|dhcpc|3|01|Program eth0 to use router 10.252.149.1, result 0.
000024.210|dhcpc|3|01|getLease v4: Succeeded to fork dhclient for interface eth0.
000025.205|ares |*|01|Initial log entry. Current logging level 3
000025.206|dns  |*|01|DNS resolver servers are '10.252.122.120' '10.252.130.10'
000025.206|dns  |*|01|DNS resolver search domain is 't3voipuk.lab'
000025.206|app1 |3|01|DNS resolver servers are '10.252.122.120' '10.252.130.10'
000025.206|app1 |3|01|DNS resolver search domain is 't3voipuk.lab'
000025.208|app1 |3|01|DHCP returned result 0x3A7 from server 10.252.149.249.
000025.208|app1 |3|01|   Phone IPv4 address is 10.252.149.103.
000025.208|app1 |3|01|   Subnet mask is 255.255.255.0.
000025.208|app1 |3|01|   Gateway address is 10.252.149.1.
000025.208|app1 |3|01|   Time server is 10.252.122.120.
000025.208|app1 |3|01|   DNS server is 10.252.122.120
000025.208|app1 |3|01|   DNS alternate server is 10.252.130.10.
000025.208|app1 |3|01|   DNS domain is t3voipuk.lab.

UC Software 5.2.0.8330

000022.362|dhcpc|3|01|dhcAddIf v4 succeeds: eth0.
000022.366|dhcpc|3|01|dhcRebind v4: Will wait until sync rebind completes.
000022.953|dhcpc|3|01|dhcListener: Read succeeds: state:
.
000022.955|dhcpc|3|01|relLease(0) v4: Succeeded to fork dhclient to terminate.
000023.546|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: PREINIT
.
000023.546|dhcpc|4|01|DhcpClient::processLine: no callback for state 1 if eth0
000025.650|dhcpc|3|01|dhcListener: Read succeeds: eth0 ip: 10.252.149.104
.
000025.651|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: subnet-mask 255.255.255.0
.
000025.652|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: routers 10.252.149.1
.
000025.653|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name-servers 10.252.79.124 172.27.1.21
.
000025.654|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: domain-name polycom.com
.
000025.655|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 604800
.
000025.656|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-server-identifier 10.252.149.1
.
000025.659|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: broadcast-address 10.252.149.255
.
000025.662|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-lease-time 604800
.
000025.663|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-message-type 5
.
000025.664|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp-renewal-time 302400
.
000025.664|dhcpc|3|01|dhcListener: Read succeeds: eth0 option: dhcp_rebinding_time 529200
.
000025.685|dhcpc|3|01|dhcListener: Read succeeds: eth0 state: BOUND
.
000025.686|dhcpc|4|01|DhcpClient::processLine: no callback for state 2 if eth0
000025.686|dhcpc|3|01|dhcRebind v4: Sync rebind succeeds.
000025.687|dhcpc|3|01|Program eth0 to use subnet mask 255.255.255.0, result -1.
000025.687|dhcpc|3|01|Program eth0 to use ip address 10.252.149.104, result 0.
000025.687|dhcpc|3|01|Program eth0 to use router 10.252.149.1, result 0.
000025.698|dhcpc|3|01|getLease v4: Succeeded to fork dhclient for interface eth0.
000026.694|ares |*|01|Initial log entry. Current logging level 3
000026.694|dns  |*|01|DNS resolver servers are '10.252.79.124' '172.27.1.21'
000026.694|dns  |*|01|DNS resolver search domain is 'polycom.com'
000026.694|app1 |5|01|Preliminary Updater, beta use only.
000026.695|app1 |3|01|DNS resolver servers are '10.252.79.124' '172.27.1.21'
000026.695|app1 |3|01|DNS resolver search domain is 'polycom.com'
000026.695|app1 |4|01|Could not load time from  (0.0.0.0).
000026.696|app1 |3|01|DHCP returned result 0x387 from server 10.252.149.1.
000026.696|app1 |3|01|   Phone IPv4 address is 10.252.149.104.
000026.696|app1 |3|01|   Subnet mask is 255.255.255.0.
000026.696|app1 |3|01|   Gateway address is 10.252.149.1.
000026.696|app1 |3|01|   DNS server is 10.252.79.124
000026.696|app1 |3|01|   DNS alternate server is 172.27.1.21.
000026.696|app1 |3|01|   DNS domain is polycom.com.

It must be something on your end. The App logs are maybe more suitable for this and you can simply set the DHCPC log level to debug.

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

----------------

If official support is required please check how to phone or open a case here

----------------
The title Poly Employee & Community Manager is a community setting and does not reflect my role. I am just a simple volunteer in the community like everybody else. All posts and words are my own & do not represent the views of Employer.

----------------

⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓SIGNATURE ⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓⇓
Notice: This community forum is not an official Poly support resource, thus responses from Poly employees, partners, and customers alike are best-effort in attempts to share learned knowledge.
Please also ensure you always check the VoIP , Video Endpoint , Microsoft Voice , PSTN or other FAQ's in the different sections

Squigley · ‎02-05-2015

Hi,

Thanks for the response. I wasn't sure if this was the result of a config setting/change we'd made to the phone, or the default logging level in newer versions of the bootrom.

We do have some syslog settings in our config files, so it must be one of these doing it:

device.syslog.facility="16"
device.syslog.facility.set="1"
device.syslog.prependMac="Enabled"
device.syslog.prependMac.set="1"
device.syslog.renderLevel="0"
device.syslog.serverName="prov.versature.com"
device.syslog.serverName.set="1"
device.syslog.transport="0"
device.syslog.transport.set="1"

log.level.change.sip="0"
log.render.file="0"
log.render.stdout="0"

While writing this post I notcied that device.syslog.renderLevel.set="1" is missing, even though it's specified in our config, so our provisioning server must be stripping this for some reason, and as a result the device.syslog.renderLevel="0" setting won't be applying to the phone. I'll open a ticket with our vendor.

I also found your page at http://community.polycom.com/t5/VoIP/FAQ-How-can-change-Logging-Levels-or-use-Syslog/td-p/4741 which will help me to adjust the logging levels as necessary.

Thanks

Squigley · ‎03-09-2015

OK, I worked this out.

It seems that the VVX phones default to syslog level 4 for most modules, and the information I was looking for is a syslog level 3 message.

By adding some settings to the phone's config such as:

log.level.change.boot="3"
log.level.change.cdp="3"
log.level.change.copy="3"
log.level.change.curl="3"
log.level.change.dhcpc="3"
log.level.change.dot1x="3"
log.level.change.lldp="3"

I was then able to see the information I was looking for.

boot.log dhcp information

boot.log dhcp information

Re: boot.log dhcp information

Re: boot.log dhcp information

Re: boot.log dhcp information

Re: boot.log dhcp information