sentry-javascript icon indicating copy to clipboard operation
sentry-javascript copied to clipboard

Published 20 hours ago • verified publisher icon getsentry

Error on span using sentry-opentelemetry

Open MeCapron opened this issue 1 year ago • 5 comments

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 SDK are you using?

@sentry/remix

SDK Version

8.13.0

Framework Version

Remix 2.8.1

Link to Sentry event

https://adexos.sentry.io/issues/5547923468/?project=4507505661837312&query=is%3Aunresolved+issue.priority%3A%5Bhigh%2C+medium%5D&referrer=issue-stream&statsPeriod=14d&stream_index=0

SDK Setup/Reproduction Example

Steps to Reproduce

See file configurations below

Specs

Here are the specs :

  • OS : Alpine 3.18.4
  • Kernel : 5.15.0-87-generic
  • Node version : 20.9.0
  • pnpm 8.8.0
  • Running on K8S
  • Using an express server
  • Using vite plugin for sentry

I tried to reproduce it locally with the same docker config but I do not have any errors on my side

File configurations

Here are my files :

import * as Sentry from "@sentry/remix";
/**
 * By default, Remix will handle hydrating your app on the client for you.
 * You are free to delete this file if you'd like to, but if you ever want it revealed again, you can run `npx remix reveal` ✨
 * For more information, see https://remix.run/docs/en/main/file-conventions/entry.client
 */
import { RemixBrowser, useLocation, useMatches } from "@remix-run/react";
import { startTransition, useEffect } from "react";
import { hydrateRoot } from "react-dom/client";

Sentry.init({
  // @ts-ignore set from root.tsx
  dsn: window.ENV.SENTRY_DSN,
  // @ts-ignore set from root .tsx
  environment: window.ENV.SENTRY_ENV,
  tracesSampleRate: 1,
  replaysSessionSampleRate: 0.1,
  replaysOnErrorSampleRate: 1,

  integrations: [Sentry.browserTracingIntegration({
    useEffect,
    useLocation,
    useMatches
  }), Sentry.replayIntegration()]
})

const hydrate = async () => {
  hydrateRoot(
    document,
    <RemixBrowser />
  );
};

startTransition(() => {
  hydrate();
});

import * as Sentry from "@sentry/remix";

Sentry.init({
  dsn: process.env.SENTRY_DSN,
  environment: process.env.SENTRY_ENV,
  tracesSampleRate: 1,
  autoInstrumentRemix: true
})

export default defineConfig((env) => {
  const viteEnv = loadEnv(env.mode, process.cwd(), "");

  return {
    build: {
      sourcemap: true
    },
    plugins: [
      sentryVitePlugin({
        authToken: viteEnv.SENTRY_AUTH_TOKEN,
        org: "adexos",
        project: "my-project",
        debug: true,
        sourcemaps: {
          filesToDeleteAfterUpload: ["**/*.map"]
        },
        release: {
          deploy: {
            env: viteEnv.SENTRY_ENV
          }
        }
      })
    ],
    resolve: {
      alias: {
        '@helpers': path.resolve(__dirname, 'extensions/helpers'),
      }
    }
  };
});

import { startExpressServer } from "./server/express";
import "./instrumentation.server.mjs";

startExpressServer();

  "dependencies": {
    "@graphql-typed-document-node/core": "^3.2.0",
    "@hookform/resolvers": "^3.4.2",
    "@react-leaflet/universal-leaflet": "^1.0.1",
    "@remix-run/css-bundle": "2.8.1",
    "@remix-run/express": "2.8.1",
    "@remix-run/node": "2.8.1",
    "@remix-run/react": "2.8.1",
    "@sentry/remix": "^8.13.0",
    "@sentry/vite-plugin": "^2.20.1",
    "@vite-pwa/assets-generator": "^0.2.4",
    "axios": "^1.6.7",
    "bowser": "^2.11.0",
    "classnames": "^2.5.1",
    "cli-boxes": "^3.0.0",
    "common-tags": "^1.8.2",
    "compression": "^1.7.4",
    "cross-env": "^7.0.3",
    "dataloader": "^2.2.2",
    "dotenv": "^16.4.5",
    "express": "^4.18.2",
    "fbjs": "^3.0.5",
    "framer-motion": "^10.18.0",
    "glob": "^10.3.10",
    "html-react-parser": "^5.1.8",
    "isbot": "^4.4.0",
    "leaflet": "^1.9.4",
    "lodash": "^4.17.21",
    "morgan": "^1.10.0",
    "notistack": "^3.0.1",
    "prop-types": "^15.8.1",
    "qs": "^6.12.0",
    "react": "^18.2.0",
    "react-apollo": "3.1.5",
    "react-dom": "^18.2.0",
    "react-h5-audio-player": "^3.9.1",
    "react-hook-form": "^7.51.5",
    "react-intl": "6.6.2",
    "react-leaflet": "^4.2.1",
    "react-leaflet-cluster": "^2.1.0",
    "react-text-truncate": "^0.19.0",
    "remix-utils": "^7.5.0",
    "sharp": "^0.33.3",
    "source-map-support": "^0.5.21",
    "strapi-sdk-js": "^2.3.3",
    "swiper": "^11.0.6",
    "tsx": "^4.7.1",
    "winston": "^3.12.0",
    "workbox-routing": "^7.0.0",
    "workbox-window": "^7.0.0",
    "zod": "^3.23.8"
  }

I launch the server this way : "start": "cross-env NODE_ENV=production node --import tsx/esm ./server.mjs"

What I tried

Sorry I could not reproduce it locally, but maybe you have an idea of what is going on.

I also tried with a lower version of @sentry/remix:8.0.0 instead of my @sentry/remix:8.13.0 and the same result occurs.

Not tried with a different version of the vite plugin.

Since I cannot reproduce it locally, I only checked the code regarding Sentry and open telemetry and did not find anything suspicious regarding my issue.

I linked an issue where you can see the crash happening on Sentry side (that is captured)

Expected Result

Having no error on Node side

Actual Result

The logs

I have installed Sentry properly on my local docker without any problem, evertyhing is running smoothly.

However, in production I have a problem I cannot tackle, here are the two traces that reboot the server again and again :

2024-06-28T15:32:10.725Z TypeError: number 1719588728485 is not iterable (cannot read property Symbol(Symbol.iterator))
2024-06-28T15:32:10.725Z     at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)
2024-06-28T15:32:10.725Z     at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)
2024-06-28T15:32:10.725Z     at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)
2024-06-28T15:32:10.725Z     at Array.forEach ()
2024-06-28T15:32:10.725Z     at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)
2024-06-28T15:32:10.725Z     at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)
2024-06-28T15:32:10.725Z     at Timeout. (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:68:12)
2024-06-28T15:32:10.725Z     at listOnTimeout (node:internal/timers:573:17)
2024-06-28T15:32:10.725Z     at process.processTimers (node:internal/timers:514:7)

and

2024-06-28T15:32:11.175Z TypeError: number 1719588728485 is not iterable (cannot read property Symbol(Symbol.iterator))gst
2024-06-28T15:32:11.176Z     at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)
2024-06-28T15:32:11.176Z     at shouldCleanupSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:179:10)
2024-06-28T15:32:11.176Z     at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:109:26)
2024-06-28T15:32:11.176Z     at Array.filter ()
2024-06-28T15:32:11.176Z     at SentrySpanExporter._cleanupOldSpans (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:108:33)
2024-06-28T15:32:11.176Z     at SentrySpanExporter.export (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:59:12)
2024-06-28T15:32:11.176Z     at SentrySpanProcessor.onEnd (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:98:26)
2024-06-28T15:32:11.176Z     at MultiSpanProcessor.onEnd (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:58:21)
2024-06-28T15:32:11.176Z     at Span.end (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/Span.ts:267:25)
2024-06-28T15:32:11.176Z     at HttpInstrumentation._closeHttpSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/instrumentation-http/src/http.ts:696:10)

The application crashes here : https://github.com/getsentry/sentry-javascript/blob/develop/packages/opentelemetry/src/spanExporter.ts#L239 where the span.startTime is a full number instead of an array [number, number]

I hope you have some ideas!

Thanks you

MeCapron avatar Jun 28 '24 15:06 MeCapron

Thanks for the detailed issue report @MeCapron. On the prod environment you're using, it looks like the timestamp is recorded as milliseconds in OpenTelemetry and breaks our converting utility. I'll open a PR to add a support for that case 👍

onurtemizkan avatar Jun 28 '24 16:06 onurtemizkan

Thanks for the detailed issue report @MeCapron. On the prod environment you're using, it looks like the timestamp is recorded as milliseconds in OpenTelemetry and breaks our converting utility. I'll open a PR to add a support for that case 👍

Do you know what causes this? From my side the only thing that differs from my Docker environment to the production one in K8S is the Kernel.

I might miss some thing, I'm trying to add some context by adding the full debug mode in the server side

When I looked of the code related to opentelemetry, AFAIK the startTime must be a HrTime type which is the array, I may be wrong though and the type could be also wrong in specific cases

MeCapron avatar Jun 28 '24 16:06 MeCapron

Here are the logs found on server side from server started to server crash :

2024-06-28T16:46:30.854Z 

2024-06-28T16:46:30.854Z > [email protected] start /project

2024-06-28T16:46:30.854Z > cross-env NODE_ENV=production node --import tsx/esm ./server.mjs

2024-06-28T16:46:30.854Z 

2024-06-28T16:46:32.333Z Sentry Logger [log]: Initializing Sentry: process: 52, thread: main.

2024-06-28T16:46:32.336Z Sentry Logger [log]: Integration installed: InboundFilters

2024-06-28T16:46:32.336Z Sentry Logger [log]: Integration installed: FunctionToString

2024-06-28T16:46:32.336Z Sentry Logger [log]: Integration installed: LinkedErrors

2024-06-28T16:46:32.336Z Sentry Logger [log]: Integration installed: RequestData

2024-06-28T16:46:32.337Z Sentry Logger [log]: Integration installed: Console

2024-06-28T16:46:32.337Z Sentry Logger [log]: Integration installed: NodeFetch

2024-06-28T16:46:32.338Z Sentry Logger [log]: Integration installed: OnUncaughtException

2024-06-28T16:46:32.338Z Sentry Logger [log]: Integration installed: OnUnhandledRejection

2024-06-28T16:46:32.338Z Sentry Logger [log]: Integration installed: ContextLines

2024-06-28T16:46:32.338Z Sentry Logger [log]: Integration installed: LocalVariablesAsync

