ITお絵かき修行

3歩歩いても忘れないために

EhcacheとTerracottaでキャッシュレプリケーション（４）資産配置・動作確認・FAQ

Ehcache Terracotta

EhcacheとTerracottaでキャッシュレプリケーション（３）資産作成(SV側・CL側資産) - ITお絵かき修行
で用意した資産をサーバ内に用意、また定義体を作成・編集し、動作確認を行う。


【資産配置手順】
０．AWSのセキュリテイグループ変更
(1)APサーバ1・2号機、Terracottaサーバのセキュリティグループ設定を以下のように変更する。
f:id:hhhhhskw:20140510145407p:plain

１．warファイル・定義体をAPサーバ１・２号機にアップロードし配置、および作成する。
(1)APサーバ１・２号機内のvsftpd等のFTPサーバの設定変更・起動or再起動
→サーバに対してファイルをアップロードできるようにする。
参考：AWSにvsftpd導入（２）設定編 - ITお絵かき修行

(2)FTPクライアントソフト(FFFTPなど)でAPサーバ１・２号機に入り、資産をアップロードする。
→warファイルをtomcatのwebapps配下に置く。置いたwarファイルのユーザはtomcatの操作用のユーザアカウントへ変更する


(3)Teratermなどのターミナルソフト(以下、ターミナル)より定義体を作成・編集する。
SV側資産のURL仕様は以下の通りとする。
f:id:hhhhhskw:20140510171038p:plain

●httpd-proxy.conf(httpd.conf)
[APサーバ１号機]
記述内容：

<Location /terracotta/cacheReplication/>
    ProxyPass ajp://localhost:8009/AP01/terracotta/1.0/cacheReplication/
</Location>

[APサーバ２号機]
記述内容：

<Location /terracotta/cacheReplication/>
    ProxyPass ajp://localhost:8009/AP02/terracotta/1.0/cacheReplication/
</Location>

●コンテキストファイル
[APサーバ１号機]
ファイル名：AP01.xml
ファイル内容：

<Context path="/AP01">

[APサーバ２号機]
ファイル名：AP02.xml
ファイル内容：

<Context path="/AP02">

２．ターミナルよりApacheとtomcat起動
(1)Apacheとtomcatを起動する。
(2)ログを見て正常稼動しているか確認
Apache：(Apacheインストールディレクトリ)/logs/error_log
Tomcat：(tomcatインストールディレクトリ)/logs/catalina.out

３．APサーバ１・２号機に配置したwarファイルと定義体設定内容の動作確認を行う。
(1)以下のコマンドをターミナルより実行する。

tail -f (tomcatインストールディレクトリまでのパス)/logs/catalina.out

→APサーバ１・２号機の(tomcatインストールディレクトリ)/logs/catalina.outを出力しっぱなしにする。

(2)ブラウザから以下にアクセスする。
[APサーバ1号機]

http://(APサーバ1号機のホスト名・IPアドレス)/terracotta/cacheReplication/

[APサーバ2号機]

http://(APサーバ2号機のホスト名・IPアドレス)/terracotta/cacheReplication/

(3)(1)のコマンド実行画面に「doGet」が出力されていればOK。（ブラウザには空白の画面が表示される。）

４．AWSのセキュリテイグループ変更
(1)APサーバ1・2号機、Terracottaサーバのセキュリティグループ設定を以下のように変更する。
f:id:hhhhhskw:20140510155154p:plain
→要はポートを全開にする。好ましくない。ただポート番号の設定でかなりハマった（各サーバ間の通信をIPアドレス単位で指定し、ポートレンジを「0-65535」にしてもうまくいかなかった）ので、動作確認程度なら問題ないと判断した。つかれた。
※自己判断でお願いします。途中で作業を中断する際はこの設定を解除してから作業中断してください。
※AP2号機からTerracottaサーバへはへ内部IP(10.～)使って見にいっているので、Terracottaサーバ起動時に定義体使ってグローバルIP指定する必要がある？とか妄想しています。

(2)Terracottaサーバ起動
→Terracottaサーバにて以下の.shファイルを実行する。

./(terracotta-3.7.7を展開したディレクトリまでのパス)/bin/start-tc-server.sh

問題なく起動したら以下のメッセージが出力される。
[出力内容]

