Add Logger ability to contacts API

[alorma]

This PR adds Logger to Contacts API, so it can be used to track features like query, insert, ...

I not plan to add on this PR the logs to every feature, but my idea is to add it later following up a discussion with you about what and how should be tracked.

Code example with android logger:

val contacts = Contacts(
   context = this@Activity,
   logger = AndroidLogger(),
)

Code example with custom logger:

val contacts = Contacts(
   context = this@Activity,
   logger = object: Logger() {
      override fun log(message: String) {
          Timber.w() ...
      }
   },
)

This PR closes #144

[vestrel00]

@alorma, as I mentioned in #144, I'm super excited about this idea. I'm hoping you can own this part of the library!

It might take a while because I have work and we live in different parts of the world (I live in Hawaii), so please be patient with my responses.
😄

I'll look at this tomorrow. We'll have to come to an agreement about the internal architecture, consumer usage, and what to log and when. Then it would be AWESOME if you can own this part of the library and implement all part of it 😁 ❤️

[alorma]

For sure! I live on Barcelona, no problem on async communication

[vestrel00]

Sorry I clicked the close button by accident!

[vestrel00]

I like how it is currently looking! There are a several things we need to discuss. This is a long comment but it should contain most of the stuff we need to discuss and agree on. After this, writing the code should be a 🍰

1. Logging functions in the debug module vs logging in the core module.
2. Provide GDPR-compliant and customizable logging in the core module.
3. What to log in the core module.

Please note that code samples I provide in this comment are just suggestions to help you because you are a new contributor to this lib and I kinda want to keep the design the same for all APIs, including the logger.

1. Logging functions in the debug module vs logging in the core module.

Based on your initial code in this PR, I think you are already aware that the functions in the debug module are completely unrelated to the core module. I think we are already on the same page that the logger you are building will not log the Contacts database. I updated How do I debug the Contacts Provider tables? with the following information;

I think we are good with this part but let me know if you disagree.

2. Provide GDPR-compliant and customizable logging in the core module.

I have worked on a lot of mobile apps that managed or interacted with user data in some way. In order to protect private user data, we had to "redact" sensitive information when we log stuff in our crash reporting and analytics. User's contacts definitely counts as "private user data" 🤜

There are libraries our there to make redacting easier. For example, https://github.com/ZacSweers/redacted-compiler-plugin However, in spirit of keeping dependencies of this library to a minimum, this library should just provide redacted versions of toString for all of its entities.

If this library is going to provide consumers a logging API that they can customize, the following could occur;

val contacts = Contacts(
   ...
   logger = object: Logger() {
      override fun log(nonGDPRCompliantMessage: String) {
          logToAnalyticsServer(nonGDPRCompliantMessage)
      }
   }
)

I know that we cannot prevent consumers of this API from violating privacy laws if they really want to. BUT, if we are implementing a logging API, it should definitely be GDPR-compliant by default! This is not necessary for all libraries to implement but this library deals with sensitive, private data so we need to be extra careful and provide consumers a GDPR-compliant string versions of our APIs and entities.

I created issue #147 for this. You can take a look at it for more details. I'll work on it now so you can use it when you build this logger component 🔥

This means that the logger interface should specify if the messages passed to the logging function should be redacted or not. This would probably require us to keep an internal logger that holds a reference to the consumer logger.

Preferably, we would follow the pattern already used by the library such as CustomDataRegistry.

Using the code you already have in this PR, the wrapper might look something like,

// Intentionally a final class. The redactedMessages is true by default
class LoggerRegistry @JvmOverloads constructor(
   val logger: Logger = EmptyLogger()
   val redactMessages: Boolean = true
) {
    internal fun log(redactable: Redactable) {
        logger.log(
            if (redactMessages) {
                redactable.redactedCopy().toString()
            } else {
                redactable.toString()
            }
        )
    }
}

I will be implementing the Redactable interface in #147.

This registry would be the one that we would keep a reference to in the Contacts interface,

interface Contacts {
    ...
    val customDataRegistry: CustomDataRegistry
    val loggerRegistry: LoggerRegistry
}

Initialization could then look like,

val contacts = Contacts(
   context = ...,
   logger = LoggerRegistry(AndroidLogger(), redactMessages = false),
)

Having an internal logger wrapper allows our logging API to be more future-proof. In the future, we could allow multiple consumer loggers or other optional customizations.

3. What to log in the core module.

For now, we can just log all of the query, insert, update, and delete APIs that get executed and their results. For example, in Insert.kt,

