search

metabrainz / musicbrainz-docker

Docker Compose project for the MusicBrainz Server with replication, search, and development setup
https://musicbrainz.org/doc/MusicBrainz_Server/Setup
284 stars 72 forks source link

Replication issues after upgrading to v-2022-08-25-hotfixes #235

Closed JoshDi closed 1 year ago

JoshDi commented 1 year ago

I upgraded to v-2022-08-25-hotfixes yesterday and followed all of the steps successfully. The last command that confirms that this upgrade was successful, shows over 200k rows.

However, now when I run replication, I get the following errors. Any ideas how to fix this? 

    'INSERT INTO "musicbrainz"."release_group_tag" ("count", "last_updated", "release_group", "tag") VALUES (?, ?, ?, ?)'
    (1 2022-08-26 10:47:21.228028+00 1014099 7)
23505 DBD::Pg::st execute failed: ERROR:  duplicate key value violates unique constraint "release_group_tag_pkey"
DETAIL:  Key (release_group, tag)=(1014099, 7) already exists. [for Statement "INSERT INTO "musicbrainz"."release_group_tag" ("count", "last_updated", "release_group", "tag") VALUES (?, ?, ?, ?)" with ParamValues: 1='1', 2='2022-08-26 10:47:21.228028+00', 3='1014099', 4='7']
 at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
    Sql::catch {...} (MusicBrainz::Server::Exceptions::DatabaseError=HASH(0x55f1eabb0580)) called at /root/perl5/lib/perl5/Try/Tiny.pm line 123
    Try::Tiny::try(CODE(0x55f1eabbeba8), Try::Tiny::Catch=REF(0x55f1eabbe8f0)) called at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 117
    Sql::do(Sql=HASH(0x55f1eaa4c060), "INSERT INTO \"musicbrainz\".\"release_group_tag\" (\"count\", \"last"..., 1, "2022-08-26 10:47:21.228028+00", 1014099, 7) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 332
    main::mirrorInsert(Sql=HASH(0x55f1ea71fb80), Sql=HASH(0x55f1eaa4c060), ARRAY(0x55f1ea622810), 1241579422) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 269
    main::mirrorCommand("i", Sql=HASH(0x55f1ea71fb80), Sql=HASH(0x55f1eaa4c060), ARRAY(0x55f1ea622810), 1241579422, CODE(0x55f1eabbe458)) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 178
Fri Aug 26 17:46:51 2022 : Continuing a previously aborted load
Fri Aug 26 17:46:51 2022 : Processing replication changes
     XIDs     Stmts est%  XIDs/sec  Stmt/sec
        0         0   0%         0         0Failed query:
    'INSERT INTO "musicbrainz"."release_group_tag" ("count", "last_updated", "release_group", "tag") VALUES (?, ?, ?, ?)'
    (1 2022-08-26 10:47:21.228028+00 1014099 7)
23505 DBD::Pg::st execute failed: ERROR:  duplicate key value violates unique constraint "release_group_tag_pkey"
DETAIL:  Key (release_group, tag)=(1014099, 7) already exists. [for Statement "INSERT INTO "musicbrainz"."release_group_tag" ("count", "last_updated", "release_group", "tag") VALUES (?, ?, ?, ?)" with ParamValues: 1='1', 2='2022-08-26 10:47:21.228028+00', 3='1014099', 4='7']
 at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
    Sql::catch {...} (MusicBrainz::Server::Exceptions::DatabaseError=HASH(0x55d4d07defb0)) called at /root/perl5/lib/perl5/Try/Tiny.pm line 123
    Try::Tiny::try(CODE(0x55d4d07ed598), Try::Tiny::Catch=REF(0x55d4d07ed2e0)) called at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 117
    Sql::do(Sql=HASH(0x55d4d06dd120), "INSERT INTO \"musicbrainz\".\"release_group_tag\" (\"count\", \"last"..., 1, "2022-08-26 10:47:21.228028+00", 1014099, 7) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 332
    main::mirrorInsert(Sql=HASH(0x55d4d0350298), Sql=HASH(0x55d4d06dd120), ARRAY(0x55d4d0250fc8), 1241579422) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 269
    main::mirrorCommand("i", Sql=HASH(0x55d4d0350298), Sql=HASH(0x55d4d06dd120), ARRAY(0x55d4d0250fc8), 1241579422, CODE(0x55d4d07ece48)) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 178