[root@ip-xxx-xxx-xxx-xxx bin]# ./start-tc-server.sh
2014-05-10 05:15:08,555 INFO - Terracotta 3.7.7, as of 20140117-104005 (Revision 24356 by jenkins-slave@sfo-c64-jenkins-slave-007.eur.ad.sag from 3.7.7-rc)
2014-05-10 05:15:09,567 INFO - Successfully loaded base configuration from Java resource at '/com/tc/config/schema/setup/default-config.xml', relative to class com.tc.config.schema.setup.StandardXMLFileConfigurationCreator.
2014-05-10 05:15:09,807 INFO - Log file: '/root/terracotta/server-logs/terracotta-server.log'.
2014-05-10 05:15:12,841 INFO - Available Max Runtime Memory: 494MB
2014-05-10 05:15:15,651 INFO - JMX Server started. Available at URL[service:jmx:jmxmp://0.0.0.0:9520]
2014-05-10 05:15:22,091 INFO - Becoming State[ ACTIVE-COORDINATOR ]
2014-05-10 05:15:22,133 INFO - Terracotta Server instance has started up as ACTIVE node on 0:0:0:0:0:0:0:0:9510 successfully, and is now ready for work.

※Terracottaサーバ内にデフォルトで用意されている「tc-config.xml(default-config.xml)」を使用して起動している。


各サーバ側のログは以下の通り。
●Terracottaサーバ

・terracotta-server.log

2014-05-10 05:30:09,368 [main] INFO com.terracottatech.general - New logging session started.
2014-05-10 05:30:09,392 [main] INFO com.terracottatech.console - Terracotta 3.7.7, as of 20140117-104005 (Revision 24356 by jenkins-slave@sfo-c64-jenkins-slave-007.eur.ad.sag from 3.7.7-rc)
2014-05-10 05:30:09,446 [main] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - Attempting to load configuration from the Java resource at '/com/tc/config/schema/setup/default-config.xml', relative to class com.tc.config.schema.setup.StandardXMLFileConfigurationCreator...
2014-05-10 05:30:10,228 [main] INFO com.terracottatech.console - Successfully loaded base configuration from Java resource at '/com/tc/config/schema/setup/default-config.xml', relative to class com.tc.config.schema.setup.StandardXMLFileConfigurationCreator.
2014-05-10 05:30:10,253 [main] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - The configuration specified by 'base configuration from Java resource at '/com/tc/config/schema/setup/default-config.xml', relative to class com.tc.config.schema.setup.StandardXMLFileConfigurationCreator':

(中略)

2014-05-10 05:30:16,461 [main] INFO com.terracottatech.dso - Terracotta persistence version is 2.2
2014-05-10 05:30:16,713 [main] INFO com.tc.net.core.TCWorkerCommManager - Creating 2 worker comm threads for L2_L1
2014-05-10 05:30:16,729 [main] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Server - HealthChecker Started
2014-05-10 05:30:16,729 [main] INFO com.tc.net.protocol.tcm.CommunicationsManager - HealthCheck CallbackPort Listener not requested
2014-05-10 05:30:16,738 [main] INFO com.tc.objectserver.l1.impl.ClientObjectReferenceSet - ServerMapEviction Client Object References refresh interval 60 seconds.
2014-05-10 05:30:16,775 [main] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: Copy
2014-05-10 05:30:16,775 [main] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: MarkSweepCompact
2014-05-10 05:30:16,957 [main] INFO com.tc.net.core.TCWorkerCommManager - Creating 2 worker comm threads for L2_L2
2014-05-10 05:30:16,959 [main] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: TCGroupManager - HealthChecker Started
2014-05-10 05:30:16,959 [main] INFO com.tc.net.protocol.tcm.CommunicationsManager - HealthCheck CallbackPort Listener not requested
2014-05-10 05:30:16,979 [main] INFO com.terracottatech.dso - L2 Networked HA Enabled 
2014-05-10 05:30:17,085 [main] INFO com.tc.statistics.StatisticRetrievalAction - "message monitor" statistic is not enabled. Please enable the property "tcm.monitor.delay" to collect this statistics.
2014-05-10 05:30:17,085 [main] INFO com.tc.statistics.retrieval.actions.SRAL2FaultsFromDisk - "l2 faults from disk" statistic is not enabled. Please enable the property "l2.objectmanager.fault.logging.enabled" to collect this statistic.
2014-05-10 05:30:17,093 [main] INFO com.tc.l2.L2DebugLogging - L2 debug logging: DISABLED
2014-05-10 05:30:17,113 [main] INFO com.terracottatech.dso - This L2 Node ID = NodeID[(Terracottaサーバの内部IPアドレス):9510]
2014-05-10 05:30:17,114 [main] INFO com.tc.l2.state.ElectionManagerImpl - Election Started : Enrollment [ NodeID[(Terracottaサーバの内部IPアドレス):9510], isNew = true, weights = -6255337585280992779,296281413396586777 ]
2014-05-10 05:30:22,115 [main] INFO com.tc.l2.state.ElectionManagerImpl - Election Complete : [Enrollment [ NodeID[(Terracottaサーバの内部IPアドレス):9510], isNew = true, weights = -6255337585280992779,296281413396586777 ]] : State[ Election-Complete ]
2014-05-10 05:30:22,116 [main] INFO com.tc.l2.state.StateManagerImpl - Becoming State[ ACTIVE-COORDINATOR ]
2014-05-10 05:30:22,116 [main] INFO com.terracottatech.console - Becoming State[ ACTIVE-COORDINATOR ]
2014-05-10 05:30:22,123 [main] INFO tc.operator.event - NODE : (Terracottaサーバの内部IPアドレス):9510  Subsystem: CLUSTER_TOPOLOGY Message: Moved to ACTIVE-COORDINATOR
2014-05-10 05:30:22,123 [main] INFO com.tc.l2.state.ElectionManagerImpl - Declared as Winner: Winner is : Enrollment [ NodeID[(Terracottaサーバの内部IPアドレス):9510], isNew = true, weights = -6255337585280992779,296281413396586777 ]

(中略)

2014-05-10 05:30:22,195 [main] INFO com.tc.server.TCServer - Server started as (Terracottaサーバの内部IPアドレス):9510
2014-05-10 05:30:22,196 [Update Checker] INFO com.tc.server.UpdateCheckAction - Update Checker: Checking...
2014-05-10 05:30:26,146 [Update Checker] INFO com.tc.server.UpdateCheckAction - Update Checker: No updates found
2014-05-10 05:30:26,146 [Update Checker] INFO com.tc.server.UpdateCheckAction - Update Checker: Next check at Sat May 17 05:30:26 UTC 2014

またAPサーバ側では以下のログが出力されている。

●APサーバ１号機

・catalina.out

AP1号機put開始 put回数：50
May 10, 2014 5:32:57 AM net.sf.ehcache.terracotta.TerracottaClient info
INFO: Thread [ajp-bio-8009-exec-1] [cacheManager: no name]: Creating new ClusteredInstanceFactory
2014-05-10 05:32:59,465 INFO - Terracotta 3.7.7, as of 20140117-102107 (Revision 24373 by jenkins-slave@sfo-c64-jenkins-slave-007.eur.ad.sag from 3.7.7)
2014-05-10 05:33:00,774 INFO - Successfully loaded base configuration from server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'.
2014-05-10 05:33:00,939 INFO - Successfully loaded base configuration from file at '/var/cache/tomcat7/temp/tc-config7585171491784117166.xml'.
2014-05-10 05:33:01,029 INFO - Log file: '/usr/share/tomcat7/terracotta/client-logs/terracotta-client.log'.
2014-05-10 05:33:05,694 INFO - Connection successfully established to server at (Terracottaサーバの内部IPアドレス):9510
May 10, 2014 5:33:10 AM org.terracotta.modules.ehcache.store.ClusteredStore createConcurrentDistributedMap
INFO: Cache [terracottaCacheAP01] using concurrency: 64
May 10, 2014 5:33:10 AM net.sf.ehcache.pool.sizeof.filter.AnnotationSizeOfFilter <clinit>
INFO: Using regular expression provided through VM argument net.sf.ehcache.pool.sizeof.ignore.pattern for IgnoreSizeOf annotation : ^.*cache\..*IgnoreSizeOf$
May 10, 2014 5:33:10 AM net.sf.ehcache.pool.sizeof.AgentLoader <clinit>
INFO: Unavailable or unrecognised attach API : java.lang.ClassNotFoundException: com.sun.tools.attach.VirtualMachine
May 10, 2014 5:33:10 AM net.sf.ehcache.pool.sizeof.JvmInformation <clinit>
INFO: Detected JVM data model settings of: Unrecognized 64-Bit JVM
May 10, 2014 5:33:10 AM net.sf.ehcache.pool.impl.DefaultSizeOfEngine <init>
INFO: using Unsafe sizeof engine
May 10, 2014 5:33:10 AM net.sf.ehcache.pool.impl.DefaultSizeOfEngine <init>
INFO: using Unsafe sizeof engine
[put]値：AP01Cliant to AP010
1553781086187
[put]値：AP01Cliant to AP011
1555790931938

(以下略)

・terracotta-client.log

2014-05-10 05:32:59,414 [ajp-bio-8009-exec-1] INFO com.terracottatech.general - New logging session started.
2014-05-10 05:32:59,465 [ajp-bio-8009-exec-1] INFO com.terracottatech.console - Terracotta 3.7.7, as of 20140117-102107 (Revision 24373 by jenkins-slave@sfo-c64-jenkins-slave-007.eur.ad.sag from 3.7.7)
2014-05-10 05:32:59,566 [ajp-bio-8009-exec-1] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - Attempting to load configuration from the server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'...
2014-05-10 05:33:00,774 [ajp-bio-8009-exec-1] INFO com.terracottatech.console - Successfully loaded base configuration from server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'.
2014-05-10 05:33:00,793 [ajp-bio-8009-exec-1] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - The configuration specified by 'base configuration from server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'':

(中略)

2014-05-10 05:33:03,964 [ajp-bio-8009-exec-1] INFO com.tc.object.ApplicatorDNAEncodingImpl - Compressed String constructor not present
2014-05-10 05:33:04,110 [ajp-bio-8009-exec-1] INFO com.tc.net.core.TCCommImpl - Comm Worker Threads NOT requested
2014-05-10 05:33:04,170 [ajp-bio-8009-exec-1] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Client - HealthChecker Started
2014-05-10 05:33:04,360 [ajp-bio-8009-exec-1] INFO com.tc.net.protocol.tcm.CommunicationsManager - HealthCheck CallbackPort Listener started at /0:0:0:0:0:0:0:0:54979
2014-05-10 05:33:04,819 [Statistics Logger] INFO com.terracottatech.dso - memory free : 243.972183 MB
2014-05-10 05:33:04,819 [Statistics Logger] INFO com.terracottatech.dso - memory used : 44.152817 MB
2014-05-10 05:33:04,819 [Statistics Logger] INFO com.terracottatech.dso - memory max : 288.125000 MB
2014-05-10 05:33:04,822 [ajp-bio-8009-exec-1] INFO com.terracottatech.dso - Statistics buffer opened
2014-05-10 05:33:04,897 [ajp-bio-8009-exec-1] INFO com.tc.statistics.StatisticRetrievalAction - "message monitor" statistic is not enabled. Please enable the property "tcm.monitor.delay" to collect this statistics.
2014-05-10 05:33:05,178 [ajp-bio-8009-exec-1] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: Copy
2014-05-10 05:33:05,179 [ajp-bio-8009-exec-1] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: MarkSweepCompact
2014-05-10 05:33:05,379 [L1Management JMX registration] INFO com.tc.management.L1Management - Terracotta JMX connector available at[service:jmx:terracotta://localhost]
2014-05-10 05:33:05,415 [ajp-bio-8009-exec-1] INFO com.tc.net.core.TCConnection - Comms Message Batching enabled
2014-05-10 05:33:05,429 [ajp-bio-8009-exec-1] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(-1.ffffffffffffffffffffffffffffffff.6560c542-6e5a-4316-bc3a-0dea6cdeffd0-145e498c196)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@340795669: connected: true, closed: false local=(APサーバ１号機の内部IPアドレス):52835 remote=(Terracottaサーバの内部IPアドレス):9510 connect=[Sat May 10 05:33:05 UTC 2014] idle=12ms [0 read, 0 write]
2014-05-10 05:33:05,609 [ajp-bio-8009-exec-1] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - Health monitoring agent started for (Terracottaサーバのホスト名).internal:9510
2014-05-10 05:33:05,617 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:54979)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - HealthCheckCallbackPort verification PASSED for (Terracottaサーバのホスト名).internal:9510(callbackport: 9510)
2014-05-10 05:33:05,629 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[0]: Connected: Unpausing from State[ PAUSED ] RemoteNode : GroupID[0]. Disconnect count : 1
2014-05-10 05:33:05,694 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[0]: Received Handshake ack for this node :GroupID[0]
2014-05-10 05:33:05,694 [ajp-bio-8009-exec-1] INFO com.terracottatech.console - Connection successfully established to server at (Terracottaサーバの内部IPアドレス):9510
2014-05-10 05:33:05,694 [ajp-bio-8009-exec-1] INFO com.terracottatech.dso - Connection successfully established to server at (Terracottaサーバの内部IPアドレス):9510
2014-05-10 05:33:05,700 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.management.remote.protocol.terracotta.TunnelingEventHandler - Client JMX server ready; sending notification to L2 server
2014-05-10 05:33:05,977 [ajp-bio-8009-exec-1] INFO org.terracotta.api.org.terracotta.modules.ehcache.store.TerracottaClusteredInstanceFactory - Ehcache Core version 2.6.8 was built on 20140116-1421, at revision 8641, with jdk 1.6.0_35 by jenkins-slave@sfo-c64-jenkins-slave-013.eur.ad.sag
2014-05-10 05:33:09,443 [ajp-bio-8009-exec-1] INFO org.terracotta.cache.logging.TCLoggerConfigChangeListener - Changed cache [Distributed Cache]  maxTTLSeconds from 0 to 60
2014-05-10 05:33:09,444 [ajp-bio-8009-exec-1] INFO org.terracotta.cache.logging.TCLoggerConfigChangeListener - Changed cache [Distributed Cache]  maxTTISeconds from 0 to 60
2014-05-10 05:33:09,444 [ajp-bio-8009-exec-1] INFO org.terracotta.cache.logging.TCLoggerConfigChangeListener - Changed cache [__DEFAULT__|terracottaCacheAP01]  name from Distributed Cache to __DEFAULT__|terracottaCacheAP01
2014-05-10 05:33:09,456 [ajp-bio-8009-exec-1] INFO org.terracotta.cache.logging.TCLoggerConfigChangeListener - Changed cache [__DEFAULT__|terracottaCacheAP01]  capacityEvictionPolicyDataFactory from org.terracotta.cache.evictor.LFUCapacityEvictionPolicyData$Factory@79ef71b4 to org.terracotta.cache.evictor.LRUCapacityEvictionPolicyData$Factory@57121ef6
2014-05-10 05:33:09,456 [ajp-bio-8009-exec-1] INFO org.terracotta.cache.logging.TCLoggerConfigChangeListener - Changed cache [__DEFAULT__|terracottaCacheAP01]  targetMaxInMemoryCount from 0 to 100
2014-05-10 05:33:09,457 [ajp-bio-8009-exec-1] INFO org.terracotta.cache.logging.TCLoggerConfigChangeListener - Changed cache [__DEFAULT__|terracottaCacheAP01]  targetMaxTotalCount from 0 to 100
2014-05-10 05:33:10,696 [ajp-bio-8009-exec-1] INFO org.terracotta.api.org.terracotta.modules.ehcache.store.ClusteredStore - Clustered Store [cache=terracottaCacheAP01] with checkContainsKeyOnPut: false

●APサーバ２号機

・catalina.out

May 10, 2014 5:41:51 AM net.sf.ehcache.terracotta.TerracottaClient info
INFO: Thread [ajp-bio-8009-exec-2] [cacheManager: no name]: Creating new ClusteredInstanceFactory
2014-05-10 05:41:53,034 INFO - Terracotta 3.7.7, as of 20140117-102107 (Revision 24373 by jenkins-slave@sfo-c64-jenkins-slave-007.eur.ad.sag from 3.7.7)
2014-05-10 05:41:54,163 INFO - Successfully loaded base configuration from server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'.
2014-05-10 05:41:54,335 INFO - Successfully loaded base configuration from file at '/var/cache/tomcat7/temp/tc-config4978790012419607096.xml'.
2014-05-10 05:41:54,379 INFO - Log file: '/usr/share/tomcat7/terracotta/client-logs/terracotta-client.log'.
2014-05-10 05:41:58,443 INFO - Connection successfully established to server at (Terracottaサーバの内部IPアドレス):9510
May 10, 2014 5:42:04 AM net.sf.ehcache.pool.sizeof.filter.AnnotationSizeOfFilter <clinit>
INFO: Using regular expression provided through VM argument net.sf.ehcache.pool.sizeof.ignore.pattern for IgnoreSizeOf annotation : ^.*cache\..*IgnoreSizeOf$
May 10, 2014 5:42:04 AM net.sf.ehcache.pool.sizeof.AgentLoader <clinit>
INFO: Unavailable or unrecognised attach API : java.lang.ClassNotFoundException: com.sun.tools.attach.VirtualMachine
May 10, 2014 5:42:04 AM net.sf.ehcache.pool.sizeof.JvmInformation <clinit>
INFO: Detected JVM data model settings of: Unrecognized 64-Bit JVM
May 10, 2014 5:42:04 AM net.sf.ehcache.pool.impl.DefaultSizeOfEngine <init>
INFO: using Unsafe sizeof engine
May 10, 2014 5:42:04 AM net.sf.ehcache.pool.impl.DefaultSizeOfEngine <init>
INFO: using Unsafe sizeof engine
[get]値：[ key = key, value=AP01Cliant to AP0142, version=1, hitCount=1, CreationTime = 1399700526000, LastAccessTime = 1399700526000 ]
2086433004273
[get]値：[ key = key, value=AP01Cliant to AP0142, version=1, hitCount=1, CreationTime = 1399700526000, LastAccessTime = 1399700526000 ]
2087434053389

(以下略)

・terracotta-client.log

2014-05-10 05:41:52,970 [ajp-bio-8009-exec-2] INFO com.terracottatech.general - New logging session started.
2014-05-10 05:41:53,034 [ajp-bio-8009-exec-2] INFO com.terracottatech.console - Terracotta 3.7.7, as of 20140117-102107 (Revision 24373 by jenkins-slave@sfo-c64-jenkins-slave-007.eur.ad.sag from 3.7.7)
2014-05-10 05:41:53,147 [ajp-bio-8009-exec-2] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - Attempting to load configuration from the server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'...
2014-05-10 05:41:54,163 [ajp-bio-8009-exec-2] INFO com.terracottatech.console - Successfully loaded base configuration from server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'.
2014-05-10 05:41:54,181 [ajp-bio-8009-exec-2] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - The configuration specified by 'base configuration from server at '(Terracottaサーバのホスト名・公開用IPアドレス):9510'':

(中略)

2014-05-10 05:41:56,974 [ajp-bio-8009-exec-2] INFO com.terracottatech.dso - Trying to get Groupname ID Map from http://(Terracottaサーバの内部IPアドレス):9510/groupidmap
2014-05-10 05:41:56,979 [ajp-bio-8009-exec-2] INFO com.terracottatech.dso - Trying to get Cluster topology from http://(Terracottaサーバの内部IPアドレス):9510/groupinfo
2014-05-10 05:41:56,987 [ajp-bio-8009-exec-2] INFO com.terracottatech.dso - Trying to get Cluster topology from http://(Terracottaサーバの内部IPアドレス):9510/groupinfo
2014-05-10 05:41:57,006 [ajp-bio-8009-exec-2] INFO com.terracottatech.dso - Trying to get L1 Reconnect Properties from http://(Terracottaサーバの内部IPアドレス):9510/l1reconnectproperties
2014-05-10 05:41:57,049 [ajp-bio-8009-exec-2] INFO com.tc.object.ApplicatorDNAEncodingImpl - Compressed String constructor not present
2014-05-10 05:41:57,134 [ajp-bio-8009-exec-2] INFO com.tc.net.core.TCCommImpl - Comm Worker Threads NOT requested
2014-05-10 05:41:57,167 [ajp-bio-8009-exec-2] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Client - HealthChecker Started
2014-05-10 05:41:57,337 [ajp-bio-8009-exec-2] INFO com.tc.net.protocol.tcm.CommunicationsManager - HealthCheck CallbackPort Listener started at /0:0:0:0:0:0:0:0:39196
2014-05-10 05:41:57,796 [Statistics Logger] INFO com.terracottatech.dso - memory free : 243.526161 MB
2014-05-10 05:41:57,797 [Statistics Logger] INFO com.terracottatech.dso - memory used : 44.598839 MB
2014-05-10 05:41:57,797 [Statistics Logger] INFO com.terracottatech.dso - memory max : 288.125000 MB
2014-05-10 05:41:57,803 [ajp-bio-8009-exec-2] INFO com.terracottatech.dso - Statistics buffer opened
2014-05-10 05:41:57,865 [ajp-bio-8009-exec-2] INFO com.tc.statistics.StatisticRetrievalAction - "message monitor" statistic is not enabled. Please enable the property "tcm.monitor.delay" to collect this statistics.
2014-05-10 05:41:58,135 [ajp-bio-8009-exec-2] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: Copy
2014-05-10 05:41:58,135 [ajp-bio-8009-exec-2] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: MarkSweepCompact
2014-05-10 05:41:58,319 [L1Management JMX registration] INFO com.tc.management.L1Management - Terracotta JMX connector available at[service:jmx:terracotta://localhost]
2014-05-10 05:41:58,348 [ajp-bio-8009-exec-2] INFO com.tc.net.core.TCConnection - Comms Message Batching enabled
2014-05-10 05:41:58,357 [ajp-bio-8009-exec-2] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(-1.ffffffffffffffffffffffffffffffff.b3aa5d70-0866-4b3a-bb02-22b883fc1b9e-145e49a5f87)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@1312054033: connected: true, closed: false local=(APサーバ２号機の内部IPアドレス):58776 remote=(Terracottaサーバの内部IPアドレス):9510 connect=[Sat May 10 05:41:58 UTC 2014] idle=7ms [0 read, 0 write]
2014-05-10 05:41:58,385 [ajp-bio-8009-exec-2] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - Health monitoring agent started for (Terracottaサーバのホスト名).internal:9510
2014-05-10 05:41:58,391 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:39196)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - HealthCheckCallbackPort verification PASSED for (Terracottaサーバのホスト名).internal:9510(callbackport: 9510)
2014-05-10 05:41:58,413 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[1]: Connected: Unpausing from State[ PAUSED ] RemoteNode : GroupID[0]. Disconnect count : 1
2014-05-10 05:41:58,442 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[1]: Received Handshake ack for this node :GroupID[0]
2014-05-10 05:41:58,443 [ajp-bio-8009-exec-2] INFO com.terracottatech.console - Connection successfully established to server at (Terracottaサーバの内部IPアドレス):9510
2014-05-10 05:41:58,443 [ajp-bio-8009-exec-2] INFO com.terracottatech.dso - Connection successfully established to server at (Terracottaサーバの内部IPアドレス):9510
2014-05-10 05:41:58,448 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.management.remote.protocol.terracotta.TunnelingEventHandler - Client JMX server ready; sending notification to L2 server
2014-05-10 05:41:58,789 [ajp-bio-8009-exec-2] INFO org.terracotta.api.org.terracotta.modules.ehcache.store.TerracottaClusteredInstanceFactory - Ehcache Core version 2.6.8 was built on 20140116-1421, at revision 8641, with jdk 1.6.0_35 by jenkins-slave@sfo-c64-jenkins-slave-013.eur.ad.sag


５．CL側資産を実行する。
(1)各APサーバのTomcatのCatailna.outをtail -fで垂れ流しにすれば起動時の様子が見られる。
(2)実行結果は以下の通り。

[APサーバ1号機]Catalina.out

AP1号機put開始 put回数：50

（中略）

[put]値：AP01Cliant to AP010
1553781086187
[put]値：AP01Cliant to AP011
1555790931938
[put]値：AP01Cliant to AP012
1557793965298
[put]値：AP01Cliant to AP013
1559797908105
[put]値：AP01Cliant to AP014
1561800728808
[put]値：AP01Cliant to AP015
1563805586264
[put]値：AP01Cliant to AP016
1565808450367
[put]値：AP01Cliant to AP017
1567811264433
[put]値：AP01Cliant to AP018
1569814142276
[put]値：AP01Cliant to AP019
1571817287515
[put]値：AP01Cliant to AP0110
1573820254239

(中略)

[put]値：AP01Cliant to AP0140
1633967832449
[put]値：AP01Cliant to AP0141
1635971262964
[put]値：AP01Cliant to AP0142
1637974666100
[put]値：AP01Cliant to AP0143
1639978206590
[put]値：AP01Cliant to AP0144
1641981711172
[put]値：AP01Cliant to AP0145
1643985158824
[put]値：AP01Cliant to AP0146
1645989129761
[put]値：AP01Cliant to AP0147
1647992640562
[put]値：AP01Cliant to AP0148
1649996104492
[put]値：AP01Cliant to AP0149
1651999938281

[APサーバ2号機]Catalina.out

(略)

[get]値：[ key = key, value=AP01Cliant to AP0143, version=1, hitCount=1, CreationTime = 1399700528000, LastAccessTime = 1399700528000 ]
2088443700649
[get]値：[ key = key, value=AP01Cliant to AP0143, version=1, hitCount=1, CreationTime = 1399700528000, LastAccessTime = 1399700528000 ]
2089444962384
[get]値：[ key = key, value=AP01Cliant to AP0144, version=1, hitCount=1, CreationTime = 1399700530000, LastAccessTime = 1399700530000 ]
2090458645671
[get]値：[ key = key, value=AP01Cliant to AP0144, version=1, hitCount=1, CreationTime = 1399700530000, LastAccessTime = 1399700530000 ]
2091459624931
[get]値：[ key = key, value=AP01Cliant to AP0145, version=1, hitCount=1, CreationTime = 1399700532000, LastAccessTime = 1399700532000 ]
2092469835733
[get]値：[ key = key, value=AP01Cliant to AP0145, version=1, hitCount=1, CreationTime = 1399700532000, LastAccessTime = 1399700532000 ]
2093471113326
[get]値：[ key = key, value=AP01Cliant to AP0146, version=1, hitCount=1, CreationTime = 1399700534000, LastAccessTime = 1399700534000 ]
2094479478273
[get]値：[ key = key, value=AP01Cliant to AP0146, version=1, hitCount=1, CreationTime = 1399700534000, LastAccessTime = 1399700534000 ]
2095483531734
[get]値：[ key = key, value=AP01Cliant to AP0147, version=1, hitCount=1, CreationTime = 1399700536000, LastAccessTime = 1399700536000 ]
2096490724402
[get]値：[ key = key, value=AP01Cliant to AP0147, version=1, hitCount=1, CreationTime = 1399700536000, LastAccessTime = 1399700536000 ]
2097491920195
[get]値：[ key = key, value=AP01Cliant to AP0148, version=1, hitCount=1, CreationTime = 1399700538000, LastAccessTime = 1399700538000 ]
2098498984909
[get]値：[ key = key, value=AP01Cliant to AP0148, version=1, hitCount=1, CreationTime = 1399700538000, LastAccessTime = 1399700538000 ]
2099500183805
[get]値：[ key = key, value=AP01Cliant to AP0149, version=1, hitCount=1, CreationTime = 1399700540000, LastAccessTime = 1399700540000 ]
2100511435375
[get]値：[ key = key, value=AP01Cliant to AP0149, version=1, hitCount=1, CreationTime = 1399700540000, LastAccessTime = 1399700540000 ]
2101512674844
[get]値：[ key = key, value=AP01Cliant to AP0149, version=1, hitCount=1, CreationTime = 1399700540000, LastAccessTime = 1399700540000 ]
2102513865737

出力内容はアレだが、APサーバ1号機でputした値『AP01Cliant to AP01～』がAPサーバ2号機で出力されているので、キャッシュレプリケーションには成功している。

【課題】
・AWSのネットワーク設定
・キャッシュの出力内容
・Tomcat落としてもキャッシュ内容が喪失しないことの確認
→APサーバ1号機or2号機のTomcatを落としてキャッシュ取得確認すればいいだけ。


【詰まったときに疑うべきポイント(FAQ)】
１．AWSのネットワーク設定
→詰まったときはだいたいここの設定がおかしいか足りてない。
　以下の例外が出た場合はホストが見えないと怒られているのでネットワーク周りの設定を疑うべき。

2014-05-06 10:17:19,331 [main] INFO com.terracottatech.dso - Statistics store: '/usr/local/terracotta-3.7.7/statistics'.
2014-05-06 10:17:19,348 [main] INFO com.terracottatech.console - Available Max Runtime Memory: 494MB
2014-05-06 10:17:19,560 [main] INFO com.terracottatech.dso - Standard DSO Server created
2014-05-06 10:17:19,562 [main] INFO com.terracottatech.dso - Creating server nodeID: NodeID[(Terracottaサーバのホスト名・IPアドレス):9510:9510]
2014-05-06 10:17:19,584 [main] ERROR com.tc.server.TCServerMain - Thread:Thread[main,5,main] got an uncaught exception. calling CallbackOnExitDefaultHandlers.
java.net.UnknownHostException: (Terracottaサーバのホスト名・IPアドレス):9510: Name or service not known
        at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
        at java.net.InetAddress$1.lookupAllHostAddr(InetAddress.java:901)
        at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1293)
        at java.net.InetAddress.getAllByName0(InetAddress.java:1246)
        at java.net.InetAddress.getAllByName(InetAddress.java:1162)
        at java.net.InetAddress.getAllByName(InetAddress.java:1098)
        at java.net.InetAddress.getByName(InetAddress.java:1048)
        at com.tc.objectserver.impl.DistributedObjectServer.start(DistributedObjectServer.java:499)
        at com.tc.server.TCServerImpl.startDSOServer(TCServerImpl.java:531)
        at com.tc.server.TCServerImpl.access$600(TCServerImpl.java:92)
        at com.tc.server.TCServerImpl$StartAction.execute(TCServerImpl.java:479)
        at com.tc.lang.StartupHelper.startUp(StartupHelper.java:39)
        at com.tc.server.TCServerImpl.startServer(TCServerImpl.java:510)
        at com.tc.server.TCServerImpl.start(TCServerImpl.java:271)
        at com.tc.server.TCServerMain.main(TCServerMain.java:30)
