Workplace search loading time problem

Gunbay_Park · April 4, 2023, 4:56am

HI, there.
I'm testing workplace search in internetless intranet env.
When I start workplace search (x.x.x.x:5601/ws/search) ,
it takes time too long to open first page. it takes almost 90 seconds.
After opening first pgae it works well without congestion.

I tried same workplace search in internet env also and it took just five seconds to open.

I think WS try to connet internet when it initialize and that is why page open is so slow.

Is there any way to reduce loading time?
thanks for listening.

Sean_Story · April 4, 2023, 2:50pm

Hi @Gunbay_Park ,

Workplace Search's UI isn't trying to access the internet on startup. However, Enterprise Search's app server, which is the backend for the x.x.x.x:5601/ws/search, can take a minute or two to boot. Are you sure that you'd waited for the server to be running in your intranet example?

If so, you could open up your browser dev tools and watch the network tab, to see if you're just having a network latency issue in your intranet deployment.

Gunbay_Park · April 5, 2023, 2:33am

Thanks for your advice, Sean.
I attach my WS startup network capture image.
It still takes about one minute to start.

My content source is just index for intranet DB custom api.
I tested to set all source unsearchable and loaded WS but still took time one minute more.

In bottom of captured image, error messages says " failed to load resource: net : err_connection_timed_out" and those points some css files.
I'm curious those css file cause congestion.

Please let me know if there is way to solve this problem. thank you.

Sander_Philipse · April 5, 2023, 4:28pm

Hi @Gunbay_Park, I would expect those CSS files to be symptoms of the problem rather than a cause. Browsers should continue rendering even if CSS files are unavailable. It looks like the website content itself loaded after about 300ms in your screenshot, was this a screenshot of an occurrence of this delay issue?

Could you look at the logging of your Enterprise Search server when trying a request like this? It's more likely to provide useful information, as the issue is probably on the server side rather than the client side.

Gunbay_Park · April 5, 2023, 11:44pm

My carpture image doesn't look like it took 80 seconds, but it really did.
Then I attach my Enterprise-search log with WS startup.
It took about one minute to startup and
23:18:56 is the time of workplace search finished startup.
And my elasticsearch version is 8.5.3
Thank you Sander.

