kagemomiji / airsonic-advanced

airsonic-advanced
GNU General Public License v3.0
174 stars 15 forks source link

[Bug] Failed to create search index #96

Closed awsms closed 1 year ago

awsms commented 1 year ago

What happened?

I've a quite big music collection, and I can't find a good 80% of it using the search function (web or mobile app). I can't see a ton of

2023-01-31 15:08:14.532 ERROR --- o.a.p.s.search.IndexManager              : Failed to create search index for xxxxxxxx

in my logs. This is a common bug on airsonic-advanced that was never fixed since the dev left.

https://github.com/airsonic-advanced/airsonic-advanced/issues?q=Failed+to+create+search+index

Steps to reproduce

  1. launch airsonic
  2. wait a few sec
  3. automatic scans end up in "faled to create search index"
  4. can't find the failed artists/albums/songs querries in web app/mobile app

Version

11.0.2 (Stable)

Version Detail

No response

Operating System

ubuntu 22.04 jammy

Java Version

openjdk version "17.0.5" 2022-10-18

Proxy Server

No response

client detail

No response

language

None

Relevant log output

2023-01-31 15:08:14.703 ERROR --- o.a.p.s.search.IndexManager              : Failed to create search index for org.airsonic.player.domain.Album@2f835684

java.lang.NullPointerException: Cannot invoke "org.apache.lucene.index.IndexWriter.updateDocument(org.apache.lucene.index.Term, java.lang.Iterable)" because the return value of "java.util.Map.get(Object)" is null
    at org.airsonic.player.service.search.IndexManager.index(IndexManager.java:116) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.updateAlbum(MediaScannerService.java:413) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.scanFile(MediaScannerService.java:316) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.lambda$24(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[na:na]
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290) ~[na:na]
    at java.base/java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:754) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.helpComplete(ForkJoinPool.java:1223) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.helpComplete(ForkJoinPool.java:1915) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.awaitDone(ForkJoinTask.java:433) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:687) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:159) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:173) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:765) ~[na:na]
    at org.airsonic.player.service.MediaScannerService.scanFile(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.lambda$24(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[na:na]
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290) ~[na:na]
    at java.base/java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:754) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:686) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:159) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:173) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:765) ~[na:na]
    at org.airsonic.player.service.MediaScannerService.scanFile(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.lambda$24(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[na:na]
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290) ~[na:na]
    at java.base/java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:754) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.helpComplete(ForkJoinPool.java:1223) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.helpComplete(ForkJoinPool.java:1915) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.awaitDone(ForkJoinTask.java:433) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:687) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:159) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:173) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:765) ~[na:na]
    at org.airsonic.player.service.MediaScannerService.scanFile(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.lambda$24(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[na:na]
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290) ~[na:na]
    at java.base/java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:754) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.helpComplete(ForkJoinPool.java:1223) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.helpComplete(ForkJoinPool.java:1915) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.awaitDone(ForkJoinTask.java:433) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:687) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:159) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:173) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[na:na]
    at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:765) ~[na:na]
    at org.airsonic.player.service.MediaScannerService.scanFile(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at org.airsonic.player.service.MediaScannerService.lambda$24(MediaScannerService.java:313) ~[classes!/:11.0.2]
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[na:na]
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[na:na]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[na:na]
    at java.base/java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290) ~[na:na]
    at java.base/java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:754) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) ~[na:na]
mmskv commented 1 year ago

Hi, are you sure that you were running 11.0.2 (Stable)? I get no errors on that build, but on builds following #83 error count reaches 16k:

[me@airsonic-test ~]$ sudo docker logs airsonic-stable | grep -c "Failed to create search index"
0
[me@airsonic-test ~]$ sudo docker logs airsonic-pr-83 | grep -c "Failed to create search index"
15724
kagemomiji commented 1 year ago

@mmskv

From error message, this is stable. Because latest edge version will throw Failed to create search index for album XXXX, if exception is thrown at IndexManager:116

kagemomiji commented 1 year ago

Analyzation

the following instance in the IndexManger.java is empty when the reported error message occured.

https://github.com/kagemomiji/airsonic-advanced/blob/6db9539c3f714a1991180fec2e06132ca05803d3/airsonic-main/src/main/java/org/airsonic/player/service/search/IndexManager.java#L110

Normally, this instance is initialized here

https://github.com/kagemomiji/airsonic-advanced/blob/6db9539c3f714a1991180fec2e06132ca05803d3/airsonic-main/src/main/java/org/airsonic/player/service/search/IndexManager.java#L150-L158

If media library scan start, it is initialized and has 5 keys, but a few minutes after the scan start , MediaFileScannerService excecute the following step. This step clear the writers map.

https://github.com/kagemomiji/airsonic-advanced/blob/6db9539c3f714a1991180fec2e06132ca05803d3/airsonic-main/src/main/java/org/airsonic/player/service/MediaScannerService.java#L288

However, indexing is not finished, then IndexManager failed with the reported error message.

awsms commented 1 year ago

Thanks for fixing this kagemomiji. Hyped for the future of this fork!

edit: looks like this made a new bug.. airsonic has been endlessly re-scanning my library for a while now. My postgres database folder is over 2.7gigs, and keeps increasing

kagemomiji commented 1 year ago

@awsms

edit: looks like this made a new bug.. airsonic has been endlessly re-scanning my library for a while now. My postgres database folder is over 2.7gigs, and keeps increasing

thank you for feedback. I haven't examined it properly, but I wonder if there is a loop in the folder structure between parent and child, such as a symbolic link.