Hi Ryan,

Thanks for the detailed answer, and the confirmation! Created the pull request:

https://github.com/apache/iceberg/pull/1394 
<https://github.com/apache/iceberg/pull/1394>
Hive: Add logging for Hive related classes #1394

 <https://github.com/apache/iceberg/pull/1394>
One comment for the message below: One place where DEBUG level can be useful, 
if an issue is only reproducible on customer side they can turn on DEBUG 
logging and share the logs - connecting with a debugger is not always desirable.

I have seen multiline log messages in Iceberg - this could cause hard to read 
logs if there are plenty of concurrent users and the log lines start to mix-up. 
I suggest collapsing them to a single line.

Thanks,
Peter


> On Aug 26, 2020, at 18:33, Ryan Blue <rb...@netflix.com.INVALID> wrote:
> 
> Hi Peter,
> 
> Thanks for thinking about this! Improving logs is a great contribution.
> 
> My philosophy is to stick to the usual definitions of logging levels. Here’s 
> my quick summary:
> 
> FATAL: the event that caused the service to stop (not used in Iceberg, since 
> it’s a library)
> ERROR: an event that stops an operation
> WARNING: an unexpected event where the operation can continue but there may 
> be a bigger problem
> INFO: events that help you understand what’s happening in normal operation
> DEBUG: events that help you spot bugs by looking for unexpected values
> In general, I think that we can do better with INFO logging. But there is a 
> balance to target because we don’t want Iceberg to be so verbose that people 
> turn the logging off. We have to remember that Iceberg is typically 
> integrated into some other framework that is more important. Iceberg should 
> log the messages that help someone understand what the engine is doing, 
> rather than logging internal concerns. A good example of what not to do comes 
> from Parquet, where INFO messages were printed with stats from each row group 
> — this was too much because Parquet’s contribution to the overall picture of 
> what the engine was doing was just that it was storing data at the file 
> level. Parquet internal concerns should not have leaked.
> 
> I also don’t typically like to use DEBUG logging because you almost never 
> keep those logs. For debugging, I prefer to use a debugger and keep the code 
> clean. I think you could argue that DEBUG is appropriate for cases like my 
> Parquet example above, where INFO isn’t a good idea for the final 
> application, but you may still want to log information about the operations 
> in a library. I think that’s fine, just not things like logging the value of 
> arguments to functions all over the codebase. I think the use of DEBUG for 
> files that are being opened sounds reasonable.
> 
> I think the additional logs you’re proposing mostly look good. The scan 
> configuration is logged in Iceberg’s BaseTableScan, so you should already get 
> snapshot ID and filters. I’m not sure that we keep the time. We also have a 
> system for emitting events with more detail. Those can be used for additional 
> logging if you choose. We send them through a Kafka pipeline so we can 
> analyze all the scans taking place in our data warehouse.
> 
> rb
> 
> 
> On Wed, Aug 26, 2020 at 6:24 AM Peter Vary <pv...@cloudera.com.invalid> wrote:
> Hi Team,
> 
> I was wondering if there is a general best practice for using log levels in 
> Iceberg, what is the usual way we do it.
> 
> I have been playing around with Iceberg/Hive integration and was wondering 
> how I would be able to debug a customer case based on the logs.
> To be the honest answer based on the current code is most probably using some 
> additional method to generate new log lines, which I think is not a good 
> situation.
> 
> I was thinking about adding some more logging to the code and added the 
> proposed log level next to it:
> CatalogLoader/Catalogs:
> Which catalog is used to fetch the table - INFO
> What is the table being fetched in the end - INFO
> HiveCatalog:
> Table is created/dropped/renamed - INFO
> Catalog is created/dropped - INFO
> HiveTableOperation:
> Write committed / table created - INFO 
> IcebergInputFormat:
> Scan parameters provided - DEBUG
> SnapshotId
> Time
> Filters
> Final snapshotId being read - INFO (if I find a way to get this)
> Opening specific files and their format - DEBUG
> 
> Are the logs above are compliant with the current practice? Shall I modify 
> them up or down? Any places around Iceberg/Hive you think it would be good to 
> add logging?
> 
> Thanks,
> Peter
> 
> 
> -- 
> Ryan Blue
> Software Engineer
> Netflix

Reply via email to