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

[v0.6.3]windows d2.exe -w is crashed. #1767

Closed
bo-ku-ra opened this issue Dec 8, 2023 · 16 comments · Fixed by #1768 or #1895
Closed

[v0.6.3]windows d2.exe -w is crashed. #1767

bo-ku-ra opened this issue Dec 8, 2023 · 16 comments · Fixed by #1768 or #1895

Comments

@bo-ku-ra
Copy link
Contributor

bo-ku-ra commented Dec 8, 2023

d2.exe -w "sandbox.d2" "sandbox.svg"

'detected change' occurs frequently.
i did not save 'sandbox.d2'. (only the first time)
'd2.exe' sometimes crashed.

�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 103.344ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 125.8546ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 95.0012ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 107.1851ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 102.4472ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 147.4784ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 88.3592ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 153.6542ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 87.7296ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
.
.
.
.
.
.
panic: runtime error: index out of range [0] with length 0

goroutine 13 [running]:
oss.terrastruct.com/d2/d2cli.(*watcher).watchLoop(0xc00007a1e0, {0x282ff88, 0xc000707c70})
        oss.terrastruct.com/d2/d2cli/watch.go:297 +0xb7e
oss.terrastruct.com/d2/d2cli.(*watcher).goFunc.func1()
        oss.terrastruct.com/d2/d2cli/watch.go:203 +0x76
created by oss.terrastruct.com/d2/d2cli.(*watcher).goFunc
        oss.terrastruct.com/d2/d2cli/watch.go:199 +0x8d
@cyborg-ts cyborg-ts added this to D2 Dec 8, 2023
@bo-ku-ra
Copy link
Contributor Author

bo-ku-ra commented Dec 8, 2023 

�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 507.888ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
�[32msuccess�[0m: successfully compiled sandbox.d2 to sandbox.svg in 582.9534ms
�[34minfo�[0m: broadcasting update to 1 client
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
panic: runtime error: index out of range [0] with length 0

goroutine 7 [running]:
oss.terrastruct.com/d2/d2cli.(*watcher).watchLoop(0xc0005d8000, {0x1e3ff88, 0xc0000d2050})
        oss.terrastruct.com/d2/d2cli/watch.go:297 +0xb7e
oss.terrastruct.com/d2/d2cli.(*watcher).goFunc.func1()
        oss.terrastruct.com/d2/d2cli/watch.go:203 +0x76
created by oss.terrastruct.com/d2/d2cli.(*watcher).goFunc
        oss.terrastruct.com/d2/d2cli/watch.go:199 +0x8d

@alixander alixander mentioned this issue Dec 8, 2023
Merged
@alixander
Copy link
Collaborator

Strange. Can't reproduce but I've made an attempted fix on inspection of logic. We'll followup with 0.6.3 shortly.

Are you sure the file wasn't auto-saving on keystrokes or something? E.g. if you type into the file, close it, and then re-open it, those aren't saved?

@github-project-automation github-project-automation bot moved this to Done in D2 Dec 8, 2023
@alixander
Copy link
Collaborator

reopening until confirmed fix

@alixander alixander reopened this Dec 8, 2023
@bo-ku-ra
Copy link
Contributor Author

bo-ku-ra commented Dec 8, 2023

i do not encounter v0.6.1.
v0.6.2 occurs on both win 10 and 11. so i can not use v0.6.2.

>editor.exe "sandbox.d2"

a

>editor.exe (exit)
the editor saves "sandbox.d2". (1 byte + CRLF = a\n)

>d2.exe -w "sandbox.d2"

(Wait for a while) <- happens!

@bo-ku-ra
Copy link
Contributor Author

d2 v0.6.3 (windows)

�[34minfo�[0m: broadcasting update to 0 clients
�[34minfo�[0m: detected change in sandbox.svg: recompiling...
panic: runtime error: index out of range [0] with length 0

goroutine 12 [running]:
oss.terrastruct.com/d2/d2cli.(*watcher).watchLoop(0xc0007ca1e0, {0x1d34068, 0xc0006b7a40})
        oss.terrastruct.com/d2/d2cli/watch.go:298 +0xb38
oss.terrastruct.com/d2/d2cli.(*watcher).goFunc.func1()
        oss.terrastruct.com/d2/d2cli/watch.go:203 +0x76
created by oss.terrastruct.com/d2/d2cli.(*watcher).goFunc
        oss.terrastruct.com/d2/d2cli/watch.go:199 +0x8d

@bo-ku-ra bo-ku-ra changed the title [v0.6.2]windows d2.exe -w is crashed. [v0.6.3]windows d2.exe -w is crashed. Dec 17, 2023
@bo-ku-ra
Copy link
Contributor Author

it was changed watch.go when '--target' was added in v0.6.2.
is it relevant?

b0cbd66#diff-fc70cf71bc274a18a06914bfd17d043d0cdc7795896c3f1abf9597d0340c0ef5

@artiga033
Copy link

I've also encountered this in v0.6.2 & 0.6.3 while v0.6.1 is fine. I did not even open any editor and just ran d2 -w myfile.d2 in the command line. Several seconds later it will say 'detected change' and recompile endlessly.

@Melandel
Copy link

Melandel commented Jan 30, 2024 •
edited
Loading

Hi, chiming in.

I can confirm I also have this behavior In version 0.6.3 and 0.6.2, but it works in 0.6.1

Logs:

debug: using theme Neutral default (ID: 0)
success: listening on http://127.0.0.1:61566
info: compiling sandbox.d2...
debug: using layout plugin dagre (bundled)
success: successfully compiled sandbox.d2 to sandbox.svg in 48.6529ms
info: broadcasting update to 0 clients
success: GET / 200 446B 0s
success: GET /static/watch.css 200 206B 30.7101ms
success: GET /static/watch.js 200 2,661B 44.1008ms
success: GET /static/favicon.ico 200 1,150B 0s
success: GET /watch 101 0B 0s

# At this point I'm going to do one action: saving the file (without changing it beforehand)

debug: received file system event REMOVE        "some\path\sandbox.d2"
debug: received file system event WRITE         "some\path\sandbox.d2"
info: detected change in sandbox.d2: recompiling...
debug: using layout plugin dagre (bundled)
success: successfully compiled sandbox.d2 to sandbox.svg in 51.1195ms
info: broadcasting update to 1 client
debug: using layout plugin dagre (bundled)
debug: received file system event WRITE         "some\path\sandbox.svg"
success: successfully compiled sandbox.d2 to sandbox.svg in 45.6776ms
debug: received file system event WRITE         "some\path\sandbox.svg"
info: broadcasting update to 1 client
debug: received file system event WRITE         "some\path\sandbox.svg"
info: detected change in sandbox.svg: recompiling...
debug: using layout plugin dagre (bundled)
debug: received file system event WRITE         "some\path\sandbox.svg"
success: successfully compiled sandbox.d2 to sandbox.svg in 43.8889ms
debug: received file system event WRITE         "some\path\sandbox.svg"
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
debug: using layout plugin dagre (bundled)
debug: received file system event WRITE         "some\path\sandbox.svg"
success: successfully compiled sandbox.d2 to sandbox.svg in 45.5243ms
debug: received file system event WRITE         "some\path\sandbox.svg"
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
debug: using layout plugin dagre (bundled)
debug: received file system event WRITE         "some\path\sandbox.svg"
success: successfully compiled sandbox.d2 to sandbox.svg in 43.6988ms
debug: received file system event WRITE         "some\path\sandbox.svg"
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
debug: using layout plugin dagre (bundled)
debug: received file system event WRITE         "some\path\sandbox.svg"
success: successfully compiled sandbox.d2 to sandbox.svg in 43.8911ms
debug: received file system event WRITE         "some\path\sandbox.svg"
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...

@garymevs
Copy link

garymevs commented Jan 31, 2024 •
edited
Loading

Could be a red herring, but the fsnotify watcher WatchList() function appears to be returning a different path depending on platform:

Windows - debug: watch list: [C:\Users\garymevs\Documents\tempgit\d2]
Debian - debug: watch list: [/home/debian/personal/d2/test.d2]

(Both results are from throwing a debug print in the pollTicker case of watch loop and running with "go run . -w test.d2 -d")

Looks like at that point d2 is essentially watching for any change in the parent folder. Instead of the specified watch file.
The d2 instance is then starting a new compile on all WRITE events even if it's an output .svg.

Update:
The above is reproducible in a new project with just fsnotify:

package main

import (
	"fmt"

	"github.com/fsnotify/fsnotify"
)

func main() {
	w, _ := fsnotify.NewWatcher()
	w.Add("C:/path/to/file.go")
	fmt.Printf("watch list: %v", w.WatchList())
}

Prints: watch list: [C:\path\to]

@Lercher
Copy link

Lercher commented Feb 21, 2024

Had a look into the fsnotify code for Windows. IMO the WatchList function is not implemented correctly according to its documentation as it indeed only lists the directories. However, the watcher associates a map of the filenames Add-ed with the directory, and when an event needs to be handled the map watch.names is checked at https://github.com/fsnotify/fsnotify/blob/v1.7.0/backend_windows.go#L573 w.sendEvent(filepath.Join(watch.path, name), watch.names[name]&sysFSIGNORED). I didn't try it, so, this finding is only based of my understanding of the code.

In conclusion, I guess, the "The above is reproducible in a new project with just fsnotify" code needs a bit more elaboration: i.e. change file.go and change a different file and see what events are received. Currently I don't see fsnotify as the reason for unintentionally monitoring changes in the output file on Windows.

@artiga033
Copy link

Yes. The fsnotify does handle file names internally on Windows. However, I believe it's WatchList function's misbehavior causing the issue.

The codes introduces in this commit, which is also just the version where this issue got: v0.6.2

f328eb3#diff-fc70cf71bc274a18a06914bfd17d043d0cdc7795896c3f1abf9597d0340c0ef5L240-R255

Where it calls fw.WatchList() and re-added the results to the watcher, but as we knew:

Could be a red herring, but the fsnotify watcher WatchList() function appears to be returning a different path depending on platform:

Windows - debug: watch list: [C:\Users\garymevs\Documents\tempgit\d2]
Debian - debug: watch list: [/home/debian/personal/d2/test.d2]

So on Windows it's adding the whole directory to the watch list, and caused the infinite loop of writing and notified and re-writing the svg file.

@artiga033 artiga033 mentioned this issue Apr 2, 2024
Closed
@artiga033
Copy link

this have been fixed since github.com/fsnotify/fsnotify@7086bea, but a patch version is not planned to be released.

@alixander if you would like to bump the dependency version by that commit, this issue could be fixed.

@alixander alixander mentioned this issue Apr 9, 2024
Merged
@alixander alixander reopened this Apr 9, 2024
@alixander
Copy link
Collaborator

Just did a release with the fsnotify patch. Can someone test if this is fixed? If not, it must be something in d2's code rather than dependencies

@artiga033
Copy link

Have tested on my two diffrent Windows machines and it seems everything is fine

@bo-ku-ra
Copy link
Contributor Author

solved on v0.6.4 !!! thx.

@alixander
Copy link
Collaborator

Thanks to @artiga033 ! 🍺

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

Successfully merging a pull request may close this issue.

fix watch race alixander/d2
upgrade fsnotify alixander/d2
6 participants
@garymevs @alixander @Lercher @artiga033 @Melandel @bo-ku-ra