Solved: Re: Failed health check since device is stuck in non-terminal state PROVISIONING_CONFIG for more tha...

michael.taylor · ‎02-23-2017

Having succesfuly deployed a brand new Cisco 4331 ( isr4300-universalk9.03.16.04b.S.155-3.S4b-ext.SPA.bi) the health check message appears.

Here's the current pnp status:

4331SWA#sho pnp sum

------------------ show pnp summary ------------------

PnP Schema Version: 1.0, Baseline Tracking: rel18.1.160426

Device UDI: PID:ISR4331/K9,VID:V02,SN:FD123456789

UDI Checking: Yes

Security Enforced: No, PostReloadPriv'd Profile: pnp-zero-touch

SUDI Certificate: CISCO_IDEVID_SUDI

Device SUDI: PID:ISR4331/K9,SN:FDO21020KZM

------------------ show pnp udi tracking ---------

Best UDI:[PID:ISR4331/K9,VID:V02,SN:FD123456789]

Good UDI:[PID:ISR4331/K9,VID:,SN:FD123456789]

Incomplete UDI:[-]

UDI by Master Registry:[]

UDI by Entity MIBS:[PID:ISR4331/K9,VID:V02,SN:FD123456789]

UDI by Platform Registry:[PID:ISR4331/K9,VID:,SN:FD123456789]

-------------- show pnp config tracking ---------------

Config Monitor: Off, Switched: 2

Config Control Level:[Basic-Check], Last-ConfControl:[Basic-Check]

Config Retry: 300, Interval: 1000 ms

Config Reserved By:[-], Last-ConfReserve:[-]

Startup Config: Found, Write Started: 0, Done: 0, PID: 0, Last-PID: 0

Running Config: Not Locked, Safe Now: Yes, CLI Changed: 7, Bulk Count: 3, Last Delta: 2, PID: 531, Last-PID: 364

-------------- show pnp ha tracking ---------------

HA Presence Checking: No, RF Support Yes

RF Op-Mode Registry: Yes, State: 0

Config-Sync Registry: Yes, State: -

Standby Notify Hot: 0, Cold: 0

------------------ show pnp discovery -----------------

Auto-Install: Started: 1, Done: 0, PID: 0, Last-PID: 0

DHCP Auto-Install: Registry: Yes, Running: No, IP-Resolved: Yes

Network Download: Enabled: Yes, Loaded: No

Host Download: Enabled: Yes, Loaded: No

PnP Auto-Wait: Complete: Yes, BT-Stopped: No, PID: -1, Last-PID: 610

PnP Discovery: PFD:[pnp-zero-touch], Run Count: 1, Status: Finished, Last Run: Success

PnP DHCP Discovery: Idn:[GigabitEthernet0/0/0] Op43-Text:[5A1N;B2;K4;I10.x.y.z;J80], Last-Op43-Text:[-]

PnP WebUI Discovery: Enabled: No, Allowed: No

PnP WebUI Config: IP: No, DHCP: No, DNS: No, HTTP: No

PnP DHCP Snooping: Supported: No, Validation: No, Registry: DHCP: No, Vlan: No, Trust Interfaces: No

PnP DHCP-Op43: N/A, Ready: No, DHCP-Op60: ciscopnp, Ready: Yes

PnP Proxy Name: none(Not Ready), Associated Profile: pnp-zero-touch(Found)

PnP Proxy Service Count: Change=1 Up=0 Down=0 NoOP=0 Fail=0 UDI=0 RSP=0

------------------ show pnp profiles ------------------

Name CBType Node Primary-Path Primary-Trans Backup-Trans

pnp-zero-touch DHCP visible pnp/WORK-REQUEST HTTPS none

Initiator Profile pnp-zero-touch: 0 open connections: 0 closing connections

Encap: pnp

WSSE header is not required. Configured authorization level is 1

Work-Request Tracking: Validation Yes, Total 76, SID=[-], Violation 0, PSR 0, PSB 0

Pending-WR: X/M/R=0/0/67, UDI=[PID:ISR4331/K9,VID:V02,SN:FD123456789], SID=[-], Correlator=[CiscoPnP-1.0-1 3-214-7FEAFD507788-10]

Last-WR: X/M/R=0/1/0, UDI=[PID:ISR4331/K9,VID:V02,SN:FD123456789], SID=[-], Correlator=[CiscoPnP-1.0-12-21 4-7FEAFD4FFAD0-9]

PnP Response Tracking: Retry-Allowed 0, Total 0

Last-PR: X/M/R=0/0/0, UDI=[PID:ISR4331/K9,VID:V02,SN:FD123456789], SID=[-], Correlator=[CiscoPnP-1.0-12-21 4-7FEAFD4FFAD0-9]

PnP Backoff Time Tracking: Default 60, Current 60, Last 60

Countdown: Security Unlock: S=2/F=0/T=0, Service Lock: S=2/F=0/T=0, Service Req Wait: S=0/F=0/T=1, Prxoy Req Wait S=101/F=0/T=0, Service Resp Ack: S=23/F=0/T=0

Max message (RX) is 50 Kbytes

XEP Faults are sent

Idle timeout infinite

Keepalive not configured

Reconnect time 60 seconds

Primary Transport:https to Host:-, IP:10.x.y.z, Port:443, Src-Intf:-, VRF:-, URL pnp/WORK-REQUEST

Not connected, next reconnect attempt in 1 seconds

------------------ show pnp counters ------------------

Statistics for profile pnp-zero-touch

incoming total 15, bad XML 0, authentication errors 0, oversized 0

outgoing total 86, absorbed 0

message internal errors 7

Connection Accepts 70, local hangup 0, remote hangup 70, keepalive hangup 0

session internal errors 0, continuous faults 0, total faults 0

------------------ show pnp tasks ---------------------

Certificate-Install Task - Last Run ID:4, ST:7201, Result:Success, LT:102693, ET:3 ms

Src:[-], Dst:[-]

Image-Install Task - Never Run

Config-Upgrade Task - Last Run ID:7, ST:5202, Result:Failed, LT:263730, ET:14309 ms

