feat: TEMP ADD PERF LOGS

Author: Ldoppea

packages/cozy-client/src/CozyClient.js

@@ -474,6 +474,7 @@ class CozyClient {
   }
 
   async _login(options) {
+    console.log('🟥 login 1')
     this.emit('beforeLogin')
 
     this.registerClientOnLinks()
@@ -487,18 +488,21 @@ class CozyClient {
       }
     }
 
+    console.log('🟥 login 2')
     for (const link of this.links) {
       if (link.onLogin) {
         await link.onLogin()
       }
     }
+    console.log('🟥 login 3')
 
     this.isLogged = true
     this.isRevoked = false
 
     if (this.stackClient instanceof OAuthClient) {
       await this.loadInstanceOptionsFromStack()
     }
+    console.log('🟥 login 4')
 
     this.emit('login')
   }
@@ -926,6 +930,8 @@ client.query(Q('io.cozy.bills'))`)
    * @returns {Promise<import("./types").QueryResult>}
    */
   async query(queryDefinition, { update, executeFromStore, ...options } = {}) {
+    console.log('⏰query 1')
+    const beginPrepare = performance.now()
     const markQuery = this.performanceApi.mark(
       `client.query(${queryDefinition.doctype})`
     )
@@ -976,21 +982,28 @@ client.query(Q('io.cozy.bills'))`)
               executeQueryFromState(this.store.getState(), queryDefinition)
             )
         : () => this.requestQuery(queryDefinition, options)
+      const endPrepare = performance.now()
+      console.log('🍺 CozyClient query prepare took', (endPrepare - beginPrepare), 'ms')
+      const beginExec = performance.now()
       const response = await this._promiseCache.exec(requestFn, () =>
         stringify(queryDefinition)
       )
+      const endExec = performance.now()
+      console.log('🍺 CozyClient query exec took', (endExec - beginExec), 'ms')
 
+      const beginReceive = performance.now()
+      const queryReceivedResult = receiveQueryResult(queryId, response, {
+        update,
+        backgroundFetching
+      })
+      const endReceive = performance.now()
+      console.log('🍺 CozyClient query receiveQueryResult took', (endReceive - beginReceive), 'ms')
+      const beginDispatch = performance.now()
       this.dispatch(
-        receiveQueryResult(queryId, response, {
-          update,
-          backgroundFetching
-        })
+        queryReceivedResult
       )
-      this.performanceApi.measure({
-        markName: markQuery,
-        measureName: `${markQuery} success`,
-        color: 'primary'
-      })
+      const endDispatch = performance.now()
+      console.log('🍺 CozyClient query Dispatch took', (endDispatch - beginDispatch), 'ms')
       return response
     } catch (error) {
       this.performanceApi.measure({
@@ -1025,10 +1038,14 @@ client.query(Q('io.cozy.bills'))`)
       options.as || this.queryIdGenerator.generateId(queryDefinition)
     const mergedOptions = { ...options, as: queryId }
     try {
+      const begin = performance.now()
       let resp = await this.query(queryDefinition, mergedOptions)
+      const end = performance.now()
+      console.log('🍺 first query took', (end - begin), 'ms')
       const documents = resp.data
 
       while (resp && resp.next) {
+        console.log('🍺 while')
         if (resp.bookmark) {
           resp = await this.query(
             queryDefinition.offsetBookmark(resp.bookmark),
@@ -1046,6 +1063,7 @@ client.query(Q('io.cozy.bills'))`)
         }
         documents.push(...resp.data)
       }
