Express API / CaptureMessage not receive or sent to Sentry

[jenovateurs]

Is there an existing issue for this?

• [x] I have checked for existing issues https://github.com/getsentry/sentry-javascript/issues
• [x] I have reviewed the documentation https://docs.sentry.io/
• [x] I am using the latest SDK release https://github.com/getsentry/sentry-javascript/releases

How do you use Sentry?

Self-hosted/on-premise

Which SDK are you using?

@sentry/node

SDK Version

8.22.0

Framework Version

Express 4.19.2 / Node v20.10.0 / NPM 10.2.3

Link to Sentry event

No response

Reproduction Example/SDK Setup

main.js

const Sentry = require('@sentry/node');
const { nodeProfilingIntegration } = require("@sentry/profiling-node");

Sentry.init({ dsn: __YOUR_DSN__ ,integrations: [
    nodeProfilingIntegration(),
  ],
  tracesSampleRate: 1.0,
  profilesSampleRate: 1.0,});

const express = require('express');
const app = express();
Sentry.setupExpressErrorHandler(app);
Sentry.captureMessage("one init test"); //is Working

const port = 3000;

app.get('/', (req, res) => {
    Sentry.captureMessage("index message"); //not Working
    res.send('Hello World!');
});

app.get('/error', (req, res) => {
    throw new Error('Broke!');  //not Working
});

// Optional fallthrough error handler
app.use((err, req, res, next) => {
    res.statusCode = 500;
    res.end(res.sentry + "\n");
});

app.get("/debug-sentry", function mainHandler(req, res) {
  throw new Error("My first Sentry error!");  //not Working
});

app.listen(port, () => {
    console.log(`Example app listening at http://localhost:${port}`);
});

package.json

{
  "name": "express",
  "version": "1.0.0",
  "description": "",
  "main": "main.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "keywords": [],
  "author": "",
  "license": "ISC",
  "dependencies": {
    "@sentry/node": "^8.22.0",
    "@sentry/profiling-node": "^8.22.0",
    "express": "^4.19.2"
  }
}

Steps to Reproduce

Hi everyone, I hope you are all doing well :-). I have a simple issue: I can't send a message to Sentry when I'm in an Express API function.

Steps to Reproduce :

1. Update __YOUR_DSN__
2. npm install
3. node main.js
4. go to http://localhost:3000/debug-sentry or http://localhost:3000/
5. check if you receive "index message" in your sentry platform

Thanks for your help

Expected Result

I expect receive 3 messages on my Sentry Saas :

• one init test
• index message
• My first Sentry error!

Actual Result

But I only get "one init test"

I put debug property to true and have this :

Sentry Logger [log]: [Tracing] Starting sampled root span
  op: < unknown op >
  name: GET
  ID: eb350927d40b9bf5
Sentry Logger [log]: [Profiling] started profiling transaction: GET
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for middleware - query: true
Sentry Logger [log]: [Tracing] Starting sampled span
  op: < unknown op >
  name: middleware - query
  ID: 193cd20de0af4a0d
  parent ID: eb350927d40b9bf5
  root ID: eb350927d40b9bf5
  root description: GET
Sentry Logger [log]: [Tracing] Finishing "middleware.express" span "query" with ID 193cd20de0af4a0d
Sentry Logger [log]: SpanExporter has 1 unsent spans remaining
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for middleware - expressInit: true
Sentry Logger [log]: [Tracing] Starting sampled span
  op: < unknown op >
  name: middleware - expressInit
  ID: 438b7e423b2627f5
  parent ID: eb350927d40b9bf5
  root ID: eb350927d40b9bf5
  root description: GET
Sentry Logger [log]: [Tracing] Finishing "middleware.express" span "expressInit" with ID 438b7e423b2627f5
Sentry Logger [log]: SpanExporter has 2 unsent spans remaining
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for request handler - /debug-sentry: true
Sentry Logger [log]: [Tracing] Starting sampled span
  op: < unknown op >
  name: request handler - /debug-sentry
  ID: 68232ac682f377b5
  parent ID: eb350927d40b9bf5
  root ID: eb350927d40b9bf5
  root description: GET
Sentry Logger [log]: [Tracing] Finishing "request_handler.express" span "/debug-sentry" with ID 68232ac682f377b5

...

Sentry Logger [log]: SpanExporter has 3 unsent spans remaining
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" root span "GET /" with ID 69143fdb77b1b631
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /
Sentry Logger [log]: SpanExporter exported 4 spans, 0 unsent spans remaining
Sentry Logger [log]: Flushing client reports based on interval.
Sentry Logger [log]: Flushing outcomes...
Sentry Logger [log]: No outcomes to send
Sentry Logger [log]: [Profiling] max profile duration elapsed, stopping profiling for: GET /debug-sentry
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /debug-sentry
Sentry Logger [log]: [Profiling] profiler returned null profile for: GET /debug-sentry this may indicate an overlapping span or a call to stopProfiling with a profile title that was never started
Sentry Logger [log]: [Profiling] max profile duration elapsed, stopping profiling for: GET /
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /
Sentry Logger [log]: [Profiling] profiler returned null profile for: GET / this may indicate an overlapping span or a call to stopProfiling with a profile title that was never started

Sentry Logger [log]: Flushing client reports based on interval.
Sentry Logger [log]: Flushing outcomes...

[Lms24]

Hi @jenovateurs thanks for writing in! I'm gonna try to reproduce this and report back.

[Lms24]

So I copied your example 1:1 and I get "Index Message" issues in Sentry:

You probably need to remove the default issue priority filter from your issues search on top to get captured messages:

[Lms24]

I did find an issue though in your setup: You need to register our Error Handler after all routes but before any other error handlers, as written in our docs. So if you change the order in your app, you also get the "My first Sentry error!" error:

const Sentry = require("@sentry/node");
const { nodeProfilingIntegration } = require("@sentry/profiling-node");

Sentry.init({
  dsn: "DSN",
  integrations: [nodeProfilingIntegration()],
  tracesSampleRate: 1.0,
  profilesSampleRate: 1.0,
  debug: true,
});

const express = require("express");
const app = express();
Sentry.captureMessage("one init test"); //is Working

const port = 3000;

app.get("/", (req, res) => {
  Sentry.captureMessage("index message"); //not Working
  res.send("Hello World!");
});

app.get("/error", (req, res) => {
  throw new Error("Broke!"); //not Working
});

app.get("/debug-sentry", function mainHandler(req, res) {
  throw new Error("My first Sentry error!"); //not Working
});

Sentry.setupExpressErrorHandler(app);

// Optional fallthrough error handler
app.use((err, req, res, next) => {
  res.statusCode = 500;
  res.end(res.sentry + "\n");
});

app.listen(port, () => {
  console.log(`Example app listening at http://localhost:${port}`);
});

[jenovateurs]

Thanks for your help, I will test it. Did you also get the "index message" when you go to http://localhost:3000 ?

[jenovateurs]

I've just tested your solution/code, and I have no message returned in my Sentry platform. Do you have another suggestion?

Sentry Logger [log]: [Tracing] Finishing "request_handler.express" span "/debug-sentry" with ID 8b94eff4293cf65f
Sentry Logger [log]: SpanExporter has 3 unsent spans remaining
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" root span "GET /debug-sentry" with ID 82ce5b20e0e11511
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /debug-sentry
Sentry Logger [log]: SpanExporter exported 4 spans, 0 unsent spans remaining
Sentry Logger [log]: [Profiling] max profile duration elapsed, stopping profiling for: GET /debug-sentry
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /debug-sentry
Sentry Logger [log]: [Profiling] profiler returned null profile for: GET /debug-sentry this may indicate an overlapping span or a call to stopProfiling with a profile title that was never started
Sentry Logger [log]: Flushing client reports based on interval.
Sentry Logger [log]: Flushing outcomes...
Sentry Logger [log]: No outcomes to send
Sentry Logger [log]: [Profiling] max profile duration elapsed, stopping profiling for: GET /debug-sentry
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /debug-sentry
Sentry Logger [log]: [Profiling] profiler returned null profile for: GET /debug-sentry this may indicate an overlapping span or a call to stopProfiling with a profile title that was never started

[jenovateurs]

I also removed all specific filters in my Sentry platform.

[Lms24]

I get very similar logs around profiling but none of them indicate that an error or message event was dropped.

To check if we're actually sending events from the SDK, you can log out the events in beforeSend:

Sentry.init({
  dsn: "https://0d1038ca38c71c2c43f713d0c2aa58c5@o447951.ingest.us.sentry.io/4507655858946048",
  integrations: [nodeProfilingIntegration()],
  tracesSampleRate: 1.0,
  profilesSampleRate: 1.0,
  debug: true,
  beforeSend(event) {
    console.log("beforeSend", event);
    return event;
  },
});

Let's check if the events are sent but maybe dropped on the server-side.

[jenovateurs]

Good idea to check beforeSend :

beforeSend {
  event_id: 'e3e90fdc562e4ed9b7b09f94a073059e',
  level: 'info',
  message: 'index message',
  platform: 'node',
  contexts: {
    trace: {
      trace_id: 'e0a3656695f591f0390a8498abc80e0e',
      span_id: 'deb0f0788d421306'
    },
    runtime: { name: 'node', version: 'v20.10.0' },
    app: {
      app_start_time: '2024-08-02T14:15:34.175Z',
      app_memory: 86474752
    },
    os: {
      kernel_version: '23.5.0',
      name: 'macOS',
      version: '14.5',
      build: '23F79'
    },
    device: {
      boot_time: '2024-08-02T12:28:41.967Z',
      arch: 'arm64',
      memory_size: 17179869184,
      free_memory: 43892736,
      processor_count: 8,
      cpu_description: 'Apple M1',
      processor_frequency: 2400
    },
    culture: { locale: 'en-US', timezone: 'Europe/Paris' },
    cloud_resource: {}
  },
  server_name: 'mbp-jenov.home',
  sdkProcessingMetadata: {
    dynamicSamplingContext: {
      environment: 'production',
      public_key: 'HIDE_KEY',
      trace_id: 'e0a3656695f591f0390a8498abc80e0e',
      sample_rate: '1',
      transaction: 'GET /',
      sampled: 'true'
    },
    request: IncomingMessage {
      _readableState: [ReadableState],
      _events: [Object: null prototype],
      _eventsCount: 1,
      _maxListeners: undefined,
      socket: [Socket],
      httpVersionMajor: 1,
      httpVersionMinor: 1,
      httpVersion: '1.1',
      complete: true,
      rawHeaders: [Array],
      rawTrailers: [],
      joinDuplicateHeaders: null,
      aborted: false,
      upgrade: false,
      url: '/',
      method: 'GET',
      statusCode: null,
      statusMessage: null,
      client: [Socket],
      _consuming: false,
      _dumped: true,
      addListener: [Function (anonymous)],
      on: [Function (anonymous)],
      once: [Function (anonymous)],
      prependListener: [Function (anonymous)],
      prependOnceListener: [Function (anonymous)],
      removeListener: [Function (anonymous)],
      off: [Function (anonymous)],
      removeAllListeners: [Function (anonymous)],
      next: [Function (anonymous)],
      baseUrl: '',
      originalUrl: '/',
      _parsedUrl: [Url],
      params: {},
      query: {},
      res: [ServerResponse],
      route: [Route],
      [Symbol(kCapture)]: false,
      [Symbol(kHeaders)]: [Object],
      [Symbol(kHeadersCount)]: 26,
      [Symbol(kTrailers)]: null,
      [Symbol(kTrailersCount)]: 0,
      [Symbol(OtListeners)]: [Object: null prototype]
    }
  },
  timestamp: 1722608141.938,
  environment: 'production',
  sdk: {
    integrations: [
      'InboundFilters',       'FunctionToString',
      'LinkedErrors',         'RequestData',
      'Console',              'Http',
      'NodeFetch',            'OnUncaughtException',
      'OnUnhandledRejection', 'ContextLines',
      'LocalVariablesAsync',  'Context',
      'Modules',              'Express',
      'Fastify',              'Graphql',
      'Mongo',                'Mongoose',
      'Mysql',                'Mysql2',
      'Redis',                'Postgres',
      'Nest',                 'Hapi',
      'Koa',                  'Connect',
      'ProfilingIntegration'
    ]
  },
  transaction: 'GET ',
  breadcrumbs: [
    {
      timestamp: 1722608134.656,
      category: 'console',
      level: 'log',
      message: 'Example app listening at http://localhost:3000'
    }
  ],
  request: {
    method: 'GET',
    cookies: {
      '-': '-'
    },
    headers: {
      host: 'localhost:3000',
      'user-agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:129.0) Gecko/20100101 Firefox/129.0',
      accept: 'text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/png,image/svg+xml,*/*;q=0.8',
      'accept-language': 'fr,en-US;q=0.7,en;q=0.3',
      'accept-encoding': 'gzip, deflate, br, zstd',
      connection: 'keep-alive',
      cookie: '-'
      'upgrade-insecure-requests': '1',
      'sec-fetch-dest': 'document',
      'sec-fetch-mode': 'navigate',
      'sec-fetch-site': 'none',
      'sec-fetch-user': '?1',
      priority: 'u=0, i'
    },
    query_string: undefined,
    url: 'http://localhost:3000/'
  },
  modules: {
    semver: '7.6.3',
    shimmer: '1.2.1',
    'require-in-the-middle': '7.4.0',
    resolve: '1.22.8',
    'is-core-module': '2.15.0',
    hasown: '2.0.2',
    'function-bind': '1.1.2',
    'module-details-from-path': '1.0.3',
    'import-in-the-middle': '1.11.0',
    'detect-libc': '2.0.3',
    'node-abi': '3.65.0',
    express: '4.19.2',
    'body-parser': '1.20.2',
    depd: '2.0.0',
    'merge-descriptors': '1.0.1',
    finalhandler: '1.2.0',
    debug: '2.6.9',
    ms: '2.0.0',
    encodeurl: '1.0.2',
    'escape-html': '1.0.3',
    'on-finished': '2.4.1',
    'ee-first': '1.1.1',
    parseurl: '1.3.3',
    statuses: '2.0.1',
    unpipe: '1.0.0',
    'array-flatten': '1.1.1',
    'path-to-regexp': '0.1.7',
    methods: '1.1.2',
    'utils-merge': '1.0.1',
    setprototypeof: '1.2.0',
    qs: '6.11.0',
    'side-channel': '1.0.6',
    'get-intrinsic': '1.2.4',
    'es-errors': '1.3.0',
    'has-symbols': '1.0.3',
    'has-proto': '1.0.3',
    'call-bind': '1.0.7',
    'set-function-length': '1.2.2',
    'define-data-property': '1.1.4',
    'es-define-property': '1.0.0',
    gopd: '1.0.1',
    'has-property-descriptors': '1.0.2',
    'object-inspect': '1.13.2',
    'safe-buffer': '5.2.1',
    'content-disposition': '0.5.4',
    'content-type': '1.0.5',
    send: '0.18.0',
    'http-errors': '2.0.0',
    inherits: '2.0.4',
    toidentifier: '1.0.1',
    destroy: '1.2.0',
    etag: '1.8.1',
    fresh: '0.5.2',
    mime: '1.6.0',
    'range-parser': '1.2.1',
    'proxy-addr': '2.0.7',
    forwarded: '0.2.0',
    'ipaddr.js': '1.9.1',
    accepts: '1.3.8',
    negotiator: '0.6.3',
    'mime-types': '2.1.35',
    'mime-db': '1.52.0',
    'type-is': '1.6.18',
    'media-typer': '0.3.0',
    'cookie-signature': '1.0.6',
    cookie: '0.6.0',
    vary: '1.1.2',
    bytes: '3.1.2',
    'raw-body': '2.5.2',
    'iconv-lite': '0.4.24',
    'safer-buffer': '2.1.2',
    'serve-static': '1.15.0',
    'opentelemetry-instrumentation-fetch-node': '1.2.3'
  }
}

