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

Firmata fails to start a connection with Arduino mega2560 #374

Closed
matipan opened this issue Feb 20, 2017 · 26 comments
Closed

Firmata fails to start a connection with Arduino mega2560 #374

matipan opened this issue Feb 20, 2017 · 26 comments
Labels

Comments

@matipan
Copy link

matipan commented Feb 20, 2017

Hi!
I'm trying to run the blinking example with an Arduino MEGA2560.
These are the steps I followed:

$ gort scan serial
/dev/cu.Bluetooth-Incoming-Port		/dev/tty.Bluetooth-Incoming-Port
/dev/cu.usbmodem1421			/dev/tty.usbmodem1421

So I changed the NewAdaptor to firmata.NewAdaptor("/dev/tty.usbmodem1421").
Then gort arduino install and it installed avrdude-6.3 successfully.
Now I run:

$ gort arduino upload firmata /dev/tty.usbmodem1421 -b mega2560
avrdude: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 0.01s

avrdude: Device signature = 0x1e9801 (probably m2560)
avrdude: reading input file "/var/folders/2l/2x1l6t5530s25fzgvyfzdp_r0000gn/T/816739554"
avrdude: writing flash (12224 bytes):

Writing | ################################################## | 100% 1.97s

avrdude: 12224 bytes of flash written
avrdude: verifying flash memory against /var/folders/2l/2x1l6t5530s25fzgvyfzdp_r0000gn/T/816739554:
avrdude: load data flash data from input file /var/folders/2l/2x1l6t5530s25fzgvyfzdp_r0000gn/T/816739554:
avrdude: input file /var/folders/2l/2x1l6t5530s25fzgvyfzdp_r0000gn/T/816739554 contains 12224 bytes
avrdude: reading on-chip flash data:

Reading | ################################################## | 100% 1.57s

avrdude: verifying ...
avrdude: 12224 bytes of flash verified

avrdude done.  Thank you.

According to the output of that command, the firmata software was successfully loaded. So the only thing left to do is run the program:

$ go run main.go
2017/02/20 20:10:49 Initializing connections...
2017/02/20 20:10:49 Initializing connection Firmata-3BD25BC8D8022818 ...
2017/02/20 20:10:49 Initializing devices...
2017/02/20 20:10:49 Initializing device LED-4A0D0593775CB601 ...
2017/02/20 20:10:49 Robot bot initialized.
2017/02/20 20:10:49 Starting Robot bot ...
2017/02/20 20:10:49 Starting connections...
2017/02/20 20:10:49 Starting connection Firmata-3BD25BC8D8022818 on port /dev/tty.usbmodem1421...

And it just hangs there.

I tried debugging it, and I got here. For some reason, the program stays in that Read method forever.

I'm running macOS Sierra 10.12.2 and go version 1.8

PS: I tried the blinking example from the Arduino IDE and it worked fine

@deadprogram
Copy link
Member

Hi @matipan thanks for the detailed report.

I personally do not have a MEGA2560 to test with, so a little hard to diagnose your problem.

Any way you can provide the call stack at the point where it hangs?

@matipan
Copy link
Author

matipan commented Feb 21, 2017

Hi @deadprogram, thanks for the quick response!

Sure, this is the stack trace I could get:

panic: STACK TRACE

goroutine 1 [running]:
github.com/tarm/serial.(*Port).Read(0xc420080058, 0xc42006f482, 0x3, 0x3, 0x2, 0x4294960, 0x0)
	/Users/Matias/Code/GoWorkspace/src/github.com/tarm/serial/serial_posix.go:180 +0x64
io.ReadAtLeast(0x4504098, 0xc420080058, 0xc42006f482, 0x3, 0x3, 0x3, 0x41385e0, 0x4010700, 0x4504098)
	/usr/local/opt/go/libexec/src/io/io.go:307 +0xa9
io.ReadFull(0x4504098, 0xc420080058, 0xc42006f482, 0x3, 0x3, 0x3, 0x4031afe, 0xc4200001a0)
	/usr/local/opt/go/libexec/src/io/io.go:325 +0x58
gobot.io/x/gobot/platforms/firmata/client.(*Client).read(0xc4200b6280, 0x3, 0x4, 0xc42006f481, 0x1, 0x1, 0x0)
	/Users/Matias/Code/GoWorkspace/src/gobot.io/x/gobot/platforms/firmata/client/client.go:343 +0xbb
gobot.io/x/gobot/platforms/firmata/client.(*Client).process(0xc4200b6280, 0x0, 0x12)
	/Users/Matias/Code/GoWorkspace/src/gobot.io/x/gobot/platforms/firmata/client/client.go:348 +0x4c
gobot.io/x/gobot/platforms/firmata/client.(*Client).Connect(0xc4200b6280, 0x41f37e0, 0xc420080058, 0xc420080058, 0x0)
	/Users/Matias/Code/GoWorkspace/src/gobot.io/x/gobot/platforms/firmata/client/client.go:192 +0x3db
gobot.io/x/gobot/platforms/firmata.(*Adaptor).Connect(0xc4200b0240, 0x1, 0x1)
	/Users/Matias/Code/GoWorkspace/src/gobot.io/x/gobot/platforms/firmata/firmata_adaptor.go:83 +0x53
gobot.io/x/gobot.(*Connections).Start(0xc4200826c0, 0x3, 0x3)
	/Users/Matias/Code/GoWorkspace/src/gobot.io/x/gobot/connection.go:54 +0x293
gobot.io/x/gobot.(*Robot).Start(0xc4200b0300, 0x0, 0x0, 0x0, 0xc420084190, 0xc42006f200)
	/Users/Matias/Code/GoWorkspace/src/gobot.io/x/gobot/robot.go:151 +0x1a7
main.main()
	/Users/Matias/Code/GoWorkspace/src/github.com/kriox26/gobot/main.go:30 +0x33d
exit status 2

The problem is that this stack trace is not complete, this is right before it hangs. I don't know which Read method this function uses, so I can't get inside that funcion and run panic there to get the real call stack.

Do you know how I can do that?

Thanks!

@matipan
Copy link
Author

matipan commented Feb 21, 2017

So I created a Docker image with all the things I needed to run the program.
Then I executed:

docker run -it --privileged --device=/dev/tty.usbmodem1411:/dev/ttyS0 [image_id]

to run the program inside the container, and It gets stuck in the same point. So it's not a problem of Mac OS apparently

@matipan
Copy link
Author

matipan commented Feb 22, 2017

Hi again! I tried running the same program on an Arduino UNO and it worked. So it's either an issue with the mega2560 in general or with mine in particular!
Should we close this or keep it open in case someone else with an arduino mega2560 has the same problem?

@deadprogram deadprogram changed the title Fails to start a connection with Arduino mega2560 Firmata fails to start a connection with Arduino mega2560 Feb 25, 2017
@tampajohn
Copy link

I just tested blink with my mega2560 and all seems to work. It certainly may be your board. I'm running on OSX Sierra with go 1.7.3.

@tampajohn
Copy link

Well that's weird, it worked once, and now no longer works. Will try to see what's going on.

@deadprogram
Copy link
Member

Anyone find out more information on this?

@matipan
Copy link
Author

matipan commented Mar 14, 2017

Hi there, no updates here. I don't know what else I can do though

@rkjdid
Copy link
Contributor

rkjdid commented Apr 7, 2017

Hi all,

I'm having a recurrent hang-at-connect on a Arduino Nano (I think v3.2) - just starting to tackle that but I'm under the impression that there's a problem either with locks or order of "Events" triggered (CapabilityQuery etc.)

So yeah basically program hangs on client.Connect() 95/100 times, I've seen it work 2 times so far...

@rkjdid
Copy link
Contributor

rkjdid commented Apr 7, 2017

tell me if you think this is unrelated I'll start another issue ;

here's the stack trace - definitely a deadlock here :

goroutine 10 [running]:
main.main.func3()
        /home/rkj/go/src/github.com/solar3s/regenbox/goregen/main.go:52 +0x9e
created by main.main
        /home/rkj/go/src/github.com/solar3s/regenbox/goregen/main.go:53 +0x3a1

