Sync Gateway - Mobile Replication - 503 - Service Unavailable
Setup:
-
Sync Gateway v3.0.0
-
Community Edition 7.0.2 build 6703
-
Couchbase Lite (Kotlin) v3.0.0
-
Couchbase Lite Test Tool (GitHub - Infosys/CouchbaseLiteTester: This app provides a UI to create a local Couchbase Lite Db and Sync Data to the DB from a Couchbase Sync Gateway)
Details
I am getting the 503 “Service Unavailable” message when I am trying to start the mobile replication thru non-TLS endpoint ws://xx.xxx.xxx:4984/test.
I firstly tested using the native android app, afterthat I only tested with Couchbase Lite Test Tool.
Test via Admin Rest API
I am able to put via ADMIN REST API with no error in the endpoint http://10.12.57.71:4984/test/hotel_88802. The data are synchronized from Sync gateway to CB server.
Sync gateway config:
{
"bootstrap": {
"group_id": "default",
"config_update_frequency": "10s",
"server": "couchbase://localhost",
"username": "sync_gateway",
"password": "xxxxx",
"server_tls_skip_verify": true,
"use_tls_server": false
},
"api": {
"public_interface": ":4984",
"admin_interface": ":4985",
"metrics_interface": "127.0.0.1:4986",
"admin_interface_authentication": true,
"metrics_interface_authentication": true,
"enable_advanced_auth_dp": false,
"read_header_timeout": "5s",
"idle_timeout": "1m30s",
"compress_responses": true,
"https": {
"tls_minimum_version": "tlsv1.2"
},
"cors": {}
},
"logging": {
"log_file_path": "/home/sync_gateway/logs",
"redaction_level": "partial",
"console": {
"enabled": true,
"rotation": {
"max_size": 0,
"max_age": 0,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 10,
"log_level": "debug",
"log_keys": [
"*",
"HTTP"
],
"color_enabled": true
},
"error": {
"enabled": true,
"rotation": {
"max_size": 100,
"max_age": 360,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 0
},
"warn": {
"enabled": true,
"rotation": {
"max_size": 100,
"max_age": 180,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 0
},
"info": {
"enabled": true,
"rotation": {
"max_size": 100,
"max_age": 6,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 1000
},
"debug": {
"enabled": false,
"rotation": {
"max_size": 100,
"max_age": 2,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 1000
},
"trace": {
"enabled": false,
"rotation": {
"max_size": 100,
"max_age": 2,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 1000
},
"stats": {
"enabled": true,
"rotation": {
"max_size": 100,
"max_age": 6,
"rotated_logs_size_limit": 1024
},
"collation_buffer_size": 0
}
},
"auth": {
"bcrypt_cost": 10
},
"replicator": {},
"unsupported": {
"stats_log_frequency": "1m0s",
"http2": {}
},
"max_file_descriptors": 5000,
"databases": {
"test": {
"server": "couchbase://localhost",
"bucket": "test",
"username": "sync_gateway",
"password": "xxxxx",
"name": "test",
"sync": "function(doc){channel(doc.channels);}",
"revs_limit": 100,
"import_docs": true,
"import_partitions": 16,
"import_backup_old_rev": false,
"allow_empty_password": true,
"cache": {
"rev_cache": {
"size": 5000,
"shard_count": 16
},
"channel_cache": {
"max_number": 50000,
"compact_high_watermark_pct": 80,
"compact_low_watermark_pct": 60,
"max_wait_pending": 5000,
"max_num_pending": 10000,
"max_wait_skipped": 3600000,
"enable_star_channel": false,
"max_length": 500,
"min_length": 50,
"expiry_seconds": 60
}
},
"offline": false,
"unsupported": {
"warning_thresholds": {
"xattr_size_bytes": 943718,
"channels_per_doc": 50,
"access_and_role_grants_per_doc": 50,
"channels_per_user": 50000,
"channel_name_size": 250
}
},
"old_rev_expiry_seconds": 300,
"view_query_timeout_secs": 75,
"local_doc_expiry_secs": 7776000,
"enable_shared_bucket_access": true,
"session_cookie_secure": false,
"session_cookie_http_only": true,
"allow_conflicts": true,
"num_index_replicas": 0,
"use_views": false,
"send_www_authenticate_header": true,
"slow_query_warning_threshold": 500,
"delta_sync": {
"enabled": false,
"rev_max_age_seconds": 86400
},
"compact_interval_days": 86400,
"sgreplicate_enabled": true,
"sgreplicate_websocket_heartbeat_secs": 300,
"serve_insecure_attachment_types": false,
"query_pagination_limit": 5000,
"client_partition_window_secs": 2592000,
"guest": {
"name": "",
"admin_channels": [
"*"
],
"disabled": false
}
}
}
}
Couchbae Lite Tester Config
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE properties SYSTEM "http://java.sun.com/dtd/properties.dtd">
<properties>
<comment>Configuration</comment>
<entry key="sgCert">none</entry>
<entry key="sgAdminAuth">Basic <encoded pass></entry>
<entry key="author">amrishraje@gmail.com</entry>
<entry key="sgDB">test</entry>
<entry key="sgAdminURL">http://10.12.57.71:4985</entry>
<entry key="cblite-loc">C:\prg\couchbasetest</entry>
<entry key="version">v1.7+</entry>
<entry key="sgURL">ws://10.12.57.71:4984/test</entry>
</properties>
Couchbase Lite Tester Logs
W/CouchbaseLite/REPLICATOR:Replicator{@332391fd,<-,Database{@1d2444a6, name='test'},URLEndpoint{url=ws://10.12.57.71:4984/test}]: received unrecognized activity level:
W/CouchbaseLite/NETWORK:WebSocketListener failed with response Response{protocol=http/1.1, code=503, message=Service Unavailable, url=http://10.12.57.71:4984/test/_blipsync} (java.net.ProtocolException: Expected HTTP 101 response but was '503 Service Unavailable')
W/CouchbaseLite/NETWORK:{C4SocketImpl#9}==> class litecore::repl::C4SocketImpl ws://10.12.57.71:4984/test/_blipsync @000001AC041CF440
W/CouchbaseLite/NETWORK:{C4SocketImpl#9} WebSocket closed abnormally with status 503
W/CouchbaseLite/REPLICATOR:Replicator{@332391fd,<-,Database{@1d2444a6, name='test'},URLEndpoint{url=ws://10.12.57.71:4984/test}]: received unrecognized activity level:
2022-04-08 09:50:42 ERROR SyncController:163 - Error replicating from Sync GW, error: Service Unavailable 10503
2022-04-08 09:50:42 ERROR SyncController:163 - Error replicating from Sync GW, error: Service Unavailable 10503
E/CouchbaseLite/REPLICATOR:{Repl#10}==> class litecore::repl::Replicator C:\Users\alesousa\dev\prg\couchbasetest\test.cblite2\ ->ws://10.12.57.71:4984/test/_blipsync @000001AC040D77F8
E/CouchbaseLite/REPLICATOR:{Repl#10} Got LiteCore error: WebSocket error 503 "Service Unavailable"
E/CouchbaseLite/REPLICATOR:{Repl#10} Stopping due to error: WebSocket error 503 "Service Unavailable"
Sync Gateway Logs - JournalCtl:
rootSRV-PTD-SH4AL02:/home/sync_gateway/logs# systemctl status sync_gateway
sync_gateway.service - Couchbase Sync Gateway server
Loaded: loaded (/lib/systemd/system/sync_gateway.service; enabled; vendor preset: enabled)
Active: active (running) since Fri 2022-04-08 11:37:07 WEST; 1min 18s ago
Process: 2478807 ExecStartPre=/bin/mkdir -p /home/sync_gateway/logs (code=exited, status=0/SUCCESS)
Process: 2478825 ExecStartPre=/bin/chown -R sync_gateway:sync_gateway /home/sync_gateway/logs (code=exited, status=0/SUCCESS)
Process: 2478826 ExecStartPre=/bin/mkdir -p /home/sync_gateway/data (code=exited, status=0/SUCCESS)
Process: 2478827 ExecStartPre=/bin/chown -R sync_gateway:sync_gateway /home/sync_gateway/data (code=exited, status=0/SUCCESS)
Main PID: 2478828 (sync_gateway)
Tasks: 10 (limit: 9443)
Memory: 232.4M
CGroup: /system.slice/sync_gateway.service
2478828 /opt/couchbase-sync-gateway/bin/sync_gateway --defaultLogFilePath /home/sync_gateway/logs /home/sync_gateway/sync_gateway.json
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.143+01:00 [DBG] gocb+: Creating new agent group: &{AgentConfig:{BucketName: UserAgent:gocb/v2.3.1 SeedConfig:{HTTPAddrs:[localhost:8091] MemdAddrs:[localhost:11210]} Sec>
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.143+01:00 [DBG] gocb+: SDK Version: gocbcore/v10.0.2
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.143+01:00 [DBG] gocb+: Creating new agent: &{BucketName: UserAgent:gocb/v2.3.1 SeedConfig:{HTTPAddrs:[localhost:8091] MemdAddrs:[localhost:11210]} SecurityConfig:{UseTLS>
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.143+01:00 [DBG] gocb+: CCCP Looper starting.
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.210+01:00 [DBG] gocb+: SDK Version: gocbcore/v10.0.2
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.210+01:00 [DBG] gocb+: Creating new agent: &{BucketName:test UserAgent:gocb/v2.3.1 SeedConfig:{HTTPAddrs:[localhost:8091] MemdAddrs:[localhost:11210]} SecurityConfig:{Us>
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.210+01:00 [DBG] gocb+: CCCP Looper starting.
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.223+01:00 [DBG] Config+: Got config for group "default" from bucket "test" with cas 1649368078121828352
Apr 08 11:38:21 SRV-PTD-SH4AL02 bash[2478828]: 2022-04-08T11:38:21.223+01:00 [DBG] Config+: Database "test" bucket "test" config has not changed since last update
SG Error
2022-04-08T11:37:07.236+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
2022-04-08T11:37:07.236+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
SG Warn
2022-04-07T22:47:56.215+01:00 [WRN] c:test-SGI Error processing DCP stream - will attempt to restart/reconnect if appropriate: pkt.Receive, err: read tcp 127.0.0.1:40024->127.0.0.1:11210: use of closed network connection. -- base.(*DCPReceiver).OnError() at dcp_receiver.go:60
2022-04-07T22:47:57.853+01:00 [WRN] destKey test_import already exists in cbgtDestFactories - new value will replace the existing dest -- base.StoreDestFactory() at dcp_sharded.go:570
2022-04-08T09:41:04.126+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
2022-04-08T09:41:04.126+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
2022-04-08T09:41:08.207+01:00 [WRN] Automatic compaction can only be enabled on nodes running an Import process -- db.NewDatabaseContext() at database.go:554
2022-04-08T11:37:07.236+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
2022-04-08T11:37:07.236+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
2022-04-08T11:37:09.204+01:00 [WRN] Automatic compaction can only be enabled on nodes running an Import process -- db.NewDatabaseContext() at database.go:554
SG Debug
2022-04-08T11:43:11.083+01:00 [DBG] gocb+: SDK Version: gocbcore/v10.0.2
2022-04-08T11:43:11.083+01:00 [DBG] gocb+: CCCP Looper starting.
2022-04-08T11:43:11.111+01:00 [DBG] DCP+: c:test-SGI cbdatasource: server: 127.0.0.1:11210, uprOpenName: SGI-v-3.0-commit--uuid-d8cd917f-b727-11ec-a904-0050569d2b9d, worker, looping beg, vbucketState: "running" (has 1024 vbuckets), 0-1023
2022-04-08T11:43:11.161+01:00 [DBG] gocb+: SDK Version: gocbcore/v10.0.2
2022-04-08T11:43:11.161+01:00 [DBG] gocb+: Creating new agent group: &{AgentConfig:{BucketName: UserAgent:gocb/v2.3.1 SeedConfig:{HTTPAddrs:[localhost:8091] MemdAddrs:[localhost:11210]} SecurityConfig:{UseTLS:false TLSRootCAProvider:0xa1a8c0 InitialBootstrapNonTLS:false Auth:0xc0003b0ab0 AuthMechanisms:[]} CompressionConfig:{Enabled:false DisableDecompression:false MinSize:0 MinRatio:0} ConfigPollerConfig:{HTTPRedialPeriod:0s HTTPRetryDelay:0s HTTPMaxWait:0s CccpMaxWait:0s CccpPollPeriod:0s} IoConfig:{NetworkType: UseMutationTokens:true UseDurations:true UseOutOfOrderResponses:true DisableXErrorHello:false DisableJSONHello:false DisableSyncReplicationHello:false EnablePITRHello:false UseCollections:true} KVConfig:{ConnectTimeout:10s PoolSize:0 MaxQueueSize:0} HTTPConfig:{MaxIdleConns:0 MaxIdleConnsPerHost:0 IdleConnectionTimeout:0s} DefaultRetryStrategy:0xc0003b0210 CircuitBreakerConfig:{Enabled:true VolumeThreshold:0 ErrorThresholdPercentage:0 SleepWindow:0s RollingWindow:0s CompletionCallback:<nil> CanaryTimeout:0s} OrphanReporterConfig:{Enabled:true ReportInterval:0s SampleSize:0} TracerConfig:{Tracer:0xc0003b0240 NoRootTraceSpans:true} MeterConfig:{Meter:<nil>}}}
2022-04-08T11:43:11.192+01:00 [DBG] gocb+: CCCP Looper starting.
2022-04-08T11:43:11.207+01:00 [DBG] gocb+: SDK Version: gocbcore/v10.0.2
2022-04-08T11:43:11.207+01:00 [DBG] gocb+: Creating new agent: &{BucketName:test UserAgent:gocb/v2.3.1 SeedConfig:{HTTPAddrs:[localhost:8091] MemdAddrs:[localhost:11210]} SecurityConfig:{UseTLS:false TLSRootCAProvider:0xa1a8c0 InitialBootstrapNonTLS:false Auth:0xc0003b1440 AuthMechanisms:[]} CompressionConfig:{Enabled:false DisableDecompression:false MinSize:0 MinRatio:0} ConfigPollerConfig:{HTTPRedialPeriod:0s HTTPRetryDelay:0s HTTPMaxWait:0s CccpMaxWait:0s CccpPollPeriod:0s} IoConfig:{NetworkType: UseMutationTokens:true UseDurations:true UseOutOfOrderResponses:true DisableXErrorHello:false DisableJSONHello:false DisableSyncReplicationHello:false EnablePITRHello:false UseCollections:true} KVConfig:{ConnectTimeout:10s PoolSize:0 MaxQueueSize:0} HTTPConfig:{MaxIdleConns:0 MaxIdleConnsPerHost:0 IdleConnectionTimeout:0s} DefaultRetryStrategy:0xc00aa9f100 CircuitBreakerConfig:{Enabled:true VolumeThreshold:0 ErrorThresholdPercentage:0 SleepWindow:0s RollingWindow:0s CompletionCallback:<nil> CanaryTimeout:0s} OrphanReporterConfig:{Enabled:true ReportInterval:0s SampleSize:0} TracerConfig:{Tracer:0xc00aa9f120 NoRootTraceSpans:true} MeterConfig:{Meter:<nil>}}
2022-04-08T11:43:11.207+01:00 [DBG] gocb+: CCCP Looper starting.
2022-04-08T11:43:11.221+01:00 [DBG] Config+: Got config for group "default" from bucket "test" with cas 1649368078121828352
2022-04-08T11:43:11.221+01:00 [DBG] Config+: Database "test" bucket "test" config has not changed since last update
SG Info
2022-04-08T11:37:07.236+01:00 ==== Couchbase Sync Gateway/3.0.0(541;46803d1) CE ====
2022-04-08T11:37:07.236+01:00 [INF] Loading content from [/home/sync_gateway/sync_gateway.json] ...
2022-04-08T11:37:07.237+01:00 [INF] Config: Starting in persistent mode using config group "default"
2022-04-08T11:37:07.237+01:00 [INF] Logging: Console to stderr
2022-04-08T11:37:07.244+01:00 [INF] Logging: Files to /home/sync_gateway/logs
2022-04-08T11:37:07.259+01:00 [INF] Logging: Console level: debug
2022-04-08T11:37:07.259+01:00 [INF] Logging: Console keys: [* HTTP]
2022-04-08T11:37:07.259+01:00 [INF] Logging: Redaction level: partial
2022-04-08T11:37:07.259+01:00 [INF] Logging stats with frequency: &{1m0s}
2022-04-08T11:37:07.330+01:00 [INF] Config: Successfully initialized cluster agent
2022-04-08T11:37:07.720+01:00 [INF] DCP: Using network type: auto
2022-04-08T11:37:07.721+01:00 [INF] Cache: Waiting 1.475194137s for sequence allocation...
2022-04-08T11:37:07.764+01:00 [INF] CBGoUtilsLogger: Using plain authentication for user <ud>sync_gateway</ud>
2022-04-08T11:37:09.204+01:00 [INF] Using metadata purge interval of 3.00 days for tombstone compaction.
2022-04-08T11:37:09.204+01:00 [WRN] Automatic compaction can only be enabled on nodes running an Import process -- db.NewDatabaseContext() at database.go:554
2022-04-08T11:37:09.210+01:00 [INF] Using default sync function 'channel(doc.channels)' for database "dtx-therapeutics-adherence"
2022-04-08T11:37:09.210+01:00 [INF] Opening db /test as bucket "test", pool "default", server <couchbase://localhost>
2022-04-08T11:37:09.210+01:00 [INF] GoCBv2 Opening Couchbase database test on <couchbase://localhost> as user "<ud>sync_gateway</ud>"
2022-04-08T11:37:09.210+01:00 [INF] Auth: Using credential authentication for bucket test on couchbase://localhost
2022-04-08T11:37:09.210+01:00 [INF] Setting query timeouts for bucket test to 1m15s
2022-04-08T11:37:09.241+01:00 [INF] Setting max_concurrent_query_ops to 256 based on query node count (1)
2022-04-08T11:37:09.241+01:00 [INF] Initializing indexes with numReplicas: 0...
2022-04-08T11:37:09.281+01:00 [INF] Verifying index availability for bucket test...
2022-04-08T11:37:09.325+01:00 [INF] Indexes ready for bucket test.
2022-04-08T11:37:09.325+01:00 [INF] delta_sync enabled=false with rev_max_age_seconds=86400 for database test
2022-04-08T11:37:09.325+01:00 [INF] DCP: Registering PindexImplType for syncGateway-import-
2022-04-08T11:37:09.327+01:00 [INF] Created background task: "CleanAgedItems" with interval 1m0s
2022-04-08T11:37:09.327+01:00 [INF] Cache: Initializing changes cache for database <ud>test</ud> with options {ChannelCacheOptions:{ChannelCacheMinLength:50 ChannelCacheMaxLength:500 ChannelCacheAge:1m0s MaxNumChannels:50000 CompactHighWatermarkPercent:80 CompactLowWatermarkPercent:60 ChannelQueryLimit:5000} CachePendingSeqMaxWait:5s CachePendingSeqMaxNum:10000 CacheSkippedSeqMaxWait:1h0m0s}
2022-04-08T11:37:09.327+01:00 [INF] Created background task: "InsertPendingEntries" with interval 2.5s
2022-04-08T11:37:09.327+01:00 [INF] Created background task: "CleanSkippedSequenceQueue" with interval 30m0s
2022-04-08T11:37:09.327+01:00 [INF] DCP: Starting mutation feed on bucket test due to either channel cache mode or doc tracking (auto-import)
2022-04-08T11:37:09.327+01:00 [INF] DCP: Using DCP feed for bucket: "test" (based on feed_type specified in config file)
2022-04-08T11:37:09.328+01:00 [INF] DCP: c:test-SG Using DCP Logging Receiver
2022-04-08T11:37:09.363+01:00 [INF] DCP: c:test-SG DCP feed starting with name SG-v-3.0-commit--uuid-d7ca9c90-b727-11ec-a904-0050569d2b9d
2022-04-08T11:37:09.363+01:00 [INF] DCP: Using network type: auto
2022-04-08T11:37:09.363+01:00 [INF] Cache: Waiting 1.464767893s for sequence allocation...
2022-04-08T11:37:09.394+01:00 [INF] CBGoUtilsLogger: Using plain authentication for user <ud>sync_gateway</ud>
2022-04-08T11:37:10.828+01:00 [INF] DCP: Attempting to start import DCP feed...
2022-04-08T11:37:10.828+01:00 [INF] DCP: Starting DCP import feed for bucket: "<ud>test</ud>"
2022-04-08T11:37:10.828+01:00 [INF] DCP: c:test-SGI Using DCP Logging Receiver
2022-04-08T11:37:11.059+01:00 [INF] DCP: c:test-SGI Restarting vb 1023 using metadata sequence 0 (backfill 0 not in [0-0])
2022-04-08T11:37:11.060+01:00 [INF] DCP: c:test-SGI DCP feed starting with name SGI-v-3.0-commit--uuid-d8cd917f-b727-11ec-a904-0050569d2b9d
2022-04-08T11:37:11.060+01:00 [INF] DCP: Using network type: auto
2022-04-08T11:37:11.069+01:00 [INF] Using metadata purge interval of 3.00 days for tombstone compaction.
2022-04-08T11:37:11.069+01:00 [INF] Created background task: "Compact" with interval 24h0m0s
2022-04-08T11:37:11.078+01:00 [INF] Using default sync function 'channel(doc.channels)' for database "test"
2022-04-08T11:37:11.079+01:00 [INF] Reset guest user to config
2022-04-08T11:37:11.079+01:00 [INF] Config: Successfully fetched 2 database configs from buckets in cluster
2022-04-08T11:37:11.079+01:00 [INF] Config: Starting background polling for new configs/buckets: 10s
2022-04-08T11:37:11.079+01:00 [INF] Starting metrics server on 127.0.0.1:4986
2022-04-08T11:37:11.079+01:00 [INF] Starting admin server on :4985
2022-04-08T11:37:11.079+01:00 [INF] Starting server on :4984 ...
2022-04-08T11:37:11.092+01:00 [INF] CBGoUtilsLogger: Using plain authentication for user <ud>sync_gateway</ud>
2022-04-08T11:37:11.119+01:00 [INF] DCP: Backfill in progress: 2% (1 / 43)