search

garrettsummerfi3ld / SkyStone-Dev

Skystone FTC SDK for Season 2019-2020
https://www.firstinspires.org/robotics/ftc/what-is-first-tech-challenge
0 stars 0 forks source link

Driver Station and Robot Controller pairs do not have a heartbeat #1

Open garrettsummerfi3ld opened 4 years ago

garrettsummerfi3ld commented 4 years ago

Describe the bug Phones connect, but do not see a heartbeat

To Reproduce Steps to reproduce the behavior:

  1. Connect the Driver Station to the Robot Controller
  2. Set phones to see each other in the "Pair with Robot Controller"
  3. Go back to the main screen
  4. Phones connect, but there is no heartbeat

Expected behavior Phones have a heartbeat

Screenshots N/A

Driver Station:

Robot Controller:

Additional context Other phones are able to connect, this could be an issue with how Android 10 handles WiFi security and other weird new permissions.

garrettsummerfi3ld commented 4 years ago

Logcat from Driver Station

2019-11-23 10:58:04.858 737-737/? I/wpa_supplicant: P2P-GO-NEG-SUCCESS role=client freq=5180 ht40=0 peer_dev=d2:db:5d:e1:c6:47 peer_iface=ca:2a:29:a8:13:3b wps_method=PBC
2019-11-23 10:58:05.158 737-737/? I/wpa_supplicant: p2p-p2p0-5: Trying to associate with ca:2a:29:a8:13:3b (SSID='DIRECT-DK-0000-RC' freq=5180 MHz)
2019-11-23 10:58:05.203 737-737/? I/wpa_supplicant: p2p-p2p0-5: Associated with ca:2a:29:a8:13:3b
2019-11-23 10:58:05.206 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
2019-11-23 10:58:05.209 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-EAP-STARTED EAP authentication started
2019-11-23 10:58:05.218 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=14122 method=1
2019-11-23 10:58:05.220 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-EAP-METHOD EAP vendor 14122 method 1 (WSC) selected
2019-11-23 10:58:05.369 737-737/? I/wpa_supplicant: p2p-p2p0-5: WPS-CRED-RECEIVED 
2019-11-23 10:58:05.371 737-737/? I/wpa_supplicant: p2p-p2p0-5: WPS-SUCCESS 
2019-11-23 10:58:05.373 737-737/? I/wpa_supplicant: P2P-GROUP-FORMATION-SUCCESS 
2019-11-23 10:58:05.397 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-EAP-FAILURE EAP authentication failed
2019-11-23 10:58:05.409 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-DISCONNECTED bssid=ca:2a:29:a8:13:3b reason=3 locally_generated=1
2019-11-23 10:58:05.423 737-737/? I/wpa_supplicant: p2p-p2p0-5: Trying to associate with ca:2a:29:a8:13:3b (SSID='DIRECT-DK-0000-RC' freq=5180 MHz)
2019-11-23 10:58:05.465 737-737/? I/wpa_supplicant: p2p-p2p0-5: Associated with ca:2a:29:a8:13:3b
2019-11-23 10:58:05.473 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
2019-11-23 10:58:05.500 737-737/? I/wpa_supplicant: p2p-p2p0-5: WPA: Key negotiation completed with ca:2a:29:a8:13:3b [PTK=CCMP GTK=CCMP]
2019-11-23 10:58:05.502 737-737/? I/wpa_supplicant: p2p-p2p0-5: CTRL-EVENT-CONNECTED - Connection to ca:2a:29:a8:13:3b completed [id=0 id_str=]
2019-11-23 10:58:05.514 737-737/? I/wpa_supplicant: P2P-GROUP-STARTED p2p-p2p0-5 client ssid="DIRECT-DK-0000-RC" freq=5180 go_dev_addr=d2:db:5d:e1:c6:47 [PERSISTENT]
2019-11-23 10:58:05.530 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: wifi direct remembered groups cleared
2019-11-23 10:58:05.632 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: peers found: count=1
2019-11-23 10:58:05.632 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast:     peer: d2:db:5d:e1:c6:47 0000-RC
2019-11-23 10:58:05.632 12851-12851/? D/WifiDirect: broadcast: peers changed
2019-11-23 10:58:05.636 565-646/? D/WifiP2pService: GroupCreatedStatemPendingReformGroupIndication=false
2019-11-23 10:58:05.638 12851-12851/? D/WifiDirect: broadcast: this device changed
2019-11-23 10:58:05.638 12851-12851/? V/WifiDirect: device information: 0000-RC 5e:0a:5b:47:51:a8
2019-11-23 10:58:05.638 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: this device changed: Device=0000-RC deviceAddress=5e:0a:5b:47:51:a8 primary type=10-0050F204-5 secondary type=null wps=0 grpcapab=0 devcapab=0 status=0 wfdInfo=WFD enabled=falseWFD DeviceInfo=0 WFD CtrlPort=0 WFD MaxThroughput=0
2019-11-23 10:58:05.639 12851-12879/? V/NetDiscover_name: remembering wifiDirectName: 0000-RC...
2019-11-23 10:58:05.639 12851-12879/? V/NetDiscover_name: ...remembering wifiDirectName
2019-11-23 10:58:05.646 12851-12851/? V/WifiDirect: peers found: 1
2019-11-23 10:58:05.646 12851-12851/? V/WifiDirect:     peer: d2:db:5d:e1:c6:47 0000-RC
2019-11-23 10:58:05.679 251-586/? D/CommandListener: Clearing all IP addresses on p2p-p2p0-5
2019-11-23 10:58:05.699 565-13129/? D/DhcpClient: Receive thread started
2019-11-23 10:58:05.699 565-13128/? D/DhcpClient: Broadcasting DHCPDISCOVER
2019-11-23 10:58:08.494 565-13129/? D/DhcpClient: Received packet: 5e:0a:5b:47:d1:a8 OFFER, ip /192.168.49.12, mask /255.255.255.0, DNS servers: /192.168.49.1 , gateways [/192.168.49.1] lease time 3600, domain null
2019-11-23 10:58:08.496 565-13128/? D/DhcpClient: Got pending lease: IP address 192.168.49.12/24 Gateway 192.168.49.1  DNS servers: [ 192.168.49.1 ] Domains  DHCP server /192.168.49.1 Vendor info ANDROID_METERED lease 3600 seconds
2019-11-23 10:58:08.498 565-13128/? D/DhcpClient: Broadcasting DHCPREQUEST ciaddr=0.0.0.0 request=192.168.49.12 serverid=192.168.49.1
2019-11-23 10:58:08.515 565-13129/? D/DhcpClient: Received packet: 5e:0a:5b:47:d1:a8 ACK: your new IP /192.168.49.12, netmask /255.255.255.0, gateways [/192.168.49.1] DNS servers: /192.168.49.1 , lease time 3600
2019-11-23 10:58:08.516 565-13128/? D/DhcpClient: Confirmed lease: IP address 192.168.49.12/24 Gateway 192.168.49.1  DNS servers: [ 192.168.49.1 ] Domains  DHCP server /192.168.49.1 Vendor info ANDROID_METERED lease 3600 seconds
2019-11-23 10:58:08.522 251-586/? D/CommandListener: Setting iface cfg
2019-11-23 10:58:08.542 565-13128/? D/DhcpClient: Scheduling renewal in 1799s
2019-11-23 10:58:08.542 565-13128/? D/DhcpClient: Scheduling rebind in 3149s
2019-11-23 10:58:08.542 565-13128/? D/DhcpClient: Scheduling expiry in 3599s
2019-11-23 10:58:08.546 12851-12879/? D/NetDiscover_wifiDirectAgent_bcast: connection changed: networkInfo.state=CONNECTED
2019-11-23 10:58:08.546 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: NetworkInfo: [type: WIFI_P2P[], state: CONNECTED/CONNECTED, reason: (unspecified), extra: (none), failover: false, available: true, roaming: false, metered: false]
2019-11-23 10:58:08.546 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: WifiP2pInfo: groupFormed: true isGroupOwner: false groupOwnerAddress: /192.168.49.1
2019-11-23 10:58:08.546 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: WifiP2pGroup: network: DIRECT-DK-0000-RC, isGO: false, GO: Device: 0000-RC, deviceAddress: d2:db:5d:e1:c6:47, primary type: 10-0050F204-5, secondary type: null, wps: 392, grpcapab: 0, devcapab: 37, status: 4, wfdInfo: WFD enabled: falseWFD DeviceInfo: 0, WFD CtrlPort: 0, WFD MaxThroughput: 0, interface: p2p-p2p0-5, networkId: 0
2019-11-23 10:58:08.547 12851-12851/? D/WifiDirect: broadcast: connection changed: connectStatus=NOT_CONNECTED networkInfo.state=CONNECTED
2019-11-23 10:58:08.547 12851-12851/? V/WifiDirect: writing pref name=pref_wifip2p_groupowner_connectedto value=0000-RC
2019-11-23 10:58:08.547 12851-12851/? V/DriverStation: onSharedPreferenceChanged() pref=pref_wifip2p_groupowner_connectedto
2019-11-23 10:58:08.547 12851-12851/? I/DriverStation: Show match logging UI
2019-11-23 10:58:08.548 12851-12851/? V/NetDiscover_prefremds: onSharedPreferenceChanged(name=pref_wifip2p_groupowner_connectedto, value=0000-RC)
2019-11-23 10:58:08.548 12851-12851/? V/NetDiscover_prefremds: writing pref name=pref_wifip2p_groupowner_lastconnectedto value=0000-RC
2019-11-23 10:58:08.548 12851-12851/? V/DriverStation: onSharedPreferenceChanged() pref=pref_wifip2p_groupowner_lastconnectedto
2019-11-23 10:58:08.548 12851-12851/? I/DriverStation: Show match logging UI
2019-11-23 10:58:08.548 12851-12851/? V/NetDiscover_prefremds: onSharedPreferenceChanged(name=pref_wifip2p_groupowner_lastconnectedto, value=0000-RC)
2019-11-23 10:58:08.649 12851-12851/? D/WifiDirect: group owners address: /192.168.49.1
2019-11-23 10:58:08.649 12851-12851/? D/WifiDirect: group formed, this device is a client
2019-11-23 10:58:08.652 12851-12851/? V/WifiDirect: connection information available
2019-11-23 10:58:08.652 12851-12851/? V/WifiDirect: connection information - groupOwnerName = 0000-RC
2019-11-23 10:58:08.653 12851-12851/? V/WifiDirect: connection information - groupOwnerMacAddress = d2:db:5d:e1:c6:47
2019-11-23 10:58:08.653 12851-12851/? V/WifiDirect: connection information - groupInterface = p2p-p2p0-5
2019-11-23 10:58:08.653 12851-12851/? V/WifiDirect: connection information - groupNetworkName = DIRECT-DK-0000-RC
2019-11-23 10:58:19.032 13063-13063/? D/AdvancedWifiSettings: Fail to get priority pref...
2019-11-23 10:58:19.162 13063-13144/? W/TileUtils: Found com.android.systemui.tuner.TunerActivity for intent Intent { act=com.android.settings.action.EXTRA_SETTINGS } missing metadata 
2019-11-23 10:58:19.203 13063-13147/? D/Index: Indexing locale 'en_US' took 35 millis
2019-11-23 10:58:19.256 13063-13147/? D/Index: Indexing locale 'en_US' took 11 millis
2019-11-23 10:58:19.867 565-3203/? I/ActivityManager: START u0 {flg=0x10804000 cmp=com.android.systemui/.recents.RecentsActivity} from uid 10023 on display 0
2019-11-23 10:58:20.126 565-6877/? E/ActivityManager: applyOptionsLocked: Unknown animationType=0
2019-11-23 10:58:20.187 12851-12851/? E/RobotConfigFileManager: unable to find header text 0x7f070073
2019-11-23 10:58:20.245 685-700/? I/art: Background partial concurrent mark sweep GC freed 201706(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 16MB/26MB, paused 976us total 349.092ms
2019-11-23 10:58:20.455 565-575/? I/art: Background partial concurrent mark sweep GC freed 94545(4MB) AllocSpace objects, 8(160KB) LOS objects, 33% free, 18MB/27MB, paused 6.256ms total 551.381ms
2019-11-23 10:58:21.378 12851-12851/? V/RobotCore: FtcDriverStationSettingsActivity: backPressed received
2019-11-23 10:58:21.409 12851-12851/? V/DriverStation: onActivityResult(request=4)
2019-11-23 10:58:21.410 12851-12851/? V/DriverStation: startOrRestartNetwork()
2019-11-23 10:58:21.410 12851-12851/? V/DriverStation: Assuming client disconnected
2019-11-23 10:58:21.410 12851-12851/? V/DriverStation: ui:uiRobotControllerIsDisconnected
2019-11-23 10:58:21.410 12851-12851/? I/DriverStation: Show match logging UI
2019-11-23 10:58:21.411 12851-12851/? V/RobotCore: Getting network assistant of type: WIFIDIRECT
2019-11-23 10:58:21.413 12851-12851/? V/WifiDirect: There are 2 Wifi Direct Assistant Clients (+)
2019-11-23 10:58:21.417 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: wifiP2pEnabled=true
2019-11-23 10:58:21.418 12851-12851/? V/Robocol: Spoofing a Network Connection event...
2019-11-23 10:58:21.418 12851-12851/? I/RobotCore: Received networkConnectionEvent: CONNECTION_INFO_AVAILABLE
2019-11-23 10:58:21.419 12851-12879/? D/NetDiscover_wifiDirectAgent_bcast: connection changed: networkInfo.state=CONNECTED
2019-11-23 10:58:21.419 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: NetworkInfo: [type: WIFI_P2P[], state: CONNECTED/CONNECTED, reason: (unspecified), extra: (none), failover: false, available: true, roaming: false, metered: false]
2019-11-23 10:58:21.420 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: WifiP2pInfo: groupFormed: true isGroupOwner: false groupOwnerAddress: /192.168.49.1
2019-11-23 10:58:21.420 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: WifiP2pGroup: network: DIRECT-DK-0000-RC, isGO: false, GO: Device: 0000-RC, deviceAddress: d2:db:5d:e1:c6:47, primary type: 10-0050F204-5, secondary type: null, wps: 392, grpcapab: 0, devcapab: 37, status: 4, wfdInfo: WFD enabled: falseWFD DeviceInfo: 0, WFD CtrlPort: 0, WFD MaxThroughput: 0, interface: p2p-p2p0-5, networkId: 0
2019-11-23 10:58:21.431 12851-12851/? I/NetworkConnectionHandler: Handling new network connection infomation, connected: true setup needed: true
2019-11-23 10:58:21.431 12851-12851/? D/WifiDirect: stop discovering peers
2019-11-23 10:58:21.432 12851-12851/? V/DriverStation: Assuming client connected
2019-11-23 10:58:21.432 12851-12851/? V/DriverStation: writing pref name=pref_rc_connected value=true
2019-11-23 10:58:21.432 12851-12851/? V/DriverStation: onSharedPreferenceChanged() pref=pref_rc_connected
2019-11-23 10:58:21.432 12851-12851/? I/DriverStation: Show match logging UI
2019-11-23 10:58:21.433 12851-12851/? V/NetDiscover_prefremds: onSharedPreferenceChanged(name=pref_rc_connected, value=true)
2019-11-23 10:58:21.433 12851-12851/? V/DriverStation: ui:uiRobotControllerIsConnected
2019-11-23 10:58:21.435 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: this device changed: Device=0000-RC deviceAddress=5e:0a:5b:47:51:a8 primary type=10-0050F204-5 secondary type=null wps=0 grpcapab=0 devcapab=0 status=0 wfdInfo=WFD enabled=falseWFD DeviceInfo=0 WFD CtrlPort=0 WFD MaxThroughput=0
2019-11-23 10:58:21.436 12851-12879/? V/NetDiscover_name: remembering wifiDirectName: 0000-RC...
2019-11-23 10:58:21.436 12851-12879/? V/NetDiscover_name: ...remembering wifiDirectName
2019-11-23 10:58:21.436 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: p2p discoverPeers()=false
2019-11-23 10:58:21.443 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: wifi direct remembered groups cleared
2019-11-23 10:58:21.443 12851-12879/? V/NetDiscover_wifiDirectAgent_bcast: wifiState=ENABLED
2019-11-23 10:58:21.445 12851-12851/? V/DriverStation: onStart()
2019-11-23 10:58:21.445 12851-12851/? V/StateMachine: State with no transitions: WifiState
2019-11-23 10:58:21.445 12851-12851/? I/StateMachine: Unmasking STOPPED_OPMODE
2019-11-23 10:58:21.446 12851-12851/? V/DriverStation: onResume()
2019-11-23 10:58:21.446 12851-12851/? V/DriverStation: updateBatteryIndependence(true)
2019-11-23 10:58:21.505 12851-13169/? V/RobotCore: thread: 'SetupRunnable.run()' starting...
2019-11-23 10:58:21.585 12851-13169/? D/Robocol: RobocolDatagramSocket listening addr=/192.168.49.12:20884 cbRec=65520 cbSend=81920 msRecTO=300
2019-11-23 10:58:21.585 12851-13169/? D/Robocol: RobocolDatagramSocket connected to /192.168.49.1:20884
2019-11-23 10:58:21.587 12851-13169/? V/Robocol: RecvLoopRunnable created
2019-11-23 10:58:21.588 12851-13169/? V/ThreadPool: container(0x08e79499: ReceiveLoopService) added id=6019 TID=0 count=1
2019-11-23 10:58:21.591 12851-13169/? V/ThreadPool: container(0x08e79499: ReceiveLoopService) added id=6020 TID=0 count=2
2019-11-23 10:58:21.592 12851-13169/? V/PeerDiscovery: Starting peer discovery remote: /192.168.49.1 local: /192.168.49.12
2019-11-23 10:58:21.593 12851-13169/? V/ThreadPool: container(0x0295940c: discovery service) added id=6021 TID=0 count=1
2019-11-23 10:58:21.593 12851-13169/? V/RobotCore: Setup complete
2019-11-23 10:58:21.593 12851-13169/? V/RobotCore: thread: ...terminating 'SetupRunnable.run()'
2019-11-23 10:58:21.594 12851-13176/? V/RobotCore: thread: 'RecvLoopRunnable.run()' starting...
2019-11-23 10:58:21.854 233-233/? W/SurfaceFlinger: couldn't log to binary event log: overflow.
2019-11-23 10:58:21.910 12851-13176/? E/Robocol: exception SocketTimeoutException(Receive timed out): no packet received [java.net.PlainDatagramSocketImpl.receive0(Native Method)]