ER queue data
Folks, IDS11.70 FC7, RedHat Linux 5 These days, we are really struggling with Informix ER replication, it just queues data there ( see below, a three site replication Anywhere). The problem started after we upgraded from IDS11.50 FC8 . We were happy with IDS11.50 FC8 and had no such problem with it for years ! But frustrated now :-( Thanks, Frank [informix@maggie ~]$ cdr view servers SERVERS Server Peer ID State Status Queue Connection Changed --------------------------------------------------------------------------- g_ncdcops g_ncdcops 22 Active Local 0 g_ngdcops 23 Active Connected 2019393999 Oct 1 19:29:47 g_nsofops 21 Active Connected 1150 Oct 1 19:04:27 g_ngdcops g_ncdcops 22 Active Connected 1981723906 Oct 1 19:29:48 g_ngdcops 23 Active Local 0 g_nsofops 21 Active Connected 0 Oct 1 19:07:16 g_nsofops g_ncdcops 22 Active Connected 24168402804 Oct 1 19:04:27 g_ngdcops 23 Active Connected 10582241649 Oct 1 19:07:17 g_nsofops 21 Active Local 0 It takes 10 minutes to run the follwoing command !! [informix@walter ~]$ time cdr view profile ER PROFILE for Node g_ncdcops ER State Active DDR - Running SPOOL DISK USAGE Current 80834:513060864 Total 20000000 Snoopy 80834:513057208 Metadata Free 727416 Replay 80834:512827416 Userdata Free 18653710 Pages from Log Lag State 30594741 RECVQ SENDQ Txn In Queue 0 Txn In Queue 10 Txn In Pending List 0 Txn Spooled 0 Acks Pending 0 APPLY - Running Txn Processed 4051709 NETWORK - Running Commit Rate 46.31 Currently connected to 2 out of 2 Avg. Active Apply 2.57 Msg Sent 6825365 Fail Rate 0.00 Msg Received 12119333 Total Failures 154 Throughput -10690.02 Avg Latency 0.00 Pending Messages 0 Max Latency 0 ATS File Count 9106 RIS File Count 9106 --------------------------------------------------------------------------- ER PROFILE for Node g_ngdcops ER State Active DDR - Running SPOOL DISK USAGE Current 174170:575250432 Total 20000000 Snoopy 174170:575246448 Metadata Free 225676 Replay 174170:571887840 Userdata Free 18153712 Pages from Log Lag State 30579558 RECVQ SENDQ Txn In Queue 0 Txn In Queue 12 Txn In Pending List 0 Txn Spooled 0 Acks Pending 0 APPLY - Running Txn Processed 4018341 NETWORK - Running Commit Rate 46.02 Currently connected to 2 out of 2 Avg. Active Apply 2.85 Msg Sent 7053004 Fail Rate 0.00 Msg Received 12032857 Total Failures 619 Throughput -10645.47 Avg Latency 0.50 Pending Messages 0 Max Latency 1 ATS File Count 34 RIS File Count 34 --------------------------------------------------------------------------- ER PROFILE for Node g_nsofops ER State Active DDR - Running SPOOL DISK USAGE Current 114575:129708032 Total 20000000 Snoopy 114575:129704600 Metadata Free 0 Replay 114575:129020424 Userdata Free 18653710 Pages from Log Lag State 30688333 RECVQ SENDQ Txn In Queue 0 Txn In Queue 37 Txn In Pending List 0 Txn Spooled 0 Acks Pending 0 APPLY - Running Txn Processed 961994 NETWORK - Running Commit Rate 10.97 Currently connected to 2 out of 2 Avg. Active Apply 2.83 Msg Sent 20369608 Fail Rate 0.00 Msg Received 10048584 Total Failures 307 Throughput -3332.02 Avg Latency 0.00 Pending Messages 0 Max Latency 0 ATS File Count 17 RIS File Count 17 --------------------------------------------------------------------------- real 10m49.626s user 0m0.228s sys 0m0.040s --047d7b33d79c62f11d04e7c71687
Paul,
The following are the three outputs of the commands. Please Let me know
if you see some clue.
The ER rejected transactions in ATS/RIS directory is fine to us( we
lived with this for years, we can do manual data sync late, no problem at
all).
As long as ER continue to process the new coming transactions,
we would be happy...
But it queues data , does not send data(or intolerably slow) to other
sites.....
Thanks,
Frank
[fqu@maggie bin]$ cdr list server
SERVER ID STATE STATUS QUEUE CONNECTION CHANGED
-----------------------------------------------------------------------
g_ncdcops 22 Active Connected 24142400034 Oct 1 19:04:27
g_ngdcops 23 Active Connected 6495057993 Oct 1 19:07:17
g_nsofops 21 Active Local 0
[fqu@maggie bin]$ onstat -g rcv
IBM Informix Dynamic Server Version 11.70.FC7 -- On-Line -- Up 5 days
01:16:54 -- 8359540 KbytesServerId: 23
Flags 0x0
ServerId: 22
Flags 0x0
Threads:
Id Name State Handle
6353620 CDRACK_5 Idle 0x143f98cc8
6280008 CDRACK_4 Idle 0x1436b44f8
6229955 CDRACK_3 Idle 0x148ce3028
6229671 CDRACK_2 Idle 0x144acd0d8
6228209 CDRACK_1 Idle 0x14acdb0d8
6228208 CDRACK_0 Idle 0x14acdb4b8
Receive Manager global block 0x1429fb028
cdrRM_inst_ct: 2
cdrRM_State: 00000040
cdrRM_numSleepers: 12
cdrRM_DsCreated: 12
cdrRM_MinDSThreads: 12
cdrRM_MaxDSThreads: 48
cdrRM_DSBlock 0
cdrRM_DSParallelPL 0
cdrRM_DSFailRate 0.000000
cdrRM_DSNumRun: 975682
cdrRM_DSNumLockTimeout 0
cdrRM_DSNumLockRB 123
cdrRM_DSNumDeadLocks 184
cdrRM_DSNumPCommits 22284
cdrRM_ACKwaiting 0
cdrRM_totSleep: 398
cdrRM_Sleeptime: 64965
cdrRM_Workload: 0
cdrRM_optscale: 4
cdrRM_MinFloatThreads: 2
cdrRM_MaxFloatThreads: 7
cdrRM_AckThreadCount: 6
cdrRM_AckWaiters: 6
cdrRM_AckCreateStamp: Wed Oct 2 00:38:19 2013
cdrRM_DSCreateStamp: Wed Oct 2 18:18:10 2013
cdrRM_acksInList: 0
cdrRM_BlobErrorBufs: 0
Receive Parallelism Statistics
Server Tot.Txn. Pending Active MaxPnd MaxAct AvgPnd AvgAct CommitRt
22 473537 0 0 3806 15 34.59 1.45 5.26
23 502145 0 0 2927 17 12.86 1.37 5.58
Tot Pending:0 Tot Active:0 Avg Pending:23.41 Avg Active:1.41
Commit Rate:10.84
Time Spent In RM Parallel Pipeline Levels
Lev. TimeInSec Pcnt.
0 89800 100.00%
1 0 0.00%
2 0 0.00%
[fqu@maggie bin]$ onstat -g ath
IBM Informix Dynamic Server Version 11.70.FC7 -- On-Line -- Up 5 days
01:17:36 -- 8359540 Kbytes
Threads:tid tcb rstcb prty status
vp-class
name
2 1412741d8 0 1 IO Idle
3lio* lio vp 0
3 1412962e0 0 1 IO Idle
4pio* pio vp 0
4 1412b72e0 0 1 IO Idle
5aio* aio vp 0
5 1412d82e0 1bc2320 1 IO Idle
6msc* msc vp 0
6 1413092e0 0 1 IO Idle
7fifo* fifo vp 0
7 14137f808 0 1 IO Idle
20aio* aio vp 1
8 1413a02e0 0 1 IO Idle
21aio* aio vp 2
9 1413c12e0 0 1 IO Idle
22aio* aio vp 3
10 1413f7580 13f5ad028 3 sleeping secs: 1
17cpu main_loop()
11 1413e2c48 0 1 running
26soc* soctcppoll
12 1413e9ba0 0 1 running
27soc* soctcppoll
13 14132b4d8 0 1 running
28soc* soctcppoll
14 14132bca8 0 1 running
29soc* soctcppoll
15 141332778 0 1 running
1cpu* sm_poll
16 1414e14c0 0 2 sleeping forever
1cpu* soctcplst
17 141514028 0 2 sleeping forever
10cpu sm_listen
18 141549d00 0 1 sleeping secs: 1
17cpu sm_discon
19 141563178 0 2 sleeping forever
9cpu* soctcplst
20 141576a78 0 2 sleeping forever
10cpu* soctcplst
21 1415906a0 13f5ad870 1 sleeping secs: 1
17cpu flush_sub(0)
22 1415909d8 13f5ae0b8 1 sleeping secs: 1
19cpu flush_sub(1)
23 141590d10 13f5ae900 1 sleeping secs: 1
19cpu flush_sub(2)
24 1415ca0e0 13f5af148 1 sleeping secs: 1
19cpu flush_sub(3)
25 1415ca418 13f5af990 1 sleeping secs: 1
19cpu flush_sub(4)
26 1415ca750 13f5b01d8 1 sleeping secs: 1
18cpu flush_sub(5)
27 1415caa88 13f5b0a20 1 sleeping secs: 1
19cpu flush_sub(6)
28 141658028 13f5b1268 1 sleeping secs: 1
17cpu flush_sub(7)
29 141658360 13f5b1ab0 1 sleeping secs: 1
17cpu flush_sub(8)
30 141658698 13f5b22f8 1 sleeping secs: 1
19cpu flush_sub(9)
31 1416589d0 13f5b2b40 1 sleeping secs: 1
17cpu flush_sub(10)
32 141658d08 13f5b3388 1 sleeping secs: 1
14cpu flush_sub(11)
33 1416f8028 13f5b3bd0 1 sleeping secs: 1
18cpu flush_sub(12)
34 1416f8360 13f5b4418 1 sleeping secs: 1
10cpu flush_sub(13)
35 1416f8698 13f5b4c60 1 sleeping secs: 1
16cpu flush_sub(14)
36 1416f89d0 13f5b54a8 1 sleeping secs: 1
17cpu flush_sub(15)
37 1416f8d58 0 3 IO Idle
1cpu* kaio
38 141811220 0 3 IO Idle
9cpu* kaio
39 141811558 0 3 IO Idle
16cpu* kaio
40 14184f658 13f5b5cf0 2 sleeping secs: 1
14cpu aslogflush
41 1418f9568 13f5b6538 1 sleeping secs: 7
10cpu btscanner_0
42 1419166b8 13f5b6d80 3 cond wait ReadAhead
1cpu readahead_0
72 141f1a360 0 3 IO Idle
18cpu* kaio
74 141f1ad50 13f5b7e10 3 sleeping secs: 1
1cpu* onmode_mon
75 1419336c8 13f5b8ea0 3 sleeping secs: 1
17cpu periodic
82 141c96188 0 3 IO Idle
10cpu* kaio
83 141e688e0 0 3 IO Idle
14cpu* kaio
84 141e68b60 0 3 IO Idle
15cpu* kaio
85 141def028 0 3 IO Idle
11cpu* kaio
86 141def2a8 0 3 IO Idle
19cpu* kaio
87 141def578 0 3 IO Idle
13cpu* kaio
88 141def900 0 3 IO Idle
17cpu* kaio
89 141defc88 0 3 IO Idle
12cpu* kaio
92 141c9a610 13f5ba778 1 sleeping secs: 56
9cpu dbScheduler
93 141ded568 13f5b9f30 1 sleeping forever
11cpu dbWorker1
94 141ceb958 13f5b96e8 1 sleeping forever
11cpu dbWorker2
129 1425704b0 13f5c7680 1 cond wait bp_cond
16cpu bf_priosweep()
1875 1431bccf8 13f5d0b90 1 cond wait netnorm
9cpu sqlexec
1876 143589290 13f5c8f58 1 cond wait netnorm
1cpu sqlexec
1879 1436c69a8 13f5ce228 1 cond wait netnorm
1cpu sqlexec
1880 1437a81e8 13f5c97a0 1 cond wait netnorm
9cpu sqlexec
1883 143840398 13f5cf2b8 1 cond wait netnorm
10cpu sqlexec
1884 143816af0 13f5d2468 1 cond wait netnorm
1cpu sqlexec
1885 1437ff968 13f5d2cb0 1 cond wait netnorm
9cpu sqlexec
1886 14387c148 13f5d34f8 1 cond wait netnorm
9cpu sqlexec
1889 14321c4d8 13f5d4dd0 1 cond wait netnorm
9cpu sqlexec
1890 141cfec28 13f5d5618 1 cond wait netnorm
19cpu sqlexec
1891 142fd1028 13f5d5e60 1 cond wait netnorm
1cpu sqlexec
1892 143a40418 13f5d66a8 1 cond wait netnorm
19cpu sqlexec
1895 143b0d450 13f5d13d8 1 cond wait netnorm
9cpu sqlexec
1901 143c8b028 13f5da8e8 1 cond wait netnorm
9cpu sqlexec
1905 143b13bb0 13f5db978 1 cond wait netnorm
19cpu sqlexec
1915 143c1aa58 13f5dda98 1 cond wait netnorm
10cpu sqlexec
1916 143e95028 13f5de2e0 1 cond wait netnorm
9cpu sqlexec
4584083 1467d1028 14826f250 1 cond wait netnorm
10cpu sqlexec
5824374 14519b4b0 148267e60 1 cond wait netnorm
9cpu sqlexec
6106863 154046d20 148251200 1 cond wait netnorm
9cpu sqlexec
6138651 14a262be8 14461fb50 1 cond wait netnorm
1cpu sqlexec
6178376 154906c68 1445f8e38 1 cond wait netnorm
1cpu sqlexec@@NL@
get onstat -g stk on each of the servers. We want to focus on the data=
sync
(CDRD).
M.P.
=
From: "FRANK" <yunyaoqu@gmail.com> =
=
To: ids@iiug.org, =
=
Date: 10/02/2013 02:18 PM =
=
Subject: Re: ER queue data [31578] =
=
Sent by: ids-bounces@iiug.org =
=
Paul,
The following are the three outputs of the commands. Please Let me know=
if you see some clue.
The ER rejected transactions in ATS/RIS directory is fine to us( we
lived with this for years, we can do manual data sync late, no problem =
at
all).
As long as ER continue to process the new coming transactions,
we would be happy...
But it queues data , does not send data(or intolerably slow) to other
sites.....
Thanks,
Frank
[fqu@maggie bin]$ cdr list server
SERVER ID STATE STATUS QUEUE CONNECTION CHANGED
-----------------------------------------------------------------------=
g_ncdcops 22 Active Connected 24142400034 Oct 1 19:04:27
g_ngdcops 23 Active Connected 6495057993 Oct 1 19:07:17
g_nsofops 21 Active Local 0
[fqu@maggie bin]$ onstat -g rcv
IBM Informix Dynamic Server Version 11.70.FC7 -- On-Line -- Up 5 days
01:16:54 -- 8359540 KbytesServerId: 23
Flags 0x0
ServerId: 22
Flags 0x0
Threads:
Id Name State Handle
6353620 CDRACK_5 Idle 0x143f98cc8
6280008 CDRACK_4 Idle 0x1436b44f8
6229955 CDRACK_3 Idle 0x148ce3028
6229671 CDRACK_2 Idle 0x144acd0d8
6228209 CDRACK_1 Idle 0x14acdb0d8
6228208 CDRACK_0 Idle 0x14acdb4b8
Receive Manager global block 0x1429fb028
cdrRM_inst_ct: 2
cdrRM_State: 00000040
cdrRM_numSleepers: 12
cdrRM_DsCreated: 12
cdrRM_MinDSThreads: 12
cdrRM_MaxDSThreads: 48
cdrRM_DSBlock 0
cdrRM_DSParallelPL 0
cdrRM_DSFailRate 0.000000
cdrRM_DSNumRun: 975682
cdrRM_DSNumLockTimeout 0
cdrRM_DSNumLockRB 123
cdrRM_DSNumDeadLocks 184
cdrRM_DSNumPCommits 22284
cdrRM_ACKwaiting 0
cdrRM_totSleep: 398
cdrRM_Sleeptime: 64965
cdrRM_Workload: 0
cdrRM_optscale: 4
cdrRM_MinFloatThreads: 2
cdrRM_MaxFloatThreads: 7
cdrRM_AckThreadCount: 6
cdrRM_AckWaiters: 6
cdrRM_AckCreateStamp: Wed Oct 2 00:38:19 2013
cdrRM_DSCreateStamp: Wed Oct 2 18:18:10 2013
cdrRM_acksInList: 0
cdrRM_BlobErrorBufs: 0
Receive Parallelism Statistics
Server Tot.Txn. Pending Active MaxPnd MaxAct AvgPnd AvgAct CommitRt
22 473537 0 0 3806 15 34.59 1.45 5.26
23 502145 0 0 2927 17 12.86 1.37 5.58
Tot Pending:0 Tot Active:0 Avg Pending:23.41 Avg Active:1.41
Commit Rate:10.84
Time Spent In RM Parallel Pipeline Levels
Lev. TimeInSec Pcnt.
0 89800 100.00%
1 0 0.00%
2 0 0.00%
[fqu@maggie bin]$ onstat -g ath
IBM Informix Dynamic Server Version 11.70.FC7 -- On-Line -- Up 5 days
01:17:36 -- 8359540 Kbytes
Threads:tid tcb rstcb prty status
vp-class
name
2 1412741d8 0 1 IO Idle
3lio* lio vp 0
3 1412962e0 0 1 IO Idle
4pio* pio vp 0
4 1412b72e0 0 1 IO Idle
5aio* aio vp 0
5 1412d82e0 1bc2320 1 IO Idle
6msc* msc vp 0
6 1413092e0 0 1 IO Idle
7fifo* fifo vp 0
7 14137f808 0 1 IO Idle
20aio* aio vp 1
8 1413a02e0 0 1 IO Idle
21aio* aio vp 2
9 1413c12e0 0 1 IO Idle
22aio* aio vp 3
10 1413f7580 13f5ad028 3 sleeping secs: 1
17cpu main_loop()
11 1413e2c48 0 1 running
26soc* soctcppoll
12 1413e9ba0 0 1 running
27soc* soctcppoll
13 14132b4d8 0 1 running
28soc* soctcppoll
14 14132bca8 0 1 running
29soc* soctcppoll
15 141332778 0 1 running
1cpu* sm_poll
16 1414e14c0 0 2 sleeping forever
1cpu* soctcplst
17 141514028 0 2 sleeping forever
10cpu sm_listen
18 141549d00 0 1 sleeping secs: 1
17cpu sm_discon
19 141563178 0 2 sleeping forever
9cpu* soctcplst
20 141576a78 0 2 sleeping forever
10cpu* soctcplst
21 1415906a0 13f5ad870 1 sleeping secs: 1
17cpu flush_sub(0)
22 1415909d8 13f5ae0b8 1 sleeping secs: 1
19cpu flush_sub(1)
23 141590d10 13f5ae900 1 sleeping secs: 1
19cpu flush_sub(2)
24 1415ca0e0 13f5af148 1 sleeping secs: 1
19cpu flush_sub(3)
25 1415ca418 13f5af990 1 sleeping secs: 1
19cpu flush_sub(4)
26 1415ca750 13f5b01d8 1 sleeping secs: 1
18cpu flush_sub(5)
27 1415caa88 13f5b0a20 1 sleeping secs: 1
19cpu flush_sub(6)
28 141658028 13f5b1268 1 sleeping secs: 1
17cpu flush_sub(7)
29 141658360 13f5b1ab0 1 sleeping secs: 1
17cpu flush_sub(8)
30 141658698 13f5b22f8 1 sleeping secs: 1
19cpu flush_sub(9)
31 1416589d0 13f5b2b40 1 sleeping secs: 1
17cpu flush_sub(10)
32 141658d08 13f5b3388 1 sleeping secs: 1
14cpu flush_sub(11)
33 1416f8028 13f5b3bd0 1 sleeping secs: 1
18cpu flush_sub(12)
34 1416f8360 13f5b4418 1 sleeping secs: 1
10cpu flush_sub(13)
35 1416f8698 13f5b4c60 1 sleeping secs: 1
16cpu flush_sub(14)
36 1416f89d0 13f5b54a8 1 sleeping secs: 1
17cpu flush_sub(15)
37 1416f8d58 0 3 IO Idle
1cpu* kaio
38 141811220 0 3 IO Idle
9cpu* kaio
39 141811558 0 3 IO Idle
16cpu* kaio
40 14184f658 13f5b5cf0 2 sleeping secs: 1
14cpu aslogflush
41 1418f9568 13f5b6538 1 sleeping secs: 7
10cpu btscanner_0
42 1419166b8 13f5b6d80 3 cond wait ReadAhead
1cpu readahead_0
72 141f1a360 0 3 IO Idle
18cpu* kaio
74 141f1ad50 13f5b7e10 3 sleeping secs: 1
1cpu* onmode_mon
75 1419336c8 13f5b8ea0 3 sleeping secs: 1
17cpu periodic
82 141c96188 0 3 IO Idle
10cpu* kaio
83 141e688e0 0 3 IO Idle
14cpu* kaio
84 141e68b60 0 3 IO Idle
15cpu* kaio
85 141def028 0 3 IO Idle
11cpu* kaio
86 141def2a8 0 3 IO Idle
19cpu* kaio
87 141def578 0 3 IO Idle
13cpu* kaio
88 141def900 0 3 IO Idle
17cpu* kaio
89 141defc88 0 3 IO Idle
12cpu* kaio
92 141c9a610 13f5ba778 1 sleeping secs: 56
9cpu dbScheduler
93 141ded568 13f5b9f30 1 sleeping forever
11cpu dbWorker1
94 141ceb958 13f5b96e8 1 sleeping forever
11cpu dbWorker2
129 1425704b0 13f5c7680 1 cond wait bp_cond
16cpu bf_priosweep()
1875 1431bccf8 13f5d0b90 1 cond wait netnorm
9cpu sqlexec
1876 143589290 13f5c8f58 1 cond wait netnorm
1cpu sqlexec
1879 1436c69a8 13f5ce228 1 cond wait netnorm
1cpu sqlexec
1880 1437a81e8 13f5c97a0 1 cond wait netnorm
9cpu sqlexec
1883 143840398 13f5cf2b8 1 cond wait netnorm
10cpu sqlexec
1884 143816af0 13f5d2468 1 cond wait netnorm
1cpu sqlexec
1885 1437ff968 13f5d2cb0 1 cond wait netnorm
9cpu sqlexec
1886 14387c148 13f5d34f8 1 cond wait netnorm
9cpu sqlexec
1889 14321c4d8 13f5d4dd0 1 cond wait netnorm
9cpu sqlexec
1890 141cfec28 13f5d5618 1 cond wait netnorm
19cpu sqlexec
1891 142fd1028 13f5d5e60 1 cond wait netnorm
1cpu sqlexec
1892 143a40418 13f5d66a8 1 cond wait netnorm
19cpu sqlexec
1895 143b0d450 13f5d13d8 1 cond wait netnorm
9cpu sqlexec
1901 143c8b028 13f5da8e8 1 cond wait netnorm
9cpu sqlexec
1905 143b13bb0 13f5db978 1 cond wait netnorm
19cpu sqlexec
1915 143c1aa58 13f5dda98 1 cond wait netnorm
10