Src:[https://10.x.y.z:443/api/v1/file/onetimedownload/5cb9616d-cbca-48d7-8c19-a06d502995ed], Dst:[running]

Error Code:1413, Msg:[Invalid input detected]

CLI-Config Task - Never Run

Licensing Task - Never Run

File-Transfer Task - Never Run

Redirection Task - Never Run

CLI-Exec Task - Last Run ID:6, ST:5401, Result:Success, LT:117745, ET:3 ms

Src:[cli-exec request], Dst:[running-exec]

---------- show pnp file backup tracking -------------

Last Backup Result:[1 _pbf.s2d.don: src=[https://10.x.y.z:443/api/v1/file/onetimedownload/5cb9616d-cbca-48d7-8c19-a0 6d502995ed], dest=[bootflash:], dpath=[bootflash:tmp-pnp_1_15_32_44_UTC_Thu_Feb_23_2017]]

Last Src File Path:[https://10.x.y.z:443/api/v1/file/onetimedownload/5cb9616d-cbca-48d7-8c19-a06d502995ed], Size: 1, Checksum=[-]

Last Src Backup Path:[bootflash:tmp-pnp_1_15_32_44_UTC_Thu_Feb_23_2017], Size: 6862

Last Src Backup Result:[1 _pactr.b2s.ok: src backup file [bootflash:tmp-pnp_1_15_32_44_UTC_Thu_Feb_23_2017] copied to runn ing ok]

Total Src Backup Count: 1

Last Dest File Path:[system:/running-config], Size: 3933

Last Dest Backup Path:[-]

Last Dest Backup Result:[-]

Total Dest Backup Count: 0

Last Free FS0 Dir Name:[bootflash:], Free Bytes: 33545577

Last Free FS1 Dir Name:[nvram:], Free Bytes: 0

------------------ show pnp services ------------------

Service name: XML Auto-Install Service, Status: Never Run

Service name: XML Discovery Service, Run Count: 1 (S=1/F=0/O=0), Status: Last Run Success, Elapsed Time: 49167 ms

Service name: XML DHCP Discovery Service, Run Count: 1 (S=1/F=0/O=0), Status: Last Run Success, Elapsed Time: 18073 ms

Service name: XML DNS Discovery Service, Status: Never Run

Service name: XML Platform Discovery Service, Status: Never Run

Service name: XML CCO Discovery Service, Status: Never Run

Service name: XML Webui Discovery Service, Status: Never Run

Service name: XML NAPP Discovery Service, Status: Never Run

Service name: XML SMI Discovery Service, Status: Never Run

Service name: XML Capability Service, Status: Never Run

Service name: XML Certificate-Install Service, Run Count: 2 (S=2/F=0/O=0), Status: Last Run Success, Elapsed Time: 3 ms

Service name: XML Config-Change Service, Run Count: 3 (S=3/F=0/O=0), Status: Last Run Success, Elapsed Time: 6064 ms

Service name: XML Config-Upgrade Service, Run Count: 1 (S=0/F=1/O=0), Status: Last Run Failed, Elapsed Time: 14309 ms

Service name: XML CLI-Config Service, Status: Never Run

Service name: XML Device-Info Service, Run Count: 3 (S=3/F=0/O=0), Status: Last Run Success, Elapsed Time: <1 ms

Service name: XML CLI-Exec Service, Run Count: 4 (S=4/F=0/O=0), Status: Last Run Success, Elapsed Time: 3 ms

Service name: XML File-Transfer Service, Status: Never Run

Service name: XML Image-Install Service, Status: Never Run

Service name: XML Licensing Service, Status: Never Run

Service name: XML Location Service, Status: Never Run

Service name: XML Napp Service, Status: Never Run

Service name: XML NappServer Service, Status: Never Run

Service name: XML Notify Service, Status: Never Run

Service name: XML Proxy Service, Status: Never Run

Service name: XML Server redirection Service, Status: Never Run

Service name: XML Snooping Service, Status: Never Run

Service name: XML Syslog Service, Status: Never Run

Service name: XML Device-Auth Service, Status: Never Run

Service name: XML Work-Req Service, Run Count: 489 (S=70/F=2/O=417), Status: Last Run Success, Elapsed Time: <1 ms

Service name: XML Work-Backoff Service, Run Count: 2 (S=2/F=0/O=0), Status: Last Run Success, Elapsed Time: <1 ms

Service name: XML Response Service, Run Count: 12 (S=12/F=0/O=0), Status: Last Run Success, Elapsed Time: 15911 ms

Service name: XML Fault Service, Status: Never Run

Service name: XML Work-Info Service, Run Count: 10 (S=10/F=0/O=0), Status: Last Run Success, Elapsed Time: <1 ms

------------------ show pnp history ------------------

PnP Job History:1, T:4473388, QS:528

.!!. T:4055378, Job 489:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4055378, Job 490:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4055378, Job 491:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4055378, Job 492:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

.xx. T:4115378, Job 493:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.zz. T:4115379, Job 494:XML Work-Req Service, Elapsed:60001 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.!!. T:4115379, Job 495:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4115379, Job 496:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4115379, Job 497:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4115379, Job 498:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

.xx. T:4175379, Job 499:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.zz. T:4175379, Job 500:XML Work-Req Service, Elapsed:60000 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.!!. T:4175379, Job 501:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4175379, Job 502:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4175379, Job 503:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4175379, Job 504:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

.xx. T:4235379, Job 505:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.zz. T:4235380, Job 506:XML Work-Req Service, Elapsed:60001 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.!!. T:4235380, Job 507:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4235380, Job 508:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4235380, Job 509:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4235380, Job 510:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

.xx. T:4295380, Job 511:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.zz. T:4295380, Job 512:XML Work-Req Service, Elapsed:60000 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.!!. T:4295380, Job 513:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4295380, Job 514:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4295380, Job 515:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4295380, Job 516:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

.xx. T:4355381, Job 517:XML Work-Req Service, Elapsed:60001 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.zz. T:4355381, Job 518:XML Work-Req Service, Elapsed:60001 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.!!. T:4355381, Job 519:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4355381, Job 520:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4355381, Job 521:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4355381, Job 522:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

.xx. T:4415381, Job 523:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.zz. T:4415382, Job 524:XML Work-Req Service, Elapsed:60001 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FE AFD507788-10

.!!. T:4415382, Job 525:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.zz. T:4415382, Job 526:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

.!!. T:4415382, Job 527:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD5 07788-10

-1-> T:4415382, Job 528:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-13-214-7FEAFD507788 -10

4331SWA#sho pnp trace

[02/23/17 15:28:25.231 UTC 1 531] Info: Startup config does not exists

[02/23/17 15:28:25.231 UTC 2 531] start_pnpa_discovery: PnP Discovery trial number[1]

[02/23/17 15:28:25.231 UTC 3 531] start_pnpa_discovery: Initiating PnP discovery manager

[02/23/17 15:28:25.231 UTC 4 531] pnpa_discovery_autoinstall_pid_create: waiting for autoinstall

[02/23/17 15:28:55.325 UTC 5 531] pnpa_discovery_autoinstall_pid_create:Received autoinstall complete status

[02/23/17 15:28:56.324 UTC 6 531] pnpa_disc_dhcp_option_43.1: op43 strict protocol: Yes, must secure: No

[02/23/17 15:28:56.324 UTC 7 531] pnpa_disc_dhcp_option_43: op43 profile pnp-zero-touch

[02/23/17 15:28:56.324 UTC 8 531] pnpa_disc_dhcp_option_43: op43 ipaddr 10.x.y.z

[02/23/17 15:28:56.324 UTC 9 531] pnpa_disc_dhcp_option_43: op43 transport 1

[02/23/17 15:28:56.324 UTC A 531] pnpa_disc_dhcp_option_43: transport http

[02/23/17 15:28:56.324 UTC B 531] pnpa_validate_port_type: Port is 80

[02/23/17 15:28:56.324 UTC C 531] pnpa_disc_dhcp_option_43: op43 port 80

[02/23/17 15:28:56.324 UTC D 531] pnpa_validate_ip_type: op43 iptype ipv4

[02/23/17 15:28:56.324 UTC E 531] pnp_httpc_register: PnP httpc registered

[02/23/17 15:28:56.324 UTC F 531] get_pnp_work_req_url: Port is 80

[02/23/17 15:28:56.324 UTC 10 531] pnp_httpc_send_get: url http://10.x.y.z:80/pnp/HELLO

[02/23/17 15:28:56.324 UTC 11 531] pnp_httpc_send_get: HTTP SEND SUCCESS

[02/23/17 15:29:08.331 UTC 12 313] pnp_http_resp_data_alloc: PnP response data alloc 4096 bytes

[02/23/17 15:29:08.331 UTC 13 313] pnp_resp_data: request status Response data recieved, successfully

[02/23/17 15:29:08.331 UTC 14 313] pnp_resp_data: DATA STARTS HERE

[02/23/17 15:29:08.331 UTC 15 313] pnp_resp_data: DATA ENDS HERE

[02/23/17 15:29:08.331 UTC 16 313] pnp_resp_data: Status of this transaction is 200

[02/23/17 15:29:08.331 UTC 17 313] pnp_resp_data: Length of data handed over 21

[02/23/17 15:29:08.331 UTC 18 313] pnp_resp_data: session id : 3

[02/23/17 15:29:08.331 UTC 19 313] pnp_resp_data: transaction id : 1

[02/23/17 15:29:08.331 UTC 1A 313] pnp_resp_data: status_code : 200

[02/23/17 15:29:08.331 UTC 1B 313] pnp_resp_data: status_string : OK

[02/23/17 15:29:08.331 UTC 1C 313] pnp_resp_data: content_type : application/json;charset=UTF-8

[02/23/17 15:29:08.331 UTC 1D 313] pnp_resp_data: content_encoding :

[02/23/17 15:29:08.331 UTC 1E 313] pnp_resp_data: content_length : 21

[02/23/17 15:29:08.331 UTC 1F 313] pnp_resp_data: Location :

[02/23/17 15:29:08.331 UTC 20 313] pnp_resp_data: Server : Jetty(9.0.z-SNAPSHOT)

[02/23/17 15:29:08.331 UTC 21 313] pnp_resp_data: Data has not been cached

[02/23/17 15:29:08.331 UTC 22 313] pnp_http_resp_data_free: pnp response data freed

[02/23/17 15:29:08.331 UTC 23 531] pnp_httpc_send_get: HTTP send success()

[02/23/17 15:29:08.331 UTC 24 531] send_work_req: HTTP SEND GET REQUEST SUCCESS

[02/23/17 15:29:08.331 UTC 25 531] pnp_setup_abort:Setup abort initiated

[02/23/17 15:29:14.397 UTC 26 531] HA, config safe check [OK], for configuring[try:0]

[02/23/17 15:29:14.397 UTC 27 531] pnpa_dhcp_discovery:Configured pnp profile

[02/23/17 15:29:14.397 UTC 28 531] start_pnpa_discovery: PnP discovery process successful

[02/23/17 15:29:14.397 UTC 29 531] pnp_autoinstall_terminate: Terminating ip autoinstall

[02/23/17 15:29:14.397 UTC 2A 531] pnp_autoinstall_terminate: Terminating DHCP autoinstall

[02/23/17 15:29:43.005 UTC 2B 176] HA, config safe check [OK], for configuring[try:0]

[02/23/17 15:29:55.810 UTC 2C 157] HA, config safe check [OK], for configuring[try:0]

[02/23/17 15:34:31.585 UTC 2D 419] revert_pnpa_webui_discovery:PnP Webui config reverted (4)

[02/23/17 16:42:58.792 UTC 2E 614] Non-redundancy mode (0) after 2 retries.

46 entries printed

There are no connecivity issues between APIC's VIP and the routers management network.

It's ironic that the downstream Cosco 2960X is in a provisioned state.

Help and advice would be much appreciated.

Thanks in anticipation

michael.taylor · ‎04-19-2017

Hello Adam,

Resolution to Service Request 682005792, involving Peng Xu (San Jose BU) was achieved by adding an undocumented "ip http client source-interface" configuration command enabling the designated ssub-interface to initiate an xml heartbeat back to APIC-EM. However, the ongoing absence of nvram resident start-up configuration was addressed with the addition of a run-once-self destructing eem script attached to the foot of each and every deployed configuration.

Cisco also advised that manually deployed configurations should not include RSA keys; they are always generated by APIC-EM. Other issues raised include DHCP binding. APIC-EM forms an association using the initial DHCP supplied IP address; the bond is broken if for any reason this adrresss changes.

Since closure of the case my customer has also regained the ability to automatically upgrade IOS during the deployment.

I consider that this discussion can now be closed.

View solution in original post

aradford · ‎02-23-2017

HI Michael,

do you have "aaa command authorisation" in your configuration file?

Adam

aradford · ‎02-23-2017

Actually, just took a closer look. seems like there was an issue with the configuration file?

Config-Upgrade Task - Last Run ID:7, ST:5202, Result:Failed, LT:263730, ET:14309 ms

Src:[https://10.x.y.z:443/api/v1/file/onetimedownload/5cb9616d-cbca-48d7-8c19-a06d502995ed], Dst:[running]

Error Code:1413, Msg:[Invalid input detected]

That still might be due to "aaa command authorisation".

Have you tried pasting the config in manually to see where it fails?

Adam

michael.taylor · ‎02-23-2017

Hello Adam,

Would you please expand on your concerns regarding "aaa authorization"; you have referred to this command in other postings. It is not included within my configuration

Meanwhile, the router has now deployed withouterror although I waiting for the Provisioned Green light in my browser.

The ISR43xx router'd default inclusion of a interface vlan 1 SVI is strange to say the least; I had not stripped it from the deployed config and it generated the error.

Unfortunately I have just received another "PROVISIONING_CONFIG for more than threshold time: 0 hours, 16 minutes, 0 seconds".

Here's a fresh show pnp summary:

4331SWA#sho pnp summ

------------------ show pnp summary ------------------

PnP Schema Version: 1.0, Baseline Tracking: rel18.1.160426

Device UDI: PID:ISR4331/K9,VID:V02,SN:FD123456789

UDI Checking: Yes

Security Enforced: Yes, PostReloadPriv'd Profile: pnp-zero-touch

SUDI Certificate: CISCO_IDEVID_SUDI

Device SUDI: PID:ISR4331/K9,SN:FDO21020KZM

------------------ show pnp udi tracking ---------

Best UDI:[PID:ISR4331/K9,VID:V02,SN:FD123456789]

Good UDI:[PID:ISR4331/K9,VID:,SN:FD123456789]

Incomplete UDI:[-]

UDI by Master Registry:[]

UDI by Entity MIBS:[PID:ISR4331/K9,VID:V02,SN:FD123456789]

UDI by Platform Registry:[PID:ISR4331/K9,VID:,SN:FD123456789]

-------------- show pnp config tracking ---------------

Config Monitor: Off, Switched: 2

Config Control Level:[Basic-Check], Last-ConfControl:[Basic-Check]

Config Retry: 300, Interval: 1000 ms

Config Reserved By:[-], Last-ConfReserve:[-]

Startup Config: Found, Write Started: 0, Done: 0, PID: 0, Last-PID: 0

Running Config: Not Locked, Safe Now: Yes, CLI Changed: 7, Bulk Count: 3, Last Delta: 2, PID: 531, Last-PID: 364

-------------- show pnp ha tracking ---------------

HA Presence Checking: No, RF Support Yes

RF Op-Mode Registry: Yes, State: 0

Config-Sync Registry: Yes, State: -

Standby Notify Hot: 0, Cold: 0

------------------ show pnp discovery -----------------

Auto-Install: Started: 1, Done: 0, PID: 0, Last-PID: 0

DHCP Auto-Install: Registry: Yes, Running: No, IP-Resolved: Yes

Network Download: Enabled: Yes, Loaded: No

Host Download: Enabled: Yes, Loaded: No

PnP Auto-Wait: Complete: Yes, BT-Stopped: No, PID: -1, Last-PID: 610

PnP Discovery: PFD:[pnp-zero-touch], Run Count: 1, Status: Finished, Last Run: Success

PnP DHCP Discovery: Idn:[GigabitEthernet0/0/0] Op43-Text:[5A1N;B2;K4;I10.x.y.z;J80], Last-Op43-Text:[-]

PnP WebUI Discovery: Enabled: No, Allowed: No

PnP WebUI Config: IP: No, DHCP: No, DNS: No, HTTP: No

PnP DHCP Snooping: Supported: No, Validation: No, Registry: DHCP: No, Vlan: No, Trust Interfaces: No

PnP DHCP-Op43: N/A, Ready: No, DHCP-Op60: ciscopnp, Ready: Yes

PnP Proxy Name: none(Not Ready), Associated Profile: pnp-zero-touch(Found)

PnP Proxy Service Count: Change=1 Up=0 Down=0 NoOP=0 Fail=0 UDI=0 RSP=0

------------------ show pnp profiles ------------------

Name CBType Node Primary-Path Primary-Trans Backup-Trans

pnp-zero-touch DHCP visible pnp/WORK-REQUEST HTTPS none

Initiator Profile pnp-zero-touch: 0 open connections: 0 closing connections

Encap: pnp

WSSE header is not required. Configured authorization level is 1

Work-Request Tracking: Validation Yes, Total 30, SID=[-], Violation 0, PSR 0, PSB 0

Pending-WR: X/M/R=0/0/21, UDI=[PID:ISR4331/K9,VID:V02,SN:FD123456789], SID=[-], Correlator=[CiscoPnP-1.0-12-214-7F6BBAA8FA50-10]

Last-WR: X/M/R=0/1/0, UDI=[PID:ISR4331/K9,VID:V02,SN:FD123456789], SID=[-], Correlator=[CiscoPnP-1.0-11-214-7F6BBAA8CE70-9]

PnP Response Tracking: Retry-Allowed 0, Total 0

Last-PR: X/M/R=0/0/0, UDI=[PID:ISR4331/K9,VID:V02,SN:FD123456789], SID=[-], Correlator=[CiscoPnP-1.0-11-214-7F6BBAA8CE70-9]

PnP Backoff Time Tracking: Default 60, Current 60, Last 60

Countdown: Security Unlock: S=2/F=0/T=2152, Service Lock: S=2/F=0/T=0, Service Req Wait: S=0/F=0/T=17, Prxoy Req Wait S=54/F=0/T=0, Service Resp Ack: S=23/F=0/T=0

Max message (RX) is 50 Kbytes

XEP Faults are sent

Idle timeout infinite

Keepalive not configured

Reconnect time 60 seconds

Primary Transport:https to Host:-, IP:10.x.y.z, Port:443, Src-Intf:-, VRF:-, URL pnp/WORK-REQUEST

Not connected, next reconnect attempt in 18 seconds

------------------ show pnp counters ------------------

Statistics for profile pnp-zero-touch

incoming total 15, bad XML 0, authentication errors 0, oversized 0

outgoing total 40, absorbed 0

message internal errors 7

Connection Accepts 24, local hangup 0, remote hangup 24, keepalive hangup 0

session internal errors 0, continuous faults 0, total faults 0

------------------ show pnp tasks ---------------------

Certificate-Install Task - Last Run ID:3, ST:7201, Result:Success, LT:93756, ET:3 ms

Src:[-], Dst:[-]

Image-Install Task - Never Run

Config-Upgrade Task - Last Run ID:6, ST:5202, Result:Success, LT:254150, ET:13787 ms

Src:[https://10.x.y.z:443/api/v1/file/onetimedownload/e9421674-6d85-4caf-89e8-5dab3ceb8ff5], Dst:[running]

CLI-Config Task - Never Run

Licensing Task - Never Run

File-Transfer Task - Never Run

Redirection Task - Never Run

CLI-Exec Task - Last Run ID:5, ST:5401, Result:Success, LT:108856, ET:3 ms

Src:[cli-exec request], Dst:[running-exec]

---------- show pnp file backup tracking -------------

Last Backup Result:[1 _pbf.s2d.don: src=[https://10.x.y.z:443/api/v1/file/onetimedownload/e9421674-6d85-4caf-89e8-5dab3ceb8ff5], dest=[bootflash:], dpath=[bootflash:tmp-pnp_1_19_26_10_UTC_Thu_Feb_23_2017]]

Last Src File Path:[https://10.x.y.z:443/api/v1/file/onetimedownload/e9421674-6d85-4caf-89e8-5dab3ceb8ff5], Size: 1, Checksum=[-]

Last Src Backup Path:[bootflash:tmp-pnp_1_19_26_10_UTC_Thu_Feb_23_2017], Size: 6815

Last Src Backup Result:[1 _pactr.b2s.ok: src backup file [bootflash:tmp-pnp_1_19_26_10_UTC_Thu_Feb_23_2017] copied to running ok]

Total Src Backup Count: 1

Last Dest File Path:[system:/running-config], Size: 3933

Last Dest Backup Path:[-]

Last Dest Backup Result:[-]

Total Dest Backup Count: 0

Last Free FS0 Dir Name:[bootflash:], Free Bytes: 33545577

Last Free FS1 Dir Name:[nvram:], Free Bytes: 0

------------------ show pnp services ------------------

Service name: XML Auto-Install Service, Status: Never Run

Service name: XML Discovery Service, Run Count: 1 (S=1/F=0/O=0), Status: Last Run Success, Elapsed Time: 49329 ms

Service name: XML DHCP Discovery Service, Run Count: 1 (S=1/F=0/O=0), Status: Last Run Success, Elapsed Time: 18076 ms

Service name: XML DNS Discovery Service, Status: Never Run

Service name: XML Platform Discovery Service, Status: Never Run

Service name: XML CCO Discovery Service, Status: Never Run

Service name: XML Webui Discovery Service, Status: Never Run

Service name: XML NAPP Discovery Service, Status: Never Run

Service name: XML SMI Discovery Service, Status: Never Run

Service name: XML Capability Service, Status: Never Run

Service name: XML Certificate-Install Service, Run Count: 2 (S=2/F=0/O=0), Status: Last Run Success, Elapsed Time: 3 ms

Service name: XML Config-Change Service, Run Count: 3 (S=3/F=0/O=0), Status: Last Run Success, Elapsed Time: 6065 ms

Service name: XML Config-Upgrade Service, Run Count: 1 (S=1/F=0/O=0), Status: Last Run Success, Elapsed Time: 13787 ms

Service name: XML CLI-Config Service, Status: Never Run

Service name: XML Device-Info Service, Run Count: 3 (S=3/F=0/O=0), Status: Last Run Success, Elapsed Time: <1 ms

Service name: XML CLI-Exec Service, Run Count: 3 (S=3/F=0/O=0), Status: Last Run Success, Elapsed Time: 3 ms

Service name: XML File-Transfer Service, Status: Never Run

Service name: XML Image-Install Service, Status: Never Run

Service name: XML Licensing Service, Status: Never Run

Service name: XML Location Service, Status: Never Run

Service name: XML Napp Service, Status: Never Run

Service name: XML NappServer Service, Status: Never Run

Service name: XML Notify Service, Status: Never Run

Service name: XML Proxy Service, Status: Never Run

Service name: XML Server redirection Service, Status: Never Run

Service name: XML Snooping Service, Status: Never Run

Service name: XML Syslog Service, Status: Never Run

Service name: XML Device-Auth Service, Status: Never Run

Service name: XML Work-Req Service, Run Count: 206 (S=24/F=2/O=180), Status: Last Run Success, Elapsed Time: <1 ms

Service name: XML Work-Backoff Service, Run Count: 2 (S=2/F=0/O=0), Status: Last Run Success, Elapsed Time: <1 ms

Service name: XML Response Service, Run Count: 11 (S=11/F=0/O=0), Status: Last Run Success, Elapsed Time: 15149 ms

Service name: XML Fault Service, Status: Never Run

Service name: XML Work-Info Service, Run Count: 9 (S=9/F=0/O=0), Status: Last Run Success, Elapsed Time: <1 ms

------------------ show pnp history ------------------

PnP Job History:4, T:1693741, QS:242

.!!. T:1285528, Job 203:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1285528, Job 204:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1285528, Job 205:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1285528, Job 206:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.xx. T:1345528, Job 207:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1345528, Job 208:XML Work-Req Service, Elapsed:60000 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1345528, Job 209:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1345528, Job 210:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1345528, Job 211:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1345528, Job 212:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.xx. T:1405528, Job 213:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1405529, Job 214:XML Work-Req Service, Elapsed:60001 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1405529, Job 215:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1405529, Job 216:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1405529, Job 217:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1405529, Job 218:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.xx. T:1465529, Job 219:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1465529, Job 220:XML Work-Req Service, Elapsed:60000 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1465529, Job 221:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1465529, Job 222:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1465529, Job 223:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1465529, Job 224:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.xx. T:1525529, Job 225:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1525530, Job 226:XML Work-Req Service, Elapsed:60001 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1525530, Job 227:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1525530, Job 228:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1525530, Job 229:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1525530, Job 230:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.xx. T:1585530, Job 231:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1585530, Job 232:XML Work-Req Service, Elapsed:60000 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1585531, Job 233:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1585531, Job 234:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1585531, Job 235:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1585531, Job 236:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.xx. T:1645531, Job 237:XML Work-Req Service, Elapsed:60000 ms, Status: TimerExpired, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1645531, Job 238:XML Work-Req Service, Elapsed:60000 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1645531, Job 239:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.zz. T:1645531, Job 240:XML Work-Req Service, Elapsed:1 ms, Status: TimerStopped, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

.!!. T:1645531, Job 241:XML Work-Req Service, Elapsed:1 ms, Status: TimerStarted, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

-1-> T:1645531, Job 242:XML Work-Req Service, Elapsed:1 ms, Status: Success, WorkReqCorr: CiscoPnP-1.0-12-214-7F6BBAA8FA50-10

Thank you for helping thus far..

FYI The APIC-EM device credentials give the appliance Level 15 access by virtue of vty privilege level 15 commands. Access is limited toi SSH and has been verified from a DHCP Server sat on the APIC-EM's subnet.

aradford · ‎02-23-2017

Hi Michael,

I have written up the issue (and a solution) in this blog post Network Automation with Plug and Play (PnP) – Part 7 It is also addressed in IOS in

That looks like the configuration has been upgraded successfully. Are you saying the device did not deploy successfully?

A couple more things:

1) Can you verify the "show run" is the same as the config you pushed?

2) Can you discover the device (using the discovery process in APIC-EM)?

3) How did you deploy this device? A pre-provisioned rule or Ad-Hoc?

4) is there anything in "show loggin" that is interesting?

Adam

michael.taylor · ‎04-19-2017

Hello Adam,

Resolution to Service Request 682005792, involving Peng Xu (San Jose BU) was achieved by adding an undocumented "ip http client source-interface" configuration command enabling the designated ssub-interface to initiate an xml heartbeat back to APIC-EM. However, the ongoing absence of nvram resident start-up configuration was addressed with the addition of a run-once-self destructing eem script attached to the foot of each and every deployed configuration.

Cisco also advised that manually deployed configurations should not include RSA keys; they are always generated by APIC-EM. Other issues raised include DHCP binding. APIC-EM forms an association using the initial DHCP supplied IP address; the bond is broken if for any reason this adrresss changes.

Since closure of the case my customer has also regained the ability to automatically upgrade IOS during the deployment.

I consider that this discussion can now be closed.

Failed health check since device is stuck in non-terminal state PROVISIONING_CONFIG for more than threshold time!!