Investigate performance issues

I debugged this ELT (a log file with 13+ GB of content), and there are no traces of redundancy, every record appears only once.

The target-postgres batch_processing_time is an average of 20 s to each batch, and it sums to ~6 minutes of total COPY operation time, which is acceptable.

The tap-postgres average extraction time interval between records is ~0.001 s, what leads (roughly) to a total of 90 minutes of data reading.

If anyone has ideas, evidence (or even better, a flame graph 😉) as to what's causing this performance problem, they're more than welcome!

Links

@edgarrmondragon

Hi @edgarrmondragon , I've just started looking into this, since I noticed that this variant of tap-postgres is (on my data streams) about 5x slower than the transferwise variant. Unfortunately, I couldn't get viztracer (from the docs) to work when this tap was being run as part of an E+L pipeline via meltano, e.g. viztracer meltano run this-tap some-target. Just double-checking: Would you expect that sort of call to work?

Since so much of this tap's functionality is implemented in the sdk, I started spelunking through code over there. I got as far as def _sync_records() here before stopping -- I can see things that could be slow, but hard to say without a proper tool like viztracer. I'm happy to keep investigating, but could use an assist in actually getting these profiling tools working with my setup. 🙏

@bdewilde

Hey @bdewilde, thanks for taking the time to dive into the performance problem 🙏

The way I'd approach this is by running this tap in isolation. That is, clone the repo locally and use viztracer like this:

uv run viztracer tap-postgres --config ENV  # assuming you have a .env file with your Postgres instance settings

I should also mention https://github.com/benfred/py-spy, which we've used in the past to profile Meltano (see meltano/meltano#8342) and some connectors.

@edgarrmondragon

Hi @edgarrmondragon , thanks for the pointer! py-spy worked as advertised 🎉

I'm attaching two flamegraphs to this comment, one for a full-refresh run of tap-postgres => target-postgres (both meltanolabs variants), and the other for a log-based incremental run of the same pipeline. As far as I can tell, in both cases, the system quickly gets into an async loop over E+L blocks in ExtractLoadBlocks._start_blocks() here, then spends the vast majority of its time waiting on those blocks to finish in threading.py.

I don't think GitHub lets these SVGs stay interactive, so here's a zoomed-in view of the meltano stack where we're iterating over blocks:

This flamegraph is similar in structure but very different in distribution to the one you linked to in that existing meltano issue. Unfortunately, it doesn't seem like we have great visibility into what's going on, but probably you'll understand what's going on better than I do ☺️

For just a bit more context, here's what the plugin configs look like:

plugins:
  extractors:
    - name: tap-postgres
      variant: meltanolabs
      pip_url: meltanolabs-tap-postgres~=0.3.0
    - name: tap-postgres-foo
      inherit_from: tap-postgres
      config:
        ...
        replication_slot_name: "pipelinewise_utility_common"
        filter_schemas:
          - public
      select:
        # six data streams
        ...
      metadata:
        "*":
          replication_method: LOG_BASED
          replication_key: _sdc_lsn
  loaders:
    - name: target-postgres
      variant: meltanolabs
      pip_url: meltanolabs-target-postgres~=0.4.0
      config:
        ...
        hard_delete: false
        activate_version: true
        add_record_metadata: true
        use_copy: true
        batch_size_rows: 100000

Ah, a bit more detail here: When subprocesses are included, you can see the tap/target stacks:

@edgarrmondragon

Hi again @edgarrmondragon ! I've been looking back into these perf issues, now that log-based replication state seems to be working as expected. :)

After digging deeper into the code here, and comparing to the related implementation on the transferwise variant -- and assuming I'm understanding it all correctly -- a couple related things jump out at me:

PostgresLogBasedStream.get_records() is called separately for each stream to be replicated, while the other variant's sync_tables() function is called for all streams together
the status_interval of 5s used here is applied per stream, while the 10s used by transferwise is applied for all streams, so the minimum runtime of PostgresLogBasedStream scales as 5s * N streams while for sync_tables it's just 10s
iterating over the db's WAL N times is bound to be slower than iterating just once

I think this ^ is why my changes in PR #667 had such a minor effect on the overall runtime: most of the time was spent repeatedly iterating over the WAL, and not processing the messages that were selected (though I was able to make processing messages faster). Does all this make sense?

Is there any way to run psycopg2's ReplicationCursor.start_replication() over multiple streams at once within the PostgresLogBasedStream framework? Would it make sense to reduce the status_interval to mitigate the minimum runtime scaling by number of streams?

@edgarrmondragon

Hi @edgarrmondragon , just a friendly bump. Have you been able to give my previous comment any thought? I'm pretty desperate to migrate off the unmaintained pipelinewise variants, but since postgres E+L is already my performance bottleneck, I can't accept any real degradation here. Would love to help, even if just as a tester.

Is there any way to run psycopg2's ReplicationCursor.start_replication() over multiple streams at once within the PostgresLogBasedStream framework? Would it make sense to reduce the status_interval to mitigate the minimum runtime scaling by number of streams?

Unfortunately not without some non-trivial refactoring here (or much harder, in the SDK). I might be able to take a look in the coming weeks.

feat: Single-pass WAL streaming for LOG_BASED replication (MeltanoLab…

Navigation Menu

Repository navigation

Investigate performance issues #587

Related

Links

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Investigate performance issues #587

Description

Related

Links

Activity

bdewilde commented on Jul 17, 2025

edgarrmondragon commented on Jul 18, 2025

edgarrmondragon commented on Jul 18, 2025

bdewilde commented on Jul 21, 2025

bdewilde commented on Jul 21, 2025

bdewilde commented on Nov 25, 2025

bdewilde commented on Jan 6, 2026

edgarrmondragon commented on Feb 4, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions