Hi. I'm trying to do an initial sync of a rather l...
# troubleshooting
p
Hi. I'm trying to do an initial sync of a rather large table from MSSQL to Snowflake, and its going rather slow due to random pauses where it seems nothing is happening. The logs will show it loading 10's of thousands of rows for a few minutes, then it pauses for anywhere from 5-45 minutes doing nothing before it writes its state to azure blob storage and then resumes. During that time I don't see any DTU usage happening in the SQL server and I don't see any queries being run in snowflake. My setup is running meltano from the given docker image, I have Azure storage setup for saving state and logs, and airflow for scheduling/UI connected to postgres. I also don't see any spiking in CPU or memory for my container, so I don't think its a matter of container hardware limits. From my observation, it always seems to happen right before we write state to azure blob storage. But this is just updating the simple meltano state file, its not like there's any large data copying to blob storage that should be an issue. I have also tried to post relevant metlano.yml configuration below these logs, with some data omitted for privacy. Here is just one example of the logs pausing between 2025-02-13, 185424 and 2025-02-13, 191044:
Copy code
[2025-02-13, 18:53:26 UTC] {subprocess.py:93} INFO - [2025-02-13T18:53:26.123113Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 4.307430982589722, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 18:53:26 UTC] {subprocess.py:93} INFO - [2025-02-13T18:53:26.637487Z[ [[[info     [] [time=2025-02-13 18:53:26 name=singer level=INFO message=METRIC: b'{"type":"counter","metric":"record_count","value":29997,"tags":{"database":"dbo","table":"role_users"}}'[ [[=[[ [consumer[=[False[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[tap-mssql--rbac[ [producer[=[True[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[tap-mssql--rbac[
[2025-02-13, 18:54:01 UTC] {subprocess.py:93} INFO - [2025-02-13T18:54:01.703247Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 34.31813979148865, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 18:54:07 UTC] {subprocess.py:93} INFO - [2025-02-13T18:54:07.101263Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 4.348176002502441, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 18:54:12 UTC] {subprocess.py:93} INFO - [2025-02-13T18:54:12.144568Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 3.9662907123565674, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 18:54:17 UTC] {subprocess.py:93} INFO - [2025-02-13T18:54:17.177047Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 3.974202871322632, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 18:54:23 UTC] {subprocess.py:93} INFO - [2025-02-13T18:54:23.994344Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 5.567358732223511, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 18:54:24 UTC] {subprocess.py:93} INFO - [2025-02-13T18:54:23.998431Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "counter", "metric": "record_count", "value": 30000, "tags": {"stream": "dbo-role_users", "pid": 213}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.513919Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 979.4570729732513, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.530655Z[ [[[info     [] [Writing state to Azure Blob Storage[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.579007Z[ [[[info     [] [uploading part #1, 17 bytes (total 0.000GB)[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.597839Z[ [[[info     [] [uploading part #1, 547 bytes (total 0.000GB)[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.623114Z[ [[[info     [] [Incremental state has been updated at 2025-02-13 19:10:44.623089+00:00.[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.624339Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "counter", "metric": "record_count", "value": 5000, "tags": {"stream": "dbo-role_users", "pid": 213}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:10:44 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:44.856061Z[ [[[info     [] [time=2025-02-13 19:10:44 name=singer level=INFO message=METRIC: b'{"type":"counter","metric":"record_count","value":28863,"tags":{"database":"dbo","table":"role_users"}}'[ [[=[[ [consumer[=[False[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[tap-mssql--rbac[ [producer[=[True[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[tap-mssql--rbac[
[2025-02-13, 19:10:51 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:51.404714Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 5.569474220275879, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:10:57 UTC] {subprocess.py:93} INFO - [2025-02-13T19:10:57.912801Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 5.435643911361694, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:11:06 UTC] {subprocess.py:93} INFO - [2025-02-13T19:11:06.362279Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 7.266654014587402, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:11:12 UTC] {subprocess.py:93} INFO - [2025-02-13T19:11:12.017499Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 4.604991912841797, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
[2025-02-13, 19:11:18 UTC] {subprocess.py:93} INFO - [2025-02-13T19:11:18.278536Z[ [[[info     [] [INFO:singer_sdk.metrics:METRIC: {"type": "timer", "metric": "batch_processing_time", "value": 5.034445285797119, "tags": {"stream": "dbo-role_users", "pid": 213, "status": "succeeded"}}[ [[=[[ [consumer[=[True[ [job_name[=[prod:tap-mssql--rbac-to-target-snowflake--rbac[ [name[=[target-snowflake--rbac[ [producer[=[False[ [run_id[=[203c091d-7f78-4dd3-ab1c-b16e50bb5801[ [stdio[=[stderr[ [string_id[=[target-snowflake--rbac[
Configuration:
Copy code
plugins:
  extractors:
  - name: tap-mssql--rbac
    inherit_from: tap-mssql
    variant: wintersrd
    pip_url: tap-mssql
    config:
      database: ***
      port: '***'
      cursor_array_size: 5000
    select:
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    - dbo-role_users.***
    metadata:
      dbo-role_users:
        replication-method: LOG_BASED

    
plugins:
  loaders:
  - name: target-snowflake--rbac
    inherit_from: target-snowflake
    variant: meltanolabs
    pip_url: meltanolabs-target-snowflake
    config:
      add_record_metadata: true
      default_target_schema: ***
      user: ***
      role: ***
      warehouse: ***
      load_method: upsert
      batch_size_rows: 5000

jobs:
- name: rbac-sync
  tasks:
  - tap-mssql--rbac target-snowflake--rbac
👀 3