Problem with SDS server disconnecting - Informix 1

I am having a problem where my SDS server is disconnecting from the primary after being connected for a while. I just upgraded a client to Informix 11.50FC3 from Informix 10.00FC5 in production today and I am receiving the following issues with the SDS server. I had to shut down the SDS instance until I can find out what is causing the problem. Has anyone seen this behavior? Environment: HP-UX 11.23 Informix 11.50FC3 KAIO - On Here are the messages from the online.log file for both Primary and SDS server. SDS Server 05:52:06 Finished processing open transactions on secondary during startup. 05:52:06 HPUX KAIO Segment locked addr=0x23e7c000 size=274243584 05:52:06 HPUX KAIO Segment locked addr=0xd4920000 size=3072000000 05:54:12 listener-thread: err = -27001: oserr = 0: errstr = : Read error occurred during connection attempt. 05:56:00 HPUX KAIO Segment locked addr=0x23e7c000 size=274243584 05:56:00 HPUX KAIO Segment locked addr=0xd4920000 size=3072000000 05:56:00 HPUX KAIO Segment locked addr=0x23e7c000 size=274243584 05:56:00 HPUX KAIO Segment locked addr=0xd4920000 size=3072000000 05:56:00 HPUX KAIO Segment locked addr=0x23e7c000 size=274243584 05:56:00 HPUX KAIO Segment locked addr=0xd4920000 size=3072000000 05:57:04 Booting Language <spl> from module <> 05:57:04 Loading Module <SPLNULL> 06:26:04 Logical Log 2204697 Complete, timestamp: 0x557c067c. 06:45:13 Logical Log 2204698 Complete, timestamp: 0x5580fd98. 07:26:57 Logical Log 2204699 Complete, timestamp: 0x560ac5e1. 08:17:45 SDS: Lost connection to tuc_tcp_pri 08:17:49 SDS: Reconnected to tuc_tcp_pri 08:17:49 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Primary Server Restarted 08:17:49 DR:Shutting down the server. 08:17:50 IBM Informix Dynamic Server Stopped. 08:48:05 B-tree scanners disabled. 08:48:06 DR: SDS secondary server operational 08:48:06 Started processing open transactions on secondary during startup 08:48:06 Finished processing open transactions on secondary during startup. 08:48:06 Checkpoint Completed: duration was 0 seconds. 08:48:06 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x5721171f Interval: 169 08:48:06 Maximum server connections 0 08:48:06 HPUX KAIO Segment locked addr=0x23e8c000 size=3072000000 08:48:06 HPUX KAIO Segment locked addr=0xd4920000 size=274243584 08:48:07 HPUX KAIO Segment locked addr=0x23e8c000 size=3072000000 08:48:07 HPUX KAIO Segment locked addr=0xd4920000 size=274243584 08:53:48 HPUX KAIO Segment locked addr=0x23e8c000 size=3072000000 08:53:48 HPUX KAIO Segment locked addr=0xd4920000 size=274243584 09:03:46 Booting Language <spl> from module <> 09:03:46 Loading Module <SPLNULL> 09:17:41 listener-thread: err = -408: oserr = 0: errstr = : Invalid message type received from the sqlexec process. 09:20:06 SDS: Lost connection to tuc_tcp_pri 09:20:06 SDS: Reconnected to tuc_tcp_pri 09:20:06 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Primary Server Restarted 09:20:06 DR:Shutting down the server. 09:20:07 IBM Informix Dynamic Server Stopped. 09:41:10 HPUX KAIO Segment locked addr=0xd4920000 size=274243584 09:41:10 Checkpoint Completed: duration was 1 seconds. 09:41:10 Sun Feb 15 - loguniq 2204702, logpos 0x209d018, timestamp: 0x57f49d59 Interval: 171 09:41:10 Maximum server connections 0 09:41:10 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 26, Llog used 1 09:41:10 On-Line Mode 09:41:11 SCHAPI: Started dbScheduler thread. 09:41:12 Booting Language <spl> from module <> 09:41:12 Loading Module <SPLNULL> 09:41:12 SCHAPI: Started 2 dbWorker threads. Here is the log file on the primary: PRIMARY 06:29:25 Logical Log 2204697 Complete, timestamp: 0x557a8640. 06:29:29 Logical Log 2204697 - Backup Started 06:29:31 Logical Log 2204697 - Backup Completed 06:48:34 Logical Log 2204698 - Backup Started 06:48:34 Logical Log 2204698 Complete, timestamp: 0x55802904. 06:48:36 Logical Log 2204698 - Backup Completed 07:30:17 Logical Log 2204699 Complete, timestamp: 0x560ac82d. 07:30:20 Logical Log 2204699 - Backup Started 07:30:22 Logical Log 2204699 - Backup Completed 08:21:04 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:21:05 ERROR: Removing SDS Node informex has timed out - removing 08:21:05 SDS Server tuc_tcp - state is now disconnected 08:21:09 SDS: Reconnect from tuc_tcp rejected - server not known or needs to be restarted. 08:21:11 Encountered problem processing update on secondary : Cannot send sync 08:21:11 Encountered problem processing update on secondary : Cannot send sync 08:28:29 Logical Log 2204700 Complete, timestamp: 0x56f2bc56. 08:28:32 Logical Log 2204700 - Backup Started 08:28:32 Logical Log 2204700 - Backup Completed 08:34:48 Checkpoint Completed: duration was 1 seconds. 08:34:48 Sun Feb 15 - loguniq 2204701, logpos 0xf69018, timestamp: 0x56ffcf22 Interval: 168 08:34:48 Maximum server connections 34 08:34:48 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 786533, Llog used 188440 08:35:33 SDS Server tuc_tcp - state is now connected 08:43:08 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:43:09 ERROR: Removing SDS Node informex has timed out - removing 08:43:09 SDS Server tuc_tcp - state is now disconnected 08:43:10 SDS: Reconnect from tuc_tcp rejected - server not known or needs to be restarted. 08:50:34 Checkpoint Completed: duration was 0 seconds. 08:50:34 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x57210fb6 Interval: 169 08:50:34 Maximum server connections 34 08:50:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 7018, Llog used 5761 08:51:13 SDS Server tuc_tcp - state is now connected 09:23:26 ERROR: Removing SDS Node tuc_tcp has timed out - removing 09:23:26 ERROR: Removing SDS Node informex has timed out - removing 09:23:26 SDS Server tuc_tcp - state is now disconnected 09:23:26 SDS: Reconnect from tuc_tcp rejected - server not known or needs to be restarted. Thanks, Jeff