2024-06-28T16:46:32.338Z Sentry Logger [log]: Integration installed: Context

2024-06-28T16:46:32.338Z Sentry Logger [log]: Integration installed: Modules

2024-06-28T16:46:32.341Z Sentry Logger [log]: Integration installed: Express

2024-06-28T16:46:32.342Z Sentry Logger [log]: Integration installed: Fastify

2024-06-28T16:46:32.347Z Sentry Logger [log]: Integration installed: Graphql

2024-06-28T16:46:32.348Z Sentry Logger [log]: Integration installed: Mongo

2024-06-28T16:46:32.349Z Sentry Logger [log]: Integration installed: Mongoose

2024-06-28T16:46:32.350Z Sentry Logger [log]: Integration installed: Mysql

2024-06-28T16:46:32.350Z Sentry Logger [log]: Integration installed: Mysql2

2024-06-28T16:46:32.353Z Sentry Logger [log]: Integration installed: Redis

2024-06-28T16:46:32.354Z Sentry Logger [log]: Integration installed: Postgres

2024-06-28T16:46:32.355Z Sentry Logger [log]: Integration installed: Nest

2024-06-28T16:46:32.355Z Sentry Logger [log]: Integration installed: Hapi

2024-06-28T16:46:32.356Z Sentry Logger [log]: Integration installed: Koa

2024-06-28T16:46:32.357Z Sentry Logger [log]: Integration installed: Connect

2024-06-28T16:46:32.359Z Sentry Logger [log]: Integration installed: Http

2024-06-28T16:46:32.360Z Sentry Logger [log]: Integration installed: Remix

2024-06-28T16:46:32.361Z Sentry Logger [log]: Running in CommonJS mode.

2024-06-28T16:46:32.361Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.

2024-06-28T16:46:32.365Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.

2024-06-28T16:46:32.365Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.

2024-06-28T16:46:32.365Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.

2024-06-28T16:46:33.659Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }

2024-06-28T16:46:33.660Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }

2024-06-28T16:46:34.506Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying patch for [email protected]

2024-06-28T16:46:34.507Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying patch for [email protected]

2024-06-28T16:46:40.539Z Fri, 28 Jun 2024 16:46:40 GMT @front-commerce/compat/shop/ShopContext deprecated `withShop` is deprecated. Use `withPublicConfig` instead:

2024-06-28T16:46:40.539Z   

2024-06-28T16:46:40.539Z   import { withPublicConfig } from "@front-commerce/core/react";

2024-06-28T16:46:40.539Z   const Component = ({ shop }) => 
{shop.id}
;

2024-06-28T16:46:40.539Z   export default withPublicConfig()(Component);

2024-06-28T16:46:40.539Z 

2024-06-28T16:46:40.539Z  at node:internal/modules/esm/module_job:217:25

2024-06-28T16:46:40.581Z Express server listening at http://localhost:4000

2024-06-28T16:46:41.443Z Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest

2024-06-28T16:46:41.449Z Sentry Logger [log]: [Tracing] Starting sampled root span

2024-06-28T16:46:41.449Z   op: < unknown op >

2024-06-28T16:46:41.449Z   name: HTTP POST

2024-06-28T16:46:41.449Z   ID: 0eae8b31bfdc4120

2024-06-28T16:46:44.259Z Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for HTTPS GET: true

2024-06-28T16:46:44.259Z Sentry Logger [log]: [Tracing] Starting sampled span

2024-06-28T16:46:44.259Z   op: < unknown op >

2024-06-28T16:46:44.259Z   name: HTTPS GET

2024-06-28T16:46:44.259Z   ID: deca37b0eeb93055

2024-06-28T16:46:44.259Z   parent ID: 0eae8b31bfdc4120

2024-06-28T16:46:44.259Z   root ID: 0eae8b31bfdc4120

2024-06-28T16:46:44.259Z   root description: HTTP POST

2024-06-28T16:46:44.315Z Sentry Logger [debug]: @opentelemetry/instrumentation-http https instrumentation outgoingRequest

2024-06-28T16:46:44.315Z Sentry Logger [debug]: @opentelemetry/instrumentation-http http.ClientRequest return request

2024-06-28T16:46:44.336Z (node:52) Warning: Setting the NODE_TLS_REJECT_UNAUTHORIZED environment variable to '0' makes TLS connections and HTTPS requests insecure by disabling certificate verification.

2024-06-28T16:46:44.336Z (Use `node --trace-warnings ...` to show where the warning was created)

2024-06-28T16:46:44.339Z Sentry Logger [log]: [Tracing] Finishing "< unknown op >" root span "HTTP POST" with ID 0eae8b31bfdc4120

2024-06-28T16:46:44.340Z POST /graphql 200 24 - 2880.220 ms

2024-06-28T16:46:44.391Z TypeError: number 1719593201451 is not iterable (cannot read property Symbol(Symbol.iterator))

2024-06-28T16:46:44.391Z     at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)

2024-06-28T16:46:44.391Z     at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)

2024-06-28T16:46:44.391Z     at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)

2024-06-28T16:46:44.391Z     at Array.forEach ()

2024-06-28T16:46:44.391Z     at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)

2024-06-28T16:46:44.391Z     at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)

2024-06-28T16:46:44.391Z     at Timeout. (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:68:12)

