search

airbytehq / airbyte

The leading data integration platform for ETL / ELT data pipelines from APIs, databases & files to data warehouses, data lakes & data lakehouses. Both self-hosted and Cloud-hosted.
https://airbyte.com
Other
16.19k stars 4.14k forks source link

Github sync appears to succeed when some endpoint calls are failing critically #1752

Closed jrhizor closed 3 years ago

jrhizor commented 3 years ago

Expected Behavior

Critical errors should result in a failed sync.

Current Behavior

The following resulted in a "successful" sync of zero records even though it wasn't able to access the data due to "Bad credentials":

2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) WorkerRun(call):58 - Executing worker wrapper...
2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) DefaultSyncWorker(run):82 - configured sync modes: {stargazers=incremental}
2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) DefaultAirbyteDestination(start):67 - Running target...
2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Checking if airbyte/destination-postgres:0.1.12 exists...
2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - airbyte/destination-postgres:0.1.12 was found locally.
2021-01-20 23:31:56 DEBUG (/tmp/workspace/8/0) DockerProcessBuilderFactory(create):104 - Preparing command: docker run --rm -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/8/0 --network host airbyte/destination-postgres:0.1.12 write --config target_config.json --catalog catalog.json
2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Checking if airbyte/source-github-singer:0.1.6 exists...
2021-01-20 23:31:56 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - airbyte/source-github-singer:0.1.6 was found locally.
2021-01-20 23:31:56 DEBUG (/tmp/workspace/8/0) DockerProcessBuilderFactory(create):104 - Preparing command: docker run --rm -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/8/0 --network host airbyte/source-github-singer:0.1.6 read --config tap_config.json --catalog catalog.json
2021-01-20 23:31:58 INFO (/tmp/workspace/8/0) DefaultAirbyteStreamFactory(internalLog):110 - Starting sync of repository: airbytehq/airbyte
2021-01-20 23:31:58 INFO (/tmp/workspace/8/0) DefaultAirbyteStreamFactory(internalLog):110 - METRIC: {"type": "timer", "metric": "http_request_duration", "value": 0.25496649742126465, "tags": {"endpoint": "stargazers", "status": "failed"}}
2021-01-20 23:31:58 INFO (/tmp/workspace/8/0) DefaultAirbyteStreamFactory(internalLog):110 - METRIC: {"type": "counter", "metric": "record_count", "value": 0, "tags": {"endpoint": "stargazers"}}
2021-01-20 23:31:58 ERROR (/tmp/workspace/8/0) DefaultAirbyteStreamFactory(internalLog):108 - CRITICAL {"message":"Bad credentials","documentation_url":"https://docs.github.com/rest"}

2021-01-20 23:31:58 ERROR (/tmp/workspace/8/0) DefaultAirbyteStreamFactory(internalLog):108 - Traceback (most recent call last):

2021-01-20 23:31:58 ERROR (/tmp/workspace/8/0) DefaultAirbyteStreamFactory(internalLog):108 -   File "/usr/local/bin/tap-github", line 8, in <module>

2021-01-20 23:31:58 DEBUG (/tmp/workspace/8/0) DefaultAirbyteSource(close):109 - Closing tap process
2021-01-20 23:31:58 DEBUG (/tmp/workspace/8/0) DefaultAirbyteDestination(close):102 - Closing target process
2021-01-20 23:31:59 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:31:59 INFO i.a.i.d.p.PostgresDestination(main):68 - {} - starting destination: class io.airbyte.integrations.destination.postgres.PostgresDestination
2021-01-20 23:31:59 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:31:59 INFO i.a.i.b.IntegrationRunner(run):78 - {} - Running integration: io.airbyte.integrations.destination.postgres.PostgresDestination
2021-01-20 23:31:59 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:31:59 INFO i.a.i.b.IntegrationCliParser(parseOptions):135 - {} - integration args: {catalog=catalog.json, write=null, config=target_config.json}
2021-01-20 23:31:59 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:31:59 INFO i.a.i.b.IntegrationRunner(run):82 - {} - Command: WRITE
2021-01-20 23:31:59 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:31:59 INFO i.a.i.b.IntegrationRunner(run):83 - {} - Integration config: IntegrationConfig{command=WRITE, configPath='target_config.json', catalogPath='catalog.json', statePath='null'}
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:32:00 INFO i.a.i.b.FailureTrackingConsumer(close):64 - {} - hasFailed: false.
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:32:00 INFO i.a.i.d.b.BufferedStreamConsumer(close):156 - {} - executing on success close procedure.
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:32:00 INFO i.a.i.b.IntegrationRunner(run):117 - {} - Completed integration: io.airbyte.integrations.destination.postgres.PostgresDestination
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 2021-01-20 23:32:00 INFO i.a.i.d.p.PostgresDestination(main):70 - {} - completed destination: class io.airbyte.integrations.destination.postgres.PostgresDestination
2021-01-20 23:32:00 ERROR (/tmp/workspace/8/0) LineGobbler(voidCall):69 - WARNING: An illegal reflective access operation has occurred
2021-01-20 23:32:00 ERROR (/tmp/workspace/8/0) LineGobbler(voidCall):69 - WARNING: Illegal reflective access by com.leansoft.bigqueue.page.MappedPageImpl$Cleaner (file:/airbyte/lib/leansoft-bigqueue-0.7.3.jar) to method java.nio.DirectByteBuffer.cleaner()
2021-01-20 23:32:00 ERROR (/tmp/workspace/8/0) LineGobbler(voidCall):69 - WARNING: Please consider reporting this to the maintainers of com.leansoft.bigqueue.page.MappedPageImpl$Cleaner
2021-01-20 23:32:00 ERROR (/tmp/workspace/8/0) LineGobbler(voidCall):69 - WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
2021-01-20 23:32:00 ERROR (/tmp/workspace/8/0) LineGobbler(voidCall):69 - WARNING: All illegal access operations will be denied in a future release
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) DefaultSyncWorker(run):110 - Running normalization.
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Checking if airbyte/normalization:0.1.8 exists...
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - airbyte/normalization:0.1.8 was found locally.
2021-01-20 23:32:00 DEBUG (/tmp/workspace/8/0) DockerProcessBuilderFactory(create):104 - Preparing command: docker run --rm -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/8/0/normalize --network host airbyte/normalization:0.1.8 run --integration-type postgres --config target_config.json --catalog catalog.json
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Namespace(config='target_config.json', integration_type=<DestinationType.postgres: 'postgres'>, out='/data/8/0/normalize')
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - transform_postgres
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Processing catalog.json...
2021-01-20 23:32:00 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 -   Generating stargazers.sql in /data/8/0/normalize/models/generated/
2021-01-20 23:32:01 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Running with dbt=0.18.1
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Found 1 model, 0 tests, 0 snapshots, 0 analyses, 308 macros, 0 operations, 0 seed files, 1 source
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 23:32:03 | Concurrency: 32 threads (target='prod')
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 23:32:03 | 
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 23:32:03 | 1 of 1 START table model public.stargazers................................................................... [RUN]
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 23:32:03 | 1 of 1 OK created table model public.stargazers.............................................................. [SELECT 0 in 0.14s]
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 23:32:03 | 
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 23:32:03 | Finished running 1 table model in 0.37s.
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Completed successfully
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - 
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) LineGobbler(voidCall):69 - Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
2021-01-20 23:32:03 DEBUG (/tmp/workspace/8/0) DefaultNormalizationRunner(close):97 - Closing tap process
2021-01-20 23:32:03 INFO (/tmp/workspace/8/0) DefaultSyncWorker(run):128 - sync summary: io.airbyte.config.StandardSyncSummary@c2993a7[status=completed,recordsSynced=0,bytesSynced=0,startTime=1611185516611,endTime=1611185523991]

Severity of the bug for you

Medium/Low

Airbyte Version

0.12.1-alpha

sherifnada commented 3 years ago

@jrhizor which creds did you use so we can repro?

jrhizor commented 3 years ago

Any creds that don't have any public repo can be used to replicate this against airbytehq/airbyte.

vitaliizazmic commented 3 years ago

The estimate time to complete this task is 4h

sherifnada commented 3 years ago

solved by #2051 which is blocked on fixing Github's CI credentials. Issue seems to be that GH credentials work locally but not from GH actions.