eikek
dockerized docspell resulting jobs in waiting forever
Hello,
i have deployed this fantastic piece of software on my central docker server. I used docker compose approach with minor modifications (aded traefik for front). The application(s) containers come up, no errors in starting, no errors with loading. Once in, I choose to load one 3 page document and - nothing. then go check jobs and all I see is job waiting for like 30min now. Nothing moves ahead. In logs, I see no errors in any of containers, the only thing that comes up periodically is in the restserver:
2024.03.22 16:05:02:0000 [io-comp...] [ERROR] org.http4s.ember.server.EmberServerBuilderCompanionPlatform - WebSocket connection terminated with exception
java.util.concurrent.TimeoutException: 60 seconds
at timeout @ org.http4s.ember.core.Util$.timeoutMaybe(Util.scala:106)
at main$ @ docspell.restserver.Main$.main(Main.scala:14)
at timeout @ org.http4s.ember.core.Util$.timeoutMaybe(Util.scala:106)
at timeout @ org.http4s.ember.core.Util$.timeoutMaybe(Util.scala:106)
Beyond that error, there is nothing. I see tmp/ folder getting populated but that is about it. Any insight to what to check at all, what to do or try to repair? The compose file I use is attached to this post. Thanks in advance!
NOTE: the database is externally hosted pg
Hello @damjankumin, it could be that the two components (joex and server) are not seeing each other. Can you check whether you can connect from one to the other? The timeout exception also indicates some connection problems. Of course, just a guess. Can you create accounts and log in successfully? If so, then the postgres connection is good. If the job is in state waiting it means that joex didn't get notified. You can do so manually by sending a post request (just to see if it works in general)
curl -XPOST http://docspell-joex:7878/api/v1/notify
So i could create username, also generate organisation.. in the startup of containers I could also see that database connection is successfully done. I made sure that all containers are on the same docker network (its the network where all containers are residing) - only difference is the restserver that also has traefik network attached so that it is also accessible from outside docker network.
Now I just exec into restserver and ran suggested command, and here is the result:
/opt # curl -XPOST http://docspell-joex:7878/api/v1/notify
{"success":true,"message":"Schedulers notified."}/opt #
/opt #
Seems that notification is just fine. Also just double confirmed, all containers are on the same net, even IP addresses go one after another (as created)..
Ok so that means joex should be correctly notified, if it has the correct base-url configured. After you initiated this curl, has the job in the job queue been picked up and processed? Do you see any interesting logs for joex?
once submitted notification, the jobs have not progresses in pipeline... nothing happened actually. In logs, the only thing I see what I posted above, that was from restserver - joex has nothing, apart from regular startup log entries, all i see is
2024.03.22 15:57:14:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.22 15:57:14:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
Hm, very strange to me. So just to re-assure I understood correctly: there is a job in the queue in state "waiting", after running this curl, joex didn't print any logs and the job is still there in state "waiting"?
Can you perhaps restart joex with more logging enabled, maybe set this env variable for joex:
DOCSPELL_SERVER_LOGGING_LEVELS_DOCSPELL="Debug"
After restarting, joex should also pick up this job.
OK, so I added the variable. After restart, job is still in waiting - look at the attached image for proof. In the logs, there is this:
Starting unoconv listener
/usr/local/bin/unoconv:1231: DeprecationWarning: distutils Version classes are deprecated. Use packaging.version instead.
if product.ooName != "LibreOffice" or LooseVersion(product.ooSetupVersion) <= LooseVersion('3.3'):
2024.03.23 11:52:32:178 io-compute-blocker-12 INFO docspell.config.ConfigFactory.default:47
Using config from environment variables!
2024.03.23 11:52:33:0000 [io-comp...] [INFO ] docspell.joex.Main.run:37 -
***> ______ _ _
***> | _ \ | | |
***> | | | |___ ___ ___ _ __ ___| | |
***> | | | / _ \ / __/ __| '_ \ / _ \ | |
***> | |/ / (_) | (__\__ \ |_) | __/ | |
***> |___/ \___/ \___|___/ .__/ \___|_|_|
***> | |
***> |_| v0.41.0 (#50dadad4)
***> << JOEX >>
***> Id: joex1
***> Base-Url: http://docspell-joex:7878
***> Database: jdbc:postgresql://postgresql.data.mj12.lab:5432/docspelljoex_db
***> Fts: Solr(http://docspell-solr:8983/solr/docspell)
***> Config:
***> FileRepo: DefaultDatabase(true)
***>
2024.03.23 11:52:34:0000 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:34 - Creating Flyway for: List(classpath:db/fixups/postgresql, classpath:db/fixups/common)
2024.03.23 11:52:34:0001 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.runFixups:79 - !!! Running fixup migrations (repair=false)
2024.03.23 11:52:34:0002 [io-comp...] [INFO ] org.flywaydb.core.FlywayExecutor - Database: jdbc:postgresql://postgresql.data.mj12.lab:5432/docspelljoex_db (PostgreSQL 16.2)
2024.03.23 11:52:34:0003 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbValidate - Successfully validated 2 migrations (execution time 00:00.049s)
2024.03.23 11:52:34:0004 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Current version of schema "public": 1.33.0
2024.03.23 11:52:34:0005 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Schema "public" is up to date. No migration necessary.
2024.03.23 11:52:34:0006 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:34 - Creating Flyway for: List(classpath:db/migration/postgresql, classpath:db/migration/common)
2024.03.23 11:52:34:0007 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.runMain:59 - !!! Running main migrations (repair=false)
2024.03.23 11:52:34:0008 [io-comp...] [INFO ] org.flywaydb.core.FlywayExecutor - Database: jdbc:postgresql://postgresql.data.mj12.lab:5432/docspelljoex_db (PostgreSQL 16.2)
2024.03.23 11:52:34:0009 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbValidate - Successfully validated 68 migrations (execution time 00:00.074s)
2024.03.23 11:52:34:0010 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Current version of schema "public": 1.39.3
2024.03.23 11:52:34:0011 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Schema "public" is up to date. No migration necessary.
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.analysis.nlp.PipelineCache.create:129 - Clearing StanfordNLP cache after Duration(900000ms) idle time
2024.03.23 11:52:36:0001 [io-comp...] [INFO ] docspell.analysis.nlp.PipelineCache.apply:44 - Creating nlp pipeline cache
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.backend.ops.ONode.register:52 - Registering node joex1
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.backend.joex.FindJobOwnerAccount.apply:24 - Searching for account of ids: AccountId(Ident(docspell-system),Ident(docspell-system))
2024.03.23 11:52:36:0000 [io-comp...] [DEBUG] docspell.backend.joex.FindJobOwnerAccount.apply:24 - Searching for account of ids: AccountId(Ident(docspell-system),Ident(docspell-system))
2024.03.23 11:52:36:0000 [io-comp...] [DEBUG] docspell.backend.joex.FindJobOwnerAccount.apply:24 - Searching for account of ids: AccountId(Ident(docspell-system),Ident(docspell-system))
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.scheduler.impl.PeriodicSchedulerImpl.start:33 - Starting periodic scheduler
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.scheduler.impl.SchedulerImpl.start:133 - Starting scheduler
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.notification.api.EventExchange.consume:48 - Starting up 2 notification event consumers
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:140 - Try to acquire permit (1 free)
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:69 - Going into main loop
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:71 - Looking for next periodic task
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:143 - New permit acquired
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.pubsub.naive.NaivePubSub.subscribe:89 - Adding subscriber for topics: NonEmptyList(Topic(periodic-task-notify))
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.pubsub.naive.NaivePubSub.subscribe:89 - Adding subscriber for topics: NonEmptyList(Topic(job-cancel-request))
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.pubsub.naive.NaivePubSub.subscribe:89 - Adding subscriber for topics: NonEmptyList(Topic(jobs-notify))
2024.03.23 11:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:78 - Found periodic task 'Docspell house-keeping/Sun *-*-* 00:00:00 UTC'
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.scheduleNotify:132 - Scheduling next notify for timer Sun *-*-* 00:00:00 UTC -> Some(2024-03-24T00:00)
2024.03.23 11:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.mainLoop:101 - Waiting for notify
2024.03.23 11:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.QJob.markJob:70 - Scheduled job FaiXybu93.../docspell-system/full-text-index/Low to worker joex1
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:153 - Next job found: Some(FaiXybu93.../docspell-system/full-text-index/Low)
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.execute:213 - Creating context for job FaiXybu93.../docspell-system/full-text-index/Low to run JobTask(Ident(full-text-index),docspell.scheduler.Task$$anonfun$apply$4@57965507,docspell.scheduler.Task$$anonfun$contramap$4@7ecf0eb6)
2024.03.23 11:52:36:0003 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.forkRun:327 - Forking job FaiXybu93.../docspell-system/full-text-index/Low
2024.03.23 11:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.wrapTask:275 - Starting task now
2024.03.23 11:52:36:0004 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:140 - Try to acquire permit (0 free)
2024.03.23 11:52:36:0000 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:36.971203400Z Info FaiXybu93.../docspell-system/full-text-index/Low: Running full-text-index migrations now (jobId: "FaiXybu93aW-VDqoBHkspWJ-361vu4nBEE6-PkjPzKpkxV9", task: "full-text-index", group: "docspell-system", jobInfo: "FaiXybu93.../docspell-system/full-text-index/Low")
2024.03.23 11:52:37:0000 [io-comp...] [INFO ] org.http4s.ember.server.EmberServerBuilderCompanionPlatform - Ember-Server service bound to address: 0.0.0.0:7878
2024.03.23 11:52:36:0002 [io-comp...] [INFO ] docspell.scheduler.impl.SchedulerImpl.wrapTask:278 - Job execution successful: FaiXybu93.../docspell-system/full-text-index/Low
2024.03.23 11:52:36:0003 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.433580136Z Info FaiXybu93.../docspell-system/full-text-index/Low: No fulltext search migrations to run. (jobId: "FaiXybu93aW-VDqoBHkspWJ-361vu4nBEE6-PkjPzKpkxV9", task: "full-text-index", group: "docspell-system", jobInfo: "FaiXybu93.../docspell-system/full-text-index/Low")
2024.03.23 11:52:36:0003 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.onFinish:224 - Job FaiXybu93.../docspell-system/full-text-index/Low done Success. Releasing resources.
2024.03.23 11:52:36:0004 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.onFinish:226 - Permit released (0 free)
2024.03.23 11:52:37:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:143 - New permit acquired
2024.03.23 11:52:37:0000 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.435276598Z Info FaiXybu93.../docspell-system/full-text-index/Low: Job execution successful (jobId: "FaiXybu93aW-VDqoBHkspWJ-361vu4nBEE6-PkjPzKpkxV9", task: "full-text-index", group: "docspell-system", jobInfo: "FaiXybu93.../docspell-system/full-text-index/Low")
2024.03.23 11:52:37:0000 [io-comp...] [DEBUG] docspell.backend.joex.FindJobOwnerAccount.apply:24 - Searching for account of ids: AccountId(Ident(docspell-system),Ident(docspell-system))
2024.03.23 11:52:37:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.makeJobDoneEvent:246 - Found job owner None for job RJob(Ident(FaiXybu93aW-VDqoBHkspWJ-361vu4nBEE6-PkjPzKpkxV9),Ident(full-text-index),Ident(docspell-system),{},Create full-text index,Timestamp(2024-03-23T10:52:36.674069Z),Ident(docspell-system),Low,Waiting,0,0,Some(Ident(full-text-index-tracker)),None,None,None)
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.QJob.markJob:70 - Scheduled job Ehh4eqiE2.../docspell-system/all-previews/Low to worker joex1
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:153 - Next job found: Some(Ehh4eqiE2.../docspell-system/all-previews/Low)
2024.03.23 11:52:36:0003 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.execute:213 - Creating context for job Ehh4eqiE2.../docspell-system/all-previews/Low to run JobTask(Ident(all-previews),docspell.scheduler.Task$$anonfun$apply$4@15b5e61c,docspell.scheduler.Task$$anonfun$contramap$4@b4d400c)
2024.03.23 11:52:36:0004 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.forkRun:327 - Forking job Ehh4eqiE2.../docspell-system/all-previews/Low
2024.03.23 11:52:36:0005 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:140 - Try to acquire permit (0 free)
2024.03.23 11:52:37:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.wrapTask:275 - Starting task now
2024.03.23 11:52:37:0000 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.482023086Z Info Ehh4eqiE2.../docspell-system/all-previews/Low: Generating previews for attachments (jobId: "Ehh4eqiE2Bv-zRTFCx7Gqhg-akLgN1LiCaL-CJEK8zqPD2A", task: "all-previews", group: "docspell-system", jobInfo: "Ehh4eqiE2.../docspell-system/all-previews/Low")
2024.03.23 11:52:36:0004 [io-comp...] [INFO ] docspell.scheduler.impl.SchedulerImpl.wrapTask:278 - Job execution successful: Ehh4eqiE2.../docspell-system/all-previews/Low
2024.03.23 11:52:36:0005 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.onFinish:224 - Job Ehh4eqiE2.../docspell-system/all-previews/Low done Success. Releasing resources.
2024.03.23 11:52:36:0006 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.onFinish:226 - Permit released (0 free)
2024.03.23 11:52:37:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:143 - New permit acquired
2024.03.23 11:52:37:0000 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.509798815Z Info Ehh4eqiE2.../docspell-system/all-previews/Low: Submitted 0 jobs (jobId: "Ehh4eqiE2Bv-zRTFCx7Gqhg-akLgN1LiCaL-CJEK8zqPD2A", task: "all-previews", group: "docspell-system", jobInfo: "Ehh4eqiE2.../docspell-system/all-previews/Low")
2024.03.23 11:52:36:0003 [io-comp...] [DEBUG] docspell.backend.joex.FindJobOwnerAccount.apply:24 - Searching for account of ids: AccountId(Ident(docspell-system),Ident(docspell-system))
2024.03.23 11:52:37:0000 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.510474978Z Info Ehh4eqiE2.../docspell-system/all-previews/Low: Job execution successful (jobId: "Ehh4eqiE2Bv-zRTFCx7Gqhg-akLgN1LiCaL-CJEK8zqPD2A", task: "all-previews", group: "docspell-system", jobInfo: "Ehh4eqiE2.../docspell-system/all-previews/Low")
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.makeJobDoneEvent:246 - Found job owner None for job RJob(Ident(Ehh4eqiE2Bv-zRTFCx7Gqhg-akLgN1LiCaL-CJEK8zqPD2A),Ident(all-previews),Ident(docspell-system),{"collective":null,"storeMode":"whenmissing"},Create preview images,Timestamp(2024-03-23T10:52:36.752058Z),Ident(docspell-system),Low,Waiting,0,0,Some(Ident(generate-all-previews)),None,None,None)
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.QJob.markJob:70 - Scheduled job EUmhLZiMW.../docspell-system/all-page-count/Low to worker joex1
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:153 - Next job found: Some(EUmhLZiMW.../docspell-system/all-page-count/Low)
2024.03.23 11:52:36:0003 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.execute:213 - Creating context for job EUmhLZiMW.../docspell-system/all-page-count/Low to run JobTask(Ident(all-page-count),docspell.scheduler.Task$$anonfun$apply$4@7a7d23e9,docspell.scheduler.Task$$anonfun$contramap$4@17328d70)
2024.03.23 11:52:36:0004 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.forkRun:327 - Forking job EUmhLZiMW.../docspell-system/all-page-count/Low
2024.03.23 11:52:36:0005 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:140 - Try to acquire permit (0 free)
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.wrapTask:275 - Starting task now
2024.03.23 11:52:37:0001 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.544926870Z Info EUmhLZiMW.../docspell-system/all-page-count/Low: Generating previews for attachments (jobId: "EUmhLZiMW5t-edLPc1VQqFi-mp8XhxUF8N3-TXGCJgVvXge", task: "all-page-count", group: "docspell-system", jobInfo: "EUmhLZiMW.../docspell-system/all-page-count/Low")
2024.03.23 11:52:36:0001 [io-comp...] [INFO ] docspell.scheduler.impl.SchedulerImpl.wrapTask:278 - Job execution successful: EUmhLZiMW.../docspell-system/all-page-count/Low
2024.03.23 11:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.onFinish:224 - Job EUmhLZiMW.../docspell-system/all-page-count/Low done Success. Releasing resources.
2024.03.23 11:52:36:0003 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.onFinish:226 - Permit released (0 free)
2024.03.23 11:52:37:0001 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.562248418Z Info EUmhLZiMW.../docspell-system/all-page-count/Low: Submitted 0 jobs (jobId: "EUmhLZiMW5t-edLPc1VQqFi-mp8XhxUF8N3-TXGCJgVvXge", task: "all-page-count", group: "docspell-system", jobInfo: "EUmhLZiMW.../docspell-system/all-page-count/Low")
2024.03.23 11:52:37:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:143 - New permit acquired
2024.03.23 11:52:36:0004 [io-comp...] [DEBUG] docspell.backend.joex.FindJobOwnerAccount.apply:24 - Searching for account of ids: AccountId(Ident(docspell-system),Ident(docspell-system))
2024.03.23 11:52:37:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:153 - Next job found: None
2024.03.23 11:52:37:0002 [io-comp...] [INFO ] docspell.scheduler.impl.LogSink.logInternal:41 - >>> 2024-03-23T10:52:37.562754442Z Info EUmhLZiMW.../docspell-system/all-page-count/Low: Job execution successful (jobId: "EUmhLZiMW5t-edLPc1VQqFi-mp8XhxUF8N3-TXGCJgVvXge", task: "all-page-count", group: "docspell-system", jobInfo: "EUmhLZiMW.../docspell-system/all-page-count/Low")
2024.03.23 11:52:37:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.mainLoop:168 - Waiting for notify
2024.03.23 11:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.makeJobDoneEvent:246 - Found job owner None for job RJob(Ident(EUmhLZiMW5t-edLPc1VQqFi-mp8XhxUF8N3-TXGCJgVvXge),Ident(all-page-count),Ident(docspell-system),{},Create all page-counts,Timestamp(2024-03-23T10:52:36.776223Z),Ident(docspell-system),Low,Waiting,0,0,Some(Ident(all-page-count-tracker)),None,None,None)
2024.03.23 11:53:30:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 11:53:30:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
The rest server log is long and attached.
rest.txt
I think we can leave the restserver aside for now. It seems that joex can't pick up this job. It could be that the processing threads are occupied. There are system jobs also running. If you create an account docspell-system (user and collective) and login with it, you can see these jobs in its job page. I suspect there is something going on which occupies the slots
I am sorry - I do not get it, what am I do to? Login in docspell or docker host? In any case, there is nothing happening, I also gave all containers free reign for resources, and host is like 36core/128GB on U.2 disks - no one is using it - there is only one dest doc uploaded (which is still in waiting from yesterday) to the docspell system itself
What I meant is creating a new account in the docspell app, name it docspell-system (for collective and user). When you then login with this account and go to the job page, you'll see the system jobs. One cause could be that some jobs are sitting there occupying the slots so your pdf cannot be processed. It's only strange that there is nothing in the logs.
Man I do not know - I must be doing something wrong... I created as you requested - nothing changes, visually or processing(ly).. take a look at screenshots.. Also, some excerpt from logs...
2024.03.23 21:42:07:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:42:07:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:42:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.periodicAwake:43 - Periodic awake reached
2024.03.23 21:42:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.mainLoop:103 - Notify signal, going into main loop
2024.03.23 21:42:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:69 - Going into main loop
2024.03.23 21:42:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:71 - Looking for next periodic task
2024.03.23 21:42:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:78 - Found periodic task 'Docspell house-keeping/Sun *-*-* 00:00:00 UTC'
2024.03.23 21:42:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.scheduleNotify:132 - Scheduling next notify for timer Sun *-*-* 00:00:00 UTC -> Some(2024-03-24T00:00)
2024.03.23 21:42:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.mainLoop:101 - Waiting for notify
2024.03.23 21:43:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:43:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:44:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:44:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:45:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:45:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:46:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:46:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:47:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:47:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:48:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:48:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:49:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:49:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:50:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:50:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:51:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:51:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:52:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:52:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
2024.03.23 21:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.periodicAwake:64 - Periodic awake reached
2024.03.23 21:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.periodicAwake:43 - Periodic awake reached
2024.03.23 21:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.mainLoop:170 - Notify signal, going into main loop
2024.03.23 21:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.mainLoop:103 - Notify signal, going into main loop
2024.03.23 21:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:140 - Try to acquire permit (1 free)
2024.03.23 21:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:69 - Going into main loop
2024.03.23 21:52:36:0002 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:143 - New permit acquired
2024.03.23 21:52:36:0003 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:71 - Looking for next periodic task
2024.03.23 21:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.body:153 - Next job found: None
2024.03.23 21:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.SchedulerImpl.mainLoop:168 - Waiting for notify
2024.03.23 21:52:36:0000 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.body:78 - Found periodic task 'Docspell house-keeping/Sun *-*-* 00:00:00 UTC'
2024.03.23 21:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.scheduleNotify:132 - Scheduling next notify for timer Sun *-*-* 00:00:00 UTC -> Some(2024-03-24T00:00)
2024.03.23 21:52:36:0001 [io-comp...] [DEBUG] docspell.scheduler.impl.PeriodicSchedulerImpl.mainLoop:101 - Waiting for notify
2024.03.23 21:53:08:0000 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 GET /api/info/version
2024.03.23 21:53:08:0001 [io-comp...] [INFO ] org.http4s.server.middleware.Logger - HTTP/1.1 200 OK
Hm, ok so this means you also uploaded a document as user docspell-system? The screenshots look a bit strange, because I would expect more jobs running in the system user's job queue.
Can you perhaps share exactly how you are running and accessing docspell? So I could try to reproduce it here. Or maybe you can try with the provided docker-compose if that also yields this problem? I couldn't reproduce it this way at least, but there has to be some cause :-)
Indeed, I saw no jobs as docspell-system - no system or other jobs..
I can try running it on test environment as default compose, no changes or anything. After that I can post my compose here. Give me short time to test
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. This only applies to 'question' issues. Always feel free to reopen or create new issues. Thank you!
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}