getting a 'has already been deployed" message

[fleetfootmike]

After catching up a slightly messed-up commit/deploy, with
sqitch deploy my_project_staging --log-only
which succeeded and deployed the three changes I expected it to, I run it again and get

Deploying changes to my_project_staging
Change "organisations/add_org_admin_permission (d8798f8359580743b534e2f1b007132cd485eb5e)" has already been deployed

Where should I be looking for the cause of this?

organisations/add_org_admin_permission is the most recent change, and as far as I can see change_ids and script_hashs are correct in the changes table.

[theory]

Do the two change have identical deploy scripts? That will fail because they need to generate different script hashes.

[fleetfootmike]

no, and both
find sql/deploy/ -name '*.sql' | xargs -n 1 sha1sum | sort
and
select script_hash, group_concat(change) from changes group by script_hash;
returns unique answers.

[fleetfootmike]

organisations/add_org_admin_permission has been deployed, and is in sqitch.plan and the output of sqitch log (and thus the changes table). What's puzzling me is why sqitch deploy is choosing it to be redeployed.

[theory]

Yeah I don't understand that, either. Unless…are the dates out of order in the changes table? If organisations/add_org_admin_permission doesn't have the latest committed_at, it won't be considered the last deployed.

[fleetfootmike]

Ok - the result of a sqitch deploy --log-only had put three changes in changes with exactly the same (to the second, as MariaDB seems not to do < second timestamps) timestamps which were sorting in sqitch log in the opposite order to which they'd been deployed.

Fix was to remove the rows from changes and events by hand (caution to anyone else doing this: do not do this unless you understand what you're doing AND have a backup of the tables), and then deploy the three changes one after another using sqitch deploy --log-only <change name> at least a second apart :D

Thanks for listening :D

[theory]

That's odd. Sqitch uses DATETIME(6) for timestamps, which the docs report using "microsecond precision". Sqitch then sets its value with utc_timestamp(6) if it the database supports fractional seconds. It determines whether fractional second are supported with this function:

sqitch/lib/App/Sqitch/Engine/mysql.pm

Lines 215 to 217 in 558651c

	return $dbh->{mariadb_serverinfo} =~ /mariadb/i
	? $dbh->{mariadb_serverversion} >= 50305
	: $dbh->{mariadb_serverversion} >= 50604;

What version of Sqitch are you using? I wonder if something got messed up in the switch from DBD::mysql to DBD::MariaDB. Do mariadb_serverinfo and mariadb_serverversion exist in the handle?

[fleetfootmike]

 `committed_at` datetime NOT NULL COMMENT 'Date the change was deployed.',

:(

$ sqitch --version
sqitch (App::Sqitch) v1.3.0

from the project cpanfile, this seems to have been explicitly pinned.

requires 'App::Sqitch' => '== 1.3.0';

I shall have words :D

[theory]

Oh wow, that was a while ago. What version of MariaDB are you running? Or was the registry moved over from an earlier version, perhaps?

[fleetfootmike]

I have a nasty feeling it was pinned by design due to a bug in one of the dependencies....

ahah - in fact, it was one of us raising #874, which I note you appear to have fixed. I'll see if we can upgrade now.

[theory]

Ah, okay, that'll be released next week.