[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17871350#comment-17871350 ] Mark Linley edited comment on DAEMON-460 at 8/6/24 2:29 PM: Hi [~markt] I tried changing our code to blocking on start until stop is called and that did appear to resolve the issue. Thanks for pointing that out in the documentation. I accept that we missed the documentation here. I think the confusion for me comes down to the naming. I would expect a start method to return quickly and then the application would be in a running state. Then later you call 'stop' and it stops. In this case the 'start' method is more of a 'run' method which would be expected to block until the app is no longer running. Perhaps on the native side, things could be more robust to cater for scenarios where a possible 100% CPU utilization condition is exposed, like in this case. At the least, perhaps a warning in the log file saying that the start method has returned before stop has been called. I also think some throttle or pause to avoid the stuck loop in this scenario might be advisable. Thanks for all your help. was (Author: plasm0r): Hi [~markt] I tried changing our code to blocking on start until stop is called and that did appear to resolve the issue. Thanks for pointing that out in the documentation. I accept that we missed the documentation here. I think the confusion for me comes down to the naming. I would expect a start method to return quickly and then the application would be in a running state. Then later you call 'stop' and it stops. In this case the 'start' method is more of a 'run' method which would be expected to block until the app is no longer running. Perhaps on the native side, things could be more robust to cater for scenarios where a possible 100% CPU utilization condition is exposed, like in this case. At the least, perhaps a warning in the log file saying that the start method has returned before stop has been called. I also think some throttle or pause to avoid the stuck loop in this scenario might also be advisable. Thanks for all your help. > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png, test-windows-service.zip > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Commented] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17871350#comment-17871350 ] Mark Linley commented on DAEMON-460: Hi [~markt] I tried changing our code to blocking on start until stop is called and that did appear to resolve the issue. Thanks for pointing that out in the documentation. I accept that we missed the documentation here. I think the confusion for me comes down to the naming. I would expect a start method to return quickly and then the application would be in a running state. Then later you call 'stop' and it stops. In this case the 'start' method is more of a 'run' method which would be expected to block until the app is no longer running. Perhaps on the native side, things could be more robust to cater for scenarios where a possible 100% CPU utilization condition is exposed, like in this case. At the least, perhaps a warning in the log file saying that the start method has returned before stop has been called. I also think some throttle or pause to avoid the stuck loop in this scenario might also be advisable. Thanks for all your help. > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png, test-windows-service.zip > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 6:02 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns, you then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
Change directory to 'C:\temp\test-windows-service' and then run this command to
register the Windows service and start it to test:
{{prunsrv.exe //IS//TestService -Startup=auto --DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8}}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 3:48 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
Change directory to 'C:\temp\test-windows-service' and then run this command to
register the Windows service and start it to test:
{{prunsrv.exe //IS//TestService -Startup=auto --DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8}}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:30 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{{prunsrv.exe //IS//TestService -Startup=auto --DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8}}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:29 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
"prunsrv.exe //IS//TestService --Startup=auto --DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop --StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug --JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8"
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:29 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{{prunsrv.exe //IS//TestService --Startup=auto --DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop --StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug --JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8}}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense t
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:28 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{{prunsrv.exe //IS//TestService --Startup=auto --DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop --StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug --JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8}}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense t
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:27 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{quote}prunsrv.exe //IS//TestService {}Startup=auto -DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
{quote}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make se
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:27 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
prunsrv.exe //IS//TestService --Startup=auto --DisplayName="Test
Service" --Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop --StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug --JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:27 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{quote}prunsrv.exe //IS//TestService --Startup=auto --DisplayName="Test
Service" --Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop --StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug --JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
{quote}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't mak
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:26 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{quote}prunsrv.exe //IS//TestService {}Startup=auto -DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
{quote}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make se
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:26 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns. You then see prunsrv.exe detecting that
and putting it's native java worker thread in state=0 triggering the tight loop
then the CPU core immediately sits at 100%:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{quote}prunsrv.exe //IS//TestService {}Startup=auto -DisplayName="Test Service"
--Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
{quote}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make se
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley edited comment on DAEMON-460 at 6/21/24 2:24 PM:
-
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, the OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns, then the CPU core immediately sits at
100%. You then see prunsrv.exe detecting that and putting it's native java
worker thread in state=0, triggering the tight loop:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{quote}prunsrv.exe //IS//TestService -{-}Startup=auto --DisplayName="Test
Service" --Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop{-} -StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug- -JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
{quote}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
was (Author: plasm0r):
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn
[jira] [Commented] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[
https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17856781#comment-17856781
]
Mark Linley commented on DAEMON-460:
[~markt],
I had a deeper look at this yesterday. I ran remote debug sessions with both
"Tomcat 10" and our problematic Java windows service that uses 100% of a CPU
core. The "Tomcat 10" service did not suffer from the same high CPU core usage
problem. Both services were using the exact same JVM (openjdk version
"11.0.14.1" 2022-02-08) and prunsrv.exe v1.3.4.
Something that caught my attention was a difference in the service log between
each of the two services. Shortly after service startup, our problematic Java
service has this line in the service log:
{quote}[2024-06-21 10:00:29] [debug] ( javajni.c:1092) [11744] Java worker
thread finished ourservice/util/OurService:main with status = 0
{quote}
This didn't make sense to me because the app was still running and functioning
seemingly normally despite the single CPU core being at 100%. This log
statement is not present in the "Tomcat 10" service log until you stop the
Tomcat10 windows service.
Then I thought about it, and it occurred to me that in our case our startup
'main' method will spawn some application worker threads that our app needs to
function and it then returns, i.e. it doesn't block. When stopping the windows
service, The OurService::stop() method will then signal to the app threads to
shutdown and our application then terminates normally.
The problem I think is that on the prunsrv.exe native C java worker thread side
it likely detects that the JNI method call to OurService::main has terminated
and therefore our application has terminated, so it places the prunsrv.exe
native C java worker thread into state 0, which will trigger the tight loop we
are seeing. I highlighted the line in a code snippet above (line 1165 above).
I tested this using a simple java application and it appears to confirm my
suspicions.
When the java start main() method blocks, processing in a while loop waiting on
a boolean condition and doing work every 5 seconds, there is
low/normal/expected CPU usage. The stop() method will then change a static
boolean variable which the loop is monitoring, and it will then terminate
normally.
However, when the java service's main() start method spawns a thread to do work
asynchronously and immediately returns, then the CPU core immediately sits at
100%. You then see prunsrv.exe detecting that and putting it's native java
worker thread in state=0, triggering the tight loop:
{quote}[2024-06-21 11:13:39] [debug] ( javajni.c:1067) [ 7928] Java worker
thread started for test/commons/daemon/TestWindowsService:main
[2024-06-21 11:13:39] [debug] ( javajni.c:1073) [ 7928] JNI calling static void
method test/commons/daemon/TestWindowsService:main
*[2024-06-21 11:13:39] [debug] ( javajni.c:1092) [ 7928] Java worker thread
finished test/commons/daemon/TestWindowsService:main with status = 0*
[2024-06-21 11:13:40] [debug] ( prunsrv.c:1490) [ 2084] Java started
'test/commons/daemon/TestWindowsService'.
[2024-06-21 11:13:40] [info] ( prunsrv.c:1589) [ 2084] Service started in 1096
milliseconds.
{quote}
I have a test app you can unzip to c:\temp attached [^test-windows-service.zip].
You can then run this command to register the Windows service and start it to
test:
{quote}prunsrv.exe //IS//TestService --Startup=auto --DisplayName="Test
Service" --Description="This is a test Java service"
--Install="C:\temp\test-windows-service\prunsrv.exe"
--Classpath="C:\temp\test-windows-service"
--Jvm="C:\java11jdk\bin\client\jvm.dll" --StartMode=jvm --StopTimeout=30
--StopMode=jvm --StartClass=test/commons/daemon/TestWindowsService
--StopMethod=stop --StopClass=test/commons/daemon/TestWindowsService
--StartMethod=main --LogPath="C:\temp\test-windows-service"
--LogPrefix=Test-Service-Log --LogLevel=Debug --JvmMs=128 --JvmMx=256
--JvmOptions=-Dfile.encoding=UTF8
{quote}
Hopefully this helps recreate the issue on your side. Let me know if you need
anything else.
Thanks
Mark
> High CPU usage in prunsrv.exe since Daemon 1.3.3
>
>
> Key: DAEMON-460
> URL: https://issues.apache.org/jira/browse/DAEMON-460
> Project: Commons Daemon
> Issue Type: Bug
> Components: prunsrv
>Affects Versions: 1.3.3
>Reporter: Japie vd Linde
>Priority: Major
> Attachments: EspRun-Service-Log.2023-06-05.log,
> image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png,
> image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png,
> image-2024-05-31-10-00-10-916.png, test-windows-service.zip
>
>
> When using the --StopTimeout=30 parameter on service using prunsrv the CPU
> usage is reported as very high on Windows. Rollin
[jira] [Updated] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Mark Linley updated DAEMON-460: --- Attachment: test-windows-service.zip > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png, test-windows-service.zip > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 6/13/24 3:53 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method javajni.c::apxJavaWait that receives the wait time value of 2000 milliseconds but the wait time value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. In my case, I think the loop is effectively polling the JVM, via the JNI layer, to see if is still running or it is in a shutdown state, in which case the service wrapper (prunsrv.exe) will terminate. The wait should be used so there is a JVM polling interval of 2 seconds, but it's not happening. I'm not totally clear about how this wait value should be used in javajni.c::apxJavaWait for this scenario where the code looks to be checking the JVM worker thread to be in a certain state. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the wait time value of 2000 milliseconds but the wait time value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 6/13/24 3:53 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was javajni.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method javajni.c::apxJavaWait that receives the wait time value of 2000 milliseconds but the wait time value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. In my case, I think the loop is effectively polling the JVM, via the JNI layer, to see if is still running or it is in a shutdown state, in which case the service wrapper (prunsrv.exe) will terminate. The wait should be used so there is a JVM polling interval of 2 seconds, but it's not happening. I'm not totally clear about how this wait value should be used in javajni.c::apxJavaWait for this scenario where the code looks to be checking the JVM worker thread to be in a certain state. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method javajni.c::apxJavaWait that receives the wait time value of 2000 milliseconds but the wait time value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. In my case, I think the loop is effectively polling the JVM, via the JNI layer, to see if is still running or it is in a shutdown state, in which case the service wrapper (prunsrv.exe) will terminate. The wait should be used so there is a JVM polling interval of 2 seconds, but it's not happening. I'm not totally clear about how this wait value should be used in javajni.c::apxJavaWait for this scenario where the code looks to be checking the JVM worker thread to be in a certain state. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe sin
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 6/4/24 2:29 PM: Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the wait time value of 2000 milliseconds but the wait time value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/31/24 1:43 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! Looking at the first code snippet above, it does seem that you need to have the stop timeout configured, in my case "--StopTimeout=30 ", to reproduce the issue. If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/31/24 1:04 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool. The VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool, the VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/31/24 1:01 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! Here is the CPU usage breakdown by C function from the Visual Studio 2022 diagnostic tool, the VM has 4 cores allocated, so you can see that one core is maxed out: !image-2024-05-31-10-00-10-916.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png, > image-2024-05-31-10-00-10-916.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/29/24 7:20 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that receives the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/29/24 7:09 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I analyzed the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/29/24 7:08 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping into apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping down into the callstack in apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/29/24 7:08 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping down into the callstack in apxHandleWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping down into the callstack in apxHandlerWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Comment Edited] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley edited comment on DAEMON-460 at 5/29/24 7:04 PM: - Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU core utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping down into the callstack in apxHandlerWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark was (Author: plasm0r): Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping down into the callstack in apxHandlerWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Commented] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17850467#comment-17850467 ] Mark Linley commented on DAEMON-460: Hi Our Java application is managed as a Windows service by Apache Commons Daemon. Upgrading to v1.3.4 showed what others have been seeing. One of the CPU cores constantly sits at close to 100% CPU utilization. I was able to successfully configure Visual Studio 2022 to do remote debugging of prunsrv.exe v1.3.4. I recorded the CPU profile in Visual Studio once the debugger was connected to the remote prunsrv.exe process. I could see one of the threads of prunsrv.exe consuming almost 100% of the CPU. I looked at the top function, based on CPU usage, and it was prunsrv.c::apxJavaWait. With a breakpoint activated, my attention was drawn to this code in prunsrv.c::serviceMain : !image-2024-05-29-15-56-35-585.png! I could see in my debug session that the wait of 2 seconds is definitely not happening, resulting in the loop iterating as fast as the CPU core will allow it to, which likely explains the 100% CPU utilization issue. Pull request 64, mentioned above, did add this loop so it could be related to the problem we are seeing. Stepping down into the callstack in apxHandlerWait you arrive at the method prunsrv.c::apxJavaWait that received the timeout value of 2000 milliseconds but the timeout value is effectively never used because the code keeps returning here: !image-2024-05-29-15-57-37-665.png! If someone more experienced in C or one of the maintainers could comment, I'd appreciate it. I'm a Java developer :) Thanks! Mark > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Updated] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Mark Linley updated DAEMON-460: --- Attachment: image-2024-05-29-15-57-37-665.png > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png, image-2024-05-29-15-57-37-665.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
[jira] [Updated] (DAEMON-460) High CPU usage in prunsrv.exe since Daemon 1.3.3
[ https://issues.apache.org/jira/browse/DAEMON-460?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Mark Linley updated DAEMON-460: --- Attachment: image-2024-05-29-15-56-35-585.png > High CPU usage in prunsrv.exe since Daemon 1.3.3 > > > Key: DAEMON-460 > URL: https://issues.apache.org/jira/browse/DAEMON-460 > Project: Commons Daemon > Issue Type: Bug > Components: prunsrv >Affects Versions: 1.3.3 >Reporter: Japie vd Linde >Priority: Major > Attachments: EspRun-Service-Log.2023-06-05.log, > image-2023-05-31-09-31-21-485.png, image-2023-06-05-13-38-38-435.png, > image-2024-05-29-15-56-35-585.png > > > When using the --StopTimeout=30 parameter on service using prunsrv the CPU > usage is reported as very high on Windows. Rolling back to older prunsrv > seems to resolve the problem. > !image-2023-05-31-09-31-21-485.png! > What could be the possible causes for this problem? -- This message was sent by Atlassian Jira (v8.20.10#820010)