+      console.log('🍺 return docs')
       return documents
     } catch (e) {
       logger.log(`queryAll error for ${e.toString()}`)
@@ -1111,17 +1129,27 @@ client.query(Q('io.cozy.bills'))`)
    * @returns {Promise<import("./types").ClientResponse>}
    */
   async requestQuery(definition, options) {
+    const begin = performance.now()
     const mainResponse = await this.chain.request(definition, options)
+    const end = performance.now()
+    console.log('🛋️ CozyClient chain.request took', (end - begin), 'ms')
 
+    const begin2 = performance.now()
     await this.persistVirtualDocuments(definition, mainResponse.data)
+    const end2 = performance.now()
+    console.log('🛋️ CozyClient persistVirtualDocuments took', (end2 - begin2), 'ms')
 
     if (!definition.includes) {
+      console.log('🛋️ CozyClient return no-includes')
       return mainResponse
     }
+    const begin3 = performance.now()
     const withIncluded = await this.fetchRelationships(
       mainResponse,
       this.getIncludesRelationships(definition)
     )
+    const end3 = performance.now()
+    console.log('🛋️ CozyClient fetchRelationships took', (end3 - begin3), 'ms')
     return withIncluded
   }
 
@@ -1188,6 +1216,7 @@ client.query(Q('io.cozy.bills'))`)
     }
 
     if ((!document.meta?.rev && !document._rev) || enforce) {
+      console.log('🚨🚨🚨🚨 PERSIST')
       await this.chain.persistCozyData(document)
     }
   }
@@ -1814,12 +1843,20 @@ instantiation of the client.`
    * @returns {Promise<void>}
    */
   async loadInstanceOptionsFromStack() {
+    console.log('🔰 loadInstanceOptionsFromStack 1')
     const results = await Promise.all([
       this.query(
         Q('io.cozy.settings').getById('io.cozy.settings.capabilities')
-      ),
-      this.query(Q('io.cozy.settings').getById('io.cozy.settings.instance'))
+      ).catch(error => {
+        console.log(error)
+        throw error
+      }),
+      this.query(Q('io.cozy.settings').getById('io.cozy.settings.instance')).catch(error => {
+        console.log(error)
+        throw error
+      })
     ])
+    console.log('🔰 loadInstanceOptionsFromStack 2')
 
     const { data: capabilitiesData } = results[0]
     const { data: instanceData } = results[1]

packages/cozy-client/src/StackLink.js

@@ -90,7 +90,9 @@ export default class StackLink extends CozyLink {
   }
 
   async request(operation, options, result, forward) {
+    console.log('stack request')
     if (!options?.forceStack && this.isOnline && !(await this.isOnline())) {
+      console.log('forward')
       return forward(operation, options)
     }
 
@@ -108,6 +110,7 @@ export default class StackLink extends CozyLink {
   }
 
   async persistCozyData(data, forward) {
+    console.log('persistCozyData from StackLink')
     return forward(data)
   }
   /**

packages/cozy-client/src/WebFlagshipLink.js

@@ -23,6 +23,7 @@ export default class WebFlagshipLink extends CozyLink {
   }
 
   async persistCozyData(data, forward) {
+    console.log('persistCozyData from WebFlagshipLink')
     // Persist data should do nothing here as data is already persisted on Flagship side
     return
   }

packages/cozy-client/src/hooks/utils.js

@@ -10,6 +10,7 @@
  * @returns
  */
 export const equalityCheckForQuery = (queryResA, queryResB) => {
+  // console.log('🌈 Equality check for query')
   //console.log('Call equality check : ', queryResA, queryResB)
   if (queryResA === queryResB) {
     // Referential equality

packages/cozy-client/src/store/documents.js

@@ -14,6 +14,7 @@ import { isReceivingMutationResult } from './mutations'
 import { properId } from './helpers'
 
 const storeDocument = (state, document) => {
+  console.log('🏪 storeDocument')
   const type = document._type
   if (!type) {
     if (process.env.NODE_ENV !== 'production') {
@@ -50,6 +51,7 @@ export const mergeDocumentsWithRelationships = (
   prevDocument = {},
   nextDocument = {}
 ) => {
+  console.log('🏪 mergeDocumentsWithRelationships')
   /**
    * @type {import("../types").CozyClientDocument}
    */
@@ -69,6 +71,8 @@ export const mergeDocumentsWithRelationships = (
 
 // reducer
 const documents = (state = {}, action) => {
+  // console.log('🏪 documents reducer')
+  // const begin = performance.now()
   if (!isReceivingData(action) && !isReceivingMutationResult(action)) {
     return state
   }
@@ -80,28 +84,40 @@ const documents = (state = {}, action) => {
   ) {
     const docId = action.definition.document._id
     const _type = action.definition.document._type
+
+    // const end = performance.now()
+    // console.log('🏪 documents reducer 1 took', (end - begin), 'ms')
     return {
       ...state,
       [_type]: omit(state[_type], docId)
     }
   }
 
   const { data, included } = action.response
-  if (!data || (Array.isArray(data) && data.length === 0)) return state
+  if (!data || (Array.isArray(data) && data.length === 0)) {
+    // const end = performance.now()
+    // console.log('🏪 documents reducer 2 took', (end - begin), 'ms')
+    return state
+  }
 
   const updatedStateWithIncluded = included
     ? included.reduce(storeDocument, state)
     : state
   if (!Array.isArray(data)) {
+    // const end = performance.now()
+    // console.log('🏪 documents reducer 3 took', (end - begin), 'ms')
     return storeDocument(updatedStateWithIncluded, data)
   }
+  // const end = performance.now()
+  // console.log('🏪 documents reducer 4 took', (end - begin), 'ms')
   return extractAndMergeDocument(data, updatedStateWithIncluded)
 }
 
 export default documents
 
 // selector
 export const getDocumentFromSlice = (state = {}, doctype, id) => {
+  // console.log('🏪 getDocumentFromSlice')
   if (!doctype) {
     throw new Error(
       'getDocumentFromSlice: Cannot retrieve document with undefined doctype'
@@ -133,6 +149,7 @@ export const getDocumentFromSlice = (state = {}, doctype, id) => {
 }
 
 export const getCollectionFromSlice = (state = {}, doctype) => {
+  // console.log('🏪 getCollectionFromSlice')
   if (!doctype) {
     throw new Error(
       'getDocumentFromSlice: Cannot retrieve document with undefined doctype'

packages/cozy-client/src/store/queries.js

@@ -140,6 +140,7 @@ const query = (
   action,
   documents
 ) => {
+  // console.log('🏪 query', action.type)
   switch (action.type) {
     case INIT_QUERY:
       if (
@@ -172,12 +173,15 @@ const query = (
         fetchStatus: 'loading'
       }
     case RECEIVE_QUERY_RESULT: {
+      // const begin = performance.now()
       const markName = performanceApi.mark('RECEIVE_QUERY_RESULT')
       const response = action.response
       // Data can be null when we get a 404 not found
       // see Collection.get()
       // but we still need to update the fetchStatus.
       if (!response.data) {
+        // const end = performance.now()
+        // console.log('🏪 RECEIVE_QUERY_RESULT with no data took', (end - begin), 'ms')
         performanceApi.measure({
           markName: markName,
           measureName: `${markName} with no data`,
@@ -204,6 +208,8 @@ const query = (
       }
 
       if (!Array.isArray(response.data)) {
+        // const end = performance.now()
+        // console.log('🏪 RECEIVE_QUERY_RESULT with object took', (end - begin), 'ms')
         performanceApi.measure({
           markName: markName,
           measureName: `${markName} with object`,
@@ -227,6 +233,8 @@ const query = (
           measureName: `${markName} with background fetching`,
           category: 'CozyClientStore'
         })
+        // const end = performance.now()
+        // console.log('🏪 RECEIVE_QUERY_RESULT with background fetching took', (end - begin), 'ms')
         return {
           ...state,
           ...common,
@@ -243,6 +251,8 @@ const query = (
         fetchedPagesCount
       })
 
+      // const end = performance.now()
+      // console.log('🏪 RECEIVE_QUERY_RESULT default took', (end - begin), 'ms')
       performanceApi.measure({
         markName: markName,
         measureName: `${markName} default`,