不加Preload，查询时间为20ms，加上Preload之后，查询时间达到40-70ms，我使用的是空数据库，仅两个字段，加上Preload,性能直接大幅度降低

Without preload, the query time is 20ms. After adding preload, the query time reaches 40-70ms. I am using an empty database with only two fields. With preload, the performance will be greatly reduced directly.

Comment From: github-actions[bot]

The issue has been automatically marked as stale as it missing playground pull request link, which is important to help others understand your issue effectively and make sure the issue hasn't been fixed on latest master, checkout https://github.com/go-gorm/playground for details. it will be closed in 30 days if no further activity occurs. if you are asking question, please use the Question template, most likely your question already answered https://github.com/go-gorm/gorm/issues or described in the document https://gorm.io ✨ Search Before Asking ✨

Comment From: a631807682

When executing nested sql statements, the time will be superimposed. When we print the log, user thinks it is the sql execution time, but it is actually the api execution time. https://github.com/go-gorm/gorm/blob/master/callbacks.go#L138

Comment From: black-06

When executing nested sql statements, the time will be superimposed. When we print the log, user thinks it is the sql execution time, but it is actually the api execution time. https://github.com/go-gorm/gorm/blob/master/callbacks.go#L138

So it should be sql exec time? How about Trace it in Wrapper for ConnPool? 


func (wrapper *ConnPoolWrapper) ExecContext (...) {
    curTime := time.Now()
    wrapper.ConnPool.ExecContext(...)
    Logger.Trace...
}

Comment From: a631807682

When executing nested sql statements, the time will be superimposed. When we print the log, user thinks it is the sql execution time, but it is actually the api execution time. master/callbacks.go#L138

So it should be sql exec time? How about Trace it in Wrapper for ConnPool?

go func (wrapper *ConnPoolWrapper) ExecContext (...) { curTime := time.Now() wrapper.ConnPool.ExecContext(...) Logger.Trace... }

It doesn't seem to work, because the error that needs to be tracked may be defined by the user.

func (u *User) AfterCreate(*gorm.DB) error {
    time.Sleep(time.Second)
    return errors.New("throw error")
}

Comment From: black-06

When executing nested sql statements, the time will be superimposed. When we print the log, user thinks it is the sql execution time, but it is actually the api execution time. master/callbacks.go#L138

So it should be sql exec time? How about Trace it in Wrapper for ConnPool?

go func (wrapper *ConnPoolWrapper) ExecContext (...) { curTime := time.Now() wrapper.ConnPool.ExecContext(...) Logger.Trace... }

It doesn't seem to work, because the error that needs to be tracked may be defined by the user. go func (u *User) AfterCreate(*gorm.DB) error { time.Sleep(time.Second) return errors.New("throw error") }

I think if we only track the SQL time, then we should not consider the errors that users actively throw

Comment From: a631807682

I think if we only track the SQL time, then we should not consider the errors that users actively throw

But this is a breaking change, and we should also trace the error thrown by the user, because the sql may be rollback and it will not take effect.

Comment From: black-06

I think if we only track the SQL time, then we should not consider the errors that users actively throw

But this is a breaking change, and we should also trace the error thrown by the user, because the sql may be rollback and it will not take effect.

So we can't modify this...

Comment From: a631807682

We can’t seem to find a way to make changes without breaking, but we seem to be able to implement it through plugins, which can be achieved by hijacking logger.Trace and registering callbacks. It can also avoid the current inconsistency between the execution order of SQL and the actual problem.