Skip to content

Dgraph service does not start without meaningful error message when 8080 used by another program #2918

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
kokizzu opened this issue Jan 21, 2019 · 3 comments
Closed

Dgraph service does not start without meaningful error message when 8080 used by another program #2918

kokizzu opened this issue Jan 21, 2019 · 3 comments
Assignees
@codexnull
Labels
exp/beginner Something most people could solve. kind/maintenance Maintenance tasks, such as refactoring, with no impact in features.

Comments

@kokizzu
Copy link
Contributor

kokizzu commented Jan 21, 2019

If you suspect this could be a bug, follow the template.

  • What version of Dgraph are you using?
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.827471   18913 init.go:88]
Jan 21 02:17:57 kiswono dgraph[18913]: Dgraph version   : v1.0.11
Jan 21 02:17:57 kiswono dgraph[18913]: Commit SHA-1     : b2a09c5b
Jan 21 02:17:57 kiswono dgraph[18913]: Commit timestamp : 2018-12-17 09:50:56 -0800
Jan 21 02:17:57 kiswono dgraph[18913]: Branch           : HEAD
Jan 21 02:17:57 kiswono dgraph[18913]: Go version       : go1.11.1
Jan 21 02:17:57 kiswono dgraph[18913]: For Dgraph official documentation, visit https://docs.dgraph.io.
Jan 21 02:17:57 kiswono dgraph[18913]: For discussions about Dgraph     , visit https://discuss.dgraph.io.
Jan 21 02:17:57 kiswono dgraph[18913]: To say hi to the community       , visit https://dgraph.slack.com.
Jan 21 02:17:57 kiswono dgraph[18913]: Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Jan 21 02:17:57 kiswono dgraph[18913]: Copyright 2015-2018 Dgraph Labs, Inc.
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.828512   18913 server.go:113] Setting Badger table load option: mmap
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.828533   18913 server.go:125] Setting Badger value log load option: mmap
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.828546   18913 server.go:153] Opening write-ahead log BadgerDB with options: {Dir:/
Jan 21 02:17:57 kiswono dgraph[18913]: badger2019/01/21 02:17:57 INFO: Replaying file id: 0 at offset: 0
Jan 21 02:17:57 kiswono dgraph[18913]: badger2019/01/21 02:17:57 INFO: Replay took: 11.376µs
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.831269   18913 server.go:113] Setting Badger table load option: mmap
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.831283   18913 server.go:125] Setting Badger value log load option: mmap
Jan 21 02:17:57 kiswono dgraph[18913]: I0121 02:17:57.831292   18913 server.go:167] Opening postings BadgerDB with options: {Dir:/var/run
Jan 21 02:17:57 kiswono dgraph[18913]: badger2019/01/21 02:17:57 INFO: Replaying file id: 0 at offset: 0
Jan 21 02:17:57 kiswono dgraph[18913]: badger2019/01/21 02:17:57 INFO: Replay took: 7.462µs
Jan 21 02:17:57 kiswono systemd[1]: dgraph.service: Main process exited, code=exited, status=1/FAILURE
Jan 21 02:17:57 kiswono systemd[1]: dgraph.service: Unit entered failed state.
Jan 21 02:17:57 kiswono systemd[1]: dgraph.service: Failed with result 'exit-code'.

while dgraph zero works fine

Jan 21 02:17:06 kiswono dgraph[18081]: I0121 02:17:06.199426   18081 raft.go:458] CID set for cluster: 5a75bf4a-96ee-4ac3-b5e9-ca759e3d0a
Jan 21 02:17:04 kiswono dgraph[18081]: W0121 02:17:04.198975   18081 node.go:550] [1] Read index context timed out
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.479107   18081 assign.go:44] Updated Lease id: 1. Txn Ts: 1
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.479094   18081 raft.go:613] I've become the leader, updating leases.
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478988   18081 node.go:83] raft.node: 1 elected leader 1 at term 2
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478979   18081 node.go:83] 1 became leader at term 2
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478954   18081 node.go:83] 1 received MsgVoteResp from 1 at term 2
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478947   18081 node.go:83] 1 became candidate at term 2
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478906   18081 node.go:83] 1 received MsgPreVoteResp from 1 at term 1
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478897   18081 node.go:83] 1 became pre-candidate at term 1
Jan 21 02:17:03 kiswono dgraph[18081]: I0121 02:17:03.478871   18081 node.go:83] 1 is starting a new election at term 1
Jan 21 02:17:03 kiswono dgraph[18081]: E0121 02:17:03.199139   18081 raft.go:464] While proposing CID: Not Zero leader. Aborting proposal
Jan 21 02:17:01 kiswono dgraph[18081]: I0121 02:17:01.198922   18081 node.go:83] 1 no leader at term 1; dropping index reading msg
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.199073   18081 run.go:265] Running Dgraph Zero...
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.199039   18081 raft.go:596] Done applying conf change at 1
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.198937   18081 node.go:173] Setting conf state to nodes:1
Jan 21 02:17:00 kiswono dgraph[18081]: E0121 02:17:00.198805   18081 raft.go:464] While proposing CID: Not Zero leader. Aborting proposal
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.198442   18081 node.go:83] 1 became follower at term 1
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.198425   18081 node.go:83] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, la
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.198351   18081 node.go:83] 1 became follower at term 0
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.198264   18081 node.go:290] Group 0 found 1 entries
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.196879   18081 node.go:151] Setting raft.Config to: &{ID:1 peers:[] learners:[] Ele
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.194426   18081 run.go:98] Setting up http listener at: 0.0.0.0:6080
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.194291   18081 run.go:98] Setting up grpc listener at: 0.0.0.0:5080
Jan 21 02:17:00 kiswono dgraph[18081]: Copyright 2015-2018 Dgraph Labs, Inc.
Jan 21 02:17:00 kiswono dgraph[18081]: Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Jan 21 02:17:00 kiswono dgraph[18081]: To say hi to the community       , visit https://dgraph.slack.com.
Jan 21 02:17:00 kiswono dgraph[18081]: For discussions about Dgraph     , visit https://discuss.dgraph.io.
Jan 21 02:17:00 kiswono dgraph[18081]: For Dgraph official documentation, visit https://docs.dgraph.io.
Jan 21 02:17:00 kiswono dgraph[18081]: Go version       : go1.11.1
Jan 21 02:17:00 kiswono dgraph[18081]: Branch           : HEAD
Jan 21 02:17:00 kiswono dgraph[18081]: Commit timestamp : 2018-12-17 09:50:56 -0800
Jan 21 02:17:00 kiswono dgraph[18081]: Commit SHA-1     : b2a09c5b
Jan 21 02:17:00 kiswono dgraph[18081]: Dgraph version   : v1.0.11
Jan 21 02:17:00 kiswono dgraph[18081]: I0121 02:17:00.193924   18081 init.go:88]
Jan 21 02:17:00 kiswono systemd[1]: Started dgraph.io zero server.

  • Have you tried reproducing the issue with latest release?
    yes

  • What is the hardware spec (RAM, OS)?
    OpenVZ Linux kiswono 2.6.32-042stab117.16 Product Roadmap #1 SMP Fri Sep 9 21:57:19 MSK 2016 x86_64 x86_64 x86_64 GNU/Linux

  • Steps to reproduce the issue (command/config used to run Dgraph).
    https://github.com/dgraph-io/dgraph/tree/master/contrib/systemd/centos

  • Expected behaviour and actual result.
    expected giving an error message like when running manually without service
    dgraph alpha --lru_mb 2048 --zero localhost:5080
@codexnull codexnull self-assigned this Jan 21, 2019
@codexnull codexnull added the kind/maintenance Maintenance tasks, such as refactoring, with no impact in features. label Jan 21, 2019
@codexnull
Copy link
Contributor

This has always annoyed me too.

@codexnull codexnull added the exp/beginner Something most people could solve. label Jan 21, 2019
@codexnull
Copy link
Contributor

After looking at this more closely, this seems to be more of an issue with systemd that with dgraph.

I reproduced the behavior above and looked at the system logs with 'journalctl' instead of 'systemctl status' and found:

an 22 16:12:48 CENTOS7 dgraph[72845]: To say hi to the community       , visit https://dgraph.slack.com.
Jan 22 16:12:48 CENTOS7 dgraph[72845]: Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Jan 22 16:12:48 CENTOS7 dgraph[72845]: Copyright 2015-2018 Dgraph Labs, Inc.
Jan 22 16:12:48 CENTOS7 systemd[1]: dgraph.service: main process exited, code=exited, status=1/FAILURE
Jan 22 16:12:48 CENTOS7 dgraph[72845]: I0122 16:12:48.852669   72845 server.go:113] Setting Badger table load option: mmap
Jan 22 16:12:48 CENTOS7 dgraph[72845]: I0122 16:12:48.852699   72845 server.go:125] Setting Badger value log load option: mmap
Jan 22 16:12:48 CENTOS7 dgraph[72845]: I0122 16:12:48.852713   72845 server.go:153] Opening write-ahead log BadgerDB with opti
Jan 22 16:12:48 CENTOS7 dgraph[72845]: 2019/01/22 16:12:48 Error while creating badger KV WAL store error: resource temporaril
Jan 22 16:12:48 CENTOS7 dgraph[72845]: Cannot acquire directory lock on "/var/run/dgraph/w".  Another process is using this Ba
Jan 22 16:12:48 CENTOS7 dgraph[72845]: github.com/dgraph-io/dgraph/vendor/github.com/dgraph-io/badger.acquireDirectoryLock
Jan 22 16:12:48 CENTOS7 dgraph[72845]: /ext-go/1/src/github.com/dgraph-io/dgraph/vendor/github.com/dgraph-io/badger/dir_unix.g
Jan 22 16:12:48 CENTOS7 dgraph[72845]: github.com/dgraph-io/dgraph/vendor/github.com/dgraph-io/badger.Open

As you can see, dgraph does output the reason why it couldn't start (badger database, not port, is already in use), but the full dgraph error message is interrupted by systemd's own error message about dgraph exiting. 'systemctl status' stops showing the log at the 'main processes exited' line so it doesn't show the actual error.

I don't know that there's anything dgraph can do to ensure this doesn't happen.

@codexnull
Copy link
Contributor

Closing due to inactivity. Please reopen if this is still a problem.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@codexnull codexnull

Labels
exp/beginner Something most people could solve. kind/maintenance Maintenance tasks, such as refactoring, with no impact in features.
Milestone
No milestone
Development

No branches or pull requests
2 participants
@kokizzu @codexnull