Buy or Renew
Buy or Renew
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
4133
Views
8
Helpful
10
Replies

APIC-EM PNP switch deployment error - uses DHCP-server as config server

trylvis123
Level 1
Level 1

‎04-20-2017 04:55 AM - edited ‎03-01-2019 04:37 AM

Greetings everyone,

I've just set up Cisco Prime and APIC-EM, and plan to use PNP to deploy a number of new switches, primary 2960X-series, aswell as access points.


I've integrated APIC-EM into Cisco Prime, and I've created an PNP profile in Prime which and deployed it as a project to APIC-EM.


For testing purposes both the APIC-EM, Cisco Prime and switch used for testing is placed in the same subnet.


By the logs on the switch, it seems like it successfully connect to the APIC-EM server, but then it looks like it tries to download config from the DHCP-server.

Of the switch output you see the following:

Apr 20 11:18:59.826: AUTOINSTALL: Obtain siaddr 192.168.1.20 (as config server)

Where 192.168.1.20 is the DHCP-server, not APIC-EM. Why do the switch try to use this address as "config server"? Where is this address obtained from?


So I first tried to use PNP with the DHCP option 43, but thought that I might give DNS a try instead, but it seems like the ouput is the same.

The config below is with DNS-entry with "pnpserver.domain.local", no DHCP option 43.

See the error messages below:


Output form APIC-EM:

2017-04-20 13:40:34Failed health check since device is stuck in non-terminal state FILESYSTEM_INFO_REQUESTED for more than threshold time: 0 hours, 16 minutes, 0 seconds
2017-04-20 13:40:07Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:40:06Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:40:06Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:38:06Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:38:05Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:38:05Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:36:05Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:36:04Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:36:04Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:34:04Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:34:03Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:34:03Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:32:03Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:32:02Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:32:02Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:30:01Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:30:01Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:30:01Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:28:00Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:28:00Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:28:00Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:25:59Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:25:59Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:25:59Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:23:58Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:23:58Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:23:58Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:21:57Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:21:57Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:21:57Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:19:56Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:
2017-04-20 13:19:56Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:
2017-04-20 13:19:56Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED
2017-04-20 13:19:56Device authentication status has changed to Unauthenticated(SUDI feature not supported by device)
2017-04-20 13:19:19Device first contact

Output from switch (where 192.168.1.20 is theDHCP-server) :

Switch Ports Model                 SW Version        SW Image
------ ----- -----                 ----------        ----------
*1 52WS-C2960X-48LPS-L     15.2(2)E6         C2960X-UNIVERSALK9-M

Press RETURN to get started!

*Mar  1 00:00:27.615: Read env variable - LICENSE_BOOT_LEVEL =

*Jan  2 00:00:00.153: %IOS_LICENSE_IMAGE_APPLICATION-6-LICENSE_LEVEL: Module name = c2960x_lanbase Next reboot level = lanbase and License = lanbase

Apr 20 11:16:57.118:  in Switch 0. Cannot read pid from Flexstack module

Apr 20 11:16:57.212: %HPAA:hpaa_port_bitmap_init:254:n_ports = 52, sizeof (**hpaa_port_bitmap.bitlist_array) = 16

Apr 20 11:17:39.977: %STACKMGR-4-SWITCH_ADDED: Switch 1 has been ADDED to the stack

Apr 20 11:17:41.399: %LINEPROTO-5-UPDOWN: Line protocol on Interface Vlan1, changed state to down

Apr 20 11:17:41.399: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet0, changed state to down

Apr 20 11:17:43.248: %SPANTREE-5-EXTENDED_SYSID: Extended SysId enabled for type vlan

Apr 20 11:18:05.887: %STACKMGR-5-SWITCH_READY: Switch 1 is READY

Apr 20 11:18:05.887: %STACKMGR-4-STACK_LINK_CHANGE: Stack Port 1 Switch 1 has changed to state DOWN

Apr 20 11:18:05.887: %STACKMGR-4-STACK_LINK_CHANGE: Stack Port 2 Switch 1 has changed to state DOWN

Apr 20 11:18:06.404: %STACKMGR-5-MASTER_READY: Master Switch 1 is READY

Apr 20 11:18:06.408: %SYS-5-RESTART: System restarted --

Cisco IOS Software, C2960X Software (C2960X-UNIVERSALK9-M), Version 15.2(2)E6, RELEASE SOFTWARE (fc1)

Technical Support: http://www.cisco.com/techsupport

Copyright (c) 1986-2016 by Cisco Systems, Inc.

Compiled Fri 16-Dec-16 21:27 by prod_rel_team

Apr 20 11:18:06.523: %USB_CONSOLE-6-MEDIA_RJ45: Console media-type is RJ45.

Apr 20 11:18:08.344: %LINK-3-UPDOWN: Interface FastEthernet0, changed state to down

Apr 20 11:18:09.347: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet0, changed state to down

Apr 20 11:18:11.375: %LINK-3-UPDOWN: Interface GigabitEthernet1/0/1, changed state to up

Apr 20 11:18:12.374: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/1, changed state to up

Apr 20 11:18:39.382: %LINEPROTO-5-UPDOWN: Line protocol on Interface Vlan1, changed state to up got vend id vend spec. info ret: succeed

Apr 20 11:18:59.826: AUTOINSTALL: Obtain siaddr 192.168.1.20 (as config server)

Apr 20 11:19:15.859: %PNP-6-HTTP_CONNECTING: PnP Discovery trying to connect to PnP server http://pnpserver.domain.local/pnp/HELLO

Apr 20 11:19:15.880: %PNP-6-HTTP_CONNECTED: PnP Discovery connected to PnP server http://pnpserver.domain.local/pnp/HELLO

Apr 20 11:19:16.893: %PNP-6-PROFILE_CONFIG: PnP Discovery profile pnp-zero-touch configured

%Error opening tftp://192.168.1.20/network-confg (Timed out)

Apr 20 11:19:45.010: %SYS-6-CLOCKUPDATE: System clock has been updated from 11:19:41 UTC Thu Apr 20 2017 to 11:19:45 UTC Thu Apr 20 2017, configured from console by console.[OK]

Apr 20 11:19:53.189: %PKI-6-CONFIGAUTOSAVE: Running configuration saved to NVRAM

%Error opening tftp://192.168.1.20/cisconet.cfg (Timed out)

%Error opening tftp://192.168.1.20/router-confg (Timed out)

%Error opening tftp://192.168.1.20/ciscortr.cfg (Timed out)


Thanks in advance!

Labels:
10 Replies 10

m.volodko
Level 1
Level 1

‎04-21-2017 01:39 AM

Hi,

From what I see it still tries to locate APIC-EM.

What configuration (with options) you're passing to the switch from DHCP server?

For clear test I'd suggest:

- temporary forget about prime - apic-em intergation

- define local dhcp server with option 43 on your L3

- wipe switch and try again

Misha

trylvis123
Level 1
Level 1
In response to m.volodko

‎04-24-2017 02:34 AM

So I tried again with DHCP option 43.

In the below logs, 192.168.1.20 is the DHCP server, 192.168.1.40 is the APIC-EM server.

It seems to me, that the switch manages to read the DCHP option 43, and get the correct IP. However it still tries to use the DHCP server as config server.

The DHCP option looks like this, Microsoft DHCP Server:

pnpScopeOption.png

Output from switch console:

Press RETURN to get started!

*Mar  1 00:00:27.661: Read env variable - LICENSE_BOOT_LEVEL =

*Jan  2 00:00:00.150: %IOS_LICENSE_IMAGE_APPLICATION-6-LICENSE_LEVEL: Module name = c2960x_lanbase Next reboot level = lanbase and License = lanbase

Apr 24 09:11:57.114:  in Switch 0. Cannot read pid from Flexstack module

Apr 24 09:11:57.212: %HPAA:hpaa_port_bitmap_init:254:n_ports = 52, sizeof (**hpaa_port_bitmap.bitlist_array) = 16

Apr 24 09:12:40.973: %STACKMGR-4-SWITCH_ADDED: Switch 1 has been ADDED to the stack

Apr 24 09:12:42.399: %LINEPROTO-5-UPDOWN: Line protocol on Interface Vlan1, changed state to down

Apr 24 09:12:42.399: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet0, changed state to down

Apr 24 09:12:44.251: %SPANTREE-5-EXTENDED_SYSID: Extended SysId enabled for type vlan

Apr 24 09:13:06.897: %STACKMGR-5-SWITCH_READY: Switch 1 is READY

Apr 24 09:13:06.897: %STACKMGR-4-STACK_LINK_CHANGE: Stack Port 1 Switch 1 has changed to state DOWN

Apr 24 09:13:06.897: %STACKMGR-4-STACK_LINK_CHANGE: Stack Port 2 Switch 1 has changed to state DOWN

Apr 24 09:13:07.366: %STACKMGR-5-MASTER_READY: Master Switch 1 is READY

Apr 24 09:13:07.415: %USB_CONSOLE-6-MEDIA_RJ45: Console media-type is RJ45.

Apr 24 09:13:07.418: %SYS-5-RESTART: System restarted --

Cisco IOS Software, C2960X Software (C2960X-UNIVERSALK9-M), Version 15.2(2)E6, RELEASE SOFTWARE (fc1)

Technical Support: http://www.cisco.com/techsupport

Copyright (c) 1986-2016 by Cisco Systems, Inc.

Compiled Fri 16-Dec-16 21:27 by prod_rel_team

Apr 24 09:13:09.354: %LINK-3-UPDOWN: Interface FastEthernet0, changed state to down

Apr 24 09:13:10.358: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet0, changed state to down

Apr 24 09:13:12.346: %LINK-3-UPDOWN: Interface GigabitEthernet1/0/1, changed state to up

Apr 24 09:13:13.349: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/1, changed state to up

Apr 24 09:13:40.354: %LINEPROTO-5-UPDOWN: Line protocol on Interface Vlan1, changed state to up

Apr 24 09:13:44.838: %PNPA-DHCP Op-43 Msg: Process state = READY

Apr 24 09:13:44.838: %PNPA-DHCP Op-43 Msg: OK to process message

Apr 24 09:13:44.838: XML-UPDOWN: PNPA_DHCP_OP43 XML Interface(102) UP. PID=141

Apr 24 09:13:44.838: %PNPA-DHCP Op-43 Msg: _pdoon.1.ntf.don=141

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdoop.1.org=[A1D;B2;K4;I192.168.1.40;J80]

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdgfa.1.inp=[B2;K4;I192.168.1.40;J80]

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdgfa.1.B2.s12=[ ipv4 ]

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdgfa.1.K4.htp=[ transport http ]

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdgfa.1.Ix.srv.ip.rm=[ 192.168.1.40 ]

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdgfa.1.Jx.srv.rt.rm=[ port 80 ]

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdoop.1.ztp=[pnp-zero-touch] host=[] ipad=[192.168.1.40] port=80

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pors.done=1

Apr 24 09:13:44.852: %PNPA-DHCP Op-43 Msg: _pdokp.1.now=PNPA_DHCP_OP43 pid=141

Apr 24 09:13:44.852: XML-UPDOWN: PNPA_DHCP_OP43 XML Interface(102) SHUTDOWN(101). PID=141 got vend id vend spec. info ret: succeed

Apr 24 09:14:00.811: AUTOINSTALL: Obtain siaddr 192.168.1.20 (as config server)

Apr 24 09:14:10.818: %PNP-6-HTTP_CONNECTING: PnP Discovery trying to connect to PnP server http://192.168.1.40:80/pnp/HELLO

Apr 24 09:14:11.825: %PNP-6-HTTP_CONNECTED: PnP Discovery connected to PnP server http://192.168.1.40:80/pnp/HELLO

Apr 24 09:14:12.839: %PNP-6-PROFILE_CONFIG: PnP Discovery profile pnp-zero-touch configured

Apr 24 09:14:38.353: %SYS-6-CLOCKUPDATE: System clock has been updated from 09:14:37 UTC Mon Apr 24 2017 to 09:14:38 UTC Mon Apr 24 2017, configured from console by console.

%Error opening tftp://192.168.1.20/network-confg (Timed out)[OK]

Apr 24 09:14:46.482: %PKI-6-CONFIGAUTOSAVE: Running configuration saved to NVRAM

%Error opening tftp://192.168.1.20/cisconet.cfg (Timed out)

%Error opening tftp://192.168.1.20/router-confg (Timed out)

%Error opening tftp://192.168.1.20/ciscortr.cfg (Timed out)

aradford
Cisco Employee
Cisco Employee

