NPM and JSVM, custom basic-auth plugin more details?

41

Ok so as suggested my key is now

var myKey = orgId+myhash(authheader)

This myKey is then set on the x-internal-authorization header and passed to TykSetKeyData(myKey,...) as well as set as the alias for the session. (hash_keys:true is enabled everywhere)

When I go to “Activity by Key” in the dashboard I see the value as expected listed.

3e769148 (5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc)

Where 5976507eb46f2e00016bb4a1 is the orgId and the remainder the concatenation of my hash. I can search in “Activity by Key” w/ value “3e769148” successfully, but the alias yields nothing as confirmed by you guys in another post.

When I go to “System Management -> Key Search” nothing is found by searching on any of these values:

  • 3e769148
  • 5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc
  • 5976507eb46f2e00016bb4a1

All I get when searching on the above values is a dump to “Edit Key” with the error “Key doesn’t seem to exist! Using defaults…”

I really don’t understand the point of setting the alias, or this orgid prefix… perhaps I am missing something.

Its great that I can see stats by the keys in “Activity by Key” but not being able to search on anything meaningful to me makes it a bit useless.

42

Thanks for the feedback, we’ll look into it.

43

When you search for 5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc What do you see in the gateway logs?

The reason I ask is, if the Auth token middleware can validate this key, (it uses the same method to look up the token), then the dashboard should be able to use it too. Since the dashboard uses the gateway to lookup the token data, and the API lookup uses the same method.

IS the dashboard connected to the same gateway and redis DB that you have the middleware running on?

44

The gateway logs screen just says “No gateway logs to display, please wait a few seconds for events to populate.”

The setup was just started w/ this: //tyk.io/docs/tyk-on-premises/docker/

45

Wait, so if you run

docker logs --tail=100 --follow {gateway_container_name}

You don’t get any output at all?

46

Yes if I tail the logs for the gateway container I always get logs, but in the dashboard when I go to the “gateway logs” screen I see nothing there and just the message noted above.

47

Can you share the tail please?

48

here is one request

