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.

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

fatal error: sync: Unlock of unlocked RWMutex #300

Open
OfekShochat opened this issue Mar 17, 2022 · 30 comments
Open

fatal error: sync: Unlock of unlocked RWMutex #300

OfekShochat opened this issue Mar 17, 2022 · 30 comments
Labels
bug Something isn't working
Milestone

Comments

@OfekShochat
Copy link

OfekShochat commented Mar 17, 2022

hello!
Ive looked at gemini quite some time ago, and looking back at it, its gotten really cool. though when I tried to open amfora after installing it in arch (tried both the amfora-git and amfora packages) I got this traceback:

atal error: sync: Unlock of unlocked RWMutex

goroutine 1 [running]:
runtime.throw({0xba92b1?, 0x5553dd?})
	/usr/lib/go/src/runtime/panic.go:992 +0x71 fp=0xc000207d80 sp=0xc000207d50 pc=0x432f31
sync.throw({0xba92b1?, 0x5693ba?})
	/usr/lib/go/src/runtime/panic.go:978 +0x1e fp=0xc000207da0 sp=0xc000207d80 pc=0x45dd3e
sync.(*RWMutex).Unlock(0xc00032500c)
	/usr/lib/go/src/sync/rwmutex.go:201 +0x4a fp=0xc000207dd8 sp=0xc000207da0 pc=0x47746a
code.rocketnine.space/tslocum/cview.(*Application).Init.func1()
	/home/ghostway/go/pkg/mod/code.rocketnine.space/tslocum/cview@v1.5.6-0.20210530175404-7e8817f20bdc/application.go:225 +0x26 fp=0xc000207df0 sp=0xc000207dd8 pc=0x569286
code.rocketnine.space/tslocum/cview.(*Application).Init(0xc000324f00)
	/home/ghostway/go/pkg/mod/code.rocketnine.space/tslocum/cview@v1.5.6-0.20210530175404-7e8817f20bdc/application.go:226 +0x98 fp=0xc000207e40 sp=0xc000207df0 pc=0x569218
main.main()
	/home/ghostway/.cache/paru/clone/amfora-git/src/amfora/amfora.go:76 +0x594 fp=0xc000207f80 sp=0xc000207e40 pc=0xa72594
runtime.main()
	/usr/lib/go/src/runtime/proc.go:250 +0x212 fp=0xc000207fe0 sp=0xc000207f80 pc=0x435652
runtime.goexit()
	/usr/lib/go/src/runtime/asm_amd64.s:1571 +0x1 fp=0xc000207fe8 sp=0xc000207fe0 pc=0x462401

goroutine 18 [sleep]:
time.Sleep(0x1a3185c5000)
	/usr/lib/go/src/runtime/time.go:194 +0x12e
github.com/makeworld-the-better-one/amfora/subscriptions.Init.func1()
	/home/ghostway/.cache/paru/clone/amfora-git/src/amfora/subscriptions/subscriptions.go:79 +0x3d
created by github.com/makeworld-the-better-one/amfora/subscriptions.Init
	/home/ghostway/.cache/paru/clone/amfora-git/src/amfora/subscriptions/subscriptions.go:76 +0x2a5

the same thing is happening when compiling from source.
thanks aot

@makew0rld
Copy link
Owner

Thanks for reporting, this is a strange bug and I can't reproduce it. Never seen it before. Can you show the output of amfora -v so I can see what version you're running?

@makew0rld makew0rld added bug Something isn't working question Further information is requested labels Mar 17, 2022
@OfekShochat
Copy link
Author

OfekShochat commented Mar 17, 2022

Amfora v1.9.2-27-gea9c7f2
Commit: ea9c7f214a06138e064992fdf6f7a1cdddb522f7
Built by: Makefile

It's the latest one

@OfekShochat

This comment was marked as spam.

@alexsavage
Copy link

Same on freebsd 13.0 on arm64, using either the v1.9.2 pkg binary or building from source myself.

% uname -a
FreeBSD pebbles 13.0-RELEASE-p6 FreeBSD 13.0-RELEASE-p6 #0: Mon Jan 10 06:33:27 UTC 2022     root@arm64-builder.daemonology.net:/usr/obj/usr/src/arm64.aarch64/sys/GENERIC  arm64
% amfora -v
Amfora v1.9.2
Commit: 61d8645
Built by: unknown
% amfora
fatal error: sync: Unlock of unlocked RWMutex

goroutine 1 [running]:
runtime.throw({0x4ad6ab, 0x20})
        runtime/panic.go:1198 +0x54 fp=0x40001cdd60 sp=0x40001cdd30 pc=0x45fe4
sync.throw({0x4ad6ab, 0x20})
        runtime/panic.go:1184 +0x30 fp=0x40001cdd80 sp=0x40001cdd60 pc=0x73650
sync.(*RWMutex).Unlock(0x400022688c)
        sync/rwmutex.go:142 +0x88 fp=0x40001cddc0 sp=0x40001cdd80 pc=0x8c6f8
code.rocketnine.space/tslocum/cview.(*Application).Init(0x4000226780)
        code.rocketnine.space/tslocum/cview@v1.5.6-0.20210530175404-7e8817f20bdc/application.go:226 +0x8c fp=0x40001cde10 sp=0x40001cddc0 pc=0x179e1c
main.main()
        github.com/makeworld-the-better-one/amfora/amfora.go:71 +0x6ac fp=0x40001cdf70 sp=0x40001cde10 pc=0x3d4ccc
runtime.main()
        runtime/proc.go:255 +0x284 fp=0x40001cdfd0 sp=0x40001cdf70 pc=0x48884
runtime.goexit()
        runtime/asm_arm64.s:1133 +0x4 fp=0x40001cdfd0 sp=0x40001cdfd0 pc=0x77b94

goroutine 6 [runnable]:
github.com/makeworld-the-better-one/amfora/subscriptions.(*jsonData).RUnlock(0x893780)
        github.com/makeworld-the-better-one/amfora/subscriptions/structs.go:62 +0xdc
github.com/makeworld-the-better-one/amfora/subscriptions.updateAll()
        github.com/makeworld-the-better-one/amfora/subscriptions/subscriptions.go:393 +0x108
github.com/makeworld-the-better-one/amfora/subscriptions.Init.func1()
        github.com/makeworld-the-better-one/amfora/subscriptions/subscriptions.go:78 +0x20
created by github.com/makeworld-the-better-one/amfora/subscriptions.Init
        github.com/makeworld-the-better-one/amfora/subscriptions/subscriptions.go:76 +0x3f0

@makew0rld
Copy link
Owner

@alexsavage thanks for that output, that should be enough for me to fix this issue. Concerning it's happening even with v1.9.2. I will look into it and try to fix it tomorrow evening (March 23).

@makew0rld
Copy link
Owner

makew0rld commented Mar 23, 2022

@OfekShochat @alexsavage could you answer some questions to help me understand the bug? I've been looking into it but it's tricky.

  1. Does the crash occur immediately after running Amfora, or after the screen opening or some length of time?
  2. Does the crash occur consistently every time you open Amfora, or somewhat randomly?

I would also appreciate if you both could share your subscriptions.json and config.toml file. On *nix those files are stored at ~/.local/share/amfora/subscriptions.json and ~/.config/amfora/config.toml. Note that your subscriptions may contain data you wish to keep private, so take a look before sharing.

This hopefully will help me track down why this is occurring. Confused at the moment.

@OfekShochat
Copy link
Author

OfekShochat commented Mar 24, 2022

Instantly and consistantly. Ive just built it, no further config. I can try and gdb it which will give you more info than you're asking, though it might take some time for me (not at home). But I'm confused as you are, but I'm not that familiar with go's internals (when does it lock? When does it unlock? Why does it even unlock if it didn't lock? Afaik it doesnt schedule it like a async runtime which would make sense, somewhat, to lock on time.Sleep). It would maybe make sense on viper.getInt cuz it has to lock to get the shared(?) memory. And then if this is true, it might be a go issue.
Edit realized that gdb won't really help here

@OfekShochat
Copy link
Author

Hmm, seems like the problem solved itself? I had many disk related issues in the last week but well idk. I'm going to leave this issue open though

@makew0rld
Copy link
Owner

Instantly and consistantly. Ive just built it, no further config.

Thanks. So sounds like you have no subscriptions and the default config. Really not sure why this is happening then.

Hmm, seems like the problem solved itself?

Wow, it no longer appears? Let me know if it comes back or if you can figure out what is causing it.

I'm going to leave this issue open though

Yes thanks. I'd like to continue debugging with @alexsavage to get this fixed.

@makew0rld makew0rld added the help wanted Extra attention is needed label Mar 24, 2022
@alexsavage
Copy link

alexsavage commented Mar 25, 2022

This is on a clean user with no amfora files - here is the config.toml that got dropped. I don’t have a subscriptions.json file at all, though!
config.toml

On the “disk slow” thought - I am running on a Raspberry Pi 4, not slow but not a high end server or anything. Perhaps there is a race condition between some of the default files being created, and the startup?

@makew0rld
Copy link
Owner

Thanks for sharing your config. Of course it's just the default one because it's a fresh install, so I'm not sure if there's many clues there.

I don’t have a subscriptions.json file at all, though!

That makes sense, it's only created once you add a subscription.

I tried running Amfora v1.9.2 on my computer, no config file and no subscriptions file, and I still can't replicate this. Frustrating.

Perhaps there is a race condition between some of the default files being created, and the startup?

I don't think so, I can't see where that would happen. I guess it's possible though, and @OfekShochat did mention disk issues above.

Could you try this binary instead? Just built this myself, just want to sanity check this isn't some strange build issue. Don't expect it will be.

amfora_v1.9.2_freebsd_arm64.zip

@alexsavage
Copy link

Okay, on to something! The pkg distribution, my own build from source, and your build all run outside tmux just fine, but are crashing when run under tmux, along with tip of trunk.

Looks like when TERM=tmux-256color is when I get the crash.

asavage@pebbles ~ % amfora -v
Amfora v1.9.2
Commit: 61d8645
Built by: unknown
asavage@pebbles ~ % amfora
asavage@pebbles ~ % export TERM=tmux-256color
asavage@pebbles ~ % amfora
fatal error: sync: Unlock of unlocked RWMutex

goroutine 1 [running]:
runtime.throw({0x4ad6ab, 0x20})
        runtime/panic.go:1198 +0x54 fp=0x40001cbd60 sp=0x40001cbd30 pc=0x45fe4
sync.throw({0x4ad6ab, 0x20})
        runtime/panic.go:1184 +0x30 fp=0x40001cbd80 sp=0x40001cbd60 pc=0x73650
sync.(*RWMutex).Unlock(0x40001f0b0c)
        sync/rwmutex.go:142 +0x88 fp=0x40001cbdc0 sp=0x40001cbd80 pc=0x8c6f8
code.rocketnine.space/tslocum/cview.(*Application).Init(0x40001f0a00)
        code.rocketnine.space/tslocum/cview@v1.5.6-0.20210530175404-7e8817f20bdc/application.go:226 +0x8c fp=0x40001cbe10 sp=0x40001cbdc0 pc=0x179e1c
main.main()
        github.com/makeworld-the-better-one/amfora/amfora.go:71 +0x6ac fp=0x40001cbf70 sp=0x40001cbe10 pc=0x3d4ccc
runtime.main()
        runtime/proc.go:255 +0x284 fp=0x40001cbfd0 sp=0x40001cbf70 pc=0x48884
runtime.goexit()
        runtime/asm_arm64.s:1133 +0x4 fp=0x40001cbfd0 sp=0x40001cbfd0 pc=0x77b94

goroutine 6 [runnable]:
github.com/makeworld-the-better-one/amfora/subscriptions.(*jsonData).RUnlock(0x893780)
        github.com/makeworld-the-better-one/amfora/subscriptions/structs.go:62 +0xdc
github.com/makeworld-the-better-one/amfora/subscriptions.updateAll()
        github.com/makeworld-the-better-one/amfora/subscriptions/subscriptions.go:393 +0x108
github.com/makeworld-the-better-one/amfora/subscriptions.Init.func1()
        github.com/makeworld-the-better-one/amfora/subscriptions/subscriptions.go:78 +0x20
created by github.com/makeworld-the-better-one/amfora/subscriptions.Init
        github.com/makeworld-the-better-one/amfora/subscriptions/subscriptions.go:76 +0x3f0

@makew0rld
Copy link
Owner

Thanks for this info. I think I've figured a lot of this out. You don't have to read all this, but I'm documenting the cause of the bug here. Check down at the bottom for a fix for you to try.


The second section of the stack trace, such as goroutine 6 [runnable] in your latest post, is a red herring. It's just what happens to be running at the time, so when the crash happens in another goroutine (the first section of the stack trace) it also crashes.

Here, I was able to get my own similar crash by running Amfora v1.9.2 in a chroot (unrelated goroutines removed):

➤ cp amfora tmp && sudo chroot tmp /amfora
fatal error: sync: Unlock of unlocked RWMutex

goroutine 1 [running]:
runtime.throw({0x8c1317?, 0x54e85d?})
	/usr/lib/go/src/runtime/panic.go:992 +0x71 fp=0xc0001d1d78 sp=0xc0001d1d48 pc=0x432f31
sync.throw({0x8c1317?, 0x56283a?})
	/usr/lib/go/src/runtime/panic.go:978 +0x1e fp=0xc0001d1d98 sp=0xc0001d1d78 pc=0x45dd3e
sync.(*RWMutex).Unlock(0xc00022a88c)
	/usr/lib/go/src/sync/rwmutex.go:201 +0x4a fp=0xc0001d1dd0 sp=0xc0001d1d98 pc=0x4773aa
code.rocketnine.space/tslocum/cview.(*Application).Init.func1()
	/home/makeworld/go/pkg/mod/code.rocketnine.space/tslocum/cview@v1.5.6-0.20210530175404-7e8817f20bdc/application.go:225 +0x26 fp=0xc0001d1de8 sp=0xc0001d1dd0 pc=0x562706
code.rocketnine.space/tslocum/cview.(*Application).Init(0xc00022a780)
	/home/makeworld/go/pkg/mod/code.rocketnine.space/tslocum/cview@v1.5.6-0.20210530175404-7e8817f20bdc/application.go:226 +0x98 fp=0xc0001d1e38 sp=0xc0001d1de8 pc=0x562698
main.main()
	/home/makeworld/go/src/github.com/makeworld-the-better-one/amfora/amfora.go:71 +0x59b fp=0xc0001d1f80 sp=0xc0001d1e38 pc=0x7f169b
runtime.main()
	/usr/lib/go/src/runtime/proc.go:250 +0x212 fp=0xc0001d1fe0 sp=0xc0001d1f80 pc=0x435652
runtime.goexit()
	/usr/lib/go/src/runtime/asm_amd64.s:1571 +0x1 fp=0xc0001d1fe8 sp=0xc0001d1fe0 pc=0x462401

The stack trace leads me to cview, an upstream dependency used as a terminal framework. Specifically application.go. This code initializes the terminal among other things, using a low-level terminal library called tcell.

Here is the relevant code (note the lines matching the stack trace): https://code.rocketnine.space/tslocum/cview/src/commit/7e8817f20bdc/application.go#L223-L243

func (a *Application) Init() error {
	a.Lock()
	defer a.Unlock()
	return a.init()
}

func (a *Application) init() error {
	if a.screen != nil {
		return nil
	}

	var err error
	a.screen, err = tcell.NewScreen()
	if err != nil {
		a.Unlock()
		return err
	}
	if err = a.screen.Init(); err != nil {
		a.Unlock()
		return err
	}

The Init function calls init, and will call Unlock after init runs. But the init code also calls Unlock if it runs into an error!

This leads to a double-unlock, causing the stack trace we've seen.

So, why is calling tcell.NewScreen or screen.Init returning an error? In my case, it's because I'm running in a chroot with literally no files in the filesystem other than amfora, so tcell can't tell any information about the terminal. In your case, with tmux, I think it's because the version of tcell in the dep tree (v2.3.3) doesn't recognize TERM=tmux-256color. See issues like these as evidence:

So in the theory there are two things to fix:

  1. tmux not being supported
    • Fixed by updating tcell directly or updating cview, of which newer versions depend on fixed versions of tcell
  2. crashing happening when tcell init fails, instead of an error being returned
    • Will have to be fixed in cview

As a quick fix for now, I'll update tcell in-place, and we can see how that goes. See below. For the future, an issue needs to be filed in cview, and then I should look at all the differences between the current cview version imported and the latest one. If I can't upgrade easily, I can fork cview, but ideally the upgrade would be made.

Since tmux is commonly used (although your TERM is not the default, I didn't have it set), even the quick fix of upgrading tcell is enough for me to make a v1.9.3 bugfix release -- if this fix works and doesn't cause any other issues of course.


Please try this binary and let me know if it fixes your issue with Amfora running in tmux.

amfora_v1.9.2-dirty_freebsd_arm64.zip

@makew0rld
Copy link
Owner

@OfekShochat please let me know what terminal emulators (and emulators within emulators like tmux, screen, etc) you were using when Amfora crashed and didn't crash. If you could also include the output of your TERM env var in those scenarios that would be great.

@makew0rld makew0rld added upstream The issue is with a library. and removed help wanted Extra attention is needed labels Mar 26, 2022
@OfekShochat
Copy link
Author

OfekShochat commented Mar 26, 2022

Ive used alacritty, with leftwm on both occasions

@makew0rld
Copy link
Owner

Ok thanks. Not sure what the issue would be then but feel free to report back if you figure more out.

@makew0rld
Copy link
Owner

@alexsavage from some discussion with others online, it seems that most people have no issue with Amfora in tmux even with the same TERMvalue, so this bug is rarer than I thought. From what I can gather, this issue is occurring because both tcell and your system don't have a terminfo for tmux-256color. But on a lot tmux users' systems they have that terminfo installed already. For example on Arch Linux the terminfo for tmux-256color comes in the ncurses package. And on Debian I'm told it comes with the ncurses-term package.

So another solution would be to install some other package on your system, probably some ncurses stuff, that can provide the terminfo you need. Perhaps this is related to FreeBSD, as on Linux having the ncurses package might be more common? Not sure. Once this is all said and done I'll see if it really warrants a new release, might be more of an edge case.

@alexsavage
Copy link

Installing ncurses (though interestingly not the suggested terminfo-db) resolved this on my machine. I’ll open a suggestion to the port maintainers to either specify ncurses as a dependency, or add a post install message to recommend it at least. Thanks for the research!

@makew0rld
Copy link
Owner

makew0rld commented Mar 26, 2022

Great to hear this! Thanks you. Could you also confirm whether the binary I uploaded fixes the problem (with the ncurses package uninstalled!)

A post-install message mentioning tmux and ncurses sounds appropriate, good idea.

@OfekShochat
Copy link
Author

OfekShochat commented Mar 26, 2022

Ah wait, I think this it is a specific terminal issue. When it worked it wasn't alacritty (but wasn't leftwm too)

@alexsavage
Copy link

alexsavage commented Mar 27, 2022

Same crash with the test binary and no ncurses:


asavage@pebbles ~/amfora_v1.9.2-dirty_freebsd_arm64
 % ./amfora -v                                                                      
Amfora v1.9.2                                                                       
Commit: 61d864540140f463a183e187e4211c258bd518bf                                    
Built by: Makefile                                                                  
asavage@pebbles ~/amfora_v1.9.2-dirty_freebsd_arm64                                 
 % ./amfora                                                                         
fatal error: sync: Unlock of unlocked RWMutex                                                                                 
goroutine 1 [running]:                                                              
runtime.throw({0x4803d1?, 0x395b4c?})                                                       /usr/lib/go/src/runtime/panic.go:992 +0x50 fp=0x4000207d50 sp=0x4000207d20 p
c=0x40cd0                                                                           
sync.throw({0x4803d1?, 0x0?})                                                       
        /usr/lib/go/src/runtime/panic.go:978 +0x24 fp=0x4000207d70 sp=0x4000207d50 p
c=0x6b204
sync.(*RWMutex).Unlock(0x400025a88c)
        /usr/lib/go/src/sync/rwmutex.go:201 +0x80 fp=0x4000207db0 sp=0x4000207d70 pc
=0x834d0
code.rocketnine.space/tslocum/cview.(*Application).Init.func1()
        /home/makeworld/go/pkg/mod/code.rocketnine.space/tslocum/cview@v1.5.6-0.2021
0530175404-7e8817f20bdc/application.go:225 +0x2c fp=0x4000207dd0 sp=0x4000207db0 pc=
0x163a7c
code.rocketnine.space/tslocum/cview.(*Application).Init(0x400025a780)
        /home/makeworld/go/pkg/mod/code.rocketnine.space/tslocum/cview@v1.5.6-0.2021
0530175404-7e8817f20bdc/application.go:226 +0x88 fp=0x4000207e20 sp=0x4000207dd0 pc=
0x163a08
        /home/makeworld/go/src/github.com/makeworld-the-better-one/amfora/amfora.go:
71 +0x570 fp=0x4000207f70 sp=0x4000207e20 pc=0x3acd10
runtime.main()
        /usr/lib/go/src/runtime/proc.go:250 +0x254 fp=0x4000207fd0 sp=0x4000207f70 p
c=0x432a4
runtime.goexit()
        /usr/lib/go/src/runtime/asm_arm64.s:1259 +0x4 fp=0x4000207fd0 sp=0x4000207fd
0 pc=0x6f784

Suggested the workaround to the ports maintainer at Bugzilla 262863

@makew0rld
Copy link
Owner

@alexsavage thanks for testing that. I see you've filed a tcell bug and figured out why this is occurring at all, that's great thank you, you've saved me that work.

Ah wait, I think this it is a specific terminal issue. When it worked it wasn't alacritty (but wasn't leftwm too)

@OfekShochat could you narrow down the bug to either alacritty or leftwm? And after that try this binary (Linux 64-bit), and let me know if it fixes the issue. Thanks!

amfora_v1.9.2-dirty_linux_arm64.zip

@OfekShochat
Copy link
Author

its probably the terminal, the window manager should have nothing to do with it. and it actually would make sense cuz I remember something about alacritty and 256color (for example in vim I have to set it to work with colors)

@makew0rld
Copy link
Owner

makew0rld commented Apr 26, 2022

Created cview issue: https://code.rocketnine.space/tslocum/cview/issues/85

@makew0rld
Copy link
Owner

There is a now a fix for this error, described in the cview issue linked above. It requires upgrading cview though, so I would need to evaluate that and fix and bugs that arise from upgrading.

@makew0rld makew0rld removed upstream The issue is with a library. question Further information is requested labels Jun 10, 2022
@makew0rld makew0rld added this to the v1.10.0 milestone Jun 10, 2022
@OfekShochat
Copy link
Author

sure, thank you! quite cool. dont count on me, but if I have time Id to help

@koyuawsmbrtn
Copy link

Same thing happening to me as well. Arch Linux 2022/07/01 at 13:25 CEST.

@OfekShochat
Copy link
Author

Same thing happening to me as well. Arch Linux 2022/07/01 at 13:25 CEST.

What's your terminal emulator? Read the conversation :)

@koyuawsmbrtn
Copy link

Same thing happening to me as well. Arch Linux 2022/07/01 at 13:25 CEST.

What's your terminal emulator? Read the conversation :)

GNOME terminal

@omnivagant
Copy link

https://code.rocket9labs.com/tslocum/cview/releases/tag/v1.5.9

Patrycja should have credit for finding a fix for the cview issue in https://gitlab.alpinelinux.org/alpine/aports/-/merge_requests/57975

@makew0rld makew0rld modified the milestones: v1.10.0, v1.11.0 Feb 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

5 participants