Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

serf id should be the different when restart #1739

Closed
WALL-E opened this issue Oct 12, 2016 · 14 comments
Closed

serf id should be the different when restart #1739

WALL-E opened this issue Oct 12, 2016 · 14 comments
Labels

Comments

@WALL-E
Copy link
Contributor

WALL-E commented Oct 12, 2016

Summary

Follow code logic, serf id should be the different when restart, but my test results do not meet expectations

@/kong/cmd/utils/prefix_handler.lua
...
  log.verbose("saving serf identifier to %s", kong_config.serf_node_id)
  if not pl_path.exists(kong_config.serf_node_id) then
    local id = utils.get_hostname().."_"..kong_config.cluster_listen.."_"..utils.random_string()
    pl_file.write(kong_config.serf_node_id, id)
  end
...

@/kong/tools/utils.lua
--- Generates a random unique string
-- @return string  The random string (a uuid without hyphens)
function _M.random_string()
  return v4_uuid():gsub("-", "")
end

Steps To Reproduce

  1. kong start

    cat /usr/local/kong/serf/serf.id
    vagrant-101_172.28.32.101:7946_465a78ad93cc432ea8369824d49506d6

  2. kong stop

  3. rm -f /usr/local/kong/serf/serf.id

  4. kong start

    cat /usr/local/kong/serf/serf.id
    vagrant-101_172.28.32.101:7946_465a78ad93cc432ea8369824d49506d6

Additional Details & Logs

  • Kong version (0.9.3)
  • Kong debug-level startup logs
2016/10/12 04:22:09 [verbose] Kong: 0.9.3
2016/10/12 04:22:09 [debug] ngx_lua: 10005
2016/10/12 04:22:09 [debug] nginx: 1009015
2016/10/12 04:22:09 [debug] Lua: LuaJIT 2.1.0-beta2
2016/10/12 04:22:09 [verbose] reading config file at /etc/kong/kong.conf
2016/10/12 04:22:09 [debug] admin_listen = "0.0.0.0:8001"
2016/10/12 04:22:09 [debug] anonymous_reports = true
2016/10/12 04:22:09 [debug] cassandra_consistency = "ONE"
2016/10/12 04:22:09 [debug] cassandra_contact_points = {"172.28.32.102"}
2016/10/12 04:22:09 [debug] cassandra_data_centers = {"dc1:2","dc2:3"}
2016/10/12 04:22:09 [debug] cassandra_keyspace = "kong"
2016/10/12 04:22:09 [debug] cassandra_port = 9042
2016/10/12 04:22:09 [debug] cassandra_repl_factor = 1
2016/10/12 04:22:09 [debug] cassandra_repl_strategy = "SimpleStrategy"
2016/10/12 04:22:09 [debug] cassandra_ssl = false
2016/10/12 04:22:09 [debug] cassandra_ssl_verify = false
2016/10/12 04:22:09 [debug] cassandra_timeout = 5000
2016/10/12 04:22:09 [debug] cassandra_username = "kong"
2016/10/12 04:22:09 [debug] cluster_listen = "172.28.32.101:7946"
2016/10/12 04:22:09 [debug] cluster_listen_rpc = "127.0.0.1:7373"
2016/10/12 04:22:09 [debug] cluster_profile = "lan"
2016/10/12 04:22:09 [debug] cluster_ttl_on_failure = 3600
2016/10/12 04:22:09 [debug] custom_plugins = {"influxdb-log"}
2016/10/12 04:22:09 [debug] database = "cassandra"
2016/10/12 04:22:09 [debug] dnsmasq = true
2016/10/12 04:22:09 [debug] dnsmasq_port = 8053
2016/10/12 04:22:09 [debug] log_level = "debug"
2016/10/12 04:22:09 [debug] lua_code_cache = "on"
2016/10/12 04:22:09 [debug] lua_package_cpath = ""
2016/10/12 04:22:09 [debug] lua_package_path = "?/init.lua;./kong/?.lua"
2016/10/12 04:22:09 [debug] lua_ssl_verify_depth = 1
2016/10/12 04:22:09 [debug] mem_cache_size = "128m"
2016/10/12 04:22:09 [debug] nginx_daemon = "on"
2016/10/12 04:22:09 [debug] nginx_optimizations = true
2016/10/12 04:22:09 [debug] nginx_worker_processes = "auto"
2016/10/12 04:22:09 [debug] pg_database = "kong"
2016/10/12 04:22:09 [debug] pg_host = "127.0.0.1"
2016/10/12 04:22:09 [debug] pg_port = 5432
2016/10/12 04:22:09 [debug] pg_ssl = false
2016/10/12 04:22:09 [debug] pg_ssl_verify = false
2016/10/12 04:22:09 [debug] pg_user = "kong"
2016/10/12 04:22:09 [debug] prefix = "/usr/local/kong/"
2016/10/12 04:22:09 [debug] proxy_listen = "0.0.0.0:8000"
2016/10/12 04:22:09 [debug] proxy_listen_ssl = "0.0.0.0:8443"
2016/10/12 04:22:09 [debug] serf_path = "serf"
2016/10/12 04:22:09 [debug] ssl = true
2016/10/12 04:22:09 [verbose] prefix in use: /usr/local/kong
2016/10/12 04:22:09 [verbose] preparing nginx prefix directory at /usr/local/kong
2016/10/12 04:22:09 [verbose] saving serf identifier to /usr/local/kong/serf/serf.id
2016/10/12 04:22:09 [debug] searching for OpenResty 'resty' executable
2016/10/12 04:22:09 [debug] /usr/local/openresty/bin/resty -V: 'nginx version: openresty/1.9.15.1'
2016/10/12 04:22:09 [debug] found OpenResty 'resty' executable at /usr/local/openresty/bin/resty
2016/10/12 04:22:09 [verbose] saving serf shell script handler to /usr/local/kong/serf/serf_event.sh
2016/10/12 04:22:09 [verbose] SSL enabled, no custom certificate set: using default certificate
2016/10/12 04:22:09 [verbose] default SSL certificate found at /usr/local/kong/ssl/kong-default.crt
2016/10/12 04:22:09 [warn] ulimit is currently set to "1024". For better performance set it to at least "4096" using "ulimit -n"
2016/10/12 04:22:09 [verbose] running datastore migrations
2016/10/12 04:22:10 [verbose] migrations up to date
2016/10/12 04:22:10 [verbose] dnsmasq not running, deleting /usr/local/kong/pids/dnsmasq.pid
2016/10/12 04:22:10 [debug] searching for 'dnsmasq' executable
2016/10/12 04:22:10 [debug] /usr/local/sbin/dnsmasq -v: ''
2016/10/12 04:22:10 [debug] 'dnsmasq' executable not found at /usr/local/sbin/dnsmasq
2016/10/12 04:22:10 [debug] /usr/local/bin/dnsmasq -v: ''
2016/10/12 04:22:10 [debug] 'dnsmasq' executable not found at /usr/local/bin/dnsmasq
2016/10/12 04:22:10 [debug] /usr/sbin/dnsmasq -v: 'Dnsmasq version 2.66  Copyright (c) 2000-2013 Simon Kelley'
2016/10/12 04:22:10 [debug] found 'dnsmasq' executable at /usr/sbin/dnsmasq
2016/10/12 04:22:10 [debug] starting dnsmasq: /usr/sbin/dnsmasq -p 8053 --pid-file=/usr/local/kong/pids/dnsmasq.pid -N -o --listen-address=127.0.0.1
2016/10/12 04:22:10 [verbose] serf agent not running, deleting /usr/local/kong/pids/serf.pid
2016/10/12 04:22:10 [debug] checking 'serf' executable from 'serf_path' config setting
2016/10/12 04:22:10 [debug] serf version: 'Serf v0.7.0'
2016/10/12 04:22:10 [debug] starting serf agent: nohup serf agent -profile 'lan' -rpc-addr '127.0.0.1:7373' -event-handler 'member-join,member-leave,member-failed,member-update,member-reap,user:kong=/usr/local/kong/serf/serf_event.sh' -bind '172.28.32.101:7946' -node 'vagrant-101_172.28.32.101:7946_465a78ad93cc432ea8369824d49506d6' -log-level 'err' > /usr/local/kong/logs/serf.log 2>&1 & echo $! > /usr/local/kong/pids/serf.pid
2016/10/12 04:22:10 [verbose] waiting for serf agent to be running
2016/10/12 04:22:10 [debug] sending signal to pid at: /usr/local/kong/pids/serf.pid
2016/10/12 04:22:10 [debug] kill -0 `cat /usr/local/kong/pids/serf.pid` >/dev/null 2>&1
2016/10/12 04:22:10 [verbose] serf agent started
2016/10/12 04:22:10 [verbose] auto-joining serf cluster
2016/10/12 04:22:10 [verbose] successfully joined cluster at 172.28.32.102:7946
2016/10/12 04:22:10 [verbose] registering serf node in datastore
2016/10/12 04:22:10 [verbose] cluster joined and node registered in datastore
2016/10/12 04:22:10 [debug] searching for OpenResty 'nginx' executable
2016/10/12 04:22:10 [debug] /usr/local/openresty/nginx/sbin/nginx -v: 'nginx version: openresty/1.9.15.1'
2016/10/12 04:22:10 [debug] found OpenResty 'nginx' executable at /usr/local/openresty/nginx/sbin/nginx
2016/10/12 04:22:10 [debug] starting nginx: /usr/local/openresty/nginx/sbin/nginx -p /usr/local/kong -c nginx.conf
2016/10/12 04:22:10 [debug] nginx started
2016/10/12 04:22:10 [info] Kong started
  • Operating System CentOS Linux release 7.2.1511 (Core)
@subnetmarco
Copy link
Member

Same problem as #1623

thibaultcha added a commit that referenced this issue Oct 19, 2016
This changes the seeding technique for LuaJIT's PRNG from using a
combination of `time (s precision) + worker PID` to using OpenSSL's
`RAND_bytes()`.

Reasoning: in modern deployment setups such as application containers
and AWS AMIs (etc...), it is a common practise to deploy from a forked
VM, resulting in high chances of collision for PIDs at a seconds
precision. This could result in duplicated PRNG seeds, which is
ultimately the PRNG used to generate UUIDs in Kong, by the use of
[lua-resty-jit-uuid](https://github.com/thibaultcha/lua-resty-jit-uuid).

Solution: in order to have a higher entropy when seeding LuaJIT's PRNG,
a proposed fix was to use `/dev/urandom`. This implementation however
uses OpenSSL's `RAND_bytes()`, which has the advantage of returning an
error if the entropy is estimated to be too low. However, this won't
cover use cases where the VM has been forked, resulting in multiple VM
clones with a high entropy, but equal to that of the other clones. We
suggest that such deployment environment increase their cloned VMs
entropy before starting Kong.

Full changelog:
* use OpenSSL's `RAND_bytes()` to read random bytes
* truncate the final seed to 12 digits to prevent integer overflows
* update fallback seeding technique (time + worker PID) to use ms
precision, just in case
* introduce a new `kong` lua shared dict. This dictionary's purpose is
to hold essential data through Kong's lifecycle, and should eventually
only be used through `safe_set()` (an abstraction for this could be
envisaged later on, but is not the purpose of this patch)
* chosen seeds for each worker are stored in the kong shm, and can be
consulted via the `/` endpoint. There is currently no way to re-seed all
the workers at once unless by sending `SIGHUP`, because only 1 worker
would be receiving such a request through the Kong Admin API.
* update `debug.traceback()` calls to use lvl 2 of the call stack, to
show the actual caller of our patched `math.randomseed()`
* update log messages to be more explicit

Fix #1751 #1739 #1623
@thibaultcha
Copy link
Member

@WALL-E ,

I just pushed a hotfix to #1754 which should be applicable to 0.9.x. We really want some feedback on it and making sure it works for other production deployments than the ones its been tested on. Do you think you'd be able to apply the provided patch and see if those go away?

Note: a behavior we saw in a production deployment is that forked VMs provide the same random bytes from /dev/urandom (from which OpenSSL gets its PRNG seed), since their entropy is too similar. We strongly suggest that if this is your case as well, you increase your cloned VMs entropy before starting Kong.

Much appreciated!

@WALL-E
Copy link
Contributor Author

WALL-E commented Oct 20, 2016

I test the patch, it's ok.

  • work environment
    • CentOS+Vagrant+VirtualBox
  • home environment
    • win7+VMware

@WALL-E
Copy link
Contributor Author

WALL-E commented Oct 21, 2016

I review the patch code, I think It may not be related to the problem I found.

@thibaultcha I hope you can give me some tips.

thibaultcha added a commit that referenced this issue Oct 21, 2016
This changes the seeding technique for LuaJIT's PRNG from using a
combination of `time (s precision) + worker PID` to using OpenSSL's
`RAND_bytes()`.

Reasoning: in modern deployment setups such as application containers
and AWS AMIs (etc...), it is a common practise to deploy from a forked
VM, resulting in high chances of collision for PIDs at a seconds
precision. This could result in duplicated PRNG seeds, which is
ultimately the PRNG used to generate UUIDs in Kong, by the use of
[lua-resty-jit-uuid](https://github.com/thibaultcha/lua-resty-jit-uuid).

Solution: in order to have a higher entropy when seeding LuaJIT's PRNG,
a proposed fix was to use `/dev/urandom`. This implementation however
uses OpenSSL's `RAND_bytes()`, which has the advantage of returning an
error if the entropy is estimated to be too low. However, this won't
cover use cases where the VM has been forked, resulting in multiple VM
clones with a high entropy, but equal to that of the other clones. We
suggest that such deployment environment increase their cloned VMs
entropy before starting Kong.

Full changelog:
* use OpenSSL's `RAND_bytes()` to read random bytes
* truncate the final seed to 12 digits to prevent integer overflows
* update fallback seeding technique (time + worker PID) to use ms
precision, just in case
* introduce a new `kong` lua shared dict. This dictionary's purpose is
to hold essential data through Kong's lifecycle, and should eventually
only be used through `safe_set()` (an abstraction for this could be
envisaged later on, but is not the purpose of this patch)
* chosen seeds for each worker are stored in the kong shm, and can be
consulted via the `/` endpoint. There is currently no way to re-seed all
the workers at once unless by sending `SIGHUP`, because only 1 worker
would be receiving such a request through the Kong Admin API.
* update `debug.traceback()` calls to use lvl 2 of the call stack, to
show the actual caller of our patched `math.randomseed()`
* update log messages to be more explicit

Fix #1751 #1739 #1623
@thibaultcha
Copy link
Member

thibaultcha commented Oct 21, 2016

Your issue is that both of your serf ids are identical:

vagrant-101_172.28.32.101:7946_465a78ad93cc432ea8369824d49506d6

Here, the bold part is supposed to distinguish several nodes that would share the same hostname. It is generated there there, using utils.random_string().

utils.random_string() is implemented there, and relies on the UUID module, which itself depends on the LuaJIT PRNG.

The LuaJIT PRNG needs to be seeded, using a unique seed for each and every worker accross your cluster. If 2 seeds are shared by 2 workers, those will eventually generate identical pseudo-random numbers, and thus, identical v4 UUIDs.

The patch helps increasing the entropy for the PRNG seed by relying on OpenSSL's RAND_bytes() instead of a combination of time + workers PIDs.

Now that you have some more context around this issue, if you could describe what behavior you are seeing, that would help, because as of now I do not understand what issues you are facing, or if you are facing any at all.

@thibaultcha
Copy link
Member

If you could also include details on your deployment setup, that would help too.

@WALL-E
Copy link
Contributor Author

WALL-E commented Oct 22, 2016

@thibaultcha

deployment detail

  • Host
    • Win7
  • Virtual machine
    • VMware workstation 12.0.5
  • Guest
    • CentOS Linux release 7.2.1511 (Core)

Reproduce step

  1. yum install kong-0.9.3.el7.noarch.rpm

  2. /etc/kong/kong.conf

    database = cassandra
    
  3. kong start

  4. cat /usr/local/kong/serf/serf.id

    dockerHost-2_0.0.0.0:7946_465a78ad93cc432ea8369824d49506d6
    

issue: random string always is 465a78ad93cc432ea8369824d49506d6, even if I reboot many times and every time I delete the file /usr/local/kong/serf/serf.id.

in addition, centos+vagrant+virtualbox, the same issue will be reproduced, I see 465a78ad93cc432ea8369824d49506d6 too

@WALL-E
Copy link
Contributor Author

WALL-E commented Oct 22, 2016

I got it, the following is the key code in hotfix #1754, about this issue

@kong/cmd/init.lua

require("kong.core.globalpatches")({cli = true})
...
local prng_seed = math.randomseed()
...

kong startup script run in nginx timer phase, but at this time, the function randomseed is not run, so the seed is default value, and random string always is same value, even if I reboot many times

I guess this bug was introduced in version 0.9.0, the feature New CLI.

@thibaultcha
Copy link
Member

the function randomseed is not run

Why is that?

I just added a debug log for the CLI's verbose mode which, if you re-apply the patch, will print the following:

2016/10/23 12:40:01 [debug] ngx_lua: 10005
2016/10/23 12:40:01 [debug] nginx: 1009015
2016/10/23 12:40:01 [debug] Lua: LuaJIT 2.1.0-beta2
2016/10/23 12:40:01 [debug] PRNG seed: 137253133208

The only thing you need to ensure now is that each and every node in your cluster has a unique seed.

@WALL-E
Copy link
Contributor Author

WALL-E commented Oct 23, 2016

May be I did not express clearly. the patch is ok, I have tested it.

I'm just describing the version 0.9.3, the reason for serf-id no change when restart

@thibaultcha
Copy link
Member

Oh ok! Sorry I understood the opposite: that the patch was not working for you.

Ok, I am glad this is confirmed to be working for you too then! Actually the call to math.randomseed comes from #1641, while #1754 is about having a higher entropy for the seed itself.

Very well, this will land in 0.9.4 next week, thanks agin for trying the patch out.

@thibaultcha thibaultcha modified the milestone: 0.10 RC Oct 24, 2016
@WALL-E
Copy link
Contributor Author

WALL-E commented Oct 24, 2016

@thibaultcha Can consider deleting file(/usr/local/kong/serf/serf.id) when kong is restarted

In the following cases, the cluster can start normally, even if vm or image included /usr/local/kong/serf/serf.id

  • forked multiple vm
  • multiple containers use a base image

@thibaultcha
Copy link
Member

I'm not sure how that would play with the Serf-side of things. It could have consequences on the clustering modes and Serf table and all of that... @thefosk?

@subnetmarco
Copy link
Member

I opened #1778 as an attempt to fix this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants