Benchmark Report

Bench Output

JobId	15462
Target	172.17.130.2
Score	34,437
Status	pass
State	done
UpdatedAt	17:49:31
Message	ok
Log	09/15 17:48:29 負荷レベルが上昇しました。
 09/15 17:48:30 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:31 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:32 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:33 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:34 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:35 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:36 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:37 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:38 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:39 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:40 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:41 レスポンスが遅いため負荷レベルを上げられませんでした。/api/events/11/actions/reserve
 09/15 17:48:42 レスポンスが遅いため負荷レベルを上げられませんでした。/api/events/11/actions/reserve
 09/15 17:48:43 レスポンスが遅いため負荷レベルを上げられませんでした。/api/events/11/actions/reserve
 09/15 17:48:44 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:45 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:46 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:47 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:48 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:49 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:50 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:51 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:52 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:53 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:54 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:55 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:56 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:57 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:58 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:48:59 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:00 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:01 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:02 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:03 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:04 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:05 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:06 負荷レベルが上昇しました。
 09/15 17:49:07 負荷レベルが上昇しました。
 09/15 17:49:08 負荷レベルが上昇しました。
 09/15 17:49:09 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:10 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:11 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:12 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:13 レスポンスが遅いため負荷レベルを上げられませんでした。/admin/api/reports/sales
 09/15 17:49:14 負荷レベルが上昇しました。
 09/15 17:49:15 負荷レベルが上昇しました。
 09/15 17:49:16 レスポンスが遅いため負荷レベルを上げられませんでした。/api/events/11/sheets/B/134/reservation
 09/15 17:49:17 レスポンスが遅いため負荷レベルを上げられませんでした。/api/events/11/actions/reserve
 09/15 17:49:18 レスポンスが遅いため負荷レベルを上げられませんでした。/api/events/11/actions/reserve
 09/15 17:49:19 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:19.480285529 +0900 JST m=+56.176343567 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:20 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:20.473998604 +0900 JST m=+57.170056541 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:21 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:21.368113149 +0900 JST m=+58.064171107 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:22 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:21.368113149 +0900 JST m=+58.064171107 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:23 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:21.368113149 +0900 JST m=+58.064171107 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:24 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:21.368113149 +0900 JST m=+58.064171107 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:25 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:21.368113149 +0900 JST m=+58.064171107 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )
 09/15 17:49:26 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:26.392037663 +0900 JST m=+63.088095639 リクエストがタイムアウトしました (DELETE /api/events/11/sheets/B/275/reservation )
 09/15 17:49:27 エラーが発生したため負荷レベルを上げられませんでした。2018-09-15 17:49:27.352932671 +0900 JST m=+64.048990572 リクエストがタイムアウトしました (POST /api/events/11/actions/reserve )

Request Summary

Request by count
2432 POST /api/actions/login
1457 GET /favicon.ico
1455 GET /css/admin.css
1455 GET /css/bootstrap.min.css
1455 GET /css/layout.css
1455 GET /js/admin.js
1454 GET /js/vue.min.js
1454 GET /js/fetch.min.js
1454 GET /js/bootstrap.bundle.min.js
1454 GET /js/app.js
1454 GET /js/bootstrap-waitingfor.min.js
1454 GET /js/jquery-3.3.1.slim.min.js
1373 GET /api/events/*
1312 POST /api/events/11/actions/reserve
1258 GET /
507 DELETE /api/events/*
220 GET /admin/
219 POST /api/users
209 GET /api/users/*
183 POST /admin/api/actions/login
176 GET /admin/api/reports/events/*
82 GET /admin/api/events/*
62 POST /admin/api/events/*
42 POST /admin/api/actions/logout
42 POST /admin/api/events
41 POST /api/actions/logout
21 GET /admin/api/reports/sales
20 POST /api/events/10/actions/reserve
18 POST /api/events/0/actions/reserve

Request by total time
631.349 0.481211128049 POST /api/events/11/actions/reserve
159.651 0.314893491124 DELETE /api/events/*
64.163 0.0510039745628 GET /
54.772 2.60819047619 GET /admin/api/reports/sales
46.042 0.0335338674436 GET /api/events/*
45.024 0.0185131578947 POST /api/actions/login
22.224 0.10633492823 GET /api/users/*
7.59 0.0345 GET /admin/
4.722 0.0268295454545 GET /admin/api/reports/events/*
4.579 0.0209086757991 POST /api/users
4.193 0.022912568306 POST /admin/api/actions/login
1.788 0.0894 POST /api/events/10/actions/reserve
1.546 0.0858888888889 POST /api/events/0/actions/reserve
1.514 0.0244193548387 POST /admin/api/events/*
1.338 0.0163170731707 GET /admin/api/events/*
0.666 0.0158571428571 POST /admin/api/events
0.394 0.000270790378007 GET /css/bootstrap.min.css
0.331 0.00788095238095 POST /admin/api/actions/logout
0.122 0.0029756097561 POST /api/actions/logout

Request by out bytes
300411155 14305293 GET /admin/api/reports/sales
171531360 117890 GET /css/bootstrap.min.css
105324111 72437 GET /js/vue.min.js
86195061 59281 GET /js/bootstrap.bundle.min.js
85267116 58643 GET /js/jquery-3.3.1.slim.min.js
69789183 50829 GET /api/events/*
25400655 20191 GET /
12835282 8827 GET /js/app.js
12277651 69759 GET /admin/api/reports/events/*
10720099 7367 GET /js/admin.js
9356363 6434 GET /js/fetch.min.js
4436571 20166 GET /admin/
2972344 2044 GET /js/bootstrap-waitingfor.min.js
1773292 1217 GET /favicon.ico
1345229 553 POST /api/actions/login
1297016 891 GET /css/layout.css
1269094 872 GET /css/admin.css
550156 2632 GET /api/users/*
506208 6173 GET /admin/api/events/*
263535 200 POST /api/events/11/actions/reserve
259289 6173 POST /admin/api/events
251383 4054 POST /admin/api/events/*
68755 375 POST /admin/api/actions/login
61597 121 DELETE /api/events/*
45964 209 POST /api/users
10710 255 POST /admin/api/actions/logout
10473 255 POST /api/actions/logout
4408 220 POST /api/events/10/actions/reserve
3613 200 POST /api/events/0/actions/reserve

MySQL Slow Queries

mysql.txt not found.

myprofiler

##  2018-09-15 17:49:27.13 +0900
  37 select r.*, s.rank as sheet_rank, s.num as sheet_num, s.price as sheet_price, e.id as event_id, e.price as event_price from reservations r inner join sheets s on s.id = r.sheet_id inner join events e on e.id = r.event_id
  11 SELECT * FROM sheets ORDER BY `rank`, num
   2 SELECT COUNT(*) FROM sheets WHERE `rank` = ?
   1 SELECT SHA2(?, N)
   1 SELECT * FROM events ORDER BY id ASC

CPU Profile (pprof SVG) (FlameGraph SVG)

File: torb
Type: cpu
Time: Sep 15, 2018 at 8:48am (UTC)
Duration: 1mins, Total samples = 69.66s (115.71%)
Showing nodes accounting for 57.20s, 82.11% of 69.66s total
Dropped 686 nodes (cum <= 0.35s)
      flat  flat%   sum%        cum   cum%
     7.21s 10.35% 10.35%     13.47s 19.34%  runtime.scanobject
     3.53s  5.07% 15.42%      3.95s  5.67%  runtime.findObject
     3.33s  4.78% 20.20%     13.60s 19.52%  runtime.mallocgc
     2.62s  3.76% 23.96%      2.62s  3.76%  runtime.memmove
     1.84s  2.64% 26.60%      3.40s  4.88%  runtime.mapaccess1_faststr
     1.83s  2.63% 29.23%      1.90s  2.73%  syscall.Syscall
     1.74s  2.50% 31.73%     10.35s 14.86%  database/sql.convertAssign
     1.67s  2.40% 34.12%      2.09s  3.00%  runtime.heapBitsSetType
     1.54s  2.21% 36.33%      1.55s  2.23%  time.nextStdChunk
     1.52s  2.18% 38.52%      2.77s  3.98%  runtime.greyobject
     1.29s  1.85% 40.37%      1.29s  1.85%  runtime.memclrNoHeapPointers
     1.23s  1.77% 42.13%      1.23s  1.77%  runtime.markBits.isMarked (inline)
     1.17s  1.68% 43.81%      3.18s  4.57%  time.parse
File: torb
Type: cpu
Time: Sep 15, 2018 at 8:48am (UTC)
Duration: 1mins, Total samples = 69.66s (115.71%)
Showing nodes accounting for 57.20s, 82.11% of 69.66s total
Dropped 686 nodes (cum <= 0.35s)
      flat  flat%   sum%        cum   cum%
         0     0%     0%     56.39s 80.95%  net/http.(*conn).serve
         0     0%     0%     55.77s 80.06%  github.com/labstack/echo.(*Echo).ServeHTTP
         0     0%     0%     55.77s 80.06%  net/http.serverHandler.ServeHTTP
         0     0%     0%     55.74s 80.02%  github.com/labstack/echo-contrib/session.MiddlewareWithConfig.func1.1
         0     0%     0%     55.73s 80.00%  github.com/labstack/echo/middleware.LoggerWithConfig.func2.1
         0     0%     0%     55.60s 79.82%  github.com/labstack/echo.(*Echo).Add.func1
         0     0%     0%     34.49s 49.51%  main.adminLoginRequired.func1
     0.24s  0.34%  0.34%     33.29s 47.79%  main.main.func20
     0.14s   0.2%  0.55%     19.57s 28.09%  runtime.systemstack
     0.03s 0.043%  0.59%     15.61s 22.41%  database/sql.withLock
     0.10s  0.14%  0.73%     15.18s 21.79%  database/sql.(*Rows).Next
     0.07s   0.1%  0.83%     13.80s 19.81%  database/sql.(*Rows).Next.func1
     0.13s  0.19%  1.02%     13.73s 19.71%  database/sql.(*Rows).nextLocked

[CPU] 49.51% main.adminLoginRequired.func1

          .    407:	}
          .    408:}
          .    409:
          .    410:func adminLoginRequired(next echo.HandlerFunc) echo.HandlerFunc {
          .    411:	return func(c echo.Context) error {
       80ms    412:		if _, err := getLoginAdministrator(c); err != nil {
          .    413:			return resError(c, "admin_login_required", 401)
          .    414:		}
     34.41s    415:		return next(c)
          .    416:	}
          .    417:}
          .    418:
          .    419:func getLoginUser(c echo.Context) (*User, error) {
          .    420:	userID := sessUserID(c)

[CPU] 47.79% main.main.func20

          .   1344:			return err
          .   1345:		}
          .   1346:		defer rows.Close()
          .   1347:
          .   1348:		var reports []Report
     11.32s   1349:		for rows.Next() {
      540ms   1350:			var reservation Reservation
      400ms   1351:			var sheet Sheet
      300ms   1352:			var event Event
      7.76s   1353:			if err := rows.Scan(&reservation.ID, &reservation.EventID, &reservation.SheetID, &reservation.UserID, &reservation.ReservedAt, &reservation.CanceledAt, &sheet.Rank, &sheet.Num, &sheet.Price, &event.ID, &event.Price); err != nil {
          .   1354:				return err
          .   1355:			}
       10ms   1356:			report := Report{
          .   1357:				ReservationID: reservation.ID,
          .   1358:				EventID:       event.ID,
          .   1359:				Rank:          sheet.Rank,
          .   1360:				Num:           sheet.Num,
          .   1361:				UserID:        reservation.UserID,
      1.88s   1362:				SoldAt:        reservation.ReservedAt.Format("2006-01-02T15:04:05.000000Z"),
          .   1363:				Price:         event.Price + sheet.Price,
       10ms   1364:				ReservedAt:    reservation.ReservedAt.Unix(),
          .   1365:			}
          .   1366:			if reservation.CanceledAt != nil {
      1.42s   1367:				report.CanceledAt = reservation.CanceledAt.Format("2006-01-02T15:04:05.000000Z")
          .   1368:			}
      2.09s   1369:			reports = append(reports, report)
          .   1370:		}
      7.56s   1371:		return renderReportCSV(c, reports)
          .   1372:	}, adminLoginRequired)
          .   1373:
          .   1374:	e.Start(":" + appPort)
          .   1375:}
          .   1376:

[CPU] 15.63% main.getEvents

          .    437:	err := db.QueryRow("SELECT id, nickname FROM administrators WHERE id = ?", administratorID).Scan(&administrator.ID, &administrator.Nickname)
          .    438:	return &administrator, err
          .    439:}
          .    440:
          .    441:func getEvents(all bool) ([]*Event, error) {
       40ms    442:	tx, err := db.Begin()
          .    443:	if err != nil {
          .    444:		return nil, err
          .    445:	}
          .    446:	defer tx.Commit()
          .    447:
       30ms    448:	rows, err := tx.Query("SELECT * FROM events ORDER BY id ASC")
          .    449:	if err != nil {
          .    450:		return nil, err
          .    451:	}
          .    452:	defer rows.Close()
          .    453:
       90ms    454:	rows2, err := db.Query("SELECT * FROM sheets ORDER BY `rank`, num")
          .    455:	if err != nil {
          .    456:		return nil, err
          .    457:	}
          .    458:	defer rows2.Close()
          .    459:	var sheets []*Sheet
      830ms    460:	for rows2.Next() {
      120ms    461:		var sheet Sheet
      650ms    462:		if err := rows2.Scan(&sheet.ID, &sheet.Rank, &sheet.Num, &sheet.Price); err != nil {
          .    463:			return nil, err
          .    464:		}
       40ms    465:		sheets = append(sheets, &sheet)
          .    466:	}
          .    467:
          .    468:	/*
          .    469:		reservedTimes := make(map[int64]map[int64]int64)
          .    470:		rows3, err := db.Query("SELECT event_id, sheet_id, MIN(reserved_at) FROM reservations WHERE canceled_at IS NULL GROUP BY event_id, sheet_id")
          .    471:		if err != nil {
          .    472:			return nil, err
          .    473:		}
          .    474:		defer rows3.Close()
          .    475:		for rows3.Next() {
          .    476:			var eventId int64
          .    477:			var sheetId int64
          .    478:			var reservedAt *time.Time
          .    479:			rows3.Scan(&eventId, &sheetId, &reservedAt)
          .    480:			if _, ok := reservedTimes[eventId]; !ok {
          .    481:				reservedTimes[eventId] = make(map[int64]int64)
          .    482:			}
          .    483:			reservedTimes[eventId][sheetId] = reservedAt.Unix()
          .    484:		}
          .    485:	*/
          .    486:
          .    487:	var events []*Event
       50ms    488:	for rows.Next() {
          .    489:		var event Event
       10ms    490:		if err := rows.Scan(&event.ID, &event.Title, &event.PublicFg, &event.ClosedFg, &event.Price); err != nil {
          .    491:			return nil, err
          .    492:		}
          .    493:		if !all && !event.PublicFg {
          .    494:			continue
          .    495:		}
          .    496:		events = append(events, &event)
          .    497:	}
          .    498:	for i := range events {
          .    499:		events[i].Sheets = map[string]*Sheets{
       40ms    500:			"S": &Sheets{},
          .    501:			"A": &Sheets{},
          .    502:			"B": &Sheets{},
          .    503:			"C": &Sheets{},
          .    504:		}
          .    505:
          .    506:		for _, v := range sheets {
      2.09s    507:			sheet := *v
      920ms    508:			events[i].Sheets[sheet.Rank].Price = events[i].Price + sheet.Price
       30ms    509:			events[i].Total++
      480ms    510:			events[i].Sheets[sheet.Rank].Total++
          .    511:
          .    512:			/*
          .    513:				if a, ok := reservedTimes[events[i].ID]; ok {
          .    514:					if b, ok := a[sheet.ID]; ok {
          .    515:						sheet.Mine = false
          .    516:						sheet.Reserved = true
          .    517:						sheet.ReservedAtUnix = b
          .    518:					} else {
          .    519:						events[i].Remains++
          .    520:						events[i].Sheets[sheet.Rank].Remains++
          .    521:					}
          .    522:				} else {
          .    523:					events[i].Remains++
          .    524:					events[i].Sheets[sheet.Rank].Remains++
          .    525:				}
          .    526:			*/
      2.83s    527:			if a, ok := GetReservedTimes(events[i].ID, sheet.ID); ok {
          .    528:				sheet.Mine = false
          .    529:				sheet.Reserved = true
          .    530:				sheet.ReservedAtUnix = a
          .    531:			} else {
          .    532:				events[i].Remains++
      750ms    533:				events[i].Sheets[sheet.Rank].Remains++
          .    534:			}
      1.80s    535:			events[i].Sheets[sheet.Rank].Detail = append(events[i].Sheets[sheet.Rank].Detail, &sheet)
          .    536:		}
          .    537:
          .    538:		if err != nil {
          .    539:			return nil, err
          .    540:		}
       40ms    541:		for k := range events[i].Sheets {
       10ms    542:			events[i].Sheets[k].Detail = nil
          .    543:		}
          .    544:	}
       40ms    545:	return events, nil
          .    546:}
          .    547:
          .    548:func getEvent(eventID, loginUserID int64) (*Event, error) {
          .    549:	var event Event
          .    550:	if err := db.QueryRow("SELECT * FROM events WHERE id = ?", eventID).Scan(&event.ID, &event.Title, &event.PublicFg, &event.ClosedFg, &event.Price); err != nil {

[CPU] 13.61% main.fillinUser.func1

          .    660:	return &sanitized
          .    661:}
          .    662:
          .    663:func fillinUser(next echo.HandlerFunc) echo.HandlerFunc {
          .    664:	return func(c echo.Context) error {
       30ms    665:		if user, err := getLoginUser(c); err == nil {
          .    666:			c.Set("user", user)
          .    667:		}
      9.45s    668:		return next(c)
          .    669:	}
          .    670:}
          .    671:
          .    672:func fillinAdministrator(next echo.HandlerFunc) echo.HandlerFunc {
          .    673:	return func(c echo.Context) error {

[CPU] 13.57% main.main.func2

          .    736:	}
          .    737:	e.Use(session.Middleware(sessions.NewCookieStore([]byte("secret"))))
          .    738:	e.Use(middleware.LoggerWithConfig(middleware.LoggerConfig{Output: os.Stderr}))
          .    739:	e.Static("/", "public")
          .    740:	e.GET("/", func(c echo.Context) error {
      9.07s    741:		events, err := getEvents(false)
          .    742:		if err != nil {
          .    743:			return err
          .    744:		}
          .    745:		for i, v := range events {
          .    746:			events[i] = sanitizeEvent(v)
          .    747:		}
      370ms    748:		return c.Render(200, "index.tmpl", echo.Map{
       10ms    749:			"events": events,
          .    750:			"user":   c.Get("user"),
          .    751:			"origin": c.Scheme() + "://" + c.Request().Host,
          .    752:		})
          .    753:	}, fillinUser)
          .    754:	e.GET("/initialize", func(c echo.Context) error {

MEM Profile (pprof SVG) (FlameGraph SVG)

File: torb
Type: inuse_space
Time: Sep 15, 2018 at 8:49am (UTC)
Showing nodes accounting for 184.52MB, 99.46% of 185.53MB total
Dropped 15 nodes (cum <= 0.93MB)
      flat  flat%   sum%        cum   cum%
   47.16MB 25.42% 25.42%    47.16MB 25.42%  bytes.makeSlice
   42.38MB 22.84% 48.26%   144.04MB 77.64%  main.main.func20
   23.28MB 12.55% 60.81%    36.28MB 19.56%  main.InitReservation
      22MB 11.86% 72.67%       22MB 11.86%  time.Time.Format
      18MB  9.70% 82.37%       18MB  9.70%  fmt.Sprintf
   14.50MB  7.82% 90.19%    79.66MB 42.94%  main.renderReportCSV
   13.50MB  7.28% 97.46%    13.50MB  7.28%  reflect.New
    1.16MB  0.62% 98.09%     1.16MB  0.62%  runtime/pprof.StartCPUProfile
    1.04MB  0.56% 98.65%     1.04MB  0.56%  main.InitReservedTime
    1.01MB  0.54% 99.19%     1.01MB  0.54%  runtime/pprof.(*profMap).lookup
    0.50MB  0.27% 99.46%       14MB  7.55%  database/sql.convertAssign
         0     0% 99.46%    47.16MB 25.42%  bytes.(*Buffer).WriteString
         0     0% 99.46%    47.16MB 25.42%  bytes.(*Buffer).grow
         0     0% 99.46%       14MB  7.55%  database/sql.(*Rows).Scan
File: torb
Type: inuse_space
Time: Sep 15, 2018 at 8:49am (UTC)
Showing nodes accounting for 184.52MB, 99.46% of 185.53MB total
Dropped 15 nodes (cum <= 0.93MB)
      flat  flat%   sum%        cum   cum%
         0     0%     0%   184.02MB 99.18%  github.com/labstack/echo-contrib/session.MiddlewareWithConfig.func1.1
         0     0%     0%   184.02MB 99.18%  github.com/labstack/echo.(*Echo).Add.func1
         0     0%     0%   184.02MB 99.18%  github.com/labstack/echo.(*Echo).ServeHTTP
         0     0%     0%   184.02MB 99.18%  github.com/labstack/echo/middleware.LoggerWithConfig.func2.1
         0     0%     0%   184.02MB 99.18%  net/http.(*conn).serve
         0     0%     0%   184.02MB 99.18%  net/http.serverHandler.ServeHTTP
         0     0%     0%   144.04MB 77.64%  main.adminLoginRequired.func1
   42.38MB 22.84% 22.84%   144.04MB 77.64%  main.main.func20
   14.50MB  7.82% 30.66%    79.66MB 42.94%  main.renderReportCSV
         0     0% 30.66%    47.16MB 25.42%  bytes.(*Buffer).WriteString
         0     0% 30.66%    47.16MB 25.42%  bytes.(*Buffer).grow
   47.16MB 25.42% 56.07%    47.16MB 25.42%  bytes.makeSlice
         0     0% 56.07%    38.98MB 21.01%  main.main.func3
         0     0% 56.07%    37.82MB 20.39%  main.InitCache

[MEM] 77.64% main.adminLoginRequired.func1

          .    410:func adminLoginRequired(next echo.HandlerFunc) echo.HandlerFunc {
          .    411:	return func(c echo.Context) error {
          .    412:		if _, err := getLoginAdministrator(c); err != nil {
          .    413:			return resError(c, "admin_login_required", 401)
          .    414:		}
   144.04MB    415:		return next(c)
          .    416:	}
          .    417:}
          .    418:
          .    419:func getLoginUser(c echo.Context) (*User, error) {
          .    420:	userID := sessUserID(c)

[MEM] 77.64% main.main.func20

          .   1357:				ReservationID: reservation.ID,
          .   1358:				EventID:       event.ID,
          .   1359:				Rank:          sheet.Rank,
          .   1360:				Num:           sheet.Num,
          .   1361:				UserID:        reservation.UserID,
        8MB   1362:				SoldAt:        reservation.ReservedAt.Format("2006-01-02T15:04:05.000000Z"),
          .   1363:				Price:         event.Price + sheet.Price,
          .   1364:				ReservedAt:    reservation.ReservedAt.Unix(),
          .   1365:			}
          .   1366:			if reservation.CanceledAt != nil {
       14MB   1367:				report.CanceledAt = reservation.CanceledAt.Format("2006-01-02T15:04:05.000000Z")
          .   1368:			}
    42.38MB   1369:			reports = append(reports, report)
          .   1370:		}
    79.66MB   1371:		return renderReportCSV(c, reports)
          .   1372:	}, adminLoginRequired)
          .   1373:
          .   1374:	e.Start(":" + appPort)
          .   1375:}
          .   1376:

[MEM] 42.94% main.renderReportCSV

          .   1389:func renderReportCSV(c echo.Context, reports []Report) error {
          .   1390:	sort.Slice(reports, func(i, j int) bool { return reports[i].ReservedAt < reports[j].ReservedAt })
          .   1391:
          .   1392:	body := bytes.NewBufferString("reservation_id,event_id,rank,num,price,user_id,sold_at,canceled_at\n")
          .   1393:	for _, v := range reports {
    65.16MB   1394:		body.WriteString(fmt.Sprintf("%d,%d,%s,%d,%d,%d,%s,%s\n",
    14.50MB   1395:			v.ReservationID, v.EventID, v.Rank, v.Num, v.Price, v.UserID, v.SoldAt, v.CanceledAt))
          .   1396:	}
          .   1397:
          .   1398:	c.Response().Header().Set("Content-Type", `text/csv; charset=UTF-8`)
          .   1399:	c.Response().Header().Set("Content-Disposition", `attachment; filename="report.csv"`)
          .   1400:	_, err := io.Copy(c.Response(), body)

BLOCK Profile (pprof SVG) (FlameGraph SVG)

File: torb
Type: delay
Time: Sep 15, 2018 at 8:49am (UTC)
Showing nodes accounting for 1281.30s, 100% of 1281.73s total
Dropped 59 nodes (cum <= 6.41s)
      flat  flat%   sum%        cum   cum%
   799.82s 62.40% 62.40%    799.82s 62.40%  sync.(*Mutex).Lock
   416.60s 32.50% 94.90%    416.60s 32.50%  runtime.selectgo
    64.88s  5.06%   100%     64.88s  5.06%  runtime.chanrecv1
         0     0%   100%     50.93s  3.97%  database/sql.(*DB).connectionResetter
         0     0%   100%     21.55s  1.68%  database/sql.(*Rows).awaitDone
         0     0%   100%     64.64s  5.04%  database/sql.(*Tx).awaitDone
         0     0%   100%    344.12s 26.85%  github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1
         0     0%   100%    799.82s 62.40%  github.com/labstack/echo-contrib/session.MiddlewareWithConfig.func1.1
         0     0%   100%    799.82s 62.40%  github.com/labstack/echo.(*Echo).Add.func1
         0     0%   100%    799.82s 62.40%  github.com/labstack/echo.(*Echo).ServeHTTP
         0     0%   100%    799.82s 62.40%  github.com/labstack/echo/middleware.LoggerWithConfig.func2.1
         0     0%   100%    797.12s 62.19%  main.loginRequired.func1
         0     0%   100%    642.70s 50.14%  main.main.func10
         0     0%   100%    154.21s 12.03%  main.main.func11
File: torb
Type: delay
Time: Sep 15, 2018 at 8:49am (UTC)
Showing nodes accounting for 1281.30s, 100% of 1281.73s total
Dropped 59 nodes (cum <= 6.41s)
      flat  flat%   sum%        cum   cum%
         0     0%     0%    800.25s 62.43%  net/http.(*conn).serve
   799.82s 62.40% 62.40%    799.82s 62.40%  sync.(*Mutex).Lock
         0     0% 62.40%    799.82s 62.40%  github.com/labstack/echo-contrib/session.MiddlewareWithConfig.func1.1
         0     0% 62.40%    799.82s 62.40%  github.com/labstack/echo.(*Echo).ServeHTTP
         0     0% 62.40%    799.82s 62.40%  net/http.serverHandler.ServeHTTP
         0     0% 62.40%    799.82s 62.40%  github.com/labstack/echo/middleware.LoggerWithConfig.func2.1
         0     0% 62.40%    799.82s 62.40%  github.com/labstack/echo.(*Echo).Add.func1
         0     0% 62.40%    797.12s 62.19%  main.loginRequired.func1
         0     0% 62.40%    642.70s 50.14%  main.main.func10
   416.60s 32.50% 94.90%    416.60s 32.50%  runtime.selectgo
         0     0% 94.90%    344.12s 26.85%  github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1
         0     0% 94.90%    154.21s 12.03%  main.main.func11
    64.88s  5.06%   100%     64.88s  5.06%  runtime.chanrecv1
         0     0%   100%     64.64s  5.04%  database/sql.(*Tx).awaitDone

[BLOCK] 62.19% main.loginRequired.func1

          .    398:	sess.Save(c.Request(), c.Response())
          .    399:}
          .    400:
          .    401:func loginRequired(next echo.HandlerFunc) echo.HandlerFunc {
          .    402:	return func(c echo.Context) error {
    84.53ms    403:		if _, err := getLoginUser(c); err != nil {
          .    404:			return resError(c, "login_required", 401)
          .    405:		}
  13.28mins    406:		return next(c)
          .    407:	}
          .    408:}
          .    409:
          .    410:func adminLoginRequired(next echo.HandlerFunc) echo.HandlerFunc {
          .    411:	return func(c echo.Context) error {

[BLOCK] 50.14% main.main.func10

          .    994:			return resError(c, "not_found", 404)
          .    995:		}
          .    996:		return c.JSON(200, sanitizeEvent(event))
          .    997:	})
          .    998:	e.POST("/api/events/:id/actions/reserve", func(c echo.Context) error {
  10.71mins    999:		reqMtx.Lock()
          .   1000:		defer reqMtx.Unlock()
          .   1001:
          .   1002:		eventID, err := strconv.ParseInt(c.Param("id"), 10, 64)
          .   1003:		if err != nil {
          .   1004:			return resError(c, "not_found", 404)
          .   1005:		}
          .   1006:		var params struct {
          .   1007:			Rank string `json:"sheet_rank"`
          .   1008:		}
          .   1009:		c.Bind(&params)
          .   1010:
   742.70us   1011:		user, err := getLoginUser(c)
          .   1012:		if err != nil {
          .   1013:			return err
          .   1014:		}
          .   1015:
   130.57ms   1016:		event, err := getEvent(eventID, user.ID)
          .   1017:		if err != nil {
          .   1018:			if err == sql.ErrNoRows {
          .   1019:				return resError(c, "invalid_event", 404)
          .   1020:			}
          .   1021:			return err
          .   1022:		} else if !event.PublicFg {
          .   1023:			return resError(c, "invalid_event", 404)
          .   1024:		}
          .   1025:
   166.82ms   1026:		if !validateRank(params.Rank) {
          .   1027:			return resError(c, "invalid_rank", 400)
          .   1028:		}
          .   1029:
          .   1030:		var sheet Sheet
          .   1031:		var reservationID int64
          .   1032:		for {
    34.46ms   1033:			if err := db.QueryRow("SELECT * FROM sheets WHERE id NOT IN (SELECT sheet_id FROM reservations WHERE event_id = ? AND canceled_at IS NULL) AND `rank` = ? ORDER BY RAND() LIMIT 1", event.ID, params.Rank).Scan(&sheet.ID, &sheet.Rank, &sheet.Num, &sheet.Price); err != nil {
          .   1034:				if err == sql.ErrNoRows {
          .   1035:					return resError(c, "sold_out", 409)
          .   1036:				}
          .   1037:				return err
          .   1038:			}
          .   1039:
    38.11ms   1040:			tx, err := db.Beginx()
          .   1041:			if err != nil {
          .   1042:				return err
          .   1043:			}
          .   1044:
          .   1045:			res, err := tx.Exec("INSERT INTO reservations (event_id, sheet_id, user_id, reserved_at) VALUES (?, ?, ?, ?)", event.ID, sheet.ID, user.ID, time.Now().UTC().Format("2006-01-02 15:04:05.000000"))
          .   1046:			if err != nil {
          .   1047:				tx.Rollback()
          .   1048:				log.Println("re-try: rollback by", err)
          .   1049:				continue
          .   1050:			}
          .   1051:			reservationID, err = res.LastInsertId()
          .   1052:			if err != nil {
          .   1053:				tx.Rollback()
          .   1054:				log.Println("re-try: rollback by", err)
          .   1055:				continue
          .   1056:			}
          .   1057:
          .   1058:			var reserv Reservation
          .   1059:			err = tx.Get(&reserv, "SELECT * FROM `reservations` WHERE id = ?", reservationID)
          .   1060:			if err != nil {
          .   1061:				tx.Rollback()
          .   1062:				log.Println("re-try: rollback by", err)
          .   1063:				continue
          .   1064:			}
          .   1065:
          .   1066:			if err := tx.Commit(); err != nil {
          .   1067:				tx.Rollback()
          .   1068:				log.Println("re-try: rollback by", err)
          .   1069:				continue
          .   1070:			}
          .   1071:
    27.01ms   1072:			AddReservation(&reserv)
          .   1073:
          .   1074:			break
          .   1075:		}
          .   1076:		return c.JSON(202, echo.Map{
          .   1077:			"id":         reservationID,

[BLOCK] 12.03% main.main.func11

          .   1078:			"sheet_rank": params.Rank,
          .   1079:			"sheet_num":  sheet.Num,
          .   1080:		})
          .   1081:	}, loginRequired)
          .   1082:	e.DELETE("/api/events/:id/sheets/:rank/:num/reservation", func(c echo.Context) error {
   2.57mins   1083:		reqMtx.Lock()
          .   1084:		defer reqMtx.Unlock()
          .   1085:
          .   1086:		eventID, err := strconv.ParseInt(c.Param("id"), 10, 64)
          .   1087:		if err != nil {
          .   1088:			return resError(c, "not_found", 404)
          .   1089:		}
          .   1090:		rank := c.Param("rank")
          .   1091:		num := c.Param("num")
          .   1092:
     1.65us   1093:		user, err := getLoginUser(c)
          .   1094:		if err != nil {
          .   1095:			return err
          .   1096:		}
          .   1097:
    38.62ms   1098:		event, err := getEvent(eventID, user.ID)
          .   1099:		if err != nil {
          .   1100:			if err == sql.ErrNoRows {
          .   1101:				return resError(c, "invalid_event", 404)
          .   1102:			}
          .   1103:			return err
          .   1104:		} else if !event.PublicFg {
          .   1105:			return resError(c, "invalid_event", 404)
          .   1106:		}
          .   1107:
    32.73ms   1108:		if !validateRank(rank) {
          .   1109:			return resError(c, "invalid_rank", 404)
          .   1110:		}
          .   1111:
          .   1112:		var sheet Sheet
     7.90ms   1113:		if err := db.QueryRow("SELECT * FROM sheets WHERE `rank` = ? AND num = ?", rank, num).Scan(&sheet.ID, &sheet.Rank, &sheet.Num, &sheet.Price); err != nil {
          .   1114:			if err == sql.ErrNoRows {
          .   1115:				return resError(c, "invalid_sheet", 404)
          .   1116:			}
          .   1117:			return err
          .   1118:		}
          .   1119:
     2.60ms   1120:		tx, err := db.Begin()
          .   1121:		if err != nil {
          .   1122:			return err
          .   1123:		}
          .   1124:
          .   1125:		// TODO SELECT消したい
          .   1126:		var reservation Reservation
          .   1127:		if err := tx.QueryRow("SELECT * FROM reservations WHERE event_id = ? AND sheet_id = ? AND canceled_at IS NULL GROUP BY event_id HAVING reserved_at = MIN(reserved_at)", event.ID, sheet.ID).Scan(&reservation.ID, &reservation.EventID, &reservation.SheetID, &reservation.UserID, &reservation.ReservedAt, &reservation.CanceledAt); err != nil {
          .   1128:			tx.Rollback()
          .   1129:			if err == sql.ErrNoRows {
          .   1130:				return resError(c, "not_reserved", 400)
          .   1131:			}
          .   1132:			return err
          .   1133:		}
          .   1134:		if reservation.UserID != user.ID {
          .   1135:			tx.Rollback()
          .   1136:			return resError(c, "not_permitted", 403)
          .   1137:		}
          .   1138:
          .   1139:		cancelTime := time.Now().UTC()
          .   1140:		if _, err := tx.Exec("UPDATE reservations SET canceled_at = ? WHERE id = ?", cancelTime.Format("2006-01-02 15:04:05.000000"), reservation.ID); err != nil {
          .   1141:			tx.Rollback()
          .   1142:			return err
          .   1143:		}
          .   1144:
          .   1145:		if err := tx.Commit(); err != nil {
          .   1146:			return err
          .   1147:		}
          .   1148:
      474ns   1149:		CancelReservation(GetReservation(reservation.ID), cancelTime)
          .   1150:
          .   1151:		return c.NoContent(204)
          .   1152:	}, loginRequired)
          .   1153:	e.GET("/admin/", func(c echo.Context) error {
          .   1154:		var events []*Event