There are 8 failures from Elixir test suite on Windows

[josevalim]

Down to 8 errors...

Failures:

  1) test_absname_with_binary (PathTest)
     ** (ExUnit.ExpectationError)
                  expected: "c:/foo/bar"
       to be equal to (==): "/foo/bar"
     at test/elixir/path_test.exs:84

  2) test_absname_with_list (PathTest)
     ** (ExUnit.ExpectationError)
                  expected: 'c:/foo/bar'
       to be equal to (==): '/foo/bar'
     at test/elixir/path_test.exs:96

  3) test_expand_path_with_binary (PathTest)
     ** (ExUnit.ExpectationError)
                  expected: "c:/foo/bar"
       to be equal to (==): "/foo/bar"
     at test/elixir/path_test.exs:118

  4) test_expand_path_with_list (PathTest)
     ** (ExUnit.ExpectationError)
                  expected: 'c:/foo/bar'
       to be equal to (==): '/foo/bar'
     at test/elixir/path_test.exs:134

  5) test_argv (SystemTest)
     ** (SyntaxError) nofile:1: syntax error before: 'ERROR'
     stacktrace:

  6) test_at_exit (Kernel.CLI.AtExitTest)
     ** (ExUnit.ExpectationError)
                  expected: 'goodbye '
       to be equal to (==): 'goodbye cruel world with status 0\n'
     at test/elixir/kernel/cli_test.exs:39

  7) test_possible_deadlock (Kernel.CLI.CompileTest)
     ** (ExUnit.AssertionError) expected foo.ex to miss module Bar
     at test/elixir/kernel/cli_test.exs:88

  8) test_rm_rf_with_symlink (FileTest.Rm)
     ** (ExUnit.AssertionError) Expected false to be true
     at test/elixir/file_test.exs:774

Finished in 8.5 seconds (5.1s on load, 3.3s on tests)
1091 tests, 8 failures
make: *** [test_kernel] Error 1

[ghost]

@ToJans I'm currently trying to fix wac so it doesn't crash make on Ctrl+C and that it doesn't intersperse stderr/out, but after I'll try 'cause I like it xD

EDIT: ok done that :) to avoid interspersing this is like the only way call elixir.bat %* 2>&1 | wac (that 2>&1 that is, to make stdout and stderr both safelymix and become stdin to wac, rather than have elixir's stderr intersperse with wac's stdout). Also avoided Ctrl+C making mingw32-make loop indefinitely https://github.com/AtKaaZ/wac

[ghost]

I'm in the process of isolating the race conditions thing into some small reproducible test case (in a new project, so far managed to get the 2 files from elixir: ../test_helper.exs and cli_test.exs ( EDIT2: and fixtures folder) to act out those race conditions that they do when mix test_kernel - which happens under Windows only (reminder))

EDIT: so this is to let people know I'm on it:) so we don't do the same thing

EDIT3: made a project with the isolated test case project https://github.com/AtKaaZ/elixir_windows_racing_trackdown

[ghost]

guys do you know how to find the source code of :erlang.open_port I'm guessing is somewhere inside C/C++ ? EDIT: I just realized I was searching for port_open (swapped those by mistake) EDIT2: I think it's a matter of flush not being done before the close, that is, if the close happens sooner than the periodic flush(if such a thing)... don't know, checking.. EDIT3: I've a feeling that it's like the flush msg is sent but the loop doesn't get to process it before it processes the exit msg which was like prior to it or something... guessing around:) EDIT4: possibly related http://erlang.org/pipermail/erlang-questions/2008-May/034970.html EDIT5: also this http://erlang.org/pipermail/erlang-bugs/2013-February/003372.html

[ghost]

Yes! Progress, turns out it's erlang, well elixir.bat it exits in such a way that it doesn't flush it's own output but it's from erlang why? well I wrapped elixir.bat in another bat which outputs "ended!\n" at the end and so when the tests fail, this string is always there at the end. Take this example:

1) test_at_exit (Kernel.CLI.AtExitTest)
     ** (ExUnit.ExpectationError)
                  expected: 'goodbye '
       to be equal to (==): 'goodbye cruel world with status 0\n'
     at elixir_windows_racing_trackdown_test.exs:27

the actual output received is 'goodbye ended!\n' but I auto remove that ended!\n part not before making sure it exists and yell if it doesn't!

Reproducible with this: https://github.com/AtKaaZ/elixir_windows_racing_trackdown just run m.bat after checkout, repeat running it until you see at least 1 fail (like max 5 times) Obviously, has effect/works only on Windows!

Anyway so the point is, something happens with erlang if not at the higher level elixir(doubt it tho) that it doesn't wait for its own output to get flushed before closing/exiting... Thoughts? EDIT: and this is seen only while running in parallel :)) (async tests)

[ghost]

since the race-condition failing tests don't fail when async: false is that an acceptable workaround for Windows? ie. something like use ExUnit.Case, async: !is_win? when surrounding the specific failing test in a defmodule

[josevalim]

@AtKaaZ Nice discovery. Would we have to set async: false for that particular test cases or for all of them?

[ghost]

only for those tests that fail due to race condition when executing elixir(c) themselves EDIT: AND care about the output (like 5 7 8 tests I think I know), still testing them for fails as I'm already trying this; but this was already obvious so far (that they don't fail when async is false) though I was hoping for a direct solution (erl.exe needs to get fixed unless this behaviour is documented)

EDIT: Does Elixir have an at_exit hook that flushes all output(stdout+stderr) ? EDIT2: but then there's still the matter of Process.exit(pid, :kill), how'd that one know when to flush output if it doesn't trap signals EDIT3: I'll post a PR, at the very least you can see which ones (and which don't need it)

[ToJans]

Great find! I'm for async: false for now, but this should really be fixed in erlang. As long as people do not call other elixir apps through ports we should be fine, but this should be mentioned somewhere: capturing stdio.out with multiple processes in parallel might cause race conditions errors and truncated stdio output.

[ToJans]

Progress now! All we need to fix is mix, and we're there...

[ghost]

Did you fix or not encountering this error?

==> kernel (exunit)
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
.......F...........................................................................................
........

Failures:

  1) test_rm_rf_with_symlink (FileTest.Rm)
     ** (MatchError) no match of right hand side value: {:error, {:error, :eperm}, "s:/workspace.el
ixir.2013/elixir/lib/elixir/tmp/tmp/from"}
     at test/elixir/file_test.exs:801

Finished in 30.7 seconds (17.2s on load, 13.4s on tests)
1196 tests, 1 failures
Makefile:151: recipe for target 'test_kernel' failed
mingw32-make: *** [test_kernel] Error 1

EDIT: that folder is a folder symlink

 Directory of s:\workspace.elixir.2013\elixir\lib\elixir\tmp\tmp

07/30/2013  12:52    <DIR>          .
07/30/2013  12:52    <DIR>          ..
07/30/2013  12:52    <SYMLINKD>     from [s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/to]
07/30/2013  12:52    <DIR>          to

[ToJans]

I do not get that error:

Update: wrong test :p

[ghost]

try make test_kernel , I don't get it if I do make test_ex_unit, the second time I run it I get a different result sorta (than when I just make clean -ed prior to make test_kernel)

Tue 07/30/2013 12:58:15.03 s:\workspace.elixir.2013\elixir>mingw32-make test_kernel   2>&1  | wac
==> elixir (compile)
==> kernel (exunit)
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
.FFFF..F...........................................................................................
........

Failures:

  1) test_rm_rf (FileTest.Rm)
     ** (MatchError) no match of right hand side value: {:error, {:error, {:error, :eperm}, "s:/wor
kspace.elixir.2013/elixir/lib/elixir/tmp/tmp/from"}, "s:/workspace.elixir.2013/elixir/lib/elixir/tm
p/tmp"}
     at test/elixir/file_test.exs:779

=ERROR REPORT==== 30-Jul-2013::12:58:53 ===
** Generic server <0.654.0> terminating
** Last message in was {suite_finished,14662000,17627000}
** When Server state == {'Elixir.ExUnit.CLIFormatter.Config',1196,0,
                         [{'Elixir.ExUnit.Test',test_rm_rf_with_symlink,
                           'Elixir.FileTest.Rm',
                           {error,
                            {'Elixir.MatchError','__exception__',
                             {error,
                              {error,eperm},
                              <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/from">>}},
                            [{'Elixir.FileTest.Rm',test_rm_rf_with_symlink,1,
                              [{file,
                                "s:/workspace.elixir.2013/elixir/lib/elixir/test/elixir/file_test.e
xs"},
                               {line,801}]}]},
                           6000},
                          {'Elixir.ExUnit.Test',test_rm_rf_with_file,
                           'Elixir.FileTest.Rm',
                           {error,
                            {'Elixir.ExUnit.ExpectationError',
                             '__exception__',
                             <<"{:error, {:error, {:error, :eperm}, \"s:/workspace.elixir.2013/elix
ir/lib/elixir/tmp/tmp/from\"}, \"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp\"}">>,
                             <<"{:ok, [\"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp\"]}">>,

                             <<"be equal to (==)">>,false,<<"Expected">>,nil},
                            [{'Elixir.FileTest.Rm',test_rm_rf_with_file,1,
                              [{file,
                                "s:/workspace.elixir.2013/elixir/lib/elixir/test/elixir/file_test.e
xs"},
                               {line,834}]}]},
                           9000},
                          {'Elixir.ExUnit.Test',test_rm_rf_with_char_list,
                           'Elixir.FileTest.Rm',
                           {error,
                            {'Elixir.MatchError','__exception__',
                             {error,
                              {error,
                               {error,eperm},
                               <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/from">>},
                              <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp">>}},
                            [{'Elixir.FileTest.Rm',test_rm_rf_with_char_list,
                              1,
                              [{file,
                                "s:/workspace.elixir.2013/elixir/lib/elixir/test/elixir/file_test.e
xs"},
                               {line,820}]}]},
                           15000},
                          {'Elixir.ExUnit.Test','test_rm_rf!',
                           'Elixir.FileTest.Rm',
                           {error,
                            {'Elixir.File.Error','__exception__',
                             {error,
                              {error,eperm},
                              <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/from">>},
                             <<"remove files and directories recursively from">>,
                             <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp">>},
                            [{'Elixir.FileTest.Rm','test_rm_rf!',1,
                              [{file,
                                "s:/workspace.elixir.2013/elixir/lib/elixir/test/elixir/file_test.e
xs"},
                               {line,856}]}]},
                           21000},
                          {'Elixir.ExUnit.Test',test_rm_rf,
                           'Elixir.FileTest.Rm',
                           {error,
                            {'Elixir.MatchError','__exception__',
                             {error,
                              {error,
                               {error,eperm},
                               <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/from">>},
                              <<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp">>}},
                            [{'Elixir.FileTest.Rm',test_rm_rf,1,
                              [{file,
                                "s:/workspace.elixir.2013/elixir/lib/elixir/test/elixir/file_test.e
xs"},
                               {line,779}]}]},
                           16000}],
                         [],false,true}
** Reason for termination ==
** {'module could not be loaded',
       [{error,format_error,
            [<<"s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/from">>,
             {error,eperm}],
            []},
        {file,format_error,1,[{file,"file.erl"},{line,153}]},
        {'Elixir.File.Error',message,1,
            [{file,"s:/workspace.elixir.2013/elixir/lib/elixir/lib/file.ex"},
             {line,36}]},
        {'Elixir.ExUnit.Formatter',format_kind_reason,3,
            [{file,
                 "s:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit/formatter.ex"},
             {line,111}]},
        {'Elixir.ExUnit.Formatter',format_test_failure,4,
            [{file,
                 "s:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit/formatter.ex"},
             {line,78}]},
        {'Elixir.ExUnit.CLIFormatter',print_test_failure,4,
            [{file,
                 "s:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit/cli_formatter.ex"},
             {line,161}]},
        {'Elixir.Enumerable.List',reduce,3,
            [{file,"s:/workspace.elixir.2013/elixir/lib/elixir/lib/enum.ex"},
             {line,1522}]},
        {'Elixir.ExUnit.CLIFormatter',print_suite,7,
            [{file,
                 "s:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit/cli_formatter.ex"},
             {line,143}]}]}
** exit {{:undef, [{:error, :format_error, ["s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/fro
m", {:error, :eperm}], []}, {:file, :format_error, 1, [file: 'file.erl', line: 153]}, {File.Error,
:message, 1, [file: 's:/workspace.elixir.2013/elixir/lib/elixir/lib/file.ex', line: 36]}, {ExUnit.F
ormatter, :format_kind_reason, 3, [file: 's:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit/f
ormatter.ex', line: 111]}, {ExUnit.Formatter, :format_test_failure, 4, [file: 's:/workspace.elixir.
2013/elixir/lib/ex_unit/lib/ex_unit/formatter.ex', line: 78]}, {ExUnit.CLIFormatter, :print_test_fa
ilure, 4, [file: 's:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit/cli_formatter.ex', line:
161]}, {Enumerable.List, :reduce, 3, [file: 's:/workspace.elixir.2013/elixir/lib/elixir/lib/enum.ex
', line: 1522]}, {ExUnit.CLIFormatter, :print_suite, 7, [file: 's:/workspace.elixir.2013/elixir/lib
/ex_unit/lib/ex_unit/cli_formatter.ex', line: 143]}]}, {:gen_server, :call, [#PID<0.654.0>, {:suite
_finished, 14662000, 17627000}, 30000]}}
    gen_server.erl:188: :gen_server.call/3
    s:/workspace.elixir.2013/elixir/lib/ex_unit/lib/ex_unit.ex:115: ExUnit."-start/1-fun-1-"/1
    s:/workspace.elixir.2013/elixir/lib/elixir/lib/kernel/cli.ex:64: Kernel.CLI."-at_exit/1-lc$^0/1
-0-"/2
    s:/workspace.elixir.2013/elixir/lib/elixir/lib/kernel/cli.ex:62: Kernel.CLI.at_exit/1
    s:/workspace.elixir.2013/elixir/lib/elixir/lib/kernel/cli.ex:40: Kernel.CLI.run/2
    init.erl:1054: :init.start_it/1
    init.erl:1034: :init.start_em/1

Tue 07/30/2013 12:58:54.46 s:\workspace.elixir.2013\elixir>

[ghost]

I just noticed that the lines differ EDIT: that is, other than the obvious ERROR REPORT being dumped (EDIT2: and 4 more failures)

at test/elixir/file_test.exs:801
at test/elixir/file_test.exs:779

The first one happens when make clean then make test_kernel the second one happen on any successive make test_kernel (without make clean)

[ghost]

Also, could someone explain why some exceptions are not reported in Failures: section? if you look at the ERROR REPORT (2 comments above ^ ) it has like 4 assert failures which should (right?) show in Failures: but only the first last one in the report is shown... is this normal?

[ToJans]

@AtKaaZ probably because stderr is uncaptured when calling mix?

[ToJans]

@AtKaaZ Any ability to resolve this, as I do not seem to have this problem on my machine?

[ghost]

Sorry, I didn't try since then(like 9 days ago)... I'm kinda lost as to what to do (generally speaking too)

[ToJans]

I know what it feels like: first you think you found the solution, but it fails from the start:

Then you think you really found it:

And all of a sudden: a bug report:

Then you start feeling like this:

Here's what we need:

[ToJans]

@josevalim Maybe we can split this up in 2 issues: the error @AtKaaZ gets, and the failing mix tests ? That way I can proceed with mix.

[ToJans]

ping @josevalim

[josevalim]

@AtKaaZ I have pushed a fix that will hopefully make your windows no longer crash when reporting the failures.

@ToJans Could you please open up a new issue with your failures? This issue has grown quite long, I think it is a good time to start fresh again. :)

[ghost]

@josevalim I just tried a quick check. Thanks, that fix seems to be working! No crashing then, so I see failures reported in "Failures:" like so (currently, with today's master):

==> kernel (exunit)
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...................................................................................................
...............................................................................FFFF..F.............
......................................................................................

Failures:

  1) test_rm_rf (FileTest.Rm)
     ** (MatchError) no match of right hand side value: {:error, :eperm, "s:/workspace.elixir.2013/
elixir/lib/elixir/tmp/tmp/from"}
     at test/elixir/file_test.exs:779

  2) test_rm_rf! (FileTest.Rm)
     ** (File.Error) could not remove files and directories recursively from s:/workspace.elixir.20
13/elixir/lib/elixir/tmp/tmp: not owner
     at test/elixir/file_test.exs:856

  3) test_rm_rf_with_char_list (FileTest.Rm)
     ** (MatchError) no match of right hand side value: {:error, :eperm, "s:/workspace.elixir.2013/
elixir/lib/elixir/tmp/tmp/from"}
     at test/elixir/file_test.exs:820

  4) test_rm_rf_with_file (FileTest.Rm)
     ** (ExUnit.ExpectationError)
                  expected: {:error, :eperm, "s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp/fr
om"}
       to be equal to (==): {:ok, ["s:/workspace.elixir.2013/elixir/lib/elixir/tmp/tmp"]}
     at test/elixir/file_test.exs:834

  5) test_rm_rf_with_symlink (FileTest.Rm)
     ** (MatchError) no match of right hand side value: {:error, :eperm, "s:/workspace.elixir.2013/
elixir/lib/elixir/tmp/tmp/from"}
     at test/elixir/file_test.exs:801

Finished in 25.4 seconds (17.7s on load, 7.7s on tests)
1274 tests, 5 failures
Makefile:151: recipe for target 'test_kernel' failed
mingw32-make: *** [test_kernel] Error 1

I might try to track some down after I wake up, laterz. /night

EDIT: at first glance it would seem that it could be related to https://github.com/elixir-lang/elixir/commit/91d5ee1d8f1c4a3ba16a8d591bd93fa9d42d70be so either that jinxed it or that can fix it, not sure, looking into it... EDIT2: looks like it's that rm issue (under Windows) again? unsure but seems like it can't remove folder symlinks again...

[ghost]

EDIT4: basically File.rm("symlinkfolderhere") returns {:error, :eperm}

so basically, look at failure1 above, it tries to remove the tmp folder but inside it there's a symlink folder from and that it fails to remove, maybe someone can understand why rm_rf doesn't properly remove directory symlinks... I can't read that

EDIT: I shall note that the tmp and from folders do not exist after a make clean and they are created by make test they are just not (able to be)removed... during the test EDIT2: note that failure5 above is the one creating the from symlink and it fails to remove it, so on successive make test causes extra tests to fail (there's only this failure after a make clean)

EDIT3: ok i read the code, it reduces to F.delete(from) where from is a symlinkdir, failing... and F is :file

[ghost]

To summarize: if File.rm is not meant to remove symlink folders then rm_rf should, so attention needed here: https://github.com/elixir-lang/elixir/blob/master/lib/elixir/lib/file.ex#L691 Failure1 's return is https://github.com/elixir-lang/elixir/blob/master/lib/elixir/lib/file.ex#L695

ideas?

[josevalim]

Right. The error, according to Erlang, is this:

• eperm - The file is a directory and the user is not super-user.

But, it is not supposed to remove the directory, just the link, and I am uncertain on how to do so on Windows. File.rm/1 (or :file.delete/1) seems to be fine on most machines but, surprisingly, not on yours.

[ghost]

Oddly enough, also, I am super-user at all times. This user is an admin and I have UAC turned off (so it doesn't have to ask me if I allow or not, it always allows). On Windows 7 64bit, ... it's really odd that it works for @ToJans , or rather that it doesn't for me....

Erlang R16B01 (erts-5.10.2) [64-bit] [smp:4:4] [async-threads:10](I wonder if I am matching with @ToJans so far) I'll keep checking on this... thanks for the info

[ghost]

It's almost as if that's the problem it sees the symlinkdir as a dir, ... so eperm makes sense (?)

Erlang R16B01 (erts-5.10.2) [64-bit] [smp:4:4] [async-threads:10]

Eshell V5.10.2  (abort with ^G)
1> file:get_cwd().
{ok,"c:/1"}
2> file:make_dir("cookies").
ok
3> file:make_symlink("cookies","thesymdir").
ok
4> file:read_file_info("thesymdir").
{ok,{file_info,0,directory,read_write,
               {{2013,8,11},{11,9,13}},
               {{2013,8,11},{11,9,13}},
               {{2013,8,11},{11,9,13}},
               16895,3222601728,3,0,0,0,0}}
5> file:read_link_info("thesymdir")
5> .
{ok,{file_info,0,symlink,read_write,
               {{2013,8,11},{11,9,39}},
               {{2013,8,11},{11,9,39}},
               {{2013,8,11},{11,9,39}},
               16895,81851696,3,0,0,0,0}}

7> file:delete("thesymdir").
{error,eperm}
8> file:del_dir("thesymdir").
ok
9> file:read_file_info("thesymdir").
{error,enoent}

EDIT: btw, I also tried putting some files inside the symlinkdir and file:del_dir still worked EDIT2: honestly, this seems to work as I'd expect it, so I'm surprised that it works for @ToJans ... EDIT3: I have just tried this in 32bit erlang, exactly the same thing happens (I expected it to not but wtw xD) EDIT4: so basically the way to delete a symlinkdir is via file:del_dir and probably the way to delete a symlinkfile is via file:delete... but why does it work for other machines... EDIT5: I note that the owner is the same for both files and folder and symlinkdirs and that's the Administrators group (as reported by Properties->Security->Advanced->Owner in explorer) Also I've tried making my user owner of the symlinkdir and then file:delete it, still :eperm

EDIT6: Could @ToJans maybe try the above erlang commands in werl to see if file:delete actually works for him?

[josevalim]

@AtKaaZ I have pushed another commit to master. Could you please let me know if it addresses the issues you are seeing?

[ghost]

That worked @josevalim , now all I see are the next (mix) failures. I guess this thread stops here, as I've seen you mention above that for those failures a new one should be started. Thanks.

EDIT: I'd still wanna know why it worked for @ToJans though... it bugs me

[ToJans]

Haven't tried it (been at a conf in another country yesterday & got back by noon today), but I'll focus on fixing the mix errors now... But first some time with the kids ;-) ...