We're experiencing hangs on Git operations (pull/push etc.) on all our Google Source Repositories since around November 2020. It usually happens 1-2 times out of 10.
We're experiencing this on different computers (both with Ubuntu and Fedora OS with totally different configuration environments) located in 2 different offices in different countries (which all have unfiltered, good quality, regular internet access and we don't use VPNs, so network issues can be ruled out). Changing IPv6/IPv4 connectivity does not seem to affect this.
The fetch and push URLs for our repositories look like this:
ssh://[email protected]:2022/p/xxx/r/yyy
(We've replaced the email, project name with xxx and the repo name with yyy)
We've tried the following:
- Setting the http.postBuffer both to 524288000 and 5000 but this does not affect the issue (we know that SSH is used but we gave this a shot).
- Running
gcloud auth loginagain to refresh credentials
Here's a git pull log excerpt which hangs for minutes, but eventually finished with a success:
febr 10 09:51:41 debug2: channel 0: request env confirm 0
febr 10 09:51:41 debug3: send packet: type 98
febr 10 09:51:41 debug3: Ignored env OSP_KSDK_PATH
febr 10 09:51:41 debug3: Ignored env QT_PLATFORM_PLUGIN
febr 10 09:51:41 debug3: Ignored env VTE_VERSION
febr 10 09:51:41 debug1: Sending command: git-upload-pack '/p/xxx/r/yyy'
febr 10 09:51:41 debug2: channel 0: request exec confirm 1
febr 10 09:51:41 debug3: send packet: type 98
febr 10 09:51:41 debug2: channel_input_open_confirmation: channel 0: callback done
febr 10 09:51:41 debug2: channel 0: open confirm rwindow 2097152 rmax 32768
febr 10 09:51:41 debug3: receive packet: type 99
febr 10 09:51:41 debug2: channel_input_status_confirm: type 99 id 0
febr 10 09:51:41 debug2: exec request accepted on channel 0
febr 10 09:55:08 debug2: channel 0: read<=0 rfd 4 len 0
febr 10 09:55:08 debug2: channel 0: read failed
febr 10 09:55:08 debug2: channel 0: chan_shutdown_read (i0 o0 sock -1 wfd 4 efd 6 [write])
febr 10 09:55:08 debug2: channel 0: input open -> drain
febr 10 09:55:08 debug2: channel 0: ibuf empty
febr 10 09:55:08 debug2: channel 0: send eof
febr 10 09:55:08 debug3: send packet: type 96
febr 10 09:55:08 debug2: channel 0: input drain -> closed
febr 10 09:55:08 debug2: channel 0: rcvd adjust 4
febr 10 10:05:08 debug3: receive packet: type 98
febr 10 10:05:08 debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
febr 10 10:05:08 debug2: channel 0: rcvd ext data 39
febr 10 10:05:08 CANCELLED The operation was cancelled.
febr 10 10:05:08 debug2: channel 0: written 39 to efd 6
febr 10 10:05:08 debug2: channel 0: rcvd ext data 112
febr 10 10:05:08 debug2: channel 0: rcvd ext data 99
febr 10 10:05:08 debug3: receive packet: type 97
febr 10 10:05:08 debug2: channel 0: rcvd close
febr 10 10:05:08 debug2: channel 0: output open -> drain
febr 10 10:05:08 debug3: channel 0: will not send data after close
febr 10 10:05:08 debug2: channel 0: obuf_empty delayed efd 6/(211)
febr 10 10:05:08 [type.googleapis.com/devtools.gerritcodereview.proto.GerritCodeReviewError]: {
febr 10 10:05:08 error_type: CLIENT_TIMED_OUT
febr 10 10:05:08 }
febr 10 10:05:08 [type.googleapis.com/google.rpc.RequestInfo]: {
febr 10 10:05:08 request_id: "d4c27f7f36644520a0da17841c907b00"
febr 10 10:05:08 }
febr 10 10:05:08 debug2: channel 0: written 211 to efd 6
febr 10 10:05:08 debug3: channel 0: will not send data after close
febr 10 10:05:08 debug2: channel 0: obuf empty
febr 10 10:05:08 debug2: channel 0: chan_shutdown_write (i3 o1 sock -1 wfd 5 efd 6 [write])
febr 10 10:05:08 debug2: channel 0: output drain -> closed
febr 10 10:05:08 debug2: channel 0: almost dead
febr 10 10:05:08 debug2: channel 0: gc: notify user
febr 10 10:05:08 debug2: channel 0: gc: user detached
febr 10 10:05:08 debug2: channel 0: send close
febr 10 10:05:08 debug3: send packet: type 97
febr 10 10:05:08 debug2: channel 0: is dead
febr 10 10:05:08 debug2: channel 0: garbage collecting
febr 10 10:05:08 debug1: channel 0: free: client-session, nchannels 1
febr 10 10:05:08 debug3: channel 0: status: The following connections are open:
febr 10 10:05:08 #0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1)
febr 10 10:05:08
febr 10 10:05:08 debug3: send packet: type 1
febr 10 10:05:08 debug1: fd 0 clearing O_NONBLOCK
febr 10 10:05:08 debug3: fd 1 is not O_NONBLOCK
febr 10 10:05:08 Transferred: sent 3816, received 2100 bytes, in 807.1 seconds
febr 10 10:05:08 Bytes per second: sent 4.7, received 2.6
febr 10 10:05:08 debug1: Exit status 1
febr 10 10:05:08 Already up to date.
Here's an excerpt which hangs for minutes and fails with an auth error (sometimes this happens, sometimes it completes like in the previous log):
febr 10 09:39:34 debug1: Sending env LC_PAPER = hu_HU.UTF-8
febr 10 09:39:34 debug2: channel 0: request env confirm 0
febr 10 09:39:34 debug3: send packet: type 98
febr 10 09:39:34 debug3: Ignored env OSP_KSDK_PATH
febr 10 09:39:34 debug3: Ignored env QT_PLATFORM_PLUGIN
febr 10 09:39:34 debug3: Ignored env VTE_VERSION
febr 10 09:39:34 debug1: Sending command: git-upload-pack '/p/xxx/r/yyy'
febr 10 09:39:34 debug2: channel 0: request exec confirm 1
febr 10 09:39:34 debug3: send packet: type 98
febr 10 09:39:34 debug2: channel_input_open_confirmation: channel 0: callback done
febr 10 09:39:34 debug2: channel 0: open confirm rwindow 2097152 rmax 32768
febr 10 09:39:34 debug3: receive packet: type 99
febr 10 09:39:34 debug2: channel_input_status_confirm: type 99 id 0
febr 10 09:39:34 debug2: exec request accepted on channel 0
febr 10 09:45:07 debug3: receive packet: type 98
febr 10 09:45:07 debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
febr 10 09:45:07 debug2: channel 0: rcvd ext data 232
febr 10 09:45:07 debug2: channel 0: rcvd ext data 125
febr 10 09:45:07 UNAUTHENTICATED Request is missing required authentication credential. Expected OAuth 2 access token, login cookie or other
valid authentication credential. See https://developers.google.com/identity/sign-in/web/devconsole-project.
febr 10 09:45:07 [type.googleapis.com/devtools.gerritcodereview.proto.GerritCodeReviewError]: {
febr 10 09:45:07 error_type: CREDENTIAL_LIFETIME_TOO_SHORT
febr 10 09:45:07 }
febr 10 09:45:07 debug2: channel 0: written 357 to efd 6
febr 10 09:45:07 debug2: channel 0: rcvd ext data 99
febr 10 09:45:07 debug3: receive packet: type 97
febr 10 09:45:07 debug2: channel 0: rcvd close
febr 10 09:45:07 debug2: channel 0: output open -> drain
febr 10 09:45:07 debug2: channel 0: chan_shutdown_read (i0 o1 sock -1 wfd 4 efd 6 [write])
febr 10 09:45:07 debug2: channel 0: input open -> closed
febr 10 09:45:07 debug3: channel 0: will not send data after close
febr 10 09:45:07 debug2: channel 0: obuf_empty delayed efd 6/(99)
febr 10 09:45:07 [type.googleapis.com/google.rpc.RequestInfo]: {
febr 10 09:45:07 request_id: "5e3ea7c0a78442ff9a1aca05f8d36c5e"
febr 10 09:45:07 }
febr 10 09:45:07 debug2: channel 0: written 99 to efd 6
febr 10 09:45:07 debug3: channel 0: will not send data after close
febr 10 09:45:07 debug2: channel 0: obuf empty
febr 10 09:45:07 debug2: channel 0: chan_shutdown_write (i3 o1 sock -1 wfd 5 efd 6 [write])
febr 10 09:45:07 debug2: channel 0: output drain -> closed
febr 10 09:45:07 debug2: channel 0: almost dead
febr 10 09:45:07 debug2: channel 0: gc: notify user
febr 10 09:45:07 debug2: channel 0: gc: user detached
febr 10 09:45:07 debug2: channel 0: send close
febr 10 09:45:07 debug3: send packet: type 97
febr 10 09:45:07 debug2: channel 0: is dead
febr 10 09:45:07 debug2: channel 0: garbage collecting
febr 10 09:45:07 debug1: channel 0: free: client-session, nchannels 1
febr 10 09:45:07 debug3: channel 0: status: The following connections are open:
febr 10 09:45:07 #0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1)
febr 10 09:45:07
febr 10 09:45:07 debug3: send packet: type 1
febr 10 09:45:07 debug1: fd 0 clearing O_NONBLOCK
febr 10 09:45:07 debug3: fd 1 is not O_NONBLOCK
febr 10 09:45:07 Transferred: sent 3768, received 1924 bytes, in 333.8 seconds
febr 10 09:45:07 Bytes per second: sent 11.3, received 5.8
febr 10 09:45:07 debug1: Exit status 16
febr 10 09:45:07 fatal: Could not read from remote repository.
febr 10 09:45:07
febr 10 09:45:07 Please make sure you have the correct access rights
febr 10 09:45:07 and the repository exists.
Does anyone know what we should try to eliminate this occasional hang?
Please be sure of using the latest Cloud SDK tools latest release is 327.0.0 https://cloud.google.com/sdk/docs/release-notes
I can see a change in the Cloud Repositories in November.
Update and test your processes.