Uploaded image for project: 'Couchbase Gateway'
  1. Couchbase Gateway
  2. CBG-370

Sync gateway fails to start

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: None
    • Fix Version/s: 2.6.0
    • Component/s: SyncGateway
    • Security Level: Public
    • Labels:
      None

      Description

      SGW Version : 2.6.0-59

      SGW config: 

      {
          "interface":":4984",
          "adminInterface": "0.0.0.0:4985",
          "maxIncomingConnections": 0,
          "maxCouchbaseConnections": 16,
          "maxFileDescriptors": 90000,
          "slowServerCallWarningThreshold": 500,
          "compressResponses": false,
          "logging": {"debug": {"enabled": true} },
          "databases":{
              "db":{
                  "use_views": true,
                  "username": "data-bucket",
                  "password": "password",
                  "server":"http://192.168.33.10:8091",
                  "bucket":"data-bucket"
              }
          }
      }
      

      Steps to reproduce :

      1. Have the SGW build 2.6.0-59
      2. Have the above SGW config
      3. Start the SGW

      Result:

      Logs says that sgw has started, but when I try to access SGW through browser or http calls, I could not able to access SGW.

      Actual:

      I should be able to access SGW if logs says SGW started.

      Logs: 

      sgcollect-260-59.zip

        Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

          Hide
          sridevi.saragadam Sridevi Saragadam added a comment -

          Adam Fraser, can you reassign whoever is going to work ?

          Show
          sridevi.saragadam Sridevi Saragadam added a comment - Adam Fraser , can you reassign whoever is going to work ?
          Hide
          James Flather James Flather added a comment -

          Possible I'm missing something (and without ms in messages, it's difficult to perfectly align), but Ansible is looking a little guilty here:

          May 20 22:36:36 localhost systemd: Reloading.
          May 20 22:36:37 localhost systemd: Starting Couchbase Sync Gateway server...
          May 20 22:36:37 localhost systemd: Started Couchbase Sync Gateway server.
          May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.062Z ==== Couchbase Sync Gateway/2.6.0(59;d4fcbc9) EE ====
          May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.062Z [INF] Logging: Console disabled
          May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.062Z [INF] Logging: Files to /home/sync_gateway/logs
          May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.066Z [INF] Starting admin server on 127.0.0.1:4985
          May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.068Z [INF] Starting server on 0.0.0.0:4984 ...
          May 20 22:36:37 localhost ansible-systemd: Invoked with name=sync_gateway enabled=None daemon_reload=False state=stopped user=False masked=None
          May 20 22:36:37 localhost systemd: Stopping Couchbase Sync Gateway server...
          May 20 22:36:37 localhost systemd: Stopped Couchbase Sync Gateway server.
          2019-05-20T22:36:37.062Z ==== Couchbase Sync Gateway/2.6.0(59;d4fcbc9) EE ====
          2019-05-20T22:36:37.062Z [INF] Logging: Console disabled
          2019-05-20T22:36:37.062Z [INF] Logging: Files to /home/sync_gateway/logs
          2019-05-20T22:36:37.062Z [INF] Logging: Console level: none
          2019-05-20T22:36:37.062Z [INF] Logging: Console keys: [HTTP]
          2019-05-20T22:36:37.062Z [INF] Logging: Redaction level: none
          2019-05-20T22:36:37.062Z [INF] requestedSoftFDLimit < currentSoftFdLimit (5000 < 65535) no action needed
          2019-05-20T22:36:37.062Z [INF] Logging stats with frequency: 1m0s
          2019-05-20T22:36:37.062Z [INF] Opening db /db as bucket "db", pool "default", server <walrus:data>
          2019-05-20T22:36:37.062Z [INF] Opening Walrus database db on <walrus:data>
          2019-05-20T22:36:37.062Z [WRN] Using GSI is not supported when using a walrus bucket - switching to use views.  Set 'use_views':true in Sync Gateway's database config to avoid this warning. -- rest.(*ServerContext)._getOrAddDatabaseFromConfig() at server_context.go:480
          2019-05-20T22:36:37.062Z [INF] Design docs for current view version (2.1) do not exist - creating...
          2019-05-20T22:36:37.065Z [INF] Design docs successfully created for view version 2.1.
          2019-05-20T22:36:37.065Z [INF] Verifying view availability for bucket db...
          2019-05-20T22:36:37.066Z [INF] Views ready for bucket db.
          2019-05-20T22:36:37.066Z [INF] delta_sync enabled=false with rev_max_age_seconds=86400 for database db
          2019-05-20T22:36:37.066Z [INF] Created background task: "CleanAgedItems" with interval 1m0s
          2019-05-20T22:36:37.066Z [INF] Cache: Initializing changes cache with options {ChannelCacheOptions:{ChannelCacheMinLength:50 ChannelCacheMaxLength:500 ChannelCacheAge:1m0s ChannelCacheMaxNumber:50000} CachePendingSeqMaxWait:5s CachePendingSeqMaxNum:10000 CacheSkippedSeqMaxWait:1h0m0s}
          2019-05-20T22:36:37.066Z [INF] Initializing changes cache for database db
          2019-05-20T22:36:37.066Z [INF] Created background task: "InsertPendingEntries" with interval 2.5s
          2019-05-20T22:36:37.066Z [INF] Created background task: "CleanSkippedSequenceQueue" with interval 30m0s
          2019-05-20T22:36:37.066Z [INF] DCP: Starting mutation feed on bucket db due to either channel cache mode or doc tracking (auto-import/bucketshadow)
          2019-05-20T22:36:37.066Z [INF] Using default sync function 'channel(doc.channels)' for database "db"
          2019-05-20T22:36:37.066Z [INF] Auth: Saved _sync:user:: &{roleImpl:{Name_: ExplicitChannels_:*:1 Channels_: Sequence_:1 PreviousChannels_: vbNo:<nil> cas:3} userImplBody:{Email_: Disabled_:false PasswordHash_:[] OldPasswordHash_:<nil> ExplicitRoles_: RolesSince_: OldExplicitRoles_:[]} auth:0xc000187c80 roles:[]}
          2019-05-20T22:36:37.066Z [INF] Reset guest user to config
          2019-05-20T22:36:37.066Z [INF] Starting admin server on 127.0.0.1:4985
          2019-05-20T22:36:37.068Z [INF] Starting server on 0.0.0.0:4984 ...
          2019-05-20T22:36:37.069Z [INF] DCP: Received #1 ("_user/")
          May 20 22:36:38 localhost ansible-wait_for: Invoked with state=stopped port=4985 delay=0 host=127.0.0.1 timeout=300 exclude_hosts=None search_regex=None path=None connect_timeout=5
          May 20 22:36:38 localhost ansible-setup: Invoked with filter=* gather_subset=['all'] fact_path=/etc/ansible/facts.d gather_timeout=10
          May 20 22:36:40 localhost ansible-stat: Invoked with checksum_algorithm=sha1 mime=False get_checksum=True path=/home/sync_gateway/sync_gateway.json checksum_algo=sha1 follow=False get_md5=False
          May 20 22:36:41 localhost ansible-copy: Invoked with src=/home/vagrant/.ansible/tmp/ansible-tmp-1558391800.44-80226531789367/source directory_mode=None force=True remote_src=None unsafe_writes=None selevel=None seuser=None setype=None group=sync_gateway content=NOT_LOGGING_PARAMETER dest=/home/sync_gateway/sync_gateway.json serole=None original_basename=sync_gateway_default_functional_tests_cc.json delimiter=None mode=0644 regexp=None owner=sync_gateway follow=True validate=None backup=False
          May 20 22:36:41 localhost ansible-command: Invoked with warn=True executable=None _uses_shell=True _raw_params=cat /home/sync_gateway/sync_gateway.json removes=None creates=None chdir=None
          May 20 22:36:42 localhost ansible-stat: Invoked with checksum_algorithm=sha1 mime=False get_checksum=True path=/home/sync_gateway/sg_cert.pem checksum_algo=sha1 follow=False get_md5=False
          May 20 22:36:42 localhost ansible-copy: Invoked with src=/home/vagrant/.ansible/tmp/ansible-tmp-1558391801.75-136965761948984/source directory_mode=None force=True remote_src=None unsafe_writes=None selevel=None seuser=None setype=None group=sync_gateway content=NOT_LOGGING_PARAMETER dest=/home/sync_gateway/sg_cert.pem serole=None original_basename=sg_cert.pem delimiter=None mode=0644 regexp=None owner=sync_gateway follow=True validate=None backup=False
          May 20 22:36:42 localhost ansible-stat: Invoked with checksum_algorithm=sha1 mime=False get_checksum=True path=/home/sync_gateway/sg_privkey.pem checksum_algo=sha1 follow=False get_md5=False
          May 20 22:36:42 localhost ansible-copy: Invoked with src=/home/vagrant/.ansible/tmp/ansible-tmp-1558391802.38-35465028396030/source directory_mode=None force=True remote_src=None unsafe_writes=None selevel=None seuser=None setype=None group=sync_gateway content=NOT_LOGGING_PARAMETER dest=/home/sync_gateway/sg_privkey.pem serole=None original_basename=sg_privkey.pem delimiter=None mode=0644 regexp=None owner=sync_gateway follow=True validate=None backup=False
          May 20 22:36:43 localhost ansible-setup: Invoked with filter=* gather_subset=['all'] fact_path=/etc/ansible/facts.d gather_timeout=10
          May 20 22:36:45 localhost ansible-systemd: Invoked with name=sync_gateway enabled=None daemon_reload=False state=started user=False masked=None
          May 20 22:36:45 localhost systemd: Starting Couchbase Sync Gateway server...
          May 20 22:36:45 localhost systemd: Started Couchbase Sync Gateway server.
          May 20 22:36:45 localhost bash: 2019-05-20T22:36:45.777Z [ERR] Error reading config file /home/sync_gateway/sync_gateway.json: json: unknown field "slowServerCallWarningThreshold" -- rest.ParseCommandLine() at config.go:902
          May 20 22:36:46 localhost ansible-wait_for: Invoked with state=started port=4985 delay=0 host=127.0.0.1 timeout=240 exclude_hosts=None search_regex=None path=None connect_timeout=5
          May 20 22:36:46 localhost systemd: sync_gateway.service: main process exited, code=exited, status=1/FAILURE
          May 20 22:36:46 localhost systemd: Unit sync_gateway.service entered failed state.
          

          Sridevi Saragadam It looks like there have been loads of start ups of SG on this instance - are the logs cleaned out each time? After it fails here, it starts complaining about that field, making me wonder if the first startup didn't yet have the config you were trying to test? Not sure if I'm out of date, but I can't find a reference to that specific setting... In any event, if SG bails out before it can log, the only place you'll get that is in the platform appropriate place for the process to spit out logs - in this case, as a service, to /var/log/messages. IIRC the logic here is that if we can't read the config file, we can't find out where to log to to tell you we can't read the config file, so we just use stdout/err.

          Adam Fraser Perhaps off topic, but looks like sg_debug.log is empty despite being enabled. I guess if we're not sure the logs are the same ones that might make sense (as we'd bail out during the config parse and never enable it). If the env turns out to be legit here, could you poke me to open a ticket for that?

          Show
          James Flather James Flather added a comment - Possible I'm missing something (and without ms in messages, it's difficult to perfectly align), but Ansible is looking a little guilty here: May 20 22:36:36 localhost systemd: Reloading. May 20 22:36:37 localhost systemd: Starting Couchbase Sync Gateway server... May 20 22:36:37 localhost systemd: Started Couchbase Sync Gateway server. May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.062Z ==== Couchbase Sync Gateway/2.6.0(59;d4fcbc9) EE ==== May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.062Z [INF] Logging: Console disabled May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.062Z [INF] Logging: Files to /home/sync_gateway/logs May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.066Z [INF] Starting admin server on 127.0.0.1:4985 May 20 22:36:37 localhost bash: 2019-05-20T22:36:37.068Z [INF] Starting server on 0.0.0.0:4984 ... May 20 22:36:37 localhost ansible-systemd: Invoked with name=sync_gateway enabled=None daemon_reload=False state=stopped user=False masked=None May 20 22:36:37 localhost systemd: Stopping Couchbase Sync Gateway server... May 20 22:36:37 localhost systemd: Stopped Couchbase Sync Gateway server. 2019-05-20T22:36:37.062Z ==== Couchbase Sync Gateway/2.6.0(59;d4fcbc9) EE ==== 2019-05-20T22:36:37.062Z [INF] Logging: Console disabled 2019-05-20T22:36:37.062Z [INF] Logging: Files to /home/sync_gateway/logs 2019-05-20T22:36:37.062Z [INF] Logging: Console level: none 2019-05-20T22:36:37.062Z [INF] Logging: Console keys: [HTTP] 2019-05-20T22:36:37.062Z [INF] Logging: Redaction level: none 2019-05-20T22:36:37.062Z [INF] requestedSoftFDLimit < currentSoftFdLimit (5000 < 65535) no action needed 2019-05-20T22:36:37.062Z [INF] Logging stats with frequency: 1m0s 2019-05-20T22:36:37.062Z [INF] Opening db /db as bucket "db", pool "default", server <walrus:data> 2019-05-20T22:36:37.062Z [INF] Opening Walrus database db on <walrus:data> 2019-05-20T22:36:37.062Z [WRN] Using GSI is not supported when using a walrus bucket - switching to use views. Set 'use_views':true in Sync Gateway's database config to avoid this warning. -- rest.(*ServerContext)._getOrAddDatabaseFromConfig() at server_context.go:480 2019-05-20T22:36:37.062Z [INF] Design docs for current view version (2.1) do not exist - creating... 2019-05-20T22:36:37.065Z [INF] Design docs successfully created for view version 2.1. 2019-05-20T22:36:37.065Z [INF] Verifying view availability for bucket db... 2019-05-20T22:36:37.066Z [INF] Views ready for bucket db. 2019-05-20T22:36:37.066Z [INF] delta_sync enabled=false with rev_max_age_seconds=86400 for database db 2019-05-20T22:36:37.066Z [INF] Created background task: "CleanAgedItems" with interval 1m0s 2019-05-20T22:36:37.066Z [INF] Cache: Initializing changes cache with options {ChannelCacheOptions:{ChannelCacheMinLength:50 ChannelCacheMaxLength:500 ChannelCacheAge:1m0s ChannelCacheMaxNumber:50000} CachePendingSeqMaxWait:5s CachePendingSeqMaxNum:10000 CacheSkippedSeqMaxWait:1h0m0s} 2019-05-20T22:36:37.066Z [INF] Initializing changes cache for database db 2019-05-20T22:36:37.066Z [INF] Created background task: "InsertPendingEntries" with interval 2.5s 2019-05-20T22:36:37.066Z [INF] Created background task: "CleanSkippedSequenceQueue" with interval 30m0s 2019-05-20T22:36:37.066Z [INF] DCP: Starting mutation feed on bucket db due to either channel cache mode or doc tracking (auto-import/bucketshadow) 2019-05-20T22:36:37.066Z [INF] Using default sync function 'channel(doc.channels)' for database "db" 2019-05-20T22:36:37.066Z [INF] Auth: Saved _sync:user:: &{roleImpl:{Name_: ExplicitChannels_:*:1 Channels_: Sequence_:1 PreviousChannels_: vbNo:<nil> cas:3} userImplBody:{Email_: Disabled_:false PasswordHash_:[] OldPasswordHash_:<nil> ExplicitRoles_: RolesSince_: OldExplicitRoles_:[]} auth:0xc000187c80 roles:[]} 2019-05-20T22:36:37.066Z [INF] Reset guest user to config 2019-05-20T22:36:37.066Z [INF] Starting admin server on 127.0.0.1:4985 2019-05-20T22:36:37.068Z [INF] Starting server on 0.0.0.0:4984 ... 2019-05-20T22:36:37.069Z [INF] DCP: Received #1 ("_user/") May 20 22:36:38 localhost ansible-wait_for: Invoked with state=stopped port=4985 delay=0 host=127.0.0.1 timeout=300 exclude_hosts=None search_regex=None path=None connect_timeout=5 May 20 22:36:38 localhost ansible-setup: Invoked with filter=* gather_subset=['all'] fact_path=/etc/ansible/facts.d gather_timeout=10 May 20 22:36:40 localhost ansible-stat: Invoked with checksum_algorithm=sha1 mime=False get_checksum=True path=/home/sync_gateway/sync_gateway.json checksum_algo=sha1 follow=False get_md5=False May 20 22:36:41 localhost ansible-copy: Invoked with src=/home/vagrant/.ansible/tmp/ansible-tmp-1558391800.44-80226531789367/source directory_mode=None force=True remote_src=None unsafe_writes=None selevel=None seuser=None setype=None group=sync_gateway content=NOT_LOGGING_PARAMETER dest=/home/sync_gateway/sync_gateway.json serole=None original_basename=sync_gateway_default_functional_tests_cc.json delimiter=None mode=0644 regexp=None owner=sync_gateway follow=True validate=None backup=False May 20 22:36:41 localhost ansible-command: Invoked with warn=True executable=None _uses_shell=True _raw_params=cat /home/sync_gateway/sync_gateway.json removes=None creates=None chdir=None May 20 22:36:42 localhost ansible-stat: Invoked with checksum_algorithm=sha1 mime=False get_checksum=True path=/home/sync_gateway/sg_cert.pem checksum_algo=sha1 follow=False get_md5=False May 20 22:36:42 localhost ansible-copy: Invoked with src=/home/vagrant/.ansible/tmp/ansible-tmp-1558391801.75-136965761948984/source directory_mode=None force=True remote_src=None unsafe_writes=None selevel=None seuser=None setype=None group=sync_gateway content=NOT_LOGGING_PARAMETER dest=/home/sync_gateway/sg_cert.pem serole=None original_basename=sg_cert.pem delimiter=None mode=0644 regexp=None owner=sync_gateway follow=True validate=None backup=False May 20 22:36:42 localhost ansible-stat: Invoked with checksum_algorithm=sha1 mime=False get_checksum=True path=/home/sync_gateway/sg_privkey.pem checksum_algo=sha1 follow=False get_md5=False May 20 22:36:42 localhost ansible-copy: Invoked with src=/home/vagrant/.ansible/tmp/ansible-tmp-1558391802.38-35465028396030/source directory_mode=None force=True remote_src=None unsafe_writes=None selevel=None seuser=None setype=None group=sync_gateway content=NOT_LOGGING_PARAMETER dest=/home/sync_gateway/sg_privkey.pem serole=None original_basename=sg_privkey.pem delimiter=None mode=0644 regexp=None owner=sync_gateway follow=True validate=None backup=False May 20 22:36:43 localhost ansible-setup: Invoked with filter=* gather_subset=['all'] fact_path=/etc/ansible/facts.d gather_timeout=10 May 20 22:36:45 localhost ansible-systemd: Invoked with name=sync_gateway enabled=None daemon_reload=False state=started user=False masked=None May 20 22:36:45 localhost systemd: Starting Couchbase Sync Gateway server... May 20 22:36:45 localhost systemd: Started Couchbase Sync Gateway server. May 20 22:36:45 localhost bash: 2019-05-20T22:36:45.777Z [ERR] Error reading config file /home/sync_gateway/sync_gateway.json: json: unknown field "slowServerCallWarningThreshold" -- rest.ParseCommandLine() at config.go:902 May 20 22:36:46 localhost ansible-wait_for: Invoked with state=started port=4985 delay=0 host=127.0.0.1 timeout=240 exclude_hosts=None search_regex=None path=None connect_timeout=5 May 20 22:36:46 localhost systemd: sync_gateway.service: main process exited, code=exited, status=1/FAILURE May 20 22:36:46 localhost systemd: Unit sync_gateway.service entered failed state. Sridevi Saragadam It looks like there have been loads of start ups of SG on this instance - are the logs cleaned out each time? After it fails here, it starts complaining about that field, making me wonder if the first startup didn't yet have the config you were trying to test? Not sure if I'm out of date, but I can't find a reference to that specific setting... In any event, if SG bails out before it can log, the only place you'll get that is in the platform appropriate place for the process to spit out logs - in this case, as a service, to /var/log/messages . IIRC the logic here is that if we can't read the config file, we can't find out where to log to to tell you we can't read the config file, so we just use stdout/err. Adam Fraser Perhaps off topic, but looks like sg_debug.log is empty despite being enabled. I guess if we're not sure the logs are the same ones that might make sense (as we'd bail out during the config parse and never enable it). If the env turns out to be legit here, could you poke me to open a ticket for that?
          Hide
          James Flather James Flather added a comment -

          P.S. Love having sgcollect_info on things like this - great stuff!

          Show
          James Flather James Flather added a comment - P.S. Love having sgcollect_info on things like this - great stuff!
          Hide
          ben.brooks Ben Brooks added a comment -

          Sridevi Saragadam As James pointed out, Sync Gateway is not recognizing one of the config options.

          Turns out this was removed in 2.1 in this PR but the docs haven't been updated - I've filed DOC-5260

          14:48 $ ./sync_gateway sg_config2.json
          2019-05-21T14:48:25.072+01:00 [ERR] Error reading config file sg_config2.json: json: unknown field "slowServerCallWarningThreshold" -- rest.ParseCommandLine() at config.go:902
          

           

          Show
          ben.brooks Ben Brooks added a comment - Sridevi Saragadam As James pointed out, Sync Gateway is not recognizing one of the config options. Turns out this was removed in 2.1 in this PR but the docs haven't been updated - I've filed DOC-5260 14:48 $ ./sync_gateway sg_config2.json 2019-05-21T14:48:25.072+01:00 [ERR] Error reading config file sg_config2.json: json: unknown field "slowServerCallWarningThreshold" -- rest.ParseCommandLine() at config.go:902  
          Hide
          sridevi.saragadam Sridevi Saragadam added a comment -

          After removing  "slowServerCallWarningThreshold" from SGW config, SGW worked fine.

           

          Show
          sridevi.saragadam Sridevi Saragadam added a comment - After removing  "slowServerCallWarningThreshold" from SGW config, SGW worked fine.  
          Hide
          sridevi.saragadam Sridevi Saragadam added a comment -

          fixed sgw config with new configs in cobalt which fixed it

          Show
          sridevi.saragadam Sridevi Saragadam added a comment - fixed sgw config with new configs in cobalt which fixed it

            People

            Assignee:
            sridevi.saragadam Sridevi Saragadam
            Reporter:
            sridevi.saragadam Sridevi Saragadam
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Dates

              Created:
              Updated:

                Gerrit Reviews

                There are no open Gerrit changes

                  PagerDuty