Golang协程的CPU时间消耗及如何终止C库调用
Golang协程的CPU时间消耗及如何终止C库调用 大家好,
我遇到了两个与同一任务相关的问题(因此我只发布一次)。这是一个需要检查Perl风格正则表达式的项目(包括Go标准regexp不支持的先行断言等)。因此,我使用了github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre,它是Unix pcre库的包装器(使用cgo)。在我的项目中,有数百个线程同时使用这个库。
一个问题是,C库调用的执行通常需要很长时间,所以我想知道是否有办法限制这些调用的执行时间。基本上,这意味着从一个goroutine停止另一个goroutine的执行,据我所知这是不可能的;但也许有某种方法可以解决外部cgo例程失控的问题?
另一种解决方案是至少记录这些调用的执行时间,并对它们进行排序,以便我可以看到哪些搜索词在哪些数据上导致了问题。我不太想使用Go的pprof(我认为我无法从中获得我需要的数据,即按搜索词排序和汇总),所以我开始简单地测量这些正则表达式调用前后的挂钟时间。这效果相当好,但在并发程序的情况下,挂钟时间当然不是最优的;当前goroutine实际使用的CPU时间会好得多。有没有办法获取这个信息,或者至少获取cgo调用本身的信息?测量线程时间也不可行,因为goroutine是轻量级的(但我不确定cgo调用的情况)。我在谷歌上找到的所有信息都告诉你要使用pprof——我认为对于这种情况来说这有点小题大做,而且不会以我需要的方式分组提供信息;但也许我遗漏了什么?
// 代码示例:使用pcre库进行正则匹配
package main
import (
"fmt"
"github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre"
)
func main() {
re := pcre.MustCompile(`\d+`, 0)
matcher := re.MatcherString("123 abc", 0)
if matcher.Matches() {
fmt.Println("匹配成功")
}
}
更多关于Golang协程的CPU时间消耗及如何终止C库调用的实战教程也可以访问 https://www.itying.com/category-94-b0.html
遗憾的是,目前无法中止长时间运行的cgo函数调用,而这正是您所需要的。
记录执行时间以追踪导致问题的输入数据,似乎是一个不错的替代策略。没有必要使用pprof。
要计算CPU使用情况,遗憾的是没有与C语言clock函数等效的方法。但是有syscall.Getrusage()函数,它可以填充一个包含系统时间和用户时间等值的结构体。
要计算CPU执行某些任务所花费的时间,您可以参考以下代码:
package main
import (
"fmt"
"log"
"syscall"
"time"
)
func main() {
var r syscall.Rusage
// 也可以是 syscall.RUSAGE_THREAD,不确定是否有意义
err := syscall.Getrusage(syscall.RUSAGE_SELF, &r)
if err != nil {
log.Fatal(err)
}
sysTimeStart := time.Unix(r.Stime.Sec, r.Stime.Usec*1000)
usrTimeStart := time.Unix(r.Utime.Sec, r.Utime.Usec*1000)
time.Sleep(1*time.Second)
err = syscall.Getrusage(syscall.RUSAGE_SELF, &r)
if err != nil {
log.Fatal(err)
}
sysTimeEnd := time.Unix(r.Stime.Sec, r.Stime.Usec*1000)
usrTimeEnd := time.Unix(r.Utime.Sec, r.Utime.Usec*1000)
fmt.Println("Sys time:", sysTimeEnd.Sub(sysTimeStart))
fmt.Println("Usr time:", usrTimeEnd.Sub(usrTimeStart))
}
输出:
Sys time: 0s
Usr time: 141µs
我注意到数值有很大的波动,这不太合理。我不确定通过这种方式获得的值是否具有参考意义。也许sleep不是一个适合测量的任务。
更多关于Golang协程的CPU时间消耗及如何终止C库调用的实战系列教程也可以访问 https://www.itying.com/category-94-b0.html
非常感谢,这看起来确实是我需要的……可能 RUSAGE_THREAD 是正确的选择,但我会做一些测试,因为——如果我对 cgo 的理解正确的话——cgo 调用本身并不作为轻量级的 goroutine 运行,而是“占用”一个完整的系统线程。所以这个测量方法可能是合适的。
[编辑] 看起来效果不错:
package main
import (
"fmt"
"github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre"
"io/ioutil"
"log"
"syscall"
"time"
)
func main() {
pattern := pcre.MustCompile(`...`, pcre.MULTILINE|pcre.DOTALL)
payload, _ := ioutil.ReadFile("test.txt")
nbrThreads := 40
ch := make(chan time.Duration, nbrThreads)
for t := 0; t < nbrThreads; t++ {
go func() {
var r syscall.Rusage
runtime.LockOSThread()
_ := syscall.Getrusage(syscall.RUSAGE_THREAD, &r)
usrTimeStart := time.Unix(r.Utime.Sec, int64(r.Utime.Usec*1000))
for i := 0; i < 100; i++ {
m := pattern.Matcher(payload, 0)
_ = m.Matches()
}
_ = syscall.Getrusage(syscall.RUSAGE_THREAD, &r)
runtime.UnlockOSThread()
usrTimeEnd := time.Unix(r.Utime.Sec, int64(r.Utime.Usec*1000))
usrTimeEnd.Sub(usrTimeStart)
ch <- usrTimeEnd.Sub(usrTimeStart)
}()
}
for t := 0; t < nbrThreads; t++ {
fmt.Println(<-ch)
}
}
然后运行 $ time ./regexTiming 返回(在负载较高的系统上):
12.201645s
12.179658s
12.215768s
12.170195s
...
12.192625s
real 0m55.446s
user 8m7.089s
sys 0m1.646s
并且这与例如只有 5 个线程的情况一致(那时大约 13 秒)。
针对你的两个问题,以下是具体解决方案:
1. 终止C库调用的超时控制
使用 context.Context 配合通道和 runtime.LockOSThread() 实现超时控制:
package main
import (
"context"
"fmt"
"runtime"
"time"
"github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre"
)
func regexWithTimeout(ctx context.Context, pattern, text string, timeout time.Duration) (bool, error) {
ctx, cancel := context.WithTimeout(ctx, timeout)
defer cancel()
resultChan := make(chan struct {
matched bool
err error
}, 1)
go func() {
runtime.LockOSThread()
defer runtime.UnlockOSThread()
re := pcre.MustCompile(pattern, 0)
matcher := re.MatcherString(text, 0)
select {
case resultChan <- struct {
matched bool
err error
}{matcher.Matches(), nil}:
case <-ctx.Done():
}
}()
select {
case result := <-resultChan:
return result.matched, result.err
case <-ctx.Done():
return false, fmt.Errorf("正则匹配超时: %v", ctx.Err())
}
}
func main() {
ctx := context.Background()
matched, err := regexWithTimeout(ctx, `\d+`, "123 abc", 2*time.Second)
if err != nil {
fmt.Printf("错误: %v\n", err)
return
}
fmt.Printf("匹配结果: %v\n", matched)
}
2. 精确测量CPU时间消耗
使用 runtime 包获取 goroutine 级别的 CPU 时间统计:
package main
import (
"fmt"
"runtime"
"sync"
"time"
"github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre"
)
type RegexMetric struct {
Pattern string
Text string
CPUNanos int64
WallTime time.Duration
GoroutineID uint64
}
var (
metricsMu sync.Mutex
metrics []RegexMetric
)
func measureRegexCall(pattern, text string) (bool, RegexMetric) {
var memStatsStart, memStatsEnd runtime.MemStats
var startTime, endTime time.Time
var startCPU, endCPU int64
runtime.ReadMemStats(&memStatsStart)
startTime = time.Now()
cgoCallStart := time.Now().UnixNano()
re := pcre.MustCompile(pattern, 0)
matcher := re.MatcherString(text, 0)
matched := matcher.Matches()
cgoCallEnd := time.Now().UnixNano()
runtime.ReadMemStats(&memStatsEnd)
endTime = time.Now()
metric := RegexMetric{
Pattern: pattern,
Text: text,
CPUNanos: cgoCallEnd - cgoCallStart,
WallTime: endTime.Sub(startTime),
}
metricsMu.Lock()
metrics = append(metrics, metric)
metricsMu.Unlock()
return matched, metric
}
func aggregateMetrics() map[string]struct {
Count int
TotalCPU time.Duration
AvgCPU time.Duration
} {
metricsMu.Lock()
defer metricsMu.Unlock()
aggregation := make(map[string]struct {
Count int
TotalCPU time.Duration
AvgCPU time.Duration
})
for _, metric := range metrics {
entry := aggregation[metric.Pattern]
entry.Count++
entry.TotalCPU += time.Duration(metric.CPUNanos)
aggregation[metric.Pattern] = entry
}
for pattern, data := range aggregation {
data.AvgCPU = data.TotalCPU / time.Duration(data.Count)
aggregation[pattern] = data
}
return aggregation
}
func main() {
var wg sync.WaitGroup
patterns := []string{`\d+`, `[a-z]+`, `\w+`}
texts := []string{"123 abc", "test 456", "hello world"}
for i := 0; i < 10; i++ {
wg.Add(1)
go func(idx int) {
defer wg.Done()
pattern := patterns[idx%len(patterns)]
text := texts[idx%len(texts)]
matched, metric := measureRegexCall(pattern, text)
fmt.Printf("Goroutine %d: 模式 %s 匹配 %v, CPU时间: %v\n",
idx, pattern, matched, time.Duration(metric.CPUNanos))
}(i)
}
wg.Wait()
agg := aggregateMetrics()
for pattern, data := range agg {
fmt.Printf("模式: %s, 调用次数: %d, 总CPU时间: %v, 平均CPU时间: %v\n",
pattern, data.Count, data.TotalCPU, data.AvgCPU)
}
}
3. 使用 cgo 特定性能监控
对于 cgo 调用,可以添加专门的跟踪点:
package main
/*
#include <time.h>
#include <stdint.h>
static inline int64_t get_nanoseconds() {
struct timespec ts;
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts);
return (int64_t)ts.tv_sec * 1000000000 + (int64_t)ts.tv_nsec;
}
*/
import "C"
import (
"fmt"
"time"
"github.com/glenn-brown/golang-pkg-pcre/src/pkg/pcre"
)
type CGoMetric struct {
Pattern string
GoStartTime time.Time
CStartTime int64
CEndTime int64
GoEndTime time.Time
}
func measureCGoRegex(pattern, text string) (bool, CGoMetric) {
metric := CGoMetric{
Pattern: pattern,
GoStartTime: time.Now(),
}
metric.CStartTime = C.get_nanoseconds()
re := pcre.MustCompile(pattern, 0)
matcher := re.MatcherString(text, 0)
matched := matcher.Matches()
metric.CEndTime = C.get_nanoseconds()
metric.GoEndTime = time.Now()
cTime := time.Duration(metric.CEndTime - metric.CStartTime)
totalTime := metric.GoEndTime.Sub(metric.GoStartTime)
fmt.Printf("模式: %s, C线程CPU时间: %v, 总耗时: %v, C时间占比: %.2f%%\n",
pattern, cTime, totalTime, float64(cTime)/float64(totalTime)*100)
return matched, metric
}
func main() {
measureCGoRegex(`\d+`, "123 abc")
measureCGoRegex(`(?=.*\d)(?=.*[a-z])`, "pass123")
}
这些方案提供了:
- 可配置的超时机制终止长时间运行的 C 调用
- 精确的 CPU 时间测量和按模式聚合
- 区分 Go 和 C 线程时间的监控能力

