Test case details
Test name:
OfficeDevPnP.Core.Tests.Framework.Functional.CustomActionTests.SiteCollectionCustomActionAddingTest
Outcome:
Run at:
5/14/2019 7:44:15 PM
Duration:
00:00:01
Error message:
Assert.IsTrue failed.
Stacktrace:
at at OfficeDevPnP.Core.Tests.Framework.Functional.Implementation.CustomActionImplementation.SiteCollectionCustomActionAdding(String url) in c:\pnpbuild\Core\OfficeDevPnP.Core.Tests\Framework\Functional\Implementation\CustomActionImplementation.cs:line 20 at OfficeDevPnP.Core.Tests.Framework.Functional.CustomActionTests.SiteCollectionCustomActionAddingTest() in c:\pnpbuild\Core\OfficeDevPnP.Core.Tests\Framework\Functional\CustomActionTests.cs:line 41
Console output:
    Applying template - 1/2 - Initializing engine
Applying template - 2/2 - Custom Actions
Getting template - 1/1 - Custom Actions
Custom Action validation started...
CA_3 is not matching
CA_1 is not matching
CA_2 is not matching
CA_3 is not matching
CA_1 is not matching
CA_3 is not matching
CA_1 is not matching
CA_2 is not matching
Site Custom Actions validation False
Web Custom  Actions validation True



Debug Trace:
vstest.console.exe Information: 0 : 2019-05-14 19:44:15.9305	[OfficeDevPnP.Core]	[0]	[Debug]	AuthenticationManager:EnsureToken(siteUrl:https://portal2016.pnp.com/sites/tenantadmin,realm:d8623c9e-30c7-473a-83bc-d907df44a26e,appId:9ff790d6-1175-4abc-9891-8ed32d12b06a,appSecret:PRIVATE)	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:44:16.0243	[OfficeDevPnP.Core]	[0]	[Debug]	Lease expiration date: 5/15/2019 3:44:15 AM	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:44:16.0243	[OfficeDevPnP.Core]	[0]	[Debug]	Site search ''	0ms	
vstest.console.exe Error: 0 : 2019-05-14 19:44:16.0868	[OfficeDevPnP.Core]	[0]	[Error]	Site search error. Error = Search has encountered a problem that prevents results from being returned.  If the issue persists, please contact your administrator.	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:44:16.1023	[OfficeDevPnP.Core]	[0]	[Debug]	AuthenticationManager:EnsureToken(siteUrl:https://portal2016.pnp.com/sites/pnptest,realm:d8623c9e-30c7-473a-83bc-d907df44a26e,appId:9ff790d6-1175-4abc-9891-8ed32d12b06a,appSecret:PRIVATE)	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:44:16.1961	[OfficeDevPnP.Core]	[0]	[Debug]	Lease expiration date: 5/15/2019 3:44:16 AM	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:44:58.2280	[OfficeDevPnP.Core]	[0]	[Information]	Creating web 'sub' with template ''.	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.6344	[OfficeDevPnP.Core]	[0]	[Debug]	AuthenticationManager:EnsureToken(siteUrl:https://portal2016.pnp.com/sites/TestPnPSC_12345_ae31fe60-dc04-4a01-8f64-1de8b12acd0c,realm:d8623c9e-30c7-473a-83bc-d907df44a26e,appId:9ff790d6-1175-4abc-9891-8ed32d12b06a,appSecret:PRIVATE)	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.7282	[OfficeDevPnP.Core]	[0]	[Debug]	Lease expiration date: 5/15/2019 3:45:03 AM	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.8532	[OfficeDevPnP.Core]	[0]	[Information]	File customaction_add.xml retrieved from folder Templates	0ms	
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9157	[Provisioning]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9157	[Provisioning]	[431]	[Information]	ProgressDelegate registered	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9469	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9469	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope ended	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9469	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9469	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope ended	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:03.9469	[Custom Actions]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.0563	[Custom Actions]	[431]	[Debug]	Adding custom action 'CA_1' to scope Site	114ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.1344	[Custom Actions]	[431]	[Debug]	Adding custom action 'CA_2' to scope Site	193ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.2438	[Custom Actions]	[431]	[Debug]	Adding custom action 'CA_3' to scope Site	299ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.3375	[Custom Actions]	[431]	[Debug]	Adding custom action 'CA_4' to scope Web	397ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.4313	[Custom Actions]	[431]	[Debug]	Code execution scope ended	482ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.4313	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.4313	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope ended	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.4313	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.4313	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope ended	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.4313	[Persist Template Info]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.5564	[Persist Template Info]	[431]	[Debug]	Code execution scope ended	135ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.5564	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.5564	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope ended	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.5719	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope started	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.5719	[ProvisioningTemplate WebHook Call]	[431]	[Debug]	Code execution scope ended	0ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.5719	[Provisioning]	[431]	[Debug]	Code execution scope ended	666ms	e2055367-8031-4208-a4d1-1f1133f62f49
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.8219	[Extraction]	[431]	[Debug]	Code execution scope started	0ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.8219	[Extraction]	[431]	[Debug]	Base template available: STS0template	0ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.8219	[Extraction]	[431]	[Debug]	ProgressDelegate registered	0ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.8532	[Custom Actions]	[431]	[Debug]	Code execution scope started	0ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9319	[Custom Actions]	[431]	[Debug]	Adding web scoped custom action 'CA_4' to template	76ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9319	[Custom Actions]	[431]	[Debug]	Adding site scoped custom action 'CA_3' to template	77ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9319	[Custom Actions]	[431]	[Debug]	Adding site scoped custom action 'CA_1' to template	77ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9319	[Custom Actions]	[431]	[Debug]	Adding site scoped custom action 'CA_2' to template	77ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9319	[Custom Actions]	[431]	[Debug]	Code execution scope ended	77ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9319	[Retrieve Template Info]	[431]	[Debug]	Code execution scope started	0ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9938	[Retrieve Template Info]	[431]	[Debug]	Code execution scope ended	58ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a
vstest.console.exe Information: 0 : 2019-05-14 19:45:04.9938	[Extraction]	[431]	[Debug]	Code execution scope ended	170ms	df6adf2e-c8de-4a48-95b2-9670f0920d7a