interface Insert : Redactable {
    interface Result : Redactable
}

private class InsertImpl(
    private val contacts: Contacts,

    // this still will never be redacted
    private var allowBlanks: Boolean = false,
    private var include: Include<AbstractDataField> = allDataFields(contacts.customDataRegistry),

    // this stuff could be redacted
    private var account: Account? = null,
    private val rawContacts: MutableSet<NewRawContact> = mutableSetOf()
) {
    commit {
        contacts.loggerRegistry.log(this)
        ...
        return InsertResult(results).also(contacts.loggerRegistry::log)
    }
}

I will be implementing the Redactable interface in #147.

Apply this to all APIs;

• Query
• Insert
• Update
• Delete
• ProfileQuery
• ProfileInsert
• ProfileUpdate
• ProfileDelete
• GroupsQuery
• GroupsInsert
• GroupsUpdate
• GroupsDelete
• DataQuery
• DataUpdate
• DataDelete
• AccountsQuery
• AccountsRawContactsAssociationsUpdate
• AccountsRawContactsQuery

There are more APIs in the util package but ignore those for now. Most of them use one of the APIs listens above internally anyways.

Final thoughts

Let me know what you think! It was a long comment but it contains everything that I'm thinking of that is related to logging.

[alorma]

Point number 1, totally agree, I've thought about debug module logs and I agree those should not be logged on production... Maybe there's a way to provide a custom logger for it too, but it's another point tat it can be addressed later

[alorma]

Point number 2

Not sure about that part, I was not thinking about logging results of queries, mostly I wanted to be available to log queries themselves, like operations, are done on the database, etc...

Of course, those operations must be GDPR compliant if logged to some analytics server, as it can contain sensitive information... but as point 1 mentions, logs must not go to production, and that is the responsibility of the app.

[alorma]

Point number 3: What I just told on the previous comment, I would not log the query response, but that's up to you, and it can be discussed on following PRs, to keep the changes to minimum.

[vestrel00]

@alorma, I'm thinking that it would be very useful to log the consumer input and API output for all CRUD APIs.

The log output would look something like,

Insert {
    allowBlanks: true
    include: data1, data2, ...
    account: Account(...)
    rawContacts: (NewRawContact(...), NewRawContact(...), ...)
}

InsertResult {
    isSuccessful: true
    rawContactIds: ...
}

Those logs can either be plain (not safe for production) or redacted (safe for production).

Note that for query APIs that could return thousands of results, I'm planning to simplify the string output to something like "Query succeeded with x results".

I will be implementing the Redactable messages in #147. All you would need to do here is to log them...

commit {
        contacts.loggerRegistry.log(this)
        ...
        return InsertResult(results).also(contacts.loggerRegistry::log)
    }

But first, let's take a step back and ask why we want to add logging. We should always have a problem that we are trying to solve. Once we have a potential solution, we should see if it solves the problem. We should do this before writing any code. Otherwise, we just added code without adding any value for library maintainers and consumers.

Problem(s)

We need to...

1. Allow consumers to track usages of the APIs provided by this library in production for analytics while being GDPR-compliant.
2. Allow consumers to track issues caused by the APIs provided by this library in production while being GDPR-compliant.
3. Allow consumers to report unexpected input/output to library maintainers effectively.
4. Allow maintainers and consumers to identify issues during development using non-redacted messages.

If there is anything else I missed, let me know.

Solution

Provide a logger that can log the input and output of all APIs.

To be GDPR-compliant, both input and output must be redacted in production. However, redaction does not need to occur during development. This can be accomplished with the redactMessages option,

val contacts = Contacts(
   context = ...,
   logger = LoggerRegistry(AndroidLogger(), redactMessages = isProductionBuild)
)

class LoggerRegistry @JvmOverloads constructor(
   val logger: Logger = EmptyLogger()
   val redactMessages: Boolean = true
) {
    internal fun log(redactable: Redactable) {
        logger.log(
            if (redactMessages) {
                redactable.redactedCopy().toString()
            } else {
                redactable.toString()
            }
        )
    }
}

This is just the initial implementation. We can always iterate and add more things to it if we want to in the future. Like you said, we should keep it as simple as possible 😁

[vestrel00]

@alorma, I'll let you know once I've completed #147 so you can get started working on this. Thanks in advance! I'm looking forward to merging your work and having you as a contributor ❤️ 🔥

[vestrel00]

@alorma, I merged the changes that you need to complete this PR 😁

