React.JS Next.JS SPDY No data in elastic apm for nodejs application #3413

khteh · 2023-06-10T08:20:52Z

Describe the bug

I put the following code snippet at the top of the first file loaded server.js:

var apm = require('elastic-apm-node').start({
  // Override service name from package.json
  // Allowed characters: a-z, A-Z, 0-9, -, _, and space
  serviceName: 'my-apm',
  // Set custom APM Server URL (default: http://127.0.0.1:8200)
  serverUrl: 'https://my-apm-http:8200',
  // Only activate the agent if it's running in production
  active: process.env.NODE_ENV === 'production',
  verifyServerCert: false
})

However, there is no data at all in kibana 8.8.0. I have also tried putting this config in elastic-apm-node.js but to no avail.

To Reproduce

Steps to reproduce the behavior:

Use this config '...'
Then call '....'
Then do '....'
See error

Expected behavior

Environment (please complete the following information)

OS: [e.g. Linux] Ubuntu 23.04
Node.js version: v19.8.1
APM Server version: 8.8.0
Agent version: 3.45.0

How are you starting the agent? (please tick one of the boxes)

Calling agent.start() directly (e.g. require('elastic-apm-node').start(...))
Requiring elastic-apm-node/start from within the source code
Starting node with -r elastic-apm-node/start

Additional context

Agent config options:

Click to expand

replace this line with your agent config options

package.json dependencies:

Click to expand

replace this line with your dependencies section from package.json

The text was updated successfully, but these errors were encountered:

trentm · 2023-06-12T21:45:47Z

@khteh Thanks for the question.

The best way to try to confirm what is happening would be to get trace-level logging from the APM agent as it is running. This can be done by setting the ELASTIC_APM_LOG_LEVEL=trace environment variable (or adding logLevel: 'trace' to your config) and re-running.

Here are some guesses as to what the issue might be and questions to try to find the issue:

The support for Next.js attempts to instrument the Next server. Depending how you are running your Next.js application, using require('elastic-apm-node').start({...}) at the top of your "server.js" might be too late, because the Next server will have already initialized before calling your "server.js". https://www.elastic.co/guide/en/apm/agent/nodejs/master/nextjs.html suggests that for Next.js you start the APM agent using the --require elastic-apm-node/start.js argument to node.
What version of Next.js are you using? The current elastic-apm-node does not support the very latest version of Next.js. Currently versions >=11.1.0 <13.3.0 are supported. See https://www.elastic.co/guide/en/apm/agent/nodejs/current/supported-technologies.html#compatibility-frameworks
How are you running your Next.js application? Are you using the Next.js server (i.e. running next start or next dev)?
You mention SPDY. We have not tested Next.js instrumentation using HTTP/2. It is possible there is some different behaviour here that elastic-apm-node does not handle.

khteh · 2023-06-13T02:31:53Z

I am using Next 13.2.4. Adding this to the Dockerfile:

          env:
            - name: NODE_ENV
              value: "production"
            - name: NODE_OPTIONS
              value: --max-old-space-size=16384 --require elastic-apm-node/start.js

results in

{"log.level":"error","@timestamp":"2023-06-13T02:30:01.290Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"APM Server transport error: error fetching APM Server version: connect ECONNREFUSED 127.0.0.1:8200"}
{"log.level":"error","@timestamp":"2023-06-13T02:30:01.291Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"APM Server transport error (ECONNREFUSED): connect ECONNREFUSED 127.0.0.1:8200"}
{"log.level":"error","@timestamp":"2023-06-13T02:30:01.305Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"APM Server transport error (ECONNREFUSED): connect ECONNREFUSED 127.0.0.1:8200"}
{"log.level":"info","@timestamp":"2023-06-13T02:30:01.306Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"Sending error to Elastic APM: {\"id\":\"cbc1c6588ed0c2ef01ebc1d642e753a0\"}"}
{"log.level":"error","@timestamp":"2023-06-13T02:30:01.308Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"APM Server transport error (ECONNREFUSED): connect ECONNREFUSED 127.0.0.1:8200"}

This is how I start the application in the container:

ENTRYPOINT ["node", "--trace-warnings", "--trace-deprecation", "--experimental-specifier-resolution=node", "server.js"]

khteh · 2023-06-13T06:08:47Z

Where to check the trace? I don't see anything in APM > Logs and there is nothing in the Traces tab.

trentm · 2023-06-13T19:54:26Z

Where to check the trace?

The trace/debug logs I was referring to are printed to stdout by the APM agent. They aren't automatically sent to APM server to be visible in the Kibana APM app. Given that you are running your app in Docker, then you should be able to see the logs by running docker logs NAME-OF-YOUR-APP-CONTAINER.

results in

{"log.level":"error","@timestamp":"2023-06-13T02:30:01.290Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"APM Server transport error: error fetching APM Server version: connect ECONNREFUSED 127.0.0.1:8200"}
...

That error log from the APM agent shows that the serverUrl configuration setting is not set -- it is using the default http://127.0.0.1:8200. There is no local APM server running at 127.0.0.1:8200, so the APM agent isn't able to send any trace data.

khteh · 2023-06-14T02:22:51Z

This is all that I see in the log:

[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-14T02:22:00.482Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"b43a099f3306a4111f327ecf1df4a2d0","timeline":[[10001.410907,"completePart gzipStream",null],[10001.599615,"completePart intakeReq",null],[10002.673543,"completePart intakeRes",null]],"bytesWritten":731,"backoffDelayMs":0,"ecs":{"version":"1.6.0"},"message":"conclude intake request: success"}

The serverUrl is configured in server.js which is in the startup command of the application.

trentm · 2023-06-14T20:34:38Z

This is all that I see in the log:
[buyerportal-0 buyerportal] {"log.level":"trace"...

Okay, so you are getting trace logs. Can you please send the full log output that covers a time period when your buyerportal container has received some requests?

khteh · 2023-06-16T06:58:35Z

[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","ecs":{"version":"1.6.0"},"message":"gzipStream \"finish\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","timeout":10000,"ecs":{"version":"1.6.0"},"message":"start intakeResTimer"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","ecs":{"version":"1.6.0"},"message":"gzipStream \"end\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart gzipStream"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","ecs":{"version":"1.6.0"},"message":"intakeReq \"finish\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart intakeReq"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","statusCode":202,"reqFinished":true,"ecs":{"version":"1.6.0"},"message":"intakeReq \"response\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","ecs":{"version":"1.6.0"},"message":"intakeRes \"end\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart intakeRes"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:25.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"64e75b8cffa6419bdaa07ccfac279fa5","timeline":[[10001.564759,"completePart gzipStream",null],[10001.695262,"completePart intakeReq",null],[10002.999542,"completePart intakeRes",null]],"bytesWritten":736,"backoffDelayMs":0,"ecs":{"version":"1.6.0"},"message":"conclude intake request: success"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:38.714Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","ecs":{"version":"1.6.0"},"message":"intake request start"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:38.714Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","fullTimeMs":1.457031,"numEvents":1,"numBytes":921,"ecs":{"version":"1.6.0"},"message":"_write: encode object"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:38.715Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","ecs":{"version":"1.6.0"},"message":"intakeReq \"socket\": unref it"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:45.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","ecs":{"version":"1.6.0"},"message":"intake request start"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:45.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","fullTimeMs":1.387292,"numEvents":1,"numBytes":921,"ecs":{"version":"1.6.0"},"message":"_write: encode object"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:45.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","ecs":{"version":"1.6.0"},"message":"intakeReq \"socket\": unref it"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.715Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","ecs":{"version":"1.6.0"},"message":"gzipStream \"finish\""}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.716Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","timeout":10000,"ecs":{"version":"1.6.0"},"message":"start intakeResTimer"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.716Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","ecs":{"version":"1.6.0"},"message":"gzipStream \"end\""}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.716Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart gzipStream"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.716Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","ecs":{"version":"1.6.0"},"message":"intakeReq \"finish\""}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.716Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart intakeReq"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.717Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","statusCode":202,"reqFinished":true,"ecs":{"version":"1.6.0"},"message":"intakeReq \"response\""}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.717Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","ecs":{"version":"1.6.0"},"message":"intakeRes \"end\""}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.717Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart intakeRes"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:48.717Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"007a5566624710d7bab45987c324c77e","timeline":[[10002.567412,"completePart gzipStream",null],[10002.887287,"completePart intakeReq",null],[10003.521677,"completePart intakeRes",null]],"bytesWritten":735,"backoffDelayMs":0,"ecs":{"version":"1.6.0"},"message":"conclude intake request: success"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","ecs":{"version":"1.6.0"},"message":"gzipStream \"finish\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","timeout":10000,"ecs":{"version":"1.6.0"},"message":"start intakeResTimer"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","ecs":{"version":"1.6.0"},"message":"gzipStream \"end\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart gzipStream"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","ecs":{"version":"1.6.0"},"message":"intakeReq \"finish\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.762Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart intakeReq"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","statusCode":202,"reqFinished":true,"ecs":{"version":"1.6.0"},"message":"intakeReq \"response\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","ecs":{"version":"1.6.0"},"message":"intakeRes \"end\""}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","concluded":false,"ecs":{"version":"1.6.0"},"message":"completePart intakeRes"}
[buyerportal-1 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:57:55.764Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"f73a72929c656f6c976983f0c2b4f6ea","timeline":[[10001.761449,"completePart gzipStream",null],[10001.8982,"completePart intakeReq",null],[10003.265764,"completePart intakeRes",null]],"bytesWritten":741,"backoffDelayMs":0,"ecs":{"version":"1.6.0"},"message":"conclude intake request: success"}
[buyerportal-0 buyerportal] {"log.level":"debug","@timestamp":"2023-06-16T06:57:57.474Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"no active transaction found - cannot build new span"}
[buyerportal-0 buyerportal] {"log.level":"trace","@timestamp":"2023-06-16T06:58:08.715Z","log":{"logger":"elastic-apm-node"},"event.module":"apmclient","reqId":"15e3f453b9fba96ec1a49223921e41a1","ecs":{"version":"1.6.0"},"message":"intake request start"}

trentm · 2023-06-16T23:12:08Z

@khteh Thanks. The one line in there that is helpful is this one:

[buyerportal-0 buyerportal] {"log.level":"debug","@timestamp":"2023-06-16T06:57:57.474Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"no active transaction found - cannot build new span"}

It shows that the APM agent instrumented some activity in your code that would have generated a span, but it didn't because there is no active "transaction". Typically a transaction is created automatically for an incoming HTTP request -- if your app implements an HTTP server. (More details on the types of transactions here: https://www.elastic.co/guide/en/apm/guide/current/data-model-transactions.html) Alternatively, to get tracing for activity in your app that isn't part of an HTTP request you can manually start transactions via the apm.startTransaction(...) API (https://www.elastic.co/guide/en/apm/agent/nodejs/current/agent-api.html#apm-start-transaction).

Are you able to give some details on your app? What does it do? What modules does your app use that you expect the APM agent to be generating tracing data for?

khteh · 2023-06-18T07:31:44Z

I expect normal HTTP request tracing. This is my startup server.js:

// Add this to the very top of the first file loaded in your app
var apm = require('elastic-apm-node').start({
  // Override service name from package.json
  // Allowed characters: a-z, A-Z, 0-9, -, _, and space
  serviceName: 'buyerportal-apm',
  // Set custom APM Server URL (default: http://127.0.0.1:8200)
  serverUrl: 'https://my-apm-http:8200',
  // Only activate the agent if it's running in production
  active: process.env.NODE_ENV === 'production',
  verifyServerCert: false,
  ignoreUrls: [
    /^\/health\//i
  ],
  logLevel: 'trace'
})
const https = require('https')
const http2 = require('http2')
const fs = require('fs')
const path = require('path')
const { parse } = require('url')
const next = require('next')
const spdy = require('spdy')
const config = require('config')
const logger = require('morgan')
const json = require('morgan-json')
const express = require('express')
const compression = require('compression')
const cors = require('cors')
const helmet = require('helmet')
const createError = require('http-errors')
const cookieParser = require('cookie-parser')
const rfs = require('rotating-file-stream')
process.chdir(__dirname)
// Make sure commands gracefully respect termination signals (e.g. from Docker)
// Allow the graceful termination to be manually configurable
if (!process.env.NEXT_MANUAL_SIG_HANDLE) {
  process.on('SIGTERM', () => process.exit(0))
  process.on('SIGINT', () => process.exit(0))
  process.on('warning', (e) => console.warn(e.stack))
}
console.log(`NODE_ENV: ${process.env.NODE_ENV}`)
const port = parseInt(process.env.PORT, 10) || 443
const dev = process.env.NODE_ENV !== 'production'

const shouldCompress = (req, res) => {
  // don't compress responses asking explicitly not
  if (req.headers['x-no-compression']) {
    return false
  }

  // use compression filter function
  return compression.filter(req, res)
}
// Init the Next app:
const app = next({ dev, dir: __dirname })
const handle = app.getRequestHandler()
/*https://stackoverflow.com/questions/59534717/how-to-integrate-http2-with-expressjs-using-nodejs-module-http2
expressjs still does not officially support Node http2
https://github.com/expressjs/express/issues/5061
const server = http2.createSecureServer({
  key: fs.readFileSync('server.key'),
  cert: fs.readFileSync('server.crt')
}, app);
*/
const options = {
  key: fs.readFileSync('server.key'),
  cert: fs.readFileSync('server.crt'),
}
/*
app.prepare().then(() => { // This works perfectly well!
  https.createServer(options, (req, res) => {
    const parsedUrl = parse(req.url, true);
    handle(req, res, parsedUrl);
  }).listen(port, err => {
    if (err) throw err
    console.log(`> Ready on localhost:${port}`)
  })
})*/
app.prepare().then(() => {
  // This works perfectly too!
  // express setup
  const expressApp = express()
  /*
  expressApp.use(helmet()) // adding set of security middlewares
  */
  expressApp.use(apm.middleware.connect())
  expressApp.use(express.json())
  expressApp.use(express.urlencoded({ extended: false }))
  expressApp.use(cookieParser())
  expressApp.use(express.static(path.join(__dirname, 'public')))
  //expressApp.use(helmet()) adding set of security middlewares. This breaks!
  expressApp.use(cors()) // enable all CORS request
  expressApp.set('port', port)
  expressApp.use(compression({ filter: shouldCompress }))
  expressApp.enable("trust proxy");

  if (config.util.getEnv('NODE_ENV') !== 'test') {
    var accessLogStream = rfs.createStream('log', {
      interval: '1d', // rotate daily
      path: '/var/log/myapp',
    })
    //var format: string = ':remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] ":referrer" ":user-agent - :response-time ms"';
    const format = json({
      IP: ':remote-addr',
      User: ':remote-user',
      Timestamp: ':date[clf]',
      Method: ':method',
      Path: ':url',
      Protocol: 'HTTP/:http-version',
      Status: ':status',
      ContentLength: ':res[content-length]',
      Referrer: ':referrer',
      Agent: ':user-agent',
      ResponseTime: ':response-time ms',
    })
    // log only 4xx and 5xx responses to console
    if (config.util.getEnv('NODE_ENV') === 'development')
      expressApp.use(
        logger('combined', {
          skip: function (req, res) {
            return res.statusCode < 400
          },
        })
      )

    // log all requests to access.log
    expressApp.use(
      logger(format, {
        stream: accessLogStream,
      })
    )
  }

  // declaring routes for our pages
  expressApp.get('/index', (req, res) => {
    return app.render(req, res, '/', req.query)
  })
  /* k8s liveness check */
  expressApp.get('/health/ready', function (req, res, next) {
    res.send('OK')
  })
  expressApp.get('/health/live', function (req, res, next) {
    res.send('OK')
  })
  // fallback all request to next request handler
  expressApp.all('*', (req, res) => {
    //const parsedUrl = parse(req.url, true);
    //return handle(req, res, parsedUrl)
    return handle(req, res)
  })
  const server = spdy.createServer(options, expressApp)
  server.on('error', (error) => {
    if (error.syscall !== 'listen') {
      throw error
    }
    var bind = typeof port === 'string' ? 'Pipe ' + port : 'Port ' + port

    // handle specific listen errors with friendly messages
    switch (error.code) {
      case 'EACCES':
        console.error(bind + ' requires elevated privileges')
        process.exit(1)
      case 'EADDRINUSE':
        console.error(bind + ' is already in use')
        process.exit(1)
      default:
        throw error
    }
  })
  server.on('stream', (stream, headers) => {
    // stream is a Duplex
    stream.respond({
      'content-type': 'text/html; charset=utf-8',
      ':status': 200,
    })
    stream.end('<h1>Hello World</h1>')
  })
  server.listen(port, (err) => {
    if (err) {
      apm.captureError(err)
      console.error('Failed to start server', err)
      process.exit(1)
    } else {
      console.log(`HTTP/2 server listening on port: ${port}`)
    }
  })
})

How to get it to work?

trentm · 2023-06-21T20:28:26Z

I cannot get server.js running. Here is my attempt:

% node server.js
{"log.level":"debug","@timestamp":"2023-06-21T20:25:35.648Z","log":{"logger":"elastic-apm-node"},"ecs":{"version":"1.6.0"},"message":"Elastic APM agent disabled (`active` is false)"}
WARNING: No configurations found in configuration directory:/Users/trentm/tmp/b/config
WARNING: To disable this warning set SUPPRESS_NO_CONFIG_WARNING in the environment.
NODE_ENV: undefined
(node:58775) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.
(Use `node --trace-deprecation ...` to show where the warning was created)
DeprecationWarning: Access to process.binding('http_parser') is deprecated.
    at process.binding (node:internal/bootstrap/loaders:140:17)
    at Object.<anonymous> (/Users/trentm/tmp/b/node_modules/http-deceiver/lib/deceiver.js:22:24)
    at Module._compile (node:internal/modules/cjs/loader:1275:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1329:10)
    at Module.load (node:internal/modules/cjs/loader:1133:32)
    at Module._load (node:internal/modules/cjs/loader:972:12)
    at Module.require (node:internal/modules/cjs/loader:1157:19)
    at require (node:internal/modules/helpers:119:18)
    at Object.<anonymous> (/Users/trentm/tmp/b/node_modules/spdy/lib/spdy/handle.js:5:20)
    at Module._compile (node:internal/modules/cjs/loader:1275:14)

Using this package.json:

{
  "name": "b",
  "version": "1.0.0",
  "main": "server.js",
  "scripts": {},
  "dependencies": {
    "compression": "^1.7.4",
    "config": "^3.3.9",
    "cookie-parser": "^1.4.6",
    "cors": "^2.8.5",
    "elastic-apm-node": "^3.45.0",
    "express": "^4.18.2",
    "helmet": "^7.0.0",
    "http-errors": "^2.0.0",
    "morgan": "^1.10.0",
    "morgan-json": "^1.1.0",
    "next": "^13.2.4",
    "rotating-file-stream": "^3.1.0",
    "spdy": "^4.0.2"
  }
}

and node v19.8.1.

Can you share a small repository that reproduces the issue?

Looking at spdy-http2/node-spdy#380 I wonder if the spdy module just doesn't work with Node v19 that you mentioned you are using.

Also, if spdy is the module that is accepting incoming HTTP requests, then the elastic-apm-node agent doesn't current automatically instrument the spdy module -- so that would explain why an APM transaction is not automatically created.

khteh · 2023-06-21T23:51:31Z

Also, if spdy is the module that is accepting incoming HTTP requests, then the elastic-apm-node agent doesn't current automatically instrument the spdy module -- so that would explain why an APM transaction is not automatically created.

How to make it work without "automatically"?

trentm · 2023-06-21T23:59:23Z

You would need to use the Agent API (e.g. apm.startTransaction(...) and apm.endTransaction(...), https://www.elastic.co/guide/en/apm/agent/nodejs/current/agent-api.html#apm-start-transaction) to start and end transactions for incoming requests. It might be sufficient to write an express middleware to handle that. However, I don't know your application well, so I might be oversimplifying.

khteh · 2023-06-22T00:44:10Z

Can you share a small repository that reproduces the issue?

You can start an Next.JS app with https://nextjs.org/learn/basics/create-nextjs-app and start the app with export NODE_ENV=development PORT=3000&& node --experimental-specifier-resolution=node server.js

khteh · 2023-06-22T02:22:10Z

I added start and end:

  expressApp.all('*', (req, res) => {
    apm.startTransaction()
    const result = handle(req, res)
    apm.endTransaction()
    return result
  })

but still don't see any data in kibana

khteh · 2023-06-22T07:51:17Z

There was a delay. I see the data now.

github-actions bot added agent-nodejs Make available for APM Agents project planning. community triage labels Jun 10, 2023

khteh changed the title ~~Really no data in elastic apm for nodejs application~~ Reach.JS Next.JS SPDY No data in elastic apm for nodejs application Jun 10, 2023

khteh changed the title ~~Reach.JS Next.JS SPDY No data in elastic apm for nodejs application~~ React.JS Next.JS SPDY No data in elastic apm for nodejs application Jun 13, 2023

khteh mentioned this issue Jul 7, 2023

Trying to hide Next.JS /.next request path but it still appears as /_next #3463

Closed

3 tasks

khteh closed this as completed Sep 7, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

React.JS Next.JS SPDY No data in elastic apm for nodejs application #3413

React.JS Next.JS SPDY No data in elastic apm for nodejs application #3413

khteh commented Jun 10, 2023 •

edited by david-luna

Loading

trentm commented Jun 12, 2023

khteh commented Jun 13, 2023 •

edited

Loading

khteh commented Jun 13, 2023

trentm commented Jun 13, 2023

khteh commented Jun 14, 2023 •

edited

Loading

trentm commented Jun 14, 2023

khteh commented Jun 16, 2023

trentm commented Jun 16, 2023

khteh commented Jun 18, 2023

trentm commented Jun 21, 2023

khteh commented Jun 21, 2023

trentm commented Jun 21, 2023

khteh commented Jun 22, 2023

khteh commented Jun 22, 2023

khteh commented Jun 22, 2023

React.JS Next.JS SPDY No data in elastic apm for nodejs application #3413

React.JS Next.JS SPDY No data in elastic apm for nodejs application #3413

Comments

khteh commented Jun 10, 2023 • edited by david-luna Loading

trentm commented Jun 12, 2023

khteh commented Jun 13, 2023 • edited Loading

khteh commented Jun 13, 2023

trentm commented Jun 13, 2023

khteh commented Jun 14, 2023 • edited Loading

trentm commented Jun 14, 2023

khteh commented Jun 16, 2023

trentm commented Jun 16, 2023

khteh commented Jun 18, 2023

trentm commented Jun 21, 2023

khteh commented Jun 21, 2023

trentm commented Jun 21, 2023

khteh commented Jun 22, 2023

khteh commented Jun 22, 2023

khteh commented Jun 22, 2023

khteh commented Jun 10, 2023 •

edited by david-luna

Loading

khteh commented Jun 13, 2023 •

edited

Loading

khteh commented Jun 14, 2023 •

edited

Loading