Capturing faked migrations in django_migrations table

[steve byerly]

I couldn't find any related discussions on this topic, but I would find it helpful to have documentation whether a specific migration was faked or not. This would allow someone to look at all migrations that have been run and see which ones were actually applied.

My use case is migrating a large project to django 1.7. Since there are many apps in the project the initial migrations generated are not all 0001 - 0002, 0003 both present. These will all get faked, but it's not obvious in 6 months that migration 0003 in one app that was created as part of initializing migrations was faked vs migration 0003 in another app that was applied.

Adding a NullBooleanField to the model would solve the issue, but I'm not positive if this is good practice.

Thanks for the input in advance.

-Steve

[Tim Graham]

I'm curious to know the reason why it would be helpful to know whether or not a migration was faked. When you fake a migration, you are promising that your schema matches the migration, so it seems to me that it would only matter if you made a mistake there.

[Markus Holtermann]

Hi Steve,

apart from what Tim said, since you commit the migration files as part
of the apps' code to your source code version control system, you can
simply have a look at the commit dates there. I'm not convinced having a
marker for faked migrations in the database is useful.

/Markus

>--
>You received this message because you are subscribed to the Google Groups "Django developers (Contributions to Django itself)" group.
>To unsubscribe from this group and stop receiving emails from it, send an email to django-develop...@googlegroups.com.
>To post to this group, send email to django-d...@googlegroups.com.
>Visit this group at http://groups.google.com/group/django-developers.
>To view this discussion on the web visit https://groups.google.com/d/msgid/django-developers/a39cbdcd-c797-4db5-89be-98cffbddf2ba%40googlegroups.com.
>For more options, visit https://groups.google.com/d/optout.


--

[Andrew Godwin]

I agree with Markus/Tim - the whole point of faked migrations is that they're meant to exactly match the existing schema. If Django is auto-faking migrations that don't match the existing one that would be a bug, but it's almost too conservative in that aspect.

Are you manually faking these migrations? Or having Django do it for you and getting it wrong?

Andrew

To view this discussion on the web visit https://groups.google.com/d/msgid/django-developers/20150513172703.GA5391%40pyler.local.

[Shai Berger]

I think we had this discussion, more-or-less, around South migrations (I
looked a little, but couldn't find it). The context there was, as Tim hinted,
"forensics" -- trying to figure out how a system came into its (broken) state.
For that (as well as the OP's case, AFAICT) it makes little sense to add a flag
in the migration history (really, "applied migrations") table, but it does
make sense to have some sort of "migrations log", which would have a record
for every migration executed (including backwards).

Shai.

[Andrew Godwin]

I agree a log would be helpful, but I'm not sure that should be stored in the database? We could either add a history/audit table in the database or we could have some way of configuring a logger that stores locally (which is a much higher bar, but presumably where sysadmins actually want logs?)

Andrew

[Markus Holtermann]

I think having the Python logging module outputting the things the migrations framework does, seems to be a good idea. I can see some use cases where people want to turn that on.

I opened an issue to keep track of the feature request: https://code.djangoproject.com/ticket/24800

/Markus

[steve byerly]

Sorry all, i didn't get notified of the replies.

I guess I assumed that since you are already capturing the applied migrations in the database, why not also capture if it was faked or not? 

In the case I outlined in the original post, there were initial migrations (0001, 0002, 0003) and new migrations (0002, 0003). During a deploy, it's really nice to make sure you faked the right migrations/didn't fake the wrong migrations since it will not auto-fake this scenario - unless I'm missing something.

I'm also unclear what the argument against storing in the migrations table is vs logging them - honest question. Since I have 4 web servers, the information would be logged to any one of them - depending on which executed the migration during deploy.

[Shai Berger]

Hi Steve,

On Wednesday 20 May 2015 01:50:15 steve byerly wrote:
>
> I'm also unclear what the argument against storing in the migrations table
> is vs logging them - honest question. Since I have 4 web servers, the
> information would be logged to any one of them - depending on which
> executed the migration during deploy.
>

The argument is, basically, that logging solves a more general use-case, and
so it is a better solution for the problem.

Your use case, as you described it:

> During a deploy, it's really nice to make sure you faked the right
> migrations/didn't fake the wrong migrations

fits in the general pattern of "I want to know what happened in this system".
Logging, as far as we understand, solves that problem. The migrations table
solves a different problem -- it records which migrations the system considers
to have been executed, to support the decision of which migrations to run
(when asked to). One of the outstanding "conflicts" between the two goals is
encountered when a migration is rolled back: For "decision support", the
simplest handling is to delete the migration's record from the table (and this
is what Django does, AFAIK). For "forensics", this behavior is quite
unacceptable.

The most natural solution for knowing what happened in a system is logging.
When you have 4 servers, you want some federated logging anyway -- migrations
are probably not the only case where something that happens on one server
affects the behavior of others. Be that as it may, Python's logging library
allows you to set different handlers for different loggers -- so, assuming
migrations get their own logger, it shouldn't be very hard to set up logging
so that all migration logging goes to some special place. That place can even
be the database -- see e.g. https://pypi.python.org/pypi/django-logdb (I have
no personal experience with that package, I just searched for it).

HTH,
Shai.

[steve byerly]

Awesome, thank you very much for the detailed answer.

-Steve

[Markus Holtermann]

Hey there,

here's a pull request for this feature: https://github.com/django/django/pull/5279 . I'd appreciate some review.

/Markus

[Markus Holtermann]

First of all, thanks for all the feedback!

While the PR is in a good state there's one discussion happening with a decision that needs to be made:

The current Django documentation states that log messages are send to the console from INFO level an up. However, because of a misconfiguration this is not true; messages are logged for WARNING and above (see https://github.com/django/django/pull/5289 for a patch for that, see discussion at https://groups.google.com/forum/#!topic/django-developers/no2IhnRty68). Giving the updated default configuration, sending log messages to any logger in the `django` namespace ('django.*') will show up on the command line when run on DEBUG=True. This may make sense for `django.request` as that is issued from the runserver command, but at least the newly introduced `django.db.migrations` logger is not too helpful on the console. Even for `django.db` (query logging) I'm not too happy for it to show up in `manage.py shell` but like it in `manage.py runserver`.

I see the following solutions to bring this PR forward:

1. Configure `django.db.migrations` logger to not send messages to console by default and keep log levels to INFO (for "Applied/Unapplied migration XYZ") and DEBUG (for "Marked migraiton XYZ as applied/unapplied")
2. Change the log levels for both messages to DEBUG
3. Don't propagate messages from `django.db.migrations` logger to parents
4. Don't go forward with the above mentioned patch amending the default log level

I prefer option 1 and clearly document how people can activate the logger, while option 2 is currently implemented but comes with the disadvantage that you can't separate the two log levels. Option 3 works too, but could cause some weird behavior and confusion if not documented why it's set. Option 4, no idea, it sounds correct to me.

/Markus

[Shai Berger]

Hi,

On Wednesday 16 September 2015 03:13:35 Markus Holtermann wrote:
>
> I see the following solutions to bring this PR forward:
>

> 1. Configure `django.db.migrations` logger to not send messages to

> console by default and keep log levels to INFO (for "Applied/Unapplied
> migration XYZ") and DEBUG (for "Marked migraiton XYZ as
> applied/unapplied")

> 2. Change the log levels for both messages to DEBUG
> 3. Don't propagate messages from `django.db.migrations` logger to
> parents
> 4. Don't go forward with the above mentioned patch amending the

> default log level
>
> I prefer option 1 and clearly document how people can activate the logger,

Wait -- so you mean "turn logger off by default"? I'd find that strongly
counter-intuitive.

> while option 2 is currently implemented but comes with the disadvantage
> that you can't separate the two log levels.

As I noted on the PR, its biggest disadvantage IMO is that all migration
logging is then done at "DEBUG" level, which undermines the purpose set forth
in this thread.

> Option 3 works too, but could cause some weird behavior and confusion if not
> documented why it's set.

Yes. Exactly as counter-intuituve as option 1

> Option 4, no idea, it sounds correct to me.
>

I agree that INFO logging should go out to the console when activated by a
management command.

Let's recap: The main problem is the doubling of messages on migrations, as
the migrations framework already prints to stdout when it runs migrations.

A possible solution, then, is to turn off these printings in favor of the
logging. Its big disadvantage, AFAICT, is that the custom printing of
migrations is far prettier than the default logging format.

Another possible solution is a variation on Option 2 -- change the log levels
on both messages to DEBUG, but only if settings.DEBUG is on. Where
settings.DEBUG is off, it is also more likely that the django loggers do not go
to the console.

Yet another solution is to make a finer definition of which loggers print to
console by default -- for example, define a "django2"[1] logger hierarchy, with
the migrations logger under it instead of under "django", where django2 does
not propagate to root and, by default, has no handlers.

Out of ideas,
Shai.

[1] Yes, I know. Not a very descriptive name. It's 2AM here, it's the best I
can do now. Good night.

[Tim Graham]

Maybe we could have BaseCommand remove the 'console' handler from the 'django' logger during the command's execution (at least under normal verbosity conditions)?

As mentioned on the pull request, there is also an idea to update management commands to use logging [1]. I think the two ideas could coexist.

[1] https://github.com/django/django/pull/3467