Changing order of instrumentation changes the span start timestamp

[ashu658]

Environment
opentelemetry-api/sdk: 1.7.1
opentelemetry-instrumentation-flask/wsgi/requests: 0.26b1

Steps to reproduce

Setup: A flask app with both wsgi and flask instrumentations enabled.
Flask app used (wsgi instrumentor called first)

# flask_example.py
import flask
import requests

from opentelemetry import trace
from opentelemetry.instrumentation.flask import FlaskInstrumentor
from opentelemetry.instrumentation.requests import RequestsInstrumentor
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import (
    BatchSpanProcessor,
    ConsoleSpanExporter,
)

from opentelemetry.instrumentation.wsgi import OpenTelemetryMiddleware


app = flask.Flask(__name__)
app.wsgi_app = OpenTelemetryMiddleware(app.wsgi_app)
FlaskInstrumentor().instrument_app(app)
RequestsInstrumentor().instrument()

trace.set_tracer_provider(TracerProvider())
trace.get_tracer_provider().add_span_processor(
    BatchSpanProcessor(ConsoleSpanExporter())
)

tracer = trace.get_tracer(__name__)

@app.route("/")
def hello():
    import time
    time.sleep(0.5)
    requests.get("http://www.example.com")
    return "hello"


app.run(port=5000)

In the app above two traces are sent one for wsgi and other for flask. Start timestamp of spans of wsgi is later than that of flask spans. If the order of instrumentors called is reversed then the timestamps of the wsgi span comes becomes earlier than flask span.

Output of console span exporter for above app (wsgi instrumentor called first):

# flask trace
{
    "name": "HTTP GET",
    "context": {
        "trace_id": "0x07dd0539c8d59f63779384cccba1a397",
        "span_id": "0xde437079bb6f1aef",
        "trace_state": "[]"
    },
    "kind": "SpanKind.CLIENT",
    "parent_id": "0xafe8b3bf688693dc",
    "start_time": "2021-11-17T14:51:50.981281Z",
    "end_time": "2021-11-17T14:51:51.655743Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "http.method": "GET",
        "http.url": "http://www.example.com",
        "http.status_code": 200
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.7.1",
        "service.name": "unknown_service"
    }
}
{
    "name": "/",
    "context": {
        "trace_id": "0x07dd0539c8d59f63779384cccba1a397",
        "span_id": "0xafe8b3bf688693dc",
        "trace_state": "[]"
    },
    "kind": "SpanKind.SERVER",
    "parent_id": null,
    "start_time": "2021-11-17T14:51:50.473056Z",
    "end_time": "2021-11-17T14:51:51.656217Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "http.method": "GET",
        "http.server_name": "127.0.0.1",
        "http.scheme": "http",
        "net.host.port": 5000,
        "http.host": "localhost:5000",
        "http.target": "/",
        "net.peer.ip": "127.0.0.1",
        "http.user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.106 Safari/537.36",
        "net.peer.port": 56543,
        "http.flavor": "1.1",
        "http.route": "/",
        "http.status_code": 200
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.7.1",
        "service.name": "unknown_service"
    }
}
# wsgi trace
{
    "name": "HTTP GET",
    "context": {
        "trace_id": "0xd6abc91fc7cbce1f0353eed0229d2c4a",
        "span_id": "0x5715efd5f9b9d634",
        "trace_state": "[]"
    },
    "kind": "SpanKind.SERVER",
    "parent_id": null,
    "start_time": "2021-11-17T14:51:50.475583Z",
    "end_time": "2021-11-17T14:51:51.657066Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "http.method": "GET",
        "http.server_name": "127.0.0.1",
        "http.scheme": "http",
        "net.host.port": 5000,
        "http.host": "localhost:5000",
        "http.target": "/",
        "net.peer.ip": "127.0.0.1",
        "http.user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.106 Safari/537.36",
        "net.peer.port": 56543,
        "http.flavor": "1.1",
        "http.status_code": 200
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.7.1",
        "service.name": "unknown_service"
    }
}

What is the expected behavior?
Order of instrumentors called should not affect span start timestamps.
What is the actual behavior?
Order of instrumentors called is affecting span start timestamps.

Additional context
Found this issue while working on [#446]. Upon marking the flask spans as internal in presence of a server span by wsgi, the start timestamp of flask span(child) comes before wsgi span(parent).
Slack conversation for more details: https://cloud-native.slack.com/archives/C01PD4HUVBL/p1637134298083200