Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fulltext search causes solr error #609 #909

Closed
lopiuh opened this issue Jul 3, 2021 · 13 comments
Closed

Fulltext search causes solr error #609 #909

lopiuh opened this issue Jul 3, 2021 · 13 comments
Labels
bug Something isn't working or in unexpected ways docker All things regarding docker setup

Comments

@lopiuh
Copy link

lopiuh commented Jul 3, 2021

Hi Docspell fans,

I really don't get it trying to search generates a:

ocspell-restserver | [docspell-restserver-blocking-5] ERROR o.h.s.service-errors - Error servicing request: POST /api/v1/sec/item/searchStats from 172.18.0.1

it is a plain docker installation docspell.conf is default:
solr_url="http://localhost:8983/solr/docspell"

I just set the admin PW to regenerate the index with success but no change in search failure.

Anybody?

Thanks

lopiuh

@eikek
Copy link
Owner

eikek commented Jul 3, 2021

Hi @lopiuh ,

I need more information :). You said it is a solr error - but the log line doesn't show anything related to solr. Could you paste more logs around the ERROR?

The solr-url of localhost looks a bit suspicious. The default url for the provided docker-compose setup is solr_url="http://docspell-solr:8983/docspell" - did you change it and if yes, why? If it's not the provided docker setup, can you give more details on how you setup is?

Thanks!

@lopiuh
Copy link
Author

lopiuh commented Jul 3, 2021

it is the provided (docker) setup and search did not work from the beginning. In the meantime I tried a manual installation (debian) but I did not came to a successfull state. I returned to the default docker installation. Maybe now, the local solr installation and docker images of several other tested dms may interfere. The following log is directly after pressing enter in the search box. The second one ofter api call reindex.

Both times "docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found

docspell-restserver | [blaze-selector-2] INFO  o.h.b.c.n.NIO1SocketServerGroup - Accepted connection from /172.18.0.1:37832 
docspell-restserver | [ioapp-compute-1] DEBUG d.b.o.OSimpleSearch - Using index only search: Some(foo) 
docspell-restserver | [docspell-restserver-blocking-37] INFO  o.h.s.m.Logger - HTTP/1.1 POST /api/v1/sec/item/search 
docspell-restserver | [docspell-restserver-blocking-37] INFO  o.h.s.m.Logger - service raised an error: class org.http4s.client.UnexpectedStatus 
docspell-restserver | [docspell-restserver-blocking-37] ERROR o.h.s.service-errors - Error servicing request: POST /api/v1/sec/item/search from 172.18.0.1 
docspell-restserver | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-restserver | [docspell-restserver-blocking-35] INFO  o.h.s.m.Logger - HTTP/1.1 POST /api/v1/sec/item/searchStats 
docspell-restserver | [docspell-restserver-blocking-35] INFO  o.h.s.m.Logger - service raised an error: class org.http4s.client.UnexpectedStatus 
docspell-restserver | [docspell-restserver-blocking-35] ERROR o.h.s.service-errors - Error servicing request: POST /api/v1/sec/item/searchStats from 172.18.0.1 
docspell-restserver | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-restserver | [blaze-selector-3] INFO  o.h.b.c.n.NIO1SocketServerGroup - Accepted connection from /127.0.0.1:37052 
docspell-restserver | [ioapp-compute-1] INFO  o.h.s.m.Logger - HTTP/1.1 GET / 
docspell-restserver | [ioapp-compute-1] INFO  o.h.s.m.Logger - HTTP/1.1 303 See Other 
docspell-restserver | [blaze-selector-4] INFO  o.h.b.c.n.NIO1SocketServerGroup - Accepted connection from /127.0.0.1:37054 
docspell-restserver | [ioapp-compute-0] INFO  o.h.s.m.Logger - HTTP/1.1 GET /app 
docspell-restserver | [ioapp-compute-0] INFO  o.h.s.m.Logger - HTTP/1.1 200 OK 

and this is giving the command: curl -H 'Docspell-Admin-Secret:123' -XPOST "http://localhost:7880/api/v1/admin/fts/reIndexAll"

docspell-restserver | [ioapp-compute-1] INFO  o.h.s.m.Logger - HTTP/1.1 GET / 
docspell-restserver | [ioapp-compute-1] INFO  o.h.s.m.Logger - HTTP/1.1 303 See Other 
docspell-restserver | [blaze-selector-3] INFO  o.h.b.c.n.NIO1SocketServerGroup - Accepted connection from /127.0.0.1:37092 
docspell-restserver | [ioapp-compute-0] INFO  o.h.s.m.Logger - HTTP/1.1 GET /app 
docspell-restserver | [ioapp-compute-0] INFO  o.h.s.m.Logger - HTTP/1.1 200 OK 
docspell-restserver | [blaze-selector-4] INFO  o.h.b.c.n.NIO1SocketServerGroup - Accepted connection from /172.18.0.1:37882 
docspell-restserver | [ioapp-compute-3] INFO  d.b.o.OFulltext - Re-index all. 
docspell-restserver | [ioapp-compute-2] DEBUG d.j.c.JoexClient - Notify joex at http://docspell-joex:7878/api/v1/notify 
docspell-joex | [blaze-selector-1] INFO  o.h.b.c.n.NIO1SocketServerGroup - Accepted connection from /172.18.0.4:35684 
docspell-joex | [ioapp-compute-2] DEBUG d.j.s.SchedulerImpl - Notify signal, going into main loop 
docspell-joex | [ioapp-compute-0] DEBUG d.j.s.PeriodicSchedulerImpl - Notify signal, going into main loop 
docspell-joex | [ioapp-compute-2] DEBUG d.j.s.SchedulerImpl - Try to acquire permit (1 free) 
docspell-joex | [ioapp-compute-2] DEBUG d.j.s.SchedulerImpl - New permit acquired 
docspell-joex | [ioapp-compute-0] DEBUG d.j.s.PeriodicSchedulerImpl - Going into main loop 
docspell-joex | [ioapp-compute-0] DEBUG d.j.s.PeriodicSchedulerImpl - Looking for next periodic task 
docspell-joex | [ioapp-compute-1] INFO  o.h.s.m.Logger - HTTP/1.1 POST /api/v1/notify 
docspell-joex | [ioapp-compute-1] INFO  o.h.s.m.Logger - HTTP/1.1 200 OK 
docspell-joex | [ioapp-compute-1] DEBUG d.j.s.PeriodicSchedulerImpl - Found periodic task 'Docspell house-keeping/Sun *-*-* 00:00:00' 
docspell-joex | [ioapp-compute-1] DEBUG d.j.s.PeriodicSchedulerImpl - Scheduling next notify for timer Sun *-*-* 00:00:00 -> Some(2021-07-04T00:00) 
docspell-restserver | [docspell-restserver-blocking-40] INFO  o.h.s.m.Logger - HTTP/1.1 POST /api/v1/admin/fts/reIndexAll 
docspell-restserver | [docspell-restserver-blocking-40] INFO  o.h.s.m.Logger - HTTP/1.1 200 OK 
docspell-joex | [ioapp-compute-2] DEBUG d.j.s.PeriodicSchedulerImpl - Waiting for notify 
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.SchedulerImpl - Next job found: Some(35e9RMVMA.../docspell-system/full-text-reindex/Low) 
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.SchedulerImpl - Creating context for job 35e9RMVMA.../docspell-system/full-text-reindex/Low to run JobTask(Ident(full-text-reindex),docspell.joex.scheduler.Task$$anonfun$contramap$4@300159a4,docspell.joex.scheduler.Task$$anonfun$contramap$4@cb3b87a) 
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.SchedulerImpl - Forking job 35e9RMVMA.../docspell-system/full-text-reindex/Low 
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.SchedulerImpl - Try to acquire permit (0 free) 
docspell-joex | [ioapp-compute-1] DEBUG d.j.s.SchedulerImpl - Starting task now 
docspell-joex | [ioapp-compute-0] INFO  d.j.s.LogSink - >>> 2021-07-03T20:30:40.511775Z Info 35e9RMVMA.../docspell-system/full-text-reindex/Low: Running full-text re-index now 
docspell-joex | [ioapp-compute-0] INFO  d.j.s.LogSink - >>> 2021-07-03T20:30:40.519165Z Info 35e9RMVMA.../docspell-system/full-text-reindex/Low: Clearing index data 
docspell-joex | [ioapp-compute-0] INFO  d.j.s.LogSink - >>> 2021-07-03T20:30:40.519726Z Info 35e9RMVMA.../docspell-system/full-text-reindex/Low: Running re-create index 
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.LogSink - >>> 2021-07-03T20:30:40.580824Z Debug 35e9RMVMA.../docspell-system/full-text-reindex/Low: Apply (solr): Delete all data 
docspell-joex | [ioapp-compute-3] ERROR d.j.s.SchedulerImpl - Job 35e9RMVMA.../docspell-system/full-text-reindex/Low execution failed. Retrying later. 
docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.SchedulerImpl - Job 35e9RMVMA.../docspell-system/full-text-reindex/Low done Stuck. Releasing resources. 
docspell-joex | [ioapp-compute-0] ERROR d.j.s.LogSink - >>> 2021-07-03T20:30:40.621083Z Error 35e9RMVMA.../docspell-system/full-text-reindex/Low: Job 35e9RMVMA.../docspell-system/full-text-reindex/Low execution failed. Retrying later. 
docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-joex | [ioapp-compute-3] DEBUG d.j.s.SchedulerImpl - Permit released (0 free) 
docspell-joex | [ioapp-compute-1] DEBUG d.j.s.SchedulerImpl - New permit acquired 
docspell-joex | [ioapp-compute-0] DEBUG d.j.s.SchedulerImpl - Next job found: None 
docspell-joex | [ioapp-compute-0] DEBUG d.j.s.SchedulerImpl - Waiting for notify 
docspell-solr | 2021-07-03 20:30:51.277 INFO  (qtp1360518503-20) [   x:docspell] o.a.s.c.S.Request [docspell]  webapp=/solr path=/admin/ping params={} hits=0 status=0 QTime=0
docspell-solr | 2021-07-03 20:30:51.277 INFO  (qtp1360518503-20) [   x:docspell] o.a.s.c.S.Request [docspell]  webapp=/solr path=/admin/ping params={} status=0 QTime=0

@eikek
Copy link
Owner

eikek commented Jul 4, 2021

It seems that the solr requests are not going to solr. Did you change the docker-compose setup in any way? For example, the config file or the docker-compose file?

The solr url must point to the solr container and not localhost. Try the default url: solr_url="http://docspell-solr:8983/docspell" and then do the reindex again. There shouldn't be any of these unexpected HTTP status: 404 Not Found log messages.

@lopiuh
Copy link
Author

lopiuh commented Jul 4, 2021

I did leave everything on default and even installed in a virtualmachine with a vanilla debian buster install. Maybe we should "debug" in that installation because it is a "clean" install. I do the VM way once more and give the logs of that instance...

Thanks

@eikek
Copy link
Owner

eikek commented Jul 4, 2021

Ah, so it's not the docker setup anymore? Using the debian-way you need to install solr via debian and create a solr core (this solr doc might be helpful).

@eikek eikek added the question Further information is requested label Jul 5, 2021
@lopiuh
Copy link
Author

lopiuh commented Jul 6, 2021

Hi eikek,

No, all docker installations, I did a test with fedora (new OS installation in virtualbox) with the same error I got in debian buster (nativly and vitrualbox). The error comes when trying to search. OS, docker and docspell-docker are freshly installed. In debian and fedora I had to manually update docker-compose to a new version (1.29.2) in order to get the container up. I did not configure anything.

Any idea?

log.txt

@eikek
Copy link
Owner

eikek commented Jul 7, 2021

Really strange! Solr always returns a 404, I don't see why. What I usually do when testing the docker setup is to prune everything (but of course only applicable in testing environments):

docker system prune -a
docker volume prune

This removes all containers, images and volumes. Or try to remove the solr volume only. I couldn't see it creating a new core; from the logs it seemed that it found an existing one (see line 5). So there maybe some weird state. If this doesn't work (I suspect it, since you tried from a clean system anyways), try using a different solr version (and always remove the existing solr container and volume, so it can be re-created). Maybe the new version 8.9 changed too much; try 8.4 for example (I'm using this).

@lopiuh
Copy link
Author

lopiuh commented Jul 7, 2021

Hi eikek,

thanks for your thoughts. As far as the docker images are concerned it "should" work shouldn't it? Especially with a clean os Install in a virtual machine, so there is no old solr config.., interestingly would be if someone could reproduce the problem with the actual docker image. What I could do: test an old docker image (with Solr 8.4 e.g.), Is it still downloadable?

Thanks

lopiuh

@eikek
Copy link
Owner

eikek commented Jul 7, 2021

It should work :-) I think I tested it when releasing the latest version, but I may have failed or a new solr version is now not compatible anymore (this is my current guess). You can try this by changing the docker-compose file: there is the solr container defined, just replace image: solr:8 with image: solr:8.4 for example. Then remove the solr volume and container and run docker-compose up - it should then use the latest 8.4 release. I think you don't need to setup a new VM for this - removing the docker volumes and containers should be enough.

@arndtseegers
Copy link

Hello, this is reproducible behavior for me as well. Installing via default docker-compose routine, no changes to configs results in:

at boot:

docspell-joex | [ioapp-compute-6] DEBUG d.j.s.SchedulerImpl - Next job found: Some(G2srK12WL.../docspell-system/full-text-index/Low)
docspell-joex | [ioapp-compute-6] DEBUG d.j.s.SchedulerImpl - Creating context for job G2srK12WL.../docspell-system/full-text-index/Low to run JobTask(Ident(full-text-index),docspell.joex.scheduler.Task$$anonfun$contramap$4@39c8d6d9,docspell.joex.scheduler.Task$$anonfun$contramap$4@439b5675)
docspell-joex | [ioapp-compute-7] INFO  o.h.b.c.n.NIO1SocketServerGroup - Service bound to address /0.0.0.0:7878
docspell-joex | [ioapp-compute-6] DEBUG d.j.s.SchedulerImpl - Forking job G2srK12WL.../docspell-system/full-text-index/Low
docspell-joex | [ioapp-compute-7] INFO  o.h.s.b.BlazeServerBuilder - http4s v0.21.24 on blaze v0.14.17 started at http://0.0.0.0:7878/
docspell-joex | [ioapp-compute-6] DEBUG d.j.s.SchedulerImpl - Try to acquire permit (0 free)
docspell-joex | [ioapp-compute-7] DEBUG d.j.s.SchedulerImpl - Starting task now
docspell-joex | [ioapp-compute-3] INFO  d.j.s.LogSink - >>> 2021-07-07T12:19:46.165491Z Info G2srK12WL.../docspell-system/full-text-index/Low: Running full-text-index migrations now
docspell-joex | [ioapp-compute-6] ERROR d.j.s.SchedulerImpl - Job G2srK12WL.../docspell-system/full-text-index/Low execution failed. Retrying later.
docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-joex | [ioapp-compute-6] DEBUG d.j.s.SchedulerImpl - Job G2srK12WL.../docspell-system/full-text-index/Low done Stuck. Releasing resources.
docspell-joex | [ioapp-compute-4] ERROR d.j.s.LogSink - >>> 2021-07-07T12:19:46.603345Z Error G2srK12WL.../docspell-system/full-text-index/Low: Job G2srK12WL.../docspell-system/full-text-index/Low execution failed. Retrying later.
docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found

when uploading a file:

docspell-joex | [ioapp-compute-7] DEBUG d.j.s.SchedulerImpl - Next job found: Some(G2srK12WL.../docspell-system/full-text-index/Low)
docspell-joex | [ioapp-compute-7] DEBUG d.j.s.SchedulerImpl - Creating context for job G2srK12WL.../docspell-system/full-text-index/Low to run JobTask(Ident(full-text-index),docspell.joex.scheduler.Task$$anonfun$contramap$4@39c8d6d9,docspell.joex.scheduler.Task$$anonfun$contramap$4@439b5675)
docspell-joex | [ioapp-compute-7] DEBUG d.j.s.SchedulerImpl - Forking job G2srK12WL.../docspell-system/full-text-index/Low
docspell-joex | [ioapp-compute-7] DEBUG d.j.s.SchedulerImpl - Try to acquire permit (0 free)
docspell-joex | [ioapp-compute-4] DEBUG d.j.s.SchedulerImpl - Starting task now
docspell-joex | [ioapp-compute-0] INFO  d.j.s.LogSink - >>> 2021-07-07T12:21:58.209160Z Info G2srK12WL.../docspell-system/full-text-index/Low: Running full-text-index migrations now
docspell-joex | [ioapp-compute-5] ERROR d.j.s.SchedulerImpl - Job G2srK12WL.../docspell-system/full-text-index/Low execution failed. Retrying later.
docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-joex | [ioapp-compute-5] DEBUG d.j.s.SchedulerImpl - Job G2srK12WL.../docspell-system/full-text-index/Low done Stuck. Releasing resources.
docspell-joex | [ioapp-compute-5] DEBUG d.j.s.SchedulerImpl - Permit released (0 free)
docspell-joex | [ioapp-compute-0] DEBUG d.j.s.SchedulerImpl - New permit acquired
docspell-joex | [ioapp-compute-2] ERROR d.j.s.LogSink - >>> 2021-07-07T12:21:58.223278Z Error G2srK12WL.../docspell-system/full-text-index/Low: Job G2srK12WL.../docspell-system/full-text-index/Low execution failed. Retrying later.
docspell-joex | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found