goroutine 1 [chan receive]:
main.main()
        /home/rkj/go/src/github.com/solar3s/regenbox/goregen/main.go:55 +0x3d7

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:2197 +0x1

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
        /usr/local/go/src/runtime/sigqueue.go:116 +0x104
os/signal.loop()
        /usr/local/go/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.1
        /usr/local/go/src/os/signal/signal_unix.go:28 +0x41

goroutine 6 [chan send]:
gobot.io/x/gobot.NewEventer.func1(0xc42000c8a0)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:68 +0x115
created by gobot.io/x/gobot.NewEventer
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:73 +0x154

goroutine 7 [chan receive]:
gobot.io/x/gobot.NewEventer.func1(0xc42000c8c0)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:65 +0x6c
created by gobot.io/x/gobot.NewEventer
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:73 +0x154

goroutine 8 [chan receive]:
gobot.io/x/gobot.NewEventer.func1(0xc42000c9c0)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:65 +0x6c
created by gobot.io/x/gobot.NewEventer
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:73 +0x154

goroutine 9 [chan send]:
gobot.io/x/gobot.(*eventer).Publish(0xc42000c8a0, 0x55571c, 0xd, 0x520760, 0xc420011650)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:102 +0xa3
gobot.io/x/gobot/platforms/firmata/client.(*Client).process(0xc4200a0140, 0x0, 0x0)
        /home/rkj/go/src/gobot.io/x/gobot/platforms/firmata/client/client.go:481 +0x655
gobot.io/x/gobot/platforms/firmata/client.(*Client).Connect(0xc4200a0140, 0x7f3a40, 0xc42000e078, 0xc42000e078, 0x0)
        /home/rkj/go/src/gobot.io/x/gobot/platforms/firmata/client/client.go:192 +0x3db
gobot.io/x/gobot/platforms/firmata.(*Adaptor).Connect(0xc42006e2a0, 0x1, 0x1)
        /home/rkj/go/src/gobot.io/x/gobot/platforms/firmata/firmata_adaptor.go:83 +0x53
gobot.io/x/gobot.(*Connections).Start(0xc42000c9e0, 0x3, 0x3)
        /home/rkj/go/src/gobot.io/x/gobot/connection.go:54 +0x293
gobot.io/x/gobot.(*Robot).Start(0xc42006e3c0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/rkj/go/src/gobot.io/x/gobot/robot.go:151 +0x1a7
main.main.func2(0xc42006e3c0)
        /home/rkj/go/src/github.com/solar3s/regenbox/goregen/main.go:44 +0x4a
created by main.main
        /home/rkj/go/src/github.com/solar3s/regenbox/goregen/main.go:48 +0x389

goroutine 13 [semacquire]:
sync.runtime_SemacquireMutex(0xc42000c8bc)
        /usr/local/go/src/runtime/sema.go:62 +0x34
sync.(*Mutex).Lock(0xc42000c8b8)
        /usr/local/go/src/sync/mutex.go:87 +0x9d
gobot.io/x/gobot.(*eventer).Unsubscribe(0xc42000c8a0, 0xc42006e540)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:116 +0x3a
gobot.io/x/gobot.(*eventer).Once.func1(0xc42006e540, 0x55571c, 0xd, 0xc420011470, 0xc42000c8a0)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:146 +0xe9
created by gobot.io/x/gobot.(*eventer).Once
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:150 +0x79

goroutine 14 [chan receive]:
gobot.io/x/gobot.(*eventer).Once.func1(0xc42006e5a0, 0x555cec, 0xf, 0xc420011480, 0xc42000c8a0)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:143 +0x4e
created by gobot.io/x/gobot.(*eventer).Once
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:150 +0x79

goroutine 15 [chan receive]:
gobot.io/x/gobot.(*eventer).Once.func1(0xc42006e600, 0x5567f0, 0x12, 0xc420011490, 0xc42000c8a0)
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:143 +0x4e
created by gobot.io/x/gobot.(*eventer).Once
        /home/rkj/go/src/gobot.io/x/gobot/eventer.go:150 +0x79

@rkjdid
Copy link
Contributor

rkjdid commented Apr 7, 2017

this above solves it for me, probably not the way to do it though.

@matipan could you try it on your hardware?

@deadprogram
Copy link
Member

Hi @rkjdid to me that makes sense to increase the size of the one buffered channel, and to the make the other one buffered. It does not introduce any race conditions that are not already there, certainly.

I'd be happy to accept a PR with that change, if you wanted to submit one. :)

@rkjdid
Copy link
Contributor

rkjdid commented Apr 7, 2017

gladly, let me get back to you soon

deadprogram added a commit that referenced this issue Apr 7, 2017
core: use 10-buffered chans for events, see #374
@deadprogram
Copy link
Member

The buffered channel code that seems to have addressed this has now been released as part of Gobot 1.4 so I am now closing this issue. Please reopen if needed. Thank you!

@emmeblm
Copy link

emmeblm commented Aug 2, 2017

Hi everyone!

I'm having the exact same problem as the original one in this issue. I'm using an Arduino Mega 2560 with the blinking example.
The problem now is that instead of hanging out in the Starting connection Firmata-7E113A8AAF4C13D2 on port /dev/cu.usbmodem1411... line, some seconds later this error message appears:

2017/08/02 15:34:45 1 error occurred:

* unable to connect. Perhaps you need to flash your Arduino with Firmata?

But firmdata was sucessfully loaded in the Arduino.

I'm not able to run any gobot nor artoo program into my arduino. I checked the hardware loading the same blinking example in c with Arduino Ide and the hw works fine. It's definitely something with the firmdata platform creating the adaptor that's not able to communicate with Mega 2560.

For instance, when running:
gort arduino upload firmata /dev/tty.usbmodem1411 -b mega2560
you can see that the -b mega2560 option is needed (as it doesn't work when it is not specified). Only when sending this option in the gort command, it is able to sync with the arduino and load firmdata on it. The error that outputs when you just type gort arduino upload firmata /dev/tty.usbmodem1411 is the following:

avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 1 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 2 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 3 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 4 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 5 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 6 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 7 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 8 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 9 of 10: not in sync: resp=0x00
avrdude: stk500_recv(): programmer is not responding
avrdude: stk500_getsync() attempt 10 of 10: not in sync: resp=0x00

avrdude done.  Thank you.

2017/08/02 17:27:55 exit status 1

I can just imagine that the same is happening at the firmdata adaptor level of gobot as the error that I see is printed on port communication timeout.

Can you help me @deadprogram?

Thanks!

@deadprogram
Copy link
Member

Hi @emmeblm I suspect that the problem lies in the specific firmware being loaded to the Mega. The version that is part of Gort is specific to the Uno and clones, and so even tho it might flash properly, it probably is not executing correctly.

One way to test this out is to try compiling and flashing Firmata onto the Mega directly from the Arduino IDE, and then try running the Gobot code.

My man @thoughtentity is working on some updates to Gort to allow for compiling and flashing with different boards, such as the mega. Also, I now have a Mega (somewhere) to test with.

I am going to reopen this issue, since it seems like it is still around.

@deadprogram deadprogram reopened this Aug 3, 2017
@emmeblm
Copy link

emmeblm commented Aug 3, 2017

Hi @deadprogram, thanks for the answer.. I tried what you mentioned with no success.. Uploaded firmata directly from Arduino Ide and still get the message:

2017/08/03 12:40:19 1 error occurred:
* unable to connect. Perhaps you need to flash your Arduino with Firmata?

when running go run blink_led.go. I still have the feeling that this problem lies at the firmata client level.

@deadprogram
Copy link
Member

I just tried flashing my Arduino Mega 2560 with the StandardFirmata sketch. I then ran the firmata_blink.go program with no problems:

$ go run examples/firmata_blink.go /dev/ttyACM0 
2017/08/04 11:25:28 Initializing connections...
2017/08/04 11:25:28 Initializing connection Firmata-19F592BB979D619A ...
2017/08/04 11:25:28 Initializing devices...
2017/08/04 11:25:28 Initializing device LED-4AC7E7C7618A98B1 ...
2017/08/04 11:25:28 Robot bot initialized.
2017/08/04 11:25:28 Starting Robot bot ...
2017/08/04 11:25:28 Starting connections...
2017/08/04 11:25:28 Starting connection Firmata-19F592BB979D619A on port /dev/ttyACM0...
2017/08/04 11:25:31 Starting devices...
2017/08/04 11:25:31 Starting device LED-4AC7E7C7618A98B1 on pin 13...
2017/08/04 11:25:31 Starting work...

I did notice that I needed to exit the Arduino IDE before trying to run the Gobot program, possibly the Arduino IDE connected itself to the serial port for debugging?

Also which version of Arduino and StandardFirmata did you use to flash your board?

@deadprogram
Copy link
Member

Hello, there. Just checking in to see if there was any further info, I am not able to reproduce with the latest code.

@allsputnik
Copy link

allsputnik commented Nov 8, 2017

Hello, I also had a problem with Arduino Mega 2560.

sudo ./gobot 
2017/11/09 00:26:10 Initializing connections...
2017/11/09 00:26:10 Initializing connection Firmata-382E6917 ...
2017/11/09 00:26:10 Initializing devices...
2017/11/09 00:26:10 Initializing device LED-789CC02E ...
2017/11/09 00:26:10 Robot bot initialized.
2017/11/09 00:26:10 Starting Robot bot ...
2017/11/09 00:26:10 Starting connections...
2017/11/09 00:26:10 Starting connection Firmata-382E6917 on port /dev/ttyACM0...
2017/11/09 00:26:25 1 error occurred:

* unable to connect. Perhaps you need to flash your Arduino with Firmata?

"I did notice that I needed to exit the Arduino IDE before trying to run the Gobot program, possibly the Arduino IDE connected itself to the serial port for debugging?" - Did not quite understand what you meant?
I ran both in the MAC OS and in the Raspberry Pi result is the same (

@allsputnik
Copy link

Hello, now I tried to do the same with Arduino Uno

gort scan serial

1 serial port(s) found.

1. [/dev/ttyACM0] - [usb-Arduino__www.arduino.cc__0043_5543830343935101A1D0-if00]
  USB device:  Bus 001 Device 004: ID 2341:0043 Arduino SA Uno R3 (CDC ACM)

./gobotLinux
2017/11/09 09:15:55 Initializing connections...
2017/11/09 09:15:55 Initializing connection Firmata-BA337390F6407B4 ...
2017/11/09 09:15:55 Initializing devices...
2017/11/09 09:15:55 Initializing device LED-7B8343061C1A48E4 ...
2017/11/09 09:15:55 Robot bot initialized.
2017/11/09 09:15:55 Starting Robot bot ...
2017/11/09 09:15:55 Starting connections...
2017/11/09 09:15:55 Starting connection Firmata-BA337390F6407B4 on port /dev/ttyACM0...
2017/11/09 09:16:10 1 error occurred:

* unable to connect. Perhaps you need to flash your Arduino with Firmata?

@deadprogram
Copy link
Member

I've been doing a bunch of experiments with different boards, and have found some cases where when partial data has been read from the board, the messages can get out of sync. Currently experimenting with some different fixes for additional robustness.

More very soon...

@deadprogram
Copy link
Member

The dev branch now includes this commit eb3b166 which should better handle cases with extra out-of-sync data bytes.

I've just tested on a real Arduino Uno R3, a real Arduino 101, a clone Arduino Uno, and a clone Arduino Mega 2560, and they all were able to connect multiple times.

Next release of Gobot will include this update. In the meantime, any testing/feedback is appreciated.

@deadprogram
Copy link
Member

This code was released in v1.8.0 so now closing. Please reopen if needed. Thanks everyone!

@gyldcs
Copy link

gyldcs commented Nov 16, 2018

I am getting the same issue with esp8266 and gobot 1.12

@akshitj1
Copy link

For future readers still encountering this error.
gort arduino upload firmata /dev/tty.usbmodem1411 -b mega2560
seems to flash correctly but blinking_led eg. doesn't runs and shows message:
* unable to connect. Perhaps you need to flash your Arduino with Firmata?

I instead uploaded Firmata Using arduino IDE and led eg. worked fine.
Quoting doc

Open arduino IDE and go to File > Examples > Firmata > StandardFirmata and open it. Select the appriate port for your arduino and click upload.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

8 participants