Bug 17333 - _wapi_handle_ref/_wapi_handle_unref_full errors
Summary: _wapi_handle_ref/_wapi_handle_unref_full errors
Status: RESOLVED NOT_REPRODUCIBLE
Alias: None
Product: Runtime
Classification: Mono
Component: GC ()
Version: 3.2.x
Hardware: Other Other
: --- normal
Target Milestone: ---
Assignee: Bugzilla
URL:
Depends on:
Blocks:
 
Reported: 2014-01-20 12:58 UTC by Jiri {x2} Cincura
Modified: 2017-07-08 03:25 UTC (History)
5 users (show)

Tags:
Is this bug a regression?: ---
Last known good build:

Notice (2018-05-24): bugzilla.xamarin.com is now in read-only mode.

Please join us on Visual Studio Developer Community and in the Xamarin and Mono organizations on GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs, copy them to the new locations as needed for follow-up, and add the new items under Related Links.

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.


Please create a new report on GitHub or Developer Community with your current version information, steps to reproduce, and relevant error messages or log files if you are hitting an issue that looks similar to this resolved bug and you do not yet see a matching new report.

Related Links:
Status:
RESOLVED NOT_REPRODUCIBLE

Description Jiri {x2} Cincura 2014-01-20 12:58:34 UTC
I'm trying to run application on a Raspberry Pi (ARMv6) on a Raspbian (hard float). When the application runs fine (see https://bugzilla.xamarin.com/show_bug.cgi?id=17217) after a while it starts showing:

_wapi_handle_ref: Attempting to ref unused handle 0x770
_wapi_handle_unref_full: Attempting to unref unused handle 0x770

Of course the "0x770" is always different. The application runs fine a while with these errors, but then stops progressing - looks like a deadlock/livelock. The trace from GDB when the application is "dead" is below.

I'm running Mono built from sources:
Mono JIT compiler version 3.2.7 (master/47071c9 Fri Jan 17 20:03:13 CET 2014)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
        TLS:           __thread
        SIGSEGV:       normal
        Notifications: epoll
        Architecture:  armel,vfp+hard
        Disabled:      none
        Misc:          softdebug
        LLVM:          supported, not enabled.
        GC:            sgen

Trace from GDB:

#0  0xb6e57494 in pthread_cond_wait@@GLIBC_2.4 () from /lib/arm-linux-gnueabihf/                                                                                libpthread.so.0
No symbol table info available.
#1  0x001db658 in _wapi_handle_timedwait_signal_handle (handle=0xd51, timeout=0x                                                                                0, alertable=1, poll=<optimized out>) at handles.c:1588
        idx = 3409
        res = <optimized out>
        cond = 0x205ccc8
        mutex = 0x205ccac
#2  0x001ee56c in WaitForSingleObjectEx (handle=0x1ee56c, timeout=3053780, alert                                                                                able=3409) at wait.c:196
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {-1225609216, -1                                                                                , -1093384356, 1, 0, 29468872, -1230389232, 0, -1093384760, 2024236, 0 <repeats                                                                                 16 times>, -2147483632, 0 <repeats 13 times>, -2147483632, 1534040, -1230057460,                                                                                 370223615, -1258972848, 29459424, 1, 4096, 46, 1531904, 12, -1230057460, 294594                                                                                24, -1258972848, -1230057460, 10, 47, 1534040, 1548372, 3090136, 1548372, -12367                                                                                92912, 1023, 3090140}, __mask_was_saved = 0}}, __pad = {0xbed45078, 0x0, 0x1d503                                                                                cc, 0xb64809b0}}
        __cancel_routine = 0x1edfac <_wapi_handle_unlock_handle>
        __cancel_arg = 0xd51
        __not_first_call = <optimized out>
        ret = <optimized out>
        waited = <optimized out>
        abstime = {tv_sec = -1236792936, tv_nsec = 30737356}
        apc_pending = 0
        current_thread = 0x1
#3  0x0015d2c4 in mono_wait_uninterrupted (thread=0xb6a9c010, multiple=-12367929                                                                                36, numhandles=1, handles=0xbed4475c, waitall=0, ms=-1, alertable=1) at threads.                                                                                c:1281
        exc = <optimized out>
        ret = <optimized out>
        start = 30737356
        diff_ms = <optimized out>
        wait = -1
#4  0x0015ec80 in ves_icall_System_Threading_WaitHandle_WaitOne_internal (this=<                                                                                optimized out>, handle=0x1c53d20, ms=-1, exitContext=<optimized out>) at threads                                                                                .c:1413
        ret = <optimized out>
        thread = 0xb6a9c010
#5  0xb5364fc0 in ?? ()
No symbol table info available.
#6  0xb5364fc0 in ?? ()
No symbol table info available.
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
Comment 1 Jiri {x2} Cincura 2014-01-23 01:15:16 UTC
After roughly 2 days of running the program stopped progressing again. Not without any "_wapi_handle_xxx" messages. But in GDB last lines were:

Program received signal SIGPIPE, Broken pipe.
[Switching to Thread 0xb5200430 (LWP 7442)]
0xb6e65e14 in send () from /lib/arm-linux-gnueabihf/libpthread.so.0

Then I obtained backtrace:

#0  0xb6e62494 in pthread_cond_wait@@GLIBC_2.4 () from /lib/arm-linux-gnueabihf/libpthread.so.0
No symbol table info available.
#1  0x001db658 in _wapi_handle_timedwait_signal_handle (handle=0x1030, timeout=0x0, alertable=1, poll=<optimized out>) at handles.c:1588
        idx = 4144
        res = <optimized out>
        cond = 0x1c5bd38
        mutex = 0x1c5bd1c
#2  0x001ee56c in WaitForSingleObjectEx (handle=0x1ee56c, timeout=3053780, alertable=4144) at wait.c:196
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {-1225564160, -1, -1093097636, 1, 0, 25110728, -1230356464, 0, -1093098040, 2024236, 0 <repeats 16 times>, -2147483632, 0 <repeats 13 times>, -2147483632, 1534040, -1230012404, 370223615, -1260060944, 25101280, 1, 4096, 3, 1531904, 14, -1230012404, 25101280, -1260060944, -1230012404, 12, 3, 1534040, 1548372, 3090136, 1548372, -1236662288, 1023, 3090140}, __mask_was_saved = 0}}, __pad = {0xbed8b078, 0x0, 0x19283fc, 0xb64a07f0}}
        __cancel_routine = 0x1edfac <_wapi_handle_unlock_handle>
        __cancel_arg = 0x1030
        __not_first_call = <optimized out>
        ret = <optimized out>
        waited = <optimized out>
        abstime = {tv_sec = -1236662312, tv_nsec = 26379260}
        apc_pending = 0
        current_thread = 0x1
#3  0x0015d2c4 in mono_wait_uninterrupted (thread=0xb6aa4010, multiple=-1236662312, numhandles=1, handles=0xbed8a75c, waitall=0, ms=-1, alertable=1) at threads.c:1281
        exc = <optimized out>
        ret = <optimized out>
        start = 26379260
        diff_ms = <optimized out>
        wait = -1
#4  0x0015ec80 in ves_icall_System_Threading_WaitHandle_WaitOne_internal (this=<optimized out>, handle=0x182bd10, ms=-1, exitContext=<optimized out>) at threads.c:1413
        ret = <optimized out>
        thread = 0xb6aa4010
#5  0xb5375fc0 in ?? ()
No symbol table info available.
#6  0xb5375fc0 in ?? ()
No symbol table info available.
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
Comment 2 Jiri {x2} Cincura 2014-01-26 06:21:50 UTC
Again, it stopped progressing, though again without any "_wapi_handle_xxx" message. The trace obtained then was:

#0  0xb6e9e494 in pthread_cond_wait@@GLIBC_2.4 () from /lib/arm-linux-gnueabihf/libpthread.so.0
No symbol table info available.
#1  0x001db658 in _wapi_handle_timedwait_signal_handle (handle=0xd78, timeout=0x0, alertable=1, poll=<optimized out>) at handles.c:1588
        idx = 3448
        res = <optimized out>
        cond = 0x20e23c0
        mutex = 0x20e23a4
#2  0x001ee56c in WaitForSingleObjectEx (handle=0x1ee56c, timeout=3053780, alertable=3448) at wait.c:196
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {-1225318400, -1, -1098492068, 1, 0, 30218440, -1245757424, 0, -1098492472, 2024236,
    0 <repeats 16 times>, -2147483632, 0 <repeats 13 times>, -2147483632, 1534040, -1229766644, 370223615, -1258702680, 30208992, 1, 4096, 44, 1531904, 12,
    -1229766644, 30208992, -1258702680, -1229766644, 10, 44, 1534040, 1548372, 3090136, 1548372, -1236769616, 1023, 3090140}, __mask_was_saved = 0}}, __pad = {
    0xbe866078, 0x0, 0x1e0733c, 0xb64864b0}}
        __cancel_routine = 0x1edfac <_wapi_handle_unlock_handle>
        __cancel_arg = 0xd78
        __not_first_call = <optimized out>
        ret = <optimized out>
        waited = <optimized out>
        abstime = {tv_sec = -1236769640, tv_nsec = 31486780}
        apc_pending = 0
        current_thread = 0x1
#3  0x0015d2c4 in mono_wait_uninterrupted (thread=0xb5bf4010, multiple=-1236769640, numhandles=1, handles=0xbe86575c, waitall=0, ms=-1, alertable=1)
    at threads.c:1281
        exc = <optimized out>
        ret = <optimized out>
        start = 31486780
        diff_ms = <optimized out>
        wait = -1
#4  0x0015ec80 in ves_icall_System_Threading_WaitHandle_WaitOne_internal (this=<optimized out>, handle=0x1d0ad10, ms=-1, exitContext=<optimized out>)
    at threads.c:1413
        ret = <optimized out>
        thread = 0xb5bf4010
#5  0xb53bf138 in ?? ()
No symbol table info available.
#6  0xb53bf138 in ?? ()
No symbol table info available.
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Basically the same as previously. Is there anything I can do to help you find the problem?
Comment 3 Jiri {x2} Cincura 2014-01-27 08:26:57 UTC
Today I was able to not only see "_wapi_handle_xxx" messages, but also attach debugger while these messages were coming. The trace is below. I still have it stopped in gdb. Some information I can provide in this state to help to spot the issue? Now if I would let it run it will deadlock/livelock itself as previously.

#0  0xb6e2f494 in pthread_cond_wait@@GLIBC_2.4 () from /lib/arm-linux-gnueabihf/libpthread.so.0
No symbol table info available.
#1  0x001db658 in _wapi_handle_timedwait_signal_handle (handle=0xf6e, timeout=0x0, alertable=1, poll=<optimized out>) at handles.c:1588
        idx = 3950
        res = <optimized out>
        cond = 0x13a0558
        mutex = 0x13a053c
#2  0x001ee56c in WaitForSingleObjectEx (handle=0x1ee56c, timeout=3053780, alertable=3950) at wait.c:196
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {-1225773056, -1, -1097111716, 1, 0, 15964360, -1230553072, 0, -1097112120, 2024236, 0 <repeats 16 times>, -2147483632, 0 <repeats 13 times>, -2147483632, 1534040,
    -1230221300, 370223615, -1259144936, 15954912, 1, 4096, 57, 1531904, 12, -1230221300, 15954912, -1259144936, -1230221300, 10, 58, 1534040, 1548372, 3090136, 1548372, -1236949712, 1023, 3090140}, __mask_was_saved = 0}},
          __pad = {0xbe9b7078, 0x0, 0x1078efc, 0xb645a530}}
        __cancel_routine = 0x1edfac <_wapi_handle_unlock_handle>
        __cancel_arg = 0xf6e
        __not_first_call = <optimized out>
        ret = <optimized out>
        waited = <optimized out>
        abstime = {tv_sec = -1236949736, tv_nsec = 17272572}
        apc_pending = 0
        current_thread = 0x1
#3  0x0015d2c4 in mono_wait_uninterrupted (thread=0xb6a74010, multiple=-1236949736, numhandles=1, handles=0xbe9b675c, waitall=0, ms=-1, alertable=1) at threads.c:1281
        exc = <optimized out>
        ret = <optimized out>
        start = 17272572
        diff_ms = <optimized out>
        wait = -1
#4  0x0015ec80 in ves_icall_System_Threading_WaitHandle_WaitOne_internal (this=<optimized out>, handle=0xf72d10, ms=-1, exitContext=<optimized out>) at threads.c:1413
        ret = <optimized out>
        thread = 0xb6a74010
#5  0xb53607b8 in ?? ()
No symbol table info available.
#6  0xb53607b8 in ?? ()
No symbol table info available.
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
Comment 4 Zoltan Varga 2014-02-27 19:07:33 UTC
A testcase showing the problem would help. Also, try using
thread apply all bt
in gdb to show backtraces for all threads.
Comment 5 Jiri {x2} Cincura 2014-03-08 13:21:01 UTC
I don't see the message now with 3.2.8 (compiled form sources, from tag mono-3.2.8). Although the application still [dead|live]locks itself. I'm trying to find some clue and extract repro.

Mono JIT compiler version 3.2.8 ((no/b1e8599 Thu Mar  6 03:29:58 CET 2014)
Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
        TLS:           __thread
        SIGSEGV:       normal
        Notifications: epoll
        Architecture:  armel,vfp+hard
        Disabled:      none
        Misc:          softdebug
        LLVM:          supported, not enabled.
        GC:            sgen
Comment 6 Vlad Brezae 2016-12-20 01:12:57 UTC
Hello Jiri. Is this problem still present will recent mono ?
Comment 7 Jiri {x2} Cincura 2016-12-20 13:00:29 UTC
I can't tell. I no longer run that app in this environment.
Comment 8 Ludovic Henry 2017-07-08 03:25:47 UTC
If you can still reproduce with latest mono, feel free to reopen, and please provide a repro case. Thank you.