Skip to content

ServiceContext lost when eager loading parent modelsΒ #591

@Iipin

Description

@Iipin

Describe the bug

Hello πŸ‘‹ I've stumbled upon a behavior that may be not a bug per se but was a bit unexpected, at least for me. I'd like to instrument my Vapor application for OpenTelemetry (in accordance with https://github.com/apple/swift-distributed-tracing) and for that reason wanted to create a new OT span for each database query. My approach was to decorate Fluent's Database:

import Fluent
import Tracing  // from https://github.com/apple/swift-distributed-tracing

struct TracedDatabase: Database {
    private let db: any Database

    // MARK: - Database

    public func execute(
        query: DatabaseQuery,
        onOutput: @escaping (DatabaseOutput) -> ()
    ) -> EventLoopFuture<Void> {
        let span = startSpan(query.description, ofKind: .client)
        let result = db.execute(query: query, onOutput: onOutput)
        result.whenComplete { _ in span.end() }
        return result
    }

    /* ... */
}

I could then do e.g. let myTracedDatabase = TracedDatabase(application.db) and use it as usual.
However, when performing MyModel.query(on: myTracedDatabase).with(.\$someParent).all() I could observe that:

  • the first database query's span got properly attached to the same trace as request's root span,
  • each of the following queries for MyModel's parents (.someParent in this case) got its own, new trace.

In other words, looking at https://github.com/apple/swift-distributed-tracing/blob/61c272fe72c9728c85952f0c6170cf491ac61dc0/Sources/Tracing/Tracer.swift#L47: parent model queries are executed with a different service context (so within separate tasks?) than the initial one.

As I said before, this might be an expected behavior which would be fine too – it's easy enough to work around this by storing the context object beforehand and passing it to startSpan explicitly.

To Reproduce

  1. Install https://github.com/apple/swift-service-context,
  2. Create a model ModelA with a parent model .modelB: ModelB,
  3. Create a decorated database class; a slightly more compact example would be:
struct TracedDatabase: Database {
    let db: any Database

    // MARK: - Database

    public func execute(
        query: DatabaseQuery,
        onOutput: @escaping (DatabaseOutput) -> ()
    ) -> EventLoopFuture<Void> {
        print("current service context: \(ServiceContext.current)")
        return db.execute(query: query, onOutput: onOutput)
    }

    /* ... */
}
  1. await ModelA.query(on: TracedDatabase(req.db)).with(\.$modelB).all(), inspect the output.

Expected behavior

The same service context object is printed twice.

Environment

  • Vapor Framework version: 4.92.1
  • Vapor Toolbox version: n/a
  • OS version: swift:5.9 Docker image

The app is running with PostgreSQL 16 database, with fluent-postgres-driver version 2.8.0.

Additional context

Add any other context about the problem here.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions