Phoenix: Auto-generated tests fail on datetime fields

[smadeja]

I'm not sure if this is the right place to post this, so sorry in advance. ;-)

Environment

• Elixir version: 1.4.2
• Phoenix version: master @ 074a584ae324f78fa89f7ca097c38f8805d3021e
• Operating system: macOS Sierra 10.12.3 (16D32)
• PostgreSQL version: 9.6.2

Steps to reproduce

1. Run mix phx.gen.html Accounts User users some_date:datetime
2. (Update the router and migrate)
3. Run mix test

Expected behavior

Tests that were generated with the resource pass.

Actual behavior

Some time-related tests fail. Microseconds don't match.

...........

  1) test create_user/1 with valid data creates a user (DevApp.AccountsTest)
     test/accounts_test.exs:26
     Assertion with == failed
     code:  user.some_date() == %{day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010}
     left:  ~N[2010-04-17 14:00:00]
     right: %{day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010}
     stacktrace:
       test/accounts_test.exs:29: (test)



  2) test list_users/1 returns all users (DevApp.AccountsTest)
     test/accounts_test.exs:16
     Assertion with == failed
     code:  Accounts.list_users() == [user]
     left:  [%DevApp.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "accounts_users">, id: 7, inserted_at: ~N[2017-03-04 12:17:50.154579], updated_at: ~N[2017-03-04 12:17:50.154589], some_date: %NaiveDateTime{calendar: Calendar.ISO, day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010, microsecond: {0, 6}}}]
     right: [%DevApp.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "accounts_users">, id: 7, inserted_at: ~N[2017-03-04 12:17:50.154579], updated_at: ~N[2017-03-04 12:17:50.154589], some_date: %NaiveDateTime{calendar: Calendar.ISO, day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010, microsecond: {0, 0}}}]
     stacktrace:
       test/accounts_test.exs:18: (test)

...

  3) test update_user/2 with valid data updates the user (DevApp.AccountsTest)
     test/accounts_test.exs:36
     Assertion with == failed
     code:  user.some_date() == %{day: 18, hour: 15, minute: 1, month: 5, second: 1, year: 2011}
     left:  ~N[2011-05-18 15:01:01]
     right: %{day: 18, hour: 15, minute: 1, month: 5, second: 1, year: 2011}
     stacktrace:
       test/accounts_test.exs:41: (test)



  4) test get_user! returns the user with given id (DevApp.AccountsTest)
     test/accounts_test.exs:21
     Assertion with == failed
     code:  Accounts.get_user!(user.id()) == user
     left:  %DevApp.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "accounts_users">, id: 11, inserted_at: ~N[2017-03-04 12:17:50.175148], updated_at: ~N[2017-03-04 12:17:50.175157], some_date: %NaiveDateTime{calendar: Calendar.ISO, day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010, microsecond: {0, 6}}}
     right: %DevApp.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "accounts_users">, id: 11, inserted_at: ~N[2017-03-04 12:17:50.175148], updated_at: ~N[2017-03-04 12:17:50.175157], some_date: %NaiveDateTime{calendar: Calendar.ISO, day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010, microsecond: {0, 0}}}
     stacktrace:
       test/accounts_test.exs:23: (test)



  5) test update_user/2 with invalid data returns error changeset (DevApp.AccountsTest)
     test/accounts_test.exs:44
     Assertion with == failed
     code:  user == Accounts.get_user!(user.id())
     left:  %DevApp.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "accounts_users">, id: 12, inserted_at: ~N[2017-03-04 12:17:50.182251], updated_at: ~N[2017-03-04 12:17:50.182260], some_date: %NaiveDateTime{calendar: Calendar.ISO, day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010, microsecond: {0, 0}}}
     right: %DevApp.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "accounts_users">, id: 12, inserted_at: ~N[2017-03-04 12:17:50.182251], updated_at: ~N[2017-03-04 12:17:50.182260], some_date: %NaiveDateTime{calendar: Calendar.ISO, day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010, microsecond: {0, 6}}}
     stacktrace:
       test/accounts_test.exs:47: (test)

.

Finished in 0.3 seconds
20 tests, 5 failures

Randomized with seed 761748

[smadeja]

In this case I can get it to pass by replacing

%{day: 17, hour: 14, minute: 0, month: 4, second: 0, year: 2010}

with

%NaiveDateTime{day: 17, hour: 14, microsecond: {0, 6}, minute: 0, month: 4, second: 0, year: 2010}

and

%{day: 18, hour: 15, minute: 1, month: 5, second: 1, year: 2011}

with

%NaiveDateTime{day: 18, hour: 15, microsecond: {1, 6}, minute: 1, month: 5, second: 1, year: 2011}

[LostKobrakai]

I have the same issue with utc_datetime fields, same {0, 0} to {0, 6} difference.

[pshoukry]

@chrismccord I can still reproduce this on phoenix 1.3 the problem still exists on the inserted_at and updated_at fields

3) test posts update_post/2 with invalid data returns error changeset (Plus.BlogTest)                                                         
     test/plus/blog/blog_test.exs:53
     Assertion with == failed       
     code:  assert post == Blog.get_post!(post.id())                    
     left:  %Plus.Blog.Post{__meta__: #Ecto.Schema.Metadata<:loaded, "posts">, content: "some content", id: 54, slug: "some slug", title: "some title", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 21, minute: 16, month: 9, second: 52, year: 2017, microsecond: {361353, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 21, minute: 16, month: 9, second: 52, year: 2017, microsecond: {361362, 6}}}                              
     right: %Plus.Blog.Post{__meta__: #Ecto.Schema.Metadata<:loaded, "posts">, content: "some content", id: 54, slug: "some slug", title: "some title", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 21, minute: 16, month: 9, second: 52, year: 2017, microsecond: {0, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 21, minute: 16, month: 9, second: 52, year: 2017, microsecond: {0, 6}}}    
     stacktrace:                    
       test/plus/blog/blog_test.exs:56: (test)      

[hogihung]

I am also having the issue:

  1) test host_roles list_host_roles/0 returns all host_roles (Maestro.AssetMetadataTest)
     test/maestro/asset_metadata/asset_metadata_test.exs:24
     Assertion with == failed
     code:  assert AssetMetadata.list_host_roles() == [host_role]
     left:  [%Maestro.AssetMetadata.HostRole{__meta__: #Ecto.Schema.Metadata<:loaded, "host_roles">, created_by: "Seed-File", description: "Oracle VMS", hosts: #Ecto.Association.NotLoaded<association :hosts is not loaded>, id: 1, name: "DOM0", updated_by: "Seed-File", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 23, minute: 44, month: 9, second: 33, year: 2017, microsecond: {0, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 23, minute: 44, month: 9, second: 33, year: 2017, microsecond: {0, 6}}}]
     right: [%Maestro.AssetMetadata.HostRole{__meta__: #Ecto.Schema.Metadata<:loaded, "host_roles">, created_by: "Seed-File", description: "Oracle VMS", hosts: #Ecto.Association.NotLoaded<association :hosts is not loaded>, id: 1, name: "DOM0", updated_by: "Seed-File", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 23, minute: 44, month: 9, second: 33, year: 2017, microsecond: {17616, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 15, hour: 23, minute: 44, month: 9, second: 33, year: 2017, microsecond: {17625, 6}}}]
     stacktrace:
       test/maestro/asset_metadata/asset_metadata_test.exs:26: (test)




➜  maestro git:(refactor_test_suite) ✗ elixir --version
Erlang/OTP 20 [erts-9.0.4] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Elixir 1.5.1
➜  maestro git:(refactor_test_suite)

➜  maestro git:(refactor_test_suite) ✗ mix -h | grep phx
mix local.phx          # Updates the Phoenix project generator locally
{--sniip--}
mix phx.new            # Creates a new Phoenix v1.3.0 application

Forgot to mention this is with MySQL as the database. Thank you.

Hogi...

P.s. Found a work around:

 @timestamps_opts [usec: Mix.env != :test]

Put that before your schema code.

Source: https://stackoverflow.com/questions/41555655/asserting-timestamp-with-microseconds-equals-mysql-database-value-in-ecto-phoeni

[chrismccord]

@pshoukry can you verify what generator command you ran as well as the DB you are using?

[pshoukry]

@chrismccord I used
mix phx.gen.html Blog Post posts title:string content:text slug:string
and my database is MySQL.

[chenxsan]

Can confirm it in my test.

1. Phoenix v1.3.0
2. MariaDB 10.1.18

how to reproduce

1. Run mix phx.new hello --database mysql
2. cd hello
3. mix phx.gen.html Accounts User users username:unique password_hash nickname
4. add resources "/users", UserController to router.ex
5. Run mix test

And here's the test results:

1) test users list_users/0 returns all users (Hello.AccountsTest)                      
     test/hello/accounts/accounts_test.exs:22                                            
     Assertion with == failed               
     code:  assert Accounts.list_users() == [user]                                       
     left:  [%Hello.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 7, nickname: "some nickname", password_hash: "some password_hash", username: "some username", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {0, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {0, 6}}}]
     right: [%Hello.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 7, nickname: "some nickname", password_hash: "some password_hash", username: "some username", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {106114, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {106120, 6}}}]
     stacktrace:                            
       test/hello/accounts/accounts_test.exs:24: (test)                                  



  2) test users get_user!/1 returns the user with given id (Hello.AccountsTest)          
     test/hello/accounts/accounts_test.exs:27                                            
     Assertion with == failed               
     code:  assert Accounts.get_user!(user.id()) == user                                 
     left:  %Hello.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 8, nickname: "some nickname", password_hash: "some password_hash", username: "some username", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {0, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {0, 6}}}
     right: %Hello.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 8, nickname: "some nickname", password_hash: "some password_hash", username: "some username", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {110233, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {110239, 6}}}
     stacktrace:                            
       test/hello/accounts/accounts_test.exs:29: (test)                                  