Fri Aug 26 17:47:14 2022 : Continuing a previously aborted load
Fri Aug 26 17:47:15 2022 : Processing replication changes
     XIDs     Stmts est%  XIDs/sec  Stmt/sec
        0         0   0%         0         0Failed query:
    'INSERT INTO "musicbrainz"."release_group_tag" ("count", "last_updated", "release_group", "tag") VALUES (?, ?, ?, ?)'
    (1 2022-08-26 10:47:21.228028+00 1014099 7)
23505 DBD::Pg::st execute failed: ERROR:  duplicate key value violates unique constraint "release_group_tag_pkey"
DETAIL:  Key (release_group, tag)=(1014099, 7) already exists. [for Statement "INSERT INTO "musicbrainz"."release_group_tag" ("count", "last_updated", "release_group", "tag") VALUES (?, ?, ?, ?)" with ParamValues: 1='1', 2='2022-08-26 10:47:21.228028+00', 3='1014099', 4='7']
 at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
    Sql::catch {...} (MusicBrainz::Server::Exceptions::DatabaseError=HASH(0x557f4bac8e20)) called at /root/perl5/lib/perl5/Try/Tiny.pm line 123
    Try::Tiny::try(CODE(0x557f4bad7448), Try::Tiny::Catch=REF(0x557f4bad7190)) called at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 117
    Sql::do(Sql=HASH(0x557f4b9b51b0), "INSERT INTO \"musicbrainz\".\"release_group_tag\" (\"count\", \"last"..., 1, "2022-08-26 10:47:21.228028+00", 1014099, 7) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 332
    main::mirrorInsert(Sql=HASH(0x557f4b638630), Sql=HASH(0x557f4b9b51b0), ARRAY(0x557f4b53abc0), 1241579422) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 269
    main::mirrorCommand("i", Sql=HASH(0x557f4b638630), Sql=HASH(0x557f4b9b51b0), ARRAY(0x557f4b53abc0), 1241579422, CODE(0x557f4bad6cf8)) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 178
mwiencek commented 1 year ago

Can you connect to the database with psql (I guess sudo docker-compose exec db psql -U musicbrainz musicbrainz_db) and run some queries and post the output?

SELECT * FROM replication_control;

SELECT * FROM release_group_tag WHERE release_group = 1014099 AND tag = 7;

SELECT * FROM release_group_tag WHERE tag NOT IN (SELECT id FROM tag);

Also, do you happen to have the log from when you ran the release upgrade steps?

JoshDi commented 1 year ago

Unfortunately I am rebuilding my database and indexes as we speak to fix the problem.

JoshDi commented 1 year ago

Okay - I just restored my DB and indexes to the latest fulldump (rebuilt indexes myself). I am still getting errors:

root@HTPC-Xeon:/storage/musicbrainz-docker# docker exec -ti musicbrainz-docker_musicbrainz_1 cat mirror.log
Sat Aug 27 00:21:41 2022 : Downloading https://metabrainz.org/api/musicbrainz/replication-152173.tar.bz2 to /tmp/replication-152173.tar.bz2
Sat Aug 27 00:21:42 2022 : Decompressing /tmp/replication-152173.tar.bz2 to /tmp/loadrep-izdsg1
TIMESTAMP
COPYING
README
REPLICATION_SEQUENCE
SCHEMA_SEQUENCE
mbdump/dbmirror_pending
mbdump/dbmirror_pendingdata
Sat Aug 27 00:21:42 2022 : This packet was produced (or begins) at 2022-08-24 01:46:57.911294+00
Sat Aug 27 00:21:42 2022 : Importing the pending data files
NOTICE:  drop cascades to constraint dbmirror_pendingdata_seqid_fkey on table dbmirror_pendingdata
Sat Aug 27 00:21:42 2022 : starting import
Table                               Rows est%  rows/sec
Sat Aug 27 00:21:42 2022 : load dbmirror_pending
dbmirror_pending                    9427 100%    492605 0.02 sec
Sat Aug 27 00:21:42 2022 : load dbmirror_pendingdata
dbmirror_pendingdata               14139 100%    861766 0.02 sec
Sat Aug 27 00:21:42 2022 : import finished
Loaded 2 tables (23566 rows) in 0 seconds
Sat Aug 27 00:21:42 2022 : Removing /tmp/loadrep-izdsg1
Sat Aug 27 00:21:43 2022 : Processing replication changes
     XIDs     Stmts est%  XIDs/sec  Stmt/sec
        0         0   0%         0         0Use of uninitialized value $params[1] in join or string at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
