Details
-
Bug
-
Resolution: Fixed
-
Test Blocker
-
7.6.0, 7.2.1
-
Untriaged
-
0
-
Yes
Description
Ns_server node addition tests are affected by a strange issue where memcached doesn't always stop. At least it looks like so in logs. Please help with investigation.
This test run failed when node 3 was trying to add node 4 to the cluster. Node began to join, and were shutting down all the ports but it the whole process timed out because it seems like memcached process never stopped.
In logs (that are attached: test_cluster_data-3.zip ) in babysitter on node4 I see that it tries to stop memcached:
[ns_server:info,2023-09-11T18:22:47.646Z,babysitter_of_n_4@cb.local:ns_ports_manager<0.138.0>:ns_child_ports_sup:terminate_port:95]unsupervising port: {memcached,"/home/couchbase/jenkins/workspace/ns-serve
|
["-C",
|
"/home/couchbase/jenkins/workspace/ns-server-cluster-tests/ns_server/cluster_tests/test_cluster_data-3/data/n_4/config/memcached.json"],
|
[{env,[{"EVENT_NOSELECT","1"},
|
{"CBSASL_PWFILE",
|
"/home/couchbase/jenkins/workspace/ns-server-cluster-tests/ns_server/cluster_tests/test_cluster_data-3/data/n_4/isasl.pw"}]},
|
use_stdio,stderr_to_stdout,exit_status,
|
port_server_dont_start,stream]}
|
[ns_server:debug,2023-09-11T18:22:47.646Z,babysitter_of_n_4@cb.local:<0.143.0>:ns_port_server:terminate:198]Shutting down port memcached
|
[ns_server:debug,2023-09-11T18:22:47.646Z,babysitter_of_n_4@cb.local:<0.143.0>:ns_port_server:port_shutdown:335]Shutdown command: "shutdown"
|
[ns_server:info,2023-09-11T18:22:47.847Z,babysitter_of_n_4@cb.local:<0.143.0>:ns_port_server:log:226]memcached<0.143.0>: EOL on stdin. Initiating shutdown
|
<nothing happens>
|
[ns_server:debug,2023-09-11T18:23:56.446Z,babysitter_of_n_4@cb.local:<0.9.0>:child_erlang:child_loop:151]124808: Got EOL <-- the test times out and tries to stop the node
|
memcached logs at node 4 look like the following:
2023-09-11T18:22:47.631855+00:00 INFO Shutting down Prometheus exporter: {"family":"inet","host":"127.0.0.1","port":11980,"type":"prometheus","uuid":"456971a2-e224-4643-919b-294bfbebb9ba"}
|
2023-09-11T18:22:47.646498+00:00 INFO Gracefully shutting down due to shutdown message or stdin closure
|
2023-09-11T18:22:47.833449+00:00 INFO Initiating graceful shutdown. sigint:false sigterm:false
|
2023-09-11T18:22:47.833459+00:00 INFO Stop all buckets
|
2023-09-11T18:22:47.833463+00:00 INFO Shutting down client worker threads
|
2023-09-11T18:22:47.833515+00:00 INFO Stopping worker thread 0
|
2023-09-11T18:22:47.833520+00:00 INFO Stopping worker thread 1
|
2023-09-11T18:22:47.833553+00:00 INFO Stopping worker thread 3
|
2023-09-11T18:22:47.833561+00:00 INFO Stopping worker thread 6
|
2023-09-11T18:22:47.833590+00:00 INFO Stopping worker thread 2
|
2023-09-11T18:22:47.833675+00:00 INFO Stopping worker thread 12
|
2023-09-11T18:22:47.833742+00:00 INFO Stopping worker thread 4
|
2023-09-11T18:22:47.833836+00:00 INFO Stopping worker thread 11
|
2023-09-11T18:22:47.833961+00:00 INFO Stopping worker thread 5
|
2023-09-11T18:22:47.834136+00:00 INFO Stopping worker thread 7
|
2023-09-11T18:22:47.834487+00:00 INFO Stopping worker thread 8
|
2023-09-11T18:22:47.834837+00:00 INFO Stopping worker thread 9
|
2023-09-11T18:22:47.835172+00:00 INFO Stopping worker thread 10
|
While when I run it locally I see more "shutdown" logs in memcached.log:
2023-09-11T17:15:26.516826-07:00 INFO Shutting down Prometheus exporter: {"family":"inet","host":"127.0.0.1","port":11992,"type":"prometheus","uuid":"ad0c437d-53c9-4bb4-82c9-b63772dda10f"}
|
2023-09-11T17:15:26.618455-07:00 INFO Shutting down client worker threads
|
2023-09-11T17:15:26.618491-07:00 INFO Stopping worker thread 0
|
2023-09-11T17:15:26.618492-07:00 INFO Stopping worker thread 2
|
2023-09-11T17:15:26.618513-07:00 INFO Stopping worker thread 1
|
2023-09-11T17:15:26.618537-07:00 INFO Stopping worker thread 4
|
2023-09-11T17:15:26.618552-07:00 INFO Stopping worker thread 5
|
2023-09-11T17:15:26.618587-07:00 INFO Stopping worker thread 6
|
2023-09-11T17:15:26.618588-07:00 INFO Stopping worker thread 7
|
2023-09-11T17:15:26.618592-07:00 INFO Stopping worker thread 8
|
2023-09-11T17:15:26.618606-07:00 INFO Stopping worker thread 9
|
2023-09-11T17:15:26.618751-07:00 INFO Stopping worker thread 3
|
2023-09-11T17:15:26.619237-07:00 INFO Releasing server sockets
|
2023-09-11T17:15:26.619303-07:00 INFO Shutting down IPv6 interface: [::]:11993
|
2023-09-11T17:15:26.619336-07:00 INFO Shutting down IPv6 interface: [::]:11994
|
2023-09-11T17:15:26.619354-07:00 INFO Shutting down IPv6 interface: [::]:11995
|
2023-09-11T17:15:26.619364-07:00 INFO Shutting down IPv6 interface: [::]:12002
|
2023-09-11T17:15:26.619376-07:00 INFO Shutting down IPv4 interface: 0.0.0.0:11993
|
2023-09-11T17:15:26.619389-07:00 INFO Shutting down IPv4 interface: 0.0.0.0:11994
|
2023-09-11T17:15:26.619401-07:00 INFO Shutting down IPv4 interface: 0.0.0.0:11995
|
2023-09-11T17:15:26.619409-07:00 INFO Shutting down IPv4 interface: 0.0.0.0:12002
|
2023-09-11T17:15:26.619420-07:00 INFO Releasing bucket resources
|
2023-09-11T17:15:26.619443-07:00 INFO Shutting down RBAC subsystem
|
2023-09-11T17:15:26.619450-07:00 INFO Shutting down executor pool
|
2023-09-11T17:15:26.620876-07:00 INFO Releasing signal handlers
|
2023-09-11T17:15:26.620886-07:00 INFO Shutting down external authentication service
|
2023-09-11T17:15:26.620967-07:00 INFO Shutting down SASL server
|
2023-09-11T17:15:26.620971-07:00 INFO Deinitialising tracing
|
2023-09-11T17:15:26.620974-07:00 INFO Shutting down all engines
|
2023-09-11T17:15:26.621097-07:00 INFO Shutting down audit daemon
|
2023-09-11T17:15:26.621229-07:00 INFO Removing breakpad
|
2023-09-11T17:15:26.621234-07:00 INFO Shutting down event base
|
2023-09-11T17:15:26.621254-07:00 INFO Shutting down logger extension
|
2023-09-11T17:15:26.621397-07:00 INFO ---------- Closing logfile
|
Is it possible that memcached is hanging?
Attachments
Issue Links
- is duplicated by
-
MB-59567 [ipv6] All requests to ipv6 node returns status code 500 reason:"Unexpected server error, request logged."
- Closed