Bug 249435 - Analyzing wine programs with callgrind triggers a crash
Summary: Analyzing wine programs with callgrind triggers a crash
Status: RESOLVED FIXED
Alias: None
Product: valgrind
Classification: Developer tools
Component: callgrind (other bugs)
Version First Reported In: 3.6 SVN
Platform: Compiled Sources Linux
: NOR crash
Target Milestone: blocking3.6.0
Assignee: Josef Weidendorfer
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-08-29 18:46 UTC by Bart Van Assche
Modified: 2014-09-17 23:08 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:
Sentry Crash Report:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Bart Van Assche 2010-08-29 18:46:05 UTC
Version:           3.6 SVN (using Devel) 
OS:                Linux

OS: Linux, 64-bit.
Valgrind version: trunk revision 11304.
Wine version: master branch of Wine git repository cloned on August 28, 2010.

$ ./vg-in-place --trace-children=yes --vex-iropt-precise-memory-exns=yes --tool=callgrind wine notepad
[ ... ]
==351== Callgrind, a call-graph generating cache profiler
==351== Copyright (C) 2002-2010, and GNU GPL'd, by Josef Weidendorfer et al.
==351== Using Valgrind-3.6.0.SVN and LibVEX; rerun with -h for copyright info
==351== Command: /usr/bin/wine-preloader /usr/bin/wine C:\\windows\\system32\\winedevice.exe MountMgr
==351== 
==351== For interactive control, run 'callgrind_control -h'.
preloader: Warning: failed to reserve range 00110000-68000000
0x0000e670
BB# 619749

Callgrind: threads.c:248 (vgCallgrind_post_signal): Assertion 'sigNum == vgCallgrind_current_state.sig' failed.
==349==    at 0x3801E225: report_and_quit (m_libcassert.c:191)
==349==    by 0x3801E385: vgPlain_assert_fail (m_libcassert.c:265)
==349==    by 0x3801C047: vgCallgrind_post_signal (threads.c:248)
==349==    by 0x3805DFF4: vgPlain_sigframe_destroy (sigframe-x86-linux.c:723)
==349==    by 0x3808F875: vgSysWrap_x86_linux_sys_rt_sigreturn_before (syswrap-x86-linux.c:1034)
==349==    by 0x3805E9F0: vgPlain_client_syscall (syswrap-main.c:1443)
==349==    by 0x3805B052: handle_syscall (scheduler.c:895)
==349==    by 0x3805C558: vgPlain_scheduler (scheduler.c:1091)
==349==    by 0x3806E634: run_a_thread_NORETURN (syswrap-linux.c:94)
==349==    by 0x3806E8F2: vgModuleLocal_start_thread_NORETURN (syswrap-linux.c:225)
==349==    by 0x3808CDE8: ??? (in /home/bart/software/valgrind/callgrind/callgrind-x86-linux)

sched status:
  running_tid=3

Thread 1: status = VgTs_WaitSys
==349==    at 0x494412B: ??? (in /lib/libpthread-2.11.2.so)
==349==    by 0x7BC73C06: NTDLL_wait_for_multiple_objects (sync.c:1124)
==349==    by 0x7BC73D20: NtWaitForMultipleObjects (sync.c:1162)
==349==    by 0x7BC73D6B: NtWaitForSingleObject (sync.c:1171)
==349==    by 0x7BC3E98F: server_ioctl_file (file.c:1276)
==349==    by 0x7BC41521: NtFsControlFile (file.c:1501)
==349==    by 0x7B865091: ConnectNamedPipe (sync.c:1592)
==349==    by 0x491A50F: service_start (services.c:651)
==349==    by 0x491AB3C: main (services.c:270)

