[React Router] Transaction unexpectedly ended early, cancelling spans from componentDidMount()

[realkosty]

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?

Sentry Saas (sentry.io)

Which package are you using?

@sentry/react

SDK Version

7.17.3 - but tested on 7.23.0 with same result

Framework Version

17.0.2 (react-router-dom: 6.4.3)

Link to Sentry event

https://sentry.io/organizations/testorg-az/performance/application-monitoring-javascript:755fa61c341044a19a38b718efff2b35/?project=5808623&query=sdk.version%3A7.17.3&referrer=performance-transaction-summary&statsPeriod=30d&transaction=%2Fproducts&unselectedSeries=p100()

Steps to Reproduce

0. Examine our project's SDK configuration index.js#L60-65 and index.js#L104 0.1 Examine code that initiates span that gets cut short before it finishes: Products.js#L39 - called from componentDidMount()
1. Go to https://application-monitoring-react-dot-sales-engineering-sf.appspot.com/products
2. Open devtools
3. (optional) set breakpoint in idletransaction.tx - will eventually point you to reactrouterv6.tsx: handleNavigation() and _useEffect()
4. Reload page
5. Inspect console log (Debug level)
6. Get transaction ID from Network tab and plug into search in /products transaction of this project

• Internal ticket: https://getsentry.atlassian.net/browse/FEEDBACK-1679

Expected Result

Transaction runs its course and does not finish prematurely before http.client span (GET https://.../**products**) is complete.

Actual Result

• Logs show "[Tracing] cancelling span since transaction ended early"
• In Sentry UI the last http.client span (GET https://.../**products**) of the transaction is cut short even though corresponding backend transaction is ~ 2 seconds.

[thinkocapo]

As a result of the problem described above, see that the bottom http.client txn here says 90.40ms...

but when you click the plus '+' to open it, it says 3,447 ms

Here's an additonal [transaction](https://sentry.io/organizations/testorg-az/performance/application-monitoring-javascript:755fa61c341044a19a38b718efff2b35/?project=5808623&query=sdk.version%3A7.17.3&referrer=performance-transaction-summary&statsPeriod=30d&transaction=%2Fproducts&unselectedSeries=p100()) showing the same problem.

VIDEO - If you want to see the expected behavior (how it worked with JS SDK v6.X.X) watch this VIDEO (2minutes) where I show v6 versus v7 outcomes.

You'll see that with v6 you get all those additional spans which are now getting cancelled in v7. https://www.loom.com/share/ff29f11806b94b94a79de46171e4c69b

[thinkocapo]

Here is some output from using Sentry.init({ debug:true }) regarding the cancelled spans.

example1

ENVIRONMENT test
index.js:49 RELEASE application.monitoring.javascript@22.12.1
logger.ts:72 Sentry Logger [log]: Integration installed: InboundFilters
logger.ts:72 Sentry Logger [log]: Integration installed: FunctionToString
logger.ts:72 Sentry Logger [log]: Integration installed: TryCatch
logger.ts:72 Sentry Logger [log]: Integration installed: Breadcrumbs
logger.ts:72 Sentry Logger [log]: Global Handler attached: onerror
logger.ts:72 Sentry Logger [log]: Global Handler attached: onunhandledrejection
logger.ts:72 Sentry Logger [log]: Integration installed: GlobalHandlers
logger.ts:72 Sentry Logger [log]: Integration installed: LinkedErrors
logger.ts:72 Sentry Logger [log]: Integration installed: Dedupe
logger.ts:72 Sentry Logger [log]: Integration installed: HttpContext
logger.ts:72 Sentry Logger [log]: [Tracing] Starting pageload transaction on scope
logger.ts:72 Sentry Logger [log]: Setting idle transaction on scope. Span ID: a5bcc5765a16423b
logger.ts:72 Sentry Logger [log]: [Tracing] starting pageload transaction - /products
logger.ts:72 Sentry Logger [log]: Starting heartbeat
logger.ts:72 Sentry Logger [log]: pinging Heartbeat -> current counter: 0
logger.ts:72 Sentry Logger [log]: Integration installed: BrowserTracing
instrument.ts:124 > backendType: flask | backendUrl: http://localhost:8080
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: bb772d712718d0d2
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 1
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.mount' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: 98c45cc4588817f8
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 2
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.mount' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] popActivity bb772d712718d0d2
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 1
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: b88747278ae470fc
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 2
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: 98e6977faabf9cb5
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 3
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: 895f72bf4987c75a
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 4
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: b6b657b27c142019
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 5
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] popActivity 98c45cc4588817f8
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 4
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.long-task' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] finishing IdleTransaction 2022-12-05T15:51:40.280Z pageload
logger.ts:72 Sentry Logger [log]: [Tracing] Adding & adjusting spans using Performance API
2logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (a5bcc5765a16423b).
2logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'resource.link' span on transaction '/products' (a5bcc5765a16423b).
3logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'resource.script' span on transaction '/products' (a5bcc5765a16423b).
4logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'resource.css' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'mark' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'paint' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Measurements] Adding FP
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'paint' span on transaction '/products' (a5bcc5765a16423b).
logger.ts:72 Sentry Logger [log]: [Measurements] Adding FCP
logger.ts:72 Sentry Logger [log]: [Measurements] Adding TTFB
logger.ts:72 Sentry Logger [log]: [Measurements] Normalized fcp from 464.3999999985099 to 460.70003509521484 (-3.69996490329504)
logger.ts:72 Sentry Logger [log]: [Measurements] Normalized fp from 464.3999999985099 to 460.70003509521484 (-3.69996490329504)
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/api",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/api",
  "op": "http.client",
  "parent_span_id": "a5bcc5765a16423b",
  "span_id": "b88747278ae470fc",
  "start_timestamp": 1670255500.2338,
  "status": "cancelled",
  "timestamp": 1670255500.2808,
  "trace_id": "8ce93f2af23e4b5b9b458282e15222be"
}
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/connect",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/connect",
  "op": "http.client",
  "parent_span_id": "a5bcc5765a16423b",
  "span_id": "98e6977faabf9cb5",
  "start_timestamp": 1670255500.2353,
  "status": "cancelled",
  "timestamp": 1670255500.2808,
  "trace_id": "8ce93f2af23e4b5b9b458282e15222be"
}
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/organization",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/organization",
  "op": "http.client",
  "parent_span_id": "a5bcc5765a16423b",
  "span_id": "895f72bf4987c75a",
  "start_timestamp": 1670255500.2372003,
  "status": "cancelled",
  "timestamp": 1670255500.2808,
  "trace_id": "8ce93f2af23e4b5b9b458282e15222be"
}
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/products",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/products",
  "op": "http.client",
  "parent_span_id": "a5bcc5765a16423b",
  "span_id": "b6b657b27c142019",
  "start_timestamp": 1670255500.2388,
  "status": "cancelled",
  "timestamp": 1670255500.2808,
  "trace_id": "8ce93f2af23e4b5b9b458282e15222be"
}
logger.ts:72 Sentry Logger [log]: [Tracing] flushing IdleTransaction
logger.ts:72 Sentry Logger [log]: [Measurements] Adding measurements to transaction {
  "fp": {
    "value": 460.70003509521484,
    "unit": "millisecond"
  },
  "fcp": {
    "value": 460.70003509521484,
    "unit": "millisecond"
  },
  "connection.rtt": {
    "value": 50,
    "unit": "millisecond"
  },
  "ttfb": {
    "value": 14.299869537353516,
    "unit": "millisecond"
  },
  "ttfb.requestTime": {
    "value": 11.399984359741211,
    "unit": "millisecond"
  }
}
logger.ts:72 Sentry Logger [log]: [Tracing] Finishing pageload transaction: /products.
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.update' span on transaction '/products' (a5bcc5765a16423b).
instrument.ts:124 > Nav shouldComponentUpdate
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.update' span on transaction '/products' (a5bcc5765a16423b).
redux-logger.js:1  action SET_PRODUCTS @ 16:51:43.795
instrument.ts:124  prev state {cart: {…}, products: Array(0), flag: false}
instrument.ts:124  action     {type: 'SET_PRODUCTS', payload: {…}}
instrument.ts:124  next state {cart: {…}, products: Array(4), flag: undefined}

example2

ENVIRONMENT test
index.js:49 RELEASE application.monitoring.javascript@22.12.1
logger.ts:72 Sentry Logger [log]: Integration installed: InboundFilters
logger.ts:72 Sentry Logger [log]: Integration installed: FunctionToString
logger.ts:72 Sentry Logger [log]: Integration installed: TryCatch
logger.ts:72 Sentry Logger [log]: Integration installed: Breadcrumbs
logger.ts:72 Sentry Logger [log]: Global Handler attached: onerror
logger.ts:72 Sentry Logger [log]: Global Handler attached: onunhandledrejection
logger.ts:72 Sentry Logger [log]: Integration installed: GlobalHandlers
logger.ts:72 Sentry Logger [log]: Integration installed: LinkedErrors
logger.ts:72 Sentry Logger [log]: Integration installed: Dedupe
logger.ts:72 Sentry Logger [log]: Integration installed: HttpContext
logger.ts:72 Sentry Logger [log]: [Tracing] Starting pageload transaction on scope
logger.ts:72 Sentry Logger [log]: Setting idle transaction on scope. Span ID: 844e01d036946228
logger.ts:72 Sentry Logger [log]: [Tracing] starting pageload transaction - /products
logger.ts:72 Sentry Logger [log]: Starting heartbeat
logger.ts:72 Sentry Logger [log]: pinging Heartbeat -> current counter: 0
logger.ts:72 Sentry Logger [log]: Integration installed: BrowserTracing
instrument.ts:124 > backendType: flask | backendUrl: http://localhost:8080
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: b9e87bc225e51447
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 1
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.mount' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: aa1dc2f175479627
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 2
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.mount' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] popActivity b9e87bc225e51447
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 1
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: 8ed131ee0a77df49
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 2
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: 8cb0c82b3bfdec0a
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 3
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: b492710e0e9d587a
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 4
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] pushActivity: abb1a35702a7ffd3
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 5
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] popActivity aa1dc2f175479627
logger.ts:72 Sentry Logger [log]: [Tracing] new activities count 4
2logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.long-task' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] finishing IdleTransaction 2022-12-05T15:53:37.810Z pageload
logger.ts:72 Sentry Logger [log]: [Tracing] Adding & adjusting spans using Performance API
2logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'browser' span on transaction '/products' (844e01d036946228).
2logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'resource.link' span on transaction '/products' (844e01d036946228).
3logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'resource.script' span on transaction '/products' (844e01d036946228).
4logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'resource.css' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'mark' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'paint' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Measurements] Adding FP
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'paint' span on transaction '/products' (844e01d036946228).
logger.ts:72 Sentry Logger [log]: [Measurements] Adding FCP
logger.ts:72 Sentry Logger [log]: [Measurements] Adding TTFB
logger.ts:72 Sentry Logger [log]: [Measurements] Normalized fcp from 559.6000000014901 to 553.4000396728516 (-6.199960328638554)
logger.ts:72 Sentry Logger [log]: [Measurements] Normalized fp from 559.6000000014901 to 553.4000396728516 (-6.199960328638554)
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/api",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/api",
  "op": "http.client",
  "parent_span_id": "844e01d036946228",
  "span_id": "8ed131ee0a77df49",
  "start_timestamp": 1670255617.7614002,
  "status": "cancelled",
  "timestamp": 1670255617.8103,
  "trace_id": "abae10f022ab40028b8563ebaa2de109"
}
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/connect",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/connect",
  "op": "http.client",
  "parent_span_id": "844e01d036946228",
  "span_id": "8cb0c82b3bfdec0a",
  "start_timestamp": 1670255617.7628,
  "status": "cancelled",
  "timestamp": 1670255617.8103,
  "trace_id": "abae10f022ab40028b8563ebaa2de109"
}
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/organization",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/organization",
  "op": "http.client",
  "parent_span_id": "844e01d036946228",
  "span_id": "b492710e0e9d587a",
  "start_timestamp": 1670255617.764,
  "status": "cancelled",
  "timestamp": 1670255617.8103,
  "trace_id": "abae10f022ab40028b8563ebaa2de109"
}
logger.ts:72 Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "GET",
    "url": "http://localhost:8080/products",
    "type": "fetch"
  },
  "description": "GET http://localhost:8080/products",
  "op": "http.client",
  "parent_span_id": "844e01d036946228",
  "span_id": "abb1a35702a7ffd3",
  "start_timestamp": 1670255617.7655,
  "status": "cancelled",
  "timestamp": 1670255617.8103,
  "trace_id": "abae10f022ab40028b8563ebaa2de109"
}
logger.ts:72 Sentry Logger [log]: [Tracing] flushing IdleTransaction
logger.ts:72 Sentry Logger [log]: [Measurements] Adding measurements to transaction {
  "fp": {
    "value": 553.4000396728516,
    "unit": "millisecond"
  },
  "fcp": {
    "value": 553.4000396728516,
    "unit": "millisecond"
  },
  "connection.rtt": {
    "value": 50,
    "unit": "millisecond"
  },
  "ttfb": {
    "value": 5.299806594848633,
    "unit": "millisecond"
  },
  "ttfb.requestTime": {
    "value": 0.8997917175292969,
    "unit": "millisecond"
  }
}
logger.ts:72 Sentry Logger [log]: [Tracing] Finishing pageload transaction: /products.
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.update' span on transaction '/products' (844e01d036946228).
instrument.ts:124 > Nav shouldComponentUpdate
logger.ts:72 Sentry Logger [log]: [Tracing] Starting 'ui.react.update' span on transaction '/products' (844e01d036946228).
redux-logger.js:1  action SET_PRODUCTS @ 16:53:41.992
instrument.ts:124  prev state {cart: {…}, products: Array(0), flag: false}
instrument.ts:124  action     {type: 'SET_PRODUCTS', payload: {…}}
instrument.ts:124  next state {cart: {…}, products: Array(4), flag: undefined}

