Merge pull request #735 from gre/debug-network

Add DEBUG_NETWORK for logging http queries

src/api/network.js

@@ -9,12 +9,13 @@ export const LedgerAPIErrorWithMessage = createCustomErrorClass('LedgerAPIErrorW
 export const LedgerAPIError = createCustomErrorClass('LedgerAPIError')
 export const NetworkDown = createCustomErrorClass('NetworkDown')
 
-const userFriendlyError = <A>(p: Promise<A>): Promise<A> =>
+const userFriendlyError = <A>(p: Promise<A>, { url, method, startTime }): Promise<A> =>
   p.catch(error => {
+    let errorToThrow
     if (error.response) {
       // The request was made and the server responded with a status code
       // that falls out of the range of 2xx
-      const { data } = error.response
+      const { data, status } = error.response
       if (data && typeof data.error === 'string') {
         let msg = data.error || data.message
         if (typeof msg === 'string') {
@@ -32,19 +33,28 @@ const userFriendlyError = <A>(p: Promise<A>): Promise<A> =>
           } catch (e) {
             logger.warn("can't parse server result", e)
           }
-
           if (msg && msg[0] !== '<') {
-            throw new LedgerAPIErrorWithMessage(msg)
+            errorToThrow = new LedgerAPIErrorWithMessage(msg)
+          }
         }
       }
+      if (!errorToThrow) {
+        errorToThrow = new LedgerAPIError(`LedgerAPIError ${status}`, { status })
       }
-      const { status } = error.response
+      logger.networkError({
-      logger.log('Ledger API: HTTP status', status, 'data: ', error.response.data)
+        status,
-      throw new LedgerAPIError(`LedgerAPIError ${status}`, { status })
+        url,
+        method,
+        error: errorToThrow.message,
+        responseTime: Date.now() - startTime,
+      })
+      throw errorToThrow
     } else if (error.request) {
-      // The request was made but no response was received
+      logger.networkDown({
-      // `error.request` is an instance of XMLHttpRequest in the browser and an instance of
+        url,
-      // http.ClientRequest in node.js
+        method,
+        responseTime: Date.now() - startTime,
+      })
       throw new NetworkDown()
     }
     throw error
@@ -62,7 +72,20 @@ let implementation = (arg: Object) => {
   } else {
     promise = axios(arg)
   }
-  return userFriendlyError(promise)
+  const meta = {
+    url: arg.url,
+    method: arg.method,
+    startTime: Date.now(),
+  }
+  logger.network(meta)
+  promise.then(response => {
+    logger.networkSucceed({
+      ...meta,
+      status: response.status,
+      responseTime: Date.now() - meta.startTime,
+    })
+  })
+  return userFriendlyError(promise, meta)
 }
 
 export const setImplementation = (impl: *) => {

src/config/constants.js

@@ -78,6 +78,7 @@ export const HIGHLIGHT_I18N = boolFromEnv('HIGHLIGHT_I18N')
 export const DISABLE_ACTIVITY_INDICATORS = boolFromEnv('DISABLE_ACTIVITY_INDICATORS')
 export const EXPERIMENTAL_CENTER_MODAL = boolFromEnv('EXPERIMENTAL_CENTER_MODAL')
 export const EXPERIMENTAL_FIRMWARE_UPDATE = boolFromEnv('EXPERIMENTAL_FIRMWARE_UPDATE')
+export const EXPERIMENTAL_HTTP_ON_RENDERER = boolFromEnv('EXPERIMENTAL_HTTP_ON_RENDERER')
 
 // Other constants
 

src/internals/index.js

@@ -4,7 +4,7 @@ import logger from 'logger'
 import uuid from 'uuid/v4'
 import { setImplementation } from 'api/network'
 import sentry from 'sentry/node'
-import { DEBUG_NETWORK } from 'config/constants'
+import { EXPERIMENTAL_HTTP_ON_RENDERER } from 'config/constants'
 import { serializeError } from 'helpers/errors'
 
 require('../env')
@@ -17,7 +17,7 @@ let sentryEnabled = process.env.INITIAL_SENTRY_ENABLED || false
 
 sentry(() => sentryEnabled, process.env.SENTRY_USER_ID)
 
-if (DEBUG_NETWORK) {
+if (EXPERIMENTAL_HTTP_ON_RENDERER) {
   setImplementation(networkArg => {
     const id = uuid()
     return new Promise((resolve, reject) => {

src/logger.js

@@ -10,6 +10,7 @@
  */
 
 import {
+  DEBUG_NETWORK,
   DEBUG_COMMANDS,
   DEBUG_DB,
   DEBUG_ACTION,
@@ -62,6 +63,7 @@ const logRedux = !__DEV__ || DEBUG_ACTION
 const logTabkey = !__DEV__ || DEBUG_TAB_KEY
 const logLibcore = !__DEV__ || DEBUG_LIBCORE
 const logWS = !__DEV__ || DEBUG_WS
+const logNetwork = !__DEV__ || DEBUG_NETWORK
 
 export default {
   onCmd: (type: string, id: string, spentTime: number, data?: any) => {
@@ -128,6 +130,70 @@ export default {
     addLog('action', `🛠  ${level}: ${msg}`)
   },
 
+  network: ({ method, url }: { method: string, url: string }) => {
+    const log = `➡📡  ${method} ${url}`
+    if (logNetwork) {
+      console.log(log)
+    }
+    addLog('network', log)
+  },
+
+  networkSucceed: ({
+    method,
+    url,
+    status,
+    responseTime,
+  }: {
+    method: string,
+    url: string,
+    status: number,
+    responseTime: number,
+  }) => {
+    const log = `✔📡  HTTP ${status} ${method} ${url} – finished in ${responseTime.toFixed(0)}ms`
+    if (logNetwork) {
+      console.log(log)
+    }
+    addLog('network-response', log)
+  },
+
+  networkError: ({
+    method,
+    url,
+    status,
+    error,
+    responseTime,
+  }: {
+    method: string,
+    url: string,
+    status: number,
+    error: string,
+    responseTime: number,
+  }) => {
+    const log = `✖📡  HTTP ${status} ${method} ${url} – ${error} – failed after ${responseTime.toFixed(
+      0,
+    )}ms`
+    if (logNetwork) {
+      console.log(log)
+    }
+    addLog('network-error', log)
+  },
+
+  networkDown: ({
+    method,
+    url,
+    responseTime,
+  }: {
+    method: string,
+    url: string,
+    responseTime: number,
+  }) => {
+    const log = `✖📡  NETWORK DOWN – ${method} ${url} – after ${responseTime.toFixed(0)}ms`
+    if (logNetwork) {
+      console.log(log)
+    }
+    addLog('network-down', log)
+  },
+
   // General functions in case the hooks don't apply
 
   log: (...args: any) => {