search

projectkudu / kudu

Kudu is the engine behind git/hg deployments, WebJobs, and various other features in Azure Web Sites. It can also run outside of Azure.
Apache License 2.0
3.12k stars 652 forks source link

GitHub webhook deployments and manually triggered deployments fail with "Cannot create directory '.ssh'" #1815

Closed breiter closed 6 months ago

breiter commented 8 years ago

I'm having a problem on a new Kudu S47 with Git 2.6.3 deployment on an in-house server. Builds succeed when pushed to the http git endpoint.

Unfortunately, deployments triggered by GitHub webhook or the "Trigger Deployment" feature of the deployments tab fail with "Cannot create directory '.ssh'".

I have set up an ssh key for the application and the .ssh directory exists and contains a key and known_hosts and GitHub shows the API key having been accessed. GitHub webhook API ping works but an actual deployment trigger fails with 500.

The HOME environment variable says it is "C:\inetpub\apps\pims" in the service console for the site.

I'm at a loss to figure out why git ssh can't find the .ssh directory in c:\inetpub\apps\pims when invoked by Kudu.

Thanks in advance for your help.

cd /c/inetpub/apps/pims
$ ssh -i .ssh/id_rsa -vv git@github.com
OpenSSH_7.1p1, OpenSSL 1.0.2d 9 Jul 2015
debug1: Reading configuration data /etc/ssh/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to github.com [192.30.252.130] port 22.
debug1: Connection established.
debug1: identity file .ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file .ssh/id_rsa-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.1
debug1: Remote protocol version 2.0, remote software version libssh-0.7.0
debug1: no match: libssh-0.7.0
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to github.com:22 as 'git'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1
debug2: kex_parse_kexinit: ssh-rsa-cert-v01@openssh.com,ssh-rsa,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-dss,ssh-rsa
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc
debug2: kex_parse_kexinit: hmac-sha1,hmac-sha2-256,hmac-sha2-512
debug2: kex_parse_kexinit: hmac-sha1,hmac-sha2-256,hmac-sha2-512
debug2: kex_parse_kexinit: none,zlib,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib,zlib@openssh.com
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug1: kex: server->client chacha20-poly1305@openssh.com <implicit> none
debug1: kex: client->server chacha20-poly1305@openssh.com <implicit> none
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ssh-rsa SHA256:nThbg6kXUpJWGl7E1IGOCspRomTxdCARLviKw6E5SY8
debug1: Host 'github.com' is known and matches the RSA host key.
debug1: Found key in /c/Users/Administrator/.ssh/known_hosts:1
Warning: Permanently added the RSA host key for IP address '192.30.252.130' to the list of known hosts.
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: .ssh/id_rsa (0x60006bbc0), explicit
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering RSA public key: .ssh/id_rsa
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 279
debug2: input_userauth_pk_ok: fp SHA256:QKdOsCcWCjKhRQbNG266z4aPe3ijBR7zoJii7mkNazE
debug1: Authentication succeeded (publickey).
Authenticated to github.com ([192.30.252.130]:22).
debug1: channel 0: new [client-session]
debug2: channel 0: send open
debug1: Entering interactive session.
debug2: callback start
debug2: fd 3 setting TCP_NODELAY
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug2: channel 0: request shell confirm 1
debug2: callback done
debug2: channel 0: open confirm rwindow 32000 rmax 35000
debug2: channel_input_status_confirm: type 100 id 0
PTY allocation request failed on channel 0
debug2: channel_input_status_confirm: type 99 id 0
debug2: shell request accepted on channel 0
debug2: channel 0: rcvd ext data 102
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: rcvd close
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug2: channel 0: obuf_empty delayed efd 6/(102)
Hi WolfeReiter/msh-pims! You've successfully authenticated, but GitHub does not provide shell access.
debug2: channel 0: written 102 to efd 6
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
Connection to github.com closed.
Transferred: sent 3388, received 1804 bytes, in 0.7 seconds
Bytes per second: sent 4765.0, received 2537.2
debug1: Exit status 1
Log Name:      Application
Source:        ASP.NET 4.0.30319.0
Date:          11/25/2015 5:15:21 PM
Event ID:      1309
Task Category: Web Event
Level:         Warning
Keywords:      Classic
User:          N/A
Computer:      WIN-B93U6E5AP0S
Description:
Event code: 3005 
Event message: An unhandled exception has occurred. 
Event time: 11/25/2015 5:15:21 PM 
Event time (UTC): 11/25/2015 5:15:21 PM 
Event ID: 5bceb99971f14474ac8251f3f0e053c6 
Event sequence: 8 
Event occurrence: 1 
Event detail code: 0 

Application information: 
    Application domain: /LM/W3SVC/2/ROOT-1-130929453022812398 
    Trust level: Full 
    Application Virtual Path: / 
    Application Path: C:\inetpub\Kudu.Services.Web\ 
    Machine name: WIN-B93U6E5AP0S 

Process information: 
    Process ID: 3756 
    Process name: w3wp.exe 
    Account name: IIS APPPOOL\pims 

Exception information: 
    Exception type: CommandLineException 
    Exception message: Could not create directory '/.ssh'.
Host key verification failed.
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

C:\Program Files (x86)\Git\bin\git.exe fetch external --progress
   at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.Infrastructure.OperationManager.Attempt[T](Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry)
   at Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)
   at Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger)
   at Kudu.Services.FetchHandler.<PerformDeployment>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Services.FetchHandler.<>c__DisplayClass10_1.<<ProcessRequestAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Contracts.Infrastructure.LockExtensions.<TryLockOperationAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at Kudu.Services.FetchHandler.<ProcessRequestAsync>d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Request information: 
    Request URL: http://localhost:30075/deploy/ 
    Request path: /deploy/ 
    User host address: 127.0.0.1 
    User: WIN-B93U6E5AP0S\kudu 
    Is authenticated: True 
    Authentication Type: Basic 
    Thread account name: IIS APPPOOL\pims 

Thread information: 
    Thread ID: 8 
    Thread account name: IIS APPPOOL\pims 
    Is impersonating: False 
    Stack trace:    at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.Infrastructure.OperationManager.Attempt[T](Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry)
   at Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)
   at Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger)
   at Kudu.Services.FetchHandler.<PerformDeployment>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Services.FetchHandler.<>c__DisplayClass10_1.<<ProcessRequestAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Contracts.Infrastructure.LockExtensions.<TryLockOperationAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at Kudu.Services.FetchHandler.<ProcessRequestAsync>d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Custom event details: 

Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="ASP.NET 4.0.30319.0" />
    <EventID Qualifiers="32768">1309</EventID>
    <Level>3</Level>
    <Task>3</Task>
    <Keywords>0x80000000000000</Keywords>
    <TimeCreated SystemTime="2015-11-25T17:15:21.000000000Z" />
    <EventRecordID>13775</EventRecordID>
    <Channel>Application</Channel>
    <Computer>WIN-B93U6E5AP0S</Computer>
    <Security />
  </System>
  <EventData>
    <Data>3005</Data>
    <Data>An unhandled exception has occurred.</Data>
    <Data>11/25/2015 5:15:21 PM</Data>
    <Data>11/25/2015 5:15:21 PM</Data>
    <Data>5bceb99971f14474ac8251f3f0e053c6</Data>
    <Data>8</Data>
    <Data>1</Data>
    <Data>0</Data>
    <Data>/LM/W3SVC/2/ROOT-1-130929453022812398</Data>
    <Data>Full</Data>
    <Data>/</Data>
    <Data>C:\inetpub\Kudu.Services.Web\</Data>
    <Data>WIN-B93U6E5AP0S</Data>
    <Data>
    </Data>
    <Data>3756</Data>
    <Data>w3wp.exe</Data>
    <Data>IIS APPPOOL\pims</Data>
    <Data>CommandLineException</Data>
    <Data>Could not create directory '/.ssh'.
Host key verification failed.
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

C:\Program Files (x86)\Git\bin\git.exe fetch external --progress
   at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.Infrastructure.OperationManager.Attempt[T](Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry)
   at Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)
   at Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger)
   at Kudu.Services.FetchHandler.&lt;PerformDeployment&gt;d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Services.FetchHandler.&lt;&gt;c__DisplayClass10_1.&lt;&lt;ProcessRequestAsync&gt;b__0&gt;d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Contracts.Infrastructure.LockExtensions.&lt;TryLockOperationAsync&gt;d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at Kudu.Services.FetchHandler.&lt;ProcessRequestAsync&gt;d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean&amp; completedSynchronously)

</Data>
    <Data>http://localhost:30075/deploy/</Data>
    <Data>/deploy/</Data>
    <Data>127.0.0.1</Data>
    <Data>WIN-B93U6E5AP0S\kudu</Data>
    <Data>True</Data>
    <Data>Basic</Data>
    <Data>IIS APPPOOL\pims</Data>
    <Data>8</Data>
    <Data>IIS APPPOOL\pims</Data>
    <Data>False</Data>
    <Data>   at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.Infrastructure.OperationManager.Attempt[T](Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry)
   at Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)
   at Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger)
   at Kudu.Services.FetchHandler.&lt;PerformDeployment&gt;d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Services.FetchHandler.&lt;&gt;c__DisplayClass10_1.&lt;&lt;ProcessRequestAsync&gt;b__0&gt;d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Contracts.Infrastructure.LockExtensions.&lt;TryLockOperationAsync&gt;d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at Kudu.Services.FetchHandler.&lt;ProcessRequestAsync&gt;d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean&amp; completedSynchronously)
</Data>
  </EventData>
</Event>
suwatch commented 8 years ago

The clue is Could not create directory /.ssh.. Could you check, using iis manager, if your http://localhost:30075/ site has a vdir _app defined.

breiter commented 8 years ago

Yes. There is an _app virtual directory app in the kudu_service_pims site on 30075 that that points to C:\inetpub\apps\pims and has the pims app-pool. The site kudu_pims is on port 80 at C:\inetpub\apps\pims\site\wwwroot with the same app-pool.

suwatch commented 8 years ago

from your log above, it seems like your SSH key is in c:\Users\Administrator\.ssh folder.

Try create a dir c:\inetpub\apps\pims\.ssh and xcopy c:\Users\Administrator\.ssh to c:\inetpub\apps\pims\.ssh.

breiter commented 8 years ago

There already is a c:\inetpub\apps\pims\.ssh which contains a key pair and known_hosts. The interactive ssh session just used $HOME\.ssh of my interactive shell session in bash to find the known_hosts file for the administrator account.

suwatch commented 8 years ago

umm .. if you browse to http://localhost:30075/Env, do you see environment variable HOME? This is where SSH looks for $HOME and its .ssh.

breiter commented 8 years ago

HOME is C:\inetpub\apps\pims. And yet the behavior when a webhook triggers a build seems exactly like if $HOME were not set.

And also here is what happens if I invoke ssh -vv from cmd with HOME set to C:\inetpub\apps\pims.

Microsoft Windows [Version 6.3.9600]
(c) 2013 Microsoft Corporation. All rights reserved.

C:\Users\Administrator>set HOME=c:\inetpub\apps\pims

C:\Users\Administrator>"c:\Program Files (x86)\git\usr\bin\ssh" -vv git@github.c
om
OpenSSH_7.1p1, OpenSSL 1.0.2d 9 Jul 2015
debug1: Reading configuration data /c/inetpub/apps/pims/.ssh/config
debug1: /c/inetpub/apps/pims/.ssh/config line 1: Applying options for *
debug1: Reading configuration data /etc/ssh/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to github.com [192.30.252.129] port 22.
debug1: Connection established.
debug1: identity file /c/inetpub/apps/pims/.ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_rsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_dsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_dsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_ecdsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_ecdsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_ed25519 type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/inetpub/apps/pims/.ssh/id_ed25519-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.1
debug1: Remote protocol version 2.0, remote software version libssh-0.7.0
debug1: no match: libssh-0.7.0
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to github.com:22 as 'git'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-
sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hel
lman-group-exchange-sha1,diffie-hellman-group14-sha1
debug2: kex_parse_kexinit: ssh-rsa-cert-v01@openssh.com,ssh-rsa,ecdsa-sha2-nistp
256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nis
tp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256,
ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,a
es256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,arcfour256,arcfour128,ae
s128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndae
l-cbc@lysator.liu.se
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,a
es256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,arcfour256,arcfour128,ae
s128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndae
l-cbc@lysator.liu.se
debug2: kex_parse_kexinit: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac
-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.co
m,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
,hmac-md5-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openss
h.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-ripemd160,hmac-ripemd160@openssh
.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac
-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.co
m,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
,hmac-md5-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openss
h.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-ripemd160,hmac-ripemd160@openssh
.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,diffi
e-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-dss,ssh-rsa
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes256-ctr,aes192-ctr,a
es128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes256-ctr,aes192-ctr,a
es128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc
debug2: kex_parse_kexinit: hmac-sha1,hmac-sha2-256,hmac-sha2-512
debug2: kex_parse_kexinit: hmac-sha1,hmac-sha2-256,hmac-sha2-512
debug2: kex_parse_kexinit: none,zlib,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib,zlib@openssh.com
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug1: kex: server->client chacha20-poly1305@openssh.com <implicit> none
debug1: kex: client->server chacha20-poly1305@openssh.com <implicit> none
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ssh-rsa SHA256:nThbg6kXUpJWGl7E1IGOCspRomTxdCARLviKw6E5
SY8
debug1: Host 'github.com' is known and matches the RSA host key.
debug1: Found key in /c/inetpub/apps/pims/.ssh/known_hosts:1
Warning: Permanently added the RSA host key for IP address '192.30.252.129' to t
he list of known hosts.
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /c/inetpub/apps/pims/.ssh/id_rsa (0x60006cf80),
debug2: key: /c/inetpub/apps/pims/.ssh/id_dsa (0x0),
debug2: key: /c/inetpub/apps/pims/.ssh/id_ecdsa (0x0),
debug2: key: /c/inetpub/apps/pims/.ssh/id_ed25519 (0x0),
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering RSA public key: /c/inetpub/apps/pims/.ssh/id_rsa
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 279
debug2: input_userauth_pk_ok: fp SHA256:QKdOsCcWCjKhRQbNG266z4aPe3ijBR7zoJii7mkN
azE
debug1: Authentication succeeded (publickey).
Authenticated to github.com ([192.30.252.129]:22).
debug1: channel 0: new [client-session]
debug2: channel 0: send open
debug1: Entering interactive session.
debug2: callback start
debug2: fd 3 setting TCP_NODELAY
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug2: channel 0: request shell confirm 1
debug2: callback done
debug2: channel 0: open confirm rwindow 32000 rmax 35000
debug2: channel_input_status_confirm: type 100 id 0
PTY allocation request failed on channel 0
debug2: channel_input_status_confirm: type 99 id 0
debug2: shell request accepted on channel 0
debug2: channel 0: rcvd ext data 102
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: rcvd close
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug2: channel 0: obuf_empty delayed efd 6/(102)
Hi **********/*********! You've successfully authenticated, but GitHub does not
provide shell access.
debug2: channel 0: written 102 to efd 6
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
Connection to github.com closed.
Transferred: sent 3388, received 1804 bytes, in 0.2 seconds
Bytes per second: sent 15777.8, received 8401.2
debug1: Exit status 1

System info

AppSettings

Connection Strings

Environment variables

PATH

HTTP headers

Server variables

suwatch commented 8 years ago

Thank for being patience. If you browse to http://localhost:30075/DebugConsole , and run the same ssh command on that console, does it work? Also try set HOME, does it echo the expected HOME value?

When you did POST /deploy and ran into error, could you share the kudu log content? The log will be C:\inetpub\apps\pims\logFiles\kudu\trace directory.

breiter commented 8 years ago

This looks significant. It fails in the same way from the debug console cmd session.

DebugConsole Output

C:\inetpub\apps\pims>set HOME
HOME=C:\inetpub\apps\pims
HOMEDRIVE=C:
HOMEPATH=\inetpub\apps\pims

C:\inetpub\apps\pims>"C:\Program Files (x86)\git\usr\bin\ssh" -vv git@github.com
OpenSSH_7.1p1, OpenSSL 1.0.2d 9 Jul 2015
debug1: Reading configuration data /etc/ssh/ssh_config
Pseudo-terminal will not be allocated because stdin is not a terminal.
debug2: ssh_connect: needpriv 0
debug1: Connecting to github.com [192.30.252.130] port 22.
debug1: Connection established.
Could not create directory '/.ssh'.
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_rsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_rsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_dsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_dsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_ecdsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_ecdsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_ed25519 type -1
debug1: key_load_public: No such file or directory
debug1: identity file /.ssh/id_ed25519-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.1
debug1: Remote protocol version 2.0, remote software version libssh-0.7.0
debug1: no match: libssh-0.7.0
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to github.com:22 as 'git'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1
debug2: kex_parse_kexinit: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,ssh-rsa
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-dss,ssh-rsa
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc
debug2: kex_parse_kexinit: hmac-sha1,hmac-sha2-256,hmac-sha2-512
debug2: kex_parse_kexinit: hmac-sha1,hmac-sha2-256,hmac-sha2-512
debug2: kex_parse_kexinit: none,zlib,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib,zlib@openssh.com
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug1: kex: server->client chacha20-poly1305@openssh.com <implicit> none
debug1: kex: client->server chacha20-poly1305@openssh.com <implicit> none
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY

debug1: Server host key: ssh-rsa SHA256:nThbg6kXUpJWGl7E1IGOCspRomTxdCARLviKw6E5SY8
debug1: read_passphrase: can't open /dev/tty: No such device or address
Host key verification failed.
breiter commented 8 years ago

The key difference is that in the Debug Console, it is trying to read from /etc/ssh/ instead of /c/inetpub/apps/pims/.ssh/.

breiter commented 8 years ago

Post Deploy Trace

<step title="Incoming Request" date="2015-12-01T08:29:19.584" instance="WIN-B9" url="/deploy" method="POST" type="request" pid="3624,3,21" Content-Length="6834" Content-Type="application/json" Accept="*/*" Host="52.30.18.220:30075" User-Agent="GitHub-Hookshot/333881f" X-GitHub-Event="push" X-GitHub-Delivery="e1a1fd80-97b6-11e5-9ff8-c45c4a31be79" >
  <step title="FetchHandler" date="2015-12-01T08:29:19.697" >
    <step title="Attempting to fetch target branch stage" date="2015-12-01T08:29:19.755" /><!-- duration: 0ms -->
    <step title="Assuming git repository at C:\inetpub\apps\pims\site\repository" date="2015-12-01T08:29:19.794" /><!-- duration: 0ms -->
    <step title="Performing fetch based deployment" date="2015-12-01T08:29:19.814" >
      <step title="Creating temporary deployment" date="2015-12-01T08:29:19.834" /><!-- duration: 17ms -->
      <step title="Warning" date="2015-12-01T08:29:19.994" type="warning" text="LibGit2SharpRepository fetch failed with LibGit2Sharp.LibGit2SharpException: Unsupported URL protocol
   at LibGit2Sharp.Core.Ensure.HandleError(Int32 result)
   at LibGit2Sharp.Core.Proxy.git_remote_fetch(RemoteSafeHandle remote, Signature signature, String logMessage)
   at LibGit2Sharp.Network.DoFetch(RemoteSafeHandle remoteHandle, FetchOptions options, Signature signature, String logMessage)
   at LibGit2Sharp.Network.Fetch(Remote remote, FetchOptions options, Signature signature, String logMessage)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)" /><!-- duration: 0ms -->
      <step title="Warning" date="2015-12-01T08:29:19.995" type="warning" text="LibGit2SharpRepository fallback to git.exe" /><!-- duration: 0ms -->
      <step title="Executing external process" date="2015-12-01T08:29:20.009" type="process" path="git.exe" arguments="remote add -t stage external &quot;git@github.com:WolfeReiter/msh-pims&quot;" >
        <step title="Process dump" date="2015-12-01T08:29:20.083" exitCode="128" type="processOutput" /><!-- duration: 0ms -->
      </step><!-- duration: 74ms -->
      <step title="Executing external process" date="2015-12-01T08:29:20.085" type="process" path="git.exe" arguments="remote rm external" /><!-- duration: 32ms -->
      <step title="Executing external process" date="2015-12-01T08:29:20.119" type="process" path="git.exe" arguments="remote add -t stage external &quot;git@github.com:WolfeReiter/msh-pims&quot;" /><!-- duration: 25ms -->
      <step title="Executing external process" date="2015-12-01T08:29:20.145" type="process" path="git.exe" arguments="branch" /><!-- duration: 29ms -->
      <step title="Executing external process" date="2015-12-01T08:29:20.176" type="process" path="git.exe" arguments="fetch external --progress" >
        <step title="Process dump" date="2015-12-01T08:29:20.640" exitCode="128" type="processOutput" /><!-- duration: 1ms -->
      </step><!-- duration: 465ms -->
      <step title="Executing external process" date="2015-12-01T08:29:20.643" type="process" path="git.exe" arguments="remote rm external" /><!-- duration: 27ms -->
    </step><!-- duration: 862ms -->
  </step><!-- duration: 979ms -->
  <step title="Error occurred" date="2015-12-01T08:29:20.689" type="error" text="Could not create directory &apos;/.ssh&apos;.