login as: search
search@192.168.150.140's password:
Last login: Wed Apr 5 17:47:59 2023 from 172.16.201.60
TMOUT=0
(base) [search@datamine ~]$ TMOUT=0
(base) [search@datamine ~]$ ps -ef |grep enterprise
search 11815 1 0 4 03 00:01:46 /home/search/enterprise-search-8.5.3/bin/vendor/filebeat/filebeat-linux-x86_64 -v --path.config=/home/search/enterprise-search-8.5.3/tmp --c=ent-search-filebeat.yml
search 18812 1 3 4 05 00:37:25 java -cp /home/search/enterprise-search-8.5.3/lib/war/lib/jruby-stdlib-9.3.3.0.jar:/home/search/enterprise-search-8.5.3/lib/war/lib/jruby-core-9.3.3.0-complete.jar -Dsun.jnu.encoding=UTF-8 -Dfile.encoding=UTF-8 -Djruby.cli.warning.level=NIL -Djava.awt.headless=true -Djruby.regexp.interruptible=true -server -Xms2g -Xmx2g -Djava.io.tmpdir=/home/search/enterprise-search-8.5.3/tmp -Xlog:gc*,gc+age=trace,safepoint:file=log/gc.log:utctime,pid,tags:filecount=10,filesize=10m org.jruby.Main -r rubygems -x/home/search/enterprise-search-8.5.3/lib/war -S bin/enterprise-search-internal
search 23612 23552 0 08:17 pts/0 00:00:00 grep --color=auto enterprise
(base) [search@datamine ~]$ kill -9 18812
(base) [search@datamine ~]$ en*/bin/enterprise-search
Found java executable in PATH
Java version detected: 11.0.2 (major version: 11)
Enterprise Search is starting...
[2023-04-05T23:18:29.711+00:00][23639][4004][app-server][INFO]: Elastic Enterprise Search version=8.5.3, JRuby version=9.3.3.0, Ruby version=2.6.8, Rails version=5.2.8.1
[2023-04-05T23:18:30.711+00:00][23639][4004][app-server][INFO]: Performing pre-flight checks for Elasticsearch running on http://192.168.150.140:9200...
[2023-04-05T23:18:30.907+00:00][23639][4004][app-server][INFO]: [pre-flight] Elasticsearch cluster is ready
[2023-04-05T23:18:30.908+00:00][23639][4004][app-server][INFO]: [pre-flight] Successfully connected to Elasticsearch
[2023-04-05T23:18:30.926+00:00][23639][4004][app-server][INFO]: [pre-flight] Successfully loaded Elasticsearch plugin information for all nodes
[2023-04-05T23:18:30.930+00:00][23639][4004][app-server][INFO]: [pre-flight] Elasticsearch running with an active trial license
[2023-04-05T23:18:30.943+00:00][23639][4004][app-server][INFO]: [pre-flight] Elasticsearch API key service is enabled
[2023-04-05T23:18:30.946+00:00][23639][4004][app-server][INFO]: [pre-flight] Elasticsearch will be used for authentication
[2023-04-05T23:18:30.947+00:00][23639][4004][app-server][INFO]: Elasticsearch looks healthy and configured correctly to run Enterprise Search
[2023-04-05T23:18:30.948+00:00][23639][4004][app-server][INFO]: Performing pre-flight checks for Kibana running on http://192.168.150.140:5601...
[2023-04-05T23:18:30.969+00:00][23639][4004][app-server][INFO]: [pre-flight] Successfully connected to Kibana
[2023-04-05T23:18:31.039+00:00][23639][4004][app-server][INFO]: Kibana looks healthy and configured correctly to run Enterprise Search
[2023-04-05T23:18:33.378+00:00][23639][4004][app-server][INFO]: Elastic APM agent is disabled
[2023-04-05T23:18:39.876+00:00][23639][4004][app-server][WARN]: Index .elastic-connectors-v1 already exists!
[2023-04-05T23:18:39.885+00:00][23639][4004][app-server][WARN]: Going to re-create the existing empty index .elastic-connectors-v1
[2023-04-05T23:18:39.996+00:00][23639][4004][app-server][WARN]: Index .elastic-connectors-sync-jobs-v1 already exists!
[2023-04-05T23:18:40.005+00:00][23639][4004][app-server][WARN]: Going to re-create the existing empty index .elastic-connectors-sync-jobs-v1
[2023-04-05T23:18:40.088+00:00][23639][4004][app-server][INFO]: [db_lock] [installation] Status: [Starting] Ensuring migrations tracking index exists
[2023-04-05T23:18:40.110+00:00][23639][4004][app-server][INFO]: [db_lock] [installation] Status: [Finished] Ensuring migrations tracking index exists
[2023-04-05T23:18:40.242+00:00][23639][4004][app-server][INFO]: Found no migrations to run
[2023-04-05T23:18:40.242+00:00][23639][4004][app-server][INFO]: Enterprise Search indices are ready
[2023-04-05T23:18:40.296+00:00][23639][4004][app-server][INFO]: Elasticsearch ingest pipeline app_search_crawler (version 1) already exists
[2023-04-05T23:18:40.300+00:00][23639][4004][app-server][INFO]: Elasticsearch ingest pipeline ent_search_connector (version 2) already exists
[2023-04-05T23:18:40.305+00:00][23639][4004][app-server][INFO]: Elasticsearch ingest pipeline ent-search-generic-ingestion (version 1) already exists
[2023-04-05T23:18:40.309+00:00][23639][4004][app-server][INFO]: Elasticsearch ingest pipeline ent_search_crawler (version 2) already exists
[2023-04-05T23:18:40.315+00:00][23639][4004][app-server][INFO]: Elasticsearch ingest pipeline elastic_analytics_events (version 1) already exists
[2023-04-05T23:18:41.518+00:00][23639][4004][app-server][INFO]: Starting background workers...
[2023-04-05T23:18:41.520+00:00][23639][4004][app-server][INFO]: [workers] Configuring periodic background jobs...
[2023-04-05T23:18:41.521+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job CleanupHeartbeatIndex: {:execution_interval=>300, :timeout_interval=>30, :run_now=>false}
[2023-04-05T23:18:41.523+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job RefreshElasticsearchLicense: {:execution_interval=>60, :timeout_interval=>30, :run_now=>false}
[2023-04-05T23:18:41.523+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job RefreshFritoPieContentSources: {:execution_interval=>360, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.525+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job UpdateCustomSourcesConfig: {:execution_interval=>360, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.525+00:00][23639][4380][app-server][INFO]: Running task: RefreshFritoPieContentSources
[2023-04-05T23:18:41.526+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job DeleteOldConnectorsJobs: {:execution_interval=>21600, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.526+00:00][23639][4388][app-server][INFO]: Running task: UpdateCustomSourcesConfig
[2023-04-05T23:18:41.527+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job DeleteOldDoorkeeperRecords: {:execution_interval=>21600, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.530+00:00][23639][4380][cron-Work::Cron::RefreshFritoPieContentSources][INFO]: Performing task: RefreshFritoPieContentSources
[2023-04-05T23:18:41.530+00:00][23639][4388][cron-Work::Cron::UpdateCustomSourcesConfig][INFO]: Performing task: UpdateCustomSourcesConfig
[2023-04-05T23:18:41.530+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job KeepSidecarsAlive: {:execution_interval=>300, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.531+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job ScheduleCrawls: {:execution_interval=>3600, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.533+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job ScheduleCrawls2: {:execution_interval=>3600, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.535+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job SendTelemetry: {:execution_interval=>21600, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.536+00:00][23639][4004][app-server][INFO]: [workers] Configuring background job UpdateSearchRelevanceSuggestions: {:execution_interval=>60, :timeout_interval=>30, :run_now=>true}
[2023-04-05T23:18:41.537+00:00][23639][4004][app-server][INFO]: [workers] Configuring background jobs for Workplace Search Connectors...
[2023-04-05T23:18:41.538+00:00][23639][4004][connectors][INFO]: Starting to process jobs.
[2023-04-05T23:18:41.541+00:00][23639][4428][app-server][INFO]: Running task: DeleteOldConnectorsJobs
[2023-04-05T23:18:41.543+00:00][23639][4432][app-server][INFO]: Running task: DeleteOldDoorkeeperRecords
[2023-04-05T23:18:41.544+00:00][23639][4004][app-server][INFO]: [workers] Starting a background process for the Crawl Queue Manager...
[2023-04-05T23:18:41.544+00:00][23639][4456][app-server][INFO]: Running task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:18:41.545+00:00][23639][4432][cron-Work::Cron::DeleteOldDoorkeeperRecords][INFO]: Performing task: DeleteOldDoorkeeperRecords
[2023-04-05T23:18:41.545+00:00][23639][4428][cron-Work::Cron::DeleteOldConnectorsJobs][INFO]: Performing task: DeleteOldConnectorsJobs
[2023-04-05T23:18:41.547+00:00][23639][4456][cron-Work::Cron::UpdateSearchRelevanceSuggestions][INFO]: Performing task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:18:41.548+00:00][23639][4004][app-server][INFO]: [workers] Starting a background process for the Crawler2 Queue Manager...
[2023-04-05T23:18:41.549+00:00][23639][4484][app-server][INFO]: Running task: ScheduleCrawls2
[2023-04-05T23:18:41.550+00:00][23639][4492][app-server][INFO]: Running task: ScheduleCrawls
[2023-04-05T23:18:41.557+00:00][23639][4004][app-server][INFO]: [workers] Starting crawler watchers
[2023-04-05T23:18:41.558+00:00][23639][4528][app-server][INFO]: Running task: KeepSidecarsAlive
[2023-04-05T23:18:41.558+00:00][23639][4536][app-server][INFO]: Running task: SendTelemetry
[2023-04-05T23:18:41.566+00:00][23639][4484][cron-Work::Cron::ScheduleCrawls2][INFO]: Performing task: ScheduleCrawls2
[2023-04-05T23:18:41.566+00:00][23639][4492][cron-Work::Cron::ScheduleCrawls][INFO]: Performing task: ScheduleCrawls
[2023-04-05T23:18:41.568+00:00][23639][4564][crawler2][INFO]: [cqm] Starting CQM monitoring loop (with support for up to 16 parallel crawls)...
[2023-04-05T23:18:41.570+00:00][23639][4576][crawler][INFO]: [cqm] Starting CQM monitoring loop (with support for up to 16 parallel crawls)...
[2023-04-05T23:18:41.574+00:00][23639][4004][app-server][INFO]: Starting asynchronous processing workers...
[2023-04-05T23:18:41.581+00:00][23639][4592][app-server][INFO]: [workers] Starting EsqueuesMe background jobs...
[2023-04-05T23:18:41.596+00:00][23639][4528][cron-Work::Cron::KeepSidecarsAlive][INFO]: Performing task: KeepSidecarsAlive
[2023-04-05T23:18:41.596+00:00][23639][4528][app-server][INFO]: [sidecar] [filebeat] Starting the child process...
[2023-04-05T23:18:41.601+00:00][23639][4528][app-server][INFO]: [sidecar] [filebeat] Writing config: /home/search/enterprise-search-8.5.3/tmp/ent-search-filebeat.yml
[2023-04-05T23:18:41.601+00:00][23639][4536][cron-Work::Cron::SendTelemetry][INFO]: Performing task: SendTelemetry
[2023-04-05T23:18:41.584+00:00][23639][4592][worker][INFO]: Ensuring esqueues me queues exist
[2023-04-05T23:18:41.639+00:00][23639][4380][cron-Work::Cron::RefreshFritoPieContentSources][INFO]: Done performing task: RefreshFritoPieContentSources
[2023-04-05T23:18:41.640+00:00][23639][4380][app-server][INFO]: Done running task: RefreshFritoPieContentSources
[2023-04-05T23:18:41.643+00:00][23639][4432][cron-Work::Cron::DeleteOldDoorkeeperRecords][INFO]: Done performing task: DeleteOldDoorkeeperRecords
[2023-04-05T23:18:41.643+00:00][23639][4432][app-server][INFO]: Done running task: DeleteOldDoorkeeperRecords
[2023-04-05T23:18:41.644+00:00][23639][4492][cron-Work::Cron::ScheduleCrawls][INFO]: Done performing task: ScheduleCrawls
[2023-04-05T23:18:41.647+00:00][23639][4492][app-server][INFO]: Done running task: ScheduleCrawls
[2023-04-05T23:18:41.663+00:00][23639][4484][cron-Work::Cron::ScheduleCrawls2][INFO]: Done performing task: ScheduleCrawls2
[2023-04-05T23:18:41.664+00:00][23639][4484][app-server][INFO]: Done running task: ScheduleCrawls2
2023-04-06 08:18:41.712:INFO::main: Logging initialized @23281ms to org.eclipse.jetty.util.log.StdErrLog
[2023-04-05T23:18:41.950+00:00][23639][4528][app-server][INFO]: [sidecar] [filebeat] Started a child process with PID #23736
[2023-04-05T23:18:41.968+00:00][23639][4456][cron-Work::Cron::UpdateSearchRelevanceSuggestions][INFO]: Done performing task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:18:41.987+00:00][23639][4592][worker][INFO]: Ensuring heartbeat index exists
[2023-04-05T23:18:41.991+00:00][23639][4456][app-server][INFO]: Done running task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:18:42.073+00:00][23639][4592][worker][INFO]: esqueues me while I process jobs on engine_destroyer, process_crawl, mailer, process_crawl2
[2023-04-05T23:18:42.073+00:00][23639][4528][app-server][INFO]: [sidecar] [metricbeat] Writing config: /home/search/enterprise-search-8.5.3/tmp/ent-search-metricbeat.yml
[2023-04-05T23:18:42.080+00:00][23639][4528][app-server][INFO]: [sidecar] [metricbeat] Sidecar process disabled
[2023-04-05T23:18:42.081+00:00][23639][4528][cron-Work::Cron::KeepSidecarsAlive][INFO]: Done performing task: KeepSidecarsAlive
[2023-04-05T23:18:42.081+00:00][23639][4528][app-server][INFO]: Done running task: KeepSidecarsAlive
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.jruby.javasupport.binding.ConstantField (file:/home/search/enterprise-search-8.5.3/lib/war/lib/jruby-core-9.3.3.0-complete.jar) to field com.sun.jmx.mbeanserver.JmxMBeanServer.DEFAULT_FAIR_LOCK_POLICY
WARNING: Please consider reporting this to the maintainers of org.jruby.javasupport.binding.ConstantField
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
[2023-04-05T23:18:42.328+00:00][23639][4004][app-server][INFO]: Starting HTTP server...
2023-04-06 08:18:42.333:INFO:oejs.Server:main: jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git: 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm 11.0.2+9
[2023-04-05T23:18:42.362+00:00][23639][4536][cron-Work::Cron::SendTelemetry][INFO]: Done performing task: SendTelemetry
[2023-04-05T23:18:42.362+00:00][23639][4536][app-server][INFO]: Done running task: SendTelemetry
2023-04-06 08:18:42.375:INFO:oejsh.ContextHandler:main: Started o.e.j.s.ServletContextHandler@434522b7{/,file:///home/search/enterprise-search-8.5.3/lib/war/,AVAILABLE}
2023-04-06 08:18:42.401:INFO:oejs.AbstractConnector:main: Started ServerConnector@4fc5f450{HTTP/1.1, (http/1.1)}{192.168.150.140:3002}
2023-04-06 08:18:42.402:INFO:oejs.Server:main: Started @23971ms
[2023-04-05T23:18:42.402+00:00][23639][4004][app-server][INFO]: Jetty successfully started and is ready to handle requests!
[2023-04-05T23:18:42.403+00:00][23639][4004][app-server][INFO]:
#########################################################

Success! Elastic Enterprise Search is starting successfully.

Advanced tooling and management interfaces are available via Kibana. Learn more about configuring and running
Kibana with Enterprise Search at https://www.elastic.co/guide/en/enterprise-search/master/user-interfaces.html.

In a few moments, you'll be able to access Enterprise Search from Kibana at the following address:

Kibana URL: http://192.168.150.140:5601/app/enterprise_search/overview

If this is your first time starting Enterprise Search, check the console output above for your user authentication credentials.

Visit the documentation: Elastic Enterprise Search documentation [master] | Elastic

#########################################################

[2023-04-05T23:18:42.459+00:00][23639][4388][cron-Work::Cron::UpdateCustomSourcesConfig][INFO]: Done performing task: UpdateCustomSourcesConfig
[2023-04-05T23:18:42.460+00:00][23639][4388][app-server][INFO]: Done running task: UpdateCustomSourcesConfig
[2023-04-05T23:18:42.635+00:00][23639][4428][cron-Work::Cron::DeleteOldConnectorsJobs][INFO]: Done performing task: DeleteOldConnectorsJobs
[2023-04-05T23:18:42.636+00:00][23639][4428][app-server][INFO]: Done running task: DeleteOldConnectorsJobs
[2023-04-05T23:18:54.370+00:00][23639][5008][app-server][INFO]: [da49260d-f120-48f0-a787-59e38a6f9c16] Started GET "/ws/search" for 172.16.201.60 at 2023-04-05 23:18:54 +0000
[2023-04-05T23:18:54.440+00:00][23639][5008][action_controller][INFO]: Processing by SessionFailureController#index as HTML
[2023-04-05T23:18:54.455+00:00][23639][5008][action_controller][INFO]: Redirected to http://192.168.150.140:5601/app/enterprise_search/workplace_search/p/authorize_search?state=TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ%3D%3D
[2023-04-05T23:18:54.455+00:00][23639][5008][action_controller][INFO]: Completed 302 Found in 14ms
172.16.201.60 - - [05/4월/2023:23:18:54 +0000] "GET /ws/search HTTP/1.1" 302 282 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:18:56.202+00:00][23639][5024][app-server][INFO]: [918f02b4-e7a5-4c8a-9716-a5df084e0d9e] Started GET "/api/ent/v2/internal/client_config" for 192.168.150.140 at 2023-04-05 23:18:56 +0000
[2023-04-05T23:18:56.210+00:00][23639][5024][action_controller][INFO]: Processing by Api::SharedTogo::V2::Internal::ClientConfigController#show as /
[2023-04-05T23:18:56.404+00:00][23639][5024][action_controller][INFO]: Completed 200 OK in 193ms (Views: 1.5ms)
192.168.150.140 - - [05/4월/2023:23:18:56 +0000] "GET /api/ent/v2/internal/client_config HTTP/1.1" 200 1049 "-" "node-fetch/1.0 (+https://github.com/bitinn/node-fetch)"
[2023-04-05T23:18:56.569+00:00][23639][5044][app-server][INFO]: [e88095b2-2dc1-48ef-8aea-6ba1e317425e] Started GET "/ws/oauth/authorize?client_id=e53876d47a463841eccfe0ec37ac5adb5cab252b3f241668824e77e7dc4b7d0e&response_type=code&redirect_uri=http%3A%2F%2F192.168.150.140%3A3002%2Fws%2Fsearch_callback&scope=default_search&state=TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ%3D%3D" for 192.168.150.140 at 2023-04-05 23:18:56 +0000
[2023-04-05T23:18:56.575+00:00][23639][5044][action_controller][INFO]: Processing by FritoPie::Oauth::AuthorizationsController#new as JSON
[2023-04-05T23:18:56.576+00:00][23639][5044][action_controller][INFO]: Parameters: {"client_id"=>"e53876d47a463841eccfe0ec37ac5adb5cab252b3f241668824e77e7dc4b7d0e", "response_type"=>"code", "redirect_uri"=>"http://192.168.150.140:3002/ws/search_callback", "scope"=>"default_search", "state"=>"TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ=="}
[2023-04-05T23:18:56.724+00:00][23639][5044][action_controller][INFO]: Completed 200 OK in 147ms (Views: 0.4ms)
192.168.150.140 - - [05/4월/2023:23:18:56 +0000] "GET /ws/oauth/authorize?client_id=e53876d47a463841eccfe0ec37ac5adb5cab252b3f241668824e77e7dc4b7d0e&response_type=code&redirect_uri=http%3A%2F%2F192.168.150.140%3A3002%2Fws%2Fsearch_callback&scope=default_search&state=TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ%3D%3D HTTP/1.1" 200 331 "-" "node-fetch/1.0 (+https://github.com/bitinn/node-fetch)"
[2023-04-05T23:18:56.764+00:00][23639][5056][app-server][INFO]: [47c6a47d-22ec-4b4c-a16e-d11c53a01419] Started POST "/ws/oauth/authorize" for 192.168.150.140 at 2023-04-05 23:18:56 +0000
[2023-04-05T23:18:56.770+00:00][23639][5056][action_controller][INFO]: Processing by FritoPie::Oauth::AuthorizationsController#create as JSON
[2023-04-05T23:18:56.771+00:00][23639][5056][action_controller][INFO]: Parameters: {"client_id"=>"e53876d47a463841eccfe0ec37ac5adb5cab252b3f241668824e77e7dc4b7d0e", "response_type"=>"code", "redirect_uri"=>"http://192.168.150.140:3002/ws/search_callback", "scope"=>"default_search", "state"=>"TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ=="}
[2023-04-05T23:18:56.919+00:00][23639][5056][action_controller][INFO]: Completed 200 OK in 148ms (Views: 0.4ms)
192.168.150.140 - - [05/4월/2023:23:18:56 +0000] "POST /ws/oauth/authorize HTTP/1.1" 200 271 "-" "node-fetch/1.0 (+https://github.com/bitinn/node-fetch)"
[2023-04-05T23:18:56.943+00:00][23639][5024][app-server][INFO]: [8c1352bf-4ece-4d09-b885-97c6053bfb01] Started GET "/ws/search_callback?code=[FILTERED]&state=TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ%3D%3D" for 172.16.201.60 at 2023-04-05 23:18:56 +0000
[2023-04-05T23:18:56.955+00:00][23639][5024][action_controller][INFO]: Processing by FritoPie::EwebController#authenticate as HTML
[2023-04-05T23:18:56.955+00:00][23639][5024][action_controller][INFO]: Parameters: {"code"=>"[FILTERED]", "state"=>"TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ=="}
[2023-04-05T23:18:57.020+00:00][23639][5024][action_controller][INFO]: Redirected to http://192.168.150.140:3002/ws/search
[2023-04-05T23:18:57.035+00:00][23639][5024][action_controller][INFO]: Completed 302 Found in 79ms
172.16.201.60 - - [05/4월/2023:23:18:56 +0000] "GET /ws/search_callback?code=f2abeca6c0d48e4cc0281ff3d5a750e0529c9e8aad4a2fb09a6fdc8fbb65c4ef&state=TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ%3D%3D HTTP/1.1" 302 103 "http://192.168.150.140:5601/app/enterprise_search/workplace_search/p/authorize_search?state=TkxySnhnTUgrbk9HMGVDRGlNNU80ZkZPVzU4RzNVY3dZZzdiSXV1UkU4R0pzRVFXUnNDMU91ZWJWVVdCV3kyL01UYTVxWnVIalZFYWUwWVhKUE9pOEE9PQ%3D%3D" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:18:57.050+00:00][23639][5072][app-server][INFO]: [2f59cf15-cc47-499c-82fc-29078d2bafab] Started GET "/ws/search" for 172.16.201.60 at 2023-04-05 23:18:57 +0000
[2023-04-05T23:18:57.060+00:00][23639][5072][action_controller][INFO]: Processing by FritoPie::EwebController#index as HTML
[2023-04-05T23:18:57.098+00:00][23639][5072][action_view][INFO]: Rendering frito_pie/app/views/frito_pie/eweb/index.html.rb
[2023-04-05T23:18:57.139+00:00][23639][5072][action_view][INFO]: Rendered frito_pie/app/views/frito_pie/eweb/index.html.rb (40.4ms)
[2023-04-05T23:18:57.161+00:00][23639][5072][action_controller][INFO]: Completed 200 OK in 100ms (Views: 57.7ms)
172.16.201.60 - - [05/4월/2023:23:18:57 +0000] "GET /ws/search HTTP/1.1" 200 764 "http://192.168.150.140:5601/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:19:41.525+00:00][23639][4388][app-server][INFO]: Running task: RefreshElasticsearchLicense
[2023-04-05T23:19:41.531+00:00][23639][4388][cron-Work::Cron::RefreshElasticsearchLicense][INFO]: Performing task: RefreshElasticsearchLicense
[2023-04-05T23:19:41.538+00:00][23639][4388][cron-Work::Cron::RefreshElasticsearchLicense][INFO]: Done performing task: RefreshElasticsearchLicense
[2023-04-05T23:19:41.539+00:00][23639][4388][app-server][INFO]: Done running task: RefreshElasticsearchLicense
[2023-04-05T23:19:41.995+00:00][23639][4388][app-server][INFO]: Running task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:19:41.996+00:00][23639][4388][cron-Work::Cron::UpdateSearchRelevanceSuggestions][INFO]: Performing task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:19:42.069+00:00][23639][4388][cron-Work::Cron::UpdateSearchRelevanceSuggestions][INFO]: Done performing task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:19:42.070+00:00][23639][4388][app-server][INFO]: Done running task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:20:21.383+00:00][23639][5008][app-server][INFO]: [370284d6-aa8d-4ca3-83b4-bbb101253af3] Started GET "/ws/authenticate/my_user_info" for 172.16.201.60 at 2023-04-05 23:20:21 +0000
[2023-04-05T23:20:21.393+00:00][23639][5008][action_controller][INFO]: Processing by FritoPie::AuthenticateController#my_user_info as JSON
172.16.201.60 - - [05/4월/2023:23:20:21 +0000] "GET /swiftype-app-version?ts=1680736821351 HTTP/1.1" 200 80 "http://192.168.150.140:3002/ws/search" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Mobile Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:20:21.567+00:00][23639][5008][action_controller][INFO]: Completed 200 OK in 174ms (Views: 0.7ms)
172.16.201.60 - - [05/4월/2023:23:20:21 +0000] "GET /ws/authenticate/my_user_info HTTP/1.1" 304 0 "http://192.168.150.140:3002/ws/search" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Mobile Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:20:21.625+00:00][23639][5024][app-server][INFO]: [94c79f2c-5e92-4ff5-8492-29742efecef5] Started GET "/ws/sources/status?searchable_only=true&fetch_icons=true" for 172.16.201.60 at 2023-04-05 23:20:21 +0000
[2023-04-05T23:20:21.626+00:00][23639][5116][app-server][INFO]: [c0dd73dc-793c-43f3-a312-dd3317d9261c] Started GET "/ws/query/trigger_prefetch_suggestions" for 172.16.201.60 at 2023-04-05 23:20:21 +0000
[2023-04-05T23:20:21.626+00:00][23639][5072][app-server][INFO]: [f93f294d-21a2-4cba-a0ca-82f004896e3c] Started GET "/ws/query/history_prefetch_suggestions" for 172.16.201.60 at 2023-04-05 23:20:21 +0000
[2023-04-05T23:20:21.640+00:00][23639][5024][action_controller][INFO]: Processing by FritoPie::ContentSourcesController#status as /
[2023-04-05T23:20:21.641+00:00][23639][5024][action_controller][INFO]: Parameters: {"searchable_only"=>"true", "fetch_icons"=>"true", "context"=>:account}
[2023-04-05T23:20:21.641+00:00][23639][5056][app-server][INFO]: [9df7e48a-c867-4f55-acb9-8eca97ade811] Started POST "/ws/query/search.json" for 172.16.201.60 at 2023-04-05 23:20:21 +0000
[2023-04-05T23:20:21.643+00:00][23639][5072][action_controller][INFO]: Processing by FritoPie::Query::QueryController#history_prefetch_suggestions as JSON
[2023-04-05T23:20:21.644+00:00][23639][5116][action_controller][INFO]: Processing by FritoPie::Query::QueryController#trigger_prefetch_suggestions as JSON
[2023-04-05T23:20:21.652+00:00][23639][5056][action_controller][INFO]: Processing by FritoPie::Query::QueryController#search as JSON
[2023-04-05T23:20:21.653+00:00][23639][5056][action_controller][INFO]: Parameters: {"q"=>"", "page"=>"1", "per_page"=>"10", "filters"=>{"all"=>{"source"=>{"type"=>"and", "values"=>["!crawler", "!custom"]}}}, "sort_field"=>{"all"=>"last_updated"}, "spelling"=>"", "document_types"=>["all"]}
[2023-04-05T23:20:21.779+00:00][23639][5072][action_controller][INFO]: Completed 200 OK in 135ms (Views: 0.7ms)
172.16.201.60 - - [05/4월/2023:23:20:21 +0000] "GET /ws/query/history_prefetch_suggestions HTTP/1.1" 304 0 "http://192.168.150.140:3002/ws/search" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Mobile Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:20:21.844+00:00][23639][5116][action_controller][INFO]: Completed 200 OK in 200ms (Views: 0.4ms)
172.16.201.60 - - [05/4월/2023:23:20:21 +0000] "GET /ws/query/trigger_prefetch_suggestions HTTP/1.1" 304 0 "http://192.168.150.140:3002/ws/search" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Mobile Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:20:22.027+00:00][23639][5024][action_controller][INFO]: Completed 200 OK in 386ms (Views: 2.1ms)
172.16.201.60 - - [05/4월/2023:23:20:21 +0000] "GET /ws/sources/status?searchable_only=true&fetch_icons=true HTTP/1.1" 304 0 "http://192.168.150.140:3002/ws/search" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Mobile Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:20:22.358+00:00][23639][5056][active_job][INFO]: Enqueued Work::FritoPie::EmitAnalyticsEvent job (4e7e790c-c1a4-4a43-9f59-a04768609cc7) on unknown
[2023-04-05T23:20:22.361+00:00][23639][5056][active_job][INFO]: Enqueued Work::FritoPie::EmitAnalyticsEvent (Job ID: 4e7e790c-c1a4-4a43-9f59-a04768609cc7) to Async(unknown) with arguments: "emit_frito_pie_query", {:start_time=>1680736821.768144, :account_id=>"63ff376d6b0b6d4946eccd00", :request_id=>"9df7e48a-c867-4f55-acb9-8eca97ade811", :remote_ip=>"172.16.201.60", :query_info=>{:value=>"", :submitted_query=>"", :refinements=>, :filters=>["{"all":{"source":{"type":"and","values":["!crawler","!custom"]}}}"], :content_sources=>["64008d1a6b0b6d68e200a8d3", "64015ebd6b0b6d486ac34646", "642531096b0b6d524646b0f7", "6428e7ed6b0b6d3df54ea7b5", "642915ac6b0b6d963951e376", "64293bfa6b0b6ddd4058ec3c", "642a51ad6b0b6d044158f2fd", "642c1d256b0b6d3f40ebe9d6", "642c1ea36b0b6d3f40ebea02", "642c1f496b0b6d56aaebea43", "642cc2626b0b6d3099ebf23f", "642cfce06b0b6d32c00a8f51", "642d54d66b0b6d62de0a9083"], :query_hash=>"LVYunLaiLJrED0dTQjSyOuwe62M="}, :duration=>581050157, :page=>1, :total=>0, :documents_payload=>, :tags=>["eweb"]}
[2023-04-05T23:20:22.367+00:00][23639][5168][active_job][INFO]: Performing Work::FritoPie::EmitAnalyticsEvent (Job ID: 4e7e790c-c1a4-4a43-9f59-a04768609cc7) from Async(unknown) with arguments: "emit_frito_pie_query", {:start_time=>1680736821.768144, :account_id=>"63ff376d6b0b6d4946eccd00", :request_id=>"9df7e48a-c867-4f55-acb9-8eca97ade811", :remote_ip=>"172.16.201.60", :query_info=>{:value=>"", :submitted_query=>"", :refinements=>, :filters=>["{"all":{"source":{"type":"and","values":["!crawler","!custom"]}}}"], :content_sources=>["64008d1a6b0b6d68e200a8d3", "64015ebd6b0b6d486ac34646", "642531096b0b6d524646b0f7", "6428e7ed6b0b6d3df54ea7b5", "642915ac6b0b6d963951e376", "64293bfa6b0b6ddd4058ec3c", "642a51ad6b0b6d044158f2fd", "642c1d256b0b6d3f40ebe9d6", "642c1ea36b0b6d3f40ebea02", "642c1f496b0b6d56aaebea43", "642cc2626b0b6d3099ebf23f", "642cfce06b0b6d32c00a8f51", "642d54d66b0b6d62de0a9083"], :query_hash=>"LVYunLaiLJrED0dTQjSyOuwe62M="}, :duration=>581050157, :page=>1, :total=>0, :documents_payload=>, :tags=>["eweb"]}
[2023-04-05T23:20:22.385+00:00][23639][5168][active_job][INFO]: Completed Work::FritoPie::EmitAnalyticsEvent job (4e7e790c-c1a4-4a43-9f59-a04768609cc7) on unknown
[2023-04-05T23:20:22.387+00:00][23639][5168][active_job][INFO]: Performed Work::FritoPie::EmitAnalyticsEvent (Job ID: 4e7e790c-c1a4-4a43-9f59-a04768609cc7) from Async(unknown) in 17.21ms
[2023-04-05T23:20:22.389+00:00][23639][5056][action_controller][INFO]: Completed 200 OK in 736ms (Views: 1.7ms)
172.16.201.60 - - [05/4월/2023:23:20:21 +0000] "POST /ws/query/search.json HTTP/1.1" 200 165 "http://192.168.150.140:3002/ws/search" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Mobile Safari/537.36 Edg/111.0.1661.54"
[2023-04-05T23:20:41.541+00:00][23639][4388][app-server][INFO]: Running task: RefreshElasticsearchLicense
[2023-04-05T23:20:41.543+00:00][23639][4388][cron-Work::Cron::RefreshElasticsearchLicense][INFO]: Performing task: RefreshElasticsearchLicense
[2023-04-05T23:20:41.549+00:00][23639][4388][cron-Work::Cron::RefreshElasticsearchLicense][INFO]: Done performing task: RefreshElasticsearchLicense
[2023-04-05T23:20:41.550+00:00][23639][4388][app-server][INFO]: Done running task: RefreshElasticsearchLicense
[2023-04-05T23:20:42.073+00:00][23639][4388][app-server][INFO]: Running task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:20:42.074+00:00][23639][4388][cron-Work::Cron::UpdateSearchRelevanceSuggestions][INFO]: Performing task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:20:42.151+00:00][23639][4388][cron-Work::Cron::UpdateSearchRelevanceSuggestions][INFO]: Done performing task: UpdateSearchRelevanceSuggestions
[2023-04-05T23:20:42.152+00:00][23639][4388][app-server][INFO]: Done running task: UpdateSearchRelevanceSuggestions

