[jira] [Commented] (TS-3430) why cpu 100% on a occasion?
[
https://issues.apache.org/jira/browse/TS-3430?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14497505#comment-14497505
]
Bryan Call commented on TS-3430:
We are seeing a similar issue in production when we are putting a lot of
traffic on a server:
{code}
Samples: 1M of event 'cycles', Event count (approx.): 270418638057
22.50% [kernel] [k] established_get_next
9.14% libcrypto.so.1.0.0 [.] bn_mul_mont
7.99% [kernel] [k] _spin_lock_bh
6.74% [kernel] [k] _spin_lock
2.06% [kernel] [k] listening_get_next
2.00% [kernel] [k] _spin_unlock_bh
1.48% [kernel] [k] __write_lock_failed
1.42% traffic_server [.] LogObject::_checkout_write(unsigned
long*, unsigned long)
1.05% traffic_server [.]
UrlRewrite::_regexMappingLookup(QueueUrlRewrite::RegexMapping,
UrlRewrite::RegexMapping::Link_link, URL*, i
1.03% libc-2.12.so [.] __strncmp_sse42
{code}
why cpu 100% on a occasion?
---
Key: TS-3430
URL: https://issues.apache.org/jira/browse/TS-3430
Project: Traffic Server
Issue Type: Bug
Components: Core
Reporter: Zhaonanli
Assignee: Bryan Call
Fix For: 6.0.0
trafficserver 4.2.2; Centos 6.5 64bit; 32G mem.
1. top:
Cpu0 : 99.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 1.0%si, 0.0%st
Cpu1 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 99.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 1.0%si, 0.0%st
Cpu3 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 0.0%us,100.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu7 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu8 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu9 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu10 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu11 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu12 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu13 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu14 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu15 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 32819596k total, 32507016k used, 312580k free, 325852k buffers
Swap: 16777212k total,25276k used, 16751936k free, 11826164k cached
PID USER PR NI VIRT RES SHR S %CPU %MEMTIME+ COMMAND
21089 traffics 20 0 22.2g 18g 29m R 100.1 58.9 17:20.61 [ET_NET 0]
21091 traffics 20 0 22.2g 18g 29m R 100.1 58.9 17:11.08 [ET_NET 1]
all thread is 100%.
2. perf top:
58.50% traffic_server [.] LogObject::_checkout_write(unsigned
long*, unsigned long)
34.01% traffic_server [.] bool
ink_atomic_cas__int128(__int128 volatile*, __int128, __int128)
is log questions?
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (TS-3430) why cpu 100% on a occasion?
[ https://issues.apache.org/jira/browse/TS-3430?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14354089#comment-14354089 ] Zhaonanli commented on TS-3430: --- i have found this function [ do while (retry write_offset); ] retry 11108 times in LogObject::_checkout_write. why cpu 100% on a occasion? --- Key: TS-3430 URL: https://issues.apache.org/jira/browse/TS-3430 Project: Traffic Server Issue Type: Bug Components: Core Reporter: Zhaonanli Fix For: sometime trafficserver 4.2.2; Centos 6.5 64bit; 32G mem. 1. top: Cpu0 : 99.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 1.0%si, 0.0%st Cpu1 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu2 : 99.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 1.0%si, 0.0%st Cpu3 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu4 : 0.0%us,100.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu5 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu6 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu7 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu8 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu9 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu10 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu11 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu12 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu13 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu14 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu15 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 32819596k total, 32507016k used, 312580k free, 325852k buffers Swap: 16777212k total,25276k used, 16751936k free, 11826164k cached PID USER PR NI VIRT RES SHR S %CPU %MEMTIME+ COMMAND 21089 traffics 20 0 22.2g 18g 29m R 100.1 58.9 17:20.61 [ET_NET 0] 21091 traffics 20 0 22.2g 18g 29m R 100.1 58.9 17:11.08 [ET_NET 1] all thread is 100%. 2. perf top: 58.50% traffic_server [.] LogObject::_checkout_write(unsigned long*, unsigned long) 34.01% traffic_server [.] bool ink_atomic_cas__int128(__int128 volatile*, __int128, __int128) is log questions? -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (TS-3430) why cpu 100% on a occasion?
[ https://issues.apache.org/jira/browse/TS-3430?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14352412#comment-14352412 ] Leif Hedstrom commented on TS-3430: --- Interesting, sounds like some sort of race / deadlock (intermittent) in the logging code. why cpu 100% on a occasion? --- Key: TS-3430 URL: https://issues.apache.org/jira/browse/TS-3430 Project: Traffic Server Issue Type: Bug Components: Core Reporter: Zhaonanli Fix For: sometime trafficserver 4.2.2; Centos 6.5 64bit; 32G mem. 1. top: Cpu0 : 99.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 1.0%si, 0.0%st Cpu1 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu2 : 99.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 1.0%si, 0.0%st Cpu3 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu4 : 0.0%us,100.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu5 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu6 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu7 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu8 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu9 : 99.0%us, 1.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu10 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu11 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu12 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu13 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu14 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu15 :100.0%us, 0.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 32819596k total, 32507016k used, 312580k free, 325852k buffers Swap: 16777212k total,25276k used, 16751936k free, 11826164k cached PID USER PR NI VIRT RES SHR S %CPU %MEMTIME+ COMMAND 21089 traffics 20 0 22.2g 18g 29m R 100.1 58.9 17:20.61 [ET_NET 0] 21091 traffics 20 0 22.2g 18g 29m R 100.1 58.9 17:11.08 [ET_NET 1] all thread is 100%. 2. perf top: 58.50% traffic_server [.] LogObject::_checkout_write(unsigned long*, unsigned long) 34.01% traffic_server [.] bool ink_atomic_cas__int128(__int128 volatile*, __int128, __int128) is log questions? -- This message was sent by Atlassian JIRA (v6.3.4#6332)
