we just updated from meltano 1.100.0 to 2.4.0 and im noticing that meltano commands (elt, config, etc.) are significantly slower than before. seems like something as simple as meltano config <plugin> list went from taking a few seconds to taking ~2 minutes to complete. tried running in debug mode but the added information isn’t super helpful. is this magnitude of slowdown expected? is there something we’re missing that would speed things up?

@Will Da Silva (Arch) I know you spent some time looking at performance on the CLI. Any ideas?

@taylor telemetry is currently disabled

I’ll wait for an engineer to chime in then <!subteam^S02BCD9FFEF> 😄

Such commands taking minutes to complete is definitely a bug, and is probably unrelated to the sort of stuff I was looking at (e.g. reducing/deferring imports).

@david_wallace any more details on the setup? python version, os version?

python 3.9.10 monterey 12.4

@david_wallace - Do you mind opening an issue with the debug logging enabled? Specifically, it would be helpful to see the full output from

meltano config <plugin> list

before and after.

yeah np

Wild - definitely not normal 😁 If you can run one with a

--log-level=debug

for the issue that might help. Even if theres no useful log lines, the timestamps between log messages might help narrow down where the delay is coming from.

(.venv) ➜  dutchie-dagster-meltano git:(NoJIRA-upgrade-dagster-meltano) ✗ meltano --version
meltano, version 1.100.0
(.venv) ➜  dutchie-dagster-meltano git:(NoJIRA-upgrade-dagster-meltano) ✗ time meltano --log-level debug config tap-exchange-rates-api list
2022-08-08T22:33:35.566057Z [debug    ] Creating engine <meltano.core.project.Project object at 0x10e248970>@sqlite:////Users/dwall/repos/dagster/dutchie-dagster-meltano/.meltano/meltano.db
2022-08-08T22:33:35.815951Z [debug    ] Using selector: KqueueSelector
2022-08-08T22:33:35.848522Z [debug    ] Created configuration at /Users/dwall/repos/dagster/dutchie-dagster-meltano/.meltano/run/tap-exchange-rates-api/tap.e8b67d7e-f096-4197-b805-e51bcf5971a8.config.json
2022-08-08T22:33:35.848773Z [debug    ] Could not find tap.properties.json in /Users/dwall/repos/dagster/dutchie-dagster-meltano/.meltano/extractors/tap-exchange-rates-api/tap.properties.json, skipping.
2022-08-08T22:33:35.848938Z [debug    ] Could not find tap.properties.cache_key in /Users/dwall/repos/dagster/dutchie-dagster-meltano/.meltano/extractors/tap-exchange-rates-api/tap.properties.cache_key, skipping.
2022-08-08T22:33:35.849094Z [debug    ] Could not find state.json in /Users/dwall/repos/dagster/dutchie-dagster-meltano/.meltano/extractors/tap-exchange-rates-api/state.json, skipping.

Custom, possibly unsupported by the plugin:
base [env: TAP_EXCHANGE_RATES_API_BASE] current value: 'USD' (from `meltano.yml`)
start_date [env: TAP_EXCHANGE_RATES_API_START_DATE] current value: '2018-01-01' (from `meltano.yml`)
symbols [env: TAP_EXCHANGE_RATES_API_SYMBOLS] current value: ['CAD', 'MXN', 'AUD', 'EUR', 'USD'] (from `meltano.yml`)
meltano --log-level debug config tap-exchange-rates-api list  1.64s user 0.20s system 99% cpu 1.849 total

(.venv) ➜  dutchie-dagster-meltano git:(NoJIRA-upgrade-dagster-meltano) ✗ meltano --version
meltano, version 2.4.0
(.venv) ➜  dutchie-dagster-meltano git:(NoJIRA-upgrade-dagster-meltano) ✗ date && time meltano --log-level debug config tap-exchange-rates-api list && date
Mon Aug  8 15:46:01 PDT 2022
2022-08-08T22:46:45.104438Z [debug    ] Creating engine <meltano.core.project.Project object at 0x10c521760>@sqlite:////Users/dwall/repos/dagster/dutchie-dagster-meltano/.meltano/meltano.db
2022-08-08T22:46:45.406143Z [debug    ] loaded lazy attr 'SafeConfigParser': <class 'configparser.ConfigParser'>
2022-08-08T22:46:45.406251Z [debug    ] loaded lazy attr 'NativeStringIO': <class '_io.StringIO'>
2022-08-08T22:46:45.406330Z [debug    ] loaded lazy attr 'BytesIO': <class '_io.BytesIO'>

Custom, possibly unsupported by the plugin:
base [env: TAP_EXCHANGE_RATES_API_BASE] current value: 'USD' (from `meltano.yml`)
start_date [env: TAP_EXCHANGE_RATES_API_START_DATE] current value: '2018-01-01' (from `meltano.yml`)
symbols [env: TAP_EXCHANGE_RATES_API_SYMBOLS] current value: ['CAD', 'MXN', 'AUD', 'EUR', 'USD'] (from `meltano.yml`)
meltano --log-level debug config tap-exchange-rates-api list  76.80s user 0.50s system 97% cpu 1:18.94 total
Mon Aug  8 15:47:20 PDT 2022

Question for triaging purposes: • Does this happen for existing (upgraded) meltano project as well as brand new meltano projects equally?

@christoph there may be a significant difference. I imagine running

meltano lock

after upgrading to

2.x

would get rid of some of the slowness. New projects would get the lockfiles right away when they

add

plugins.

thats interesting - I can try experimenting with adding lockfiles

I didn't see an already logged issue, so I opened one for tracking and assignment here: Bug: Meltano is slow to start · Issue #6597 · meltano/meltano (github.com)

just following up to show the magnitude of how this is affecting our workloads. this is the change in runtime for one of our el jobs post 2.4.0 migration

just following up to show the magnitude of how this is affecting our workloads. this is the change in runtime for one of our el jobs post 2.4.0 migration

To clarify, is your production system also running the same macOS and Python version you mentioned before?

production is linux but same python version

@david_wallace - Thanks for your patience. Dropped a status update in the issue: https://github.com/meltano/meltano/issues/6597#issuecomment-1212377484 Not sure if GitHub will ping if you have not already commented in the issue, so I'm dropping the note here also.

yeah i got the ping. thanks for the update. def happy to help you guys troubleshoot. nothing changed on our end other than the version bump, and we're seeing the same magnitude of performance change across all plugins and all execution environments