[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: [e-mail]
          Reporter: [e-mail]
      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

[Bug 38272] 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

--- Comment #1 from [e-mail] ---
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

[Bug 38272] 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

--- Comment #2 from Nikolay Sivov  ---
First thing to look at is to figure out how time.Now()/Sleep() things are
implemented.

[Bug 38272] 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

--- Comment #3 from Nikolay Sivov  ---
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;
}
---

[Bug 38272] 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

Brad Fitzpatrick  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

--- Comment #4 from Brad Fitzpatrick  ---
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)

[Bug 38272] 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

Sebastian Lackner  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

--- Comment #5 from Sebastian Lackner  ---
(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.

[Bug 38272] 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

--- Comment #6 from Nikolay Sivov  ---
(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.

[Bug 38272] 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

--- Comment #7 from Brad Fitzpatrick  ---
> 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.

[Bug 38272] 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

Alex Brainman  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

--- Comment #8 from Alex Brainman  ---
(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

[Bug 38272] 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

--- Comment #9 from Nikolay Sivov  ---
(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

[Bug 38272] 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

--- Comment #10 from Alex Brainman  ---
(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

[Bug 38272] 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

--- Comment #11 from Alex Brainman  ---
(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

[Bug 38272] 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

--- Comment #12 from [e-mail] ---
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.

[Bug 38272] 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

--- Comment #13 from Nikolay Sivov  ---
(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.

[Bug 38272] 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

--- Comment #14 from [e-mail] ---
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>

[Bug 38272] 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

--- Comment #15 from Bruno Jesus  ---
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

[Bug 38272] 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

--- Comment #16 from [e-mail] ---
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.

[Bug 38272] binaries produced by Go 1.4+ compiler hang when using time.Sleep() and time.Now() (KSYSTEM_TIME members in KUSER_SHARED_DATA are not updated)

https://bugs.winehq.org/show_bug.cgi?id=38272

Anastasius Focht  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|UNCONFIRMED                 |RESOLVED
                 CC|                            |[e-mail]
         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  ---
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 ***

[Bug 38272] binaries produced by Go 1.4+ compiler hang when using time.Sleep() and time.Now() (KSYSTEM_TIME members in KUSER_SHARED_DATA are not updated)

https://bugs.winehq.org/show_bug.cgi?id=38272

Bruno Jesus  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #18 from Bruno Jesus  ---
Closing duplicate bugs.

[Bug 38272] binaries produced by Go 1.4+ compiler hang when using time.Sleep() and time.Now() (KSYSTEM_TIME members in KUSER_SHARED_DATA are not updated)

https://bugs.winehq.org/show_bug.cgi?id=38272

Qian Hong  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

[Bug 38272] binaries produced by Go 1.4+ compiler hang when using time.Sleep() and time.Now() (KSYSTEM_TIME members in KUSER_SHARED_DATA are not updated)

https://bugs.winehq.org/show_bug.cgi?id=38272

Anastasius Focht  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

--- Comment #19 from Anastasius Focht  ---
*** Bug 38636 has been marked as a duplicate of this bug. ***