when searching:

docspell-restserver | [ioapp-compute-6] DEBUG d.b.o.OSimpleSearch - Using index only search: Some(Leitfaden)
docspell-restserver | [docspell-restserver-blocking-9] INFO  o.h.s.m.Logger - HTTP/1.1 POST /api/v1/sec/item/search
docspell-restserver | [docspell-restserver-blocking-9] INFO  o.h.s.m.Logger - service raised an error: class org.http4s.client.UnexpectedStatus
docspell-restserver | [docspell-restserver-blocking-9] ERROR o.h.s.service-errors - Error servicing request: POST /api/v1/sec/item/search from 172.25.0.1
docspell-restserver | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found
docspell-restserver | [docspell-restserver-blocking-11] INFO  o.h.s.m.Logger - HTTP/1.1 POST /api/v1/sec/item/searchStats
docspell-restserver | [docspell-restserver-blocking-11] INFO  o.h.s.m.Logger - service raised an error: class org.http4s.client.UnexpectedStatus
docspell-restserver | [docspell-restserver-blocking-11] ERROR o.h.s.service-errors - Error servicing request: POST /api/v1/sec/item/searchStats from 172.25.0.1
docspell-restserver | org.http4s.client.UnexpectedStatus: unexpected HTTP status: 404 Not Found

health check:

docspell-solr | 2021-07-07 12:28:05.480 INFO  (qtp1481818223-19) [   x:docspell] o.a.s.c.S.Request [docspell]  webapp=/solr path=/admin/ping params={} hits=0 status=0 QTime=21
docspell-solr | 2021-07-07 12:28:05.481 INFO  (qtp1481818223-19) [   x:docspell] o.a.s.c.S.Request [docspell]  webapp=/solr path=/admin/ping params={} status=0 QTime=22

Same issue after downgrading solr to 8.4 and 7 on a pruned docker system. The docspell-solr container is pingable and the webinterface is accessible via its internal address 172.26.0.2:8983 but not through localhost:8983.

Changing solr_url in docspell.conf to an IP or FQDN on the local network results in:

[ioapp-compute-4] DEBUG d.j.s.SchedulerImpl - Job HPNtdz2ZF.../docspell-system/full-text-index/Low done Stuck. Releasing resources.
docspell-joex | [ioapp-compute-6] ERROR d.j.s.LogSink - >>> 2021-07-07T12:44:06.160410Z Error HPNtdz2ZF.../docspell-system/full-text-index/Low: Job HPNtdz2ZF.../docspell-system/full-text-index/Low execution failed. Retrying later.
docspell-joex | org.http4s.client.ConnectionFailure: Error connecting to http://docker.int.example.com:8983 using address docker.int.example.com:8983 (unresolved: false)

@eikek
Copy link
Owner

eikek commented Jul 7, 2021

Thank you @arndto for all these details! Now it is clearly an ordinary bug :/ (easily reproducible by 2 :)) I haven't had time to take a closer look, I'll look more into it in the next days. I can't think of a change that could have caused this right now.

Solr is not by default exposed, because it is not necessary. So it is expected that it is not reachable via "localhost" (your host system). Within the docker network, all containers should see each other. The 404 means that at least someone is responding here… really strange. Hope I can figure it out soon. It should work with solr 8.x actually, but I'm myself on solr 8.6 while not using docker (sorry for the wrong info about, but it should also work with 8.4 - I tested these two in the past).

@eikek eikek added bug Something isn't working or in unexpected ways docker All things regarding docker setup and removed question Further information is requested labels Jul 7, 2021
@eikek
Copy link
Owner

eikek commented Jul 7, 2021

Oh my, I'm very sorry for the confusion! Turns out that I broke the config file - the correct solr url is http://docspell-solr:8983/solr/docspell (see the additional solr/ path). Please change the corresponding line in docspell.conf to this:

solr_url="http://docspell-solr:8983/solr/docspell"

I really thought I tried it before the release, but it cannot have worked.

Edit: I just pushed a fix that hopefully solves this. Running docker-compose up from current master branch should work now.

@lopiuh
Copy link
Author

lopiuh commented Jul 8, 2021

Works like a charm now ;-)

THANK YOU!

@lopiuh lopiuh closed this as completed Jul 8, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working or in unexpected ways docker All things regarding docker setup
Projects
None yet
Development

No branches or pull requests

3 participants