#java #ubuntu #tomcat #hybris
#java #ubuntu #tomcat #sap-коммерция-облако
Вопрос:
Я новичок в проекте sap hybris, и уже несколько недель у нас возникает проблема с тем, что наш hybris сам отключается в процессе производства.
На производстве у нас есть внутренний сервер для бэк-офиса, cronjobs, импорта и т.д., И у нас есть внешний сервер для … ну и интерфейс. Оба являются полноценными приложениями hybris. Также наш solr находится на выделенной машине.
Внешний сервер работает нормально все время. Только наш резервный сервер отключается без какой-либо уважительной причины.
Внутренний сервер выглядит следующим образом:
- Java 8
- Hybris 6.7
- 36 ГБ оперативной памяти
- java.mem составляет 28 ГБ
- Ubuntu 16.04.2
Это то, что выводится на консоль:
INFO | jvm 1 | main | 2020/08/27 09:04:50.411 | INFO [cluster-ClusterId{value='5f462504979dc05c35c5afff', description='null'}-111.22.12.16:27017] [connection] Opened connection [connectionId{localValue:33, serverValue:8662}] to 111.22.12.16:27017
INFO | jvm 1 | main | 2020/08/27 09:04:50.513 | INFO [cluster-ClusterId{value='5f462504979dc05c35c5afff', description='null'}-111.22.12.16:27017] [cluster] Monitor thread successfully connected to server with description ServerDescription{address=111.22.12.16:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 4, 10]}, minWireVersion=0, maxWireVersion=5, maxDocumentSize=16777216, roundTripTimeNanos=115245710}
INFO | jvm 1 | main | 2020/08/27 09:04:51.014 |
INFO | jvm 1 | main | 2020/08/27 09:05:01.224 | INFO [RemoveFavouriteListEntryWithProductEmptyCronJob::de.hybris.platform.servicelayer.internal.jalo.ScriptingJob] (RemoveFavouriteListEntryWithProductEmptyCronJob) [ScriptingJobPerformable] ### Starting executing script : model://removeFavouriteListEntryWithProductEmptyScript ###
INFO | jvm 1 | main | 2020/08/27 09:05:01.224 | INFO [update-shopOrderIndex-cronJob::de.hybris.platform.servicelayer.internal.jalo.ServicelayerJob] (update-shopOrderIndex-cronJob) [SolrIndexerJob] Started indexer cronjob.
INFO | jvm 1 | main | 2020/08/27 09:05:01.324 | INFO [RemoveFavouriteListEntryWithProductEmptyCronJob::de.hybris.platform.servicelayer.internal.jalo.ScriptingJob] (RemoveFavouriteListEntryWithProductEmptyCronJob) [ScriptingJobPerformable] de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService$$EnhancerBySpringCGLIB$$d7ee97a3@7ca8259bFavoritesListEntry removed []done
INFO | jvm 1 | main | 2020/08/27 09:05:01.324 | INFO [RemoveFavouriteListEntryWithProductEmptyCronJob::de.hybris.platform.servicelayer.internal.jalo.ScriptingJob] (RemoveFavouriteListEntryWithProductEmptyCronJob) [ScriptingJobPerformable] ### Finished executing script, returned script result = null ###
INFO | jvm 1 | main | 2020/08/27 09:05:01.324 | INFO [update-shopStockItemIndex-cronJob::de.hybris.platform.servicelayer.internal.jalo.ServicelayerJob] (update-shopStockItemIndex-cronJob) [SolrIndexerJob] Started indexer cronjob.
INFO | jvm 1 | main | 2020/08/27 09:05:01.425 | INFO [update-shopQuoteIndex-cronJob::de.hybris.platform.servicelayer.internal.jalo.ServicelayerJob] (update-shopQuoteIndex-cronJob) [SolrIndexerJob] Started indexer cronjob.
INFO | jvm 1 | main | 2020/08/27 09:05:01.826 | INFO [update-shopQuoteIndex-cronJob::de.hybris.platform.servicelayer.internal.jalo.ServicelayerJob] (update-shopQuoteIndex-cronJob) [SolrIndexerJob] Finished indexer cronjob.
INFO | jvm 1 | main | 2020/08/27 09:05:02.127 | INFO [update-shopStockItemIndex-cronJob::de.hybris.platform.servicelayer.internal.jalo.ServicelayerJob] (update-shopStockItemIndex-cronJob) [SolrIndexerJob] Finished indexer cronjob.
INFO | jvm 1 | main | 2020/08/27 09:05:02.429 | INFO [update-shopOrderIndex-cronJob::de.hybris.platform.servicelayer.internal.jalo.ServicelayerJob] (update-shopOrderIndex-cronJob) [SolrIndexerJob] Finished indexer cronjob.
INFO | jvm 1 | main | 2020/08/27 09:05:02.931 |
INFO | jvm 1 | main | 2020/08/27 09:05:27.177 | WARN [jgroups-11,shoplive-broadcast,hybrisnode-1] [NAKACK2] JGRP000011: hybrisnode-1: dropped message batch from non-member hybrisnode-2 (view=[hybrisnode-1|2] (1) [hybrisnode-1])
INFO | jvm 1 | main | 2020/08/27 09:05:27.677 |
INFO | jvm 1 | main | 2020/08/27 09:05:49.412 | INFO [solrclient-cleanup-master] [DefaultSolrClientPool] Checking pooled Solr client [config=shopSolrServerConfig]
INFO | jvm 1 | main | 2020/08/27 09:05:49.912 |
INFO | jvm 1 | main | 2020/08/27 09:06:19.376 | INFO [cluster-ClusterId{value='5f462504979dc05c35c5afff', description='null'}-111.22.12.16:27017] [connection] Opened connection [connectionId{localValue:34, serverValue:8664}] to 111.22.12.16:27017
INFO | jvm 1 | main | 2020/08/27 09:06:19.877 |
INFO | jvm 1 | main | 2020/08/27 09:06:29.399 | WARN [jgroups-11,shoplive-broadcast,hybrisnode-1] [NAKACK2] JGRP000011: hybrisnode-1: dropped message batch from non-member hybrisnode-2 (view=[hybrisnode-1|2] (1) [hybrisnode-1]) (received 3 identical messages from hybrisnode-2 in the last 62247 ms)
INFO | jvm 1 | main | 2020/08/27 09:06:29.900 |
INFO | jvm 1 | main | 2020/08/27 09:06:49.436 | INFO [solrclient-cleanup-master] [DefaultSolrClientPool] Checking pooled Solr client [config=shopSolrServerConfig]
INFO | jvm 1 | main | 2020/08/27 09:06:49.937 |
INFO | jvm 1 | main | 2020/08/27 09:07:49.358 | INFO [solrclient-cleanup-master] [DefaultSolrClientPool] Checking pooled Solr client [config=shopSolrServerConfig]
INFO | jvm 1 | main | 2020/08/27 09:07:49.860 |
INFO | jvm 1 | main | 2020/08/27 09:07:51.064 | WARN [jgroups-25,shoplive-broadcast,hybrisnode-1] [NAKACK2] JGRP000011: hybrisnode-1: dropped message batch from non-member hybrisnode-2 (view=[hybrisnode-1|2] (1) [hybrisnode-1]) (received 2 identical messages from hybrisnode-2 in the last 81647 ms)
INFO | jvm 1 | main | 2020/08/27 09:07:51.565 |
INFO | jvm 1 | main | 2020/08/27 09:08:20.737 | INFO [cluster-ClusterId{value='5f462504979dc05c35c5afff', description='null'}-111.22.12.16:27017] [connection] Opened connection [connectionId{localValue:35, serverValue:8665}] to 111.22.12.16:27017
INFO | jvm 1 | main | 2020/08/27 09:08:21.238 |
STATUS | wrapper | main | 2020/08/27 09:08:35.081 | Pinging the JVM took 2 seconds to respond.
INFO | jvm 1 | main | 2020/08/27 09:08:49.617 | INFO [solrclient-cleanup-master] [DefaultSolrClientPool] Checking pooled Solr client [config=shopSolrServerConfig]
INFO | jvm 1 | main | 2020/08/27 09:08:50.118 |
INFO | jvm 1 | main | 2020/08/27 09:09:16.324 | INFO [cluster-ClusterId{value='5f462504979dc05c35c5afff', description='null'}-111.22.12.16:27017] [connection] Opened connection [connectionId{localValue:36, serverValue:8688}] to 111.22.12.16:27017
INFO | jvm 1 | main | 2020/08/27 09:09:16.825 |
STATUS | wrapper | main | 2020/08/27 09:09:46.483 | Pinging the JVM took 1 seconds to respond.
STATUS | wrapper | main | 2020/08/27 09:09:52.562 | JVM received a signal SIGKILL (9).
STATUS | wrapper | main | 2020/08/27 09:09:52.563 | JVM process is gone.
ERROR | wrapper | main | 2020/08/27 09:09:52.563 | JVM exited unexpectedly.
STATUS | wrapper | main | 2020/08/27 09:09:52.984 | Reloading Wrapper configuration...
STATUS | wrapper | main | 2020/08/27 09:09:53.209 | Launching a JVM...
INFO | jvm 2 | main | 2020/08/27 09:09:53.415 | Java HotSpot(TM) 64-Bit Server VM warning: INFO: os::commit_memory(0x00000000e9990000, 29366878208, 0) failed; error='Cannot allocate memory' (errno=12)
INFO | jvm 2 | main | 2020/08/27 09:09:53.416 | #
INFO | jvm 2 | main | 2020/08/27 09:09:53.416 | # There is insufficient memory for the Java Runtime Environment to continue.
INFO | jvm 2 | main | 2020/08/27 09:09:53.416 | # Native memory allocation (mmap) failed to map 29366878208 bytes for committing reserved memory.
INFO | jvm 2 | main | 2020/08/27 09:09:53.416 | # An error report file with more information is saved as:
INFO | jvm 2 | main | 2020/08/27 09:09:53.416 | # /home/user/hybris/bin/platform/tomcat/bin/hs_err_pid31526.log
ERROR | wrapper | main | 2020/08/27 09:09:53.459 | JVM exited while loading the application.
STATUS | wrapper | main | 2020/08/27 09:09:53.862 | Reloading Wrapper configuration...
STATUS | wrapper | main | 2020/08/27 09:09:54.076 | Launching a JVM...
ERROR | wrapper | main | 2020/08/27 09:09:54.117 | JVM exited while loading the application.
INFO | jvm 3 | main | 2020/08/27 09:09:54.118 | Java HotSpot(TM) 64-Bit Server VM warning: INFO: os::commit_memory(0x00000000e9990000, 29366878208, 0) failed; error='Cannot allocate memory' (errno=12)
INFO | jvm 3 | main | 2020/08/27 09:09:54.118 | #
INFO | jvm 3 | main | 2020/08/27 09:09:54.118 | # There is insufficient memory for the Java Runtime Environment to continue.
INFO | jvm 3 | main | 2020/08/27 09:09:54.118 | # Native memory allocation (mmap) failed to map 29366878208 bytes for committing reserved memory.
INFO | jvm 3 | main | 2020/08/27 09:09:54.118 | # An error report file with more information is saved as:
INFO | jvm 3 | main | 2020/08/27 09:09:54.118 | # /home/user/hybris/bin/platform/tomcat/bin/hs_err_pid31536.log
STATUS | wrapper | main | 2020/08/27 09:09:54.521 | Reloading Wrapper configuration...
STATUS | wrapper | main | 2020/08/27 09:09:54.737 | Launching a JVM...
ERROR | wrapper | main | 2020/08/27 09:09:54.773 | JVM exited while loading the application.
INFO | jvm 4 | main | 2020/08/27 09:09:54.773 | Java HotSpot(TM) 64-Bit Server VM warning: INFO: os::commit_memory(0x00000000e9990000, 29366878208, 0) failed; error='Cannot allocate memory' (errno=12)
INFO | jvm 4 | main | 2020/08/27 09:09:54.773 | #
INFO | jvm 4 | main | 2020/08/27 09:09:54.773 | # There is insufficient memory for the Java Runtime Environment to continue.
INFO | jvm 4 | main | 2020/08/27 09:09:54.773 | # Native memory allocation (mmap) failed to map 29366878208 bytes for committing reserved memory.
INFO | jvm 4 | main | 2020/08/27 09:09:54.773 | # An error report file with more information is saved as:
INFO | jvm 4 | main | 2020/08/27 09:09:54.773 | # /home/user/hybris/bin/platform/tomcat/bin/hs_err_pid31546.log
STATUS | wrapper | main | 2020/08/27 09:09:55.176 | Reloading Wrapper configuration...
STATUS | wrapper | main | 2020/08/27 09:09:55.385 | Launching a JVM...
ERROR | wrapper | main | 2020/08/27 09:09:55.425 | JVM exited while loading the application.
INFO | jvm 5 | main | 2020/08/27 09:09:55.425 | Java HotSpot(TM) 64-Bit Server VM warning: INFO: os::commit_memory(0x00000000e9990000, 29366878208, 0) failed; error='Cannot allocate memory' (errno=12)
INFO | jvm 5 | main | 2020/08/27 09:09:55.425 | #
INFO | jvm 5 | main | 2020/08/27 09:09:55.425 | # There is insufficient memory for the Java Runtime Environment to continue.
INFO | jvm 5 | main | 2020/08/27 09:09:55.425 | # Native memory allocation (mmap) failed to map 29366878208 bytes for committing reserved memory.
INFO | jvm 5 | main | 2020/08/27 09:09:55.425 | # An error report file with more information is saved as:
INFO | jvm 5 | main | 2020/08/27 09:09:55.425 | # /home/user/hybris/bin/platform/tomcat/bin/hs_err_pid31556.log
STATUS | wrapper | main | 2020/08/27 09:09:55.827 | Reloading Wrapper configuration...
STATUS | wrapper | main | 2020/08/27 09:09:56.039 | Launching a JVM...
ERROR | wrapper | main | 2020/08/27 09:09:56.076 | JVM exited while loading the application.
INFO | jvm 6 | main | 2020/08/27 09:09:56.077 | Java HotSpot(TM) 64-Bit Server VM warning: INFO: os::commit_memory(0x00000000e9990000, 29366878208, 0) failed; error='Cannot allocate memory' (errno=12)
INFO | jvm 6 | main | 2020/08/27 09:09:56.077 | #
INFO | jvm 6 | main | 2020/08/27 09:09:56.077 | # There is insufficient memory for the Java Runtime Environment to continue.
INFO | jvm 6 | main | 2020/08/27 09:09:56.077 | # Native memory allocation (mmap) failed to map 29366878208 bytes for committing reserved memory.
INFO | jvm 6 | main | 2020/08/27 09:09:56.077 | # An error report file with more information is saved as:
INFO | jvm 6 | main | 2020/08/27 09:09:56.077 | # /home/user/hybris/bin/platform/tomcat/bin/hs_err_pid31566.log
FATAL | wrapper | main | 2020/08/27 09:09:56.378 | There were 5 failed launches in a row, each lasting less than 300 seconds. Giving up.
FATAL | wrapper | main | 2020/08/27 09:09:56.379 | There may be a configuration problem: please check the logs.
STATUS | wrapper | main | 2020/08/27 09:09:56.580 | <-- Wrapper Stopped
Для меня это выглядит так, как будто сервер отключается без причины, но делает это не полностью и сохраняет текущую оперативную память, а затем пытается запустить снова, но оперативной памяти недостаточно.
Также это первый проект, в котором я вижу, что hybris отключается сам. Я уже работал в 4 других крупных проектах, никогда не сталкивался с такой проблемой.
Комментарии:
1. Я тоже это вижу, но это не так. После того, как он убивает себя, достаточно оперативной памяти. Также достаточно оперативной памяти для всех задач, которые он выполняет. И Java должна сама обрабатывать используемую оперативную память или нет?
2. В журнале указано, что у вас недостаточно памяти. Каков максимальный размер кучи, установленный на? Вы должны искать параметр -Xms. Вы запускаете его с помощью сценария оболочки?
3. для -Xms и -Xmx установлено значение 28 ГБ. И да, я запускаю сервер с помощью обычного
hybrisserver.shскрипта, который запускаетtomcat/bin/catalina.shкоторый запускаетtomcat/bin/wrapper.sh.4. Добавьте флаг » -XX: HeapDumpOnOutOfMemoryError » в JAVA_OPTS, это создаст файл дампа при сбое. Этот файл дампа может быть открыт JConsole, и вы можете отлаживать его оттуда.
5. Спасибо, я добавлю флаг и тогда посмотрим 🙂
Ответ №1:
Для меня это выглядит как нестандартное завершение. В журнале вы можете увидеть
JVM получил сигнал SIGKILL (9)
Это что-то внешнее, отправляющее kill -9. Если оболочка делает это, вы должны увидеть сообщения о запросе завершения работы, а затем время ожидания операции завершения работы, прежде чем оболочка в конечном итоге завершит работу -9. Этот журнал показывает, что что-то происходит прямо с kill -9.
Я думаю, вам нужно будет посмотреть на внешние системы и / или O / S — мне сказали, что O / S может сделать это сам, если система испытывает сильную нехватку памяти. Я знаю, вы говорите, что в системе много памяти, но может ли что-то еще использоваться для использования этой памяти в другом месте … или это может быть виртуальная машина, где фактическое оборудование перегружено, поэтому у виртуальной машины не так много памяти, как кажется?
Комментарии:
1. Операционная система чистая. Есть только приложение sap hybris и ничего больше. Внезапно у меня нет никакой информации об оборудовании или конфигурации их виртуальной машины. Наш хостер сообщает нам, что все в порядке. Также я думаю, что он никогда не рассматривал проблему.