2014-05-06 10:17:19,609 [main] ERROR com.tc.logging.ThreadDumpHandler - Tue May 06 10:17:19 UTC 2014
Full thread dump OpenJDK 64-Bit Server VM (24.51-b03 mixed mode):

２．warファイルの中身
→warファイルのサイズを確認する。
３．資産(jarファイル)がクラスパスから読み込まれていることを確認する
→Terracotta・Ehcache絡みのエラーメッセージが出る場合は大体資産が足りてないか見えてない。
→特に定義体については、APサーバ内でキャッシュが取得できなくてNullPointerExceptiionで落ちることがある。これはehcache.xmlがクラスパスより取得できずキャッシュが生成できていないため。

May 06, 2014 4:41:24 AM net.sf.ehcache.config.ConfigurationFactory parseConfiguration
WARNING: No configuration found. Configuring ehcache from ehcache-failsafe.xml  found in the classpath: jar:file:/var/lib/tomcat7/webapps/AP02/WEB-INF/lib/ehcache-core-2.6.8.jar!/ehcache-failsafe.xml
java.lang.NullPointerException
        at ap.TerracottaServletAp02.doPost(TerracottaServletAp02.java:30)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
        at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:200)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:603)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)
java.lang.NullPointerException
        at ap.TerracottaServletAp02.doPost(TerracottaServletAp02.java:30)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
--

４．APサーバのTomcatが起動してからコマンドetcを実行しているか
→割と遅いため、一応確認する。


【感想】
・完全に別VM上のJVM同士でデータの共有ができたのはいい勉強になった。

WEB+DB PRESS Vol.61

WEB+DB PRESS Vol.61