hook fmt.Println 编译后就是失效了

[shanjunmei]

如题，这是什么原因，同样的代码，hook log.Println,就没问题 debug的时候也没问题，但是编译后就G了

[shanjunmei]

如题，这是什么原因，同样的代码，hook log.Println,就没问题 debug的时候也没问题，但是编译后就G了

即便编译了，log.Println 的hook 还是有效，唯独fmt.Println 没用了

[shanjunmei]

除了内联，还有社么会影响这个结果,以下是两次测试结果，我有在代码上加注解阻止内联，我在编译时候指定 阻止内联，结果就对了，附版本信息 go version go version go1.16.5 windows/amd64

` //go:noinline func test(v ...interface{}) (n int, err error) { fmt.Println("tx") return rand.Intn(1), nil }

//go:noinline func test1(v ...interface{}) { fmt.Println("t") }` 以下是两次编译测试的结果，调试也表现这如预期

`go build -gcflags="-m -m -l"

test

.\main.go:50:14: "tx" escapes to heap: .\main.go:50:14: flow: {storage for ... argument} = &{storage for "tx"}: .\main.go:50:14: from "tx" (spill) at .\main.go:50:14 .\main.go:50:14: from ... argument (slice-literal-element) at .\main.go:50:13 .\main.go:50:14: flow: {heap} = {storage for ... argument}: .\main.go:50:14: from ... argument (spill) at .\main.go:50:13 .\main.go:50:14: from fmt.Println(... argument...) (call parameter) at .\main.go:50:13 .\main.go:49:11: v does not escape .\main.go:50:13: ... argument does not escape .\main.go:50:14: "tx" escapes to heap .\main.go:43:7: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:43:7: flow: {heap} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:43:7: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:43:7 .\main.go:43:7: from v[0] = "traceId : " + fmt.Sprintf("%v", tid) (assign) at .\main.go:43:7 .\main.go:43:23: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:43:23: flow: {storage for "traceId : " + fmt.Sprintf("%v", tid)} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:43:23: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:43:23 .\main.go:43:23: from "traceId : " + fmt.Sprintf("%v", tid) (interface-converted) at .\main.go:43:7 .\main.go:37:19: parameter v leaks to {heap} with derefs=1: .\main.go:37:19: flow: {heap} = v: .\main.go:37:19: from v[:len(v) - 1] (slice) at .\main.go:42:15 .\main.go:37:19: from copy(v[1:], v[:len(v) - 1]) (call parameter) at .\main.go:42:6 .\main.go:37:19: from copy(v[1:], v[:len(v) - 1]) (copied slice) at .\main.go:42:6 .\main.go:37:19: leaking param content: v .\main.go:43:7: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:43:23: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:43:36: ... argument does not escape .\main.go:56:14: "t" escapes to heap: .\main.go:56:14: flow: {storage for ... argument} = &{storage for "t"}: .\main.go:56:14: from "t" (spill) at .\main.go:56:14 .\main.go:56:14: from ... argument (slice-literal-element) at .\main.go:56:13 .\main.go:56:14: flow: {heap} = {storage for ... argument}: .\main.go:56:14: from ... argument (spill) at .\main.go:56:13 .\main.go:56:14: from fmt.Println(... argument...) (call parameter) at .\main.go:56:13 .\main.go:55:12: v does not escape .\main.go:56:13: ... argument does not escape .\main.go:56:14: "t" escapes to heap .\main.go:65:7: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:65:7: flow: {heap} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:65:7: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:65:7 .\main.go:65:7: from v[0] = "traceId : " + fmt.Sprintf("%v", tid) (assign) at .\main.go:65:7 .\main.go:65:23: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:65:23: flow: {storage for "traceId : " + fmt.Sprintf("%v", tid)} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:65:23: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:65:23 .\main.go:65:23: from "traceId : " + fmt.Sprintf("%v", tid) (interface-converted) at .\main.go:65:7 .\main.go:59:15: parameter v leaks to {heap} with derefs=1: .\main.go:59:15: flow: {heap} = v: .\main.go:59:15: from v[:len(v) - 1] (slice) at .\main.go:64:15 .\main.go:59:15: from copy(v[1:], v[:len(v) - 1]) (call parameter) at .\main.go:64:6 .\main.go:59:15: from copy(v[1:], v[:len(v) - 1]) (copied slice) at .\main.go:64:6 .\main.go:59:15: leaking param content: v .\main.go:65:7: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:65:23: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:65:36: ... argument does not escape .\main.go:29:19: uuid.NewV4().String() escapes to heap: .\main.go:29:19: flow: {heap} = &{storage for uuid.NewV4().String()}: .\main.go:29:19: from uuid.NewV4().String() (spill) at .\main.go:29:19 .\main.go:29:19: from _ctx["traceId"] = uuid.NewV4().String() (assign) at .\main.go:29:19 .\main.go:32:15: i escapes to heap: .\main.go:32:15: flow: {storage for ... argument} = &{storage for i}: .\main.go:32:15: from i (spill) at .\main.go:32:15 .\main.go:32:15: from ... argument (slice-literal-element) at .\main.go:32:14 .\main.go:32:15: flow: {heap} = {storage for ... argument}: .\main.go:32:15: from ... argument (spill) at .\main.go:32:14 .\main.go:32:15: from log.Println(... argument...) (call parameter) at .\main.go:32:14 .\main.go:32:15: "test log " escapes to heap: .\main.go:32:15: flow: {storage for ... argument} = &{storage for "test log "}: .\main.go:32:15: from "test log " (spill) at .\main.go:32:15 .\main.go:32:15: from ... argument (slice-literal-element) at .\main.go:32:14 .\main.go:32:15: flow: {heap} = {storage for ... argument}: .\main.go:32:15: from ... argument (spill) at .\main.go:32:14 .\main.go:32:15: from log.Println(... argument...) (call parameter) at .\main.go:32:14 .\main.go:31:15: i escapes to heap: .\main.go:31:15: flow: {storage for ... argument} = &{storage for i}: .\main.go:31:15: from i (spill) at .\main.go:31:15 .\main.go:31:15: from ... argument (slice-literal-element) at .\main.go:31:14 .\main.go:31:15: from ... argument (spill) at .\main.go:31:14 .\main.go:31:15: from fmt.Println(... argument...) (call parameter) at .\main.go:31:14 .\main.go:31:15: flow: {storage for ... argument} = &{storage for "test println "}: .\main.go:31:15: from "test println " (spill) at .\main.go:31:15 .\main.go:31:15: from ... argument (slice-literal-element) at .\main.go:31:14 .\main.go:31:15: flow: {heap} = {storage for ... argument}: .\main.go:31:15: from ... argument (spill) at .\main.go:31:14 .\main.go:31:15: from fmt.Println(... argument...) (call parameter) at .\main.go:31:14 .\main.go:17:14: make(map[string]interface {}) escapes to heap: .\main.go:17:14: flow: _ctx = &{storage for make(map[string]interface {})}: .\main.go:17:14: from make(map[string]interface {}) (spill) at .\main.go:17:14 .\main.go:17:14: from _ctx := make(map[string]interface {}) (assign) at .\main.go:17:7 .\main.go:17:14: flow: {heap} = _ctx: .\main.go:17:14: from _ctx (interface-converted) at .\main.go:30:18 .\main.go:17:14: from threadLocal.Set(_ctx) (call parameter) at .\main.go:30:18 .\main.go:17:14: make(map[string]interface {}) escapes to heap .\main.go:21:14: ... argument does not escape .\main.go:25:14: ... argument does not escape .\main.go:29:19: uuid.NewV4().String() escapes to heap .\main.go:31:14: ... argument does not escape .\main.go:31:15: "test println " escapes to heap .\main.go:31:15: i escapes to heap .\main.go:32:14: ... argument does not escape .\main.go:32:15: "test log " escapes to heap .\main.go:32:15: i escapes to heap PS D:\goworkspace\test> .\test.exe traceId : a73357ea-cabf-46f1-b065-3389adf7a92d test println 0 2022/08/28 12:07:43 traceId : a73357ea-cabf-46f1-b065-3389adf7a92d test log 0 PS D:\goworkspace\test> go build -gcflags="-m -m"

test

.\main.go:49:6: cannot inline test: marked go:noinline .\main.go:50:13: inlining call to fmt.Println func(...interface {}) (int, error) { var fmt..autotmp_3 int; fmt..autotmp_3 = ; var fmt..autotmp_4 error; fmt..autotmp_4 = ; fmt..autotmp_3, fmt..autotmp_4 = fmt.Fprintln(io.Writer(os.Stdout), fmt.a...); return fmt..autotmp_3, fmt..autotmp_4 } .\main.go:51:18: inlining call to rand.Intn func(int) int { return rand.globalRand.Intn(rand.n) } .\main.go:37:6: cannot inline tracePrintln: function too complex: cost 230 exceeds budget 80 .\main.go:55:6: cannot inline test1: marked go:noinline .\main.go:56:13: inlining call to fmt.Println func(...interface {}) (int, error) { var fmt..autotmp_3 int; fmt..autotmp_3 = ; var fmt..autotmp_4 error; fmt..autotmp_4 = ; fmt..autotmp_3, fmt..autotmp_4 = fmt.Fprintln(io.Writer(os.Stdout), fmt.a...); return fmt..autotmp_3, fmt..autotmp_4 } .\main.go:59:6: cannot inline traceLog: function too complex: cost 220 exceeds budget 80 .\main.go:15:6: cannot inline main: function too complex: cost 644 exceeds budget 80 .\main.go:21:14: inlining call to fmt.Println func(...interface {}) (int, error) { var fmt..autotmp_3 int; fmt..autotmp_3 = ; var fmt..autotmp_4 error; fmt..autotmp_4 = ; fmt..autotmp_3, fmt..autotmp_4 = fmt.Fprintln(io.Writer(os.Stdout), fmt.a...); return fmt..autotmp_3, fmt..autotmp_4 } .\main.go:25:14: inlining call to fmt.Println func(...interface {}) (int, error) { var fmt..autotmp_3 int; fmt..autotmp_3 = ; var fmt..autotmp_4 error; fmt..autotmp_4 = ; fmt..autotmp_3, fmt..autotmp_4 = fmt.Fprintln(io.Writer(os.Stdout), fmt.a...); return fmt..autotmp_3, fmt..autotmp_4 } .\main.go:29:31: inlining call to uuid.NewV4 func() uuid.UUID { return uuid.global.NewV4() } .\main.go:31:14: inlining call to fmt.Println func(...interface {}) (int, error) { var fmt..autotmp_3 int; fmt..autotmp_3 = ; var fmt..autotmp_4 error; fmt..autotmp_4 = ; fmt..autotmp_3, fmt..autotmp_4 = fmt.Fprintln(io.Writer(os.Stdout), fmt.a...); return fmt..autotmp_3, fmt..autotmp_4 } .\main.go:13:5: can inline init with cost 35 as: func() { threadLocal = routine.NewThreadLocal() } .\main.go:13:41: inlining call to routine.NewThreadLocal func() routine.ThreadLocal { return routine.ThreadLocal(&routine.threadLocal{...}) } .\main.go:13:41: inlining call to routine.nextThreadLocalIndex func() int { var routine.index·2 int32; routine.index·2 = ; routine.index·2 = atomic.AddInt32(&routine.threadLocalIndex, int32(1)); if routine.index·2 < int32(0) { atomic.AddInt32(&routine.threadLocalIndex, int32(-1)); panic(string("too many thread-local indexed variables")) }; return int(routine.index·2) } .\main.go:50:14: "tx" escapes to heap: .\main.go:50:14: flow: ~arg0 = &{storage for "tx"}: .\main.go:50:14: from "tx" (spill) at .\main.go:50:14 .\main.go:50:14: from ~arg0 := "tx" (assign-pair) at .\main.go:50:13 .\main.go:50:14: flow: {storage for []interface {}{...}} = ~arg0: .\main.go:50:14: from []interface {}{...} (slice-literal-element) at .\main.go:50:13 .\main.go:50:14: flow: fmt.a = &{storage for []interface {}{...}}: .\main.go:50:14: from []interface {}{...} (spill) at .\main.go:50:13 .\main.go:50:14: from fmt.a = []interface {}{...} (assign) at .\main.go:50:13 .\main.go:50:14: flow: {heap} = fmt.a: .\main.go:50:14: from fmt.Fprintln(io.Writer(os.Stdout), fmt.a...) (call parameter) at .\main.go:50:13 .\main.go:49:11: v does not escape .\main.go:50:14: "tx" escapes to heap .\main.go:50:13: []interface {}{...} does not escape .\main.go:43:7: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:43:7: flow: {heap} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:43:7: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:43:7 .\main.go:43:7: from v[0] = "traceId : " + fmt.Sprintf("%v", tid) (assign) at .\main.go:43:7 .\main.go:43:23: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:43:23: flow: {storage for "traceId : " + fmt.Sprintf("%v", tid)} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:43:23: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:43:23 .\main.go:43:23: from "traceId : " + fmt.Sprintf("%v", tid) (interface-converted) at .\main.go:43:7 .\main.go:37:19: parameter v leaks to {heap} with derefs=1: .\main.go:37:19: flow: {heap} = v: .\main.go:37:19: from v[:len(v) - 1] (slice) at .\main.go:42:15 .\main.go:37:19: from copy(v[1:], v[:len(v) - 1]) (call parameter) at .\main.go:42:6 .\main.go:37:19: from copy(v[1:], v[:len(v) - 1]) (copied slice) at .\main.go:42:6 .\main.go:37:19: leaking param content: v .\main.go:43:7: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:43:23: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:43:36: ... argument does not escape .\main.go:56:14: "t" escapes to heap: .\main.go:56:14: flow: ~arg0 = &{storage for "t"}: .\main.go:56:14: from "t" (spill) at .\main.go:56:14 .\main.go:56:14: from ~arg0 := "t" (assign-pair) at .\main.go:56:13 .\main.go:56:14: flow: {storage for []interface {}{...}} = ~arg0: .\main.go:56:14: from []interface {}{...} (slice-literal-element) at .\main.go:56:13 .\main.go:56:14: flow: fmt.a = &{storage for []interface {}{...}}: .\main.go:56:14: from []interface {}{...} (spill) at .\main.go:56:13 .\main.go:56:14: from fmt.a = []interface {}{...} (assign) at .\main.go:56:13 .\main.go:56:14: flow: {heap} = fmt.a: .\main.go:56:14: from fmt.Fprintln(io.Writer(os.Stdout), fmt.a...) (call parameter) at .\main.go:56:13 .\main.go:55:12: v does not escape .\main.go:56:14: "t" escapes to heap .\main.go:56:13: []interface {}{...} does not escape .\main.go:65:7: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:65:7: flow: {heap} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:65:7: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:65:7 .\main.go:65:7: from v[0] = "traceId : " + fmt.Sprintf("%v", tid) (assign) at .\main.go:65:7 .\main.go:65:23: "traceId : " + fmt.Sprintf("%v", tid) escapes to heap: .\main.go:65:23: flow: {storage for "traceId : " + fmt.Sprintf("%v", tid)} = &{storage for "traceId : " + fmt.Sprintf("%v", tid)}: .\main.go:65:23: from "traceId : " + fmt.Sprintf("%v", tid) (spill) at .\main.go:65:23 .\main.go:65:23: from "traceId : " + fmt.Sprintf("%v", tid) (interface-converted) at .\main.go:65:7 .\main.go:59:15: parameter v leaks to {heap} with derefs=1: .\main.go:59:15: flow: {heap} = v: .\main.go:59:15: from v[:len(v) - 1] (slice) at .\main.go:64:15 .\main.go:59:15: from copy(v[1:], v[:len(v) - 1]) (call parameter) at .\main.go:64:6 .\main.go:59:15: from copy(v[1:], v[:len(v) - 1]) (copied slice) at .\main.go:64:6 .\main.go:59:15: leaking param content: v .\main.go:65:7: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:65:23: "traceId : " + fmt.Sprintf("%v", ... argument...) escapes to heap .\main.go:65:36: ... argument does not escape .\main.go:29:19: uuid.UUID(~R0).String() escapes to heap: .\main.go:29:19: flow: {heap} = &{storage for uuid.UUID(~R0).String()}: .\main.go:29:19: from uuid.UUID(~R0).String() (spill) at .\main.go:29:19 .\main.go:29:19: from _ctx["traceId"] = uuid.UUID(~R0).String() (assign) at .\main.go:29:19 .\main.go:32:15: i escapes to heap: .\main.go:32:15: flow: {storage for ... argument} = &{storage for i}: .\main.go:32:15: from i (spill) at .\main.go:32:15 .\main.go:32:15: from ... argument (slice-literal-element) at .\main.go:32:14 .\main.go:32:15: flow: {heap} = {storage for ... argument}: .\main.go:32:15: from ... argument (spill) at .\main.go:32:14 .\main.go:32:15: from log.Println(... argument...) (call parameter) at .\main.go:32:14 .\main.go:32:15: "test log " escapes to heap: .\main.go:32:15: flow: {storage for ... argument} = &{storage for "test log "}: .\main.go:32:15: from "test log " (spill) at .\main.go:32:15 .\main.go:32:15: from ... argument (slice-literal-element) at .\main.go:32:14 .\main.go:32:15: flow: {heap} = {storage for ... argument}: .\main.go:32:15: from ... argument (spill) at .\main.go:32:14 .\main.go:32:15: from log.Println(... argument...) (call parameter) at .\main.go:32:14 .\main.go:31:15: i escapes to heap: .\main.go:31:15: flow: ~arg1 = &{storage for i}: .\main.go:31:15: from i (spill) at .\main.go:31:15 .\main.go:31:15: from ~arg0, ~arg1 := "test println ", i (assign-pair) at .\main.go:31:14 .\main.go:31:15: flow: {storage for []interface {}{...}} = ~arg1: .\main.go:31:15: from []interface {}{...} (slice-literal-element) at .\main.go:31:14 .\main.go:31:15: flow: fmt.a = &{storage for []interface {}{...}}: .\main.go:31:15: from []interface {}{...} (spill) at .\main.go:31:14 .\main.go:31:15: from fmt.a = []interface {}{...} (assign) at .\main.go:31:14 .\main.go:31:15: flow: {heap} = fmt.a: .\main.go:31:15: from fmt.Fprintln(io.Writer(os.Stdout), fmt.a...) (call parameter) at .\main.go:31:14 .\main.go:31:15: "test println " escapes to heap: .\main.go:31:15: flow: ~arg0 = &{storage for "test println "}: .\main.go:31:15: from "test println " (spill) at .\main.go:31:15 .\main.go:31:15: from ~arg0, ~arg1 := "test println ", i (assign-pair) at .\main.go:31:14 .\main.go:31:15: flow: {storage for []interface {}{...}} = ~arg0: .\main.go:31:15: from []interface {}{...} (slice-literal-element) at .\main.go:31:14 .\main.go:31:15: flow: fmt.a = &{storage for []interface {}{...}}: .\main.go:31:15: from []interface {}{...} (spill) at .\main.go:31:14 .\main.go:31:15: from fmt.a = []interface {}{...} (assign) at .\main.go:31:14 .\main.go:31:15: flow: {heap} = fmt.a: .\main.go:31:15: from fmt.Fprintln(io.Writer(os.Stdout), fmt.a...) (call parameter) at .\main.go:31:14 .\main.go:17:14: flow: _ctx = &{storage for make(map[string]interface {})}: .\main.go:17:14: from make(map[string]interface {}) (spill) at .\main.go:17:14 .\main.go:17:14: from _ctx := make(map[string]interface {}) (assign) at .\main.go:17:7 .\main.go:17:14: flow: {heap} = _ctx: .\main.go:17:14: from _ctx (interface-converted) at .\main.go:30:18 .\main.go:17:14: from threadLocal.Set(_ctx) (call parameter) at .\main.go:30:18 .\main.go:17:14: make(map[string]interface {}) escapes to heap .\main.go:21:14: []interface {}{...} does not escape .\main.go:25:14: []interface {}{...} does not escape .\main.go:29:19: uuid.UUID(~R0).String() escapes to heap .\main.go:31:15: "test println " escapes to heap .\main.go:31:15: i escapes to heap .\main.go:31:14: []interface {}{...} does not escape .\main.go:32:14: ... argument does not escape .\main.go:32:15: "test log " escapes to heap .\main.go:32:15: i escapes to heap .\main.go:13:41: &routine.threadLocal{...} escapes to heap: .\main.go:13:41: flow: ~R0 = &{storage for &routine.threadLocal{...}}: .\main.go:13:41: from &routine.threadLocal{...} (spill) at .\main.go:13:41 .\main.go:13:41: from routine.ThreadLocal(&routine.threadLocal{...}) (interface-converted) at .\main.go:13:41 .\main.go:13:41: from ~R0 = (assign-pair) at .\main.go:13:41 .\main.go:13:41: flow: {heap} = ~R0: .\main.go:13:41: from threadLocal = routine.ThreadLocal(~R0) (assign) at .\main.go:13:5 .\main.go:13:41: &routine.threadLocal{...} escapes to heap

:1: .this does not escape :1: .this does not escape PS D:\goworkspace\test> .\test.exe test println 0 2022/08/28 12:08:05 traceId : 9ab88ffe-675b-4285-a739-33f89436a83a test log 0`

[kmalloc]

只有当没内联才可以 hook, noinline 可以用来修饰你写的函数 对库函数应该是不行的 编译的时候加个选项可以去掉所有内联 但对程序性能有影响

[shanjunmei]

只有当没内联才可以 hook, noinline 可以用来修饰你写的函数 对库函数应该是不行的 编译的时候加个选项可以去掉所有内联 但对程序性能有影响

这个说法似乎站不住脚啊，log.Println 也是你说的库函数吧，但是可以的

[kmalloc]

意思是用来修饰你能控制源码的, 这是个编译开头.