‎04-22-2017 08:34 PM

Ok, looks like dns is working.

A couple of things:

1) Are you also setting option 150 in the dhcp scope (you should not)?

2) Can you show the rule that PI created for the device in APIC-EM?  Look in the PnP app on APIC under projects.  Did you specify SUDI or certificates?

3) as Misha suggested a good way to troubleshoot in the beginning would be to just use APIC-EM initially, once you understand the process, include PI.

Adam

0 Helpful

trylvis123
Level 1
Level 1
In response to aradford

‎04-24-2017 01:48 AM

Misha:

I first tried with DHCP option 43, with the same result as what posted above. I now have removed DHCP option 43, and tried to use DNS instead to see if that helped.

From what I see in the logs, it looks like there is some connection to the PnP server, but that it uses DHCP-server as config server even before that connection takes place:

     Apr 20 11:18:59.826: AUTOINSTALL: Obtain siaddr 192.168.1.20 (as config server)

     Apr 20 11:19:15.859: %PNP-6-HTTP_CONNECTING: PnP Discovery trying to connect to PnP      server http://pnpserver.domain.local/pnp/HELLO

     Apr 20 11:19:15.880: %PNP-6-HTTP_CONNECTED: PnP Discovery connected to PnP server http://pnpserver.domain.local/pnp/HELLO

     Apr 20 11:19:16.893: %PNP-6-PROFILE_CONFIG: PnP Discovery profile pnp-zero-touch configured

I can try again with removing DNS entry, and use DHCP option 43 and post the results.

Adam:

  • I have not used DHCP option 150 in the DHCP scope. Should I?
  • I have not specified and certificates or SUDI. As I understand this is not necessary? It will be used only for in house switches, no deployment for remote branches or so.
    SwitchProfile.png

Thanks again.

aradford
Cisco Employee
Cisco Employee
In response to trylvis123

‎04-24-2017 02:58 PM

No need for the certificates.  I just wanted to simplify things.

You should not have option 150 in scope.  I was trying to see where the tftp server was coming from?  Likely picking it up from a broadcast?  It should not matter either.

What is the host with ip address 192.168.1.20?

Would it be possible to test without PI, just to eliminate another part?

0 Helpful

trylvis123
Level 1
Level 1
In response to aradford

‎04-25-2017 12:34 AM

192.168.1.20 is the DHCP server. In real life the DHCP server is placed on another subnet, I've just edited the IP addresses before uploading the logs.

For fun I tried to deploy another switch aswell, but with the same result.

I will try to deploy without PI, and just create a new project in APIC-EM.

trylvis123
Level 1
Level 1
In response to aradford

‎04-25-2017 02:21 AM

So I created a new project in APIC-EM, added a new switch with a simple template setting hostname and some username and passwords, I still get the same results.

Also with no projects configured, when I turn on a switch, it get's the same. (When the switch is not predefined in APIC-EM).

A question, the pnp profile is added with the correct IP to the APIC-EM server. When the switch reboots, wouldn't it try to connect to this PNP profile? Or is the profile used for something else?

Is there any commands available to debug how the switch recieves the "config server" address?

Update:

Also upgraded firmware of one of the switches to 15.2.2 E6, with no improvements.

aradford
Cisco Employee
Cisco Employee
In response to trylvis123

‎04-27-2017 02:07 AM

You can ignore the autoinstall message.  If the server does not respond the PnP process will just continue.

Do you see the same errors on APIC-EM in all cases?

show pnp trace on the switch will show where the pnp process is up to.

show pnp history will show all of the events that have occured.

0 Helpful

trylvis123
Level 1
Level 1
In response to aradford

‎05-02-2017 06:29 AM

Hi again,

I installed APIC-EM in another enviroment, and at first I experienced the same problems.

Then I changed the DHCP option 43 from:

"5A1D;B2;K4;I<ipAddress>;J80"

to

"5A1N;B2;K4;I<ipAddress>;J80"


which seemd to do the trick. I will keep you updated when I get back to the enviroment where I first experienced the error.

aradford
Cisco Employee
Cisco Employee
In response to trylvis123

‎05-02-2017 02:30 PM

That is interesting...  the "D" option turns on debugging.

0 Helpful
Customers Also Viewed These Support Documents