Skip to content

Commit e968af6

Browse files
dbernheiseldbernheisel
authored
Add log_sql_mode to output lock and adapter-specific commands during migrations (#347)
1 parent f096fa5 commit e968af6

14 files changed

Lines changed: 409 additions & 25 deletions

File tree

‎integration_test/myxql/migrations_test.exs‎

Lines changed: 115 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,115 @@
1+
defmodule Ecto.Integration.MigrationsTest do
2+
use ExUnit.Case, async: true
3+
4+
alias Ecto.Integration.PoolRepo
5+
import ExUnit.CaptureLog
6+
7+
@moduletag :capture_log
8+
@base_migration 3_000_000
9+
10+
defmodule NormalMigration do
11+
use Ecto.Migration
12+
13+
def change do
14+
create_if_not_exists table(:log_mode_table)
15+
end
16+
end
17+
18+
describe "Migrator" do
19+
@get_lock_command ~s[SELECT GET_LOCK("ecto_Ecto.Integration.PoolRepo", -1)]
20+
@release_lock_command ~s[SELECT RELEASE_LOCK("ecto_Ecto.Integration.PoolRepo")]
21+
@create_table_sql ~s[CREATE TABLE IF NOT EXISTS `log_mode_table`]
22+
@create_table_log "create table if not exists log_mode_table"
23+
@drop_table_sql ~s[DROP TABLE IF EXISTS `log_mode_table`]
24+
@drop_table_log "drop table if exists log_mode_table"
25+
@version_insert ~s[INSERT INTO `schema_migrations`]
26+
@version_delete ~s[DELETE s0.* FROM `schema_migrations`]
27+
28+
test "logs locking and transaction commands when log_all: true" do
29+
num = @base_migration + System.unique_integer([:positive])
30+
up_log =
31+
capture_log(fn ->
32+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log_all: true, log_sql: :info, log: :info)
33+
end)
34+
35+
assert up_log =~ "begin []"
36+
assert up_log =~ @get_lock_command
37+
assert up_log =~ @create_table_sql
38+
assert up_log =~ @create_table_log
39+
assert up_log =~ @release_lock_command
40+
assert up_log =~ @version_insert
41+
assert up_log =~ "commit []"
42+
43+
down_log =
44+
capture_log(fn ->
45+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log_all: true, log_sql: :info, log: :info)
46+
end)
47+
48+
assert down_log =~ "begin []"
49+
assert down_log =~ @get_lock_command
50+
assert down_log =~ @drop_table_sql
51+
assert down_log =~ @drop_table_log
52+
assert down_log =~ @release_lock_command
53+
assert down_log =~ @version_delete
54+
assert down_log =~ "commit []"
55+
end
56+
57+
test "does not log locking and transaction commands when log_sql is true" do
58+
num = @base_migration + System.unique_integer([:positive])
59+
up_log =
60+
capture_log(fn ->
61+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log_sql: :info, log: :info)
62+
end)
63+
64+
refute up_log =~ "begin []"
65+
refute up_log =~ @get_lock_command
66+
assert up_log =~ @create_table_sql
67+
assert up_log =~ @create_table_log
68+
refute up_log =~ @release_lock_command
69+
refute up_log =~ @version_insert
70+
refute up_log =~ "commit []"
71+
72+
down_log =
73+
capture_log(fn ->
74+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log_sql: :info, log: :info)
75+
end)
76+
77+
refute down_log =~ "begin []"
78+
refute down_log =~ @get_lock_command
79+
assert down_log =~ @drop_table_sql
80+
assert down_log =~ @drop_table_log
81+
refute down_log =~ @release_lock_command
82+
refute down_log =~ @version_delete
83+
refute down_log =~ "commit []"
84+
end
85+
86+
test ~s(does not log sql when log is default) do
87+
num = @base_migration + System.unique_integer([:positive])
88+
up_log =
89+
capture_log(fn ->
90+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log: :info)
91+
end)
92+
93+
refute up_log =~ "begin []"
94+
refute up_log =~ @get_lock_command
95+
refute up_log =~ @create_table_sql
96+
assert up_log =~ @create_table_log
97+
refute up_log =~ @release_lock_command
98+
refute up_log =~ @version_insert
99+
refute up_log =~ "commit []"
100+
101+
down_log =
102+
capture_log(fn ->
103+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log: :info)
104+
end)
105+
106+
refute down_log =~ "begin []"
107+
refute down_log =~ @get_lock_command
108+
refute down_log =~ @drop_table_sql
109+
assert down_log =~ @drop_table_log
110+
refute down_log =~ @release_lock_command
111+
refute down_log =~ @version_delete
112+
refute down_log =~ "commit []"
113+
end
114+
end
115+
end

