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

fs_util directory materialize prints timing information to stderr #7871

Merged

Conversation

Projects
None yet
2 participants
@illicitonion
Copy link
Contributor

commented Jun 7, 2019

This helps in profiling why materializes are slow.

It's pretty verbose, and we may want to tone it down and/or clean it up at some point, but it will be useful in the short term as-is.

Commits are separately useful.

Example out:

     Running `target/debug/fs_util --local-store-path=/Users/dwagnerhall/tmp/store '--server-address=localhost:61578' directory materialize 1a8f4cf3f956be34c154961f24f7a4a1349e08087cf1a374d2f33a1d450556c5 322 /Users/dwagnerhall/tmp/mat`
{
  "metadata": {
    "source": "Remote",
    "start": 1559934853.5456588,
    "duration": 0.004036486
  },
  "child_directories": {
    ".dwhtemp": {
      "metadata": {
        "source": "Remote",
        "start": 1559934853.5497978,
        "duration": 0.002109302
      },
      "child_directories": {
        ".pants.d": {
          "metadata": {
            "source": "Remote",
            "start": 1559934853.5519328,
            "duration": 0.001037263
          },
          "child_directories": {
            "bootstrap": {
              "metadata": {
                "source": "Remote",
                "start": 1559934853.552997,
                "duration": 0.000746087
              },
              "child_directories": {
                "bootstrap-jvm-tools": {
                  "metadata": {
                    "source": "Remote",
                    "start": 1559934853.553777,
                    "duration": 0.001177418
                  },
                  "child_directories": {
                    "7c0a62077e8f": {
                      "metadata": {
                        "source": "Remote",
                        "start": 1559934853.554987,
                        "duration": 0.001259715
                      },
                      "child_directories": {
                        "ivy": {
                          "metadata": {
                            "source": "Remote",
                            "start": 1559934853.556273,
                            "duration": 0.000833806
                          },
                          "child_directories": {
                            "jars": {
                              "metadata": {
                                "source": "Remote",
                                "start": 1559934853.557133,
                                "duration": 0.048746768
                              },
                              "child_directories": {
                                "org.scala-lang": {
                                  "metadata": {
                                    "source": "Remote",
                                    "start": 1559934853.605939,
                                    "duration": 0.006758074
                                  },
                                  "child_directories": {
                                    "scala-compiler": {
                                      "metadata": {
                                        "source": "Remote",
                                        "start": 1559934853.612747,
                                        "duration": 0.006060426
                                      },
                                      "child_directories": {
                                        "jars": {
                                          "metadata": {
                                            "source": "Remote",
                                            "start": 1559934853.618859,
                                            "duration": 0.004744778
                                          },
                                          "child_directories": {},
                                          "child_files": {
                                            "scala-compiler-2.12.8.jar": {
                                              "source": "Remote",
                                              "start": 1559934853.6236281,
                                              "duration": 3.773785812
                                            }
                                          }
                                        }
                                      },
                                      "child_files": {}
                                    },
                                    "scala-library": {
                                      "metadata": {
                                        "source": "Remote",
                                        "start": 1559934853.612777,
                                        "duration": 0.00613949
                                      },
                                      "child_directories": {
                                        "jars": {
                                          "metadata": {
                                            "source": "Remote",
                                            "start": 1559934853.61895,
                                            "duration": 0.00472107
                                          },
                                          "child_directories": {},
                                          "child_files": {
                                            "scala-library-2.12.8.jar": {
                                              "source": "Remote",
                                              "start": 1559934853.623691,
                                              "duration": 2.316036718
                                            }
                                          }
                                        }
                                      },
                                      "child_files": {}
                                    },
                                    "scala-reflect": {
                                      "metadata": {
                                        "source": "Remote",
                                        "start": 1559934853.6128,
                                        "duration": 0.006192942
                                      },
                                      "child_directories": {
                                        "jars": {
                                          "metadata": {
                                            "source": "Remote",
                                            "start": 1559934853.619021,
                                            "duration": 0.004708559
                                          },
                                          "child_directories": {},
                                          "child_files": {
                                            "scala-reflect-2.12.8.jar": {
                                              "source": "Remote",
                                              "start": 1559934853.623749,
                                              "duration": 1.713186374
                                            }
                                          }
                                        }
                                      },
                                      "child_files": {}
                                    }
                                  },
                                  "child_files": {}
                                },
                                "org.scala-lang.modules": {
                                  "metadata": {
                                    "source": "Remote",
                                    "start": 1559934853.605967,
                                    "duration": 0.007205637
                                  },
                                  "child_directories": {
                                    "scala-xml_2.12": {
                                      "metadata": {
                                        "source": "Remote",
                                        "start": 1559934853.613205,
                                        "duration": 0.007158205
                                      },
                                      "child_directories": {
                                        "jars": {
                                          "metadata": {
                                            "source": "Remote",
                                            "start": 1559934853.6204002,
                                            "duration": 0.003387392
                                          },
                                          "child_directories": {},
                                          "child_files": {
                                            "scala-xml_2.12-1.0.6.jar": {
                                              "source": "Remote",
                                              "start": 1559934853.623807,
                                              "duration": 0.350211899
                                            }
                                          }
                                        }
                                      },
                                      "child_files": {}
                                    }
                                  },
                                  "child_files": {}
                                },
                                "org.scala-sbt": {
                                  "metadata": {
                                    "source": "Remote",
                                    "start": 1559934853.605983,
                                    "duration": 0.007262791
                                  },
                                  "child_directories": {
                                    "compiler-bridge_2.12": {
                                      "metadata": {
                                        "source": "Remote",
                                        "start": 1559934853.6132731,
                                        "duration": 0.007174929
                                      },
                                      "child_directories": {
                                        "jars": {
                                          "metadata": {
                                            "source": "Remote",
                                            "start": 1559934853.620477,
                                            "duration": 0.003367212
                                          },
                                          "child_directories": {},
                                          "child_files": {
                                            "compiler-bridge_2.12-1.0.3-sources.jar": {
                                              "source": "Remote",
                                              "start": 1559934853.623863,
                                              "duration": 0.066368064
                                            }
                                          }
                                        }
                                      },
                                      "child_files": {}
                                    }
                                  },
                                  "child_files": {}
                                }
                              },
                              "child_files": {}
                            }
                          },
                          "child_files": {}
                        }
                      },
                      "child_files": {}
                    },
                    "tool_cache": {
                      "metadata": {
                        "source": "Remote",
                        "start": 1559934853.5550132,
                        "duration": 0.001296908
                      },
                      "child_directories": {
                        "shaded_jars": {
                          "metadata": {
                            "source": "Remote",
                            "start": 1559934853.556333,
                            "duration": 0.001213698
                          },
                          "child_directories": {},
                          "child_files": {
                            "no.such.main.Main-a6da447d452f0635bafcd343f20afa7f91023dcf-ShadedToolFingerprintStrategy_a729bb28c531.jar": {
                              "source": "Remote",
                              "start": 1559934853.557566,
                              "duration": 0.120638968
                            },
                            "org.pantsbuild.zinc.compiler.Main-bf0e3110c2a2760b34ea8d6f99fae361680a5768-ShadedToolFingerprintStrategy_a729bb28c531.jar": {
                              "source": "Remote",
                              "start": 1559934853.557586,
                              "duration": 8.41385437
                            }
                          }
                        }
                      },
                      "child_files": {}
                    }
                  },
                  "child_files": {}
                }
              },
              "child_files": {}
            },
            "compile": {
              "metadata": {
                "source": "Remote",
                "start": 1559934853.5530229,
                "duration": 0.001142287
              },
              "child_directories": {
                "rsc": {
                  "metadata": {
                    "source": "Remote",
                    "start": 1559934853.554202,
                    "duration": 0.000842591
                  },
                  "child_directories": {
                    "b296c10728f0": {
                      "metadata": {
                        "source": "Remote",
                        "start": 1559934853.555068,
                        "duration": 0.001593522
                      },
                      "child_directories": {
                        "examples.src.java.org.pantsbuild.example.hello.greet.greet": {
                          "metadata": {
                            "source": "Remote",
                            "start": 1559934853.55669,
                            "duration": 0.00137371
                          },
                          "child_directories": {
                            "current": {
                              "metadata": {
                                "source": "Remote",
                                "start": 1559934853.558096,
                                "duration": 0.048273058
                              },
                              "child_directories": {
                                "zinc": {
                                  "metadata": {
                                    "source": "Remote",
                                    "start": 1559934853.606396,
                                    "duration": 0.007034734
                                  },
                                  "child_directories": {
                                    "backup": {
                                      "metadata": {
                                        "source": "Local",
                                        "start": null,
                                        "duration": null
                                      },
                                      "child_directories": {},
                                      "child_files": {}
                                    },
                                    "classes": {
                                      "metadata": {
                                        "source": "Remote",
                                        "start": 1559934853.6135209,
                                        "duration": 0.006264819
                                      },
                                      "child_directories": {
                                        "org": {
                                          "metadata": {
                                            "source": "Remote",
                                            "start": 1559934853.619821,
                                            "duration": 0.004119666
                                          },
                                          "child_directories": {
                                            "pantsbuild": {
                                              "metadata": {
                                                "source": "Remote",
                                                "start": 1559934853.623971,
                                                "duration": 0.035485796
                                              },
                                              "child_directories": {
                                                "example": {
                                                  "metadata": {
                                                    "source": "Remote",
                                                    "start": 1559934853.65952,
                                                    "duration": 0.006255534
                                                  },
                                                  "child_directories": {
                                                    "hello": {
                                                      "metadata": {
                                                        "source": "Remote",
                                                        "start": 1559934853.665832,
                                                        "duration": 0.003876938
                                                      },
                                                      "child_directories": {
                                                        "greet": {
                                                          "metadata": {
                                                            "source": "Remote",
                                                            "start": 1559934853.669744,
                                                            "duration": 0.005551092
                                                          },
                                                          "child_directories": {},
                                                          "child_files": {
                                                            "Greeting.class": {
                                                              "source": "Remote",
                                                              "start": 1559934853.675318,
                                                              "duration": 0.009592613
                                                            }
                                                          }
                                                        }
                                                      },
                                                      "child_files": {}
                                                    }
                                                  },
                                                  "child_files": {}
                                                }
                                              },
                                              "child_files": {}
                                            }
                                          },
                                          "child_files": {}
                                        }
                                      },
                                      "child_files": {}
                                    }
                                  },
                                  "child_files": {
                                    "z.analysis": {
                                      "source": "Remote",
                                      "start": 1559934853.6134558,
                                      "duration": 0.007170911
                                    },
                                    "z.jar": {
                                      "source": "Remote",
                                      "start": 1559934853.613479,
                                      "duration": 0.007162416
                                    }
                                  }
                                }
                              },
                              "child_files": {}
                            }
                          },
                          "child_files": {}
                        }
                      },
                      "child_files": {}
                    }
                  },
                  "child_files": {}
                }
              },
              "child_files": {}
            },
            "zinc": {
              "metadata": {
                "source": "Remote",
                "start": 1559934853.553045,
                "duration": 0.001197541
              },
              "child_directories": {
                "compiler-bridge": {
                  "metadata": {
                    "source": "Remote",
                    "start": 1559934853.554268,
                    "duration": 0.001514048
                  },
                  "child_directories": {
                    "c4fc6a00dfe9": {
                      "metadata": {
                        "source": "Remote",
                        "start": 1559934853.55581,
                        "duration": 0.001168222
                      },
                      "child_directories": {},
                      "child_files": {
                        "scala-compiler-bridge.jar": {
                          "source": "Remote",
                          "start": 1559934853.556997,
                          "duration": 0.165911773
                        }
                      }
                    }
                  },
                  "child_files": {}
                }
              },
              "child_files": {}
            }
          },
          "child_files": {}
        }
      },
      "child_files": {}
    },
    "examples": {
      "metadata": {
        "source": "Remote",
        "start": 1559934853.549819,
        "duration": 0.001927327
      },
      "child_directories": {
        "src": {
          "metadata": {
            "source": "Remote",
            "start": 1559934853.5518138,
            "duration": 0.001063936
          },
          "child_directories": {
            "java": {
              "metadata": {
                "source": "Remote",
                "start": 1559934853.55291,
                "duration": 0.001953766
              },
              "child_directories": {
                "org": {
                  "metadata": {
                    "source": "Remote",
                    "start": 1559934853.5548952,
                    "duration": 0.000957071
                  },
                  "child_directories": {
                    "pantsbuild": {
                      "metadata": {
                        "source": "Remote",
                        "start": 1559934853.555876,
                        "duration": 0.001509457
                      },
                      "child_directories": {
                        "example": {
                          "metadata": {
                            "source": "Remote",
                            "start": 1559934853.557411,
                            "duration": 0.049043837
                          },
                          "child_directories": {
                            "hello": {
                              "metadata": {
                                "source": "Remote",
                                "start": 1559934853.606484,
                                "duration": 0.007556386
                              },
                              "child_directories": {
                                "greet": {
                                  "metadata": {
                                    "source": "Remote",
                                    "start": 1559934853.614073,
                                    "duration": 0.006755243
                                  },
                                  "child_directories": {},
                                  "child_files": {
                                    "Greeting.java": {
                                      "source": "Remote",
                                      "start": 1559934853.620852,
                                      "duration": 0.004520117
                                    }
                                  }
                                }
                              },
                              "child_files": {}
                            }
                          },
                          "child_files": {}
                        }
                      },
                      "child_files": {}
                    }
                  },
                  "child_files": {}
                }
              },
              "child_files": {}
            }
          },
          "child_files": {}
        }
      },
      "child_files": {}
    }
  },
  "child_files": {
    "cmd": {
      "source": "Remote",
      "start": 1559934853.54974,
      "duration": 0.002127099
    },
    "roland": {
      "source": "Remote",
      "start": 1559934853.549769,
      "duration": 0.002111813
    }
  }
}

illicitonion added some commits Jun 7, 2019

Pass around metadata with digest fetch results
This will allow us to better profile how much remote fetch critical
paths are problematic.
@stuhood

stuhood approved these changes Jun 7, 2019

Copy link
Member

left a comment

The output is awesome! Thanks.

stuhood added some commits Jun 7, 2019

@illicitonion illicitonion merged commit 4296902 into pantsbuild:master Jun 7, 2019

1 check was pending

continuous-integration/travis-ci/pr The Travis CI build is in progress
Details

@illicitonion illicitonion deleted the twitter:dwagnerhall/snapshotprofile/0 branch Jun 7, 2019

illicitonion added a commit that referenced this pull request Jun 10, 2019

fs_util directory materialize prints timing information to stderr (#7871
)

This helps in profiling why materializes are slow.

It's pretty verbose, and we may want to tone it down and/or clean it up at some point, but it will be useful in the short term as-is.

cattibrie added a commit to cattibrie/pants that referenced this pull request Jun 19, 2019

fs_util directory materialize prints timing information to stderr (pa…
…ntsbuild#7871)

This helps in profiling why materializes are slow.

It's pretty verbose, and we may want to tone it down and/or clean it up at some point, but it will be useful in the short term as-is.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.