SAP Hybris s'arrête de lui-même


Je suis nouveau dans un projet sap hybris et depuis quelques semaines, nous avons ce problème que notre hybris s'arrête lui-même en production.

En production, nous avons un serveur backend pour le backoffice, les cronjobs, les importations, etc. et nous avons un serveur frontend pour ... eh bien le frontend. Les deux sont des applications hybris complètes. Aussi notre solr est sur un maschine dédié.

Le serveur frontend fonctionne bien tout le temps. Seul notre serveur sauvegardé s'arrête sans aucun bon raison.

Le serveur principal ressemble à ceci:

  • Java 8
  • Hybris 6.7
  • 36 Go DE RAM
  • java.mem est de 28 Go
  • Ubuntu 16.04.2

Voici ce que dit la sortie de la console:

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

Pour moi, il semble que le serveur s'arrête, sans raison, mais ne le fait pas complètement et conserve la RAM actuelle, puis il essaie de recommencer, mais n'a pas assez de RAM.

C'est aussi le premier projet où je vois qu'un hybris se ferme bas lui-même. J'ai déjà travaillé dans 4 autres grands projets, je n'ai jamais eu ce genre de problème.

Author: Mr.Tr33, 2020-08-27

1 answers

Cela ressemble à une terminaison non standard pour moi. Dans le journal, vous pouvez voir

JVM a reçu un signal SIGKILL (9)

C'est quelque chose d'externe envoyant un kill -9. Si le wrapper le fait, vous devriez voir des messages sur la demande d'arrêt et le timing de l'opération d'arrêt, avant que le wrapper ne tue finalement -9. Ce journal montre quelque chose qui va directement avec kill -9.

Je suppose que vous devrez regarder les systèmes externes et / ou le O / S-je suis dit le O / S peut le faire lui-même si le système est sous forte pression de mémoire. Je sais que vous dites que le système a beaucoup de mémoire, mais que quelque chose d'autre pourrait consommer cette mémoire ailleurs ... ou pourrait-il s'agir d'une machine virtuelle où le matériel réel est sur-abonné afin que la machine virtuelle n'ait pas autant de mémoire qu'il n'y paraît?

 0
Author: Neil Hubert-Price, 2020-08-27 09:06:38