_____ __ _ ____ _____ / ___/ __ _____ __ ___ __ ___ _/ /_ ____(_)___ / __ | / ___/ \__ \ / / / / _ `_ \/ _ `_ \/ _ \/_ __// __/ / __/ / / / / \__ \ ___/ // /_/ / // // / // // / __// / / / / / /_ / /_/ / ___/ / /____/ \__ /_//_//_/_//_//_/\___/ \_/ /_/ /_/\__/ /_____/ /____/ /____/ +-----------------------------------------------------------------+ | Copyright (C) 2007-2020 JumpMind, Inc. | | | | Licensed under the GNU General Public License version 3. | | This software comes with ABSOLUTELY NO WARRANTY. | | See http://www.gnu.org/licenses/gpl.html | +-----------------------------------------------------------------+ 2020-04-13 14:59:59,904 INFO [startup] [SymmetricWebServer] [main] About to start SymmetricDS web server on host:port 0.0.0.0:31415 2020-04-13 15:00:00,770 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Initializing connection to database 2020-04-13 15:00:05,751 INFO [startup] [SymmetricWebServer] [main] Starting JMX HTTP console on port 31416 2020-04-13 15:00:05,832 INFO [startup] [SymmetricWebServer] [main] Joining the web server main thread 2020-04-13 15:00:08,542 INFO [corp-000] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-1] Detected database 'postgres95', version '11', protocol 'postgresql' 2020-04-13 15:00:08,575 INFO [corp-000] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-1] The IDatabasePlatform being used is org.jumpmind.db.platform.postgresql.PostgreSql95DatabasePlatform 2020-04-13 15:00:08,777 INFO [corp-000] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] The DbDialect being used is org.jumpmind.symmetric.db.postgresql.PostgreSqlSymmetricDialect 2020-04-13 15:00:08,856 INFO [corp-000] [ExtensionService] [symmetric-engine-startup-1] Found 0 extension points from the database that will be registered 2020-04-13 15:00:08,878 INFO [corp-000] [StagingManager] [symmetric-engine-startup-1] The staging directory was initialized at the following location: tmp/corp-000 2020-04-13 15:00:10,116 INFO [corp-000] [ExtensionService] [symmetric-engine-startup-1] Found 0 extension points from the database that will be registered 2020-04-13 15:00:10,117 INFO [corp-000] [ClientExtensionService] [symmetric-engine-startup-1] Found 8 extension points from spring that will be registered 2020-04-13 15:00:10,138 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Initializing SymmetricDS database 2020-04-13 15:00:10,209 INFO [corp-000] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] Checking if SymmetricDS tables need created or altered 2020-04-13 15:00:10,665 INFO [corp-000] [SymmetricServlet] [qtp147022238-17] Requests for engine corp-000 are being rejected while it is starting 2020-04-13 15:00:12,517 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Done initializing SymmetricDS database 2020-04-13 15:00:12,517 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS database version : 3.11.7 2020-04-13 15:00:12,517 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS software version : 3.11.7 2020-04-13 15:00:12,556 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Starting registered node [group=corp, id=000, nodeId=000] 2020-04-13 15:00:12,560 INFO [corp-000] [ClusterService] [symmetric-engine-startup-1] This node picked a server id of atlas-crm-dev-vm-db 2020-04-13 15:00:12,561 INFO [corp-000] [TriggerRouterService] [symmetric-engine-startup-1] Synchronizing triggers 2020-04-13 15:00:14,263 INFO [corp-000] [TriggerRouterService] [symmetric-engine-startup-1] Done synchronizing triggers 2020-04-13 15:00:14,315 INFO [corp-000] [RouterJob] [symmetric-engine-startup-1] Starting Routing on periodic schedule: every 5000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,319 INFO [corp-000] [PushJob] [symmetric-engine-startup-1] Starting Push on periodic schedule: every 10000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,320 INFO [corp-000] [PullJob] [symmetric-engine-startup-1] Starting Pull on periodic schedule: every 10000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,320 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job Offline Push not configured for auto start 2020-04-13 15:00:14,320 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job Offline Pull not configured for auto start 2020-04-13 15:00:14,322 INFO [corp-000] [OutgoingPurgeJob] [symmetric-engine-startup-1] Starting job 'Purge Outgoing' with cron expression: '0 0 */4 * * *' 2020-04-13 15:00:14,324 INFO [corp-000] [IncomingPurgeJob] [symmetric-engine-startup-1] Starting job 'Purge Incoming' with cron expression: '0 0 */4 * * *' 2020-04-13 15:00:14,325 INFO [corp-000] [StatisticFlushJob] [symmetric-engine-startup-1] Starting job 'Stat Flush' with cron expression: '0 0/5 * * * *' 2020-04-13 15:00:14,329 INFO [corp-000] [SyncTriggersJob] [symmetric-engine-startup-1] Starting job 'SyncTriggers' with cron expression: '0 0 0 * * *' 2020-04-13 15:00:14,331 INFO [corp-000] [HeartbeatJob] [symmetric-engine-startup-1] Starting Heartbeat on periodic schedule: every 900000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,332 INFO [corp-000] [WatchdogJob] [symmetric-engine-startup-1] Starting Watchdog on periodic schedule: every 3600000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,333 INFO [corp-000] [StageManagementJob] [symmetric-engine-startup-1] Starting job 'Stage Management' with cron expression: '0 0 * * * *' 2020-04-13 15:00:14,333 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job Refresh Cache not configured for auto start 2020-04-13 15:00:14,333 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job File Sync Tracker not configured for auto start 2020-04-13 15:00:14,333 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job File Sync Pull not configured for auto start 2020-04-13 15:00:14,333 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job File Sync Push not configured for auto start 2020-04-13 15:00:14,333 INFO [corp-000] [InitialLoadExtractorJob] [symmetric-engine-startup-1] Starting Initial Load Extract on periodic schedule: every 10000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,334 INFO [corp-000] [MonitorJob] [symmetric-engine-startup-1] Starting Monitor on periodic schedule: every 60000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,334 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job Report Status not configured for auto start 2020-04-13 15:00:14,334 INFO [corp-000] [JobManager] [symmetric-engine-startup-1] Job Log Miner not configured for auto start 2020-04-13 15:00:14,335 INFO [corp-000] [InitialLoadJob] [symmetric-engine-startup-1] Starting Initial Load Queue on periodic schedule: every 10000ms with the first run at Mon Apr 13 15:00:24 UTC 2020 2020-04-13 15:00:14,339 INFO [corp-000] [AbstractSymmetricEngine] [symmetric-engine-startup-1] SymmetricDS Node STARTED: nodeId=000 groupId=corp type=server subType=null name=corp-000 softwareVersion=3.11.7 databaseName=PostgreSQL databaseVersion=11.7 driverName=PostgreSQL JDBC Driver driverVersion=42.2.8 uptime=0 sec. 2020-04-13 15:00:24,051 INFO [corp-000] [DataGapFastDetector] [corp-000-job-1] Full gap analysis is running 2020-04-13 15:00:24,057 INFO [corp-000] [DataGapFastDetector] [corp-000-job-1] Querying data in gaps from database took 5 ms 2020-04-13 15:00:24,058 INFO [corp-000] [DataGapFastDetector] [corp-000-job-1] Full gap analysis is done after 6 ms 2020-04-13 15:00:24,089 INFO [corp-000] [NodeCommunicationService] [corp-000-job-3] pull will use 10 threads 2020-04-13 15:00:29,412 INFO [corp-000] [RouterService] [corp-000-job-11] Routed 2 data events in 275 ms 2020-04-13 15:00:30,661 INFO [corp-000] [PullUriHandler] [qtp147022238-16] 1 data and 1 batches sent during pull request from client:002:002 2020-04-13 15:00:47,854 INFO [corp-000] [RegistrationService] [qtp147022238-19] Registration was reopened for 4A549477EDFF 2020-04-13 15:00:47,875 INFO [corp-000] [RegistrationService] [qtp147022238-19] Completed registration of node android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:00:49,481 INFO [corp-000] [ConfigurationChangedDataRouter] [corp-000-job-7] About to refresh the cache of nodes because new configuration came through the data router 2020-04-13 15:00:49,481 INFO [corp-000] [ConfigurationChangedDataRouter] [corp-000-job-7] About to refresh the cache of node security because new configuration came through the data router 2020-04-13 15:00:49,519 INFO [corp-000] [RouterService] [corp-000-job-7] Routed 7 data events in 90 ms 2020-04-13 15:00:53,444 INFO [corp-000] [PullUriHandler] [qtp147022238-20] 3 data and 3 batches sent during pull request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:00:54,337 INFO [corp-000] [InitialLoadService] [corp-000-job-4] Creating load request from node 000 to node 4A549477EDFF 2020-04-13 15:00:54,561 INFO [corp-000] [ConfigurationChangedDataRouter] [corp-000-job-11] About to refresh the cache of node security because new configuration came through the data router 2020-04-13 15:00:54,562 INFO [corp-000] [RouterService] [corp-000-job-11] Routed 4 data events in 39 ms 2020-04-13 15:00:59,005 INFO [corp-000] [IncomingBatchService] [corp-000-dataloader-1] Skipping batch 4A549477EDFF-2 that was already loaded 2020-04-13 15:00:59,009 INFO [corp-000] [DataLoaderService] [qtp147022238-18] 1 data and 1 batches loaded during push request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:01:04,546 INFO [corp-000] [PullUriHandler] [qtp147022238-16] 1 data and 1 batches sent during pull request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:05:40,937 INFO [corp-000] [DataLoaderService] [qtp147022238-19] 1 data and 1 batches loaded during push request from client:002:002 2020-04-13 15:05:44,872 INFO [corp-000] [RouterService] [corp-000-job-7] Routed 1 data events in 35 ms 2020-04-13 15:05:44,902 INFO [corp-000] [IncomingBatchService] [corp-000-dataloader-3] Skipping batch 4A549477EDFF-6 that was already loaded 2020-04-13 15:05:44,907 INFO [corp-000] [DataLoaderService] [qtp147022238-15] 1 data and 1 batches loaded during push request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:10:41,893 INFO [corp-000] [IncomingBatchService] [corp-000-dataloader-4] Skipping batch 4A549477EDFF-7 that was already loaded 2020-04-13 15:10:41,897 INFO [corp-000] [DataLoaderService] [qtp147022238-18] 1 data and 1 batches loaded during push request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:15:25,537 INFO [corp-000] [RouterService] [corp-000-job-18] Routed 2 data events in 117 ms 2020-04-13 15:15:30,798 INFO [corp-000] [PullUriHandler] [qtp147022238-15] 1 data and 1 batches sent during pull request from client:002:002 2020-04-13 15:15:33,514 INFO [corp-000] [PullUriHandler] [qtp147022238-17] 1 data and 1 batches sent during pull request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:15:49,855 INFO [corp-000] [IncomingBatchService] [corp-000-dataloader-5] Skipping batch 4A549477EDFF-9 that was already loaded 2020-04-13 15:15:49,859 INFO [corp-000] [DataLoaderService] [qtp147022238-18] 1 data and 1 batches loaded during push request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:20:46,866 INFO [corp-000] [IncomingBatchService] [corp-000-dataloader-6] Skipping batch 4A549477EDFF-10 that was already loaded 2020-04-13 15:20:46,869 INFO [corp-000] [DataLoaderService] [qtp147022238-13] 1 data and 1 batches loaded during push request from android-client:4A549477EDFF:4A549477EDFF 2020-04-13 15:20:51,127 INFO [corp-000] [DataLoaderService] [qtp147022238-15] 1 data and 1 batches loaded during push request from client:002:002 2020-04-13 15:20:55,895 INFO [corp-000] [RouterService] [corp-000-job-3] Routed 1 data events in 35 ms