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
15.58k stars 4.01k forks source link

Kustomer source fails loading schema with KeyError: 'user_agent'" #14965

Open marcosmarxm opened 2 years ago

marcosmarxm commented 2 years ago

This Github issue is synchronized with Zendesk:

Ticket ID: #1655 Priority: normal Group: Community Assistance Engineer Assignee: Sajarin Dider

Original ticket description:

  • Is this your first time deploying Airbyte?: Yes
  • OS Version / Instance:
  • Memory / Disk: you can use something like 4Gb / 1 Tb
  • Deployment: Docker
  • Airbyte Version: What version are you using now? 0.39.37-alpha
  • Source name/version: Kustomer 0.1.2
  • Destination name/version: Snowflake
  • Step: The issue is happening during sync, creating the connection or a new source? When creating the connection
  • Description: Not able to fetch schema for the Kustomer connector
0: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/28a116d2-2f02-4a46-befa-f3ff95ea163a/0/logs.log"
1: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.37-alpha"
2: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):43 - Using default value for environment variable USE_STREAM_CAPABLE_STATE: 'false'"
3: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/source-kustomer-singer:0.1.2 exists..."
4: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.c.i.LineGobbler(voidCall):82 - airbyte/source-kustomer-singer:0.1.2 was found locally."
5: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 28a116d2-2f02-4a46-befa-f3ff95ea163a"
6: "2022-07-19 21:00:34 \u001b[32mINFO\u001b[m i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/28a116d2-2f02-4a46-befa-f3ff95ea163a/0 --log-driver none --name source-kustomer-singer-discover-28a116d2-2f02-4a46-befa-f3ff95ea163a-0-rdwcj --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=false -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-kustomer-singer:0.1.2 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=0.39.37-alpha -e WORKER_JOB_ID=28a116d2-2f02-4a46-befa-f3ff95ea163a airbyte/source-kustomer-singer:0.1.2 discover --config source_config.json"
7: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 - CRITICAL 'user_agent'"
8: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 - Traceback (most recent call last):"
9: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 -   File \"/usr/local/bin/tap-kustomer\", line 8, in <module>"
10: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 -     sys.exit(main())"
11: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 -   File \"/usr/local/lib/python3.7/site-packages/singer/utils.py\", line 229, in wrapped"
12: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 -     return fnc(*args, **kwargs)"
13: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 -   File \"/usr/local/lib/python3.7/site-packages/tap_kustomer/__init__.py\", line 37, in main"
14: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 -     parsed_args.config['user_agent']) as client:"
15: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.w.i.DefaultAirbyteStreamFactory(internalLog):95 - KeyError: 'user_agent'"
16: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 - Traceback (most recent call last):"
17: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/airbyte/integration_code/main.py\", line 12, in <module>"
18: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     launch(source, sys.argv[1:])"
19: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/site-packages/airbyte_cdk/entrypoint.py\", line 117, in launch"
20: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     for message in source_entrypoint.run(parsed_args):"
21: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/site-packages/airbyte_cdk/entrypoint.py\", line 102, in run"
22: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     catalog = self.source.discover(logger, config)"
23: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/site-packages/airbyte_cdk/sources/singer/source.py\", line 117, in discover"
24: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     return self._discover_internal(logger, config_container.config_path).airbyte_catalog"
25: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/site-packages/airbyte_cdk/sources/singer/source.py\", line 103, in _discover_internal"
26: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     catalogs = SingerHelper.get_catalogs(logger, cmd, self.get_sync_mode_overrides(), self.get_excluded_streams())"
27: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/site-packages/airbyte_cdk/sources/singer/singer_helpers.py\", line 157, in get_catalogs"
28: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     singer_catalog = json.loads(completed_process.stdout)"
29: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/json/__init__.py\", line 348, in loads"
30: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     return _default_decoder.decode(s)"
31: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/json/decoder.py\", line 337, in decode"
32: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     obj, end = self.raw_decode(s, idx=_w(s, 0).end())"
33: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -   File \"/usr/local/lib/python3.7/json/decoder.py\", line 355, in raw_decode"
34: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 -     raise JSONDecodeError(\"Expecting value\", s, err.value) from None"
35: "2022-07-19 21:00:36 \u001b[1;31mERROR\u001b[m i.a.c.i.LineGobbler(voidCall):82 - json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)"
36: "2022-07-19 21:00:36 \u001b[32mINFO\u001b[m i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$2):161 - Completing future exceptionally..."
37: "io.airbyte.workers.exception.WorkerException: Discover job subprocess finished with exit code 1"
38: "\tat io.airbyte.workers.general.DefaultDiscoverCatalogWorker.run(DefaultDiscoverCatalogWorker.java:83) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
39: "\tat io.airbyte.workers.general.DefaultDiscoverCatalogWorker.run(DefaultDiscoverCatalogWorker.java:26) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
40: "\tat io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
41: "\tat java.lang.Thread.run(Thread.java:833) [?:?]"
42: "2022-07-19 21:00:36 \u001b[32mINFO\u001b[m i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling..."
43: "2022-07-19 21:00:36 \u001b[33mWARN\u001b[m i.t.i.a.POJOActivityTaskHandler(activityFailureToResult):307 - Activity failure. ActivityId=5ccde613-7fde-3ff3-a537-22ad64660252, activityType=Run, attempt=1"
44: "java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Discover job subprocess finished with exit code 1"
45: "\tat java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]"
46: "\tat java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]"
47: "\tat io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
48: "\tat io.airbyte.workers.temporal.discover.catalog.DiscoverCatalogActivityImpl.run(DiscoverCatalogActivityImpl.java:83) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
49: "\tat jdk.internal.reflect.GeneratedMethodAccessor551.invoke(Unknown Source) ~[?:?]"
50: "\tat jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]"
51: "\tat java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]"
52: "\tat io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]"
53: "\tat io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]"
54: "\tat io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]"
55: "\tat io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]"
56: "\tat io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]"
57: "\tat io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]"
58: "\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]"
59: "\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]"
60: "\tat java.lang.Thread.run(Thread.java:833) [?:?]"
61: "Caused by: io.airbyte.workers.exception.WorkerException: Discover job subprocess finished with exit code 1"
62: "\tat io.airbyte.workers.general.DefaultDiscoverCatalogWorker.run(DefaultDiscoverCatalogWorker.java:83) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
63: "\tat io.airbyte.workers.general.DefaultDiscoverCatalogWorker.run(DefaultDiscoverCatalogWorker.java:26) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
64: "\tat io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.37-alpha.jar:?]"
65: "\t... 1 more"
[Discourse post]
marcosmarxm commented 2 years ago

Comment made from Zendesk by Sajarin Dider on 2022-07-22 at 18:49:

Thanks for the post Ivan and welcome to the community. I was able to replicate your error and created an issue for this here: https://github.com/airbytehq/airbyte/issues/14965. If you're willing to investigate further and make a PR, I'd be happy to review it. 
marcosmarxm commented 2 years ago

Comment made from Zendesk by Marcos Marx on 2022-07-26 at 21:24:

Thanks, we’re probably going to give it a stab this or next sprint and can push a PR if we find a fix

[Discourse post]
marcosmarxm commented 2 years ago

Comment made from Zendesk by Marcos Marx on 2022-07-28 at 22:51:

jan-benisek commented 1 year ago

@marcosmarxm Hi, we just stumbled upon this issue (mentioned in discuss and in this issue, probably being fixed here). Do you have an idea when this could be fixed please? Thank you.

luancaarvalho commented 1 year ago

Hello guys ! Any updates here ?

marcosmarxm commented 1 year ago

No updates so far. You can submit a fix for that or migrate the connector to low-code to improve maintenance