Initial clone operation can incorrectly look for repo in site\repository folder

[davidebbo]

For the initial clone scenario, the repo goes in site\wwwroot. Yet in one case, we saw the git-upload-pack request look for it in site\repository, and fail.

Here is the trace (slightly trimmed for brevity):

  <step title="Incoming Request" date="04/24 4:53:49" url="/mattharrnodejsempty.git/info/refs?service=git-upload-pack" method="GET" type="request" instance="558ba1" pid="2160,2,6" Connection="Keep-Alive" Pragma="no-cache" Accept="*/*" Accept-Encoding="gzip" Host="mattharrnodejsempty.scm.azurewebsites.net" User-Agent="git/1.9.0.msysgit.0" X-SITE-DEPLOYMENT-ID="mattharrnodejsempty" X-MS-CLIENT-PRINCIPAL-NAME="mattharr" elapsed="3008">
    <step title="InfoRefsService.Execute" date="04/24 4:53:49" elapsed="2308">
      <step title="InfoRefsService.SmartInfoRefs" date="04/24 4:53:49" elapsed="2296">
        <step title="GitExeRepository.Initialize" date="04/24 4:53:49" elapsed="1588">
          <step title="Executing external process" date="04/24 4:53:50" type="process" path="git.exe" arguments="init" elapsed="592" />
        </step>
        <step title="Executing external process" date="04/24 4:53:51" type="process" path="git.exe" arguments="add -A" elapsed="290" />
        <step title="Executing external process" date="04/24 4:53:51" type="process" path="git.exe" arguments="commit -m &quot;Initial Commit&quot;" elapsed="219" />
        <step title="Executing external process" date="04/24 4:53:51" type="process" path="git.exe" arguments="rev-parse --git-dir" elapsed="51" />
        <step title="Assuming git repository at D:\home\site\wwwroot" date="04/24 4:53:51" elapsed="0" />
        <step title="GitExeServer.AdvertiseUploadPack" date="04/24 4:53:51" elapsed="90">
          <step title="Executing external process" date="04/24 4:53:51" type="process" path="git.exe" arguments="upload-pack --stateless-rpc --advertise-refs &quot;D:\home\site\wwwroot&quot;" elapsed="88" />
        </step>
        <step title="Writing 290 bytes" date="04/24 4:53:52" elapsed="0" />
      </step>
    </step>
    <step title="Outgoing response" date="04/24 4:53:52" type="response" statusCode="200" statusText="OK" Server="Microsoft-IIS/8.0" Pragma="no-cache" Cache-Control="must-revalidate, no-cache, max-age=0" Expires="Tue, 01 Jan 1980 00:00:00 GMT" Content-Length="290" X-AspNet-Version="4.0.30319" Content-Type="application/x-git-upload-pack-advertisement" elapsed="0" />
  </step>
  <step title="Incoming Request" date="04/24 4:53:52" url="/mattharrnodejsempty.git/git-upload-pack" method="POST" type="request" instance="7cdd22" pid="3280,2,9" Connection="Keep-Alive" Content-Length="200" Content-Type="application/x-git-upload-pack-request" Accept="application/x-git-upload-pack-result" Accept-Encoding="gzip" Host="mattharrnodejsempty.scm.azurewebsites.net" User-Agent="git/1.9.0.msysgit.0" X-SITE-DEPLOYMENT-ID="mattharrnodejsempty" X-MS-CLIENT-PRINCIPAL-NAME="mattharr" elapsed="408">
    <step title="RpcService.UploadPackHandler" date="04/24 4:53:52" elapsed="224">
      <step title="GitExeServer.Upload" date="04/24 4:53:52" elapsed="221">
        <step title="Executing external process" date="04/24 4:53:52" type="process" path="git.exe" arguments="upload-pack --stateless-rpc &quot;D:\home\site\repository&quot;" elapsed="187">
          <step title="Process dump" date="04/24 4:53:52" exitCode="128" type="processOutput" elapsed="0" />
        </step>
      </step>
    </step>
    <step title="Error occurred" date="04/24 4:53:53" type="error" text="fatal: 'D:\home\site\repository' does not appear to be a git repository&#xA;&#xD;&#xA;D:\Program Files (x86)\Git\bin\git.exe upload-pack --stateless-rpc &quot;D:\home\site\repository&quot;" stackTrace="   at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, Stream input, Stream output, String arguments, Object[] args)&#xD;&#xA;   at Kudu.Core.SourceControl.Git.GitExeServer.ServiceRpc(ITracer tracer, String serviceName, Stream input, Stream output)&#xD;&#xA;   at Kudu.Core.SourceControl.Git.GitExeServer.Upload(Stream inputStream, Stream outputStream)&#xD;&#xA;   at Kudu.Services.GitServer.UploadPackHandler.ProcessRequestBase(HttpContextBase context)&#xD;&#xA;   at Kudu.Services.GitServer.GitServerHttpHandler.ProcessRequest(HttpContext context)&#xD;&#xA;   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()&#xD;&#xA;   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean&amp; completedSynchronously)" elapsed="0" />
    <step title="Outgoing response" date="04/24 4:53:53" type="response" statusCode="500" statusText="Internal Server Error" Cache-Control="private" X-AspNet-Version="4.0.30319" Content-Type="text/html; charset=utf-8" elapsed="0" />
  </step>

[suwatch]

I noticed that the info-ref request went to instance="558ba1" while the upload pack itself went to different instance="7cdd22". We suspected that it might be something to do with the UNC Share stale cache between instances. The settings.xml (telling where the repo folder is) is saved during info-ref request by one instance; however, it is read by another instance.

We will setup our environment (Kudu2) to cover this scenario.

[jvano]

Hi

Kudu will continue to run in Azure App Service. However, this repo will no longer be maintained. If the problem persists and is related to running on Azure App Service, please open a support incident in Azure: https://learn.microsoft.com/en-us/azure/azure-portal/supportability/how-to-create-azure-support-request

This way we can better track and assist you on this case

Thanks,

Joaquin Vano Azure App Service