#711  After update to v7.x CPU is loaded on 100%
Released
Kruzya opened 3 weeks ago

After update to v7.0.3, my OneDev installation started load CPU to 100%. Also response time is greatly increased (i can wait load index page (with projects) 2 minutes).

I tried yesterday update to v7.1.2, but this don't helped.
My environment:

  • Home server with 4 CPUs cores (or 8 with HyperThreading)
  • OneDev is running in Docker on host with 2 vCPU and 1GB RAM
  • PostgreSQL is placed on same server, but in another virtual machine with 6 vCPUs and 2GB RAM

OneDev VM:
image.png

PostgreSQL VM:
image.png

Also when this problem started, i see this error periodically:

05:27:29 ERROR o.a.w.p.w.a.AbstractWebSocketProcessor - An error occurred during processing of a WebSocket message
java.lang.IllegalStateException: This time is in the future
        at org.apache.wicket.util.time.Time.elapsedSince(Time.java:262)
        at org.apache.wicket.page.PageAccessSynchronizer.lockPage(PageAccessSynchronizer.java:108)
        at org.apache.wicket.page.PageAccessSynchronizer$2.getPage(PageAccessSynchronizer.java:245)
        at org.apache.wicket.protocol.ws.api.AbstractWebSocketProcessor.getPage(AbstractWebSocketProcessor.java:336)
        at org.apache.wicket.protocol.ws.api.AbstractWebSocketProcessor.broadcastMessage(AbstractWebSocketProcessor.java:250)
        at org.apache.wicket.protocol.ws.api.AbstractWebSocketProcessor.onConnect(AbstractWebSocketProcessor.java:186)
        at io.onedev.server.web.websocket.WebSocketProcessor.access$200(WebSocketProcessor.java:43)
        at io.onedev.server.web.websocket.WebSocketProcessor$1.run(WebSocketProcessor.java:74)
        at io.onedev.server.persistence.DefaultSessionManager$2.call(DefaultSessionManager.java:100)
        at io.onedev.server.persistence.DefaultSessionManager$2.call(DefaultSessionManager.java:96)
        at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:79)
        at io.onedev.server.persistence.DefaultSessionManager.run(DefaultSessionManager.java:96)
        at io.onedev.server.web.websocket.WebSocketProcessor.run(WebSocketProcessor.java:86)
        at io.onedev.server.web.websocket.WebSocketProcessor.onWebSocketConnect(WebSocketProcessor.java:68)
        at org.eclipse.jetty.websocket.common.events.JettyListenerEventDriver.onConnect(JettyListenerEventDriver.java:159)
        at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.openSession(AbstractEventDriver.java:217)
        at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:493)
        at org.eclipse.jetty.websocket.common.WebSocketSession.onOpened(WebSocketSession.java:459)
        at org.eclipse.jetty.io.AbstractConnection.onOpened(AbstractConnection.java:213)
        at org.eclipse.jetty.io.AbstractConnection.onOpen(AbstractConnection.java:205)
        at org.eclipse.jetty.io.AbstractEndPoint.upgrade(AbstractEndPoint.java:444)
        at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:407)
        at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:820)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:368)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
        at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:386)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
        at java.lang.Thread.run(Thread.java:748)

Time on servers is set correctly.

Robin Shen commented 3 weeks ago

Please increase the memory to 2G to see if it works. If CPU is still 100%, please login to the docker container and get the stack trace by running:

jstack <QB JVM process id>
Kruzya commented 3 weeks ago

Increased RAM to 2GB, restarted VM and looks like it not helped.
image.png
CPU continue be loaded on 100%, but i noticed strange behavior: before any request to web, OneDev loads only one CPU core. When i try perform request, it starts load 2 CPU core.

Found java in /usr/bin, but don't see jstack. Can i run from host OS or I need download jstack in Docker container?

Robin Shen commented 3 weeks ago

My mistake. jstack is not available in onedev image, please login to the container and install openjdk to get jstack:

apt update 
apt install openjdk-8-jdk

This command needs to run inside container.

Kruzya commented 3 weeks ago

https://pastebin.com/2WfQV7ii

Uploaded to Pastebin. It does not fit here by the number of characters

Robin Shen commented 3 weeks ago

This is a bug of Hibernate library used by OneDev:
https://hibernate.atlassian.net/browse/HHH-13664

To solve the issue, please make sure the system time is not set back in the past.

Kruzya commented 3 weeks ago

As I said previously, my time is set correctly.
But on VMs set different time zones: on VM with PostgreSQL set my real timezone (GMT+4), on VM with OneDev - UTC. Different timezones may be the reason of this behavior?

I will try change timezone on VM with OneDev.
Looks like it helped: OneDev stopped loading CPU on 100% since start. Solved 🤦

Kruzya commented 3 weeks ago

As I understand, OneDev writes current time in DB via PostgreSQL functions, which return the current time according to the timezone. It is possible use UTC time in this cases and allow admin set required for displaying timezone in options?

Robin Shen commented 3 weeks ago

I guess you want to show time in your local timezone? If so, please watch this issue:

https://code.onedev.io/projects/160/issues/639

OneDev changed state to 'Closed' 3 weeks ago
Previous Value Current Value
Open
Closed
OneDev commented 3 weeks ago

State changed as code fixing the issue is committed

OneDev changed state to 'Released' 3 weeks ago
Previous Value Current Value
Closed
Released
OneDev commented 3 weeks ago

State changed as build #2645 (7.1.4) is successful

Robin Shen commented 3 weeks ago

The 7.1.4 version should work fine even if you are using different timezone for OneDev.

Kruzya commented 3 weeks ago

Yes, it fixed, thanks!

issue 1 of 1
Type
Bug
Priority
Normal
Assignee
Seen Builds
Issue Votes (0)
Watchers (4)
Reference
issue onedev/server#711
Please wait...
Page is in error, reload to recover