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

Race condition in file sync w/ spinner #160

Open
grayside opened this issue Mar 6, 2018 · 6 comments
Open

Race condition in file sync w/ spinner #160

grayside opened this issue Mar 6, 2018 · 6 comments
Labels
bug

Comments

@grayside
Copy link
Contributor

grayside commented Mar 6, 2018

Problem

A race condition in the spinner logging around the rig sync initialization is causing a panic. I've seen this once during rig development where I'd been triggering sync dozens of times, and there has been one other reported case.

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1075db2]

goroutine 1 [running]:
time.(*Ticker).Stop(0x0)
        /usr/local/go/src/time/tick.go:46 +0x22
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).Stop(0xc4200883c0, 0x0, 0x0)
        /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:197 +0x103
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).FinishWithMessage(0xc4200883c0, 0xc420013ea0, 0xc, 0xc420018c00, 0x23, 0x3, 0xc420107840)
        /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:240 +0x40
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).FinishWithSymbol(0xc4200883c0, 0xc420013ea0, 0xc, 0x0, 0x0)
        /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:235 +0x51
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).Warn(0xc4200883c0, 0xc420018c00, 0x23)
        /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:220 +0x94
github.com/phase2/rig/util.(*RigLogger).Warning(0xc4200758c0, 0x13fe190, 0x23, 0x0, 0x0, 0x0)
        /go/src/github.com/phase2/rig/util/logger.go:101 +0x186
github.com/phase2/rig/util.(*RigLogger).PrivilegeEscallationPrompt(0xc4200758c0)
        /go/src/github.com/phase2/rig/util/logger.go:149 +0xc0
github.com/phase2/rig/util.Executor.CombinedOutput(0xc4200c4840, 0x0, 0x0, 0x0, 0x0, 0x0)
        /go/src/github.com/phase2/rig/util/shell_exec.go:103 +0xf9
github.com/phase2/rig/commands.(*Machine).SetSysctl(0xc42000ebf8, 0x13fa03b, 0x1b, 0x13f1f07, 0x6, 0x0, 0x0)
        /go/src/github.com/phase2/rig/commands/machine.go:277 +0x27b
github.com/phase2/rig/commands.(*ProjectSync).StartUnisonSync(0xc42000ebe0, 0xc4200c46e0, 0xc42016e0c0, 0x11, 0xc420166120, 0xc4200186f0, 0x20, 0x0, 0xc420107860)
        /go/src/github.com/phase2/rig/commands/project_sync.go:123 +0x73
github.com/phase2/rig/commands.(*ProjectSync).RunStart(0xc42000ebe0, 0xc4200c46e0, 0xc420140ef0, 0xc42009ebb0)
        /go/src/github.com/phase2/rig/commands/project_sync.go:116 +0x277
github.com/phase2/rig/commands.(*ProjectSync).RunStart-fm(0xc4200c46e0, 0x0, 0x0)
        /go/src/github.com/phase2/rig/commands/project_sync.go:72 +0x34
github.com/phase2/rig/vendor/github.com/urfave/cli.HandleAction(0x1379ce0, 0xc420140000, 0xc4200c46e0, 0xc420166000, 0x0)
        /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:490 +0xd2
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.Run(0x13f3419, 0xa, 0x0, 0x0, 0xc420140010, 0x1, 0x1, 0x1402a0d, 0x2f, 0x0, ...)
        /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:210 +0xa95
github.com/phase2/rig/vendor/github.com/urfave/cli.(*App).RunAsSubcommand(0xc4200116c0, 0xc4200c4420, 0x0, 0x0)
        /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:379 +0xa7b
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.startApp(0x13f259d, 0x7, 0x0, 0x0, 0xc420047fc0, 0x1, 0x1, 0x13fb8b2, 0x1e, 0x0, ...)
        /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:298 +0x944
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.Run(0x13f259d, 0x7, 0x0, 0x0, 0xc420047fc0, 0x1, 0x1, 0x13fb8b2, 0x1e, 0x0, ...)
        /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:98 +0x1319
github.com/phase2/rig/vendor/github.com/urfave/cli.(*App).Run(0xc4200111e0, 0xc42000e140, 0x5, 0x5, 0x0, 0x0)
        /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:255 +0x6f8
main.main()
        /go/src/github.com/phase2/rig/cmd/main.go:64 +0x12b1

Solution

Figure out why this is happening and fix that? Failing this, find the right spot to drop a recover statement to re-start the sync since most runs don't hit this problem.
@grayside grayside added the bug label Mar 6, 2018
@tekante
Copy link
Member

tekante commented May 22, 2018

Note that simply re-running the desired command is usually ok and avoids this issue since it is a race condition.

@tjheffner
Copy link

I am able to semi-reliably reproduce this error with these steps:

  • use rig for day to day tasks (currently 3 projects running)
  • don't stop dev machine before ending the day, so rig is still running while computer sleeps
  • sometime during the computer's sleep, rig project sync dies but the rig instance/dev machine is still running
  • next day notice project link (e.g. www.project.vm) can't be reached, try to run "rig project up" in an existing terminal window
  • see this error:
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1072502]

goroutine 1 [running]:
time.(*Ticker).Stop(0x0)
    /usr/local/go/src/time/tick.go:46 +0x22
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).Stop(0xc4200a83c0, 0x0, 0x0)
    /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:197 +0xe6
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).FinishWithMessage(0xc4200a83c0, 0xc420089b60, 0xc, 0xc420086c60, 0x23, 0x3, 0xc4201336e0)
    /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:240 +0x40
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).FinishWithSymbol(0xc4200a83c0, 0xc420089b60, 0xc, 0x0, 0x0)
    /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:235 +0x51
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).Warn(0xc4200a83c0, 0xc420086c60, 0x23)
    /go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:220 +0x8a
github.com/phase2/rig/util.(*RigLogger).Warning(0xc420083980, 0x13f71c1, 0x23, 0x0, 0x0, 0x0)
    /go/src/github.com/phase2/rig/util/logger.go:126 +0x17c
github.com/phase2/rig/util.(*RigLogger).PrivilegeEscallationPrompt(0xc420083980)
    /go/src/github.com/phase2/rig/util/logger.go:176 +0xb6
github.com/phase2/rig/util.Executor.CombinedOutput(0xc4200f0c60, 0x0, 0x0, 0x0, 0x0, 0x0)
    /go/src/github.com/phase2/rig/util/shell_exec.go:103 +0xe2
github.com/phase2/rig/commands.(*Machine).SetSysctl(0xc420096b58, 0x13f2dbc, 0x1b, 0x13ea825, 0x6, 0x1362b60, 0xc42016ee70)
    /go/src/github.com/phase2/rig/commands/machine.go:277 +0x254
github.com/phase2/rig/commands.(*ProjectSync).StartUnisonSync(0xc420096b40, 0xc4200f0b00, 0xc4201a3740, 0x11, 0xc420157a40, 0xc4200eea80, 0x27, 0x0, 0xc420133700)
    /go/src/github.com/phase2/rig/commands/project_sync.go:125 +0x9b
github.com/phase2/rig/commands.(*ProjectSync).RunStart(0xc420096b40, 0xc4200f0b00, 0xc42016ed20, 0xc4200c0bb0)
    /go/src/github.com/phase2/rig/commands/project_sync.go:116 +0x264
github.com/phase2/rig/commands.(*ProjectSync).RunStart-fm(0xc4200f0b00, 0x0, 0x0)
    /go/src/github.com/phase2/rig/commands/project_sync.go:72 +0x34
github.com/phase2/rig/vendor/github.com/urfave/cli.HandleAction(0x136ec00, 0xc42007fe80, 0xc4200f0b00, 0xc420157900, 0x0)
    /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:490 +0xc8
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.Run(0x13ebdd9, 0xa, 0x0, 0x0, 0xc42007fe90, 0x1, 0x1, 0x13fbfc8, 0x2f, 0x0, ...)
    /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:210 +0xa36
github.com/phase2/rig/vendor/github.com/urfave/cli.(*App).RunAsSubcommand(0xc42008d380, 0xc4200f0840, 0x0, 0x0)
    /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:379 +0xa10
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.startApp(0x13eaf10, 0x7, 0x0, 0x0, 0xc42007fe40, 0x1, 0x1, 0x13f46de, 0x1e, 0x0, ...)
    /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:298 +0x8d9
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.Run(0x13eaf10, 0x7, 0x0, 0x0, 0xc42007fe40, 0x1, 0x1, 0x13f46de, 0x1e, 0x0, ...)
    /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:98 +0x1246
github.com/phase2/rig/vendor/github.com/urfave/cli.(*App).Run(0xc42008cea0, 0xc420082090, 0x3, 0x3, 0x0, 0x0)
    /go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:255 +0x6a0
main.main()
    /go/src/github.com/phase2/rig/cmd/main.go:70 +0x13df
Error [COMMAND-ERROR]

i generally then run rig stop, rig start, eval "$(rig config)" and everything works just fine

@dnmurray dnmurray mentioned this issue Jun 9, 2018
Merged
@dnmurray
Copy link
Contributor

dnmurray commented Jun 9, 2018

I think I found it: slok/gospinner#3

@dnmurray dnmurray mentioned this issue Jun 19, 2018
Merged
@tekante
Copy link
Member

tekante commented Jun 23, 2018

Believe this fixed with #173 which should be out with the 2.2.0 release which is now available as an RC

@tekante tekante closed this as completed Jun 23, 2018
@tekante
Copy link
Member

tekante commented Jul 27, 2018

Looks like the firx with gospinner hasn't been completely successful in resolving this issue. I just received the following on a rig project sync:start command with version 2.2.20-rc2

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1071712]

goroutine 1 [running]:
time.(*Ticker).Stop(0x0)
	/usr/local/go/src/time/tick.go:46 +0x22
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).Stop(0xc4200923c0, 0x0, 0x0)
	/go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:197 +0xe6
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).FinishWithMessage(0xc4200923c0, 0xc4200197e0, 0xc, 0xc4200166f0, 0x23, 0x3, 0xc4201194c0)
	/go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:240 +0x40
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).FinishWithSymbol(0xc4200923c0, 0xc4200197e0, 0xc, 0x0, 0x0)
	/go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:235 +0x51
github.com/phase2/rig/vendor/github.com/slok/gospinner.(*Spinner).Warn(0xc4200923c0, 0xc4200166f0, 0x23)
	/go/src/github.com/phase2/rig/vendor/github.com/slok/gospinner/spinner.go:220 +0x8a
github.com/phase2/rig/util.(*RigLogger).Warning(0xc42000f9e0, 0x13fb44f, 0x23, 0x0, 0x0, 0x0)
	/go/src/github.com/phase2/rig/util/logger.go:126 +0x17c
github.com/phase2/rig/util.(*RigLogger).PrivilegeEscalationPrompt(0xc42000f9e0)
	/go/src/github.com/phase2/rig/util/logger.go:176 +0xb6
github.com/phase2/rig/util.Executor.CombinedOutput(0xc4200d69a0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/go/src/github.com/phase2/rig/util/shell_exec.go:134 +0xe2
github.com/phase2/rig/commands.(*Machine).SetSysctl(0xc420086dd8, 0x13f6f44, 0x1b, 0x13ee7cf, 0x6, 0x4, 0x3)
	/go/src/github.com/phase2/rig/commands/machine.go:277 +0x254
github.com/phase2/rig/commands.(*ProjectSync).StartUnisonSync(0xc420086dc0, 0xc4200d6840, 0xc42017a820, 0x11, 0xc42013ec60, 0xc42001c870, 0x39, 0x0, 0x0)
	/go/src/github.com/phase2/rig/commands/project_sync.go:316 +0x9b
github.com/phase2/rig/commands.(*ProjectSync).RunStart(0xc420086dc0, 0xc4200d6840, 0xc42016a8c0, 0xc4200aaba8)
	/go/src/github.com/phase2/rig/commands/project_sync.go:167 +0x1ee
github.com/phase2/rig/commands.(*ProjectSync).RunStart-fm(0xc4200d6840, 0x0, 0x0)
	/go/src/github.com/phase2/rig/commands/project_sync.go:71 +0x34
github.com/phase2/rig/vendor/github.com/urfave/cli.HandleAction(0x1372720, 0xc42004fb70, 0xc4200d6840, 0xc42013eb00, 0x0)
	/go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:490 +0xc8
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.Run(0x13efdbd, 0xa, 0x0, 0x0, 0xc42004fb80, 0x1, 0x1, 0x1400395, 0x2f, 0x0, ...)
	/go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:210 +0xa36
github.com/phase2/rig/vendor/github.com/urfave/cli.(*App).RunAsSubcommand(0xc42007f1e0, 0xc4200d6580, 0x0, 0x0)
	/go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:379 +0xa10
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.startApp(0x13eeeb3, 0x7, 0x0, 0x0, 0xc42004fb30, 0x1, 0x1, 0x13f892b, 0x1e, 0x0, ...)
	/go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:298 +0x8d9
github.com/phase2/rig/vendor/github.com/urfave/cli.Command.Run(0x13eeeb3, 0x7, 0x0, 0x0, 0xc42004fb30, 0x1, 0x1, 0x13f892b, 0x1e, 0x0, ...)
	/go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/command.go:98 +0x1246
github.com/phase2/rig/vendor/github.com/urfave/cli.(*App).Run(0xc42007eea0, 0xc42000e0c0, 0x3, 0x3, 0x0, 0x0)
	/go/src/github.com/phase2/rig/vendor/github.com/urfave/cli/app.go:255 +0x6a0
main.main()
	/go/src/github.com/phase2/rig/cmd/main.go:71 +0x1545

@tekante tekante reopened this Jul 27, 2018
@mike-potter
Copy link
Member

Just to add...I have also gotten this seg fault in the rc2 version.

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

No branches or pull requests
5 participants
@tekante @grayside @mike-potter @dnmurray @tjheffner