2017-08-03T21:04:53.518881231Z time="Aug  3 21:04:53" level=info msg="----> Running myAuth JSVM Auth Middleware" type=log-msg
2017-08-03T21:04:53.518948748Z time="Aug  3 21:04:53" level=info msg="config = {\"config_data\":{\"api_id\":\"3b30b68340b8492858ea00be8c9b248e\",\"api_name\":\"/my/auth/authTest/1.0\",\"debug_mode\":\"true\",\"my_auth_host\":\"http://10.23.16.53:9080\",\"org_id\":\"5976507eb46f2e00016bb4a1\",\"protected_system_host\":\"tyk-my-auth\",\"requested_resource_tags\":\"omg-ws-soap-all,#FROM_HEADER\",\"requesting_system\":\"MONKEY\",\"rrt_from_header_name\":\"X-Test-Op-One\",\"rrt_postfix\":\"\",\"rrt_prefix\":\"my-ws-soap-authws-\",\"session_expires_seconds\":\"60\",\"session_key_include_headers\":\"X-Test-Op-One\",\"soap_operation_header_name\":\"X-Test-Op-One\",\"strip_authorization_header\":\"true\",\"strip_soap_op_namespace\":\"true\"}}" type=log-msg
2017-08-03T21:04:53.519429436Z time="Aug  3 21:04:53" level=info msg="request = {\"AddParams\":{},\"Body\":\"\\u003csoapenv:Envelope xmlns:soapenv=\\\"http://schemas.xmlsoap.org/soap/envelope/\\\" xmlns:test=\\\"http://test.bof.com/\\\"\\u003e\\n   \\u003csoapenv:Header/\\u003e\\n   \\u003csoapenv:Body\\u003e\\n      \\u003ctest:getDog/\\u003e\\n   \\u003c/soapenv:Body\\u003e\\n\\u003c/soapenv:Envelope\\u003e\",\"DeleteHeaders\":[],\"DeleteParams\":[],\"ExtendedParams\":{},\"Headers\":{\"Accept-Encoding\":[\"gzip,deflate\"],\"Authorization\":[\"Basic XXXXXXbHZ5LmNvbTpQQHNzdzByZDY=\"],\"Connection\":[\"Keep-Alive\"],\"Content-Length\":[\"240\"],\"Content-Type\":[\"text/xml;charset=UTF-8\"],\"Soapaction\":[\"\\\"\\\"\"],\"User-Agent\":[\"Apache-HttpClient/4.1.1 (java 1.5)\"],\"X-Test-Op-One\":[\"getDog\"]},\"IgnoreBody\":false,\"Params\":{},\"ReturnOverrides\":{\"ResponseCode\":0,\"ResponseError\":\"\"},\"SetHeaders\":{},\"URL\":\"/my/auth/authTest/1.0\"}" type=log-msg
2017-08-03T21:04:53.519769405Z time="Aug  3 21:04:53" level=info msg="session = {\"access_rights\":null,\"alias\":\"\",\"allowance\":0,\"apply_policy_id\":\"\",\"basic_auth_data\":{\"hash_type\":\"\",\"password\":\"\"},\"data_expires\":0,\"enable_detail_recording\":false,\"expires\":0,\"hmac_enabled\":false,\"hmac_string\":\"\",\"id_extractor_deadline\":0,\"is_inactive\":false,\"jwt_data\":{\"secret\":\"\"},\"last_check\":0,\"last_updated\":\"\",\"meta_data\":null,\"monitor\":{\"trigger_limits\":null},\"oauth_client_id\":\"\",\"oauth_keys\":null,\"org_id\":\"\",\"per\":0,\"quota_max\":0,\"quota_remaining\":0,\"quota_renewal_rate\":0,\"quota_renews\":0,\"rate\":0,\"session_lifetime\":0,\"tags\":null}" type=log-msg
2017-08-03T21:04:53.519792668Z time="Aug  3 21:04:53" level=info msg="pre-hash clearSessionKey: /my/auth/authTest/1.0-gettest-XXXXXXbHZ5LmNvbTpQQHNzdzByZDY=" type=log-msg
2017-08-03T21:04:53.540717787Z time="Aug  3 21:04:53" level=info msg="rawAuthorization = Basic XXXXXXbHZ5LmNvbTpQQHNzdzByZDY=" type=log-msg
2017-08-03T21:04:53.540767632Z time="Aug  3 21:04:53" level=info msg="hashedSessionKey = 5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc" type=log-msg
2017-08-03T21:04:53.541301928Z time="Aug  3 21:04:53" level=info msg="Retrieved key detail." key="****56bc" status=ok
2017-08-03T21:04:53.541785833Z time="Aug  3 21:04:53" level=info msg="tykSession = {\"access_rights\":{\"3b30b68340b8492858ea00be8c9b248e\":{\"allowed_urls\":null,\"api_id\":\"3b30b68340b8492858ea00be8c9b248e\",\"api_name\":\"/my/auth/authTest/1.0\",\"versions\":[\"Default\"]}},\"alias\":\"5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc\",\"allowance\":0,\"apply_policy_id\":\"\",\"basic_auth_data\":{\"hash_type\":\"\",\"password\":\"\"},\"data_expires\":0,\"enable_detail_recording\":false,\"expires\":1501794345,\"hmac_enabled\":false,\"hmac_string\":\"\",\"id_extractor_deadline\":0,\"is_inactive\":false,\"jwt_data\":{\"secret\":\"\"},\"last_check\":0,\"last_updated\":\"1501794286\",\"meta_data\":null,\"monitor\":{\"trigger_limits\":null},\"oauth_client_id\":\"\",\"oauth_keys\":null,\"org_id\":\"\",\"per\":0,\"quota_max\":1000,\"quota_remaining\":999,\"quota_renewal_rate\":60,\"quota_renews\":1501794346,\"rate\":0,\"session_lifetime\":0,\"tags\":null}" type=log-msg
2017-08-03T21:04:53.541822513Z time="Aug  3 21:04:53" level=info msg="Pre-existing session exists... using, no MY auth check, curr_epoch: 1501794294 session.expires: 1501794345" type=log-msg

