Elixir: Improve ExUnit output for assertions on process mailbox

[devonestes]

Moving this over from the mailing list per instructions from José. Here's the link to the mailing list discussion: https://groups.google.com/forum/#!topic/elixir-lang-core/qLO2IQ9PWUg

In short, the current output for ExUnit when you're asserting that a process receives a certain message is not very helpful, especially on messages with a large number of arguments. Some improvements in the output would make for a much better user experience.

Here is an example of the current behavior:

That output makes finding the differences between the expected messages and the received messages hard. It would be really helpful to perform some more illustrative diffing to highlight the differences.

Props to @bradurani for finding this and recommending that it be improved upon!

[kelvinst]

This is the next one I'll try. Not sure if I have the skills needed, but let's do it!

[kelvinst]

Well, the time has come. I'll start of making a function on ExUnit.Diff to actually diff a match statement. Is that a good place to start?

An example of the final result I'm planning is something like:

Assertion with = failed
code: assert %{a: 1, b: 2, c: _} = %{a: 1, b: 3, c: 4, d: 5}
left: %{a: 1, b: [red]2[/red], c: _}
right: %{a: 1, b: [green]3[/green], c: 4, d: 5}
stacktrace:
...

I know the examples shows a match assertion, and the card is for a receive assertion, but they're related because an assert_receive actually try to match the given expression on any mailbox message.

[kelvinst]

Another thing: I'll start by tuples and lists of numbers, and when I have them I'll open a WIP PR for you to review the work so far.

[Edited]

I guess maps and structs are pretty complex to handle.

[kelvinst]

This is actually a lot harder than I thought it would be, the differ will need to receive the AST of the left side and also the pinned variables. I will invest my time now on some easier issues and leave this one for later when I get some time to deeply study this.

Also, if someone is interested to help me on it, be my guest. 😉

[jeremyowensboggs]

I'd like to have a look, kelvinst, do you already have some tests and or scenarios written up?

[kelvinst]

@jeremyowensboggs nope! I was just studying ways to do it first. Feel free to do what you want, I'm not able to work on it right now. Thanks for asking!

[jeremyowensboggs]

I've looked things over, and just want to talk over the approach out-loud. Feel free to ignore or offer opinions/comments

Inside the assert macro, when we have a pattern, we will put the escaped AST of the pattern, a keyword list of the pinned vars and their values, and the unbound vars into a struct that we will assign to the :left option of assert. I will call this struct ExUnit.Pattern.

In the ExUnit.Diff, create a def script(%ExUnit.Pattern{} = left, right) function to do the diff.
In ExUnit.Pattern, create a functions to step through the compare, and accumulate the tagged output

for the pattern
is lhs a map, and is rhs a map?
pop the first key from lhs, and attempt to pop the same key from rhs
if no rhs, {:del, key}
else compare_value(lhs, rhs)
repeat til no elements

is lhs a list, and is rhs a list? - get the value based on keys
pop the first key from lhs, and attempt to pop the same key from rhs
if no rhs, {:del, key}
else compare_value(lhs, rhs)
repeat til no elements

is the lhs a tuple, and is the rhs a tuple? - get the value based on position.
pop the first element from lhs, and attempt to pop the first element from rhs
if no rhs, {:del, val},
if no lhs, {:ins, val}
else compare_value
repeat til no elements on lhs or rhs

else compare_value

for the compare_value - outptus either {:eq or :diff}
is the lhs value pinned, and does it match the rhs value?
is the lhs value is a var that was previously bound, then compare it to the rhs value?
is the lhs value is an unbound var, then bind it to the rhs value, unless it is ':_'?

afterwords
for maps & lists, replace any remainging elements on rhs with a single {:ins, '...'} to indicate that they don't matter in the match.

[josevalim]

@jeremyowensboggs I think you got the idea really well. :+1: To sum it up, we will need a pattern evaluator that is able to emit diffs as it evaluates the pattern against a value. The pattern will be AST, the value will be well, a value.

My suggestion is also to completely ignore ExUnit.Diff exists. They are too different to try to put them together. ExUnit.Pattern is a good starting name. Also don't forget other pattern exists too, such as a just a variable or ^var as well as guards and also binary patterns.

Also, for simplicity, I wouldn't focus on having diffs only on the patterns. Green for what worked, red for what did not.

[jeremyowensboggs]

After some thought and work, I would like to split this into two issues. One to handle match? and one to handle assert_receive(d). Match? is similiar to ==, so it makes sense to have the left and the right like the current diff. My impression about assert_received is that we should match against the mailbox contents -> printing out the contents with green for the parts of the match that worked, and red for the parts of the match that didn't?