Host key verification failed.
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

C:\Program Files (x86)\Git\bin\git.exe fetch external --progress" stackTrace="   at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.Infrastructure.OperationManager.Attempt[T](Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry)
   at Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)
   at Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger)
   at Kudu.Services.FetchHandler.&lt;PerformDeployment&gt;d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Services.FetchHandler.&lt;&gt;c__DisplayClass10_1.&lt;&lt;ProcessRequestAsync&gt;b__0&gt;d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Contracts.Infrastructure.LockExtensions.&lt;TryLockOperationAsync&gt;d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at Kudu.Services.FetchHandler.&lt;ProcessRequestAsync&gt;d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean&amp; completedSynchronously)" /><!-- duration: 0ms -->
  <step title="Outgoing response" date="2015-12-01T08:29:20.693" type="response" statusCode="500" statusText="Internal Server Error" Cache-Control="private" X-AspNet-Version="4.0.30319" Content-Type="text/html; charset=utf-8" /><!-- duration: 0ms -->
</step><!-- duration: 1111ms -->

HTTP Response 500

Headers

Cache-Control: private
Content-Length: 9043
Content-Type: text/html; charset=utf-8
Date: Tue, 01 Dec 2015 08:29:20 GMT
Server: Microsoft-IIS/8.5
X-AspNet-Version: 4.0.30319
X-Powered-By: ASP.NET

Body

<!DOCTYPE html>
<html>
    <head>
        <title>Could not create directory '/.ssh'.<br>Host key verification failed.<br>fatal: Could not read from remote repository.<br><br>Please make sure you have the correct access rights<br>and the repository exists.<br><br>C:\Program Files (x86)\Git\bin\git.exe fetch external --progress</title>
        <meta name="viewport" content="width=device-width" />
        <style>
         body {font-family:"Verdana";font-weight:normal;font-size: .7em;color:black;} 
         p {font-family:"Verdana";font-weight:normal;color:black;margin-top: -5px}
         b {font-family:"Verdana";font-weight:bold;color:black;margin-top: -5px}
         H1 { font-family:"Verdana";font-weight:normal;font-size:18pt;color:red }
         H2 { font-family:"Verdana";font-weight:normal;font-size:14pt;color:maroon }
         pre {font-family:"Consolas","Lucida Console",Monospace;font-size:11pt;margin:0;padding:0.5em;line-height:14pt}
         .marker {font-weight: bold; color: black;text-decoration: none;}
         .version {color: gray;}
         .error {margin-bottom: 10px;}
         .expandable { text-decoration:underline; font-weight:bold; color:navy; cursor:hand; }
         @media screen and (max-width: 639px) {
          pre { width: 440px; overflow: auto; white-space: pre-wrap; word-wrap: break-word; }
         }
         @media screen and (max-width: 479px) {
          pre { width: 280px; }
         }
        </style>
    </head>

    <body bgcolor="white">

            <span><H1>Server Error in '/' Application.<hr width=100% size=1 color=silver></H1>

            <h2> <i>Could not create directory '/.ssh'.<br>Host key verification failed.<br>fatal: Could not read from remote repository.<br><br>Please make sure you have the correct access rights<br>and the repository exists.<br><br>C:\Program Files (x86)\Git\bin\git.exe fetch external --progress</i> </h2></span>

            <font face="Arial, Helvetica, Geneva, SunSans-Regular, sans-serif ">

            <b> Description: </b>An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code.

            <br><br>

            <b> Exception Details: </b>Kudu.Core.Infrastructure.CommandLineException: Could not create directory '/.ssh'.<br>Host key verification failed.<br>fatal: Could not read from remote repository.<br><br>Please make sure you have the correct access rights<br>and the repository exists.<br><br>C:\Program Files (x86)\Git\bin\git.exe fetch external --progress<br><br>

            <b>Source Error:</b> <br><br>

            <table width=100% bgcolor="#ffffcc">
               <tr>
                  <td>
                      <code>

An unhandled exception was generated during the execution of the current web request. Information regarding the origin and location of the exception can be identified using the exception stack trace below.</code>

                  </td>
               </tr>
            </table>

            <br>

            <b>Stack Trace:</b> <br><br>

            <table width=100% bgcolor="#ffffcc">
               <tr>
                  <td>
                      <code><pre>