And another, that re-establishes the session/saves again after expiry

2017-08-03T21:09:01.798914202Z time="Aug  3 21:09:01" level=info msg="----> Running myAuth JSVM Auth Middleware" type=log-msg
2017-08-03T21:09:01.799155892Z time="Aug  3 21:09:01" level=info msg="config = {\"config_data\":{\"api_id\":\"3b30b68340b8492858ea00be8c9b248e\",\"api_name\":\"/my/nof/nofExt/1.0\",\"debug_mode\":\"true\",\"my_nof_host\":\"http://10.23.16.53:9080\",\"org_id\":\"5976507eb46f2e00016bb4a1\",\"protected_system_host\":\"tyk-my-nof\",\"requested_resource_tags\":\"omg-ws-xxxxx-all,#FROM_HEADER\",\"requesting_system\":\"MONKEY\",\"rrt_from_header_name\":\"X-My-Test\",\"rrt_postfix\":\"\",\"rrt_prefix\":\"my-ws-xxxxx-nofws-\",\"session_expires_seconds\":\"60\",\"session_key_include_headers\":\"X-My-Test\",\"xxxxx_operation_header_name\":\"X-My-Test\",\"strip_noforization_header\":\"true\",\"strip_xxxxx_op_namespace\":\"true\"}}" type=log-msg
2017-08-03T21:09:01.799192107Z time="Aug  3 21:09:01" level=info msg="request = {\"AddParams\":{},\"Body\":\"\\u003cxxxxxenv:Envelope xmlns:xxxxxenv=\\\"http://schemas.xmlxxxxx.org/xxxxx/envelope/\\\" xmlns:test=\\\"http://XXXX.nof.services.test.com/\\\"\\u003e\\n   \\u003cxxxxxenv:Header/\\u003e\\n   \\u003cxxxxxenv:Body\\u003e\\n      \\u003ctest:getTest/\\u003e\\n   \\u003c/xxxxxenv:Body\\u003e\\n\\u003c/xxxxxenv:Envelope\\u003e\",\"DeleteHeaders\":[],\"DeleteParams\":[],\"ExtendedParams\":{},\"Headers\":{\"Accept-Encoding\":[\"gzip,deflate\"],\"Authorization\":[\"Basic XXXXXXXLmNvbTpQQHNzdzByZDY=\"],\"Connection\":[\"Keep-Alive\"],\"Content-Length\":[\"240\"],\"Content-Type\":[\"text/xml;charset=UTF-8\"],\"Soapaction\":[\"\\\"\\\"\"],\"User-Agent\":[\"Apache-HttpClient/4.1.1 (java 1.5)\"],\"X-My-Test\":[\"getTest\"]},\"IgnoreBody\":false,\"Params\":{},\"ReturnOverrides\":{\"ResponseCode\":0,\"ResponseError\":\"\"},\"SetHeaders\":{},\"URL\":\"/my/nof/nofExt/1.0\"}" type=log-msg
2017-08-03T21:09:01.799522511Z time="Aug  3 21:09:01" level=info msg="session = {\"access_rights\":null,\"alias\":\"\",\"allowance\":0,\"apply_policy_id\":\"\",\"basic_nof_data\":{\"hash_type\":\"\",\"password\":\"\"},\"data_expires\":0,\"enable_detail_recording\":false,\"expires\":0,\"hmac_enabled\":false,\"hmac_string\":\"\",\"id_extractor_deadline\":0,\"is_inactive\":false,\"jwt_data\":{\"secret\":\"\"},\"last_check\":0,\"last_updated\":\"\",\"meta_data\":null,\"monitor\":{\"trigger_limits\":null},\"onof_client_id\":\"\",\"onof_keys\":null,\"org_id\":\"\",\"per\":0,\"quota_max\":0,\"quota_remaining\":0,\"quota_renewal_rate\":0,\"quota_renews\":0,\"rate\":0,\"session_lifetime\":0,\"tags\":null}" type=log-msg
2017-08-03T21:09:01.799584720Z time="Aug  3 21:09:01" level=info msg="pre-hash clearSessionKey: /my/nof/nofExt/1.0-getsystemstatus-XXXXXXXLmNvbTpQQHNzdzByZDY=" type=log-msg
2017-08-03T21:09:01.820105296Z time="Aug  3 21:09:01" level=info msg="rawAuthorization = Basic XXXXXXXLmNvbTpQQHNzdzByZDY=" type=log-msg
2017-08-03T21:09:01.820199133Z time="Aug  3 21:09:01" level=info msg="hashedSessionKey = 5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc" type=log-msg
2017-08-03T21:09:01.820693286Z time="Aug  3 21:09:01" level=info msg="Retrieved key detail." key="****56bc" status=ok
2017-08-03T21:09:01.820997183Z time="Aug  3 21:09:01" level=info msg="tykSession = {\"access_rights\":{\"3b30b68340b8492858ea00be8c9b248e\":{\"allowed_urls\":null,\"api_id\":\"3b30b68340b8492858ea00be8c9b248e\",\"api_name\":\"/my/nof/nofExt/1.0\",\"versions\":[\"Default\"]}},\"alias\":\"5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc\",\"allowance\":0,\"apply_policy_id\":\"\",\"basic_nof_data\":{\"hash_type\":\"\",\"password\":\"\"},\"data_expires\":0,\"enable_detail_recording\":false,\"expires\":1501794345,\"hmac_enabled\":false,\"hmac_string\":\"\",\"id_extractor_deadline\":0,\"is_inactive\":false,\"jwt_data\":{\"secret\":\"\"},\"last_check\":0,\"last_updated\":\"1501794286\",\"meta_data\":null,\"monitor\":{\"trigger_limits\":null},\"onof_client_id\":\"\",\"onof_keys\":null,\"org_id\":\"\",\"per\":0,\"quota_max\":1000,\"quota_remaining\":998,\"quota_renewal_rate\":60,\"quota_renews\":1501794346,\"rate\":0,\"session_lifetime\":0,\"tags\":null}" type=log-msg
2017-08-03T21:09:01.821170708Z time="Aug  3 21:09:01" level=info msg="Succesfully extracted from HTTP header 'rrt_from_header_name':X-My-Test, formulated new requestedResourceTag: my-ws-xxxxx-nofws-getTest" type=log-msg
2017-08-03T21:09:01.821237370Z time="Aug  3 21:09:01" level=info msg="session.status=undefined curr_epoch: 1501794542 session.expires: 1501794345, attempting nof against: http://10.23.16.53:9080 as: MONKEY for: omg-ws-xxxxx-all,my-ws-xxxxx-nofws-getTest" type=log-msg
2017-08-03T21:09:03.651459816Z time="Aug  3 21:09:03" level=info msg="raw MY nof response: {\"Code\":200,\"Body\":\"\",\"Headers\":{\"Cache-Control\":[\"no-cache, no-store, max-age=0, must-revalidate\"],\"Content-Length\":[\"0\"],\"Date\":[\"Thu, 03 Aug 2017 21:09:03 GMT\"],\"Expires\":[\"0\"],\"Pragma\":[\"no-cache\"],\"Server\":[\"Apache-Coyote/1.1\"],\"X-Content-Type-Options\":[\"nosniff\"],\"X-Frame-Options\":[\"DENY\"],\"X-Xss-Protection\":[\"1; mode=block\"]}}" type=log-msg
2017-08-03T21:09:03.651574004Z time="Aug  3 21:09:03" level=info msg="curr_epoch=1501794542 new session expires_at:1501794602" type=log-msg
2017-08-03T21:09:03.651591566Z time="Aug  3 21:09:03" level=info msg="new session object = {\"access_rights\":{\"3b30b68340b8492858ea00be8c9b248e\":{\"allowed_urls\":null,\"api_id\":\"3b30b68340b8492858ea00be8c9b248e\",\"api_name\":\"/my/nof/nofExt/1.0\",\"versions\":[\"Default\"]}},\"alias\":\"5976507eb46f2e00016bb4a13a4e7ca913238ee243102a32d27e56bc\",\"expires\":1501794602,\"quota_max\":1000,\"quota_remaining\":1000,\"quota_renewal_rate\":60}" type=log-msg
2017-08-03T21:09:03.651610904Z time="Aug  3 21:09:03" level=info msg="Reset quota for key." inbound-key="****56bc" key=quota-3e769148
2017-08-03T21:09:03.651619776Z time="Aug  3 21:09:03" level=info msg="Key added or updated." api_id=-- expires=1501794602 key="****56bc" org_id= path=-- server_name=system user_id=system user_ip=--
49

Ok, so now what do the gateway logs say when you run the search in the dashboard - that’s what we’re looking for.

50

again, I go here http://localhost:3000/#/realtime-logs/

and all that it says is “No gateway logs to display, please wait a few seconds for events to populate.”

While reloading that page there is nothing in the gateway log that I am tailing in the terminal…

Under “System Management - Keys” Search

  • 3e769148 = console → “2017-08-03T21:15:39.014543019Z time=“Aug 3 21:15:39” level=warning msg=“Failed to retrieve key detail.” err=“not found” key=”****9148" status=fail"… the UI says “Key doesn’t seem to exist! Using defaults…” on the edit key screen

  • 5976507eb46f2e00016bb4a13a4… = console → “2017-08-03T21:16:48.168796158Z time=“Aug 3 21:16:48” level=info msg=“Retrieved key detail.” key=”****56bc" status=ok"… the UI says “Key doesn’t seem to exist! Using defaults…” on the edit key screen

“Activity by Key” screen shows “3e769148 (5976507eb46f2e00016bb4a13a4…)”

51

Excellent! Here we establish that the key is in redis and that it is being queried properly by the gateway on behalf of the dashboard.

Now, let’s look at the logs from the dashboard container, is there a corresponding error?

I reckon there’s something missing in the session object and the dashboard is blocking it because it suspects a cross-tenant keycheck.

52

Searching for “3e769148”

2017-08-03T21:22:45.951312194Z time=“Aug 3 21:22:45” level=error msg=“API Request failed!”
2017-08-03T21:22:45.951423216Z {“status”:“error”,“message”:“Key not found”}
2017-08-03T21:22:45.951510996Z time=“Aug 3 21:22:45” level=error msg="45 "
2017-08-03T21:22:45.951864179Z time=“Aug 3 21:22:45” level=error msg=“Key detail request failed”
2017-08-03T21:22:45.951898803Z time=“Aug 3 21:22:45” level=warning msg=“Key retrieval failed”
2017-08-03T21:22:45.951947844Z time=“Aug 3 21:22:45” level=error msg=“Attempted access to non-owned key”

Searching for “5976507eb46f2e00016bb4a13a4…”

2017-08-03T21:23:37.568756479Z time=“Aug 3 21:23:37” level=warning msg=“Org ID did not match”
2017-08-03T21:23:37.569718213Z time=“Aug 3 21:23:37” level=error msg=“Attempted access to non-owned key”

ORG id = 5976507eb46f2e00016bb4a1

53

There you have it - the org ID set in the session object so not match the org ID of the user doing the lookup. You need to allign the org IDs in your apindefinition, session object and dashboard user. It’s likely not even set in the session object.

54

ok, I added “org_id” to the top level of the session and now its searchable in the “System Management” Keys section

  • searching on the alias “5976507eb46f2e00016bb4a13a4…” works

  • but the Tyk hashed key (3e769148) the above is the alias is for… is not

55

You search for the raw key, it’s a one way hash search, so you can’t search for the hash itself. Otherwise it would be pointless to hash in the first place.

56

Ok so HASHED keys are searchable via “Activity By Key” but not clear keys

But the reverse for System Management Keys (search by pre-hashed key, not hashed key)…

57

This doesn’t affect security

This directly affects user access.