Skip to content
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

broken gitbase service when creating indexes #383

Open
dpordomingo opened this issue Mar 28, 2019 · 8 comments
Open

broken gitbase service when creating indexes #383

dpordomingo opened this issue Mar 28, 2019 · 8 comments
Labels
bug Something isn't working

Comments

@dpordomingo
Copy link
Contributor

using srcd/gitbase:v0.19.0 and running

$ srcd sql "CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)"

over a 7495 repositories dataset, I got this error in container logs:

$ docker logs -f  srcd-cli-gitbase
...
time="2019-03-28T08:11:24Z" level=info msg="NewConnection: client 16"
time="2019-03-28T08:11:24Z" level=info msg="audit trail" action=authentication address="172.28.0.2:36346" success=true system=audit user=root
time="2019-03-28T08:11:24Z" level=debug msg="executing query" query="CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)"
time="2019-03-28T08:11:24Z" level=info msg="audit trail" action=authorization address="172.28.0.2:36346" connection_id=16 permission="read, write" pid=16 query="CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)" success=true system=audit user=root
time="2019-03-28T08:11:27Z" level=info msg="starting to save the index" async=true driver=pilosa id=repo_idx
time="2019-03-28T08:11:27Z" level=info msg="audit trail" action=query address="172.28.0.2:36346" connection_id=16 duration=3.107514097s pid=16 query="CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)" success=true system=audit user=root
...
time="2019-03-28T08:12:45Z" level=debug msg="still creating index" driver=pilosa duration=1.358409ms id=repo_idx rows=10000
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x58 pc=0x9a1437]

goroutine 22572 [running]:
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*loggingKeyValueIter).Next(0xc0abdc15e0, 0xc057f07020, 0x0, 0x270e, 0xc0c74d4630, 0x2d, 0x30, 0x0, 0x0)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:501 +0x187
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa.(*Driver).savePartition(0xc00120f9a0, 0xc05ed66d20, 0x14cfc40, 0xc02b2f08f0, 0x14d4060, 0xc0abdc15e0, 0xc0adf3cd80, 0xc0b378aa40, 0x270e, 0xc002ba1c08, ...)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa/driver.go:273 +0x451
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa.(*Driver).Save(0xc00120f9a0, 0xc05ed66d20, 0x14e83a0, 0xc0adf3cd80, 0x14d40a0, 0xc0068c5aa0, 0x0, 0x0)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa/driver.go:358 +0x515
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*CreateIndex).createIndex(0xc001fd58f0, 0xc05871ea00, 0xc082368540, 0x14e2780, 0xc00120f9a0, 0x14e83a0, 0xc0adf3cd80, 0x14d3e60, 0xc082366aa0, 0xc07f897620, ...)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:207 +0x46e
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*CreateIndex).RowIter.func1()
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:174 +0x92
created by github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*CreateIndex).RowIter
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:181 +0x866

Next time I run a sql query, container logs says:


```shell
$ docker logs -f  srcd-cli-gitbase
...
time="2019-03-28T08:18:37Z" level=warning msg="could not read index file, index is corrupt and will be deleted" db=gitbase dir=/var/lib/gitbase/index/pilosa/gitbase/repositories/repo_idx err="<nil>" id=repo_idx table=repositories
...
@dpordomingo dpordomingo added the bug Something isn't working label Mar 28, 2019
@carlosms
Copy link
Contributor

Is this caused by the way we deploy the containers in engine? it looks like it's a problem in gitbase.
@src-d/data-processing should we transfer this issue to the gitbase repo?

@kuba--
Copy link

kuba-- commented Mar 28, 2019 •
edited
Loading

yeah, looks like it was in mysql: plan.(*loggingKeyValueIter).Next
Can you give some details (repo) how to reproduce it, or if it happens just in docker, how did you mount volumes?
Please move this issue to mysql-server.

@erizocosmico
Copy link
Contributor

By the log message err="<nil>" and the place where it happens, this seems like a case of "nil is not nil" and then when err.Error() is called, it panics.

@dpordomingo
Copy link
Contributor Author

I got the same error with plain srcd/gitbase:v0.19.0 image over a dataset of 7495 siva files, as it follows

$ docker run --rm --name gitbase -p 3306:3306 -v /repos:/opt/repos srcd/gitbase:v0.19.0

time="2019-03-28T11:49:43Z" level=debug msg="repository added" path=/opt/repos/00/002177a3ddfaba267e7a0a108839932e73855e4d.siva
time="2019-03-28T11:49:43Z" level=debug msg="repository added" path=/opt/repos/00/00269a8f9304aa4ee45794890b9cb38dbfc647be.siva
...
time="2019-03-28T11:49:43Z" level=debug msg="registered database to catalog" db=gitbase
time="2019-03-28T11:49:43Z" level=debug msg="registered all available functions in catalog"
time="2019-03-28T11:49:43Z" level=debug msg="created index storage"
time="2019-03-28T11:49:43Z" level=debug msg="registered pilosa index driver"
time="2019-03-28T11:49:43Z" level=info msg="squash tables rule is enabled"
time="2019-03-28T11:50:08Z" level=info msg="server started and listening on 0.0.0.0:3306"
...
time="2019-03-28T11:51:18Z" level=info msg="NewConnection: client 1"
time="2019-03-28T11:51:18Z" level=error msg="Error parsing auth server config: unexpected end of JSON input"
time="2019-03-28T11:51:18Z" level=info msg="audit trail" action=authentication address="172.17.0.1:55398" success=true system=audit user=root
time="2019-03-28T11:51:18Z" level=debug msg="executing query" query="select @@version_comment limit 1"
time="2019-03-28T11:51:18Z" level=info msg="audit trail" action=authorization address="172.17.0.1:55398" connection_id=1 permission=read pid=1 query="select @@version_comment limit 1" success=true system=audit user=root
time="2019-03-28T11:51:18Z" level=info msg="audit trail" action=query address="172.17.0.1:55398" connection_id=1 duration=2.198346ms pid=1 query="select @@version_comment limit 1" success=true system=audit user=root
time="2019-03-28T11:51:18Z" level=debug msg="executing query" query="CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)"
time="2019-03-28T11:51:18Z" level=info msg="audit trail" action=authorization address="172.17.0.1:55398" connection_id=1 permission="read, write" pid=2 query="CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)" success=true system=audit user=root
time="2019-03-28T11:51:19Z" level=info msg="starting to save the index" async=true driver=pilosa id=repo_idx
time="2019-03-28T11:51:19Z" level=info msg="audit trail" action=query address="172.17.0.1:55398" connection_id=1 duration=1.981242092s pid=2 query="CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)" success=true system=audit user=root
time="2019-03-28T11:51:19Z" level=info msg="ConnectionClosed: client 1"
time="2019-03-28T11:52:26Z" level=debug msg="still creating index" driver=pilosa duration="608.387µs" id=repo_idx rows=10000
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x58 pc=0x9a1437]

goroutine 39 [running]:
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*loggingKeyValueIter).Next(0xc0010698b0, 0xc0016a06c0, 0x0, 0x270e, 0xc00142a660, 0x2d, 0x30, 0x0, 0x0)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:501 +0x187
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa.(*Driver).savePartition(0xc00101afe0, 0xc00169c000, 0x14cfc40, 0xc00101b140, 0x14d4060, 0xc0010698b0, 0xc0011ce080, 0xc000ec16c0, 0x270e, 0xc001575c08, ...)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa/driver.go:273 +0x451
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa.(*Driver).Save(0xc00101afe0, 0xc00169c000, 0x14e83a0, 0xc0011ce080, 0x14d40a0, 0xc001130090, 0x0, 0x0)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/index/pilosa/driver.go:358 +0x515
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*CreateIndex).createIndex(0xc00022d030, 0xc0014d2eb0, 0xc0013213e0, 0x14e2780, 0xc00101afe0, 0x14e83a0, 0xc0011ce080, 0x14d3e60, 0xc00187b0e0, 0xc001746de0, ...)
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:207 +0x46e
github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*CreateIndex).RowIter.func1()
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:174 +0x92
created by github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan.(*CreateIndex).RowIter
	/go/src/github.com/src-d/gitbase/vendor/gopkg.in/src-d/go-mysql-server.v0/sql/plan/create_index.go:181 +0x866

And here is the command that causes the panic.

mysql --port=3306 --user=root --host=127.0.0.1 --execute "CREATE INDEX repo_idx ON repositories USING pilosa (repository_id)"

@kuba--
Copy link

kuba-- commented Mar 28, 2019

@dpordomingo - I need some repo, so I'll try to reproduce it locally.
So far, based on 10 repos from PGA I could not reproduce it.

@dpordomingo
Copy link
Contributor Author

I ran borges to get those 7k repos... I'm not sure if you're interested in downloading them, or if I could run any command to get more logs from my laptop.
Or we can even wait till there is a new release in gitbase, because I saw you did a lot of changes and maybe one of them fixed this problem.

@kuba--
Copy link

kuba-- commented Mar 29, 2019

I don't need repos (maybe just command how did you get them). Maybe it's fixed on the master, but from the log it looks that in happen in LogKV in open tracing, so maybe you got io.EOF and somehow lost connection with jagger caused that segfault, but this is just guessing

@dpordomingo
Copy link
Contributor Author

This is the list of repos that I retrieved with borges
repos.todo.clean.log

  • 86GB
  • 7493 siva files
  • 8004 remotes
  • ~3h downloading

I only fetched HEAD, so no prs, no tags, no strange branches...
To do so, I used a slightly modified version of borges, that can be also started with docker-compose

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@erizocosmico @carlosms @dpordomingo @kuba--