[Bug 38272] New: binaries produced by Go compiler hang when using time.Sleep() and time.Now() is not updated
https://bugs.winehq.org/show_bug.cgi?id=38272 Bug ID: 38272 Summary: binaries produced by Go compiler hang when using time.Sleep() and time.Now() is not updated Product: Wine Version: 1.7.38 Hardware: x86 OS: Linux Status: UNCONFIRMED Severity: normal Priority: P2 Component: -unknown Assignee: wine-bugs(a)winehq.org Reporter: leonbogaert+winehq(a)gmail.com Distribution: --- Created attachment 51100 --> https://bugs.winehq.org/attachment.cgi?id=51100 executable + go source of example that hangs forever When I compile this simple program and run it under wine (1.7, ubuntu 14.04) it hangs indefinitely: package main import ( "fmt" "time" ) func main() { fmt.Println("before") fmt.Println(time.Now()) time.Sleep(10 * time.Second) fmt.Println(time.Now()) fmt.Println("after") } Is there a way I could debug this? Can somebody else reproduce this behavior? I tried cross-compiling it on my linux laptop and under Windows but it doesn't make a difference: it hangs. When run on Windows it works fine. When I directly call the windows sycall Sleep(): package main import ( "fmt" "time" "github.com/akavel/winq" ) func main() { var try winq.Try fmt.Println("before") fmt.Println(time.Now()) try.N("Sleep", 5000) fmt.Println(time.Now()) fmt.Println("after") } time.Now() is never updated: before 2015-03-23 18:41:35.543452 +0100 CET 2015-03-23 18:41:35.543452 +0100 CET after -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #1 from leonbogaert+winehq(a)gmail.com --- When running it under the debug mode when it hangs this message get repeated over and over: 0063:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=0042fe55 0063:Call KERNEL32.WaitForSingleObject(00000048,00002710) ret=0042fe55 0063:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=0042fe55 0063:Call KERNEL32.WaitForSingleObject(00000048,00002710) ret=0042fe55 0063:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=0042fe55 0063:Call KERNEL32.WaitForSingleObject(00000048,00002710) ret=0042fe55 0063:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=0042fe55 0063:Call KERNEL32.WaitForSingleObject(00000048,00002710) ret=0042fe55 -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #2 from Nikolay Sivov <bunglehead(a)gmail.com> --- First thing to look at is to figure out how time.Now()/Sleep() things are implemented. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #3 from Nikolay Sivov <bunglehead(a)gmail.com> --- I looked it up out of curiosity, and the reason seems to be that Go runtime doesn't use APIs to get timestamps, and instead uses fixed address access to read process memory, where supposedly kernel mirrors some time info as well other information: --- src/runtime/os_windows.c --- #pragma dataflag NOPTR const KSYSTEM_TIME* INTERRUPT_TIME = (KSYSTEM_TIME*)0x7ffe0008; #pragma dataflag NOPTR const KSYSTEM_TIME* SYSTEM_TIME = (KSYSTEM_TIME*)0x7ffe0014; static void badsystime(void); #pragma textflag NOSPLIT int64 runtimeВ·systime(KSYSTEM_TIME *timeaddr) { KSYSTEM_TIME t; int32 i; void (*fn)(void); for(i = 1; i < 10000; i++) { // these fields must be read in that order (see URL above) t.High1Time = timeaddr->High1Time; t.LowPart = timeaddr->LowPart; t.High2Time = timeaddr->High2Time; if(t.High1Time == t.High2Time) return (int64)t.High1Time<<32 | t.LowPart; if((i%100) == 0) runtimeВ·osyield(); } fn = badsystime; runtimeВ·onM(&fn); return 0; } #pragma textflag NOSPLIT int64 runtimeВ·unixnano(void) { return (runtimeВ·systime(SYSTEM_TIME) - 116444736000000000LL) * 100LL; } --- -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Brad Fitzpatrick <bradfitz(a)golang.org> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |bradfitz(a)golang.org --- Comment #4 from Brad Fitzpatrick <bradfitz(a)golang.org> --- FWIW, the Go runtime changed from using GetSystemTimeAsFileTime to reading the time from memory directly on Windows for Go 1.4 via this change: https://codereview.appspot.com/108700045 to address this monotonic clock issue: https://github.com/golang/go/issues/6007 (which used to be about several OSes, not just NetBSD) -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Sebastian Lackner <sebastian(a)fds-team.de> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |sebastian(a)fds-team.de --- Comment #5 from Sebastian Lackner <sebastian(a)fds-team.de> --- (In reply to Nikolay Sivov from comment #3)
I looked it up out of curiosity, and the reason seems to be that Go runtime doesn't use APIs to get timestamps, and instead uses fixed address access to read process memory, where supposedly kernel mirrors some time info as well other information:
That means its a duplicate of https://bugs.winehq.org/show_bug.cgi?id=29168 The bug report contains several hacks (for example https://bugs.winehq.org/attachment.cgi?id=47704&action=diff ) to workaround the problem. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #6 from Nikolay Sivov <bunglehead(a)gmail.com> --- (In reply to Brad Fitzpatrick from comment #4)
FWIW, the Go runtime changed from using GetSystemTimeAsFileTime to reading the time from memory directly on Windows for Go 1.4 via this change:
https://codereview.appspot.com/108700045
to address this monotonic clock issue:
https://github.com/golang/go/issues/6007 (which used to be about several OSes, not just NetBSD)
Hi, Brad. Do you happen to know why QueryPerformanceCounter/QueryPerformanceFrequency/NtQueryPerformanceCounter wasn't used for that? (In reply to Sebastian Lackner from comment #5)
That means its a duplicate of https://bugs.winehq.org/show_bug.cgi?id=29168
Looks like it, yes. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #7 from Brad Fitzpatrick <bradfitz(a)golang.org> ---
Do you happen to know why QueryPerformanceCounter/QueryPerformanceFrequency/NtQueryPerformanceCounter wasn't used for that?
I'm not a Windows person, but the bug tracker suggests that it was at least partially because it doesn't work on Windows XP, which Go supports. It might also be due to performance. I'll point the Go Windows people at this bug where they might correct me. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Alex Brainman <alex.brainman(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |alex.brainman(a)gmail.com --- Comment #8 from Alex Brainman <alex.brainman(a)gmail.com> --- (In reply to Nikolay Sivov from comment #6)
Do you happen to know why QueryPerformanceCounter/QueryPerformanceFrequency/NtQueryPerformanceCounter wasn't used for that?
As I recall it, QPC didn't work properly on my PC. From https://codereview.appspot.com/108700045#msg11
... But it does not work on my XP https://code.google.com/p/go/issues/detail?id=6007#c36 ...
If you follow that link, you can see small program and its output. As I interpret my results, QPC is wrong. And second reason was performance. Some CL reviewers raised concerns about QPC performance. And Dmitriy suggested something simple. I was sceptical first, but we haven't had anyone complained yet. Except people who use WINE. Alex -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #9 from Nikolay Sivov <bunglehead(a)gmail.com> --- (In reply to Alex Brainman from comment #8)
(In reply to Nikolay Sivov from comment #6)
Do you happen to know why QueryPerformanceCounter/QueryPerformanceFrequency/NtQueryPerformanceCounter wasn't used for that?
As I recall it, QPC didn't work properly on my PC. From https://codereview.appspot.com/108700045#msg11
... But it does not work on my XP https://code.google.com/p/go/issues/detail?id=6007#c36 ...
If you follow that link, you can see small program and its output. As I interpret my results, QPC is wrong.
Yes, looks strange. However it will be interesting to see native program result on this system. Also msdn claims that in some cases XP will fail to provide accurate values, depending on hardware. How can I run this Go test program of yours in Wine? Could you attach a binary here?
And second reason was performance. Some CL reviewers raised concerns about QPC performance. And Dmitriy suggested something simple. I was sceptical first, but we haven't had anyone complained yet. Except people who use WINE.
Yes, for Wine QPC would be preferred currently, as long as we don't have an acceptable solution that updates this process memory data you're using (and having another entity like a separate thread to update it probably won't help performance, but it needs testing).
Alex
-- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #10 from Alex Brainman <alex.brainman(a)gmail.com> --- (In reply to Nikolay Sivov from comment #9)
... However it will be interesting to see native program result on this system.
I wrote similar program with MS Visual C. It reports similar results.
... How can I run this Go test program of yours in Wine?
You can build it yourself ( the source http://play.golang.org/p/8xApPuS-Ah ). You can build it on any OS - Go cross compile pretty well.
Could you attach a binary here?
I will try.
Yes, for Wine QPC would be preferred currently, as long as we don't have an acceptable solution that updates this process memory data you're using (and having another entity like a separate thread to update it probably won't help performance, but it needs testing).
I understand. But I am not sure there is enough Go programs running on WINE for Go Team to invest their time maintaining WINE support. Alex -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #11 from Alex Brainman <alex.brainman(a)gmail.com> --- (In reply to Nikolay Sivov from comment #9)
... Could you attach a binary here?
The binary is too big. It is under 2M. Your bug tracking system refuses to accept files that large. Alex -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #12 from leonbogaert+winehq(a)gmail.com --- Created attachment 51105 --> https://bugs.winehq.org/attachment.cgi?id=51105 Alex' go program as binary I've attached the program Alex' mentioned as windows binary. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #13 from Nikolay Sivov <bunglehead(a)gmail.com> --- (In reply to leonbogaert+winehq from comment #12)
Created attachment 51105 [details] Alex' go program as binary
I've attached the program Alex' mentioned as windows binary.
Thank you. With current Wine it gives me: --- freq=10000000 c1=20212930054540 c2=20212940066008 expected to sleep 1000 milliseconds, but slept for 1001 --- On Windows 7 installation it's valid as well: --- freq=3125009 c1=232775435882 c2=232778559918 expected to sleep 1000 milliseconds, but slept for 999 --- Win8.1 vbox vm: --- freq=2186688 c1=144158294 c2=146345314 expected to sleep 1000 milliseconds, but slept for 1000 --- I don't have winxp installation to test, but it looks like you was unlucky to hit this system problem msdn talks about, or something like that.(In reply to Alex Brainman from comment #10)
(In reply to Nikolay Sivov from comment #9)
Yes, for Wine QPC would be preferred currently, as long as we don't have an acceptable solution that updates this process memory data you're using (and having another entity like a separate thread to update it probably won't help performance, but it needs testing).
I understand. But I am not sure there is enough Go programs running on WINE for Go Team to invest their time maintaining WINE support.
Sure, I don't expect you to. Maybe someone interested enough will. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #14 from leonbogaert+winehq(a)gmail.com --- My Windows XP SP3 virtualbox image (https://www.modern.ie/en-us/virtualization-tools#downloads) gives: Microsoft Windows XP [Version 5.1.2600] (C) Copyright 1985-2001 Microsoft Corp. C:\Documents and Settings\IEUser>e:\test.exe freq=2287660000 c1=133139353787 c2=135425055055 expected to sleep 1000 milliseconds, but slept for 999 C:\Documents and Settings\IEUser>e:\test.exe freq=2287660000 c1=140968654941 c2=143254470263 expected to sleep 1000 milliseconds, but slept for 999 C:\Documents and Settings\IEUser> -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #15 from Bruno Jesus <00cpxxx(a)gmail.com> --- Is this bug related to bug 29168? The address 0x7ffe0008 seems to be the same from the user_shared_data that is requested by the game in that bug and the following patch/hack was produced to fix it. https://bugs.winehq.org/show_bug.cgi?id=29168#c274 -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 --- Comment #16 from leonbogaert+winehq(a)gmail.com --- Looks like the same unimplemented feature indeed. I'm going to try the patch (https://bugs.winehq.org/attachment.cgi?id=47704) and see if it works. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|UNCONFIRMED |RESOLVED CC| |focht(a)gmx.net Resolution|--- |DUPLICATE Summary|binaries produced by Go |binaries produced by Go |compiler hang when using |1.4+ compiler hang when |time.Sleep() and time.Now() |using time.Sleep() and |is not updated |time.Now() (KSYSTEM_TIME | |members in | |KUSER_SHARED_DATA are not | |updated) --- Comment #17 from Anastasius Focht <focht(a)gmx.net> --- Hello folks, no need to keep this ticket opened separately since this is obviously a dupe of bug 29168 Regards *** This bug has been marked as a duplicate of bug 29168 *** -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Bruno Jesus <00cpxxx(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED --- Comment #18 from Bruno Jesus <00cpxxx(a)gmail.com> --- Closing duplicate bugs. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Qian Hong <fracting(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |fracting(a)gmail.com -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=38272 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |michael.tiller(a)gmail.com --- Comment #19 from Anastasius Focht <focht(a)gmx.net> --- *** Bug 38636 has been marked as a duplicate of this bug. *** -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
participants (1)
-
wine-bugs＠winehq.org