GOLDENGATE EXTRACT (11.2.1.0.7 - 11.2.1.0.12) IS SLOW WRITING TO TRAIL FILE, TOO MANY FSYNC CALLS (Doc ID 1589437.1)

Last updated on MARCH 26, 2019

Applies to:

Symptoms

There is an extract performance problem after upgrade from 11.2.1.0.6.


1. The performance is good again with TESTMAPPINGSPEED. It indicates that the problem might be at writing to trail.

2. From trace2 it can be seen that, there is 50 ms delay:

e.g.,

in case of 11.2.1.0.9
20:35:41.718 (144961) fetching row for table <SCHEMA>.<TABLE>
20:35:41.718 (144961) Nothing to bind and fetch from database
20:35:41.764 (145007) * --- entering READ_EXTRACT_RECORD --- *
20:35:41.764 (145007) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=0)

while in 11.2.1.0.6 there is no delay before entering reading the record :
20:40:50.289 (120973) fetching row for table <SCHEMA>.<TABLE>
20:40:50.289 (120973) Nothing to bind and fetch from database
20:40:50.289 (120973) * --- entering READ_EXTRACT_RECORD --- *
20:40:50.289 (120973) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=0)

3. from strace/truss trace file, there are many 'fsync' calls

In 11.2.1.0.10, after ~10000 records written to trail the number of fsync calls:
$ grep fsync sb_e.trc.66* | wc
2578 10312 113544

In 11.2.1.0.6, after 100000 records written to trail:
$ grep fsync in_e.trc.67* | wc
13 52 614

4. from pstack output, we see _fdsync often

ffffffff7acdb318 __fdsync (14, 0, ffffffff7e000200, 10133c68c, ffffffff7e000200, 0) + 8
0000000100358f60 __1cIgg_fsync6Fi_i_ (14, 70000, 1839ac, fffffffffff0bdc0, 10133c688, 0) + 4
0000000100132048 __1cOext_file_flush6FpnLextract_def_i_v_ (1030d4018, 1, 0, 0, 1030d4018, 0) + 24
000000010013597c __1cNflush_buffers6Fi_v_ (1, 100c38, 101800, 1, ffffffff, 1) + 70
00000001001f49e4 __1cRcheckpoint_status6Fhh_b_ (41, 1, 100c4c770, 100c37, 100c38000, df) + a0
00000001001b1388 __1cOcheck_messages6FpnPchkpt_context_t_hpkcb_h_ (101f63550, 0, 100a10763, 1, 100c38000, 64) + 1a0
00000001001e6a14 __1cUprocess_extract_loop6F_h_ (100c52, 100a10763, 100c00, 101940490, 101941918, 100c375c8) + 2fc
00000001002095a0 main (100c00, 100c37000, 101f69d82, 100c4db20, 0, 100c37) + 770
00000001000dbf3c _start (0, 0, 0, 0, 0, 0) + 17c

Cause

My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.