2024-06-28T16:46:44.391Z     at listOnTimeout (node:internal/timers:573:17)

2024-06-28T16:46:44.391Z     at process.processTimers (node:internal/timers:514:7)

2024-06-28T16:46:44.402Z Sentry Logger [error]: {"stack":"TypeError: number 1719593201451 is not iterable (cannot read property Symbol(Symbol.iterator))
    at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)
    at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)
    at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)
    at Array.forEach ()
    at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)
    at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)
    at SentrySpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:77:20)
    at MultiSpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:34:35)
    at NodeClient.flush (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/node/src/sdk/client.ts:55:107)
    at NodeClient.close (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/core/src/baseclient.ts:293:17)","message":"number 1719593201451 is not iterable (cannot read property Symbol(Symbol.iterator))","name":"TypeError"}

2024-06-28T16:46:44.405Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts'

2024-06-28T16:46:44.405Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts'

2024-06-28T16:46:44.405Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts'

2024-06-28T16:46:44.405Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts'

2024-06-28T16:46:44.405Z Sentry Logger [error]: Could not find line 61 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T16:46:44.406Z Sentry Logger [error]: Could not find line 71 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T16:46:44.406Z Sentry Logger [error]: Could not find line 130 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T16:46:44.406Z Sentry Logger [error]: Could not find line 133 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T16:46:44.406Z Sentry Logger [error]: Could not find line 232 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T16:46:44.406Z Sentry Logger [error]: Could not find line 1 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts

2024-06-28T16:46:44.584Z Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for HTTPS POST: true

2024-06-28T16:46:44.584Z Sentry Logger [log]: [Tracing] Starting sampled span

2024-06-28T16:46:44.584Z   op: < unknown op >

2024-06-28T16:46:44.584Z   name: HTTPS POST

2024-06-28T16:46:44.584Z   ID: d8bda6c942b49d91

2024-06-28T16:46:44.584Z   parent ID: 0eae8b31bfdc4120

2024-06-28T16:46:44.584Z   root ID: 0eae8b31bfdc4120

2024-06-28T16:46:44.584Z   root description: HTTP POST

2024-06-28T16:46:44.586Z Sentry Logger [debug]: @opentelemetry/instrumentation-http https instrumentation outgoingRequest

2024-06-28T16:46:44.586Z Sentry Logger [debug]: @opentelemetry/instrumentation-http http.ClientRequest return request

2024-06-28T16:46:44.627Z Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on response()

2024-06-28T16:46:44.629Z Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on end()

2024-06-28T16:46:44.629Z Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "HTTPS POST" with ID d8bda6c942b49d91

2024-06-28T16:46:44.629Z Sentry Logger [log]: SpanExporter has 2 unsent spans remaining

2024-06-28T16:46:44.630Z Sentry Logger [warn]: uncaught exception after calling fatal error shutdown callback - this is bad! forcing shutdown

2024-06-28T16:46:44.633Z TypeError: number 1719593201451 is not iterable (cannot read property Symbol(Symbol.iterator))

2024-06-28T16:46:44.633Z     at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)

2024-06-28T16:46:44.633Z     at shouldCleanupSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:179:10)

2024-06-28T16:46:44.633Z     at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:109:26)

2024-06-28T16:46:44.633Z     at Array.filter ()

2024-06-28T16:46:44.633Z     at SentrySpanExporter._cleanupOldSpans (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:108:33)

2024-06-28T16:46:44.633Z     at SentrySpanExporter.export (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:59:12)

2024-06-28T16:46:44.633Z     at SentrySpanProcessor.onEnd (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:98:26)

2024-06-28T16:46:44.633Z     at MultiSpanProcessor.onEnd (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:58:21)

2024-06-28T16:46:44.633Z     at Span.end (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/Span.ts:267:25)

2024-06-28T16:46:44.633Z     at HttpInstrumentation._closeHttpSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/instrumentation-http/src/http.ts:696:10)

2024-06-28T16:46:44.635Z Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on request close()

2024-06-28T16:46:44.635Z Sentry Logger [warn]: Can not execute the operation on ended Span {traceId: 0004bf6243fbd3f8a17635c51c490ffd, spanId: d8bda6c942b49d91}

2024-06-28T16:46:44.635Z Sentry Logger [error]: HTTPS POST 0004bf6243fbd3f8a17635c51c490ffd-d8bda6c942b49d91 - You can only call end() on a span once.

2024-06-28T16:46:44.637Z Sentry Logger [error]: {"stack":"TypeError: number 1719593201451 is not iterable (cannot read property Symbol(Symbol.iterator))
    at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)
    at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)
    at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)
    at Array.forEach ()
    at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)
    at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)
    at SentrySpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:77:20)
    at MultiSpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:34:35)
    at NodeClient.flush (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/node/src/sdk/client.ts:55:107)
    at NodeClient.close (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/core/src/baseclient.ts:293:17)","message":"number 1719593201451 is not iterable (cannot read property Symbol(Symbol.iterator))","name":"TypeError"}

2024-06-28T16:46:44.774Z  ELIFECYCLE  Command failed with exit code 1.

In any case it helps, here is the same thing I do (build and start the server) locally :

> [email protected] start /usr/src/app
> cross-env NODE_ENV=production node --import tsx/esm ./server.mjs
Sentry Logger [log]: Initializing Sentry: process: 443, thread: main.
Sentry Logger [log]: Integration installed: InboundFilters
Sentry Logger [log]: Integration installed: FunctionToString
Sentry Logger [log]: Integration installed: LinkedErrors
Sentry Logger [log]: Integration installed: RequestData
Sentry Logger [log]: Integration installed: Console
Sentry Logger [log]: Integration installed: NodeFetch
Sentry Logger [log]: Integration installed: OnUncaughtException
Sentry Logger [log]: Integration installed: OnUnhandledRejection
Sentry Logger [log]: Integration installed: ContextLines
Sentry Logger [log]: Integration installed: LocalVariablesAsync
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: Modules
Sentry Logger [log]: Integration installed: Express
Sentry Logger [log]: Integration installed: Fastify
Sentry Logger [log]: Integration installed: Graphql
Sentry Logger [log]: Integration installed: Mongo
Sentry Logger [log]: Integration installed: Mongoose
Sentry Logger [log]: Integration installed: Mysql
Sentry Logger [log]: Integration installed: Mysql2
Sentry Logger [log]: Integration installed: Redis
Sentry Logger [log]: Integration installed: Postgres
Sentry Logger [log]: Integration installed: Nest
Sentry Logger [log]: Integration installed: Hapi
Sentry Logger [log]: Integration installed: Koa
Sentry Logger [log]: Integration installed: Connect
Sentry Logger [log]: Integration installed: Http
Sentry Logger [log]: Integration installed: Remix
Sentry Logger [log]: Running in CommonJS mode.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.
Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
@front-commerce/compat/shop/ShopContext deprecated `withShop` is deprecated. Use `withPublicConfig` instead:
  import { withPublicConfig } from "@front-commerce/core/react";
  const Component = ({ shop }) => <div>{shop.id}</div>;
  export default withPublicConfig()(Component);
 node:internal/modules/esm/module_job:217:25
Express server listening at http://localhost:4000
POST /graphql 200 - - 418.466 ms

Here are some spans after the POST

Some things that appears in my production but not in local :

2024-06-28T16:50:14.001Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying patch for [email protected]
2024-06-28T16:50:14.002Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying patch for [email protected]

MeCapron avatar Jun 28 '24 16:06 MeCapron 

import { startExpressServer } from "./server/express";
import "./instrumentation.server.mjs";

startExpressServer();

Could you move import "./instrumentation.server.mjs"; before any other imports and check if that changes anything?

onurtemizkan avatar Jun 28 '24 17:06 onurtemizkan 

import { startExpressServer } from "./server/express";
import "./instrumentation.server.mjs";

startExpressServer();

Could you move import "./instrumentation.server.mjs"; before any other imports and check if that changes anything?

A span appeared but it crahses after! I updated my comment just before to add the logs of my local

Here is the full stack after the change you asked for :

2024-06-28T17:18:29.237Z  ELIFECYCLE  Command failed with exit code 1.

2024-06-28T17:18:39.071Z 

2024-06-28T17:18:39.071Z > [email protected] start /project

2024-06-28T17:18:39.071Z > cross-env NODE_ENV=production node --import tsx/esm ./server.mjs

2024-06-28T17:18:39.071Z 

2024-06-28T17:18:40.547Z Sentry Logger [log]: Initializing Sentry: process: 60, thread: main.

2024-06-28T17:18:40.549Z Sentry Logger [log]: Integration installed: InboundFilters

2024-06-28T17:18:40.549Z Sentry Logger [log]: Integration installed: FunctionToString

2024-06-28T17:18:40.549Z Sentry Logger [log]: Integration installed: LinkedErrors

2024-06-28T17:18:40.549Z Sentry Logger [log]: Integration installed: RequestData

2024-06-28T17:18:40.549Z Sentry Logger [log]: Integration installed: Console

2024-06-28T17:18:40.550Z Sentry Logger [log]: Integration installed: NodeFetch

2024-06-28T17:18:40.550Z Sentry Logger [log]: Integration installed: OnUncaughtException

2024-06-28T17:18:40.550Z Sentry Logger [log]: Integration installed: OnUnhandledRejection

2024-06-28T17:18:40.550Z Sentry Logger [log]: Integration installed: ContextLines

2024-06-28T17:18:40.551Z Sentry Logger [log]: Integration installed: LocalVariablesAsync

2024-06-28T17:18:40.551Z Sentry Logger [log]: Integration installed: Context

2024-06-28T17:18:40.551Z Sentry Logger [log]: Integration installed: Modules

2024-06-28T17:18:40.553Z Sentry Logger [log]: Integration installed: Express

2024-06-28T17:18:40.554Z Sentry Logger [log]: Integration installed: Fastify

2024-06-28T17:18:40.555Z Sentry Logger [log]: Integration installed: Graphql

2024-06-28T17:18:40.557Z Sentry Logger [log]: Integration installed: Mongo

2024-06-28T17:18:40.557Z Sentry Logger [log]: Integration installed: Mongoose

2024-06-28T17:18:40.558Z Sentry Logger [log]: Integration installed: Mysql

2024-06-28T17:18:40.559Z Sentry Logger [log]: Integration installed: Mysql2

2024-06-28T17:18:40.561Z Sentry Logger [log]: Integration installed: Redis

2024-06-28T17:18:40.562Z Sentry Logger [log]: Integration installed: Postgres