What is SDS_TIMEOUT set to? ------------------------------------- Madison Pruet, STSM IDS Replication Architect = "Jeff Filippi" = <iiug@itdataconsu = lting.com> = To Sent by: ids@iiug.org = ids-bounces@iiug. = cc org = Subj= ect Problem with SDS server = 02/15/2009 11:54 disconnecting - Inform.... [148= 85] AM = = = Please respond to = ids@iiug.org = = = I am having a problem where my SDS server is disconnecting from the pri= mary after being connected for a while. I just upgraded a client to Informix= 11.50FC3 from Informix 10.00FC5 in production today and I am receiving = the following issues with the SDS server. I had to shut down the SDS instance until I can find out what is causin= g the problem. Has anyone seen this behavior? Environment: HP-UX 11.23 Informix 11.50FC3 KAIO - On Here are the messages from the online.log file for both Primary and SDS= server. SDS Server 05:52:06 Finished processing open transactions on secondary during star= tup. 05:52:06 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:52:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:54:12 listener-thread: err =3D -27001: oserr =3D 0: errstr =3D : Rea= d error occurred during connection attempt. 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:57:04 Booting Language <spl> from module <> 05:57:04 Loading Module <SPLNULL> 06:26:04 Logical Log 2204697 Complete, timestamp: 0x557c067c. 06:45:13 Logical Log 2204698 Complete, timestamp: 0x5580fd98. 07:26:57 Logical Log 2204699 Complete, timestamp: 0x560ac5e1. 08:17:45 SDS: Lost connection to tuc_tcp_pri 08:17:49 SDS: Reconnected to tuc_tcp_pri 08:17:49 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 08:17:49 DR:Shutting down the server. 08:17:50 IBM Informix Dynamic Server Stopped. 08:48:05 B-tree scanners disabled. 08:48:06 DR: SDS secondary server operational 08:48:06 Started processing open transactions on secondary during start= up 08:48:06 Finished processing open transactions on secondary during star= tup. 08:48:06 Checkpoint Completed: duration was 0 seconds. 08:48:06 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x5721171f Interval: 169 08:48:06 Maximum server connections 0 08:48:06 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:48:07 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:07 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:53:48 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:53:48 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:03:46 Booting Language <spl> from module <> 09:03:46 Loading Module <SPLNULL> 09:17:41 listener-thread: err =3D -408: oserr =3D 0: errstr =3D : Inval= id message type received from the sqlexec process. 09:20:06 SDS: Lost connection to tuc_tcp_pri 09:20:06 SDS: Reconnected to tuc_tcp_pri 09:20:06 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 09:20:06 DR:Shutting down the server. 09:20:07 IBM Informix Dynamic Server Stopped. 09:41:10 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:41:10 Checkpoint Completed: duration was 1 seconds. 09:41:10 Sun Feb 15 - loguniq 2204702, logpos 0x209d018, timestamp: 0x57f49d59 Interval: 171 09:41:10 Maximum server connections 0 09:41:10 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 26, Llog used 1 09:41:10 On-Line Mode 09:41:11 SCHAPI: Started dbScheduler thread. 09:41:12 Booting Language <spl> from module <> 09:41:12 Loading Module <SPLNULL> 09:41:12 SCHAPI: Started 2 dbWorker threads. Here is the log file on the primary: PRIMARY 06:29:25 Logical Log 2204697 Complete, timestamp: 0x557a8640. 06:29:29 Logical Log 2204697 - Backup Started 06:29:31 Logical Log 2204697 - Backup Completed 06:48:34 Logical Log 2204698 - Backup Started 06:48:34 Logical Log 2204698 Complete, timestamp: 0x55802904. 06:48:36 Logical Log 2204698 - Backup Completed 07:30:17 Logical Log 2204699 Complete, timestamp: 0x560ac82d. 07:30:20 Logical Log 2204699 - Backup Started 07:30:22 Logical Log 2204699 - Backup Completed 08:21:04 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:21:05 ERROR: Removing SDS Node informex has timed out - removing 08:21:05 SDS Server tuc_tcp - state is now disconnected 08:21:09 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:28:29 Logical Log 2204700 Complete, timestamp: 0x56f2bc56. 08:28:32 Logical Log 2204700 - Backup Started 08:28:32 Logical Log 2204700 - Backup Completed 08:34:48 Checkpoint Completed: duration was 1 seconds. 08:34:48 Sun Feb 15 - loguniq 2204701, logpos 0xf69018, timestamp: 0x56ffcf22 Interval: 168 08:34:48 Maximum server connections 34 08:34:48 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 786533, Llog used 188440 08:35:33 SDS Server tuc_tcp - state is now connected 08:43:08 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:43:09 ERROR: Removing SDS Node informex has timed out - removing 08:43:09 SDS Server tuc_tcp - state is now disconnected 08:43:10 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:50:34 Checkpoint Completed: duration was 0 seconds. 08:50:34 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x57210fb6 Interval: 169 08:50:34 Maximum server connections 34 08:50:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 7018, Llog used 5761 08:51:13 SDS Server tuc_tcp - state is now connected 09:23:26 ERROR: Removing SDS Node tuc_tcp has timed out - removing 09:23:26 ERROR: Removing SDS Node informex has timed out - removing 09:23:26 SDS Server tuc_tcp - state is now disconnected 09:23:26 SDS: Reconnect from tuc_tcp rejected

SDS_TIMEOUT is set to 500 -----Original Message----- From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of Madison Pruet Sent: Sunday, February 15, 2009 12:18 PM To: ids@iiug.org Subject: Re: Problem with SDS server disconnecting - In.... [14886] What is SDS_TIMEOUT set to? ------------------------------------- Madison Pruet, STSM IDS Replication Architect = "Jeff Filippi" = <iiug@itdataconsu = lting.com> = To Sent by: ids@iiug.org = ids-bounces@iiug. = cc org = Subj= ect Problem with SDS server = 02/15/2009 11:54 disconnecting - Inform.... [148= 85] AM = = = Please respond to = ids@iiug.org = = = I am having a problem where my SDS server is disconnecting from the pri= mary after being connected for a while. I just upgraded a client to Informix= 11.50FC3 from Informix 10.00FC5 in production today and I am receiving = the following issues with the SDS server. I had to shut down the SDS instance until I can find out what is causin= g the problem. Has anyone seen this behavior? Environment: HP-UX 11.23 Informix 11.50FC3 KAIO - On Here are the messages from the online.log file for both Primary and SDS= server. SDS Server 05:52:06 Finished processing open transactions on secondary during star= tup. 05:52:06 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:52:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:54:12 listener-thread: err =3D -27001: oserr =3D 0: errstr =3D : Rea= d error occurred during connection attempt. 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:57:04 Booting Language <spl> from module <> 05:57:04 Loading Module <SPLNULL> 06:26:04 Logical Log 2204697 Complete, timestamp: 0x557c067c. 06:45:13 Logical Log 2204698 Complete, timestamp: 0x5580fd98. 07:26:57 Logical Log 2204699 Complete, timestamp: 0x560ac5e1. 08:17:45 SDS: Lost connection to tuc_tcp_pri 08:17:49 SDS: Reconnected to tuc_tcp_pri 08:17:49 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 08:17:49 DR:Shutting down the server. 08:17:50 IBM Informix Dynamic Server Stopped. 08:48:05 B-tree scanners disabled. 08:48:06 DR: SDS secondary server operational 08:48:06 Started processing open transactions on secondary during start= up 08:48:06 Finished processing open transactions on secondary during star= tup. 08:48:06 Checkpoint Completed: duration was 0 seconds. 08:48:06 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x5721171f Interval: 169 08:48:06 Maximum server connections 0 08:48:06 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:48:07 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:07 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:53:48 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:53:48 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:03:46 Booting Language <spl> from module <> 09:03:46 Loading Module <SPLNULL> 09:17:41 listener-thread: err =3D -408: oserr =3D 0: errstr =3D : Inval= id message type received from the sqlexec process. 09:20:06 SDS: Lost connection to tuc_tcp_pri 09:20:06 SDS: Reconnected to tuc_tcp_pri 09:20:06 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 09:20:06 DR:Shutting down the server. 09:20:07 IBM Informix Dynamic Server Stopped. 09:41:10 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:41:10 Checkpoint Completed: duration was 1 seconds. 09:41:10 Sun Feb 15 - loguniq 2204702, logpos 0x209d018, timestamp: 0x57f49d59 Interval: 171 09:41:10 Maximum server connections 0 09:41:10 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 26, Llog used 1 09:41:10 On-Line Mode 09:41:11 SCHAPI: Started dbScheduler thread. 09:41:12 Booting Language <spl> from module <> 09:41:12 Loading Module <SPLNULL> 09:41:12 SCHAPI: Started 2 dbWorker threads. Here is the log file on the primary: PRIMARY 06:29:25 Logical Log 2204697 Complete, timestamp: 0x557a8640. 06:29:29 Logical Log 2204697 - Backup Started 06:29:31 Logical Log 2204697 - Backup Completed 06:48:34 Logical Log 2204698 - Backup Started 06:48:34 Logical Log 2204698 Complete, timestamp: 0x55802904. 06:48:36 Logical Log 2204698 - Backup Completed 07:30:17 Logical Log 2204699 Complete, timestamp: 0x560ac82d. 07:30:20 Logical Log 2204699 - Backup Started 07:30:22 Logical Log 2204699 - Backup Completed 08:21:04 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:21:05 ERROR: Removing SDS Node informex has timed out - removing 08:21:05 SDS Server tuc_tcp - state is now disconnected 08:21:09 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:28:29 Logical Log 2204700 Complete, timestamp: 0x56f2bc56. 08:28:32 Logical Log 2204700 - Backup Started 08:28:32 Logical Log 2204700 - Backup Completed 08:34:48 Checkpoint Completed: duration was 1 seconds. 08:34:48 Sun Feb 15 - loguniq 2204701, logpos 0xf69018, timestamp: 0x56ffcf22 Interval: 168 08:34:48 Maximum server connections 34 08:34:48 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 786533, Llog used 188440 08:35:33 SDS Server tuc_tcp - state is now connected 08:43:08 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:43:09 ERROR: Removing SDS Node informex has timed out - removing 08:43:09 SDS Server tuc_tcp - state is now disconnected 08:43:10 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:50:34 Checkpoint Completed: duration was 0 seconds. 08:50:34 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x57210fb6 Interval: 169 08:50:34 Maximum server connections 34 08:50:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 7018, Llog used 5761 08:51:13 SDS Server tuc_