‎integration_test/pg/migrations_test.exs‎

Lines changed: 101 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ defmodule Ecto.Integration.MigrationsTest do
22
use ExUnit.Case, async: true
33

44
alias Ecto.Integration.PoolRepo
5+
import ExUnit.CaptureLog
56

67
@moduletag :capture_log
78
@base_migration 3_000_000
@@ -15,13 +16,112 @@ defmodule Ecto.Integration.MigrationsTest do
1516
end
1617
end
1718

19+
defmodule NormalMigration do
20+
use Ecto.Migration
21+
22+
def change do
23+
create_if_not_exists table(:log_mode_table)
24+
end
25+
end
26+
1827
test "logs Postgres notice messages" do
1928
log =
20-
ExUnit.CaptureLog.capture_log(fn ->
29+
capture_log(fn ->
2130
num = @base_migration + System.unique_integer([:positive])
2231
Ecto.Migrator.up(PoolRepo, num, DuplicateTableMigration, log: false)
2332
end)
2433

2534
assert log =~ ~s(relation "duplicate_table" already exists, skipping)
2635
end
36+
37+
describe "Migrator" do
38+
@get_lock_command ~s(LOCK TABLE "schema_migrations" IN SHARE UPDATE EXCLUSIVE MODE)
39+
@create_table_sql ~s(CREATE TABLE IF NOT EXISTS "log_mode_table")
40+
@create_table_log "create table if not exists log_mode_table"
41+
@drop_table_sql ~s(DROP TABLE IF EXISTS "log_mode_table")
42+
@drop_table_log "drop table if exists log_mode_table"
43+
@version_insert ~s(INSERT INTO "schema_migrations")
44+
@version_delete ~s(DELETE FROM "schema_migrations")
45+
46+
test "logs locking and transaction commands when log_all: true" do
47+
num = @base_migration + System.unique_integer([:positive])
48+
up_log =
49+
capture_log(fn ->
50+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log_all: true, log_sql: :info, log: :info)
51+
end)
52+
53+
assert Regex.scan(~r/(begin \[\])/, up_log) |> length() == 2
54+
assert up_log =~ @get_lock_command
55+
assert up_log =~ @create_table_sql
56+
assert up_log =~ @create_table_log
57+
assert up_log =~ @version_insert
58+
assert Regex.scan(~r/(commit \[\])/, up_log) |> length() == 2
59+
60+
down_log =
61+
capture_log(fn ->
62+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log_all: true, log_sql: :info, log: :info)
63+
end)
64+
65+
assert down_log =~ "begin []"
66+
assert down_log =~ @get_lock_command
67+
assert down_log =~ @drop_table_sql
68+
assert down_log =~ @drop_table_log
69+
assert down_log =~ @version_delete
70+
assert down_log =~ "commit []"
71+
end
72+
73+
test "does not log locking and transaction commands when log_sql is true" do
74+
num = @base_migration + System.unique_integer([:positive])
75+
up_log =
76+
capture_log(fn ->
77+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log_sql: :info, log: :info)
78+
end)
79+
80+
refute up_log =~ "begin []"
81+
refute up_log =~ @get_lock_command
82+
assert up_log =~ @create_table_sql
83+
assert up_log =~ @create_table_log
84+
refute up_log =~ @version_insert
85+
refute up_log =~ "commit []"
86+
87+
down_log =
88+
capture_log(fn ->
89+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log_sql: :info, log: :info)
90+
end)
91+
92+
refute down_log =~ "begin []"
93+
refute down_log =~ @get_lock_command
94+
assert down_log =~ @drop_table_sql
95+
assert down_log =~ @drop_table_log
96+
refute down_log =~ @version_delete
97+
refute down_log =~ "commit []"
98+
end
99+
100+
test ~s(does not log sql when log is default) do
101+
num = @base_migration + System.unique_integer([:positive])
102+
up_log =
103+
capture_log(fn ->
104+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log: :info)
105+
end)
106+
107+
refute up_log =~ "begin []"
108+
refute up_log =~ @get_lock_command
109+
refute up_log =~ @create_table_sql
110+
assert up_log =~ @create_table_log
111+
refute up_log =~ @version_insert
112+
refute up_log =~ "commit []"
113+
114+
down_log =
115+
capture_log(fn ->
116+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log: :info)
117+
end)
118+
119+
refute down_log =~ "begin []"
120+
refute down_log =~ @get_lock_command
121+
refute down_log =~ @drop_table_sql
122+
assert down_log =~ @drop_table_log
123+
refute down_log =~ @version_delete
124+
refute down_log =~ "commit []"
125+
end
126+
end
27127
end