2024-06-28T17:18:40.562Z Sentry Logger [log]: Integration installed: Nest

2024-06-28T17:18:40.563Z Sentry Logger [log]: Integration installed: Hapi

2024-06-28T17:18:40.564Z Sentry Logger [log]: Integration installed: Koa

2024-06-28T17:18:40.565Z Sentry Logger [log]: Integration installed: Connect

2024-06-28T17:18:40.567Z Sentry Logger [log]: Integration installed: Http

2024-06-28T17:18:40.570Z Sentry Logger [log]: Integration installed: Remix

2024-06-28T17:18:40.570Z Sentry Logger [log]: Running in CommonJS mode.

2024-06-28T17:18:40.571Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.

2024-06-28T17:18:40.576Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.

2024-06-28T17:18:40.576Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.

2024-06-28T17:18:40.576Z Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.

2024-06-28T17:18:40.658Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }

2024-06-28T17:18:40.658Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }

2024-06-28T17:18:43.017Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying patch for [email protected]

2024-06-28T17:18:43.017Z Sentry Logger [debug]: @opentelemetry/instrumentation-http Applying patch for [email protected]

2024-06-28T17:18:43.456Z 2024-06-28T17:18:43.456Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.457Z 2024-06-28T17:18:43.457Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.457Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:43.458Z 2024-06-28T17:18:43.458Z front-commerce:config Creating GraphQL module from schema shorthand: node_modules/decitre-fc/graphql/**/schema.gql

2024-06-28T17:18:49.274Z Fri, 28 Jun 2024 17:18:49 GMT @front-commerce/compat/shop/ShopContext deprecated `withShop` is deprecated. Use `withPublicConfig` instead:

2024-06-28T17:18:49.275Z   

2024-06-28T17:18:49.275Z   import { withPublicConfig } from "@front-commerce/core/react";

2024-06-28T17:18:49.275Z   const Component = ({ shop }) => 
{shop.id}
;

2024-06-28T17:18:49.275Z   export default withPublicConfig()(Component);

2024-06-28T17:18:49.275Z 

2024-06-28T17:18:49.275Z  at node:internal/modules/esm/module_job:217:25

2024-06-28T17:18:49.326Z Express server listening at http://localhost:4000

2024-06-28T17:18:52.384Z 2024-06-28T17:18:52.384Z front-commerce:contribution-mode Directive @storefrontContent(extractorIdentifier: "Magento1Customer") on type Customer

2024-06-28T17:18:52.385Z 2024-06-28T17:18:52.385Z front-commerce:contribution-mode Directive @storefrontContent(extractorIdentifier: "Magento1Order") on type Order

2024-06-28T17:18:52.385Z 2024-06-28T17:18:52.385Z front-commerce:contribution-mode Directive @storefrontContent(extractorIdentifier: "Magento1Product") on type Product

2024-06-28T17:18:52.385Z 2024-06-28T17:18:52.385Z front-commerce:contribution-mode Directive @storefrontContent(extractorIdentifier: "Magento1Category") on type Category

2024-06-28T17:18:52.386Z 2024-06-28T17:18:52.385Z front-commerce:contribution-mode Directive @storefrontContent(extractorIdentifier: "Magento1CmsBlock") on type CmsBlock

2024-06-28T17:18:52.386Z 2024-06-28T17:18:52.386Z front-commerce:contribution-mode Directive @storefrontContent(extractorIdentifier: "Magento1CmsPage") on type CmsPage

2024-06-28T17:18:53.940Z Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest

2024-06-28T17:18:53.947Z Sentry Logger [log]: [Tracing] Starting sampled root span

2024-06-28T17:18:53.947Z   op: < unknown op >

2024-06-28T17:18:53.947Z   name: HTTP POST

2024-06-28T17:18:53.947Z   ID: 1afdd73b5224816e

2024-06-28T17:18:53.999Z 2024-06-28T17:18:53.999Z front-commerce:config Url used to find shop: https://localhost:4000/graphql

2024-06-28T17:18:53.999Z 2024-06-28T17:18:53.999Z front-commerce:config Current shop: default

2024-06-28T17:18:54.034Z 2024-06-28T17:18:54.034Z front-commerce:config Current device: bot (360 px)

2024-06-28T17:18:54.329Z Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for remix.request: true

2024-06-28T17:18:54.329Z Sentry Logger [log]: [Tracing] Starting sampled span

2024-06-28T17:18:54.329Z   op: < unknown op >

2024-06-28T17:18:54.329Z   name: remix.request

2024-06-28T17:18:54.329Z   ID: ed024dffb3fdecdc

2024-06-28T17:18:54.329Z   parent ID: 1afdd73b5224816e

2024-06-28T17:18:54.329Z   root ID: 1afdd73b5224816e

2024-06-28T17:18:54.329Z   root description: HTTP POST

2024-06-28T17:18:54.356Z Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for ACTION routes/graphql: true

2024-06-28T17:18:54.356Z Sentry Logger [log]: [Tracing] Starting sampled span

2024-06-28T17:18:54.356Z   op: < unknown op >

2024-06-28T17:18:54.356Z   name: ACTION routes/graphql

2024-06-28T17:18:54.356Z   ID: 85854290665c013b

2024-06-28T17:18:54.356Z   parent ID: ed024dffb3fdecdc

2024-06-28T17:18:54.356Z   root ID: 1afdd73b5224816e

2024-06-28T17:18:54.356Z   root description: HTTP POST

2024-06-28T17:18:54.416Z 2024-06-28T17:18:54.414Z front-commerce:cache Redis: connecting to server with config { host: 'nosoli-decitre-redis-cache', port: '6379', db: 1 }

2024-06-28T17:18:54.444Z Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for HTTPS GET: true

2024-06-28T17:18:54.444Z Sentry Logger [log]: [Tracing] Starting sampled span

2024-06-28T17:18:54.444Z   op: < unknown op >

2024-06-28T17:18:54.444Z   name: HTTPS GET

2024-06-28T17:18:54.444Z   ID: a5d8214f7deaeb78

2024-06-28T17:18:54.444Z   parent ID: 85854290665c013b

2024-06-28T17:18:54.444Z   root ID: 1afdd73b5224816e

2024-06-28T17:18:54.444Z   root description: HTTP POST

2024-06-28T17:18:54.499Z Sentry Logger [debug]: @opentelemetry/instrumentation-http https instrumentation outgoingRequest

2024-06-28T17:18:54.499Z Sentry Logger [debug]: @opentelemetry/instrumentation-http http.ClientRequest return request

2024-06-28T17:18:54.519Z Sentry Logger [log]: [Tracing] Finishing "action.remix" span "ACTION routes/graphql" with ID 85854290665c013b

2024-06-28T17:18:54.519Z Sentry Logger [log]: SpanExporter has 1 unsent spans remaining

2024-06-28T17:18:54.520Z Sentry Logger [log]: [Tracing] Finishing "http.server" span "remix.request graphql" with ID ed024dffb3fdecdc

2024-06-28T17:18:54.520Z Sentry Logger [log]: SpanExporter has 2 unsent spans remaining

2024-06-28T17:18:54.525Z (node:60) Warning: Setting the NODE_TLS_REJECT_UNAUTHORIZED environment variable to '0' makes TLS connections and HTTPS requests insecure by disabling certificate verification.

2024-06-28T17:18:54.525Z (Use `node --trace-warnings ...` to show where the warning was created)

2024-06-28T17:18:54.528Z Sentry Logger [log]: [Tracing] Finishing "< unknown op >" root span "HTTP POST" with ID 1afdd73b5224816e

2024-06-28T17:18:54.529Z POST /graphql 200 24 - 569.554 ms

2024-06-28T17:18:54.583Z TypeError: number 1719595133949 is not iterable (cannot read property Symbol(Symbol.iterator))

2024-06-28T17:18:54.583Z     at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)

2024-06-28T17:18:54.583Z     at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)

2024-06-28T17:18:54.583Z     at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)

2024-06-28T17:18:54.583Z     at Array.forEach ()

2024-06-28T17:18:54.583Z     at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)

2024-06-28T17:18:54.583Z     at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)

2024-06-28T17:18:54.583Z     at Timeout. (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:68:12)

2024-06-28T17:18:54.583Z     at listOnTimeout (node:internal/timers:573:17)

2024-06-28T17:18:54.583Z     at process.processTimers (node:internal/timers:514:7)

2024-06-28T17:18:54.604Z Sentry Logger [error]: {"stack":"TypeError: number 1719595133949 is not iterable (cannot read property Symbol(Symbol.iterator))
    at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)
    at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)
    at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)
    at Array.forEach ()
    at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)
    at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)
    at SentrySpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:77:20)
    at MultiSpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:34:35)
    at NodeClient.flush (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/node/src/sdk/client.ts:55:107)
    at NodeClient.close (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/core/src/baseclient.ts:293:17)","message":"number 1719595133949 is not iterable (cannot read property Symbol(Symbol.iterator))","name":"TypeError"}

2024-06-28T17:18:54.608Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts'

2024-06-28T17:18:54.608Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts'

2024-06-28T17:18:54.608Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts'

2024-06-28T17:18:54.608Z Sentry Logger [error]: Failed to read file: /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts. Error: Error: ENOENT: no such file or directory, open '/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts'

2024-06-28T17:18:54.609Z Sentry Logger [error]: Could not find line 61 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T17:18:54.609Z Sentry Logger [error]: Could not find line 71 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T17:18:54.609Z Sentry Logger [error]: Could not find line 130 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T17:18:54.609Z Sentry Logger [error]: Could not find line 133 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T17:18:54.609Z Sentry Logger [error]: Could not find line 232 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts

2024-06-28T17:18:54.609Z Sentry Logger [error]: Could not find line 1 in file /project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts

2024-06-28T17:18:54.615Z 2024-06-28T17:18:54.615Z front-commerce:cache Redis: connected successfully

2024-06-28T17:18:54.616Z 2024-06-28T17:18:54.616Z front-commerce:cache Redis: connected successfully

2024-06-28T17:18:55.024Z Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for HTTPS POST: true

2024-06-28T17:18:55.024Z Sentry Logger [log]: [Tracing] Starting sampled span

2024-06-28T17:18:55.024Z   op: < unknown op >

2024-06-28T17:18:55.024Z   name: HTTPS POST

2024-06-28T17:18:55.024Z   ID: 590cf147ec978c65

2024-06-28T17:18:55.024Z   parent ID: 1afdd73b5224816e

2024-06-28T17:18:55.024Z   root ID: 1afdd73b5224816e

2024-06-28T17:18:55.024Z   root description: HTTP POST

2024-06-28T17:18:55.026Z Sentry Logger [debug]: @opentelemetry/instrumentation-http https instrumentation outgoingRequest

2024-06-28T17:18:55.027Z Sentry Logger [debug]: @opentelemetry/instrumentation-http http.ClientRequest return request

2024-06-28T17:18:55.084Z Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on response()

2024-06-28T17:18:55.086Z Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on end()

2024-06-28T17:18:55.087Z Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "HTTPS POST" with ID 590cf147ec978c65

2024-06-28T17:18:55.087Z Sentry Logger [log]: SpanExporter has 4 unsent spans remaining

2024-06-28T17:18:55.087Z Sentry Logger [warn]: uncaught exception after calling fatal error shutdown callback - this is bad! forcing shutdown

2024-06-28T17:18:55.091Z TypeError: number 1719595133949 is not iterable (cannot read property Symbol(Symbol.iterator))

2024-06-28T17:18:55.091Z     at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)

2024-06-28T17:18:55.091Z     at shouldCleanupSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:179:10)

2024-06-28T17:18:55.091Z     at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:109:26)

2024-06-28T17:18:55.091Z     at Array.filter ()

2024-06-28T17:18:55.091Z     at SentrySpanExporter._cleanupOldSpans (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:108:33)

2024-06-28T17:18:55.091Z     at SentrySpanExporter.export (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:59:12)

2024-06-28T17:18:55.091Z     at SentrySpanProcessor.onEnd (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:98:26)

2024-06-28T17:18:55.091Z     at MultiSpanProcessor.onEnd (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:58:21)

2024-06-28T17:18:55.092Z     at Span.end (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/Span.ts:267:25)

2024-06-28T17:18:55.092Z     at HttpInstrumentation._closeHttpSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/instrumentation-http/src/http.ts:696:10)

2024-06-28T17:18:55.093Z Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on request close()

2024-06-28T17:18:55.093Z Sentry Logger [warn]: Can not execute the operation on ended Span {traceId: 1095deb0582b1a35022f7895227a74f0, spanId: 590cf147ec978c65}

2024-06-28T17:18:55.093Z Sentry Logger [error]: HTTPS POST 1095deb0582b1a35022f7895227a74f0-590cf147ec978c65 - You can only call end() on a span once.

2024-06-28T17:18:55.097Z Sentry Logger [error]: {"stack":"TypeError: number 1719595133949 is not iterable (cannot read property Symbol(Symbol.iterator))
    at convertOtelTimeToSeconds (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/utils/convertOtelTimeToSeconds.ts:2:41)
    at createTransactionForOtelSpan (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:239:22)
    at  (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:140:30)
    at Array.forEach ()
    at maybeSend (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:137:13)
    at SentrySpanExporter.flush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanExporter.ts:78:28)
    at SentrySpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]_@[email protected]_@opentelemet_jwpm2sqfekexay3qqlibo6vqxm/node_modules/@sentry/opentelemetry/src/spanProcessor.ts:77:20)
    at MultiSpanProcessor.forceFlush (/project/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/sdk-trace-base/src/MultiSpanProcessor.ts:34:35)
    at NodeClient.flush (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/node/src/sdk/client.ts:55:107)
    at NodeClient.close (/project/node_modules/.pnpm/@[email protected]/node_modules/@sentry/core/src/baseclient.ts:293:17)","message":"number 1719595133949 is not iterable (cannot read property Symbol(Symbol.iterator))","name":"TypeError"}

2024-06-28T17:18:55.216Z  ELIFECYCLE  Command failed with exit code 1.

MeCapron avatar Jun 28 '24 17:06 MeCapron

Thanks for the additional info, we are looking into it!

I still don't really get how a span may have a different startTime type, because it should not really be possible according to the spec/types, but we'll guard more carefully there anyhow!

mydea avatar Jul 01 '24 08:07 mydea

Hello @mydea @onurtemizkan

I thank you for your glad help and looking into this issue.

I can say how precisely this scenario appears. After digging a bit more in the code side and debugging locally, I checked on the server side (since it was only happening there) just to find, after getting some accesses from the provider, that they were installing on the deployment side some packages :

ni [email protected] [email protected] @opentelemetry/[email protected] @opentelemetry/[email protected] @opentelemetry/[email protected]

Sentry JS needs version 0.52.0 for telemetry and instrumentation, 1.9.0 for its main API

It seemed to conflict.

Removing these packages solved the issue, I did not took the time to dug into oldest telemetry and API on their repository but it might be the oldest way they handled starting time for spans.

However one thing that comes in my mind (tbh I'm not fully comfortable with npm management regarding conflicts since I come from composer) and I would be glad if you can give me some hints : how can the install goes well in terms of conflict management?

AFAIK the installation is not forced, even though it made the all system incompatible between the requirements of the provider vs Sentry. I think that it should have crashed, am I wrong?

MeCapron avatar Jul 01 '24 12:07 MeCapron

Yeah, this is unfortunate as of today 😬 Especially because all/most of these packages are <1, deduping does not work at all for them.

Ideally we can find some ways to report on this better than we do today, but this is a bit tricky. For now, I believe if you enable debug: true you should see some logs about mismatching versions at least!

mydea avatar Jul 02 '24 12:07 mydea