get.pme.sh/pnats@v0.0.0-20240304004023-26bb5a137ed0/server/msgtrace_test.go (about) 1 // Copyright 2024 The NATS Authors 2 // Licensed under the Apache License, Version 2.0 (the "License"); 3 // you may not use this file except in compliance with the License. 4 // You may obtain a copy of the License at 5 // 6 // http://www.apache.org/licenses/LICENSE-2.0 7 // 8 // Unless required by applicable law or agreed to in writing, software 9 // distributed under the License is distributed on an "AS IS" BASIS, 10 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 11 // See the License for the specific language governing permissions and 12 // limitations under the License. 13 14 package server 15 16 import ( 17 "bytes" 18 "compress/gzip" 19 "encoding/json" 20 "fmt" 21 "io" 22 "net" 23 "strings" 24 "sync/atomic" 25 "testing" 26 "time" 27 28 "github.com/klauspost/compress/s2" 29 "github.com/nats-io/jwt/v2" 30 "github.com/nats-io/nats.go" 31 "github.com/nats-io/nkeys" 32 ) 33 34 func init() { 35 msgTraceRunInTests = true 36 } 37 38 func TestMsgTraceConnName(t *testing.T) { 39 c := &client{kind: ROUTER, route: &route{remoteName: "somename"}} 40 c.opts.Name = "someid" 41 42 // If route.remoteName is set, it will take precedence. 43 val := getConnName(c) 44 require_Equal[string](t, val, "somename") 45 // When not set, we revert to c.opts.Name 46 c.route.remoteName = _EMPTY_ 47 val = getConnName(c) 48 require_Equal[string](t, val, "someid") 49 50 // Now same for GW. 51 c.route = nil 52 c.gw = &gateway{remoteName: "somename"} 53 c.kind = GATEWAY 54 val = getConnName(c) 55 require_Equal[string](t, val, "somename") 56 // Revert to c.opts.Name 57 c.gw.remoteName = _EMPTY_ 58 val = getConnName(c) 59 require_Equal[string](t, val, "someid") 60 61 // For LeafNode now 62 c.gw = nil 63 c.leaf = &leaf{remoteServer: "somename"} 64 c.kind = LEAF 65 val = getConnName(c) 66 require_Equal[string](t, val, "somename") 67 // But if not set... 68 c.leaf.remoteServer = _EMPTY_ 69 val = getConnName(c) 70 require_Equal[string](t, val, "someid") 71 72 c.leaf = nil 73 c.kind = CLIENT 74 val = getConnName(c) 75 require_Equal[string](t, val, "someid") 76 } 77 78 func TestMsgTraceGenHeaderMap(t *testing.T) { 79 for _, test := range []struct { 80 name string 81 header []byte 82 expected map[string][]string 83 external bool 84 }{ 85 {"missing header line", []byte("Nats-Trace-Dest: val\r\n"), nil, false}, 86 {"no trace header present", []byte(hdrLine + "Header1: val1\r\nHeader2: val2\r\n"), nil, false}, 87 {"trace header with some prefix", []byte(hdrLine + "Some-Prefix-" + MsgTraceDest + ": some value\r\n"), nil, false}, 88 {"trace header with some suffix", []byte(hdrLine + MsgTraceDest + "-Some-Suffix: some value\r\n"), nil, false}, 89 {"trace header with space before colon", []byte(hdrLine + MsgTraceDest + " : some value\r\n"), nil, false}, 90 {"trace header with missing cr_lf for value", []byte(hdrLine + MsgTraceDest + " : bogus"), nil, false}, 91 {"external trace header with some prefix", []byte(hdrLine + "Some-Prefix-" + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\n"), nil, false}, 92 {"external trace header with some suffix", []byte(hdrLine + traceParentHdr + "-Some-Suffix: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\n"), nil, false}, 93 {"external header with space before colon", []byte(hdrLine + traceParentHdr + " : 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\n"), nil, false}, 94 {"external header with missing cr_lf for value", []byte(hdrLine + traceParentHdr + " : 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"), nil, false}, 95 {"trace header first", []byte(hdrLine + MsgTraceDest + ": some.dest\r\nSome-Header: some value\r\n"), 96 map[string][]string{"Some-Header": {"some value"}, MsgTraceDest: {"some.dest"}}, false}, 97 {"trace header last", []byte(hdrLine + "Some-Header: some value\r\n" + MsgTraceDest + ": some.dest\r\n"), 98 map[string][]string{"Some-Header": {"some value"}, MsgTraceDest: {"some.dest"}}, false}, 99 {"trace header multiple values", []byte(hdrLine + MsgTraceDest + ": some.dest\r\nSome-Header: some value\r\n" + MsgTraceDest + ": some.dest.2"), 100 map[string][]string{"Some-Header": {"some value"}, MsgTraceDest: {"some.dest", "some.dest.2"}}, false}, 101 {"trace header and some empty key", []byte(hdrLine + MsgTraceDest + ": some.dest\r\n: bogus\r\nSome-Header: some value\r\n"), 102 map[string][]string{"Some-Header": {"some value"}, MsgTraceDest: {"some.dest"}}, false}, 103 {"trace header and some header missing cr_lf for value", []byte(hdrLine + MsgTraceDest + ": some.dest\r\nSome-Header: bogus"), 104 map[string][]string{MsgTraceDest: {"some.dest"}}, false}, 105 {"trace header and external after", []byte(hdrLine + MsgTraceDest + ": some.dest\r\n" + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\nSome-Header: some value\r\n"), 106 map[string][]string{"Some-Header": {"some value"}, MsgTraceDest: {"some.dest"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}}, false}, 107 {"trace header and external before", []byte(hdrLine + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\n" + MsgTraceDest + ": some.dest\r\nSome-Header: some value\r\n"), 108 map[string][]string{"Some-Header": {"some value"}, MsgTraceDest: {"some.dest"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}}, false}, 109 {"external malformed", []byte(hdrLine + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-01\r\n"), nil, false}, 110 {"external first and sampling", []byte(hdrLine + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\nSome-Header: some value\r\n"), 111 map[string][]string{"Some-Header": {"some value"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}}, true}, 112 {"external middle and sampling", []byte(hdrLine + "Some-Header: some value1\r\n" + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\nSome-Header: some value2\r\n"), 113 map[string][]string{"Some-Header": {"some value1", "some value2"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}}, true}, 114 {"external last and sampling", []byte(hdrLine + "Some-Header: some value\r\n" + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\n"), 115 map[string][]string{"Some-Header": {"some value"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}}, true}, 116 {"external sampling with not just 01", []byte(hdrLine + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-27\r\nSome-Header: some value\r\n"), 117 map[string][]string{"Some-Header": {"some value"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-27"}}, true}, 118 {"external with different case and sampling", []byte(hdrLine + "TrAcEpArEnT: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\r\nSome-Header: some value\r\n"), 119 map[string][]string{"Some-Header": {"some value"}, traceParentHdr: {"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}}, true}, 120 {"external first and not sampling", []byte(hdrLine + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00\r\nSome-Header: some value\r\n"), nil, false}, 121 {"external middle and not sampling", []byte(hdrLine + "Some-Header: some value1\r\n" + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00\r\nSome-Header: some value2\r\n"), nil, false}, 122 {"external last and not sampling", []byte(hdrLine + "Some-Header: some value\r\n" + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00\r\n"), nil, false}, 123 {"external not sampling with not just 00", []byte(hdrLine + traceParentHdr + ": 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-22\r\nSome-Header: some value\r\n"), nil, false}, 124 } { 125 t.Run(test.name, func(t *testing.T) { 126 m, ext := genHeaderMapIfTraceHeadersPresent(test.header) 127 if test.external != ext { 128 t.Fatalf("Expected external to be %v, got %v", test.external, ext) 129 } 130 if len(test.expected) != len(m) { 131 t.Fatalf("Expected map to be of size %v, got %v", len(test.expected), len(m)) 132 } 133 // If external, we should find traceParentHdr 134 if test.external { 135 if _, ok := m[traceParentHdr]; !ok { 136 t.Fatalf("Expected traceparent header to be present, it was not: %+v", m) 137 } 138 // Header should have been rewritten, so we should find it in original header. 139 if !bytes.Contains(test.header, []byte(traceParentHdr)) { 140 t.Fatalf("Header should have been rewritten to have the traceparent in lower case: %s", test.header) 141 } 142 } 143 for k, vv := range m { 144 evv, ok := test.expected[k] 145 if !ok { 146 t.Fatalf("Did not find header %q in resulting map: %+v", k, m) 147 } 148 for i, v := range vv { 149 if evv[i] != v { 150 t.Fatalf("Expected value %v of key %q to be %q, got %q", i, k, evv[i], v) 151 } 152 } 153 } 154 }) 155 } 156 } 157 158 func TestMsgTraceBasic(t *testing.T) { 159 conf := createConfFile(t, []byte(` 160 listen: 127.0.0.1:-1 161 mappings = { 162 foo: bar 163 } 164 `)) 165 s, _ := RunServerWithConfig(conf) 166 defer s.Shutdown() 167 168 nc := natsConnect(t, s.ClientURL()) 169 defer nc.Close() 170 cid, err := nc.GetClientID() 171 require_NoError(t, err) 172 173 traceSub := natsSubSync(t, nc, "my.trace.subj") 174 natsFlush(t, nc) 175 176 // Send trace message to a dummy subject to check that resulting trace's 177 // SubjectMapping and Egress are nil. 178 msg := nats.NewMsg("dummy") 179 msg.Header.Set(MsgTraceDest, traceSub.Subject) 180 msg.Header.Set(MsgTraceOnly, "true") 181 msg.Data = []byte("hello!") 182 err = nc.PublishMsg(msg) 183 require_NoError(t, err) 184 185 traceMsg := natsNexMsg(t, traceSub, time.Second) 186 var e MsgTraceEvent 187 json.Unmarshal(traceMsg.Data, &e) 188 require_Equal[string](t, e.Server.Name, s.Name()) 189 // We don't remove the headers, so we will find the tracing header there. 190 require_True(t, e.Request.Header != nil) 191 require_Equal[int](t, len(e.Request.Header), 2) 192 // The message size is 6 + whatever size for the 2 trace headers. 193 // Let's just make sure that size is > 20... 194 require_True(t, e.Request.MsgSize > 20) 195 ingress := e.Ingress() 196 require_True(t, ingress != nil) 197 require_True(t, ingress.Kind == CLIENT) 198 require_True(t, ingress.Timestamp != time.Time{}) 199 require_Equal[uint64](t, ingress.CID, cid) 200 require_Equal[string](t, ingress.Name, _EMPTY_) 201 require_Equal[string](t, ingress.Account, globalAccountName) 202 require_Equal[string](t, ingress.Subject, "dummy") 203 require_Equal[string](t, ingress.Error, _EMPTY_) 204 require_True(t, e.SubjectMapping() == nil) 205 require_True(t, e.StreamExports() == nil) 206 require_True(t, e.ServiceImports() == nil) 207 require_True(t, e.JetStream() == nil) 208 require_True(t, e.Egresses() == nil) 209 210 // Now setup subscriptions that generate interest on the subject. 211 nc2 := natsConnect(t, s.ClientURL(), nats.Name("sub1And2")) 212 defer nc2.Close() 213 sub1 := natsSubSync(t, nc2, "bar") 214 sub2 := natsSubSync(t, nc2, "bar") 215 natsFlush(t, nc2) 216 nc2CID, _ := nc2.GetClientID() 217 218 nc3 := natsConnect(t, s.ClientURL()) 219 defer nc3.Close() 220 sub3 := natsSubSync(t, nc3, "*") 221 natsFlush(t, nc3) 222 223 for _, test := range []struct { 224 name string 225 deliverMsg bool 226 }{ 227 {"just trace", false}, 228 {"deliver msg", true}, 229 } { 230 t.Run(test.name, func(t *testing.T) { 231 msg = nats.NewMsg("foo") 232 msg.Header.Set("Some-App-Header", "some value") 233 msg.Header.Set(MsgTraceDest, traceSub.Subject) 234 if !test.deliverMsg { 235 msg.Header.Set(MsgTraceOnly, "true") 236 } 237 msg.Data = []byte("hello!") 238 err = nc.PublishMsg(msg) 239 require_NoError(t, err) 240 241 checkAppMsg := func(sub *nats.Subscription, expected bool) { 242 if expected { 243 appMsg := natsNexMsg(t, sub, time.Second) 244 require_Equal[string](t, string(appMsg.Data), "hello!") 245 // We don't remove message trace header, so we should have 246 // 2 headers (the app + trace destination) 247 require_True(t, len(appMsg.Header) == 2) 248 require_Equal[string](t, appMsg.Header.Get("Some-App-Header"), "some value") 249 require_Equal[string](t, appMsg.Header.Get(MsgTraceDest), traceSub.Subject) 250 } 251 // Check that no (more) messages are received. 252 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 253 t.Fatalf("Did not expect application message, got %s", msg.Data) 254 } 255 } 256 for _, sub := range []*nats.Subscription{sub1, sub2, sub3} { 257 checkAppMsg(sub, test.deliverMsg) 258 } 259 260 traceMsg = natsNexMsg(t, traceSub, time.Second) 261 e = MsgTraceEvent{} 262 json.Unmarshal(traceMsg.Data, &e) 263 require_Equal[string](t, e.Server.Name, s.Name()) 264 require_True(t, e.Request.Header != nil) 265 // We should have the app header and the trace header(s) too. 266 expected := 2 267 if !test.deliverMsg { 268 // The "trace-only" header is added. 269 expected++ 270 } 271 require_Equal[int](t, len(e.Request.Header), expected) 272 require_Equal[string](t, e.Request.Header["Some-App-Header"][0], "some value") 273 // The message size is 6 + whatever size for the 2 trace headers. 274 // Let's just make sure that size is > 20... 275 require_True(t, e.Request.MsgSize > 20) 276 ingress := e.Ingress() 277 require_True(t, ingress.Kind == CLIENT) 278 require_True(t, ingress.Timestamp != time.Time{}) 279 require_Equal[string](t, ingress.Account, globalAccountName) 280 require_Equal[string](t, ingress.Subject, "foo") 281 sm := e.SubjectMapping() 282 require_True(t, sm != nil) 283 require_True(t, sm.Timestamp != time.Time{}) 284 require_Equal[string](t, sm.MappedTo, "bar") 285 egress := e.Egresses() 286 require_Equal[int](t, len(egress), 3) 287 var sub1And2 int 288 for _, eg := range egress { 289 // All Egress should be clients 290 require_True(t, eg.Kind == CLIENT) 291 require_True(t, eg.Timestamp != time.Time{}) 292 // For nc2CID, we should have two egress 293 if eg.CID == nc2CID { 294 // Check name 295 require_Equal[string](t, eg.Name, "sub1And2") 296 require_Equal[string](t, eg.Subscription, "bar") 297 sub1And2++ 298 } else { 299 // No name set 300 require_Equal[string](t, eg.Name, _EMPTY_) 301 require_Equal[string](t, eg.Subscription, "*") 302 } 303 } 304 require_Equal[int](t, sub1And2, 2) 305 }) 306 } 307 } 308 309 func TestMsgTraceIngressMaxPayloadError(t *testing.T) { 310 o := DefaultOptions() 311 o.MaxPayload = 1024 312 s := RunServer(o) 313 defer s.Shutdown() 314 315 nc := natsConnect(t, s.ClientURL()) 316 defer nc.Close() 317 318 traceSub := natsSubSync(t, nc, "my.trace.subj") 319 natsSub(t, nc, "foo", func(_ *nats.Msg) {}) 320 natsFlush(t, nc) 321 322 for _, test := range []struct { 323 name string 324 deliverMsg bool 325 }{ 326 {"just trace", false}, 327 {"deliver msg", true}, 328 } { 329 t.Run(test.name, func(t *testing.T) { 330 nc2, err := net.Dial("tcp", fmt.Sprintf("127.0.0.1:%d", o.Port)) 331 require_NoError(t, err) 332 defer nc2.Close() 333 334 nc2.Write([]byte("CONNECT {\"protocol\":1,\"headers\":true,\"no_responders\":true}\r\n")) 335 336 var traceOnlyHdr string 337 if !test.deliverMsg { 338 traceOnlyHdr = fmt.Sprintf("%s:true\r\n", MsgTraceOnly) 339 } 340 hdr := fmt.Sprintf("%s%s:%s\r\n%s\r\n", hdrLine, MsgTraceDest, traceSub.Subject, traceOnlyHdr) 341 hPub := fmt.Sprintf("HPUB foo %d 2048\r\n%sAAAAAAAAAAAAAAAAAA...", len(hdr), hdr) 342 nc2.Write([]byte(hPub)) 343 344 traceMsg := natsNexMsg(t, traceSub, time.Second) 345 var e MsgTraceEvent 346 json.Unmarshal(traceMsg.Data, &e) 347 require_Equal[string](t, e.Server.Name, s.Name()) 348 require_True(t, e.Request.Header == nil) 349 require_True(t, e.Ingress() != nil) 350 require_Contains(t, e.Ingress().Error, ErrMaxPayload.Error()) 351 require_True(t, e.Egresses() == nil) 352 }) 353 } 354 } 355 356 func TestMsgTraceIngressErrors(t *testing.T) { 357 conf := createConfFile(t, []byte(` 358 port: -1 359 accounts { 360 A { 361 users: [ 362 { 363 user: a 364 password: pwd 365 permissions { 366 subscribe: ["my.trace.subj", "foo"] 367 publish { 368 allow: ["foo", "bar.>"] 369 deny: ["bar.baz"] 370 } 371 } 372 } 373 ] 374 } 375 } 376 `)) 377 s, _ := RunServerWithConfig(conf) 378 defer s.Shutdown() 379 380 nc := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 381 defer nc.Close() 382 383 traceSub := natsSubSync(t, nc, "my.trace.subj") 384 natsSub(t, nc, "foo", func(_ *nats.Msg) {}) 385 natsFlush(t, nc) 386 387 for _, test := range []struct { 388 name string 389 deliverMsg bool 390 }{ 391 {"just trace", false}, 392 {"deliver msg", true}, 393 } { 394 t.Run(test.name, func(t *testing.T) { 395 nc2 := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 396 defer nc2.Close() 397 398 sendMsg := func(subj, reply, errTxt string) { 399 msg := nats.NewMsg(subj) 400 msg.Header.Set(MsgTraceDest, traceSub.Subject) 401 if !test.deliverMsg { 402 msg.Header.Set(MsgTraceOnly, "true") 403 } 404 msg.Reply = reply 405 msg.Data = []byte("hello") 406 nc2.PublishMsg(msg) 407 408 traceMsg := natsNexMsg(t, traceSub, time.Second) 409 var e MsgTraceEvent 410 json.Unmarshal(traceMsg.Data, &e) 411 require_Equal[string](t, e.Server.Name, s.Name()) 412 require_True(t, e.Request.Header != nil) 413 require_Contains(t, e.Ingress().Error, errTxt) 414 require_True(t, e.Egresses() == nil) 415 } 416 417 // Send to a subject that causes permission violation 418 sendMsg("bar.baz", _EMPTY_, "Permissions Violation for Publish to") 419 420 // Send to a subject that is reserved for GW replies 421 sendMsg(gwReplyPrefix+"foo", _EMPTY_, "Permissions Violation for Publish to") 422 423 // Send with a Reply that is reserved 424 sendMsg("foo", replyPrefix+"bar", "Permissions Violation for Publish with Reply of") 425 }) 426 } 427 } 428 429 func TestMsgTraceEgressErrors(t *testing.T) { 430 conf := createConfFile(t, []byte(` 431 port: -1 432 accounts { 433 A { 434 users: [ 435 { 436 user: a 437 password: pwd 438 permissions { 439 subscribe: { 440 allow: ["my.trace.subj", "foo", "bar.>"] 441 deny: "bar.bat" 442 } 443 publish { 444 allow: ["foo", "bar.>"] 445 deny: ["bar.baz"] 446 } 447 } 448 } 449 ] 450 } 451 } 452 `)) 453 s, _ := RunServerWithConfig(conf) 454 defer s.Shutdown() 455 456 nc := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 457 defer nc.Close() 458 459 traceSub := natsSubSync(t, nc, "my.trace.subj") 460 natsFlush(t, nc) 461 462 for _, test := range []struct { 463 name string 464 deliverMsg bool 465 }{ 466 {"just trace", false}, 467 {"deliver msg", true}, 468 } { 469 t.Run(test.name, func(t *testing.T) { 470 sendMsg := func(pubc *nats.Conn, subj, errTxt string) { 471 t.Helper() 472 473 msg := nats.NewMsg(subj) 474 msg.Header.Set(MsgTraceDest, traceSub.Subject) 475 if !test.deliverMsg { 476 msg.Header.Set(MsgTraceOnly, "true") 477 } 478 msg.Data = []byte("hello") 479 pubc.PublishMsg(msg) 480 481 traceMsg := natsNexMsg(t, traceSub, time.Second) 482 var e MsgTraceEvent 483 json.Unmarshal(traceMsg.Data, &e) 484 require_Equal[string](t, e.Server.Name, s.Name()) 485 egress := e.Egresses() 486 require_Equal[int](t, len(egress), 1) 487 require_Contains(t, egress[0].Error, errTxt) 488 } 489 490 // Test no-echo. 491 nc2 := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd"), nats.NoEcho()) 492 defer nc2.Close() 493 natsSubSync(t, nc2, "foo") 494 sendMsg(nc2, "foo", errMsgTraceNoEcho) 495 nc2.Close() 496 497 // Test deny sub. 498 nc2 = natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 499 defer nc2.Close() 500 natsSubSync(t, nc2, "bar.>") 501 sendMsg(nc2, "bar.bat", errMsgTraceSubDeny) 502 nc2.Close() 503 504 // Test sub closed 505 nc2 = natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 506 defer nc2.Close() 507 natsSubSync(t, nc2, "bar.>") 508 natsFlush(t, nc2) 509 // Aritifially change the closed status of the subscription 510 cid, err := nc2.GetClientID() 511 require_NoError(t, err) 512 c := s.GetClient(cid) 513 c.mu.Lock() 514 for _, sub := range c.subs { 515 if string(sub.subject) == "bar.>" { 516 sub.close() 517 } 518 } 519 c.mu.Unlock() 520 sendMsg(nc2, "bar.bar", errMsgTraceSubClosed) 521 nc2.Close() 522 523 // The following applies only when doing delivery. 524 if test.deliverMsg { 525 // Test auto-unsub exceeded 526 nc2 = natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 527 defer nc2.Close() 528 sub := natsSubSync(t, nc2, "bar.>") 529 err := sub.AutoUnsubscribe(10) 530 require_NoError(t, err) 531 natsFlush(t, nc2) 532 533 // Modify sub.nm to be already over the 10 limit 534 cid, err := nc2.GetClientID() 535 require_NoError(t, err) 536 c := s.GetClient(cid) 537 c.mu.Lock() 538 for _, sub := range c.subs { 539 if string(sub.subject) == "bar.>" { 540 sub.nm = 20 541 } 542 } 543 c.mu.Unlock() 544 545 sendMsg(nc2, "bar.bar", errMsgTraceAutoSubExceeded) 546 nc2.Close() 547 548 // Test client closed 549 nc2 = natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd")) 550 defer nc2.Close() 551 natsSubSync(t, nc2, "bar.>") 552 cid, err = nc2.GetClientID() 553 require_NoError(t, err) 554 c = s.GetClient(cid) 555 c.mu.Lock() 556 c.out.stc = make(chan struct{}) 557 c.mu.Unlock() 558 msg := nats.NewMsg("bar.bar") 559 msg.Header.Set(MsgTraceDest, traceSub.Subject) 560 if !test.deliverMsg { 561 msg.Header.Set(MsgTraceOnly, "true") 562 } 563 msg.Data = []byte("hello") 564 nc2.PublishMsg(msg) 565 time.Sleep(10 * time.Millisecond) 566 cid, err = nc2.GetClientID() 567 require_NoError(t, err) 568 c = s.GetClient(cid) 569 c.mu.Lock() 570 c.flags.set(closeConnection) 571 c.mu.Unlock() 572 573 traceMsg := natsNexMsg(t, traceSub, time.Second) 574 var e MsgTraceEvent 575 json.Unmarshal(traceMsg.Data, &e) 576 require_Equal[string](t, e.Server.Name, s.Name()) 577 egress := e.Egresses() 578 require_Equal[int](t, len(egress), 1) 579 require_Contains(t, egress[0].Error, errMsgTraceClientClosed) 580 c.mu.Lock() 581 c.flags.clear(closeConnection) 582 c.mu.Unlock() 583 nc2.Close() 584 } 585 }) 586 } 587 } 588 589 func TestMsgTraceWithQueueSub(t *testing.T) { 590 o := DefaultOptions() 591 s := RunServer(o) 592 defer s.Shutdown() 593 594 nc := natsConnect(t, s.ClientURL()) 595 defer nc.Close() 596 597 traceSub := natsSubSync(t, nc, "my.trace.subj") 598 natsFlush(t, nc) 599 600 nc2 := natsConnect(t, s.ClientURL(), nats.Name("sub1")) 601 defer nc2.Close() 602 sub1 := natsQueueSubSync(t, nc2, "foo", "bar") 603 natsFlush(t, nc2) 604 605 nc3 := natsConnect(t, s.ClientURL(), nats.Name("sub2")) 606 defer nc3.Close() 607 sub2 := natsQueueSubSync(t, nc3, "foo", "bar") 608 sub3 := natsQueueSubSync(t, nc3, "*", "baz") 609 natsFlush(t, nc3) 610 611 for _, test := range []struct { 612 name string 613 deliverMsg bool 614 }{ 615 {"just trace", false}, 616 {"deliver msg", true}, 617 } { 618 t.Run(test.name, func(t *testing.T) { 619 msg := nats.NewMsg("foo") 620 msg.Header.Set(MsgTraceDest, traceSub.Subject) 621 if !test.deliverMsg { 622 msg.Header.Set(MsgTraceOnly, "true") 623 } 624 if !test.deliverMsg { 625 msg.Data = []byte("hello1") 626 } else { 627 msg.Data = []byte("hello2") 628 } 629 err := nc.PublishMsg(msg) 630 require_NoError(t, err) 631 632 if test.deliverMsg { 633 // Only one should have got the message... 634 msg1, err1 := sub1.NextMsg(100 * time.Millisecond) 635 msg2, err2 := sub2.NextMsg(100 * time.Millisecond) 636 if err1 == nil && err2 == nil { 637 t.Fatalf("Only one message should have been received") 638 } 639 var val string 640 if msg1 != nil { 641 val = string(msg1.Data) 642 } else { 643 val = string(msg2.Data) 644 } 645 require_Equal[string](t, val, "hello2") 646 // Queue baz should also have received the message 647 msg := natsNexMsg(t, sub3, time.Second) 648 require_Equal[string](t, string(msg.Data), "hello2") 649 } 650 // Check that no (more) messages are received. 651 for _, sub := range []*nats.Subscription{sub1, sub2, sub3} { 652 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 653 t.Fatalf("Expected no message, got %s", msg.Data) 654 } 655 } 656 657 traceMsg := natsNexMsg(t, traceSub, time.Second) 658 var e MsgTraceEvent 659 json.Unmarshal(traceMsg.Data, &e) 660 require_Equal[string](t, e.Server.Name, s.Name()) 661 ingress := e.Ingress() 662 require_True(t, ingress != nil) 663 require_True(t, ingress.Kind == CLIENT) 664 require_Equal[string](t, ingress.Subject, "foo") 665 egress := e.Egresses() 666 require_Equal[int](t, len(egress), 2) 667 var qbar, qbaz int 668 for _, eg := range egress { 669 switch eg.Queue { 670 case "bar": 671 require_Equal[string](t, eg.Subscription, "foo") 672 qbar++ 673 case "baz": 674 require_Equal[string](t, eg.Subscription, "*") 675 qbaz++ 676 default: 677 t.Fatalf("Wrong queue name: %q", eg.Queue) 678 } 679 } 680 require_Equal[int](t, qbar, 1) 681 require_Equal[int](t, qbaz, 1) 682 }) 683 } 684 } 685 686 func TestMsgTraceWithRoutes(t *testing.T) { 687 tmpl := ` 688 port: -1 689 accounts { 690 A { users: [{user:A, password: pwd}] } 691 B { users: [{user:B, password: pwd}] } 692 } 693 cluster { 694 name: "local" 695 port: -1 696 accounts: ["A"] 697 %s 698 } 699 ` 700 conf1 := createConfFile(t, []byte(fmt.Sprintf(tmpl, _EMPTY_))) 701 s1, o1 := RunServerWithConfig(conf1) 702 defer s1.Shutdown() 703 704 conf2 := createConfFile(t, []byte(fmt.Sprintf(tmpl, fmt.Sprintf("routes: [\"nats://127.0.0.1:%d\"]", o1.Cluster.Port)))) 705 s2, _ := RunServerWithConfig(conf2) 706 defer s2.Shutdown() 707 708 checkClusterFormed(t, s1, s2) 709 710 checkDummy := func(user string) { 711 nc := natsConnect(t, s1.ClientURL(), nats.UserInfo(user, "pwd")) 712 defer nc.Close() 713 714 traceSub := natsSubSync(t, nc, "my.trace.subj") 715 natsFlush(t, nc) 716 717 // Send trace message to a dummy subject to check that resulting trace 718 // is as expected. 719 msg := nats.NewMsg("dummy") 720 msg.Header.Set(MsgTraceDest, traceSub.Subject) 721 msg.Header.Set(MsgTraceOnly, "true") 722 msg.Data = []byte("hello!") 723 err := nc.PublishMsg(msg) 724 require_NoError(t, err) 725 726 traceMsg := natsNexMsg(t, traceSub, time.Second) 727 var e MsgTraceEvent 728 json.Unmarshal(traceMsg.Data, &e) 729 require_Equal[string](t, e.Server.Name, s1.Name()) 730 ingress := e.Ingress() 731 require_True(t, ingress != nil) 732 require_True(t, ingress.Kind == CLIENT) 733 // "user" is same than account name in this test. 734 require_Equal[string](t, ingress.Account, user) 735 require_Equal[string](t, ingress.Subject, "dummy") 736 require_True(t, e.SubjectMapping() == nil) 737 require_True(t, e.Egresses() == nil) 738 739 // We should also not get an event from the remote server. 740 if msg, err := traceSub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 741 t.Fatalf("Expected no message, got %s", msg.Data) 742 } 743 } 744 checkDummy("A") 745 checkDummy("B") 746 747 for _, test := range []struct { 748 name string 749 acc string 750 }{ 751 {"pinned account", "A"}, 752 {"reg account", "B"}, 753 } { 754 t.Run(test.name, func(t *testing.T) { 755 acc := test.acc 756 // Now create subscriptions on both s1 and s2 757 nc2 := natsConnect(t, s2.ClientURL(), nats.UserInfo(acc, "pwd"), nats.Name("sub2")) 758 defer nc2.Close() 759 sub2 := natsQueueSubSync(t, nc2, "foo.*", "my_queue") 760 761 nc3 := natsConnect(t, s2.ClientURL(), nats.UserInfo(acc, "pwd"), nats.Name("sub3")) 762 defer nc3.Close() 763 sub3 := natsQueueSubSync(t, nc3, "*.*", "my_queue_2") 764 765 checkSubInterest(t, s1, acc, "foo.bar", time.Second) 766 767 nc1 := natsConnect(t, s1.ClientURL(), nats.UserInfo(acc, "pwd"), nats.Name("sub1")) 768 defer nc1.Close() 769 sub1 := natsSubSync(t, nc1, "*.bar") 770 771 nct := natsConnect(t, s1.ClientURL(), nats.UserInfo(acc, "pwd"), nats.Name("tracer")) 772 defer nct.Close() 773 traceSub := natsSubSync(t, nct, "my.trace.subj") 774 775 for _, test := range []struct { 776 name string 777 deliverMsg bool 778 }{ 779 {"just trace", false}, 780 {"deliver msg", true}, 781 } { 782 t.Run(test.name, func(t *testing.T) { 783 msg := nats.NewMsg("foo.bar") 784 msg.Header.Set(MsgTraceDest, traceSub.Subject) 785 if !test.deliverMsg { 786 msg.Header.Set(MsgTraceOnly, "true") 787 } 788 msg.Data = []byte("hello!") 789 err := nct.PublishMsg(msg) 790 require_NoError(t, err) 791 792 checkAppMsg := func(sub *nats.Subscription, expected bool) { 793 if expected { 794 appMsg := natsNexMsg(t, sub, time.Second) 795 require_Equal[string](t, string(appMsg.Data), "hello!") 796 } 797 // Check that no (more) messages are received. 798 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 799 t.Fatalf("Did not expect application message, got %s", msg.Data) 800 } 801 } 802 for _, sub := range []*nats.Subscription{sub1, sub2, sub3} { 803 checkAppMsg(sub, test.deliverMsg) 804 } 805 806 check := func() { 807 traceMsg := natsNexMsg(t, traceSub, time.Second) 808 var e MsgTraceEvent 809 json.Unmarshal(traceMsg.Data, &e) 810 ingress := e.Ingress() 811 require_True(t, ingress != nil) 812 switch ingress.Kind { 813 case CLIENT: 814 require_Equal[string](t, e.Server.Name, s1.Name()) 815 require_Equal[string](t, ingress.Account, acc) 816 require_Equal[string](t, ingress.Subject, "foo.bar") 817 egress := e.Egresses() 818 require_Equal[int](t, len(egress), 2) 819 for _, eg := range egress { 820 if eg.Kind == CLIENT { 821 require_Equal[string](t, eg.Name, "sub1") 822 require_Equal[string](t, eg.Subscription, "*.bar") 823 require_Equal[string](t, eg.Queue, _EMPTY_) 824 } else { 825 require_True(t, eg.Kind == ROUTER) 826 require_Equal[string](t, eg.Name, s2.Name()) 827 require_Equal[string](t, eg.Subscription, _EMPTY_) 828 require_Equal[string](t, eg.Queue, _EMPTY_) 829 } 830 } 831 case ROUTER: 832 require_Equal[string](t, e.Server.Name, s2.Name()) 833 require_Equal[string](t, ingress.Account, acc) 834 require_Equal[string](t, ingress.Subject, "foo.bar") 835 egress := e.Egresses() 836 require_Equal[int](t, len(egress), 2) 837 var gotSub2, gotSub3 int 838 for _, eg := range egress { 839 require_True(t, eg.Kind == CLIENT) 840 switch eg.Name { 841 case "sub2": 842 require_Equal[string](t, eg.Subscription, "foo.*") 843 require_Equal[string](t, eg.Queue, "my_queue") 844 gotSub2++ 845 case "sub3": 846 require_Equal[string](t, eg.Subscription, "*.*") 847 require_Equal[string](t, eg.Queue, "my_queue_2") 848 gotSub3++ 849 default: 850 t.Fatalf("Unexpected egress name: %+v", eg) 851 } 852 } 853 require_Equal[int](t, gotSub2, 1) 854 require_Equal[int](t, gotSub3, 1) 855 default: 856 t.Fatalf("Unexpected ingress: %+v", ingress) 857 } 858 } 859 // We should get 2 events. Order is not guaranteed. 860 check() 861 check() 862 // Make sure we are not receiving more traces 863 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 864 t.Fatalf("Should not have received trace message: %s", tm.Data) 865 } 866 }) 867 } 868 }) 869 } 870 } 871 872 func TestMsgTraceWithRouteToOldServer(t *testing.T) { 873 msgTraceCheckSupport = true 874 defer func() { msgTraceCheckSupport = false }() 875 tmpl := ` 876 port: -1 877 cluster { 878 name: "local" 879 port: -1 880 pool_size: -1 881 %s 882 } 883 ` 884 conf1 := createConfFile(t, []byte(fmt.Sprintf(tmpl, _EMPTY_))) 885 s1, o1 := RunServerWithConfig(conf1) 886 defer s1.Shutdown() 887 888 conf2 := createConfFile(t, []byte(fmt.Sprintf(tmpl, fmt.Sprintf("routes: [\"nats://127.0.0.1:%d\"]", o1.Cluster.Port)))) 889 o2 := LoadConfig(conf2) 890 // Make this server behave like an older server 891 o2.overrideProto = setServerProtoForTest(MsgTraceProto - 1) 892 s2 := RunServer(o2) 893 defer s2.Shutdown() 894 895 checkClusterFormed(t, s1, s2) 896 897 // Now create subscriptions on both s1 and s2 898 nc2 := natsConnect(t, s2.ClientURL(), nats.Name("sub2")) 899 defer nc2.Close() 900 sub2 := natsSubSync(t, nc2, "foo") 901 902 checkSubInterest(t, s1, globalAccountName, "foo", time.Second) 903 904 nc1 := natsConnect(t, s1.ClientURL(), nats.Name("sub1")) 905 defer nc1.Close() 906 sub1 := natsSubSync(t, nc1, "foo") 907 908 nct := natsConnect(t, s1.ClientURL(), nats.Name("tracer")) 909 defer nct.Close() 910 traceSub := natsSubSync(t, nct, "my.trace.subj") 911 912 for _, test := range []struct { 913 name string 914 deliverMsg bool 915 }{ 916 {"just trace", false}, 917 {"deliver msg", true}, 918 } { 919 t.Run(test.name, func(t *testing.T) { 920 msg := nats.NewMsg("foo") 921 msg.Header.Set(MsgTraceDest, traceSub.Subject) 922 if !test.deliverMsg { 923 msg.Header.Set(MsgTraceOnly, "true") 924 } 925 msg.Data = []byte("hello!") 926 err := nct.PublishMsg(msg) 927 require_NoError(t, err) 928 929 checkAppMsg := func(sub *nats.Subscription, expected bool) { 930 if expected { 931 appMsg := natsNexMsg(t, sub, time.Second) 932 require_Equal[string](t, string(appMsg.Data), "hello!") 933 } 934 // Check that no (more) messages are received. 935 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 936 t.Fatalf("Did not expect application message, got %s", msg.Data) 937 } 938 } 939 // Even if a server does not support tracing, as long as the header 940 // TraceOnly is not set, the message should be forwarded to the remote. 941 for _, sub := range []*nats.Subscription{sub1, sub2} { 942 checkAppMsg(sub, test.deliverMsg) 943 } 944 945 traceMsg := natsNexMsg(t, traceSub, time.Second) 946 var e MsgTraceEvent 947 json.Unmarshal(traceMsg.Data, &e) 948 ingress := e.Ingress() 949 require_True(t, ingress != nil) 950 require_True(t, ingress.Kind == CLIENT) 951 require_Equal[string](t, e.Server.Name, s1.Name()) 952 egress := e.Egresses() 953 require_Equal[int](t, len(egress), 2) 954 for _, ci := range egress { 955 switch ci.Kind { 956 case CLIENT: 957 require_Equal[string](t, ci.Name, "sub1") 958 case ROUTER: 959 require_Equal[string](t, ci.Name, s2.Name()) 960 if test.deliverMsg { 961 require_Contains(t, ci.Error, errMsgTraceNoSupport) 962 } else { 963 require_Contains(t, ci.Error, errMsgTraceOnlyNoSupport) 964 } 965 default: 966 t.Fatalf("Unexpected egress: %+v", ci) 967 } 968 } 969 // We should not get a second trace 970 if msg, err := traceSub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 971 t.Fatalf("Did not expect other trace, got %s", msg.Data) 972 } 973 }) 974 } 975 } 976 977 func TestMsgTraceWithLeafNode(t *testing.T) { 978 for _, mainTest := range []struct { 979 name string 980 fromHub bool 981 leafUseLocalAcc bool 982 }{ 983 {"from hub", true, false}, 984 {"from leaf", false, false}, 985 {"from hub with local account", true, true}, 986 {"from leaf with local account", false, true}, 987 } { 988 t.Run(mainTest.name, func(t *testing.T) { 989 confHub := createConfFile(t, []byte(` 990 port: -1 991 server_name: "A" 992 accounts { 993 A { users: [{user: "a", password: "pwd"}]} 994 B { users: [{user: "b", password: "pwd"}]} 995 } 996 leafnodes { 997 port: -1 998 } 999 `)) 1000 hub, ohub := RunServerWithConfig(confHub) 1001 defer hub.Shutdown() 1002 1003 var accs string 1004 var lacc string 1005 if mainTest.leafUseLocalAcc { 1006 accs = `accounts { B { users: [{user: "b", password: "pwd"}]} }` 1007 lacc = `account: B` 1008 } 1009 confLeaf := createConfFile(t, []byte(fmt.Sprintf(` 1010 port: -1 1011 server_name: "B" 1012 %s 1013 leafnodes { 1014 remotes [ 1015 { 1016 url: "nats://a:pwd@127.0.0.1:%d" 1017 %s 1018 } 1019 ] 1020 } 1021 `, accs, ohub.LeafNode.Port, lacc))) 1022 leaf, _ := RunServerWithConfig(confLeaf) 1023 defer leaf.Shutdown() 1024 1025 checkLeafNodeConnected(t, hub) 1026 checkLeafNodeConnected(t, leaf) 1027 1028 var s1, s2 *Server 1029 if mainTest.fromHub { 1030 s1, s2 = hub, leaf 1031 } else { 1032 s1, s2 = leaf, hub 1033 } 1034 // Now create subscriptions on both s1 and s2 1035 opts := []nats.Option{nats.Name("sub2")} 1036 var user string 1037 // If fromHub, then it means that s2 is the leaf. 1038 if mainTest.fromHub { 1039 if mainTest.leafUseLocalAcc { 1040 user = "b" 1041 } 1042 } else { 1043 // s2 is the hub, always connect with user "a'" 1044 user = "a" 1045 } 1046 if user != _EMPTY_ { 1047 opts = append(opts, nats.UserInfo(user, "pwd")) 1048 } 1049 nc2 := natsConnect(t, s2.ClientURL(), opts...) 1050 defer nc2.Close() 1051 sub2 := natsSubSync(t, nc2, "foo") 1052 1053 if mainTest.fromHub { 1054 checkSubInterest(t, s1, "A", "foo", time.Second) 1055 } else if mainTest.leafUseLocalAcc { 1056 checkSubInterest(t, s1, "B", "foo", time.Second) 1057 } else { 1058 checkSubInterest(t, s1, globalAccountName, "foo", time.Second) 1059 } 1060 1061 user = _EMPTY_ 1062 opts = []nats.Option{nats.Name("sub1")} 1063 if mainTest.fromHub { 1064 // s1 is the hub, so we need user "a" 1065 user = "a" 1066 } else if mainTest.leafUseLocalAcc { 1067 // s1 is the leaf, we need user "b" if leafUseLocalAcc 1068 user = "b" 1069 } 1070 if user != _EMPTY_ { 1071 opts = append(opts, nats.UserInfo(user, "pwd")) 1072 } 1073 nc1 := natsConnect(t, s1.ClientURL(), opts...) 1074 defer nc1.Close() 1075 sub1 := natsSubSync(t, nc1, "foo") 1076 1077 opts = []nats.Option{nats.Name("tracer")} 1078 if user != _EMPTY_ { 1079 opts = append(opts, nats.UserInfo(user, "pwd")) 1080 } 1081 nct := natsConnect(t, s1.ClientURL(), opts...) 1082 defer nct.Close() 1083 traceSub := natsSubSync(t, nct, "my.trace.subj") 1084 1085 for _, test := range []struct { 1086 name string 1087 deliverMsg bool 1088 }{ 1089 {"just trace", false}, 1090 {"deliver msg", true}, 1091 } { 1092 t.Run(test.name, func(t *testing.T) { 1093 msg := nats.NewMsg("foo") 1094 msg.Header.Set(MsgTraceDest, traceSub.Subject) 1095 if !test.deliverMsg { 1096 msg.Header.Set(MsgTraceOnly, "true") 1097 } 1098 msg.Data = []byte("hello!") 1099 err := nct.PublishMsg(msg) 1100 require_NoError(t, err) 1101 1102 checkAppMsg := func(sub *nats.Subscription, expected bool) { 1103 if expected { 1104 appMsg := natsNexMsg(t, sub, time.Second) 1105 require_Equal[string](t, string(appMsg.Data), "hello!") 1106 } 1107 // Check that no (more) messages are received. 1108 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1109 t.Fatalf("Did not expect application message, got %s", msg.Data) 1110 } 1111 } 1112 for _, sub := range []*nats.Subscription{sub1, sub2} { 1113 checkAppMsg(sub, test.deliverMsg) 1114 } 1115 1116 check := func() { 1117 traceMsg := natsNexMsg(t, traceSub, time.Second) 1118 var e MsgTraceEvent 1119 json.Unmarshal(traceMsg.Data, &e) 1120 ingress := e.Ingress() 1121 require_True(t, ingress != nil) 1122 switch ingress.Kind { 1123 case CLIENT: 1124 require_Equal[string](t, e.Server.Name, s1.Name()) 1125 egress := e.Egresses() 1126 require_Equal[int](t, len(egress), 2) 1127 for _, eg := range egress { 1128 switch eg.Kind { 1129 case CLIENT: 1130 require_Equal[string](t, eg.Name, "sub1") 1131 case LEAF: 1132 require_Equal[string](t, eg.Name, s2.Name()) 1133 require_Equal[string](t, eg.Error, _EMPTY_) 1134 default: 1135 t.Fatalf("Unexpected egress: %+v", eg) 1136 } 1137 } 1138 case LEAF: 1139 require_Equal[string](t, e.Server.Name, s2.Name()) 1140 require_True(t, ingress.Kind == LEAF) 1141 require_Equal(t, ingress.Name, s1.Name()) 1142 egress := e.Egresses() 1143 require_Equal[int](t, len(egress), 1) 1144 eg := egress[0] 1145 require_True(t, eg.Kind == CLIENT) 1146 require_Equal[string](t, eg.Name, "sub2") 1147 default: 1148 t.Fatalf("Unexpected ingress: %+v", ingress) 1149 } 1150 } 1151 check() 1152 check() 1153 // Make sure we are not receiving more traces 1154 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 1155 t.Fatalf("Should not have received trace message: %s", tm.Data) 1156 } 1157 }) 1158 } 1159 }) 1160 } 1161 } 1162 1163 func TestMsgTraceWithLeafNodeToOldServer(t *testing.T) { 1164 msgTraceCheckSupport = true 1165 defer func() { msgTraceCheckSupport = false }() 1166 for _, mainTest := range []struct { 1167 name string 1168 fromHub bool 1169 }{ 1170 {"from hub", true}, 1171 {"from leaf", false}, 1172 } { 1173 t.Run(mainTest.name, func(t *testing.T) { 1174 confHub := createConfFile(t, []byte(` 1175 port: -1 1176 server_name: "A" 1177 leafnodes { 1178 port: -1 1179 } 1180 `)) 1181 ohub := LoadConfig(confHub) 1182 if !mainTest.fromHub { 1183 // Make this server behave like an older server 1184 ohub.overrideProto = setServerProtoForTest(MsgTraceProto - 1) 1185 } 1186 hub := RunServer(ohub) 1187 defer hub.Shutdown() 1188 1189 confLeaf := createConfFile(t, []byte(fmt.Sprintf(` 1190 port: -1 1191 server_name: "B" 1192 leafnodes { 1193 remotes [{url: "nats://127.0.0.1:%d"}] 1194 } 1195 `, ohub.LeafNode.Port))) 1196 oleaf := LoadConfig(confLeaf) 1197 if mainTest.fromHub { 1198 // Make this server behave like an older server 1199 oleaf.overrideProto = setServerProtoForTest(MsgTraceProto - 1) 1200 } 1201 leaf := RunServer(oleaf) 1202 defer leaf.Shutdown() 1203 1204 checkLeafNodeConnected(t, hub) 1205 checkLeafNodeConnected(t, leaf) 1206 1207 var s1, s2 *Server 1208 if mainTest.fromHub { 1209 s1, s2 = hub, leaf 1210 } else { 1211 s1, s2 = leaf, hub 1212 } 1213 1214 // Now create subscriptions on both s1 and s2 1215 nc2 := natsConnect(t, s2.ClientURL(), nats.Name("sub2")) 1216 defer nc2.Close() 1217 sub2 := natsSubSync(t, nc2, "foo") 1218 1219 checkSubInterest(t, s1, globalAccountName, "foo", time.Second) 1220 1221 nc1 := natsConnect(t, s1.ClientURL(), nats.Name("sub1")) 1222 defer nc1.Close() 1223 sub1 := natsSubSync(t, nc1, "foo") 1224 1225 nct := natsConnect(t, s1.ClientURL(), nats.Name("tracer")) 1226 defer nct.Close() 1227 traceSub := natsSubSync(t, nct, "my.trace.subj") 1228 1229 for _, test := range []struct { 1230 name string 1231 deliverMsg bool 1232 }{ 1233 {"just trace", false}, 1234 {"deliver msg", true}, 1235 } { 1236 t.Run(test.name, func(t *testing.T) { 1237 msg := nats.NewMsg("foo") 1238 msg.Header.Set(MsgTraceDest, traceSub.Subject) 1239 if !test.deliverMsg { 1240 msg.Header.Set(MsgTraceOnly, "true") 1241 } 1242 msg.Data = []byte("hello!") 1243 err := nct.PublishMsg(msg) 1244 require_NoError(t, err) 1245 1246 checkAppMsg := func(sub *nats.Subscription, expected bool) { 1247 if expected { 1248 appMsg := natsNexMsg(t, sub, time.Second) 1249 require_Equal[string](t, string(appMsg.Data), "hello!") 1250 } 1251 // Check that no (more) messages are received. 1252 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1253 t.Fatalf("Did not expect application message, got %s", msg.Data) 1254 } 1255 } 1256 // Even if a server does not support tracing, as long as the header 1257 // TraceOnly is not set, the message should be forwarded to the remote. 1258 for _, sub := range []*nats.Subscription{sub1, sub2} { 1259 checkAppMsg(sub, test.deliverMsg) 1260 } 1261 1262 traceMsg := natsNexMsg(t, traceSub, time.Second) 1263 var e MsgTraceEvent 1264 json.Unmarshal(traceMsg.Data, &e) 1265 ingress := e.Ingress() 1266 require_True(t, ingress != nil) 1267 require_True(t, ingress.Kind == CLIENT) 1268 require_Equal[string](t, e.Server.Name, s1.Name()) 1269 egress := e.Egresses() 1270 require_Equal[int](t, len(egress), 2) 1271 for _, ci := range egress { 1272 switch ci.Kind { 1273 case CLIENT: 1274 require_Equal[string](t, ci.Name, "sub1") 1275 case LEAF: 1276 require_Equal[string](t, ci.Name, s2.Name()) 1277 if test.deliverMsg { 1278 require_Contains(t, ci.Error, errMsgTraceNoSupport) 1279 } else { 1280 require_Contains(t, ci.Error, errMsgTraceOnlyNoSupport) 1281 } 1282 default: 1283 t.Fatalf("Unexpected egress: %+v", ci) 1284 } 1285 } 1286 // We should not get a second trace 1287 if msg, err := traceSub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1288 t.Fatalf("Did not expect other trace, got %s", msg.Data) 1289 } 1290 }) 1291 } 1292 }) 1293 } 1294 } 1295 1296 func TestMsgTraceWithLeafNodeDaisyChain(t *testing.T) { 1297 confHub := createConfFile(t, []byte(` 1298 port: -1 1299 server_name: "A" 1300 accounts { 1301 A { users: [{user: "a", password: "pwd"}]} 1302 } 1303 leafnodes { 1304 port: -1 1305 } 1306 `)) 1307 hub, ohub := RunServerWithConfig(confHub) 1308 defer hub.Shutdown() 1309 1310 confLeaf1 := createConfFile(t, []byte(fmt.Sprintf(` 1311 port: -1 1312 server_name: "B" 1313 accounts { 1314 B { users: [{user: "b", password: "pwd"}]} 1315 } 1316 leafnodes { 1317 port: -1 1318 remotes [{url: "nats://a:pwd@127.0.0.1:%d", account: B}] 1319 } 1320 `, ohub.LeafNode.Port))) 1321 leaf1, oleaf1 := RunServerWithConfig(confLeaf1) 1322 defer leaf1.Shutdown() 1323 1324 confLeaf2 := createConfFile(t, []byte(fmt.Sprintf(` 1325 port: -1 1326 server_name: "C" 1327 accounts { 1328 C { users: [{user: "c", password: "pwd"}]} 1329 } 1330 leafnodes { 1331 remotes [{url: "nats://b:pwd@127.0.0.1:%d", account: C}] 1332 } 1333 `, oleaf1.LeafNode.Port))) 1334 leaf2, _ := RunServerWithConfig(confLeaf2) 1335 defer leaf2.Shutdown() 1336 1337 checkLeafNodeConnected(t, hub) 1338 checkLeafNodeConnectedCount(t, leaf1, 2) 1339 checkLeafNodeConnected(t, leaf2) 1340 1341 nct := natsConnect(t, hub.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("Tracer")) 1342 defer nct.Close() 1343 traceSub := natsSubSync(t, nct, "my.trace.subj") 1344 natsFlush(t, nct) 1345 // Make sure that subject interest travels down to leaf2 1346 checkSubInterest(t, leaf2, "C", traceSub.Subject, time.Second) 1347 1348 nc1 := natsConnect(t, leaf1.ClientURL(), nats.UserInfo("b", "pwd"), nats.Name("sub1")) 1349 defer nc1.Close() 1350 1351 nc2 := natsConnect(t, leaf2.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("sub2")) 1352 defer nc2.Close() 1353 sub2 := natsQueueSubSync(t, nc2, "foo.bar", "my_queue") 1354 natsFlush(t, nc2) 1355 1356 // Check the the subject interest makes it to leaf1 1357 checkSubInterest(t, leaf1, "B", "foo.bar", time.Second) 1358 1359 // Now create the sub on leaf1 1360 sub1 := natsSubSync(t, nc1, "foo.*") 1361 natsFlush(t, nc1) 1362 1363 // Check that subject interest registered on "hub" 1364 checkSubInterest(t, hub, "A", "foo.bar", time.Second) 1365 1366 for _, test := range []struct { 1367 name string 1368 deliverMsg bool 1369 }{ 1370 {"just trace", false}, 1371 {"deliver msg", true}, 1372 } { 1373 t.Run(test.name, func(t *testing.T) { 1374 msg := nats.NewMsg("foo.bar") 1375 msg.Header.Set(MsgTraceDest, traceSub.Subject) 1376 if !test.deliverMsg { 1377 msg.Header.Set(MsgTraceOnly, "true") 1378 } 1379 msg.Data = []byte("hello!") 1380 err := nct.PublishMsg(msg) 1381 require_NoError(t, err) 1382 1383 checkAppMsg := func(sub *nats.Subscription, expected bool) { 1384 if expected { 1385 appMsg := natsNexMsg(t, sub, time.Second) 1386 require_Equal[string](t, string(appMsg.Data), "hello!") 1387 } 1388 // Check that no (more) messages are received. 1389 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1390 t.Fatalf("Did not expect application message, got %s", msg.Data) 1391 } 1392 } 1393 for _, sub := range []*nats.Subscription{sub1, sub2} { 1394 checkAppMsg(sub, test.deliverMsg) 1395 } 1396 1397 check := func() { 1398 traceMsg := natsNexMsg(t, traceSub, time.Second) 1399 var e MsgTraceEvent 1400 json.Unmarshal(traceMsg.Data, &e) 1401 1402 ingress := e.Ingress() 1403 require_True(t, ingress != nil) 1404 switch ingress.Kind { 1405 case CLIENT: 1406 require_Equal[string](t, e.Server.Name, hub.Name()) 1407 require_Equal[string](t, ingress.Name, "Tracer") 1408 require_Equal[string](t, ingress.Account, "A") 1409 require_Equal[string](t, ingress.Subject, "foo.bar") 1410 egress := e.Egresses() 1411 require_Equal[int](t, len(egress), 1) 1412 eg := egress[0] 1413 require_True(t, eg.Kind == LEAF) 1414 require_Equal[string](t, eg.Name, leaf1.Name()) 1415 require_Equal[string](t, eg.Account, _EMPTY_) 1416 require_Equal[string](t, eg.Subscription, _EMPTY_) 1417 case LEAF: 1418 switch e.Server.Name { 1419 case leaf1.Name(): 1420 require_Equal(t, ingress.Name, hub.Name()) 1421 require_Equal(t, ingress.Account, "B") 1422 require_Equal[string](t, ingress.Subject, "foo.bar") 1423 egress := e.Egresses() 1424 require_Equal[int](t, len(egress), 2) 1425 for _, eg := range egress { 1426 switch eg.Kind { 1427 case CLIENT: 1428 require_Equal[string](t, eg.Name, "sub1") 1429 require_Equal[string](t, eg.Subscription, "foo.*") 1430 require_Equal[string](t, eg.Queue, _EMPTY_) 1431 case LEAF: 1432 require_Equal[string](t, eg.Name, leaf2.Name()) 1433 require_Equal[string](t, eg.Account, _EMPTY_) 1434 require_Equal[string](t, eg.Subscription, _EMPTY_) 1435 require_Equal[string](t, eg.Queue, _EMPTY_) 1436 default: 1437 t.Fatalf("Unexpected egress: %+v", eg) 1438 } 1439 } 1440 case leaf2.Name(): 1441 require_Equal(t, ingress.Name, leaf1.Name()) 1442 require_Equal(t, ingress.Account, "C") 1443 require_Equal[string](t, ingress.Subject, "foo.bar") 1444 egress := e.Egresses() 1445 require_Equal[int](t, len(egress), 1) 1446 eg := egress[0] 1447 require_True(t, eg.Kind == CLIENT) 1448 require_Equal[string](t, eg.Name, "sub2") 1449 require_Equal[string](t, eg.Subscription, "foo.bar") 1450 require_Equal[string](t, eg.Queue, "my_queue") 1451 default: 1452 t.Fatalf("Unexpected ingress: %+v", ingress) 1453 } 1454 default: 1455 t.Fatalf("Unexpected ingress: %+v", ingress) 1456 } 1457 } 1458 check() 1459 check() 1460 check() 1461 // Make sure we are not receiving more traces 1462 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 1463 t.Fatalf("Should not have received trace message: %s", tm.Data) 1464 } 1465 }) 1466 } 1467 } 1468 1469 func TestMsgTraceWithGateways(t *testing.T) { 1470 o2 := testDefaultOptionsForGateway("B") 1471 o2.NoSystemAccount = false 1472 s2 := runGatewayServer(o2) 1473 defer s2.Shutdown() 1474 1475 o1 := testGatewayOptionsFromToWithServers(t, "A", "B", s2) 1476 o1.NoSystemAccount = false 1477 s1 := runGatewayServer(o1) 1478 defer s1.Shutdown() 1479 1480 waitForOutboundGateways(t, s1, 1, time.Second) 1481 waitForInboundGateways(t, s2, 1, time.Second) 1482 waitForOutboundGateways(t, s2, 1, time.Second) 1483 1484 nc2 := natsConnect(t, s2.ClientURL(), nats.Name("sub2")) 1485 defer nc2.Close() 1486 sub2 := natsQueueSubSync(t, nc2, "foo.*", "my_queue") 1487 1488 nc3 := natsConnect(t, s2.ClientURL(), nats.Name("sub3")) 1489 defer nc3.Close() 1490 sub3 := natsQueueSubSync(t, nc3, "*.*", "my_queue_2") 1491 1492 nc1 := natsConnect(t, s1.ClientURL(), nats.Name("sub1")) 1493 defer nc1.Close() 1494 sub1 := natsSubSync(t, nc1, "*.bar") 1495 1496 nct := natsConnect(t, s1.ClientURL(), nats.Name("tracer")) 1497 defer nct.Close() 1498 traceSub := natsSubSync(t, nct, "my.trace.subj") 1499 1500 for _, test := range []struct { 1501 name string 1502 deliverMsg bool 1503 }{ 1504 {"just trace", false}, 1505 {"deliver msg", true}, 1506 } { 1507 t.Run(test.name, func(t *testing.T) { 1508 msg := nats.NewMsg("foo.bar") 1509 msg.Header.Set(MsgTraceDest, traceSub.Subject) 1510 if !test.deliverMsg { 1511 msg.Header.Set(MsgTraceOnly, "true") 1512 } 1513 msg.Data = []byte("hello!") 1514 err := nct.PublishMsg(msg) 1515 require_NoError(t, err) 1516 1517 checkAppMsg := func(sub *nats.Subscription, expected bool) { 1518 if expected { 1519 appMsg := natsNexMsg(t, sub, time.Second) 1520 require_Equal[string](t, string(appMsg.Data), "hello!") 1521 } 1522 // Check that no (more) messages are received. 1523 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1524 t.Fatalf("Did not expect application message, got %s", msg.Data) 1525 } 1526 } 1527 for _, sub := range []*nats.Subscription{sub1, sub2, sub3} { 1528 checkAppMsg(sub, test.deliverMsg) 1529 } 1530 1531 check := func() { 1532 traceMsg := natsNexMsg(t, traceSub, time.Second) 1533 var e MsgTraceEvent 1534 json.Unmarshal(traceMsg.Data, &e) 1535 1536 ingress := e.Ingress() 1537 require_True(t, ingress != nil) 1538 switch ingress.Kind { 1539 case CLIENT: 1540 require_Equal[string](t, e.Server.Name, s1.Name()) 1541 require_Equal[string](t, ingress.Account, globalAccountName) 1542 require_Equal[string](t, ingress.Subject, "foo.bar") 1543 egress := e.Egresses() 1544 require_Equal[int](t, len(egress), 2) 1545 for _, eg := range egress { 1546 switch eg.Kind { 1547 case CLIENT: 1548 require_Equal[string](t, eg.Name, "sub1") 1549 require_Equal[string](t, eg.Subscription, "*.bar") 1550 require_Equal[string](t, eg.Queue, _EMPTY_) 1551 case GATEWAY: 1552 require_Equal[string](t, eg.Name, s2.Name()) 1553 require_Equal[string](t, eg.Error, _EMPTY_) 1554 require_Equal[string](t, eg.Subscription, _EMPTY_) 1555 require_Equal[string](t, eg.Queue, _EMPTY_) 1556 default: 1557 t.Fatalf("Unexpected egress: %+v", eg) 1558 } 1559 } 1560 case GATEWAY: 1561 require_Equal[string](t, e.Server.Name, s2.Name()) 1562 require_Equal[string](t, ingress.Account, globalAccountName) 1563 require_Equal[string](t, ingress.Subject, "foo.bar") 1564 egress := e.Egresses() 1565 require_Equal[int](t, len(egress), 2) 1566 var gotSub2, gotSub3 int 1567 for _, eg := range egress { 1568 require_True(t, eg.Kind == CLIENT) 1569 switch eg.Name { 1570 case "sub2": 1571 require_Equal[string](t, eg.Subscription, "foo.*") 1572 require_Equal[string](t, eg.Queue, "my_queue") 1573 gotSub2++ 1574 case "sub3": 1575 require_Equal[string](t, eg.Subscription, "*.*") 1576 require_Equal[string](t, eg.Queue, "my_queue_2") 1577 gotSub3++ 1578 default: 1579 t.Fatalf("Unexpected egress name: %+v", eg) 1580 } 1581 } 1582 require_Equal[int](t, gotSub2, 1) 1583 require_Equal[int](t, gotSub3, 1) 1584 1585 default: 1586 t.Fatalf("Unexpected ingress: %+v", ingress) 1587 } 1588 } 1589 // We should get 2 events 1590 check() 1591 check() 1592 // Make sure we are not receiving more traces 1593 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 1594 t.Fatalf("Should not have received trace message: %s", tm.Data) 1595 } 1596 }) 1597 } 1598 } 1599 1600 func TestMsgTraceWithGatewayToOldServer(t *testing.T) { 1601 msgTraceCheckSupport = true 1602 defer func() { msgTraceCheckSupport = false }() 1603 1604 o2 := testDefaultOptionsForGateway("B") 1605 o2.NoSystemAccount = false 1606 // Make this server behave like an older server 1607 o2.overrideProto = setServerProtoForTest(MsgTraceProto - 1) 1608 s2 := runGatewayServer(o2) 1609 defer s2.Shutdown() 1610 1611 o1 := testGatewayOptionsFromToWithServers(t, "A", "B", s2) 1612 o1.NoSystemAccount = false 1613 s1 := runGatewayServer(o1) 1614 defer s1.Shutdown() 1615 1616 waitForOutboundGateways(t, s1, 1, time.Second) 1617 waitForInboundGateways(t, s2, 1, time.Second) 1618 waitForOutboundGateways(t, s2, 1, time.Second) 1619 1620 nc2 := natsConnect(t, s2.ClientURL(), nats.Name("sub2")) 1621 defer nc2.Close() 1622 sub2 := natsSubSync(t, nc2, "foo") 1623 1624 nc1 := natsConnect(t, s1.ClientURL(), nats.Name("sub1")) 1625 defer nc1.Close() 1626 sub1 := natsSubSync(t, nc1, "foo") 1627 1628 nct := natsConnect(t, s1.ClientURL(), nats.Name("tracer")) 1629 defer nct.Close() 1630 traceSub := natsSubSync(t, nct, "my.trace.subj") 1631 1632 for _, test := range []struct { 1633 name string 1634 deliverMsg bool 1635 }{ 1636 {"just trace", false}, 1637 {"deliver msg", true}, 1638 } { 1639 t.Run(test.name, func(t *testing.T) { 1640 msg := nats.NewMsg("foo") 1641 msg.Header.Set(MsgTraceDest, traceSub.Subject) 1642 if !test.deliverMsg { 1643 msg.Header.Set(MsgTraceOnly, "true") 1644 } 1645 msg.Data = []byte("hello!") 1646 err := nct.PublishMsg(msg) 1647 require_NoError(t, err) 1648 1649 checkAppMsg := func(sub *nats.Subscription, expected bool) { 1650 if expected { 1651 appMsg := natsNexMsg(t, sub, time.Second) 1652 require_Equal[string](t, string(appMsg.Data), "hello!") 1653 } 1654 // Check that no (more) messages are received. 1655 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1656 t.Fatalf("Did not expect application message, got %s", msg.Data) 1657 } 1658 } 1659 // Even if a server does not support tracing, as long as the header 1660 // TraceOnly is not set, the message should be forwarded to the remote. 1661 for _, sub := range []*nats.Subscription{sub1, sub2} { 1662 checkAppMsg(sub, test.deliverMsg) 1663 } 1664 1665 traceMsg := natsNexMsg(t, traceSub, time.Second) 1666 var e MsgTraceEvent 1667 json.Unmarshal(traceMsg.Data, &e) 1668 ingress := e.Ingress() 1669 require_True(t, ingress != nil) 1670 switch ingress.Kind { 1671 case CLIENT: 1672 require_Equal[string](t, e.Server.Name, s1.Name()) 1673 egress := e.Egresses() 1674 require_Equal[int](t, len(egress), 2) 1675 for _, ci := range egress { 1676 switch ci.Kind { 1677 case CLIENT: 1678 require_Equal[string](t, ci.Name, "sub1") 1679 case GATEWAY: 1680 require_Equal[string](t, ci.Name, s2.Name()) 1681 if test.deliverMsg { 1682 require_Contains(t, ci.Error, errMsgTraceNoSupport) 1683 } else { 1684 require_Contains(t, ci.Error, errMsgTraceOnlyNoSupport) 1685 } 1686 default: 1687 t.Fatalf("Unexpected egress: %+v", ci) 1688 } 1689 } 1690 default: 1691 t.Fatalf("Unexpected ingress: %+v", ingress) 1692 } 1693 // We should not get a second trace 1694 if msg, err := traceSub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 1695 t.Fatalf("Did not expect other trace, got %s", msg.Data) 1696 } 1697 }) 1698 } 1699 } 1700 1701 func TestMsgTraceServiceImport(t *testing.T) { 1702 tmpl := ` 1703 listen: 127.0.0.1:-1 1704 accounts { 1705 A { 1706 users: [{user: a, password: pwd}] 1707 exports: [ { service: ">", allow_trace: %v} ] 1708 mappings = { 1709 bar: bozo 1710 } 1711 } 1712 B { 1713 users: [{user: b, password: pwd}] 1714 imports: [ { service: {account: "A", subject:">"} } ] 1715 exports: [ { service: ">", allow_trace: %v} ] 1716 } 1717 C { 1718 users: [{user: c, password: pwd}] 1719 exports: [ { service: ">", allow_trace: %v } ] 1720 } 1721 D { 1722 users: [{user: d, password: pwd}] 1723 imports: [ 1724 { service: {account: "B", subject:"bar"}, to: baz } 1725 { service: {account: "C", subject:">"} } 1726 ] 1727 mappings = { 1728 bat: baz 1729 } 1730 } 1731 } 1732 ` 1733 conf := createConfFile(t, []byte(fmt.Sprintf(tmpl, false, false, false))) 1734 s, _ := RunServerWithConfig(conf) 1735 defer s.Shutdown() 1736 1737 nc := natsConnect(t, s.ClientURL(), nats.UserInfo("d", "pwd"), nats.Name("Requestor")) 1738 defer nc.Close() 1739 1740 traceSub := natsSubSync(t, nc, "my.trace.subj") 1741 sub := natsSubSync(t, nc, "my.service.response.inbox") 1742 1743 nc2 := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("ServiceA")) 1744 defer nc2.Close() 1745 recv := int32(0) 1746 natsQueueSub(t, nc2, "*", "my_queue", func(m *nats.Msg) { 1747 atomic.AddInt32(&recv, 1) 1748 m.Respond(m.Data) 1749 }) 1750 natsFlush(t, nc2) 1751 1752 nc3 := natsConnect(t, s.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("ServiceC")) 1753 defer nc3.Close() 1754 natsSub(t, nc3, "baz", func(m *nats.Msg) { 1755 atomic.AddInt32(&recv, 1) 1756 m.Respond(m.Data) 1757 }) 1758 natsFlush(t, nc3) 1759 1760 for mainIter, mainTest := range []struct { 1761 name string 1762 allow bool 1763 }{ 1764 {"not allowed", false}, 1765 {"allowed", true}, 1766 {"not allowed again", false}, 1767 } { 1768 atomic.StoreInt32(&recv, 0) 1769 t.Run(mainTest.name, func(t *testing.T) { 1770 for _, test := range []struct { 1771 name string 1772 deliverMsg bool 1773 }{ 1774 {"just trace", false}, 1775 {"deliver msg", true}, 1776 } { 1777 t.Run(test.name, func(t *testing.T) { 1778 msg := nats.NewMsg("bat") 1779 msg.Header.Set(MsgTraceDest, traceSub.Subject) 1780 if !test.deliverMsg { 1781 msg.Header.Set(MsgTraceOnly, "true") 1782 } 1783 if !test.deliverMsg { 1784 msg.Data = []byte("request1") 1785 } else { 1786 msg.Data = []byte("request2") 1787 } 1788 msg.Reply = sub.Subject 1789 1790 err := nc.PublishMsg(msg) 1791 require_NoError(t, err) 1792 1793 if test.deliverMsg { 1794 for i := 0; i < 2; i++ { 1795 appMsg := natsNexMsg(t, sub, time.Second) 1796 require_Equal[string](t, string(appMsg.Data), "request2") 1797 } 1798 } 1799 // Check that no (more) messages are received. 1800 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 1801 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 1802 } 1803 if !test.deliverMsg { 1804 // Just to make sure that message was not delivered to service 1805 // responders, wait a bit and check the recv value. 1806 time.Sleep(50 * time.Millisecond) 1807 if n := atomic.LoadInt32(&recv); n != 0 { 1808 t.Fatalf("Expected no message to be received, but service callback fired %d times", n) 1809 } 1810 } 1811 1812 traceMsg := natsNexMsg(t, traceSub, time.Second) 1813 var e MsgTraceEvent 1814 json.Unmarshal(traceMsg.Data, &e) 1815 1816 require_Equal[string](t, e.Server.Name, s.Name()) 1817 ingress := e.Ingress() 1818 require_True(t, ingress != nil) 1819 require_True(t, ingress.Kind == CLIENT) 1820 require_Equal[string](t, ingress.Account, "D") 1821 require_Equal[string](t, ingress.Subject, "bat") 1822 sm := e.SubjectMapping() 1823 require_True(t, sm != nil) 1824 require_Equal[string](t, sm.MappedTo, "baz") 1825 simps := e.ServiceImports() 1826 require_True(t, simps != nil) 1827 var expectedServices int 1828 if mainTest.allow { 1829 expectedServices = 3 1830 } else { 1831 expectedServices = 2 1832 } 1833 require_Equal[int](t, len(simps), expectedServices) 1834 for _, si := range simps { 1835 require_True(t, si.Timestamp != time.Time{}) 1836 switch si.Account { 1837 case "C": 1838 require_Equal[string](t, si.From, "baz") 1839 require_Equal[string](t, si.To, "baz") 1840 case "B": 1841 require_Equal[string](t, si.From, "baz") 1842 require_Equal[string](t, si.To, "bar") 1843 case "A": 1844 if !mainTest.allow { 1845 t.Fatalf("Without allow_trace, we should not see service for account A") 1846 } 1847 require_Equal[string](t, si.From, "bar") 1848 require_Equal[string](t, si.To, "bozo") 1849 default: 1850 t.Fatalf("Unexpected account name: %s", si.Account) 1851 } 1852 } 1853 egress := e.Egresses() 1854 if !mainTest.allow { 1855 require_Equal[int](t, len(egress), 0) 1856 } else { 1857 require_Equal[int](t, len(egress), 2) 1858 var gotA, gotC bool 1859 for _, eg := range egress { 1860 // All Egress should be clients 1861 require_True(t, eg.Kind == CLIENT) 1862 // We should have one for ServiceA and one for ServiceC 1863 if eg.Name == "ServiceA" { 1864 require_Equal[string](t, eg.Account, "A") 1865 require_Equal[string](t, eg.Subscription, "*") 1866 require_Equal[string](t, eg.Queue, "my_queue") 1867 gotA = true 1868 } else if eg.Name == "ServiceC" { 1869 require_Equal[string](t, eg.Account, "C") 1870 require_Equal[string](t, eg.Queue, _EMPTY_) 1871 gotC = true 1872 } 1873 } 1874 if !gotA { 1875 t.Fatalf("Did not get Egress for serviceA: %+v", egress) 1876 } 1877 if !gotC { 1878 t.Fatalf("Did not get Egress for serviceC: %+v", egress) 1879 } 1880 } 1881 1882 // Make sure we properly remove the responses. 1883 checkResp := func(an string) { 1884 acc, err := s.lookupAccount(an) 1885 require_NoError(t, err) 1886 checkFor(t, time.Second, 15*time.Millisecond, func() error { 1887 if n := acc.NumPendingAllResponses(); n != 0 { 1888 return fmt.Errorf("Still %d responses pending for account %q on server %s", n, acc, s) 1889 } 1890 return nil 1891 }) 1892 } 1893 for _, acc := range []string{"A", "B", "C", "D"} { 1894 checkResp(acc) 1895 } 1896 }) 1897 } 1898 switch mainIter { 1899 case 0: 1900 reloadUpdateConfig(t, s, conf, fmt.Sprintf(tmpl, true, true, true)) 1901 case 1: 1902 reloadUpdateConfig(t, s, conf, fmt.Sprintf(tmpl, false, false, false)) 1903 } 1904 }) 1905 } 1906 } 1907 1908 func TestMsgTraceServiceImportWithSuperCluster(t *testing.T) { 1909 for _, mainTest := range []struct { 1910 name string 1911 allowStr string 1912 allow bool 1913 }{ 1914 {"allowed", "true", true}, 1915 {"not allowed", "false", false}, 1916 } { 1917 t.Run(mainTest.name, func(t *testing.T) { 1918 tmpl := ` 1919 listen: 127.0.0.1:-1 1920 server_name: %s 1921 jetstream: {max_mem_store: 256MB, max_file_store: 2GB, store_dir: '%s'} 1922 1923 cluster { 1924 name: %s 1925 listen: 127.0.0.1:%d 1926 routes = [%s] 1927 } 1928 accounts { 1929 A { 1930 users: [{user: a, password: pwd}] 1931 exports: [ { service: ">", allow_trace: ` + mainTest.allowStr + ` } ] 1932 mappings = { 1933 bar: bozo 1934 } 1935 trace_dest: "a.trace.subj" 1936 } 1937 B { 1938 users: [{user: b, password: pwd}] 1939 imports: [ { service: {account: "A", subject:">"} } ] 1940 exports: [ { service: ">" , allow_trace: ` + mainTest.allowStr + ` } ] 1941 trace_dest: "b.trace.subj" 1942 } 1943 C { 1944 users: [{user: c, password: pwd}] 1945 exports: [ { service: ">" , allow_trace: ` + mainTest.allowStr + ` } ] 1946 trace_dest: "c.trace.subj" 1947 } 1948 D { 1949 users: [{user: d, password: pwd}] 1950 imports: [ 1951 { service: {account: "B", subject:"bar"}, to: baz } 1952 { service: {account: "C", subject:">"} } 1953 ] 1954 mappings = { 1955 bat: baz 1956 } 1957 trace_dest: "d.trace.subj" 1958 } 1959 $SYS { users = [ { user: "admin", pass: "s3cr3t!" } ] } 1960 } 1961 ` 1962 sc := createJetStreamSuperClusterWithTemplate(t, tmpl, 3, 2) 1963 defer sc.shutdown() 1964 1965 sfornc := sc.clusters[0].servers[0] 1966 nc := natsConnect(t, sfornc.ClientURL(), nats.UserInfo("d", "pwd"), nats.Name("Requestor")) 1967 defer nc.Close() 1968 1969 traceSub := natsSubSync(t, nc, "my.trace.subj") 1970 sub := natsSubSync(t, nc, "my.service.response.inbox") 1971 1972 sfornc2 := sc.clusters[0].servers[1] 1973 nc2 := natsConnect(t, sfornc2.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("ServiceA")) 1974 defer nc2.Close() 1975 subSvcA := natsQueueSubSync(t, nc2, "*", "my_queue") 1976 natsFlush(t, nc2) 1977 1978 sfornc3 := sc.clusters[1].servers[0] 1979 nc3 := natsConnect(t, sfornc3.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("ServiceC")) 1980 defer nc3.Close() 1981 subSvcC := natsSubSync(t, nc3, "baz") 1982 natsFlush(t, nc3) 1983 1984 // Create a subscription for each account trace destination to make 1985 // sure that we are not sending it there. 1986 var accSubs []*nats.Subscription 1987 for _, user := range []string{"a", "b", "c", "d"} { 1988 nc := natsConnect(t, sfornc.ClientURL(), nats.UserInfo(user, "pwd")) 1989 defer nc.Close() 1990 accSubs = append(accSubs, natsSubSync(t, nc, user+".trace.subj")) 1991 } 1992 1993 for _, test := range []struct { 1994 name string 1995 deliverMsg bool 1996 }{ 1997 {"just trace", false}, 1998 {"deliver msg", true}, 1999 } { 2000 t.Run(test.name, func(t *testing.T) { 2001 msg := nats.NewMsg("bat") 2002 msg.Header.Set(MsgTraceDest, traceSub.Subject) 2003 if !test.deliverMsg { 2004 msg.Header.Set(MsgTraceOnly, "true") 2005 } 2006 // We add the traceParentHdr header to make sure that it is 2007 // deactivated in addition to the Nats-Trace-Dest header too 2008 // when needed. 2009 traceParentHdrVal := "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01" 2010 msg.Header.Set(traceParentHdr, traceParentHdrVal) 2011 if !test.deliverMsg { 2012 msg.Data = []byte("request1") 2013 } else { 2014 msg.Data = []byte("request2") 2015 } 2016 msg.Reply = sub.Subject 2017 2018 err := nc.PublishMsg(msg) 2019 require_NoError(t, err) 2020 2021 if test.deliverMsg { 2022 processSvc := func(sub *nats.Subscription) { 2023 t.Helper() 2024 appMsg := natsNexMsg(t, sub, time.Second) 2025 // This test causes a message to be routed to the 2026 // service responders. When not allowing, we need 2027 // to make sure that the trace header has been 2028 // disabled. Not receiving the trace event from 2029 // the remote is not enough to verify since the 2030 // trace would not reach the origin server because 2031 // the origin account header will not be present. 2032 if mainTest.allow { 2033 if hv := appMsg.Header.Get(MsgTraceDest); hv != traceSub.Subject { 2034 t.Fatalf("Expecting header with %q, but got %q", traceSub.Subject, hv) 2035 } 2036 if hv := appMsg.Header.Get(traceParentHdr); hv != traceParentHdrVal { 2037 t.Fatalf("Expecting header with %q, but got %q", traceParentHdrVal, hv) 2038 } 2039 } else { 2040 if hv := appMsg.Header.Get(MsgTraceDest); hv != _EMPTY_ { 2041 t.Fatalf("Expecting no header, but header was present with value: %q", hv) 2042 } 2043 if hv := appMsg.Header.Get(traceParentHdr); hv != _EMPTY_ { 2044 t.Fatalf("Expecting no header, but header was present with value: %q", hv) 2045 } 2046 // We don't really need to check that, but we 2047 // should see the header with the first letter 2048 // being an `X`. 2049 hnb := []byte(MsgTraceDest) 2050 hnb[0] = 'X' 2051 hn := string(hnb) 2052 if hv := appMsg.Header.Get(hn); hv != traceSub.Subject { 2053 t.Fatalf("Expected header %q to be %q, got %q", hn, traceSub.Subject, hv) 2054 } 2055 hnb = []byte(traceParentHdr) 2056 hnb[0] = 'X' 2057 hn = string(hnb) 2058 if hv := appMsg.Header.Get(hn); hv != traceParentHdrVal { 2059 t.Fatalf("Expected header %q to be %q, got %q", hn, traceParentHdrVal, hv) 2060 } 2061 } 2062 appMsg.Respond(appMsg.Data) 2063 } 2064 processSvc(subSvcA) 2065 processSvc(subSvcC) 2066 2067 for i := 0; i < 2; i++ { 2068 appMsg := natsNexMsg(t, sub, time.Second) 2069 require_Equal[string](t, string(appMsg.Data), "request2") 2070 } 2071 } 2072 // Check that no (more) messages are received. 2073 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 2074 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 2075 } 2076 if !test.deliverMsg { 2077 // Just to make sure that message was not delivered to service 2078 // responders, wait a bit and check the recv value. 2079 time.Sleep(50 * time.Millisecond) 2080 for _, sub := range []*nats.Subscription{subSvcA, subSvcC} { 2081 if msg, err := sub.NextMsg(250 * time.Millisecond); err == nil { 2082 t.Fatalf("Expected no message to be received, but service subscription got %s", msg.Data) 2083 } 2084 } 2085 } 2086 2087 check := func() { 2088 traceMsg := natsNexMsg(t, traceSub, time.Second) 2089 var e MsgTraceEvent 2090 json.Unmarshal(traceMsg.Data, &e) 2091 2092 ingress := e.Ingress() 2093 require_True(t, ingress != nil) 2094 switch ingress.Kind { 2095 case CLIENT: 2096 require_Equal[string](t, e.Server.Name, sfornc.Name()) 2097 require_Equal[string](t, ingress.Account, "D") 2098 require_Equal[string](t, ingress.Subject, "bat") 2099 sm := e.SubjectMapping() 2100 require_True(t, sm != nil) 2101 require_Equal[string](t, sm.MappedTo, "baz") 2102 simps := e.ServiceImports() 2103 require_True(t, simps != nil) 2104 var expectedServices int 2105 if mainTest.allow { 2106 expectedServices = 3 2107 } else { 2108 expectedServices = 2 2109 } 2110 require_Equal[int](t, len(simps), expectedServices) 2111 for _, si := range simps { 2112 switch si.Account { 2113 case "C": 2114 require_Equal[string](t, si.From, "baz") 2115 require_Equal[string](t, si.To, "baz") 2116 case "B": 2117 require_Equal[string](t, si.From, "baz") 2118 require_Equal[string](t, si.To, "bar") 2119 case "A": 2120 if !mainTest.allow { 2121 t.Fatalf("Without allow_trace, we should not see service for account A") 2122 } 2123 require_Equal[string](t, si.From, "bar") 2124 require_Equal[string](t, si.To, "bozo") 2125 default: 2126 t.Fatalf("Unexpected account name: %s", si.Account) 2127 } 2128 } 2129 egress := e.Egresses() 2130 if !mainTest.allow { 2131 require_Equal[int](t, len(egress), 0) 2132 } else { 2133 require_Equal[int](t, len(egress), 2) 2134 for _, eg := range egress { 2135 switch eg.Kind { 2136 case ROUTER: 2137 require_Equal[string](t, eg.Name, sfornc2.Name()) 2138 require_Equal[string](t, eg.Account, _EMPTY_) 2139 case GATEWAY: 2140 require_Equal[string](t, eg.Name, sfornc3.Name()) 2141 require_Equal[string](t, eg.Account, _EMPTY_) 2142 } 2143 } 2144 } 2145 case ROUTER: 2146 require_Equal[string](t, e.Server.Name, sfornc2.Name()) 2147 require_Equal[string](t, ingress.Account, "A") 2148 require_Equal[string](t, ingress.Subject, "bozo") 2149 egress := e.Egresses() 2150 require_Equal[int](t, len(egress), 1) 2151 eg := egress[0] 2152 require_True(t, eg.Kind == CLIENT) 2153 require_Equal[string](t, eg.Name, "ServiceA") 2154 require_Equal[string](t, eg.Account, _EMPTY_) 2155 require_Equal[string](t, eg.Subscription, "*") 2156 require_Equal[string](t, eg.Queue, "my_queue") 2157 case GATEWAY: 2158 require_Equal[string](t, e.Server.Name, sfornc3.Name()) 2159 require_Equal[string](t, ingress.Account, "C") 2160 require_Equal[string](t, ingress.Subject, "baz") 2161 egress := e.Egresses() 2162 require_Equal[int](t, len(egress), 1) 2163 eg := egress[0] 2164 require_True(t, eg.Kind == CLIENT) 2165 require_Equal[string](t, eg.Name, "ServiceC") 2166 require_Equal[string](t, eg.Account, _EMPTY_) 2167 require_Equal[string](t, eg.Subscription, "baz") 2168 require_Equal[string](t, eg.Queue, _EMPTY_) 2169 default: 2170 t.Fatalf("Unexpected ingress: %+v", ingress) 2171 } 2172 } 2173 // We should receive 3 events when allowed, a single when not. 2174 check() 2175 if mainTest.allow { 2176 check() 2177 check() 2178 } 2179 // Make sure we are not receiving more traces 2180 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 2181 t.Fatalf("Should not have received trace message: %s", tm.Data) 2182 } 2183 // Make sure that we never receive on any of the account 2184 // trace destination's sub. 2185 for _, sub := range accSubs { 2186 if tm, err := sub.NextMsg(100 * time.Millisecond); err == nil { 2187 t.Fatalf("Should not have received trace message on account's trace sub, got %s", tm.Data) 2188 } 2189 } 2190 // Make sure we properly remove the responses. 2191 checkResp := func(an string) { 2192 for _, s := range []*Server{sfornc, sfornc2, sfornc3} { 2193 acc, err := s.lookupAccount(an) 2194 require_NoError(t, err) 2195 checkFor(t, time.Second, 15*time.Millisecond, func() error { 2196 if n := acc.NumPendingAllResponses(); n != 0 { 2197 return fmt.Errorf("Still %d responses pending for account %q on server %s", n, acc, s) 2198 } 2199 return nil 2200 }) 2201 } 2202 } 2203 for _, acc := range []string{"A", "B", "C", "D"} { 2204 checkResp(acc) 2205 } 2206 }) 2207 } 2208 }) 2209 } 2210 } 2211 2212 func TestMsgTraceServiceImportWithLeafNodeHub(t *testing.T) { 2213 confHub := createConfFile(t, []byte(` 2214 listen: 127.0.0.1:-1 2215 server_name: "S1" 2216 accounts { 2217 A { 2218 users: [{user: a, password: pwd}] 2219 exports: [ { service: ">", allow_trace: true } ] 2220 mappings = { 2221 bar: bozo 2222 } 2223 } 2224 B { 2225 users: [{user: b, password: pwd}] 2226 imports: [ { service: {account: "A", subject:">"} } ] 2227 exports: [ { service: ">", allow_trace: true } ] 2228 } 2229 C { 2230 users: [{user: c, password: pwd}] 2231 exports: [ { service: ">", allow_trace: true } ] 2232 } 2233 D { 2234 users: [{user: d, password: pwd}] 2235 imports: [ 2236 { service: {account: "B", subject:"bar"}, to: baz } 2237 { service: {account: "C", subject:">"} } 2238 ] 2239 mappings = { 2240 bat: baz 2241 } 2242 } 2243 $SYS { users = [ { user: "admin", pass: "s3cr3t!" } ] } 2244 } 2245 leafnodes { 2246 port: -1 2247 } 2248 `)) 2249 hub, ohub := RunServerWithConfig(confHub) 2250 defer hub.Shutdown() 2251 2252 confLeaf := createConfFile(t, []byte(fmt.Sprintf(` 2253 listen: 127.0.0.1:-1 2254 server_name: "S2" 2255 leafnodes { 2256 remotes [{url: "nats://d:pwd@127.0.0.1:%d"}] 2257 } 2258 `, ohub.LeafNode.Port))) 2259 leaf, _ := RunServerWithConfig(confLeaf) 2260 defer leaf.Shutdown() 2261 2262 checkLeafNodeConnectedCount(t, hub, 1) 2263 checkLeafNodeConnectedCount(t, leaf, 1) 2264 2265 nc2 := natsConnect(t, hub.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("ServiceA")) 2266 defer nc2.Close() 2267 recv := int32(0) 2268 natsQueueSub(t, nc2, "*", "my_queue", func(m *nats.Msg) { 2269 atomic.AddInt32(&recv, 1) 2270 m.Respond(m.Data) 2271 }) 2272 natsFlush(t, nc2) 2273 2274 nc3 := natsConnect(t, hub.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("ServiceC")) 2275 defer nc3.Close() 2276 natsSub(t, nc3, "baz", func(m *nats.Msg) { 2277 atomic.AddInt32(&recv, 1) 2278 m.Respond(m.Data) 2279 }) 2280 natsFlush(t, nc3) 2281 2282 nc := natsConnect(t, leaf.ClientURL(), nats.Name("Requestor")) 2283 defer nc.Close() 2284 2285 traceSub := natsSubSync(t, nc, "my.trace.subj") 2286 sub := natsSubSync(t, nc, "my.service.response.inbox") 2287 2288 checkSubInterest(t, leaf, globalAccountName, "bat", time.Second) 2289 2290 for _, test := range []struct { 2291 name string 2292 deliverMsg bool 2293 }{ 2294 {"just trace", false}, 2295 {"deliver msg", true}, 2296 } { 2297 t.Run(test.name, func(t *testing.T) { 2298 msg := nats.NewMsg("bat") 2299 msg.Header.Set(MsgTraceDest, traceSub.Subject) 2300 if !test.deliverMsg { 2301 msg.Header.Set(MsgTraceOnly, "true") 2302 } 2303 if !test.deliverMsg { 2304 msg.Data = []byte("request1") 2305 } else { 2306 msg.Data = []byte("request2") 2307 } 2308 msg.Reply = sub.Subject 2309 2310 err := nc.PublishMsg(msg) 2311 require_NoError(t, err) 2312 2313 if test.deliverMsg { 2314 for i := 0; i < 2; i++ { 2315 appMsg := natsNexMsg(t, sub, time.Second) 2316 require_Equal[string](t, string(appMsg.Data), "request2") 2317 } 2318 } 2319 // Check that no (more) messages are received. 2320 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 2321 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 2322 } 2323 if !test.deliverMsg { 2324 // Just to make sure that message was not delivered to service 2325 // responders, wait a bit and check the recv value. 2326 time.Sleep(50 * time.Millisecond) 2327 if n := atomic.LoadInt32(&recv); n != 0 { 2328 t.Fatalf("Expected no message to be received, but service callback fired %d times", n) 2329 } 2330 } 2331 2332 check := func() { 2333 traceMsg := natsNexMsg(t, traceSub, time.Second) 2334 var e MsgTraceEvent 2335 json.Unmarshal(traceMsg.Data, &e) 2336 2337 ingress := e.Ingress() 2338 require_True(t, ingress != nil) 2339 switch ingress.Kind { 2340 case CLIENT: 2341 require_Equal[string](t, e.Server.Name, "S2") 2342 require_Equal[string](t, ingress.Account, globalAccountName) 2343 require_Equal[string](t, ingress.Subject, "bat") 2344 require_True(t, e.SubjectMapping() == nil) 2345 egress := e.Egresses() 2346 require_Equal[int](t, len(egress), 1) 2347 eg := egress[0] 2348 require_True(t, eg.Kind == LEAF) 2349 require_Equal[string](t, eg.Name, "S1") 2350 require_Equal[string](t, eg.Account, _EMPTY_) 2351 case LEAF: 2352 require_Equal[string](t, e.Server.Name, hub.Name()) 2353 require_Equal[string](t, ingress.Name, leaf.Name()) 2354 require_Equal[string](t, ingress.Account, "D") 2355 require_Equal[string](t, ingress.Subject, "bat") 2356 sm := e.SubjectMapping() 2357 require_True(t, sm != nil) 2358 require_Equal[string](t, sm.MappedTo, "baz") 2359 simps := e.ServiceImports() 2360 require_True(t, simps != nil) 2361 require_Equal[int](t, len(simps), 3) 2362 for _, si := range simps { 2363 switch si.Account { 2364 case "C": 2365 require_Equal[string](t, si.From, "baz") 2366 require_Equal[string](t, si.To, "baz") 2367 case "B": 2368 require_Equal[string](t, si.From, "baz") 2369 require_Equal[string](t, si.To, "bar") 2370 case "A": 2371 require_Equal[string](t, si.From, "bar") 2372 require_Equal[string](t, si.To, "bozo") 2373 default: 2374 t.Fatalf("Unexpected account name: %s", si.Account) 2375 } 2376 } 2377 egress := e.Egresses() 2378 require_Equal[int](t, len(egress), 2) 2379 for _, eg := range egress { 2380 require_True(t, eg.Kind == CLIENT) 2381 switch eg.Account { 2382 case "C": 2383 require_Equal[string](t, eg.Name, "ServiceC") 2384 require_Equal[string](t, eg.Subscription, "baz") 2385 require_Equal[string](t, eg.Queue, _EMPTY_) 2386 case "A": 2387 require_Equal[string](t, eg.Name, "ServiceA") 2388 require_Equal[string](t, eg.Subscription, "*") 2389 require_Equal[string](t, eg.Queue, "my_queue") 2390 default: 2391 t.Fatalf("Unexpected egress: %+v", eg) 2392 } 2393 } 2394 default: 2395 t.Fatalf("Unexpected ingress: %+v", ingress) 2396 } 2397 } 2398 // We should receive 2 events. 2399 check() 2400 check() 2401 // Make sure we are not receiving more traces 2402 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 2403 t.Fatalf("Should not have received trace message: %s", tm.Data) 2404 } 2405 2406 // Make sure we properly remove the responses. 2407 checkResp := func(an string) { 2408 acc, err := hub.lookupAccount(an) 2409 require_NoError(t, err) 2410 checkFor(t, time.Second, 15*time.Millisecond, func() error { 2411 if n := acc.NumPendingAllResponses(); n != 0 { 2412 return fmt.Errorf("Still %d responses for account %q pending on %s", n, an, hub) 2413 } 2414 return nil 2415 }) 2416 } 2417 for _, acc := range []string{"A", "B", "C", "D"} { 2418 checkResp(acc) 2419 } 2420 }) 2421 } 2422 } 2423 2424 func TestMsgTraceServiceImportWithLeafNodeLeaf(t *testing.T) { 2425 confHub := createConfFile(t, []byte(` 2426 listen: 127.0.0.1:-1 2427 server_name: "S1" 2428 accounts { 2429 A { 2430 users: [{user: a, password: pwd}] 2431 exports: [ { service: "bar", allow_trace: true } ] 2432 } 2433 B { 2434 users: [{user: b, password: pwd}] 2435 imports: [{ service: {account: "A", subject:"bar"}, to: baz }] 2436 } 2437 $SYS { users = [ { user: "admin", pass: "s3cr3t!" } ] } 2438 } 2439 leafnodes { 2440 port: -1 2441 } 2442 `)) 2443 hub, ohub := RunServerWithConfig(confHub) 2444 defer hub.Shutdown() 2445 2446 confLeaf := createConfFile(t, []byte(fmt.Sprintf(` 2447 listen: 127.0.0.1:-1 2448 server_name: "S2" 2449 accounts { 2450 A { 2451 users: [{user: a, password: pwd}] 2452 exports: [ { service: "bar"} ] 2453 } 2454 B { users: [{user: b, password: pwd}] } 2455 $SYS { users = [ { user: "admin", pass: "s3cr3t!" } ] } 2456 } 2457 leafnodes { 2458 remotes [ 2459 { 2460 url: "nats://a:pwd@127.0.0.1:%d" 2461 account: A 2462 } 2463 { 2464 url: "nats://b:pwd@127.0.0.1:%d" 2465 account: B 2466 } 2467 ] 2468 } 2469 `, ohub.LeafNode.Port, ohub.LeafNode.Port))) 2470 leaf, _ := RunServerWithConfig(confLeaf) 2471 defer leaf.Shutdown() 2472 2473 checkLeafNodeConnectedCount(t, hub, 2) 2474 checkLeafNodeConnectedCount(t, leaf, 2) 2475 2476 nc2 := natsConnect(t, leaf.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("ServiceA")) 2477 defer nc2.Close() 2478 recv := int32(0) 2479 natsQueueSub(t, nc2, "*", "my_queue", func(m *nats.Msg) { 2480 atomic.AddInt32(&recv, 1) 2481 m.Respond(m.Data) 2482 }) 2483 natsFlush(t, nc2) 2484 2485 nc := natsConnect(t, hub.ClientURL(), nats.UserInfo("b", "pwd"), nats.Name("Requestor")) 2486 defer nc.Close() 2487 2488 traceSub := natsSubSync(t, nc, "my.trace.subj") 2489 sub := natsSubSync(t, nc, "my.service.response.inbox") 2490 2491 // Check that hub has a subscription interest on "baz" 2492 checkSubInterest(t, hub, "A", "baz", time.Second) 2493 // And check that the leaf has the sub interest on the trace subject 2494 checkSubInterest(t, leaf, "B", traceSub.Subject, time.Second) 2495 2496 for _, test := range []struct { 2497 name string 2498 deliverMsg bool 2499 }{ 2500 {"just trace", false}, 2501 {"deliver msg", true}, 2502 } { 2503 t.Run(test.name, func(t *testing.T) { 2504 msg := nats.NewMsg("baz") 2505 msg.Header.Set(MsgTraceDest, traceSub.Subject) 2506 if !test.deliverMsg { 2507 msg.Header.Set(MsgTraceOnly, "true") 2508 } 2509 if !test.deliverMsg { 2510 msg.Data = []byte("request1") 2511 } else { 2512 msg.Data = []byte("request2") 2513 } 2514 msg.Reply = sub.Subject 2515 2516 err := nc.PublishMsg(msg) 2517 require_NoError(t, err) 2518 2519 if test.deliverMsg { 2520 appMsg := natsNexMsg(t, sub, time.Second) 2521 require_Equal[string](t, string(appMsg.Data), "request2") 2522 } 2523 // Check that no (more) messages are received. 2524 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 2525 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 2526 } 2527 if !test.deliverMsg { 2528 // Just to make sure that message was not delivered to service 2529 // responders, wait a bit and check the recv value. 2530 time.Sleep(50 * time.Millisecond) 2531 if n := atomic.LoadInt32(&recv); n != 0 { 2532 t.Fatalf("Expected no message to be received, but service callback fired %d times", n) 2533 } 2534 } 2535 2536 check := func() { 2537 traceMsg := natsNexMsg(t, traceSub, time.Second) 2538 var e MsgTraceEvent 2539 json.Unmarshal(traceMsg.Data, &e) 2540 2541 ingress := e.Ingress() 2542 require_True(t, ingress != nil) 2543 2544 switch ingress.Kind { 2545 case CLIENT: 2546 require_Equal[string](t, e.Server.Name, "S1") 2547 require_Equal[string](t, ingress.Name, "Requestor") 2548 require_Equal[string](t, ingress.Account, "B") 2549 require_Equal[string](t, ingress.Subject, "baz") 2550 require_True(t, e.SubjectMapping() == nil) 2551 simps := e.ServiceImports() 2552 require_True(t, simps != nil) 2553 require_Equal[int](t, len(simps), 1) 2554 si := simps[0] 2555 require_Equal[string](t, si.Account, "A") 2556 require_Equal[string](t, si.From, "baz") 2557 require_Equal[string](t, si.To, "bar") 2558 egress := e.Egresses() 2559 require_Equal[int](t, len(egress), 1) 2560 eg := egress[0] 2561 require_True(t, eg.Kind == LEAF) 2562 require_Equal[string](t, eg.Name, "S2") 2563 require_Equal[string](t, eg.Account, "A") 2564 require_Equal[string](t, eg.Subscription, _EMPTY_) 2565 case LEAF: 2566 require_Equal[string](t, e.Server.Name, leaf.Name()) 2567 require_Equal[string](t, ingress.Name, hub.Name()) 2568 require_Equal[string](t, ingress.Account, "A") 2569 require_Equal[string](t, ingress.Subject, "bar") 2570 require_True(t, e.SubjectMapping() == nil) 2571 require_True(t, e.ServiceImports() == nil) 2572 egress := e.Egresses() 2573 require_Equal[int](t, len(egress), 1) 2574 eg := egress[0] 2575 require_True(t, eg.Kind == CLIENT) 2576 require_Equal[string](t, eg.Name, "ServiceA") 2577 require_Equal[string](t, eg.Subscription, "*") 2578 require_Equal[string](t, eg.Queue, "my_queue") 2579 default: 2580 t.Fatalf("Unexpected ingress: %+v", ingress) 2581 } 2582 } 2583 // We should receive 2 events. 2584 check() 2585 check() 2586 // Make sure we are not receiving more traces 2587 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 2588 t.Fatalf("Should not have received trace message: %s", tm.Data) 2589 } 2590 2591 // Make sure we properly remove the responses. 2592 checkResp := func(an string) { 2593 acc, err := leaf.lookupAccount(an) 2594 require_NoError(t, err) 2595 checkFor(t, time.Second, 15*time.Millisecond, func() error { 2596 if n := acc.NumPendingAllResponses(); n != 0 { 2597 return fmt.Errorf("Still %d responses for account %q pending on %s", n, an, leaf) 2598 } 2599 return nil 2600 }) 2601 } 2602 for _, acc := range []string{"A", "B"} { 2603 checkResp(acc) 2604 } 2605 }) 2606 } 2607 } 2608 2609 func TestMsgTraceStreamExport(t *testing.T) { 2610 tmpl := ` 2611 listen: 127.0.0.1:-1 2612 accounts { 2613 A { 2614 users: [{user: a, password: pwd}] 2615 exports: [ 2616 { stream: "info.*.*.>"} 2617 ] 2618 } 2619 B { 2620 users: [{user: b, password: pwd}] 2621 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "B.info.$2.$1.>", allow_trace: %v } ] 2622 } 2623 C { 2624 users: [{user: c, password: pwd}] 2625 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "C.info.$1.$2.>", allow_trace: %v } ] 2626 } 2627 } 2628 ` 2629 conf := createConfFile(t, []byte(fmt.Sprintf(tmpl, false, false))) 2630 s, _ := RunServerWithConfig(conf) 2631 defer s.Shutdown() 2632 2633 nc := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("Tracer")) 2634 defer nc.Close() 2635 traceSub := natsSubSync(t, nc, "my.trace.subj") 2636 2637 nc2 := natsConnect(t, s.ClientURL(), nats.UserInfo("b", "pwd"), nats.Name("sub1")) 2638 defer nc2.Close() 2639 sub1 := natsSubSync(t, nc2, "B.info.*.*.>") 2640 natsFlush(t, nc2) 2641 2642 nc3 := natsConnect(t, s.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("sub2")) 2643 defer nc3.Close() 2644 sub2 := natsQueueSubSync(t, nc3, "C.info.>", "my_queue") 2645 natsFlush(t, nc3) 2646 2647 for mainIter, mainTest := range []struct { 2648 name string 2649 allow bool 2650 }{ 2651 {"not allowed", false}, 2652 {"allowed", true}, 2653 {"not allowed again", false}, 2654 } { 2655 t.Run(mainTest.name, func(t *testing.T) { 2656 for _, test := range []struct { 2657 name string 2658 deliverMsg bool 2659 }{ 2660 {"just trace", false}, 2661 {"deliver msg", true}, 2662 } { 2663 t.Run(test.name, func(t *testing.T) { 2664 msg := nats.NewMsg("info.11.22.bar") 2665 msg.Header.Set(MsgTraceDest, traceSub.Subject) 2666 if !test.deliverMsg { 2667 msg.Header.Set(MsgTraceOnly, "true") 2668 } 2669 msg.Data = []byte("hello") 2670 2671 err := nc.PublishMsg(msg) 2672 require_NoError(t, err) 2673 2674 if test.deliverMsg { 2675 appMsg := natsNexMsg(t, sub1, time.Second) 2676 require_Equal[string](t, appMsg.Subject, "B.info.22.11.bar") 2677 appMsg = natsNexMsg(t, sub2, time.Second) 2678 require_Equal[string](t, appMsg.Subject, "C.info.11.22.bar") 2679 } 2680 // Check that no (more) messages are received. 2681 for _, sub := range []*nats.Subscription{sub1, sub2} { 2682 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 2683 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 2684 } 2685 } 2686 2687 traceMsg := natsNexMsg(t, traceSub, time.Second) 2688 var e MsgTraceEvent 2689 json.Unmarshal(traceMsg.Data, &e) 2690 2691 require_Equal[string](t, e.Server.Name, s.Name()) 2692 ingress := e.Ingress() 2693 require_True(t, ingress != nil) 2694 require_True(t, ingress.Kind == CLIENT) 2695 require_Equal[string](t, ingress.Account, "A") 2696 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 2697 require_True(t, e.SubjectMapping() == nil) 2698 require_True(t, e.ServiceImports() == nil) 2699 stexps := e.StreamExports() 2700 require_True(t, stexps != nil) 2701 require_Equal[int](t, len(stexps), 2) 2702 for _, se := range stexps { 2703 require_True(t, se.Timestamp != time.Time{}) 2704 switch se.Account { 2705 case "B": 2706 require_Equal[string](t, se.To, "B.info.22.11.bar") 2707 case "C": 2708 require_Equal[string](t, se.To, "C.info.11.22.bar") 2709 default: 2710 t.Fatalf("Unexpected stream export: %+v", se) 2711 } 2712 } 2713 egress := e.Egresses() 2714 if mainTest.allow { 2715 require_Equal[int](t, len(egress), 2) 2716 for _, eg := range egress { 2717 require_True(t, eg.Kind == CLIENT) 2718 switch eg.Account { 2719 case "B": 2720 require_Equal[string](t, eg.Name, "sub1") 2721 require_Equal[string](t, eg.Subscription, "info.*.*.>") 2722 require_Equal[string](t, eg.Queue, _EMPTY_) 2723 case "C": 2724 require_Equal[string](t, eg.Name, "sub2") 2725 require_Equal[string](t, eg.Subscription, "info.*.*.>") 2726 require_Equal[string](t, eg.Queue, "my_queue") 2727 default: 2728 t.Fatalf("Unexpected egress: %+v", eg) 2729 } 2730 } 2731 } else { 2732 require_Equal[int](t, len(egress), 0) 2733 } 2734 }) 2735 } 2736 switch mainIter { 2737 case 0: 2738 reloadUpdateConfig(t, s, conf, fmt.Sprintf(tmpl, true, true)) 2739 case 1: 2740 reloadUpdateConfig(t, s, conf, fmt.Sprintf(tmpl, false, false)) 2741 } 2742 }) 2743 } 2744 } 2745 2746 func TestMsgTraceStreamExportWithSuperCluster(t *testing.T) { 2747 for _, mainTest := range []struct { 2748 name string 2749 allowStr string 2750 allow bool 2751 }{ 2752 {"allowed", "true", true}, 2753 {"not allowed", "false", false}, 2754 } { 2755 t.Run(mainTest.name, func(t *testing.T) { 2756 tmpl := ` 2757 listen: 127.0.0.1:-1 2758 server_name: %s 2759 jetstream: {max_mem_store: 256MB, max_file_store: 2GB, store_dir: '%s'} 2760 2761 cluster { 2762 name: %s 2763 listen: 127.0.0.1:%d 2764 routes = [%s] 2765 } 2766 accounts { 2767 A { 2768 users: [{user: a, password: pwd}] 2769 exports: [ 2770 { stream: "info.*.*.>"} 2771 ] 2772 } 2773 B { 2774 users: [{user: b, password: pwd}] 2775 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "B.info.$2.$1.>", allow_trace: ` + mainTest.allowStr + ` } ] 2776 } 2777 C { 2778 users: [{user: c, password: pwd}] 2779 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "C.info.$1.$2.>", allow_trace: ` + mainTest.allowStr + ` } ] 2780 } 2781 $SYS { users = [ { user: "admin", pass: "s3cr3t!" } ] } 2782 } 2783 ` 2784 sc := createJetStreamSuperClusterWithTemplate(t, tmpl, 2, 2) 2785 defer sc.shutdown() 2786 2787 sfornc := sc.clusters[0].servers[0] 2788 nc := natsConnect(t, sfornc.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("Tracer")) 2789 defer nc.Close() 2790 traceSub := natsSubSync(t, nc, "my.trace.subj") 2791 2792 sfornc2 := sc.clusters[0].servers[1] 2793 nc2 := natsConnect(t, sfornc2.ClientURL(), nats.UserInfo("b", "pwd"), nats.Name("sub1")) 2794 defer nc2.Close() 2795 sub1 := natsSubSync(t, nc2, "B.info.*.*.>") 2796 natsFlush(t, nc2) 2797 checkSubInterest(t, sfornc2, "A", traceSub.Subject, time.Second) 2798 2799 sfornc3 := sc.clusters[1].servers[0] 2800 nc3 := natsConnect(t, sfornc3.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("sub2")) 2801 defer nc3.Close() 2802 sub2 := natsQueueSubSync(t, nc3, "C.info.>", "my_queue") 2803 natsFlush(t, nc3) 2804 2805 checkSubInterest(t, sfornc, "A", "info.1.2.3.4", time.Second) 2806 for _, s := range sc.clusters[0].servers { 2807 checkForRegisteredQSubInterest(t, s, "C2", "A", "info.1.2.3", 1, time.Second) 2808 } 2809 2810 for _, test := range []struct { 2811 name string 2812 deliverMsg bool 2813 }{ 2814 {"just trace", false}, 2815 {"deliver msg", true}, 2816 } { 2817 t.Run(test.name, func(t *testing.T) { 2818 msg := nats.NewMsg("info.11.22.bar") 2819 msg.Header.Set(MsgTraceDest, traceSub.Subject) 2820 if !test.deliverMsg { 2821 msg.Header.Set(MsgTraceOnly, "true") 2822 } 2823 msg.Data = []byte("hello") 2824 2825 err := nc.PublishMsg(msg) 2826 require_NoError(t, err) 2827 2828 if test.deliverMsg { 2829 appMsg := natsNexMsg(t, sub1, time.Second) 2830 require_Equal[string](t, appMsg.Subject, "B.info.22.11.bar") 2831 appMsg = natsNexMsg(t, sub2, time.Second) 2832 require_Equal[string](t, appMsg.Subject, "C.info.11.22.bar") 2833 } 2834 // Check that no (more) messages are received. 2835 for _, sub := range []*nats.Subscription{sub1, sub2} { 2836 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 2837 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 2838 } 2839 } 2840 2841 check := func() { 2842 traceMsg := natsNexMsg(t, traceSub, time.Second) 2843 var e MsgTraceEvent 2844 json.Unmarshal(traceMsg.Data, &e) 2845 2846 ingress := e.Ingress() 2847 require_True(t, ingress != nil) 2848 switch ingress.Kind { 2849 case CLIENT: 2850 require_Equal[string](t, e.Server.Name, sfornc.Name()) 2851 require_Equal[string](t, ingress.Name, "Tracer") 2852 require_Equal[string](t, ingress.Account, "A") 2853 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 2854 require_True(t, e.SubjectMapping() == nil) 2855 require_True(t, e.ServiceImports() == nil) 2856 require_True(t, e.StreamExports() == nil) 2857 egress := e.Egresses() 2858 require_Equal[int](t, len(egress), 2) 2859 for _, eg := range egress { 2860 switch eg.Kind { 2861 case ROUTER: 2862 require_Equal[string](t, eg.Name, sfornc2.Name()) 2863 require_Equal[string](t, eg.Account, _EMPTY_) 2864 case GATEWAY: 2865 require_Equal[string](t, eg.Name, sfornc3.Name()) 2866 require_Equal[string](t, eg.Account, _EMPTY_) 2867 default: 2868 t.Fatalf("Unexpected egress: %+v", eg) 2869 } 2870 } 2871 case ROUTER: 2872 require_Equal[string](t, e.Server.Name, sfornc2.Name()) 2873 require_Equal[string](t, ingress.Name, sfornc.Name()) 2874 require_Equal[string](t, ingress.Account, "A") 2875 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 2876 require_True(t, e.SubjectMapping() == nil) 2877 require_True(t, e.ServiceImports() == nil) 2878 stexps := e.StreamExports() 2879 require_True(t, stexps != nil) 2880 require_Equal[int](t, len(stexps), 1) 2881 se := stexps[0] 2882 require_Equal[string](t, se.Account, "B") 2883 require_Equal[string](t, se.To, "B.info.22.11.bar") 2884 egress := e.Egresses() 2885 if mainTest.allow { 2886 require_Equal[int](t, len(egress), 1) 2887 eg := egress[0] 2888 require_True(t, eg.Kind == CLIENT) 2889 require_Equal[string](t, eg.Name, "sub1") 2890 require_Equal[string](t, eg.Subscription, "info.*.*.>") 2891 require_Equal[string](t, eg.Queue, _EMPTY_) 2892 } else { 2893 require_Equal[int](t, len(egress), 0) 2894 } 2895 case GATEWAY: 2896 require_Equal[string](t, e.Server.Name, sfornc3.Name()) 2897 require_Equal[string](t, ingress.Name, sfornc.Name()) 2898 require_Equal[string](t, ingress.Account, "A") 2899 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 2900 require_True(t, e.SubjectMapping() == nil) 2901 require_True(t, e.ServiceImports() == nil) 2902 stexps := e.StreamExports() 2903 require_True(t, stexps != nil) 2904 require_Equal[int](t, len(stexps), 1) 2905 se := stexps[0] 2906 require_Equal[string](t, se.Account, "C") 2907 require_Equal[string](t, se.To, "C.info.11.22.bar") 2908 egress := e.Egresses() 2909 if mainTest.allow { 2910 require_Equal[int](t, len(egress), 1) 2911 eg := egress[0] 2912 require_True(t, eg.Kind == CLIENT) 2913 require_Equal[string](t, eg.Name, "sub2") 2914 require_Equal[string](t, eg.Subscription, "info.*.*.>") 2915 require_Equal[string](t, eg.Queue, "my_queue") 2916 } else { 2917 require_Equal[int](t, len(egress), 0) 2918 } 2919 default: 2920 t.Fatalf("Unexpected ingress: %+v", ingress) 2921 } 2922 } 2923 // We expect 3 events 2924 check() 2925 check() 2926 check() 2927 // Make sure we are not receiving more traces 2928 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 2929 t.Fatalf("Should not have received trace message: %s", tm.Data) 2930 } 2931 }) 2932 } 2933 }) 2934 } 2935 } 2936 2937 func TestMsgTraceStreamExportWithLeafNode_Hub(t *testing.T) { 2938 confHub := createConfFile(t, []byte(` 2939 listen: 127.0.0.1:-1 2940 server_name: "S1" 2941 accounts { 2942 A { 2943 users: [{user: a, password: pwd}] 2944 exports: [ 2945 { stream: "info.*.*.>"} 2946 ] 2947 } 2948 B { 2949 users: [{user: b, password: pwd}] 2950 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "B.info.$2.$1.>", allow_trace: true } ] 2951 } 2952 C { 2953 users: [{user: c, password: pwd}] 2954 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "C.info.$1.$2.>", allow_trace: true } ] 2955 } 2956 } 2957 leafnodes { 2958 port: -1 2959 } 2960 `)) 2961 hub, ohub := RunServerWithConfig(confHub) 2962 defer hub.Shutdown() 2963 2964 confLeaf := createConfFile(t, []byte(fmt.Sprintf(` 2965 listen: 127.0.0.1:-1 2966 server_name: "S2" 2967 accounts { 2968 LEAF { users: [{user: leaf, password: pwd}] } 2969 } 2970 leafnodes { 2971 remotes [ 2972 { url: "nats://a:pwd@127.0.0.1:%d", account: "LEAF" } 2973 ] 2974 } 2975 `, ohub.LeafNode.Port))) 2976 leaf, _ := RunServerWithConfig(confLeaf) 2977 defer leaf.Shutdown() 2978 2979 checkLeafNodeConnectedCount(t, hub, 1) 2980 checkLeafNodeConnectedCount(t, leaf, 1) 2981 2982 nc := natsConnect(t, leaf.ClientURL(), nats.UserInfo("leaf", "pwd"), nats.Name("Tracer")) 2983 defer nc.Close() 2984 traceSub := natsSubSync(t, nc, "my.trace.subj") 2985 2986 checkSubInterest(t, hub, "A", traceSub.Subject, time.Second) 2987 2988 nc2 := natsConnect(t, hub.ClientURL(), nats.UserInfo("b", "pwd"), nats.Name("sub1")) 2989 defer nc2.Close() 2990 sub1 := natsSubSync(t, nc2, "B.info.*.*.>") 2991 natsFlush(t, nc2) 2992 2993 nc3 := natsConnect(t, hub.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("sub2")) 2994 defer nc3.Close() 2995 sub2 := natsQueueSubSync(t, nc3, "C.info.>", "my_queue") 2996 natsFlush(t, nc3) 2997 2998 acc, err := leaf.LookupAccount("LEAF") 2999 require_NoError(t, err) 3000 checkFor(t, time.Second, 50*time.Millisecond, func() error { 3001 acc.mu.RLock() 3002 sl := acc.sl 3003 acc.mu.RUnlock() 3004 r := sl.Match("info.1.2.3") 3005 ok := len(r.psubs) > 0 3006 if ok && (len(r.qsubs) == 0 || len(r.qsubs[0]) == 0) { 3007 ok = false 3008 } 3009 if !ok { 3010 return fmt.Errorf("Subscription interest not yet propagated") 3011 } 3012 return nil 3013 }) 3014 3015 for _, test := range []struct { 3016 name string 3017 deliverMsg bool 3018 }{ 3019 3020 {"just trace", false}, 3021 {"deliver msg", true}, 3022 } { 3023 3024 t.Run(test.name, func(t *testing.T) { 3025 msg := nats.NewMsg("info.11.22.bar") 3026 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3027 if !test.deliverMsg { 3028 msg.Header.Set(MsgTraceOnly, "true") 3029 } 3030 msg.Data = []byte("hello") 3031 3032 err := nc.PublishMsg(msg) 3033 require_NoError(t, err) 3034 3035 if test.deliverMsg { 3036 appMsg := natsNexMsg(t, sub1, time.Second) 3037 require_Equal[string](t, appMsg.Subject, "B.info.22.11.bar") 3038 appMsg = natsNexMsg(t, sub2, time.Second) 3039 require_Equal[string](t, appMsg.Subject, "C.info.11.22.bar") 3040 } 3041 // Check that no (more) messages are received. 3042 for _, sub := range []*nats.Subscription{sub1, sub2} { 3043 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 3044 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 3045 } 3046 } 3047 check := func() { 3048 traceMsg := natsNexMsg(t, traceSub, time.Second) 3049 var e MsgTraceEvent 3050 json.Unmarshal(traceMsg.Data, &e) 3051 3052 ingress := e.Ingress() 3053 require_True(t, ingress != nil) 3054 3055 switch ingress.Kind { 3056 case CLIENT: 3057 require_Equal[string](t, e.Server.Name, leaf.Name()) 3058 require_Equal[string](t, ingress.Name, "Tracer") 3059 require_Equal[string](t, ingress.Account, "LEAF") 3060 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 3061 require_True(t, e.SubjectMapping() == nil) 3062 require_True(t, e.ServiceImports() == nil) 3063 require_True(t, e.StreamExports() == nil) 3064 egress := e.Egresses() 3065 require_Equal[int](t, len(egress), 1) 3066 eg := egress[0] 3067 require_True(t, eg.Kind == LEAF) 3068 require_Equal[string](t, eg.Name, hub.Name()) 3069 require_Equal[string](t, eg.Account, _EMPTY_) 3070 require_Equal[string](t, eg.Subscription, _EMPTY_) 3071 require_Equal[string](t, eg.Queue, _EMPTY_) 3072 case LEAF: 3073 require_Equal[string](t, e.Server.Name, hub.Name()) 3074 require_Equal[string](t, ingress.Name, leaf.Name()) 3075 require_Equal[string](t, ingress.Account, "A") 3076 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 3077 require_True(t, e.SubjectMapping() == nil) 3078 require_True(t, e.ServiceImports() == nil) 3079 stexps := e.StreamExports() 3080 require_True(t, stexps != nil) 3081 require_Equal[int](t, len(stexps), 2) 3082 for _, se := range stexps { 3083 switch se.Account { 3084 case "B": 3085 require_Equal[string](t, se.To, "B.info.22.11.bar") 3086 case "C": 3087 require_Equal[string](t, se.To, "C.info.11.22.bar") 3088 default: 3089 t.Fatalf("Unexpected stream export: %+v", se) 3090 } 3091 } 3092 egress := e.Egresses() 3093 require_Equal[int](t, len(egress), 2) 3094 for _, eg := range egress { 3095 require_True(t, eg.Kind == CLIENT) 3096 switch eg.Account { 3097 case "B": 3098 require_Equal[string](t, eg.Name, "sub1") 3099 require_Equal[string](t, eg.Subscription, "info.*.*.>") 3100 require_Equal[string](t, eg.Queue, _EMPTY_) 3101 case "C": 3102 require_Equal[string](t, eg.Name, "sub2") 3103 require_Equal[string](t, eg.Subscription, "info.*.*.>") 3104 require_Equal[string](t, eg.Queue, "my_queue") 3105 default: 3106 t.Fatalf("Unexpected egress: %+v", eg) 3107 } 3108 } 3109 default: 3110 t.Fatalf("Unexpected ingress: %+v", ingress) 3111 } 3112 } 3113 // We expect 2 events 3114 check() 3115 check() 3116 // Make sure we are not receiving more traces 3117 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 3118 t.Fatalf("Should not have received trace message: %s", tm.Data) 3119 } 3120 }) 3121 } 3122 } 3123 3124 func TestMsgTraceStreamExportWithLeafNode_Leaf(t *testing.T) { 3125 confHub := createConfFile(t, []byte(` 3126 listen: 127.0.0.1:-1 3127 server_name: "S1" 3128 accounts { 3129 HUB { users: [{user: hub, password: pwd}] } 3130 } 3131 leafnodes { 3132 port: -1 3133 } 3134 `)) 3135 hub, ohub := RunServerWithConfig(confHub) 3136 defer hub.Shutdown() 3137 3138 confLeaf := createConfFile(t, []byte(fmt.Sprintf(` 3139 listen: 127.0.0.1:-1 3140 server_name: "S2" 3141 accounts { 3142 A { 3143 users: [{user: a, password: pwd}] 3144 exports: [ 3145 { stream: "info.*.*.>"} 3146 ] 3147 } 3148 B { 3149 users: [{user: b, password: pwd}] 3150 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "B.info.$2.$1.>", allow_trace: true } ] 3151 } 3152 C { 3153 users: [{user: c, password: pwd}] 3154 imports: [ { stream: {account: "A", subject:"info.*.*.>"}, to: "C.info.$1.$2.>", allow_trace: true } ] 3155 } 3156 } 3157 leafnodes { 3158 remotes [ 3159 { url: "nats://hub:pwd@127.0.0.1:%d", account: "A" } 3160 ] 3161 } 3162 `, ohub.LeafNode.Port))) 3163 leaf, _ := RunServerWithConfig(confLeaf) 3164 defer leaf.Shutdown() 3165 3166 checkLeafNodeConnectedCount(t, hub, 1) 3167 checkLeafNodeConnectedCount(t, leaf, 1) 3168 3169 nc := natsConnect(t, hub.ClientURL(), nats.UserInfo("hub", "pwd"), nats.Name("Tracer")) 3170 defer nc.Close() 3171 traceSub := natsSubSync(t, nc, "my.trace.subj") 3172 3173 checkSubInterest(t, leaf, "A", traceSub.Subject, time.Second) 3174 3175 nc2 := natsConnect(t, leaf.ClientURL(), nats.UserInfo("b", "pwd"), nats.Name("sub1")) 3176 defer nc2.Close() 3177 sub1 := natsSubSync(t, nc2, "B.info.*.*.>") 3178 natsFlush(t, nc2) 3179 3180 nc3 := natsConnect(t, leaf.ClientURL(), nats.UserInfo("c", "pwd"), nats.Name("sub2")) 3181 defer nc3.Close() 3182 sub2 := natsQueueSubSync(t, nc3, "C.info.>", "my_queue") 3183 natsFlush(t, nc3) 3184 3185 acc, err := hub.LookupAccount("HUB") 3186 require_NoError(t, err) 3187 checkFor(t, time.Second, 50*time.Millisecond, func() error { 3188 acc.mu.RLock() 3189 sl := acc.sl 3190 acc.mu.RUnlock() 3191 r := sl.Match("info.1.2.3") 3192 ok := len(r.psubs) > 0 3193 if ok && (len(r.qsubs) == 0 || len(r.qsubs[0]) == 0) { 3194 ok = false 3195 } 3196 if !ok { 3197 return fmt.Errorf("Subscription interest not yet propagated") 3198 } 3199 return nil 3200 }) 3201 3202 for _, test := range []struct { 3203 name string 3204 deliverMsg bool 3205 }{ 3206 3207 {"just trace", false}, 3208 {"deliver msg", true}, 3209 } { 3210 3211 t.Run(test.name, func(t *testing.T) { 3212 msg := nats.NewMsg("info.11.22.bar") 3213 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3214 if !test.deliverMsg { 3215 msg.Header.Set(MsgTraceOnly, "true") 3216 } 3217 msg.Data = []byte("hello") 3218 3219 err := nc.PublishMsg(msg) 3220 require_NoError(t, err) 3221 3222 if test.deliverMsg { 3223 appMsg := natsNexMsg(t, sub1, time.Second) 3224 require_Equal[string](t, appMsg.Subject, "B.info.22.11.bar") 3225 appMsg = natsNexMsg(t, sub2, time.Second) 3226 require_Equal[string](t, appMsg.Subject, "C.info.11.22.bar") 3227 } 3228 // Check that no (more) messages are received. 3229 for _, sub := range []*nats.Subscription{sub1, sub2} { 3230 if msg, err := sub.NextMsg(100 * time.Millisecond); msg != nil || err != nats.ErrTimeout { 3231 t.Fatalf("Did not expect application message, got msg=%v err=%v", msg, err) 3232 } 3233 } 3234 check := func() { 3235 traceMsg := natsNexMsg(t, traceSub, time.Second) 3236 var e MsgTraceEvent 3237 json.Unmarshal(traceMsg.Data, &e) 3238 3239 ingress := e.Ingress() 3240 require_True(t, ingress != nil) 3241 3242 switch ingress.Kind { 3243 case CLIENT: 3244 require_Equal[string](t, e.Server.Name, hub.Name()) 3245 require_Equal[string](t, ingress.Name, "Tracer") 3246 require_Equal[string](t, ingress.Account, "HUB") 3247 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 3248 require_True(t, e.SubjectMapping() == nil) 3249 require_True(t, e.ServiceImports() == nil) 3250 require_True(t, e.StreamExports() == nil) 3251 egress := e.Egresses() 3252 require_Equal[int](t, len(egress), 1) 3253 eg := egress[0] 3254 require_True(t, eg.Kind == LEAF) 3255 require_Equal[string](t, eg.Name, leaf.Name()) 3256 require_Equal[string](t, eg.Account, _EMPTY_) 3257 require_Equal[string](t, eg.Subscription, _EMPTY_) 3258 require_Equal[string](t, eg.Queue, _EMPTY_) 3259 case LEAF: 3260 require_Equal[string](t, e.Server.Name, leaf.Name()) 3261 require_Equal[string](t, ingress.Name, hub.Name()) 3262 require_Equal[string](t, ingress.Account, "A") 3263 require_Equal[string](t, ingress.Subject, "info.11.22.bar") 3264 require_True(t, e.SubjectMapping() == nil) 3265 require_True(t, e.ServiceImports() == nil) 3266 stexps := e.StreamExports() 3267 require_True(t, stexps != nil) 3268 require_Equal[int](t, len(stexps), 2) 3269 for _, se := range stexps { 3270 switch se.Account { 3271 case "B": 3272 require_Equal[string](t, se.To, "B.info.22.11.bar") 3273 case "C": 3274 require_Equal[string](t, se.To, "C.info.11.22.bar") 3275 default: 3276 t.Fatalf("Unexpected stream export: %+v", se) 3277 } 3278 } 3279 egress := e.Egresses() 3280 require_Equal[int](t, len(egress), 2) 3281 for _, eg := range egress { 3282 require_True(t, eg.Kind == CLIENT) 3283 switch eg.Account { 3284 case "B": 3285 require_Equal[string](t, eg.Name, "sub1") 3286 require_Equal[string](t, eg.Subscription, "info.*.*.>") 3287 require_Equal[string](t, eg.Queue, _EMPTY_) 3288 case "C": 3289 require_Equal[string](t, eg.Name, "sub2") 3290 require_Equal[string](t, eg.Subscription, "info.*.*.>") 3291 require_Equal[string](t, eg.Queue, "my_queue") 3292 default: 3293 t.Fatalf("Unexpected egress: %+v", eg) 3294 } 3295 } 3296 default: 3297 t.Fatalf("Unexpected ingress: %+v", ingress) 3298 } 3299 } 3300 // We expect 2 events 3301 check() 3302 check() 3303 // Make sure we are not receiving more traces 3304 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 3305 t.Fatalf("Should not have received trace message: %s", tm.Data) 3306 } 3307 }) 3308 } 3309 } 3310 3311 func TestMsgTraceJetStream(t *testing.T) { 3312 opts := DefaultTestOptions 3313 opts.Port = -1 3314 opts.JetStream = true 3315 opts.JetStreamMaxMemory = 270 3316 opts.StoreDir = t.TempDir() 3317 s := RunServer(&opts) 3318 defer s.Shutdown() 3319 3320 nc, js := jsClientConnect(t, s) 3321 defer nc.Close() 3322 3323 cfg := &nats.StreamConfig{ 3324 Name: "TEST", 3325 Storage: nats.MemoryStorage, 3326 Subjects: []string{"foo"}, 3327 Replicas: 1, 3328 AllowRollup: true, 3329 SubjectTransform: &nats.SubjectTransformConfig{ 3330 Source: "foo", 3331 Destination: "bar", 3332 }, 3333 } 3334 _, err := js.AddStream(cfg) 3335 require_NoError(t, err) 3336 3337 nct := natsConnect(t, s.ClientURL(), nats.Name("Tracer")) 3338 defer nct.Close() 3339 3340 traceSub := natsSubSync(t, nct, "my.trace.subj") 3341 natsFlush(t, nct) 3342 3343 msg := nats.NewMsg("foo") 3344 msg.Header.Set(JSMsgId, "MyId") 3345 msg.Data = make([]byte, 50) 3346 _, err = js.PublishMsg(msg) 3347 require_NoError(t, err) 3348 3349 checkStream := func(t *testing.T, expected int) { 3350 t.Helper() 3351 checkFor(t, time.Second, 15*time.Millisecond, func() error { 3352 si, err := js.StreamInfo("TEST") 3353 if err != nil { 3354 return err 3355 } 3356 if n := si.State.Msgs; int(n) != expected { 3357 return fmt.Errorf("Expected %d messages, got %v", expected, n) 3358 } 3359 return nil 3360 }) 3361 } 3362 checkStream(t, 1) 3363 3364 for _, test := range []struct { 3365 name string 3366 deliverMsg bool 3367 }{ 3368 {"just trace", false}, 3369 {"deliver msg", true}, 3370 } { 3371 t.Run(test.name, func(t *testing.T) { 3372 msg := nats.NewMsg("foo") 3373 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3374 if !test.deliverMsg { 3375 msg.Header.Set(MsgTraceOnly, "true") 3376 } 3377 msg.Data = make([]byte, 50) 3378 err = nct.PublishMsg(msg) 3379 require_NoError(t, err) 3380 3381 // Wait a bit and check if message should be in the stream or not. 3382 time.Sleep(50 * time.Millisecond) 3383 if test.deliverMsg { 3384 checkStream(t, 2) 3385 } else { 3386 checkStream(t, 1) 3387 } 3388 3389 traceMsg := natsNexMsg(t, traceSub, time.Second) 3390 var e MsgTraceEvent 3391 json.Unmarshal(traceMsg.Data, &e) 3392 require_Equal[string](t, e.Server.Name, s.Name()) 3393 ingress := e.Ingress() 3394 require_True(t, ingress != nil) 3395 require_True(t, ingress.Kind == CLIENT) 3396 require_Equal[string](t, ingress.Name, "Tracer") 3397 require_Equal[int](t, len(e.Egresses()), 0) 3398 js := e.JetStream() 3399 require_True(t, js != nil) 3400 require_True(t, js.Timestamp != time.Time{}) 3401 require_Equal[string](t, js.Stream, "TEST") 3402 require_Equal[string](t, js.Subject, "bar") 3403 require_False(t, js.NoInterest) 3404 require_Equal[string](t, js.Error, _EMPTY_) 3405 }) 3406 } 3407 3408 jst, err := nct.JetStream() 3409 require_NoError(t, err) 3410 3411 mset, err := s.globalAccount().lookupStream("TEST") 3412 require_NoError(t, err) 3413 3414 // Now we will not ask for delivery and use headers that will fail checks 3415 // and make sure that message is not added, that the stream's clfs is not 3416 // increased, and that the JS trace shows the error. 3417 newMsg := func() *nats.Msg { 3418 msg = nats.NewMsg("foo") 3419 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3420 msg.Header.Set(MsgTraceOnly, "true") 3421 msg.Data = []byte("hello") 3422 return msg 3423 } 3424 3425 msgCount := 2 3426 for _, test := range []struct { 3427 name string 3428 headerName string 3429 headerVal string 3430 expectedErr string 3431 special int 3432 }{ 3433 {"unexpected stream name", JSExpectedStream, "WRONG", "expected stream does not match", 0}, 3434 {"duplicate id", JSMsgId, "MyId", "duplicate", 0}, 3435 {"last seq by subject mismatch", JSExpectedLastSubjSeq, "10", "last sequence by subject mismatch", 0}, 3436 {"last seq mismatch", JSExpectedLastSeq, "10", "last sequence mismatch", 0}, 3437 {"last msgid mismatch", JSExpectedLastMsgId, "MyId3", "last msgid mismatch", 0}, 3438 {"invalid rollup command", JSMsgRollup, "wrong", "rollup value invalid: \"wrong\"", 0}, 3439 {"rollup not permitted", JSMsgRollup, JSMsgRollupSubject, "rollup not permitted", 1}, 3440 {"max msg size", _EMPTY_, _EMPTY_, ErrMaxPayload.Error(), 2}, 3441 {"normal message ok", _EMPTY_, _EMPTY_, _EMPTY_, 3}, 3442 {"insufficient resources", _EMPTY_, _EMPTY_, NewJSInsufficientResourcesError().Error(), 0}, 3443 {"stream sealed", _EMPTY_, _EMPTY_, NewJSStreamSealedError().Error(), 4}, 3444 } { 3445 t.Run(test.name, func(t *testing.T) { 3446 msg = newMsg() 3447 if test.headerName != _EMPTY_ { 3448 msg.Header.Set(test.headerName, test.headerVal) 3449 } 3450 switch test.special { 3451 case 1: 3452 // Update stream to prevent rollups, and set a max size. 3453 cfg.AllowRollup = false 3454 cfg.MaxMsgSize = 100 3455 _, err = js.UpdateStream(cfg) 3456 require_NoError(t, err) 3457 case 2: 3458 msg.Data = make([]byte, 200) 3459 case 3: 3460 pa, err := jst.Publish("foo", make([]byte, 100)) 3461 require_NoError(t, err) 3462 msgCount++ 3463 checkStream(t, msgCount) 3464 require_Equal[uint64](t, pa.Sequence, 3) 3465 return 3466 case 4: 3467 cfg.Sealed = true 3468 _, err = js.UpdateStream(cfg) 3469 require_NoError(t, err) 3470 default: 3471 } 3472 jst.PublishMsg(msg) 3473 3474 // Message count should not have increased and stay at 2. 3475 checkStream(t, msgCount) 3476 // Check that clfs does not increase 3477 mset.mu.RLock() 3478 clfs := mset.getCLFS() 3479 mset.mu.RUnlock() 3480 if clfs != 0 { 3481 t.Fatalf("Stream's clfs was expected to be 0, is %d", clfs) 3482 } 3483 traceMsg := natsNexMsg(t, traceSub, time.Second) 3484 var e MsgTraceEvent 3485 json.Unmarshal(traceMsg.Data, &e) 3486 require_Equal[string](t, e.Server.Name, s.Name()) 3487 ingress := e.Ingress() 3488 require_True(t, ingress != nil) 3489 require_True(t, ingress.Kind == CLIENT) 3490 require_Equal[string](t, ingress.Name, "Tracer") 3491 require_Equal[int](t, len(e.Egresses()), 0) 3492 js := e.JetStream() 3493 require_True(t, js != nil) 3494 require_Equal[string](t, js.Stream, "TEST") 3495 require_Equal[string](t, js.Subject, _EMPTY_) 3496 require_False(t, js.NoInterest) 3497 if et := js.Error; !strings.Contains(et, test.expectedErr) { 3498 t.Fatalf("Expected JS error to contain %q, got %q", test.expectedErr, et) 3499 } 3500 }) 3501 } 3502 3503 // Create a stream with interest retention policy 3504 _, err = js.AddStream(&nats.StreamConfig{ 3505 Name: "NO_INTEREST", 3506 Subjects: []string{"baz"}, 3507 Retention: nats.InterestPolicy, 3508 }) 3509 require_NoError(t, err) 3510 msg = nats.NewMsg("baz") 3511 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3512 msg.Header.Set(MsgTraceOnly, "true") 3513 msg.Data = []byte("hello") 3514 err = nct.PublishMsg(msg) 3515 require_NoError(t, err) 3516 3517 traceMsg := natsNexMsg(t, traceSub, time.Second) 3518 var e MsgTraceEvent 3519 json.Unmarshal(traceMsg.Data, &e) 3520 require_Equal[string](t, e.Server.Name, s.Name()) 3521 ingress := e.Ingress() 3522 require_True(t, ingress != nil) 3523 require_True(t, ingress.Kind == CLIENT) 3524 require_Equal[string](t, ingress.Name, "Tracer") 3525 require_Equal[int](t, len(e.Egresses()), 0) 3526 ejs := e.JetStream() 3527 require_True(t, js != nil) 3528 require_Equal[string](t, ejs.Stream, "NO_INTEREST") 3529 require_Equal[string](t, ejs.Subject, "baz") 3530 require_True(t, ejs.NoInterest) 3531 require_Equal[string](t, ejs.Error, _EMPTY_) 3532 } 3533 3534 func TestMsgTraceJetStreamWithSuperCluster(t *testing.T) { 3535 sc := createJetStreamSuperCluster(t, 3, 2) 3536 defer sc.shutdown() 3537 3538 traceDest := "my.trace.subj" 3539 3540 // Hack to set the trace destination for the global account in order 3541 // to make sure that the traceParentHdr header is disabled when a message 3542 // is stored in JetStream, which will prevent emitting a trace 3543 // when such message is retrieved and traverses a route. 3544 // Without the account destination set, the trace would not be 3545 // triggered, but that does not mean that we would have been 3546 // doing the right thing of disabling the header. 3547 for _, cl := range sc.clusters { 3548 for _, s := range cl.servers { 3549 acc, err := s.LookupAccount(globalAccountName) 3550 require_NoError(t, err) 3551 acc.setTraceDest(traceDest) 3552 } 3553 } 3554 3555 c1 := sc.clusters[0] 3556 c2 := sc.clusters[1] 3557 nc, js := jsClientConnect(t, c1.randomServer()) 3558 defer nc.Close() 3559 3560 checkStream := func(t *testing.T, stream string, expected int) { 3561 t.Helper() 3562 checkFor(t, time.Second, 15*time.Millisecond, func() error { 3563 si, err := js.StreamInfo(stream) 3564 if err != nil { 3565 return err 3566 } 3567 if n := si.State.Msgs; int(n) != expected { 3568 return fmt.Errorf("Expected %d messages for stream %q, got %v", expected, stream, n) 3569 } 3570 return nil 3571 }) 3572 } 3573 3574 for mainIter, mainTest := range []struct { 3575 name string 3576 stream string 3577 }{ 3578 {"from stream leader", "TEST1"}, 3579 {"from non stream leader", "TEST2"}, 3580 {"from other cluster", "TEST3"}, 3581 } { 3582 t.Run(mainTest.name, func(t *testing.T) { 3583 cfg := &nats.StreamConfig{ 3584 Name: mainTest.stream, 3585 Replicas: 3, 3586 AllowRollup: true, 3587 } 3588 _, err := js.AddStream(cfg) 3589 require_NoError(t, err) 3590 sc.waitOnStreamLeader(globalAccountName, mainTest.stream) 3591 3592 // The streams are created from c1 cluster. 3593 slSrv := c1.streamLeader(globalAccountName, mainTest.stream) 3594 3595 // Store some messages 3596 payload := make([]byte, 50) 3597 for i := 0; i < 5; i++ { 3598 _, err = js.Publish(mainTest.stream, payload) 3599 require_NoError(t, err) 3600 } 3601 3602 // We will connect the app that sends the trace message to a server 3603 // that is either the stream leader, a random server in c1, or 3604 // a server in c2 (to go through a GW). 3605 var s *Server 3606 switch mainIter { 3607 case 0: 3608 s = slSrv 3609 case 1: 3610 s = c1.randomNonStreamLeader(globalAccountName, mainTest.stream) 3611 case 2: 3612 s = c2.randomServer() 3613 } 3614 3615 nct := natsConnect(t, s.ClientURL(), nats.Name("Tracer")) 3616 defer nct.Close() 3617 3618 traceSub := natsSubSync(t, nct, traceDest) 3619 natsFlush(t, nct) 3620 3621 for _, test := range []struct { 3622 name string 3623 deliverMsg bool 3624 }{ 3625 {"just trace", false}, 3626 {"deliver msg", true}, 3627 } { 3628 t.Run(test.name, func(t *testing.T) { 3629 msg := nats.NewMsg(mainTest.stream) 3630 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3631 if !test.deliverMsg { 3632 msg.Header.Set(MsgTraceOnly, "true") 3633 } 3634 // We add the traceParentHdr header to make sure that it 3635 // is deactivated in addition to the Nats-Trace-Dest 3636 // header too when needed. 3637 msg.Header.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 3638 msg.Header.Set(JSMsgId, "MyId") 3639 msg.Data = payload 3640 err = nct.PublishMsg(msg) 3641 require_NoError(t, err) 3642 3643 if test.deliverMsg { 3644 checkStream(t, mainTest.stream, 6) 3645 } else { 3646 checkStream(t, mainTest.stream, 5) 3647 } 3648 3649 check := func() bool { 3650 traceMsg := natsNexMsg(t, traceSub, time.Second) 3651 var e MsgTraceEvent 3652 json.Unmarshal(traceMsg.Data, &e) 3653 3654 checkJS := func() { 3655 t.Helper() 3656 js := e.JetStream() 3657 require_True(t, js != nil) 3658 require_Equal[string](t, js.Stream, mainTest.stream) 3659 require_Equal[string](t, js.Subject, mainTest.stream) 3660 require_False(t, js.NoInterest) 3661 require_Equal[string](t, js.Error, _EMPTY_) 3662 } 3663 3664 ingress := e.Ingress() 3665 require_True(t, ingress != nil) 3666 switch mainIter { 3667 case 0: 3668 require_Equal[string](t, e.Server.Name, s.Name()) 3669 require_True(t, ingress.Kind == CLIENT) 3670 require_Equal[string](t, ingress.Name, "Tracer") 3671 require_Equal[int](t, len(e.Egresses()), 0) 3672 checkJS() 3673 case 1: 3674 switch ingress.Kind { 3675 case CLIENT: 3676 require_Equal[string](t, e.Server.Name, s.Name()) 3677 require_Equal[string](t, ingress.Name, "Tracer") 3678 egress := e.Egresses() 3679 require_Equal[int](t, len(egress), 1) 3680 ci := egress[0] 3681 require_True(t, ci.Kind == ROUTER) 3682 require_Equal[string](t, ci.Name, slSrv.Name()) 3683 case ROUTER: 3684 require_Equal[string](t, e.Server.Name, slSrv.Name()) 3685 require_Equal[int](t, len(e.Egresses()), 0) 3686 checkJS() 3687 default: 3688 t.Fatalf("Unexpected ingress: %+v", ingress) 3689 } 3690 case 2: 3691 switch ingress.Kind { 3692 case CLIENT: 3693 require_Equal[string](t, e.Server.Name, s.Name()) 3694 require_Equal[string](t, ingress.Name, "Tracer") 3695 egress := e.Egresses() 3696 require_Equal[int](t, len(egress), 1) 3697 ci := egress[0] 3698 require_True(t, ci.Kind == GATEWAY) 3699 // It could have gone to any server in the C1 cluster. 3700 // If it is not the stream leader, it should be 3701 // routed to it. 3702 case GATEWAY: 3703 require_Equal[string](t, ingress.Name, s.Name()) 3704 // If the server that emitted this event is the 3705 // stream leader, then we should have the stream, 3706 // otherwise, it should be routed. 3707 if e.Server.Name == slSrv.Name() { 3708 require_Equal[int](t, len(e.Egresses()), 0) 3709 checkJS() 3710 } else { 3711 egress := e.Egresses() 3712 require_Equal[int](t, len(egress), 1) 3713 ci := egress[0] 3714 require_True(t, ci.Kind == ROUTER) 3715 require_Equal[string](t, ci.Name, slSrv.Name()) 3716 return true 3717 } 3718 case ROUTER: 3719 require_Equal[string](t, e.Server.Name, slSrv.Name()) 3720 require_Equal[int](t, len(e.Egresses()), 0) 3721 checkJS() 3722 default: 3723 t.Fatalf("Unexpected ingress: %+v", ingress) 3724 } 3725 } 3726 return false 3727 } 3728 check() 3729 if mainIter > 0 { 3730 if check() { 3731 check() 3732 } 3733 } 3734 // Make sure we are not receiving more traces 3735 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 3736 t.Fatalf("Should not have received trace message: %s", tm.Data) 3737 } 3738 }) 3739 } 3740 3741 jst, err := nct.JetStream() 3742 require_NoError(t, err) 3743 3744 newMsg := func() *nats.Msg { 3745 msg := nats.NewMsg(mainTest.stream) 3746 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3747 msg.Header.Set(MsgTraceOnly, "true") 3748 msg.Header.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 3749 msg.Data = []byte("hello") 3750 return msg 3751 } 3752 3753 msgCount := 6 3754 for _, subtest := range []struct { 3755 name string 3756 headerName string 3757 headerVal string 3758 expectedErr string 3759 special int 3760 }{ 3761 {"unexpected stream name", JSExpectedStream, "WRONG", "expected stream does not match", 0}, 3762 {"duplicate id", JSMsgId, "MyId", "duplicate", 0}, 3763 {"last seq by subject mismatch", JSExpectedLastSubjSeq, "3", "last sequence by subject mismatch", 0}, 3764 {"last seq mismatch", JSExpectedLastSeq, "10", "last sequence mismatch", 0}, 3765 {"last msgid mismatch", JSExpectedLastMsgId, "MyId3", "last msgid mismatch", 0}, 3766 {"invalid rollup command", JSMsgRollup, "wrong", "rollup value invalid: \"wrong\"", 0}, 3767 {"rollup not permitted", JSMsgRollup, JSMsgRollupSubject, "rollup not permitted", 1}, 3768 {"max msg size", _EMPTY_, _EMPTY_, ErrMaxPayload.Error(), 2}, 3769 {"new message ok", _EMPTY_, _EMPTY_, _EMPTY_, 3}, 3770 {"stream sealed", _EMPTY_, _EMPTY_, NewJSStreamSealedError().Error(), 4}, 3771 } { 3772 t.Run(subtest.name, func(t *testing.T) { 3773 msg := newMsg() 3774 if subtest.headerName != _EMPTY_ { 3775 msg.Header.Set(subtest.headerName, subtest.headerVal) 3776 } 3777 switch subtest.special { 3778 case 1: 3779 // Update stream to prevent rollups, and set a max size. 3780 cfg.AllowRollup = false 3781 cfg.MaxMsgSize = 100 3782 _, err = js.UpdateStream(cfg) 3783 require_NoError(t, err) 3784 case 2: 3785 msg.Data = make([]byte, 200) 3786 case 3: 3787 pa, err := jst.Publish(mainTest.stream, []byte("hello")) 3788 require_NoError(t, err) 3789 msgCount++ 3790 checkStream(t, mainTest.stream, msgCount) 3791 require_Equal[uint64](t, pa.Sequence, 7) 3792 return 3793 case 4: 3794 cfg.Sealed = true 3795 _, err = js.UpdateStream(cfg) 3796 require_NoError(t, err) 3797 default: 3798 } 3799 jst.PublishMsg(msg) 3800 checkStream(t, mainTest.stream, msgCount) 3801 checkJSTrace := func() bool { 3802 traceMsg := natsNexMsg(t, traceSub, time.Second) 3803 var e MsgTraceEvent 3804 json.Unmarshal(traceMsg.Data, &e) 3805 3806 checkJS := func() { 3807 t.Helper() 3808 js := e.JetStream() 3809 require_True(t, e.JetStream() != nil) 3810 require_Equal[string](t, js.Stream, mainTest.stream) 3811 require_Equal[string](t, js.Subject, _EMPTY_) 3812 require_False(t, js.NoInterest) 3813 if et := js.Error; !strings.Contains(et, subtest.expectedErr) { 3814 t.Fatalf("Expected JS error to contain %q, got %q", subtest.expectedErr, et) 3815 } 3816 } 3817 3818 ingress := e.Ingress() 3819 require_True(t, ingress != nil) 3820 // We will focus only on the trace message that 3821 // includes the JetStream event. 3822 switch mainIter { 3823 case 0: 3824 require_Equal[string](t, e.Server.Name, s.Name()) 3825 require_True(t, ingress.Kind == CLIENT) 3826 require_Equal[string](t, ingress.Name, "Tracer") 3827 require_Equal[int](t, len(e.Egresses()), 0) 3828 checkJS() 3829 case 1: 3830 if ingress.Kind == ROUTER { 3831 require_Equal[string](t, e.Server.Name, slSrv.Name()) 3832 require_Equal[int](t, len(e.Egresses()), 0) 3833 require_True(t, e.JetStream() != nil) 3834 checkJS() 3835 } 3836 case 2: 3837 switch ingress.Kind { 3838 case GATEWAY: 3839 require_Equal[string](t, ingress.Name, s.Name()) 3840 // If the server that emitted this event is the 3841 // stream leader, then we should have the stream, 3842 // otherwise, it should be routed. 3843 if e.Server.Name == slSrv.Name() { 3844 require_Equal[int](t, len(e.Egresses()), 0) 3845 checkJS() 3846 } else { 3847 return true 3848 } 3849 case ROUTER: 3850 require_Equal[string](t, e.Server.Name, slSrv.Name()) 3851 require_Equal[int](t, len(e.Egresses()), 0) 3852 checkJS() 3853 } 3854 } 3855 return false 3856 } 3857 checkJSTrace() 3858 if mainIter > 0 { 3859 if checkJSTrace() { 3860 checkJSTrace() 3861 } 3862 } 3863 }) 3864 } 3865 }) 3866 } 3867 3868 // Now cause a step-down, and verify count is as expected. 3869 for _, stream := range []string{"TEST1", "TEST2", "TEST3"} { 3870 _, err := nc.Request(fmt.Sprintf(JSApiStreamLeaderStepDownT, stream), nil, time.Second) 3871 require_NoError(t, err) 3872 sc.waitOnStreamLeader(globalAccountName, stream) 3873 checkStream(t, stream, 7) 3874 } 3875 3876 s := c1.randomNonStreamLeader(globalAccountName, "TEST1") 3877 // Try to get a message that will come from a route and make sure that 3878 // this does not trigger a trace message, that is, that headers have 3879 // been properly removed so that they don't trigger it. 3880 nct := natsConnect(t, s.ClientURL(), nats.Name("Tracer")) 3881 defer nct.Close() 3882 traceSub := natsSubSync(t, nct, traceDest) 3883 natsFlush(t, nct) 3884 3885 jct, err := nct.JetStream() 3886 require_NoError(t, err) 3887 3888 sub, err := jct.SubscribeSync("TEST1") 3889 require_NoError(t, err) 3890 for i := 0; i < 7; i++ { 3891 jmsg, err := sub.NextMsg(time.Second) 3892 require_NoError(t, err) 3893 require_Equal[string](t, jmsg.Header.Get(MsgTraceDest), _EMPTY_) 3894 } 3895 3896 msg, err := traceSub.NextMsg(250 * time.Millisecond) 3897 if err != nats.ErrTimeout { 3898 if msg != nil { 3899 t.Fatalf("Expected timeout, got msg headers=%+v data=%s", msg.Header, msg.Data) 3900 } 3901 t.Fatalf("Expected timeout, got err=%v", err) 3902 } 3903 } 3904 3905 func TestMsgTraceWithCompression(t *testing.T) { 3906 o := DefaultOptions() 3907 s := RunServer(o) 3908 defer s.Shutdown() 3909 3910 nc := natsConnect(t, s.ClientURL()) 3911 defer nc.Close() 3912 3913 traceSub := natsSubSync(t, nc, "my.trace.subj") 3914 natsFlush(t, nc) 3915 3916 for _, test := range []struct { 3917 compressAlgo string 3918 expectedHdr string 3919 unsupported bool 3920 }{ 3921 {"gzip", "gzip", false}, 3922 {"snappy", "snappy", false}, 3923 {"s2", "snappy", false}, 3924 {"bad one", "identity", true}, 3925 } { 3926 t.Run(test.compressAlgo, func(t *testing.T) { 3927 msg := nats.NewMsg("foo") 3928 msg.Header.Set(MsgTraceDest, traceSub.Subject) 3929 msg.Header.Set(acceptEncodingHeader, test.compressAlgo) 3930 msg.Data = []byte("hello!") 3931 err := nc.PublishMsg(msg) 3932 require_NoError(t, err) 3933 3934 traceMsg := natsNexMsg(t, traceSub, time.Second) 3935 data := traceMsg.Data 3936 eh := traceMsg.Header.Get(contentEncodingHeader) 3937 require_Equal[string](t, eh, test.expectedHdr) 3938 if test.unsupported { 3939 // We should be able to unmarshal directly 3940 } else { 3941 switch test.expectedHdr { 3942 case "gzip": 3943 zr, err := gzip.NewReader(bytes.NewReader(data)) 3944 require_NoError(t, err) 3945 data, err = io.ReadAll(zr) 3946 if err != nil && err != io.ErrUnexpectedEOF { 3947 t.Fatalf("Unexpected error: %v", err) 3948 } 3949 err = zr.Close() 3950 require_NoError(t, err) 3951 case "snappy": 3952 sr := s2.NewReader(bytes.NewReader(data)) 3953 data, err = io.ReadAll(sr) 3954 if err != nil && err != io.ErrUnexpectedEOF { 3955 t.Fatalf("Unexpected error: %v", err) 3956 } 3957 } 3958 } 3959 var e MsgTraceEvent 3960 err = json.Unmarshal(data, &e) 3961 require_NoError(t, err) 3962 ingress := e.Ingress() 3963 require_True(t, ingress != nil) 3964 require_Equal[string](t, e.Server.Name, s.Name()) 3965 require_Equal[string](t, ingress.Subject, "foo") 3966 }) 3967 } 3968 } 3969 3970 func TestMsgTraceHops(t *testing.T) { 3971 // Will have a test with following toplogy 3972 // 3973 // =================== =================== 3974 // = C1 cluster = = C2 cluster = 3975 // =================== <--- Gateway ---> =================== 3976 // = C1-S1 <-> C1-S2 = = C2-S1 = 3977 // =================== =================== 3978 // ^ ^ ^ 3979 // | Leafnode | | Leafnode 3980 // | | | 3981 // =================== =================== 3982 // = C3 cluster = = C4 cluster = 3983 // =================== =================== 3984 // = C3-S1 <-> C3-S2 = = C4-S1 = 3985 // =================== =================== 3986 // ^ 3987 // | Leafnode 3988 // |-------| 3989 // =================== 3990 // = C5 cluster = 3991 // =================== 3992 // = C5-S1 <-> C5-S2 = 3993 // =================== 3994 // 3995 // And a subscription on "foo" attached to all servers, and the subscription 3996 // on the trace subject attached to c1-s1 (and where the trace message will 3997 // be sent from). 3998 // 3999 commonTmpl := ` 4000 port: -1 4001 server_name: "%s-%s" 4002 accounts { 4003 A { users: [{user:"a", pass: "pwd"}] } 4004 $SYS { users: [{user:"admin", pass: "s3cr3t!"}] } 4005 } 4006 system_account: "$SYS" 4007 cluster { 4008 port: -1 4009 name: "%s" 4010 %s 4011 } 4012 ` 4013 genCommon := func(cname, sname string, routePort int) string { 4014 var routes string 4015 if routePort > 0 { 4016 routes = fmt.Sprintf(`routes: ["nats://127.0.0.1:%d"]`, routePort) 4017 } 4018 return fmt.Sprintf(commonTmpl, cname, sname, cname, routes) 4019 } 4020 c1s1conf := createConfFile(t, []byte(fmt.Sprintf(` 4021 %s 4022 gateway { 4023 port: -1 4024 name: "C1" 4025 } 4026 leafnodes { 4027 port: -1 4028 } 4029 `, genCommon("C1", "S1", 0)))) 4030 c1s1, oc1s1 := RunServerWithConfig(c1s1conf) 4031 defer c1s1.Shutdown() 4032 4033 c1s2conf := createConfFile(t, []byte(fmt.Sprintf(` 4034 %s 4035 gateway { 4036 port: -1 4037 name: "C1" 4038 } 4039 leafnodes { 4040 port: -1 4041 } 4042 `, genCommon("C1", "S2", oc1s1.Cluster.Port)))) 4043 c1s2, oc1s2 := RunServerWithConfig(c1s2conf) 4044 defer c1s2.Shutdown() 4045 4046 checkClusterFormed(t, c1s1, c1s2) 4047 4048 c2s1conf := createConfFile(t, []byte(fmt.Sprintf(` 4049 %s 4050 gateway { 4051 port: -1 4052 name: "C2" 4053 gateways [ 4054 { 4055 name: "C1" 4056 url: "nats://a:pwd@127.0.0.1:%d" 4057 } 4058 ] 4059 } 4060 leafnodes { 4061 port: -1 4062 } 4063 `, genCommon("C2", "S1", 0), oc1s1.Gateway.Port))) 4064 c2s1, oc2s1 := RunServerWithConfig(c2s1conf) 4065 defer c2s1.Shutdown() 4066 4067 c4s1conf := createConfFile(t, []byte(fmt.Sprintf(` 4068 %s 4069 leafnodes { 4070 remotes [{url: "nats://a:pwd@127.0.0.1:%d", account: "A"}] 4071 } 4072 `, genCommon("C4", "S1", 0), oc2s1.LeafNode.Port))) 4073 c4s1, _ := RunServerWithConfig(c4s1conf) 4074 defer c4s1.Shutdown() 4075 4076 for _, s := range []*Server{c1s1, c1s2, c2s1} { 4077 waitForOutboundGateways(t, s, 1, time.Second) 4078 } 4079 waitForInboundGateways(t, c2s1, 2, time.Second) 4080 4081 c3s1conf := createConfFile(t, []byte(fmt.Sprintf(` 4082 %s 4083 leafnodes { 4084 port: -1 4085 remotes [{url: "nats://a:pwd@127.0.0.1:%d", account: "A"}] 4086 } 4087 `, genCommon("C3", "S1", 0), oc1s1.LeafNode.Port))) 4088 c3s1, oc3s1 := RunServerWithConfig(c3s1conf) 4089 defer c3s1.Shutdown() 4090 4091 c3s2conf := createConfFile(t, []byte(fmt.Sprintf(` 4092 %s 4093 leafnodes { 4094 port: -1 4095 remotes [{url: "nats://a:pwd@127.0.0.1:%d", account: "A"}] 4096 } 4097 system_account: "$SYS" 4098 `, genCommon("C3", "S2", oc3s1.Cluster.Port), oc1s2.LeafNode.Port))) 4099 c3s2, oc3s2 := RunServerWithConfig(c3s2conf) 4100 defer c3s2.Shutdown() 4101 4102 checkClusterFormed(t, c3s1, c3s2) 4103 checkLeafNodeConnected(t, c1s1) 4104 checkLeafNodeConnected(t, c1s2) 4105 checkLeafNodeConnected(t, c3s1) 4106 checkLeafNodeConnected(t, c3s2) 4107 4108 c5s1conf := createConfFile(t, []byte(fmt.Sprintf(` 4109 %s 4110 leafnodes { 4111 remotes [{url: "nats://a:pwd@127.0.0.1:%d", account: "A"}] 4112 } 4113 `, genCommon("C5", "S1", 0), oc3s2.LeafNode.Port))) 4114 c5s1, oc5s1 := RunServerWithConfig(c5s1conf) 4115 defer c5s1.Shutdown() 4116 4117 c5s2conf := createConfFile(t, []byte(fmt.Sprintf(` 4118 %s 4119 leafnodes { 4120 remotes [{url: "nats://a:pwd@127.0.0.1:%d", account: "A"}] 4121 } 4122 `, genCommon("C5", "S2", oc5s1.Cluster.Port), oc3s2.LeafNode.Port))) 4123 c5s2, _ := RunServerWithConfig(c5s2conf) 4124 defer c5s2.Shutdown() 4125 4126 checkLeafNodeConnected(t, c5s1) 4127 checkLeafNodeConnected(t, c5s2) 4128 checkLeafNodeConnectedCount(t, c3s2, 3) 4129 4130 nct := natsConnect(t, c1s1.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name("Tracer")) 4131 defer nct.Close() 4132 traceSub := natsSubSync(t, nct, "my.trace.subj") 4133 natsFlush(t, nct) 4134 4135 allServers := []*Server{c1s1, c1s2, c2s1, c3s1, c3s2, c4s1, c5s1, c5s2} 4136 // Check that the subscription interest on the trace subject reaches all servers. 4137 for _, s := range allServers { 4138 if s == c2s1 { 4139 // Gateway needs to be checked differently. 4140 checkGWInterestOnlyModeInterestOn(t, c2s1, "C1", "A", traceSub.Subject) 4141 continue 4142 } 4143 checkSubInterest(t, s, "A", traceSub.Subject, time.Second) 4144 } 4145 4146 var subs []*nats.Subscription 4147 // Now create a subscription on "foo" on all servers (do in reverse order). 4148 for i := len(allServers) - 1; i >= 0; i-- { 4149 s := allServers[i] 4150 nc := natsConnect(t, s.ClientURL(), nats.UserInfo("a", "pwd"), nats.Name(fmt.Sprintf("sub%d", i+1))) 4151 defer nc.Close() 4152 subs = append(subs, natsSubSync(t, nc, "foo")) 4153 natsFlush(t, nc) 4154 } 4155 4156 // Check sub interest on "foo" on all servers. 4157 for _, s := range allServers { 4158 checkSubInterest(t, s, "A", "foo", time.Second) 4159 } 4160 4161 // Now send a trace message from c1s1 4162 msg := nats.NewMsg("foo") 4163 msg.Header.Set(MsgTraceDest, traceSub.Subject) 4164 msg.Data = []byte("hello!") 4165 err := nct.PublishMsg(msg) 4166 require_NoError(t, err) 4167 4168 // Check that all subscriptions received the message 4169 for i, sub := range subs { 4170 appMsg, err := sub.NextMsg(time.Second) 4171 if err != nil { 4172 t.Fatalf("Error getting app message for server %q", allServers[i]) 4173 } 4174 require_Equal[string](t, string(appMsg.Data), "hello!") 4175 // Check that no (more) messages are received. 4176 if msg, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 4177 t.Fatalf("Did not expect application message, got %s", msg.Data) 4178 } 4179 } 4180 4181 events := make(map[string]*MsgTraceEvent, 8) 4182 // We expect 8 events 4183 for i := 0; i < 8; i++ { 4184 traceMsg := natsNexMsg(t, traceSub, time.Second) 4185 var e MsgTraceEvent 4186 json.Unmarshal(traceMsg.Data, &e) 4187 4188 var hop string 4189 if hopVals := e.Request.Header[MsgTraceHop]; len(hopVals) > 0 { 4190 hop = hopVals[0] 4191 } 4192 events[hop] = &e 4193 } 4194 // Make sure we are not receiving more traces 4195 if tm, err := traceSub.NextMsg(250 * time.Millisecond); err == nil { 4196 t.Fatalf("Should not have received trace message: %s", tm.Data) 4197 } 4198 4199 checkIngress := func(e *MsgTraceEvent, kind int, name, hop string) *MsgTraceIngress { 4200 t.Helper() 4201 ingress := e.Ingress() 4202 require_True(t, ingress != nil) 4203 require_True(t, ingress.Kind == kind) 4204 require_Equal[string](t, ingress.Account, "A") 4205 require_Equal[string](t, ingress.Subject, "foo") 4206 require_Equal[string](t, ingress.Name, name) 4207 var hhop string 4208 if hopVals := e.Request.Header[MsgTraceHop]; len(hopVals) > 0 { 4209 hhop = hopVals[0] 4210 } 4211 require_Equal[string](t, hhop, hop) 4212 return ingress 4213 } 4214 4215 checkEgressClient := func(eg *MsgTraceEgress, name string) { 4216 t.Helper() 4217 require_True(t, eg.Kind == CLIENT) 4218 require_Equal[string](t, eg.Name, name) 4219 require_Equal[string](t, eg.Hop, _EMPTY_) 4220 require_Equal[string](t, eg.Subscription, "foo") 4221 require_Equal[string](t, eg.Queue, _EMPTY_) 4222 } 4223 4224 // First, we should have an event without a "hop" header, that is the 4225 // ingress from the client. 4226 e, ok := events[_EMPTY_] 4227 require_True(t, ok) 4228 checkIngress(e, CLIENT, "Tracer", _EMPTY_) 4229 require_Equal[int](t, e.Hops, 3) 4230 egress := e.Egresses() 4231 require_Equal[int](t, len(egress), 4) 4232 var ( 4233 leafC3S1Hop string 4234 leafC3S2Hop string 4235 leafC4S1Hop string 4236 leafC5S1Hop string 4237 leafC5S2Hop string 4238 routeC1S2Hop string 4239 gwC2S1Hop string 4240 ) 4241 for _, eg := range egress { 4242 switch eg.Kind { 4243 case CLIENT: 4244 checkEgressClient(eg, "sub1") 4245 case ROUTER: 4246 require_Equal[string](t, eg.Name, c1s2.Name()) 4247 routeC1S2Hop = eg.Hop 4248 case LEAF: 4249 require_Equal[string](t, eg.Name, c3s1.Name()) 4250 leafC3S1Hop = eg.Hop 4251 case GATEWAY: 4252 require_Equal[string](t, eg.Name, c2s1.Name()) 4253 gwC2S1Hop = eg.Hop 4254 default: 4255 t.Fatalf("Unexpected egress: %+v", eg) 4256 } 4257 } 4258 // All "hop" ids should be not empty and different from each other 4259 require_True(t, leafC3S1Hop != _EMPTY_ && routeC1S2Hop != _EMPTY_ && gwC2S1Hop != _EMPTY_) 4260 require_True(t, leafC3S1Hop != routeC1S2Hop && leafC3S1Hop != gwC2S1Hop && routeC1S2Hop != gwC2S1Hop) 4261 4262 // Now check the routed server in C1 (c1s2) 4263 e, ok = events[routeC1S2Hop] 4264 require_True(t, ok) 4265 checkIngress(e, ROUTER, c1s1.Name(), routeC1S2Hop) 4266 require_Equal[int](t, e.Hops, 1) 4267 egress = e.Egresses() 4268 require_Equal[int](t, len(egress), 2) 4269 for _, eg := range egress { 4270 switch eg.Kind { 4271 case CLIENT: 4272 checkEgressClient(eg, "sub2") 4273 case LEAF: 4274 require_Equal[string](t, eg.Name, c3s2.Name()) 4275 require_Equal[string](t, eg.Hop, routeC1S2Hop+".1") 4276 leafC3S2Hop = eg.Hop 4277 default: 4278 t.Fatalf("Unexpected egress: %+v", eg) 4279 } 4280 } 4281 require_True(t, leafC3S2Hop != _EMPTY_) 4282 4283 // Let's check the gateway server 4284 e, ok = events[gwC2S1Hop] 4285 require_True(t, ok) 4286 checkIngress(e, GATEWAY, c1s1.Name(), gwC2S1Hop) 4287 require_Equal[int](t, e.Hops, 1) 4288 egress = e.Egresses() 4289 require_Equal[int](t, len(egress), 2) 4290 for _, eg := range egress { 4291 switch eg.Kind { 4292 case CLIENT: 4293 checkEgressClient(eg, "sub3") 4294 case LEAF: 4295 require_Equal[string](t, eg.Name, c4s1.Name()) 4296 require_Equal[string](t, eg.Hop, gwC2S1Hop+".1") 4297 leafC4S1Hop = eg.Hop 4298 default: 4299 t.Fatalf("Unexpected egress: %+v", eg) 4300 } 4301 } 4302 require_True(t, leafC4S1Hop != _EMPTY_) 4303 4304 // Let's check the C3 cluster, starting at C3-S1 4305 e, ok = events[leafC3S1Hop] 4306 require_True(t, ok) 4307 checkIngress(e, LEAF, c1s1.Name(), leafC3S1Hop) 4308 require_Equal[int](t, e.Hops, 0) 4309 egress = e.Egresses() 4310 require_Equal[int](t, len(egress), 1) 4311 checkEgressClient(egress[0], "sub4") 4312 4313 // Now C3-S2 4314 e, ok = events[leafC3S2Hop] 4315 require_True(t, ok) 4316 checkIngress(e, LEAF, c1s2.Name(), leafC3S2Hop) 4317 require_Equal[int](t, e.Hops, 2) 4318 egress = e.Egresses() 4319 require_Equal[int](t, len(egress), 3) 4320 for _, eg := range egress { 4321 switch eg.Kind { 4322 case CLIENT: 4323 checkEgressClient(eg, "sub5") 4324 case LEAF: 4325 require_True(t, eg.Name == c5s1.Name() || eg.Name == c5s2.Name()) 4326 require_True(t, eg.Hop == leafC3S2Hop+".1" || eg.Hop == leafC3S2Hop+".2") 4327 if eg.Name == c5s1.Name() { 4328 leafC5S1Hop = eg.Hop 4329 } else { 4330 leafC5S2Hop = eg.Hop 4331 } 4332 default: 4333 t.Fatalf("Unexpected egress: %+v", eg) 4334 } 4335 } 4336 // The leafC5SxHop must be different and not empty 4337 require_True(t, leafC5S1Hop != _EMPTY_ && leafC5S1Hop != leafC5S2Hop && leafC5S2Hop != _EMPTY_) 4338 4339 // Check the C4 cluster 4340 e, ok = events[leafC4S1Hop] 4341 require_True(t, ok) 4342 checkIngress(e, LEAF, c2s1.Name(), leafC4S1Hop) 4343 require_Equal[int](t, e.Hops, 0) 4344 egress = e.Egresses() 4345 require_Equal[int](t, len(egress), 1) 4346 checkEgressClient(egress[0], "sub6") 4347 4348 // Finally, the C5 cluster, starting with C5-S1 4349 e, ok = events[leafC5S1Hop] 4350 require_True(t, ok) 4351 checkIngress(e, LEAF, c3s2.Name(), leafC5S1Hop) 4352 require_Equal[int](t, e.Hops, 0) 4353 egress = e.Egresses() 4354 require_Equal[int](t, len(egress), 1) 4355 checkEgressClient(egress[0], "sub7") 4356 4357 // Then C5-S2 4358 e, ok = events[leafC5S2Hop] 4359 require_True(t, ok) 4360 checkIngress(e, LEAF, c3s2.Name(), leafC5S2Hop) 4361 require_Equal[int](t, e.Hops, 0) 4362 egress = e.Egresses() 4363 require_Equal[int](t, len(egress), 1) 4364 checkEgressClient(egress[0], "sub8") 4365 } 4366 4367 func TestMsgTraceTriggeredByExternalHeader(t *testing.T) { 4368 tmpl := ` 4369 port: -1 4370 server_name: "%s" 4371 accounts { 4372 A { 4373 users: [{user:A, password: pwd}] 4374 trace_dest: "acc.trace.dest" 4375 } 4376 B { 4377 users: [{user:B, password: pwd}] 4378 %s 4379 } 4380 } 4381 cluster { 4382 name: "local" 4383 port: -1 4384 %s 4385 } 4386 ` 4387 conf1 := createConfFile(t, []byte(fmt.Sprintf(tmpl, "A", _EMPTY_, _EMPTY_))) 4388 s1, o1 := RunServerWithConfig(conf1) 4389 defer s1.Shutdown() 4390 4391 conf2 := createConfFile(t, []byte(fmt.Sprintf(tmpl, "B", _EMPTY_, fmt.Sprintf(`routes: ["nats://127.0.0.1:%d"]`, o1.Cluster.Port)))) 4392 s2, _ := RunServerWithConfig(conf2) 4393 defer s2.Shutdown() 4394 4395 checkClusterFormed(t, s1, s2) 4396 4397 nc2 := natsConnect(t, s2.ClientURL(), nats.UserInfo("A", "pwd")) 4398 defer nc2.Close() 4399 appSub := natsSubSync(t, nc2, "foo") 4400 natsFlush(t, nc2) 4401 4402 checkSubInterest(t, s1, "A", "foo", time.Second) 4403 4404 nc1 := natsConnect(t, s1.ClientURL(), nats.UserInfo("A", "pwd")) 4405 defer nc1.Close() 4406 4407 traceSub := natsSubSync(t, nc1, "trace.dest") 4408 accTraceSub := natsSubSync(t, nc1, "acc.trace.dest") 4409 natsFlush(t, nc1) 4410 4411 checkSubInterest(t, s1, "A", traceSub.Subject, time.Second) 4412 checkSubInterest(t, s1, "A", accTraceSub.Subject, time.Second) 4413 4414 var msgCount int 4415 for _, test := range []struct { 4416 name string 4417 setHeaders func(h nats.Header) 4418 traceTriggered bool 4419 traceOnly bool 4420 expectedAccSub bool 4421 }{ 4422 // Tests with external header only (no Nats-Trace-Dest). In this case, the 4423 // trace is triggered based on sampling (last token is `-01`). The presence 4424 // of Nats-Trace-Only has no effect and message should always be delivered 4425 // to the application. 4426 {"only external header sampling", 4427 func(h nats.Header) { 4428 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4429 }, 4430 true, 4431 false, 4432 true}, 4433 {"only external header with different case and sampling", 4434 func(h nats.Header) { 4435 h.Set("TraceParent", "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4436 }, 4437 true, 4438 false, 4439 true}, 4440 {"only external header sampling but not simply 01", 4441 func(h nats.Header) { 4442 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-25") 4443 }, 4444 true, 4445 false, 4446 true}, 4447 {"only external header no sampling", 4448 func(h nats.Header) { 4449 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00") 4450 }, 4451 false, 4452 false, 4453 false}, 4454 {"external header sampling and trace only", 4455 func(h nats.Header) { 4456 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4457 h.Set(MsgTraceOnly, "true") 4458 }, 4459 true, 4460 false, 4461 true}, 4462 {"external header no sampling and trace only", 4463 func(h nats.Header) { 4464 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00") 4465 h.Set(MsgTraceOnly, "true") 4466 }, 4467 false, 4468 false, 4469 false}, 4470 // Tests where Nats-Trace-Dest is present, so ignore external header and 4471 // always deliver to the Nats-Trace-Dest, not the account. 4472 {"trace dest and external header sampling", 4473 func(h nats.Header) { 4474 h.Set(MsgTraceDest, traceSub.Subject) 4475 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4476 }, 4477 true, 4478 false, 4479 false}, 4480 {"trace dest and external header no sampling", 4481 func(h nats.Header) { 4482 h.Set(MsgTraceDest, traceSub.Subject) 4483 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00") 4484 }, 4485 true, 4486 false, 4487 false}, 4488 {"trace dest with trace only and external header sampling", 4489 func(h nats.Header) { 4490 h.Set(MsgTraceDest, traceSub.Subject) 4491 h.Set(MsgTraceOnly, "true") 4492 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4493 }, 4494 true, 4495 true, 4496 false}, 4497 {"trace dest with trace only and external header no sampling", 4498 func(h nats.Header) { 4499 h.Set(MsgTraceDest, traceSub.Subject) 4500 h.Set(MsgTraceOnly, "true") 4501 h.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00") 4502 }, 4503 true, 4504 true, 4505 false}, 4506 } { 4507 t.Run(test.name, func(t *testing.T) { 4508 msg := nats.NewMsg("foo") 4509 test.setHeaders(msg.Header) 4510 msgCount++ 4511 msgPayload := fmt.Sprintf("msg%d", msgCount) 4512 msg.Data = []byte(msgPayload) 4513 err := nc1.PublishMsg(msg) 4514 require_NoError(t, err) 4515 4516 if !test.traceOnly { 4517 appMsg := natsNexMsg(t, appSub, time.Second) 4518 require_Equal[string](t, string(appMsg.Data), msgPayload) 4519 } 4520 // Make sure we don't receive more (or not if trace only) 4521 if appMsg, err := appSub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 4522 t.Fatalf("Expected no app message, got %q", appMsg.Data) 4523 } 4524 4525 checkTrace := func(sub *nats.Subscription) { 4526 // We should receive 2 traces, 1 per server. 4527 for i := 0; i < 2; i++ { 4528 tm := natsNexMsg(t, sub, time.Second) 4529 var e MsgTraceEvent 4530 err := json.Unmarshal(tm.Data, &e) 4531 require_NoError(t, err) 4532 } 4533 } 4534 4535 if test.traceTriggered { 4536 if test.expectedAccSub { 4537 checkTrace(accTraceSub) 4538 } else { 4539 checkTrace(traceSub) 4540 } 4541 } 4542 // Make sure no trace is received in the other trace sub 4543 // or no trace received at all. 4544 for _, sub := range []*nats.Subscription{accTraceSub, traceSub} { 4545 if tm, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 4546 t.Fatalf("Expected no trace for the trace sub on %q, got %q", sub.Subject, tm.Data) 4547 } 4548 } 4549 }) 4550 } 4551 4552 nc1.Close() 4553 nc2.Close() 4554 4555 // Now replace connections and subs for account "B" 4556 nc2 = natsConnect(t, s2.ClientURL(), nats.UserInfo("B", "pwd")) 4557 defer nc2.Close() 4558 appSub = natsSubSync(t, nc2, "foo") 4559 natsFlush(t, nc2) 4560 4561 checkSubInterest(t, s1, "B", "foo", time.Second) 4562 4563 nc1 = natsConnect(t, s1.ClientURL(), nats.UserInfo("B", "pwd")) 4564 defer nc1.Close() 4565 4566 traceSub = natsSubSync(t, nc1, "trace.dest") 4567 accTraceSub = natsSubSync(t, nc1, "acc.trace.dest") 4568 natsFlush(t, nc1) 4569 4570 checkSubInterest(t, s1, "B", traceSub.Subject, time.Second) 4571 checkSubInterest(t, s1, "B", accTraceSub.Subject, time.Second) 4572 4573 for _, test := range []struct { 4574 name string 4575 reload bool 4576 }{ 4577 {"external header but no account destination", true}, 4578 {"external header with account destination added through config reload", false}, 4579 } { 4580 t.Run(test.name, func(t *testing.T) { 4581 msg := nats.NewMsg("foo") 4582 msg.Header.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4583 msg.Data = []byte("hello") 4584 err := nc1.PublishMsg(msg) 4585 require_NoError(t, err) 4586 4587 // Application should receive the message 4588 appMsg := natsNexMsg(t, appSub, time.Second) 4589 require_Equal[string](t, string(appMsg.Data), "hello") 4590 // Only once... 4591 if appMsg, err := appSub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 4592 t.Fatalf("Expected no app message, got %q", appMsg.Data) 4593 } 4594 if !test.reload { 4595 // We should receive the traces (1 per server) on the account destination 4596 for i := 0; i < 2; i++ { 4597 tm := natsNexMsg(t, accTraceSub, time.Second) 4598 var e MsgTraceEvent 4599 err := json.Unmarshal(tm.Data, &e) 4600 require_NoError(t, err) 4601 } 4602 } 4603 // No (or no more) trace message should be received. 4604 for _, sub := range []*nats.Subscription{accTraceSub, traceSub} { 4605 if tm, err := sub.NextMsg(100 * time.Millisecond); err != nats.ErrTimeout { 4606 t.Fatalf("Expected no trace for the trace sub on %q, got %q", sub.Subject, tm.Data) 4607 } 4608 } 4609 // Do the config reload and we will repeat the test and now 4610 // we should receive the trace message into the account 4611 // destination trace. 4612 if test.reload { 4613 reloadUpdateConfig(t, s1, conf1, fmt.Sprintf(tmpl, "A", `trace_dest: "acc.trace.dest"`, _EMPTY_)) 4614 reloadUpdateConfig(t, s2, conf2, fmt.Sprintf(tmpl, "B", `trace_dest: "acc.trace.dest"`, fmt.Sprintf(`routes: ["nats://127.0.0.1:%d"]`, o1.Cluster.Port))) 4615 } 4616 }) 4617 } 4618 } 4619 4620 func TestMsgTraceAccountTraceDestJWTUpdate(t *testing.T) { 4621 // create system account 4622 sysKp, _ := nkeys.CreateAccount() 4623 sysPub, _ := sysKp.PublicKey() 4624 sysCreds := newUser(t, sysKp) 4625 // create account A 4626 akp, _ := nkeys.CreateAccount() 4627 aPub, _ := akp.PublicKey() 4628 claim := jwt.NewAccountClaims(aPub) 4629 aJwt, err := claim.Encode(oKp) 4630 require_NoError(t, err) 4631 4632 dir := t.TempDir() 4633 conf := createConfFile(t, []byte(fmt.Sprintf(` 4634 listen: -1 4635 operator: %s 4636 resolver: { 4637 type: full 4638 dir: '%s' 4639 } 4640 system_account: %s 4641 `, ojwt, dir, sysPub))) 4642 s, _ := RunServerWithConfig(conf) 4643 defer s.Shutdown() 4644 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 4645 4646 nc := natsConnect(t, s.ClientURL(), createUserCreds(t, nil, akp)) 4647 defer nc.Close() 4648 4649 sub := natsSubSync(t, nc, "acc.trace.dest") 4650 natsFlush(t, nc) 4651 4652 for i, test := range []struct { 4653 name string 4654 traceTriggered bool 4655 }{ 4656 {"no acc dest", false}, 4657 {"adding trace dest", true}, 4658 {"removing trace dest", false}, 4659 } { 4660 t.Run(test.name, func(t *testing.T) { 4661 msg := nats.NewMsg("foo") 4662 msg.Header.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4663 msg.Data = []byte("hello") 4664 err = nc.PublishMsg(msg) 4665 require_NoError(t, err) 4666 4667 if test.traceTriggered { 4668 tm := natsNexMsg(t, sub, time.Second) 4669 var e MsgTraceEvent 4670 err = json.Unmarshal(tm.Data, &e) 4671 require_NoError(t, err) 4672 // Simple check 4673 require_Equal[string](t, e.Server.Name, s.Name()) 4674 } 4675 // No (more) trace message expected. 4676 tm, err := sub.NextMsg(250 * time.Millisecond) 4677 if err != nats.ErrTimeout { 4678 t.Fatalf("Expected no trace message, got %s", tm.Data) 4679 } 4680 if i < 2 { 4681 if i == 0 { 4682 claim.Trace = &jwt.MsgTrace{Destination: "acc.trace.dest"} 4683 } else { 4684 claim.Trace = nil 4685 } 4686 aJwt, err = claim.Encode(oKp) 4687 require_NoError(t, err) 4688 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 4689 } 4690 }) 4691 } 4692 } 4693 4694 func TestMsgTraceServiceJWTUpdate(t *testing.T) { 4695 // create system account 4696 sysKp, _ := nkeys.CreateAccount() 4697 sysPub, _ := sysKp.PublicKey() 4698 sysCreds := newUser(t, sysKp) 4699 // create account A 4700 akp, _ := nkeys.CreateAccount() 4701 aPub, _ := akp.PublicKey() 4702 aClaim := jwt.NewAccountClaims(aPub) 4703 serviceExport := &jwt.Export{Subject: "req", Type: jwt.Service} 4704 aClaim.Exports.Add(serviceExport) 4705 aJwt, err := aClaim.Encode(oKp) 4706 require_NoError(t, err) 4707 // create account B 4708 bkp, _ := nkeys.CreateAccount() 4709 bPub, _ := bkp.PublicKey() 4710 bClaim := jwt.NewAccountClaims(bPub) 4711 serviceImport := &jwt.Import{Account: aPub, Subject: "req", Type: jwt.Service} 4712 bClaim.Imports.Add(serviceImport) 4713 bJwt, err := bClaim.Encode(oKp) 4714 require_NoError(t, err) 4715 4716 dir := t.TempDir() 4717 conf := createConfFile(t, []byte(fmt.Sprintf(` 4718 listen: -1 4719 operator: %s 4720 resolver: { 4721 type: full 4722 dir: '%s' 4723 } 4724 system_account: %s 4725 `, ojwt, dir, sysPub))) 4726 s, _ := RunServerWithConfig(conf) 4727 defer s.Shutdown() 4728 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 4729 updateJwt(t, s.ClientURL(), sysCreds, bJwt, 1) 4730 4731 ncA := natsConnect(t, s.ClientURL(), createUserCreds(t, nil, akp), nats.Name("Service")) 4732 defer ncA.Close() 4733 4734 natsSub(t, ncA, "req", func(m *nats.Msg) { 4735 m.Respond([]byte("resp")) 4736 }) 4737 natsFlush(t, ncA) 4738 4739 ncB := natsConnect(t, s.ClientURL(), createUserCreds(t, nil, bkp)) 4740 defer ncB.Close() 4741 4742 sub := natsSubSync(t, ncB, "trace.dest") 4743 natsFlush(t, ncB) 4744 4745 for i, test := range []struct { 4746 name string 4747 allowTrace bool 4748 }{ 4749 {"trace not allowed", false}, 4750 {"trace allowed", true}, 4751 {"trace not allowed again", false}, 4752 } { 4753 t.Run(test.name, func(t *testing.T) { 4754 msg := nats.NewMsg("req") 4755 msg.Header.Set(MsgTraceDest, sub.Subject) 4756 msg.Data = []byte("request") 4757 reply, err := ncB.RequestMsg(msg, time.Second) 4758 require_NoError(t, err) 4759 require_Equal[string](t, string(reply.Data), "resp") 4760 4761 tm := natsNexMsg(t, sub, time.Second) 4762 var e MsgTraceEvent 4763 err = json.Unmarshal(tm.Data, &e) 4764 require_NoError(t, err) 4765 require_Equal[string](t, e.Server.Name, s.Name()) 4766 require_Equal[string](t, e.Ingress().Account, bPub) 4767 sis := e.ServiceImports() 4768 require_Equal[int](t, len(sis), 1) 4769 si := sis[0] 4770 require_Equal[string](t, si.Account, aPub) 4771 egresses := e.Egresses() 4772 if !test.allowTrace { 4773 require_Equal[int](t, len(egresses), 0) 4774 } else { 4775 require_Equal[int](t, len(egresses), 1) 4776 eg := egresses[0] 4777 require_Equal[string](t, eg.Name, "Service") 4778 require_Equal[string](t, eg.Account, aPub) 4779 require_Equal[string](t, eg.Subscription, "req") 4780 } 4781 // No (more) trace message expected. 4782 tm, err = sub.NextMsg(250 * time.Millisecond) 4783 if err != nats.ErrTimeout { 4784 t.Fatalf("Expected no trace message, got %s", tm.Data) 4785 } 4786 if i < 2 { 4787 // Set AllowTrace to true at the first iteration, then 4788 // false at the second. 4789 aClaim.Exports[0].AllowTrace = (i == 0) 4790 aJwt, err = aClaim.Encode(oKp) 4791 require_NoError(t, err) 4792 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 4793 } 4794 }) 4795 } 4796 } 4797 4798 func TestMsgTraceStreamJWTUpdate(t *testing.T) { 4799 // create system account 4800 sysKp, _ := nkeys.CreateAccount() 4801 sysPub, _ := sysKp.PublicKey() 4802 sysCreds := newUser(t, sysKp) 4803 // create account A 4804 akp, _ := nkeys.CreateAccount() 4805 aPub, _ := akp.PublicKey() 4806 aClaim := jwt.NewAccountClaims(aPub) 4807 streamExport := &jwt.Export{Subject: "info", Type: jwt.Stream} 4808 aClaim.Exports.Add(streamExport) 4809 aJwt, err := aClaim.Encode(oKp) 4810 require_NoError(t, err) 4811 // create account B 4812 bkp, _ := nkeys.CreateAccount() 4813 bPub, _ := bkp.PublicKey() 4814 bClaim := jwt.NewAccountClaims(bPub) 4815 streamImport := &jwt.Import{Account: aPub, Subject: "info", To: "b", Type: jwt.Stream} 4816 bClaim.Imports.Add(streamImport) 4817 bJwt, err := bClaim.Encode(oKp) 4818 require_NoError(t, err) 4819 4820 dir := t.TempDir() 4821 conf := createConfFile(t, []byte(fmt.Sprintf(` 4822 listen: -1 4823 operator: %s 4824 resolver: { 4825 type: full 4826 dir: '%s' 4827 } 4828 system_account: %s 4829 `, ojwt, dir, sysPub))) 4830 s, _ := RunServerWithConfig(conf) 4831 defer s.Shutdown() 4832 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 4833 updateJwt(t, s.ClientURL(), sysCreds, bJwt, 1) 4834 4835 ncA := natsConnect(t, s.ClientURL(), createUserCreds(t, nil, akp)) 4836 defer ncA.Close() 4837 4838 traceSub := natsSubSync(t, ncA, "trace.dest") 4839 natsFlush(t, ncA) 4840 4841 ncB := natsConnect(t, s.ClientURL(), createUserCreds(t, nil, bkp), nats.Name("BInfo")) 4842 defer ncB.Close() 4843 4844 appSub := natsSubSync(t, ncB, "b.info") 4845 natsFlush(t, ncB) 4846 4847 for i, test := range []struct { 4848 name string 4849 allowTrace bool 4850 }{ 4851 {"trace not allowed", false}, 4852 {"trace allowed", true}, 4853 {"trace not allowed again", false}, 4854 } { 4855 t.Run(test.name, func(t *testing.T) { 4856 msg := nats.NewMsg("info") 4857 msg.Header.Set(MsgTraceDest, traceSub.Subject) 4858 msg.Data = []byte("some info") 4859 err = ncA.PublishMsg(msg) 4860 require_NoError(t, err) 4861 4862 appMsg := natsNexMsg(t, appSub, time.Second) 4863 require_Equal[string](t, string(appMsg.Data), "some info") 4864 4865 tm := natsNexMsg(t, traceSub, time.Second) 4866 var e MsgTraceEvent 4867 err = json.Unmarshal(tm.Data, &e) 4868 require_NoError(t, err) 4869 require_Equal[string](t, e.Server.Name, s.Name()) 4870 ses := e.StreamExports() 4871 require_Equal[int](t, len(ses), 1) 4872 se := ses[0] 4873 require_Equal[string](t, se.Account, bPub) 4874 require_Equal[string](t, se.To, "b.info") 4875 egresses := e.Egresses() 4876 if !test.allowTrace { 4877 require_Equal[int](t, len(egresses), 0) 4878 } else { 4879 require_Equal[int](t, len(egresses), 1) 4880 eg := egresses[0] 4881 require_Equal[string](t, eg.Name, "BInfo") 4882 require_Equal[string](t, eg.Account, bPub) 4883 require_Equal[string](t, eg.Subscription, "info") 4884 } 4885 // No (more) trace message expected. 4886 tm, err = traceSub.NextMsg(250 * time.Millisecond) 4887 if err != nats.ErrTimeout { 4888 t.Fatalf("Expected no trace message, got %s", tm.Data) 4889 } 4890 if i < 2 { 4891 // Set AllowTrace to true at the first iteration, then 4892 // false at the second. 4893 bClaim.Imports[0].AllowTrace = (i == 0) 4894 bJwt, err = bClaim.Encode(oKp) 4895 require_NoError(t, err) 4896 updateJwt(t, s.ClientURL(), sysCreds, bJwt, 1) 4897 } 4898 }) 4899 } 4900 } 4901 4902 func TestMsgTraceParseAccountDestWithSampling(t *testing.T) { 4903 tmpl := ` 4904 port: -1 4905 accounts { 4906 A { 4907 users: [{user: a, password: pwd}] 4908 %s 4909 } 4910 } 4911 ` 4912 for _, test := range []struct { 4913 name string 4914 samplingStr string 4915 want int 4916 }{ 4917 {"trace sampling no dest", `msg_trace: {sampling: 50}`, 0}, 4918 {"trace dest only", `msg_trace: {dest: foo}`, 100}, 4919 {"trace dest with number only", `msg_trace: {dest: foo, sampling: 20}`, 20}, 4920 {"trace dest with percentage", `msg_trace: {dest: foo, sampling: 50%}`, 50}, 4921 } { 4922 t.Run(test.name, func(t *testing.T) { 4923 conf := createConfFile(t, []byte(fmt.Sprintf(tmpl, test.samplingStr))) 4924 o := LoadConfig(conf) 4925 _, sampling := o.Accounts[0].getTraceDestAndSampling() 4926 require_Equal[int](t, test.want, sampling) 4927 }) 4928 } 4929 } 4930 4931 func TestMsgTraceAccountDestWithSampling(t *testing.T) { 4932 tmpl := ` 4933 port: -1 4934 server_name: %s 4935 accounts { 4936 A { 4937 users: [{user: a, password:pwd}] 4938 msg_trace: {dest: "acc.dest"%s} 4939 } 4940 } 4941 cluster { 4942 port: -1 4943 %s 4944 } 4945 ` 4946 conf1 := createConfFile(t, []byte(fmt.Sprintf(tmpl, "A", _EMPTY_, _EMPTY_))) 4947 s1, o1 := RunServerWithConfig(conf1) 4948 defer s1.Shutdown() 4949 4950 routes := fmt.Sprintf("routes: [\"nats://127.0.0.1:%d\"]", o1.Cluster.Port) 4951 conf2 := createConfFile(t, []byte(fmt.Sprintf(tmpl, "B", _EMPTY_, routes))) 4952 s2, _ := RunServerWithConfig(conf2) 4953 defer s2.Shutdown() 4954 4955 checkClusterFormed(t, s1, s2) 4956 4957 nc2 := natsConnect(t, s2.ClientURL(), nats.UserInfo("a", "pwd")) 4958 defer nc2.Close() 4959 natsSub(t, nc2, "foo", func(_ *nats.Msg) {}) 4960 natsFlush(t, nc2) 4961 4962 nc1 := natsConnect(t, s1.ClientURL(), nats.UserInfo("a", "pwd")) 4963 defer nc1.Close() 4964 sub := natsSubSync(t, nc1, "acc.dest") 4965 natsFlush(t, nc1) 4966 4967 checkSubInterest(t, s1, "A", "foo", time.Second) 4968 checkSubInterest(t, s2, "A", "acc.dest", time.Second) 4969 4970 for iter, test := range []struct { 4971 name string 4972 samplingStr string 4973 sampling int 4974 }{ 4975 // Sampling is considered 100% if not specified or <=0 or >= 100. 4976 // To disable sampling, the account destination should not be specified. 4977 {"no sampling specified", _EMPTY_, 100}, 4978 {"sampling specified", ", sampling: \"25%\"", 25}, 4979 {"no sampling again", _EMPTY_, 100}, 4980 } { 4981 t.Run(test.name, func(t *testing.T) { 4982 if iter > 0 { 4983 reloadUpdateConfig(t, s1, conf1, fmt.Sprintf(tmpl, "A", test.samplingStr, _EMPTY_)) 4984 reloadUpdateConfig(t, s2, conf2, fmt.Sprintf(tmpl, "B", test.samplingStr, routes)) 4985 } 4986 msg := nats.NewMsg("foo") 4987 msg.Header.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 4988 total := 400 4989 for i := 0; i < total; i++ { 4990 err := nc1.PublishMsg(msg) 4991 require_NoError(t, err) 4992 } 4993 // Wait a bit to make sure that we received all traces that should 4994 // have been received. 4995 time.Sleep(500 * time.Millisecond) 4996 n, _, err := sub.Pending() 4997 require_NoError(t, err) 4998 fromClient := 0 4999 fromRoute := 0 5000 for i := 0; i < n; i++ { 5001 msg = natsNexMsg(t, sub, time.Second) 5002 var e MsgTraceEvent 5003 err = json.Unmarshal(msg.Data, &e) 5004 require_NoError(t, err) 5005 ingress := e.Ingress() 5006 require_True(t, ingress != nil) 5007 switch ingress.Kind { 5008 case CLIENT: 5009 fromClient++ 5010 case ROUTER: 5011 fromRoute++ 5012 default: 5013 t.Fatalf("Unexpected ingress: %+v", ingress) 5014 } 5015 } 5016 // There should be as many messages coming from the origin server 5017 // and the routed server. This checks that if sampling is not 100% 5018 // then when a message is routed, the header is properly deactivated. 5019 require_Equal[int](t, fromClient, fromRoute) 5020 // Now check that if sampling was 100%, we have the total number 5021 // of published messages. 5022 if test.sampling == 100 { 5023 require_Equal[int](t, fromClient, total) 5024 } else { 5025 // Otherwise, we should have no more (but let's be conservative) 5026 // than the sampling number. 5027 require_LessThan[int](t, fromClient, int(float64(test.sampling*total/100)*1.35)) 5028 } 5029 }) 5030 } 5031 } 5032 5033 func TestMsgTraceAccDestWithSamplingJWTUpdate(t *testing.T) { 5034 // create system account 5035 sysKp, _ := nkeys.CreateAccount() 5036 sysPub, _ := sysKp.PublicKey() 5037 sysCreds := newUser(t, sysKp) 5038 // create account A 5039 akp, _ := nkeys.CreateAccount() 5040 aPub, _ := akp.PublicKey() 5041 claim := jwt.NewAccountClaims(aPub) 5042 claim.Trace = &jwt.MsgTrace{Destination: "acc.trace.dest"} 5043 aJwt, err := claim.Encode(oKp) 5044 require_NoError(t, err) 5045 5046 dir := t.TempDir() 5047 conf := createConfFile(t, []byte(fmt.Sprintf(` 5048 listen: -1 5049 operator: %s 5050 resolver: { 5051 type: full 5052 dir: '%s' 5053 } 5054 system_account: %s 5055 `, ojwt, dir, sysPub))) 5056 s, _ := RunServerWithConfig(conf) 5057 defer s.Shutdown() 5058 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 5059 5060 nc := natsConnect(t, s.ClientURL(), createUserCreds(t, nil, akp)) 5061 defer nc.Close() 5062 5063 sub := natsSubSync(t, nc, "acc.trace.dest") 5064 natsFlush(t, nc) 5065 5066 for iter, test := range []struct { 5067 name string 5068 sampling int 5069 }{ 5070 {"no sampling specified", 100}, 5071 {"sampling", 25}, 5072 {"set back sampling to 0", 100}, 5073 } { 5074 t.Run(test.name, func(t *testing.T) { 5075 if iter > 0 { 5076 claim.Trace = &jwt.MsgTrace{Destination: "acc.trace.dest", Sampling: test.sampling} 5077 aJwt, err = claim.Encode(oKp) 5078 require_NoError(t, err) 5079 updateJwt(t, s.ClientURL(), sysCreds, aJwt, 1) 5080 } 5081 5082 msg := nats.NewMsg("foo") 5083 msg.Header.Set(traceParentHdr, "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") 5084 msg.Data = []byte("hello") 5085 5086 total := 400 5087 for i := 0; i < total; i++ { 5088 err := nc.PublishMsg(msg) 5089 require_NoError(t, err) 5090 } 5091 // Wait a bit to make sure that we received all traces that should 5092 // have been received. 5093 time.Sleep(500 * time.Millisecond) 5094 n, _, err := sub.Pending() 5095 require_NoError(t, err) 5096 for i := 0; i < n; i++ { 5097 msg = natsNexMsg(t, sub, time.Second) 5098 var e MsgTraceEvent 5099 err = json.Unmarshal(msg.Data, &e) 5100 require_NoError(t, err) 5101 } 5102 // Now check that if sampling was 100%, we have the total number 5103 // of published messages. 5104 if test.sampling == 100 { 5105 require_Equal[int](t, n, total) 5106 } else { 5107 // Otherwise, we should have no more (but let's be conservative) 5108 // than the sampling number. 5109 require_LessThan[int](t, n, int(float64(test.sampling*total/100)*1.35)) 5110 } 5111 }) 5112 } 5113 }