ftctechnh / ftc_app

FTC Android Studio project to create FTC Robot Controller app.
759 stars 3.17k forks source link

Moto G4 driver phone will not init program after 5-6 successful runs #447

Open jdkunzeman opened 6 years ago

jdkunzeman commented 6 years ago

First of all, I have not updated to 3.5, so I apologize if this is resolved in that version. I will update soon and test again. These problems are occurring on 3.4.

We are using Moto G4 play phones and two Rev Robotics Expansion Hubs. We have noticed that after about 5-6 successful autonomous runs the driver station phone will not respond to pushing the init button in the app. It says it is connected and shows good ping times, but sometimes also does not display the battery voltage from the robot. Occasionally the DS phone will react to pushing the init button, but the robot only actually inits after about 10 seconds, which is significant lag.

Here's what I tried, in order, without success:

  1. Restart the DS phone
  2. Restart both phones
  3. Disconnect DS from RC, kill DS app, re-pair, accept connection of RC phone (This also did not fix. Could init, but had lots of lag.)

Finally powered both phones and robot off for 7 minutes, then restarted everything. Everything was fine for six autonomous runs, then the problem reoccurred. Shut everything off for 3 minutes and the problem went away for five runs.

It looks like we have a workaround in shutting everything down for at least 3 minutes, which is good some our first competition is coming up. However, any ideas what's wrong?

Also, autorun is disabled.

Thanks

ftctechnh commented 6 years ago

Hi jdkunzeman,

I believe this issue is fixed in V3.5. Please checkout the README for details of the fixes included with 3.5:

https://github.com/ftctechnh/ftc_app#release-information

Tom

gorpong commented 6 years ago

I don't think it's fixed in 3.5, because he's describing EXACTLY the issue that I've posted on the FTC forums asking if anyone else on 3.5 is seeing it. We upgraded to 3.5 on Saturday and we had three of our matches lock up and the robot sat motionless because of this issue, so it is definitely still happening in 3.5.

gorpong commented 6 years ago

Also, the following two issues don't seem to be fixed in 3.5, because I'm experiencing them:

The first issue, with the battery voltage, started happening when we upgraded, we'd never seen it before.

Now, I upgraded to 3.5 by taking the .zip file and overlaying that on top of our existing 3.4 system (not fork/clone, but downloading zip and creating own repository from it), but I did that from 2.6 to 3.4 and didn't seem to have a problem.

emmell620 commented 6 years ago

I believe I saw this as well as an FTA at a qualifier this past weekend. I believe the team was running 3.5 (finding out now). We had to power everything down (about 1 minute, not 7) and restart everything to get things back in gear. But we also saw this happen to the team in back-to-back runs (not between 5-6).

ftctechnh commented 6 years ago

Hi Folks,

Would it be possible to get copies of the log files from the Robot Controller and Driver Station phones for the robots that were having issues?

Tom

gorpong commented 6 years ago

I can get the log files tonight when I get home. I have possession of the robot and phones from this weekend's competition. Tom, do you want them posted here or just email you directly?

-- Gordon.

jdkunzeman commented 6 years ago

We have changed 3.5 and are still experiencing issues, which actually seem worse. Here is a section of the log from this afternoon right before the phone had to be rebooted. You can see multiple attempts to init. I am also attaching the log. Any help you can provide would be greatly appreciated: 171108 DS log.txt

11-08 16:10:57.845 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 57.534} WifiP2pGroup: network: null, isGO: false, Operating Channel: 0, GO: null, interface: null, networkId: 0, mGoOperFreq: 0 11-08 16:10:57.845 4725 4725 V NetDiscover_prefremds: { -310 57.534} onSharedPreferenceChanged(name=pref_wifip2p_groupowner_connectedto, value=null) 11-08 16:10:57.845 4725 4725 V NetDiscover_prefremds: { -310 57.534} pref_wifip2p_groupowner_connectedto has been removed 11-08 16:10:57.845 4725 4725 V DriverStation: { -310 57.534} onSharedPreferenceChanged() pref=pref_wifip2p_groupowner_connectedto 11-08 16:10:57.846 4725 4725 V WifiDirect: { -310 57.535} peers found: 0 11-08 16:10:57.846 4725 4725 I RobotCore: { -310 57.535} Received networkConnectionEvent: PEERS_AVAILABLE 11-08 16:10:57.849 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 57.538} p2p discoverPeers()=true 11-08 16:10:57.868 4725 4725 I RobotCore: { -310 57.557} Received networkConnectionEvent: DISCOVERING_PEERS 11-08 16:10:57.868 4725 4725 D WifiDirect: { -310 57.557} discovering peers 11-08 16:10:57.895 4725 6507 E Robocol : { -310 57.584} exception SocketException(sendto failed: EINVAL (Invalid argument)): exception sending datagram [libcore.io.IoBridge.maybeThrowAfterSendto(IoBridge.java:542)] 11-08 16:10:58.032 4725 4725 V DriverStation: { -310 57.721} onPause() 11-08 16:10:58.054 4725 6507 V GamepadManager: { -310 57.743} transmitting synthetic gamepad user=ONE 11-08 16:10:58.055 4725 6507 V GamepadManager: { -310 57.743} transmitting synthetic gamepad user=TWO 11-08 16:10:58.056 4725 6507 V Robocol : { -310 57.744} sending CMD_INIT_OP_MODE(15608), attempt: 0 11-08 16:10:58.098 4725 4725 V DriverStation: { -310 57.787} onStop() 11-08 16:10:58.294 4725 6507 V Robocol : { -310 57.983} sending CMD_INIT_OP_MODE(15608), attempt: 1 11-08 16:10:58.299 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 57.988} peers found: count=1 11-08 16:10:58.300 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 57.988} peer: cc:61:e5:4e:4d:ee 5202-M-RC 11-08 16:10:58.300 4725 4725 D WifiDirect: { -310 57.988} broadcast: peers changed 11-08 16:10:58.301 4725 4725 V WifiDirect: { -310 57.990} peers found: 1 11-08 16:10:58.301 4725 4725 V WifiDirect: { -310 57.990} peer: cc:61:e5:4e:4d:ee 5202-M-RC 11-08 16:10:58.301 4725 4725 I RobotCore: { -310 57.990} Received networkConnectionEvent: PEERS_AVAILABLE 11-08 16:10:58.302 4725 4725 D WifiDirect: { -310 57.990} connecting to cc:61:e5:4e:4d:ee 11-08 16:10:58.534 4725 6507 V Robocol : { -310 58.223} sending CMD_INIT_OP_MODE(15608), attempt: 2 11-08 16:10:58.735 4725 6507 V Robocol : { -310 58.424} sending CMD_INIT_OP_MODE(15608), attempt: 3 11-08 16:10:58.814 4725 4725 D WifiDirect: { -310 58.502} connect started 11-08 16:10:58.814 4725 4725 I RobotCore: { -310 58.503} Received networkConnectionEvent: CONNECTING 11-08 16:10:58.815 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 58.504} peers found: count=1 11-08 16:10:58.816 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 58.504} peer: cc:61:e5:4e:4d:ee 5202-M-RC 11-08 16:10:58.817 4725 4741 V NetDiscover_wifiDirectAgent_bcast: { -310 58.506} p2p discoverPeers()=false 11-08 16:10:58.829 4725 4725 D WifiDirect: { -310 58.518} broadcast: peers changed 11-08 16:10:58.832 4725 4725 V WifiDirect: { -310 58.521} peers found: 1 11-08 16:10:58.833 4725 4725 V WifiDirect: { -310 58.521} peer: cc:61:e5:4e:4d:ee 5202-M-RC 11-08 16:10:58.833 4725 4725 I RobotCore: { -310 58.522} Received networkConnectionEvent: PEERS_AVAILABLE 11-08 16:10:58.975 4725 6507 V Robocol : { -310 58.663} sending CMD_INIT_OP_MODE(15608), attempt: 4 --------- beginning of main 11-08 16:13:04.621 4723 4723 V AppUtil : initializing: getExternalStorageDirectory()=/storage/emulated

jdkunzeman commented 6 years ago

I was not here when the team was running, but they mentioned that they had disconnects or fails to init in practically every practice match they tried to run. Where are those showing up in the log? Going to try old phones and/or App 3.4 next.

jdkunzeman commented 6 years ago

Here is the log from the robot controller phone for the same time period: robotControllerLog 171108.txt

jdkunzeman commented 6 years ago

Same problems tonight. Switched to ZTE speed from Moto and seemed to have less problem for just a while. Tried fixing it one time by leaving the phones on and just turning off all power to the Rev hubs for three minutes. This fixed the problem the only time it was tried. The best solution still seems to be to shut phones and hubs down for a few minutes. Have not reverted to 3.4 yet.

emmell620 commented 6 years ago

Tom? Any updates??

ftctechnh commented 6 years ago

Hi Folks,

When you updated to v3.5 software, did you do so on the Robot Controller AND the Driver Station? If not, could you please verify that both the RC and DS are using the V3.5 software and retest?

Tom

jdkunzeman commented 6 years ago

Both the Driver Station and the Robot Controller phones were using 3.5. This was true whether we were using a pair of Moto G4 phones or a pair of ZTE Speed phones.

emmell620 commented 6 years ago

I agree with @jdkunzeman. Both apps were updated. Trying to get the logs from the team now.

gorpong commented 6 years ago

I agree with both @jdkunzeman and @emmell620 - 3.5 was updated on both (copied from the doc/apk directory in ftc_app-master directory) and verified with the built-in self-check code.

ftctechnh commented 6 years ago

can you get both the DS and RC logs and post them online so we can download them for review? Also, sorry ask for so much info, but could you also post the source code (blocks or java) for your op modes and your .xml config file? I would like to see if I can reproduce the issue. We have not yet been able to reproduce the issue in our testing.

ftctechnh commented 6 years ago

@jdkunzeman @emmell620 Are the teams that are experiencing this issue using Modern Robotics or REV hardware?

emmell620 commented 6 years ago

I believe the team I've been working with had two REV hubs.

gearsincorg commented 6 years ago

Hi

I'm looking at these logs too. Unfortunately, when the phones/apps are intentionally stopped/restarted/minimized, they cause a lot of "noise" entries in the logs, so it's hard to know what was intentional, and what wasn't.

It can help us if the event in questions is easy to identify. So it needs to stand out in the log.
In this case, it helps if you save out the log immediately after a clear instance of the event...

