dotnet / aspnetcore

ASP.NET Core is a cross-platform .NET framework for building modern cloud-based web applications on Windows, Mac, or Linux.
https://asp.net
MIT License
35.5k stars 10.04k forks source link

Deploying ASP.NET Core from git with kudu fails because of locked pdb file #3269

Closed leecow closed 5 years ago

leecow commented 6 years ago

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"

screen shot 2018-06-22 at 09 01 15

This issue is copied from projectkudu/kudu#2788

olsh commented 6 years ago

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 commented 6 years ago

cc @Petermarcu @rynowak @richlander

olsh commented 6 years ago

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 commented 6 years ago

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 (hajek.j@hotmail.com).

Eilon commented 6 years ago

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

mjyeaney commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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

severisv commented 6 years ago

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

aykay76 commented 6 years ago

+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:\home\site\wwwroot\bin\azure-functions.dll"

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

muratg commented 6 years ago

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

rynowak commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

@SergeyKanzhelev Yes, App Insights SDK in my case

SergeyKanzhelev commented 6 years ago

@severisv so no App Insights extension there?

image

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

severisv commented 6 years ago

That's right, no AppInsights extension there :)

erikbra commented 6 years ago

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 commented 6 years ago

@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 commented 6 years ago

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 commented 6 years ago

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

erikbra commented 6 years ago

No, they are REST APIs.

muratg commented 6 years ago

Thanks!

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

shirhatti commented 6 years ago

@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 commented 6 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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: image

JiriKovar commented 5 years ago

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 commented 5 years ago

Is anyone here using app insights?

MasodSaidi commented 5 years ago

Yes

30 apr. 2019 kl. 19:57 skrev David Fowler notifications@github.com:

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 commented 5 years ago

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 commented 5 years ago

We have the same issue deploy function apps

JontyMC commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

steveglen commented 5 years ago

@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 commented 5 years ago

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

davidfowl commented 5 years ago

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 commented 5 years ago

@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 commented 5 years ago

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

analogrelay commented 5 years ago

@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 commented 5 years ago

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

analogrelay commented 5 years ago

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!