Also - what are the two machines? # processors, etc. ------------------------------------- Madison Pruet, STSM IDS Replication Architect = "Jeff Filippi" = <iiug@itdataconsu = lting.com> = To Sent by: ids@iiug.org = ids-bounces@iiug. = cc org = Subj= ect Problem with SDS server = 02/15/2009 11:54 disconnecting - Inform.... [148= 85] AM = = = Please respond to = ids@iiug.org = = = I am having a problem where my SDS server is disconnecting from the pri= mary after being connected for a while. I just upgraded a client to Informix= 11.50FC3 from Informix 10.00FC5 in production today and I am receiving = the following issues with the SDS server. I had to shut down the SDS instance until I can find out what is causin= g the problem. Has anyone seen this behavior? Environment: HP-UX 11.23 Informix 11.50FC3 KAIO - On Here are the messages from the online.log file for both Primary and SDS= server. SDS Server 05:52:06 Finished processing open transactions on secondary during star= tup. 05:52:06 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:52:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:54:12 listener-thread: err =3D -27001: oserr =3D 0: errstr =3D : Rea= d error occurred during connection attempt. 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:57:04 Booting Language <spl> from module <> 05:57:04 Loading Module <SPLNULL> 06:26:04 Logical Log 2204697 Complete, timestamp: 0x557c067c. 06:45:13 Logical Log 2204698 Complete, timestamp: 0x5580fd98. 07:26:57 Logical Log 2204699 Complete, timestamp: 0x560ac5e1. 08:17:45 SDS: Lost connection to tuc_tcp_pri 08:17:49 SDS: Reconnected to tuc_tcp_pri 08:17:49 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 08:17:49 DR:Shutting down the server. 08:17:50 IBM Informix Dynamic Server Stopped. 08:48:05 B-tree scanners disabled. 08:48:06 DR: SDS secondary server operational 08:48:06 Started processing open transactions on secondary during start= up 08:48:06 Finished processing open transactions on secondary during star= tup. 08:48:06 Checkpoint Completed: duration was 0 seconds. 08:48:06 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x5721171f Interval: 169 08:48:06 Maximum server connections 0 08:48:06 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:48:07 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:07 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:53:48 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:53:48 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:03:46 Booting Language <spl> from module <> 09:03:46 Loading Module <SPLNULL> 09:17:41 listener-thread: err =3D -408: oserr =3D 0: errstr =3D : Inval= id message type received from the sqlexec process. 09:20:06 SDS: Lost connection to tuc_tcp_pri 09:20:06 SDS: Reconnected to tuc_tcp_pri 09:20:06 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 09:20:06 DR:Shutting down the server. 09:20:07 IBM Informix Dynamic Server Stopped. 09:41:10 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:41:10 Checkpoint Completed: duration was 1 seconds. 09:41:10 Sun Feb 15 - loguniq 2204702, logpos 0x209d018, timestamp: 0x57f49d59 Interval: 171 09:41:10 Maximum server connections 0 09:41:10 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 26, Llog used 1 09:41:10 On-Line Mode 09:41:11 SCHAPI: Started dbScheduler thread. 09:41:12 Booting Language <spl> from module <> 09:41:12 Loading Module <SPLNULL> 09:41:12 SCHAPI: Started 2 dbWorker threads. Here is the log file on the primary: PRIMARY 06:29:25 Logical Log 2204697 Complete, timestamp: 0x557a8640. 06:29:29 Logical Log 2204697 - Backup Started 06:29:31 Logical Log 2204697 - Backup Completed 06:48:34 Logical Log 2204698 - Backup Started 06:48:34 Logical Log 2204698 Complete, timestamp: 0x55802904. 06:48:36 Logical Log 2204698 - Backup Completed 07:30:17 Logical Log 2204699 Complete, timestamp: 0x560ac82d. 07:30:20 Logical Log 2204699 - Backup Started 07:30:22 Logical Log 2204699 - Backup Completed 08:21:04 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:21:05 ERROR: Removing SDS Node informex has timed out - removing 08:21:05 SDS Server tuc_tcp - state is now disconnected 08:21:09 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:28:29 Logical Log 2204700 Complete, timestamp: 0x56f2bc56. 08:28:32 Logical Log 2204700 - Backup Started 08:28:32 Logical Log 2204700 - Backup Completed 08:34:48 Checkpoint Completed: duration was 1 seconds. 08:34:48 Sun Feb 15 - loguniq 2204701, logpos 0xf69018, timestamp: 0x56ffcf22 Interval: 168 08:34:48 Maximum server connections 34 08:34:48 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 786533, Llog used 188440 08:35:33 SDS Server tuc_tcp - state is now connected 08:43:08 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:43:09 ERROR: Removing SDS Node informex has timed out - removing 08:43:09 SDS Server tuc_tcp - state is now disconnected 08:43:10 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:50:34 Checkpoint Completed: duration was 0 seconds. 08:50:34 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x57210fb6 Interval: 169 08:50:34 Maximum server connections 34 08:50:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 7018, Llog used 5761 08:51:13 SDS Server tuc_tcp - state is now connected 09:23:26 ERROR: Removing SDS Node tuc_tcp has timed out - removing 09:23:26 ERROR: Removing SDS Node informex has timed out - removing 09:23:26 SDS Server tuc_tcp - state is now disconnected 09:23:26 SDS: Reconne

Primary 16 CPU's 32 gig memory CPUSVP's 15 7.6 gig of memory allocated to Informix SDS 16 CPU's 32 gig memory CPUVP's 11 (Another instance is also on this machine) UPDATABLE_SECONDARY 22 7.6 gig of memory allocated to Informix Thanks, Jeff -----Original Message----- From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of Madison Pruet Sent: Sunday, February 15, 2009 12:59 PM To: ids@iiug.org Subject: Re: Problem with SDS server disconnecting - In.... [14888] Also - what are the two machines? # processors, etc. ------------------------------------- Madison Pruet, STSM IDS Replication Architect = "Jeff Filippi" = <iiug@itdataconsu = lting.com> = To Sent by: ids@iiug.org = ids-bounces@iiug. = cc org = Subj= ect Problem with SDS server = 02/15/2009 11:54 disconnecting - Inform.... [148= 85] AM = = = Please respond to = ids@iiug.org = = = I am having a problem where my SDS server is disconnecting from the pri= mary after being connected for a while. I just upgraded a client to Informix= 11.50FC3 from Informix 10.00FC5 in production today and I am receiving = the following issues with the SDS server. I had to shut down the SDS instance until I can find out what is causin= g the problem. Has anyone seen this behavior? Environment: HP-UX 11.23 Informix 11.50FC3 KAIO - On Here are the messages from the online.log file for both Primary and SDS= server. SDS Server 05:52:06 Finished processing open transactions on secondary during star= tup. 05:52:06 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:52:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:54:12 listener-thread: err =3D -27001: oserr =3D 0: errstr =3D : Rea= d error occurred during connection attempt. 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:56:00 HPUX KAIO Segment locked addr=3D0x23e7c000 size=3D274243584 05:56:00 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D3072000000 05:57:04 Booting Language <spl> from module <> 05:57:04 Loading Module <SPLNULL> 06:26:04 Logical Log 2204697 Complete, timestamp: 0x557c067c. 06:45:13 Logical Log 2204698 Complete, timestamp: 0x5580fd98. 07:26:57 Logical Log 2204699 Complete, timestamp: 0x560ac5e1. 08:17:45 SDS: Lost connection to tuc_tcp_pri 08:17:49 SDS: Reconnected to tuc_tcp_pri 08:17:49 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 08:17:49 DR:Shutting down the server. 08:17:50 IBM Informix Dynamic Server Stopped. 08:48:05 B-tree scanners disabled. 08:48:06 DR: SDS secondary server operational 08:48:06 Started processing open transactions on secondary during start= up 08:48:06 Finished processing open transactions on secondary during star= tup. 08:48:06 Checkpoint Completed: duration was 0 seconds. 08:48:06 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x5721171f Interval: 169 08:48:06 Maximum server connections 0 08:48:06 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:06 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:48:07 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:48:07 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 08:53:48 HPUX KAIO Segment locked addr=3D0x23e8c000 size=3D3072000000 08:53:48 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:03:46 Booting Language <spl> from module <> 09:03:46 Loading Module <SPLNULL> 09:17:41 listener-thread: err =3D -408: oserr =3D 0: errstr =3D : Inval= id message type received from the sqlexec process. 09:20:06 SDS: Lost connection to tuc_tcp_pri 09:20:06 SDS: Reconnected to tuc_tcp_pri 09:20:06 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= ry Server Restarted 09:20:06 DR:Shutting down the server. 09:20:07 IBM Informix Dynamic Server Stopped. 09:41:10 HPUX KAIO Segment locked addr=3D0xd4920000 size=3D274243584 09:41:10 Checkpoint Completed: duration was 1 seconds. 09:41:10 Sun Feb 15 - loguniq 2204702, logpos 0x209d018, timestamp: 0x57f49d59 Interval: 171 09:41:10 Maximum server connections 0 09:41:10 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 26, Llog used 1 09:41:10 On-Line Mode 09:41:11 SCHAPI: Started dbScheduler thread. 09:41:12 Booting Language <spl> from module <> 09:41:12 Loading Module <SPLNULL> 09:41:12 SCHAPI: Started 2 dbWorker threads. Here is the log file on the primary: PRIMARY 06:29:25 Logical Log 2204697 Complete, timestamp: 0x557a8640. 06:29:29 Logical Log 2204697 - Backup Started 06:29:31 Logical Log 2204697 - Backup Completed 06:48:34 Logical Log 2204698 - Backup Started 06:48:34 Logical Log 2204698 Complete, timestamp: 0x55802904. 06:48:36 Logical Log 2204698 - Backup Completed 07:30:17 Logical Log 2204699 Complete, timestamp: 0x560ac82d. 07:30:20 Logical Log 2204699 - Backup Started 07:30:22 Logical Log 2204699 - Backup Completed 08:21:04 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:21:05 ERROR: Removing SDS Node informex has timed out - removing 08:21:05 SDS Server tuc_tcp - state is now disconnected 08:21:09 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:21:11 Encountered problem processing update on secondary : Cannot se= nd sync 08:28:29 Logical Log 2204700 Complete, timestamp: 0x56f2bc56. 08:28:32 Logical Log 2204700 - Backup Started 08:28:32 Logical Log 2204700 - Backup Completed 08:34:48 Checkpoint Completed: duration was 1 seconds. 08:34:48 Sun Feb 15 - loguniq 2204701, logpos 0xf69018, timestamp: 0x56ffcf22 Interval: 168 08:34:48 Maximum server connections 34 08:34:48 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= ked 0, Plog used 786533, Llog used 188440 08:35:33 SDS Server tuc_tcp - state is now connected 08:43:08 ERROR: Removing SDS Node tuc_tcp has timed out - removing 08:43:09 ERROR: Removing SDS Node informex has timed out - removing 08:43:09 SDS Server tuc_tcp - state is now disconnected 08:43:10 SDS: Reconnect from tuc_tcp rejected - server not known or nee= ds to be restarted. 08:50:34 Checkpoint Completed: duration was

