Source Kustomer: source fails loading schema with KeyError: 'user_agent'

ivansabik · July 19, 2022, 9:03pm

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"

sajarin · July 22, 2022, 6:49pm

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.

ivansabik · July 26, 2022, 9:24pm

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

ivansabik · July 28, 2022, 10:50pm

Here is the PR: 🐛 Source Kustomer: fix `KeyError: 'user_agent'` when retrieving schema by ivansabik · Pull Request #15132 · airbytehq/airbyte · GitHub

Topic		Replies	Views
Getting Error on last step while connecting Source Destination Connector Questions & Issues connectors	2	199	November 16, 2022
Zuora Source "failed to fetch schema" Connector Questions & Issues connectors	12	451	November 16, 2022
Failed to fetch schema(502 error) Connector Questions & Issues data-loading , connectors	1	199	March 23, 2023
Redshift source "Failed to fetch schema" Connector Questions & Issues connectors	2	321	September 12, 2022
ERROR: unsupported startup parameter: search_path Connector Questions & Issues data-loading , connectors	6	603	June 6, 2022

Source Kustomer: source fails loading schema with KeyError: 'user_agent'

Related Topics