is there a way to get more detailed logging for a ...
# ask-community-for-troubleshooting
r
is there a way to get more detailed logging for a connector? I have a few rows of data that are missing and trying to understand why. Postgres -> snowflake. testing airbyte to replace stitch, which was loses a few rows of the same table....
✍️ 1
u
@[DEPRECATED] Marcos Marx turned this message into Zendesk ticket 2491 to ensure timely resolution!
r
turned on debug in the .env file, but only a few more logs
s
Hey @Robert Put, what type of information do you feel is missing from the logs? I can go ahead and forward the suggestion to our team. Regarding your issue, could you describe what those rows look like? Sounds like it could be a normalization issue and therefore something to be escalated to Github for the dev team to reproduce and triage.
r
I see some errors like this, but they apear each run and don't see corollated to the missing rows:
Copy code
2022-09-23 21:47:22 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No timezone information: 2021-01-18T23:42:48.000000
I'm looking for logs that will show me that this row pkey was read and it failed to be imported
should i be looking at the intermediatary table and not the final one?
if emitted and commited records match for the connector, would it be more so on the extraction that there is an issue?
the cursor column is of:
(type timestamp[29])
any hits would be helpful to troubleshoot a missing rows... if a row fails 1 day, will the next day it be blacklisted and not re-replicated? as the
Invalid date-time
are mainly just for each day
when looking at the rows that are missing nothing seems to be out of place compared to other rows
the troubleshooting steps in on the wiki just say to update everything if you have missing rows
s
You should probably be looking at the final table and not the intermediary one, although if emitted and committed records match then that’s more of an indication that something is wrong with the data and how it’s parsed
1. have you updated everything? 2. is it the same rows missing every time you run the sync or is it different rows missing? 3. I think if a row fails one day, it will not be replicated the next day since the cursor has updated to the new date. In which case, you’d have to make a separate sync for the rows that didn’t sync properly.
r
it was all up to date when it was running, now i updated source/destination by 1-2 minor versions. postgres to snowlfkae
0.40.7
for airbyte version
looking at the different version patch notes though, nothing was done to address anything related to this
s
Yes, I doubt the upgrade would fix this issue but since those connectors are updated frequently it’s a general suggestion that sometimes works
Let me know if you get answers to other question about whether it’s the same row
I can make an issue of this on Github afterwards
r
its new rows every day
it syncs ever 24 hours the table has rows added all day seems to be no patter in when the rows are missing, a spread across all hours of the day
u
This issue may be related to what you're experiencing: https://github.com/airbytehq/airbyte/issues/10782
r
The records failing to sync have updated timestamps from all hours of the day though in this case, not just near the stored cursor value
The thing is I had the same issue in stitch… so I’m leaning towards the issue being related to something in the source db but having issue troubleshooting it
s
It might be a source issue. I initially thought it might be something with the cursor field. Since you’re using timestamp though, I don’t see why some rows would be ignored in the incremental syncs. Is it impossible to upload the full sync log, that way I can make an issue on Github relating to this?
Also, have you considered using something like CDC?
r
Thats an option but it seems a little bit frail if issues appear trying to find the root of the issue
Let me get a full log and see if I can sanatize it, is there any specific info that would help?
s
Would be good to know the size of the tables, how much data is being ingested, which streams get the datatimevalidater error, if there are any issues with normalization, etc. And having the logs would be a good way to tell if we successfully reproduced the error.
r
Let me pull it and sanatize it a bit to get you as much info as I can
👍 1
Copy code
2022-10-02 11:00:27 WARN i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$5):366 - Schema validation errors found for stream publicpos_order. Error messages: [$.created_at is of an incorrect type. Expected it to be date-time, $.deleted_at is of an incorrect type. Expected it to be string, $.closed_at is of an incorrect type. Expected it to be date-time, $.updated_at is of an incorrect type. Expected it to be date-time]
this is probably the issue?
s
Hey @Robert Put, I’m guessing that’s the issue. Are the records that are missing always from publicpos_order? Since there’s a mismatch of types, what is the type for the created_at field, deleted_at field, closed_at field? I’m assuming some of them are using strings where it should be using date-time and date-time when it should be using string?
r
yes always some for each day, not at specific times but spread out
how could i check that? shouldn't the db enforce the type for the column?
Copy code
created_at                  | timestamp without time zone |           |          |         | plain    |              |
 updated_at                  | timestamp without time zone |           |          |         | plain    |              |
 deleted_at                  | timestamp without time zone |           |          |         | plain    |              |
s
In the transformation settings, normalization is turned on for tabular data right?
r
yup, going into snowlfkae
but if normalization was the error would emitted and committed records mismatch by the # of missing rows?
s
I believe normalization happens after records are emitted and committed. So this likely is either a problem with the source since you mentioned that emitted records and committed records are the same. The missing records are not being emitted. One last thing we can try/investigate with: have we considered using a different cursor field? https://docs.airbyte.com/integrations/sources/postgres/#supported-cursors
r
i can try a new cursor field, for testing, but wouldn't work in the long run. What would be the best way to figure out why certain rows are not being emitted. Some where to see each row it checks? Or would i have to instrument that in postgres?
digging into the data model on our side and it seem there is some confusion on how this column is supposed to be used... update related to the row vs tracking progression of the item in the row
but the rows shouldn't be missing if anything just missing data/old data
even if it was null
Copy code
original cursor field: null, original cursor value null, cursor field: closed_at, new cursor value: 2022-04-02T19:08:56.989606
it would get pulled later
u
I realize that data is added in throughout the day but as a way to test would you be able to create a new connection and run a smaller sync of a few of the records that don't get synced properly? This should rule out whether it's a problem with the rows or if it's a problem with the cursor/state. Also where are you getting the original cursor field and new cursor values from?
r
Is there a way to specify a smaller sync? Set max count of records? Or range for the cursor values?
both are a part of the tables already,
closed_at
and
created_at
are columns in the orders tables
u
Not through the UI I think, you may just have to create a new table with those records and then create a new connection with only that stream being ingested.
r
may be a little hard on a prod DB, I'll see what i can do, but already found a few issues that need to be addressed internally while going down this rabbithole
s
For sure, I appreciate you being willing to experiment here despite how cumbersome it probably is to do so. I hope we can get this working for you.