osrf / uctf

Unmanned Capture the Flag (U-CTF) project.
Apache License 2.0
24 stars 10 forks source link

Tactics deactivating on copters due to invalid altitudes #114

Open tfoote opened 7 years ago

tfoote commented 7 years ago

I'm filing this ticket here since it's an observation of a overall system behavior and it's important to document. It will likely need to be refiled and fixed somewhere else eventually once it's root caused.

While running tests I observed several vehicles reporting invalid altitudes briefly.

I got a few screen shots of the conditions. The vehicles would be reporting invalid altitudes temporarily before returning to expect altutides in the FTI interface. invalid altitudes invalid altitudes_stil active

I was observing this during the ingress phase, documented it as above and then moved on. It did not appear to be effecting the actual flying. And going from 150m to single digit and back to 150m in a few seconds is not physically feasible.

After engaging some tactics I observed some of them drop out immediately and there seemed to be a correlation with the ones reporting bad altitudes.

After the run I dug into the logs and saw that in swarm_control Behaviors were self disabling.

Looking at the logs for Iris 3

[rosout][INFO] 2017-03-03 22:58:52,622: Swarm state updated to Flight Ready
[rosout][INFO] 2017-03-03 23:02:07,648: Swarm state updated to Ingress
[rospy.internal][INFO] 2017-03-03 23:05:48,026: topic[/network/net_reset] adding connection to [http://192.168.2.12:33635/], count 0
[rosout][INFO] 2017-03-03 23:05:56,301: Swarm state updated to Swarm Ready
[rosout][INFO] 2017-03-03 23:12:33,730: Subswarm updated to 1
[rosout][INFO] 2017-03-03 23:13:18,243: Active swarm behavior updated to standby
[rosout][INFO] 2017-03-03 23:13:19,268: Active swarm behavior updated to tactic_interface
[rosout][INFO] 2017-03-03 23:13:19,269: tactic_interface behavior successfully activated
[rospy.internal][INFO] 2017-03-03 23:13:33,124: topic[/network/recv_swarm_data] adding connection to [http://192.168.2.12:33635/], count 0
[rosout][WARNING] 2017-03-03 23:15:43,954: Behavior 14 unexpected inactive report
[rosout][INFO] 2017-03-03 23:15:43,979: Active swarm behavior updated to standby
[rosout][INFO] 2017-03-03 23:17:18,772: Active swarm behavior updated to standby
[rosout][INFO] 2017-03-03 23:17:19,787: Active swarm behavior updated to tactic_interface
[rosout][INFO] 2017-03-03 23:17:19,788: tactic_interface behavior successfully activated
[rosout][WARNING] 2017-03-03 23:18:42,146: Behavior 14 unexpected inactive report
[rosout][INFO] 2017-03-03 23:18:42,217: Active swarm behavior updated to standby
[rosout][INFO] 2017-03-03 23:19:18,250: Active swarm behavior updated to standby
[rosout][INFO] 2017-03-03 23:19:18,251: Subswarm updated to 0
[rosout][INFO] 2017-03-03 23:19:18,251: Received game reset--set to pre-game states
[rosout][INFO] 2017-03-03 23:19:37,441: Swarm state updated to State Error
[rosout][INFO] 2017-03-03 23:19:37,451: Active swarm behavior updated to standby
[rosout][INFO] 2017-03-03 23:19:37,453: Subswarm updated to 0

And the swarm tracker gave a reason:

[rosout][INFO] 2017-03-03 23:13:18,226: tactic_interface ready state set to 'True'
[rosout][INFO] 2017-03-03 23:13:18,226: tactic_interface set request returned True
[rosout][INFO] 2017-03-03 23:13:18,240: tactic_interface activate request False returned False
[rosout][INFO] 2017-03-03 23:13:19,255: activating behavior tactic_interface
[rosout][INFO] 2017-03-03 23:13:19,256: tactic_interface activate request True returned True
[rospy.internal][INFO] 2017-03-03 23:13:33,103: topic[/network/recv_swarm_data] adding connection to [http://192.168.2.12:33635/], count 0
[rosout][INFO] 2017-03-03 23:15:43,944: deactivating behavior tactic_interface
[rospy.internal][INFO] 2017-03-03 23:15:43,944: topic impl's ref count is zero, deleting topic /swarm_tracker/swarm_uav_states...
[rospy.internal][INFO] 2017-03-03 23:15:43,945: topic[/swarm_tracker/swarm_uav_states] removing connection to http://192.168.2.12:38942/
[rospy.internal][INFO] 2017-03-03 23:15:43,948: topic impl's ref count is zero, deleting topic /red_tracker/red_uav_states...
[rospy.internal][INFO] 2017-03-03 23:15:43,948: topic[/red_tracker/red_uav_states] removing connection to http://192.168.2.12:41357/
[rosout][INFO] 2017-03-03 23:15:43,954: tactic_interface ready state and active state set to 'False'
[rosout][WARNING] 2017-03-03 23:15:43,954: Altitude control mode invalid or invalid altitude order
[rosout][WARNING] 2017-03-03 23:15:43,955: Attempted invalid waypoint:
[rosout][WARNING] 2017-03-03 23:15:43,955: lat: 35.7215871437
lon: -120.7663218
alt: -0.25
[rosout][INFO] 2017-03-03 23:15:43,975: tactic_interface activate request False returned False
[rospy.internal][INFO] 2017-03-03 23:17:17,687: topic[/red_tracker/red_uav_states] adding connection to [http://192.168.2.12:41357/], count 0
[rospy.internal][INFO] 2017-03-03 23:17:18,191: topic[/swarm_tracker/swarm_uav_states] adding connection to [http://192.168.2.12:38942/], count 0
[rosout][INFO] 2017-03-03 23:17:18,762: tactic_interface ready state set to 'True'
[rosout][INFO] 2017-03-03 23:17:18,763: tactic_interface set request returned True
[rosout][INFO] 2017-03-03 23:17:18,770: tactic_interface activate request False returned False
[rosout][INFO] 2017-03-03 23:17:19,780: activating behavior tactic_interface
[rosout][INFO] 2017-03-03 23:17:19,781: tactic_interface activate request True returned True
[rosout][INFO] 2017-03-03 23:17:24,871: Swarm shooter fired at UAV 136: (35.722561, -120.769105, 463.550000)
[rosout][INFO] 2017-03-03 23:18:42,137: deactivating behavior tactic_interface
[rospy.internal][INFO] 2017-03-03 23:18:42,137: topic impl's ref count is zero, deleting topic /swarm_tracker/swarm_uav_states...
[rospy.internal][INFO] 2017-03-03 23:18:42,138: topic[/swarm_tracker/swarm_uav_states] removing connection to http://192.168.2.12:38942/
[rospy.internal][INFO] 2017-03-03 23:18:42,143: topic impl's ref count is zero, deleting topic /red_tracker/red_uav_states...
[rospy.internal][INFO] 2017-03-03 23:18:42,143: topic[/red_tracker/red_uav_states] removing connection to http://192.168.2.12:41357/
[rosout][INFO] 2017-03-03 23:18:42,146: tactic_interface ready state and active state set to 'False'
[rosout][WARNING] 2017-03-03 23:18:42,159: Altitude control mode invalid or invalid altitude order
[rosout][WARNING] 2017-03-03 23:18:42,160: Attempted invalid waypoint:
[rosout][WARNING] 2017-03-03 23:18:42,160: lat: 35.7215874
lon: -120.7663218
alt: -0.24
[rosout][INFO] 2017-03-03 23:18:42,208: tactic_interface activate request False returned False

And I noticed the altitude of -0.24 looks a lot like some of the invalid altitude reports I had seen. Thus I believe that the copters are temporarily getting invalid states, and when they compute their target waypoints based on their current states they're deemed invalid as being too low.

A screen capture of the run can be seen here: https://youtu.be/acDmHkkub7I

I have a full log of the engagement period. Iris 3 only appeared to deactivate 2 times.

There was an event at ~ 2:35 where all blue vehicles deactivated: https://youtu.be/acDmHkkub7I?t=2m33s also that is undiagnosted.

It happened a 2nd time around 5:29 https://youtu.be/acDmHkkub7I?t=5m29s

tfoote commented 7 years ago

Debugging with Paul the invalid altitudes have also been observed on zephyrs causing deactivations.

[rosout][INFO] 2017-03-06 17:28:42,663: tactic_interface ready state set to 'True'
[rosout][INFO] 2017-03-06 17:28:42,663: tactic_interface set request returned True
[rosout][INFO] 2017-03-06 17:28:42,672: tactic_interface activate request False returned False
[rosout][INFO] 2017-03-06 17:28:43,692: activating behavior tactic_interface
[rosout][INFO] 2017-03-06 17:28:43,693: tactic_interface activate request True returned True
[rosout][INFO] 2017-03-06 17:28:43,840: deactivating behavior tactic_interface
[rospy.internal][INFO] 2017-03-06 17:28:43,840: topic impl's ref count is zero, deleting topic /swarm_tracker/swarm_uav_states...
[rospy.internal][INFO] 2017-03-06 17:28:43,841: topic[/swarm_tracker/swarm_uav_states] removing connection to http://192.168.2.10:35423/
[rospy.internal][INFO] 2017-03-06 17:28:43,861: topic impl's ref count is zero, deleting topic /red_tracker/red_uav_states...
[rospy.internal][INFO] 2017-03-06 17:28:43,862: topic[/red_tracker/red_uav_states] removing connection to http://192.168.2.10:35993/
[rosout][INFO] 2017-03-06 17:28:43,971: tactic_interface ready state and active state set to 'False'
[rosout][WARNING] 2017-03-06 17:28:43,975: Altitude control mode invalid or invalid altitude order
[rosout][WARNING] 2017-03-06 17:28:43,977: Attempted invalid waypoint:
[rosout][WARNING] 2017-03-06 17:28:43,977: lat: 35.7201016869
lon: -120.758527138
alt: -10132.22
[rosout][INFO] 2017-03-06 17:28:52,067: tactic_interface activate request False returned False
[rospy.internal][INFO] 2017-03-06 17:29:17,618: topic[/red_tracker/red_uav_states] adding connection to [http://192.168.2.10:35993/], count 0
[rospy.internal][INFO] 2017-03-06 17:29:18,119: topic[/swarm_tracker/swarm_uav_states] adding connection to [http://192.168.2.10:35423/], count 0
[rosout][INFO] 2017-03-06 17:29:18,825: tactic_interface ready state set to 'True'
[rosout][INFO] 2017-03-06 17:29:18,826: tactic_interface set request returned True
[rosout][INFO] 2017-03-06 17:29:18,835: tactic_interface activate request False returned False
[rosout][INFO] 2017-03-06 17:29:19,867: activating behavior tactic_interface
[rosout][INFO] 2017-03-06 17:29:19,870: tactic_interface activate request True returned True
[rosout][INFO] 2017-03-06 17:29:56,956: deactivating behavior tactic_interface
[rospy.internal][INFO] 2017-03-06 17:29:56,956: topic impl's ref count is zero, deleting topic /swarm_tracker/swarm_uav_states...
[rospy.internal][INFO] 2017-03-06 17:29:56,956: topic[/swarm_tracker/swarm_uav_states] removing connection to http://192.168.2.10:35423/
[rospy.internal][INFO] 2017-03-06 17:29:56,959: topic impl's ref count is zero, deleting topic /red_tracker/red_uav_states...
[rospy.internal][INFO] 2017-03-06 17:29:56,959: topic[/red_tracker/red_uav_states] removing connection to http://192.168.2.10:35993/
[rosout][INFO] 2017-03-06 17:29:56,963: tactic_interface ready state and active state set to 'False'
[rosout][WARNING] 2017-03-06 17:29:56,963: Altitude control mode invalid or invalid altitude order
[rosout][WARNING] 2017-03-06 17:29:56,964: Attempted invalid waypoint:
[rosout][WARNING] 2017-03-06 17:29:56,966: lat: 35.7219474052
lon: -120.757675004
alt: -10132.26
[rosout][INFO] 2017-03-06 17:29:56,975: tactic_interface activate request False returned False
[rospy.internal][INFO] 2017-03-06 17:41:02,700: topic[/red_tracker/red_uav_states] adding connection to [http://192.168.2.10:35993/], count 0
[rospy.internal][INFO] 2017-03-06 17:41:03,166: topic[/swarm_tracker/swarm_uav_states] adding connection to [http://192.168.2.10:35423/], count 0
[rosout][INFO] 2017-03-06 17:41:03,769: tactic_interface ready state set to 'True'
[rosout][INFO] 2017-03-06 17:41:03,769: tactic_interface set request returned True
[rosout][INFO] 2017-03-06 17:41:03,784: tactic_interface activate request False returned False
[rosout][INFO] 2017-03-06 17:41:04,811: activating behavior tactic_interface
[rosout][INFO] 2017-03-06 17:41:04,811: tactic_interface activate request True returned True
[rosout][INFO] 2017-03-06 17:41:19,158: deactivating behavior tactic_interface
[rospy.internal][INFO] 2017-03-06 17:41:19,159: topic impl's ref count is zero, deleting topic /swarm_tracker/swarm_uav_states...
[rospy.internal][INFO] 2017-03-06 17:41:19,159: topic[/swarm_tracker/swarm_uav_states] removing connection to http://192.168.2.10:35423/
[rospy.internal][INFO] 2017-03-06 17:41:19,161: topic impl's ref count is zero, deleting topic /red_tracker/red_uav_states...
[rospy.internal][INFO] 2017-03-06 17:41:19,162: topic[/red_tracker/red_uav_states] removing connection to http://192.168.2.10:35993/
[rosout][INFO] 2017-03-06 17:41:19,164: tactic_interface ready state and active state set to 'False'
[rosout][WARNING] 2017-03-06 17:41:19,164: Altitude control mode invalid or invalid altitude order
[rosout][WARNING] 2017-03-06 17:41:19,165: Attempted invalid waypoint:
[rosout][WARNING] 2017-03-06 17:41:19,165: lat: 35.7210690792
lon: -120.757645338
alt: -10132.82
[rosout][INFO] 2017-03-06 17:41:19,177: tactic_interface activate request False returned False
[rospy.internal][INFO] 2017-03-06 17:41:35,213: topic[/red_tracker/red_uav_states] adding connection to [http://192.168.2.10:35993/], count 0
[rospy.internal][INFO] 2017-03-06 17:41:35,712: topic[/swarm_tracker/swarm_uav_states] adding connection to [http://192.168.2.10:35423/], count 0
[rosout][INFO] 2017-03-06 17:41:36,314: tactic_interface ready state set to 'True'
[rosout][INFO] 2017-03-06 17:41:36,315: tactic_interface set request returned True
[rosout][INFO] 2017-03-06 17:41:36,350: tactic_interface activate request False returned False
[rosout][INFO] 2017-03-06 17:41:37,360: activating behavior tactic_interface
[rosout][INFO] 2017-03-06 17:41:37,361: tactic_interface activate request True returned True
[rosout][INFO] 2017-03-06 17:41:58,796: Swarm shooter fired at UAV 138: (35.722030, -120.767603, 522.429000)
[rosout][INFO] 2017-03-06 17:41:59,112: Swarm shooter fired at UAV 138: (35.722030, -120.767603, 522.308000)
[rosout][INFO] 2017-03-06 17:41:59,379: Swarm shooter fired at UAV 138: (35.722022, -120.767610, 522.308000)
[rosout][INFO] 2017-03-06 17:41:59,698: Swarm shooter fired at UAV 138: (35.722013, -120.767616, 522.210000)
[rosout][INFO] 2017-03-06 17:41:59,969: Swarm shooter fired at UAV 138: (35.721996, -120.767629, 522.080000)
[rosout][INFO] 2017-03-06 17:42:00,235: Swarm shooter fired at UAV 138: (35.721988, -120.767635, 522.080000)
[rosout][INFO] 2017-03-06 17:42:00,505: Swarm shooter fired at UAV 138: (35.721979, -120.767640, 522.000000)
[rosout][INFO] 2017-03-06 17:42:00,823: Swarm shooter fired at UAV 138: (35.721962, -120.767651, 521.950000)
[rosout][INFO] 2017-03-06 17:42:01,142: Swarm shooter fired at UAV 138: (35.721954, -120.767657, 521.950000)
[rosout][INFO] 2017-03-06 17:42:12,018: Swarm shooter fired at UAV 139: (35.721722, -120.766971, 515.480000)
[rosout][INFO] 2017-03-06 17:42:12,339: Swarm shooter fired at UAV 139: (35.721732, -120.766995, 515.289000)
[rosout][INFO] 2017-03-06 17:42:12,655: Swarm shooter fired at UAV 139: (35.721737, -120.767006, 515.280000)
[rosout][INFO] 2017-03-06 17:42:12,972: Swarm shooter fired at UAV 139: (35.721742, -120.767018, 515.330000)
[rosout][INFO] 2017-03-06 17:42:13,242: Swarm shooter fired at UAV 139: (35.721746, -120.767030, 515.419000)
[rosout][INFO] 2017-03-06 17:42:13,510: Swarm shooter fired at UAV 139: (35.721746, -120.767030, 515.419000)
[rosout][INFO] 2017-03-06 17:42:13,827: Swarm shooter fired at UAV 139: (35.721755, -120.767053, 515.690000)
[rosout][INFO] 2017-03-06 17:42:14,093: Swarm shooter fired at UAV 139: (35.721759, -120.767065, 515.840000)
[rosout][INFO] 2017-03-06 17:42:14,361: Swarm shooter fired at UAV 139: (35.721763, -120.767076, 515.990000)
[rosout][INFO] 2017-03-06 17:42:14,627: Swarm shooter fired at UAV 139: (35.721767, -120.767088, 516.120000)
[rosout][INFO] 2017-03-06 17:42:14,896: Swarm shooter fired at UAV 139: (35.721767, -120.767088, 516.120000)
[rosout][INFO] 2017-03-06 17:42:15,213: Swarm shooter fired at UAV 139: (35.721774, -120.767111, 516.320000)