List item

Sander_Philipse · April 6, 2023, 9:02am

Thanks, @Gunbay_Park. I'm not seeing anything out of the ordinary in these logs. The only delay is from starting workplace search to being ready, which is to be expected. Testing this in an internetless environment locally I also don't see any delays, the application just loads.

Is there anything in your network settings that might be causing a delay like this? Sometimes proxy misconfiguration can cause long network delays.

Gunbay_Park · April 6, 2023, 10:58am

I see.. thank you for your concern.
Then is there any possibility of es configuration problem?
I attach my elasticsearch/kibana/enterprise-search yml file.
Please check if there is some problem in my configuration

elasticsearch.yml

kibana

enterprise-search

Sean_Story · April 6, 2023, 7:48pm

@Gunbay_Park

Given that search is working, there's not an error in your config files. There's not a configuration that would make things faster or slower.

From your logs, we can see evidence that the slowest response was 736ms (less than 1 second). So I think that, in conjunction with:

It took about one minute to startup and
23:18:56 is the time of workplace search finished startup.

tells me that the issue is that you just need to wait for the server to start up. Once it's up, you shouldn't see any significant delays. Both your logs and your screenshot of your browser dev tools show that all the network traffic is completing at a reasonable speed.

Gunbay_Park · April 7, 2023, 6:48am

I found the reason of delay.
As I suspected, connection_timedout for css download was the problem!
After I modified my PC host file to redirect google and rsms css site to local server,
WS page finished startup just in three seconds.

In intranet on-premiese environment, WS react should download internet css files and it cause delay.

Thanks for your help, Sean and Sander.
I hope you have a great day!

system · May 5, 2023, 6:48am

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.