Aspnetcore: Deploying ASP.NET Core from git with kudu fails because of locked pdb file

[leecow]

Moved from https://github.com/dotnet/core/issues/1721 - opened by @ellern. PTAL @pakrym. cc @muratg

---

I got a couple of web apps running .NET Core 2.1.0 on different Azure service plans running on Windows.

Lately I've started getting a file locked error when deploying from git on Azure. Almost every single time I push, it errors out telling me the file (Site.Views.pdb) is in use. Restart app, redeploy works every time, but it's annoying. I found out if I push two changes within a short timespan then there is no lock on the pdb file and the deployment works as expected.

Remote debugging is disabled for the web apps, so I have no idea why there is a lock on the pdb file.

I can't remember having any issues before I updated my web apps to .NET Core 2.0.0

KuduSync.NET from: 'D:\local\Temp\8d5d80c09bb9d1c' to: 'D:\home\site\wwwroot'
Error: Failed to change file that is currently being used "D:\home\site\wwwroot\Site.Web.Views.pdb"
Copying file: 'Site.Web.deps.json'
Copying file: 'Site.Web.runtimeconfig.json'
Copying file: 'Site.Web.Views.dll'
Copying file: 'Site.Web.Views.pdb'
Failed exitCode=1, command="kudusync" -v 50 -f "D:\local\Temp\8d5d80c09bb9d1c" -t "D:\home\site\wwwroot" -n "D:\home\site\deployments\c764c8a77ef871df3f13953049f5bc51088cac1f\manifest" -p "D:\home\site\deployments\bd8a3c2f17acba1e45b1c14276d9530f24e5a649\manifest" -i ".git;.hg;.deployment;deploy.cmd"
An error has occurred during web site deployment.
Error: Failed to change file that is currently being used "D:\home\site\wwwroot\Site.Web.Views.pdb"\r\nD:\Program Files (x86)\SiteExtensions\Kudu\74.10611.3437\bin\Scripts\starter.cmd "D:\home\site\deployments\tools\deploy.cmd"

This issue is copied from projectkudu/kudu#2788

[olsh]

The same issue.

Here is the deployment log:

[
{
    "log_time": "2018-06-26T22:26:33.317431Z",
    "id": "",
    "message": "Command: \"D:\\home\\site\\deployments\\tools\\deploy.cmd\"",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:34.3799913Z",
    "id": "",
    "message": "Handling Basic Web Site deployment.",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7237958Z",
    "id": "",
    "message": "Cannot removed the 'to be deleted' directory, ignoring",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7237958Z",
    "id": "",
    "message": "Error: Failed to change file that is currently being used \"D:\\home\\site\\wwwroot\\CurlToCSharp.pdb\"",
    "type": 1,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7237958Z",
    "id": "",
    "message": "KuduSync.NET from: 'D:\\local\\Temp\\zipdeploy\\extracted' to: 'D:\\home\\site\\wwwroot'",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7394195Z",
    "id": "",
    "message": "Copying file: 'appsettings.Development.json'",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7550254Z",
    "id": "",
    "message": "Copying file: 'appsettings.json'",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7550254Z",
    "id": "",
    "message": "Copying file: 'CurlToCSharp.deps.json'",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.770675Z",
    "id": "",
    "message": "Copying file: 'CurlToCSharp.dll'",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7862697Z",
    "id": "",
    "message": "Copying file: 'CurlToCSharp.pdb'",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.7862697Z",
    "id": "",
    "message": "Failed exitCode=1, command=\"kudusync\" -v 50  -f \"D:\\local\\Temp\\zipdeploy\\extracted\" -t \"D:\\home\\site\\wwwroot\" -n \"D:\\home\\site\\deployments\\010d093fca7b44479e9d0eac2b3c723d\\manifest\" -p \"D:\\home\\site\\deployments\\ba4b36117f9942d1b1813f5b7dc9c32b\\manifest\" -i \".git;.hg;.deployment;deploy.cmd\"",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.8018911Z",
    "id": "",
    "message": "An error has occurred during web site deployment.",
    "type": 0,
    "details_url": null
},
{
    "log_time": "2018-06-26T22:26:35.8175451Z",
    "id": "",
    "message": "Error: Failed to change file that is currently being used \"D:\\home\\site\\wwwroot\\CurlToCSharp.pdb\"\\r\\nD:\\Program Files (x86)\\SiteExtensions\\Kudu\\74.10620.3448\\bin\\Scripts\\starter.cmd \"D:\\home\\site\\deployments\\tools\\deploy.cmd\"",
    "type": 2,
    "details_url": null
}]

