Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add additional sync timing information #17643

Merged
merged 14 commits into from
Oct 13, 2022
Merged

Conversation

evantahler
Copy link
Contributor

@evantahler evantahler commented Oct 5, 2022

Closes #17407

whimsical link

Screen Shot 2022-10-12 at 11 10 55 AM

This PR adds a plethora of additional time information for each part of the replication workflow so we can better analyze performance.


The times that are added are different from the existing startTime and endTime in subtle but interesting ways:

  • startTime - the start of the workflow
  • replication_start_time - the start of the replication activity
  • replication_end_time - the end of the replication activity
  • source_read_start_time - the start of the source container
  • source_read_end_time - the end of the source container
  • destination_write_start_time - the start of the destination container
  • destination_write_end_time - the end of the destination container
  • normalization_start_time - the start of the normalization container
  • normalization_end_time - the end of the normalization container
  • endTime - the conclusion of the workflow

While it might appear that startTime, replication_start_time, and source_read_start_time should all be the same, there is often a lag, which is due to things like downloading the docker image, starting the K8s pod, etc.


{
  "status" : "completed",
  "recordsSynced" : 1222,
  "bytesSynced" : 344396,
  "startTime" : 1665531403219, // Exists
  "endTime" : 1665531405935, // Exists
  "totalStats" : {
    "recordsEmitted" : 1222,
    "bytesEmitted" : 344396,
    "sourceStateMessagesEmitted" : 8,
    "destinationStateMessagesEmitted" : 1,
    "recordsCommitted" : 1222,
    "meanSecondsBeforeSourceStateMessageEmitted" : 0,
    "maxSecondsBeforeSourceStateMessageEmitted" : 0,
    "maxSecondsBetweenStateMessageEmittedandCommitted" : 1,
    "meanSecondsBetweenStateMessageEmittedandCommitted" : 1,
    "replicationStartTime" : 1665531403219, // NEW!
    "replicationEndTime" : 1665531405932,  // NEW!
    "sourceReadStartTime" : 1665531403274, // NEW!
    "sourceReadEndTime" : 1665531405623, // NEW!
    "destinationWriteStartTime" : 1665531403339, // NEW!
    "destinationWriteEndTime" : 1665531405931 // NEW!
  },
}

Confirming that the data appears in BiqQuery:

select
  attempt_completion_status
  , attempt_stage
  , connection_id
  , workspace_id
  , connector_source
  , connector_destination
  , job_type
  , replication_start_time
  , replication_end_time
  , source_read_start_time
  , source_read_end_time
  , destination_write_start_time
  , destination_write_end_time
  , normalization_start_time
  , normalization_end_time
from api.connector_jobs 
WHERE 1=1
AND loaded_at >= "2022-09-01 00:00:00"
AND workspace_id = '40c15f0a-027e-48ef-943f-956e1258264a' 
order by loaded_at desc
limit 100

Produces

attempt_completion_status attempt_stage connection_id workspace_id connector_source connector_destination job_type replication_start_time replication_end_time source_read_start_time source_read_end_time destination_write_start_time destination_write_end_time normalization_start_time normalization_end_time
SUCCEEDED ENDED 335c7727-42aa-4331-8846-7b33348de803 40c15f0a-027e-48ef-943f-956e1258264a Faker Postgres SYNC 1665442059649 1665442061312 1665442059700 1665442060972 1665442059753 1665442061311 1665442061493 1665442115182

@github-actions github-actions bot added area/platform issues related to the platform area/worker Related to worker labels Oct 5, 2022
@evantahler evantahler temporarily deployed to more-secrets October 5, 2022 23:26 Inactive
Comment on lines 132 to 134
long replicationEndTime = -1;
long sourceReadStartTime = -1;
long destinationWriteStartTime = -1;
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It seems that these longs needed to be initialized or else they couldn't be used below in withSourceReadStartTime() - I'll be there's an Optional<> Java thing I don't know about that's better than all the ternaries...

@evantahler evantahler changed the title WIP - Add additional sync timing information Add additional sync timing information Oct 5, 2022
@evantahler evantahler temporarily deployed to more-secrets October 7, 2022 20:58 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 7, 2022 21:03 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 7, 2022 21:32 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 10, 2022 16:53 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 10, 2022 18:01 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 10, 2022 22:38 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 11, 2022 00:14 Inactive
@evantahler evantahler marked this pull request as ready for review October 11, 2022 00:50
@evantahler evantahler temporarily deployed to more-secrets October 11, 2022 21:03 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 11, 2022 21:44 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 11, 2022 22:46 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 11, 2022 23:38 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 11, 2022 23:45 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 12, 2022 00:37 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 12, 2022 18:30 Inactive
@evantahler
Copy link
Contributor Author

Tests are finally green! Now ready for review!

@evantahler evantahler temporarily deployed to more-secrets October 12, 2022 21:22 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 12, 2022 21:46 Inactive
@pedroslopez
Copy link
Contributor

LGTM, not too familiar with the whole java threaded synchronization stuff though

Copy link
Contributor

@davinchia davinchia left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Very nice!

Most of my comments are suggestions/nits for improving readability.

Approving since I don't think these are blocking comments.

Copy link
Contributor

@alex-gron alex-gron left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The names look good to me and make sense. Thanks @evantahler !

@evantahler evantahler temporarily deployed to more-secrets October 13, 2022 20:34 Inactive
@evantahler evantahler temporarily deployed to more-secrets October 13, 2022 22:37 Inactive
@evantahler evantahler merged commit f338e47 into master Oct 13, 2022
@evantahler evantahler deleted the evan/sync-timing-information branch October 13, 2022 23:16
letiescanciano added a commit that referenced this pull request Oct 14, 2022
…vation

* master: (98 commits)
  🐛 Source Bing Ads - Fix Campaigns stream misses Audience and Shopping (#17873)
  Source S3 - fix schema inference (#17991)
  🎉 JDBC sources: store cursor record count in db state (#15535)
  Introduce webhook configs into workspace api and persistence (#17950)
  ci: upload test results to github for analysis (#17953)
  Trigger the connectors build if there are worker changes. (#17976)
  Add additional sync timing information (#17643)
  Use page_token_option instead of page_token (#17892)
  capture metrics around json messages size (#17973)
  🐛 Correct kube annotations variable as per the docs. (#17972)
  🪟 🎉 Add /connector-builder page with embedded YAML editor (#17482)
  fix `est_num_metrics_emitted_by_reporter` not being emitted (#17929)
  Update schema dumps (#17960)
  Remove the bump in the value.yml (#17959)
  Ensure database initialization in test container (#17697)
  Remove typo line from incremental reads docs (#17920)
  DocS: Update authentication.md (#17931)
  Use MessageMigration for Source Connection Check. (#17656)
  fixed links (#17949)
  remove usages of YamlSeedConfigPersistence (#17895)
  ...
jhammarstedt pushed a commit to jhammarstedt/airbyte that referenced this pull request Oct 31, 2022
* WIP - Add additional sync timing information

* Fixup tests

* fix PMD problem

* send data to segment

* Test JobTracker

* respond to PR suggestions

* fixup test

* formatting

* fix initializer for stats

* Make thread-safe with synchronized

* Don't clobber syncStats on init

* add comments and fix init

* Do what Pedro says

* Extract timeTracker pojo
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/platform issues related to the platform area/worker Related to worker
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Additional timing information is needed for sync analysis
5 participants