You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.
 
 
 

968 lines
27 KiB

  1. // Copyright 2016 Google LLC
  2. //
  3. // Licensed under the Apache License, Version 2.0 (the "License");
  4. // you may not use this file except in compliance with the License.
  5. // You may obtain a copy of the License at
  6. //
  7. // http://www.apache.org/licenses/LICENSE-2.0
  8. //
  9. // Unless required by applicable law or agreed to in writing, software
  10. // distributed under the License is distributed on an "AS IS" BASIS,
  11. // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12. // See the License for the specific language governing permissions and
  13. // limitations under the License.
  14. package trace
  15. import (
  16. "context"
  17. "encoding/json"
  18. "errors"
  19. "fmt"
  20. "io/ioutil"
  21. "math/rand"
  22. "net/http"
  23. "regexp"
  24. "strings"
  25. "sync"
  26. "testing"
  27. "time"
  28. "cloud.google.com/go/datastore"
  29. "cloud.google.com/go/internal/testutil"
  30. "cloud.google.com/go/storage"
  31. api "google.golang.org/api/cloudtrace/v1"
  32. compute "google.golang.org/api/compute/v1"
  33. "google.golang.org/api/iterator"
  34. "google.golang.org/api/option"
  35. dspb "google.golang.org/genproto/googleapis/datastore/v1"
  36. "google.golang.org/grpc"
  37. )
  38. const testProjectID = "testproject"
  39. type fakeRoundTripper struct {
  40. reqc chan *http.Request
  41. }
  42. func newFakeRoundTripper() *fakeRoundTripper {
  43. return &fakeRoundTripper{reqc: make(chan *http.Request)}
  44. }
  45. func (rt *fakeRoundTripper) RoundTrip(r *http.Request) (*http.Response, error) {
  46. rt.reqc <- r
  47. resp := &http.Response{
  48. Status: "200 OK",
  49. StatusCode: 200,
  50. Body: ioutil.NopCloser(strings.NewReader("{}")),
  51. }
  52. return resp, nil
  53. }
  54. func newTestClient(rt http.RoundTripper) *Client {
  55. t, err := NewClient(context.Background(), testProjectID, option.WithHTTPClient(&http.Client{Transport: rt}))
  56. if err != nil {
  57. panic(err)
  58. }
  59. return t
  60. }
  61. type fakeDatastoreServer struct {
  62. dspb.DatastoreServer
  63. fail bool
  64. }
  65. func (f *fakeDatastoreServer) Lookup(ctx context.Context, req *dspb.LookupRequest) (*dspb.LookupResponse, error) {
  66. if f.fail {
  67. return nil, errors.New("lookup failed")
  68. }
  69. return &dspb.LookupResponse{}, nil
  70. }
  71. // makeRequests makes some requests.
  72. // span is the root span. rt is the trace client's http client's transport.
  73. // This is used to retrieve the trace uploaded by the client, if any. If
  74. // expectTrace is true, we expect a trace will be uploaded. If synchronous is
  75. // true, the call to Finish is expected not to return before the client has
  76. // uploaded any traces.
  77. func makeRequests(t *testing.T, span *Span, rt *fakeRoundTripper, synchronous bool, expectTrace bool) *http.Request {
  78. ctx := NewContext(context.Background(), span)
  79. tc := newTestClient(&noopTransport{})
  80. // An HTTP request.
  81. {
  82. req2, err := http.NewRequest("GET", "http://example.com/bar", nil)
  83. if err != nil {
  84. t.Fatal(err)
  85. }
  86. resp := &http.Response{StatusCode: 200}
  87. s := span.NewRemoteChild(req2)
  88. s.Finish(WithResponse(resp))
  89. }
  90. // An autogenerated API call.
  91. {
  92. rt := &fakeRoundTripper{reqc: make(chan *http.Request, 1)}
  93. hc := &http.Client{Transport: rt}
  94. computeClient, err := compute.New(hc)
  95. if err != nil {
  96. t.Fatal(err)
  97. }
  98. _, err = computeClient.Zones.List(testProjectID).Context(ctx).Do()
  99. if err != nil {
  100. t.Fatal(err)
  101. }
  102. }
  103. // A cloud library call that uses the autogenerated API.
  104. {
  105. rt := &fakeRoundTripper{reqc: make(chan *http.Request, 1)}
  106. hc := &http.Client{Transport: rt}
  107. storageClient, err := storage.NewClient(context.Background(), option.WithHTTPClient(hc))
  108. if err != nil {
  109. t.Fatal(err)
  110. }
  111. it := storageClient.Bucket("testbucket").Objects(ctx, nil)
  112. for {
  113. _, err := it.Next()
  114. if err != nil && err != iterator.Done {
  115. t.Fatal(err)
  116. }
  117. if err == iterator.Done {
  118. break
  119. }
  120. }
  121. }
  122. // A cloud library call that uses grpc internally.
  123. for _, fail := range []bool{false, true} {
  124. srv, err := testutil.NewServer()
  125. if err != nil {
  126. t.Fatalf("creating test datastore server: %v", err)
  127. }
  128. dspb.RegisterDatastoreServer(srv.Gsrv, &fakeDatastoreServer{fail: fail})
  129. srv.Start()
  130. conn, err := grpc.Dial(srv.Addr, grpc.WithInsecure(), grpc.WithUnaryInterceptor(tc.GRPCClientInterceptor()))
  131. if err != nil {
  132. t.Fatalf("connecting to test datastore server: %v", err)
  133. }
  134. datastoreClient, err := datastore.NewClient(ctx, testProjectID, option.WithGRPCConn(conn))
  135. if err != nil {
  136. t.Fatalf("creating datastore client: %v", err)
  137. }
  138. k := datastore.NameKey("Entity", "stringID", nil)
  139. e := new(datastore.Entity)
  140. datastoreClient.Get(ctx, k, e)
  141. }
  142. done := make(chan struct{})
  143. go func() {
  144. if synchronous {
  145. err := span.FinishWait()
  146. if err != nil {
  147. t.Errorf("Unexpected error from span.FinishWait: %v", err)
  148. }
  149. } else {
  150. span.Finish()
  151. }
  152. done <- struct{}{}
  153. }()
  154. if !expectTrace {
  155. <-done
  156. select {
  157. case <-rt.reqc:
  158. t.Errorf("Got a trace, expected none.")
  159. case <-time.After(5 * time.Millisecond):
  160. }
  161. return nil
  162. } else if !synchronous {
  163. <-done
  164. return <-rt.reqc
  165. } else {
  166. select {
  167. case <-done:
  168. t.Errorf("Synchronous Finish didn't wait for trace upload.")
  169. return <-rt.reqc
  170. case <-time.After(5 * time.Millisecond):
  171. r := <-rt.reqc
  172. <-done
  173. return r
  174. }
  175. }
  176. }
  177. func TestHeader(t *testing.T) {
  178. tests := []struct {
  179. header string
  180. wantTraceID string
  181. wantSpanID uint64
  182. wantOpts optionFlags
  183. wantOK bool
  184. }{
  185. {
  186. header: "0123456789ABCDEF0123456789ABCDEF/1;o=1",
  187. wantTraceID: "0123456789ABCDEF0123456789ABCDEF",
  188. wantSpanID: 1,
  189. wantOpts: 1,
  190. wantOK: true,
  191. },
  192. {
  193. header: "0123456789ABCDEF0123456789ABCDEF/1;o=0",
  194. wantTraceID: "0123456789ABCDEF0123456789ABCDEF",
  195. wantSpanID: 1,
  196. wantOpts: 0,
  197. wantOK: true,
  198. },
  199. {
  200. header: "0123456789ABCDEF0123456789ABCDEF/1",
  201. wantTraceID: "0123456789ABCDEF0123456789ABCDEF",
  202. wantSpanID: 1,
  203. wantOpts: 0,
  204. wantOK: true,
  205. },
  206. {
  207. header: "",
  208. wantTraceID: "",
  209. wantSpanID: 0,
  210. wantOpts: 0,
  211. wantOK: false,
  212. },
  213. }
  214. for _, tt := range tests {
  215. traceID, parentSpanID, opts, _, ok := traceInfoFromHeader(tt.header)
  216. if got, want := traceID, tt.wantTraceID; got != want {
  217. t.Errorf("TraceID(%v) = %q; want %q", tt.header, got, want)
  218. }
  219. if got, want := parentSpanID, tt.wantSpanID; got != want {
  220. t.Errorf("SpanID(%v) = %v; want %v", tt.header, got, want)
  221. }
  222. if got, want := opts, tt.wantOpts; got != want {
  223. t.Errorf("Options(%v) = %v; want %v", tt.header, got, want)
  224. }
  225. if got, want := ok, tt.wantOK; got != want {
  226. t.Errorf("Header exists (%v) = %v; want %v", tt.header, got, want)
  227. }
  228. }
  229. }
  230. func TestOutgoingReqHeader(t *testing.T) {
  231. all, _ := NewLimitedSampler(1, 1<<16) // trace every request
  232. tests := []struct {
  233. desc string
  234. traceHeader string
  235. samplingPolicy SamplingPolicy
  236. wantHeaderRe *regexp.Regexp
  237. }{
  238. {
  239. desc: "Parent span without sampling options, client samples all",
  240. traceHeader: "0123456789ABCDEF0123456789ABCDEF/1",
  241. samplingPolicy: all,
  242. wantHeaderRe: regexp.MustCompile("0123456789ABCDEF0123456789ABCDEF/\\d+;o=1"),
  243. },
  244. {
  245. desc: "Parent span without sampling options, without client sampling",
  246. traceHeader: "0123456789ABCDEF0123456789ABCDEF/1",
  247. samplingPolicy: nil,
  248. wantHeaderRe: regexp.MustCompile("0123456789ABCDEF0123456789ABCDEF/\\d+;o=0"),
  249. },
  250. {
  251. desc: "Parent span with o=1, client samples none",
  252. traceHeader: "0123456789ABCDEF0123456789ABCDEF/1;o=1",
  253. samplingPolicy: nil,
  254. wantHeaderRe: regexp.MustCompile("0123456789ABCDEF0123456789ABCDEF/\\d+;o=1"),
  255. },
  256. {
  257. desc: "Parent span with o=0, without client sampling",
  258. traceHeader: "0123456789ABCDEF0123456789ABCDEF/1;o=0",
  259. samplingPolicy: nil,
  260. wantHeaderRe: regexp.MustCompile("0123456789ABCDEF0123456789ABCDEF/\\d+;o=0"),
  261. },
  262. }
  263. tc := newTestClient(nil)
  264. for _, tt := range tests {
  265. tc.SetSamplingPolicy(tt.samplingPolicy)
  266. span := tc.SpanFromHeader("/foo", tt.traceHeader)
  267. req, _ := http.NewRequest("GET", "http://localhost", nil)
  268. span.NewRemoteChild(req)
  269. if got, re := req.Header.Get(httpHeader), tt.wantHeaderRe; !re.MatchString(got) {
  270. t.Errorf("%v (parent=%q): got header %q; want in format %q", tt.desc, tt.traceHeader, got, re)
  271. }
  272. }
  273. }
  274. func TestTrace(t *testing.T) {
  275. t.Parallel()
  276. testTrace(t, false, true)
  277. }
  278. func TestTraceWithWait(t *testing.T) {
  279. testTrace(t, true, true)
  280. }
  281. func TestTraceFromHeader(t *testing.T) {
  282. t.Parallel()
  283. testTrace(t, false, false)
  284. }
  285. func TestTraceFromHeaderWithWait(t *testing.T) {
  286. testTrace(t, false, true)
  287. }
  288. func TestNewSpan(t *testing.T) {
  289. t.Skip("flaky")
  290. const traceID = "0123456789ABCDEF0123456789ABCDEF"
  291. rt := newFakeRoundTripper()
  292. traceClient := newTestClient(rt)
  293. span := traceClient.NewSpan("/foo")
  294. span.trace.traceID = traceID
  295. uploaded := makeRequests(t, span, rt, true, true)
  296. if uploaded == nil {
  297. t.Fatalf("No trace uploaded, expected one.")
  298. }
  299. expected := api.Traces{
  300. Traces: []*api.Trace{
  301. {
  302. ProjectId: testProjectID,
  303. Spans: []*api.TraceSpan{
  304. {
  305. Kind: "RPC_CLIENT",
  306. Labels: map[string]string{
  307. "trace.cloud.google.com/http/host": "example.com",
  308. "trace.cloud.google.com/http/method": "GET",
  309. "trace.cloud.google.com/http/status_code": "200",
  310. "trace.cloud.google.com/http/url": "http://example.com/bar",
  311. },
  312. Name: "example.com/bar",
  313. },
  314. {
  315. Kind: "RPC_CLIENT",
  316. Labels: map[string]string{
  317. "trace.cloud.google.com/http/host": "www.googleapis.com",
  318. "trace.cloud.google.com/http/method": "GET",
  319. "trace.cloud.google.com/http/status_code": "200",
  320. "trace.cloud.google.com/http/url": "https://www.googleapis.com/compute/v1/projects/testproject/zones",
  321. },
  322. Name: "www.googleapis.com/compute/v1/projects/testproject/zones",
  323. },
  324. {
  325. Kind: "RPC_CLIENT",
  326. Labels: map[string]string{
  327. "trace.cloud.google.com/http/host": "www.googleapis.com",
  328. "trace.cloud.google.com/http/method": "GET",
  329. "trace.cloud.google.com/http/status_code": "200",
  330. "trace.cloud.google.com/http/url": "https://www.googleapis.com/storage/v1/b/testbucket/o",
  331. },
  332. Name: "www.googleapis.com/storage/v1/b/testbucket/o",
  333. },
  334. {
  335. Kind: "RPC_CLIENT",
  336. Labels: nil,
  337. Name: "/google.datastore.v1.Datastore/Lookup",
  338. },
  339. {
  340. Kind: "RPC_CLIENT",
  341. Labels: map[string]string{"error": "rpc error: code = Unknown desc = lookup failed"},
  342. Name: "/google.datastore.v1.Datastore/Lookup",
  343. },
  344. {
  345. Kind: "SPAN_KIND_UNSPECIFIED",
  346. Labels: map[string]string{},
  347. Name: "/foo",
  348. },
  349. },
  350. TraceId: traceID,
  351. },
  352. },
  353. }
  354. body, err := ioutil.ReadAll(uploaded.Body)
  355. if err != nil {
  356. t.Fatal(err)
  357. }
  358. var patch api.Traces
  359. err = json.Unmarshal(body, &patch)
  360. if err != nil {
  361. t.Fatal(err)
  362. }
  363. checkTraces(t, patch, expected)
  364. n := len(patch.Traces[0].Spans)
  365. rootSpan := patch.Traces[0].Spans[n-1]
  366. for i, s := range patch.Traces[0].Spans {
  367. if a, b := s.StartTime, s.EndTime; a > b {
  368. t.Errorf("span %d start time is later than its end time (%q, %q)", i, a, b)
  369. }
  370. if a, b := rootSpan.StartTime, s.StartTime; a > b {
  371. t.Errorf("trace start time is later than span %d start time (%q, %q)", i, a, b)
  372. }
  373. if a, b := s.EndTime, rootSpan.EndTime; a > b {
  374. t.Errorf("span %d end time is later than trace end time (%q, %q)", i, a, b)
  375. }
  376. if i > 1 && i < n-1 {
  377. if a, b := patch.Traces[0].Spans[i-1].EndTime, s.StartTime; a > b {
  378. t.Errorf("span %d end time is later than span %d start time (%q, %q)", i-1, i, a, b)
  379. }
  380. }
  381. }
  382. if x := rootSpan.ParentSpanId; x != 0 {
  383. t.Errorf("Incorrect ParentSpanId: got %d want %d", x, 0)
  384. }
  385. for i, s := range patch.Traces[0].Spans {
  386. if x, y := rootSpan.SpanId, s.ParentSpanId; i < n-1 && x != y {
  387. t.Errorf("Incorrect ParentSpanId in span %d: got %d want %d", i, y, x)
  388. }
  389. }
  390. for i, s := range patch.Traces[0].Spans {
  391. s.EndTime = ""
  392. labels := &expected.Traces[0].Spans[i].Labels
  393. for key, value := range *labels {
  394. if v, ok := s.Labels[key]; !ok {
  395. t.Errorf("Span %d is missing Label %q:%q", i, key, value)
  396. } else if key == "trace.cloud.google.com/http/url" {
  397. if !strings.HasPrefix(v, value) {
  398. t.Errorf("Span %d Label %q: got value %q want prefix %q", i, key, v, value)
  399. }
  400. } else if v != value {
  401. t.Errorf("Span %d Label %q: got value %q want %q", i, key, v, value)
  402. }
  403. }
  404. for key := range s.Labels {
  405. if _, ok := (*labels)[key]; key != "trace.cloud.google.com/stacktrace" && !ok {
  406. t.Errorf("Span %d: unexpected label %q", i, key)
  407. }
  408. }
  409. *labels = nil
  410. s.Labels = nil
  411. s.ParentSpanId = 0
  412. if s.SpanId == 0 {
  413. t.Errorf("Incorrect SpanId: got 0 want nonzero")
  414. }
  415. s.SpanId = 0
  416. s.StartTime = ""
  417. }
  418. if !testutil.Equal(patch, expected) {
  419. got, _ := json.Marshal(patch)
  420. want, _ := json.Marshal(expected)
  421. t.Errorf("PatchTraces request: got %s want %s", got, want)
  422. }
  423. }
  424. func testTrace(t *testing.T, synchronous bool, fromRequest bool) {
  425. t.Skip("flaky")
  426. const header = `0123456789ABCDEF0123456789ABCDEF/42;o=3`
  427. rt := newFakeRoundTripper()
  428. traceClient := newTestClient(rt)
  429. span := traceClient.SpanFromHeader("/foo", header)
  430. headerOrReqLabels := map[string]string{}
  431. headerOrReqName := "/foo"
  432. if fromRequest {
  433. req, err := http.NewRequest("GET", "http://example.com/foo", nil)
  434. if err != nil {
  435. t.Fatal(err)
  436. }
  437. req.Header.Set("X-Cloud-Trace-Context", header)
  438. span = traceClient.SpanFromRequest(req)
  439. headerOrReqLabels = map[string]string{
  440. "trace.cloud.google.com/http/host": "example.com",
  441. "trace.cloud.google.com/http/method": "GET",
  442. "trace.cloud.google.com/http/url": "http://example.com/foo",
  443. }
  444. headerOrReqName = "example.com/foo"
  445. }
  446. uploaded := makeRequests(t, span, rt, synchronous, true)
  447. if uploaded == nil {
  448. t.Fatalf("No trace uploaded, expected one.")
  449. }
  450. expected := api.Traces{
  451. Traces: []*api.Trace{
  452. {
  453. ProjectId: testProjectID,
  454. Spans: []*api.TraceSpan{
  455. {
  456. Kind: "RPC_CLIENT",
  457. Labels: map[string]string{
  458. "trace.cloud.google.com/http/host": "example.com",
  459. "trace.cloud.google.com/http/method": "GET",
  460. "trace.cloud.google.com/http/status_code": "200",
  461. "trace.cloud.google.com/http/url": "http://example.com/bar",
  462. },
  463. Name: "example.com/bar",
  464. },
  465. {
  466. Kind: "RPC_CLIENT",
  467. Labels: map[string]string{
  468. "trace.cloud.google.com/http/host": "www.googleapis.com",
  469. "trace.cloud.google.com/http/method": "GET",
  470. "trace.cloud.google.com/http/status_code": "200",
  471. "trace.cloud.google.com/http/url": "https://www.googleapis.com/compute/v1/projects/testproject/zones",
  472. },
  473. Name: "www.googleapis.com/compute/v1/projects/testproject/zones",
  474. },
  475. {
  476. Kind: "RPC_CLIENT",
  477. Labels: map[string]string{
  478. "trace.cloud.google.com/http/host": "www.googleapis.com",
  479. "trace.cloud.google.com/http/method": "GET",
  480. "trace.cloud.google.com/http/status_code": "200",
  481. "trace.cloud.google.com/http/url": "https://www.googleapis.com/storage/v1/b/testbucket/o",
  482. },
  483. Name: "www.googleapis.com/storage/v1/b/testbucket/o",
  484. },
  485. {
  486. Kind: "RPC_CLIENT",
  487. Labels: nil,
  488. Name: "/google.datastore.v1.Datastore/Lookup",
  489. },
  490. {
  491. Kind: "RPC_CLIENT",
  492. Labels: map[string]string{"error": "rpc error: code = Unknown desc = lookup failed"},
  493. Name: "/google.datastore.v1.Datastore/Lookup",
  494. },
  495. {
  496. Kind: "RPC_SERVER",
  497. Labels: headerOrReqLabels,
  498. Name: headerOrReqName,
  499. },
  500. },
  501. TraceId: "0123456789ABCDEF0123456789ABCDEF",
  502. },
  503. },
  504. }
  505. body, err := ioutil.ReadAll(uploaded.Body)
  506. if err != nil {
  507. t.Fatal(err)
  508. }
  509. var patch api.Traces
  510. err = json.Unmarshal(body, &patch)
  511. if err != nil {
  512. t.Fatal(err)
  513. }
  514. checkTraces(t, patch, expected)
  515. n := len(patch.Traces[0].Spans)
  516. rootSpan := patch.Traces[0].Spans[n-1]
  517. for i, s := range patch.Traces[0].Spans {
  518. if a, b := s.StartTime, s.EndTime; a > b {
  519. t.Errorf("span %d start time is later than its end time (%q, %q)", i, a, b)
  520. }
  521. if a, b := rootSpan.StartTime, s.StartTime; a > b {
  522. t.Errorf("trace start time is later than span %d start time (%q, %q)", i, a, b)
  523. }
  524. if a, b := s.EndTime, rootSpan.EndTime; a > b {
  525. t.Errorf("span %d end time is later than trace end time (%q, %q)", i, a, b)
  526. }
  527. if i > 1 && i < n-1 {
  528. if a, b := patch.Traces[0].Spans[i-1].EndTime, s.StartTime; a > b {
  529. t.Errorf("span %d end time is later than span %d start time (%q, %q)", i-1, i, a, b)
  530. }
  531. }
  532. }
  533. if x := rootSpan.ParentSpanId; x != 42 {
  534. t.Errorf("Incorrect ParentSpanId: got %d want %d", x, 42)
  535. }
  536. for i, s := range patch.Traces[0].Spans {
  537. if x, y := rootSpan.SpanId, s.ParentSpanId; i < n-1 && x != y {
  538. t.Errorf("Incorrect ParentSpanId in span %d: got %d want %d", i, y, x)
  539. }
  540. }
  541. for i, s := range patch.Traces[0].Spans {
  542. s.EndTime = ""
  543. labels := &expected.Traces[0].Spans[i].Labels
  544. for key, value := range *labels {
  545. if v, ok := s.Labels[key]; !ok {
  546. t.Errorf("Span %d is missing Label %q:%q", i, key, value)
  547. } else if key == "trace.cloud.google.com/http/url" {
  548. if !strings.HasPrefix(v, value) {
  549. t.Errorf("Span %d Label %q: got value %q want prefix %q", i, key, v, value)
  550. }
  551. } else if v != value {
  552. t.Errorf("Span %d Label %q: got value %q want %q", i, key, v, value)
  553. }
  554. }
  555. for key := range s.Labels {
  556. if _, ok := (*labels)[key]; key != "trace.cloud.google.com/stacktrace" && !ok {
  557. t.Errorf("Span %d: unexpected label %q", i, key)
  558. }
  559. }
  560. *labels = nil
  561. s.Labels = nil
  562. s.ParentSpanId = 0
  563. if s.SpanId == 0 {
  564. t.Errorf("Incorrect SpanId: got 0 want nonzero")
  565. }
  566. s.SpanId = 0
  567. s.StartTime = ""
  568. }
  569. if !testutil.Equal(patch, expected) {
  570. got, _ := json.Marshal(patch)
  571. want, _ := json.Marshal(expected)
  572. t.Errorf("PatchTraces request: got %s \n\n want %s", got, want)
  573. }
  574. }
  575. func TestNoTrace(t *testing.T) {
  576. testNoTrace(t, false, true)
  577. }
  578. func TestNoTraceWithWait(t *testing.T) {
  579. testNoTrace(t, true, true)
  580. }
  581. func TestNoTraceFromHeader(t *testing.T) {
  582. testNoTrace(t, false, false)
  583. }
  584. func TestNoTraceFromHeaderWithWait(t *testing.T) {
  585. testNoTrace(t, true, false)
  586. }
  587. func testNoTrace(t *testing.T, synchronous bool, fromRequest bool) {
  588. for _, header := range []string{
  589. `0123456789ABCDEF0123456789ABCDEF/42;o=2`,
  590. `0123456789ABCDEF0123456789ABCDEF/42;o=0`,
  591. `0123456789ABCDEF0123456789ABCDEF/42`,
  592. `0123456789ABCDEF0123456789ABCDEF`,
  593. ``,
  594. } {
  595. rt := newFakeRoundTripper()
  596. traceClient := newTestClient(rt)
  597. var span *Span
  598. if fromRequest {
  599. req, err := http.NewRequest("GET", "http://example.com/foo", nil)
  600. if header != "" {
  601. req.Header.Set("X-Cloud-Trace-Context", header)
  602. }
  603. if err != nil {
  604. t.Fatal(err)
  605. }
  606. span = traceClient.SpanFromRequest(req)
  607. } else {
  608. span = traceClient.SpanFromHeader("/foo", header)
  609. }
  610. uploaded := makeRequests(t, span, rt, synchronous, false)
  611. if uploaded != nil {
  612. t.Errorf("Got a trace, expected none.")
  613. }
  614. }
  615. }
  616. func TestSample(t *testing.T) {
  617. // A deterministic test of the sampler logic.
  618. type testCase struct {
  619. rate float64
  620. maxqps float64
  621. want int
  622. }
  623. const delta = 25 * time.Millisecond
  624. for _, test := range []testCase{
  625. // qps won't matter, so we will sample half of the 79 calls
  626. {0.50, 100, 40},
  627. // with 1 qps and a burst of 2, we will sample twice in second #1, once in the partial second #2
  628. {0.50, 1, 3},
  629. } {
  630. sp, err := NewLimitedSampler(test.rate, test.maxqps)
  631. if err != nil {
  632. t.Fatal(err)
  633. }
  634. s := sp.(*sampler)
  635. sampled := 0
  636. tm := time.Now()
  637. for i := 0; i < 80; i++ {
  638. if s.sample(Parameters{}, tm, float64(i%2)).Sample {
  639. sampled++
  640. }
  641. tm = tm.Add(delta)
  642. }
  643. if sampled != test.want {
  644. t.Errorf("rate=%f, maxqps=%f: got %d samples, want %d", test.rate, test.maxqps, sampled, test.want)
  645. }
  646. }
  647. }
  648. func TestSampling(t *testing.T) {
  649. t.Parallel()
  650. // This scope tests sampling in a larger context, with real time and randomness.
  651. wg := sync.WaitGroup{}
  652. type testCase struct {
  653. rate float64
  654. maxqps float64
  655. expectedRange [2]int
  656. }
  657. for _, test := range []testCase{
  658. {0, 5, [2]int{0, 0}},
  659. {5, 0, [2]int{0, 0}},
  660. {0.50, 100, [2]int{20, 60}},
  661. {0.50, 1, [2]int{3, 4}}, // Windows, with its less precise clock, sometimes gives 4.
  662. } {
  663. wg.Add(1)
  664. go func(test testCase) {
  665. rt := newFakeRoundTripper()
  666. traceClient := newTestClient(rt)
  667. traceClient.bundler.BundleByteLimit = 1
  668. p, err := NewLimitedSampler(test.rate, test.maxqps)
  669. if err != nil {
  670. t.Errorf("NewLimitedSampler: %v", err)
  671. }
  672. traceClient.SetSamplingPolicy(p)
  673. ticker := time.NewTicker(25 * time.Millisecond)
  674. sampled := 0
  675. for i := 0; i < 79; i++ {
  676. req, err := http.NewRequest("GET", "http://example.com/foo", nil)
  677. if err != nil {
  678. t.Error(err)
  679. }
  680. span := traceClient.SpanFromRequest(req)
  681. span.Finish()
  682. select {
  683. case <-rt.reqc:
  684. <-ticker.C
  685. sampled++
  686. case <-ticker.C:
  687. }
  688. }
  689. ticker.Stop()
  690. if test.expectedRange[0] > sampled || sampled > test.expectedRange[1] {
  691. t.Errorf("rate=%f, maxqps=%f: got %d samples want ∈ %v", test.rate, test.maxqps, sampled, test.expectedRange)
  692. }
  693. wg.Done()
  694. }(test)
  695. }
  696. wg.Wait()
  697. }
  698. func TestBundling(t *testing.T) {
  699. t.Parallel()
  700. rt := newFakeRoundTripper()
  701. traceClient := newTestClient(rt)
  702. traceClient.bundler.DelayThreshold = time.Second / 2
  703. traceClient.bundler.BundleCountThreshold = 10
  704. p, err := NewLimitedSampler(1, 99) // sample every request.
  705. if err != nil {
  706. t.Fatalf("NewLimitedSampler: %v", err)
  707. }
  708. traceClient.SetSamplingPolicy(p)
  709. for i := 0; i < 35; i++ {
  710. go func() {
  711. req, err := http.NewRequest("GET", "http://example.com/foo", nil)
  712. if err != nil {
  713. t.Error(err)
  714. }
  715. span := traceClient.SpanFromRequest(req)
  716. span.Finish()
  717. }()
  718. }
  719. // Read the first three bundles.
  720. <-rt.reqc
  721. <-rt.reqc
  722. <-rt.reqc
  723. // Test that the fourth bundle isn't sent early.
  724. select {
  725. case <-rt.reqc:
  726. t.Errorf("bundle sent too early")
  727. case <-time.After(time.Second / 4):
  728. <-rt.reqc
  729. }
  730. // Test that there aren't extra bundles.
  731. select {
  732. case <-rt.reqc:
  733. t.Errorf("too many bundles sent")
  734. case <-time.After(time.Second):
  735. }
  736. }
  737. func TestWeights(t *testing.T) {
  738. const (
  739. expectedNumTraced = 10100
  740. numTracedEpsilon = 100
  741. expectedTotalWeight = 50000
  742. totalWeightEpsilon = 5000
  743. )
  744. rng := rand.New(rand.NewSource(1))
  745. const delta = 2 * time.Millisecond
  746. for _, headerRate := range []float64{0.0, 0.5, 1.0} {
  747. // Simulate 10 seconds of requests arriving at 500qps.
  748. //
  749. // The sampling policy tries to sample 25% of them, but has a qps limit of
  750. // 100, so it will not be able to. The returned weight should be higher
  751. // for some sampled requests to compensate.
  752. //
  753. // headerRate is the fraction of incoming requests that have a trace header
  754. // set. The qps limit should not be exceeded, even if headerRate is high.
  755. sp, err := NewLimitedSampler(0.25, 100)
  756. if err != nil {
  757. t.Fatal(err)
  758. }
  759. s := sp.(*sampler)
  760. tm := time.Now()
  761. totalWeight := 0.0
  762. numTraced := 0
  763. seenLargeWeight := false
  764. for i := 0; i < 50000; i++ {
  765. d := s.sample(Parameters{HasTraceHeader: rng.Float64() < headerRate}, tm, rng.Float64())
  766. if d.Trace {
  767. numTraced++
  768. }
  769. if d.Sample {
  770. totalWeight += d.Weight
  771. if x := int(d.Weight) / 4; x <= 0 || x >= 100 || d.Weight != float64(x)*4.0 {
  772. t.Errorf("weight: got %f, want a small positive multiple of 4", d.Weight)
  773. }
  774. if d.Weight > 4 {
  775. seenLargeWeight = true
  776. }
  777. }
  778. tm = tm.Add(delta)
  779. }
  780. if !seenLargeWeight {
  781. t.Errorf("headerRate %f: never saw sample weight higher than 4.", headerRate)
  782. }
  783. if numTraced < expectedNumTraced-numTracedEpsilon || expectedNumTraced+numTracedEpsilon < numTraced {
  784. t.Errorf("headerRate %f: got %d traced requests, want ∈ [%d, %d]", headerRate, numTraced, expectedNumTraced-numTracedEpsilon, expectedNumTraced+numTracedEpsilon)
  785. }
  786. if totalWeight < expectedTotalWeight-totalWeightEpsilon || expectedTotalWeight+totalWeightEpsilon < totalWeight {
  787. t.Errorf("headerRate %f: got total weight %f want ∈ [%d, %d]", headerRate, totalWeight, expectedTotalWeight-totalWeightEpsilon, expectedTotalWeight+totalWeightEpsilon)
  788. }
  789. }
  790. }
  791. type alwaysTrace struct{}
  792. func (a alwaysTrace) Sample(p Parameters) Decision {
  793. return Decision{Trace: true}
  794. }
  795. type neverTrace struct{}
  796. func (a neverTrace) Sample(p Parameters) Decision {
  797. return Decision{Trace: false}
  798. }
  799. func TestPropagation(t *testing.T) {
  800. rt := newFakeRoundTripper()
  801. traceClient := newTestClient(rt)
  802. for _, header := range []string{
  803. `0123456789ABCDEF0123456789ABCDEF/42;o=0`,
  804. `0123456789ABCDEF0123456789ABCDEF/42;o=1`,
  805. `0123456789ABCDEF0123456789ABCDEF/42;o=2`,
  806. `0123456789ABCDEF0123456789ABCDEF/42;o=3`,
  807. `0123456789ABCDEF0123456789ABCDEF/0;o=0`,
  808. `0123456789ABCDEF0123456789ABCDEF/0;o=1`,
  809. `0123456789ABCDEF0123456789ABCDEF/0;o=2`,
  810. `0123456789ABCDEF0123456789ABCDEF/0;o=3`,
  811. ``,
  812. } {
  813. for _, policy := range []SamplingPolicy{
  814. nil,
  815. alwaysTrace{},
  816. neverTrace{},
  817. } {
  818. traceClient.SetSamplingPolicy(policy)
  819. req, err := http.NewRequest("GET", "http://example.com/foo", nil)
  820. if err != nil {
  821. t.Fatal(err)
  822. }
  823. if header != "" {
  824. req.Header.Set("X-Cloud-Trace-Context", header)
  825. }
  826. span := traceClient.SpanFromRequest(req)
  827. req2, err := http.NewRequest("GET", "http://example.com/bar", nil)
  828. if err != nil {
  829. t.Fatal(err)
  830. }
  831. req3, err := http.NewRequest("GET", "http://example.com/baz", nil)
  832. if err != nil {
  833. t.Fatal(err)
  834. }
  835. span.NewRemoteChild(req2)
  836. span.NewRemoteChild(req3)
  837. var (
  838. t1, t2, t3 string
  839. s1, s2, s3 uint64
  840. o1, o2, o3 uint64
  841. )
  842. fmt.Sscanf(header, "%32s/%d;o=%d", &t1, &s1, &o1)
  843. fmt.Sscanf(req2.Header.Get("X-Cloud-Trace-Context"), "%32s/%d;o=%d", &t2, &s2, &o2)
  844. fmt.Sscanf(req3.Header.Get("X-Cloud-Trace-Context"), "%32s/%d;o=%d", &t3, &s3, &o3)
  845. if header == "" {
  846. if t2 != t3 {
  847. t.Errorf("expected the same trace ID in child requests, got %q %q", t2, t3)
  848. }
  849. } else {
  850. if t2 != t1 || t3 != t1 {
  851. t.Errorf("trace IDs should be passed to child requests")
  852. }
  853. }
  854. trace := policy == alwaysTrace{} || policy == nil && (o1&1) != 0
  855. if header == "" {
  856. if trace && (s2 == 0 || s3 == 0) {
  857. t.Errorf("got span IDs %d %d in child requests, want nonzero", s2, s3)
  858. }
  859. if trace && s2 == s3 {
  860. t.Errorf("got span IDs %d %d in child requests, should be different", s2, s3)
  861. }
  862. if !trace && (s2 != 0 || s3 != 0) {
  863. t.Errorf("got span IDs %d %d in child requests, want zero", s2, s3)
  864. }
  865. } else {
  866. if trace && (s2 == s1 || s3 == s1 || s2 == s3) {
  867. t.Errorf("parent span IDs in input and outputs should be all different, got %d %d %d", s1, s2, s3)
  868. }
  869. if !trace && (s2 != s1 || s3 != s1) {
  870. t.Errorf("parent span ID in input, %d, should have been equal to parent span IDs in output: %d %d", s1, s2, s3)
  871. }
  872. }
  873. expectTraceOption := policy == alwaysTrace{} || (o1&1) != 0
  874. if expectTraceOption != ((o2&1) != 0) || expectTraceOption != ((o3&1) != 0) {
  875. t.Errorf("tracing flag in child requests should be %t, got options %d %d", expectTraceOption, o2, o3)
  876. }
  877. }
  878. }
  879. }
  880. func BenchmarkSpanFromHeader(b *testing.B) {
  881. const header = `0123456789ABCDEF0123456789ABCDEF/42;o=0`
  882. const name = "/foo"
  883. rt := newFakeRoundTripper()
  884. traceClient := newTestClient(rt)
  885. for n := 0; n < b.N; n++ {
  886. traceClient.SpanFromHeader(name, header)
  887. }
  888. }
  889. func checkTraces(t *testing.T, patch, expected api.Traces) {
  890. if len(patch.Traces) != len(expected.Traces) || len(patch.Traces[0].Spans) != len(expected.Traces[0].Spans) {
  891. diff := testutil.Diff(patch.Traces, expected.Traces)
  892. t.Logf("diff:\n%s", diff)
  893. got, _ := json.Marshal(patch)
  894. want, _ := json.Marshal(expected)
  895. t.Fatalf("PatchTraces request: got %s want %s", got, want)
  896. }
  897. }