[muratg]

cc @Petermarcu @rynowak @richlander

[olsh]

Forgot to mention, I'm using this method for the deployments.
https://www.appveyor.com/docs/deployment/azure-app-service-zip-push-deploy/

Here is the repo with appveyor.yml
https://github.com/olsh/curl-to-csharp

[hajekj]

I am hitting the same issue with Git deploy. Currently tracked here https://github.com/projectkudu/kudu/issues/2788. The App Service is currently in the broken state, so if any of you want to try to do some debugging on it, feel free. If you need credentials or something to access the App Service, just ping me ([email protected]).

[Eilon]

Is it possible to run some tool to see what is locking the PDB file?

[mjyeaney]

All - having same issues with Functions running on .NET Core 2.1.302. Any updates on what is locking the files?

As a workaround, I've changed the release scripts to stop shipping PDB's, but this doesn't help dev deploys.

[ellern]

I've just noticed that one of the web apps that troubles me the most is having a Application Insights service attached - don't know if this has anything to do with it.

[dv00d00]

Same issue. Asp.Net Core 2.1 + Microsoft.ApplicationInsights.AspNetCore 2.4.1

[severisv]

Any news on this? Is it best to revert to good ol' WebDeploy?

[aykay76]

+1, trying out Azure Function App deployment from Visual Studio Code and getting the same error:

Error: Failed to change file that is currently being used "D:homesitewwwrootbinazure-functions.dll"

I concur with Ellen and dv00d00 - I deleted App Insights, restarted and can now deploy without issues.

[muratg]

Adding @SergeyKanzhelev here. Sergey, any thoughts on this?

[rynowak]

I believe we had an email thread about this. The .NET runtime will load/lock the PDB when an exception is thrown (and the call stack evaluated).

[SergeyKanzhelev]

Anybody, who has a repro - follow up on Application Insights suspicion. Is Application Insights extension is installed on web app or Application Insights SDK in the deployed app?

[mortenmg]

I had this problem today after updating my app to .NETCore 2.1.4 (from 2.0.3)
Removing Application Insights from my App Service and restarting the service fixed the problem.

Note that I did not try to restart it before removing Application Insights (my AI setup was broken anyways), so a simple restart may have fixed the problem without removing Application Insights, but I can't confirm this.

[severisv]

@SergeyKanzhelev Yes, App Insights SDK in my case

[SergeyKanzhelev]

@severisv so no App Insights extension there?

Than it seems like an issue with exception stack traces calculations. which @rynowak mentioned

[severisv]

That's right, no AppInsights extension there :)

[erikbra]

We're experiencing the same problem here... ASP.NET Core 2.1. We're pushing to the site using git. No custom deploy.cmd script, but it seems like the standard deploy.cmd is putting an app_offline.htm file there, however, something is still locking the PDB:

2018-11-01T12:29:51.8546477Z,Updating branch 'master'.,cfb14059-486a-480e-b68b-a056e35b5131,0
2018-11-01T12:29:55.5734310Z,Updating submodules.,5f3b6c05-f55e-4210-ac90-4ff2002484fd,0
2018-11-01T12:29:55.6359017Z,Preparing deployment for commit id '043f87ea5f'.,169a2a4e-11a6-4780-852a-ffddb566b1ca,0
2018-11-01T12:29:55.9952781Z,Generating deployment script.,aaf73c8a-b872-41f5-8460-f8c4d94a1bf8,0
    2018-11-01T12:29:56.0421521Z,Using cached version of deployment script (command: 'azure -y --no-dot-deployment -r "D:\home\site\repository" -o "D:\home\site\deployments\tools" --basic --sitePath "D:\home\site\repository"').,,0
