ralphy wrote:
> ...
> Please try 'squeezelite-1.9.8-1324-test3-win64.zip'
> (https://www.dropbox.com/s/put1qx5j9flhajv/squeezelite-1.9.8-1324-test3-win64.zip?dl=1).
No luck yet. See my log below with lines inserted where I detect cpu
load.
[22:52:50.094] process_strm:280 strm command t
[22:52:50.094] sendSTAT:195 STAT: STMt
[22:52:52.096] sendSTAT:195 STAT: STMt
[22:52:54.097] sendSTAT:195 STAT: STMt
[22:52:55.095] process:527 strm
[22:52:55.095] process_strm:280 strm command t
[22:52:55.095] sendSTAT:195 STAT: STMt
[22:52:56.095] sendSTAT:195 STAT: STMt
[22:52:58.095] sendSTAT:195 STAT: STMt
[22:53:00.094] sendSTAT:195 STAT: STMt
[22:53:00.094] process:527 strm
[22:53:00.094] process_strm:280 strm command t
[22:53:00.094] sendSTAT:195 STAT: STMt
[22:53:02.096] sendSTAT:195 STAT: STMt
[22:53:04.096] sendSTAT:195 STAT: STMt
-22:53:04.208- ########## START OF HEAVY CPU LOAD
-22:53:04.208- ########## CPU LOAD: total:64,0% user:12,2%
kernel:51,8%
-22:53:04.701- ########## CPU LOAD: total:100,0% user:9,5%
kernel:91,9%
[22:53:05.094] process:527 strm
[22:53:05.094] process_strm:280 strm command t
[22:53:05.094] sendSTAT:195 STAT: STMt
-22:53:05.196- ########## CPU LOAD: total:100,0% user:9,5%
kernel:91,5%
-22:53:05.708- ########## CPU LOAD: total:97,8% user:9,2%
kernel:88,7%
[22:53:06.095] sendSTAT:195 STAT: STMt
-22:53:06.197- ########## CPU LOAD: total:100,0% user:19,2%
kernel:83,0%
-22:53:06.696- ########## CPU LOAD: total:100,0% user:3,1%
kernel:97,1%
-22:53:07.208- ########## CPU LOAD: total:97,7% user:15,3%
kernel:82,4%
-22:53:07.699- ########## CPU LOAD: total:100,0% user:19,1%
kernel:82,7%
[22:53:08.097] sendSTAT:195 STAT: STMt
-22:53:08.207- ########## CPU LOAD: total:98,4% user:12,3%
kernel:86,1%
-22:53:08.696- ########## CPU LOAD: total:100,0% user:22,4%
kernel:79,9%
-22:53:09.206- ########## CPU LOAD: total:97,9% user:12,2%
kernel:85,7%
-22:53:09.700- ########## CPU LOAD: total:100,0% user:9,5%
kernel:91,7%
[22:53:10.095] sendSTAT:195 STAT: STMt
[22:53:10.095] process:527 strm
[22:53:10.095] process_strm:280 strm command t
[22:53:10.095] sendSTAT:195 STAT: STMt
-22:53:10.209- ########## CPU LOAD: total:98,4% user:12,3%
kernel:86,1%
-22:53:10.703- ########## CPU LOAD: total:100,0% user:22,1%
kernel:79,1%
-22:53:11.196- ########## CPU LOAD: total:98,2% user:6,3%
kernel:91,9%
-22:53:11.707- ########## CPU LOAD: total:97,7% user:15,3%
kernel:82,5%
[22:53:12.095] sendSTAT:195 STAT: STMt
-22:53:12.199- ########## CPU LOAD: total:100,0% user:19,1%
kernel:82,6%
-22:53:12.696- ########## CPU LOAD: total:100,0% user:3,1%
kernel:97,6%
-22:53:13.207- ########## CPU LOAD: total:97,7% user:15,3%
kernel:82,4%
-22:53:13.701- ########## CPU LOAD: total:100,0% user:6,3%
kernel:94,9%
[22:53:14.096] sendSTAT:195 STAT: STMt
-22:53:14.210- ########## CPU LOAD: total:98,2% user:3,1%
kernel:95,2%
-22:53:14.697- ########## CPU LOAD: total:100,0% user:9,6%
kernel:93,0%
[22:53:15.094] process:527 strm
[22:53:15.094] process_strm:280 strm command t
[22:53:15.094] sendSTAT:195 STAT: STMt
-22:53:15.196- ########## CPU LOAD: total:100,0% user:6,3%
kernel:97,1%
-22:53:15.707- ########## CPU LOAD: total:98,0% user:15,3%
kernel:82,7%
[22:53:16.095] sendSTAT:195 STAT: STMt
-22:53:16.203- ########## CPU LOAD: total:100,0% user:12,6%
kernel:88,2%
-22:53:16.696- ########## CPU LOAD: total:100,0% user:0,0%
kernel:100,0%
-22:53:17.203- ########## CPU LOAD: total:98,6% user:3,1%
kernel:95,5%
-22:53:17.696- ########## CPU LOAD: total:100,0% user:9,5%
kernel:91,8%
[22:53:18.095] sendSTAT:195 STAT: STMt
-22:53:18.205- ########## CPU LOAD: total:98,2% user:9,2%
kernel:89,0%
-22:53:18.697- ########## CPU LOAD: total:100,0% user:0,0%
kernel:100,0%
-22:53:19.209- ########## CPU LOAD: total:97,6% user:3,1%
kernel:94,6%
-22:53:19.703- ########## CPU LOAD: total:100,0% user:6,3%
kernel:95,0%
[22:53:20.094] sendSTAT:195 STAT: STMt
[22:53:20.094] process:527 strm
[22:53:20.094] process_strm:280 strm command t
[22:53:20.094] sendSTAT:195 STAT: STMt
-22:53:20.210- ########## CPU LOAD: total:98,6% user:9,2%
kernel:89,4%
-22:53:20.695- ########## CPU LOAD: total:100,0% user:6,4%
kernel:96,5%
-22:53:21.203- ########## CPU LOAD: total:98,4% user:12,3%
kernel:86,1%
-22:53:21.696- ########## CPU LOAD: total:100,0% user:19,0%
kernel:82,5%
[22:53:22.096] sendSTAT:195 STAT: STMt
-22:53:22.204- ########## CPU LOAD: total:98,4% user:9,2%
kernel:89,1%
-22:53:22.709- ########## CPU LOAD: total:98,9% user:6,2%
kernel:92,8%
-22:53:23.202- ########## CPU LOAD: total:100,0% user:9,5%
kernel:92,0%
-22:53:23.711- ########## CPU LOAD: total:100,0% user:18,4%
kernel:82,9%
[22:53:24.097] sendSTAT:195 STAT: STMt
[22:53:24.097] sendSTAT:195 STAT: STMo
[22:53:24.099] process:527 strm
[22:53:24.099] process_strm:280 strm command p
[22:53:24.099] sendSTAT:195 STAT: STMp
[22:53:24.099] process_strm:316 pause interval: 0
-22:53:24.216- ########## CPU LOAD: total:98,9% user:9,3%
kernel:89,7%
[22:53:24.231] process:527 strm
[22:53:24.231] process_strm:280 strm command t
[22:53:24.231] sendSTAT:195 STAT: STMt
[22:53:24.533] process:527 strm
[22:53:24.533] process_strm:280 strm command t
[22:53:24.533] sendSTAT:195 STAT: STMt
-22:53:24.715- ########## CPU LOAD: total:100,0% user:3,1%
kernel:97,2%
[22:53:24.835] process:527 strm
[22:53:24.835] process_strm:280 strm command t
[22:53:24.835] sendSTAT:195 STAT: STMt
[22:53:25.094] process:527 strm
[22:53:25.094] process_strm:280 strm command t
[22:53:25.094] sendSTAT:195 STAT: STMt
Heavy cpu load starts at 22:53:04.208. At 22:53:24.097, that is about 20
seconds later, the behavior of the stream thread changes from 'STAT:
STMt' to 'STMo' followed by 'strm command p' and 'pause interval: 0'. I'
curious whether that behavior changes when 100% cpu load is avoided.
Let me explain my reasoning: What I saw when I attached the Visual
Studio Debugger to squeezelite and interruped it while in 100% cpu load
was, that its from one thread and this thread sometimes had its priority
elevated slightly, presumably when in kernel code. Such a situation
could possibly derail other threads and trigger unexpected behavior.
100% cpu load is in essence an extreme stress test for the system and it
fails obviously. We don't realy know whether the cpu load is cause or
effect, but it seems to me of no use to find a solution in a stressed
system we do not control 100%. The fault may well be in the Windows
TCP/IP stack implementation. We would not know. So my priority would be
to get rid of the cpu load, then to look further.
I assume the source of the cpu load is a tight loop in
Code:
--------------------
static void slimproto_run() {
...
while (running && !new_server) {
....
if ((ev = wait_readwake(ehandles, 1000)) != EVENT_TIMEOUT) {
....
}
....
}
--------------------
Inside the *if* section there are two *continue*s that could, when
permanently triggered, make the loop tight. The stream thread is another
thread presumably. It might be just perfect only to get derailed inside
a system call. We don't know yet.
My proposal would be to find the source of the cpu load, slow the thread
down a bit by inserting a short sleep(), insert some temporary logging
and see what happens.
Does it make sense to insert a debug log followed by a sleep(1)
immediately before the two continues? You know the code better than me
but it should not be too often one gets a EVENT_READ and then read
nothing.
------------------------------------------------------------------------
fpo's Profile: http://forums.slimdevices.com/member.php?userid=71212
View this thread: http://forums.slimdevices.com/showthread.php?t=113554
_______________________________________________
plugins mailing list
[email protected]
http://lists.slimdevices.com/mailman/listinfo/plugins