[josevalim]

@jeremyowensboggs can you please expand? Both assert match? and assert_receive rely on pattern matching, so the logic for handling both should be the same.

[jeremyowensboggs]

The format for match output fits in nicely with existing paradigms. We have a left and a right, so it was easy to use the existing formatter with a small extension to handle pins and assigns. When I think through the output for assert_receive, I'm not convinced the left/right is the right way to go, since you could have multiple items in a mailbox. Do we need to show the diff for each one?

[josevalim]

@jeremyowensboggs don't worry about the left and right now. The most important is something that diffs a value against a pattern. Everything else is just exhibitation. For match?, we will diff the right side against the pattern, for assert_receive we will diff the last 10 messages or so in the inbox.

[jeremyowensboggs]

That exhibition is what I am getting hung up on. Should the mailbox item be printed with the elements that match the pattern in green, and the elements that contradict the pattern in red? How should we then represent items that are missing? Should we do a left and a right for each item in the mailbox?
Perhaps print the mailbox item colored as described above, and afterwords if any required elements were missing, then just list those elements?

[josevalim]

Should we do a left and a right for each item in the mailbox?

I see. Would printing the parts of the pattern that does not match in red be enough? That's what we do for Exception.blame and undefined function errors.

Then for the mailbox we can do as you said, show the value and the failing pattern side by side for each message.

[jeremyowensboggs]

I'll play around with it for a little bit and see how it looks.

[ggcampinho]

Hey @jeremyowensboggs, did you have success? I tried a little bit out and I think I have a prototype working with lists, tuples and atoms that need some refactoring but it's working.

[jeremyowensboggs]

Yes, I'm pretty happy with what I have that deconstructs the pattern and determines what matches, but I'm using the exiting diff that applies to '==' matches. I need to make up something that just colorizes the pattern based on status of the matching. You can see what it is currently doing at https://github.com/jeremyowensboggs/elixir - if you cd into ex_unit, then run ../../bin/elixir -r test/test_helper.exs -pr "test/ex_unit/seeitmatch.exs" you can visually see the cases that are covered.

[hylkealons]

Is there an update about this issue? It would be really nice to have this!

[josevalim]

Hi @hylkealons, @jeremyowensboggs has not sent a PR, so we don't know the state of their work yet.

But this is really hard to implement correctly, so it may take a while. Maybe a fair compromise is to implement only a subset of pattern matching to point obvious mistakes. But some other aspects like binary matching are non trivial.

[hylkealons]

That would help a lot in my case. Especially for Maps and Lists it would be very helpful!

Thanks for the quick reply.

[jeremyowensboggs]

I lost momentum while considering the various ways to format the output for the receive, since it compares against multiple candidate messages. I think I'll just push forward with uncolored matches, green - need to add that value to the message to make it match, and red means you need to remove that value from the match.

[hylkealons]

how about making them yellow instead of green? for me yellow makes more sense because green means something that is proper/good. If you need help testing it, let me know!

[jeremyowensboggs]

@hylkealons If that offer to help testing is still open, I could use a second set of eyes. I've run through a handful of real world scenarios but could use some more.
the code is at https://github.com/jeremyowensboggs/elixir
Once cloned, just do a make in the clone directory, then cd to your project and do a
'export PATH="/elixir/bin:$PATH"'
followed by a mix clean, then a mix test. Then find some assert_recieves and make the fail.
When you have issues, just let me know.

[hylkealons]

@jeremyowensboggs I have been testing but I am not seeing any color coding yet. Maybe I forgot a step, but this is what I did:

1. Checked out your repo on the branch pattern_diff
2. make
3. Exported the path
4. Wrote a test
   
   Test code

defmodule AssertReceiveTest do
  use ExUnit.Case

  describe "string" do
    test "simple" do
      string = "abc"
      send(self(), string)

      match = "cde"
      assert_receive(^match)
    end
  end

  describe "map" do
    test "simple" do
      map = %{a: "1"}
      send(self(), map)

      match = %{a: "1", b: "2"}
      assert_receive(^match)
    end
  end

  describe "array" do
    test "simple" do
      array = [1,2,3,4,5,6]
      send self(), array

      match = [3,4,5,6]
      assert_receive(^match)
    end
  end

  describe "map nested" do
    test "map with atom keys" do
      map = %{a: "1", b: "string", c: [1,2,3], d: %{foo: :bar}}
      send self(), map

      match = %{a: "2", b: "string", c: [3,4,5], d: %{bar: :foo}}
      assert_receive(^match)
    end
  end
end

Result mix test:

Compare: %ExUnit.PatternDiff{
  diff_result: :neq,
  lh: %{ast: {:^, [line: 30], [{:match, [line: 30], nil}]}},
  rh: [1, 2, 3, 4, 5, 6],
  type: :value
}


  1) test array simple (AssertReceiveTest)
     test/assert_test.exs:25
     No message matching ^match after 100ms.
     The following variables were pinned:
       match = [3, 4, 5, 6]
     message: [1, 2, 3, 4, 5, 6]
     code:  assert_receive(^match)
     stacktrace:
       test/assert_test.exs:30: (test)

Compare: %ExUnit.PatternDiff{
  diff_result: :neq,
  lh: %{ast: {:^, [line: 20], [{:match, [line: 20], nil}]}},
  rh: %{a: "1"},
  type: :value
}


  2) test map simple (AssertReceiveTest)
     test/assert_test.exs:15
     No message matching ^match after 100ms.
     The following variables were pinned:
       match = %{a: "1", b: "2"}
     message: %{a: "1"}
     code:  assert_receive(^match)
     stacktrace:
       test/assert_test.exs:20: (test)

Compare: %ExUnit.PatternDiff{
  diff_result: :neq,
  lh: %{ast: {:^, [line: 10], [{:match, [line: 10], nil}]}},
  rh: "abc",
  type: :value
}


  3) test string simple (AssertReceiveTest)
     test/assert_test.exs:5
     No message matching ^match after 100ms.
     The following variables were pinned:
       match = "cde"
     message: "abc"
     code:  assert_receive(^match)
     stacktrace:
       test/assert_test.exs:10: (test)

Compare: %ExUnit.PatternDiff{
  diff_result: :neq,
  lh: %{ast: {:^, [line: 40], [{:match, [line: 40], nil}]}},
  rh: %{a: "1", b: "string", c: [1, 2, 3], d: %{foo: :bar}},
  type: :value
}


  4) test map nested map with atom keys (AssertReceiveTest)
     test/assert_test.exs:35
     No message matching ^match after 100ms.
     The following variables were pinned:
       match = %{a: "2", b: "string", c: [3, 4, 5], d: %{bar: :foo}}
     message: %{a: "1", b: "string", c: [1, 2, 3], d: %{foo: :bar}}
     code:  assert_receive(^match)
     stacktrace:
       test/assert_test.exs:40: (test)

..

Finished in 0.3 seconds

[jeremyowensboggs]

Thanks! I had only been using pins as primitives in my tests. Have another go, I updated the code to diff through a pin, rather than just stop if it didn't match.

[jeremyowensboggs]

I don't know if this is the right place to ask this question, but ... I was merging in upstream changes and some of my tests around guard usage started to fail.

send(self(), [1, 2, 3])
    assert_receive [a, b, 3] when is_binary(a) and is_binary(b)

now fails during macro expansion with the error (ArgumentError) invalid expression in match, and is not allowed on patterns such as function clauses, case clauses or on the left side of the = operator

A quick look at the code in kernel.ex, and this appears to be deliberate, that is :and and :or no longer valid in a match. Is this a deliberate change, or am I misreading what should be happening?

[josevalim]

“or” and “and” are still definitely valid in a guard.

José Valimwww.plataformatec.com.br
http://www.plataformatec.com.br/Founder and Director of R&D

[jeremyowensboggs]

Looks like this line: https://github.com/elixir-lang/elixir/blob/ffb931a5ac805ade8dca2e9dae78c0032655e3ce/lib/ex_unit/lib/ex_unit/assertions.ex#L439
Puts the state of the macro into a :match context, which causes the expansion of the :and or :or to fail when the pattern is expanded on the next line.

[josevalim]

That’s definitely a bug then. Can you please open up a new issue? Thanks!

José Valimwww.plataformatec.com.br
http://www.plataformatec.com.br/Founder and Director of R&D

[hylkealons]

hey @jeremyowensboggs, how's this PR coming along? Can I help you out with anything?

[josevalim]

The pattern diff mechanism is in. There are two next steps left:

1. Use the new diff on assert_receive

2. Also compute the diff when guards are involved. In other words, if the pattern matches, then it likely because of guards, so we need to evaluate it. We only need to evaluate the root nodes of every when, or, and and. So if we have something like: condition and tuple_size(foo) == tuple_size(bar), we extract both sides of or, and if it fails, we paint it in red. The unfortunate complexity in this approach is that it requires us to implement a subset of the language (basically function calls and the creation of lists, tuples, maps).

Let me know if you someone wants to contribute on these remaining changes!

[ggcampinho]

Thank you! I'll work on the remaining changes and I'll send them soon! :)

[josevalim]

Closing in favor of the last PR. :heart: