Maher4Ever / wdm

Windows Directory Monitor (WDM) is a threaded directories monitor for Windows.
https://rubygems.org/gems/wdm
MIT License
50 stars 14 forks source link

fail with listen gem #15

Open net1957 opened 10 years ago

net1957 commented 10 years ago

I have a strange issue on windows 8.1 x64 Microsoft Windows [version 6.3.9600] with ruby 1.9.3p545 (2014-02-24) [i386-mingw32] and the listen gem

wdm seems to fail in entry->user_data->dir = wdm_utils_full_pathname(entry->user_data->dir); in rb_monitor.rb line 201

The correct 32b devkit is used

see https://github.com/guard/listen/issues/149

@net1957

e2 commented 10 years ago

You could try adding debugs to: https://github.com/Maher4Ever/wdm/blob/master/ext/wdm/utils.c (That's where the wdm_utils_full_pathname is defined).

net1957 commented 10 years ago

@e,

Already tried,

wdm_utils_full_pathname(const LPWSTR path)
{
    WCHAR maxed_path[WDM_MAX_WCHAR_LONG_PATH];
    LPWSTR full_path;
    size_t full_path_len;
    BOOL is_directory;
    WDM_DEBUG("- SK x1 -");
    if ( GetFullPathNameW(path, WDM_MAX_WCHAR_LONG_PATH, maxed_path, NULL) == 0 ) {
        WDM_DEBUG("- SK x2 -");
        return 0;
    }
    WDM_DEBUG("- SK x3 -");

.....

But it never display anything. It's seems to break before the first debug line!

If I call wdm directly it work and display the debug messages....

e2 commented 10 years ago

If it's crashing badly, it won't display the last few debug lines due to buffering.

You'd have to add flushing in wdm.h, so:

#if WDM_DEBUG_ENABLED == TRUE
    #define WDM_DEBUG(str, ...) \
        fprintf(stderr, "[DEBUG] (%s@%d): " str "\n", __FILE__, __LINE__, ##__VA_ARGS__)

    #define WDM_WDEBUG(str, ...) \
        fwprintf(stderr, L"[DEBUG] (%S@%d): " str "\n", __FILE__, __LINE__, ##__VA_ARGS__)

#else
    #define WDM_DEBUG(str, ...)
    #define WDM_WDEBUG(str, ...)
#endif

becomes:

#if WDM_DEBUG_ENABLED == TRUE
    #define WDM_DEBUG(str, ...) \
        { fprintf(stderr, "[DEBUG] (%s@%d): " str "\n", __FILE__, __LINE__, ##__VA_ARGS__); fflush(stderr); }

    #define WDM_WDEBUG(str, ...) \
        { fwprintf(stderr, L"[DEBUG] (%S@%d): " str "\n", __FILE__, __LINE__, ##__VA_ARGS__); fflush(stderr); }

#else
    #define WDM_DEBUG(str, ...)
    #define WDM_WDEBUG(str, ...)
#endif

Also, in your wdm makefile, you'd want to turn off optimization for better debugging:

optflags = -O3 -fno-fast-math

should be:

optflags = -O0 -fno-fast-math

That should help find which line is actually failing. Though, probably running it under a debugger would be best (e.g. from a development environment).

If there's a gdb command with the Windows devkit, you should be able to do this:

gdb --args ruby my_listen_test.rb

Then when you see the (gdb) prompt, type in: run Then, when it runs and crashes, type in :bt

Then the backtrace should give a hint as to where it's actually failing and why.

net1957 commented 10 years ago

@e2

I modified wdm.h but did not find wdm makefile...

the result of gdb is

D:\Dvlt\ruby\projects\_tmp\listen>gdb --args ruby.exe code.rb l
GNU gdb (GDB) 7.3
Copyright (C) 2011 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "mingw32".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from d:\program\dvlt\ruby\ruby193\bin\ruby.exe...done.
(gdb) run
Starting program: d:\program\dvlt\ruby\ruby193\bin\ruby.exe code.rb l
[New Thread 4920.0x20a8]
[New Thread 4920.0x2258]
[New Thread 4920.0x1eec]
[New Thread 4920.0x1a88]
warning: Application "\??\D:\program\dvlt\Git\cmd\git.exe" found in cache

warning: Application "\??\D:\program\dvlt\Git\cmd\git.exe" found in cache

[DEBUG] (../../../../ext/wdm/wdm.c@37): Registering WDM with Ruby!
[DEBUG] (../../../../ext/wdm/rb_monitor.c@556): Registering WDM::Monitor with Ruby!
[DEBUG] (../../../../ext/wdm/rb_change.c@185): Registering WDM::Event with Ruby!
I, [2014-05-25T20:04:40.731083 #4920]  INFO -- : Celluloid loglevel set to: 0
env: LISTEN_GEM_DEBUGGING=
Listen: Running the monitor...
[New Thread 4920.0x2254]
[New Thread 4920.0x21e0]
[New Thread 4920.0x232c]
[New Thread 4920.0x20c0]
[New Thread 4920.0x1d98]
[New Thread 4920.0x21f0]
[New Thread 4920.0x21d8]
[New Thread 4920.0x2218]
[New Thread 4920.0x22bc]
[New Thread 4920.0x2214]
[New Thread 4920.0x2180]
[New Thread 4920.0x2200]
D, [2014-05-25T20:04:40.762334 #4920] DEBUG -- : Adapter: considering TCP ...
D, [2014-05-25T20:04:40.762334 #4920] DEBUG -- : Adapter: considering polling ...
D, [2014-05-25T20:04:40.762334 #4920] DEBUG -- : Adapter: considering optimized backend...
[New Thread 4920.0xc90]
[New Thread 4920.0x2168]
Listen: Started...
D, [2014-05-25T20:04:40.766240 #4920] DEBUG -- : wdm - starting...
[DEBUG] (../../../../ext/wdm/rb_monitor.c@105): --------------------------------
[DEBUG] (../../../../ext/wdm/rb_monitor.c@106): Allocating a new monitor object!
[DEBUG] (../../../../ext/wdm/rb_monitor.c@107): --------------------------------
D, [2014-05-25T20:04:40.781866 #4920] DEBUG -- : wdm - watching recursively: "D:/Dvlt/ruby/projects/_tmp/listen/xxx"
[DEBUG] (../../../../ext/wdm/rb_monitor.c@199): New path to watch: 'D:/Dvlt/ruby/projects/_tmp/listen/xxx'
[DEBUG] (../../../../ext/wdm/rb_monitor.c@200): - SK 0 -
gdb: unknown target exception 0x80000001 at 0x6448446a

Program received signal ?, Unknown signal.
[Switching to Thread 4920.0xc90]
0x6448446a in wdm_ext!Init_wdm_ext () from D:\Dvlt\ruby\projects\_test\wdm\lib\wdm_ext.so
(gdb) bt
#0  0x6448446a in wdm_ext!Init_wdm_ext () from D:\Dvlt\ruby\projects\_test\wdm\lib\wdm_ext.so
#1  0x64482b60 in ?? () from D:\Dvlt\ruby\projects\_test\wdm\lib\wdm_ext.so
#2  0x62e68a4d in rb_vm_mark () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#3  0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#4  0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#5  0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#6  0x62e73afe in rb_eval_string () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#7  0x62e792e3 in rb_yield () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#8  0x62d06eaa in rb_ary_each () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#9  0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#10 0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#11 0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#12 0x62e73afe in rb_eval_string () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#13 0x62e792e3 in rb_yield () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#14 0x62d9ad72 in rb_obj_tap () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#15 0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#16 0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#17 0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#18 0x62e743d9 in rb_vm_invoke_proc () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#19 0x62e68a4d in rb_vm_mark () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#20 0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#21 0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#22 0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#23 0x62e73afe in rb_eval_string () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#24 0x62e73fab in rb_vm_invoke_proc () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#25 0x62e877af in rb_fiber_start () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#26 0x62e879c7 in rb_fiber_start () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#27 0x756acd43 in KERNEL32!BaseDllReadWriteIniFile () from C:\WINDOWS\SysWOW64\kernel32.dll
#28 0x00000000 in ?? ()
(gdb)
e2 commented 10 years ago

The makefile is created by running ruby extconf.rb in the wdm ext folder (happens when the gem is installed). If you're using wdm from soruces, you can probably also use the rake tasks, e.g. rake compile:wdm_ext).

(https://github.com/Maher4Ever/wdm/blob/master/ext/wdm/extconf.rb)

As for the above debugs, they unfortunately don't say much (likely because of the lack of makefile settings for debugging). Also, it seems the debugging symbols were not loaded for the wdm_ext.so ...

... so you might want to check out the set solib-search-path command in gdb - (it should say that it's reading symbols for/from wdm_ext.so). Setting the directory for source may also show something.

So the gdb session would be e.g.:

C:\> gdb --args ruby.exe code.rb
(gdb) set solib-search-path your_path_to_wdm_ext_so_build_dir_or_whatever
(gdb) directory your_path_to_wdm_c_source_files
(gdb) sharedlibrary wdm_ext
(gdb) info sharedlibrary
(gdb) info sources
(gdb) run
(gdb) bt

Or, if you prefer, you might want to look for a gdb frontend for Windows (I have no clue).

Anyway, that's as far as I can get you. I don't know if all this effort is worth it (I gave up on Windows over 10 years ago), though the above is still pretty generic and cross-platform - and would apply to almost any crashing extension on any platform.

Again, the other option is for me to rework how adapters are handled in Listen, which might mean this will work anyway.

net1957 commented 10 years ago

@e2,

tried with yous advices. in the makefile:

optflags = -O3 -fno-omit-frame-pointer
debugflags = -ggdb

if I use -O0 I have nothing in gdb

result is:

D:\Dvlt\ruby\projects\_tmp\listen>gdb --args ruby.exe code.rb l
GNU gdb (GDB) 7.3
Copyright (C) 2011 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "mingw32".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from d:\program\dvlt\ruby\ruby193\bin\ruby.exe...done.
(gdb) set solib-search-path D:/Dvlt/ruby/projects/_test/wdm/tmp/i386-mingw32/wdm_ext/1.9.3
(gdb) directory D:/Dvlt/ruby/projects/_test/wdm/ext/wdm
Source directories searched: D:/Dvlt/ruby/projects/_test/wdm/ext/wdm;$cdir;$cwd
(gdb) sharedlibrary wdm_ext
No loaded shared libraries match the pattern `wdm_ext'.
(gdb) info sharedlibrary
No shared libraries loaded at this time.
(gdb) info sources
Source files for which symbols have been read in:

Source files for which symbols will be read in on demand:

../../../../src/gcc-4.5.2/libgcc/../gcc/libgcc2.c, ../mingw/pseudo-reloc-list.c, ../mingw/tlsthrd.c, ../mingw/crtst.c, ../mingw/gccmain.c, ../mingw/pseudo-reloc.c,
../mingw/CRT_fp10.c, ../mingw/cpu_features.c, ../mingw/txtmode.c, ../mingw/CRTfmode.c, ../mingw/CRTglob.c, ../mingw/tlssup.c, ../ruby_1_9/main.c, ../mingw/init.c, ../m
(gdb) run
Starting program: d:\program\dvlt\ruby\ruby193\bin\ruby.exe code.rb l
[New Thread 8792.0x20c8]
[New Thread 8792.0x2290]
[New Thread 8792.0x1e28]
[New Thread 8792.0x1f10]
warning: Application "\??\D:\program\dvlt\Git\cmd\git.exe" found in cache

warning: Application "\??\D:\program\dvlt\Git\cmd\git.exe" found in cache

[DEBUG] (../../../../ext/wdm/wdm.c@37): Registering WDM with Ruby!
[DEBUG] (../../../../ext/wdm/rb_monitor.c@556): Registering WDM::Monitor with Ruby!
[DEBUG] (../../../../ext/wdm/rb_change.c@185): Registering WDM::Event with Ruby!
I, [2014-05-26T21:43:16.163127 #8792]  INFO -- : Celluloid loglevel set to: 0
env: LISTEN_GEM_DEBUGGING=
Listen: Running the monitor...
[New Thread 8792.0x25a4]
[New Thread 8792.0x24c4]
[New Thread 8792.0x1d74]
[New Thread 8792.0x2538]
[New Thread 8792.0x1f88]
[New Thread 8792.0x260c]
[New Thread 8792.0x1b94]
[New Thread 8792.0xb58]
[New Thread 8792.0x16e4]
[New Thread 8792.0x2720]
[New Thread 8792.0x20d4]
[New Thread 8792.0x20e0]
D, [2014-05-26T21:43:16.190471 #8792] DEBUG -- : Adapter: considering TCP ...
D, [2014-05-26T21:43:16.194378 #8792] DEBUG -- : Adapter: considering polling ...
D, [2014-05-26T21:43:16.194378 #8792] DEBUG -- : Adapter: considering optimized backend...
[New Thread 8792.0x3d4]
[New Thread 8792.0x20a0]
Listen: Started...
D, [2014-05-26T21:43:16.198284 #8792] DEBUG -- : wdm - starting...
[DEBUG] (../../../../ext/wdm/rb_monitor.c@105): --------------------------------
[DEBUG] (../../../../ext/wdm/rb_monitor.c@106): Allocating a new monitor object!
[DEBUG] (../../../../ext/wdm/rb_monitor.c@107): --------------------------------
D, [2014-05-26T21:43:16.210003 #8792] DEBUG -- : wdm - watching recursively: "D:/Dvlt/ruby/projects/_tmp/listen/xxx"
[DEBUG] (../../../../ext/wdm/rb_monitor.c@199): New path to watch: 'D:/Dvlt/ruby/projects/_tmp/listen/xxx'
[DEBUG] (../../../../ext/wdm/rb_monitor.c@200): - SK 0 -
gdb: unknown target exception 0x80000001 at 0x6448446a

Program received signal ?, Unknown signal.
[Switching to Thread 8792.0x3d4]
_alloca () at ../../../../src/gcc-4.5.2/libgcc/../gcc/config/i386/cygwin.asm:45
45      ../../../../src/gcc-4.5.2/libgcc/../gcc/config/i386/cygwin.asm: No such file or directory.
        in ../../../../src/gcc-4.5.2/libgcc/../gcc/config/i386/cygwin.asm
(gdb) bt
#0  _alloca () at ../../../../src/gcc-4.5.2/libgcc/../gcc/config/i386/cygwin.asm:45
#1  0x644837d0 in wdm_utils_full_pathname (path=0x63cf1a0 L"D:/Dvlt/ruby/projects/_tmp/listen/xxx") at ../../../../ext/wdm/utils.c:24
#2  0x64482b60 in combined_watch (recursively=<optimized out>, argc=<optimized out>, argv=<optimized out>, self=31132776) at ../../../../ext/wdm/rb_monitor.c:202
#3  0x62e68a4d in rb_vm_mark () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#4  0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#5  0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#6  0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#7  0x62e73afe in rb_eval_string () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#8  0x62e792e3 in rb_yield () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#9  0x62d06eaa in rb_ary_each () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#10 0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#11 0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#12 0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#13 0x62e73afe in rb_eval_string () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#14 0x62e792e3 in rb_yield () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#15 0x62d9ad72 in rb_obj_tap () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#16 0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#17 0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#18 0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#19 0x62e743d9 in rb_vm_invoke_proc () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#20 0x62e68a4d in rb_vm_mark () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#21 0x62e7874a in rb_vm_call () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#22 0x62e6e7d8 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#23 0x62e72eb1 in rb_vm_localjump_error () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#24 0x62e73afe in rb_eval_string () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#25 0x62e73fab in rb_vm_invoke_proc () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#26 0x62e877af in rb_fiber_start () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#27 0x62e879c7 in rb_fiber_start () from d:\program\dvlt\ruby\ruby193\bin\msvcrt-ruby191.dll
#28 0x756acd43 in KERNEL32!BaseDllReadWriteIniFile () from C:\WINDOWS\SysWOW64\kernel32.dll
#29 0x00000000 in ?? ()
(gdb)
luislavena commented 10 years ago

@net1957 @e2 if I may chime in.

Seems wdm is using it's own methods to allocate memory (wdm_memory_*) which are not using the Ruby wrapped methods (xalloc*) which is safer.

It is weird the reference to gcc/config/i386/cygwin.asm:45, but seems to be around that.

From the backtrace seems to be related to that, but I cannot test locally now to confirm.

Will confirm once I get back home.

net1957 commented 10 years ago

I tried with Netbeans on windows, but it is not consistent. Most of the time it fails, but not all the time! So I think it's a memory problem. We have many "threads" and "Celluloid" in the game! When it fails, it is always in "wdm_utils_full_pathname" or in procedures called from there. It's always because of the unknown signal. I'm not very familiar with the inner part of the system, so I'm surely wrong!