Thread 2: status = VgTs_WaitSys
==349==    at 0x494412B: ??? (in /lib/libpthread-2.11.2.so)
==349==    by 0x7BC73C06: NTDLL_wait_for_multiple_objects (sync.c:1124)
==349==    by 0x7BC73D20: NtWaitForMultipleObjects (sync.c:1162)
==349==    by 0x7B862A68: WaitForMultipleObjectsEx (sync.c:191)
==349==    by 0x6B49CC9: rpcrt4_protseq_np_wait_for_new_connection (rpc_transport.c:715)
==349==    by 0x6B4042E: RPCRT4_server_thread (rpc_server.c:674)
==349==    by 0x7BC6DF1F: ??? (in /usr/lib/wine/ntdll.dll.so)
==349==    by 0x7BC6FFB9: call_thread_entry_point (signal_i386.c:2473)
==349==    by 0x7BC755DD: start_thread (thread.c:399)
==349==    by 0x493CB24: start_thread (in /lib/libpthread-2.11.2.so)
==349==    by 0x4A2546D: clone (in /lib/libc-2.11.2.so)

Thread 3: status = VgTs_Runnable
==349==    at 0x49420E6: pthread_sigmask (in /lib/libpthread-2.11.2.so)
==349==    by 0x7BC7554A: start_thread (thread.c:388)
==349==    by 0x493CB24: start_thread (in /lib/libpthread-2.11.2.so)
==349==    by 0x4A2546D: clone (in /lib/libc-2.11.2.so)


Note: see also the FAQ in the source distribution.
It contains workarounds to several common problems.
In particular, if Valgrind aborted or crashed after
identifying problems in your program, there's a good chance
that fixing those problems will prevent Valgrind aborting or
crashing, especially if it happened in m_mallocfree.c.

If that doesn't help, please report this bug to: www.valgrind.org

In the bug report, send all the above text, the valgrind
version, and what OS and version you are using.  Thanks.


Reproducible: Always
Comment 1 Josef Weidendorfer 2010-08-31 19:41:43 UTC
Ah, thanks, I can reproduce it.
Comment 2 Josef Weidendorfer 2010-09-02 20:20:17 UTC
Wow... it seems that VG core can call into the post_signal hook of a tool
more than once for exactly the same signal. How can this be?
Or do I misinterpret the following debug output?

I just log the calls into pre/post_signal like that:

  void CLG_(pre_signal)(ThreadId tid, Int sigNum, Bool alt_stack)
  {
    VG_(message)(Vg_DebugMsg, ">> pre_signal(TID %d, sig %d, alt_st %s)\n",
                tid, sigNum, alt_stack ? "yes":"no");
    ...
  }

and with

  ./vg-in-place --trace-children=yes --vex-iropt-precise-memory-exns=yes \
     --trace-signals=yes --tool=callgrind wine notepad

I get

...
--994-- poll_signals: got signal 10 for thread 3
--994-- Polling found signal 10 for tid 3
--994-- delivering signal 10 (SIGUSR1):-6 to thread 3
--994-- push_signal_frame (thread 3): signal 10
==994==    at 0x41BC0E6: pthread_sigmask (pthread_sigmask.c:50)
==994==    by 0x7BC7ACF5: ??? (in /usr/lib/wine/ntdll.dll.so)
==994==    by 0x41B6B24: start_thread (pthread_create.c:297)
==994==    by 0x429F46D: clone (clone.S:130)
--994-- delivering signal 10 (SIGUSR1) to thread 3: on ALT STACK (0x7FFD1000-0x7FFD4000; 12288 bytes)
--994-- >> pre_signal(TID 3, sig 10, alt_st yes)
--994-- >> post_signal(TID 3, sig 10)

... [a few lines with do_setmask skipped]

--994-- do_setmask: tid = 3 how = 2 (SIG_SETMASK), newset = 0x7FFD2B74 (0000000010012a03)
--994-- do_setmask: tid = 3 how = 0 (SIG_BLOCK), newset = 0x7BCC7AC0 (0000000010012a03)
--994--         oldset=0x7FFD2DA4 0000000010012a03
--994-- do_setmask: tid = 3 how = 2 (SIG_SETMASK), newset = 0x7FFD2DA4 (0000000010012a03)
--994-- VG_(signal_return) (thread 3): isRT=1 valid magic; EIP=0x4000832
--994-- >> post_signal(TID 3, sig 10)
0x0000e670
BB# 799857

Callgrind: threads.c:250 (vgCallgrind_post_signal): Assertion 'sigNum == vgCallgrind_current_state.sig' failed.
==994==    at 0x3801E155: report_and_quit (m_libcassert.c:191)
...


Callgrind maintans a stack of signal handlers currently active for each thread
(signal handlers should be seens as sponaneous calls, and not pollute the
applications call graph). Thus, it relies on just one post_signal for every pre_signal.

So, is this a bug in VG, or do I need to handle this in Callgrind?
Comment 3 Bart Van Assche 2010-09-02 20:26:41 UTC
(In reply to comment #2)
> [ ... ]
> So, is this a bug in VG, or do I need to handle this in Callgrind?

It depends ... is the last line that reads ">> post_signal(TID 3, sig 10)" generated by a call from the core into CLG_(post_signal)() or by a call from CLG_(run_post_signal_on_call_stack_bottom)() into CLG_(post_signal)() ?
Comment 4 Josef Weidendorfer 2010-09-02 20:44:06 UTC
Good point :-) I obviously do not know my own code.

CLG_(post_signal)() is called from CLG_(run_post_signal_on_call_stack_bottom)()
when I assume that there will be no call into post_signal from VG core anymore
because of a longjmp back from the signal handler...

Hmm. It looks like the bug is actually in Callgrind. It makes no sense to
assume a longjmp from the signal handler whenever there is a return from a function :-)
Comment 5 Josef Weidendorfer 2010-10-31 21:42:05 UTC
Note regarding my last sentence in comment #4: it sounded like I know
the problem, but it is more tricky than that. Have to investigate further...
Comment 6 Julian Seward 2011-02-09 12:16:41 UTC
Josef, do you think this is related to (or a dup of) bug 246152 ?
Comment 7 Josef Weidendorfer 2011-02-10 02:44:34 UTC
That was the first thing I tested after fixing 246152.
No, this bug still appears :(

It could be that my assumption on what should happen after
running a signal handler simply is wrong. Callgrind itself
triggers a call to post_signal, as on its shadow stack, the
signal handler frame is unwound for some reason. This would
happen if the stack pointer in the signal handler is going
beyound the point where it was when the signal handler was
called. ..
Comment 8 Austin English 2014-05-28 00:32:37 UTC
This appears to be fixed in 3.9.0:

austin@aw25 ~/src/valgrind $ valgrind --trace-children=yes --vex-iropt-precise-memory-exns=yes --tool=callgrind wine notepad
valgrind: Bad option: --vex-iropt-precise-memory-exns=yes
valgrind: --vex-iropt-precise-memory-exns is obsolete
valgrind: Use --vex-iropt-register-updates=allregs-at-mem-access instead
valgrind:  (or --vex-iropt-register-updates=allregs-at-each-insn)
valgrind: Use --help for more information or consult the user manual.
austin@aw25 ~/src/valgrind $ valgrind --trace-children=yes --vex-iropt-register-updates=allregs-at-mem-access --tool=callgrind wine notepad
==13434== Callgrind, a call-graph generating cache profiler
==13434== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==13434== Using Valgrind-3.9.0 and LibVEX; rerun with -h for copyright info
==13434== Command: wine notepad
==13434== 
==13434== For interactive control, run 'callgrind_control -h'.
==13434== Callgrind, a call-graph generating cache profiler
==13434== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==13434== Using Valgrind-3.9.0 and LibVEX; rerun with -h for copyright info
==13434== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine notepad
==13434== 
==13434== For interactive control, run 'callgrind_control -h'.
preloader: Warning: failed to reserve range 00110000-68000000
preloader: Warning: failed to reserve range 7f000000-82000000
==13434== 
==13434== Events    : Ir
==13434== Collected : 139667288
==13434== 
==13434== I   refs:      139,667,288
austin@aw25 ~/src/valgrind $ valgrind --version
valgrind-3.9.0
Comment 9 Julian Seward 2014-08-29 23:26:10 UTC
Closing.  Please reopen if you can still reproduce with the trunk.
Comment 10 Austin English 2014-09-01 22:09:33 UTC
For reference, just checked in SVN. It works if  start a wine process before running callgrind (to start wineserver):
austin@debian-home:~/src/valgrind$ ./vg-in-place --trace-children=yes --vex-iropt-register-updates=allregs-at-mem-access --tool=callgrind wine notepad
==14317== Callgrind, a call-graph generating cache profiler
==14317== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14317== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14317== Command: wine notepad
==14317== 
==14317== For interactive control, run 'callgrind_control -h'.
==14317== Callgrind, a call-graph generating cache profiler
==14317== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14317== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14317== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine notepad
==14317== 
==14317== For interactive control, run 'callgrind_control -h'.
preloader: Warning: failed to reserve range 00110000-68000000
==14317== 
==14317== Events    : Ir
==14317== Collected : 163293285
==14317== 
==14317== I   refs:      163,293,285

But if no wine process is running first (wineserver -k); then I do get this:
austin@debian-home:~/src/valgrind$ ./vg-in-place --trace-children=yes --vex-iropt-register-updates=allregs-at-mem-access --tool=callgrind wine notepad
==14330== Callgrind, a call-graph generating cache profiler
==14330== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14330== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14330== Command: wine notepad
==14330== 
==14330== For interactive control, run 'callgrind_control -h'.
==14330== Callgrind, a call-graph generating cache profiler
==14330== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14330== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14330== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine notepad
==14330== 
==14330== For interactive control, run 'callgrind_control -h'.
preloader: Warning: failed to reserve range 00110000-68000000
==14332== Callgrind, a call-graph generating cache profiler
==14332== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14332== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14332== Command: /usr/local/bin/wineserver
==14332== 
==14332== For interactive control, run 'callgrind_control -h'.
==14332== 
==14332== Events    : Ir
==14332== Collected : 540259
==14332== 
==14332== I   refs:      540,259
==14335== 
==14336== Callgrind, a call-graph generating cache profiler
==14336== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14336== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14336== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine C:\\windows\\system32\\wineboot.exe --init
==14336== 
==14336== For interactive control, run 'callgrind_control -h'.
==14335== Events    : Ir
==14335== Collected : 2526245
==14335== 
==14335== I   refs:      2,526,245
preloader: Warning: failed to reserve range 00110000-68000000
==14337== 
==14338== Callgrind, a call-graph generating cache profiler
==14338== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14338== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14338== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine C:\\windows\\system32\\winemenubuilder.exe -a -r
==14338== 
==14338== For interactive control, run 'callgrind_control -h'.
==14337== Events    : Ir
==14337== Collected : 4030842
==14337== 
==14337== I   refs:      4,030,842
preloader: Warning: failed to reserve range 00110000-68000000
==14339== 
==14340== Callgrind, a call-graph generating cache profiler
==14340== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14340== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14340== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine C:\\windows\\system32\\services.exe
==14340== 
==14340== For interactive control, run 'callgrind_control -h'.
==14339== Events    : Ir
==14339== Collected : 4116033
==14339== 
==14339== I   refs:      4,116,033
preloader: Warning: failed to reserve range 00110000-68000000
==14343== 
==14344== Callgrind, a call-graph generating cache profiler
==14344== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14344== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14344== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine C:\\windows\\system32\\winedevice.exe MountMgr
==14344== 
==14344== For interactive control, run 'callgrind_control -h'.
==14343== Events    : Ir
==14343== Collected : 3797396
==14343== 
==14343== I   refs:      3,797,396
preloader: Warning: failed to reserve range 00110000-68000000
==14345== 
==14346== Callgrind, a call-graph generating cache profiler
==14346== Copyright (C) 2002-2013, and GNU GPL'd, by Josef Weidendorfer et al.
==14346== Using Valgrind-3.10.0.SVN and LibVEX; rerun with -h for copyright info
==14346== Command: /usr/local/bin/wine-preloader /usr/local/bin/wine C:\\windows\\system32\\explorer.exe /desktop
==14346== 
==14346== For interactive control, run 'callgrind_control -h'.
==14345== Events    : Ir
==14345== Collected : 65482795
==14345== 
==14345== I   refs:      65,482,795
preloader: Warning: failed to reserve range 00110000-68000000
0x0000ecd0
BB# 898456

Callgrind: threads.c:246 (vgCallgrind_post_signal): Assertion 'sigNum == vgCallgrind_current_state.sig' failed.

host stacktrace:
==14340==    at 0x3803DBE0: show_sched_status_wrk (m_libcassert.c:319)
==14340==    by 0x3803DCF1: report_and_quit (m_libcassert.c:390)
==14340==    by 0x3803DE10: vgPlain_assert_fail (m_libcassert.c:455)
==14340==    by 0x3803B5F5: vgCallgrind_post_signal (threads.c:246)
==14340==    by 0x38089527: vgPlain_sigframe_destroy (sigframe-x86-linux.c:724)
==14340==    by 0x380B7CFF: vgSysWrap_x86_linux_sys_rt_sigreturn_before (syswrap-x86-linux.c:1013)
==14340==    by 0x38089EAA: vgPlain_client_syscall (syswrap-main.c:1586)
==14340==    by 0x38086BD0: handle_syscall (scheduler.c:1103)
==14340==    by 0x38088176: vgPlain_scheduler (scheduler.c:1416)
==14340==    by 0x38096461: run_a_thread_NORETURN (syswrap-linux.c:103)
==14340==    by 0x380967CA: vgModuleLocal_start_thread_NORETURN (syswrap-linux.c:316)
==14340==    by 0x380B6C08: ??? (in /home/austin/src/valgrind/callgrind/callgrind-x86-linux)

sched status:
  running_tid=4

Thread 1: status = VgTs_WaitSys
==14340==    at 0x420A9FB: ??? (syscall-template.S:81)
==14340==    by 0x7BC77E1E: wait_select_reply (server.c:335)
==14340==    by 0x7BC7922A: server_select (server.c:599)
==14340==    by 0x7BC80E48: NtWaitForMultipleObjects (sync.c:863)
==14340==    by 0x7B86AE4B: WaitForMultipleObjectsEx.part.0 (sync.c:188)
==14340==    by 0x7B86B0A4: WaitForMultipleObjectsEx (sync.c:197)
==14340==    by 0x7B86B16E: WaitForMultipleObjects (sync.c:148)
==14340==    by 0x45EE102: service_start (services.c:752)
==14340==    by 0x45E820A: main (services.c:303)

Thread 2: status = VgTs_WaitSys
==14340==    at 0x420A9FB: ??? (syscall-template.S:81)
==14340==    by 0x7BC77E1E: wait_select_reply (server.c:335)
==14340==    by 0x7BC7922A: server_select (server.c:599)
==14340==    by 0x7BC80E48: NtWaitForMultipleObjects (sync.c:863)
==14340==    by 0x7B86AE4B: WaitForMultipleObjectsEx.part.0 (sync.c:188)
==14340==    by 0x7B86B0A4: WaitForMultipleObjectsEx (sync.c:197)
==14340==    by 0x464C2F7: rpcrt4_protseq_np_wait_for_new_connection (rpc_transport.c:719)
==14340==    by 0x4641B34: RPCRT4_server_thread (rpc_server.c:668)
==14340==    by 0x7BC7A20F: ??? (in /usr/local/lib/wine/ntdll.dll.so)
==14340==    by 0x7BC7CDF0: call_thread_func (signal_i386.c:2637)
==14340==    by 0x7BC7A1ED: ??? (in /usr/local/lib/wine/ntdll.dll.so)
==14340==    by 0x7BC833D2: start_thread (thread.c:429)
==14340==    by 0x4203EFA: start_thread (pthread_create.c:309)
==14340==    by 0x43040ED: clone (clone.S:129)

Thread 3: status = VgTs_WaitSys
==14340==    at 0x420A9FB: ??? (syscall-template.S:81)
==14340==    by 0x7BC45BB4: NtReadFile (file.c:654)
==14340==    by 0x7B83AED8: ReadFile (file.c:443)
==14340==    by 0x4647394: rpcrt4_conn_np_read (rpc_transport.c:423)
==14340==    by 0x4640496: RPCRT4_receive_fragment (rpc_binding.h:183)
==14340==    by 0x4640760: RPCRT4_ReceiveWithAuth (rpc_message.c:1396)
==14340==    by 0x46431C7: RPCRT4_io_thread (rpc_server.c:564)
==14340==    by 0x7BC7A20F: ??? (in /usr/local/lib/wine/ntdll.dll.so)
==14340==    by 0x7BC7CDF0: call_thread_func (signal_i386.c:2637)
==14340==    by 0x7BC7A1ED: ??? (in /usr/local/lib/wine/ntdll.dll.so)
==14340==    by 0x7BC833D2: start_thread (thread.c:429)
==14340==    by 0x4203EFA: start_thread (pthread_create.c:309)
==14340==    by 0x43040ED: clone (clone.S:129)

Thread 4: status = VgTs_Runnable
==14340==    at 0x4208CBF: pthread_sigmask (pthread_sigmask.c:48)
==14340==    by 0x7BC833B0: start_thread (thread.c:422)
==14340==    by 0x4203EFA: start_thread (pthread_create.c:309)
==14340==    by 0x43040ED: clone (clone.S:129)


Note: see also the FAQ in the source distribution.
It contains workarounds to several common problems.
In particular, if Valgrind aborted or crashed after
identifying problems in your program, there's a good chance
that fixing those problems will prevent Valgrind aborting or
crashing, especially if it happened in m_mallocfree.c.

If that doesn't help, please report this bug to: www.valgrind.org

In the bug report, send all the above text, the valgrind
version, and what OS and version you are using.  Thanks.

err:wineboot:start_services_process Unexpected termination of services.exe - exit code 0
err:service:service_run_main_thread failed to open service manager error 1726
==14344== 
==14344== Events    : Ir
==14344== Collected : 3000323
==14344== 
==14344== I   refs:      3,000,323
==14336== 
==14336== Events    : Ir
==14336== Collected : 20524324
==14336== 
==14336== I   refs:      20,524,324
==14338== 
==14338== Events    : Ir
==14338== Collected : 1349311845
==14338== 
==14338== I   refs:      1,349,311,845

austin@debian-home:~/src/valgrind$ svn info
Path: .
Working Copy Root Path: /home/austin/src/valgrind
URL: svn://svn.valgrind.org/valgrind/trunk
Relative URL: ^/trunk
Repository Root: svn://svn.valgrind.org/valgrind
Repository UUID: a5019735-40e9-0310-863c-91ae7b9d1cf9
Revision: 14397
Node Kind: directory
Schedule: normal
Last Changed Author: sewardj
Last Changed Rev: 14397
Last Changed Date: 2014-08-30 14:24:05 -0500 (Sat, 30 Aug 2014)
Comment 11 Mark Browning 2014-09-17 06:17:43 UTC
I'm getting the same error as Austin with 3.10 from trunk. However, unlike Austin, I hit it even if wineserver is already running...

valgrind  --tool=callgrind --instr-atstart=yes --trace-children=yes --vex-iropt-register-updates=allregs-at-mem-access wine ERA

<snip>

Callgrind: ../../callgrind/threads.c:246 (vgCallgrind_post_signal): Assertion 'sigNum == vgCallgrind_current_state.sig' failed.

host stacktrace:
==25920==    at 0x3803BA64: show_sched_status_wrk (m_libcassert.c:319)
==25920==    by 0x3803BBB6: report_and_quit (m_libcassert.c:390)
==25920==    by 0x3803BD19: vgPlain_assert_fail (m_libcassert.c:455)
==25920==    by 0x380394E2: vgCallgrind_post_signal (threads.c:246)
==25920==    by 0x38095A14: vgPlain_sigframe_destroy (sigframe-x86-linux.c:724)
==25920==    by 0x380DAA39: vgSysWrap_x86_linux_sys_rt_sigreturn_before (syswrap-x86-linux.c:1013)
==25920==    by 0x38096405: vgPlain_client_syscall (syswrap-main.c:1586)
==25920==    by 0x3809277F: handle_syscall (scheduler.c:1103)
==25920==    by 0x38093F16: vgPlain_scheduler (scheduler.c:1416)
==25920==    by 0x380A6747: run_a_thread_NORETURN (syswrap-linux.c:103)

sched status:
  running_tid=1

Thread 1: status = VgTs_Runnable
==25920==    at 0x41FBF7F: pthread_sigmask (pthread_sigmask.c:48)
==25920==    by 0x7BC77DFE: wine_server_call (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC7805A: server_select (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC80797: NtWaitForMultipleObjects (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC807F5: NtWaitForSingleObject (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC4115E: server_ioctl_file (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC427BB: NtDeviceIoControlFile (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7B84192F: DeviceIoControl (in /usr/lib/i386-linux-gnu/wine/kernel32.dll.so)
==25920==    by 0x7B87E9E9: GetVolumeInformationW (in /usr/lib/i386-linux-gnu/wine/kernel32.dll.so)
==25920==    by 0x787EBEAF: ?_AfxFullPath2@@YGHPA_WPB_WPAVCFileException@@@ (in /media/psf/Home/ERA 3/mfc100u.dll)
==25920==    by 0x787EB4D6: ?Open@CFile@@UAEHPB_WIPAVCFileException@@@Z (in /media/psf/Home/ERA 3/mfc100u.dll)
==25920==    by 0x406697: CUtility::FileExists (utility.cpp:461)
==25920==    by 0x404051: CAppSettingsMgr::Initialize (appsettingsmgr.cpp:130)
==25920==    by 0x401211: CMainApp::InitInstance (tad10.cpp:119)
==25920==    by 0x788477C5: ?AfxWinMain@@YGHPAUHINSTANCE__@@0PA_WH@ (in /media/psf/Home/ERA 3/mfc100u.dll)
==25920==    by 0xBD7CC7: __tmainCRTStartup (crtexe.c:547)
==25920==    by 0x7B85E5CB: ??? (in /usr/lib/i386-linux-gnu/wine/kernel32.dll.so)
==25920==    by 0x7B85F652: start_process (in /usr/lib/i386-linux-gnu/wine/kernel32.dll.so)
==25920==    by 0x7BC799AF: ??? (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC7C93C: call_thread_func (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC7998D: ??? (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x7BC4E8FD: start_process (in /usr/lib/i386-linux-gnu/wine/ntdll.dll.so)
==25920==    by 0x403050C: ??? (in /usr/lib/i386-linux-gnu/libwine.so.1.0)
Comment 12 Mark Browning 2014-09-17 06:22:21 UTC
Its possible that wine's version of notepad has changed so that it doesn't prod this bug anymore if started with a running wineserver.... my comment above was running some of my own code (hoping to get perf numbers, but here I am debugging valgrind ;) )
Comment 13 Josef Weidendorfer 2014-09-17 23:08:15 UTC
Looking at comment 2:

--994-- delivering signal 10 (SIGUSR1) to thread 3: on ALT STACK (0x7FFD1000-0x7FFD4000; 12288 bytes)
--994-- >> pre_signal(TID 3, sig 10, alt_st yes)

I just played around with signal handlers using an alternate stack.
Allocating the alternate stack as global variable or heap works fine.
However, noting above address range (0x7FFD1000-0x7FFD4000), wine seems to actually
allocate an alternate stack area on the original stack.

And indeed, that results in the same crash of callgrind as given in this bug report.
I am not sure this is the real issue here, so I just opened another bug for this: bug 339160.