Say, you start an opmode and it stops by itself. Make a note of the opmode you were running, and the time it happened. Now... DO NOT run that opmode again until you have a copy of both logfiles (so it's the last run in the file). This make it easier for us to find the instance in both logs, and relly know for sure what we are looking at. It helps if you rename the log file with the three key pieces of info: App, opmode and date-time. eg: DS_MyTELEOP_2017-11-12_16-03-12

I know that in many cases you are busy trying to do other stuff, but just one really great log pair can crack an issue.

jdkunzeman commented 6 years ago

Our team is using two Rev hubs as well. I won't be able to post anything more until this evening, beyond the logs that I posted yesterday. I will try to follow the recommendations above, but we are also in the midst of final meet preparations.

gearsincorg commented 6 years ago

@tomeng70 @cmacfarl

The RD log shown above (robotControllerLog 171108.txt) has got some pretty blatant issues.

It appears that when the app starts up, the rev modules are not accessible (show up with unknown revision).

11-08 15:09:36.897 2471 2719 I RobotCore: Expansion Hub (unknown firmware) Expansion Hub 1 USB DQ15PF06; module 1

At some time later, the Hubs appear on the USB (Anyone know if this was a case of starting the app, and then plugging in the USB cable) ?

11-08 15:10:26.852 2471 2471 V RCActivity: ACTION_USB_DEVICE_ATTACHED: /dev/bus/usb/001/002

Shortly thereafter the DS attempts to start the opmode

11-08 15:11:43.884 2471 2826 V Robocol : received command: CMD_INIT_OP_MODE(11597) Th30-AutoB2

At which point we get a whole slew of NAC's from the Expansion hub.

11-08 15:11:44.171 2471 3292 V RobotCore: nack rec'd mod=2 msg#=162 ref#=0 reason=I2C_MASTER_BUSY:40

So I assume the failure to initialize the expansion hub causes the DS to continually isue an INIT.

11-08 15:11:43.884 2471 2826 V Robocol : received command: CMD_INIT_OP_MODE(11597) Th30-AutoB2 11-08 15:11:45.192 2471 2826 V Robocol : received command: CMD_INIT_OP_MODE(11615) Th30-AutoB2 11-08 15:11:48.072 2471 2826 V Robocol : received command: CMD_INIT_OP_MODE(11642) Th30-AutoB2

followed by some other error reporting.

11-08 15:11:46.774 2471 3292 E LynxModule: unable to find originating LynxRespondable for mod=2 msg#=158 ref#=152

But it's basically dead at this point.

ftctechnh commented 6 years ago

@jdkunzeman To clarify what Mr. Phil (gearsinc) asked, do you know if the team turned on the power to their two Expansion Hubs first, and then connected the Android Robot Controller using the USB cable to the phone, to auto launch the Robot Controller app?

Or did the team manually (or perhaps by installing a new version of the RC app with Android Studio) launch the app, and then connect it to the hardware with the USB cable?

jdkunzeman commented 6 years ago

The RC app was probably started before the Expansion Hub was plugged in, and it's possible that the DS app had already been started as well. However, at least some of the cases where the Init button of the DS would "quit working" occurred right after an autonomous run without breaking any connections between runs. In some of those cases the auto runs may have been terminated early from the DS phone. We are also seeing some cases where the app will init, but it only occurs with a significant lag time after the init button is pressed in the DS app.

ftctechnh commented 6 years ago

@jdkunzeman I am wondering if I2C comm issues might be related to what your team is specifically seeing.

Would you be able to do some testing to explore this problem? I was wondering if your team could write a very simple auto op mode and a very simple teleop op mode. Each op mode should only contain references to motors or servos, and not to any sensors.

If you have such op modes, and if you run several cycles of autonomous, then teleop, then stop, then autonomous, etc. will you encounter the same issue where the control system fails to initialize properly.

I'd be curious to see if eliminating references in your op modes to the sensors makes the observed problem go away. There would be two sub conditions... one where you keep your current config file (with the I2C sensors configured), and the other where you modify and create a new config file that only references the motors and servos.

Is this something that your team might be able to do?

jdkunzeman commented 6 years ago

@ftctechnh Yes, we could do this, but probably not until next week. We only have four MR color sensors on the robot. We also have four encoders plugged in, but we're not currently using them. Color sensors are only used in autonomous. As far as sending you code, I assume you only want the relevant classes from the Teamcode section of our app, in addition to the config file?

gearsincorg commented 6 years ago

In the case of (robotControllerLog 171108.txt), the fact that the App was probably started before the Hubs were connected means that we don't have some of the initial device checking that would be in the log if the hub was plugged in to launch the app.

For what it's worth, I think the best way to get a clean start on a REV robot configuration (after unplugging the phone) is to adopt the following steps:

1) If the USB is ever disconnected (eg: for programming), make sure you turn OFF the robot 12V. (to clear any past conditions) 2) Before you re-connect the phone to the robot, make sure the RC App is stopped and swiped off. (to clear any prior USB actions, and allow the App a clean start) 3) Turn the Robot's 12V back on, BEFORE plugging in the phone (so it's there to autostart the app) 4) Plug in the phone and observe the App start up. Make sure the Hub is recognized. and that it connects to the DS. If it does not connect (no ping), Swipe OFF the Driver Station app and restart it.

If there is a problem at this point, exit both apps and capture the log file.

gearsincorg commented 6 years ago

One follow up note:
If you have two REV Hubs, you need to be careful when powering the robot up and down. Remember that the Master Gateway hub (the one with the phone attached) gets power from the phone, but the other hub does not, SO, if you have the phone plugged in, but the 12V turned off, only one of your hubs is powered (could lead to all sorts of communications issues)

This is why I recommend powering the hubs down after you unplug the phone, and back on before re-attaching.

emmell620 commented 6 years ago

@gearsincorg - Phil: Thanks for the trouble shooting and the suggestions. I'm thinking this should be incorporated in with the CSA/FTA bag of tricks as we will see more dual REV hubs in the near future.

technova12611 commented 6 years ago

@ftctechnh @gearsincorg We had this happened before. After we removed all MR I2C sensors, we have been running clean for a while on SDK3.5. "Problem with ...." occurred many times in the logcat ( robotControllerLog 171108.txt).

I have been reporting this issue in FTC forum & /r/ftc reddit. https://ftcforum.usfirst.org/forum/ftc-technology/53758-problem-with-color-sensor-or-problem-with-range-sensor, ,but haven't got any response. Somehow I think these two issues could be related and caused the communication breakdown.

Simply adding two MR I2C sensors (MR Range + Color), you can easily reproduce "Problem with ..." issue, and after a few successful runs (if you can avoid getting "Problem with ..."), you may experience complete lock up issue.

    Line 4652: 11-08 15:14:30.570  4760  5842 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
    Line 5536: 11-08 15:20:59.403  4732  5699 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
    Line 7122: 11-08 15:34:28.181  7357  7779 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
    Line 10833: 11-08 15:36:32.017  7357  7779 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "rs1"; problem with "ls2""
    Line 10833: 11-08 15:36:32.017  7357  7779 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "rs1"; problem with "ls2""
    Line 10834: 11-08 15:36:32.049  7357  7779 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
    Line 20807: 11-08 15:42:23.573  7357  7779 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "rs1""
    Line 20840: 11-08 15:42:32.941  7357  7779 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
    Line 28518: 11-08 16:07:59.293  4746  6332 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
    Line 32041: 11-08 16:14:00.578  4743  6368 D RobotCore: system telemetry: key=$System$Warning$ msg="problem with "ls2""
jdkunzeman commented 6 years ago

@technova12611 Whose color sensors did you end up using?

technova12611 commented 6 years ago

@jdkunzeman We use REV Color/Distance, no issue at all. We use only one of them. We go forward on Red and backward on Blue. Only one arm is needed, no need to move camera either.

We tried to use MR Range sensors, but we had "Problem with ..." issue once a while, it could be in initialization or during autonomous running. We decided not to use it. For now, we are basically not using I2C sensors because of the communication issue.

Not sure how other teams deal with it.

technova12611 commented 6 years ago

@ftctechnh @gearsincorg

Could this be the solution for my I2C Sensor issues? I will test it tonight!

https://www.reddit.com/r/FTC/comments/7bx4pe/rev_expansion_hub_firmware_release_170/

jorayvanvliet commented 6 years ago

Thank you! Very helpful JOoRay

On Thu, Nov 9, 2017 at 12:47 PM, Phil Malone notifications@github.com wrote:

In the case of (robotControllerLog 171108.txt), the fact that the App was probably started before the Hubs were connected means that we don't have some of the initial device checking that would be in the log if the hub was plugged in to launch the app.

For what it's worth, I think the best way to get a clean start on a REV robot configuration (after unplugging the phone) is to adopt the following steps:

  1. If the USB is ever disconnected (eg: for programming), make sure you turn OFF the robot 12V. (to clear any past conditions)
  2. Before you re-connect the phone to the robot, make sure the RC App is stopped and swiped off. (to clear any prior USB actions, and allow the App a clean start)
  3. Turn the Robot's 12V back on, BEFORE plugging in the phone (so it's there to autostart the app)
  4. Plug in the phone and observe the App start up. Make sure the Hub is recognized. and that it connects to the DS. If it does not connect (no ping), Swipe OFF the Driver Station app and restart it.

If there is a problem at this point, exit both apps and capture the log file.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/ftctechnh/ftc_app/issues/447#issuecomment-343234974, or mute the thread https://github.com/notifications/unsubscribe-auth/AMJctbGLSQxBWyNE3s8NO_B1FUJL2wnRks5s0zq4gaJpZM4QUIw8 .

ftctechnh commented 6 years ago

@jdkunzeman @technova12611 @jorayvanvliet Yes, I think the firmware release v1.70 might fix the problems with the use of Modern Robotics I2C sensors and the REV Expansion Hub. From the log files that jdkunzeman provided, Mr. Phil and I noticed a large number of I2C error messages.

I remembered that there is a known issue using the V1.6 REV Robotics firmware with some Modern Robotics I2C sensors. For this combination of MR sensor and REV I2C controller, sometimes the I2C comm would just stop randomly. I believe the v1.7 firmware has the ability to detect this "stuck" condition and to reset the I2C connection when it determines that communication on the bus has stopped.

I spoke with roboGreg from REV and explained what the teams have been observing and asked if REV could accelerate the release of the V1.7 firmware. They graciously agreed to do so ASAP.

You can go directly to the Expansion Hub product page on the REV Robotics website and get the instructions on how to update the firmware for your Expansion Hub.

Please let us know if the firmware updates correct the problem with the use of the Modern Robotics I2C sensors and the Expansion Hub.

Note that this firmware update will fix the issue where the I2C comm gets "stuck" when the Expansion Hub is talking to an MR I2C sensor. However, Gorpong, I don't think this is the situation your team is experiencing. There might be a second issue that is causing similar behavior to what jdkunzeman and others reported.

qwertychouskie commented 6 years ago

@ftctechnh Can you post a full changelog of the 1.7 firmware here for the curious (a.k.a. me ;)?

ftctechnh commented 6 years ago

@qwertychouskie This is what REV has listed on their reddit post:

change log Fixes a bug where some i2c sensors can lock up the bus causing other additional performance issues with the expansion hub. Changes LED light so when connected with or without the battery so you can tell if the hub is powered off of the phone or the robot battery. other minor performance tweaks.

The change in the LED light is a nice feature. with the v1.7 firmware, if the Expansion Hub does not detect 12V being supplied, it changes color to an orange/amber color to alert the user that it's only operating on 5V power (from the phone).

qwertychouskie commented 6 years ago

Nice, thanks!

jdkunzeman commented 6 years ago

When we ran teleop tonight we made changes to use both a new hardware class and a new config. Neither included any color sensors. We had no problems during teleop and the drivers did not complain about lag like they did previously. When we tried to run autonomous again with MR color sensors, we immediately had the same problems as previously. We have one REV color sensor and we are planning to use it, and no MR color sensors, for our meet on Saturday. Because one of our hubs has a bad USB port, we can't flash both with the new firmware, so that option seems off the table for now. Thanks everyone for your help, we will get through this.

ftctechnh commented 6 years ago

@jdkunzeman Good luck this weekend. By the way, if you do have a bad USB port on your Expansion Hub, please reach out to REV and see if they can help. If you do have a bad USB port, perhaps they can repair it for you. I believe Greg from REV mentioned to me once that it's a pretty straightforward process repairing/replacing the USB ports on the Expansion Hub printed circuit boards.

I would definitely recommend that you contact REV and see what they recommend.

technova12611 commented 6 years ago

The new firmware does seem to fix the Problem with issues we had before. This is great.

jdkunzeman commented 6 years ago

@ftctechnh I am already in touch with Rev. Now that we have a little time, the Rev controller with the USB hub problem will come off and be replaced by our spare.

Based on what I saw from @technova12611 above the good Rev module was flashed with the new firmware and three MR color sensors were plugged into it on Friday before we started running. I'm happy to report that we ran much better for about eight hours on Friday and for 4 of 5 matches on Saturday. So, I agree that the new firmware has definitely improved things when using MR color sensors.

We did have one failure to init our teleiop at the competition yesterday. Will report on that next.

jdkunzeman commented 6 years ago

In the last match on Saturday, our robot started on the red balancing stone closest to the audience. The autonomous program started and ran fine, but teleop would not init. We had run successfully from the same position with the same programs in two earlier matches without this problem.

I'm attached what log files I have. Autonomous mode started here per the driver station log:

11-11 15:26:35.175 4746 6624 V DriverStation: {-1797 33.376} Robot Controller starting op mode: Th30-AutoR2

The switch was supposed to occur here but multiple attempts failed to achieve the desired result:

11-11 15:27:05.191 4746 4746 V DriverStation: {-1798 3.392} Stopping current op mode, timer expired 11-11 15:27:05.227 4746 6627 V Robocol : {-1798 3.429} sending CMD_INIT_OP_MODE(12783), attempt: 0

Here's the DS log file: DS_MyTELEOP_2017-11-11init_fail_at_15_27_05_227.txt

Regarding the RC log, unfortunately the one I am able to pull starts after the event with this statement:

11-11 15:27:37.499 4814 6537 V RobotCore: nack rec'd mod=2 msg#=185 ref#=0 reason=I2C_MASTER_BUSY:40

Looking at the phones today, the DS phone's clock is about 4+ seconds ahead of the RC phone's clock, so the log started at about 15:32 in DS phone time, or about 30 seconds after the first attempt to initialize the robot. Could whatever happened have caused the RC log to get blown away, or is there some other reason it's not there? The I2C_MASTER_BUSY messages continue until 15:29:14 in the new log. Can you tell if these messages are coming from one controller or the other? Could this be related to not having updated the second controller?

Our team was not the only one who experienced the "fail to init" problem. I was the FTA and saw several occurrences. I had told our team to follow Phil's startup procedure from above, and I told several others about it during the day. The team said they did follow the procedure prior to our incident.

Here is the RC log that I have:
RC_TheoTelop_2017-11-11_16-03-12.txt

jdkunzeman commented 6 years ago

I found the earlier version of the RC log and will attach a portion.

START OF AUTONOMOUS: 11-11 15:26:33.358 4814 6530 V Robocol : received command: CMD_RUN_OP_MODE(12518) Th30-AutoR2

END OF AUTONOMOUS:? 11-11 15:27:03.456 4814 6540 V ThreadPool: executive service user linear op mode(0x056847b8) is terminated

FIRST ATTEMPT TO START TELEOP: 11-11 15:27:12.596 4814 6530 V Robocol : received command: CMD_INIT_OP_MODE(12944) Theo: TheoTeleop

It looks like we're still having I2C problems. Will get the other controller updated to the latest firmware by replacing it. I'm also wondering if we should stop using MR Color Sensors.

We also don't use the color sensors during teleop. We could maybe switch configuration files between autonomous and teleop if we had to, I guess. Or we could at least try.

RC_TheoTelop_2017-11-11_1525-end.txt

cmacfarl commented 6 years ago

From your log...

11-11 15:22:17.125 4814 6488 I RobotCore: Expansion Hub (HW: 20, Maj: 1, Min: 6, Eng: 0) Expansion Hub 2 USB DQ15PF06; module 2

You are still using 1.6. There are known i2c problems in 1.6. Please upgrade to 1.7.

On Sun, Nov 12, 2017 at 7:15 PM, jdkunzeman notifications@github.com wrote:

I found the earlier version of the RC log and will attach a portion.

START OF AUTONOMOUS: 11-11 15:26:33.358 4814 6530 V Robocol : received command: CMD_RUN_OP_MODE(12518) Th30-AutoR2

END OF AUTONOMOUS:? 11-11 15:27:03.456 4814 6540 V ThreadPool: executive service user linear op mode(0x056847b8) is terminated

FIRST ATTEMPT TO START TELEOP: 11-11 15:27:12.596 4814 6530 V Robocol : received command: CMD_INIT_OP_MODE(12944) Theo: TheoTeleop

It looks like we're still having I2C problems. Will get the other controller updated to the latest firmware by replacing it. I'm also wondering if we should stop using MR Color Sensors.

We also don't use the color sensors during teleop. We could maybe switch configuration files between autonomous and teleop if we had to, I guess. Or we could at least try.

RC_TheoTelop_2017-11-11_1525-end.txt https://github.com/ftctechnh/ftc_app/files/1465506/RC_TheoTelop_2017-11-11_1525-end.txt

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/ftctechnh/ftc_app/issues/447#issuecomment-343798950, or mute the thread https://github.com/notifications/unsubscribe-auth/ABXn93LAhsCxAjpCmCn-DQhfS4R_BinRks5s17RXgaJpZM4QUIw8 .

emmell620 commented 6 years ago

@jdkunzeman I'd recommend not switching config files (if you could) between autonomous and teleop. Eight (8) seconds is all you get and switching the config files causes the robot software to restart. I wonder if you can remove references to it in the teleop code to remove the I2C calls.

gorpong commented 6 years ago

A bit off-topic but as the suggestion is to upgrade to 1.7 of the REV firmware from this issue thread, and I've sent off a support request to REV with no response, I thought I'd post it here. I've got the latest REV Update code but when I initiate the update, (Windows 10, latest updates, can connect to the system just fine and read sensors and adjust servos, so I know communication path is fine) it brings up a the DOS window where it shows that the flash was cleared and then a countdown for the remainder of the 1.7 bin file push. Then the DOS window goes away and the device's LED immediately starts blinking amber.

I can disconnect/reconnect it and bring back up the REV program and it again sees the device, but it constantly blinks amber. I downgraded back to 1.6 and it goes back to the normal green with two blue pulses (the hub's ID), and tried to upgrade it again, with the same results (quick flashing amber). The documentation for the upgrade or the changes doesn't go into details about how things should proceed and the flashing amber isn't even specified as something the LED's will do in the documentation.

Has anyone else experienced this? How do we work around it (I've downloaded the code from REV's site twice, with identical results both times).

WardBenjamin commented 6 years ago

The orange light indicates that (assuming you have the new firmware) you are powered by the robot phone (or USB) only and there is no 12v source present.

gorpong commented 6 years ago

Good to know, thanks! Of course, it would have been nice if REV mentioned that anywhere in the readme, the documentation or anything else.

rachmo commented 6 years ago

@gorpong We have your email in the queue from yesterday and we're doing our best to answer questions in the order which they are received. Mondays are pretty high volume with all the emails from over the weekend so sometimes it takes a few hours.

We wanted to expedite getting the new firmware out since it does have some bug fixes for teams and we're going back to update the user guide with new blink codes this week. Thanks for everyone's patience!

jdkunzeman commented 6 years ago

@cmacfarl thanks for showing me how to find the firmware version in the log files. Actually I have one hub at 1.7 and another at 1.6 for reasons I've detailed above. Soon, they will both be at 1.7. We ran our MR color sensors through the hub on 1.7 and we truly did not have as many problems as earlier. The hub at 1.6 had only one Rev color sensor plugged into I2C. Hopefully getting both hubs to 1.7 will eliminate the I2C problems we've been seeing.