Mass import from GitHub with bidirectional mirroring (OD-2476)

I recently set up a OneDev instance that I would like to use for the projects I'm involved with.

One of those projects has 25k repositories with a total size of ~20 GB in a dedicated organization on GitHub.

Is there a way, perhaps through a specially crafted application, to import all those repositories and also automatically setup bidirectional mirroring?

Thanks in advance!

Activities

Robin Shen commented 6 months ago
I'd suggest to write a script to do the import. Basically the script run below for each of your github repository:

Clone your github repository

Create onedev project via restful api

Add a build spec (.onedev-buildspec.yml) to do two-way mirroring. You may set up this for a test repository via GUI to see what the generated build spec looks like.

Push the repository to OneDev project

Davide Beatrici commented 6 months ago

Thank you very much!

I set up mirroring with a test repository and it works flawlessly in both directions.

It would be amazing if there was a way to create a build spec in the parent project that applies to child projects. That way I could have a single .onedev-buildspec.yml file and outside of all repositories that have to be synced. The filtering feature already exists for forked repositories, I believe it can be duplicated for child projects.

Do you think it's feasible to implement something like that?

For reference, the build spec looks like this:

version: 40
jobs:
- name: Push to mirror
  steps:
  - !PushRepository
    name: Push to GitHub
    remoteUrl: https://github.com/<org>/@project_name@
    passwordSecret: github-org-access-token
    force: false
    condition: SUCCESSFUL
    optional: false
  triggers:
  - !BranchUpdateTrigger {}
  - !TagCreateTrigger {}
  retryCondition: never
  maxRetries: 3
  retryDelay: 30
  timeout: 14400
