[Bucardo-general] NUMLOG / BUCARDO - Only half of insert are done in database

Support EDI support.edi at numlog.fr
Thu Nov 24 10:51:20 UTC 2022 

Dear Bucardo team,

Few weeks ago I started working on building a postgresql cluster (in 
master / master mode) composed of 3 VM with Debian 11 installed.

  * 1 server is running an HA proxy server (version 2.2.9). It is used
    to provide load balancing features
  * 2 Postgresql server (version 13.8) and Bucardo (version 5.6.0).
    Bucardo is used here to provide high availability with a master /
    master mode.

I have tested inserting data in each database server locally and every 
data is available on each server. So the master / master looks working fine.
Then I have tried to insert data from a distant server through the HA 
Proxy server and I have noticed that only the half of the insert are 
available in postgresql.

I have analyzed logs of the 3 softwares to find where something goes 
wrong and think it comes from bucardo.
In this case I tried to insert 4 rows in a table named "files". In 
postgresql only 2 entries are available. The 2 entries are the same on 
both postgresql server.

  * First I checked HA proxy logs and find that it was well redirecting
    50% of insert on server 1 and 50% on server 2. No error in its logs
    so I presume that it really works fine.
  * Then I checked Postgresql log. In Postgresql logs I cannot see any
    error and I can't see any attempt to insert the missing values. I
    have changed log level to ensure I'm not missing something but
    without success.
  * At last I have checked in Bucardo and find below logs :

    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Got NOTICE
    run_sync_oneToTwo from 292748 (Bucardo DB) (line 3113)
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Adding entry
    to syncrun table
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Populating
    the dbrun table
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Adding note
    to the syncrun table
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Doing final
    maindbh commit
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Set database
    "serv1" to repeatable read read write
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Set database
    "serv2" to repeatable read read write
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Checking
    truncate_trigger table on database "serv1"
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Sequence
    public.files_code_seq from db serv1 is the highest
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Tables with
    deltas on serv1: 1 Without: 0
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Delta count
    for serv1.public.files : 2
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Total delta
    count: 2
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Setting
    session_replication_role to replica for database serv2
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Rows to push
    from serv1.public.files: 2
    *(292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Deleting
    from target serv2.public.files (round 1 of 1)**
    **(292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Rows
    deleted from serv2.public.files: 2*
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Copying from
    serv1.public.files
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Rows copied
    to (postgres) serv2.public.files: 2
    *(292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Totals:
    deletes=2 inserts=2 conflicts=0*
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Rows
    inserted to bucardo_track for serv1.public.files : 2
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Setting
    session_replication_role to default for database serv2
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Issuing
    final commit for all databases
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) All
    databases committed
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Total time
    for sync "sync_oneToTwo" (2 rows, 1 table): 0.05 secondes
    (292750) [Mon Nov 21 10:46:30 2022] KID (sync_oneToTwo) Sending
    NOTIFY "ctl_syncdone_sync_oneToTwo" (line 4937) skip_commit=0

    I'm not sure I correctly understand bucardo logs as I'm not
    experimented using it, but it looks like it deletes 2 raws  in a
    server 2 and has pushed 2 raws from server 1.

My first question is, is my analysis correct or am I wrong?
My second question if I'm right is how should I set up Bucardo to avoid 
this issue. I'm sure I'm doing something wrong but I can't find what's 
wrong.
My second question if I'm wrong, do you have any idea of the cause of 
the issue?

On server1, my bucardo set up is :

-- dbgroups:
dbgroup: sync_oneToTwo  Members: serv1:source serv2:target
-- databases:
Database: serv1  Status: active  Conn: psql -p 5432 -U bucardo -d 
hubmaster -h ***.**.**.24
Database: serv2  Status: active  Conn: psql -p 5432 -U bucardo -d 
hubmaster -h ***.**.**.25
-- relgroup:
Relgroup: one_two  DB: serv1  Members: public.files, public.files_code_seq
   Used in syncs: sync_oneToTwo
-- syncs:
Sync "sync_oneToTwo"  Relgroup "one_two"  DB group "sync_oneToTwo" 
serv1:source serv2:target  [Active]
-- tables:
2. Table: public.files  DB: serv2  PK: code (integer)
1. Table: public.files  DB: serv1  PK: code (integer)
-- sequences:
Sequence: public.files_code_seq  DB: serv1
Sequence: public.files_code_seq  DB: serv2

On server1, my bucardo set up is :

-- dbgroups:
dbgroup: sync_oneToTwo  Members: serv1:source serv2:target
-- databases:
Database: serv1  Status: active  Conn: psql -U bucardo -d hubmaster -h 
***.**.**.25
Database: serv2  Status: active  Conn: psql -U bucardo -d hubmaster -h 
***.**.**.24
-- relgroup:
Relgroup: one_two  DB: serv1  Members: public.files, public.files_code_seq
   Used in syncs: sync_oneToTwo
-- syncs:
Sync "sync_oneToTwo"  Relgroup "one_two"  DB group "sync_oneToTwo" 
serv1:source serv2:target  [Active]
-- tables:
1. Table: public.files  DB: serv1  PK: code (integer)
2. Table: public.files  DB: serv2  PK: code (integer)
-- sequences:
Sequence: public.files_code_seq  DB: serv1
Sequence: public.files_code_seq  DB: serv2

Thanks in advance for any help provided.

Best regards
-- 



*Quentin BIENFAIT *
Equipe EDI / EDI Team 	

*_Mail :_ support.edi at numlog.fr <mailto:support.edi at numlog.fr> *
*_Tél :_  +33 1 30 79 16 16 (choix 2) <tel:+33130791616> *

9 ter route de Saint Germain
78640 Villiers Saint Frédéric - France

linkedin numlog <https://www.linkedin.com/company/numlog/> 	linkedin 
<https://www.linkedin.com/company/numlog/> 	formulaire newsletter numlog 
<https://cce6ca04.sibforms.com/serve/MUIEAA5rng8bgYTlAybtSwmIjNm02i1D75jtRGGJKYmaDWA0p1F7pFksNkRD2XGHdmuAWCVoAkNLyYLSK0dJAV2FbkodU2DNptDAf4ITyjy4qK2nteGxkYQkUOM1dB65fTbAvmk7mAQkokRC02MAYzFPkVWDN_cbdU5dcNeHwpkaa2PAVFkeiSe8OQ05-QMsu4CUpRzSswD6zk_z> 
	newsletter 
<https://cce6ca04.sibforms.com/serve/MUIEAA5rng8bgYTlAybtSwmIjNm02i1D75jtRGGJKYmaDWA0p1F7pFksNkRD2XGHdmuAWCVoAkNLyYLSK0dJAV2FbkodU2DNptDAf4ITyjy4qK2nteGxkYQkUOM1dB65fTbAvmk7mAQkokRC02MAYzFPkVWDN_cbdU5dcNeHwpkaa2PAVFkeiSe8OQ05-QMsu4CUpRzSswD6zk_z> 
	site web numlog <https://www.numlog.fr> 	numlog.fr <https://www.numlog.fr>


Ce message électronique contient des informations confidentielles, 
couvertes par le secret professionnel ou réservées exclusivement à leur 
destinataire. Toute lecture, utilisation, diffusion ou divulgation sans 
autorisation expresse est strictement interdite.
Si vous n'en êtes pas le destinataire, merci de prendre contact avec 
l'expéditeur et de détruire ce message.
This message is for the designated recipient only and may contain 
privileged, proprietary, or otherwise private information. If you have 
received it in error, please notify the sender immediately and delete 
the original. Any other use of the email by you is prohibited.
Avant d'imprimer, pensez à l'environnement - Before printing, think 
about the environment
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://bucardo.org/pipermail/bucardo-general/attachments/20221124/1ec35a18/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: FgykEMgChmpTzd1v.png
Type: image/png
Size: 280656 bytes
Desc: not available
URL: <https://bucardo.org/pipermail/bucardo-general/attachments/20221124/1ec35a18/attachment-0005.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: rsybwA0MES4mYgTx.png
Type: image/png
Size: 6472 bytes
Desc: not available
URL: <https://bucardo.org/pipermail/bucardo-general/attachments/20221124/1ec35a18/attachment-0006.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 8GBlj7Itkc65hNcD.png
Type: image/png
Size: 16561 bytes
Desc: not available
URL: <https://bucardo.org/pipermail/bucardo-general/attachments/20221124/1ec35a18/attachment-0007.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: i0hi2RQF4Zrm3t0P.png
Type: image/png
Size: 16561 bytes
Desc: not available
URL: <https://bucardo.org/pipermail/bucardo-general/attachments/20221124/1ec35a18/attachment-0008.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: Bsyu0vap0xCcMQPM.png
Type: image/png
Size: 16561 bytes
Desc: not available
URL: <https://bucardo.org/pipermail/bucardo-general/attachments/20221124/1ec35a18/attachment-0009.png>

More information about the Bucardo-general mailing list