Benchmark ops

db/contrib.go

@@ -1,5 +1,9 @@
 package db
 
+import (
+	"time"
+)
+
 type Contrib struct {
 	Week      uint64 `json:"week"`
 	Author    string `json:"author"`
@@ -17,5 +21,6 @@ on duplicate key update
 commits=values(commits), additions=values(additions), deletions=values(deletions)`
 
 func (c *Contrib) Save() {
+	defer measure("SaveContrib", time.Now())
 	mustExecN(saveContribQuery, c)
 }

db/db.go

@@ -1,6 +1,9 @@
 package db
 
 import (
+	"log"
+	"time"
+
 	_ "github.com/go-sql-driver/mysql"
 	"github.com/jmoiron/sqlx"
 	"github.com/jmoiron/sqlx/reflectx"
@@ -27,3 +30,13 @@ func mustSelect(dest interface{}, query string, args ...interface{}) {
 		panic(err)
 	}
 }
+
+func measure(op string, start time.Time) {
+	duration := time.Since(start).Nanoseconds()
+	outcome := "succeeded"
+	if err := recover(); err != nil {
+		outcome = "failed"
+	}
+
+	log.Printf("Operation %s %s; time: %d (%dms)\n", op, outcome, duration, duration/1000000)
+}

db/org.go

@@ -1,5 +1,9 @@
 package db
 
+import (
+	"time"
+)
+
 type Org struct {
 	Login     string `json:"login"`
 	Descr     string `json:"descr"`
@@ -10,6 +14,7 @@ type Org struct {
 const userOrgsQuery = `select o.* from members m join orgs o on o.login = m.org where user = ?`
 
 func UserOrgs(login string) (orgs []*Org) {
+	defer measure("UserOrgs", time.Now())
 	mustSelect(&orgs, userOrgsQuery, login)
 	return
 }

db/repo.go

@@ -21,10 +21,12 @@ on duplicate key update
 updated_at=now()`
 
 func (r *Repo) Save() {
+	defer measure("SaveRepo", time.Now())
 	mustExecN(saveRepoQuery, r)
 }
 
 func OrgRepos(login string) (repos []*Repo) {
+	defer measure("OrgRepos", time.Now())
 	mustSelect(&repos, orgReposQuery, login)
 	return
 }

db/team.go

@@ -1,5 +1,9 @@
 package db
 
+import (
+	"time"
+)
+
 type Team struct {
 	ID    uint64 `json:"id"`
 	Owner string `json:"owner"`
@@ -9,6 +13,7 @@ type Team struct {
 const orgTeamsQuery = `select * from teams where owner = ?`
 
 func OrgTeams(login string) (teams []*Team) {
+	defer measure("OrgTeams", time.Now())
 	mustSelect(&teams, orgTeamsQuery, login)
 	return
 }

db/token.go

@@ -21,5 +21,6 @@ on duplicate key update
 quota = values(quota), remaining = values(remaining), reset_at = values(reset_at)`
 
 func (t *Token) Save() {
+	defer measure("SaveToken", time.Now())
 	mustExecN(saveTokenQuery, t)
 }

db/user.go

@@ -1,5 +1,7 @@
 package db
 
+import "time"
+
 type User struct {
 	Login     string `json:"login"`
 	Name      string `json:"name"`
@@ -14,5 +16,6 @@ on duplicate key update
 login=values(login), name=values(name), avatar_url=values(avatar_url)`
 
 func (u *User) Save() {
+	defer measure("SaveUser", time.Now())
 	mustExecN(saveUserQuery, u)
 }

task/auth.go

@@ -15,7 +15,7 @@ import (
 )
 
 func Authenticate(code string) (token, login string, err error) {
-	report("Authenticate", time.Now())
+	defer report("Authenticate", time.Now())
 	if token, err = FetchAccessToken(code); err != nil {
 		return
 	}
@@ -40,7 +40,7 @@ func Authenticate(code string) (token, login string, err error) {
 }
 
 func FetchAccessToken(code string) (token string, err error) {
-	report("FetchAccessToken", time.Now())
+	defer report("FetchAccessToken", time.Now())
 	payload := url.Values{}
 	payload.Set("client_id", config.C().ClientID)
 	payload.Set("client_secret", config.C().ClientSecret)
@@ -68,7 +68,7 @@ func FetchAccessToken(code string) (token string, err error) {
 }
 
 func FetchUserInfoWithToken(token string) (u *db.User, err error) {
-	report("FetchUserInfoWithToken", time.Now())
+	defer report("FetchUserInfoWithToken", time.Now())
 	var resp *http.Response
 	if resp, err = http.Get("https://api.github.com/user?access_token=" + token); err != nil {
 		return

task/sync.go

@@ -8,7 +8,7 @@ import (
 )
 
 func SyncRepos(token, owner string) {
-	report("SyncRepos", time.Now())
+	defer report("SyncRepos", time.Now())
 	client := newGithubClient(token)
 	opt := &github.RepositoryListByOrgOptions{
 		ListOptions: github.ListOptions{},
@@ -35,7 +35,7 @@ func SyncRepos(token, owner string) {
 }
 
 func SyncContrib(token, owner, repo string) {
-	report("SyncContrib", time.Now())
+	defer report("SyncContrib", time.Now())
 	client := newGithubClient(token)
 	contribs, resp, err := client.Repositories.ListContributorsStats(owner, repo)
 	saveResponseMeta(token, resp)

task/task.go

@@ -31,7 +31,7 @@ func saveResponseMeta(token string, res *github.Response) {
 
 func report(task string, start time.Time) {
 	duration := time.Since(start).Nanoseconds()
-	outcome := "done"
+	outcome := "succeeded"
 	if err := recover(); err != nil {
 		outcome = "failed"
 	}