12 Replies Latest reply on Dec 6, 2012 8:36 AM by 914264

    Why process 'timestenrepd' on the standby database keep consuming 600% CPU?

    914264
      Hi all, I have just created a empty active standby pair where there are 14 regular AWT cache groups.
      After call of ttRepStart on the standby database, it takes 600% CPU(24 cores CPU) all the time.
      There is no data in the cache groups and I found the error logs in the tterrors.log file:
      ----------------------------

      14:01:28.32 Warn: : 27703: 27710/0xf83c50: Recovery started
      14:01:31.62 Warn: : 27703: 27710/(nil): Another checkpoint is in progress. The final checkpoint will continue when the other checkpoint finishes.
      14:01:44.96 Warn: REP: 25580: [139865850070784, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'FAILOVER' (context 0x7f2f580008c0) starting
      14:01:44.97 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'REPLISTENER' (context 0x7f2f600008c0) starting
      14:01:44.97 Warn: REP: 25580: [139865846920960, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'XLA_PARENT' (context 0x7f2f680008c0) starting
      14:01:44.97 Warn: REP: 25580: [139865853220608, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'REPHOLD' (context 0x7f35040008c0) starting
      14:01:45.04 Warn: REP: 25580: [139865840621312, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'LOGFORCE' (context 0x7f3500000c50) starting
      14:01:45.04 Warn: REP: 25580: [139865834321664, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'TRANSMITTER(M)' (context 0x7f2f540008c0) starting
      14:01:45.04 Warn: REP: 25580: [139865834321664, 0, noAwt] EPPDB:transmitter.c(1112): TT16285: Replication transmitter with local store id 16289484001462337649, remote store id 15530743840010091109, track id 0 got repSlave object 0x5406d9a0
      14:01:45.05 Warn: REP: 25580: [139865837471488, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'TRANSMITTER(M)' (context 0x7f2f500008c0) starting
      14:01:45.05 Warn: REP: 25580: [139865837471488, 0, noAwt] EPPDB:transmitter.c(1112): TT16285: Replication transmitter with local store id 16289484001462337649, remote store id 2679021640115572251, track id 0 got repSlave object 0x5006d9a0
      14:01:45.05 Warn: REP: 25580: [139865834321664, 0, noAwt] EPPDB:transmitter.c(1434): TT16999: Transmitter connecting to receiver
      14:01:45.12 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:45.13 Warn: REP: 25580: [139841666549504, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2f480008c0) starting
      14:01:45.13 Warn: REP: 25580: [139841663399680, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:45.76 Warn: REP: 25580: [139841657100032, 1, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'TRANSMITTER(S)' (context 0x7f2f400008c0) starting
      14:01:45.76 Warn: REP: 25580: [139841657100032, 1, noAwt] EPPDB:transmitter.c(1112): TT16285: Replication transmitter with local store id 16289484001462337649, remote store id 15530743840010091109, track id 1 got repSlave object 0x5406d9a0
      14:01:45.76 Warn: REP: 25580: [139841657100032, 1, noAwt] EPPDB:transmitter.c(1434): TT16999: Transmitter connecting to receiver
      14:01:45.76 Warn: REP: 25580: [139841660249856, 2, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'TRANSMITTER(S)' (context 0x7f2f3c0008c0) starting
      14:01:45.76 Warn: REP: 25580: [139841660249856, 2, noAwt] EPPDB:transmitter.c(1112): TT16285: Replication transmitter with local store id 16289484001462337649, remote store id 15530743840010091109, track id 2 got repSlave object 0x5406d9a0
      14:01:45.76 Warn: REP: 25580: [139841660249856, 2, noAwt] EPPDB:transmitter.c(1434): TT16999: Transmitter connecting to receiver
      14:01:46.15 Err : REP: 25580: [139841666549504, 0, noAwt] EPPDB:meta.c(3134): TT16999: receiver slot alloc: 16289484001462337649 15530743840010091109
      14:01:46.15 Warn: REP: 25580: [139841666549504, -1, notKnown] EPPDB:receiver.c(4350): TT16999: stopRcvrThreads (track 0) set to 0
      14:01:46.46 Warn: : 27703: 25580/0x7f2f400008c0: XXX:1st CTN for track 1 was 1354600888.2 with prev as 4294967295 hdr.firstCTN 1354600888.2expectedCTN=1354600888.2
      14:01:46.46 Warn: : 27703: 25580/0x7f2f400008c0: XXX:1st CTN for track 1 was 1354600894.2 with prev as 4294967295 hdr.firstCTN 1354600894.0expectedCTN=1354600894.0
      14:01:46.83 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:46.83 Warn: REP: 25580: [139841526023936, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2f340008c0) starting
      14:01:46.83 Warn: REP: 25580: [139840594581248, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:47.04 Warn: : 27703: 25580/0x7f2f540008c0: XXX:1st CTN for track 0 was 1354600888.3 with prev as 0 hdr.firstCTN 1354600888.2expectedCTN=1354600888.2
      14:01:47.05 Warn: : 27703: 25580/0x7f2f540008c0: XXX:1st CTN for track 0 was 1354600894.0 with prev as 4294967295 hdr.firstCTN 1354600894.0expectedCTN=1354600894.0
      14:01:47.43 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:47.43 Warn: REP: 25580: [139840591431424, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2f200008c0) starting
      14:01:47.43 Warn: REP: 25580: [139841522874112, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:48.46 Warn: REP: 25580: [139841666549504, -1, notKnown] EPPDB:receiver.c(3112): TT16999: stopRcvrThreads (track 0) set to 1
      14:01:48.46 Warn: REP: 25580: [139841666549504, 0, noAwt] EPPDB:receiver.c(3113): TT16060: Failed to read data from the network. select() timed out isAwt (false) parallelism (3) trackId (0) socket (17)
      14:01:48.46 Warn: REP: 25580: [139841666549504, -1, notKnown] EPPDB:receiver.c(1829): TT16999: stopRcvrThreads (track 0) set to 1
      14:01:48.66 Warn: REP: 25580: [139840591431424, -1, notKnown] EPPDB:receiver.c(3112): TT16999: stopRcvrThreads (track 1) set to 1
      14:01:48.66 Warn: REP: 25580: [139840591431424, 1, noAwt] EPPDB:receiver.c(3113): TT16060: Failed to read data from the network. TimesTen replication receivers are stopping isAwt (false) parallelism (3) trackId (1) socket (19)
      14:01:48.66 Warn: REP: 25580: [139840591431424, -1, notKnown] EPPDB:receiver.c(1829): TT16999: stopRcvrThreads (track 1) set to 1
      14:01:48.66 Err : REP: 25580: [139841522874112, 0, noAwt] EPPDB:receiver.c(1657): TT16275: RECEIVER network helper thread terminating due to certain error already recorded in the system log
      14:01:48.66 Warn: REP: 25580: [139841522874112, 0, noAwt] EPPDB:repagent.c(1276): TT16999: Receiver exiting isAwt (false)
      14:01:48.66 Warn: REP: 25580: [139840591431424, 1, noAwt] EPPDB:repagent.c(1276): TT16999: Receiver exiting isAwt (false)
      14:01:48.66 Warn: REP: 25580: [139841526023936, -1, notKnown] EPPDB:receiver.c(3112): TT16999: stopRcvrThreads (track 2) set to 1
      14:01:48.66 Warn: REP: 25580: [139841526023936, 2, noAwt] EPPDB:receiver.c(3113): TT16060: Failed to read data from the network. TimesTen replication receivers are stopping isAwt (false) parallelism (3) trackId (2) socket (23)
      14:01:48.66 Warn: REP: 25580: [139841526023936, -1, notKnown] EPPDB:receiver.c(1829): TT16999: stopRcvrThreads (track 2) set to 1
      14:01:48.66 Warn: REP: 25580: [139841666549504, -1, notKnown] EPPDB:receiver.c(1870): TT16999: stopRcvrThreads (track 0) set to 0
      14:01:48.66 Err : REP: 25580: [139840594581248, 0, noAwt] EPPDB:receiver.c(1657): TT16275: RECEIVER network helper thread terminating due to certain error already recorded in the system log
      14:01:48.66 Warn: REP: 25580: [139840594581248, 0, noAwt] EPPDB:repagent.c(1276): TT16999: Receiver exiting isAwt (false)
      14:01:48.66 Err : REP: 25580: [139841663399680, 0, noAwt] EPPDB:receiver.c(1657): TT16275: RECEIVER network helper thread terminating due to certain error already recorded in the system log
      14:01:48.66 Warn: REP: 25580: [139841663399680, 0, noAwt] EPPDB:repagent.c(1276): TT16999: Receiver exiting isAwt (false)
      14:01:48.66 Warn: REP: 25580: [139841526023936, 2, noAwt] EPPDB:repagent.c(1276): TT16999: Receiver exiting isAwt (false)
      14:01:48.66 Warn: REP: 25580: [139841666549504, 0, noAwt] EPPDB:repagent.c(1276): TT16999: Receiver exiting isAwt (false)
      14:01:49.05 Warn: REP: 25580: [139865837471488, 0, noAwt] EPPDB:transmitter.c(1425): TT16999: Awt transmitter connecting to receiver
      14:01:49.05 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:49.05 Warn: REP: 25580: [139841666549504, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2f480008c0) starting
      14:01:49.06 Warn: REP: 25580: [139841526023936, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context 0x7f2f00000000) starting
      14:01:49.22 Warn: : 27703: 25580/0x7f2f3c0008c0: XXX:1st CTN for track 2 was 1354600894.11 with prev as 4294967295 hdr.firstCTN 1354600894.11expectedCTN=1354600894.0
      14:01:50.17 Warn: REP: 25580: [139841666549504, -1, notKnown] EPPDB:receiver.c(4350): TT16999: stopRcvrThreads (track 0) set to 0
      14:01:53.54 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:53.54 Warn: REP: 25580: [139841663399680, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2f440008c0) starting
      14:01:53.54 Warn: REP: 25580: [139840594581248, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:54.20 Warn: REP: 25580: [139840591431424, 2, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'TRANSMITTER(S)' (context 0x7f2f200008c0) starting
      14:01:54.20 Warn: REP: 25580: [139840591431424, 2, noAwt] EPPDB:transmitter.c(1112): TT16285: Replication transmitter with local store id 16289484001462337649, remote store id 2679021640115572251, track id 2 got repSlave object 0x5006d9a0
      14:01:54.20 Warn: REP: 25580: [139840591431424, 2, noAwt] EPPDB:transmitter.c(1425): TT16999: Awt transmitter connecting to receiver
      14:01:54.20 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:54.20 Warn: REP: 25580: [139841522874112, 1, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'TRANSMITTER(S)' (context 0x7f2f180008c0) starting
      14:01:54.20 Warn: REP: 25580: [139841522874112, 1, noAwt] EPPDB:transmitter.c(1112): TT16285: Replication transmitter with local store id 16289484001462337649, remote store id 2679021640115572251, track id 1 got repSlave object 0x5006d9a0
      14:01:54.20 Warn: REP: 25580: [139841533159168, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_APPLIER' (context 0x7f2f080008c0) starting
      14:01:54.20 Warn: REP: 25580: [139841533159168, 0, Awt] EPPDB:awt.c(210): TT16999: Parallel AWT Applier #4 started
      14:01:54.20 Warn: REP: 25580: [139841405417216, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_APPLIER' (context 0x7f2ef40008c0) starting
      14:01:54.20 Warn: REP: 25580: [139841405417216, 0, Awt] EPPDB:awt.c(210): TT16999: Parallel AWT Applier #1 started
      14:01:54.21 Warn: REP: 25580: [139841530009344, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_APPLIER' (context 0x7f2efc0008c0) starting
      14:01:54.21 Warn: REP: 25580: [139841530009344, 0, Awt] EPPDB:awt.c(210): TT16999: Parallel AWT Applier #3 started
      14:01:54.21 Warn: REP: 25580: [139841522874112, 1, noAwt] EPPDB:transmitter.c(1425): TT16999: Awt transmitter connecting to receiver
      14:01:54.21 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:54.21 Warn: REP: 25580: [139841402267392, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_APPLIER' (context 0x7f2ef80008c0) starting
      14:01:54.21 Warn: REP: 25580: [139841402267392, 0, Awt] EPPDB:awt.c(210): TT16999: Parallel AWT Applier #0 started
      14:01:54.21 Warn: REP: 25580: [139841536308992, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_APPLIER' (context 0x7f2f040008c0) starting
      14:01:54.21 Warn: REP: 25580: [139841536308992, 0, Awt] EPPDB:awt.c(210): TT16999: Parallel AWT Applier #5 started
      14:01:54.21 Warn: REP: 25580: [139841539458816, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_SORTER' (context 0x7f2f0c0008c0) starting
      14:01:54.21 Warn: REP: 25580: [139841539458816, 0, Awt] EPPDB:awt.c(144): TT16999: Parallel AWT Sorter started
      14:01:54.21 Warn: REP: 25580: [139841399117568, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2eec0008c0) starting
      14:01:54.22 Warn: REP: 25580: [139841392817920, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:54.22 Warn: REP: 25580: [139841395967744, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2ef00008c0) starting
      14:01:54.22 Warn: REP: 25580: [139841389668096, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:54.22 Warn: REP: 25580: [139841408567040, 0, Awt] EPPDB:repagent.c(1227): TT16025: Thread 'AWT_APPLIER' (context 0x7f2f000008c0) starting
      14:01:54.22 Warn: REP: 25580: [139841408567040, 0, Awt] EPPDB:awt.c(210): TT16999: Parallel AWT Applier #2 started
      14:01:55.87 Warn: REP: 25580: [139841663399680, -1, notKnown] EPPDB:receiver.c(4350): TT16999: stopRcvrThreads (track 0) set to 0
      14:01:56.54 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:56.55 Warn: REP: 25580: [139841182365440, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2ed80008c0) starting
      14:01:56.55 Warn: REP: 25580: [139841179215616, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:56.89 Warn: : 27703: 25580/0x7f2f180008c0: XXX:1st CTN for track 1 was 1354600759.70 with prev as 63 hdr.firstCTN 1354600759.69expectedCTN=1354600759.69
      14:01:56.89 Warn: : 27703: 25580/0x7f2f180008c0: XXX:1st CTN for track 1 was 1354600888.2 with prev as 4294967295 hdr.firstCTN 1354600888.1expectedCTN=1354600888.0
      14:01:56.89 Warn: : 27703: 25580/0x7f2f180008c0: XXX:1st CTN for track 1 was 1354600894.2 with prev as 4294967295 hdr.firstCTN 1354600894.0expectedCTN=1354600894.0
      14:01:57.26 Warn: REP: 25580: [139865843771136, 0, noAwt] EPPDB:receiver.c(2263): TT16999: RepListner succesfully done spawning a receiver
      14:01:57.27 Warn: REP: 25580: [139841176065792, 0, noAwt] EPPDB:repagent.c(1227): TT16025: Thread 'RECEIVER' (context 0x7f2ecc0008c0) starting
      14:01:57.27 Warn: REP: 25580: [139841172915968, 0, noAwt] EPPDB:repagent.c(1231): TT16025: Thread 'RECEIVERNET' (context (nil)) starting
      14:01:57.90 Warn: : 27703: 25580/0x7f2f500008c0: XXX:1st CTN for track 0 was 1354600759.71 with prev as 68 hdr.firstCTN 1354600759.69expectedCTN=1354600759.69
      14:02:04.08 Warn: : 27703: 25580/0x7f2f200008c0: XXX:1st CTN for track 2 was 1354600759.69 with prev as 64 hdr.firstCTN 1354600759.69expectedCTN=1354600759.69
      14:02:04.08 Warn: : 27703: 25580/0x7f2f200008c0: XXX:1st CTN for track 2 was 1354600888.1 with prev as 4294967295 hdr.firstCTN 1354600888.1expectedCTN=1354600888.0
      14:02:04.08 Warn: : 27703: 25580/0x7f2f200008c0: XXX:1st CTN for track 2 was 1354600894.11 with prev as 4294967295 hdr.firstCTN 1354600894.11expectedCTN=1354600894.0
      14:02:04.08 Warn: : 27703: 25580/0x7f2f500008c0: XXX:1st CTN for track 0 was 1354600888.0 with prev as 4294967295 hdr.firstCTN 1354600888.0expectedCTN=1354600888.0
      14:02:04.08 Warn: : 27703: 25580/0x7f2f500008c0: XXX:1st CTN for track 0 was 1354600894.0 with prev as 4294967295 hdr.firstCTN 1354600894.0expectedCTN=1354600894.0

      ----------------------------
      Please note that this is a newly active standby pair where there is no data or workload while the problem occurs, it makes me very depressed.