I've had a bit of a traumatic time with my new Edge 830, but unquestionably the worst part is it's inability to stay connected to my phone and, thus, maintain a LiveTrack session throughout a ride. I went out for a ride tonight, specifically to trigger this and then provide some diagnostics in the hope that I will get some assistance.
I manually started Garmin Connect on my Samsung Galaxy S8+ (Android 9, Pie, July 2019 security patches) and ensured that my Edge 830 (running 4.10 - latest) was connected. I started the ride and, as expected, LiveTrack automatically started triggering the normal SMS and email notifications. I then proceeded to ride.
Subsequent analysis shows that the LiveTrack session lasted less than half a mile from home, at which point the device disconnected and no further updates were received until around half way round the ride (approx one hour in), when I manually started GC on my phone and the device reconnected. LiveTrack continued from this point without further incident, although the first half of the ride was lost.
Diagnosing this, I can see that the LiveTrack was attempted to be started:
Aug-26;5:15:44.539PM [DispatcherRead (C0:00:2F:FF:BD:B5)] T/GFDI#LiveTrackStateManager@5edbf7e [C0:00:2F:FF:BD:B5] - Auto start live track requested
...and, after a certain amount of chatter in the logs, started successfully:
Aug-26;5:15:49.979PM [main] D/LT#GCMLiveTrackManager - mLiveTrackServiceBroadcastReceiver: GCM mode for live track start success status -> AUTO_START
...and starts to send positions (redacted for privacy):
Aug-26;5:16:05.207PM [pool-31-thread-1] D/LT#LiveTrackUtil - point 1|activity ts 1566836151000|lat yy.yyyyyyyyyy|lon xx.xxxxxxxxxxxx|point ts 05:15.51 PM|act CYCLING|dist/dist total (M):0.0/0.0|dur/dur total (S):0.0/0.0|event:BEGIN|
So, now we're up and running and I see about a dozen or so positions sent successfully in a handful of batches (it sends several positions in one go to reduce bluetooth and cellular chatter) before things stop working.
I'll post the whole snippet here and explain what I think might be happening:
Aug-26;5:16:41.021PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GFDI#ProtobufStateManagerBase@d5a71a5 [10:4E:89:EA:3D:1E] - Request-Response[protobuf message base] msg id: 5000, length: 17, data offset: 0, payload: [ B3 13 00 70 01 00 00 00 00 00 00 ], crc: 0x0000
Aug-26;5:16:41.023PM [DispatcherWrite (10:4E:89:EA:3D:1E)] D/GFDI#Dispatcher@f53a804 [10:4E:89:EA:3D:1E] - Sending response: [protobuf message base] msg id: 5000, length: 17, data offset: 0, payload: [ B3 13 00 70 01 00 00 00 00 00 00 ], crc: 0x0000
Aug-26;5:16:41.030PM [Thread-448] D/HttpProtoRequestHandler - Raw Resource Request Url: www.strava.com/.../16290757
Aug-26;5:16:41.031PM [Thread-448] D/HttpProtoRequestHandler - Raw Resource Request Max Response Length: 0
Aug-26;5:16:41.032PM [Thread-448] D/HttpProtoRequestHandler - Raw Resource Request HttpCall:www.strava.com/.../16290757
Aug-26;5:16:41.340PM [Thread-448] D/HttpProtoRequestHandler - Raw Resource Request Response Code: 400
Aug-26;5:16:41.342PM [Thread-448] D/GFDI#ProtobufStateManagerBase@8c0d97a [10:4E:89:EA:3D:1E] - addToTransferQueue
Aug-26;5:16:41.348PM [GFDI_DispatcherRetryTimer] I/GFDI#Dispatcher@f53a804 [10:4E:89:EA:3D:1E] - Queueing message: [protobuf message base] msg id: 5044, length: 29, payload size: 9, data offset: 0, payload: [ 70 01 00 00 00 00 09 00 00 00 09 00 00 00 12 07 32 05 08 00 10 90 03 ], crc: 0x0000 (retry countdown: 3)
Aug-26;5:16:41.353PM [DispatcherWrite (10:4E:89:EA:3D:1E)] D/GFDI#Dispatcher@f53a804 [10:4E:89:EA:3D:1E] - Sending message: [protobuf message base] msg id: 5044, length: 29, payload size: 9, data offset: 0, payload: [ 70 01 00 00 00 00 09 00 00 00 09 00 00 00 12 07 32 05 08 00 10 90 03 ], crc: 0x0000
Aug-26;5:16:41.450PM [DispatcherRead (10:4E:89:EA:3D:1E)] T/GFDI#Dispatcher@f53a804 [10:4E:89:EA:3D:1E] - ## Got ACK for message ID: 5044 @ 0826_17:16:41.45
Aug-26;5:16:41.453PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GFDI#ProtobufStateManagerBase@8c0d97a [10:4E:89:EA:3D:1E] - processDataResponseMessage: Processing [protobuf message base] msg id: 5000, length: 17, data offset: 0, payload: [ B4 13 00 70 01 00 00 00 00 00 00 ], crc: 0x0000
Aug-26;5:16:41.454PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GFDI#ProtobufStateManagerBase@8c0d97a [10:4E:89:EA:3D:1E] - Transfer was successful!
Aug-26;5:16:41.872PM [DispatcherRead (10:4E:89:EA:3D:1E)] I/GFDI#Dispatcher@f53a804 [10:4E:89:EA:3D:1E] - *** EXIT DISPATCHER [10:4E:89:EA:3D:1E] ***
Aug-26;5:16:41.874PM [DispatcherRead (10:4E:89:EA:3D:1E)] T/GDI#MessageHandlerContainer@ac66822 [10:4E:89:EA:3D:1E] - terminate: begin
Aug-26;5:16:41.888PM [DispatcherRead (10:4E:89:EA:3D:1E)] T/GFDI#BatteryStatusStateManager@3654070 [10:4E:89:EA:3D:1E] - Timer Stopped
Aug-26;5:16:41.892PM [DispatcherRead (10:4E:89:EA:3D:1E)] T/GDI#MessageHandlerContainer@ac66822 [10:4E:89:EA:3D:1E] - terminate: end
Aug-26;5:16:41.894PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GDI#DeviceManager@ae7f1ed [10:4E:89:EA:3D:1E] - Terminating RemoteDeviceProxy (DeviceManager)
Aug-26;5:16:41.896PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GDI#GdiRegistry@ebdb77 - Unregistered remote device proxy: macAddress=10:4E:89:EA:3D:1E
Aug-26;5:16:41.900PM [DispatcherRead (10:4E:89:EA:3D:1E)] I/GDI#GdiService@7d78023 -
************************************************************
** Remote device disconnected! [Edge 830 (10:4E:89:EA:3D:1E/3998100638) - BLUETOOTH_CLASSIC]
************************************************************
Aug-26;5:16:41.900PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GDI#GdiRegistry@ebdb77 - Unregistered remote device proxy: macAddress=10:4E:89:EA:3D:1E
Aug-26;5:16:41.901PM [DispatcherRead (10:4E:89:EA:3D:1E)] D/GDI#GdiService@7d78023 - Local & global broadcasting com.garmin.android.gdi.ACTION_DEVICE_DISCONNECTED Bundle[{com.garmin.android.gdi.EXTRA_GATT_STATUS=GCM_NOT_RECOGNIZED_GATT_FAILURE, com.garmin.android.gdi.EXTRA_REMOTE_DEVICE_MAC_ADDRESS=10:4E:89:EA:3D:1E, com.garmin.android.gdi.EXTRA_REMOTE_DEVICE_PROFILE=RemoteDeviceProfile:
unitId:xxxxxxxx
productNumber:3122
deviceName:Edge
deviceModelName:830
softwareVersion:410
dualBluetoothConnection:true
, com.garmin.android.gdi.EXTRA_REMOTE_DEVICE_UNIT_ID=xxxxxxx}]
Aug-26;5:16:41.926PM [main] D/GNCSTrace - Received action: com.garmin.android.gdi.ACTION_DEVICE_DISCONNECTED
Aug-26;5:16:41.930PM [main] D/LT#GCMLiveTrackManager - handleMesgBroadcasterRemoved: set service's mMesgBroadcasterListenersAlive to FALSE
Aug-26;5:16:41.933PM [pool-28-thread-5] D/SYNC#FullSyncStrategy [xxxxx] - Device disconnected while sync isn't running. Cleanup strategy
Aug-26;5:16:41.933PM [pool-28-thread-5] T/SYNC#FullSyncStrategy [xxxxx] - terminate: begin
Aug-26;5:16:41.933PM [SYNC_SyncDispatchThread] D/SYNC#DeviceSyncManager - [xxxxx] ACTION_DEVICE_DISCONNECTED!
Aug-26;5:16:41.938PM [pool-28-thread-5] D/SYNC#DeviceSyncTime - terminate: begin
Aug-26;5:16:41.942PM [pool-28-thread-5] D/SYNC#DeviceSyncTime - terminate: end
Aug-26;5:16:41.944PM [pool-28-thread-5] D/SYNC#DeviceSyncUpload - terminate: begin
Aug-26;5:16:41.946PM [pool-28-thread-5] D/SYNC#DeviceSyncUpload - terminate: end
Aug-26;5:16:41.946PM [pool-28-thread-5] D/SYNC#DeviceSyncDownload - terminate: begin
Aug-26;5:16:41.947PM [pool-28-thread-5] D/SYNC#DeviceSyncDownload - terminate: end
Aug-26;5:16:41.947PM [pool-28-thread-5] T/SYNC#FullSyncStrategy [xxxxx] - terminate: end
As you can see, GC attempts to make a call to Strava's API, but receives a 400 ("bad request") response. This isn't the first time this has been called, nor the first time it's received an error, but this time, immediately after, GC shuts down the message dispatcher - the component that relays messages to and from the device - which terminates cleanly. From this point, no further data is sent or received by LiveTrack, until I manually restarted Garmin Connect.
So, the big question here is why is the dispatcher being terminated and why, if it is being done intentionally, is it not automatically being restarted again? Is this a phone resource issue (I specifically rebooted my own phone immediately prior to this test so I could be sure there were no extraneous background processes running), or a side effect of the Strava API error not being handled gracefully?
I'll happily forward this on to anyone at Garmin that might be interested. I obviously have the full logs, but won't post here as they contain personal data, but I am of course happy to share them with Garmin directly. I'd also be interested to know if anyone else has experienced similar issues (the Edge 830 forums are full of them!) and sees similar symptoms in the logs.
