cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
8026
Views
22
Helpful
20
Replies

PnP not working with APIC

Someone1
Level 1
Level 1

Hi

I have tried to PnP some switches both IE3000 and a C2960X but no luck.

I get them to talk to the APIC EM through DHCP and they start the process but then I get below errors:

2017-03-05 12:54:24 Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:

2017-03-05 12:54:24 Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:

2017-03-05 12:54:24 Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED

2017-03-05 12:54:24 Device authentication status has changed to Unauthenticated(SUDI feature not supported by device)

2017-03-05 12:53:51 Device first contact

Attaching a small topology and the config I try to push

Versions:

2960x: Version 15.2(2)E3

IE3000: 15.2.4-EA5

Any help would be appreciated.

/Nils-Oskar

20 Replies 20

aradford
Cisco Employee
Cisco Employee

Hi Nils-Oskar,

One quick question.  What deployment model are you using?  Project rule or unclaimed device?

release notes say that Non-VLAN1 is not supported in 15.2.4E.  Is it possible to try a vlan 1 (as a test) or use another image 15.2.3?

Cisco Industrial Ethernet 3000 Series Switches

IE3000

15.2.2E3, 15.2.3E2, 15.2.4EA 1

1.The non-VLAN 1 feature is not supported on release 15.2.4E.

Thanks for the quick reply.

I am using Project rule.

I have also tried Project rule and Template through Prime.

I totally missed that in the release notes.

I will try a different firmware and get back to you.

/Nils-Oskar

Those devices do not support SUDI either... if you are using that in the project rule

Not using SUDI

Someone1
Level 1
Level 1

Hi

Tried to do a unplanned PnP but I get the same error so it shouldn't be my config file since it doesn't even get there.

I could not do a vlan 1 try but changed the firmware for the IE3000 to Version 15.2(3)E2 as suggested.

However I am still getting the same errors in the APIC EM Status.

A small output from the console on the IE3000

Changed the IP of the APIC to X's

*Mar  1 00:01:56.459: %PNP-6-HTTP_CONNECTING: PnP Discovery trying to connect to PnP server http://X..X.X.X:80/pnp/HELLO

*Mar  1 00:01:56.467: %PNP-6-HTTP_CONNECTED: PnP Discovery connected to PnP server http://X..X.X.X:80/pnp/HELLO

*Mar  1 00:01:57.490: %PNP-6-PROFILE_CONFIG: PnP Discovery profile pnp-zero-touch configured

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

*Mar  1 00:02:46.480: %CDP-4-NATIVE_VLAN_MISMATCH: Native VLAN mismatch discovered on GigabitEthernet1/1 (1), with  GigabitEthernet1/0/21 (10).

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

*Mar  6 18:24:02.000: %SYS-6-CLOCKUPDATE: System clock has been updated from 00:03:35 UTC Mon Mar 1 1993 to 18:24:02 UTC Mon Mar 6 2017, configured from console by console.

Also a pnp trace on the IE3000

[03/01/93 00:00:44.668 UTC 1 311] Info: Startup config does not exists

[03/01/93 00:00:44.668 UTC 2 311] start_pnpa_discovery: PnP Discovery trial number[1]

[03/01/93 00:00:44.668 UTC 3 311] start_pnpa_discovery: Initiating PnP discovery manager

[03/01/93 00:00:44.668 UTC 4 311] pnpa_discovery_autoinstall_pid_create: waiting for autoinstall

[03/01/93 00:01:46.442 UTC 5 311] pnpa_discovery_autoinstall_pid_create:Received autoinstall complete status

[03/01/93 00:01:51.450 UTC 6 311] pnpa_autonomic_discovery: Starting autonomic discovery

[03/01/93 00:01:51.450 UTC 7 311] pnpa_autonomic_discovery: Starting autonomic discovery

[03/01/93 00:01:56.458 UTC 8 311] pnpa_disc_dhcp_option_43: op43 strict protocol: Yes, must secure: No

[03/01/93 00:01:56.458 UTC 9 311] pnpa_disc_dhcp_option_43: op43 profile pnp-zero-touch

[03/01/93 00:01:56.458 UTC A 311] pnpa_disc_dhcp_option_43: op43 ipaddr X..X.X.X

[03/01/93 00:01:56.458 UTC B 311] pnpa_disc_dhcp_option_43: op43 transport 1

[03/01/93 00:01:56.458 UTC C 311] pnpa_disc_dhcp_option_43: transport http

[03/01/93 00:01:56.458 UTC D 311] pnpa_validate_port_type: Port is 80

[03/01/93 00:01:56.458 UTC E 311] pnpa_disc_dhcp_option_43: op43 port 80

[03/01/93 00:01:56.458 UTC F 311] pnpa_validate_ip_type: op43 iptype ipv4

[03/01/93 00:01:56.458 UTC 10 311] pnp_httpc_register: PnP httpc registered

[03/01/93 00:01:56.458 UTC 11 311] get_pnp_work_req_url: Port is 80

[03/01/93 00:01:56.458 UTC 12 311] send_work_req: HTTPS URL = https://X..X.X.X:80/pnp/HELLO

[03/01/93 00:01:56.458 UTC 13 311] send_work_req: ERROR: HTTP SEND GET REQUEST

[03/01/93 00:01:56.458 UTC 14 311] pnp_httpc_send_get: url http://X..X.X.X:80/pnp/HELLO

[03/01/93 00:01:56.458 UTC 15 311] pnp_httpc_send_get: HTTP SEND SUCCESS

[03/01/93 00:01:56.466 UTC 16 218] pnp_http_resp_data_alloc: PnP response data alloc 4096 bytes

[03/01/93 00:01:56.466 UTC 17 218] pnp_resp_data: request status Response data recieved, successfully

[03/01/93 00:01:56.466 UTC 18 218] pnp_resp_data: DATA STARTS HERE

[03/01/93 00:01:56.466 UTC 19 218] pnp_resp_data: DATA ENDS HERE

[03/01/93 00:01:56.466 UTC 1A 218] pnp_resp_data: Status of this transaction is 200

[03/01/93 00:01:56.466 UTC 1B 218] pnp_resp_data: Length of data handed over 21

[03/01/93 00:01:56.466 UTC 1C 218] pnp_resp_data: session id       : 3

[03/01/93 00:01:56.466 UTC 1D 218] pnp_resp_data: transaction id   : 1

[03/01/93 00:01:56.466 UTC 1E 218] pnp_resp_data: status_code      : 200

[03/01/93 00:01:56.466 UTC 1F 218] pnp_resp_data: status_string    : OK

[03/01/93 00:01:56.466 UTC 20 218] pnp_resp_data: content_type     : application/json;charset=UTF-8

[03/01/93 00:01:56.466 UTC 21 218] pnp_resp_data: content_encoding :

[03/01/93 00:01:56.466 UTC 22 218] pnp_resp_data: content_length   : 21

[03/01/93 00:01:56.466 UTC 23 218] pnp_resp_data: Location         :

[03/01/93 00:01:56.466 UTC 24 218] pnp_resp_data: Server           : Jetty(9.0.z-SNAPSHOT)

[03/01/93 00:01:56.466 UTC 25 218] pnp_resp_data: Data has not been cached

[03/01/93 00:01:56.466 UTC 26 218] pnp_http_resp_data_free: pnp response data freed

[03/01/93 00:01:56.466 UTC 27 311] pnp_httpc_send_get: HTTP send success()

[03/01/93 00:01:56.466 UTC 28 311] send_work_req: HTTP SEND GET REQUEST SUCCESS

[03/01/93 00:01:57.490 UTC 29 311] pnpa_dhcp_discovery:Configured pnp profile

[03/01/93 00:01:57.490 UTC 2A 311] start_pnpa_discovery: PnP discovery process successful

[03/01/93 00:01:57.490 UTC 2B 311] pnp_autoinstall_terminate: Terminating ip autoinstall

[03/01/93 00:01:57.490 UTC 2C 311] pnp_autoinstall_terminate: Terminating DHCP autoinstall

44 entries printed

/Nils-Oskar

That looks like the process is getting started ok.

It probably takes 5mins (depending on image download etc) to complete.

You should see that the device has matched the rule on the controller as well?

What status does the controller have for the device?

I am still getting the error messages in APIC.

The extra log output was so you can see what is happening on the switch.

2017-03-07 17:44:39 (W. Europe Standard Time) Failed 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-03-07 17:44:31 (W. Europe Standard Time) Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:A required attribute is missing:

2017-03-07 17:44:31 (W. Europe Standard Time) Received fault response from pnp agent for message correlatorId null Response String: XSVC:Client:Badly framed XML received:

2017-03-07 17:44:31 (W. Europe Standard Time) Received new work request from Agent while expecting work response. Retrying operation FILESYSTEM_INFO_REQUESTED

I get the same response from pre-provisioned project and a unclaimed one.

Regards

Nils-Oskar

This is very strange.

Can you try turning on debugging.  you need to be careful with this, if you press enter on console prior to PnP contacting the controller, the PnP process will abort.

When you see the "Mar  1 00:01:56.459: %PNP-6-HTTP_CONNECTING: PnP Discovery trying to connect to PnP server http://X..X.X.X:80/pnp/HELLO"

message, you can press enter, get a console prompt and "debug pnp all"

It looks like there is some issue with the agent on the device.  15.2(3)E2 is dated July 2015 and is minimum version of code, later versions in that train would have enhancements/fixes.

I see the latest 15.2(3)E3 is Jan 2016 build, but there are 15.2(2) builds much later. 

I would use 15.2(2)E6 - Dec 2016 as it will have all of the PnP enhancements.

Adam

Another try

Version: 15.2(2)E6

Still no luck

See the debug info:

*Mar 1 00:01:56.140: %PNP-6-HTTP_CONNECTING: PnP Discovery trying to connect to PnP server http://10.11.100.17:80/pnp/HELLO

*Mar 1 00:01:56.148: %PNP-6-HTTP_CONNECTED: PnP Discovery connected to PnP server http://10.11.100.17:80/pnp/HELLO

*Mar 1 00:01:57.172: %PNP-6-PROFILE_CONFIG: PnP Discovery profile pnp-zero-touch configured

Switch>en

Switch>enable

Switch#debug pnp

Switch#debug pnp all

Switch#

*Mar 1 00:02:09.763: PNPA-infra: PKI Initialized[0]

*Mar 1 00:02:09.763: PNPA-infra: Failed to start SUDI pki session

*Mar 1 00:02:09.763: PNPA-connection: _psm.1.encap=pnp

*Mar 1 00:02:09.763: PNPA-connection: _psm.1.wkr.don=4E739DC rcp=pnp-zero-touch

*Mar 1 00:02:09.763: PNPA-connection: _pnms.msg=4E739DC xet=3

*Mar 1 00:02:09.763: PNPA-connection: _ppsm.snd.don=4BDD140

*Mar 1 00:02:09.763: PNPA-connection: _psm.1.snd.don=1 stc=0

*Mar 1 00:02:15.811: PNPA-infra: PKI Initialized[0]

*Mar 1 00:02:15.811: PNPA-infra: Failed to start SUDI pki session

*Mar 1 00:02:15.811: PNPA-connection: _psm.2.encap=pnp

*Mar 1 00:02:15.811: PNPA-connection: _psm.2.wkr.don=4E733AC rcp=pnp-zero-touch

*Mar 1 00:02:15.811: PNPA-connection: _pnms.msg=4E733AC xet=3

*Mar 1 00:02:15.811: PNPA-connection: _ppsm.snd.don=4BDD140

*Mar 1 00:02:15.811: PNPA-connection: _psm.2.snd.don=1 stc=0

*Mar 1 00:02:21.230: PNPA-infra: PKI Initialized[0]

*Mar 1 00:02:21.230: PNPA-infra: Failed to start SUDI pki session

*Mar 1 00:02:21.230: PNPA-connection: _psm.3.encap=pnp

*Mar 1 00:02:21.230: PNPA-connection: _psm.3.wkr.don=4E7303C rcp=pnp-zero-touch

*Mar 1 00:02:21.230: PNPA-connection: _pnms.msg=4E7303C xet=3

*Mar 1 00:02:21.230: PNPA-connection: _ppsm.snd.don=4BDD140

*Mar 1 00:02:21.230: PNPA-connection: _psm.3.snd.don=1 stc=0

*Mar 1 00:02:21.448: PNPA-discovery: 4.oprmode=0

*Mar 1 00:02:21.448: PNPA-discovery: 5.oprmode=0

*Mar 1 00:02:21.448: PNPA-discovery: HA registry indicates NO standby up

*Mar 1 00:02:21.448: PNPA-discovery: 6.oprmode=0

*Mar 8 17:55:46.000: %SYS-6-CLOCKUPDATE: System clock has been updated from 00:02:21 UTC Mon Mar 1 1993 to 17:55:46 UTC Wed Mar 8 2017, configured from console by console.

Mar 8 17:55:46.033: PNPA-discovery: HA, config safe check , for configuring[try:0]

Mar 8 17:55:46.033: PNPA-cert_install: clock cli:[do clock set 17:55:46 Mar 8 2017

end

]

Mar 8 17:55:46.033: PNPA-cert_install: Clock set

Mar 8 17:55:46.041: PNPA-cert_install:

Installing trustpoint

Mar 8 17:55:46.041: PNPA-infra: Trustpoint installation using crypto pki

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

Mar 8 17:55:52.853: PNPA-config: dir name:(flash:),free_bytes:15365632

Mar 8 17:55:52.853: PNPA-config: dir name:(bs1:),free_bytes:124928

Mar 8 17:55:52.853: PNPA-infra: file_size:[2697]

Mar 8 17:55:52.853: PNPA-infra: disk_backup bool[1]

Mar 8 17:55:52.887: PNPA-infra: Successful ifs copy to

Mar 8 17:55:52.887: PNPA-infra: disk_file return value[PnP-cert_17_55_52_UTC_Wed_Mar_8_2017]

Mar 8 17:55:52.887: PNPA-infra: pbf.1.did.don=flash:PnP-cert17_55_52_UTC_Wed_Mar_8_2017.ca

Mar 8 17:55:52.887: PNPA-infra: final url:[flash://PnP-cert_17_55_52_UTC_Wed_Mar_8_2017]

Mar 8 17:55:52.928: %PKI-6-CONFIGAUTOSAVE: Running configuration saved to NVRAM

Mar 8 17:55:53.415: PNPA-infra:

Removing cert copy file from disk

Mar 8 17:55:53.415: PNPA-infra: Certificate installation done by pki.Returning TRUE.

Mar 8 17:55:53.415: PNPA-infra: Done configuring the certificate

Mar 8 17:55:53.415: PNPA-cert_install: Reconnecting the profile

Mar 8 17:55:53.415: PNPA-cert_install:

PnP profile cmd: pnp profile pnp-zero-touch

Mar 8 17:55:53.415: PNPA-cert_install:

The final str: [pnp profile pnp-zero-touch

transport https ipv4 10.11.100.17 port 443

end

]

Mar 8 17:55:53.415: PNPA-cert_install: Info: PnP profile reconnect process is not running, hence initiate

Mar 8 17:55:53.415: PNPA-cert_install: Info: Started PnP reconnect profile Process, pid=303

Mar 8 17:55:53.423: PNPA-discovery: 7.oprmode=0

Mar 8 17:55:53.423: PNPA-discovery: HA registry indicates NO standby up

Mar 8 17:55:53.423: PNPA-discovery: 8.oprmode=0

Mar 8 17:55:53.423: PNPA-connection: group: pnp, profile: pnp-zero-touch

Mar 8 17:55:53.423: PNPA-connection: update current profile

Mar 8 17:55:53.423: PNPA-connection: profile handle: created

Mar 8 17:55:53.423: PNPA-connection: profile handle: visible

Mar 8 17:55:53.423: PNPA-connection: _pctc.2.ipv4=10.11.100.17

Mar 8 17:55:53.423: PNPA-connection: _pctc.2.pfl=4BDD140 ctr=1 ipt=1 tpt=2 prt=443

Mar 8 17:55:53.423: PNPA-connection: current profile active

Mar 8 17:55:53.423: PNPA-connection: http path: pnp/WORK-REQUEST

Mar 8 17:55:53.423: PNPA-connection: _ppspo.pst=pnp/WORK-REQUEST

Mar 8 17:55:53.423: PNPA-connection: trbd.2.pname:pnp-zero-touch, node:47C5084 transport:2 Rebuild DOM now

Mar 8 17:55:53.423: PNPA-connection: trbd.2.trprim

Mar 8 17:55:53.432: PNPA-connection: trbd.2.node=47C5084, sn_rt=4BEA3C4, profile=4BDD140

Mar 8 17:55:53.432: PNPA-connection: trbd.2.pname=pnp-zero-touch

Mar 8 17:55:53.432: PNPA-connection: trbd.2.bpath=pnp.subpath=WORK-REQUEST

Mar 8 17:55:53.432: PNPA-connection: current profile active

Mar 8 17:55:53.432: PNPA-connection: http path: pnp/WORK-REQUEST

Mar 8 17:55:53.432: PNPA-connection: trbd.2.trbkup RESTORE

Mar 8 17:55:54.438: PNPA-connection: _pctcrd.2.rbd.don=47C5084 pld=0

Mar 8 17:55:54.438: PNPA-connection: _pgapb.apb.don=pnp

Mar 8 17:55:54.438: PNPA-connection: No cloud key set

Mar 8 17:55:54.438: PNPA-connection: No param

Mar 8 17:55:54.438: PNPA-infra: PKI Initialized[0]

Mar 8 17:55:54.438: PNPA-infra: Failed to start SUDI pki session

Mar 8 17:55:54.438: PNPA-connection: current profile active

Mar 8 17:55:54.438: PNPA-connection: http path: pnp/WORK-REQUEST

Mar 8 17:55:54.438: PNPA-connection: No cloud key set

Mar 8 17:55:54.438: PNPA-connection: No param

Mar 8 17:55:54.438: PNPA-connection: http url: https://10.11.100.17:443/pnp/WORK-REQUEST

Mar 8 17:55:54.438: PNPA-discovery: HA, config safe check , for configuring[try:0]

Mar 8 17:55:54.438: PNPA-redirection:

Profile Reconnect Successful

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

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

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

Mar 8 17:57:55.411: PNPA-infra: PKI Initialized[0]

Mar 8 17:57:55.411: PNPA-infra: Failed to start SUDI pki session

Mar 8 17:57:55.411: PNPA-connection: _psm.4.encap=pnp

Mar 8 17:57:55.411: PNPA-connection: _psm.4.wkr.don=4E728AC rcp=pnp-zero-touch

Mar 8 17:57:55.411: PNPA-connection: _pnms.msg=4E728AC xet=3

Mar 8 17:57:55.411: PNPA-connection: _ppsm.snd.don=4BDD140

Mar 8 17:57:55.411: PNPA-connection: _psm.4.snd.don=1 stc=0

Mar 8 17:59:56.248: PNPA-infra: PKI Initialized[0]

Mar 8 17:59:56.248: PNPA-infra: Failed to start SUDI pki session

Mar 8 17:59:56.248: PNPA-connection: _psm.5.encap=pnp

Mar 8 17:59:56.248: PNPA-connection: _psm.5.wkr.don=4E724E4 rcp=pnp-zero-touch

Mar 8 17:59:56.248: PNPA-connection: _pnms.msg=4E724E4 xet=3

Mar 8 17:59:56.248: PNPA-connection: _ppsm.snd.don=4BDD140

Mar 8 17:59:56.248: PNPA-connection: _psm.5.snd.don=1 stc=0

Mar 8 18:01:57.162: PNPA-infra: PKI Initialized[0]

Mar 8 18:01:57.162: PNPA-infra: Failed to start SUDI pki session

Mar 8 18:01:57.162: PNPA-connection: _psm.6.encap=pnp

Mar 8 18:01:57.162: PNPA-connection: _psm.6.wkr.don=4E72174 rcp=pnp-zero-touch

Mar 8 18:01:57.162: PNPA-connection: _pnms.msg=4E72174 xet=3

Mar 8 18:01:57.162: PNPA-connection: _ppsm.snd.don=4BDD140

Mar 8 18:01:57.162: PNPA-connection: _psm.6.snd.don=1 stc=0

And it does the same thing until health check fail.

Regards

Nils-Oskar

What is your APIC-EM version, Nils-Oskar?

I thought I had added that in the first post but must have missed it.

We are running APIC-EM Version 1.3.2.37.

I know you tested with project rule. can you test it with "unclaimed" work flow? It seems to be that IE3000 is stuck in SUDI state.

I have tried and added the switch through "unclaimed" work flow as well.

It appears in the unclaimed section but still fails at "retrieving device information" and ends up in the same "loop".

So it never really goes into APIC EM where I can apply a config file or image.

Can it be that APIC recognises the switch even though I removed it?

I will see if I can get a hold of another IE3000 that hasn't been used at all.

Thanks for the suggestions so far.

Can you also get "show pnp tech" when you try next time?

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community:


This community is intended for developer topics around Data Center technology and products. If you are looking for a non-developer topic about Data Center, you might find additional information in the Data Center and Cloud community