0

I'm trying to load data from MariaDB into PostgreSQL using pgloader. The dataset is fairly large with several tables containing 10s of millions of rows and the full database ending up with around 180GB in PostgreSQL.
This import has worked several times before, but the last two times I had an authentication-error after the import has been running for about four hours. It also has imported 10s of millions of rows at that point.

My first suspicion was that PostgreSQL requires a re-auth after four hours, but I was not able to find any indication that this is actually the case.

Here is what pgloader spits out:

2023-11-15T11:13:01.690988Z ERROR A thread failed with error: Failed to connect to pgsql at "10.1.128.9" (port 5432) as user "<username>": Database error 28P01: password authentication failed for user "<username>"
2023-11-15T11:13:01.695722Z ERROR Date/time: 2023-11-15-11:13!
An unhandled error condition has been signalled: Failed to connect to pgsql at "<pg-ip>" (port 5432) as user "<username>": Database error 28P01: password authentication failed for user "<username>"

 (7F77B2CB06D8) : 0 (PRINT-CALL-HISTORY :CONTEXT NIL :PROCESS NIL :ORIGIN NIL :DETAILED-P NIL :COUNT 1152921504606846975 :START-FRAME-NUMBER 0 :STREAM #<STRING-OUTPUT-STREAM  #x302024305A9D> :PRINT-LEVEL 2 :PRINT-LENGTH 5 :PRINT-STRING-LENGTH :DEFAULT :SHOW-INTERNAL-FRAMES NIL :FORMAT :TRADITIONAL) 965
 (7F77B2CB0870) : 1 (PRINT-BACKTRACE-TO-STREAM #<STRING-OUTPUT-STREAM  #x302024305A9D>) 85
 (7F77B2CB08A0) : 2 (PRINT-BACKTRACE #<PGLOADER.CONNECTION:DB-CONNECTION-ERROR #x302024305C2D> :OUTPUT NIL :IF-EXISTS :APPEND :VERBOSE NIL) 845
 (7F77B2CB0928) : 3 (FUNCALL #'#<(:INTERNAL (PGLOADER.LOAD:COPY-FROM (PGLOADER.SOURCES:COPY)))> #<PGLOADER.CONNECTION:DB-CONNECTION-ERROR #x302024305C2D>) 197
 (7F77B2CB0950) : 4 (CONDITION-HANDLER #<PGLOADER.CONNECTION:DB-CONNECTION-ERROR #x302024305C2D>) 533
 (7F77B2CB09C0) : 5 (SIGNAL #<PGLOADER.CONNECTION:DB-CONNECTION-ERROR #x302024305C2D>) 1037
 (7F77B2CB0A10) : 6 (%ERROR #<PGLOADER.CONNECTION:DB-CONNECTION-ERROR #x302024305C2D> (:MESG "Database error 28P01: password authentication failed for user \"<username>\"" :TYPE "pgsql" :HOST ...) 17519009685831) 117
 (7F77B2CB0A38) : 7 (COPY-ROWS-FROM-QUEUE #<PGLOADER.SOURCE.MYSQL:COPY-MYSQL #x3020029463DD> #S(LPARALLEL.VECTOR-QUEUE:VECTOR-QUEUE :IMPL #S(LPARALLEL.VECTOR-QUEUE::RAW-QUEUE :DATA # :START 22167 ...) :LOCK #<RECURSIVE-LOCK "Anonymous lock" [ptr @ #x7F782C0379C0] #x302002946F5D> ...) :DISABLE-TRIGGERS T :ON-ERROR-STOP NIL :COLUMNS ("id" "cola" "colb" "colc" "cold" ...)) 1589
 (7F77B2CB0AB0) : 8 (FUNCALL #'#<(:INTERNAL #:BODY-FN125094 LPARALLEL.KERNEL::MAKE-CHANNELED-TASK)>) 245
 (7F77B2CB0B18) : 9 (FUNCALL #'#<(:INTERNAL LPARALLEL.KERNEL::MAKE-CHANNELED-TASK)>) 125
 (7F77B2CB0B68) : 10 (EXEC-TASK/WORKER (#<COMPILED-LEXICAL-CLOSURE # #x302002946C2F> . :DEFAULT) #S(LPARALLEL.KERNEL::WORKER :HANDSHAKE/FROM-WORKER #S(LPARALLEL.CONS-QUEUE:CONS-QUEUE :IMPL # :LOCK #<# # [ptr @ #x7F782C036400] #x3020020BE9AD> ...) :HANDSHAKE/TO-WORKER #S(LPARALLEL.CONS-QUEUE:CONS-QUEUE :IMPL # :LOCK #<# # [ptr @ #x7F782C0364C0] #x3020020BE8DD> ...) ...)) 205
 (7F77B2CB0BD0) : 11 (WORKER-LOOP #<KERNEL :NAME "lparallel" :WORKER-COUNT 32 :USE-CALLER NIL :ALIVE T #x30200209A9FD> #S(LPARALLEL.KERNEL::WORKER :HANDSHAKE/FROM-WORKER #S(LPARALLEL.CONS-QUEUE:CONS-QUEUE :IMPL # :LOCK #<# # [ptr @ #x7F782C036400] #x3020020BE9AD> ...) :HANDSHAKE/TO-WORKER #S(LPARALLEL.CONS-QUEUE:CONS-QUEUE :IMPL # :LOCK #<# # [ptr @ #x7F782C0364C0] #x3020020BE8DD> ...) ...)) 237
 (7F77B2CB0C38) : 12 (%CALL-WITH-TASK-HANDLER #<COMPILED-LEXICAL-CLOSURE (:INTERNAL LPARALLEL.KERNEL::ENTER-WORKER-LOOP) #x3020020C42CF>) 789
 (7F77B2CB0CE0) : 13 (FUNCALL #'#<(:INTERNAL LPARALLEL.KERNEL::CALL-WITH-WORKER-CONTEXT)>) 917
 (7F77B2CB0D50) : 14 (FUNCALL #<COMPILED-LEXICAL-CLOSURE (:INTERNAL LPARALLEL.KERNEL::CALL-WITH-WORKER-CONTEXT) #x3020020C421F>) 149
 (7F77B2CB0D80) : 15 (CALL-WITH-WORKER-CONTEXT #<COMPILED-LEXICAL-CLOSURE (:INTERNAL LPARALLEL.KERNEL::ENTER-WORKER-LOOP) #x3020020C42CF> #<Compiled-function FUNCALL #x30000007ECDF> #<KERNEL :NAME "lparallel" :WORKER-COUNT 32 :USE-CALLER NIL :ALIVE T #x30200209A9FD> #S(LPARALLEL.KERNEL::WORKER :HANDSHAKE/FROM-WORKER #S(LPARALLEL.CONS-QUEUE:CONS-QUEUE :IMPL # :LOCK #<# # [ptr @ #x7F782C036400] #x3020020BE9AD> ...) :HANDSHAKE/TO-WORKER #S(LPARALLEL.CONS-QUEUE:CONS-QUEUE :IMPL # :LOCK #<# # [ptr @ #x7F782C0364C0] #x3020020BE8DD> ...) ...)) 341
 (7F77B2CB0DE8) : 16 (FUNCALL #'#<(:INTERNAL LPARALLEL.KERNEL::MAKE-WORKER-THREAD)>) 157
 (7F77B2CB0E40) : 17 (FUNCALL #'#<(:INTERNAL BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS)>) 845
 (7F77B2CB0E68) : 18 (RUN-PROCESS-INITIAL-FORM #<PROCESS lparallel(36) [Active] #x3020020BE17D> (#<COMPILED-LEXICAL-CLOSURE # #x3020020BDF0F>)) 717
 (7F77B2CB0EF0) : 19 (FUNCALL #'#<(:INTERNAL (CCL::%PROCESS-PRESET-INTERNAL (PROCESS)))> #<PROCESS lparallel(36) [Active] #x3020020BE17D> (#<COMPILED-LEXICAL-CLOSURE # #x3020020BDF0F>)) 581
 (7F77B2CB0F98) : 20 (FUNCALL #'#<(:INTERNAL CCL::THREAD-MAKE-STARTUP-FUNCTION)>) 277
KABOOM!
DB-CONNECTION-ERROR: Failed to connect to pgsql at "<pg-ip>" (port 5432) as user "<username>": Database error 28P01: password authentication failed for user "<username>"
An unhandled error condition has been signalled: Failed to connect to pgsql at "<pg-ip>" (port 5432) as user "<username>": Database error 28P01: password authentication failed for user "<username>"

What I am doing here?

Failed to connect to pgsql at "<pg-ip>" (port 5432) as user "<username>": Database error 28P01: password authentication failed for user "<username>"

This is what I get from the server:

2023-11-15 11:13:02.116 UTC [202875] ***@*** FATAL:  password authentication failed for user "<username>"
2023-11-15 11:13:02.116 UTC [202875] ***@*** DETAIL:  Connection matched file "/data/postgresql/16/main/pg_hba.conf" line 100: "host    <username> <db> <ip>     scram-sha-256"
2023-11-15 11:13:02.254 UTC [201876] ***@*** WARNING:  there is no transaction in progress
2023-11-15 11:13:02.727 UTC [201793] ***@*** LOG:  incomplete message from client
2023-11-15 11:13:02.727 UTC [201793] ***@*** CONTEXT:  COPY scan_sitemap, line 327
2023-11-15 11:13:02.727 UTC [201793] ***@*** STATEMENT:
        copy public.some_table (id,col1,col2,col3) FROM STDIN
2023-11-15 11:13:02.732 UTC [201793] ***@*** ERROR:  unexpected EOF on client connection with an open transaction
2023-11-15 11:13:02.732 UTC [201793] ***@*** CONTEXT:  COPY some_table, line 327
2023-11-15 11:13:02.732 UTC [201793] ***@*** STATEMENT:
        copy public.some_table (id,col1,col2,col3) FROM STDIN
2023-11-15 11:13:02.733 UTC [201793] ***@*** FATAL:  terminating connection because protocol synchronization was lost
2023-11-15 11:13:02.733 UTC [201793] ***@*** LOG:  could not send data to client: Broken pipe

And finally, this is my gploader file:

LOAD DATABASE
     FROM mysql://...
     INTO postgresql://...

excluding table names matching ~<random_table>

WITH truncate, data only, disable triggers, preserve index names, include no drop, prefetch rows = 100000, on error resume next, reset sequences, concurrency = 8, workers = 32

CAST type int with extra auto_increment to integer

ALTER SCHEMA '<mysql-schema>' RENAME TO 'public'
;

As I wrote, this has worked multiple times before and it is clearly not an issue with credentials, as it runs for hours importing rows before finally failing.
Also, both databases have no other clients connecting to them, their sole purpose is to test this migration. The credentials work fine and I can use them to log in directly after the import fails.

I'm at a loss why it stopped working now. I'm looking for any idea what or how to investigate here, as I'm completely out of ideas.
I gave it a third shot but if it fails again, I will try to set the client to trust in pg_hba.conf for the import as a workaround. And I would obviously be glad for any other ideas for possible workarounds.

Edit 1:
I enabled connection-logging (as suggested by jjanes) and it seems like pgloader starts new connections for each table instead of reusing old ones, which explains why it fails randomly.
Also, the workaround setting the connection to trust in pg_hba.conf worked (at least once).

5
  • Why would it be establishing new connections several hours into a load? That doesn't seem sensible to me, but I'm not a big pgloader user. Is the same PostgreSQL user supposed to be use for the entire load, or does it need to change users part way through? What was in the log file immediately prior to the first line you show? I'd turn on log_connections and log_disconnections in case those reveal something useful.
    – jjanes
    Nov 15 at 14:41
  • I don't see why it would do that either. The same user is used for the whole load. The logs prior are only checkpoints and in case of pgloader, there is no log for hours. Thanks for the hint with logging connections. I'm definitely going to do that.
    – toydarian
    Nov 16 at 7:12
  • It seems it doesn't reuse connections, but opens new connections for each table.
    – toydarian
    Nov 16 at 12:00
  • The error message in the server log looks just like it would look if the password were wrong. I think that any other plausible authentication problem should have led to a difference in the message (in the DETAIL fields). How was the password supplied? Maybe it somehow got corrupted in memory in the pgloader process, and so when it went to use it it actually was no longer correct.
    – jjanes
    Nov 17 at 1:01
  • The password is supplied in the connection-string in the INTO clause. My first suspicion was cosmic rays flipping a bit, as well ;) but three times in a row doesn't seem probable. That leaves a bug in pgloader that overwrites the password in mem or a bug in CCL that somehow causes an overflow that spilled into the password in this case.
    – toydarian
    Nov 17 at 6:26

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Browse other questions tagged or ask your own question.