search

nats-io / nats.node

Node.js client for NATS, the cloud native messaging system.
https://nats.io
Apache License 2.0
1.55k stars 163 forks source link

Can't connect to server with token authentication. #383

Closed roguh closed 3 years ago

roguh commented 3 years ago

Hello, First off thank you for writing this code. We rely on NATS and js so this is very useful for us.

I have tried connecting to a remote NATS server with token authentication and can't. My subscriptions don't receive data I send. I'm using nats@beta. My code works fine when testing with a local server that has token authentication. Our remote server is 3 NATS instances as a supercluster behind a Kubernetes load balancer.

Can you help me debug this? I tried Python and nats-pub/nats-sub; they work successfully.

Here is my sample code: https://gist.github.com/roguh/9c220782640279d040ee563c23300432

Here's the output:

$ 
NATS_AUTH_TOKEN=... NATS_URL=nats://localhost:4222 node src/nats_test.js
subscribing to test
publishing to test
Error: test publish and subscribe failed. messages received:
aricart commented 3 years ago

@roguh can you check that your environment has the token? - while your code would indicate that the token has a value, your results seem to indicate not. With that said, token authentication works:

server.conf:

authorization {
  token: "foo"
}

nats-server -DV -c server.conf

test.js

const { connect, StringCodec } = require("nats");

const sc = StringCodec();

(async () => {
  connect({token: "bad"}).catch((err) => {
    console.log("bad token:", err)
  })
  const nc = await connect({token: "foo"});
  console.log(`connected to ${nc.getServer()}`);
  nc.subscribe("hello", {callback: (err, msg) => {
    console.log(msg.subject, sc.decode(msg.data));
    }});

  nc.publish("hello", sc.encode("one"));
  nc.publish("hello", sc.encode("two"));
  await nc.flush();
  await nc.close();

})().then().catch((err) => {
  console.log(err);
})
❯ node test.js
bad token: NatsError: 'Authorization Violation'
    at Function.toError (/private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:281:20)
    at ProtocolHandler.<anonymous> (/private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:308:41)
    at Generator.next (<anonymous>)
    at /private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:8:71
    at new Promise (<anonymous>)
    at __awaiter (/private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:4:12)
    at ProtocolHandler.processError (/private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:306:16)
    at ProtocolHandler.push (/private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:366:22)
    at Parser.parse (/private/tmp/token/node_modules/nats/lib/nats-base-client/parser.js:312:45)
    at ProtocolHandler.<anonymous> (/private/tmp/token/node_modules/nats/lib/nats-base-client/protocol.js:184:45) {
  code: 'AUTHORIZATION_VIOLATION',
  chainedError: undefined
}
connected to 127.0.0.1:4222
hello one
hello two

the server:

❯ nats-server -DV -c server.conf
[98854] 2021/01/26 17:30:27.379014 [INF] Starting nats-server version 2.2.0-beta.50
[98854] 2021/01/26 17:30:27.379138 [DBG] Go build version go1.15.6
[98854] 2021/01/26 17:30:27.379141 [INF] Git commit [not set]
[98854] 2021/01/26 17:30:27.379147 [INF] Using configuration file: server.conf
[98854] 2021/01/26 17:30:27.379172 [DBG] Created system account: "$SYS"
[98854] 2021/01/26 17:30:27.379504 [INF] Server name: NDHFVJRYHPQWDHHPTNTNEAETOFASJEUGK2RCPNHIIHXTYBJ367IZX6CU
[98854] 2021/01/26 17:30:27.379507 [INF] Server node: zZ7OwbSE
[98854] 2021/01/26 17:30:27.379509 [INF] Server ID:   NDHFVJRYHPQWDHHPTNTNEAETOFASJEUGK2RCPNHIIHXTYBJ367IZX6CU
[98854] 2021/01/26 17:30:27.379510 [INF] Server is ready
[98854] 2021/01/26 17:30:27.379764 [INF] Listening for client connections on 0.0.0.0:4222
[98854] 2021/01/26 17:30:27.379771 [DBG] Get non local IPs for "0.0.0.0"
[98854] 2021/01/26 17:30:27.379932 [DBG]   ip=192.168.86.31
[98854] 2021/01/26 17:30:30.346582 [DBG] 127.0.0.1:52984 - cid:2 - Client connection created
[98854] 2021/01/26 17:30:30.346612 [DBG] 127.0.0.1:52985 - cid:3 - Client connection created
[98854] 2021/01/26 17:30:30.350197 [TRC] 127.0.0.1:52984 - cid:2 - <<- [CONNECT {"protocol":1,"version":"2.0.0-216","lang":"nats.js","verbose":false,"pedantic":false,"auth_token":"bad"}]
[98854] 2021/01/26 17:30:30.350381 [ERR] 127.0.0.1:52984 - cid:2 - "v2.0.0-216:nats.js" - authentication error
[98854] 2021/01/26 17:30:30.350386 [TRC] 127.0.0.1:52984 - cid:2 - "v2.0.0-216:nats.js" - ->> [-ERR Authorization Violation]
[98854] 2021/01/26 17:30:30.350414 [DBG] 127.0.0.1:52984 - cid:2 - "v2.0.0-216:nats.js" - Client connection closed: Authentication Failure
[98854] 2021/01/26 17:30:30.350918 [TRC] 127.0.0.1:52985 - cid:3 - <<- [CONNECT {"protocol":1,"version":"2.0.0-216","lang":"nats.js","verbose":false,"pedantic":false,"auth_token":"foo"}]
[98854] 2021/01/26 17:30:30.350953 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- [PING]
[98854] 2021/01/26 17:30:30.350956 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - ->> [PONG]
[98854] 2021/01/26 17:30:30.360078 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- [SUB hello 1]
[98854] 2021/01/26 17:30:30.360099 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- [PUB hello 3]
[98854] 2021/01/26 17:30:30.360106 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- MSG_PAYLOAD: ["one"]
[98854] 2021/01/26 17:30:30.360117 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - ->> [MSG hello 1 3]
[98854] 2021/01/26 17:30:30.360130 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- [PUB hello 3]
[98854] 2021/01/26 17:30:30.360133 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- MSG_PAYLOAD: ["two"]
[98854] 2021/01/26 17:30:30.360136 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - ->> [MSG hello 1 3]
[98854] 2021/01/26 17:30:30.360138 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <<- [PING]
[98854] 2021/01/26 17:30:30.360141 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - ->> [PONG]
[98854] 2021/01/26 17:30:30.361383 [DBG] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - Client connection closed: Client Closed
[98854] 2021/01/26 17:30:30.361407 [TRC] 127.0.0.1:52985 - cid:3 - "v2.0.0-216:nats.js" - <-> [DELSUB 1]
aricart commented 3 years ago

It would be helpful for you to show your server configuration.

roguh commented 3 years ago

I double checked that NATS_AUTH_TOKEN is set to the correct token and it is. It's the same token used successfully by the Python library and standalone executables.

aricart commented 3 years ago

@roguh can you print out the options, and the server config? As you can see it works on the example that I attached - I am testing for a bad token as well as a good one...

aricart commented 3 years ago

Also notice that I specified on the server the -DV flags so you can see the client interaction.

roguh commented 3 years ago

Yes. I will try running my servers with -DV.

roguh commented 3 years ago

My code doesn't throw AUTHORIZATION_VIOLATION though. Previously, on ts-nats, it would throw a timeout error AFTER a successful call to connect. I can't replicate this on nats@beta

roguh commented 3 years ago

the config for all 3 servers:

 nats.conf: |
    pid_file: "/var/run/nats/nats.pid"
    http: 8222
    cluster {
      port: 6222
      # Use explicit static routes to avoid intermittent DNS issues
      # that could cause partitions via gossip while bootstrapping.
      routes [
        nats://$LEAFNODE_TOKEN@nats-cloud-0.nats-cloud:6222
        nats://$LEAFNODE_TOKEN@nats-cloud-1.nats-cloud:6222
        nats://$LEAFNODE_TOKEN@nats-cloud-2.nats-cloud:6222
      ]
      cluster_advertise: $CLUSTER_ADVERTISE
      connect_retries: 60
    }
    leafnodes {
      port: 7422
    }
    authorization {
      token: $LEAFNODE_TOKEN
    }
aricart commented 3 years ago

so $LEAFNODE_TOKEN and $NATS_AUTH_TOKEN have the same values?

roguh commented 3 years ago

Yes. I just checked

aricart commented 3 years ago

Can you run my sample?

roguh commented 3 years ago

Your sample runs fine.

I caught the problem! I didn't use {callback: ...}

roguh commented 3 years ago

I'm not sure why ts-nats was giving us a timeout error and no responses to our subscription.

roguh commented 3 years ago

Thank you very much for your help! Sorry I didn't catch such a simple mistake

roguh commented 3 years ago

We're actually still having trouble. I got our tests working locally with docker compose but when we run our service in the cloud, we get a TIMEOUT error on connect. We tested our NATS server with the go utilities nats-sub and nats-sub, and with Python. What can cause this error?

roguh commented 3 years ago

I'm trying to get a stack trace for you

aricart commented 3 years ago

usually, the timeout is related to the handshake between the nats client and the server

aricart commented 3 years ago

what version are you using?

roguh commented 3 years ago

We're using nats@beta with server version nats:2.1.8 on alpine3.11

roguh commented 3 years ago

Is there a verbose mode for the library?

roguh commented 3 years ago

Here is a stack trace:

NatsError: TIMEOUT
    at Function.errorForCode (/usr/src/app/node_modules/nats/lib/nats-base-client/error.js:86:16)
    at Timeout.<anonymous> (/usr/src/app/node_modules/nats/lib/nats-base-client/util.js:118:38)
    at listOnTimeout (internal/timers.js:554:17)
    at processTimers (internal/timers.js:497:7) {