FW Uploader might provide a broken JSON

[kittaakos]

Describe the problem

From time to time, when I start IDE2, the firmware uploader does not provide a valid JSON when executing ./arduino-fwuploader" firmware list --format json.

IDE2 error is:

Uncaught (in promise) Error: Error executing "/Users/a.kitta/dev/git/arduino-ide/arduino-ide-extension/build/arduino-fwuploader" firmware list --format json: unexpected end of JSON input
    at currentExtensions.<computed> (node.cjs:963)
    at read (node.cjs:403)
    at Array.readObject [as read] (node.cjs:496)
    at recordDefinition (node.cjs:956)
    at read (node.cjs:392)
    at checkedRead (node.cjs:193)
    at Packr.unpack (node.cjs:103)
    at Packr.decode (node.cjs:175)
    at MsgPackMessageDecoder.decode (rpc-message-encoder.ts:181)
    at MsgPackMessageDecoder.parse (rpc-message-encoder.ts:185)

To reproduce

I do not know the exact steps to reproduce, but I see the same error almost weekly in the logs.

Expected behavior

The firmware list --format json command provides a valid JSON.

Arduino Firmware Uploader version

arduino-fwuploader Version: 2.2.2 Commit: 8944d4a Date: 2022-10-17T14:51:09Z

Operating system

macOS

Operating system version

12.6.3

Additional context

No response

Issue checklist

• I searched for previous reports in the issue tracker
• I verified the problem still occurs when using the latest version
• My report contains all necessary details

[umbynos]

Hi @kittaakos, when this happens, could you please attach the content of "$TMPDIR/fwuploader"? This should help us understand the problem better.

[kittaakos]

I got the same error. I do not see any problem with the JSON: fwuploader-gh-166.zip. How is the arduino-fwuploader firmware list --format json command connected to these files in the temp folder?

[umbynos]

The json inside looks ok to me.. When you run arduino-fwuploader firmware list this piece of code is executed. It downloads the module_fw_index.json you sent me and checks the available firmware for the boards

[kittaakos]

I got an exception again with IDE2 2.1.0 on Windows (this time). The JSON file looks correct in the temp folder.

2023-05-04T08:54:51.646Z fwuploader ERROR Error: Error executing "c:\Users\kittaakos\Desktop\ide2 2.1.0\resources\app\node_modules\arduino-ide-extension\build\arduino-fwuploader.exe" firmware list --format json: unexpected end of JSON input
    at ChildProcess.<anonymous> (c:\Users\kittaakos\Desktop\ide2 2.1.0\resources\app\node_modules\arduino-ide-extension\lib\node\exec-util.js:53:31)
    at ChildProcess.emit (node:events:394:28)
    at Process.ChildProcess._handle.onexit (node:internal/child_process:290:12)
2023-05-04T08:54:51.646Z root ERROR Request updatableBoards failed with error: Error executing "c:\Users\kittaakos\Desktop\ide2 2.1.0\resources\app\node_modules\arduino-ide-extension\build\arduino-fwuploader.exe" firmware list --format json: unexpected end of JSON input
2

[kittaakos]

The same has happened when starting IDE2 from sources on Windows:

2023-05-05T09:36:56.878Z root ERROR Request updatableBoards failed with error: Error executing "C:\Users\kittaakos\dev\arduino-ide\arduino-ide-extension\build\arduino-fwuploader.exe" firmware list --format json: unexpected end of JSON input Error: Error executing "C:\Users\kittaakos\dev\arduino-ide\arduino-ide-extension\build\arduino-fwuploader.exe" firmware list --format json: unexpected end of JSON input
    at ChildProcess.<anonymous> (C:\Users\kittaakos\dev\arduino-ide\arduino-ide-extension\lib\node\exec-util.js:58:31)
    at ChildProcess.emit (node:events:513:28)
    at ChildProcess._handle.onexit (node:internal/child_process:291:12)
    at Process.callbackTrampoline (node:internal/async_hooks:130:17)

[cmaglie]

We had a similar problem with the Arduino CLI running sub-processes in the past, the issue was that the child process may exit and return an exit code before we actually consume all the output. It wasn't really clear from the documentation, but we had to consume all the stdout stream until EOF before exiting the run loop.

May it be the same here?

[kittaakos]

but we had to consume all the stdout stream until EOF before exiting the run loop.

@cmaglie, could you please reference the corresponding commit/PR in the CLI repository? Thanks!

[cmaglie]

could you please reference the corresponding commit/PR in the CLI repository?

I've been searching for the PR just after writing the comment but it seems I'm not able to find it :-/.

Anyway, this is an example of what I was talking about (of course it's in golang, I don't know if it applies to JS/TS):

func main() {
	// Create a pipe
	in, out, _ := os.Pipe()

	// Spawn a thread that copies the out-side of the pipe to os.Stdout
	go func() {
		io.Copy(os.Stdout, in)
	}()

	// Exec command
	cmd := exec.Command("/usr/bin/cat", "test")
	cmd.Stdout = out // Send command output to the in-side of the pipe
	_ = cmd.Run()
	out.Close()

	fmt.Println("PROCESS EXITED") // <-- The copy thread may still not be completed here!!
	time.Sleep(time.Second)
}

I've created a very big file called test that is cat to stdout.
Basically the problem here is that the copy thread is asynchronous, and it may not complete in time before cmd.Run() returns, so the output may be something like:

xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxPROCESS EXITED
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
THIS IS THE END OF THE FILE
$

instead of the expected

xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
THIS IS THE END OF THE FILE
PROCESS EXITED
$

so the obvious patch is to wait for completion of the thread:

func main() {
	// Create a pipe
	in, out, _ := os.Pipe()

	// Spawn a thread that copies the out-side of the pipe to os.Stdout
	doneCopying := make(chan bool)
	go func() {
		io.Copy(os.Stdout, in)
		close(doneCopying) // PATCH: Signal copy completion
	}()

	// Exec command
	cmd := exec.Command("/usr/bin/cat", "test")
	cmd.Stdout = out // Send command output to the in-side of the pipe
	_ = cmd.Run()
	out.Close()

	<-doneCopying // PATCH: wait for copy thread to complete

	fmt.Println("PROCESS EXITED") // everything's good! :-)
	time.Sleep(time.Second)
}

Hope this may help!

[kittaakos]

Maybe related:

2023-09-30T16:02:59.038Z root ERROR Request updatableBoards failed with error: Command failed with exit code 1: /Users/a.kitta/dev/git/arduino-ide/arduino-ide-extension/lib/node/resources/arduino-fwuploader firmware list --format json

"error": "Can't load package index: loading json index file /private/var/folders/z1/xkw1yh5n7rz4n8djprp1mdn80000gn/T/fwuploader/package_index.json: parse error: unterminated string literal near offset 458752 of

arduino-fwuploader Version: 2.4.1 Commit: d945078 Date: 2023-08-31T07:43:04Z

#166.txt

[kittaakos]

I see a new kind of error. It's started yesterday

/Users/a.kitta/dev/git/arduino-ide/arduino-ide-extension/lib/node/resources/arduino-fwuploader firmware list --format json
{
  "error": "Can't load package index: loading json index file /private/var/folders/z1/xkw1yh5n7rz4n8djprp1mdn80000gn/T/fwuploader/package_index.json: EOF"
}