Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

runtime: improper preempt points inserting in runtimeNano #22938

Closed
zhaozhiqianghw opened this issue Nov 30, 2017 · 4 comments

Comments

Projects
None yet
4 participants
@zhaozhiqianghw
Copy link

commented Nov 30, 2017

Please answer these questions before submitting your issue. Thanks!

What version of Go are you using (go version)?

Go 1.9.2

Does this issue reproduce with the latest release?

Yes.

What operating system and processor architecture are you using (go env)?

Linux AMD64

What did you do?

I find three improper functions located in runtime/time.go:302-311, and runtime/sema.go:608-611 in Go 1.9.2.

// time.go
//go:linkname poll_runtimeNano internal/poll.runtimeNano
func poll_runtimeNano() int64 {
	return nanotime()
}

//go:linkname time_runtimeNano time.runtimeNano
func time_runtimeNano() int64 {
	return nanotime()
}

and

// sema.go
//go:linkname sync_nanotime sync.runtime_nanotime
func sync_nanotime() int64 {
	return nanotime()
}

These two functions are used to implement runtimeNano in packages time and poll. While the nanotime is implemented in assembly, and this function does not have preempt points.

0000000000452c50 <runtime.nanotime>:
  452c50:	48 83 ec 18          	sub    $0x18,%rsp
  452c54:	48 89 6c 24 10       	mov    %rbp,0x10(%rsp)
  452c59:	48 8d 6c 24 10       	lea    0x10(%rsp),%rbp
  452c5e:	48 8b 05 3b 8f 10 00 	mov    0x108f3b(%rip),%rax        # 55bba0 <runtime.__vdso_clock_gettime_sym>
  452c65:	48 83 f8 00          	cmp    $0x0,%rax
  452c69:	74 2d                	je     452c98 <runtime.nanotime+0x48>
  452c6b:	bf 01 00 00 00       	mov    $0x1,%edi
  452c70:	48 8d 34 24          	lea    (%rsp),%rsi
  452c74:	ff d0                	callq  *%rax
  452c76:	48 8b 04 24          	mov    (%rsp),%rax
  452c7a:	48 8b 54 24 08       	mov    0x8(%rsp),%rdx
  452c7f:	48 69 c0 00 ca 9a 3b 	imul   $0x3b9aca00,%rax,%rax
  452c86:	48 01 d0             	add    %rdx,%rax
  452c89:	48 89 44 24 20       	mov    %rax,0x20(%rsp)
  452c8e:	48 8b 6c 24 10       	mov    0x10(%rsp),%rbp
  452c93:	48 83 c4 18          	add    $0x18,%rsp
  452c97:	c3                   	retq   
  452c98:	48 8d 3c 24          	lea    (%rsp),%rdi
  452c9c:	31 f6                	xor    %esi,%esi
  452c9e:	48 8b 05 23 84 0d 00 	mov    0xd8423(%rip),%rax        # 52b0c8 <runtime.__vdso_gettimeofday_sym>
  452ca5:	ff d0                	callq  *%rax
  452ca7:	48 8b 04 24          	mov    (%rsp),%rax
  452cab:	8b 54 24 08          	mov    0x8(%rsp),%edx
  452caf:	48 69 d2 e8 03 00 00 	imul   $0x3e8,%rdx,%rdx
  452cb6:	48 69 c0 00 ca 9a 3b 	imul   $0x3b9aca00,%rax,%rax
  452cbd:	48 01 d0             	add    %rdx,%rax
  452cc0:	48 89 44 24 20       	mov    %rax,0x20(%rsp)
  452cc5:	48 8b 6c 24 10       	mov    0x10(%rsp),%rbp
  452cca:	48 83 c4 18          	add    $0x18,%rsp
  452cce:	c3                   	retq   
  452ccf:	cc                   	int3  

It makes sense. Because nanotime is used to get time in nano precision. But the time.runtimeNano, poll.runtime.Nano and sync.runtime_nanotime can not follow this. Because There three functions are inserted preempt points, which will make the nanotime measurament becomes unbelievable. For examples, time.runtimeNano is below:

0000000000443b60 <time.runtimeNano>:
  443b60:	64 48 8b 0c 25 f8 ff 	mov    %fs:0xfffffffffffffff8,%rcx
  443b67:	ff ff 
  443b69:	48 3b 61 10          	cmp    0x10(%rcx),%rsp
  443b6d:	76 26                	jbe    443b95 <time.runtimeNano+0x35>
  443b6f:	48 83 ec 10          	sub    $0x10,%rsp
  443b73:	48 89 6c 24 08       	mov    %rbp,0x8(%rsp)
  443b78:	48 8d 6c 24 08       	lea    0x8(%rsp),%rbp
  443b7d:	e8 ce f0 00 00       	callq  452c50 <runtime.nanotime>
  443b82:	48 8b 04 24          	mov    (%rsp),%rax
  443b86:	48 89 44 24 18       	mov    %rax,0x18(%rsp)
  443b8b:	48 8b 6c 24 08       	mov    0x8(%rsp),%rbp
  443b90:	48 83 c4 10          	add    $0x10,%rsp
  443b94:	c3                   	retq   
  443b95:	e8 16 bb 00 00       	callq  44f6b0 <runtime.morestack_noctxt>
  443b9a:	eb c4                	jmp    443b60 <time.runtimeNano>
  443b9c:	cc                   	int3   
  443b9d:	cc                   	int3   
  443b9e:	cc                   	int3   
  443b9f:	cc                   	int3   

Then I changes the code

From

//go:linkname time_runtimeNano time.runtimeNano
func time_runtimeNano() int64 {
	return nanotime()
}

To

//go:nosplit
//go:linkname time_runtimeNano time.runtimeNano
func time_runtimeNano() int64 {
	return nanotime()
}

Then, the assembly of time.runtimeNano becomes

0000000000443b60 <time.runtimeNano>:
  443b60:	48 83 ec 10          	sub    $0x10,%rsp
  443b64:	48 89 6c 24 08       	mov    %rbp,0x8(%rsp)
  443b69:	48 8d 6c 24 08       	lea    0x8(%rsp),%rbp
  443b6e:	e8 cd f0 00 00       	callq  452c40 <runtime.nanotime>
  443b73:	48 8b 04 24          	mov    (%rsp),%rax
  443b77:	48 89 44 24 18       	mov    %rax,0x18(%rsp)
  443b7c:	48 8b 6c 24 08       	mov    0x8(%rsp),%rbp
  443b81:	48 83 c4 10          	add    $0x10,%rsp
  443b85:	c3                   	retq   
  443b86:	cc                   	int3   
  443b87:	cc                   	int3   
  443b88:	cc                   	int3   
  443b89:	cc                   	int3   
  443b8a:	cc                   	int3   
  443b8b:	cc                   	int3   
  443b8c:	cc                   	int3   
  443b8d:	cc                   	int3   
  443b8e:	cc                   	int3   
  443b8f:	cc                   	int3  

This kind of version of time.runtimeNano is quite closer to runtime.nanotime.

@bradfitz

This comment has been minimized.

Copy link
Member

commented Nov 30, 2017

By "improper" do you just mean that this could be faster? Or is there a bug?

/cc @aclements

@zhaozhiqianghw

This comment has been minimized.

Copy link
Author

commented Nov 30, 2017

I think this could make it more accurate. It's not a bug.

@aclements

This comment has been minimized.

Copy link
Member

commented Dec 1, 2017

Marking these nosplit would not help with their accuracy. For one, nothing's stopping the OS from preempting the process at any point, which could potentially throw off any measurements no matter what we do. Also, these functions aren't exposed to user code, and anything that does expose their results to user space (like time.Now()) has its own preemption points. Even supposing we propagated nosplit all the way up to exported functions, which is already getting a little ridiculous, it would be really hard to use from user code without introducing preemption points in the user code. The only way I can think of is doing a duration measurement of something that's very carefully written to not have it's own preemption points:

start := time.Now()
... something that doesn't have preemption points ...
duration := time.Now().Sub(start)

But this is so dependent on the details of the compiler, linker, and runtime that I really don't want to expose any of this (e.g., if the above code used time.Since it would be broken again). Especially since the OS could swoop in at any time and make it all irrelevant anyway.

Finally, there's the fact that we want to have a lot more preemption points, not fewer, to solve #10958.

@aclements aclements added WaitingForInfo and removed NeedsFix labels Dec 1, 2017

@gopherbot

This comment has been minimized.

Copy link

commented Jan 1, 2018

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

@gopherbot gopherbot closed this Jan 1, 2018

@golang golang locked and limited conversation to collaborators Jan 1, 2019

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
You can’t perform that action at this time.