Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

curl rpc 56 errno 0 when using git clone #13899

Open
tgemvz opened this issue Jun 6, 2024 · 20 comments
Open

curl rpc 56 errno 0 when using git clone #13899

tgemvz opened this issue Jun 6, 2024 · 20 comments
Assignees

Comments

@tgemvz
Copy link

tgemvz commented Jun 6, 2024

I did this

Updated git-for-windows from version 2.43.0 to Version 2.45.1
Then I tried to use "git clone" to clone a repo behind a corporate proxy.
The proxy does unpack SSL traffic, git ist configured to use openssl and a PEM file containing the complete certificate-chain as sslCAInfo.

Using the the newer Version of git, which in turn does use a newer Version of libcurl (among others) the command fails

With the help of @dscho over at git-for-windows/git#4997 we narrowed it down to newer Versions of libcurl (8.8.0 instead of 8.4.0) and openssl (3.2.1 instead 3.1.4) being used.

Only when exchanging both dlls (with the lower Versions) does a newer git client work behind a corporate proxy.

git clone verbos log with GIT_CURL_VERBOSE=1

[...]
14:49:25.932242 http.c:868              == Info: OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0
14:49:25.933242 http.c:868              == Info: Closing connection
error: RPC failed; curl 56 OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0
14:49:25.935365 pkt-line.c:86           packet:     sideband< 0000
Receiving objects: 100% (1385/1385), 292.44 KiB | 12.71 MiB/s, done.
Resolving deltas: 100% (886/886), done.

I expected the following

git clone to complete

curl/libcurl version

libcurl 8.8.0

operating system

Windows 10

@icing
Copy link
Contributor

icing commented Jun 6, 2024

To understand what the problem is it would be good to have a look at the full debug log.

@icing icing self-assigned this Jun 6, 2024
@tgemvz
Copy link
Author

tgemvz commented Jun 6, 2024

Here is the log (same as in git-for-windows/git#4997)

14:49:22.803476 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
14:49:22.817429 git.c:465               trace: built-in: git clone https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[repo]
Cloning into '[repo]'...
14:49:22.858109 run-command.c:657       trace: run_command: git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[repo]
14:49:22.879146 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:22.888111 git.c:750               trace: exec: git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[repo]
14:49:22.888111 run-command.c:657       trace: run_command: git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[repo]
14:49:22.911111 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:22.942114 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
14:49:22.951756 http.c:868              == Info: Host [proxy]:[port] was resolved.
14:49:22.952756 http.c:868              == Info: IPv6: (none)
14:49:22.952756 http.c:868              == Info: IPv4: [proxyIP]
14:49:22.952756 http.c:868              == Info:   Trying [proxyIP]:[port]...
14:49:22.976758 http.c:868              == Info: Connected to [proxy] ([proxyIP]) port [port]
14:49:22.976758 http.c:868              == Info: CONNECT tunnel: HTTP/1.1 negotiated
14:49:22.976758 http.c:868              == Info: allocate connect buffer
14:49:22.979756 http.c:868              == Info: Proxy auth using NTLM with user ''
14:49:22.979756 http.c:868              == Info: Establish HTTP proxy tunnel to dev.azure.com:443
14:49:22.990756 http.c:868              == Info: CONNECT phase completed
14:49:22.990756 http.c:868              == Info: CONNECT tunnel established, response 200
14:49:22.990756 http.c:868              == Info: ALPN: curl offers h2,http/1.1
14:49:22.991786 http.c:868              == Info: TLSv1.3 (OUT), TLS handshake, Client hello (1):
14:49:23.010933 http.c:868              == Info:  CAfile: [pemFilePath]
14:49:23.010933 http.c:868              == Info:  CApath: none
14:49:23.012225 http.c:868              == Info: TLSv1.3 (IN), TLS handshake, Server hello (2):
14:49:23.012225 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Certificate (11):
14:49:23.015177 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server key exchange (12):
14:49:23.015726 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server finished (14):
14:49:23.017894 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
14:49:23.017894 http.c:868              == Info: TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
14:49:23.017894 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Finished (20):
14:49:23.021402 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Finished (20):
14:49:23.021402 http.c:868              == Info: SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384 / secp384r1 / rsaEncryption
14:49:23.021402 http.c:868              == Info: ALPN: server did not agree on a protocol. Uses default.
14:49:23.021402 http.c:868              == Info: Server certificate:
14:49:23.022504 http.c:868              == Info:  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=dev.azure.com
14:49:23.022504 http.c:868              == Info:  start date: Mar 27 20:48:07 2024 GMT
14:49:23.022504 http.c:868              == Info:  expire date: Sep 23 20:48:07 2024 GMT
14:49:23.023016 http.c:868              == Info:  subjectAltName: host "dev.azure.com" matched cert's "dev.azure.com"
14:49:23.023016 http.c:868              == Info:  issuer: C=CH; ST=ZH; L=ZH; O=[CorporationName]; OU=[OU Name] ; CN=[CN]; emailAddress=[ITEmailAdress]
14:49:23.023016 http.c:868              == Info:  SSL certificate verify ok.
14:49:23.023016 http.c:868              == Info:   Certificate level 0: Public key type RSA (2048/112 Bits/secBits), signed using sha256WithRSAEncryption
14:49:23.023016 http.c:868              == Info:   Certificate level 1: Public key type RSA (2048/112 Bits/secBits), signed using sha256WithRSAEncryption
14:49:23.023016 http.c:868              == Info: using HTTP/1.x
14:49:23.024016 http.c:868              == Info: Request completely sent off
14:49:23.121015 http.c:868              == Info: Ignoring the response-body
14:49:23.121015 http.c:868              == Info: Connection #0 to host [proxy] left intact
14:49:23.121015 http.c:868              == Info: Issue another request to this URL: 'https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[project]/info/refs?service=git-upload-pack'
14:49:23.121015 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
14:49:23.121015 http.c:868              == Info: Found bundle for host: 0x1f8d5466040 [serially]
14:49:23.121015 http.c:868              == Info: Can not multiplex, even if we wanted to
14:49:23.121015 http.c:868              == Info: Re-using existing connection with proxy [proxy]
14:49:23.122014 http.c:868              == Info: Server auth using Basic with user '[orgname]'
14:49:23.122014 http.c:868              == Info: Request completely sent off
14:49:23.184670 http.c:868              == Info: Authentication problem. Ignoring this.

14:49:23.186669 http.c:868              == Info: Connection #0 to host [proxy] left intact
14:49:23.186669 run-command.c:657       trace: run_command: 'git credential-manager get'
14:49:23.251288 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:23.260288 git.c:750               trace: exec: git-credential-manager get
14:49:23.261289 run-command.c:657       trace: run_command: git-credential-manager get
14:49:23.361417 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:23.371416 git.c:465               trace: built-in: git config --null --list
14:49:23.524251 http.c:868              == Info: Found bundle for host: 0x1f8d5466040 [serially]
14:49:23.524251 http.c:868              == Info: Can not multiplex, even if we wanted to
14:49:23.524251 http.c:868              == Info: Re-using existing connection with proxy [proxy]
14:49:23.524251 http.c:868              == Info: Server auth using Basic with user '[UserEmailAdress]'
14:49:23.524783 http.c:868              == Info: Request completely sent off
14:49:23.821775 http.c:868              == Info: Connection #0 to host [proxy] left intact
14:49:23.821775 run-command.c:657       trace: run_command: 'git credential-manager store'
14:49:23.897409 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:23.906409 git.c:750               trace: exec: git-credential-manager store
14:49:23.906409 run-command.c:657       trace: run_command: git-credential-manager store
14:49:23.995027 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:24.001028 git.c:465               trace: built-in: git config --null --list
14:49:24.152702 run-command.c:657       trace: run_command: 'git credential-manager store'
14:49:24.216791 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:24.225791 git.c:750               trace: exec: git-credential-manager store
14:49:24.225791 run-command.c:657       trace: run_command: git-credential-manager store
14:49:24.319423 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:24.325424 git.c:465               trace: built-in: git config --null --list
14:49:24.476084 pkt-line.c:86           packet:          git< # service=git-upload-pack
14:49:24.476084 pkt-line.c:86           packet:          git< 0000
14:49:24.476084 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
14:49:24.476084 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
14:49:24.500085 run-command.c:657       trace: run_command: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[project]/
14:49:24.523085 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:24.537085 git.c:465               trace: built-in: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[project]/_git/[project]/
14:49:24.538084 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
14:49:24.546086 http.c:868              == Info: Found bundle for host: 0x1f8d5466040 [serially]
14:49:24.546086 http.c:868              == Info: Can not multiplex, even if we wanted to
14:49:24.547084 http.c:868              == Info: Re-using existing connection with proxy [proxy]
14:49:24.547084 http.c:868              == Info: Server auth using Basic with user '[UserEmailAdress]'
14:49:24.548085 http.c:815              => Send header, 0000000412 bytes (0x0000019c)
14:49:24.548085 http.c:827              => Send header: POST /[orgname]/[project]/_git/[project]/git-upload-pack HTTP/1.1
14:49:24.548085 http.c:827              => Send header: Host: dev.azure.com
14:49:24.548085 http.c:827              => Send header: Authorization: Basic <redacted>
14:49:24.548085 http.c:827              => Send header: User-Agent: git/2.45.1.windows.1
14:49:24.548085 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
14:49:24.548085 http.c:827              => Send header: Content-Type: application/x-git-upload-pack-request
14:49:24.548085 http.c:827              => Send header: Accept: application/x-git-upload-pack-result
14:49:24.548085 http.c:827              => Send header: Content-Length: 364
14:49:24.548085 http.c:827              => Send header:
14:49:24.548085 http.c:868              == Info: upload completely sent off: 364 bytes
14:49:25.870141 pkt-line.c:86           packet:   fetch-pack< NAK
14:49:25.870141 pkt-line.c:86           packet:   fetch-pack> 0000
14:49:25.871142 pkt-line.c:86           packet:     sideband< \2Azure Repos
remote: Azure Repos
14:49:25.871142 pkt-line.c:86           packet:     sideband< \2\15Found 1385 objects to send. (93 ms)
remote: Found 1385 objects to send. (93 ms)
14:49:25.871142 pkt-line.c:86           packet:     sideband< PACK ...
14:49:25.878124 run-command.c:657       trace: run_command: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 78064 on [hostname]' --check-self-contained-and-connected --pack_header=2,1385
14:49:25.898248 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
14:49:25.908248 git.c:465               trace: built-in: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 78064 on [hostname]' --check-self-contained-and-connected --pack_header=2,1385
14:49:25.932242 http.c:868              == Info: OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0
14:49:25.933242 http.c:868              == Info: Closing connection
error: RPC failed; curl 56 OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0
14:49:25.935365 pkt-line.c:86           packet:     sideband< 0000
Receiving objects: 100% (1385/1385), 292.44 KiB | 12.71 MiB/s, done.
Resolving deltas: 100% (886/886), done.

@icing
Copy link
Contributor

icing commented Jun 6, 2024

You say "The proxy does unpack SSL traffic". Does that mean it acts as a man in the middle, terminating the git client TLS and having its own TLS session to the server?

From the log, I see that there is a 1.3 second gap between curl reporting the POST content sent and the next attempt to read the response. That fails with the SSL_Read error which indicates that the proxy seen to have just closed the TCP connection. 1.3 seconds makes it unlikely that this is a timeout at the proxy or origin server that strikes here.

Also, peculiar that you need to change both libcurl and openssl versions to have it working again.

@icing
Copy link
Contributor

icing commented Jun 6, 2024

@tgemvz could you produce a similar log with the working combination? Maybe we can see a difference.

@tgemvz
Copy link
Author

tgemvz commented Jun 6, 2024

Here is a similar log (scrubbed, demanded by company policy)
using git portable version 2.45.2 with both DLLs replaced

❯ git clone https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.103485 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/bin
10:40:54.128281 common-main.c:55                  version 2.45.2.windows.1
10:40:54.128281 common-main.c:56                  start git.exe clone https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.157288 git.c:465               trace: built-in: git clone https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.158278 git.c:466                         cmd_name clone (clone)
10:40:54.162288 repository.c:158                  worktree C:/PortableGit/2.45.2both/[repo]
Cloning into '[repo]'...
10:40:54.205257 run-command.c:724                 child_start[0] git remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.205257 run-command.c:657       trace: run_command: git remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.230283 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:54.242259 common-main.c:55                  version 2.45.2.windows.1
10:40:54.242259 common-main.c:56                  start git remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.280290 git.c:744                         cmd_name _run_dashed_ (clone/_run_dashed_)
10:40:54.280290 git.c:750               trace: exec: git-remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.280290 run-command.c:724                 child_start[0] git-remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.281257 run-command.c:657       trace: run_command: git-remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.307257 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:54.317894 common-main.c:55                  version 2.45.2.windows.1
10:40:54.318932 common-main.c:56                  start git-remote-https origin https://[orgname]@dev.azure.com/[orgname][projectname]_git/[repo]
10:40:54.353927 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:54.353927 remote-curl.c:1549                cmd_name remote-curl (clone/_run_dashed_/remote-curl)
10:40:54.367929 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
10:40:54.374896 http.c:868              == Info:   Trying [proxyIP]:[proxyPort]...
10:40:54.376894 http.c:868              == Info: Connected to [proxy] ([proxyIP]) port [proxyPort]
10:40:54.377894 http.c:868              == Info: CONNECT tunnel: HTTP/1.1 negotiated
10:40:54.378895 http.c:868              == Info: allocate connect buffer
10:40:54.381927 http.c:868              == Info: Proxy auth using NTLM with user ''
10:40:54.381927 http.c:868              == Info: Establish HTTP proxy tunnel to dev.azure.com:443
10:40:54.381927 http.c:815              => Send header, 0000000223 bytes (0x000000df)
10:40:54.381927 http.c:827              => Send header: CONNECT dev.azure.com:443 HTTP/1.1
10:40:54.382894 http.c:827              => Send header: Host: dev.azure.com:443
10:40:54.382894 http.c:827              => Send header: Proxy-Authorization: NTLM <redacted>
10:40:54.383663 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
10:40:54.383663 http.c:827              => Send header: Proxy-Connection: Keep-Alive
10:40:54.383663 http.c:827              => Send header:
[...] Removed Recv-Header by CompanyPolicy
10:40:54.391119 http.c:868              == Info: CONNECT phase completed
10:40:54.393115 http.c:868              == Info: CONNECT tunnel established, response 200
10:40:54.394121 http.c:868              == Info: ALPN: curl offers h2,http/1.1
10:40:54.394121 http.c:868              == Info: TLSv1.3 (OUT), TLS handshake, Client hello (1):
10:40:54.412087 http.c:868              == Info:  CAfile: [CAFile]
10:40:54.413089 http.c:868              == Info:  CApath: none
10:40:54.428186 http.c:868              == Info: TLSv1.3 (IN), TLS handshake, Server hello (2):
10:40:54.428186 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Certificate (11):
10:40:54.433186 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server key exchange (12):
10:40:54.433186 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server finished (14):
10:40:54.435156 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
10:40:54.436155 http.c:868              == Info: TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
10:40:54.436155 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Finished (20):
10:40:54.442156 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Finished (20):
10:40:54.442156 http.c:868              == Info: SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
10:40:54.443157 http.c:868              == Info: ALPN: server did not agree on a protocol. Uses default.
10:40:54.443157 http.c:868              == Info: Server certificate:
10:40:54.443157 http.c:868              == Info:  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=dev.azure.com
10:40:54.443157 http.c:868              == Info:  start date: Mar 27 20:48:07 2024 GMT
10:40:54.444451 http.c:868              == Info:  expire date: Sep 23 20:48:07 2024 GMT
10:40:54.444451 http.c:868              == Info:  subjectAltName: host "dev.azure.com" matched cert's "dev.azure.com"
10:40:54.444451 http.c:868              == Info:  issuer: C=CH; ST=ZH; L=ZH; O=[O]; OU=IT Services ; CN=[CN]; emailAddress=[ITEMAIL]
10:40:54.444451 http.c:868              == Info:  SSL certificate verify ok.
10:40:54.445491 http.c:868              == Info: using HTTP/1.x
10:40:54.445491 http.c:815              => Send header, 0000000254 bytes (0x000000fe)
10:40:54.445491 http.c:827              => Send header: GET /[orgname][projectname]_git[projectname]info/refs?service=git-upload-pack HTTP/1.1
10:40:54.446460 http.c:827              => Send header: Host: dev.azure.com
10:40:54.446460 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
10:40:54.446460 http.c:827              => Send header: Accept: */*
10:40:54.446460 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
10:40:54.447459 http.c:827              => Send header: Pragma: no-cache
10:40:54.447459 http.c:827              => Send header: Git-Protocol: version=2
10:40:54.447459 http.c:827              => Send header:
[...] Removed Recv-Header by CompanyPolicy
10:40:54.571582 http.c:868              == Info: Ignoring the response-body
10:40:54.571582 http.c:868              == Info: Connection #0 to host [proxy] left intact
10:40:54.571582 http.c:868              == Info: Issue another request to this URL: 'https://[orgname]@dev.azure.com/[orgname][projectname]_git[projectname]info/refs?service=git-upload-pack'
10:40:54.572582 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
10:40:54.572582 http.c:868              == Info: Found bundle for host: 0x15ee084b3e0 [serially]
10:40:54.572582 http.c:868              == Info: Can not multiplex, even if we wanted to
10:40:54.573581 http.c:868              == Info: Re-using existing connection with proxy [proxy]
10:40:54.573581 http.c:868              == Info: Server auth using Basic with user '[orgname]'
10:40:54.573581 http.c:815              => Send header, 0000000289 bytes (0x00000121)
10:40:54.573581 http.c:827              => Send header: GET /[orgname][projectname]_git[projectname]info/refs?service=git-upload-pack HTTP/1.1
10:40:54.573581 http.c:827              => Send header: Host: dev.azure.com
10:40:54.574582 http.c:827              => Send header: Authorization: Basic <redacted>
10:40:54.574582 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
10:40:54.574582 http.c:827              => Send header: Accept: */*
10:40:54.574582 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
10:40:54.575581 http.c:827              => Send header: Pragma: no-cache
10:40:54.575581 http.c:827              => Send header: Git-Protocol: version=2
10:40:54.575581 http.c:827              => Send header:
[...] Removed Recv-Header by CompanyPolicy
10:40:54.647173 http.c:868              == Info: Connection #0 to host [proxy] left intact
10:40:54.648175 run-command.c:724                 child_start[0] '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" get'
10:40:54.648175 run-command.c:657       trace: run_command: '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" get'
10:40:54.832370 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:54.844340 common-main.c:55                  version 2.45.2.windows.1
10:40:54.844340 common-main.c:56                  start 'C:/PortableGit/2.45.2both/mingw64/libexec/git-core\git.exe' config --null --list
10:40:54.889380 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:54.890340 git.c:465               trace: built-in: git config --null --list
10:40:54.891028 git.c:466                         cmd_name config (clone/_run_dashed_/remote-curl/config)
10:40:54.902026 git.c:724                         exit elapsed:0.070068 code:0
10:40:54.903026 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.070617 code:0
10:40:54.918057 Program.cs:56                     version 2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2
10:40:54.920026 Program.cs:56                     start git-credential-manager.exe get
10:40:55.011196 Program.cs:71                     exit elapsed:0.2574385 code:0
10:40:55.020164 run-command.c:977                 child_exit[0] pid:12876 code:0 elapsed:0.372100
10:40:55.020164 http.c:868              == Info: Found bundle for host: 0x15ee084b3e0 [serially]
10:40:55.020164 http.c:868              == Info: Can not multiplex, even if we wanted to
10:40:55.021199 http.c:868              == Info: Re-using existing connection with proxy [proxy]
10:40:55.021199 http.c:868              == Info: Server auth using Basic with user '[User]'
10:40:55.021199 http.c:815              => Send header, 0000000365 bytes (0x0000016d)
10:40:55.022193 http.c:827              => Send header: GET /[orgname][projectname]_git[projectname]info/refs?service=git-upload-pack HTTP/1.1
10:40:55.022193 http.c:827              => Send header: Host: dev.azure.com
10:40:55.022193 http.c:827              => Send header: Authorization: Basic <redacted>
10:40:55.022193 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
10:40:55.023196 http.c:827              => Send header: Accept: */*
10:40:55.023196 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
10:40:55.023196 http.c:827              => Send header: Pragma: no-cache
10:40:55.024200 http.c:827              => Send header: Git-Protocol: version=2
10:40:55.024200 http.c:827              => Send header:
[...] Removed Recv-Header by CompanyPolicy
10:40:55.241581 http.c:868              == Info: Connection #0 to host [proxy] left intact
10:40:55.242095 run-command.c:724                 child_start[1] '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
10:40:55.242095 run-command.c:657       trace: run_command: '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
10:40:55.403480 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:55.434235 common-main.c:55                  version 2.45.2.windows.1
10:40:55.434235 common-main.c:56                  start 'C:/PortableGit/2.45.2both/mingw64/libexec/git-core\git.exe' config --null --list
10:40:55.480393 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:55.481393 git.c:465               trace: built-in: git config --null --list
10:40:55.481393 git.c:466                         cmd_name config (clone/_run_dashed_/remote-curl/config)
10:40:55.491394 git.c:724                         exit elapsed:0.087939 code:0
10:40:55.491394 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.088042 code:0
10:40:55.506438 Program.cs:56                     version 2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2
10:40:55.508425 Program.cs:56                     start git-credential-manager.exe store
fatal: Cannot determine the organization name for this 'dev.azure.com' remote URL. Ensure the `credential.useHttpPath` configuration value is set, or set the organization name as the user in the remote URL '{org}@dev.azure.com'.
10:40:55.595996 Program.cs:71                     exit elapsed:0.2475552 code:-1
10:40:55.604999 run-command.c:977                 child_exit[1] pid:11788 code:127 elapsed:0.363483
10:40:55.604999 run-command.c:724                 child_start[2] '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
10:40:55.605998 run-command.c:657       trace: run_command: '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
10:40:55.756574 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:55.766573 common-main.c:55                  version 2.45.2.windows.1
10:40:55.767573 common-main.c:56                  start 'C:/PortableGit/2.45.2both/mingw64/libexec/git-core\git.exe' config --null --list
10:40:55.825573 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:55.825573 git.c:465               trace: built-in: git config --null --list
10:40:55.826575 git.c:466                         cmd_name config (clone/_run_dashed_/remote-curl/config)
10:40:55.838575 git.c:724                         exit elapsed:0.082388 code:0
10:40:55.838575 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.082546 code:0
10:40:55.853601 Program.cs:56                     version 2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2
10:40:55.856573 Program.cs:56                     start git-credential-manager.exe store
10:40:55.938606 Program.cs:71                     exit elapsed:0.2336074 code:0
10:40:55.948577 run-command.c:977                 child_exit[2] pid:5500 code:0 elapsed:0.343111
10:40:55.948577 pkt-line.c:86           packet:          git< # service=git-upload-pack
10:40:55.948577 pkt-line.c:86           packet:          git< 0000
10:40:55.949575 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
10:40:55.950575 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
10:40:55.967494 pkt-line.c:86           packet:          git> 0000
10:40:55.968494 run-command.c:724                 child_start[3] git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname][projectname]_git[projectname]
10:40:55.968494 run-command.c:657       trace: run_command: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname][projectname]_git[projectname]
10:40:55.992494 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:56.003493 common-main.c:55                  version 2.45.2.windows.1
10:40:56.003493 common-main.c:56                  start git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname][projectname]_git[projectname]
10:40:56.041529 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:56.045495 git.c:465               trace: built-in: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname][projectname]_git[projectname]
10:40:56.045495 git.c:466                         cmd_name fetch-pack (clone/_run_dashed_/remote-curl/fetch-pack)
10:40:56.046495 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
10:40:56.048495 pkt-line.c:86           packet:   fetch-pack< 0000
10:40:56.048495 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
10:40:56.059525 pkt-line.c:86           packet:   fetch-pack> want 284375f673bb7bb2c3574f1896eb590b2da64843
10:40:56.059525 pkt-line.c:86           packet:   fetch-pack> want 0d04bdfef3dd4399455406bf580fb71dd694b027
10:40:56.059525 pkt-line.c:86           packet:   fetch-pack> 0000
10:40:56.060495 pkt-line.c:86           packet:   fetch-pack> done
10:40:56.060495 pkt-line.c:86           packet:   fetch-pack> 0000
10:40:56.060495 pkt-line.c:86           packet:          git< 0065want 7b4c63188e7335a4eed9225a500703509eddb2ec multi_ack_detailed no-done side-band-64k thin-pack0032want a2b10484ef8c0bbd8b83448cb4d2fa0af3ebe21e0032want 2295c8a86cef38646f07314b9ec6ad44c23d53da0032want b5143bfecf4c15d76064ec748ac9936615427efd0032want 284375f673bb7bb2c3574f1896eb590b2da648430032want 0d04bdfef3dd4399455406bf580fb71dd694b0270032want a132742d74b7de80b6bb038e8237d8ba6ab7385500000009done
10:40:56.061521 pkt-line.c:86           packet:          git< 0000
10:40:56.061521 http.c:868              == Info: Found bundle for host: 0x15ee084b3e0 [serially]
10:40:56.061521 http.c:868              == Info: Can not multiplex, even if we wanted to
10:40:56.061521 http.c:868              == Info: Re-using existing connection with proxy [proxy]
10:40:56.062495 http.c:868              == Info: Server auth using Basic with user '[User]'
10:40:56.062495 http.c:815              => Send header, 0000000412 bytes (0x0000019c)
10:40:56.062495 http.c:827              => Send header: POST /[orgname][projectname]_git[projectname]git-upload-pack HTTP/1.1
10:40:56.062495 http.c:827              => Send header: Host: dev.azure.com
10:40:56.063495 http.c:827              => Send header: Authorization: Basic <redacted>
10:40:56.063495 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
10:40:56.063495 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
10:40:56.063495 http.c:827              => Send header: Content-Type: application/x-git-upload-pack-request
10:40:56.064497 http.c:827              => Send header: Accept: application/x-git-upload-pack-result
10:40:56.064497 http.c:827              => Send header: Content-Length: 414
10:40:56.064497 http.c:827              => Send header:
[...] Removed Recv-Header by CompanyPolicy
10:40:56.767172 pkt-line.c:86           packet:   fetch-pack< NAK
10:40:56.768145 pkt-line.c:86           packet:   fetch-pack> 0000
10:40:56.768573 pkt-line.c:86           packet:     sideband< \2Azure Repos
remote: Azure Repos
10:40:56.768573 pkt-line.c:86           packet:     sideband< \2\15Found 1397 objects to send. (297 ms)
remote: Found 1397 objects to send. (297 ms)
10:40:56.769580 pkt-line.c:86           packet:     sideband< PACK ...
10:40:56.769580 run-command.c:724                 child_start[0] git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29208 on P3707' --check-self-contained-and-connected --pack_header=2,1397
10:40:56.770580 run-command.c:657       trace: run_command: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29208 on P3707' --check-self-contained-and-connected --pack_header=2,1397
10:40:56.796078 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:56.807709 common-main.c:55                  version 2.45.2.windows.1
10:40:56.808142 common-main.c:56                  start git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29208 on P3707' --check-self-contained-and-connected --pack_header=2,1397
10:40:56.849495 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:56.853452 git.c:465               trace: built-in: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29208 on P3707' --check-self-contained-and-connected --pack_header=2,1397
10:40:56.854459 git.c:466                         cmd_name index-pack (clone/_run_dashed_/remote-curl/fetch-pack/index-pack)
10:40:56.879484 http.c:868              == Info: Closing connection
10:40:56.879484 http.c:868              == Info: TLSv1.2 (OUT), TLS alert, close notify (256):
10:40:56.879484 pkt-line.c:86           packet:          git< 0000
10:40:56.882248 pkt-line.c:86           packet:     sideband< 0000
Receiving objects: 100% (1397/1397), 293.39 KiB | 11.74 MiB/s, done.
Resolving deltas: 100% (896/896), done.
10:40:56.920736 git.c:724                         exit elapsed:0.124473 code:0
10:40:56.920736 trace2/tr2_tgt_normal.c:371       counter fsync/hardware-flush value:3
10:40:56.920736 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.124608 code:0
10:40:56.924736 run-command.c:977                 child_exit[0] pid:29988 code:0 elapsed:0.154969
10:40:56.925736 git.c:724                         exit elapsed:0.933471 code:0
10:40:56.925736 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.933605 code:0
10:40:56.928736 run-command.c:977                 child_exit[3] pid:29208 code:0 elapsed:0.960976
10:40:56.929932 run-command.c:724                 child_start[1] git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
10:40:56.930941 run-command.c:657       trace: run_command: git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
10:40:56.955288 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
10:40:56.967295 common-main.c:55                  version 2.45.2.windows.1
10:40:56.968295 common-main.c:56                  start git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
10:40:57.001862 repository.c:158                  worktree C:/PortableGit/2.45.2both
10:40:57.009865 git.c:465               trace: built-in: git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
10:40:57.009865 git.c:466                         cmd_name rev-list (clone/rev-list)
10:40:57.017863 git.c:724                         exit elapsed:0.062626 code:0
10:40:57.017863 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.062805 code:0
10:40:57.020863 run-command.c:977                 child_exit[1] pid:27548 code:0 elapsed:0.090905
10:40:57.045863 common-main.c:65                  exit elapsed:2.738661 code:0
10:40:57.045863 trace2/tr2_tgt_normal.c:128       atexit elapsed:2.739250 code:0
10:40:57.049863 run-command.c:977                 child_exit[0] pid:25108 code:0 elapsed:2.770075
10:40:57.050863 git.c:766                         exit elapsed:2.820375 code:0
10:40:57.050863 trace2/tr2_tgt_normal.c:128       atexit elapsed:2.820507 code:0
10:40:57.053863 run-command.c:977                 child_exit[0] pid:29704 code:0 elapsed:2.848913
10:40:57.131865 git.c:724                         exit elapsed:3.028967 code:0
10:40:57.131865 trace2/tr2_tgt_normal.c:128       atexit elapsed:3.029061 code:0

@icing
Copy link
Contributor

icing commented Jun 6, 2024

Thanks, I assume that [...] Removed Recv-Header by CompanyPolicy allows applies to the first log and we just do not see the response the server sent? That makes it hard to analyse what is going on.

You might stumble into a libcurl bug or into an incompatibility with your company proxy and OpenSSL 3.2.1 vs. 3.1.4. If you exchange the OpenSSL .dll for a libcurl it was not build with, all bets are off. So it's hard to say what is going on.

Unless you are able to reproduce a libcurl problem that we can reproduce outselves and only can give us heavily redacted logs, I do not see how we can help you. If you need confidentiality, it might be an idea to buy professional curl support via https://curl.se/support.html.

@tgemvz
Copy link
Author

tgemvz commented Jun 6, 2024

Observation: The delay comes from manually clicking "manager" in credential-selector (3 / 4 times)

I also will clarify with my superiors how to go further in regards to buying professional support.

Thank you for your efforts!

Nevertheless here are less redacted logs:

Not working constellation

❯ git clone https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.040962 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/bin
11:49:05.067523 common-main.c:55                  version 2.45.2.windows.1
11:49:05.067523 common-main.c:56                  start git.exe clone https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.099142 git.c:465               trace: built-in: git clone https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.099142 git.c:466                         cmd_name clone (clone)
11:49:05.106142 repository.c:158                  worktree C:/PortableGit/2.45.2/[repo]
Cloning into '[repo]'...
11:49:05.316021 run-command.c:724                 child_start[0] git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.316021 run-command.c:657       trace: run_command: git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.413023 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:05.424022 common-main.c:55                  version 2.45.2.windows.1
11:49:05.424022 common-main.c:56                  start git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.462222 git.c:744                         cmd_name _run_dashed_ (clone/_run_dashed_)
11:49:05.463223 git.c:750               trace: exec: git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.463223 run-command.c:724                 child_start[0] git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.464224 run-command.c:657       trace: run_command: git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.507224 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:05.517224 common-main.c:55                  version 2.45.2.windows.1
11:49:05.518224 common-main.c:56                  start git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[repo]
11:49:05.559224 repository.c:158                  worktree C:/PortableGit/2.45.2
11:49:05.559224 remote-curl.c:1549                cmd_name remote-curl (clone/_run_dashed_/remote-curl)
11:49:05.932759 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
11:49:05.938722 http.c:868              == Info: Host [proxy]:[proxyPort] was resolved.
11:49:05.939760 http.c:868              == Info: IPv6: (none)
11:49:05.939760 http.c:868              == Info: IPv4: [proxyIP]
11:49:05.942722 http.c:868              == Info:   Trying [proxyIP]:[proxyPort]...
11:49:05.943723 http.c:868              == Info: Connected to [proxy] ([proxyIP]) port [proxyPort]
11:49:05.943723 http.c:868              == Info: CONNECT tunnel: HTTP/1.1 negotiated
11:49:05.944722 http.c:868              == Info: allocate connect buffer
11:49:05.947724 http.c:868              == Info: Proxy auth using NTLM with user ''
11:49:05.947724 http.c:868              == Info: Establish HTTP proxy tunnel to dev.azure.com:443
11:49:05.947724 http.c:815              => Send header, 0000000223 bytes (0x000000df)
11:49:05.947724 http.c:827              => Send header: CONNECT dev.azure.com:443 HTTP/1.1
11:49:05.948723 http.c:827              => Send header: Host: dev.azure.com:443
11:49:05.948723 http.c:827              => Send header: Proxy-Authorization: NTLM <redacted>
11:49:05.948723 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:49:05.948723 http.c:827              => Send header: Proxy-Connection: Keep-Alive
11:49:05.948723 http.c:827              => Send header:
11:49:05.958754 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:49:05.958754 http.c:827              <= Recv header: HTTP/1.1 200 Connection established
11:49:05.959722 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:49:05.959722 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:49:05 GMT
11:49:05.959722 http.c:815              <= Recv header, 0000000030 bytes (0x0000001e)
11:49:05.960722 http.c:827              <= Recv header: Proxy-Connection: Keep-Alive
11:49:05.960722 http.c:815              <= Recv header, 0000000034 bytes (0x00000022)
11:49:05.960722 http.c:827              <= Recv header: Via: 1.1 [proxyFQDN]
11:49:05.961723 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:49:05.961723 http.c:827              <= Recv header:
11:49:05.961723 http.c:868              == Info: CONNECT phase completed
11:49:05.961723 http.c:868              == Info: CONNECT tunnel established, response 200
11:49:05.963756 http.c:868              == Info: ALPN: curl offers h2,http/1.1
11:49:05.963756 http.c:868              == Info: TLSv1.3 (OUT), TLS handshake, Client hello (1):
11:49:05.987724 http.c:868              == Info:  CAfile: [CAFile]
11:49:05.987724 http.c:868              == Info:  CApath: none
11:49:05.989756 http.c:868              == Info: TLSv1.3 (IN), TLS handshake, Server hello (2):
11:49:05.989756 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Certificate (11):
11:49:05.993725 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server key exchange (12):
11:49:05.994730 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server finished (14):
11:49:05.996724 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
11:49:05.996724 http.c:868              == Info: TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
11:49:05.997723 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Finished (20):
11:49:06.003724 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Finished (20):
11:49:06.003724 http.c:868              == Info: SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384 / secp384r1 / rsaEncryption
11:49:06.004725 http.c:868              == Info: ALPN: server did not agree on a protocol. Uses default.
11:49:06.004725 http.c:868              == Info: Server certificate:
11:49:06.004725 http.c:868              == Info:  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=dev.azure.com
11:49:06.005724 http.c:868              == Info:  start date: Mar 27 20:48:07 2024 GMT
11:49:06.005724 http.c:868              == Info:  expire date: Sep 23 20:48:07 2024 GMT
11:49:06.005724 http.c:868              == Info:  subjectAltName: host "dev.azure.com" matched cert's "dev.azure.com"
11:49:06.006724 http.c:868              == Info:  issuer: C=[C]; ST=[ST]; L=[L]; O=[O]; OU=IT Services ; CN=[CN]; emailAddress=[ITEMAIL]
11:49:06.006724 http.c:868              == Info:  SSL certificate verify ok.
11:49:06.006724 http.c:868              == Info:   Certificate level 0: Public key type RSA (2048/112 Bits/secBits), signed using sha256WithRSAEncryption
11:49:06.007723 http.c:868              == Info:   Certificate level 1: Public key type RSA (2048/112 Bits/secBits), signed using sha256WithRSAEncryption
11:49:06.007723 http.c:868              == Info: using HTTP/1.x
11:49:06.007723 http.c:815              => Send header, 0000000254 bytes (0x000000fe)
11:49:06.008723 http.c:827              => Send header: GET /[orgname]/[projectname]/_git/[projectname]/info/refs?service=git-upload-pack HTTP/1.1
11:49:06.008723 http.c:827              => Send header: Host: dev.azure.com
11:49:06.008723 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:49:06.008723 http.c:827              => Send header: Accept: */*
11:49:06.009723 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:49:06.009723 http.c:827              => Send header: Pragma: no-cache
11:49:06.009723 http.c:827              => Send header: Git-Protocol: version=2
11:49:06.009723 http.c:827              => Send header:
11:49:06.010723 http.c:868              == Info: Request completely sent off
11:49:06.143052 http.c:815              <= Recv header, 0000000027 bytes (0x0000001b)
11:49:06.143052 http.c:827              <= Recv header: HTTP/1.1 401 Unauthorized
11:49:06.144052 http.c:815              <= Recv header, 0000000024 bytes (0x00000018)
11:49:06.146052 http.c:827              <= Recv header: Cache-Control: private
11:49:06.150052 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:49:06.150052 http.c:827              <= Recv header: Content-Type: text/html
11:49:06.150052 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:49:06.153051 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:49:06.153051 http.c:815              <= Recv header, 0000000115 bytes (0x00000073)
11:49:06.155052 http.c:827              <= Recv header: WWW-Authenticate: Bearer authorization_uri=https://login.microsoftonline.com/[TENANTID]
11:49:06.158052 http.c:815              <= Recv header, 0000000071 bytes (0x00000047)
11:49:06.161051 http.c:827              <= Recv header: WWW-Authenticate: Basic realm="https://tfsprodweu6.visualstudio.com/"
11:49:06.162052 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:49:06.164053 http.c:827              <= Recv header: WWW-Authenticate: TFS-Federated
11:49:06.164053 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:49:06.167053 http.c:827              <= Recv header: X-TFS-ProcessId: [ProcessId]
11:49:06.169051 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:06.169051 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:49:06.171051 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:49:06.171051 http.c:827              <= Recv header: ActivityId: [ActivityId]
11:49:06.173053 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:49:06.175051 http.c:827              <= Recv header: X-TFS-Session: [ActivityId]
11:49:06.176051 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:49:06.177052 http.c:827              <= Recv header: X-VSS-E2EID: [ActivityId]
11:49:06.178051 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:06.180052 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [DeploymentId]
11:49:06.181052 http.c:815              <= Recv header, 0000000029 bytes (0x0000001d)
11:49:06.181052 http.c:827              <= Recv header: X-FRAME-OPTIONS: SAMEORIGIN
11:49:06.182051 http.c:815              <= Recv header, 0000000059 bytes (0x0000003b)
11:49:06.184051 http.c:827              <= Recv header: X-TFS-FedAuthRealm: https://tfsprodweu6.visualstudio.com/
11:49:06.184051 http.c:815              <= Recv header, 0000000054 bytes (0x00000036)
11:49:06.185052 http.c:827              <= Recv header: X-TFS-FedAuthIssuer: https://dev.azure.com/[orgname]/
11:49:06.185052 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:06.185052 http.c:827              <= Recv header: X-VSS-AuthorizationEndpoint: https://vssps.dev.azure.com/[orgname]/
11:49:06.185052 http.c:815              <= Recv header, 0000000060 bytes (0x0000003c)
11:49:06.185052 http.c:827              <= Recv header: X-VSS-ResourceTenant: [TENANTID]
11:49:06.186051 http.c:815              <= Recv header, 0000000710 bytes (0x000002c6)
11:49:06.186051 http.c:827              <= Recv header: X-TFS-SoapException: %3C%3Fxml%20version%3D%221.0%22%20encoding%3D%22utf-8%22%3F%3E%3Csoap%3AEnvelope%20xmlns%3Asoap%3D%22http%3A%2F%2Fwww.w3.org%2F2003%2F05%2Fsoap-envelope%22%3E%3Csoap%3ABody%3E%3Csoap%3AFault%3E%3Csoap%3ACode%3E%3Csoap%3AValue%3Esoap%3AReceiver%3C%2Fsoap%3AValue%3E%3Csoap%3ASubcode%3E%3Csoap%3AValue%3EUnauthorizedRequestException%3C%2Fsoap%3AValue%3E%3C%2Fsoap%3ASubcode%3E%3C%2Fsoap%3ACode%3E%3Csoap%3AReason%3E%3Csoap%3AText%20xml%3Alang%3D%22en%22%3ETF400813%3A%20The%20user%20%27aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa%27%20is%20not%20authorized%20to%20access%20this%20resource.%3C%2Fsoap%3AText%3E%3C%2Fsoap%3AReason%3E%3C%2Fsoap%3AFault%3E%3C%2Fsoap%3ABody%3E%3C%2Fsoap%3AEnvelope%3E
11:49:06.186051 http.c:815              <= Recv header, 0000000148 bytes (0x00000094)
11:49:06.186051 http.c:827              <= Recv header: X-TFS-ServiceError: TF400813%3A%20The%20user%20%27aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa%27%20is%20not%20authorized%20to%20access%20this%20resource.
11:49:06.186051 http.c:815              <= Recv header, 0000000079 bytes (0x0000004f)
11:49:06.187051 http.c:827              <= Recv header: X-VSS-S2STargetService: 00000002-0000-8888-8000-000000000000/visualstudio.com
11:49:06.187051 http.c:815              <= Recv header, 0000000554 bytes (0x0000022a)
11:49:06.187051 http.c:827              <= Recv header: X-TFS-FedAuthRedirect: https://spsprodweu2.vssps.visualstudio.com/_signin<redacted>
11:49:06.188052 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:06.188052 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appid]
11:49:06.188052 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:49:06.189052 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:49:06.189052 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:49:06.189052 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:49:06.189052 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:49:06.190052 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:49:06.190052 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:49:06.190052 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: 7298D71BBAF54040BFD4741C86639443 Ref B: ZRHEDGE1206 Ref C: 2024-06-06T09:49:06Z
11:49:06.191052 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:49:06.191052 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:49:05 GMT
11:49:06.191052 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:49:06.191052 http.c:827              <= Recv header: Age: 1
11:49:06.192052 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:49:06.193052 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:49:06.194052 http.c:815              <= Recv header, 0000000023 bytes (0x00000017)
11:49:06.194052 http.c:827              <= Recv header: Content-Length: 89611
11:49:06.194052 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:49:06.194052 http.c:827              <= Recv header:
11:49:06.195052 http.c:868              == Info: Ignoring the response-body
11:49:06.195052 http.c:868              == Info: Connection #0 to host [proxy] left intact
11:49:06.195052 http.c:868              == Info: Issue another request to this URL: 'https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[projectname]/info/refs?service=git-upload-pack'
11:49:06.196052 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
11:49:06.196052 http.c:868              == Info: Found bundle for host: 0x22851779ca0 [serially]
11:49:06.196052 http.c:868              == Info: Can not multiplex, even if we wanted to
11:49:06.196052 http.c:868              == Info: Re-using existing connection with proxy [proxy]
11:49:06.197052 http.c:868              == Info: Server auth using Basic with user '[orgname]'
11:49:06.197052 http.c:815              => Send header, 0000000289 bytes (0x00000121)
11:49:06.197052 http.c:827              => Send header: GET /[orgname]/[projectname]/_git/[projectname]/info/refs?service=git-upload-pack HTTP/1.1
11:49:06.197052 http.c:827              => Send header: Host: dev.azure.com
11:49:06.198052 http.c:827              => Send header: Authorization: Basic <redacted>
11:49:06.198052 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:49:06.198052 http.c:827              => Send header: Accept: */*
11:49:06.198052 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:49:06.198052 http.c:827              => Send header: Pragma: no-cache
11:49:06.199052 http.c:827              => Send header: Git-Protocol: version=2
11:49:06.199052 http.c:827              => Send header:
11:49:06.199052 http.c:868              == Info: Request completely sent off
11:49:06.272338 http.c:815              <= Recv header, 0000000027 bytes (0x0000001b)
11:49:06.272338 http.c:827              <= Recv header: HTTP/1.1 401 Unauthorized
11:49:06.272338 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:49:06.273336 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:49:06.274338 http.c:868              == Info: Authentication problem. Ignoring this.
11:49:06.274338 http.c:815              <= Recv header, 0000000071 bytes (0x00000047)
11:49:06.274338 http.c:827              <= Recv header: WWW-Authenticate: Basic realm="https://tfsprodweu6.visualstudio.com/"
11:49:06.275335 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:49:06.275335 http.c:827              <= Recv header: X-TFS-ProcessId: [ProcessId]
11:49:06.275335 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:06.275335 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:49:06.275335 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:49:06.275335 http.c:827              <= Recv header: ActivityId: 8fbbc1c4-0c7f-4d26-b7be-b35bfcc0e140
11:49:06.275335 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:49:06.275335 http.c:827              <= Recv header: X-TFS-Session: 8fbbc1c4-0c7f-4d26-b7be-b35bfcc0e140
11:49:06.275335 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:49:06.276336 http.c:827              <= Recv header: X-VSS-E2EID: 8fbbc1c4-0c7f-4d26-b7be-b35bfcc0e140
11:49:06.276336 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:06.276336 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [DeploymentId]
11:49:06.276336 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:06.276336 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appid]
11:49:06.276336 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:49:06.276336 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:49:06.276336 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:49:06.276336 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:49:06.277335 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:49:06.277335 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:49:06.277335 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:49:06.277335 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: 998BE8D688DF4DFFA234F6AD0CB601ED Ref B: ZRHEDGE1206 Ref C: 2024-06-06T09:49:06Z
11:49:06.278335 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:49:06.278335 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:49:05 GMT
11:49:06.278335 http.c:815              <= Recv header, 0000000019 bytes (0x00000013)
11:49:06.278335 http.c:827              <= Recv header: Content-Length: 0
11:49:06.279337 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:49:06.279337 http.c:827              <= Recv header: Age: 1
11:49:06.279337 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:49:06.279337 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:49:06.279337 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:49:06.280335 http.c:827              <= Recv header:
11:49:06.280335 http.c:868              == Info: Connection #0 to host [proxy] left intact
11:49:06.280335 run-command.c:724                 child_start[0] 'git credential-helper-selector get'
11:49:06.280335 run-command.c:657       trace: run_command: 'git credential-helper-selector get'
11:49:06.638961 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:06.672562 common-main.c:55                  version 2.45.2.windows.1
11:49:06.672562 common-main.c:56                  start 'C:\PortableGit\2.45.2\mingw64\libexec\git-core\git.exe' credential-helper-selector get
11:49:06.717672 git.c:744                         cmd_name _run_dashed_ (clone/_run_dashed_/remote-curl/_run_dashed_)
11:49:06.718672 git.c:750               trace: exec: git-credential-helper-selector get
11:49:06.718672 run-command.c:724                 child_start[0] git-credential-helper-selector get
11:49:06.719672 run-command.c:657       trace: run_command: git-credential-helper-selector get
11:49:13.455333 run-command.c:977                 child_exit[0] pid:30348 code:0 elapsed:6.736521
11:49:13.456332 git.c:766                         exit elapsed:6.817021 code:0
11:49:13.456332 trace2/tr2_tgt_normal.c:128       atexit elapsed:6.817401 code:0
11:49:13.462333 run-command.c:977                 child_exit[0] pid:9712 code:0 elapsed:7.181352
11:49:13.462333 http.c:868              == Info: Found bundle for host: 0x22851779ca0 [serially]
11:49:13.462333 http.c:868              == Info: Can not multiplex, even if we wanted to
11:49:13.462333 http.c:868              == Info: Re-using existing connection with proxy [proxy]
11:49:13.463333 http.c:868              == Info: Server auth using Basic with user '[UserName]'
11:49:13.463333 http.c:815              => Send header, 0000000365 bytes (0x0000016d)
11:49:13.463333 http.c:827              => Send header: GET /[orgname]/[projectname]/_git/[projectname]/info/refs?service=git-upload-pack HTTP/1.1
11:49:13.464333 http.c:827              => Send header: Host: dev.azure.com
11:49:13.464333 http.c:827              => Send header: Authorization: Basic <redacted>
11:49:13.464333 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:49:13.464333 http.c:827              => Send header: Accept: */*
11:49:13.465333 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:49:13.465333 http.c:827              => Send header: Pragma: no-cache
11:49:13.470333 http.c:827              => Send header: Git-Protocol: version=2
11:49:13.470333 http.c:827              => Send header:
11:49:13.471332 http.c:868              == Info: Request completely sent off
11:49:13.571366 http.c:815              <= Recv header, 0000000017 bytes (0x00000011)
11:49:13.571366 http.c:827              <= Recv header: HTTP/1.1 200 OK
11:49:13.572336 http.c:815              <= Recv header, 0000000024 bytes (0x00000018)
11:49:13.572336 http.c:827              <= Recv header: Cache-Control: private
11:49:13.573335 http.c:815              <= Recv header, 0000000059 bytes (0x0000003b)
11:49:13.573335 http.c:827              <= Recv header: Content-Type: application/x-git-upload-pack-advertisement
11:49:13.573335 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:49:13.574335 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:49:13.574335 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:49:13.574335 http.c:827              <= Recv header: X-TFS-ProcessId: [ProcessId]
11:49:13.575340 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:13.576336 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:49:13.576336 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:49:13.577335 http.c:827              <= Recv header: ActivityId: [ActivtiyId]
11:49:13.577335 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:49:13.577335 http.c:827              <= Recv header: X-TFS-Session: [ActivtiyId]
11:49:13.578333 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:49:13.578333 http.c:827              <= Recv header: X-VSS-E2EID: [ActivtiyId]
11:49:13.578333 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:13.578333 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [DeploymentId]
11:49:13.579334 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:13.579334 http.c:827              <= Recv header: X-VSS-UserData: [UserdataId]:[UserName]
11:49:13.579334 http.c:815              <= Recv header, 0000000029 bytes (0x0000001d)
11:49:13.579334 http.c:827              <= Recv header: X-FRAME-OPTIONS: SAMEORIGIN
11:49:13.579334 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:13.580335 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appid]
11:49:13.580335 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:49:13.580335 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:49:13.580335 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:49:13.581339 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:49:13.581339 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:49:13.581339 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:49:13.581339 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:49:13.581339 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: AA85075438074C40AE0B27769423337A Ref B: ZRHEDGE1206 Ref C: 2024-06-06T09:49:13Z
11:49:13.582334 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:49:13.582334 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:49:13 GMT
11:49:13.582334 http.c:815              <= Recv header, 0000000021 bytes (0x00000015)
11:49:13.582334 http.c:827              <= Recv header: Content-Length: 729
11:49:13.583334 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:49:13.583334 http.c:827              <= Recv header: Age: 0
11:49:13.583334 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:49:13.583334 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:49:13.584333 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:49:13.584333 http.c:827              <= Recv header:
11:49:13.584333 http.c:868              == Info: Connection #0 to host [proxy] left intact
11:49:13.584333 run-command.c:724                 child_start[1] 'git credential-helper-selector store'
11:49:13.585333 run-command.c:657       trace: run_command: 'git credential-helper-selector store'
11:49:13.646608 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:13.657609 common-main.c:55                  version 2.45.2.windows.1
11:49:13.657609 common-main.c:56                  start 'C:\PortableGit\2.45.2\mingw64\libexec\git-core\git.exe' credential-helper-selector store
11:49:13.723229 git.c:744                         cmd_name _run_dashed_ (clone/_run_dashed_/remote-curl/_run_dashed_)
11:49:13.723229 git.c:750               trace: exec: git-credential-helper-selector store
11:49:13.724274 run-command.c:724                 child_start[0] git-credential-helper-selector store
11:49:13.725229 run-command.c:657       trace: run_command: git-credential-helper-selector store
11:49:16.464588 run-command.c:977                 child_exit[0] pid:34012 code:1 elapsed:2.739591
11:49:16.465589 git.c:766                         exit elapsed:2.818875 code:1
11:49:16.466589 trace2/tr2_tgt_normal.c:128       atexit elapsed:2.820526 code:1
11:49:16.482587 run-command.c:977                 child_exit[1] pid:30732 code:1 elapsed:2.898295
11:49:16.483590 run-command.c:724                 child_start[2] 'git credential-helper-selector store'
11:49:16.483590 run-command.c:657       trace: run_command: 'git credential-helper-selector store'
11:49:16.553044 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:16.564044 common-main.c:55                  version 2.45.2.windows.1
11:49:16.564044 common-main.c:56                  start 'C:\PortableGit\2.45.2\mingw64\libexec\git-core\git.exe' credential-helper-selector store
11:49:16.613630 git.c:744                         cmd_name _run_dashed_ (clone/_run_dashed_/remote-curl/_run_dashed_)
11:49:16.613630 git.c:750               trace: exec: git-credential-helper-selector store
11:49:16.613630 run-command.c:724                 child_start[0] git-credential-helper-selector store
11:49:16.614620 run-command.c:657       trace: run_command: git-credential-helper-selector store
11:49:19.087881 run-command.c:977                 child_exit[0] pid:4544 code:0 elapsed:2.473454
11:49:19.087881 git.c:766                         exit elapsed:2.535250 code:0
11:49:19.088880 trace2/tr2_tgt_normal.c:128       atexit elapsed:2.535504 code:0
11:49:19.093884 run-command.c:977                 child_exit[2] pid:34192 code:0 elapsed:2.610902
11:49:19.094883 pkt-line.c:86           packet:          git< # service=git-upload-pack
11:49:19.094883 pkt-line.c:86           packet:          git< 0000
11:49:19.094883 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
11:49:19.096882 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:49:19.096882 pkt-line.c:86           packet:          git< 0000
11:49:19.119917 pkt-line.c:86           packet:          git> 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:49:19.121882 pkt-line.c:86           packet:          git> 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:49:19.122880 pkt-line.c:86           packet:          git> 0000
11:49:19.123881 run-command.c:724                 child_start[3] git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[projectname]/
11:49:19.123881 run-command.c:657       trace: run_command: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[projectname]/
11:49:19.143438 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:19.153672 common-main.c:55                  version 2.45.2.windows.1
11:49:19.153672 common-main.c:56                  start git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[projectname]/
11:49:19.195494 repository.c:158                  worktree C:/PortableGit/2.45.2
11:49:19.199494 git.c:465               trace: built-in: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]/_git/[projectname]/
11:49:19.199494 git.c:466                         cmd_name fetch-pack (clone/_run_dashed_/remote-curl/fetch-pack)
11:49:19.201527 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:49:19.203309 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:49:19.203309 pkt-line.c:86           packet:   fetch-pack< 0000
11:49:19.204276 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
11:49:19.205275 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:49:19.206275 pkt-line.c:86           packet:   fetch-pack< 0000
11:49:19.211275 pkt-line.c:86           packet:   fetch-pack> want 7b4c63188e7335a4eed9225a500703509eddb2ec multi_ack_detailed no-done side-band-64k thin-pack
11:49:19.212275 pkt-line.c:86           packet:   fetch-pack> want 284375f673bb7bb2c3574f1896eb590b2da64843
11:49:19.213276 pkt-line.c:86           packet:   fetch-pack> 0000
11:49:19.213276 pkt-line.c:86           packet:   fetch-pack> done
11:49:19.213276 pkt-line.c:86           packet:   fetch-pack> 0000
11:49:19.213276 pkt-line.c:86           packet:          git< 0065want 7b4c63188e7335a4eed9225a500703509eddb2ec multi_ack_detailed no-done side-band-64k thin-pack0032want a2b10484ef8c0bbd8b83448cb4d2fa0af3ebe21e0032want 2295c8a86cef38646f07314b9ec6ad44c23d53da0032want b5143bfecf4c15d76064ec748ac9936615427efd0032want 284375f673bb7bb2c3574f1896eb590b2da648430032want 0d04bdfef3dd4399455406bf580fb71dd694b0270032want a132742d74b7de80b6bb038e8237d8ba6ab7385500000009done
11:49:19.215324 pkt-line.c:86           packet:          git< 0000
11:49:19.215324 http.c:868              == Info: Found bundle for host: 0x22851779ca0 [serially]
11:49:19.215324 http.c:868              == Info: Can not multiplex, even if we wanted to
11:49:19.216308 http.c:868              == Info: Re-using existing connection with proxy [proxy]
11:49:19.216308 http.c:868              == Info: Server auth using Basic with user '[UserName]'
11:49:19.216308 http.c:815              => Send header, 0000000412 bytes (0x0000019c)
11:49:19.216308 http.c:827              => Send header: POST /[orgname]/[projectname]/_git/[projectname]/git-upload-pack HTTP/1.1
11:49:19.217276 http.c:827              => Send header: Host: dev.azure.com
11:49:19.217276 http.c:827              => Send header: Authorization: Basic <redacted>
11:49:19.217276 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:49:19.217276 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:49:19.218309 http.c:827              => Send header: Content-Type: application/x-git-upload-pack-request
11:49:19.218309 http.c:827              => Send header: Accept: application/x-git-upload-pack-result
11:49:19.218309 http.c:827              => Send header: Content-Length: 414
11:49:19.218309 http.c:827              => Send header:
11:49:19.219298 http.c:868              == Info: upload completely sent off: 414 bytes
11:49:19.656605 http.c:815              <= Recv header, 0000000017 bytes (0x00000011)
11:49:19.656605 http.c:827              <= Recv header: HTTP/1.1 200 OK
11:49:19.659639 http.c:815              <= Recv header, 0000000024 bytes (0x00000018)
11:49:19.660640 http.c:827              <= Recv header: Cache-Control: private
11:49:19.662641 http.c:815              <= Recv header, 0000000052 bytes (0x00000034)
11:49:19.663643 http.c:827              <= Recv header: Content-Type: application/x-git-upload-pack-result
11:49:19.664639 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:49:19.665653 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:49:19.667688 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:49:19.673900 http.c:827              <= Recv header: X-TFS-ProcessId: [ProcessID]
11:49:19.673900 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:19.673900 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:49:19.673900 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:49:19.674899 http.c:827              <= Recv header: ActivityId: [ActivitID]
11:49:19.674899 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:49:19.674899 http.c:827              <= Recv header: X-TFS-Session: [ActivitID]
11:49:19.674899 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:49:19.674899 http.c:827              <= Recv header: X-VSS-E2EID: [ActivitID]
11:49:19.675900 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:49:19.675900 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [DeploymentId]
11:49:19.675900 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:19.675900 http.c:827              <= Recv header: X-VSS-UserData: [UserdataId]:[UserName]
11:49:19.676899 http.c:815              <= Recv header, 0000000029 bytes (0x0000001d)
11:49:19.676899 http.c:827              <= Recv header: X-FRAME-OPTIONS: SAMEORIGIN
11:49:19.676899 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:49:19.676899 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appid]
11:49:19.677899 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:49:19.677899 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:49:19.677899 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:49:19.677899 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:49:19.678900 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:49:19.678900 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:49:19.678900 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:49:19.678900 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: 07352B4C576F4EEEBD0EA1B5A7D1899E Ref B: ZRHEDGE1621 Ref C: 2024-06-06T09:49:19Z
11:49:19.679900 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:49:19.679900 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:49:19 GMT
11:49:19.679900 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:49:19.679900 http.c:827              <= Recv header: Age: 0
11:49:19.679900 http.c:815              <= Recv header, 0000000019 bytes (0x00000013)
11:49:19.680899 http.c:827              <= Recv header: Connection: close
11:49:19.680899 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:49:19.680899 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:49:19.680899 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:49:19.681902 http.c:827              <= Recv header:
11:49:19.681902 pkt-line.c:86           packet:   fetch-pack< NAK
11:49:19.681902 pkt-line.c:86           packet:   fetch-pack> 0000
11:49:19.681902 pkt-line.c:86           packet:     sideband< \2Azure Repos
remote: Azure Repos
11:49:19.683902 pkt-line.c:86           packet:     sideband< \2\15Found 1397 objects to send. (188 ms)
remote: Found 1397 objects to send. (188 ms)
11:49:19.684900 pkt-line.c:86           packet:     sideband< PACK ...
11:49:19.685901 run-command.c:724                 child_start[0] git index-pack --stdin -v --fix-thin '--keep=fetch-pack 32760 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:49:19.685901 run-command.c:657       trace: run_command: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 32760 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:49:19.706899 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2/mingw64/libexec/git-core
11:49:19.718901 common-main.c:55                  version 2.45.2.windows.1
11:49:19.720024 common-main.c:56                  start git index-pack --stdin -v --fix-thin '--keep=fetch-pack 32760 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:49:19.763048 repository.c:158                  worktree C:/PortableGit/2.45.2
11:49:19.768049 git.c:465               trace: built-in: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 32760 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:49:19.768049 git.c:466                         cmd_name index-pack (clone/_run_dashed_/remote-curl/fetch-pack/index-pack)
11:49:19.798637 http.c:868              == Info: OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0
11:49:19.798637 http.c:868              == Info: Closing connection
11:49:19.799637 usage.c:83                        error RPC failed; curl 56 OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0error: RPC failed; curl 56 OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0
11:49:19.802638 pkt-line.c:86           packet:     sideband< 0000
Receiving objects: 100% (1397/1397), 293.39 KiB | 9.78 MiB/s, done.
Resolving deltas: 100% (896/896), done.
11:49:19.845637 git.c:724                         exit elapsed:0.139157 code:0
11:49:19.845637 trace2/tr2_tgt_normal.c:371       counter fsync/hardware-flush value:3
11:49:19.845637 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.139289 code:0
11:49:19.849638 run-command.c:977                 child_exit[0] pid:24116 code:0 elapsed:0.164308
11:49:19.850640 git.c:724                         exit elapsed:0.708157 code:0
11:49:19.850640 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.708328 code:0
11:49:19.854638 run-command.c:977                 child_exit[3] pid:32760 code:0 elapsed:0.730875
11:49:19.854638 remote-curl.c:1283                exit elapsed:14.348117 code:128
11:49:19.855638 trace2/tr2_tgt_normal.c:128       atexit elapsed:14.348582 code:128
11:49:19.859637 run-command.c:977                 child_exit[0] pid:256 code:128 elapsed:14.395363
11:49:19.859637 git.c:766                         exit elapsed:14.447188 code:128
11:49:19.859637 trace2/tr2_tgt_normal.c:128       atexit elapsed:14.447300 code:128
11:49:19.862637 transport-helper.c:419            exit elapsed:14.822118 code:128
11:49:19.873638 trace2/tr2_tgt_normal.c:128       atexit elapsed:14.833259 code:128

Working constellation

> git clone https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.507176 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/bin
11:12:06.533729 common-main.c:55                  version 2.45.2.windows.1
11:12:06.533729 common-main.c:56                  start git.exe clone https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.564716 git.c:465               trace: built-in: git clone https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.564716 git.c:466                         cmd_name clone (clone)
11:12:06.569746 repository.c:158                  worktree C:/PortableGit/2.45.2both/[repo]
Cloning into '[repo]'...
11:12:06.732307 run-command.c:724                 child_start[0] git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.732307 run-command.c:657       trace: run_command: git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.753310 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:06.763308 common-main.c:55                  version 2.45.2.windows.1
11:12:06.763308 common-main.c:56                  start git remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.803179 git.c:744                         cmd_name _run_dashed_ (clone/_run_dashed_)
11:12:06.803179 git.c:750               trace: exec: git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.804182 run-command.c:724                 child_start[0] git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.804182 run-command.c:657       trace: run_command: git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.825180 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:06.837180 common-main.c:55                  version 2.45.2.windows.1
11:12:06.837180 common-main.c:56                  start git-remote-https origin https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[repo]
11:12:06.877180 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:06.877180 remote-curl.c:1549                cmd_name remote-curl (clone/_run_dashed_/remote-curl)
11:12:06.948826 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
11:12:06.956079 http.c:868              == Info:   Trying [proxyIP]:[proxyPort]...
11:12:06.974268 http.c:868              == Info: Connected to [proxy] ([proxyIP]) port [proxyPort]
11:12:06.974268 http.c:868              == Info: CONNECT tunnel: HTTP/1.1 negotiated
11:12:06.974268 http.c:868              == Info: allocate connect buffer
11:12:06.978269 http.c:868              == Info: Proxy auth using NTLM with user ''
11:12:06.978269 http.c:868              == Info: Establish HTTP proxy tunnel to dev.azure.com:443
11:12:06.978269 http.c:815              => Send header, 0000000223 bytes (0x000000df)
11:12:06.979269 http.c:827              => Send header: CONNECT dev.azure.com:443 HTTP/1.1
11:12:06.979269 http.c:827              => Send header: Host: dev.azure.com:443
11:12:06.979269 http.c:827              => Send header: Proxy-Authorization: NTLM <redacted>
11:12:06.979269 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:12:06.980269 http.c:827              => Send header: Proxy-Connection: Keep-Alive
11:12:06.980269 http.c:827              => Send header:
11:12:07.014350 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:12:07.014915 http.c:827              <= Recv header: HTTP/1.1 200 Connection established
11:12:07.015472 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:12:07.015472 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:12:07 GMT
11:12:07.016020 http.c:815              <= Recv header, 0000000030 bytes (0x0000001e)
11:12:07.016020 http.c:827              <= Recv header: Proxy-Connection: Keep-Alive
11:12:07.016569 http.c:815              <= Recv header, 0000000034 bytes (0x00000022)
11:12:07.016569 http.c:827              <= Recv header: Via: 1.1 [proxyFQDN]
11:12:07.017119 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:12:07.017119 http.c:827              <= Recv header:
11:12:07.017636 http.c:868              == Info: CONNECT phase completed
11:12:07.017636 http.c:868              == Info: CONNECT tunnel established, response 200
11:12:07.019231 http.c:868              == Info: ALPN: curl offers h2,http/1.1
11:12:07.019782 http.c:868              == Info: TLSv1.3 (OUT), TLS handshake, Client hello (1):
11:12:07.044642 http.c:868              == Info:  CAfile: [CAFile]
11:12:07.044864 http.c:868              == Info:  CApath: none
11:12:07.059105 http.c:868              == Info: TLSv1.3 (IN), TLS handshake, Server hello (2):
11:12:07.059203 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Certificate (11):
11:12:07.062497 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server key exchange (12):
11:12:07.063044 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Server finished (14):
11:12:07.065109 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
11:12:07.065109 http.c:868              == Info: TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
11:12:07.065109 http.c:868              == Info: TLSv1.2 (OUT), TLS handshake, Finished (20):
11:12:07.069110 http.c:868              == Info: TLSv1.2 (IN), TLS handshake, Finished (20):
11:12:07.070110 http.c:868              == Info: SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
11:12:07.070110 http.c:868              == Info: ALPN: server did not agree on a protocol. Uses default.
11:12:07.070110 http.c:868              == Info: Server certificate:
11:12:07.071109 http.c:868              == Info:  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=dev.azure.com
11:12:07.071109 http.c:868              == Info:  start date: Mar 27 20:48:07 2024 GMT
11:12:07.071109 http.c:868              == Info:  expire date: Sep 23 20:48:07 2024 GMT
11:12:07.071109 http.c:868              == Info:  subjectAltName: host "dev.azure.com" matched cert's "dev.azure.com"
11:12:07.072109 http.c:868              == Info:  issuer: C=[C]; ST=[ST]; L=[L]; O=[O]; OU=[OU] ; CN=[CN]; emailAddress=[ITEMAIL]
11:12:07.072109 http.c:868              == Info:  SSL certificate verify ok.
11:12:07.072109 http.c:868              == Info: using HTTP/1.x
11:12:07.072109 http.c:815              => Send header, 0000000254 bytes (0x000000fe)
11:12:07.072109 http.c:827              => Send header: GET /[orgname]/[projectname]_git/[projectname]info/refs?service=git-upload-pack HTTP/1.1
11:12:07.072109 http.c:827              => Send header: Host: dev.azure.com
11:12:07.072109 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:12:07.073109 http.c:827              => Send header: Accept: */*
11:12:07.073109 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:12:07.073109 http.c:827              => Send header: Pragma: no-cache
11:12:07.073109 http.c:827              => Send header: Git-Protocol: version=2
11:12:07.073109 http.c:827              => Send header:
11:12:07.212150 http.c:815              <= Recv header, 0000000027 bytes (0x0000001b)
11:12:07.212948 http.c:827              <= Recv header: HTTP/1.1 401 Unauthorized
11:12:07.215890 http.c:815              <= Recv header, 0000000024 bytes (0x00000018)
11:12:07.216950 http.c:827              <= Recv header: Cache-Control: private
11:12:07.218928 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:12:07.219885 http.c:827              <= Recv header: Content-Type: text/html
11:12:07.226881 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:12:07.226881 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:12:07.229888 http.c:815              <= Recv header, 0000000115 bytes (0x00000073)
11:12:07.230882 http.c:827              <= Recv header: WWW-Authenticate: Bearer authorization_uri=https://login.microsoftonline.com/[TenantId]
11:12:07.231879 http.c:815              <= Recv header, 0000000071 bytes (0x00000047)
11:12:07.232880 http.c:827              <= Recv header: WWW-Authenticate: Basic realm="https://tfsprodweu6.visualstudio.com/"
11:12:07.233882 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:12:07.233882 http.c:827              <= Recv header: WWW-Authenticate: TFS-Federated
11:12:07.234880 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:12:07.235882 http.c:827              <= Recv header: X-TFS-ProcessId: [ProcessId]
11:12:07.236879 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:07.239878 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:12:07.239878 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:12:07.240878 http.c:827              <= Recv header: ActivityId: [SessionActivityId]
11:12:07.241878 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:12:07.241878 http.c:827              <= Recv header: X-TFS-Session: [SessionActivityId]
11:12:07.242877 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:12:07.242877 http.c:827              <= Recv header: X-VSS-E2EID: [SessionActivityId]
11:12:07.243877 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:07.243877 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [SenderDeploymentId]
11:12:07.243877 http.c:815              <= Recv header, 0000000029 bytes (0x0000001d)
11:12:07.244878 http.c:827              <= Recv header: X-FRAME-OPTIONS: SAMEORIGIN
11:12:07.244878 http.c:815              <= Recv header, 0000000059 bytes (0x0000003b)
11:12:07.245929 http.c:827              <= Recv header: X-TFS-FedAuthRealm: https://tfsprodweu6.visualstudio.com/
11:12:07.246879 http.c:815              <= Recv header, 0000000054 bytes (0x00000036)
11:12:07.246879 http.c:827              <= Recv header: X-TFS-FedAuthIssuer: https://dev.azure.com/[orgname]/
11:12:07.246879 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:07.247914 http.c:827              <= Recv header: X-VSS-AuthorizationEndpoint: https://vssps.dev.azure.com/[orgname]/
11:12:07.247914 http.c:815              <= Recv header, 0000000060 bytes (0x0000003c)
11:12:07.248911 http.c:827              <= Recv header: X-VSS-ResourceTenant: [TenantId]
11:12:07.248911 http.c:815              <= Recv header, 0000000710 bytes (0x000002c6)
11:12:07.249876 http.c:827              <= Recv header: X-TFS-SoapException: %3C%3Fxml%20version%3D%221.0%22%20encoding%3D%22utf-8%22%3F%3E%3Csoap%3AEnvelope%20xmlns%3Asoap%3D%22http%3A%2F%2Fwww.w3.org%2F2003%2F05%2Fsoap-envelope%22%3E%3Csoap%3ABody%3E%3Csoap%3AFault%3E%3Csoap%3ACode%3E%3Csoap%3AValue%3Esoap%3AReceiver%3C%2Fsoap%3AValue%3E%3Csoap%3ASubcode%3E%3Csoap%3AValue%3EUnauthorizedRequestException%3C%2Fsoap%3AValue%3E%3C%2Fsoap%3ASubcode%3E%3C%2Fsoap%3ACode%3E%3Csoap%3AReason%3E%3Csoap%3AText%20xml%3Alang%3D%22en%22%3ETF400813%3A%20The%20user%20%27aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa%27%20is%20not%20authorized%20to%20access%20this%20resource.%3C%2Fsoap%3AText%3E%3C%2Fsoap%3AReason%3E%3C%2Fsoap%3AFault%3E%3C%2Fsoap%3ABody%3E%3C%2Fsoap%3AEnvelope%3E
11:12:07.249876 http.c:815              <= Recv header, 0000000148 bytes (0x00000094)
11:12:07.250877 http.c:827              <= Recv header: X-TFS-ServiceError: TF400813%3A%20The%20user%20%27aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa%27%20is%20not%20authorized%20to%20access%20this%20resource.
11:12:07.250877 http.c:815              <= Recv header, 0000000079 bytes (0x0000004f)
11:12:07.252879 http.c:827              <= Recv header: X-VSS-S2STargetService: 00000002-0000-8888-8000-000000000000/visualstudio.com
11:12:07.254916 http.c:815              <= Recv header, 0000000554 bytes (0x0000022a)
11:12:07.255912 http.c:827              <= Recv header: X-TFS-FedAuthRedirect: https://spsprodweu2.vssps.visualstudio.com/_signin<redacted>
11:12:07.255912 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:07.256910 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appId]
11:12:07.256910 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:12:07.256910 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:12:07.257921 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:12:07.257921 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:12:07.257921 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:12:07.258907 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:12:07.258907 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:12:07.258907 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: 3A7BB75F0D844083B019F277954A93E3 Ref B: ZRHEDGE1913 Ref C: 2024-06-06T09:12:07Z
11:12:07.259918 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:12:07.259918 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:12:06 GMT
11:12:07.260909 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:12:07.260909 http.c:827              <= Recv header: Age: 1
11:12:07.260909 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:12:07.261908 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:12:07.261908 http.c:815              <= Recv header, 0000000023 bytes (0x00000017)
11:12:07.261908 http.c:827              <= Recv header: Content-Length: 89611
11:12:07.261908 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:12:07.262912 http.c:827              <= Recv header:
11:12:07.262912 http.c:868              == Info: Ignoring the response-body
11:12:07.262912 http.c:868              == Info: Connection #0 to host [proxy] left intact
11:12:07.262912 http.c:868              == Info: Issue another request to this URL: 'https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[projectname]info/refs?service=git-upload-pack'
11:12:07.263910 http.c:868              == Info: Couldn't find host dev.azure.com in the .netrc file; using defaults
11:12:07.263910 http.c:868              == Info: Found bundle for host: 0x205e4389d70 [serially]
11:12:07.263910 http.c:868              == Info: Can not multiplex, even if we wanted to
11:12:07.264906 http.c:868              == Info: Re-using existing connection with proxy [proxy]
11:12:07.264906 http.c:868              == Info: Server auth using Basic with user '[orgname]'
11:12:07.264906 http.c:815              => Send header, 0000000289 bytes (0x00000121)
11:12:07.264906 http.c:827              => Send header: GET /[orgname]/[projectname]_git/[projectname]info/refs?service=git-upload-pack HTTP/1.1
11:12:07.265875 http.c:827              => Send header: Host: dev.azure.com
11:12:07.265875 http.c:827              => Send header: Authorization: Basic <redacted>
11:12:07.265875 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:12:07.265875 http.c:827              => Send header: Accept: */*
11:12:07.266921 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:12:07.268909 http.c:827              => Send header: Pragma: no-cache
11:12:07.269909 http.c:827              => Send header: Git-Protocol: version=2
11:12:07.269909 http.c:827              => Send header:
11:12:07.558608 http.c:815              <= Recv header, 0000000027 bytes (0x0000001b)
11:12:07.558608 http.c:827              <= Recv header: HTTP/1.1 401 Unauthorized
11:12:07.559167 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:12:07.559167 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:12:07.559713 http.c:868              == Info: Authentication problem. Ignoring this.
11:12:07.560270 http.c:815              <= Recv header, 0000000071 bytes (0x00000047)
11:12:07.560270 http.c:827              <= Recv header: WWW-Authenticate: Basic realm="https://tfsprodweu6.visualstudio.com/"
11:12:07.560786 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:12:07.560786 http.c:827              <= Recv header: X-TFS-ProcessId: [processId]
11:12:07.561303 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:07.561303 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:12:07.561822 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:12:07.561822 http.c:827              <= Recv header: ActivityId: [activityId]
11:12:07.562496 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:12:07.562496 http.c:827              <= Recv header: X-TFS-Session: [activityId]
11:12:07.563034 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:12:07.563102 http.c:827              <= Recv header: X-VSS-E2EID: [activityId]
11:12:07.563621 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:07.563621 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [SenderDeploymentId]
11:12:07.563621 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:07.563621 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appId]
11:12:07.564140 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:12:07.564140 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:12:07.564140 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:12:07.564140 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:12:07.564140 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:12:07.564140 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:12:07.564685 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:12:07.564685 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: EDB949239FC54D778D94730D2A0141BF Ref B: ZRHEDGE1913 Ref C: 2024-06-06T09:12:07Z
11:12:07.564685 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:12:07.564685 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:12:06 GMT
11:12:07.565232 http.c:815              <= Recv header, 0000000019 bytes (0x00000013)
11:12:07.565232 http.c:827              <= Recv header: Content-Length: 0
11:12:07.565232 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:12:07.565232 http.c:827              <= Recv header: Age: 1
11:12:07.565232 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:12:07.565778 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:12:07.566298 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:12:07.566298 http.c:827              <= Recv header:
11:12:07.566869 http.c:868              == Info: Connection #0 to host [proxy] left intact
11:12:07.567903 run-command.c:724                 child_start[0] '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" get'
11:12:07.568439 run-command.c:657       trace: run_command: '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" get'
11:12:07.806421 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:07.818394 common-main.c:55                  version 2.45.2.windows.1
11:12:07.818394 common-main.c:56                  start 'C:/PortableGit/2.45.2both/mingw64/libexec/git-core\git.exe' config --null --list
11:12:07.883430 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:07.884427 git.c:465               trace: built-in: git config --null --list
11:12:07.884427 git.c:466                         cmd_name config (clone/_run_dashed_/remote-curl/config)
11:12:07.892395 git.c:724                         exit elapsed:0.086040 code:0
11:12:07.892395 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.086150 code:0
11:12:07.909427 Program.cs:56                     version 2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2
11:12:07.912424 Program.cs:56                     start git-credential-manager.exe get
11:12:08.003915 Program.cs:71                     exit elapsed:0.2937816 code:0
11:12:08.013436 run-command.c:977                 child_exit[0] pid:26936 code:0 elapsed:0.445638
11:12:08.013436 http.c:868              == Info: Found bundle for host: 0x205e4389d70 [serially]
11:12:08.013436 http.c:868              == Info: Can not multiplex, even if we wanted to
11:12:08.014435 http.c:868              == Info: Re-using existing connection with proxy [proxy]
11:12:08.014435 http.c:868              == Info: Server auth using Basic with user '[UserName]'
11:12:08.014435 http.c:815              => Send header, 0000000365 bytes (0x0000016d)
11:12:08.015435 http.c:827              => Send header: GET /[orgname]/[projectname]_git/[projectname]info/refs?service=git-upload-pack HTTP/1.1
11:12:08.015435 http.c:827              => Send header: Host: dev.azure.com
11:12:08.015435 http.c:827              => Send header: Authorization: Basic <redacted>
11:12:08.015435 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:12:08.015435 http.c:827              => Send header: Accept: */*
11:12:08.015435 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:12:08.015435 http.c:827              => Send header: Pragma: no-cache
11:12:08.016435 http.c:827              => Send header: Git-Protocol: version=2
11:12:08.016435 http.c:827              => Send header:
11:12:08.304950 http.c:815              <= Recv header, 0000000017 bytes (0x00000011)
11:12:08.304950 http.c:827              <= Recv header: HTTP/1.1 200 OK
11:12:08.308248 http.c:815              <= Recv header, 0000000024 bytes (0x00000018)
11:12:08.310278 http.c:827              <= Recv header: Cache-Control: private
11:12:08.311328 http.c:815              <= Recv header, 0000000059 bytes (0x0000003b)
11:12:08.312325 http.c:827              <= Recv header: Content-Type: application/x-git-upload-pack-advertisement
11:12:08.314287 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:12:08.315316 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:12:08.319286 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:12:08.325364 http.c:827              <= Recv header: X-TFS-ProcessId: [ProcessId]
11:12:08.326371 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:08.326371 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:12:08.326371 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:12:08.327372 http.c:827              <= Recv header: ActivityId: [activityId]
11:12:08.327372 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:12:08.327372 http.c:827              <= Recv header: X-TFS-Session: [activityId]
11:12:08.327372 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:12:08.328400 http.c:827              <= Recv header: X-VSS-E2EID: [activityId]
11:12:08.328400 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:08.328400 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [SenderDeploymentId]
11:12:08.328400 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:08.329397 http.c:827              <= Recv header: X-VSS-UserData: [usedataid]:[UserName]
11:12:08.329397 http.c:815              <= Recv header, 0000000029 bytes (0x0000001d)
11:12:08.329397 http.c:827              <= Recv header: X-FRAME-OPTIONS: SAMEORIGIN
11:12:08.329397 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:08.329397 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appId]
11:12:08.330373 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:12:08.330373 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:12:08.330373 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:12:08.330373 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:12:08.331405 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:12:08.331405 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:12:08.331405 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:12:08.331405 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: F6BC3493F4484ADC802577F5CB45A9D3 Ref B: ZRHEDGE1913 Ref C: 2024-06-06T09:12:08Z
11:12:08.332435 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:12:08.332435 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:12:07 GMT
11:12:08.332940 http.c:815              <= Recv header, 0000000021 bytes (0x00000015)
11:12:08.332940 http.c:827              <= Recv header: Content-Length: 729
11:12:08.332940 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:12:08.332940 http.c:827              <= Recv header: Age: 1
11:12:08.332940 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:12:08.333977 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:12:08.333977 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:12:08.333977 http.c:827              <= Recv header:
11:12:08.333977 http.c:868              == Info: Connection #0 to host [proxy] left intact
11:12:08.334978 run-command.c:724                 child_start[1] '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
11:12:08.334978 run-command.c:657       trace: run_command: '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
11:12:08.476248 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:08.488248 common-main.c:55                  version 2.45.2.windows.1
11:12:08.488248 common-main.c:56                  start 'C:/PortableGit/2.45.2both/mingw64/libexec/git-core\git.exe' config --null --list
11:12:08.548849 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:08.548849 git.c:465               trace: built-in: git config --null --list
11:12:08.548849 git.c:466                         cmd_name config (clone/_run_dashed_/remote-curl/config)
11:12:08.559625 git.c:724                         exit elapsed:0.083023 code:0
11:12:08.559625 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.083172 code:0
11:12:08.575658 Program.cs:56                     version 2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2
11:12:08.578642 Program.cs:56                     start git-credential-manager.exe store
fatal: Cannot determine the organization name for this 'dev.azure.com' remote URL. Ensure the `credential.useHttpPath` configuration value is set, or set the organization name as the user in the remote URL '{org}@dev.azure.com'.
11:12:08.669656 Program.cs:71                     exit elapsed:0.2406788 code:-1
11:12:08.679658 run-command.c:977                 child_exit[1] pid:28752 code:127 elapsed:0.345238
11:12:08.679658 run-command.c:724                 child_start[2] '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
11:12:08.680627 run-command.c:657       trace: run_command: '"C:/PortableGit/2.45.2both/mingw64/bin/git-credential-manager.exe" store'
11:12:08.814843 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:08.825842 common-main.c:55                  version 2.45.2.windows.1
11:12:08.825842 common-main.c:56                  start 'C:/PortableGit/2.45.2both/mingw64/libexec/git-core\git.exe' config --null --list
11:12:08.885842 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:08.885842 git.c:465               trace: built-in: git config --null --list
11:12:08.886843 git.c:466                         cmd_name config (clone/_run_dashed_/remote-curl/config)
11:12:08.898842 git.c:724                         exit elapsed:0.083916 code:0
11:12:08.898842 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.084371 code:0
11:12:08.914842 Program.cs:56                     version 2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2
11:12:08.916842 Program.cs:56                     start git-credential-manager.exe store
11:12:08.999154 Program.cs:71                     exit elapsed:0.2312793 code:0
11:12:09.008124 run-command.c:977                 child_exit[2] pid:36284 code:0 elapsed:0.328490
11:12:09.009122 pkt-line.c:86           packet:          git< # service=git-upload-pack
11:12:09.009122 pkt-line.c:86           packet:          git< 0000
11:12:09.009122 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
11:12:09.011123 pkt-line.c:86           packet:          git< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:12:09.011123 pkt-line.c:86           packet:          git< 0000
11:12:09.033153 pkt-line.c:86           packet:          git> 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:12:09.035124 pkt-line.c:86           packet:          git> 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:12:09.036146 pkt-line.c:86           packet:          git> 0000
11:12:09.036146 run-command.c:724                 child_start[3] git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[projectname]
11:12:09.036146 run-command.c:657       trace: run_command: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[projectname]
11:12:09.055125 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:09.066123 common-main.c:55                  version 2.45.2.windows.1
11:12:09.066123 common-main.c:56                  start git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[projectname]
11:12:09.105124 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:09.109124 git.c:465               trace: built-in: git fetch-pack --stateless-rpc --stdin --lock-pack --thin --check-self-contained-and-connected --cloning https://[orgname]@dev.azure.com/[orgname]/[projectname]_git/[projectname]
11:12:09.109124 git.c:466                         cmd_name fetch-pack (clone/_run_dashed_/remote-curl/fetch-pack)
11:12:09.109124 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:12:09.111124 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:12:09.112123 pkt-line.c:86           packet:   fetch-pack< 0000
11:12:09.112123 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 HEAD\0 multi_ack thin-pack side-band side-band-64k no-progress multi_ack_detailed no-done shallow allow-tip-sha1-in-want filter symref=HEAD:refs/heads/main
11:12:09.112123 pkt-line.c:86           packet:   fetch-pack< 284375f673bb7bb2c3574f1896eb590b2da64843 refs/heads/main
11:12:09.113123 pkt-line.c:86           packet:   fetch-pack< 0000
11:12:09.117124 pkt-line.c:86           packet:   fetch-pack> want 7b4c63188e7335a4eed9225a500703509eddb2ec multi_ack_detailed no-done side-band-64k thin-pack
11:12:09.118124 pkt-line.c:86           packet:   fetch-pack> want 284375f673bb7bb2c3574f1896eb590b2da64843
11:12:09.119124 pkt-line.c:86           packet:   fetch-pack> 0000
11:12:09.119124 pkt-line.c:86           packet:   fetch-pack> done
11:12:09.120125 pkt-line.c:86           packet:   fetch-pack> 0000
11:12:09.120125 pkt-line.c:86           packet:          git< 0065want 7b4c63188e7335a4eed9225a500703509eddb2ec multi_ack_detailed no-done side-band-64k thin-pack0032want a2b10484ef8c0bbd8b83448cb4d2fa0af3ebe21e0032want 2295c8a86cef38646f07314b9ec6ad44c23d53da0032want b5143bfecf4c15d76064ec748ac9936615427efd0032want 284375f673bb7bb2c3574f1896eb590b2da648430032want 0d04bdfef3dd4399455406bf580fb71dd694b0270032want a132742d74b7de80b6bb038e8237d8ba6ab7385500000009done
11:12:09.120125 pkt-line.c:86           packet:          git< 0000
11:12:09.121124 http.c:868              == Info: Found bundle for host: 0x205e4389d70 [serially]
11:12:09.121124 http.c:868              == Info: Can not multiplex, even if we wanted to
11:12:09.121124 http.c:868              == Info: Re-using existing connection with proxy [proxy]
11:12:09.121124 http.c:868              == Info: Server auth using Basic with user '[UserName]'
11:12:09.122125 http.c:815              => Send header, 0000000412 bytes (0x0000019c)
11:12:09.122125 http.c:827              => Send header: POST /[orgname]/[projectname]_git/[projectname]git-upload-pack HTTP/1.1
11:12:09.122125 http.c:827              => Send header: Host: dev.azure.com
11:12:09.123125 http.c:827              => Send header: Authorization: Basic <redacted>
11:12:09.123125 http.c:827              => Send header: User-Agent: git/2.45.2.windows.1
11:12:09.123125 http.c:827              => Send header: Accept-Encoding: deflate, gzip, br, zstd
11:12:09.123125 http.c:827              => Send header: Content-Type: application/x-git-upload-pack-request
11:12:09.124125 http.c:827              => Send header: Accept: application/x-git-upload-pack-result
11:12:09.124125 http.c:827              => Send header: Content-Length: 414
11:12:09.124125 http.c:827              => Send header:
11:12:09.646017 http.c:815              <= Recv header, 0000000017 bytes (0x00000011)
11:12:09.646017 http.c:827              <= Recv header: HTTP/1.1 200 OK
11:12:09.647018 http.c:815              <= Recv header, 0000000024 bytes (0x00000018)
11:12:09.647018 http.c:827              <= Recv header: Cache-Control: private
11:12:09.647018 http.c:815              <= Recv header, 0000000052 bytes (0x00000034)
11:12:09.648019 http.c:827              <= Recv header: Content-Type: application/x-git-upload-pack-result
11:12:09.648307 http.c:815              <= Recv header, 0000000124 bytes (0x0000007c)
11:12:09.648307 http.c:827              <= Recv header: P3P: CP="CAO DSP COR ADMa DEV CONo TELo CUR PSA PSD TAI IVDo OUR SAMi BUS DEM NAV STA UNI COM INT PHY ONL FIN PUR LOC CNT"
11:12:09.648307 http.c:815              <= Recv header, 0000000055 bytes (0x00000037)
11:12:09.648307 http.c:827              <= Recv header: X-TFS-ProcessId: [processid]
11:12:09.648307 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:09.648307 http.c:827              <= Recv header: Strict-Transport-Security: max-age=31536000; includeSubDomains
11:12:09.648307 http.c:815              <= Recv header, 0000000050 bytes (0x00000032)
11:12:09.649316 http.c:827              <= Recv header: ActivityId: [sessionid]
11:12:09.649316 http.c:815              <= Recv header, 0000000053 bytes (0x00000035)
11:12:09.649316 http.c:827              <= Recv header: X-TFS-Session: [sessionid]
11:12:09.649316 http.c:815              <= Recv header, 0000000051 bytes (0x00000033)
11:12:09.649316 http.c:827              <= Recv header: X-VSS-E2EID: [sessionid]
11:12:09.649316 http.c:815              <= Recv header, 0000000064 bytes (0x00000040)
11:12:09.649316 http.c:827              <= Recv header: X-VSS-SenderDeploymentId: [SenderDeploymentId]
11:12:09.649316 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:09.650328 http.c:827              <= Recv header: X-VSS-UserData: [usedataid]:[UserName]
11:12:09.650328 http.c:815              <= Recv header, 0000000029 bytes (0x0000001d)
11:12:09.650328 http.c:827              <= Recv header: X-FRAME-OPTIONS: SAMEORIGIN
11:12:09.650328 http.c:815              <= Recv header, 0000000068 bytes (0x00000044)
11:12:09.650328 http.c:827              <= Recv header: Request-Context: appId=cid-v1:[appId]
11:12:09.650328 http.c:815              <= Recv header, 0000000048 bytes (0x00000030)
11:12:09.650328 http.c:827              <= Recv header: Access-Control-Expose-Headers: Request-Context
11:12:09.650328 http.c:815              <= Recv header, 0000000033 bytes (0x00000021)
11:12:09.651315 http.c:827              <= Recv header: X-Content-Type-Options: nosniff
11:12:09.651315 http.c:815              <= Recv header, 0000000025 bytes (0x00000019)
11:12:09.651315 http.c:827              <= Recv header: X-Cache: CONFIG_NOCACHE
11:12:09.651315 http.c:815              <= Recv header, 0000000102 bytes (0x00000066)
11:12:09.651315 http.c:827              <= Recv header: X-MSEdge-Ref: Ref A: 6C9D69F841874B2792F59FE64794D602 Ref B: ZRHEDGE1719 Ref C: 2024-06-06T09:12:09Z
11:12:09.651315 http.c:815              <= Recv header, 0000000037 bytes (0x00000025)
11:12:09.651315 http.c:827              <= Recv header: Date: Thu, 06 Jun 2024 09:12:09 GMT
11:12:09.651315 http.c:815              <= Recv header, 0000000008 bytes (0x00000008)
11:12:09.651315 http.c:827              <= Recv header: Age: 0
11:12:09.651315 http.c:815              <= Recv header, 0000000019 bytes (0x00000013)
11:12:09.652314 http.c:827              <= Recv header: Connection: close
11:12:09.652314 http.c:815              <= Recv header, 0000000040 bytes (0x00000028)
11:12:09.652314 http.c:827              <= Recv header: Via: HTTPS/1.1 [proxyFQDN]
11:12:09.652314 http.c:815              <= Recv header, 0000000002 bytes (0x00000002)
11:12:09.652314 http.c:827              <= Recv header:
11:12:09.652314 pkt-line.c:86           packet:   fetch-pack< NAK
11:12:09.653316 pkt-line.c:86           packet:   fetch-pack> 0000
11:12:09.653316 pkt-line.c:86           packet:     sideband< \2Azure Repos
remote: Azure Repos
11:12:09.654316 pkt-line.c:86           packet:     sideband< \2\15Found 1397 objects to send. (151 ms)
remote: Found 1397 objects to send. (151 ms)
11:12:09.654316 pkt-line.c:86           packet:     sideband< PACK ...
11:12:09.655315 run-command.c:724                 child_start[0] git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29836 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:12:09.655315 run-command.c:657       trace: run_command: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29836 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:12:09.675316 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:09.686316 common-main.c:55                  version 2.45.2.windows.1
11:12:09.686316 common-main.c:56                  start git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29836 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:12:09.735201 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:09.741662 git.c:465               trace: built-in: git index-pack --stdin -v --fix-thin '--keep=fetch-pack 29836 on [PCHost]' --check-self-contained-and-connected --pack_header=2,1397
11:12:09.741662 git.c:466                         cmd_name index-pack (clone/_run_dashed_/remote-curl/fetch-pack/index-pack)
11:12:09.778709 http.c:868              == Info: Closing connection
11:12:09.778709 http.c:868              == Info: TLSv1.2 (OUT), TLS alert, close notify (256):
11:12:09.779709 pkt-line.c:86           packet:          git< 0000
11:12:09.780734 pkt-line.c:86           packet:     sideband< 0000
Receiving objects: 100% (1397/1397), 293.39 KiB | 10.12 MiB/s, done.
Resolving deltas: 100% (896/896), done.
11:12:09.824712 git.c:724                         exit elapsed:0.149219 code:0
11:12:09.824712 trace2/tr2_tgt_normal.c:371       counter fsync/hardware-flush value:3
11:12:09.825711 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.149372 code:0
11:12:09.830602 run-command.c:977                 child_exit[0] pid:28208 code:0 elapsed:0.175243
11:12:09.831484 git.c:724                         exit elapsed:0.776315 code:0
11:12:09.831484 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.776432 code:0
11:12:09.836558 run-command.c:977                 child_exit[3] pid:29836 code:0 elapsed:0.800317
11:12:09.837593 run-command.c:724                 child_start[1] git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
11:12:09.837593 run-command.c:657       trace: run_command: git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
11:12:09.861087 exec-cmd.c:243          trace: resolved executable dir: C:/PortableGit/2.45.2both/mingw64/libexec/git-core
11:12:09.872344 common-main.c:55                  version 2.45.2.windows.1
11:12:09.872344 common-main.c:56                  start git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
11:12:09.917769 repository.c:158                  worktree C:/PortableGit/2.45.2both
11:12:09.921769 git.c:465               trace: built-in: git rev-list --objects --stdin --not --all --quiet --alternate-refs '--progress=Checking connectivity'
11:12:09.921769 git.c:466                         cmd_name rev-list (clone/rev-list)
11:12:09.931774 git.c:724                         exit elapsed:0.071521 code:0
11:12:09.931774 trace2/tr2_tgt_normal.c:128       atexit elapsed:0.071740 code:0
11:12:09.938772 run-command.c:977                 child_exit[1] pid:10864 code:0 elapsed:0.101042
11:12:09.981006 common-main.c:65                  exit elapsed:3.156731 code:0
11:12:09.982036 trace2/tr2_tgt_normal.c:128       atexit elapsed:3.157283 code:0
11:12:09.985036 run-command.c:977                 child_exit[0] pid:12876 code:0 elapsed:3.181680
11:12:09.986005 git.c:766                         exit elapsed:3.232718 code:0
11:12:09.986005 trace2/tr2_tgt_normal.c:128       atexit elapsed:3.232839 code:0
11:12:09.989005 run-command.c:977                 child_exit[0] pid:7100 code:0 elapsed:3.257003
11:12:10.070006 git.c:724                         exit elapsed:3.563616 code:0
11:12:10.070006 trace2/tr2_tgt_normal.c:128       atexit elapsed:3.563745 code:0

@bagder
Copy link
Member

bagder commented Jun 6, 2024

Also, peculiar that you need to change both libcurl and openssl versions to have it working again.

This is peculiar indeed. If the problem is in libcurl, surely it would only be necessary to change libcurl?

@dscho
Copy link
Contributor

dscho commented Jun 11, 2024

The libcurl we had to replace the problematic one was compiled against that other OpenSSL, therefore both need to be replaced (otherwise the process would fail to start due to a runtime link error).

@dscho
Copy link
Contributor

dscho commented Jun 11, 2024

@tgemvz what are the chances that you could build a custom libcurl in Git for Windows' SDK? If you could set that up, it should be possible to bisect this to the commit that causes the behavior you observe.

@dscho
Copy link
Contributor

dscho commented Jun 11, 2024

what are the chances that you could build a custom libcurl in Git for Windows' SDK? If you could set that up, it should be possible to bisect this to the commit that causes the behavior you observe.

@tgemvz what I am thinking of is to:

  1. install Git for Windows' SDK,
  2. sdk cd mingw-w64-curl,
  3. git clone https://github.com/curl/curl
  4. cd curl
  5. git switch -d curl-8_8_0
  6. autoreconf -fiv
  7. ./configure --disable-static --enable-shared --with-ssl
  8. build via make -j$(nproc)
  9. test after copying lib/.libs/libcurl-4.dll to the Portable Git and test whether it works
  10. git switch -d curl-8_7_0 and repeat steps 6-9
  11. If, as I would expect, 8.7.0 is "good" and 8.8.0 is "bad", start a git bisect session, repeating steps 6-9 to determine whether to continue with git bisect good or git bisect bad

@tgemvz
Copy link
Author

tgemvz commented Jun 12, 2024

@dscho Thanks for your input!
I installed the sdk and
did all steps
build of curl-8_8_0 did succeed with same expected outcome when replacing freshly build DLL
--> error

tried switching to curl-8_7_0 and repeated steps 6. and 7.
sadly make did error out:

$ make -j$(nproc)
Making all in lib
make[1]: Entering directory '/usr/src/MINGW-packages/mingw-w64-curl/curl/lib'
make  all-am
make[2]: Entering directory '/usr/src/MINGW-packages/mingw-w64-curl/curl/lib'
  CC       libcurl_la-nonblock.lo
  CC       libcurl_la-sendf.lo
  CC       libcurl_la-setopt.lo
  CC       libcurl_la-sha256.lo
  CC       libcurl_la-share.lo
  CC       libcurl_la-slist.lo
  CC       libcurl_la-smtp.lo
  CC       libcurl_la-smb.lo
nonblock.c: In function 'curlx_nonblock':
nonblock.c:82:4: error: #error "no non-blocking method was found/used/set"
   82 | #  error "no non-blocking method was found/used/set"
      |    ^~~~~
make[2]: *** [Makefile:2824: libcurl_la-nonblock.lo] Error 1
make[2]: *** Waiting for unfinished jobs....
make[2]: Leaving directory '/usr/src/MINGW-packages/mingw-w64-curl/curl/lib'
make[1]: *** [Makefile:1536: all] Error 2
make[1]: Leaving directory '/usr/src/MINGW-packages/mingw-w64-curl/curl/lib'
make: *** [Makefile:1267: all-recursive] Error 1

What did I miss?

@bagder
Copy link
Member

bagder commented Jun 12, 2024

Grrr, the world is a complicated place. I assume using gcc 14? It made some default behaviors more strict so the configure checks stopped working like before. We fixed this in b65f0e0 (#13587)

@dscho
Copy link
Contributor

dscho commented Jun 12, 2024

nonblock.c: In function 'curlx_nonblock':
nonblock.c:82:4: error: #error "no non-blocking method was found/used/set"
   82 | #  error "no non-blocking method was found/used/set"
      |    ^~~~~

I had encountered that before, and "fixed" it by forcing HAVE_IOCTLSOCKET_FIONBIO to be defined in lib/curl_config.h, like so:

/* Define to 1 if you have a working ioctlsocket FIONBIO function. */
#define HAVE_IOCTLSOCKET_FIONBIO 1

I do not quite understand why that was necessary; I chalked it up to autoconf being... autoconf.

@dscho
Copy link
Contributor

dscho commented Jun 12, 2024

I assume using gcc 14?

Yes, Git for Windows' SDK (which really is a slightly modified version of MSYS2) comes with GCC v14.*.

@tgemvz
Copy link
Author

tgemvz commented Jun 12, 2024

Tried to "integrate" the fix (changing int to unsigned long)
Then i ran
autoreconf -fiv
and
./configure --disable-static --enable-shared --with-ssl
again.

output

configure: Configured to build curl/libcurl:
[...]
curl version:     8.7.0-DEV
[...]

running make -j$(nproc) does finish, BUT the created file libcurl-4.dll in curl/lib/.libs still shows
Version 8.8.0.0
and
Product Version 8.8.0-DEV

When exchanging the newly build libcurl-4.dll with the one in portablegit\mingw64\libexec\git-core the error still occurs.

Is my build "wrong" ?
Does it matter that I "only" try to build and replace libcurl-4.dll and not also libcurl-openssl-4.dll?

Again thanks for all your efforts!

@dscho
Copy link
Contributor

dscho commented Jun 12, 2024

running make -j$(nproc) does finish, BUT the created file libcurl-4.dll in curl/lib/.libs still shows
Version 8.8.0.0
and
Product Version 8.8.0-DEV

Hmm. You may need to use the "big hammer" of make clean && make -j$(nproc).

@tgemvz
Copy link
Author

tgemvz commented Jun 13, 2024

make clean did help :)

But I am unsure if our "methodology" is corect: (same question as yesterday):

I went back as far as trying to build a libcur-4.dll Version 8.5.0 always leading to the same error: RPC failed; curl 56 OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0

@dscho
When building and replacing libcurl-4.dll in portablegit\mingw64\libexec\git-core what should I do about libcurl-openssl-4.dll ?
Why are they "seperated"?

@bagder
Copy link
Member

bagder commented Jun 13, 2024

Generally, the "SSL_ERROR_SYSCALL" error is returned when the TCP connection is abruptly getting a RST and similar drastic things. I don't think libcurl can even trigger it to happen but is something OpenSSL figures out and reports itself.

@bagder bagder changed the title curl rpc 56 errono 0 when using git clone curl rpc 56 errno 0 when using git clone Jun 13, 2024
@dscho
Copy link
Contributor

dscho commented Jun 20, 2024

I went back as far as trying to build a libcur-4.dll Version 8.5.0 always leading to the same error: RPC failed; curl 56 OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 0

That would suggest to me that the OpenSSL version upgrade might have introduced an undesirable change of behavior.

When building and replacing libcurl-4.dll in portablegit\mingw64\libexec\git-core what should I do about libcurl-openssl-4.dll ?

Ideally, delete it (for testing purposes). Since you built libcurl-4.dll with support for the OpenSSL backend, Git for Windows should be happy with that library instead of trying to link libcurl-openssl-4.dll dynamically.

Why are they "seperated"?

They are separated for multiple reasons, the most important being called "DLL hell". Having them separated allows the Git for Windows project to update OpenSSL separately from having to rebuild the curl package, by using the Secure Channel backend in the automation. If the DLLs were not separate, libcurl-4.dll would not even load as soon as OpenSSL is upgraded to a new major version (because the version number is encoded in the DLLs' filenames), even if the intention is to use the Secure Channel backend. That would prevent the git push that is part of the automated workflow to build Git for Windows' packages (including OpenSSL).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

4 participants