Of course, I can merge this PR as it is right now if you don't have time or don't want to do the grunt work. That way, you will still appear as a contributor (which I would very much like). My plan is to include this in the next release (v0.1.10), which I'm aiming to complete by January 14. So you have about 2 weeks to work on this if you want to 😄 Let me know what you want to do 🔥

If you decide to work on this, here is a recap of what I think this logging API should look like for the initial implementation.

Using the code you already have in this PR and the code that I've merged in #147, #152, #153, and #154,

class LoggerRegistry @JvmOverloads constructor(
   private val logger: Logger = EmptyLogger(),
   private val redactMessages: Boolean = true
) {

    internal val apiListener: CrudApi.Listener = Listener()

    // Prevent consumers from invoking the listener functions by not having the registry implement
    // it directly.
    private inner class Listener : CrudApi.Listener {
        override fun onPreExecute(api: CrudApi) {
            logRedactable(api)
        }

        override fun onPostExecute(result: CrudApi.Result) {
            logRedactable(result)
        }

        private fun logRedactable(redactable: Redactable) {
            logger.log(redactable.redactedCopyOrThis(redactMessages).toString())
        }
    }
}

This registry would be the one that we would keep a reference to in the Contacts interface,

interface Contacts {
    ...
    val loggerRegistry: LoggerRegistry
    val apiListenerRegistry: CrudApiListenerRegistry
}

Hooking up the logger registry to receive CRUD API events to enable logging will be as simple as,

fun Contacts(
    ...
    loggerRegistry: LoggerRegistry = LoggerRegistry(),
    apiListenerRegistry: CrudApiListenerRegistry = CrudApiListenerRegistry()
): Contacts = ContactsImpl(
    ...
    loggerRegistry,
    apiListenerRegistry.register(loggerRegistry.apiListener)
)

Consumer initialization (e.g. in the sample app) could then look like,

val contacts = Contacts(
   ...
   loggerRegistry = LoggerRegistry(AndroidLogger(), redactMessages = !BuildConfig.DEBUG),
)

Let me know if you have any other questions. I think this is a good initial implementation 😁

Regardless of whether you choose to work on this or not, I will merge this PR! Thanks in advance! 🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥🔥

[alorma]

Thanks @vestrel00 !

Here on Spain I'm on holiday season until 6th of January 😅

Btw, I planned to open back my laptop here on 2022, so next week I will work on that!

Thanks for your work!

Happy new year's eve!

[vestrel00]

Thanks! Take your time. No rush 😁 Happy new year!

[alorma]

No redacted content:

D/Alorma: BroadQuery {
        includeBlanks: true
        rawContactsWhere: null
        groupMembershipWhere: null
        include: display_name, data1, _id, raw_contact_id, contact_id, mimetype, is_primary, is_super_primary
        searchString: 
        orderBy: display_name COLLATE NOCASE ASC
        limit: 2147483647
        offset: 0
        isRedacted: false
    }
D/Alorma: BroadQuery.Result {
        Number of contacts found: 2
        First contact: Contact(id=5, rawContacts=[RawContact(id=5, contactId=5, addresses=[], emails=[Email(id=14, rawContactId=5, contactId=5, isPrimary=false, isSuperPrimary=false, type=null, label=null, address=tempo@contacts.com, isRedacted=false)], events=[], groupMemberships=[], ims=[], name=null, nickname=null, note=null, organization=null, phones=[Phone(id=16, rawContactId=5, contactId=5, isPrimary=false, isSuperPrimary=false, type=null, label=null, number=637098531, normalizedNumber=null, isRedacted=false)], photo=null, relations=[], sipAddress=null, websites=[], customDataEntities={}, isRedacted=false)], displayNamePrimary=tempcontacts, displayNameAlt=null, lastUpdatedTimestamp=null, options=Options(id=5, starred=null, customRingtone=null, sendToVoicemail=null, isRedacted=false), photoUri=null, photoThumbnailUri=null, hasPhoneNumber=null, isRedacted=false)
        isRedacted: false
    }

Redacted content:

D/Alorma: BroadQuery {
        includeBlanks: true
        rawContactsWhere: null
        groupMembershipWhere: null
        include: display_name, data1, _id, raw_contact_id, contact_id, mimetype, is_primary, is_super_primary
        searchString: 
        orderBy: display_name COLLATE NOCASE ASC
        limit: 2147483647
        offset: 0
        isRedacted: true
    }