Use of uninitialized value $params[2] in join or string at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
Use of uninitialized value $params[3] in join or string at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
Use of uninitialized value $params[5] in join or string at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
Use of uninitialized value $params[6] in join or string at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
Use of uninitialized value $params[7] in join or string at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
Failed query:
        'INSERT INTO "musicbrainz"."artist_alias" ("artist", "begin_date_day", "begin_date_month", "begin_date_year", "edits_pending", "end_date_day", "end_date_month", "end_date_year", "ended", "id", "last_updated", "locale", "name", "primary_for_locale", "sort_name", "type") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)'
        (909023    0    f 379008 2022-08-24 00:21:15.889399+00 ru Игорь Давыдович Шаферан f Шаферан, Игорь Давыдович 2)
3F000 DBD::Pg::st execute failed: ERROR:  schema "amqp" does not exist
LINE 1: SELECT amqp.publish(1, 'search', 'index', (
               ^
QUERY:  SELECT amqp.publish(1, 'search', 'index', (
            WITH keys(artist, id, type) AS (SELECT NEW.artist, NEW.id, NEW.type)
            SELECT jsonb_set(jsonb_set(to_jsonb(keys), '{_table}', '"artist_alias"'),
                             '{_operation}', '"insert"')::text FROM keys
        ))
CONTEXT:  PL/pgSQL function search_artist_alias_insert() line 3 at PERFORM [for Statement "INSERT INTO "musicbrainz"."artist_alias" ("artist", "begin_date_day", "begin_date_month", "begin_date_year", "edits_pending", "end_date_day", "end_date_month", "end_date_year", "ended", "id", "last_updated", "locale", "name", "primary_for_locale", "sort_name", "type") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)" with ParamValues: 1='909023', 2=undef, 3=undef, 4=undef, 5='0', 6=undef, 7=undef, 8=undef, 9='f', 10='379008', 11='2022-08-24 00:21:15.889399+00', 12='ru', 13='�.го�.ь �.авыдови�. Ша�.е�.ан', 14='f', 15='Ша�.е�.ан, �.го�.ь �.авыдови�.', 16='2']
 at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
        Sql::catch {...} (MusicBrainz::Server::Exceptions::DatabaseError=HASH(0x55a71ba214b8)) called at /root/perl5/lib/perl5/Try/Tiny.pm line 123
        Try::Tiny::try(CODE(0x55a71b9a8d18), Try::Tiny::Catch=REF(0x55a71b9a9000)) called at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 117
        Sql::do(Sql=HASH(0x55a71b844dd0), "INSERT INTO \"musicbrainz\".\"artist_alias\" (\"artist\", \"begin_da"..., 909023, undef, undef, undef, 0, undef, ...) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 332
        main::mirrorInsert(Sql=HASH(0x55a71b518b78), Sql=HASH(0x55a71b844dd0), ARRAY(0x55a71b41b418), 1239675226) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 269
        main::mirrorCommand("i", Sql=HASH(0x55a71b518b78), Sql=HASH(0x55a71b844dd0), ARRAY(0x55a71b41b418), 1239675226, CODE(0x55a71b9b6db8)) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 178
root@HTPC-Xeon:/storage/musicbrainz-docker# musicbrainz_check 
CORE           STATUS  INDEX     DB
editor         OK      0         /0
instrument     OK      1011      /1011
series         OK      17169     /17169
place          OK      53854     /53854
event          OK      60267     /60267
area           OK      118782    /118782
tag            OK      202473    /202473
label          OK      231206    /231206
cdstub         OK      284004    /284004
annotation     OK      513514    /513514
work           OK      1722291   /1722291
artist         OK      2027735   /2027735
release-group  OK      2628494   /2628494
release        OK      3354542   /3354542
url            OK      9351036   /9351036
recording      OK      27610490  /27610490
root@HTPC-Xeon:/storage/musicbrainz-docker# musicbrainz_mq
+---------------+----------+
|     name      | messages |
+---------------+----------+
| search.delete | 0        |
| search.failed | 0        |
| search.index  | 0        |
| search.retry  | 0        |
+---------------+----------+

also here is the output from the psql db:

root@HTPC-Xeon:/storage/musicbrainz-docker# docker-compose exec db psql -U musicbrainz musicbrainz_db
psql (12.12 (Debian 12.12-1.pgdg110+1))
Type "help" for help.

musicbrainz_db=# SELECT * FROM replication_control;
 id | current_schema_sequence | current_replication_sequence |     last_replication_date     
----+-------------------------+------------------------------+-------------------------------
  1 |                      27 |                       152172 | 2022-08-24 00:20:48.327683+00
(1 row)

musicbrainz_db=# SELECT * FROM release_group_tag WHERE release_group = 1014099 AND tag = 7;
 release_group | tag | count |         last_updated          
---------------+-----+-------+-------------------------------
       1014099 |   7 |     1 | 2021-12-02 12:04:44.873187+00
(1 row)

musicbrainz_db=# SELECT * FROM release_group_tag WHERE tag NOT IN (SELECT id FROM tag);
 release_group | tag | count | last_updated 
---------------+-----+-------+--------------
(0 rows)

musicbrainz_db=#
JoshDi commented 1 year ago

Running the sql file again for 20220720, gives the following error and then i later had to restore my tags db

Sat Aug 27 02:25:33 2022 : Validating snapshot
Sat Aug 27 02:25:33 2022 : Snapshot timestamp is 2022-08-24 00:20:48.327683+00
Sat Aug 27 02:25:33 2022 : This snapshot corresponds to replication sequence #152172
Sat Aug 27 02:25:33 2022 : starting import
Table                               Rows est%  rows/sec
Sat Aug 27 02:25:33 2022 : load tag
tag                               200704  99%    346359Error loading /tmp/mbscript-GwliYZLz/MBImport-FPSSLZvm/mbdump/tag: 3F000 DBD::Pg::db pg_putcopyend failed: ERROR:  schema "amqp" does not exist
LINE 1: SELECT amqp.publish(1, 'search', 'index', (
               ^
QUERY:  SELECT amqp.publish(1, 'search', 'index', (
            WITH keys(id) AS (SELECT NEW.id)
            SELECT jsonb_set(jsonb_set(to_jsonb(keys), '{_table}', '"tag"'),
                             '{_operation}', '"insert"')::text FROM keys
        ))
CONTEXT:  PL/pgSQL function search_tag_insert() line 3 at PERFORM at ./admin/MBImport.pl line 309, <LOAD> line 202473.
rmdir: failed to remove '/tmp/mbscript-GwliYZLz': Directory not empty
root@87a078c87a6b:/musicbrainz-server/admin/sql/updates#
mwiencek commented 1 year ago

This error looks unrelated to the original, at least: schema "amqp" does not exist. Perhaps you have to re-run the AMQP setup after resetting your database? https://github.com/metabrainz/musicbrainz-docker#enable-live-indexing

BTW, if you're restoring your database from a full dump, you shouldn't run the 20220720-mbs-12508.sh script. This was only for people missing tag data after running the schema change upgrade scripts:

Please ignore this release and the rest of these instructions if: [...] you’ve already done a full re-import of your database after the schema change release

JoshDi commented 1 year ago

@mwiencek that's fine. My amqp is connected and setup with triggers properly after the DB restoration.

If you look at this post: https://github.com/metabrainz/musicbrainz-docker/issues/235#issuecomment-1229061147

you can see that MQ is connected, the indexes match the db counts for all tables, but replication still fails with this error:

Failed query:
        'INSERT INTO "musicbrainz"."artist_alias" ("artist", "begin_date_day", "begin_date_month", "begin_date_year", "edits_pending", "end_date_day", "end_date_month", "end_date_year", "ended", "id", "last_updated", "locale", "name", "primary_for_locale", "sort_name", "type") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)'
        (909023    0    f 379008 2022-08-24 00:21:15.889399+00 ru Игорь Давыдович Шаферан f Шаферан, Игорь Давыдович 2)
3F000 DBD::Pg::st execute failed: ERROR:  schema "amqp" does not exist
LINE 1: SELECT amqp.publish(1, 'search', 'index', (
               ^
QUERY:  SELECT amqp.publish(1, 'search', 'index', (
            WITH keys(artist, id, type) AS (SELECT NEW.artist, NEW.id, NEW.type)
            SELECT jsonb_set(jsonb_set(to_jsonb(keys), '{_table}', '"artist_alias"'),
                             '{_operation}', '"insert"')::text FROM keys
        ))
CONTEXT:  PL/pgSQL function search_artist_alias_insert() line 3 at PERFORM [for Statement "INSERT INTO "musicbrainz"."artist_alias" ("artist", "begin_date_day", "begin_date_month", "begin_date_year", "edits_pending", "end_date_day", "end_date_month", "end_date_year", "ended", "id", "last_updated", "locale", "name", "primary_for_locale", "sort_name", "type") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)" with ParamValues: 1='909023', 2=undef, 3=undef, 4=undef, 5='0', 6=undef, 7=undef, 8=undef, 9='f', 10='379008', 11='2022-08-24 00:21:15.889399+00', 12='ru', 13='�.го�.ь �.авыдови�. Ша�.е�.ан', 14='f', 15='Ша�.е�.ан, �.го�.ь �.авыдови�.', 16='2']
 at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 116.
        Sql::catch {...} (MusicBrainz::Server::Exceptions::DatabaseError=HASH(0x55a71ba214b8)) called at /root/perl5/lib/perl5/Try/Tiny.pm line 123
        Try::Tiny::try(CODE(0x55a71b9a8d18), Try::Tiny::Catch=REF(0x55a71b9a9000)) called at /musicbrainz-server/admin/replication/../../lib/Sql.pm line 117
        Sql::do(Sql=HASH(0x55a71b844dd0), "INSERT INTO \"musicbrainz\".\"artist_alias\" (\"artist\", \"begin_da"..., 909023, undef, undef, undef, 0, undef, ...) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 332
        main::mirrorInsert(Sql=HASH(0x55a71b518b78), Sql=HASH(0x55a71b844dd0), ARRAY(0x55a71b41b418), 1239675226) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 269
        main::mirrorCommand("i", Sql=HASH(0x55a71b518b78), Sql=HASH(0x55a71b844dd0), ARRAY(0x55a71b41b418), 1239675226, CODE(0x55a71b9b6db8)) called at /musicbrainz-server/admin/replication/ProcessReplicationChanges line 178
mwiencek commented 1 year ago

I see that, but your amqp schema is still missing. The triggers are there, but they won't work unless the pg_amqp extension is installed. In musicbrainz-docker you can install it with admin/create-amqp-extension -- maybe you ran it previously but it failed with an error.

JoshDi commented 1 year ago 
root@HTPC-Xeon:/storage/musicbrainz-docker# admin/create-amqp-extension
Installing indexer AMQP extension into PostgreSQL ...
BEGIN
CREATE EXTENSION
ALTER SCHEMA
ALTER TABLE
INSERT 0 1
COMMIT
Successfully created amqp extension in the database.

that seems to have fixed the problem oddly enough. Thank you!

JoshDi commented 1 year ago

however, now i got this message:

Sat Aug 27 22:34:09 2022 : Replication changes applied
Sat Aug 27 22:34:09 2022 : Checking that dbmirror_pendingdata is empty
Sat Aug 27 22:34:09 2022 : Optimising dbmirror_pendingdata
Sat Aug 27 22:34:09 2022 : Checking that dbmirror_pending is empty
Sat Aug 27 22:34:09 2022 : Optimising dbmirror_pending
Sat Aug 27 22:34:09 2022 : ProcessReplicationChanges complete
Use of uninitialized value $REPLICATION_SEQUENCE in integer ne (!=) at ./admin/replication/LoadReplicationChanges line 333.
Use of uninitialized value $REPLICATION_SEQUENCE in concatenation (.) or string at ./admin/replication/LoadReplicationChanges line 334.
Applied changes, but current_replication_sequence is 152173 not
JoshDi commented 1 year ago

it looks like its working now and pulling all of the latest replication packets. thank you for the suggestion