Log output from migrations

[ericdp]

Is there a way to enable logging? I'd like to get an output of the migration.

For example with the following, I'd like to look in a log and see exactly how many rows were inserted. It might not be what I expected.

START TRANSACTION;

INSERT INTO db.tbl
  SELECT col1, col2, col3 FROM db.tbl2
  WHERE col2 IN ( val1, val2, ... );

SELECT ROW_COUNT();

COMMIT;

[amacneil]

I don't think this is currently possible. Would you expect this behavior to be the default or behind some sort of --verbose flag?

[wkalt]

I want this too! I started looking into how it could be done, but it's not clear to me it's possible without some kind off additional statement delimiter within the migrations files.

The issue with the way things work today is the entire migration file is executed as one multistatement transaction, so golang is not able to log information on the statement level such as statements, timings, and insert counts.

In order to get that, I think we'd need to split the files by statement and then execute them in a for loop here:
https://github.com/amacneil/dbmate/blob/master/pkg/dbmate/db.go#L263,L265

The problem is, splitting a SQL file by statement isn't trivial. Splitting on something like ";\n" will break for statements that include triggers or dynamic SQL. Without introducing some kind of comment syntax, it may be too big a pain to handle generically.

[amacneil]

I've looked into the sql statement splitting before too. From memory it's required in order to implement a spanner driver, since the existing spanner driver doesn't support multiple statements. It might also allow us to have better error messages (including line numbers etc).

There are a few golang sql parsing libraries floating around, presumably one of them is good enough for our purposes.

However, it's not clear to me how this would interact with statements which change delimiter, start/commit transaction, etc. Will definitely require more investigation.

[vperiyasamy]

@amacneil It looks like we are throwing away Result here https://github.com/amacneil/dbmate/blob/master/pkg/dbmate/db.go#L307
where Result comes from here: https://golang.org/pkg/database/sql/#Tx.Exec
couldn't we add a verbose flag and just print Result? or am I missing something

[amacneil]

Well, we could print that Result, but it looks like the only fields it exposes are LastInsertId and RowsAffected, neither of which would be particularly useful or address the need of OP.

I might be missing an obvious way to solve this, but the only ideas I can think of right now are either importing a sql parsing library and executing each statement individually, or just piping the whole migration out to an external psql (if available). Both of which would require pretty significant refactoring and include downsides that I'm not convinced are worth the trade off.

Open to ideas if anyone has any.

[vperiyasamy]

Both LastInsertId and RowsAffected would be very useful for my organization's needs, and OP's:

I'd like to look in a log and see exactly how many rows were inserted.

at least as a minor confirmation of the executed statement. Since that would be fairly trivial, could I open a PR for that?

[amacneil]

Sure, sounds good! I was thinking more from the perspective of logging arbitrary output, but if those two fields are useful then I'm happy to merge a PR.

Not sure about the cli for it - probably something like dbmate up [-v|--verbose] would be fine, or could just have it enabled by default.

[vperiyasamy]

#138

I wasn't able to call the flag verbose because urfave cli package panicked for trying to redefine the v flag.

[amacneil]

While #138 adds some basic output, I'm going to keep this issue open because the original request was to display output of sql commands (e.g. SELECT ROW_COUNT()) during a migration.

I can't see a way to implement this using the current pq library we use, but I could be missing something so I'm open to suggestions.