pgloader is hanging without outputing any errors or loading new data

[machytkafitanalytics]

Hi,

I am sorry but I have another problem to discuss regarding latest build of pgloader (pgloader version "3.4.572f6a3" compiled with SBCL 1.4.3.236-cfa129e). We had already second case (both on different GCE instances) of pgloader not finishing the task and hanging indefinitely.

In both cases it stopped in the middle of loading data into some table (different in both cases) so some tables have been loaded but others remained empty. I was not able to investigate first case, only second one.

• top:

   VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
5340784 166200   2592 S   0.0  0.3  62:37.44 /ourpath/pgloader -v /ourpath/cf

process is sleeping

• strace: futex(0x100b57ebc0, FUTEX_WAIT_PRIVATE, 7210419, NULL without further changes

• iotop: no disk activity

• mysql - no active connection

• postgresql - no active connection

• ltrace shows never ending sequence like this:

__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
<... __errno_location resumed> )                 = 0xee3cf688
<... __errno_location resumed> )                 = 0xee81f688
<... __errno_location resumed> )                 = 0xeec6f688
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
<... __errno_location resumed> )                 = 0xef0bf688
syscall(202, 0x507d490, 128, 0x890f643 <unfinished ...>
syscall(202, 0x507d490, 128, 0x890f163 <unfinished ...>
syscall(202, 0x507d490, 128, 0x890ec83 <unfinished ...>
<... __errno_location resumed> )                 = 0xef50f688
<... __errno_location resumed> )                 = 0xef95f688
__errno_location( <unfinished ...>
<... __errno_location resumed> )                 = 0xf443f688
<... __errno_location resumed> )                 = 0xf488f688
syscall(202, 0x507d490, 128, 0x890e7a3 <unfinished ...>
syscall(202, 0x507d490, 128, 0x890e2c3 <unfinished ...>
syscall(202, 0x507d490, 128, 0x890dde3 <unfinished ...>
<... __errno_location resumed> )                 = 0xefdaf688
syscall(202, 0x507d490, 128, 0x890d423 <unfinished ...>
syscall(202, 0x507d490, 128, 0x890cf43 <unfinished ...>
<... syscall resumed> )                          = 0xffffffff
<... syscall resumed> )                          = 0xffffffff
<... syscall resumed> )                          = 0xffffffff
syscall(202, 0x507d490, 128, 0x890d903 <unfinished ...>
__errno_location( <unfinished ...>
<... syscall resumed> )                          = 0xffffffff
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
<... syscall resumed> )                          = 0xffffffff
<... syscall resumed> )                          = 0xffffffff
<... __errno_location resumed> )                 = 0xee3cf688
<... syscall resumed> )                          = 0xffffffff
<... syscall resumed> )                          = 0xffffffff
__errno_location( <unfinished ...>
<... __errno_location resumed> )                 = 0xee81f688
<... __errno_location resumed> )                 = 0xeec6f688
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
syscall(202, 0x507d490, 128, 0x890f643 <unfinished ...>
__errno_location( <unfinished ...>
__errno_location( <unfinished ...>
<... __errno_location resumed> )                 = 0xef0bf688
syscall(202, 0x507d490, 128, 0x890f163 <unfinished ...>
syscall(202, 0x507d490, 128, 0x890ec83 <unfinished ...>
<... __errno_location resumed> )                 = 0xef50f688
<... __errno_location resumed> )                 = 0xef95f688
<... syscall resumed> )                          = 0xffffffff
<... __errno_location resumed> )                 = 0xf443f688
<... __errno_location resumed> )                 = 0xf488f688

shall I try some other check?

[dimitri]

What would be helpful is sending me a dataset that allows reproducing the error locally, or issue some kind of (commercial) contract that allows me to access a (virtual/cloud) machine where I can run some tests and debug the situation. See also the https://pgloader.io/moral-licence/ which often is the easiest way around for sharing the data under some kind of a contract.

[machytkafitanalytics]

