4 Replies Latest reply: Jan 9, 2014 11:53 AM by chris_here RSS

    TimesTen cache agent policy reverting to 'manual'

    chris_here

      Hi,

       

      while using TT 11.2.2.4.1 on RedHat EL 6.3 x86_64 as a IMDB cache for an Oracle 11gR2 11.2.0.3.7 instance on a remote host, we came across a situation where the Cache Agent Policy seems to have been automatically reverted back to "manual" from "always" as it was originally set (at installation time). See line 64 in the log extract below. The event that triggered the situation was probably the Oracle DB being shut down on the remote host.

       

      $ ttAdmin -query ttcache
      RAM Residence Policy            : always
      Replication Agent Policy        : manual
      Replication Manually Started    : False
      Cache Agent Policy              : manual
      Cache Agent Manually Started    : False
      
      
      
      

       

      This situation is problematic to us because it means that the cache will not be restarted without manual intervention, which cancels the overall redundancy of our system. Is this behavior expected / documented? Is there a way to avoid it?

       

      Thanks for your help,

      Chris

       

      Edit: I realize I posted the almost exact same question a few months ago (cf Automatically respawning cache agent after Oracle bounces). However at that time our configuration was unnecessarily attaching to the grid in read/write mode, and hit a bug in TT (corrected since). The configuration was modified since to avoid this, and seemed to work pretty well up to now. In the present case though, the cache agents are purely read-only, and the problem only occurred on one of our two cache agents.

       

      14:33:29.94 Err : CAC: 51560: TT40076-51560--1726642432-refresh02436: TTCACHE Failed calling OCI function: OCIStmtExecute()
      14:33:29.94 Err : CAC: 51560: TT40077-51560--1726642432-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 33454 Session ID: 271 Serial number: 15
      14:33:30.03 Err : CAC: 51560: TT40076-51560-940111616-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.03 Err : CAC: 51560: TT40077-51560-940111616-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 277 Serial number: 15
      14:33:30.10 Err : CAC: 51560: TT40076-51560--1724000512-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.10 Err : CAC: 51560: TT40077-51560--1724000512-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 283 Serial number: 13
      14:33:30.24 Err : CAC: 51560: TT40076-51560--1725057280-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.24 Err : CAC: 51560: TT40077-51560--1725057280-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 289 Serial number: 7
      14:33:30.24 Warn: CAC: 51560: TT44000-51560--1725057280-xxagent06094: TTCACHE Warning: Statement SQLDisconnect(connP->ttHdbc)
      14:33:30.24 Err : CAC: 51560: TT40046-51560--1725057280-bcStuff01095: TTCACHE Error: [TimesTen]TT5212: No longer connected to Oracle error in OCITransRollback(): ORA-03113: end-of-file on communication channel Process ID: 33553 Session ID: 295 Serial number: 7 rc = -1 -- file "bdbConnect.c", lineno 4989, procedure "disconnectInternal()", ODBC SQL state = S1000, Additional Warning = 5212
      14:33:30.34 Err : CAC: 51560: TT40076-51560--1726114048-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.34 Err : CAC: 51560: TT40077-51560--1726114048-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 313 Serial number: 7
      14:33:30.44 Err : CAC: 51560: TT40076-51560--1724528896-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.44 Err : CAC: 51560: TT40077-51560--1724528896-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 307 Serial number: 7
      14:33:30.44 Err : CAC: 51560: TT40076-51560--1724528896-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.44 Err : CAC: 51560: TT40077-51560--1724528896-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 301 Serial number: 7
      14:33:30.96 Err : CAC: 51560: TT40076-51560--1725585664-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:30.96 Err : CAC: 51560: TT40077-51560--1725585664-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 319 Serial number: 7
      14:33:31.06 Err : CAC: 51560: TT40076-51560-940640000-xxagent06031: TTCACHE Failed calling OCI function: OCISessionEnd
      14:33:31.06 Err : CAC: 51560: TT40077-51560-940640000-raUtils00387: TTCACHE Oracle native error code = 3113, msg = ORA-03113: end-of-file on communication channel Process ID: 0 Session ID: 265 Serial number: 53
      14:33:33.00 Err : CAC:  6235: TT40076-6235-27313920-raStuff03675: TTCACHE Failed calling OCI function: OCIServerAttach()
      14:33:33.00 Err : CAC:  6235: TT40077-6235-27313920-raUtils00387: TTCACHE Oracle native error code = 12541, msg = ORA-12541: TNS:no listener
      14:33:33.02 Err : CAC:  6235: TT40018-6235--66038016-raStuff03104: TTCACHE TimesTen error code:5921, msg Could not connect to Oracle.  Please check the status of the Oracle instance.
      14:33:33.02 Err : CAC:  6235: TT40115-6235--66038016-heduler01870: TTCACHE No cache groups will be autorefreshed until a connect to Oracle can be established. Will try to connect to Oracle silently every 30 seconds. Additional error information:<none>.
      14:34:33.08 Warn: CAC:  6235: TT44023-6235--66038016-heduler01890: TTCACHE Cache agent was successfully able to connect to Oracle after 2 failed attempts
      14:36:01.29 Warn:    : 51448: 51453 ------------------: subdaemon process exited
      14:36:01.30 Warn:    : 51448: 51454 ------------------: subdaemon process exited
      14:36:01.30 Warn:    : 51448: 51452 ------------------: subdaemon process exited
      14:36:01.30 Warn:    : 51448: 51452 exited while connected to data store '/var/opt/timesten/smsgw/info/ttcache' shm 470024242 count=11
      14:36:01.30 Warn:    : 51448: daRecovery: subdaemon 51452, managing data store, failed: invalidate (failcode=202)
      14:36:01.30 Warn:    : 51448: Invalidating the data store (failcode 202, recovery for 51452)
      14:36:01.30 Warn:    : 51448: child process 51452 terminated with signal 9
      14:36:01.30 Warn:    : 51448: child process 51453 terminated with signal 9
      14:36:01.30 Warn:    : 51448: child process 51454 terminated with signal 9
      14:36:01.60 Warn:    : 51448: 51503/0x1e00dc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:01.60 Warn:    : 51448: 51503 ----------: Disconnecting from an old instance
      14:36:01.60 Warn: SRV: 51503: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:01.66 Warn:    : 51448: 51490/0x1e86dc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:01.66 Warn:    : 51448: 51490 ----------: Disconnecting from an old instance
      14:36:01.66 Warn: SRV: 51490: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:01.90 Warn:    : 51448: 51509/0x1400dc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:01.90 Warn:    : 51448: 51509 ----------: Disconnecting from an old instance
      14:36:01.90 Warn: SRV: 51509: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:02.06 Warn:    : 51448: 51455/0x14b72b0: Recovery started
      14:36:02.26 Warn:    : 51448: 51545/0x1ad9dc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:02.26 Warn:    : 51448: 51545 ----------: Disconnecting from an old instance
      14:36:02.26 Warn: SRV: 51545: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:02.40 Warn:    : 51448: 6235/0x7fcf503b31f0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:02.40 Warn:    : 51448: 6235 ----------: Disconnecting from an old instance
      14:36:02.58 Warn:    : 51448: 51549/0xe7fdc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:02.58 Warn:    : 51448: 51549 ----------: Disconnecting from an old instance
      14:36:02.58 Warn: SRV: 51549: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:02.63 Warn:    : 51448: 51579/0xf6adc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:02.63 Warn:    : 51448: 51579 ----------: Disconnecting from an old instance
      14:36:02.63 Warn: SRV: 51579: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:02.88 Warn:    : 51448: 51554/0x146cdc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:02.88 Warn:    : 51448: 51554 ----------: Disconnecting from an old instance
      14:36:02.88 Warn: SRV: 51554: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:02.90 Warn:    : 51448: 6235/0x7fcf4c014810: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:02.90 Warn:    : 51448: 6235 ----------: Disconnecting from an old instance
      14:36:03.27 Warn:    : 51448: 51497/0x7bfdc0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:03.27 Warn:    : 51448: 51497 ----------: Disconnecting from an old instance
      14:36:03.27 Warn: SRV: 51497: EventID=99| Data store connection terminated by TimesTen Server (because data store is invalid). Please reconnect.
      14:36:03.30 Warn:    : 51448: Could not start Cache agent for /var/opt/timesten/smsgw/info/ttcache (Cache agent already active for data store): setting to 'manual' policy
      14:36:03.70 Warn:    : 51448: 6235/0x7fcf44014790: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:03.70 Warn:    : 51448: 6235 ----------: Disconnecting from an old instance
      14:36:22.76 Warn:    : 51448: 12751/0x7fe73c0a5890: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:22.76 Warn:    : 51448: 12751 ----------: Disconnecting from an old instance
      14:36:22.81 Warn:    : 51448: 12751/0x7fec1c17a6f0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:22.81 Warn:    : 51448: 12751 ----------: Disconnecting from an old instance
      14:36:23.13 Warn:    : 51448: 7227/0x7f7520184f60: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:23.13 Warn:    : 51448: 7227 ----------: Disconnecting from an old instance
      14:36:23.19 Warn:    : 51448: 7227/0x7f75180a7870: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:23.19 Warn:    : 51448: 7227 ----------: Disconnecting from an old instance
      14:36:23.38 Warn:    : 51448: 10441/0x7fd92c0a38b0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:23.38 Warn:    : 51448: 10441 ----------: Disconnecting from an old instance
      14:36:23.44 Warn:    : 51448: 10441/0x7fddc8178750: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:23.44 Warn:    : 51448: 10441 ----------: Disconnecting from an old instance
      14:36:24.55 Warn:    : 51448: 8250/0x7fe1400a5890: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:24.55 Warn:    : 51448: 8250 ----------: Disconnecting from an old instance
      14:36:24.60 Warn:    : 51448: 8250/0x7fe5e417a770: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:24.60 Warn:    : 51448: 8250 ----------: Disconnecting from an old instance
      14:36:34.50 Warn:    : 51448: 6235/0x7fd3f806b7e0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:34.50 Warn:    : 51448: 6235 ----------: Disconnecting from an old instance
      14:36:34.50 Warn: CAC:  6235: TT44000-6235-27850496-xxagent05836: TTCACHE Warning: Statement SQLDisconnect(agentHdbc)
      14:36:34.50 Err : CAC:  6235: TT40046-6235-27850496-bcStuff01095: TTCACHE Error: [TimesTen]TT0994: Data store connection terminated. Please reconnect. -- file "dbAPI.c", lineno 3168, procedure "sb_dbDisconnect()", ODBC SQL state = S1000, Additional Warning = 994
      14:36:34.50 Err : CAC:  6235: TT40050-6235-27850496-bcStuff01120: TTCACHE Detected invalid data store.
      14:36:34.51 Warn:    : 51448: 6235/0x7fcf58014660: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:36:34.51 Warn:    : 51448: 6235 ----------: Disconnecting from an old instance
      14:36:34.52 Warn: CAC:  6235: TT44000-6235-27850496-xxagent05842: TTCACHE Warning: Statement SQLDisconnect(timerHdbc)
      14:36:34.52 Err : CAC:  6235: TT40046-6235-27850496-bcStuff01095: TTCACHE Error: [TimesTen]TT0994: Data store connection terminated. Please reconnect. -- file "dbAPI.c", lineno 3168, procedure "sb_dbDisconnect()", ODBC SQL state = S1000, Additional Warning = 994
      14:36:34.52 Err : CAC:  6235: TT40050-6235-27850496-bcStuff01120: TTCACHE Detected invalid data store.
      14:37:12.37 Warn:    : 51448: Invalidating in-RAM shared data store /var/opt/timesten/smsgw/info/ttcache because in use at exit
      14:37:12.37 Err :    : 51448: 51455/0x7fe9300008c0: IndexGC could not start a transaction
      14:37:12.37 Warn:    : 51448: 51455/0x7fedf80008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:37:12.37 Warn:    : 51448: 51455/0x7fe9300008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:37:12.38 Err :    : 51455: subd: IndexGC thread terminated with error
      14:37:12.38 Warn:    : 51448: 51455/0x7fe95c0008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:37:12.41 Err :    : 51448: Could not connect to subdaemon 51455, port 61049
      14:37:12.41 Warn:    : 51448: 51455 ------------------: subdaemon process exited
      14:37:12.41 Warn:    : 51448: 51455 exited while connected to data store '/var/opt/timesten/smsgw/info/ttcache' shm 520355890 count=11
      14:37:12.44 Err : CAC: 13679: TT40011-13679--1426188544-xxagent02810: TTCACHE Cache agent exiting, main daemon gone
      14:37:30.78 Warn:    : 16232: Invalidating the data store /var/opt/timesten/smsgw/info/ttcache because it had 18 users
      14:37:30.78 Warn:    : 16232: WARNING: data store /var/opt/timesten/smsgw/info/ttcache was in use at daemon termination.
      14:37:30.78 Warn:    : 16232: WARNING: data store no longer considered in use
      14:37:30.78 Warn:    : 16232: TimesTen Daemon Release 11.2.2.4.1.smsgw started.
      14:37:35.42 Warn:    : 16232: 12751 0x7fe73c0a5890: Data store in process of loading, try later
      14:37:35.58 Warn: CAC: 13679: TT44000-13679--1425119488-xxagent05836: TTCACHE Warning: Statement SQLDisconnect(agentHdbc)
      14:37:35.58 Err : CAC: 13679: TT40046-13679--1425119488-bcStuff01095: TTCACHE Error: [TimesTen]TT0994: Data store connection terminated. Please reconnect. -- file "dbAPI.c", lineno 3168, procedure "sb_dbDisconnect()", ODBC SQL state = S1000, Additional Warning = 994
      14:37:35.58 Err : CAC: 13679: TT40050-13679--1425119488-bcStuff01120: TTCACHE Detected invalid data store.
      14:37:35.58 Err : CAC: 13679: TT40046-13679--1425119488-bcStuff01095: TTCACHE Error: [TimesTen]TT0798: Daemon reports error -102 -- file "db.c", lineno 15740, procedure "sbDbAppExit", ODBC SQL state = 08001, Additional Warning = 798
      14:37:35.58 Warn: CAC: 13679: TT44000-13679--1425119488-xxagent05842: TTCACHE Warning: Statement SQLDisconnect(timerHdbc)
      14:37:35.58 Err : CAC: 13679: TT40046-13679--1425119488-bcStuff01095: TTCACHE Error: [TimesTen]TT0994: Data store connection terminated. Please reconnect. -- file "dbAPI.c", lineno 3168, procedure "sb_dbDisconnect()", ODBC SQL state = S1000, Additional Warning = 994
      14:37:35.58 Err : CAC: 13679: TT40050-13679--1425119488-bcStuff01120: TTCACHE Detected invalid data store.
      14:37:35.58 Err : CAC: 13679: TT40046-13679--1425119488-bcStuff01095: TTCACHE Error: [TimesTen]TT0798: Daemon reports error -102 -- file "db.c", lineno 15740, procedure "sbDbAppExit", ODBC SQL state = 08001, Additional Warning = 798
      14:37:35.73 Warn:    : 16232: 7227 0x7f7520184f60: Data store in process of loading, try later
      14:37:35.86 Warn:    : 16232: 16482 0x18b2dc0: Data store in process of loading, try later
      14:37:35.96 Warn:    : 16232: 10441 0x7fd92c0a38b0: Data store in process of loading, try later
      14:37:36.18 Warn:    : 16232: 16489 0x1d64dc0: Data store in process of loading, try later
      14:37:36.47 Warn:    : 16232: 16494 0x13dcdc0: Data store in process of loading, try later
      14:37:37.13 Warn:    : 16232: 8250 0x7fe1400a5890: Data store in process of loading, try later
      14:37:40.23 Warn:    : 16232: 16502 0x1a4cdc0: Data store in process of loading, try later
      14:37:40.43 Warn:    : 16232: 12751 0x7fe73c0a5890: Data store in process of loading, try later
      14:37:40.73 Warn:    : 16232: 7227 0x7f7520184f60: Data store in process of loading, try later
      14:44:22.87 Warn:    : 16232: Invalidating in-RAM shared data store /var/opt/timesten/smsgw/info/ttcache because in use at exit
      14:44:22.87 Err :    : 16232: 16236/0x7f4d340008c0: IndexGC could not start a transaction
      14:44:22.87 Warn:    : 16232: 16236/0x7f4d500008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:44:22.88 Warn:    : 16232: 16236/0x7f4d340008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:44:22.88 Err :    : 16236: subd: IndexGC thread terminated with error
      14:44:22.89 Warn:    : 16232: 16236/0x7f4d480008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:44:22.90 Warn:    : 16232: 16236/0x7f4d400008c0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache
      14:44:22.90 Err :    : 16232: Could not connect to subdaemon 16236, port 59033
      14:44:22.90 Warn:    : 16232: 16236 ------------------: subdaemon process exited
      14:44:22.90 Warn:    : 16232: 16236 exited while connected to data store '/var/opt/timesten/smsgw/info/ttcache' shm 570687538 count=11
      14:44:55.71 Warn:    : 34334: Invalidating the data store /var/opt/timesten/smsgw/info/ttcache because it had 19 users
      14:44:55.71 Warn:    : 34334: WARNING: data store /var/opt/timesten/smsgw/info/ttcache was in use at daemon termination.
      14:44:55.71 Warn:    : 34334: WARNING: data store no longer considered in use
      14:44:55.71 Warn:    : 34334: TimesTen Daemon Release 11.2.2.4.1.smsgw started.
      14:44:55.79 Warn:    : 34334: 34374 0x125cdc0: Data store in process of loading, try later
      14:44:56.03 Warn:    : 34334: 12751 0x7fec1c17e6b0: Data store in process of loading, try later
      14:44:56.24 Warn:    : 34334: 34383 0x1685dc0: Data store in process of loading, try later
      14:44:56.40 Warn:    : 34334: 8250 0x7fe5e4179780: Data store in process of loading, try later
      14:44:56.41 Warn:    : 34334: 7227 0x7f7520183f70: Data store in process of loading, try later
      14:44:56.66 Warn:    : 34334: 10441 0x7fddc817c710: Data store in process of loading, try later
      14:44:57.46 Warn:    : 34334: 34393 0x1390dc0: Data store in process of loading, try later
      14:44:57.53 Warn:    : 34334: 34398 0x2593dc0: Data store in process of loading, try later
      14:45:00.79 Warn:    : 34334: 34374 0x125cdc0: Data store in process of loading, try later
      14:45:01.03 Warn:    : 34334: 12751 0x7fec1c17e6b0: Data store in process of loading, try later
      14:45:01.24 Warn:    : 34334: 34383 0x1685dc0: Data store in process of loading, try later
      14:45:01.40 Warn:    : 34334: 8250 0x7fe5e4179780: Data store in process of loading, try later
      14:45:01.41 Warn:    : 34334: 7227 0x7f7520183f70: Data store in process of loading, try later
      14:45:01.66 Warn:    : 34334: 10441 0x7fddc817c710: Data store in process of loading, try later
      14:45:02.46 Warn:    : 34334: 34393 0x1390dc0: Data store in process of loading, try later
      14:45:02.53 Warn:    : 34334: 34398 0x2593dc0: Data store in process of loading, try later
      14:50:14.82 Warn: SRV: 34632: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:50:14.82 Warn: SRV: 34393: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:50:14.82 Warn: SRV: 34398: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:50:14.82 Warn: SRV: 34627: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:50:14.82 Warn: SRV: 34622: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:50:14.82 Warn: SRV: 34618: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:50:14.82 Warn: SRV: 34383: EventID=99| Main server has unexpectedly exited; child server exiting and client connection terminated
      14:53:45.47 Warn:    : 54768: Invalidating the data store /var/opt/timesten/smsgw/info/ttcache because it had 27 users
      14:53:45.47 Warn:    : 54768: WARNING: data store /var/opt/timesten/smsgw/info/ttcache was in use at daemon termination.
      14:53:45.47 Warn:    : 54768: WARNING: data store no longer considered in use
      14:53:45.47 Warn:    : 54768: TimesTen Daemon Release 11.2.2.4.1.smsgw started.
      14:53:45.48 Warn: SRV: 54783: EventID=99| Cleaning up shared memory from previous server invocation
      14:53:45.51 Warn:    : 54768: 54828 0x1393dc0: Data store in process of loading, try later
      14:53:46.03 Warn:    : 54768: 55166 0x7a5dc0: Data store in process of loading, try later
      14:53:46.82 Warn:    : 54768: 55597 0x125adc0: Data store in process of loading, try later
      14:53:47.20 Warn:    : 54768: 55602 0x1c54dc0: Data store in process of loading, try later
      14:53:50.51 Warn:    : 54768: 54828 0x1393dc0: Data store in process of loading, try later
      14:53:51.03 Warn:    : 54768: 55166 0x7a5dc0: Data store in process of loading, try later
      14:53:51.82 Warn:    : 54768: 55597 0x125adc0: Data store in process of loading, try later
      14:53:52.21 Warn:    : 54768: 55602 0x1c54dc0: Data store in process of loading, try later
      14:53:53.76 Warn:    : 54768: 8250 0x7fe1400aa840: Data store in process of loading, try later
      14:53:53.81 Warn:    : 54768: 12751 0x7fec1c1a20f0: Data store in process of loading, try later
      14:53:53.96 Warn:    : 54768: 7227 0x7f75180a6880: Data store in process of loading, try later
      14:53:54.22 Warn:    : 54768: 10441 0x7fddc81a0150: Data store in process of loading, try later
      14:53:55.57 Warn:    : 54768: 54778/0x1e152b0: Recovery started
      
      
      
      
      

       

      Message edited to link to a previous related issue.

       

      Message edited to link to a previous related issue

       

      Message edited to link to an earlier related issue.

        • 1. Re: TimesTen cache agent policy reverting to 'manual'
          Jspalmer-Oracle

          This sounds like the following bug:

           

          BUG 16684083 - CACHE AGENT STOPS AND DOES NOT RESTART (fixed in 11.2.2.4.7)

          BUG 16748309 - CACHE AGENT STOPS AND DOES NOT RESTART (fixed in 11.2.2.5.0)

           

          I'm including both versions that it's fixed in as I don't know what upgrade plans you might have. 16684083 has more details.

          • 2. Re: TimesTen cache agent policy reverting to 'manual'
            chris_here

            Hi,

             

            thanks for the answer. It may be the same bug indeed, however the logged messages look different. In this particular case there seemed to be a conflict of some sort and TT forcibly reset the cache policy to manual:

             

            Could not start Cache agent for /var/opt/timesten/smsgw/info/ttcache (Cache agent already active for data store): setting to 'manual' policy
            

             

            Any idea?

             

            Thanks,

            Chris

            • 3. Re: TimesTen cache agent policy reverting to 'manual'
              Jspalmer-Oracle

              I think the additional problem here is that the datastore invalidated. The "Could not start Cache agent..." message is unhelpful as it doesn't give you the PID of the Cache Agent process, but I think it's likely to be PID 6235. This says:

               

              14:34:33.08 Warn: CAC: 6235: TT44023-6235--66038016-heduler01890: TTCACHE Cache agent was successfully able to connect to Oracle after 2 failed attempts

               

              but then the datastore is invalidated here:

               

              14:36:01.30 Warn: : 51448: 51452 exited while connected to data store '/var/opt/timesten/smsgw/info/ttcache' shm 470024242 count=11

              14:36:01.30 Warn: : 51448: daRecovery: subdaemon 51452, managing data store, failed: invalidate (failcode=202)

               

              It looks like a number of subdaemon processes were forcibly killed with kill -9 around this time, which would explain why 51452 exited uncleanly and the datastore had to be invalidated.

               

              A couple of its threads then disconnect here:

               

              14:36:02.40 Warn: : 51448: 6235/0x7fcf503b31f0: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache

              14:36:02.40 Warn: : 51448: 6235 ----------: Disconnecting from an old instance

              14:36:02.90 Warn: : 51448: 6235/0x7fcf4c014810: Forced Disconnect /var/opt/timesten/smsgw/info/ttcache

              14:36:02.90 Warn: : 51448: 6235 ----------: Disconnecting from an old instance

               

               

              before this Warning is thrown:

               

              14:36:03.30 Warn: : 51448: Could not start Cache agent for /var/opt/timesten/smsgw/info/ttcache (Cache agent already active for data store): setting to 'manual' policy

               

               

              I haven't been able to find a specific reference to what triggers this warning to be issued, though there is an unfixed internal bug in this area:

               

              Bug 9030650 : CACHE AGENT IS NOT ALWAYS RESTARTED AFTER INVALIDATION

               

              Are you able to log an SR with a reference to this discussion, so it can be formally discussed with Development? If you do, please include the ttmesg.log files which cover this period as well.

               

              https://mosemp.us.oracle.com/epmos/adf/images/t.gif

              • 4. Re: TimesTen cache agent policy reverting to 'manual'
                chris_here

                Hi,

                 

                I have filed SR 3-8341016701 on this issue.

                 

                Regards,

                Chris