Show GIT_TRACE for git command in bot_update.py

GIT_TRACE=true tells us which internal git command is slow.
https://git-scm.com/book/en/v2/Git-Internals-Environment-Variables

I got following results in my local repository.
Let me confirm the bots show similar behavior.

C:\src\chromium\src>set GIT_TRACE=true

C:\src\chromium\src>git rebase-update
21:32:36.519698 git.c:576               trace: exec: 'git-rebase-update'
21:32:36.519698 run-command.c:626       trace: run_command: 'git-rebase-update'
21:32:38.889848 git.c:344               trace: built-in: git 'fetch' '--multiple' 'origin'
21:32:38.893846 run-command.c:626       trace: run_command: 'fetch' '--append' 'origin'
Fetching origin
21:32:38.911858 git.c:344               trace: built-in: git 'fetch' '--append' 'origin'
21:32:38.983909 run-command.c:626       trace: run_command: 'remote-https' 'origin' 'https://chromium.googlesource.com/chromium/src.git'
21:32:39.002923 git.c:576               trace: exec: 'git-remote-https' 'origin' 'https://chromium.googlesource.com/chromium/src.git'
21:32:39.003923 run-command.c:626       trace: run_command: 'git-remote-https' 'origin' 'https://chromium.googlesource.com/chromium/src.git'
21:32:43.782266 run-command.c:626       trace: run_command: 'rev-list' '--objects' '--stdin' '--not' '--all' '--quiet'
21:32:43.827301 run-command.c:626       trace: run_command: 'fetch-pack' '--stateless-rpc' '--stdin' '--lock-pack' '--include-tag' '--thin' 'https://chromium.googlesource.com/chromium/src.git/'
remote: Counting objects: 74400, done
remote: Finding sources: 100% (19/19)
21:35:49.348951 run-command.c:626       trace: run_command: 'unpack-objects' '--pack_header=2,19'
21:35:49.368985 git.c:344               trace: built-in: git 'unpack-objects' '--pack_header=2,19'
remote: Total 19 (delta 1), reused 18 (delta 1)
Unpacking objects: 100% (19/19), done.
21:35:49.597328 run-command.c:626       trace: run_command: 'rev-list' '--objects' '--stdin' '--not' '--all' '--quiet'
21:35:49.612375 git.c:344               trace: built-in: git 'rev-list' '--objects' '--stdin' '--not' '--all' '--quiet'
From https://chromium.googlesource.com/chromium/src
   e8994685157b..fd56d3ad0528  master     -> origin/master
21:35:50.281845 run-command.c:1452      run_processes_parallel: preparing to run up to 1 tasks
21:35:50.287848 run-command.c:1484      run_processes_parallel: done
21:35:50.309865 run-command.c:626       trace: run_command: 'gc' '--auto'
21:35:50.328880 git.c:344               trace: built-in: git 'gc' '--auto'
21:35:50.453967 run-command.c:1452      run_processes_parallel: preparing to run up to 1 tasks
21:35:50.460971 run-command.c:1484      run_processes_parallel: done
21:35:50.460971 run-command.c:626       trace: run_command: 'gc' '--auto'
21:35:50.480985 git.c:344               trace: built-in: git 'gc' '--auto'
Rebasing: direct_goma
Rebasing: python_pool

C:\src\chromium\src>git fetch
21:36:23.409703 git.c:344               trace: built-in: git 'fetch'
21:36:23.486758 run-command.c:626       trace: run_command: 'remote-https' 'origin' 'https://chromium.googlesource.com/chromium/src.git'
21:36:23.506772 git.c:576               trace: exec: 'git-remote-https' 'origin' 'https://chromium.googlesource.com/chromium/src.git'
21:36:23.506772 run-command.c:626       trace: run_command: 'git-remote-https' 'origin' 'https://chromium.googlesource.com/chromium/src.git'
21:36:28.542596 run-command.c:626       trace: run_command: 'rev-list' '--objects' '--stdin' '--not' '--all' '--quiet'
21:36:28.578620 run-command.c:626       trace: run_command: 'fetch-pack' '--stateless-rpc' '--stdin' '--lock-pack' '--include-tag' '--thin' 'https://chromium.googlesource.com/chromium/src.git/'
21:36:28.601635 git.c:344               trace: built-in: git 'fetch-pack' '--stateless-rpc' '--stdin' '--lock-pack' '--include-tag' '--thin' 'https://chromium.googlesource.com/chromium/src.git/'
remote: Counting objects: 67598, done
remote: Finding sources: 100% (28/28)
21:39:29.787441 run-command.c:626       trace: run_command: 'unpack-objects' '--pack_header=2,28'
21:39:29.812462 git.c:344               trace: built-in: git 'unpack-objects' '--pack_header=2,28'
remote: Total 28 (delta 2), reused 20 (delta 2)
Unpacking objects: 100% (28/28), done.
21:39:30.083690 run-command.c:626       trace: run_command: 'rev-list' '--objects' '--stdin' '--not' '--all' '--quiet'
21:39:30.108704 git.c:344               trace: built-in: git 'rev-list' '--objects' '--stdin' '--not' '--all' '--quiet'
From https://chromium.googlesource.com/chromium/src
   fd56d3ad0528..fbcc09282dc8  master     -> origin/master
21:39:30.788186 run-command.c:1452      run_processes_parallel: preparing to run up to 1 tasks
21:39:30.795191 run-command.c:1484      run_processes_parallel: done
21:39:30.813200 run-command.c:626       trace: run_command: 'gc' '--auto'
21:39:30.836212 git.c:344               trace: built-in: git 'gc' '--auto'


Bug:749709
Change-Id: I5b94549c42271885365c2354dc3f58399d6aebe0
Reviewed-on: https://chromium-review.googlesource.com/786691Reviewed-by: Ryan Tseng <hinoka@chromium.org>
Commit-Queue: Takuto Ikuta <tikuta@google.com>

recipes/recipe_modules/bot_update/resources/bot_update.py

@@ -620,7 +620,11 @@ def _git_checkout(sln, sln_dir, revisions, shallow, refs, git_cache_dir,
   deadline = time.time() + 60
   tries = 0
   while True:
-    git(*populate_cmd)
+    # TODO(tikuta): remove env for GIT_TRACE after fixing crbug.com/749709
+    env = {}
+    if url == CHROMIUM_SRC_URL or url + '.git' == CHROMIUM_SRC_URL:
+      env = {'GIT_TRACE': 'true'}
+    git(*populate_cmd, env=env)
     mirror_dir = git(
         'cache', 'exists', '--quiet',
         '--cache-dir', git_cache_dir, url).strip()
@@ -638,10 +642,10 @@ def _git_checkout(sln, sln_dir, revisions, shallow, refs, git_cache_dir,
             sln_dir)
       else:
         git('remote', 'set-url', 'origin', mirror_dir, cwd=sln_dir)
-        git('fetch', 'origin', cwd=sln_dir)
+        git('fetch', 'origin', cwd=sln_dir, env=env)
       for ref in refs:
         refspec = '%s:%s' % (ref, ref.lstrip('+'))
-        git('fetch', 'origin', refspec, cwd=sln_dir)
+        git('fetch', 'origin', refspec, cwd=sln_dir, env=env)
 
       # Windows sometimes has trouble deleting files.
       # This can make git commands that rely on locks fail.
@@ -737,7 +741,11 @@ def apply_gerrit_ref(gerrit_repo, gerrit_ref, root, gerrit_reset,
   # command will do so. See http://crbug.com/692067.
   git('reset', '--hard', cwd=root)
   try:
-    git('fetch', gerrit_repo, gerrit_ref, cwd=root)
+    # TODO(tikuta): remove env for GIT_TRACE after fixing crbug.com/749709
+    env = {}
+    if gerrit_repo == CHROMIUM_SRC_URL or gerrit_repo + '.git' == CHROMIUM_SRC_URL:
+      env = {'GIT_TRACE': 'true'}
+    git('fetch', gerrit_repo, gerrit_ref, cwd=root, env=env)
     git('checkout', 'FETCH_HEAD', cwd=root)
 
     if gerrit_rebase_patch_ref: