Tracing: prisma:engine spans always get sampled when using probability based samplers

[TasinIshmam]

Bug description

When using any probability-based sampler (like TraceIdRatioBasedSampler) no matter what sampling ratio I use, the prisma:engine spans are always sampled.

For example, I’m tracing an endpoint that has a prisma.model.findMany query inside. I’m also using a TraceIdRatioBasedSampler with a sampling ratio of 0.3. The samples are collected and visualized using Jaeger. The engine spans show up 100% of the time for every request I make to the endpoint, but the rest of the spans show up roughly 30% of the time.

Here 6 traces were generated correspoding to 6 client requests, despite using a TraceIdRatioBasedSampler with a sampling ratio of 0.3. Four of these requests consist of only prisma:engine spans. The remaining two traces consist of all the spans. (Note: The screenshot is from spans generated using prisma v4.2.0, but the issue persists in v4.3.0).

How to reproduce

This repository provides a reproduction, along with instructions: https://github.com/TasinIshmam/tracing-probability-sampling-prisma

Expected behavior

All spans generated by Prisma should respect the sampling ratio of the underlying probability sampler.

Prisma information

Provided in the reproduction repository.

Environment & setup

• OS: macOS Monterey 12.5.1
• Database: sqlite
• Node.js version: 16.14.2

Prisma Version

prisma                  : 4.3.0
@prisma/client          : 4.3.0
Current platform        : darwin-arm64
Query Engine (Node-API) : libquery-engine c875e43600dfe042452e0b868f7a48b817b9640b (at node_modules/@prisma/engines/libquery_engine-darwin-arm64.dylib.node)
Migration Engine        : migration-engine-cli c875e43600dfe042452e0b868f7a48b817b9640b (at node_modules/@prisma/engines/migration-engine-darwin-arm64)
Introspection Engine    : introspection-core c875e43600dfe042452e0b868f7a48b817b9640b (at node_modules/@prisma/engines/introspection-engine-darwin-arm64)
Format Binary           : prisma-fmt c875e43600dfe042452e0b868f7a48b817b9640b (at node_modules/@prisma/engines/prisma-fmt-darwin-arm64)
Format Wasm             : @prisma/prisma-fmt-wasm 4.3.0-32.c875e43600dfe042452e0b868f7a48b817b9640b
Default Engines Hash    : c875e43600dfe042452e0b868f7a48b817b9640b
Studio                  : 0.473.0
Preview Features        : tracing

[danstarns]

Thanks for your reproduction @TasinIshmam, following your steps I can confirm that this is reproducible and is an issue.

I can confirm this is an issue by taking your server.ts file and applying the diff(removing or commenting out the Prisma method calls):

import initializeTracing from "./tracing";
const tracer = initializeTracing("express-server")


import { post, PrismaClient, user } from "@prisma/client";
import express, { request, Request, response, Response } from "express";


const app = express();
const port = 4000;

const prisma = new PrismaClient({});

app.get("/users/random", async (_req: Request, res: Response) => {
    await tracer.startActiveSpan("GET /users/random", async (requestSpan) => {
        try {
-           let users = await prisma.user.findMany({
-                include: {
-                    posts: true
-                }
-            });

            // select 10 users randomly
-            const shuffledUsers = users.sort(() => 0.5 - Math.random());
-            const selectedUsers = shuffledUsers.slice(0, 10);

-            res.status(200).json(selectedUsers);
+            res.status(200).json([]);

            requestSpan.setAttribute("http.status", 200);
        } catch (e) {
            requestSpan.setAttribute("http.status", 500);
            res.status(500).json({ error: 500, details: e });
        } finally {
            requestSpan.end();
        }
    });
});

app.listen(port, () => {
    console.log(`Example app listening on port: ${port}`);
});

After removing the Prisma calls I then made 6 HTTP requests to the server and doing so only produced the following 3 traces in Jaeger:

This shows that when Prisma is disabled the probability is working.

[millsp]

Internal conversation https://prisma-company.slack.com/archives/C040E1UMBD5/p1663118347284769

[janpio]

Which PR closed this @millsp?

[millsp]

prisma/prisma-engines#3188 does two fixes