D/Alorma: BroadQuery.Result {
        Number of contacts found: 2
        First contact: Contact(id=5, rawContacts=[RawContact(id=5, contactId=5, addresses=[], emails=[Email(id=14, rawContactId=5, contactId=5, isPrimary=false, isSuperPrimary=false, type=null, label=null, address=******************, isRedacted=true)], events=[], groupMemberships=[], ims=[], name=null, nickname=null, note=null, organization=null, phones=[Phone(id=16, rawContactId=5, contactId=5, isPrimary=false, isSuperPrimary=false, type=null, label=null, number=*********, normalizedNumber=null, isRedacted=true)], photo=null, relations=[], sipAddress=null, websites=[], customDataEntities={}, isRedacted=true)], displayNamePrimary=************, displayNameAlt=null, lastUpdatedTimestamp=null, options=Options(id=5, starred=null, customRingtone=null, sendToVoicemail=null, isRedacted=true), photoUri=null, photoThumbnailUri=null, hasPhoneNumber=null, isRedacted=true)
        isRedacted: true
    }

Great!

[alorma]

What annoys me on this is... should the lib pass the whole string to log? or maybe we must add here an option to print less verbose logs?

Like Retrofit, or Koin, that allow different levels of logging:

• Operations: Show only operations and status, success or failure
• Info: Show operations with small recap info like type of operation, table, and results number
• Full: Show all content, as it's now

Of course, that is matter for another PR, this one can be merged as it's

[alorma]

I've updated a litte bit your idea...

I've moved the redactMessages boolean from LoggerRegistry to Logger.

This way we win some things:

API consumers won't need to know about the LoggerRegistry as it's an internal detail of the library, on how is tied to the other parts of it.

Also, we simplify the creation of Contacts allowing to pass a simple Logger on the constructor.

Maybe we must found a way to create a "Constructor" with LoggerRegistry but I have not found a way to do that, as both would have the same number of params and that collide with @JvmOverloads

[vestrel00]

@alorma, thank you so much for your contribution! It looks great!!! I'll leave some comments but there is really nothing that needs to be changed here. I can tell that you've put a lot of thought on this and I like it 👍 I will handle adding documentation and the howto page for it. Great work! Thanks again ❤️

I've moved the redactMessages boolean from LoggerRegistry to Logger.

This is really good because then individual loggers can be configured differently if we ever decide to support multiple loggers. Genius!

API consumers won't need to know about the LoggerRegistry as it's an internal detail of the library, on how is tied to the other parts of it.

I agree! It is still unfortunately exposed through Contacts but until Kotlin supports internal inside interfaces, there is nothing we can do.

Also, we simplify the creation of Contacts allowing to pass a simple Logger on the constructor.

This is also a great idea! I will do the same for the CrudApiRegistry because it's not really something that I want users to use.

Maybe we must found a way to create a "Constructor" with LoggerRegistry but I have not found a way to do that, as both would have the same number of params and that collide with @jvmoverloads

I don't see any issues with the way you've written this PR 😁

[vestrel00]

This should be a val. I'll make the change after merging this PR.

[vestrel00]

I made the update here e321874

[vestrel00]

Great idea hiding the creation of the LoggerRegistry. It does not need to be exposed to consumers at this point. We might change this in the future if we decide to support multiple loggers and configurations that apply to all loggers. But this is perfect for its current state!

[vestrel00]

I will actually also do the same for the apiListenerRegistry: CrudApiListenerRegistry = CrudApiListenerRegistry(). It does not need to be a parameter. It can be hidden.

[vestrel00]

I made the update here e321874

[vestrel00]

Very nice making the every logger instance configurable!

[vestrel00]

LGTM!

[vestrel00]

Awesome!

[vestrel00]

We don't really need to have a default value for this as we construct this elsewhere anyways.

[vestrel00]

I made the update here e321874

[vestrel00]

This logger actually overshadows the outer logger. I think I know what you are trying to do here. This whole thing can be simplified to,

class LoggerRegistry(logger: Logger = EmptyLogger()) {

    internal val apiListener: CrudApi.Listener = Listener(logger)

    // Prevent consumers from invoking the listener functions by not having the registry implement
    // it directly.
    private class Listener(private val logger: Logger) : CrudApi.Listener {
        
        override fun onPreExecute(api: CrudApi) {
            logRedactable(api)
        }

        override fun onPostExecute(result: CrudApi.Result) {
            logRedactable(result)
        }

        private fun logRedactable(redactable: Redactable) {
            logger.log(redactable.redactedCopyOrThis(logger.redactMessages).toString())
        }
    }
}

[vestrel00]

I made the update here e321874