terrastruct / d2

D2 is a modern diagram scripting language that turns text to diagrams.
https://d2lang.com
Mozilla Public License 2.0
17.17k stars 425 forks source link

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

Closed bo-ku-ra closed 7 months ago

bo-ku-ra commented 11 months ago

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.

info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 103.344ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 125.8546ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 95.0012ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 107.1851ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 102.4472ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 147.4784ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 88.3592ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 153.6542ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 87.7296ms
info: broadcasting update to 1 client
info: 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
bo-ku-ra commented 11 months ago
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 507.888ms
info: broadcasting update to 1 client
info: detected change in sandbox.svg: recompiling...
success: successfully compiled sandbox.d2 to sandbox.svg in 582.9534ms
info: broadcasting update to 1 client
info: 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 commented 11 months ago

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?

alixander commented 11 months ago

reopening until confirmed fix

bo-ku-ra commented 11 months ago

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 commented 11 months ago

d2 v0.6.3 (windows)

info: broadcasting update to 0 clients
info: 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 commented 11 months ago

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

https://github.com/terrastruct/d2/pull/1725/commits/b0cbd6621939f3eea025c38bf2dea376994b6f39#diff-fc70cf71bc274a18a06914bfd17d043d0cdc7795896c3f1abf9597d0340c0ef5

artiga033 commented 10 months ago

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 commented 9 months ago

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 commented 9 months ago

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 commented 8 months ago

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 commented 7 months ago

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

https://github.com/terrastruct/d2/commit/f328eb3b9f251a6fc198d89d201a0f1ea7c4075e#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 commented 7 months ago

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 commented 7 months ago

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 commented 7 months ago

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

bo-ku-ra commented 7 months ago

solved on v0.6.4 !!! thx.

alixander commented 7 months ago

Thanks to @artiga033 ! 🍺