Yes, I was thinking about it but 1) due our policies it is really impossible to give any "outsider" (sorry) access to our systems and 2) it happens only when pgloader is started as cron job. I never faced this problems during manual tests. But I can add more parameters to the cron job and send you logs.

[dimitri]

Logs appreciated, tell me when you have some.

Otherwise the Moral License means there's a payment in between moral entities and establishes a default Contract of sorts (in places I know of), making me like a subcontractor rather than an outsider. It's usually good enough in terms of lawful expectations. Also it helps me spend more time on Enterprise Support of your specific use case and environment...

[machytkafitanalytics]

Yes, I completely understand but I am not "Lord of the Money" around here - I will propose to buy moral licence and we will see...

[machytkafitanalytics]

I have caught first error with debug setting in cron job but it is most probably different problem because pgloader this time crashed:

2018-01-22T11:32:10.236000Z DATA < #("23575" "66149042" "LOCAL_SIZE" "24x34" "2017-07-28 11:01:51")
Heap exhausted during garbage collection: 48 bytes available, 80 requested.
 Gen  StaPg UbSta LaSta Boxed Unbox    LB   LUB !move    Alloc  Waste     Trig   WP GCs Mem-age
fatal error encountered in SBCL pid 22992(tid 0x7ffff4cdf700):
GC invariant lost, file "gencgc.c", line 495

Error opening /dev/tty: No such device or address
Welcome to LDB, a low-level debugger for the Lisp runtime environment.
ldb> 

[machytkafitanalytics]

Hmmm, looks like "debug" always ends with similar error - this is from manual run with -d option

2018-01-22T12:30:40.527000Z DATA > "1447026     127423  \\N     DE      de      de      normal  \\N  40       \\N     2015-12-17 16:12:59
"
Heap exhausted during garbage collection: 16 bytes available, 48 requested.
 Gen  StaPg UbSta LaSta Boxed Unbox    LB   LUB !move    Alloc  Waste     Trig   WP GCs Mem-age
fatal error encountered in SBCL pid 29644(tid 0x7ffff557f700):
GC invariant lost, file "gencgc.c", line 495

Welcome to LDB, a low-level debugger for the Lisp runtime environment.
ldb> 

can I somehow adjust settings to avoid this error?

[dimitri]

Heap Exhausted happens when there's no memory around anymore, it's a failure of the Garbage Collector of SBCL in our case here. You can see the documentation about WITH common clauses at http://pgloader.readthedocs.io/en/latest/pgloader.html#common-clauses and play with the batch size and concurrency parameters to lower memory pressure.

In particular, see prefetch rows, workers, concurrency, and batch-size.

[vgallardov]

I had the same problem.
Try recompiling with DYNSIZE=8192.

[machytkafitanalytics]

I tested different settings but generally all works well with default pgloader settings - plus already existing settings of work_mem and maintenance mem in database. I tried to fiddle with all it in command file in hope to boost pgloader performance but I got only negative effects and crushes.... Anyway latest pgloader performs very good. So I close this issue too.

[dimitri]

The series of patches that ended up yesterday evening should be a net win in terms of memory usage and maybe even performances. I you can compare between versions of pgloader, please try a fresh git copy and report what you see. It might even be enough to avoid the Heap Exhausted error as we don't keep any batch in memory any more...

So @machytkafitanalytics ; can I ask which version you're using now with the good characteristics?

[machytkafitanalytics]

Oh yes, I am sorry, my comment about version was unclear - I still run pgloader version "3.4.572f6a3" compiled with SBCL 1.4.3.236-cfa129e on all instances. I just fiddled with settings in command files. But I will try really latest version ASAP....

[dimitri]

I expect you will find that a603cd8 and following are some kind of an improvement, and I'm curious to see to which degree! Keep me posted!

[machytkafitanalytics]

+1
I did tests with pgloader version "3.4.5ecd03c" compiled with SBCL 1.4.3.315-2b33255 and it really seems to be more stable and quicker. I still get the best balance of speed and resource usage with default settings (for parallelism etc). Many thanks.