Deploy issue on local after first install

[FransdeJong]

We have a very weird issue that we think we have pinpointed right now,

When we pull the solution from dev and run it it will deploy automatically and all is fine.
After the first deploy every deploy fails with this message:

EXCEPTION:

Umbraco.Deploy.Exceptions.ProcessArtifactException: Process pass #2 failed for artifact umb://vendr-tax-class/0f3bc18d954f46cebc14017d9591e84c.
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessArtifacts(IEnumerable`1 arts, IDeployContext context, CancellationToken token)
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessPackageAsync(Guid sessionId, Package package, CancellationToken token)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<Proceed>d__17.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<ExecuteAsyncSub>d__16.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<ExecuteAsync>d__15.MoveNext()

INNER:
	System.NullReferenceException: Object reference not set to an instance of an object.
	   at Vendr.Common.Events.EventBus.Dispatch[T](T evt)
	   at Vendr.Core.Models.AggregateBase`3.Validate(IValidationEvent validationEvent)
	   at Vendr.Core.Models.TaxClass.SetDefaultTaxRate(TaxRate taxRate)
	   at Vendr.Deploy.Connectors.ServiceConnectors.VendrTaxClassServiceConnector.Pass2(ArtifactDeployState`2 state, IDeployContext context)
	   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessArtifacts(IEnumerable`1 arts, IDeployContext context, CancellationToken token)

EXCEPTION:

Umbraco.Deploy.Exceptions.ProcessArtifactException: Process pass #2 failed for artifact umb://vendr-tax-class/0f3bc18d954f46cebc14017d9591e84c.
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessArtifacts(IEnumerable`1 arts, IDeployContext context, CancellationToken token)
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessPackageAsync(Guid sessionId, Package package, CancellationToken token)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<Proceed>d__17.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<ExecuteAsyncSub>d__16.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<ExecuteAsync>d__15.MoveNext()

INNER:
	System.NullReferenceException: Object reference not set to an instance of an object.
	   at Vendr.Common.Events.EventBus.Dispatch[T](T evt)
	   at Vendr.Core.Models.AggregateBase`3.Validate(IValidationEvent validationEvent)
	   at Vendr.Core.Models.TaxClass.SetDefaultTaxRate(TaxRate taxRate)
	   at Vendr.Deploy.Connectors.ServiceConnectors.VendrTaxClassServiceConnector.Pass2(ArtifactDeployState`2 state, IDeployContext context)
	   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessArtifacts(IEnumerable`1 arts, IDeployContext context, CancellationToken token)



[Failed]



EXCEPTION
Umbraco.Deploy.Exceptions.ProcessArtifactException: Process pass #2 failed for artifact umb://vendr-tax-class/0f3bc18d954f46cebc14017d9591e84c. ---> System.NullReferenceException: Object reference not set to an instance of an object.
   at Vendr.Common.Events.EventBus.Dispatch[T](T evt)
   at Vendr.Core.Models.AggregateBase`3.Validate(IValidationEvent validationEvent)
   at Vendr.Core.Models.TaxClass.SetDefaultTaxRate(TaxRate taxRate)
   at Vendr.Deploy.Connectors.ServiceConnectors.VendrTaxClassServiceConnector.Pass2(ArtifactDeployState`2 state, IDeployContext context)
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessArtifacts(IEnumerable`1 arts, IDeployContext context, CancellationToken token)
   --- End of inner exception stack trace ---
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessArtifacts(IEnumerable`1 arts, IDeployContext context, CancellationToken token)
   at Umbraco.Deploy.Environments.CurrentEnvironment.ProcessPackageAsync(Guid sessionId, Package package, CancellationToken token)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<Proceed>d__17.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<ExecuteAsyncSub>d__16.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Umbraco.Deploy.Work.WorkItems.DiskReadWorkItem.<ExecuteAsync>d__15.MoveNext()

The Uda looks like this:

{
  "DefaultTaxRate": 0.200,
  "CountryRegionTaxRates": [
    {
      "CountryUdi": "umb://vendr-country/e0f7abe09dce45de8ee8017d95962456",
      "RegionUdi": null,
      "TaxRate": 0.200
    }
  ],
  "SortOrder": 0,
  "StoreUdi": "umb://vendr-store/2136de63a3604528a23e017d9591e753",
  "Udi": "umb://vendr-tax-class/0f3bc18d954f46cebc14017d9591e84c",
  "Dependencies": [
    {
      "Udi": "umb://vendr-country/e0f7abe09dce45de8ee8017d95962456",
      "Ordering": false,
      "Mode": 0
    },
    {
      "Udi": "umb://vendr-store/2136de63a3604528a23e017d9591e753",
      "Ordering": false,
      "Mode": 0
    }
  ],
  "Name": "Standard",
  "Alias": "standard",
  "__type": "Vendr.Deploy,Vendr.Deploy.Artifacts.TaxClassArtifact",
  "__version": "4.1.4"
}

On dev all is good and the files are exactly the same.

We tried to debug the error but it was hard to find the real issue since we don't know what happens in Vendr.Core

Please let me know how we can provide you with more information so we can find out where this issue originates.

[mattbrailsford]

Hmmm, I'm kind of surprised that this is coming from the EventBus.Dispatch as I really can't think what would be null there.

I have seen some Deploy's fail because not all the schemas had been written to disk and so when it attempts to restore one of the dependencies is missing that it's expecting not to. This can usually be fixed by reexporting schemas using the Deploy dashboard in the settings section, but I'm not entirely sure that's your issue here.

For something to be null in the EventBus class though I can only think that some dependency hasn't been registered in the DI container, but I don't see why it would locally, but not remotely 🤔

[FransdeJong]

To make it more interesting. If we do a echo > deploy-export and after that do a echo > deploy we get a error. This shouldn't be possible since we shouldn't have any changes

[mattbrailsford]

So if you deploy changes from dev locally, the first attempt will work, but the next time you restore locally, it will fail with this error?

[mattbrailsford]

PS I'm assuming this is Vendr v2 and Umbraco v9 right?

[FransdeJong]

A little more information:

It's Vendr 2.0.4 on Umbraco 8.17.1
I deleted the project and started over.

When I cloned the solution from dev and started it for the first time it did a deploy-locally-initialize as expected.
That ended in deploy-complete and my Vendr settings look the same as the settings on dev.
If I do a echo > deploy directly after that it fails with the null exception.

In between the 2 deploys I didn't touch anything.

[FransdeJong]

The same issue is happening on my collueges PC's by the way

[mattbrailsford]

Ok, so yea, that is really weird.

I'm really struggling to believe it's the EventBus that has the problem as before SetDefaultTaxRate is called, SetName is called which also raises a validation event so can't understand why that wouldn't be the one to error.

Does the project contain any sensitive information? as if not, I'm tempted to ask if I could be added to the cloud project to pull it locally and see if it does the same for me 🤔

[FransdeJong]

What email address do you want me to add?

[mattbrailsford]

[email protected]

[FransdeJong]

The dev env is the environment with vendr installed

[mattbrailsford]

Ok great, I've managed to replicate the issue so I'll have a dig into things and see what's going on

[FransdeJong]

That's greatish news.
If we can assist in anything please let me know!

[mattbrailsford]

Ok, so I can see what is null, but I need to figure out why.

I believe it might be because the initial restore is done in the web context, where as the other restores are happening in a background task. For some reason, a static variable we rely on being hooked up isn't in the background thread (which is weird, because it used to work this way before).

I'll need to dig into this further tomorrow.

[FransdeJong]

Thanks Matt, it's always a great start to find out what's happening.

[mattbrailsford]

So I've managed to slightly fix it, but not entirely.

I was caching some items in Lazy properties and one of these was getting a null value and so it remembered the null value and errored on every deploy. But I have now at least fixed it so that it doesn't remember this and triggering a deploy from the back office does then succeed.

But there is still another side to this problem that I'll investigate further. It appears that on a fresh boot (touch web.config) the Umbraco deploy is occurring before Vendr's IComponent is executed and there is some code in that component that is needed to hook some static vars up, but because Umbraco Deploy is firing first, these aren't set and so this causes is the cause of the null value (this was what was being cahed in the lazy vars).

I'll dig deeper tomorrow.

UPDATE I've also pinged HQ to see if this is expected behaviour (Deploy triggering before IComponents have executed)

[mattbrailsford]

So I think I'm going to need to wait for some input from HQ on this one as it does indeed look like Umbraco Deploy is triggering before the Vendr component is done registering. From what I can tell in DotPeek it looks like it's the Deploy component that triggers a deploy in it's initialize method which I thin runs before Vendr's due to it being registered first. I'll need to get some input from HQ as to how we work around that.

I can look to release a nightly build of the current interim fix which should mean that even if the first attempt fails, subsequent attempts should succeed once the Vendr component had initialized.

[FransdeJong]

If we could have a temporary fix that would be a great solution.
And thanks for the great effort ofcourse!!

[mattbrailsford]

There should be a new 2.0.5-beta build on our nightly feed shortly 👍 https://nuget.outfield.digital/unstable/vendr/v3/index.json

As mentioned above, deploy attempts after an app restart will still fail, but you can re-trigger a deploy from the back office which will succeed.

[mattbrailsford]

I've raised an Umbraco deploy issue here umbraco/Umbraco.Deploy.Issues#91

[FransdeJong]

Thanks Matt,

One question for now. What package do I need to update? Only the core? Or the complete Vendr package? I assume this fix is in Vendr 2.0.5-beta0004?

[mattbrailsford]

@FransdeJong sorry, it' the main Vendr package yes, so Vendr 2.0.5-beta004 as you mentioned👍

[mattbrailsford]

Looks like HQ agrees there is a problem with Deploy running too early. They are testing a PR as we speak so fingers crossed this should get resolved soon 🤞

[MichaelNielsenDK]

I would just like to add, that I'm seeing this everytime a data extraction should run, so also when creating a new environment and even when pushing changes from local to cloud.

[mattbrailsford]

@MichaelNielsenDK even when running the Vendr 2.0.5 beta mentioned above?

[mattbrailsford]

PS I believe the extraction will fail for any deploy that causes and app-restart so I think that covers what you are seeing. The only ones that will succeed currently are ones triggered via the back office of an already running site.

From what I can tell in the HQ issue tracker, a PR has been made and applied but I don't know when it is due for release.

[MichaelNielsenDK]

@mattbrailsford I haven't tried Vendr 2.0.5-beta004

And yes, my addition was just to make it clearer for anyone else, that you'll probably see this with any deployment.

I can see that it should be fixed in the Umbraco Deploy upgrade coming out tomorrow
umbraco/Umbraco.Deploy.Issues#91
so I'll just wait for that, and if that does not fix it, I'll try the 2.0.5-beta

[mattbrailsford]

Gotcha! Do let me know if the issue is still present after the Deploy update 👍

[MichaelNielsenDK]

I've upgraded Umbraco.Deploy to 9.2.0 and Vendr to 2.0.5-beta0007, but I'm still having the same issue as described in #11.

[mattbrailsford]

@MichaelNielsenDK is this only after an app pool recycle? Or do you get this error when triggering a deploy from the deploy dashboard in settings also?

[MichaelNielsenDK]

@mattbrailsford Running data extraction from backend was successful, so it would suggest that the issue is when the app pool recycles.

[mattbrailsford]

Hmm, then it really make me think it's a similar kind of issue. I've commented back on the Umbraco Deploy issue with some more info that may be relevant to Andy so hopefully this might lead somewhere.

[mattbrailsford]

Ok, so a recommendation in the HQ issue is for us to switch from using a IStartupFilter to an IComponent for some things we are doing which I've now done and there is a new 2.0.5 beta on the unstable feed.

It's not entirely clear to me whether this should just straight up fix the issue or if it's just part of the solution. If anyone wants to test this on their install though, it would be greatly appreciated.

[MichaelNielsenDK]

@mattbrailsford

The issue I had is gone after installing 2.0.5-beta0010 👍