2018-11-01T12:29:56.1046810Z,Running deployment command...,b0c63d75-e1a1-41ac-9523-85564d367572,0
    2018-11-01T12:29:56.1202853Z,Command: "D:\home\site\deployments\tools\deploy.cmd",,0
    2018-11-01T12:29:57.0109319Z,Handling Basic Web Site deployment.,,0
    2018-11-01T12:30:02.2609728Z,Creating app_offline.htm,,0
    2018-11-01T12:30:02.2609728Z,Error: Failed to change file that is currently being used "D:\home\site\wwwroot\MyApp.pdb",,1
    2018-11-01T12:30:02.2765211Z,Cannot removed the 'to be deleted' directory, ignoring,,0
    2018-11-01T12:30:02.2765211Z,KuduSync.NET from: 'D:\home\site\repository' to: 'D:\home\site\wwwroot',,0
    2018-11-01T12:30:02.2921499Z,Copying file: 'MyApp.dll',,0
    2018-11-01T12:30:02.3077806Z,Copying file: 'MyApp.pdb',,0
    2018-11-01T12:30:02.3258034Z,Failed exitCode=1, command="kudusync" -v 50  -f "D:\home\site\repository" -t "D:\home\site\wwwroot" -n "D:\home\site\deployments\043f87ea5f9afcbc4b380bb93e718cdaa172ced5\manifest" -p "D:\home\site\deployments\db5371a2c2b14fbe552e90023a26032769dec7d0\manifest" -i ".git;.hg;.deployment;deploy.cmd",,0
    2018-11-01T12:30:02.3258034Z,An error has occurred during web site deployment.,,0
    2018-11-01T12:30:02.3546532Z,Error: Failed to change file that is currently being used "D:\home\site\wwwroot\MyApp.pdb"\r\nD:\Program Files (x86)\SiteExtensions\Kudu\78.11022.3613\bin\Scripts\starter.cmd "D:\home\site\deployments\tools\deploy.cmd",,2

It happens occasionally on some of our sites, but not all. Is there anything I can do to help troubleshoot the issue? Is it a Kudu issue or a .net core issue or an Azure WebSite issue?

[muratg]

@erikbra do you have App Insights extension or SDK installed on your site? We've seen people hitting this issue with that (but not everyone.)

In your case (deploying with kudu/git), you're building on the server which is an Azure App Service VM so it may possibly be related to that. (Perhaps runtime holding onto the PDBs to keep the stack trace.)

[erikbra]

We don't have application insights installed on those instances. We're running into so much issues with that, so we skipped it.

Actually, we're only deploying binaries with git, not the source code itself. It is first built on the build server, and the pushed to the Azure site with git. That part is OK. It's the deployment with Kudu, from the deployment folder to the wwwroot that is the problem.

[muratg]

@erikbra Thanks for the information! Does your app have Razor views? (is there any runtime compilation?)

[erikbra]

No, they are REST APIs.

[muratg]

Thanks!

@pakrym, @davidfowl any thoughts on @erikbra's case? I'm a bit out of ideas at this point.

[shirhatti]

@erikbra I'm not terribly familiar with the deploy.cmd script used, but taking a look at the timestamps in your logs, it just looks like you haven't given the application sufficient time to shutdown and ergo the files are locked.

The default shutdown timelimit is 10 seconds, so I would recommend introducing a retry loop in your deploy script for at least as long as the shutdown time limit

[erikbra]

I haven't created a deploy.cmd myself. This is just what comes out-of-the-box if you don't create one yourself, @shirhatti. It's the standard deploy.cmd for kudu.

[EddyP23]

This started happening to me as well a few days ago, any ideas how to work around it? I am using ApplicationInsights and would much like to continue so.

It is very inconsistent, some deploys work, others don't

[codecadwallader]

I'm also seeing this issue fairly regularly and would love any recommendations. I suspected it was related to using a BackgroundTaskQueue pattern and there being a backlog of operations to complete.. but even as I've removed those I'm still encountering the issue with the .pdb being locked.

[EddyP23]

We have recently upgraded to 2.2 and we are still hitting this issue very often.

This is extremely troubling and a real blocker for any production application. How does this not receive much more attention?

[EddyP23]

We just moved from git push deploy to zip-deploy, but exactly the same thing keeps happening. At least this time it is less painful, as you can rerun the deploy without any git's "repo is already up to date" errors and eventually, it works. It also doesn't seem to be breaking the app that is running which is nice.

But all in all, it is extremely painful.

Therefore, it seems like this is a sign, that this is a broader issue, not only git push related.

Screenshot from the Kudu ZipDeployUI:

[JiriKovar]

We also ran into this problem.
.NET Core 2.2.105, remote debugging disabled, no custom deploy.cmd -> failure rate 95%+ on a simple service that isn't even used yet.

And please let me express my astonishment at the state of this issue. 9 months+ old, no one assigned, no milestone, no one responsible is even trying to be helpful and the only workaround is to stop the service before deployment, start it afterwards and hope it manages to finish in time. That's something I remember doing cca 7+ years ago on Azure Web Roles back when they were still young. Ahh, never gets old...

EDIT: we have actually decided to "downgrade" to .NET 4.7.2 because using KUDU Zip Deploy over WebDeploy actually brings us more value than compiling to .NET Core 2.2 over .NET 4.7.2. This was my 4th try to actually use .NET Core. Needless to say, that it has also been my 4th disappointment.

[davidfowl]

Is anyone here using app insights?

[MasodSaidi]

Yes

30 apr. 2019 kl. 19:57 skrev David Fowler [e-mail]:

Is anyone here using app insights?

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub, or mute the thread.

[henrihietala]

I'm having the same issue in Azure DevOps release pipeline while deploying a Function App.

2019-05-17T05:52:32.9082281Z Error: Failed to change file that is currently being used "D:\home\site\wwwroot\bin\MyFunctionApp.pdb"\r\nD:\Program Files (x86)\SiteExtensions\Kudu\81.10329.3844\bin\Scripts\starter.cmd "D:\home\site\deployments\tools\deploy.cmd" 2019-05-17T05:52:32.9136091Z ##[error]Failed to deploy web package to App Service. 2019-05-17T05:52:32.9145167Z ##[error]Error: Package deployment using ZIP Deploy failed. Refer logs for more details.

The previous task is stopping of my Function App but apparently it doesn't help here.

[JontyMC]

We have the same issue deploy function apps

[JontyMC]

The Kudu deployment logs also have a strange situation here:

{
    ....
    "last_success_end_time": null,
    "complete": true,
    ....
}

Not exactly sure what "last_success_end_time" means, bit of an odd name, but seems logically to assume that "complete" should not be true if "last_success_end_time" is null.

[steveglen]

I'm hitting this problem regularly, self-hosting on IIS and using kudu to deploy (git push). My "workaround" is to log onto the IIS server, find the relevant Application Pool and recycle it just before trying to deploy again. Most of the time this works.

This is only a problem with .net core (2.2) - it doesn't happen at all with full framework applications on the same server.

The failure is always trying to deploy one of my own .pdb files: Error: Failed to change file that is currently being used

I guess the relevant question is: why is something locking the .pdb file? If it needs to open the .pdb can't it get what it needs then close it again?! Or better still open in a way that doesn't lock the existing file on disk?

[davidfowl]

@steveglen you're seeing PDB locking on your local IIS? Can you reproduce that behavior on demand?

[steveglen]

@davidfowl not 100% of the time, more like 50% chance of hitting it on any given deploy attempt. When it's hit deployments consistently fail until I recycle the IIS app pool.

I'm running on Windows Server 2016, Kudu from git but I last updated 31st May 2018 so it's not up to date. I've seen no suggestion this issue is improved in newer Kudu - please let me know if this is something that is expected to improve with newer code.

[davidfowl]

OK I think I've identified the PDB locking issue. Stay tuned...

[davidfowl]

We've identified the issue and are looking at backporting the fix to older versions of .NET Core (possibly 2.1 and 2.2). More information here https://github.com/dotnet/corefx/issues/38212

[MGudgin]

@davidfowl We're running into this issue when deploying Azure Functions apps as they use .NET Core 2.2. How can I track the progress/status of this fix being backported to 2.2?

[davidfowl]

@MGudgin I opened a PR for the backport here https://github.com/dotnet/corefx/pull/38291

[anurse]

@davidfowl is there ASP.NET Core work here or is the change localized to corefx? I'd like to get this off our dispatch queue :).

[davidfowl]

@anurse It's all on corefx and it's in the pipeline for consideration for the 2.2 patch.

[anurse]

Cool, closing this now then. For the others on this thread, you can track the backport in the issue linked above (https://github.com/dotnet/corefx/pull/38291) and if you're still having a problem after that patch is deployed, feel free to file something new!