[Lms24]

Okay, so we know that the event is sent. I see you're using self-hosted Sentry, correct? I recommend updating to the latest version. I'm not aware that we dropped self-hosted version support recently but if you're on an older version, maybe we did indeed miss something.

[jenovateurs]

I receive the following log for the first captureMessage that is working and received in my Sentry platform before app.get("/"):

I noticed that this log appears lighter, lacking the long list of cookies. This makes sense since I'm accessing the index page in my web browser.

beforeSend {
  event_id: 'b53c65594e0748819dbe0ee40b02f66b',
  level: 'info',
  message: 'one init test',
  platform: 'node',
  contexts: {
    trace: {
      trace_id: '1a762cbc94b34b5bb646d5d1dbdc6d07',
      span_id: '86ad3df927a1d44f'
    },
    runtime: { name: 'node', version: 'v20.10.0' },
    app: {
      app_start_time: '2024-08-02T14:22:22.978Z',
      app_memory: 84279296
    },
    os: {
      kernel_version: '23.5.0',
      name: 'macOS',
      version: '14.5',
      build: '23F79'
    },
    device: {
      boot_time: '2024-08-02T12:28:41.371Z',
      arch: 'arm64',
      memory_size: 17179869184,
      free_memory: 61259776,
      processor_count: 8,
      cpu_description: 'Apple M1',
      processor_frequency: 2400
    },
    culture: { locale: 'en-US', timezone: 'Europe/Paris' },
    cloud_resource: {}
  },
  server_name: 'mbp-jenov.home',
  timestamp: 1722608543.342,
  environment: 'production',
  sdk: {
    integrations: [
      'InboundFilters',       'FunctionToString',
      'LinkedErrors',         'RequestData',
      'Console',              'Http',
      'NodeFetch',            'OnUncaughtException',
      'OnUnhandledRejection', 'ContextLines',
      'LocalVariablesAsync',  'Context',
      'Modules',              'Express',
      'Fastify',              'Graphql',
      'Mongo',                'Mongoose',
      'Mysql',                'Mysql2',
      'Redis',                'Postgres',
      'Nest',                 'Hapi',
      'Koa',                  'Connect',
      'ProfilingIntegration'
    ]
  },
  breadcrumbs: undefined,
  sdkProcessingMetadata: {
    dynamicSamplingContext: {
      environment: 'production',
      public_key: 'HIDE_KEY',
      trace_id: '1a762cbc94b34b5bb646d5d1dbdc6d07'
    }
  },
  modules: {
    semver: '7.6.3',
    shimmer: '1.2.1',
    'require-in-the-middle': '7.4.0',
    resolve: '1.22.8',
    'is-core-module': '2.15.0',
    hasown: '2.0.2',
    'function-bind': '1.1.2',
    'module-details-from-path': '1.0.3',
    'import-in-the-middle': '1.11.0',
    'detect-libc': '2.0.3',
    'node-abi': '3.65.0',
    express: '4.19.2',
    'body-parser': '1.20.2',
    depd: '2.0.0',
    'merge-descriptors': '1.0.1',
    finalhandler: '1.2.0',
    debug: '2.6.9',
    ms: '2.0.0',
    encodeurl: '1.0.2',
    'escape-html': '1.0.3',
    'on-finished': '2.4.1',
    'ee-first': '1.1.1',
    parseurl: '1.3.3',
    statuses: '2.0.1',
    unpipe: '1.0.0',
    'array-flatten': '1.1.1',
    'path-to-regexp': '0.1.7',
    methods: '1.1.2',
    'utils-merge': '1.0.1',
    setprototypeof: '1.2.0',
    qs: '6.11.0',
    'side-channel': '1.0.6',
    'get-intrinsic': '1.2.4',
    'es-errors': '1.3.0',
    'has-symbols': '1.0.3',
    'has-proto': '1.0.3',
    'call-bind': '1.0.7',
    'set-function-length': '1.2.2',
    'define-data-property': '1.1.4',
    'es-define-property': '1.0.0',
    gopd: '1.0.1',
    'has-property-descriptors': '1.0.2',
    'object-inspect': '1.13.2',
    'safe-buffer': '5.2.1',
    'content-disposition': '0.5.4',
    'content-type': '1.0.5',
    send: '0.18.0',
    'http-errors': '2.0.0',
    inherits: '2.0.4',
    toidentifier: '1.0.1',
    destroy: '1.2.0',
    etag: '1.8.1',
    fresh: '0.5.2',
    mime: '1.6.0',
    'range-parser': '1.2.1',
    'proxy-addr': '2.0.7',
    forwarded: '0.2.0',
    'ipaddr.js': '1.9.1',
    accepts: '1.3.8',
    negotiator: '0.6.3',
    'mime-types': '2.1.35',
    'mime-db': '1.52.0',
    'type-is': '1.6.18',
    'media-typer': '0.3.0',
    'cookie-signature': '1.0.6',
    cookie: '0.6.0',
    vary: '1.1.2',
    bytes: '3.1.2',
    'raw-body': '2.5.2',
    'iconv-lite': '0.4.24',
    'safer-buffer': '2.1.2',
    'serve-static': '1.15.0',
    'opentelemetry-instrumentation-fetch-node': '1.2.3'
  }
}

