2017-01-23 15:46:23,458 INFO [startup] [AbstractCommandLauncher] [main] Option: name=max-idle-time, value={90000} 2017-01-23 15:46:23,459 INFO [startup] [AbstractCommandLauncher] [main] Option: name=no-log-console, value={} 2017-01-23 15:46:23,813 INFO [startup] [SymmetricWebServer] [main] About to start SymmetricDS web server on host:port default:31415 2017-01-23 15:46:24,637 INFO [startup] [/] [main] Initializing Spring root WebApplicationContext 2017-01-23 15:46:25,390 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] Initializing connection to database 2017-01-23 15:46:25,390 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Initializing connection to database 2017-01-23 15:46:27,384 INFO [serverprueba] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-0] Detected database 'MySQL', version '5', protocol 'mysql' 2017-01-23 15:46:27,446 INFO [serverprueba] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-0] The IDatabasePlatform being used is org.jumpmind.db.platform.mysql.MySqlDatabasePlatform 2017-01-23 15:46:27,453 INFO [serverdevelopment] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-1] Detected database 'MySQL', version '5', protocol 'mysql' 2017-01-23 15:46:27,457 INFO [serverdevelopment] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-1] The IDatabasePlatform being used is org.jumpmind.db.platform.mysql.MySqlDatabasePlatform 2017-01-23 15:46:27,857 INFO [serverprueba] [MySqlSymmetricDialect] [symmetric-engine-startup-0] The DbDialect being used is org.jumpmind.symmetric.db.mysql.MySqlSymmetricDialect 2017-01-23 15:46:27,860 INFO [serverdevelopment] [MySqlSymmetricDialect] [symmetric-engine-startup-1] The DbDialect being used is org.jumpmind.symmetric.db.mysql.MySqlSymmetricDialect 2017-01-23 15:46:28,251 INFO [serverprueba] [ExtensionService] [symmetric-engine-startup-0] Found 0 extension points from the database that will be registered 2017-01-23 15:46:28,283 INFO [serverprueba] [StagingManager] [symmetric-engine-startup-0] The staging directory was initialized at the following location: tmp/serverprueba 2017-01-23 15:46:28,292 INFO [serverdevelopment] [ExtensionService] [symmetric-engine-startup-1] Found 0 extension points from the database that will be registered 2017-01-23 15:46:28,296 INFO [serverdevelopment] [StagingManager] [symmetric-engine-startup-1] The staging directory was initialized at the following location: tmp/serverdevelopment 2017-01-23 15:46:28,461 INFO [serverprueba] [ClusterService] [symmetric-engine-startup-0] This node picked a server id of vps-1085769-x 2017-01-23 15:46:28,462 INFO [serverdevelopment] [ClusterService] [symmetric-engine-startup-1] This node picked a server id of vps-1085769-x 2017-01-23 15:46:30,875 INFO [serverprueba] [ExtensionService] [symmetric-engine-startup-0] Found 0 extension points from the database that will be registered 2017-01-23 15:46:30,875 INFO [serverprueba] [ClientExtensionService] [symmetric-engine-startup-0] Found 7 extension points from spring that will be registered 2017-01-23 15:46:30,880 INFO [serverdevelopment] [ExtensionService] [symmetric-engine-startup-1] Found 0 extension points from the database that will be registered 2017-01-23 15:46:30,881 INFO [serverdevelopment] [ClientExtensionService] [symmetric-engine-startup-1] Found 7 extension points from spring that will be registered 2017-01-23 15:46:30,904 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Initializing SymmetricDS database 2017-01-23 15:46:30,904 INFO [serverdevelopment] [MySqlSymmetricDialect] [symmetric-engine-startup-1] Checking if SymmetricDS tables need created or altered 2017-01-23 15:46:30,905 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] Initializing SymmetricDS database 2017-01-23 15:46:30,905 INFO [serverprueba] [MySqlSymmetricDialect] [symmetric-engine-startup-0] Checking if SymmetricDS tables need created or altered 2017-01-23 15:46:32,023 INFO [startup] [/] [main] Initializing Spring FrameworkServlet 'rest' 2017-01-23 15:46:33,373 INFO [startup] [SymmetricWebServer] [main] Starting JMX HTTP console on port 31416 2017-01-23 15:46:33,477 INFO [startup] [SymmetricWebServer] [main] Joining the web server main thread 2017-01-23 15:46:34,236 INFO [serverprueba] [MySqlSymmetricDialect] [symmetric-engine-startup-0] Installing SymmetricDS database object: create function sym_transaction_id_pre_5_7_6() returns varchar(50) NOT DETERMINISTIC READS SQL DATA begin declare comm_value varchar(50); declare comm_cur cursor for select VARIABLE_VALUE from INFORMATION_SCHEMA.SESSION_STATUS where VARIABLE_NAME='COM_COMMIT'; open comm_cur; fetch comm_cur into comm_value; close comm_cur; return concat(concat(connection_id(), '.'), comm_value); end 2017-01-23 15:46:34,239 INFO [serverdevelopment] [MySqlSymmetricDialect] [symmetric-engine-startup-1] Installing SymmetricDS database object: create function sym_transaction_id_pre_5_7_6() returns varchar(50) NOT DETERMINISTIC READS SQL DATA begin declare comm_value varchar(50); declare comm_cur cursor for select VARIABLE_VALUE from INFORMATION_SCHEMA.SESSION_STATUS where VARIABLE_NAME='COM_COMMIT'; open comm_cur; fetch comm_cur into comm_value; close comm_cur; return concat(concat(connection_id(), '.'), comm_value); end 2017-01-23 15:46:34,270 INFO [serverdevelopment] [MySqlSymmetricDialect] [symmetric-engine-startup-1] Just installed sym_transaction_id_pre_5_7_6 2017-01-23 15:46:34,271 INFO [serverprueba] [MySqlSymmetricDialect] [symmetric-engine-startup-0] Just installed sym_transaction_id_pre_5_7_6 2017-01-23 15:46:34,317 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] Done initializing SymmetricDS database 2017-01-23 15:46:34,317 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] SymmetricDS database version : 3.8.11 2017-01-23 15:46:34,317 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] SymmetricDS software version : 3.8.14 2017-01-23 15:46:34,317 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] SymmetricDS database version does not match the current software version, running software upgrade listeners. 2017-01-23 15:46:34,322 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Done initializing SymmetricDS database 2017-01-23 15:46:34,322 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS database version : 3.8.11 2017-01-23 15:46:34,322 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS software version : 3.8.14 2017-01-23 15:46:34,322 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS database version does not match the current software version, running software upgrade listeners. 2017-01-23 15:46:34,335 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] Starting registered node [group=s-serverprueba, id=000, externalId=000] 2017-01-23 15:46:34,337 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Starting registered node [group=s-serverdevelopment, id=000, externalId=000] 2017-01-23 15:46:34,342 INFO [serverdevelopment] [TriggerRouterService] [symmetric-engine-startup-1] Synchronizing triggers 2017-01-23 15:46:34,343 INFO [serverprueba] [TriggerRouterService] [symmetric-engine-startup-0] Synchronizing triggers 2017-01-23 15:46:45,604 INFO [serverprueba] [TriggerRouterService] [symmetric-engine-startup-0] Done synchronizing triggers 2017-01-23 15:46:45,605 INFO [serverprueba] [RouterJob] [symmetric-engine-startup-0] Starting job.routing on periodic schedule: every 500ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,614 INFO [serverprueba] [PushJob] [symmetric-engine-startup-0] Starting job.push on periodic schedule: every 2000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,621 INFO [serverprueba] [PullJob] [symmetric-engine-startup-0] Starting job.pull on periodic schedule: every 2000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,634 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.offline.push not configured for auto start 2017-01-23 15:46:45,634 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.offline.pull not configured for auto start 2017-01-23 15:46:45,634 INFO [serverprueba] [OutgoingPurgeJob] [symmetric-engine-startup-0] Starting job.purge.outgoing with cron expression: 0 0 0 * * * 2017-01-23 15:46:45,639 INFO [serverprueba] [IncomingPurgeJob] [symmetric-engine-startup-0] Starting job.purge.incoming with cron expression: 0 0 0 * * * 2017-01-23 15:46:45,642 INFO [serverprueba] [StatisticFlushJob] [symmetric-engine-startup-0] Starting job.stat.flush with cron expression: 0 0/5 * * * * 2017-01-23 15:46:45,658 INFO [serverprueba] [SyncTriggersJob] [symmetric-engine-startup-0] Starting job.synctriggers with cron expression: 0 0 0 * * * 2017-01-23 15:46:45,672 INFO [serverprueba] [HeartbeatJob] [symmetric-engine-startup-0] Starting job.heartbeat on periodic schedule: every 900000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,672 INFO [serverprueba] [WatchdogJob] [symmetric-engine-startup-0] Starting job.watchdog on periodic schedule: every 3600000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,672 INFO [serverprueba] [StageManagementJob] [symmetric-engine-startup-0] Starting job.stage.management with cron expression: 0 0 * * * * 2017-01-23 15:46:45,676 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.refresh.cache not configured for auto start 2017-01-23 15:46:45,676 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.file.sync.tracker not configured for auto start 2017-01-23 15:46:45,676 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.file.sync.pull not configured for auto start 2017-01-23 15:46:45,676 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.file.sync.push not configured for auto start 2017-01-23 15:46:45,676 INFO [serverprueba] [InitialLoadExtractorJob] [symmetric-engine-startup-0] Starting job.initial.load.extract on periodic schedule: every 10000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,677 INFO [serverprueba] [MonitorJob] [symmetric-engine-startup-0] Starting job.monitor on periodic schedule: every 60000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,684 INFO [serverdevelopment] [TriggerRouterService] [symmetric-engine-startup-1] Done synchronizing triggers 2017-01-23 15:46:45,684 INFO [serverprueba] [JobManager] [symmetric-engine-startup-0] Job job.report.status not configured for auto start 2017-01-23 15:46:45,684 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] Started SymmetricDS 2017-01-23 15:46:45,687 INFO [serverprueba] [AbstractSymmetricEngine] [symmetric-engine-startup-0] SymmetricDS: type=server, name=serverprueba, version=3.8.14, groupId=s-serverprueba, externalId=000, databaseName=MySQL, databaseVersion=5.5, driverName=MySQL Connector Java, driverVersion=mysql-connector-java-5.1.30 ( Revision: alexander.soklakov@oracle.com-20140310090514-8xt1yoht5ksg2e7c ) 2017-01-23 15:46:45,684 INFO [serverdevelopment] [RouterJob] [symmetric-engine-startup-1] Starting job.routing on periodic schedule: every 500ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,687 INFO [serverdevelopment] [PushJob] [symmetric-engine-startup-1] Starting job.push on periodic schedule: every 2000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,689 INFO [serverdevelopment] [PullJob] [symmetric-engine-startup-1] Starting job.pull on periodic schedule: every 2000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,700 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.offline.push not configured for auto start 2017-01-23 15:46:45,702 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.offline.pull not configured for auto start 2017-01-23 15:46:45,702 INFO [serverdevelopment] [OutgoingPurgeJob] [symmetric-engine-startup-1] Starting job.purge.outgoing with cron expression: 0 0 0 * * * 2017-01-23 15:46:45,702 INFO [serverdevelopment] [IncomingPurgeJob] [symmetric-engine-startup-1] Starting job.purge.incoming with cron expression: 0 0 0 * * * 2017-01-23 15:46:45,703 INFO [serverdevelopment] [StatisticFlushJob] [symmetric-engine-startup-1] Starting job.stat.flush with cron expression: 0 0/5 * * * * 2017-01-23 15:46:45,708 INFO [serverdevelopment] [SyncTriggersJob] [symmetric-engine-startup-1] Starting job.synctriggers with cron expression: 0 0 0 * * * 2017-01-23 15:46:45,712 INFO [serverdevelopment] [HeartbeatJob] [symmetric-engine-startup-1] Starting job.heartbeat on periodic schedule: every 900000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,714 INFO [serverdevelopment] [WatchdogJob] [symmetric-engine-startup-1] Starting job.watchdog on periodic schedule: every 3600000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,717 INFO [serverdevelopment] [StageManagementJob] [symmetric-engine-startup-1] Starting job.stage.management with cron expression: 0 0 * * * * 2017-01-23 15:46:45,720 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.refresh.cache not configured for auto start 2017-01-23 15:46:45,721 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.file.sync.tracker not configured for auto start 2017-01-23 15:46:45,721 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.file.sync.pull not configured for auto start 2017-01-23 15:46:45,721 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.file.sync.push not configured for auto start 2017-01-23 15:46:45,721 INFO [serverdevelopment] [InitialLoadExtractorJob] [symmetric-engine-startup-1] Starting job.initial.load.extract on periodic schedule: every 10000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,728 INFO [serverdevelopment] [MonitorJob] [symmetric-engine-startup-1] Starting job.monitor on periodic schedule: every 60000ms with the first run at Mon Jan 23 15:46:55 ART 2017 2017-01-23 15:46:45,732 INFO [serverdevelopment] [JobManager] [symmetric-engine-startup-1] Job job.report.status not configured for auto start 2017-01-23 15:46:45,732 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Started SymmetricDS 2017-01-23 15:46:45,732 INFO [serverdevelopment] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS: type=server, name=serverdevelopment, version=3.8.14, groupId=s-serverdevelopment, externalId=000, databaseName=MySQL, databaseVersion=5.5, driverName=MySQL Connector Java, driverVersion=mysql-connector-java-5.1.30 ( Revision: alexander.soklakov@oracle.com-20140310090514-8xt1yoht5ksg2e7c ) 2017-01-23 15:46:55,368 INFO [serverprueba] [NodeCommunicationService] [serverprueba-job-4] pull will use 10 threads 2017-01-23 15:46:55,380 INFO [serverprueba] [DataGapFastDetector] [serverprueba-job-1] Full gap analysis is running 2017-01-23 15:46:55,384 INFO [serverprueba] [DataGapFastDetector] [serverprueba-job-1] Querying data in gaps from database took 4 ms 2017-01-23 15:46:55,384 INFO [serverprueba] [DataGapFastDetector] [serverprueba-job-1] Full gap analysis is done after 4 ms 2017-01-23 15:46:55,414 INFO [serverprueba] [PushHeartbeatListener] [serverprueba-job-3] Some attribute(s) of node changed. Recording changes 2017-01-23 15:46:55,414 INFO [serverprueba] [PushHeartbeatListener] [serverprueba-job-3] Updating my node configuration info according to the symmetric properties 2017-01-23 15:46:55,428 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-1] Full gap analysis is running 2017-01-23 15:46:55,436 INFO [serverdevelopment] [NodeCommunicationService] [serverdevelopment-job-3] pull will use 10 threads 2017-01-23 15:46:55,444 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-1] Querying data in gaps from database took 2 ms 2017-01-23 15:46:55,444 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-1] Full gap analysis is done after 2 ms 2017-01-23 15:46:55,453 INFO [serverdevelopment] [PushHeartbeatListener] [serverdevelopment-job-4] Some attribute(s) of node changed. Recording changes 2017-01-23 15:46:55,453 INFO [serverdevelopment] [PushHeartbeatListener] [serverdevelopment-job-4] Updating my node configuration info according to the symmetric properties 2017-01-23 15:46:55,892 INFO [serverprueba] [RouterService] [serverprueba-job-8] The 'config' channel is NOT in common batch mode 2017-01-23 15:46:55,957 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-8] The 'config' channel is NOT in common batch mode 2017-01-23 15:46:56,014 INFO [serverprueba] [ConfigurationChangedDataRouter] [serverprueba-job-8] About to refresh the cache of nodes because new configuration came through the data router 2017-01-23 15:46:56,014 INFO [serverprueba] [RouterService] [serverprueba-job-8] The 'heartbeat' channel is NOT in common batch mode 2017-01-23 15:46:56,079 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-8] About to refresh the cache of nodes because new configuration came through the data router 2017-01-23 15:46:56,080 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-8] The 'heartbeat' channel is NOT in common batch mode 2017-01-23 15:46:56,101 INFO [serverprueba] [RouterService] [serverprueba-job-8] Routed 2 data events in 213 ms 2017-01-23 15:46:56,393 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-8] Routed 2 data events in 445 ms 2017-01-23 15:47:23,073 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-15] The 'transaction' channel is NOT in common batch mode 2017-01-23 15:47:23,074 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-15] The 'transaction' channel for the 's-serverdevelopment' node group has only default routers assigned to it. Change data won't be selected during routing 2017-01-23 15:47:23,148 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-15] Routed 1 data events in 76 ms 2017-01-23 15:47:53,951 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-12] Routed 1 data events in 611 ms 2017-01-23 15:48:20,551 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Reserving connection for 002 2017-01-23 15:48:20,636 INFO [serverdevelopment] [RegistrationService] [qtp1713411479-15] Registration was reopened for 002 2017-01-23 15:48:20,768 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-5] About to refresh the cache of node security because new configuration came through the data router 2017-01-23 15:48:20,769 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-5] Routed 1 data events in 141 ms 2017-01-23 15:48:21,409 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Releasing connection for 002 2017-01-23 15:48:21,563 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-3] Full gap analysis is running 2017-01-23 15:48:21,571 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-3] Querying data in gaps from database took 3 ms 2017-01-23 15:48:21,571 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-3] Full gap analysis is done after 3 ms 2017-01-23 15:48:21,679 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-3] About to refresh the cache of nodes because new configuration came through the data router 2017-01-23 15:48:21,679 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-3] About to refresh the cache of node security because new configuration came through the data router 2017-01-23 15:48:21,679 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-3] Routed 2 data events in 116 ms 2017-01-23 15:48:22,229 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-3] Full gap analysis is running 2017-01-23 15:48:22,231 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-3] Querying data in gaps from database took 2 ms 2017-01-23 15:48:22,231 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-3] Full gap analysis is done after 2 ms 2017-01-23 15:48:22,746 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-4] Full gap analysis is running 2017-01-23 15:48:22,749 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-4] Querying data in gaps from database took 3 ms 2017-01-23 15:48:22,749 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-4] Full gap analysis is done after 3 ms 2017-01-23 15:48:23,155 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:48:23,257 INFO [serverdevelopment] [DataService] [serverdevelopment-job-11] Queueing up an initial load to node 002 2017-01-23 15:48:23,888 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Releasing connection for 002-default 2017-01-23 15:48:25,437 INFO [serverdevelopment] [PurgeService] [serverdevelopment-job-11] Purged all 0 incoming batch for node 002 2017-01-23 15:48:25,437 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-11] Inserted reload events for node 002 in 2181 ms 2017-01-23 15:48:25,438 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-11] Full gap analysis is running 2017-01-23 15:48:25,441 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-11] Querying data in gaps from database took 3 ms 2017-01-23 15:48:25,475 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-11] Full gap analysis is done after 37 ms 2017-01-23 15:48:25,486 INFO [serverdevelopment] [NodeCommunicationService] [serverdevelopment-job-19] extract will use 20 threads 2017-01-23 15:48:25,542 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-11] About to refresh the cache of node security because new configuration came through the data router 2017-01-23 15:48:25,542 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-11] Routed 2 data events in 104 ms 2017-01-23 15:48:25,611 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 941. Starting at batch 5045. Ending at batch 5045 2017-01-23 15:48:25,743 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 941 2017-01-23 15:48:25,745 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 942. Starting at batch 5046. Ending at batch 5046 2017-01-23 15:48:25,790 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 942 2017-01-23 15:48:25,792 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 943. Starting at batch 5047. Ending at batch 5047 2017-01-23 15:48:25,841 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 943 2017-01-23 15:48:25,843 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 944. Starting at batch 5048. Ending at batch 5048 2017-01-23 15:48:25,895 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 944 2017-01-23 15:48:25,897 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 945. Starting at batch 5049. Ending at batch 5049 2017-01-23 15:48:25,972 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 945 2017-01-23 15:48:25,974 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 946. Starting at batch 5050. Ending at batch 5050 2017-01-23 15:48:26,010 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 946 2017-01-23 15:48:26,011 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 947. Starting at batch 5051. Ending at batch 5051 2017-01-23 15:48:26,455 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 947 2017-01-23 15:48:26,456 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 948. Starting at batch 5052. Ending at batch 5052 2017-01-23 15:48:26,514 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 948 2017-01-23 15:48:26,515 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 949. Starting at batch 5053. Ending at batch 5053 2017-01-23 15:48:26,567 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 949 2017-01-23 15:48:26,571 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 950. Starting at batch 5054. Ending at batch 5054 2017-01-23 15:48:26,611 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 950 2017-01-23 15:48:26,613 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 951. Starting at batch 5055. Ending at batch 5055 2017-01-23 15:48:26,670 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 951 2017-01-23 15:48:26,671 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 952. Starting at batch 5056. Ending at batch 5056 2017-01-23 15:48:26,711 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 952 2017-01-23 15:48:26,712 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 953. Starting at batch 5057. Ending at batch 5057 2017-01-23 15:48:26,748 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 953 2017-01-23 15:48:26,750 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 954. Starting at batch 5058. Ending at batch 5058 2017-01-23 15:48:26,800 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 954 2017-01-23 15:48:26,802 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 955. Starting at batch 5059. Ending at batch 5059 2017-01-23 15:48:26,838 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 955 2017-01-23 15:48:26,839 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 956. Starting at batch 5060. Ending at batch 5060 2017-01-23 15:48:26,874 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 956 2017-01-23 15:48:26,875 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 957. Starting at batch 5061. Ending at batch 5061 2017-01-23 15:48:26,949 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 957 2017-01-23 15:48:26,950 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 958. Starting at batch 5062. Ending at batch 5062 2017-01-23 15:48:27,100 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 958 2017-01-23 15:48:27,101 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 959. Starting at batch 5063. Ending at batch 5063 2017-01-23 15:48:27,313 INFO [serverdevelopment] [AcknowledgeService] [qtp1713411479-15] Batch 4944 for 002 was set to OK. Updating the status to OK 2017-01-23 15:48:27,313 ERROR [serverdevelopment] [AcknowledgeService] [qtp1713411479-15] The outgoing batch 002-4944 failed: Could not find the target table ACTIVATION 2017-01-23 15:48:27,372 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 959 2017-01-23 15:48:27,374 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 960. Starting at batch 5064. Ending at batch 5064 2017-01-23 15:48:27,901 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 960 2017-01-23 15:48:27,903 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 961. Starting at batch 5065. Ending at batch 5065 2017-01-23 15:48:28,012 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 961 2017-01-23 15:48:28,013 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 962. Starting at batch 5066. Ending at batch 5066 2017-01-23 15:48:28,050 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 962 2017-01-23 15:48:28,051 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 963. Starting at batch 5067. Ending at batch 5067 2017-01-23 15:48:28,089 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 963 2017-01-23 15:48:28,090 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 964. Starting at batch 5068. Ending at batch 5068 2017-01-23 15:48:28,331 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 964 2017-01-23 15:48:28,333 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 965. Starting at batch 5069. Ending at batch 5069 2017-01-23 15:48:28,371 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 965 2017-01-23 15:48:28,372 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 966. Starting at batch 5070. Ending at batch 5070 2017-01-23 15:48:29,042 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 966 2017-01-23 15:48:29,043 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 967. Starting at batch 5071. Ending at batch 5071 2017-01-23 15:48:29,086 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 967 2017-01-23 15:48:29,087 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 968. Starting at batch 5072. Ending at batch 5073 2017-01-23 15:48:29,159 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:48:29,391 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002 2017-01-23 15:48:29,426 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:48:30,833 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-19] Routed 1 data events in 740 ms 2017-01-23 15:48:30,833 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-18] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:30,839 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Releasing connection for 002-default 2017-01-23 15:48:32,359 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002 2017-01-23 15:48:32,383 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002-default 2017-01-23 15:48:32,784 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 2 batches for request 968 2017-01-23 15:48:32,786 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 969. Starting at batch 5074. Ending at batch 5074 2017-01-23 15:48:32,867 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 969 2017-01-23 15:48:32,869 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 970. Starting at batch 5075. Ending at batch 5075 2017-01-23 15:48:33,243 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-16] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:33,244 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Releasing connection for 002-default 2017-01-23 15:48:33,275 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 970 2017-01-23 15:48:33,277 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 971. Starting at batch 5076. Ending at batch 5076 2017-01-23 15:48:33,325 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-5] Routed 1 data events in 175 ms 2017-01-23 15:48:33,325 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 971 2017-01-23 15:48:33,326 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 972. Starting at batch 5077. Ending at batch 5077 2017-01-23 15:48:33,452 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 972 2017-01-23 15:48:33,453 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 973. Starting at batch 5078. Ending at batch 5078 2017-01-23 15:48:33,535 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 973 2017-01-23 15:48:33,536 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 974. Starting at batch 5079. Ending at batch 5079 2017-01-23 15:48:33,603 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 974 2017-01-23 15:48:33,605 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 975. Starting at batch 5080. Ending at batch 5080 2017-01-23 15:48:33,879 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 975 2017-01-23 15:48:33,881 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 976. Starting at batch 5081. Ending at batch 5081 2017-01-23 15:48:33,927 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 976 2017-01-23 15:48:33,929 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 977. Starting at batch 5082. Ending at batch 5082 2017-01-23 15:48:33,976 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 977 2017-01-23 15:48:33,977 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 978. Starting at batch 5083. Ending at batch 5083 2017-01-23 15:48:34,020 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 978 2017-01-23 15:48:34,022 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 979. Starting at batch 5084. Ending at batch 5084 2017-01-23 15:48:34,286 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 979 2017-01-23 15:48:34,287 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 980. Starting at batch 5085. Ending at batch 5085 2017-01-23 15:48:34,348 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 980 2017-01-23 15:48:34,350 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 981. Starting at batch 5086. Ending at batch 5086 2017-01-23 15:48:34,403 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 981 2017-01-23 15:48:34,405 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 982. Starting at batch 5087. Ending at batch 5087 2017-01-23 15:48:34,453 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 982 2017-01-23 15:48:34,454 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 983. Starting at batch 5088. Ending at batch 5088 2017-01-23 15:48:34,961 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 983 2017-01-23 15:48:34,962 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 984. Starting at batch 5089. Ending at batch 5089 2017-01-23 15:48:35,010 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 984 2017-01-23 15:48:35,011 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 985. Starting at batch 5090. Ending at batch 5090 2017-01-23 15:48:35,261 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 985 2017-01-23 15:48:35,263 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 986. Starting at batch 5091. Ending at batch 5091 2017-01-23 15:48:35,305 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 986 2017-01-23 15:48:35,307 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 987. Starting at batch 5092. Ending at batch 5092 2017-01-23 15:48:35,368 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 987 2017-01-23 15:48:35,370 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 988. Starting at batch 5093. Ending at batch 5093 2017-01-23 15:48:35,655 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 988 2017-01-23 15:48:35,656 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 989. Starting at batch 5094. Ending at batch 5094 2017-01-23 15:48:35,776 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 989 2017-01-23 15:48:35,777 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 990. Starting at batch 5095. Ending at batch 5095 2017-01-23 15:48:35,870 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 990 2017-01-23 15:48:35,872 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 991. Starting at batch 5096. Ending at batch 5096 2017-01-23 15:48:35,984 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 991 2017-01-23 15:48:35,985 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 992. Starting at batch 5097. Ending at batch 5097 2017-01-23 15:48:36,044 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 992 2017-01-23 15:48:36,046 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 993. Starting at batch 5098. Ending at batch 5098 2017-01-23 15:48:36,111 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 993 2017-01-23 15:48:36,112 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 994. Starting at batch 5099. Ending at batch 5099 2017-01-23 15:48:36,274 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 994 2017-01-23 15:48:36,275 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 995. Starting at batch 5100. Ending at batch 5100 2017-01-23 15:48:36,390 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 995 2017-01-23 15:48:36,392 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 996. Starting at batch 5101. Ending at batch 5101 2017-01-23 15:48:36,733 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 996 2017-01-23 15:48:36,735 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 997. Starting at batch 5102. Ending at batch 5102 2017-01-23 15:48:37,040 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 997 2017-01-23 15:48:37,041 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 998. Starting at batch 5103. Ending at batch 5103 2017-01-23 15:48:37,183 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 998 2017-01-23 15:48:37,184 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 999. Starting at batch 5104. Ending at batch 5104 2017-01-23 15:48:37,301 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 999 2017-01-23 15:48:37,303 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1000. Starting at batch 5105. Ending at batch 5105 2017-01-23 15:48:37,452 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1000 2017-01-23 15:48:37,453 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1001. Starting at batch 5106. Ending at batch 5106 2017-01-23 15:48:37,508 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1001 2017-01-23 15:48:37,509 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1002. Starting at batch 5107. Ending at batch 5107 2017-01-23 15:48:37,636 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1002 2017-01-23 15:48:37,638 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1003. Starting at batch 5108. Ending at batch 5108 2017-01-23 15:48:37,708 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1003 2017-01-23 15:48:37,710 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1004. Starting at batch 5109. Ending at batch 5109 2017-01-23 15:48:37,820 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1004 2017-01-23 15:48:37,821 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1005. Starting at batch 5110. Ending at batch 5110 2017-01-23 15:48:38,363 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Reserving connection for 002 2017-01-23 15:48:38,388 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:48:40,098 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1005 2017-01-23 15:48:40,099 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1006. Starting at batch 5111. Ending at batch 5111 2017-01-23 15:48:40,162 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1006 2017-01-23 15:48:40,164 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1007. Starting at batch 5112. Ending at batch 5112 2017-01-23 15:48:40,226 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-19] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:40,227 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Releasing connection for 002-default 2017-01-23 15:48:40,228 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1007 2017-01-23 15:48:40,229 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1008. Starting at batch 5113. Ending at batch 5113 2017-01-23 15:48:40,514 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1008 2017-01-23 15:48:40,515 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1009. Starting at batch 5114. Ending at batch 5114 2017-01-23 15:48:41,367 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002 2017-01-23 15:48:41,395 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:48:45,441 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1009 2017-01-23 15:48:45,445 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1010. Starting at batch 5115. Ending at batch 5115 2017-01-23 15:48:45,718 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-13] Routed 1 data events in 5155 ms 2017-01-23 15:48:46,434 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-17] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:46,436 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Releasing connection for 002-default 2017-01-23 15:48:46,463 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1010 2017-01-23 15:48:46,467 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1011. Starting at batch 5116. Ending at batch 5116 2017-01-23 15:48:46,673 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-13] Routed 1 data events in 418 ms 2017-01-23 15:48:46,701 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1011 2017-01-23 15:48:46,703 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1012. Starting at batch 5117. Ending at batch 5117 2017-01-23 15:48:46,955 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1012 2017-01-23 15:48:46,956 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1013. Starting at batch 5118. Ending at batch 5118 2017-01-23 15:48:47,001 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1013 2017-01-23 15:48:47,002 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1014. Starting at batch 5119. Ending at batch 5119 2017-01-23 15:48:47,074 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1014 2017-01-23 15:48:47,075 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1015. Starting at batch 5120. Ending at batch 5120 2017-01-23 15:48:47,124 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1015 2017-01-23 15:48:47,125 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1016. Starting at batch 5121. Ending at batch 5121 2017-01-23 15:48:47,192 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1016 2017-01-23 15:48:47,193 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1017. Starting at batch 5122. Ending at batch 5122 2017-01-23 15:48:47,245 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1017 2017-01-23 15:48:47,246 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1018. Starting at batch 5123. Ending at batch 5123 2017-01-23 15:48:47,319 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1018 2017-01-23 15:48:47,320 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1019. Starting at batch 5124. Ending at batch 5124 2017-01-23 15:48:47,369 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002 2017-01-23 15:48:47,396 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Reserving connection for 002-default 2017-01-23 15:48:47,398 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1019 2017-01-23 15:48:47,399 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1020. Starting at batch 5125. Ending at batch 5125 2017-01-23 15:48:47,696 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1020 2017-01-23 15:48:47,699 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1021. Starting at batch 5126. Ending at batch 5126 2017-01-23 15:48:47,758 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1021 2017-01-23 15:48:47,760 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1022. Starting at batch 5127. Ending at batch 5127 2017-01-23 15:48:47,873 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-7] Routed 1 data events in 149 ms 2017-01-23 15:48:47,874 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-15] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:47,876 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Releasing connection for 002-default 2017-01-23 15:48:47,904 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1022 2017-01-23 15:48:47,906 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1023. Starting at batch 5128. Ending at batch 5128 2017-01-23 15:48:48,175 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1023 2017-01-23 15:48:48,177 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1024. Starting at batch 5129. Ending at batch 5129 2017-01-23 15:48:48,250 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1024 2017-01-23 15:48:48,251 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1025. Starting at batch 5130. Ending at batch 5130 2017-01-23 15:48:48,347 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1025 2017-01-23 15:48:48,348 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1026. Starting at batch 5131. Ending at batch 5131 2017-01-23 15:48:48,419 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1026 2017-01-23 15:48:48,420 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1027. Starting at batch 5132. Ending at batch 5132 2017-01-23 15:48:48,510 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1027 2017-01-23 15:48:48,511 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1028. Starting at batch 5133. Ending at batch 5133 2017-01-23 15:48:48,584 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1028 2017-01-23 15:48:48,585 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1029. Starting at batch 5134. Ending at batch 5134 2017-01-23 15:48:48,634 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1029 2017-01-23 15:48:48,635 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1030. Starting at batch 5135. Ending at batch 5135 2017-01-23 15:48:48,719 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1030 2017-01-23 15:48:48,721 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1031. Starting at batch 5136. Ending at batch 5136 2017-01-23 15:48:48,993 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1031 2017-01-23 15:48:48,995 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1032. Starting at batch 5137. Ending at batch 5137 2017-01-23 15:48:49,038 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1032 2017-01-23 15:48:49,039 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1033. Starting at batch 5138. Ending at batch 5138 2017-01-23 15:48:49,320 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1033 2017-01-23 15:48:49,321 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Extracting batches for request 1034. Starting at batch 5139. Ending at batch 5139 2017-01-23 15:48:49,383 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-1] Done extracting 1 batches for request 1034 2017-01-23 15:48:49,973 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Releasing connection for 002-default 2017-01-23 15:48:53,404 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002 2017-01-23 15:48:53,433 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:48:53,520 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-17] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:53,522 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Releasing connection for 002-default 2017-01-23 15:48:53,737 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-7] Routed 1 data events in 61 ms 2017-01-23 15:48:56,377 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Reserving connection for 002 2017-01-23 15:48:56,406 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:48:56,739 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-20] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:48:56,740 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Releasing connection for 002-default 2017-01-23 15:48:56,865 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-13] Routed 1 data events in 88 ms 2017-01-23 15:49:02,411 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002 2017-01-23 15:49:02,440 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:49:02,618 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-17] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:49:02,620 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Releasing connection for 002-default 2017-01-23 15:49:02,706 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Reserving connection for 002-default 2017-01-23 15:49:03,154 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-14] Routed 1 data events in 217 ms 2017-01-23 15:49:46,315 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002 2017-01-23 15:49:46,376 INFO [serverdevelopment] [RegistrationService] [qtp1713411479-19] Registration was reopened for 002 2017-01-23 15:49:46,678 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-2] Full gap analysis is running 2017-01-23 15:49:46,682 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-2] Querying data in gaps from database took 4 ms 2017-01-23 15:49:46,682 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-2] Full gap analysis is done after 4 ms 2017-01-23 15:49:46,691 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Releasing connection for 002 2017-01-23 15:49:46,876 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-2] About to refresh the cache of nodes because new configuration came through the data router 2017-01-23 15:49:46,876 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-2] About to refresh the cache of node security because new configuration came through the data router 2017-01-23 15:49:46,876 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-2] Routed 3 data events in 198 ms 2017-01-23 15:49:47,471 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-2] Full gap analysis is running 2017-01-23 15:49:47,473 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-2] Querying data in gaps from database took 2 ms 2017-01-23 15:49:47,473 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-2] Full gap analysis is done after 2 ms 2017-01-23 15:49:47,980 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-1] Full gap analysis is running 2017-01-23 15:49:47,982 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-1] Querying data in gaps from database took 1 ms 2017-01-23 15:49:47,982 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-1] Full gap analysis is done after 1 ms 2017-01-23 15:49:48,391 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:49:48,391 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:49:48,490 INFO [serverdevelopment] [DataService] [serverdevelopment-job-17] Queueing up an initial load to node 002 2017-01-23 15:49:51,420 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002-default 2017-01-23 15:49:51,420 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:49:54,427 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:49:54,945 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:49:55,295 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002 2017-01-23 15:49:55,325 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:49:55,607 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-18] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:49:55,609 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Releasing connection for 002-default 2017-01-23 15:49:57,407 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:49:57,407 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:49:58,298 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002 2017-01-23 15:49:58,331 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:49:58,352 INFO [serverdevelopment] [IncomingBatchService] [serverdevelopment-data-loader-1] Retrying batch 002-4 2017-01-23 15:49:59,082 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-20] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:49:59,083 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Releasing connection for 002-default 2017-01-23 15:49:59,354 INFO [serverdevelopment] [PurgeService] [serverdevelopment-job-17] Purged all 9 incoming batch for node 002 2017-01-23 15:49:59,354 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-17] Inserted reload events for node 002 in 10864 ms 2017-01-23 15:49:59,355 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-17] Full gap analysis is running 2017-01-23 15:49:59,357 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-17] Querying data in gaps from database took 2 ms 2017-01-23 15:49:59,411 INFO [serverdevelopment] [DataGapFastDetector] [serverdevelopment-job-17] Full gap analysis is done after 56 ms 2017-01-23 15:49:59,581 INFO [serverdevelopment] [ConfigurationChangedDataRouter] [serverdevelopment-job-17] About to refresh the cache of node security because new configuration came through the data router 2017-01-23 15:49:59,694 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-17] Routed 4 data events in 339 ms 2017-01-23 15:50:00,406 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:50:00,406 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:03,435 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:50:03,435 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:04,312 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002 2017-01-23 15:50:04,339 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002-default 2017-01-23 15:50:04,984 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-16] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:04,986 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Releasing connection for 002-default 2017-01-23 15:50:05,075 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-10] Routed 1 data events in 277 ms 2017-01-23 15:50:06,204 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1035. Starting at batch 5248. Ending at batch 5248 2017-01-23 15:50:06,251 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1035 2017-01-23 15:50:06,252 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1036. Starting at batch 5249. Ending at batch 5249 2017-01-23 15:50:06,307 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1036 2017-01-23 15:50:06,309 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1037. Starting at batch 5250. Ending at batch 5250 2017-01-23 15:50:06,375 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1037 2017-01-23 15:50:06,377 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1038. Starting at batch 5251. Ending at batch 5251 2017-01-23 15:50:06,410 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:50:06,420 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:06,449 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1038 2017-01-23 15:50:06,451 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1039. Starting at batch 5252. Ending at batch 5252 2017-01-23 15:50:06,701 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1039 2017-01-23 15:50:06,703 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1040. Starting at batch 5253. Ending at batch 5253 2017-01-23 15:50:06,751 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1040 2017-01-23 15:50:06,753 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1041. Starting at batch 5254. Ending at batch 5254 2017-01-23 15:50:06,936 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1041 2017-01-23 15:50:06,937 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1042. Starting at batch 5255. Ending at batch 5255 2017-01-23 15:50:07,256 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1042 2017-01-23 15:50:07,258 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1043. Starting at batch 5256. Ending at batch 5256 2017-01-23 15:50:07,314 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1043 2017-01-23 15:50:07,316 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1044. Starting at batch 5257. Ending at batch 5257 2017-01-23 15:50:07,357 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1044 2017-01-23 15:50:07,358 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1045. Starting at batch 5258. Ending at batch 5258 2017-01-23 15:50:07,400 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1045 2017-01-23 15:50:07,401 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1046. Starting at batch 5259. Ending at batch 5259 2017-01-23 15:50:07,449 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1046 2017-01-23 15:50:07,451 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1047. Starting at batch 5260. Ending at batch 5260 2017-01-23 15:50:07,497 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1047 2017-01-23 15:50:07,498 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1048. Starting at batch 5261. Ending at batch 5261 2017-01-23 15:50:07,756 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1048 2017-01-23 15:50:07,758 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1049. Starting at batch 5262. Ending at batch 5262 2017-01-23 15:50:07,815 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1049 2017-01-23 15:50:07,816 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1050. Starting at batch 5263. Ending at batch 5263 2017-01-23 15:50:07,868 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1050 2017-01-23 15:50:07,869 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1051. Starting at batch 5264. Ending at batch 5264 2017-01-23 15:50:07,969 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1051 2017-01-23 15:50:07,971 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1052. Starting at batch 5265. Ending at batch 5265 2017-01-23 15:50:08,087 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1052 2017-01-23 15:50:08,088 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1053. Starting at batch 5266. Ending at batch 5266 2017-01-23 15:50:08,367 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1053 2017-01-23 15:50:08,369 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1054. Starting at batch 5267. Ending at batch 5267 2017-01-23 15:50:08,627 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1054 2017-01-23 15:50:08,629 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1055. Starting at batch 5268. Ending at batch 5268 2017-01-23 15:50:08,705 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1055 2017-01-23 15:50:08,706 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1056. Starting at batch 5269. Ending at batch 5269 2017-01-23 15:50:08,982 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1056 2017-01-23 15:50:08,984 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1057. Starting at batch 5270. Ending at batch 5270 2017-01-23 15:50:09,036 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1057 2017-01-23 15:50:09,037 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1058. Starting at batch 5271. Ending at batch 5271 2017-01-23 15:50:09,109 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1058 2017-01-23 15:50:09,112 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1059. Starting at batch 5272. Ending at batch 5272 2017-01-23 15:50:09,438 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:50:09,438 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:10,309 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002 2017-01-23 15:50:10,336 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:50:10,443 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1059 2017-01-23 15:50:10,444 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1060. Starting at batch 5273. Ending at batch 5273 2017-01-23 15:50:10,660 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1060 2017-01-23 15:50:10,662 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1061. Starting at batch 5274. Ending at batch 5274 2017-01-23 15:50:10,696 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-17] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:10,697 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Releasing connection for 002-default 2017-01-23 15:50:11,149 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1061 2017-01-23 15:50:11,150 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1062. Starting at batch 5275. Ending at batch 5276 2017-01-23 15:50:11,388 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-9] Routed 1 data events in 686 ms 2017-01-23 15:50:12,323 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 2 batches for request 1062 2017-01-23 15:50:12,324 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1063. Starting at batch 5277. Ending at batch 5277 2017-01-23 15:50:12,384 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1063 2017-01-23 15:50:12,386 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1064. Starting at batch 5278. Ending at batch 5278 2017-01-23 15:50:12,419 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002-default 2017-01-23 15:50:12,430 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:12,453 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1064 2017-01-23 15:50:12,454 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1065. Starting at batch 5279. Ending at batch 5279 2017-01-23 15:50:12,530 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1065 2017-01-23 15:50:12,531 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1066. Starting at batch 5280. Ending at batch 5280 2017-01-23 15:50:12,583 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1066 2017-01-23 15:50:12,584 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1067. Starting at batch 5281. Ending at batch 5281 2017-01-23 15:50:12,626 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1067 2017-01-23 15:50:12,627 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1068. Starting at batch 5282. Ending at batch 5282 2017-01-23 15:50:12,683 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1068 2017-01-23 15:50:12,684 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1069. Starting at batch 5283. Ending at batch 5283 2017-01-23 15:50:12,797 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1069 2017-01-23 15:50:12,798 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1070. Starting at batch 5284. Ending at batch 5284 2017-01-23 15:50:12,882 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1070 2017-01-23 15:50:12,883 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1071. Starting at batch 5285. Ending at batch 5285 2017-01-23 15:50:12,926 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1071 2017-01-23 15:50:12,928 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1072. Starting at batch 5286. Ending at batch 5286 2017-01-23 15:50:12,978 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1072 2017-01-23 15:50:12,979 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1073. Starting at batch 5287. Ending at batch 5287 2017-01-23 15:50:13,055 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1073 2017-01-23 15:50:13,056 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1074. Starting at batch 5288. Ending at batch 5288 2017-01-23 15:50:13,127 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1074 2017-01-23 15:50:13,128 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1075. Starting at batch 5289. Ending at batch 5289 2017-01-23 15:50:13,244 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1075 2017-01-23 15:50:13,245 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1076. Starting at batch 5290. Ending at batch 5290 2017-01-23 15:50:13,301 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1076 2017-01-23 15:50:13,302 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1077. Starting at batch 5291. Ending at batch 5291 2017-01-23 15:50:13,311 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002 2017-01-23 15:50:13,336 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:50:13,358 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1077 2017-01-23 15:50:13,360 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1078. Starting at batch 5292. Ending at batch 5292 2017-01-23 15:50:13,662 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1078 2017-01-23 15:50:13,663 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1079. Starting at batch 5293. Ending at batch 5293 2017-01-23 15:50:13,801 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1079 2017-01-23 15:50:13,802 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1080. Starting at batch 5294. Ending at batch 5294 2017-01-23 15:50:13,845 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-3] Routed 1 data events in 278 ms 2017-01-23 15:50:13,846 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-19] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:13,848 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Releasing connection for 002-default 2017-01-23 15:50:13,878 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1080 2017-01-23 15:50:13,879 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1081. Starting at batch 5295. Ending at batch 5295 2017-01-23 15:50:14,061 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1081 2017-01-23 15:50:14,062 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1082. Starting at batch 5296. Ending at batch 5296 2017-01-23 15:50:14,198 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1082 2017-01-23 15:50:14,199 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1083. Starting at batch 5297. Ending at batch 5297 2017-01-23 15:50:14,283 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1083 2017-01-23 15:50:14,284 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1084. Starting at batch 5298. Ending at batch 5298 2017-01-23 15:50:14,324 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1084 2017-01-23 15:50:14,325 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1085. Starting at batch 5299. Ending at batch 5299 2017-01-23 15:50:14,376 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1085 2017-01-23 15:50:14,377 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1086. Starting at batch 5300. Ending at batch 5300 2017-01-23 15:50:14,420 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1086 2017-01-23 15:50:14,421 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1087. Starting at batch 5301. Ending at batch 5301 2017-01-23 15:50:14,520 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1087 2017-01-23 15:50:14,521 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1088. Starting at batch 5302. Ending at batch 5302 2017-01-23 15:50:14,583 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1088 2017-01-23 15:50:14,584 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1089. Starting at batch 5303. Ending at batch 5303 2017-01-23 15:50:14,639 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1089 2017-01-23 15:50:14,640 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1090. Starting at batch 5304. Ending at batch 5304 2017-01-23 15:50:14,779 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1090 2017-01-23 15:50:14,781 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1091. Starting at batch 5305. Ending at batch 5305 2017-01-23 15:50:14,824 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1091 2017-01-23 15:50:14,825 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1092. Starting at batch 5306. Ending at batch 5306 2017-01-23 15:50:14,878 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1092 2017-01-23 15:50:14,880 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1093. Starting at batch 5307. Ending at batch 5307 2017-01-23 15:50:14,973 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1093 2017-01-23 15:50:14,975 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1094. Starting at batch 5308. Ending at batch 5308 2017-01-23 15:50:15,044 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1094 2017-01-23 15:50:15,045 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1095. Starting at batch 5309. Ending at batch 5309 2017-01-23 15:50:15,086 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1095 2017-01-23 15:50:15,087 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1096. Starting at batch 5310. Ending at batch 5310 2017-01-23 15:50:15,133 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1096 2017-01-23 15:50:15,134 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1097. Starting at batch 5311. Ending at batch 5311 2017-01-23 15:50:15,181 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1097 2017-01-23 15:50:15,182 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1098. Starting at batch 5312. Ending at batch 5312 2017-01-23 15:50:15,421 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:50:15,463 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:15,483 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1098 2017-01-23 15:50:15,484 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1099. Starting at batch 5313. Ending at batch 5313 2017-01-23 15:50:16,647 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1099 2017-01-23 15:50:16,649 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1100. Starting at batch 5314. Ending at batch 5314 2017-01-23 15:50:16,750 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1100 2017-01-23 15:50:16,751 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1101. Starting at batch 5315. Ending at batch 5315 2017-01-23 15:50:16,825 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1101 2017-01-23 15:50:16,826 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1102. Starting at batch 5316. Ending at batch 5316 2017-01-23 15:50:16,933 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1102 2017-01-23 15:50:16,934 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1103. Starting at batch 5317. Ending at batch 5317 2017-01-23 15:50:16,989 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1103 2017-01-23 15:50:16,992 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1104. Starting at batch 5318. Ending at batch 5318 2017-01-23 15:50:17,031 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1104 2017-01-23 15:50:17,032 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1105. Starting at batch 5319. Ending at batch 5319 2017-01-23 15:50:17,084 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1105 2017-01-23 15:50:17,086 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1106. Starting at batch 5320. Ending at batch 5320 2017-01-23 15:50:17,227 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1106 2017-01-23 15:50:17,229 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1107. Starting at batch 5321. Ending at batch 5321 2017-01-23 15:50:17,287 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1107 2017-01-23 15:50:17,288 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1108. Starting at batch 5322. Ending at batch 5322 2017-01-23 15:50:17,359 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1108 2017-01-23 15:50:17,360 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1109. Starting at batch 5323. Ending at batch 5323 2017-01-23 15:50:17,456 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1109 2017-01-23 15:50:17,458 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1110. Starting at batch 5324. Ending at batch 5324 2017-01-23 15:50:17,588 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1110 2017-01-23 15:50:17,590 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1111. Starting at batch 5325. Ending at batch 5325 2017-01-23 15:50:17,888 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1111 2017-01-23 15:50:17,889 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1112. Starting at batch 5326. Ending at batch 5326 2017-01-23 15:50:17,955 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1112 2017-01-23 15:50:17,957 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1113. Starting at batch 5327. Ending at batch 5327 2017-01-23 15:50:18,044 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1113 2017-01-23 15:50:18,046 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1114. Starting at batch 5328. Ending at batch 5328 2017-01-23 15:50:18,109 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1114 2017-01-23 15:50:18,110 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1115. Starting at batch 5329. Ending at batch 5329 2017-01-23 15:50:18,191 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1115 2017-01-23 15:50:18,193 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1116. Starting at batch 5330. Ending at batch 5330 2017-01-23 15:50:18,253 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1116 2017-01-23 15:50:18,254 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1117. Starting at batch 5331. Ending at batch 5331 2017-01-23 15:50:18,302 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1117 2017-01-23 15:50:18,303 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1118. Starting at batch 5332. Ending at batch 5332 2017-01-23 15:50:18,449 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:50:18,449 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:18,557 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1118 2017-01-23 15:50:18,559 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1119. Starting at batch 5333. Ending at batch 5333 2017-01-23 15:50:18,746 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1119 2017-01-23 15:50:18,747 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1120. Starting at batch 5334. Ending at batch 5334 2017-01-23 15:50:18,836 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1120 2017-01-23 15:50:18,837 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1121. Starting at batch 5335. Ending at batch 5335 2017-01-23 15:50:18,881 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1121 2017-01-23 15:50:18,882 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1122. Starting at batch 5336. Ending at batch 5336 2017-01-23 15:50:18,933 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1122 2017-01-23 15:50:18,934 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1123. Starting at batch 5337. Ending at batch 5337 2017-01-23 15:50:18,991 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1123 2017-01-23 15:50:18,993 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1124. Starting at batch 5338. Ending at batch 5338 2017-01-23 15:50:19,076 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1124 2017-01-23 15:50:19,077 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1125. Starting at batch 5339. Ending at batch 5339 2017-01-23 15:50:19,194 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1125 2017-01-23 15:50:19,197 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1126. Starting at batch 5340. Ending at batch 5340 2017-01-23 15:50:19,242 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1126 2017-01-23 15:50:19,244 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1127. Starting at batch 5341. Ending at batch 5341 2017-01-23 15:50:19,297 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1127 2017-01-23 15:50:19,299 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Extracting batches for request 1128. Starting at batch 5342. Ending at batch 5342 2017-01-23 15:50:19,315 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002 2017-01-23 15:50:19,335 INFO [serverdevelopment] [DataExtractorService] [serverdevelopment-extract-default-2] Done extracting 1 batches for request 1128 2017-01-23 15:50:19,342 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:50:19,440 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-20] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:19,442 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Releasing connection for 002-default 2017-01-23 15:50:19,566 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-5] Routed 1 data events in 62 ms 2017-01-23 15:50:21,427 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:50:21,427 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:24,455 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:50:24,455 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:25,321 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002 2017-01-23 15:50:25,350 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002-default 2017-01-23 15:50:25,435 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-16] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:25,437 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Releasing connection for 002-default 2017-01-23 15:50:25,676 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-16] Routed 1 data events in 54 ms 2017-01-23 15:50:27,434 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:50:27,434 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:28,326 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002 2017-01-23 15:50:28,352 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:50:28,471 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-18] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:28,473 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Releasing connection for 002-default 2017-01-23 15:50:29,018 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-20] Routed 1 data events in 294 ms 2017-01-23 15:50:30,436 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:50:30,436 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:33,467 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002-default 2017-01-23 15:50:33,467 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:34,333 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002 2017-01-23 15:50:34,365 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:50:34,437 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-19] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:34,438 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Releasing connection for 002-default 2017-01-23 15:50:36,312 ERROR [serverdevelopment] [DataExtractorService] [qtp1713411479-15] Failed to extract batch 002-5072 StackTraceKey.init [RuntimeException:764789863] java.lang.RuntimeException: java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 90000/90000 ms at org.jumpmind.symmetric.service.impl.DataExtractorService.transferFromStaging(DataExtractorService.java:1151) at org.jumpmind.symmetric.service.impl.DataExtractorService.sendOutgoingBatch(DataExtractorService.java:1027) at org.jumpmind.symmetric.service.impl.DataExtractorService.extract(DataExtractorService.java:664) at org.jumpmind.symmetric.service.impl.DataExtractorService.extract(DataExtractorService.java:506) at org.jumpmind.symmetric.web.PullUriHandler.pull(PullUriHandler.java:130) at org.jumpmind.symmetric.web.PullUriHandler.handleWithCompression(PullUriHandler.java:100) at org.jumpmind.symmetric.web.AbstractCompressionUriHandler.handle(AbstractCompressionUriHandler.java:84) at org.jumpmind.symmetric.web.SymmetricServlet.service(SymmetricServlet.java:114) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669) at org.jumpmind.symmetric.web.HttpMethodFilter.doFilter(HttpMethodFilter.java:62) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) at org.eclipse.jetty.server.Server.handle(Server.java:499) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) at java.lang.Thread.run(Thread.java:745) Caused by: java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 90000/90000 ms at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:234) at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:141) at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:355) at java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.java:253) at java.util.zip.DeflaterOutputStream.write(DeflaterOutputStream.java:211) at java.util.zip.GZIPOutputStream.write(GZIPOutputStream.java:146) at org.jumpmind.symmetric.web.compression.CompressionResponseStream.write(CompressionResponseStream.java:168) at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221) at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282) at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125) at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207) at java.io.BufferedWriter.write(BufferedWriter.java:188) at org.jumpmind.symmetric.service.impl.DataExtractorService.transferFromStaging(DataExtractorService.java:1098) ... 29 more Caused by: java.util.concurrent.TimeoutException: Idle timeout expired: 90000/90000 ms at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:161) at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ... 1 more 2017-01-23 15:50:36,444 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002-default 2017-01-23 15:50:36,444 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:38,049 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-2] Routed 1 data events in 3479 ms 2017-01-23 15:50:39,473 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:50:39,474 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:40,342 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-16] Reserving connection for 002 2017-01-23 15:50:40,373 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Reserving connection for 002-default 2017-01-23 15:50:41,590 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-20] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:41,591 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-20] Releasing connection for 002-default 2017-01-23 15:50:42,105 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-19] Routed 1 data events in 1376 ms 2017-01-23 15:50:42,454 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Reserving connection for 002-default 2017-01-23 15:50:42,454 WARN [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-19] Node '002' Channel 'default' requested a /sync/serverdevelopment/pull connection, but was rejected because it already has one 2017-01-23 15:50:43,348 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-18] Reserving connection for 002 2017-01-23 15:50:43,373 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Reserving connection for 002-default 2017-01-23 15:50:43,733 INFO [serverdevelopment] [DataLoaderService] [qtp1713411479-17] 1 data and 1 batches loaded during push request from c-serverdevelopment:002:002. 2017-01-23 15:50:43,735 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-17] Releasing connection for 002-default 2017-01-23 15:50:43,766 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-12] Routed 1 data events in 130 ms 2017-01-23 15:53:36,318 INFO [serverdevelopment] [ConcurrentConnectionManager] [qtp1713411479-15] Releasing connection for 002-default 2017-01-23 16:00:00,027 INFO [serverdevelopment] [StagingManager] [serverdevelopment-job-12] Purged 2 from stage, freeing 1 kbytes of space 2017-01-23 16:01:56,452 INFO [serverdevelopment] [RouterService] [serverdevelopment-job-17] Routed 1 data events in 106 ms 2017-01-23 16:01:56,698 INFO [serverprueba] [RouterService] [serverprueba-job-11] Routed 1 data events in 352 ms