WDB end of day merge performance issues in partbyenum mode

[jonathonmcmurray]

It has been reported that when using partbyenum mode in the WDB, the end of day merge can be quite slow. Specifically it seems to be quite slow when we read multiple partitions at once, and much faster if we're only reading one e.g. compare parts 1185+638 (taking ~44 secs) to part 869 (taking ~0.001s) below with similar record counts

2025.02.07D00:01:02.022613000|host|sort|sort1|INF|merge|reading partition/partitions :f:/kdb/wdbhdb/2025.02.06/1185/mt4quote, :f:/kdb/wdbhdb/2025.02.06/638/mt4quote
2025.02.07D00:01:46.351574000|host|sort|sort1|INF|resort|Checking that the contents of this subpartition conform
2025.02.07D00:01:46.351617000|host|sort|sort1|INF|getextraparttype|parted attribute p not found in sort.csv for mt4quote table, using default instead
2025.02.07D00:01:46.399757000|host|sort|sort1|INF|merge|upserting 8566540 rows to :F:/KDB/hdb/2025.02.06/mt4quote/
2025.02.07D00:01:52.031659000|host|sort|sort1|INF|merge|reading partition/partitions :f:/kdb/wdbhdb/2025.02.06/307/mt4quote
2025.02.07D00:01:52.032956000|host|sort|sort1|INF|resort|Checking that the contents of this subpartition conform
2025.02.07D00:01:52.032992000|host|sort|sort1|INF|getextraparttype|parted attribute p not found in sort.csv for mt4quote table, using default instead
2025.02.07D00:01:55.242509000|host|sort|sort1|INF|merge|upserting 4213054 rows to :F:/KDB/hdb/2025.02.06/mt4quote/
2025.02.07D00:02:06.699865000|host|sort|sort1|INF|merge|reading partition/partitions :f:/kdb/wdbhdb/2025.02.06/869/mt4quote
2025.02.07D00:02:06.701207000|host|sort|sort1|INF|resort|Checking that the contents of this subpartition conform
2025.02.07D00:02:06.701237000|host|sort|sort1|INF|getextraparttype|parted attribute p not found in sort.csv for mt4quote table, using default instead
2025.02.07D00:02:12.820915000|host|sort|sort1|INF|merge|upserting 8576974 rows to :F:/KDB/hdb/2025.02.06/mt4quote/
2025.02.07D00:02:31.768208000|host|sort|sort1|INF|merge|reading partition/partitions :f:/kdb/wdbhdb/2025.02.06/1195/mt4quote, :f:/kdb/wdbhdb/2025.02.06/156/mt4quote

Seems like it might be better (in this case, at least) to read every partition separately - we should do some testing of the performance here and potentially rethink our approach to batching in .merge.getpartchunks

[skairulla]

Progress Report - 04/25/2025

1 - Replication of the issue on Homer

• Using a custom feed.q, the issue has been replicated as shown below.

2 - Identifying Root Cause

• Done by adding some logging in .merge.mergebypart to pinpoint which line of q code is responsible for the delay
• The table join in this if statement (if[98<>type chunks; chunks: (,/) chunks] ) is the root cause here, which only happens when multiple partitions are in the chunk

3 - Possible Options/Solutions

• Have multiple table insertions done one at a time (resulted in latency issues of up to 40 seconds when done iteratively, worse than original problem)
• Forcing merge.q to only read in 1 partition at a time when the row count exceeds some chosen threshold (e.g. setting a mergelimit of 1 in .merge.getpartchunks when ever the average row count limit in quotes is above 3 million)

Trying to re-write the script in .merge.mergebypart without the join looks to be a deadend. Don't think the join can be improved here.

If the row count is too high - table join takes so long to do that it results in reading in one partition at a time being faster than reading in multiple partitions.

If the row count is low - table join makes reading multiple partitions faster than reading one partition.

Therefore looks a decision must be made what row count/bytesize must be met before forcing merge.q to read in 1 partition.

Regards,

[jonathonmcmurray]

@skairulla thanks for the analysis. I think you're right that the raze (i.e. (,/)) is what is taking the additional time - without this, the partitions are only mmapped instead of being serialised into memory. I think we actually get a lot of that "additional" time back during the upsert, as if we serialised into memory already by doing the raze, we don't have to do that when we go to write, but we do if we only mmapped. In your examples, can't see how long the upsert is taking but in original example, the first upsert takes about 6s (when we read multiple partitions) and second takes about 11s (with roughly half as many records, but all from one partition).

Can you try and confirm this? i.e. comparing end-to-end time for full EOD merge with mergelimit set to 1 vs set to higher value

[skairulla]

Update - 04/29/2025

1 - Log results when the mergelimit = 1. Partitions are read in one at a time, which links to the case where partitions are only mmapped. Upsert time in this case takes between 7 to 17 seconds.

2025.04.29D01:00:11.204615843|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.28/225/quote
2025.04.29D01:00:11.205367698|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.29D01:00:11.205437600|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.29D01:00:12.885735603|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 3924704 rows to :/home/skairulla/deploy/data/hdb/2025.04.28/quote/

2025.04.29D01:00:22.745870049|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.28/2193/quote
2025.04.29D01:00:22.746171352|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.29D01:00:22.746193357|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.29D01:00:24.552973129|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 5025931 rows to :/home/skairulla/deploy/data/hdb/2025.04.28/quote/

2025.04.29D01:00:38.223861746|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.28/2088/quote
2025.04.29D01:00:38.224164414|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.29D01:00:38.224200200|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.29D01:00:40.401342879|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 4398528 rows to :/home/skairulla/deploy/data/hdb/2025.04.28/quote/

2025.04.29D01:00:47.486085307|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.28/2281/quote
2025.04.29D01:00:47.486396171|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.29D01:00:47.486417723|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.29D01:00:48.013791388|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 3803316 rows to :/home/skairulla/deploy/data/hdb/2025.04.28/quote/

2025.04.29D01:01:15.387597630|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.28/2208/quote

2 - Log results when merge limit is set to a higher limit (mergelimit = 9,000,000 to replicate client issue), partitions are serialized into memory. Upsert time is less than 1 second.

2025.04.20D01:28:58.094957816|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.19/2017/quote, :/home/skairulla/deploy/data/wdbhdb/2025.04.19/1796/quote
2025.04.20D01:29:18.675336928|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.20D01:29:18.675452091|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.20D01:29:18.733889333|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 7368191 rows to :/home/skairulla/deploy/data/hdb/2025.04.19/quote/

2025.04.20D01:29:19.154755450|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.19/2018/quote, :/home/skairulla/deploy/data/wdbhdb/2025.04.19/2019/quote, :/home/skairulla/deploy/data/wdbhdb/2025.04.19/886/quote
2025.04.20D01:29:49.462363733|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.20D01:29:49.462488074|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.20D01:29:49.552699697|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 8584938 rows to :/home/skairulla/deploy/data/hdb/2025.04.19/quote/

2025.04.20D01:29:50.005938432|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.19/2020/quote, :/home/skairulla/deploy/data/wdbhdb/2025.04.19/2021/quote
2025.04.20D01:30:07.120404302|homer.aquaq.co.uk|sortworker|sortworker2|INF|resort|Checking that the contents of this subpartition conform
2025.04.20D01:30:07.120511385|homer.aquaq.co.uk|sortworker|sortworker2|INF|getextraparttype|parted attribute p not found in sort.csv for quote table, using default instead
2025.04.20D01:30:07.198851141|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|upserting 5962485 rows to :/home/skairulla/deploy/data/hdb/2025.04.19/quote/

2025.04.20D01:30:07.530609304|homer.aquaq.co.uk|sortworker|sortworker2|INF|merge|reading partition/partitions :/home/skairulla/deploy/data/wdbhdb/2025.04.19/2022/quote

So your suspicions are confirmed.

Regards,

[jonathonmcmurray]

So end-to-end time in first case is 00:01:04 and in second is 00:01:09. i.e. even when the read appears to be "slower", the whole process overall is actually pretty similar. So I think we have no issue here, it's already possible to configure mergelimit to 1 and force mmapping that way if users want this.

@swfrazer are you happy if we close this issue?

[jonathonmcmurray]

Confirmed we are good to close this