"Invalid parent id!" when sending trace

Question

I have an app running on google app engine standard, python 2.7. GAE already trace calls to the Datastore and to Memcache and I want to add my own traces.

Since I'm in python 2 google-cloud-python is not available for my app.

I made something to overcome that using discovery api client. It kinda work : I can see my traces but they are not linked with GAE traces .

I work on that, checked how I can get the ID of the main span here, the one covering all the request. This information is available in the header X-Cloud-Trace-Context (source).

I found that I do not correctly parse the spanID part of this header.

Know that I do read it correctly and set it as the parent of my own span I got a 400 http error "Invalid parent id!" when I try to push my span.

Here is an example of what GAE already fill automatically in Stackdriver trace that I retrieve from Stackdriver API:

{
  "projectId": "my-project",
  "traceId": "7043814caa66c00a3fac3555e1d1e9d2",
  "spans": [
    {
      "spanId": "12635947902476947926",
      "name": "REDACTED",
      "startTime": "2018-09-18T11:44:46.666356Z",
      "endTime": "2018-09-18T11:45:02.926300478Z",
      "labels": {REDACTED}
    },
    {
      "spanId": "2895282594665317964",
      "name": "/remote_socket.CreateSocket",
      "startTime": "2018-09-18T11:44:50.469419110Z",
      "endTime": "2018-09-18T11:44:50.477561891Z",
      "parentSpanId": "12635947902476947926",
      "labels": {
        "g.co/gae/application_error": "6",
        "g.co/gae/error_message": "IP must be wildcard or be an IP returned by this RSG instance on a previous socket() call, received IP: ::1"
      }
    },
    {
      "spanId": "12635947904150929113",
      "name": "REDACTED",
      "startTime": "2018-09-18T11:44:49.588031056Z",
      "endTime": "2018-09-18T11:45:02.922000150Z",
      "parentSpanId": "12635947902476947926"
    },
    {
      "spanId": "18119035554219197767",
      "name": "/cloud_debugger.DebugletStarted",
      "startTime": "2018-09-18T11:44:49.605121020Z",
      "endTime": "2018-09-18T11:44:49.605863978Z",
      "parentSpanId": "12635947902476947926"
    },
    {
      "spanId": "12635947905824910300",
      "name": "/remote_socket.CreateSocket",
      "startTime": "2018-09-18T11:44:50.468409633Z",
      "endTime": "2018-09-18T11:44:50.478480133Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "12635947904936909686",
      "name": "/urlfetch.Fetch",
      "startTime": "2018-09-18T11:44:52.761299204Z",
      "endTime": "2018-09-18T11:44:52.766834488Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "4533572578254567247",
      "name": "/urlfetch.Fetch",
      "startTime": "2018-09-18T11:44:52.762846328Z",
      "endTime": "2018-09-18T11:44:52.766059416Z",
      "parentSpanId": "12635947902476947926",
      "labels": {
        "/http/method": "GET",
        "/http/response/size": "0",
        "/http/status_code": "0",
        "/http/url": "http://metadata.google.internal",
        "/http/host": "metadata.google.internal"
      }
    },
    {
      "spanId": "12635947904492451751",
      "name": "/user.GetOAuthUser",
      "startTime": "2018-09-18T11:45:02.857408315Z",
      "endTime": "2018-09-18T11:45:02.862760982Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "2960740089906396384",
      "name": "/user.GetOAuthUser",
      "startTime": "2018-09-18T11:45:02.858548710Z",
      "endTime": "2018-09-18T11:45:02.862337765Z",
      "parentSpanId": "12635947902476947926"
    },
    {
      "spanId": "12635947905888909837",
      "name": "/memcache.Get",
      "startTime": "2018-09-18T11:45:02.872708349Z",
      "endTime": "2018-09-18T11:45:02.875247917Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "2806170211922774912",
      "name": "/memcache.Get",
      "startTime": "2018-09-18T11:45:02.873653089Z",
      "endTime": "2018-09-18T11:45:02.874549693Z",
      "parentSpanId": "12635947902476947926",
      "labels": {
        "g.co/gae/memcache/count": "1",
        "g.co/gae/memcache/size": "26680"
      }
    },
    {
      "spanId": "12635947905612370518",
      "name": "/memcache.Get",
      "startTime": "2018-09-18T11:45:02.884082965Z",
      "endTime": "2018-09-18T11:45:02.885967828Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "1403376319062964670",
      "name": "/memcache.Get",
      "startTime": "2018-09-18T11:45:02.884984835Z",
      "endTime": "2018-09-18T11:45:02.885727464Z",
      "parentSpanId": "12635947902476947926",
      "labels": {
        "g.co/gae/memcache/count": "1",
        "g.co/gae/memcache/size": "132"
      }
    },
    {
      "spanId": "12635947905900454375",
      "name": "/urlfetch.Fetch",
      "startTime": "2018-09-18T11:45:02.886823410Z",
      "endTime": "2018-09-18T11:45:02.907643995Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "12992632058664043952",
      "name": "/urlfetch.Fetch",
      "startTime": "2018-09-18T11:45:02.887618043Z",
      "endTime": "2018-09-18T11:45:02.907269121Z",
      "parentSpanId": "12635947902476947926",
      "labels": {
        "/http/host": "cloudtrace.googleapis.com",
        "/http/method": "POST",
        "/http/request/size": "590",
        "/http/response/size": "165",
        "/http/status_code": "400",
        "/http/url": "https://cloudtrace.googleapis.com/v2/projects/lumsites-dev/traces:batchWrite?alt=json"
      }
    },
    {
      "spanId": "12635947904372387171",
      "name": "/logservice.Flush",
      "startTime": "2018-09-18T11:45:02.918746300Z",
      "endTime": "2018-09-18T11:45:02.920277782Z",
      "parentSpanId": "12635947904150929113"
    },
    {
      "spanId": "16196356337812692515",
      "name": "/logservice.Flush",
      "startTime": "2018-09-18T11:45:02.919606565Z",
      "endTime": "2018-09-18T11:45:02.919972451Z",
      "parentSpanId": "12635947902476947926"
    }
  ]
}

The header coming from the request : X-Cloud-Trace-Context : 7043814caa66c00a3fac3555e1d1e9d2/12635947902476947926;o=1 So trace ID is 7043814caa66c00a3fac3555e1d1e9d2 and parent span ID is 12635947902476947926 which looks like a 64-bit integer (trace API V1)

Here is the content of body of my request to https://cloudtrace.googleapis.com/v2/projects/my-project/traces:batchWrite?alt=json (Trace api v2) which end in 400

{"spans": [
    {
        'status': None,
        'childSpanCount': 0,
        'links': None,
        'startTime': '2018-09-18T11: 45: 02.876711Z',
        'spanId': '887188cf45b7461b',
        'stackTrace': None,
        'displayName': {
            'truncated_byte_count': 0,
            'value': 'manualSpan'
        },
        'name': 'projects/my-project/traces/7043814caa66c00a3fac3555e1d1e9d2/spans/887188cf45b7461b',
        'parentSpanId': '12635947902476947926',
        'attributes': {
            'attributeMap': {
                'g.co/agent': {
                    'string_value': {
                        'truncated_byte_count': 0,
                        'value': 'opencensus-python [
                            0.1.6
                        ]'
                    }
                }
            }
        },
        'timeEvents': None,
        'endTime': '2018-09-18T11: 45: 02.876915Z',
        'sameProcessAsParentSpan': None
    }
]}

What change between my first working version and this one is the parentSpanId : before, I used a generated spanID. Now I use the one present in the header.

As you can see the parentSpanId I'm using (12635947902476947926) DOES exist in the original trace. It is the parent of all subsequent spans.

The error message is not documented, as far as I could search. I did not see limitations on parentSpanID like maybe the parentSpanID needs to exists and be present in stackdriver BEFORE we send it.

Maybe I cannot mix incoming spanID in V1 format and sending my spans in V2 format.

Answer 1

The V2 API is expecting parentSpanId to be a 16 character hex string, but you are still sending it as a decimal. Convert it to hex (e.g. af5be7ab4f7b11d6) and the batchWrite call should work.