[jenovateurs]

Indeed, I use a self-hosted Sentry instance with version 24.4.2.

[Lms24]

Ok that's a relatively recent version. To make sure this is indeed a self-hosted issue and we're not just slightly diverging with our respective reproduction attempts, I pushed my repro code to this repo: https://github.com/Lms24/gh-sentry-javascript-13161-express-capturemessage

Would you mind swapping DSNs and checking if you still don't get the events? I just tried this again and can confirm all are visible in the Sentry.io UI:

[jenovateurs]

I've just tested your code and here are my results:

Only the first one at the initial server setup is working. Can I use your DSN to check if the issue is not with my computer?

[Lms24]

sure, go for it! Ping me once you sent events then I'll check

[jenovateurs]

Thanks @Lms24 , I've just launched index.js and navigated to the different paths that generate Sentry logs. Did you receive all of them?

[Lms24]

Yup:

[Lms24]

I suggest updating your self-hosted instance to the latest release (24.7.1 at this time) and check if you still get errors.

[Lms24]

Alternatively, you might want to check your self-hosted logs to see if there are any suggesting that events were dropped.

[jenovateurs]

Thanks for your suggestion. I will ask the provider that handles my self-hosted instance and get back to you if I have any further clues. Thank you for your time.

[jenovateurs]

Hi everyone,

I hope you are all doing well :-).

I've just fixed my problem. I created a new project in my Sentry Self-hosted and specified that it's an Express project. I launched the script with the new DSN, and it was working.

So, I checked the difference in configuration between my current project that wasn't working and the new one:

1. I switched the Platform from Node to Express.
2. I unchecked the option "Filter out events coming from localhost" in Settings > Project > Processing > Inbound Filters.

It's working now.

However, I think there is a small issue. With my previous settings, I received one Sentry log when I had a captureMessage outside the Express API endpoint. I don't understand why this log passed through the filter.

Is there a page or a place where we can find logs that were attempted to be sent but were rejected by Sentry parameters? That would be helpful.

So, I'll close this issue. Thanks for your help. Have a nice day.

[Lms24]

Hey @jenovateurs thanks for letting us know! First off, I'm glad you were able to resolve the issue!

I unchecked the option "Filter out events coming from localhost" in Settings > Project > Processing > Inbound Filters.

I just tried creating a new project in my sentry.io account (used my private one to ensure you get the customer experience) and for me, the localhost inbound filter was turned off by default. This might have changed in more recent self-hosted versions or perhaps you activated it beforehand?

I switched the Platform from Node to Express.

I don't think that this should do anything as it shouldn't interfere with which events are dropped or received by Sentry. If there really is a difference, this screams like a bug to me.

I don't understand why this log passed through the filter.

To be totally honest, me neither 😅 I think the best explanation is the localhost inbound filter overall but whatever was different in this event seemed work around the filter...