You might want to run for a while with UPDATABLE_SECONDARY turned off -= to establish a base line. When you turn it back on, you might want to set it much lower - maybe j= ust 1 for starters, then gradually add more. There's no real advantage to having it greater than the number of CPUVPS. There condition indicates that the SDS node is not able to notify the primary that it has processed log records. When the primary is trying= to flush a buffer, either as part of a checkpoint, or as part of a foregro= und write and can't because the secondary has not processed the initial log= record which dirtied that page, then the primary will wait (and retry) = up to SDS_TIMEOUT for SDS node to process the log record. At that time, i= t will force a shutdown of the SDS node so that the page can be flushed t= o disk. I'm guessing that because of the number of threads that you are using f= or UPDATABLE_SECONDARY that the proxy network interface is gummed up thus blocking the SDS ACKS as well. ------------------------------------- Madison Pruet, STSM IDS Replication Architect = "Jeff Filippi" = <iiug@itdataconsu = lting.com> = To Sent by: ids@iiug.org = ids-bounces@iiug. = cc org = Subj= ect RE: Problem with SDS server = 02/15/2009 01:13 disconnecting - In.... [14889] = PM = = = Please respond to = ids@iiug.org = = = Primary 16 CPU's 32 gig memory CPUSVP's 15 7.6 gig of memory allocated to Informix SDS 16 CPU's 32 gig memory CPUVP's 11 (Another instance is also on this machine) UPDATABLE_SECONDARY 22 7.6 gig of memory allocated to Informix Thanks, Jeff -----Original Message----- From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of Madison Pruet Sent: Sunday, February 15, 2009 12:59 PM To: ids@iiug.org Subject: Re: Problem with SDS server disconnecting - In.... [14888] Also - what are the two machines? # processors, etc. ------------------------------------- Madison Pruet, STSM IDS Replication Architect =3D "Jeff Filippi" =3D <iiug@itdataconsu =3D lting.com> =3D To Sent by: ids@iiug.org =3D ids-bounces@iiug. =3D cc org =3D Subj=3D ect Problem with SDS server =3D 02/15/2009 11:54 disconnecting - Inform.... [148=3D 85] AM =3D =3D =3D Please respond to =3D ids@iiug.org =3D =3D =3D I am having a problem where my SDS server is disconnecting from the pri= =3D mary after being connected for a while. I just upgraded a client to Informix= =3D 11.50FC3 from Informix 10.00FC5 in production today and I am receiving = =3D the following issues with the SDS server. I had to shut down the SDS instance until I can find out what is causin= =3D g the problem. Has anyone seen this behavior? Environment: HP-UX 11.23 Informix 11.50FC3 KAIO - On Here are the messages from the online.log file for both Primary and SDS= =3D server. SDS Server 05:52:06 Finished processing open transactions on secondary during star= =3D tup. 05:52:06 HPUX KAIO Segment locked addr=3D3D0x23e7c000 size=3D3D27424358= 4 05:52:06 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D30720000= 00 05:54:12 listener-thread: err =3D3D -27001: oserr =3D3D 0: errstr =3D3D= : Rea=3D d error occurred during connection attempt. 05:56:00 HPUX KAIO Segment locked addr=3D3D0x23e7c000 size=3D3D27424358= 4 05:56:00 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D30720000= 00 05:56:00 HPUX KAIO Segment locked addr=3D3D0x23e7c000 size=3D3D27424358= 4 05:56:00 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D30720000= 00 05:56:00 HPUX KAIO Segment locked addr=3D3D0x23e7c000 size=3D3D27424358= 4 05:56:00 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D30720000= 00 05:57:04 Booting Language <spl> from module <> 05:57:04 Loading Module <SPLNULL> 06:26:04 Logical Log 2204697 Complete, timestamp: 0x557c067c. 06:45:13 Logical Log 2204698 Complete, timestamp: 0x5580fd98. 07:26:57 Logical Log 2204699 Complete, timestamp: 0x560ac5e1. 08:17:45 SDS: Lost connection to tuc_tcp_pri 08:17:49 SDS: Reconnected to tuc_tcp_pri 08:17:49 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= =3D ry Server Restarted 08:17:49 DR:Shutting down the server. 08:17:50 IBM Informix Dynamic Server Stopped. 08:48:05 B-tree scanners disabled. 08:48:06 DR: SDS secondary server operational 08:48:06 Started processing open transactions on secondary during start= =3D up 08:48:06 Finished processing open transactions on secondary during star= =3D tup. 08:48:06 Checkpoint Completed: duration was 0 seconds. 08:48:06 Sun Feb 15 - loguniq 2204701, logpos 0x25ea018, timestamp: 0x5721171f Interval: 169 08:48:06 Maximum server connections 0 08:48:06 HPUX KAIO Segment locked addr=3D3D0x23e8c000 size=3D3D30720000= 00 08:48:06 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D27424358= 4 08:48:07 HPUX KAIO Segment locked addr=3D3D0x23e8c000 size=3D3D30720000= 00 08:48:07 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D27424358= 4 08:53:48 HPUX KAIO Segment locked addr=3D3D0x23e8c000 size=3D3D30720000= 00 08:53:48 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D27424358= 4 09:03:46 Booting Language <spl> from module <> 09:03:46 Loading Module <SPLNULL> 09:17:41 listener-thread: err =3D3D -408: oserr =3D3D 0: errstr =3D3D := Inval=3D id message type received from the sqlexec process. 09:20:06 SDS: Lost connection to tuc_tcp_pri 09:20:06 SDS: Reconnected to tuc_tcp_pri 09:20:06 SDS: Received Shutdown request from tuc_tcp_pri, Reason: Prima= =3D ry Server Restarted 09:20:06 DR:Shutting down the server. 09:20:07 IBM Informix Dynamic Server Stopped. 09:41:10 HPUX KAIO Segment locked addr=3D3D0xd4920000 size=3D3D27424358= 4 09:41:10 Checkpoint Completed: duration was 1 seconds. 09:41:10 Sun Feb 15 - loguniq 2204702, logpos 0x209d018, timestamp: 0x57f49d59 Interval: 171 09:41:10 Maximum server connections 0 09:41:10 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns bloc= =3D ked 0, Plog used 26, Llog used 1 09:41:10 On-Line Mode 09:41:11 SCHAPI: Started dbScheduler thread. 09:41:12 Booting Language <spl> from module <> 09:41:12 Loading Module <SPLNULL> 09:41:12 SCHAPI: Started 2 dbWorker threads. Here is the log file on the primary: PRIMARY 06:29:25 Logical Log 2204697 Complete, timestamp: 0x557a8640. 06: