Stale search index and cache?

Andy.N

Well-known member
Im running latest versions of xf 1.5 and related ES addon and servers.
When i click on a member profile and their activities, it shows their latest posts as 2 weeks old. However, forum latest post feed correctly shows their latest posts as of today. When i rebuild the search index, all is updated as it should.

Where should I go to identify the issue?
 
If the search index is not being updated automatically, I'd have to recommend testing with all add-ons other than XFES disabled. You should be able to make test posts to quickly determine whether the index is being updated. Assuming it is, then test as you enable add-ons one by one.
 
If the search index is not being updated automatically, I'd have to recommend testing with all add-ons other than XFES disabled. You should be able to make test posts to quickly determine whether the index is being updated. Assuming it is, then test as you enable add-ons one by one.
Disabled all addons except XFES. Rebuilt search index. Confirmed that it shows my very latest post.
Then I made another post, then click on my username and the post count does not increase by 1, and clicking on that post count number only show posts missing the last one.
 
XF 1.5.15a
XFES 1.1.7

Here is the stats of the Elastic Setup page in ACP
Version:5.6.3
Documents: 225,143 (85.1 MB)
Index Updates: 225,143 (0.0008 seconds average)
Searches:175 (0.0009 seconds average)
Fetches:126 (0.0012 seconds average)
 
Deleting and posting messages will instantly show the new post count correctly.
When deleting old posts, the activity feed displays correctly i.e not the deleted posts.
When adding new posts, the activity feed display incorrectly i.e not the new posts.
So search index updates if I delete posts but not if i add new posts.
 
I assume you're not seeing any errors in XF's server error log, but are there any log entries within Elasticsearch itself? What Elasticsearch version?

If we hand off to Elasticsearch, at that point, it's generally out of our hands. Technically speaking, there are some internal settings for Elasticsearch that related to index refreshing intervals, though that should update the entry at some point.
 
I assume you're not seeing any errors in XF's server error log, but are there any log entries within Elasticsearch itself? What Elasticsearch version?

If we hand off to Elasticsearch, at that point, it's generally out of our hands. Technically speaking, there are some internal settings for Elasticsearch that related to index refreshing intervals, though that should update the entry at some point.
No error log on ACP.
ES 5.6.3 version

Curiously, I disabled XFES addon and make new posts and it shows up on activity as it should.
 
Have you confirmed what's in the Elasticsearch log itself? No indications of any problems?
This line is in deprecation.log
Code:
[2017-11-06T20:26:52,943][WARN ][o.e.d.s.g.GroovyScriptEngineService] [groovy] scripts are deprecated, use [painless] scripts instead
In the regular log, last 100 lines
Code:
[2017-11-06T10:03:11,015][INFO ][o.e.n.Node               ] [VQDGHvy] closing ...
[2017-11-06T10:03:11,036][INFO ][o.e.n.Node               ] [VQDGHvy] closed
[2017-11-06T10:03:15,628][WARN ][o.e.b.Natives            ] unable to load JNA native support library, native methods will be disabled.
java.lang.UnsatisfiedLinkError: /tmp/jna--1985354563/jna6583798974064002109.tmp: /tmp/jna--1985354563/jna6583798974064002109.tmp: failed to map segment from shared object: Operation not permitted
        at java.lang.ClassLoader$NativeLibrary.load(Native Method) ~[?:1.8.0_151]
        at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1941) ~[?:1.8.0_151]
        at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1824) ~[?:1.8.0_151]
        at java.lang.Runtime.load0(Runtime.java:809) ~[?:1.8.0_151]
        at java.lang.System.load(System.java:1086) ~[?:1.8.0_151]
        at com.sun.jna.Native.loadNativeDispatchLibraryFromClasspath(Native.java:947) ~[jna-4.4.0-1.jar:4.4.0 (b0)]
        at com.sun.jna.Native.loadNativeDispatchLibrary(Native.java:922) ~[jna-4.4.0-1.jar:4.4.0 (b0)]
        at com.sun.jna.Native.<clinit>(Native.java:190) ~[jna-4.4.0-1.jar:4.4.0
(b0)]
        at java.lang.Class.forName0(Native Method) ~[?:1.8.0_151]
        at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_151]
        at org.elasticsearch.bootstrap.Natives.<clinit>(Natives.java:45) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Bootstrap.initializeNatives(Bootstrap.java:105) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Bootstrap.setup(Bootstrap.java:195) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Bootstrap.init(Bootstrap.java:342) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.init(Elasticsearch.java:132) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.execute(Elasticsearch.java:123) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.cli.EnvironmentAwareCommand.execute(EnvironmentAwareCommand.java:70) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.cli.Command.mainWithoutErrorHandling(Command.java:134) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.cli.Command.main(Command.java:90) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:91) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:84) [elasticsearch-5.6.3.jar:5.6.3]
[2017-11-06T10:03:15,645][WARN ][o.e.b.Natives            ] cannot check if running as root because JNA is not available
[2017-11-06T10:03:15,645][WARN ][o.e.b.Natives            ] cannot install system call filter because JNA is not available
[2017-11-06T10:03:15,646][WARN ][o.e.b.Natives            ] cannot register console handler because JNA is not available
[2017-11-06T10:03:15,650][WARN ][o.e.b.Natives            ] cannot getrlimit RLIMIT_NPROC because JNA is not available
[2017-11-06T10:03:15,650][WARN ][o.e.b.Natives            ] cannot getrlimit RLIMIT_AS beacuse JNA is not available
[2017-11-06T10:03:15,650][WARN ][o.e.b.Natives            ] cannot getrlimit RLIMIT_FSIZE because JNA is not available
[2017-11-06T10:03:15,875][INFO ][o.e.n.Node               ] [] initializing ...
[2017-11-06T10:03:16,104][INFO ][o.e.e.NodeEnvironment    ] [VQDGHvy] using [1]
data paths, mounts [[/ (rootfs)]], net usable_space [101.2gb], net total_space [232.1gb], spins? [unknown], types [rootfs]
[2017-11-06T10:03:16,104][INFO ][o.e.e.NodeEnvironment    ] [VQDGHvy] heap size
[1.9gb], compressed ordinary object pointers [true]
[2017-11-06T10:03:16,159][INFO ][o.e.n.Node               ] node name [VQDGHvy]
derived from node ID [VQDGHvy2QDmXFihGwIPzTw]; set [node.name] to override
[2017-11-06T10:03:16,160][INFO ][o.e.n.Node               ] version[5.6.3], pid[1394], build[1a2f265/2017-10-06T20:33:39.012Z], OS[Linux/3.10.0-327.3.1.el7.x86_64/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/1.8.0_151/25.151-b12]
[2017-11-06T10:03:16,161][INFO ][o.e.n.Node               ] JVM arguments [-Xms2g, -Xmx2g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -Djdk.io.permissionsUseCanonicalPath=true, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Dlog4j.skipJansi=true, -XX:+HeapDumpOnOutOfMemoryError, -Des.path.home=/usr/share/elasticsearch]
 
continue of the log
Code:
[2017-11-06T10:03:18,337][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [aggs-matrix-stats]
[2017-11-06T10:03:18,337][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [ingest-common]
[2017-11-06T10:03:18,337][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [lang-expression]
[2017-11-06T10:03:18,337][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [lang-groovy]
[2017-11-06T10:03:18,338][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [lang-mustache]
[2017-11-06T10:03:18,338][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [lang-painless]
[2017-11-06T10:03:18,338][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [parent-join]
[2017-11-06T10:03:18,338][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [percolator]
[2017-11-06T10:03:18,338][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [reindex]
[2017-11-06T10:03:18,338][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [transport-netty3]
[2017-11-06T10:03:18,339][INFO ][o.e.p.PluginsService     ] [VQDGHvy] loaded module [transport-netty4]
[2017-11-06T10:03:18,340][INFO ][o.e.p.PluginsService     ] [VQDGHvy] no plugins loaded
[2017-11-06T10:03:18,848][INFO ][o.e.s.ScriptService      ] [VQDGHvy] compiling
script file [/etc/elasticsearch/scripts/xf-date-weighted.groovy]
[2017-11-06T10:03:19,702][WARN ][o.e.w.FileWatcher        ] cannot notify file changes listener
java.lang.IllegalArgumentException: script file extension not supported [mvel]
        at org.elasticsearch.script.ScriptService.getScriptEngineServiceForFileExt(ScriptService.java:197) ~[elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.script.ScriptService.access$1000(ScriptService.java:80) ~[elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.script.ScriptService$ScriptChangesListener.onFileInit(ScriptService.java:574) ~[elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.onFileCreated(FileWatcher.java:256) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.init(FileWatcher.java:166) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.createChild(FileWatcher.java:173) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.listChildren(FileWatcher.java:188) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.onDirectoryCreated(FileWatcher.java:299) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.init(FileWatcher.java:162) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher$FileObserver.access$000(FileWatcher.java:75) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.FileWatcher.doInit(FileWatcher.java:65) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.AbstractResourceWatcher.init(AbstractResourceWatcher.java:36) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.ResourceWatcherService.add(ResourceWatcherService.java:143) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.watcher.ResourceWatcherService.add(ResourceWatcherService.java:136) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.script.ScriptService.<init>(ScriptService.java:167) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.script.ScriptModule.<init>(ScriptModule.java:72) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.script.ScriptModule.create(ScriptModule.java:59) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.node.Node.<init>(Node.java:338) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.node.Node.<init>(Node.java:245) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Bootstrap$5.<init>(Bootstrap.java:233) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Bootstrap.setup(Bootstrap.java:233) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Bootstrap.init(Bootstrap.java:342) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.init(Elasticsearch.java:132) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.execute(Elasticsearch.java:123) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.cli.EnvironmentAwareCommand.execute(EnvironmentAwareCommand.java:70) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.cli.Command.mainWithoutErrorHandling(Command.java:134) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.cli.Command.main(Command.java:90) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:91) [elasticsearch-5.6.3.jar:5.6.3]
        at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:84) [elasticsearch-5.6.3.jar:5.6.3]
[2017-11-06T10:03:19,707][INFO ][o.e.s.ScriptService      ] [VQDGHvy] compiling
script file [/etc/elasticsearch/scripts/xf-date-weighted.painless]
[2017-11-06T10:03:23,684][INFO ][o.e.d.DiscoveryModule    ] [VQDGHvy] using discovery type [zen]
[2017-11-06T10:03:25,146][INFO ][o.e.n.Node               ] initialized
[2017-11-06T10:03:25,146][INFO ][o.e.n.Node               ] [VQDGHvy] starting ...
[2017-11-06T10:03:25,498][INFO ][o.e.t.TransportService   ] [VQDGHvy] publish_address {127.0.0.1:9300}, bound_addresses {127.0.0.1:9300}
[2017-11-06T10:03:25,529][WARN ][o.e.b.BootstrapChecks    ] [VQDGHvy] system call filters failed to install; check the logs and fix your configuration or disable system call filters at your own risk
[2017-11-06T10:03:28,639][INFO ][o.e.c.s.ClusterService   ] [VQDGHvy] new_master {VQDGHvy}{VQDGHvy2QDmXFihGwIPzTw}{mBn3O3-YSyCFk2GvSgS62A}{127.0.0.1}{127.0.0.1:9300}, reason: zen-disco-elected-as-master ([0] nodes joined)
[2017-11-06T10:03:28,671][INFO ][o.e.h.n.Netty4HttpServerTransport] [VQDGHvy] publish_address {127.0.0.1:9200}, bound_addresses {127.0.0.1:9200}
[2017-11-06T10:03:28,672][INFO ][o.e.n.Node               ] [VQDGHvy] started
[2017-11-06T10:03:29,111][INFO ][o.e.g.GatewayService     ] [VQDGHvy] recovered
[2] indices into cluster_state
[2017-11-06T10:03:29,857][INFO ][o.e.c.r.a.AllocationService] [VQDGHvy] Cluster
health status changed from [RED] to [YELLOW] (reason: [shards started [[quantnet_xf][2]] ...]).
[2017-11-06T16:48:20,483][INFO ][o.e.c.m.MetaDataDeleteIndexService] [VQDGHvy] [quantnet/_Zrdx5oAQvmqP-BMdPnROQ] deleting index
[2017-11-06T16:48:20,686][INFO ][o.e.c.m.MetaDataCreateIndexService] [VQDGHvy] [quantnet] creating index, cause [api], templates [], shards [5]/[1], mappings [xf]
[2017-11-06T16:49:13,070][INFO ][o.e.c.m.MetaDataMappingService] [VQDGHvy] [quantnet/VLPUrYaZT4ihWBp6NsEa3A] update_mapping [xf]
[2017-11-06T16:49:14,332][INFO ][o.e.c.m.MetaDataMappingService] [VQDGHvy] [quantnet/VLPUrYaZT4ihWBp6NsEa3A] update_mapping [xf]
[2017-11-06T16:49:14,401][INFO ][o.e.c.m.MetaDataMappingService] [VQDGHvy] [quantnet/VLPUrYaZT4ihWBp6NsEa3A] update_mapping [xf]
[2017-11-06T16:53:11,582][INFO ][o.e.c.m.MetaDataMappingService] [VQDGHvy] [quantnet/VLPUrYaZT4ihWBp6NsEa3A] update_mapping [xf]
[2017-11-06T16:53:28,857][INFO ][o.e.c.m.MetaDataMappingService] [VQDGHvy] [quantnet/VLPUrYaZT4ihWBp6NsEa3A] update_mapping [xf]
[2017-11-06T16:54:03,567][INFO ][o.e.c.m.MetaDataMappingService] [VQDGHvy] [quantnet/VLPUrYaZT4ihWBp6NsEa3A] update_mapping [xf]
 
I am getting this exact same issue too.

search filtered by member does not update results after a index rebuild, however, post content does update immediately with each post.

installed yesterday, latest stable xenforo addon (not 2.0) and using AWS elasticsearch service within my VPC. version 5.5

search settings are;
relevancy on
enable recency on
half-life 365
dynamic scripting on

'Index Updates' stats (found at tools > elasticsearch setup) increment with each post and new posts appear immediately in general search, however 'Your Content' is frozen at the time of rebuild of index completion (about 18 hours ago) and do not update with users new posts since reindex .

It feels like a cached search problem, but suspect it's more a 'tag' or 'indices' issue not being pushed with each new post to elastisearch - as all members filtered searches return results that finish at time of last full reindex.
 
Last edited:
It looks like I can reproduce this in Elasticsearch 5.6.4, but it appears to only be applied in single type mode, which shouldn't be enabled unless you use Elasticsearch 6.

I'm not sure why that option would be enabled for you automatically (I can see it is enabled from the log output). Try disabling the "Enable single type mode in Elasticsearch" option and then deleting the index via the "Elasticsearch setup" page. Does it get re-enabled?
 
It looks like I can reproduce this in Elasticsearch 5.6.4, but it appears to only be applied in single type mode, which shouldn't be enabled unless you use Elasticsearch 6.

I'm not sure why that option would be enabled for you automatically (I can see it is enabled from the log output). Try disabling the "Enable single type mode in Elasticsearch" option and then deleting the index via the "Elasticsearch setup" page. Does it get re-enabled?
Disabled, deleted index, rebuilt index and the option is not re-enabled again.
Here's the fix for the issue itself: https://xenforo.com/community/threa...xed-properly-in-xfes-single-type-mode.136974/

However, I'm curious how you ended up getting single-type mode enabled, as the automatic checks for this should only trigger in Elasticsearch 6. Was this done manually?
Got the fix and it seems to be working as it should. I definitely did not enable that single type option. Most likely scenario is that I once upgraded ES to 6 and then go back to 5.6.x
I even remove ES completely and reinstalled ES from my server again. Looks like that option got enabled once the server got ES 6 and it got stuck there even I downgraded to 5.6.x
 
Here's the fix for the issue itself: https://xenforo.com/community/threa...xed-properly-in-xfes-single-type-mode.136974/

However, I'm curious how you ended up getting single-type mode enabled, as the automatic checks for this should only trigger in Elasticsearch 6. Was this done manually?


Confirming that this has fixed my install.

Single type was enabled,
(Note, when recreating the search index, this option may be automatically enabled if necessary.)

I thought it had enabled itself so left it that way (even though I knew my elasticache was 5.5). I now strongly suspect PEBCAK scenario.

Thank you for investigating.

I should have thought to toggle it myself and test - so obvious now it is revealed.
 
Top Bottom