feat(gatsby-source-drupal): Add tracing for full/delta fetches and http requests

packages/gatsby-source-drupal/package.json

@@ -12,6 +12,7 @@
     "bluebird": "^3.7.2",
     "body-parser": "^1.19.0",
     "fastq": "^1.11.1",
+    "opentracing": "^0.14.4",
     "gatsby-source-filesystem": "^3.14.0-next.2",
     "got": "^11.8.2",
     "http2-wrapper": "^2.0.5",

packages/gatsby-source-drupal/src/__tests__/index.js

@@ -553,7 +553,8 @@ describe(`gatsby-source-drupal`, () => {
         expect(reporter.activityTimer).toHaveBeenCalledTimes(1)
         expect(reporter.activityTimer).toHaveBeenNthCalledWith(
           1,
-          `Fetch all data from Drupal`
+          `Fetch all data from Drupal`,
+          { parentSpan: undefined }
         )
 
         expect(activity.start).toHaveBeenCalledTimes(1)
@@ -576,11 +577,13 @@ describe(`gatsby-source-drupal`, () => {
         expect(reporter.activityTimer).toHaveBeenCalledTimes(2)
         expect(reporter.activityTimer).toHaveBeenNthCalledWith(
           1,
-          `Fetch all data from Drupal`
+          `Fetch all data from Drupal`,
+          { parentSpan: undefined }
         )
         expect(reporter.activityTimer).toHaveBeenNthCalledWith(
           2,
-          `Remote file download`
+          `Remote file download`,
+          { parentSpan: undefined }
         )
 
         expect(activity.start).toHaveBeenCalledTimes(2)
@@ -639,7 +642,8 @@ describe(`gatsby-source-drupal`, () => {
         expect(reporter.activityTimer).toHaveBeenCalledTimes(1)
         expect(reporter.activityTimer).toHaveBeenNthCalledWith(
           1,
-          `Fetch incremental changes from Drupal`
+          `Fetch incremental changes from Drupal`,
+          { parentSpan: {} }
         )
 
         expect(activity.start).toHaveBeenCalledTimes(1)

packages/gatsby-source-drupal/src/gatsby-node.js

@@ -3,17 +3,13 @@ const _ = require(`lodash`)
 const urlJoin = require(`url-join`)
 import HttpAgent from "agentkeepalive"
 // const http2wrapper = require(`http2-wrapper`)
+const opentracing = require(`opentracing`)
 
 const { HttpsAgent } = HttpAgent
 
 const { setOptions, getOptions } = require(`./plugin-options`)
 
-const {
-  nodeFromData,
-  downloadFile,
-  isFileNode,
-  createNodeIdWithVersion,
-} = require(`./normalize`)
+const { nodeFromData, downloadFile, isFileNode } = require(`./normalize`)
 const {
   handleReferences,
   handleWebhookUpdate,
@@ -31,6 +27,13 @@ let apiRequestCount = 0
 let initialSourcing = true
 let globalReporter
 async function worker([url, options]) {
+  const tracer = opentracing.globalTracer()
+  const httpSpan = tracer.startSpan(`http.get`, {
+    childOf: options.parentSpan,
+  })
+  httpSpan.setTag(`http.url`, url)
+  httpSpan.setTag(`plugin`, `gatsby-source-drupal`)
+
   // Log out progress during the initial sourcing.
   if (initialSourcing) {
     apiRequestCount += 1
@@ -48,13 +51,23 @@ async function worker([url, options]) {
     }
   }
 
-  return got(url, {
+  const response = await got(url, {
     agent,
     cache: false,
     // request: http2wrapper.auto,
     // http2: true,
     ...options,
   })
+
+  httpSpan.setTag(`http.status_code`, response.statusCode)
+  httpSpan.setTag(`http.status_message`, response.statusMessage)
+  httpSpan.setTag(`http.method`, `GET`)
+  httpSpan.setTag(`net.peer_ip`, response.ip)
+  httpSpan.setTag(`http.response_content_length`, response.rawBody?.length)
+
+  httpSpan.finish()
+
+  return response
 }
 
 const requestQueue = require(`fastq`).promise(worker, 20)
@@ -97,6 +110,8 @@ exports.sourceNodes = async (
   },
   pluginOptions
 ) => {
+  const tracer = opentracing.globalTracer()
+
   globalReporter = reporter
   const {
     baseUrl,
@@ -213,6 +228,12 @@ ${JSON.stringify(webhookBody, null, 4)}
   }
 
   if (fastBuilds) {
+    const fastBuildsSpan = tracer.startSpan(`sourceNodes.fetch`, {
+      childOf: parentSpan,
+    })
+    fastBuildsSpan.setTag(`plugin`, `gatsby-source-drupal`)
+    fastBuildsSpan.setTag(`sourceNodes.fetch.type`, `delta`)
+
     const lastFetched =
       store.getState().status.plugins?.[`gatsby-source-drupal`]?.lastFetched ??
       0
@@ -222,7 +243,8 @@ ${JSON.stringify(webhookBody, null, 4)}
     )
 
     const drupalFetchIncrementalActivity = reporter.activityTimer(
-      `Fetch incremental changes from Drupal`
+      `Fetch incremental changes from Drupal`,
+      { parentSpan: fastBuildsSpan }
     )
     let requireFullRebuild = false
 
@@ -238,6 +260,7 @@ ${JSON.stringify(webhookBody, null, 4)}
           headers,
           searchParams: params,
           responseType: `json`,
+          parentSpan: fastBuildsSpan,
         },
       ])
 
@@ -251,12 +274,31 @@ ${JSON.stringify(webhookBody, null, 4)}
         setPluginStatus({ lastFetched: res.body.timestamp })
         requireFullRebuild = true
       } else {
+        const touchNodesSpan = tracer.startSpan(`sourceNodes.touchNodes`, {
+          childOf: fastBuildsSpan,
+        })
+        touchNodesSpan.setTag(`plugin`, `gatsby-source-drupal`)
+
         // Touch nodes so they are not garbage collected by Gatsby.
+        let touchCount = 0
         getNodes().forEach(node => {
           if (node.internal.owner === `gatsby-source-drupal`) {
+            touchCount += 1
             touchNode(node)
           }
         })
+        touchNodesSpan.setTag(`sourceNodes.touchNodes.count`, touchCount)
+        touchNodesSpan.finish()
+
+        const createNodesSpan = tracer.startSpan(`sourceNodes.createNodes`, {
+          childOf: parentSpan,
+        })
+        createNodesSpan.setTag(`plugin`, `gatsby-source-drupal`)
+        createNodesSpan.setTag(`sourceNodes.fetch.type`, `delta`)
+        createNodesSpan.setTag(
+          `sourceNodes.createNodes.count`,
+          res.body.entities?.length
+        )
 
         // Process sync data from Drupal.
         const nodesToSync = res.body.entities
@@ -298,23 +340,34 @@ ${JSON.stringify(webhookBody, null, 4)}
           }
         }
 
+        createNodesSpan.finish()
         setPluginStatus({ lastFetched: res.body.timestamp })
       }
     } catch (e) {
       gracefullyRethrow(drupalFetchIncrementalActivity, e)
+
+      drupalFetchIncrementalActivity.end()
+      fastBuildsSpan.finish()
       return
     }
 
     drupalFetchIncrementalActivity.end()
+    fastBuildsSpan.finish()
 
     if (!requireFullRebuild) {
       return
     }
   }
 
   const drupalFetchActivity = reporter.activityTimer(
-    `Fetch all data from Drupal`
+    `Fetch all data from Drupal`,
+    { parentSpan }
   )
+  const fullFetchSpan = tracer.startSpan(`sourceNodes.fetch`, {
+    childOf: parentSpan,
+  })
+  fullFetchSpan.setTag(`plugin`, `gatsby-source-drupal`)
+  fullFetchSpan.setTag(`sourceNodes.fetch.type`, `full`)
 
   // Fetch articles.
   reporter.info(`Starting to fetch all data from Drupal`)
@@ -332,6 +385,7 @@ ${JSON.stringify(webhookBody, null, 4)}
         headers,
         searchParams: params,
         responseType: `json`,
+        parentSpan: fullFetchSpan,
       },
     ])
     allData = await Promise.all(
@@ -380,6 +434,7 @@ ${JSON.stringify(webhookBody, null, 4)}
                 password: basicAuth.password,
                 headers,
                 responseType: `json`,
+                parentSpan: fullFetchSpan,
               },
             ])
           } catch (error) {
@@ -479,6 +534,13 @@ ${JSON.stringify(webhookBody, null, 4)}
   }
 
   drupalFetchActivity.end()
+  fullFetchSpan.finish()
+
+  const createNodesSpan = tracer.startSpan(`sourceNodes.createNodes`, {
+    childOf: parentSpan,
+  })
+  createNodesSpan.setTag(`plugin`, `gatsby-source-drupal`)
+  createNodesSpan.setTag(`sourceNodes.fetch.type`, `full`)
 
   const nodes = new Map()
 
@@ -492,6 +554,8 @@ ${JSON.stringify(webhookBody, null, 4)}
     })
   })
 
+  createNodesSpan.setTag(`sourceNodes.createNodes.count`, nodes.size)
+
   // second pass - handle relationships and back references
   nodes.forEach(node => {
     handleReferences(node, {
@@ -510,8 +574,10 @@ ${JSON.stringify(webhookBody, null, 4)}
     const fileNodes = [...nodes.values()].filter(isFileNode)
 
     if (fileNodes.length) {
-      const downloadingFilesActivity =
-        reporter.activityTimer(`Remote file download`)
+      const downloadingFilesActivity = reporter.activityTimer(
+        `Remote file download`,
+        { parentSpan }
+      )
       downloadingFilesActivity.start()
       try {
         await asyncPool(concurrentFileRequests, fileNodes, async node => {
@@ -545,6 +611,7 @@ ${JSON.stringify(webhookBody, null, 4)}
   // We're now done with the initial sourcing.
   initialSourcing = false
 
+  createNodesSpan.finish()
   return
 }
 

packages/gatsby/src/utils/api-runner-node.js

@@ -375,6 +375,7 @@ const runAPI = async (plugin, api, args, activity) => {
     const apiCallArgs = [
       {
         ...args,
+        parentSpan: pluginSpan,
         basePath: pathPrefix,
         pathPrefix: publicPath,
         actions,