[CommandLineException: Could not create directory &#39;/.ssh&#39;.
Host key verification failed.
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

C:\Program Files (x86)\Git\bin\git.exe fetch external --progress]
   Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args) +464
   Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args) +16
   Kudu.Core.Infrastructure.OperationManager.Attempt(Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry) +188
   Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName) +815
   Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName) +1410
   Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger) +33
   Kudu.Services.&lt;PerformDeployment&gt;d__11.MoveNext() +2056
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +144
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +84
   Kudu.Services.&lt;&lt;ProcessRequestAsync&gt;b__0&gt;d.MoveNext() +496
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +144
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +84
   Kudu.Contracts.Infrastructure.&lt;TryLockOperationAsync&gt;d__2.MoveNext() +539
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +144
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +84
   System.Runtime.CompilerServices.TaskAwaiter`1.GetResult() +49
   Kudu.Services.&lt;ProcessRequestAsync&gt;d__10.MoveNext() +1327
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +144
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +84
   System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar) +98
   System.Web.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() +606
   System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean&amp; completedSynchronously) +288
</pre></code>

                  </td>
               </tr>
            </table>

            <br>

            <hr width=100% size=1 color=silver>

            <b>Version Information:</b>&nbsp;Microsoft .NET Framework Version:4.0.30319; ASP.NET Version:4.0.30319.34274

            </font>

    </body>
</html>
<!-- 
[CommandLineException]: Could not create directory &#39;/.ssh&#39;.
Host key verification failed.
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

C:\Program Files (x86)\Git\bin\git.exe fetch external --progress
   at Kudu.Core.Infrastructure.Executable.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.SourceControl.Git.GitExeRepository.Execute(ITracer tracer, String arguments, Object[] args)
   at Kudu.Core.Infrastructure.OperationManager.Attempt[T](Func`1 action, Int32 retries, Int32 delayBeforeRetry, Func`2 shouldRetry)
   at Kudu.Core.SourceControl.Git.GitExeRepository.FetchWithoutConflict(String remote, String branchName)
   at Kudu.Core.SourceControl.Git.LibGit2SharpRepository.FetchWithoutConflict(String remoteUrl, String branchName)
   at Kudu.Services.ServiceHookHandlers.ServiceHookHandlerBase.Fetch(IRepository repository, DeploymentInfo deploymentInfo, String targetBranch, ILogger logger)
   at Kudu.Services.FetchHandler.<PerformDeployment>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Services.FetchHandler.<>c__DisplayClass10_1.<<ProcessRequestAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Contracts.Infrastructure.LockExtensions.<TryLockOperationAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at Kudu.Services.FetchHandler.<ProcessRequestAsync>d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)
--><!-- 
This error page might contain sensitive information because ASP.NET is configured to show verbose error messages using &lt;customErrors mode="Off"/&gt;. Consider using &lt;customErrors mode="On"/&gt; or &lt;customErrors mode="RemoteOnly"/&gt; in production environments.-->
breiter commented 8 years ago

I can reproduce the exact behavior from a normal cmd session if I set HOME= to make it null.

It seems like the git.exe process is not inheriting the environment when it is started by Kudu or in the DebugConsole.

I think it is a permissions problem somehow. I got it to work by setting the AppPool to run as local system.

suwatch commented 8 years ago

Strange .. the git process is a child of w3wp->cmd, hence it should inherit envs (this is windows thing not kudu specific).

One thing to try, if you look in this and search for applicationPoolDefaults, follow the instruction and see if it helps.

You can validate if permission related by http://localhost:30075/DebugConsole and try to open.ssh\id_rsa from there. If it works, then git should have the same permission.

breiter commented 8 years ago

@suwatch The environment is being set correctly. The problem is something with permissions that is not at all obvious to me. I can access the .ssh/id_rsa file and type it to the console in cmd but ssh refuses to use it when the process owner is iis apppool\pims. Users have Full Control on the apps directory. Everything works correctly if I change the app pool to run as LocalSystem and a webhook ping from github triggers a pull and build. Obviously, this is not ideal. The same code is running on another server that works normally.

suwatch commented 8 years ago

@breiter I assumed you compare the ACL and they look the same between those 2 machines.

BTW, our tests ran apppool with network service identity (due to different reason) - so we have not encountered that - though we use to run with apppool identity in the past without issues. I guess, for you, either run as network service (assuming it works and is acceptable to you) or try to dig deeper on ACL issue.

suwatch commented 8 years ago

I just got a chance to try with the new git (2.6.3) and noticed the same issue. We are working to fix it. Will update.

jvano commented 6 months ago

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