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).
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 inpgloader
that overwrites the password in mem or a bug in CCL that somehow causes an overflow that spilled into the password in this case.