‎integration_test/tds/migrations_test.exs‎

Lines changed: 108 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,108 @@
1+
defmodule Ecto.Integration.MigrationsTest do
2+
use ExUnit.Case, async: true
3+
4+
alias Ecto.Integration.PoolRepo
5+
import ExUnit.CaptureLog
6+
7+
@moduletag :capture_log
8+
@base_migration 3_000_000
9+
10+
defmodule NormalMigration do
11+
use Ecto.Migration
12+
13+
def change do
14+
create_if_not_exists table(:log_mode_table)
15+
end
16+
end
17+
18+
describe "Migrator" do
19+
@get_lock_command ~s(sp_getapplock @Resource = 'ecto_Ecto.Integration.PoolRepo', @LockMode = 'Exclusive', @LockOwner = 'Transaction', @LockTimeout = -1)
20+
@create_table_sql ~s(CREATE TABLE [log_mode_table])
21+
@create_table_log "create table if not exists log_mode_table"
22+
@drop_table_sql ~s(DROP TABLE [log_mode_table])
23+
@drop_table_log "drop table if exists log_mode_table"
24+
@version_insert ~s(INSERT INTO [schema_migrations])
25+
@version_delete ~s(DELETE s0 FROM [schema_migrations])
26+
27+
test "logs locking and transaction commands when log_all: true" do
28+
num = @base_migration + System.unique_integer([:positive])
29+
up_log =
30+
capture_log(fn ->
31+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log_all: true, log_sql: :info, log: :info)
32+
end)
33+
34+
assert Regex.scan(~r/(begin \[\])/, up_log) |> length() == 2
35+
assert up_log =~ @get_lock_command
36+
assert up_log =~ @create_table_sql
37+
assert up_log =~ @create_table_log
38+
assert up_log =~ @version_insert
39+
assert Regex.scan(~r/(commit \[\])/, up_log) |> length() == 2
40+
41+
down_log =
42+
capture_log(fn ->
43+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log_all: true, log_sql: :info, log: :info)
44+
end)
45+
46+
assert Regex.scan(~r/(begin \[\])/, up_log) |> length() == 2
47+
assert down_log =~ @get_lock_command
48+
assert down_log =~ @drop_table_sql
49+
assert down_log =~ @drop_table_log
50+
assert down_log =~ @version_delete
51+
assert Regex.scan(~r/(commit \[\])/, up_log) |> length() == 2
52+
end
53+
54+
test "does not log locking and transaction commands when log_sql is true" do
55+
num = @base_migration + System.unique_integer([:positive])
56+
up_log =
57+
capture_log(fn ->
58+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log_sql: :info, log: :info)
59+
end)
60+
61+
refute up_log =~ "begin []"
62+
refute up_log =~ @get_lock_command
63+
assert up_log =~ @create_table_sql
64+
assert up_log =~ @create_table_log
65+
refute up_log =~ @version_insert
66+
refute up_log =~ "commit []"
67+
68+
down_log =
69+
capture_log(fn ->
70+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log_sql: :info, log: :info)
71+
end)
72+
73+
refute down_log =~ "begin []"
74+
refute down_log =~ @get_lock_command
75+
assert down_log =~ @drop_table_sql
76+
assert down_log =~ @drop_table_log
77+
refute down_log =~ @version_delete
78+
refute down_log =~ "commit []"
79+
end
80+
81+
test ~s(does not log sql when log is default) do
82+
num = @base_migration + System.unique_integer([:positive])
83+
up_log =
84+
capture_log(fn ->
85+
Ecto.Migrator.up(PoolRepo, num, NormalMigration, log: :info)
86+
end)
87+
88+
refute up_log =~ "begin []"
89+
refute up_log =~ @get_lock_command
90+
refute up_log =~ @create_table_sql
91+
assert up_log =~ @create_table_log
92+
refute up_log =~ @version_insert
93+
refute up_log =~ "commit []"
94+
95+
down_log =
96+
capture_log(fn ->
97+
Ecto.Migrator.down(PoolRepo, num, NormalMigration, log: :info)
98+
end)
99+
100+
refute down_log =~ "begin []"
101+
refute down_log =~ @get_lock_command
102+
refute down_log =~ @drop_table_sql
103+
assert down_log =~ @drop_table_log
104+
refute down_log =~ @version_delete
105+
refute down_log =~ "commit []"
106+
end
107+
end
108+
end

‎lib/ecto/adapters/myxql.ex‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -231,7 +231,7 @@ defmodule Ecto.Adapters.MyXQL do
231231
Ecto.Adapters.SQL.raise_migration_pool_size_error()
232232
end
233233

234-
opts = opts ++ [log: false, timeout: :infinity]
234+
opts = Ecto.Adapters.SQL.log_options(opts) ++ [timeout: :infinity]
235235

236236
{:ok, result} =
237237
transaction(meta, opts, fn ->

‎lib/ecto/adapters/postgres.ex‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -209,7 +209,7 @@ defmodule Ecto.Adapters.Postgres do
209209
Ecto.Adapters.SQL.raise_migration_pool_size_error()
210210
end
211211

212-
opts = opts ++ [log: false, timeout: :infinity]
212+
opts = Ecto.Adapters.SQL.log_options(opts) ++ [timeout: :infinity]
213213

214214
{:ok, result} =
215215
transaction(meta, opts, fn ->

‎lib/ecto/adapters/sql.ex‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -872,6 +872,15 @@ defmodule Ecto.Adapters.SQL do
872872

873873
## Log
874874

875+
@doc false
876+
def log_options(opts) do
877+
if opts[:log_sql] && opts[:log_all] do
878+
[log: opts[:log_sql]]
879+
else
880+
[log: false]
881+
end
882+
end
883+
875884
defp with_log(telemetry, params, opts) do
876885
[log: &log(telemetry, params, &1, opts)] ++ opts
877886
end

‎lib/ecto/adapters/tds.ex‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -284,7 +284,7 @@ defmodule Ecto.Adapters.Tds do
284284
Ecto.Adapters.SQL.raise_migration_pool_size_error()
285285
end
286286

287-
opts = opts ++ [log: false, timeout: :infinity]
287+
opts = Ecto.Adapters.SQL.log_options(opts) ++ [timeout: :infinity]
288288

289289
{:ok, result} =
290290
transaction(meta, opts, fn ->

0 commit comments

Comments
 (0)