created 非常耗时 #1835

Open
opened 2020-11-25 05:30:47 +00:00 by mrjnamei · 1 comment

研究发现 sess.Commit() 比较耗时,在设置一些回调函数上耗时较长.

希望改善.

demo:

package main

import (
	"fmt"
	_ "github.com/lib/pq"
	"github.com/xormplus/xorm"
	"log"
	"time"
)

type User struct {
	Id        int64  `json:"id" xorm:"id pk autoincr"`
	Name      string `xorm:"name"`
	CreatedAt int64  `xorm:"created" json:"createdAt"`
}

func (User) TableName() string {
	return "user"
}

type UserNoCreate struct {
	Id        int64  `json:"id" xorm:"id pk autoincr"`
	Name      string `xorm:"name"`
	CreatedAt int64  `xorm:"'created'" json:"createdAt"`
}

func (UserNoCreate) TableName() string {
	return "user_no_create"
}

func main() {

	engine, _ := xorm.NewEngine("postgres", "postgres://postgres:password@localhost:5432/dso?sslmode=disable")
	engine.Sync2(new(User), new(UserNoCreate))

	{
		ti := time.Now()
		logDuration := func(msg string) {
			log.Println(fmt.Sprintf("%s d=%s", msg, time.Now().Sub(ti).String()))
		}
		sess := engine.NewSession()
		defer sess.Close()

		sess.Begin()
		defer sess.Rollback()

		var beans []*User

		// 增加beans
		for i := 0; i < 5000; i++ {
			beans = append(beans, &User{Name: "xyz"})
		}

		logDuration("begin")
		_, err := sess.InsertMulti(beans)
		if err != nil {
			log.Print(err)
			return
		}
		logDuration("inserted")

		sess.Commit()
		//sess.Exec("COMMIT")   // 不耗时

		logDuration("commit")
	}

	log.Println("start to create without create")

	{
		ti := time.Now()
		logDuration := func(msg string) {
			log.Println(fmt.Sprintf("%s d=%s", msg, time.Now().Sub(ti).String()))
		}
		sess := engine.NewSession()
		defer sess.Close()

		sess.Begin()
		defer sess.Rollback()

		var beans []*UserNoCreate

		// 增加beans
		for i := 0; i < 5000; i++ {
			beans = append(beans, &UserNoCreate{Name: "xyz", CreatedAt: time.Now().Unix()})
		}

		logDuration("begin")
		_, err := sess.InsertMulti(beans)
		if err != nil {
			log.Print(err)
			return
		}
		logDuration("inserted")

		sess.Commit()
		//sess.Exec("COMMIT")   // 不耗时

		logDuration("commit")
	}

}

output:

2020/11/25 13:28:52 begin d=2.253095ms
2020/11/25 13:28:52 inserted d=402.852644ms
2020/11/25 13:29:02 commit d=9.802656846s
2020/11/25 13:29:02 start to create without create
2020/11/25 13:29:02 begin d=2.967212ms
2020/11/25 13:29:02 inserted d=93.961209ms
2020/11/25 13:29:02 commit d=99.05491ms

同样插入5000条数据,带有created字段的commit阶段耗时9秒, 不带的耗时99ms

研究发现 `sess.Commit()` 比较耗时,在设置一些回调函数上耗时较长. 希望改善. demo: ``` package main import ( "fmt" _ "github.com/lib/pq" "github.com/xormplus/xorm" "log" "time" ) type User struct { Id int64 `json:"id" xorm:"id pk autoincr"` Name string `xorm:"name"` CreatedAt int64 `xorm:"created" json:"createdAt"` } func (User) TableName() string { return "user" } type UserNoCreate struct { Id int64 `json:"id" xorm:"id pk autoincr"` Name string `xorm:"name"` CreatedAt int64 `xorm:"'created'" json:"createdAt"` } func (UserNoCreate) TableName() string { return "user_no_create" } func main() { engine, _ := xorm.NewEngine("postgres", "postgres://postgres:password@localhost:5432/dso?sslmode=disable") engine.Sync2(new(User), new(UserNoCreate)) { ti := time.Now() logDuration := func(msg string) { log.Println(fmt.Sprintf("%s d=%s", msg, time.Now().Sub(ti).String())) } sess := engine.NewSession() defer sess.Close() sess.Begin() defer sess.Rollback() var beans []*User // 增加beans for i := 0; i < 5000; i++ { beans = append(beans, &User{Name: "xyz"}) } logDuration("begin") _, err := sess.InsertMulti(beans) if err != nil { log.Print(err) return } logDuration("inserted") sess.Commit() //sess.Exec("COMMIT") // 不耗时 logDuration("commit") } log.Println("start to create without create") { ti := time.Now() logDuration := func(msg string) { log.Println(fmt.Sprintf("%s d=%s", msg, time.Now().Sub(ti).String())) } sess := engine.NewSession() defer sess.Close() sess.Begin() defer sess.Rollback() var beans []*UserNoCreate // 增加beans for i := 0; i < 5000; i++ { beans = append(beans, &UserNoCreate{Name: "xyz", CreatedAt: time.Now().Unix()}) } logDuration("begin") _, err := sess.InsertMulti(beans) if err != nil { log.Print(err) return } logDuration("inserted") sess.Commit() //sess.Exec("COMMIT") // 不耗时 logDuration("commit") } } ``` output: ``` 2020/11/25 13:28:52 begin d=2.253095ms 2020/11/25 13:28:52 inserted d=402.852644ms 2020/11/25 13:29:02 commit d=9.802656846s 2020/11/25 13:29:02 start to create without create 2020/11/25 13:29:02 begin d=2.967212ms 2020/11/25 13:29:02 inserted d=93.961209ms 2020/11/25 13:29:02 commit d=99.05491ms ``` 同样插入5000条数据,带有`created`字段的`commit`阶段耗时9秒, 不带的耗时`99ms`
lunny added the
kind
performance
label 2020-11-25 05:34:05 +00:00
Owner

In your example, why not always defer sess.Rollback()? You should call defer sess.Close().

In your example, why not always `defer sess.Rollback()`? You should call `defer sess.Close()`.
Sign in to join this conversation.
No Milestone
No Assignees
2 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: xorm/xorm#1835
No description provided.