..                                          

  3) test users update_user/2 with invalid data returns error changeset (Hello.AccountsTest)                                                                                       
     test/hello/accounts/accounts_test.exs:52                                            
     Assertion with == failed               
     code:  assert user == Accounts.get_user!(user.id())                                 
     left:  %Hello.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 10, nickname: "some nickname", password_hash: "some password_hash", username: "some username", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {114220, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {114237, 6}}}
     right: %Hello.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 10, nickname: "some nickname", password_hash: "some password_hash", username: "some username", inserted_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {0, 6}}, updated_at: %NaiveDateTime{calendar: Calendar.ISO, day: 6, hour: 14, minute: 0, month: 10, second: 25, year: 2017, microsecond: {0, 6}}}
     stacktrace:                            
       test/hello/accounts/accounts_test.exs:55: (test)                                  

...                                         

Finished in 0.1 seconds                     
20 tests, 3 failures                        

Randomized with seed 964697

Add @timestamps_opts [type: Ecto.DateTime, usec: false] before the schema can fix the failed tests.

[chenxsan]

I'm afraid this problem is related to Ecto. As the documentation shows, the usec defaults to true. But In my test with MariaDB, the inserted_at & updated_at would get values like ~N[2017-10-09 02:58:50.000000] even usec set to true, the microsecond part is lost. That's why those generated tests failed.

[pshoukry]

@chenxsan that's a start, if its working properly in Postgres but not mysql then it has to be in Ecto.Adapters.MySQL. I will try to take a look deeper. thanks!

[brucepom]

I ran into this issue with mariaex 0.8.2 and Ecto 2.1.5. I was able to workaround by setting usec to false in my schema:
timestamps(usec: false)
Thanks for pointing me in the right direction @chenxsan.

[wdiechmann]

just like the doctor ordered :)

in my ./lib/project/invitation/device.ex in front of the schema do like above:

@timestamps_opts [type: Ecto.DateTime, usec: false]
schema "devices" do
  field :something, :string
end

and all your testing frustrations (at least pertaining to usec) goes away :)

(but the issue is still there __and__ my elixir-fu is far from able to combat Ecto code :(

[sifxtreme]

The above works! Thanks @wdiechmann

However, with the above I was getting warnings for Ecto.DateTime

$ mix test
Compiling 3 files (.ex)
warning: Ecto.DateTime is deprecated, plese use :naive_datetime instead
  lib/ecto/schema.ex:1872: Ecto.Schema.check_type!/3
  lib/ecto/schema.ex:1507: Ecto.Schema.__field__/4

Another solution is use :naive_datetime as suggested in the warning message.

  @timestamps_opts [type: :naive_datetime, usec: false]
  schema "users" do
    field :age, :integer
    field :name, :string

    timestamps()
  end

[wdiechmann]

Well, I might be jumping the gun on this - but I'm putting my two cents on the "usec: false" part of things; if I'm not entirely wrong the DB (or at least MySQL derivatives) records have no usec resolution hence will be set to '000000' by Ecto whereas the usec part of the timestamps in in-memory generated instances of say a User schema do have usec resolution - which eventually will mess up the logical ==

[josevalim]

The next version of Ecto will permanently fix this by having specific times with microseconds and without microseconds.