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

properly set thread name in thread context #10269

Merged
merged 1 commit into from
Jan 10, 2019

Conversation

colinsurprenant
Copy link
Contributor

@guyboertje recently ran through me a bug he discovered in the workers thread naming which was introduced in #9973. I decided to submit this PR because I'd like to get this fix in before I go ahead and rebase and make progress with #9991.

The problem is that the call to Util.set_thread_name was made outside the newly created thread context and the Util.set_thread_name method set the passed name to the current thread context.

The problem is that none of the worker threads were given a name and the pipeline thread name was set to the last worker thread name.

This problem was present on both Ruby and Java pipelines and for both cases using the hot thread API to gather the thread names this is the before/after:

curl -XGET 'localhost:9600/_node/hot_threads?human=true&ignore_idle_threads=false&threads=100' | grep "thread name:"

Before

Note the single [main]>worker7 thread (which is in fact the pipeline-manager thread) and the many Ruby-0-Thread-X threads:

118.77 % of cpu usage, state: timed_waiting, thread name: 'LogStash::Runner', thread id: 1
4.79 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-8', thread id: 24
2.07 % of cpu usage, state: timed_waiting, thread name: 'Api Webserver', thread id: 32
0.98 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-1', thread id: 16
0.88 % of cpu usage, state: timed_waiting, thread name: 'pool-3-thread-1', thread id: 18
0.77 % of cpu usage, state: timed_waiting, thread name: '[main]>worker7', thread id: 19
0.42 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-7', thread id: 23
0.42 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-10', thread id: 26
0.41 % of cpu usage, state: timed_waiting, thread name: 'pool-4-thread-1', thread id: 15
0.37 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-6', thread id: 22
0.35 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-11', thread id: 27
0.35 % of cpu usage, state: waiting, thread name: 'Finalizer', thread id: 3
0.34 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-4', thread id: 20
0.32 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-9', thread id: 25
0.31 % of cpu usage, state: waiting, thread name: 'Reference Handler', thread id: 2
0.31 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-5', thread id: 21
0.31 % of cpu usage, state: runnable, thread name: 'Ruby-0-Thread-17', thread id: 36
0.21 % of cpu usage, state: runnable, thread name: '[main]<stdin', thread id: 30
0.14 % of cpu usage, state: runnable, thread name: 'Ruby-0-Thread-14', thread id: 33
0.14 % of cpu usage, state: timed_waiting, thread name: 'pool-3-thread-2', thread id: 28
0.09 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-15', thread id: 34
0.07 % of cpu usage, state: timed_waiting, thread name: 'pool-3-thread-3', thread id: 29
0.05 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-16', thread id: 35
0.0 % of cpu usage, state: timed_waiting, thread name: 'logstash-pipeline-flush', thread id: 31
0.0 % of cpu usage, state: runnable, thread name: 'Signal Dispatcher', thread id: 5

After

Note all the proper [main]>workerX threads and the [main]-pipeline-manager thread:

92.38 % of cpu usage, state: timed_waiting, thread name: 'LogStash::Runner', thread id: 1
3.84 % of cpu usage, state: timed_waiting, thread name: '[main]>worker1', thread id: 20
1.64 % of cpu usage, state: timed_waiting, thread name: 'Api Webserver', thread id: 30
0.79 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-1', thread id: 16
0.67 % of cpu usage, state: timed_waiting, thread name: 'pool-3-thread-1', thread id: 29
0.56 % of cpu usage, state: timed_waiting, thread name: '[main]-pipeline-manager', thread id: 18
0.41 % of cpu usage, state: timed_waiting, thread name: '[main]>worker3', thread id: 22
0.37 % of cpu usage, state: timed_waiting, thread name: '[main]>worker4', thread id: 23
0.35 % of cpu usage, state: timed_waiting, thread name: '[main]>worker6', thread id: 25
0.34 % of cpu usage, state: timed_waiting, thread name: '[main]>worker2', thread id: 21
0.34 % of cpu usage, state: timed_waiting, thread name: 'pool-4-thread-1', thread id: 15
0.31 % of cpu usage, state: timed_waiting, thread name: '[main]>worker7', thread id: 26
0.31 % of cpu usage, state: timed_waiting, thread name: '[main]>worker0', thread id: 19
0.3 % of cpu usage, state: timed_waiting, thread name: '[main]>worker5', thread id: 24
0.28 % of cpu usage, state: waiting, thread name: 'Finalizer', thread id: 3
0.26 % of cpu usage, state: waiting, thread name: 'Reference Handler', thread id: 2
0.24 % of cpu usage, state: runnable, thread name: 'Ruby-0-Thread-17', thread id: 36
0.16 % of cpu usage, state: runnable, thread name: '[main]<stdin', thread id: 27
0.11 % of cpu usage, state: runnable, thread name: 'Ruby-0-Thread-14', thread id: 33
0.11 % of cpu usage, state: timed_waiting, thread name: 'pool-3-thread-3', thread id: 32
0.06 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-15', thread id: 34
0.03 % of cpu usage, state: timed_waiting, thread name: 'Ruby-0-Thread-16', thread id: 35
0.03 % of cpu usage, state: timed_waiting, thread name: 'pool-3-thread-2', thread id: 31
0.0 % of cpu usage, state: timed_waiting, thread name: 'logstash-pipeline-flush', thread id: 28
0.0 % of cpu usage, state: runnable, thread name: 'Signal Dispatcher', thread id: 5

@elasticsearch-bot elasticsearch-bot self-assigned this Jan 9, 2019
Copy link
Contributor

@danhermann danhermann left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM pending green CI

@colinsurprenant
Copy link
Contributor Author

Great, thanks @danhermann - looking at backports.

@colinsurprenant
Copy link
Contributor Author

backported in 6.4, 6.5, 6.6 and 6.x

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

Successfully merging this pull request may close these issues.

3 participants