[ndmanvar]

@smeubank - can we please get this prioritized and looked at? It's impacting our demos as the data isn't lining up Let us know if you need more information from us. We've posted all of our findings here and can collaborate on this issue to help move this forward.

This is a critical bug for us, as showing/tracing the /products transaction is part of the performance demo flow (/products on FE -> /products on BE [and the slowdown is a series of DB calls on the backend)

[timfish]

I'll take a look at this today!

[timfish]

I can't get application-monitoring/react to build on master.

What environment variables should I be setting? There are a lot in here but not sure which ones I need: https://github.com/sentry-demos/application-monitoring/blob/master/env-config/example.env

I don't think the build error is related to environment variables:

> application-monitoring@0.1.0 start
> react-scripts start

node:internal/modules/cjs/loader:498
      throw e;
      ^

Error [ERR_PACKAGE_PATH_NOT_EXPORTED]: Package subpath './lib/tokenize' is not defined by "exports" in /Users/tim/Documents/Repositories/application-monitoring/react/node_modules/postcss-safe-parser/node_modules/postcss/package.json
    at new NodeError (node:internal/errors:393:5)
    at throwExportsNotFound (node:internal/modules/esm/resolve:340:9)
    at packageExportsResolve (node:internal/modules/esm/resolve:619:3)
    at resolveExports (node:internal/modules/cjs/loader:492:36)
    at Module._findPath (node:internal/modules/cjs/loader:532:31)
    at Module._resolveFilename (node:internal/modules/cjs/loader:941:27)
    at Module._load (node:internal/modules/cjs/loader:803:27)
    at Module.require (node:internal/modules/cjs/loader:1021:19)
    at require (node:internal/modules/cjs/helpers:103:18)
    at Object.<anonymous> (/Users/tim/Documents/Repositories/application-monitoring/react/node_modules/postcss-safe-parser/lib/safe-parser.js:1:17) {
  code: 'ERR_PACKAGE_PATH_NOT_EXPORTED'
}

I'm in the Sentry Discord for direct messages!

[realkosty]

@timfish Hey Tim, to run our app:

From top level directory

./deploy.sh --env=local react

Or if you want to run it with hot reload:

cd react
../env.sh local npm start

[timfish]

Both of those give me an error because env-config/local.env is not checked into the repository.

[ERROR] Missing file env-config/local.env or invalid environment 'local'.

I've tried creating env-config/local.env but what environment variables should I set? I've tried setting the obvious ones and then I get I get the above error.

[realkosty]

Please create env-config/local.env with following content:

SENTRY_ORG={FILL IN YOUR ORG SLUG}

REACT_APP_DSN={{FILL IN YOUR DSN}} REACT_APP_ENGINE_SERVICE= REACT_APP_ENVIRONMENT=test REACT_RELEASE_PACKAGE_NAME=application.monitoring.javascript REACT_SENTRY_PROJECT={{FILL IN YOUR PROJECT SLUG}} REACT_SOURCEMAPS_DIR=build/static/js REACT_SOURCEMAPS_URL_PREFIX=~/static/js REACT_APP_FLASK_BACKEND={{DM-ed URL TO YOU}} REACT_APP_EXPRESS_BACKEND=https://sentry.io REACT_APP_SPRINGBOOT_BACKEND=https://sentry.io REACT_APP_ASPNETCORE_BACKEND=https://sentry.io REACT_APP_RUBY_BACKEND=https://sentry.io

[timfish]

It turns out there are some older dependencies somewhere that cause this issue which meant it wasn't working with my default node (v18). It's now working with node v16 but this should probably be documented somewhere!

For the JavaScript SDKs we use Volta which enforces the correct node version. It's nice because once setup and a version is pinned you can switch between projects and the correct version will be used with each.

[timfish]

When the the page is first loaded, in reactrouterv6.tsx, SentryRoutes + useEffect calls updatePageloadTransaction and later handleNavigation.

https://github.com/getsentry/sentry-javascript/blob/2fa11eb54f13b305dbee35687539748614583d6e/packages/react/src/reactrouterv6.tsx#L189-L201

The problem is that it calls handleNavigation with isBaseLocation == true and that causes the transaction to be finished.

This logic doesn't seem correct to me but it's been there since v7.0

https://github.com/getsentry/sentry-javascript/blob/2fa11eb54f13b305dbee35687539748614583d6e/packages/react/src/reactrouterv6.tsx#L130-L143

@onurtemizkan have you got any idea?

[realkosty]

@timfish

It turns out there are some older dependencies somewhere that cause https://github.com/facebook/create-react-app/issues/11565 which meant it wasn't working with my default node (v18). It's now working with node v16 but this should probably be documented somewhere!

thank you for pointing this out Tim, we should use Volta or document it like you suggested.

@onurtemizkan Please let me know if there's is anything I can help with investigating this.

[onurtemizkan]

The problem is that it calls handleNavigation with isBaseLocation == true and that causes the transaction to be finished. This logic doesn't seem correct to me but it's been there since v7.0

Yes, that seems implemented wrongly. When isBaseLocation is true, we only need to return early without touching anything.

@realkosty, @ndmanvar: Could you confirm if the example below is what's expected on your side? Link

[realkosty]

@onurtemizkan Yes, that looks right! http.client spans run their course and don't get cut prematurely.

(assuming no distributed tracing "+" and double slashes in request URL is just something specific to your setup).

[onurtemizkan]

Great! Opened a PR now. @timfish, @lforst - Could you take a look please?

[realkosty]

wow, thanks so much for fixing this so quick Onur

[realkosty]

Verified fix in our app 👍

[erdillon]

It seems the issue isn't fixed in my case. Running with debug:true.

Sentry Logger [log]: [Tracing] cancelling span since transaction ended early {
  "data": {
    "method": "POST",
    "url": "https://api.internal.logixboard.com/graphql",
    "type": "fetch"
  },
  "description": "POST https://api.internal.logixboard.com/graphql",
  "op": "http.client",
  "parent_span_id": "ab43e1236ea09b27",
  "span_id": "ac69f764aac1f2c6",
  "start_timestamp": 1676650240.3091,
  "status": "cancelled",
  "timestamp": 1676650260.0198,
  "trace_id": "7bc3af3d6847434f862a8e151d9eff8c"
}

Not sure what to provide to help you debug further. This is with 7.38.0

[lforst]

@erdillon Hi, the example you shared looks a bit like it's a very long-lived request that outlives the page navigation transaction (meaning a span cancellation would actually be the intended behavior).

Because I think this is unrelated to this issue, would you mind opening a new issue with concrete reproduction steps so we can debug this further in case this is actually a bug? Thanks!