- name: Pull from mirror
  steps:
  - !PullRepository
    name: Pull from GitHub
    remoteUrl: https://github.com/<org>/@project_name@
    passwordSecret: github-org-access-token
    accessTokenSecret: github-org-access-token
    refs: refs/heads/* refs/tags/*
    withLfs: true
    force: false
    condition: SUCCESSFUL
    optional: false
  triggers:
  - !ScheduleTrigger
    cronExpression: 0 0 0 * * ?
  retryCondition: never
  maxRetries: 3
  retryDelay: 30
  timeout: 14400

Robin Shen commented 6 months ago

Do you think it's feasible to implement something like that?

This will not be considered right now as it makes the project pull/push step overly complicated: the step needs to find a way to map child project to remote repository. Also the push repository step works by pushing current ref the build is running against to remote, and this mechanism does not work for child projects at all.
Robin Shen changed state to 'Closed' 6 months ago
Previous Value Current Value
Open

Closed
Davide Beatrici commented 6 months ago

Alright, I came up with a plan to automatize the task.

I thought I could at least import all repositories directly on the web interface, but it just times out when pressing on "Next". It actually doesn't even load the list of repositories to select.

Is it something that can be solved or do I have to import all repositories manually as well?

Previous Value	Current Value
Open	Closed

Davide Beatrici commented 6 months ago

I decided to automate the import process through a set of V scripts, which I will of course share once the process is complete.

Unfortunately while creating the projects OneDev became slower and slower and now most of the times the web interface just times out, even after 5 hours since the script finished.

Restarting the container has no effect and right after it boots up I see a 502 error instead of 504.

Update: Seems to have somewhat recovered after a second restart! It seems to struggle only when loading the homepage, where the extremely long projects list appears (even if it's paged).

Both CPU and RAM usage are still way too high at idle:

Oh, the server logs give a big blue:

2025-07-01 22:14:25,858 ERROR [pool-3-thread-19] i.o.s.u.c.DefaultBatchWorkManager Error doing works
com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active!
	at com.hazelcast.internal.serialization.impl.bufferpool.BufferPoolThreadLocal.get(BufferPoolThreadLocal.java:107)
	at com.hazelcast.internal.serialization.impl.AbstractSerializationService.toBytes(AbstractSerializationService.java:225)
	at com.hazelcast.internal.serialization.impl.AbstractSerializationService.toBytes(AbstractSerializationService.java:217)
	at com.hazelcast.internal.serialization.impl.AbstractSerializationService.toData(AbstractSerializationService.java:202)
	at com.hazelcast.map.impl.proxy.MapProxySupport.toDataWithStrategy(MapProxySupport.java:1334)
	at com.hazelcast.map.impl.proxy.MapProxySupport.getInternal(MapProxySupport.java:410)
	at com.hazelcast.map.impl.proxy.MapProxyImpl.get(MapProxyImpl.java:123)
	at io.onedev.server.util.MapProxy.get(MapProxy.java:40)
	at io.onedev.server.entitymanager.impl.DefaultProjectManager.findFacadeById(DefaultProjectManager.java:1317)
	at io.onedev.server.search.entitytext.EntityTextManager$1.doWorks(EntityTextManager.java:270)
	at io.onedev.server.util.concurrent.DefaultBatchWorkManager$2.doWorks(DefaultBatchWorkManager.java:106)
	at io.onedev.server.util.concurrent.DefaultBatchWorkManager$1.run(DefaultBatchWorkManager.java:74)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:199)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:195)
	at io.onedev.server.security.SecurityUtils$1.call(SecurityUtils.java:601)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor.lambda$call$0(DefaultWorkExecutor.java:70)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at io.onedev.server.security.SecurityUtils.lambda$inheritSubject$1(SecurityUtils.java:582)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

Robin Shen commented 6 months ago

Alright, I came up with a plan to automatize the task.

I thought I could at least import all repositories directly on the web interface, but it just times out when pressing on "Next". It actually doesn't even load the list of repositories to select.

Is it something that can be solved or do I have to import all repositories manually as well?

If you have 25k repositories to import, the UI cannot handle that. In this case, write a script to do the job.
Davide Beatrici commented 6 months ago

Already done, I will also share the script(s).

The issue right now is my OneDev instance being unusable...
Robin Shen commented 6 months ago

Unfortunately while creating the projects OneDev became slower and slower and now most of the times the web interface just times out, even after 5 hours since the script finished.

After pushing repositories, OneDev will analyze and index the repositories (for symbol and text search etc). This may take a while if you have many many repositories. You may configure OneDev to use less CPU cycles for indexing. This can be done via Administration / Performance Settings / CPU Intensive Task Concurrency.
Robin Shen commented 6 months ago

The issue right now is my OneDev instance being unusable...

Please get into the container, and get a thread dump by running /opt/onedev/bin/server.sh dump. The thread dump will be printed into /opt/onedev/logs/console.log. Please share console.log here and I will check if OneDev is still indexing or doing some other things.
Davide Beatrici commented 6 months ago
After pushing repositories, OneDev will analyze and index the repositories (for symbol and text search etc). This may take a while if you have many many repositories. You may configure OneDev to use less CPU cycles for indexing. This can be done via Administration / Performance Settings / CPU Intensive Task Concurrency.

I originally set it to 2 because that's the amount of threads the VM has. Lowering it to 1 didn't have an effect unfortunately.

Please note that all projects I created are currently empty, pushing the content into them will be the final step.

Please get into the container, and get a thread dump by running /opt/onedev/bin/server.sh dump. The thread dump will be printed into /opt/onedev/logs/console.log. Please share console.log here and I will check if OneDev is still indexing or doing some other things.

# /opt/onedev/bin/server.sh dump Dumping OneDev... OneDev was not running.

console.log

History
Robin Shen commented 6 months ago

This seems abnormal. Please let me know detail steps to reproduce.
Davide Beatrici commented 6 months ago
Create a fresh OneDev instance, eventually import a really big repository such as https://gitlab.winehq.org/wine/wine and use it as a benchmark (navigating in source files) to ensure there are no severe slowdowns.

Write an extremely long list of projects to create, either "manually" or scraped (in my case from a GitHub organization).

Create all projects through the RESTful API. OneDev's web interface will immediately become slower, but after thousands of projects it will worsen to the point of just timing out most of the time.

list_github_repos.vsh create_onedev_projects.vsh

github_repos.txt project_creation.log
Davide Beatrici commented 6 months ago

I can also make an archive of the entire data directory and send it to you privately, if it helps.
Robin Shen commented 6 months ago

That will be super helpful, please send to [robin AT onedev DOT io]
Robin Shen commented 6 months ago

I can also make an archive of the entire data directory and send it to you privately, if it helps.

Never mind, I will test with the script you provided first.
Davide Beatrici commented 6 months ago

No problem, the link I sent you via email is valid for 7 days.
Robin Shen commented 6 months ago

@davidebeatrici please upgrade to build OD-6456 which fixed performance issue for massive projects.

As repositories are imported into OneDev, please increase memory and open file limit for the docker process. Also suggest to switch to external database for production usage.
Davide Beatrici commented 6 months ago

Thank you very much for your impressive work!

Unfortunately it looks like the database got corrupted with the update from 11.11.2 to 11.11.4, as performing a backup only results in the projects info being saved and I keep seeing error 502. A cURL call results in curl: (56) Recv failure: Connection reset by peer.

db_backup_ko.txt

I had to restore the full backup I made of the OneDev directory and create a container with a previous version, I chose 11.11.1 because it's the one that matches the backup.

db_backup_ok.txt

History

Robin Shen commented 6 months ago

I did not see any errors in the log. Please run the container in foreground to see what happens:

docker run -it -v /path/to/local/onedev:/opt/onedev -v /var/run/docker.sock:/var/run/docker.sock -p 6610:6610 1dev/server:11.11.4

Davide Beatrici commented 6 months ago

My instance is now fully working and backed by PostgreSQL, the restore process worked perfectly with the proper backup. Performance is great so far, thank you again!

I'm currently pushing all repositories with the buildspec added to each branch using a script, I'll let you know if everything goes well.

As for the migration fault, I will attempt to reproduce the issue with the same data but on a separate machine.

Davide Beatrici commented 6 months ago

Looks like I broke something else now. I noticed the script was stuck pushing a branch through SSH and then it timed out.

On the web interface:

In the server's log:

[12436.965s][warning][os,thread] Failed to start thread "Unknown thread" - pthread_create failed (EAGAIN) for attributes: stacksize: 1024k, guardsize: 0k, detached.
[12436.965s][warning][os,thread] Failed to start the native thread for java.lang.Thread "hz.172.17.0.2:5710.cached.thread-2900"
01:04:59 ERROR c.h.s.i.e.ExecutionService - [172.17.0.2]:5710 [a64dc8cc68beb300fd9dadaefa7d91579ef439f5e1b97a9b454ef8ffa49492fe] [5.3.5] Failed to execute java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@77db80c3[Completed exceptionally: java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached]
java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached
        at java.base/java.lang.Thread.start0(Native Method)
        at java.base/java.lang.Thread.start(Thread.java:798)
        at com.hazelcast.internal.util.executor.HazelcastManagedThread.start(HazelcastManagedThread.java:92)
        at java.base/java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:937)
        at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1354)
        at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate.addNewWorkerIfRequired(CachedExecutorServiceDelegate.java:140)
        at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate.execute(CachedExecutorServiceDelegate.java:110)
        at com.hazelcast.spi.impl.executionservice.impl.DelegateAndSkipOnConcurrentExecutionDecorator.run(DelegateAndSkipOnConcurrentExecutionDecorator.java:52)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
        at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
        at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111)
[12443.301s][warning][os,thread] Failed to start thread "Unknown thread" - pthread_create failed (EAGAIN) for attributes: stacksize: 1024k, guardsize: 0k, detached.
[12443.302s][warning][os,thread] Failed to start the native thread for java.lang.Thread "HikariPool-1 connection closer"
[12447.117s][warning][os,thread] Failed to start thread "Unknown thread" - pthread_create failed (EAGAIN) for attributes: stacksize: 1024k, guardsize: 0k, detached.
[12447.117s][warning][os,thread] Failed to start the native thread for java.lang.Thread "HikariPool-1 connection closer"
[12450.563s][warning][os,thread] Failed to start thread "Unknown thread" - pthread_create failed (EAGAIN) for attributes: stacksize: 1024k, guardsize: 0k, detached.
[12450.563s][warning][os,thread] Failed to start the native thread for java.lang.Thread "HikariPool-1 connection closer"
[12455.027s][warning][os,thread] Failed to start thread "Unknown thread" - pthread_create failed (EAGAIN) for attributes: stacksize: 1024k, guardsize: 0k, detached.
[12455.028s][warning][os,thread] Failed to start the native thread for java.lang.Thread "HikariPool-1 connection closer"

As repositories are imported into OneDev, please increase memory and open file limit for the docker process.

Time to do that.

01:23:17 ERROR i.o.s.u.c.DefaultBatchWorkManager - Error doing works
java.lang.RuntimeException: org.apache.lucene.index.CorruptIndexException: file mismatch, expected id=alsj4yvv73o82j4c9gsdy7ed1, got=ejm0az804g2bckvep4hsxl46e (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
        at io.onedev.server.util.lucene.LuceneUtils.callWithWriter(LuceneUtils.java:93)
        at io.onedev.server.search.entitytext.EntityTextManager.callWithWriter(EntityTextManager.java:247)
        at io.onedev.server.search.entitytext.EntityTextManager$1.doWorks(EntityTextManager.java:289)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$2.doWorks(DefaultBatchWorkManager.java:106)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$1.run(DefaultBatchWorkManager.java:74)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:202)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:198)
        at io.onedev.server.security.SecurityUtils$1.call(SecurityUtils.java:598)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor.lambda$call$0(DefaultWorkExecutor.java:67)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at io.onedev.server.security.SecurityUtils.lambda$inheritSubject$1(SecurityUtils.java:587)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.apache.lucene.index.CorruptIndexException: file mismatch, expected id=alsj4yvv73o82j4c9gsdy7ed1, got=ejm0az804g2bckvep4hsxl46e (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
        at org.apache.lucene.codecs.CodecUtil.checkIndexHeaderID(CodecUtil.java:351)
        at org.apache.lucene.codecs.CodecUtil.checkIndexHeader(CodecUtil.java:256)
        at org.apache.lucene.codecs.lucene86.Lucene86SegmentInfoFormat.read(Lucene86SegmentInfoFormat.java:95)
        at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:357)
        at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:291)
        at org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:165)
        at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1089)
        at io.onedev.server.util.lucene.LuceneUtils.callWithWriter(LuceneUtils.java:82)
        ... 13 common frames omitted
        Suppressed: org.apache.lucene.index.CorruptIndexException: checksum passed (512d51a8). possibly transient resource issue, or a Lucene or JVM bug (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
                at org.apache.lucene.codecs.CodecUtil.checkFooter(CodecUtil.java:466)
                at org.apache.lucene.codecs.lucene86.Lucene86SegmentInfoFormat.read(Lucene86SegmentInfoFormat.java:143)
                ... 18 common frames omitted

Can this be ignored?

Robin Shen commented 6 months ago

Obviously OneDev runs out of memory now, and all kinds of errors can occur at this point. For each repository, it needs to index the code for various tasks. It also caches commit information via a key-value file store to speed up things. You may also experience max open file issue if it is not increased previously.

By default OneDev uses 50% of host memory, and this can be tuned via property "set.default.max_memory_percent" in file "conf/wrapper.conf". Watch out heap usage via "Administration / System Maintenance / Server Information" as you are pushing repositories.
Davide Beatrici commented 6 months ago

Thank you, I'm actually also going to add at least one external worker. There are a LOT of sync jobs queued, one for each branch of each repository.

OneDev is doing really well with the resource constraints!

Davide Beatrici commented 6 months ago

~10k repositories left! The process has been going well so far, I only had to restart OneDev 2 or 3 times due to the heap memory being full (~3 GB) and causing an overall slowness. The web interface and Git commands never timed out though, which is a really good thing.

The first restart took almost an hour for some reason:

2025-07-07 07:25:00,944 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-07-07 07:25:00,947 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-07-07 07:25:01,357 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-07-07 07:25:46,022 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-07-07 07:26:21,350 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-07-07 07:26:46,069 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-07-07 08:11:12,576 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-07-07 08:11:14,740 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-07-07 08:11:19,643 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...

After that most restarts only took ~5 minutes, time spent checking the projects for the most part.

Sometimes the SSH server doesn't seem to properly start:

kex_exchange_identification: read: Connection reset by peer
Connection reset by ::1 port 6611
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

Unfortunately there are no errors in the log. The first time I simply waited a few minutes, this time I had to perform another restart which resulted in the very long boot time again:

2025-07-09 00:02:44,749 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-07-09 00:02:44,848 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-07-09 00:02:49,844 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-07-09 00:03:14,292 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-07-09 00:03:15,170 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-07-09 00:03:15,600 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-07-09 00:03:15,985 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-07-09 00:03:40,147 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-07-09 01:01:21,466 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-07-09 02:26:21,456 ERROR [pool-3-thread-3] i.o.s.u.c.DefaultBatchWorkManager Error doing works
java.lang.RuntimeException: org.apache.lucene.index.CorruptIndexException: file mismatch, expected id=alsj4yvv73o82j4c9gsdy7ed1, got=ejm0az804g2bckvep4hsxl46e (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
        at io.onedev.server.util.lucene.LuceneUtils.callWithWriter(LuceneUtils.java:93)
        at io.onedev.server.search.entitytext.EntityTextManager.callWithWriter(EntityTextManager.java:247)
        at io.onedev.server.search.entitytext.EntityTextManager$1.doWorks(EntityTextManager.java:289)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$2.doWorks(DefaultBatchWorkManager.java:106)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$1.run(DefaultBatchWorkManager.java:74)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:202)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:198)
        at io.onedev.server.security.SecurityUtils$1.call(SecurityUtils.java:598)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor.lambda$call$0(DefaultWorkExecutor.java:67)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at io.onedev.server.security.SecurityUtils.lambda$inheritSubject$1(SecurityUtils.java:587)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.apache.lucene.index.CorruptIndexException: file mismatch, expected id=alsj4yvv73o82j4c9gsdy7ed1, got=ejm0az804g2bckvep4hsxl46e (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
        at org.apache.lucene.codecs.CodecUtil.checkIndexHeaderID(CodecUtil.java:351)
        at org.apache.lucene.codecs.CodecUtil.checkIndexHeader(CodecUtil.java:256)
        at org.apache.lucene.codecs.lucene86.Lucene86SegmentInfoFormat.read(Lucene86SegmentInfoFormat.java:95)
        at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:357)
        at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:291)
        at org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:165)
        at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1089)
        at io.onedev.server.util.lucene.LuceneUtils.callWithWriter(LuceneUtils.java:82)
        ... 13 common frames omitted
        Suppressed: org.apache.lucene.index.CorruptIndexException: checksum passed (512d51a8). possibly transient resource issue, or a Lucene or JVM bug (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
                at org.apache.lucene.codecs.CodecUtil.checkFooter(CodecUtil.java:466)
                at org.apache.lucene.codecs.lucene86.Lucene86SegmentInfoFormat.read(Lucene86SegmentInfoFormat.java:143)
                ... 18 common frames omitted
        Suppressed: org.apache.lucene.index.CorruptIndexException: checksum passed (e8f14e93). possibly transient resource issue, or a Lucene or JVM bug (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/segments_1")))
                at org.apache.lucene.codecs.CodecUtil.checkFooter(CodecUtil.java:466)
                at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:434)
                ... 17 common frames omitted
2025-07-09 02:28:08,406 INFO  [WrapperSimpleAppMain] i.o.s.xodus.DefaultCommitInfoManager Caching code contribution info...

Robin Shen commented 6 months ago

Not sure if it is caused by insufficient resource issue. Will help a lot if you can find a way to reproduce this.
Davide Beatrici commented 6 months ago

Definitely. Since it only happened a few times so far I suspect it may be triggered by the indexing of repositories with many lines of code.

Most of the repositories I'm importing only contain an RPM spec file and one that defines the sources + hashes, but there are some that contain a lot of patch files.

Davide Beatrici commented 6 months ago

Another weird issue: agents often show up as offline after restarting OneDev despite saying "Connected to server" on their side. This time, since they didn't want to come back online even after waiting for a long period, I decided to remove and add them again.

This resulted in a deadlock and it took a few minutes to remove the agent: deadlock.txt

I suspect there may be a bug in the code that handles builds and agents, which may also explain why the latter show up as offline despite seemingly being online.

Fun fact: adding the build agent again makes it appear in the list, but it still shows up as offline! Commands such as "Restart" work just fine though!

After waiting for a few hours and without the import script running, I noticed OneDev was not accessible anymore... unfortunately I don't know when or how it happened because all log files are spammed with the following (with the project ID changing):

2025-07-10 02:48:25,112 ERROR [pool-3-thread-100] i.o.s.u.c.DefaultBatchWorkManager Error doing works
io.onedev.commons.utils.ExplicitException: Active server not found for project id: 19127
        at io.onedev.server.entitymanager.impl.DefaultProjectManager.getActiveServer(DefaultProjectManager.java:1197)
        at io.onedev.server.entitymanager.impl.DefaultProjectManager.runOnActiveServer(DefaultProjectManager.java:1282)
        at jdk.internal.reflect.GeneratedMethodAccessor122.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:50)
        at com.sun.proxy.$Proxy30.runOnActiveServer(Unknown Source)
        at io.onedev.server.git.service.DefaultGitService.runOnProjectServer(DefaultGitService.java:153)
        at io.onedev.server.git.service.DefaultGitService.getDefaultBranch(DefaultGitService.java:181)
        at io.onedev.server.model.Project.getDefaultBranch(Project.java:760)
        at jdk.internal.reflect.GeneratedMethodAccessor117.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.hibernate.proxy.pojo.bytebuddy.ByteBuddyInterceptor.intercept(ByteBuddyInterceptor.java:56)
        at org.hibernate.proxy.ProxyConfiguration$InterceptorDispatcher.intercept(ProxyConfiguration.java:95)
        at io.onedev.server.model.Project$HibernateProxy$swh9GkWH.getDefaultBranch(Unknown Source)
        at io.onedev.server.xodus.DefaultCommitInfoManager.doCollect(DefaultCommitInfoManager.java:489)
        at io.onedev.server.xodus.DefaultCommitInfoManager$8.lambda$doWorks$0(DefaultCommitInfoManager.java:1108)
        at io.onedev.server.persistence.DefaultSessionManager.lambda$run$0(DefaultSessionManager.java:108)
        at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
        at io.onedev.server.persistence.DefaultSessionManager.run(DefaultSessionManager.java:107)
        at jdk.internal.reflect.GeneratedMethodAccessor129.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:50)
        at com.sun.proxy.$Proxy28.run(Unknown Source)
        at io.onedev.server.xodus.DefaultCommitInfoManager$8.doWorks(DefaultCommitInfoManager.java:1100)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$2.doWorks(DefaultBatchWorkManager.java:106)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$1.run(DefaultBatchWorkManager.java:74)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:202)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:198)
        at io.onedev.server.security.SecurityUtils$1.call(SecurityUtils.java:598)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor.lambda$call$0(DefaultWorkExecutor.java:67)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at io.onedev.server.security.SecurityUtils.lambda$inheritSubject$1(SecurityUtils.java:587)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)

@robin Right now the OneDev instance is up and running, but agents are not coming online... any ideas on how to debug this?

Since attempting to cancel builds in the "waiting" status from the web UI didn't work, I did it manually directly in the database:

# DELETE FROM o_build WHERE o_status = 0;
DELETE 304

Robin Shen commented 6 months ago

Never encounter this issue before. Not sure if this is caused by server overload. Are you able to reproduce this issue with few projects?

Also, OneDev is designed for self-hosted usage scenario and does not heavily consider the use case of having a large number of projects. Curious why there are so many projects to be imported.

Davide Beatrici commented 6 months ago

Never encounter this issue before. Not sure if this is caused by server overload. Are you able to reproduce this issue with few projects?

This is what I see in the log right now:

00:23:00 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=45s908ms507µs890ns).
00:23:49 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=48s243ms284µs415ns).
00:25:15 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=45s806ms260µs226ns).
00:25:58 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=46s380ms115µs623ns).
00:29:59 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=46s417ms869µs760ns).
00:30:47 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=48s71ms850µs704ns).
00:32:44 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=52s179ms596µs518ns).
00:39:10 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=47s41ms190µs492ns).
00:40:26 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m16s180ms77µs643ns).
Pinging the JVM took 8 seconds to respond.
00:48:50 WARN  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=46s281ms565µs189ns).

Both threads at 100% and the RAM that is allocated to the JVM is probably full. Now that I've deleted the stuck builds I'm curious to see if agents work again once the web interface is reachable again.

Unfortunately I have yet to discover how to make a reproducible example.

Also, OneDev is designed for self-hosted usage scenario and does not heavily consider the use case of having a large number of projects. Curious why there are so many projects to be imported.

A link is worth a thousand words: https://github.com/OpenMandrivaAssociation

Robin Shen commented 6 months ago

Thanks for the info. Originally created for self-hosting scenario, OneDev never tested with tens of thousands of repositories before. Many places may need to be fixed/tuned for your use case. I'd suggest to move step by step. Before connecting agents and run builds, please make sure all 25k repositories have been imported and indexed. Then check the cpu and memory usage and make sure the system is stable before going forward.
Davide Beatrici commented 6 months ago

Thank you very much for your help so far!

I firmly believe OneDev is better compared to the competitors and that's why I ultimately chose it in place of more popular choices.

To be honest, I never expected the import process to be smooth; I fully understand this is an extreme scenario. I'm willing to provide testing and metrics to make the software more robust and fix eventual bugs that are encountered along the way.

Davide Beatrici commented 6 months ago

I updated to 12.0.0 and found this in the log:

Exception in thread "Thread-0" java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
        at io.onedev.server.event.Listener.notify(Listener.java:21)
        at io.onedev.server.event.DefaultListenerRegistry.invokeListeners(DefaultListenerRegistry.java:104)
        at io.onedev.server.event.DefaultListenerRegistry.post(DefaultListenerRegistry.java:155)
        at io.onedev.server.persistence.TransactionInterceptor$1.call(TransactionInterceptor.java:23)
        at io.onedev.server.persistence.DefaultTransactionManager.lambda$call$0(DefaultTransactionManager.java:66)
        at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
        at io.onedev.server.persistence.DefaultTransactionManager.call(DefaultTransactionManager.java:57)
        at io.onedev.server.persistence.TransactionInterceptor.invoke(TransactionInterceptor.java:18)
        at io.onedev.server.OneDev.lambda$preStop$3(OneDev.java:263)
        at io.onedev.server.persistence.DefaultSessionManager.lambda$run$0(DefaultSessionManager.java:108)
        at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
        at io.onedev.server.persistence.DefaultSessionManager.run(DefaultSessionManager.java:107)
        at io.onedev.server.OneDev.preStop(OneDev.java:263)
        at io.onedev.commons.loader.DefaultPluginManager.stop(DefaultPluginManager.java:54)
        at io.onedev.commons.loader.AppLoader.stop(AppLoader.java:81)
        at io.onedev.commons.bootstrap.Bootstrap$1.run(Bootstrap.java:193)
Caused by: java.lang.reflect.InvocationTargetException
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.onedev.server.event.Listener.notify(Listener.java:19)
        ... 15 more
Caused by: java.lang.IllegalArgumentException: Name cannot be null.
        at org.quartz.utils.Key.<init>(Key.java:62)
        at org.quartz.JobKey.<init>(JobKey.java:62)
        at io.onedev.server.taskschedule.DefaultTaskScheduler.unschedule(DefaultTaskScheduler.java:99)
        at io.onedev.server.entitymanager.impl.DefaultReviewedDiffManager.on(DefaultReviewedDiffManager.java:87)
        ... 20 more

Aside from that, the resource usage now appears to be under control, at least at idle. Unfortunately there is still no way to make agents appear online...

The server's log doesn't say anything, any ideas on how to debug this?

Robin Shen commented 6 months ago

This error does not matter, and will be fixed though.

For agent not appearing issue, please remove all agents at OneDev server side via "Administration / Agents" page if there are any. And stop all agent processes. Then run only one of them, and show me agent log as well as server log. If agent does not appear for 1 minute, please get a thread dump by running "server.sh dump" as same user running OneDev process. Threads will be dumped into logs/console.log.

Also curious how much memory OneDev consumes now after 25k projects are imported and indexed.

Davide Beatrici commented 6 months ago

Sorry for the delay. I had already tried to stop and delete all agents, but same problem: launching a new one resulted in it appearing in the list, but marked as offline despite commands (such as restart) working immediately.

Log

2025-07-16 17:07:21,780 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=45s803ms3µs364ns).
2025-07-16 17:08:24,581 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m2s801ms583µs224ns).
2025-07-16 17:12:57,188 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=46s362ms966µs37ns).
2025-07-16 17:15:28,619 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=50s363ms598µs748ns).
2025-07-16 17:16:24,174 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=58s300ms815µs189ns).
2025-07-16 17:17:45,531 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=50s35ms424µs852ns).
2025-07-16 17:22:28,866 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=48s9ms19µs948ns).
2025-07-16 17:27:57,691 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=55s682ms58µs368ns).
2025-07-16 17:27:54,886 ERROR [hz.172.17.0.2:5710.scheduled.thread-] c.h.s.i.e.ExecutionService [172.17.0.2]:5710 [a64dc8cc68beb300fd9dadaefa7d91579ef439f5e1b97a9b454ef8ffa49492fe] [5.3.5] Failed to execute java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@18d117b4[Completed exceptionally: java.lang.OutOfMemoryError: Java heap space]
java.lang.OutOfMemoryError: Java heap space
2025-07-16 17:27:54,154 WARN  [qtp1817541862-392] o.e.j.util.thread.QueuedThreadPool
java.lang.OutOfMemoryError: Java heap space
2025-07-16 17:27:54,150 ERROR [DefaultQuartzScheduler_Worker-4] org.quartz.core.JobRunShell Job DEFAULT.93234e9f-9288-4209-9a6a-8d691f4552e6 threw an unhandled Exception:
java.lang.OutOfMemoryError: Java heap space
2025-07-16 17:27:57,697 ERROR [DefaultQuartzScheduler_Worker-4] org.quartz.core.ErrorLogger Job (DEFAULT.93234e9f-9288-4209-9a6a-8d691f4552e6 threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception.
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: java.lang.OutOfMemoryError: Java heap space
2025-07-16 17:28:28,143 WARN  [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m40s336ms221µs771ns).
2025-07-16 17:28:28,205 ERROR [hz.172.17.0.2:5710.partition-operation.thread-1] c.h.m.i.o.MultipleEntryOperation [172.17.0.2]:5710 [a64dc8cc68beb300fd9dadaefa7d91579ef439f5e1b97a9b454ef8ffa49492fe] [5.3.5] Java heap space
java.lang.OutOfMemoryError: Java heap space
2025-07-16 17:28:33,401 ERROR [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Error booting application
java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
	at io.onedev.server.event.Listener.notify(Listener.java:21)
	at io.onedev.server.event.DefaultListenerRegistry.invokeListeners(DefaultListenerRegistry.java:104)
	at io.onedev.server.event.DefaultListenerRegistry.post(DefaultListenerRegistry.java:155)
	at io.onedev.server.persistence.TransactionInterceptor$1.call(TransactionInterceptor.java:23)
	at io.onedev.server.persistence.DefaultTransactionManager.lambda$call$0(DefaultTransactionManager.java:66)
	at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
	at io.onedev.server.persistence.DefaultTransactionManager.call(DefaultTransactionManager.java:57)
	at io.onedev.server.persistence.TransactionInterceptor.invoke(TransactionInterceptor.java:18)
	at io.onedev.server.OneDev.postStart(OneDev.java:249)
	at io.onedev.server.persistence.SessionInterceptor$1.call(SessionInterceptor.java:23)
	at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
	at io.onedev.server.persistence.SessionInterceptor.invoke(SessionInterceptor.java:18)
	at io.onedev.commons.loader.DefaultPluginManager.start(DefaultPluginManager.java:48)
	at io.onedev.commons.loader.AppLoader.start(AppLoader.java:74)
	at io.onedev.commons.bootstrap.Bootstrap.main(Bootstrap.java:200)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:349)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.reflect.InvocationTargetException: null
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at io.onedev.server.event.Listener.notify(Listener.java:19)
	... 20 common frames omitted
Caused by: com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active!
	at com.hazelcast.spi.impl.operationservice.impl.InvocationRegistry.register(InvocationRegistry.java:140)
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:587)
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:558)
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:241)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:71)
	at com.hazelcast.spi.impl.operationservice.impl.InvokeOnPartitions.retryPartition(InvokeOnPartitions.java:140)
	at com.hazelcast.spi.impl.operationservice.impl.InvokeOnPartitions.access$200(InvokeOnPartitions.java:45)
	at com.hazelcast.spi.impl.operationservice.impl.InvokeOnPartitions$FirstAttemptExecutionCallback.accept(InvokeOnPartitions.java:217)
	at com.hazelcast.spi.impl.operationservice.impl.InvokeOnPartitions$FirstAttemptExecutionCallback.accept(InvokeOnPartitions.java:175)
	at com.hazelcast.spi.impl.AbstractInvocationFuture$WhenCompleteNode.lambda$execute$0(AbstractInvocationFuture.java:1570)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
	at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
	at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111)
2025-07-16 17:28:33,403 INFO  [Thread-0] io.onedev.commons.loader.AppLoader Stopping application...
2025-07-16 17:30:03,754 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-07-16 17:30:03,758 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-07-16 17:30:40,233 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-07-16 17:31:27,716 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-07-16 17:31:29,616 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-07-16 17:31:32,771 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-07-16 17:31:49,044 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-07-16 17:31:49,233 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-07-16 17:32:08,396 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...

I decided to upgrade the VPS, bumping the number of cores from 2 to 4 and the amount of RAM from 6 to 14 GB. I also let the JVM use a bigger heap by setting _JAVA_OPTIONS="-XX:MaxRAMPercentage=85" in the environment.

The problem disappeared and I finally finished the import process yesterday. Looks like heap memory was the issue all along:

Screenshots

The sudden decrease shown in the last 4 is due to me pressing on "Force Garbage Collection". Is there perhaps a memory leak somewhere?

Also, I just realized I have a "Pull from mirror" job that is scheduled to run every day... for every single one of those repositories, which is insane. Is there perhaps a way to trigger the job when someone pushes to the GitHub repository?

Robin Shen commented 6 months ago

Obviously there is a memory issue previously and it prevents agent working normally. See below error from the log:

java.lang.OutOfMemoryError: Java heap space

For the sudden decrease shown in the last 4 is due to pressing on "Force Garbage Collection", this is normal as GC runs lazily. When memory runs short, JVM will run GC automatically even if you do not run it manually.

Also, I just realized I have a "Pull from mirror" job that is scheduled to run every day... for every single one of those repositories, which is insane. Is there perhaps a way to trigger the job when someone pushes to the GitHub repository?

It is possible to run pull job only when there are changes at remote side. Check step 3 of this tutorial for details.

Davide Beatrici commented 6 months ago

Thank you. Looks like there is a missing screenshot:

In my case I ended up creating a GitHub app that I then installed in the organization, with a listener for the push events. Would you like me to document that?

I'm encountering an issue though: the job only succeeds for the default branch, with every other I see this in the log:

 java.lang.RuntimeException: Http request failed (status code: 500, error message: Invalid access token)
	at io.onedev.k8shelper.KubernetesHelper.checkStatus(KubernetesHelper.java:342)
	at io.onedev.k8shelper.KubernetesHelper.runServerStep(KubernetesHelper.java:853)
	at io.onedev.k8shelper.KubernetesHelper.runServerStep(KubernetesHelper.java:812)
	at io.onedev.agent.AgentSocket$4.doExecute(AgentSocket.java:844)
	at io.onedev.agent.AgentSocket$4.lambda$execute$1(AgentSocket.java:720)
	at io.onedev.agent.ExecutorUtils.runStep(ExecutorUtils.java:100)
	at io.onedev.agent.AgentSocket$4.execute(AgentSocket.java:717)
	at io.onedev.k8shelper.LeafFacade.execute(LeafFacade.java:12)
	at io.onedev.k8shelper.CompositeFacade.execute(CompositeFacade.java:35)
	at io.onedev.agent.AgentSocket.executeDockerJob(AgentSocket.java:632)
	at io.onedev.agent.AgentSocket.service(AgentSocket.java:1029)
	at io.onedev.agent.AgentSocket.lambda$onMessage$2(AgentSocket.java:268)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

I created the access token with a custom role that has no permissions except "Run job":

Robin Shen commented 6 months ago

Please attach an example project demonstrating the issue. Also show me screenshot of the webhook settings at GitHub side.

Davide Beatrici commented 6 months ago

The webhook is called by my application, in the following form:

https://<onedev>/~api/trigger-job?project=<project>&job=<job>&branch=<branch>&access-token=<access-token>

This is the job definition:

- name: Pull from mirror
  steps:
  - !PullRepository
    name: Pull from GitHub
    remoteUrl: https://github.com/@property:github_org@/@project_name@
    passwordSecret: github-org-access-token
    accessTokenSecret: github-org-access-token
    refs: refs/heads/* refs/tags/*
    withLfs: true
    force: true
    condition: SUCCESSFUL
    optional: false
  retryCondition: never
  maxRetries: 3
  retryDelay: 30
  timeout: 14400

Failed jobs succeed when they're restarted after setting their corresponding branch as default.

Robin Shen commented 6 months ago
passwordSecret: github-org-access-token accessTokenSecret: github-org-access-token

These two settings are using same access token secret, which is incorrect. passwordSecret is for accessing GitHub repository, and accessTokenSecret is for accessing OneDev repository. Also make sure that these secrets can be accessed by other branches instead of just the default branch.
Davide Beatrici commented 6 months ago

Thank you, the wrong access token was indeed the issue. And it's also described why it's not required for the default branch:

Specify a job secret whose value is an access token with management permission for above project. Note that access token is not required if sync to current or child project and build commit is reachable from default branch

The management permission allows full r/w access to the project though... is there no stricter way to achieve this?

History
Robin Shen commented 6 months ago

This step allows to override all branches/tags of the repository ignoring branch protection rules, it is effectively the project management permission.
Davide Beatrici commented 6 months ago

Doesn't project management also allow to edit settings that are not related to branches/tags?
Robin Shen commented 6 months ago

That is true, but there is no separate permission to overwrite all branch/tags without respecting protection rules. Currently there is no plan to add that permission only for this purpose.
Davide Beatrici removed comment 6 months ago
Davide Beatrici commented 6 months ago
No problem. I think I will always trigger the job on the default branch, as it can pull in both branches and tags even without an access token.

On that note, can we change the endpoint so that it triggers the job on the default branch when unspecified?

https://<onedev>/~api/trigger-job?project=<project>&job=<job>&access-token=<access-token>

History
Robin Shen commented 6 months ago

On that note, can we change the endpoint so that it triggers the job on the default branch when unspecified?

Will be addressed via OD-2502

Davide Beatrici commented 5 months ago

I'm now importing another organization that has a sane amount of repositories. An exception happened when pressing on Next after a long delay:

Log

org.apache.wicket.WicketRuntimeException: Method onFormSubmitted of interface org.apache.wicket.markup.html.form.IFormSubmitListener targeted at [Form [Component id = form]] on component [Form [Component id = form]] threw an exception
	at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:281)
	at org.apache.wicket.RequestListenerInterface.invoke(RequestListenerInterface.java:220)
	at org.apache.wicket.core.request.handler.ListenerInterfaceRequestHandler.invokeListener(ListenerInterfaceRequestHandler.java:241)
	at org.apache.wicket.core.request.handler.ListenerInterfaceRequestHandler.respond(ListenerInterfaceRequestHandler.java:234)
	at org.apache.wicket.request.cycle.RequestCycle$HandlerExecutor.respond(RequestCycle.java:892)
	at org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:64)
	at org.apache.wicket.request.cycle.RequestCycle.execute(RequestCycle.java:261)
	at org.apache.wicket.request.cycle.RequestCycle.processRequest(RequestCycle.java:218)
	at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:289)
	at org.apache.wicket.protocol.ws.AbstractUpgradeFilter.processRequestCycle(AbstractUpgradeFilter.java:70)
	at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:203)
	at org.apache.wicket.protocol.http.WicketServlet.doPost(WicketServlet.java:159)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at io.onedev.server.web.DefaultWicketServlet.lambda$service$0(DefaultWicketServlet.java:48)
	at io.onedev.server.persistence.DefaultSessionManager.lambda$run$0(DefaultSessionManager.java:108)
	at io.onedev.server.persistence.DefaultSessionManager.call(DefaultSessionManager.java:90)
	at io.onedev.server.persistence.DefaultSessionManager.run(DefaultSessionManager.java:107)
	at io.onedev.server.web.DefaultWicketServlet.service(DefaultWicketServlet.java:42)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656)
	at com.google.inject.servlet.DefaultFilterPipeline.dispatch(DefaultFilterPipeline.java:47)
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GoGetFilter.doFilter(GoGetFilter.java:90)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GitLfsFilter.doFilter(GitLfsFilter.java:502)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GitFilter.doFilter(GitFilter.java:395)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.security.CorsFilter.doFilter(CorsFilter.java:47)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.jetty.DisableTraceFilter.doFilter(DisableTraceFilter.java:28)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	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:409)
	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.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.reflect.InvocationTargetException
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:270)
	... 90 more
Caused by: java.lang.NullPointerException
	at io.onedev.server.plugin.imports.github.ImportServer.buildIssueImportOption(ImportServer.java:202)
	at io.onedev.server.plugin.imports.github.GitHubProjectImporter$3.newSetting(GitHubProjectImporter.java:64)
	at io.onedev.server.plugin.imports.github.GitHubProjectImporter$3.newSetting(GitHubProjectImporter.java:52)
	at io.onedev.server.web.util.ImportStep.init(ImportStep.java:30)
	at io.onedev.server.web.component.wizard.WizardPanel$5.onSubmit(WizardPanel.java:118)
	at org.apache.wicket.markup.html.form.Form.delegateSubmit(Form.java:1312)
	at org.apache.wicket.markup.html.form.Form.process(Form.java:976)
	at org.apache.wicket.markup.html.form.Form.onFormSubmitted(Form.java:797)
	at org.apache.wicket.markup.html.form.Form.onFormSubmitted(Form.java:687)
	... 95 more

A second attempt resulted in a 504 error, but reloading the page showed the final step and it's now importing just fine.

Robin Shen commented 5 months ago

As mentioned earlier, the UI currently is not able to import large amounts of repositories. Please use restful api to do the job.
Davide Beatrici commented 5 months ago

No problem, just wanted to make sure you're aware it also happens with a way lower number of repositories. 115 to be precise.
Davide Beatrici commented 5 months ago

Unfortunately the Git server and build agents issue is still there... it wasn't due to scarce resources.

Do you have any suggestions on how to debug this? I suspect it's related to the startup process, which usually takes at least 30 minutes due to the "Checking projects" step.

History
Robin Shen commented 5 months ago

Please stop all your build agents, and then connect a single agent for testing. Check server log to see if there are any errors printed.

Also please check heap memory usage via Administration / System Maintenance / Server Information. Please force a GC and post the screenshot.

Davide Beatrici commented 5 months ago

The Git server issue is rare and got fixed with a restart.

I see two identical errors in the log and I happen to have that number of agents connected:

Log

2025-07-29 08:58:41,293 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-07-29 08:58:41,295 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-07-29 08:58:56,827 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-07-29 08:59:29,414 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-07-29 08:59:49,903 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-07-29 09:43:01,873 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-07-29 09:43:07,752 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-07-29 09:43:37,087 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-07-29 09:43:38,438 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-07-29 09:44:18,807 ERROR [qtp473220910-124] i.o.s.security.ExceptionHandleFilter Error processing servlet request
io.onedev.server.exception.ServerNotReadyException: Server not ready
	at io.onedev.server.agent.ServerSocketServlet.service(ServerSocketServlet.java:44)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656)
	at com.google.inject.servlet.DefaultFilterPipeline.dispatch(DefaultFilterPipeline.java:47)
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GoGetFilter.doFilter(GoGetFilter.java:90)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GitLfsFilter.doFilter(GitLfsFilter.java:502)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GitFilter.doFilter(GitFilter.java:395)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.security.CorsFilter.doFilter(CorsFilter.java:47)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.jetty.DisableTraceFilter.doFilter(DisableTraceFilter.java:28)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	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.produce(EatWhatYouKill.java:137)
	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.base/java.lang.Thread.run(Thread.java:829)
2025-07-29 09:44:18,807 ERROR [qtp473220910-129] i.o.s.security.ExceptionHandleFilter Error processing servlet request
io.onedev.server.exception.ServerNotReadyException: Server not ready
	at io.onedev.server.agent.ServerSocketServlet.service(ServerSocketServlet.java:44)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656)
	at com.google.inject.servlet.DefaultFilterPipeline.dispatch(DefaultFilterPipeline.java:47)
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GoGetFilter.doFilter(GoGetFilter.java:90)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GitLfsFilter.doFilter(GitLfsFilter.java:502)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.git.GitFilter.doFilter(GitFilter.java:395)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.security.CorsFilter.doFilter(CorsFilter.java:47)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at io.onedev.server.jetty.DisableTraceFilter.doFilter(DisableTraceFilter.java:28)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	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.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
	at java.base/java.lang.Thread.run(Thread.java:829)

Robin Shen commented 5 months ago

This message io.onedev.server.exception.ServerNotReadyException: Server not ready means that you need to wait for server to get ready before connecting agents. It is still starting.
Davide Beatrici commented 5 months ago

Alright, that's what I suspected. The thing is that it takes more than an hour to get ready every time it's restarted... can we perhaps dump the running tasks list in order to understand what it's doing?
Robin Shen commented 5 months ago

I see that most of time is spent on checking projects. OneDev needs to go through each git repository to check if it is in good state, and this can be slow if there are many many repositories. I will check if this can be improved though.
Davide Beatrici commented 5 months ago

That would be really helpful, thanks!

By the way, according to the log it's now spending even more time "Caching build info". Thinking about it, the cause is obvious: remember when I mentioned I made the mistake of leaving a "pull from mirror" cron job set to run once every day for each repository?

Well, I'm pretty sure there are approximately 200k builds in the history...
Robin Shen commented 5 months ago

If it is still starting, please get a stack trace by running "/path/to/onedev/bin/server.sh dump" as the OneDev user. The thread dump will be generated in "/path/to/onedev/logs/console.log", and you may attach the file here.
Davide Beatrici commented 5 months ago
# /opt/onedev/bin/server.sh dump Dumping OneDev... OneDev was not running.

And no thread dump is generated... the command is run in the container as the OneDev user (root).
Robin Shen commented 5 months ago

please exec into the container to run the command

Davide Beatrici commented 5 months ago

That's what I did, looks like there is something wrong with the getpid function that is called here:

dump() {
    eval echo `gettext 'Dumping $APP_LONG_NAME...'`
    getpid
    if [ "X$pid" = "X" ]
    then
        eval echo `gettext '$APP_LONG_NAME was not running.'`
    else
        kill -3 $pid

        if [ $? -ne 0 ]
        then
            eval echo `gettext 'Failed to dump $APP_LONG_NAME.'`
            exit 1
        else
            eval echo `gettext 'Dumped $APP_LONG_NAME.'`
        fi
    fi
}

Running kill -3 manually worked, here's the result: onedev_dump.txt

Robin Shen commented 5 months ago

Startup speed of build OD-6538 is much faster, even for massive number of projects.

Davide Beatrici commented 5 months ago

Thank you for your work, as usual.

upgrade_log.txt

Startup log

2025-08-03 21:11:27,636 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-08-03 21:11:27,638 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-08-03 21:11:28,270 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-08-03 21:12:08,645 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-08-03 21:25:44,280 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-08-03 21:25:45,653 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-08-03 21:25:50,992 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-08-03 21:25:56,054 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-08-03 21:26:00,628 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-08-03 21:26:40,205 ERROR [pool-3-thread-2] i.o.s.u.c.DefaultBatchWorkManager Error doing works
java.lang.RuntimeException: org.apache.lucene.index.CorruptIndexException: file mismatch, expected id=alsj4yvv73o82j4c9gsdy7ed1, got=ejm0az804g2bckvep4hsxl46e (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
        at io.onedev.server.util.lucene.LuceneUtils.callWithWriter(LuceneUtils.java:93)
        at io.onedev.server.search.entitytext.EntityTextManager.callWithWriter(EntityTextManager.java:247)
        at io.onedev.server.search.entitytext.EntityTextManager$1.doWorks(EntityTextManager.java:289)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$2.doWorks(DefaultBatchWorkManager.java:106)
        at io.onedev.server.util.concurrent.DefaultBatchWorkManager$1.run(DefaultBatchWorkManager.java:74)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:202)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor$1.call(DefaultWorkExecutor.java:198)
        at io.onedev.server.security.SecurityUtils$1.call(SecurityUtils.java:598)
        at io.onedev.server.util.concurrent.DefaultWorkExecutor.lambda$call$0(DefaultWorkExecutor.java:67)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at io.onedev.server.security.SecurityUtils.lambda$inheritSubject$1(SecurityUtils.java:587)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.apache.lucene.index.CorruptIndexException: file mismatch, expected id=alsj4yvv73o82j4c9gsdy7ed1, got=ejm0az804g2bckvep4hsxl46e (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
        at org.apache.lucene.codecs.CodecUtil.checkIndexHeaderID(CodecUtil.java:351)
        at org.apache.lucene.codecs.CodecUtil.checkIndexHeader(CodecUtil.java:256)
        at org.apache.lucene.codecs.lucene86.Lucene86SegmentInfoFormat.read(Lucene86SegmentInfoFormat.java:95)
        at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:357)
        at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:291)
        at org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:165)
        at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1089)
        at io.onedev.server.util.lucene.LuceneUtils.callWithWriter(LuceneUtils.java:82)
        ... 13 common frames omitted
        Suppressed: org.apache.lucene.index.CorruptIndexException: checksum passed (512d51a8). possibly transient resource issue, or a Lucene or JVM bug (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/_0.si")))
                at org.apache.lucene.codecs.CodecUtil.checkFooter(CodecUtil.java:466)
                at org.apache.lucene.codecs.lucene86.Lucene86SegmentInfoFormat.read(Lucene86SegmentInfoFormat.java:143)
                ... 18 common frames omitted
        Suppressed: org.apache.lucene.index.CorruptIndexException: checksum passed (e8f14e93). possibly transient resource issue, or a Lucene or JVM bug (resource=BufferedChecksumIndexInput(MMapIndexInput(path="/opt/onedev/site/index/issue/segments_1")))
                at org.apache.lucene.codecs.CodecUtil.checkFooter(CodecUtil.java:466)
                at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:434)
                ... 17 common frames omitted
2025-08-03 21:38:11,091 WARN  [sshd-SshServer[783ce713](port=6611)-nio2-thread-2] o.a.s.s.session.ServerSessionImpl exceptionCaught(ServerSessionImpl[null@/162.142.125.210:42870])[state=Opened] SshException: Unable to negotiate key exchange for server host key algorithms (client: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,ssh-dss,ssh-ed25519,[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,ssh-dss,ssh-ed25519 / server: rsa-sha2-512,rsa-sha2-256)
2025-08-03 22:29:48,787 INFO  [WrapperSimpleAppMain] io.onedev.server.OneDev Server is ready at https://git.houseof.software.

"Checking projects" took less than 15 minutes, but unfortunately "Caching build info" took more than an hour...

Robin Shen commented 5 months ago

Looks like the Lucene index is corrupted for some reason. Please delete all files under /opt/onedev/site/index/issue/, and try again. If still stuck at caching build info for a long time. Please get a stack trace.

Davide Beatrici commented 5 months ago

Looks like the indexes were not being updated, possibly due to a write.lock being present:

$ ls -l code
total 4
-rw-r--r-- 1 root root 69 Jun 26 05:57 segments_1
-rw-r--r-- 1 root root  0 Jun 26 05:57 write.lock

$ ls -l code_comment
total 16
-rw-r--r-- 1 root root  341 Jun 25 03:40 _0.cfe
-rw-r--r-- 1 root root 1283 Jun 25 03:40 _0.cfs
-rw-r--r-- 1 root root  423 Jun 25 03:40 _0.si
-rw-r--r-- 1 root root  154 Jun 25 03:40 segments_1
-rw-r--r-- 1 root root    0 Jun 25 03:40 write.lock

$ ls -l issue
total 32
-rw-r--r-- 1 root root  341 Jun 25 03:40 _0.cfe
-rw-r--r-- 1 root root 1283 Jun 25 03:40 _0.cfs
-rw-r--r-- 1 root root  423 Jun 25 03:40 _0.si
-rw-r--r-- 1 root root  415 Jun 27 05:33 _1.cfe
-rw-r--r-- 1 root root 3062 Jun 27 05:33 _1.cfs
-rw-r--r-- 1 root root  423 Jun 27 05:33 _1.si
-rw-r--r-- 1 root root  154 Jul  5 21:19 segments_1
-rw-r--r-- 1 root root  236 Jun 27 05:33 segments_2
-rw-r--r-- 1 root root    0 Jun 25 03:40 write.lock

$ ls -l pull_request
total 16
-rw-r--r-- 1 root root  341 Jun 25 03:40 _0.cfe
-rw-r--r-- 1 root root 1283 Jun 25 03:40 _0.cfs
-rw-r--r-- 1 root root  423 Jun 25 03:40 _0.si
-rw-r--r-- 1 root root  154 Jun 25 03:40 segments_1
-rw-r--r-- 1 root root    0 Jun 25 03:40 write.lock

After moving the index folder to another place and restarting OneDev, it's taking a long time to fully prepare (agents are offline):

Server log

2025-08-04 17:55:42,281 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-08-04 17:55:42,283 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-08-04 17:55:53,885 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-08-04 17:56:25,318 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-08-04 17:56:47,610 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-08-04 17:56:49,256 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-08-04 17:56:50,044 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-08-04 17:56:50,283 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-08-04 17:57:08,380 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-08-04 18:19:08,930 ERROR [qtp2010895323-101] i.o.s.security.ExceptionHandleFilter Error processing servlet request
io.onedev.server.exception.ServerNotReadyException: Server not ready
        at io.onedev.server.agent.ServerSocketServlet.service(ServerSocketServlet.java:44)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
        at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656)
        at com.google.inject.servlet.DefaultFilterPipeline.dispatch(DefaultFilterPipeline.java:47)
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.git.GoGetFilter.doFilter(GoGetFilter.java:90)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.git.GitLfsFilter.doFilter(GitLfsFilter.java:502)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.git.GitFilter.doFilter(GitFilter.java:395)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
        at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
        at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
        at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
        at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
        at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.security.CorsFilter.doFilter(CorsFilter.java:47)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.jetty.DisableTraceFilter.doFilter(DisableTraceFilter.java:28)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        at org.eclipse.jetty.server.Server.handle(Server.java:516)
        at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
        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.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
        at java.base/java.lang.Thread.run(Thread.java:829)
2025-08-04 18:19:08,930 ERROR [qtp2010895323-95] i.o.s.security.ExceptionHandleFilter Error processing servlet request
io.onedev.server.exception.ServerNotReadyException: Server not ready
        at io.onedev.server.agent.ServerSocketServlet.service(ServerSocketServlet.java:44)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
        at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656)
        at com.google.inject.servlet.DefaultFilterPipeline.dispatch(DefaultFilterPipeline.java:47)
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.git.GoGetFilter.doFilter(GoGetFilter.java:90)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.git.GitLfsFilter.doFilter(GitLfsFilter.java:502)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.git.GitFilter.doFilter(GitFilter.java:395)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
        at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
        at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
        at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
        at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
        at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.security.CorsFilter.doFilter(CorsFilter.java:47)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at io.onedev.server.jetty.DisableTraceFilter.doFilter(DisableTraceFilter.java:28)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        at org.eclipse.jetty.server.Server.handle(Server.java:516)
        at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
        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.produce(EatWhatYouKill.java:137)
        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.base/java.lang.Thread.run(Thread.java:829)
2025-08-04 19:44:30,973 INFO  [WrapperSimpleAppMain] io.onedev.server.OneDev Server is ready at https://git.houseof.software.

stacktrace.txt

Robin Shen commented 5 months ago

Looks like the indexes were not being updated, possibly due to a write.lock being present:

It takes time to re-index

Thanks for the stack trace, OneDev 12.0.4 is released to further increase startup speed

Davide Beatrici commented 5 months ago

Way better, thank you very much!

2025-08-07 20:19:09,179 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-08-07 20:19:09,182 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-08-07 20:19:09,643 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-08-07 20:19:39,633 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-08-07 20:19:39,879 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-08-07 20:19:40,030 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-08-07 20:20:08,284 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-08-07 20:20:08,662 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-08-07 20:20:26,781 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-08-07 20:47:56,778 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Deleting directory marked for deletion: /opt/onedev/site/projects/25874
2025-08-07 20:49:05,362 INFO  [WrapperSimpleAppMain] io.onedev.server.OneDev Server is ready at https://git.houseof.software.

Robin Shen commented 5 months ago

Thanks for the feedback. Seems that project checking is dominating startup time. Next time when you start up OneDev, please get me another stack trace while it is waiting for project checking.

Davide Beatrici commented 5 months ago

A restart resulted in this:

2025-08-08 01:48:36,941 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-08-08 01:48:36,944 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-08-08 01:48:45,041 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-08-08 01:49:09,707 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-08-08 01:49:10,629 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-08-08 01:49:11,011 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-08-08 01:49:11,315 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-08-08 01:49:34,260 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-08-08 01:53:46,165 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-08-08 01:54:30,461 INFO  [WrapperSimpleAppMain] io.onedev.server.OneDev Server is ready at https://git.houseof.software.

Is it expected or should I try again?

Robin Shen commented 5 months ago

This is expected. No need to restart now. Just get a stack trace if you encounter slow startup next time.

👍 1

Davide Beatrici commented 4 months ago

Updating from 12.0.4 to 12.0.7 resulted in "Checking projects" taking a long time again.

stacktrace_1.txt stacktrace_2.txt stacktrace_3.txt

2025-08-25 11:06:08,273 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Launching application from '/opt/onedev'...
2025-08-25 11:06:08,276 INFO  [WrapperSimpleAppMain] i.onedev.commons.bootstrap.Bootstrap Cleaning temp directory...
2025-08-25 11:06:08,862 INFO  [WrapperSimpleAppMain] io.onedev.commons.loader.AppLoader Starting application...
2025-08-25 11:06:26,472 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildMetricManager Caching build metric info...
2025-08-25 11:06:43,984 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultProjectManager Checking projects...
2025-08-25 11:39:01,980 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultBuildParamManager Caching build param info...
2025-08-25 11:39:19,932 INFO  [WrapperSimpleAppMain] i.o.s.e.i.DefaultAgentAttributeManager Caching agent attribute info...
2025-08-25 11:39:22,618 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultIssueManager Caching issue info...
2025-08-25 11:39:26,549 INFO  [WrapperSimpleAppMain] i.o.s.e.impl.DefaultBuildManager Caching build info...
2025-08-25 11:45:14,312 INFO  [WrapperSimpleAppMain] io.onedev.server.OneDev Server is ready at https://git.houseof.software.

Robin Shen commented 4 months ago

The time is spent reading some project meta files from disk. This is inevitable as OneDev needs to scan all projects at startup to ensure its integrity.
Davide Beatrici commented 4 months ago

Sounds good, the server is running on a hard drive and I never performed a benchmark. It may be quite slow.
Login to comment

Type	Question
Priority	Normal
Assignee	Robin Shen
Labels	No labels

Issue Votes (0)

Watchers (2)

Reference

OD-2476