Another logging question: So I took the example <...
# troubleshooting
s
Another logging question: So I took the example logging.yaml file here and am using it without modification. When I use that file, I’m seeing log lines that include details on the individual records being synced. They look something like this:
Copy code
2022-08-23T16:44:26.577054Z [info     ] {"type": "RECORD", "stream": "wo_tags", "record": {"date_created": "2021-05-25T05:
When I don’t use the logging.yaml file, I don’t see those records, but I don’t understand what it is about the logging.yaml that is displaying those. As far as I can tell, the logging level is the same in both cases (INFO). Ultimately, I want to have a non-colored log that does not include the individual records.
If I run meltano without the logging.yaml file, I don’t get those RECORD logs. However, if I set
--log-level=debug
, then I do get them, but they’re still showing up with the
[info]
tag. Could there be some bug in the logging configuration for the Meltano SDK? I’m getting these records from tap-quickbase-json (which I developed) but that tap doesn’t explicitly log those messages, so I’m really confused where they might be coming from.
f
no thats a quirk/side effect of what all gets enabled if you set --log-level=debug or set the root logger to debug level and then us consuming the output from plugins - but not having any level context (and so logging everything at info level).
That example yaml has the root logger's level set to DEBUG. Which basically ends up being the same as calling
--log-level=debug
.
s
I see…. so when I do change the root logger to INFO, those messages are removed! However, when it was set to DEBUG, I did NOT see a lot of the debug info I see when I run meltano cli with log level to debug:
Copy code
2022-08-23T18:00:52.064975Z [debug    ] Skipping node at '.streams[0].metadata[38].breadcrumb[0]'
So I assumed they weren’t really the same thing…
When the root level is set to WARN, I don’t get any messages at all, even though the console logger is INFO. propagate seems to have no effect
f
Are you sure ? I might have miss understood, but i still see those
Skipping node at
entries.
s
Yep, in order to get those “skipping node at” messages, I have to have BOTH the root and the console logger set to DEBUG. If root is DEBUG, but console is INFO, I don’t get the “skipping node” messages, but I do get the RECORD messages
f
yea because the RECORD message is at the info level, but got flipped on by us enabling debug mode behind the scenes
the Skipping node message is at the debug level, so would get filtered out if you set the console logger to info
s
Alright, so I think I have what I want worked out right now. It would be helpful for future reference if some of this was added to that guide you wrote
f
yup totally agree - actually just pop'd to https://github.com/meltano/meltano/issues/6660 follow up
s
I’ve always found python log levels lacking in their ability to specify different components. When I’m debugging, I don’t necessarily want to debug literally everything!
f
Same. I'd love for us to get better about more carefully using things like named loggers.
In the new extension sdk we're also becoming more deliberate on how and in what format utility plugins can log output. Something like that might eventually propagate to the tap/target sdk too. Will make it a bit easier to provide a more consistent experience.