From 12505d2ab1339710006709699041b6b79ac03510 Mon Sep 17 00:00:00 2001 From: Mac DeCourcy Date: Tue, 11 Nov 2025 23:20:18 -0800 Subject: [PATCH 1/6] address backfill issue on tcp connections; add logging --- .../geeksville/mesh/service/MeshService.kt | 361 +++++++++++++----- .../service/StoreForwardHistoryRequestTest.kt | 67 ++++ .../meshtastic/core/prefs/mesh/MeshPrefs.kt | 28 ++ 3 files changed, 369 insertions(+), 87 deletions(-) create mode 100644 app/src/test/java/com/geeksville/mesh/service/StoreForwardHistoryRequestTest.kt diff --git a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt index 2b0a401893..d8707c7605 100644 --- a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt +++ b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt @@ -26,12 +26,15 @@ import android.content.pm.ServiceInfo import android.os.Build import android.os.IBinder import android.os.RemoteException +import android.util.Log +import androidx.annotation.VisibleForTesting import androidx.core.app.ServiceCompat import androidx.core.location.LocationCompat import com.geeksville.mesh.BuildConfig import com.geeksville.mesh.concurrent.handledLaunch import com.geeksville.mesh.model.NO_DEVICE_SELECTED import com.geeksville.mesh.repository.network.MQTTRepository +import com.geeksville.mesh.repository.radio.InterfaceId import com.geeksville.mesh.repository.radio.RadioInterfaceService import com.geeksville.mesh.util.ignoreException import com.geeksville.mesh.util.toRemoteExceptions @@ -50,7 +53,9 @@ import kotlinx.coroutines.flow.first import kotlinx.coroutines.flow.flatMapLatest import kotlinx.coroutines.flow.flowOf import kotlinx.coroutines.flow.launchIn +import kotlinx.coroutines.flow.onCompletion import kotlinx.coroutines.flow.onEach +import kotlinx.coroutines.flow.onStart import org.meshtastic.core.analytics.DataPair import org.meshtastic.core.analytics.platform.PlatformAnalytics import org.meshtastic.core.common.hasLocationPermission @@ -118,6 +123,7 @@ import org.meshtastic.proto.position import org.meshtastic.proto.telemetry import org.meshtastic.proto.user import timber.log.Timber +import java.util.ArrayDeque import java.util.UUID import java.util.concurrent.ConcurrentHashMap import javax.inject.Inject @@ -220,12 +226,66 @@ class MeshService : Service() { private const val DEFAULT_CONFIG_ONLY_NONCE = 69420 private const val DEFAULT_NODE_INFO_NONCE = 69421 - private const val WANT_CONFIG_DELAY = 250L + private const val WANT_CONFIG_DELAY = 50L + private const val HISTORY_TAG = "HistoryReplay" + private const val DEFAULT_HISTORY_RETURN_WINDOW_MINUTES = 60 * 24 + private const val DEFAULT_HISTORY_RETURN_MAX_MESSAGES = 100 + private const val MAX_EARLY_PACKET_BUFFER = 128 + + @VisibleForTesting + internal fun buildStoreForwardHistoryRequest( + lastRequest: Int, + historyReturnWindow: Int, + historyReturnMax: Int, + ): StoreAndForwardProtos.StoreAndForward { + val historyBuilder = StoreAndForwardProtos.StoreAndForward.History.newBuilder() + if (lastRequest > 0) historyBuilder.lastRequest = lastRequest + if (historyReturnWindow > 0) historyBuilder.window = historyReturnWindow + if (historyReturnMax > 0) historyBuilder.historyMessages = historyReturnMax + return StoreAndForwardProtos.StoreAndForward.newBuilder() + .setRr(StoreAndForwardProtos.StoreAndForward.RequestResponse.CLIENT_HISTORY) + .setHistory(historyBuilder) + .build() + } + + @VisibleForTesting + internal fun resolveHistoryRequestParameters(window: Int, max: Int): Pair { + val resolvedWindow = if (window > 0) window else DEFAULT_HISTORY_RETURN_WINDOW_MINUTES + val resolvedMax = if (max > 0) max else DEFAULT_HISTORY_RETURN_MAX_MESSAGES + return resolvedWindow to resolvedMax + } } private val serviceJob = Job() private val serviceScope = CoroutineScope(Dispatchers.IO + serviceJob) + private inline fun historyLog( + priority: Int = Log.INFO, + throwable: Throwable? = null, + crossinline message: () -> String, + ) { + if (!BuildConfig.DEBUG) return + val timber = Timber.tag(HISTORY_TAG) + val msg = message() + if (throwable != null) { + timber.log(priority, throwable, msg) + } else { + timber.log(priority, msg) + } + } + + private fun activeDeviceAddress(): String? = + meshPrefs.deviceAddress?.takeIf { !it.equals(NO_DEVICE_SELECTED, ignoreCase = true) && it.isNotBlank() } + + private fun currentTransport(address: String? = meshPrefs.deviceAddress): String = when (address?.firstOrNull()) { + InterfaceId.BLUETOOTH.id -> "BLE" + InterfaceId.TCP.id -> "TCP" + InterfaceId.SERIAL.id -> "Serial" + InterfaceId.MOCK.id -> "Mock" + InterfaceId.NOP.id -> "NOP" + else -> "Unknown" + } + private var locationFlow: Job? = null private var mqttMessageFlow: Job? = null @@ -312,9 +372,16 @@ class MeshService : Service() { // Switch to the IO thread serviceScope.handledLaunch { radioInterfaceService.connect() } radioInterfaceService.connectionState.onEach(::onRadioConnectionState).launchIn(serviceScope) - radioInterfaceService.receivedData.onEach(::onReceiveFromRadio).launchIn(serviceScope) - radioInterfaceService.connectionError - .onEach { error -> Timber.e("BLE Connection Error: ${error.message}") } + radioInterfaceService.receivedData + .onStart { + historyLog { "rxCollector START transport=${currentTransport()} scope=${serviceScope.hashCode()}" } + } + .onCompletion { cause -> + historyLog(Log.WARN) { + "rxCollector STOP transport=${currentTransport()} cause=${cause?.message ?: "completed"}" + } + } + .onEach(::onReceiveFromRadio) .launchIn(serviceScope) radioConfigRepository.localConfigFlow.onEach { localConfig = it }.launchIn(serviceScope) radioConfigRepository.moduleConfigFlow.onEach { moduleConfig = it }.launchIn(serviceScope) @@ -424,6 +491,7 @@ class MeshService : Service() { myNodeInfo = null nodeDBbyNodeNum.clear() haveNodeDB = false + earlyReceivedPackets.clear() } private var myNodeInfo: MyNodeEntity? = null @@ -761,7 +829,6 @@ class MeshService : Service() { } Portnums.PortNum.WAYPOINT_APP_VALUE -> { - Timber.d("Received WAYPOINT_APP from $fromId") val u = MeshProtos.Waypoint.parseFrom(data.payload) // Validate locked Waypoints from the original sender if (u.lockedTo != 0 && u.lockedTo != packet.from) return @@ -769,8 +836,8 @@ class MeshService : Service() { } Portnums.PortNum.POSITION_APP_VALUE -> { - Timber.d("Received POSITION_APP from $fromId") val u = MeshProtos.Position.parseFrom(data.payload) + // Timber.d("position_app ${packet.from} ${u.toOneLineString()}") if (data.wantResponse && u.latitudeI == 0 && u.longitudeI == 0) { Timber.d("Ignoring nop position update from position request") } else { @@ -780,7 +847,6 @@ class MeshService : Service() { Portnums.PortNum.NODEINFO_APP_VALUE -> if (!fromUs) { - Timber.d("Received NODEINFO_APP from $fromId") val u = MeshProtos.User.parseFrom(data.payload).copy { if (isLicensed) clearPublicKey() @@ -791,7 +857,6 @@ class MeshService : Service() { // Handle new telemetry info Portnums.PortNum.TELEMETRY_APP_VALUE -> { - Timber.d("Received TELEMETRY_APP from $fromId") val u = TelemetryProtos.Telemetry.parseFrom(data.payload).copy { if (time == 0) time = (dataPacket.time / 1000L).toInt() @@ -800,7 +865,6 @@ class MeshService : Service() { } Portnums.PortNum.ROUTING_APP_VALUE -> { - Timber.d("Received ROUTING_APP from $fromId") // We always send ACKs to other apps, because they might care about the // messages they sent shouldBroadcast = true @@ -815,28 +879,24 @@ class MeshService : Service() { } Portnums.PortNum.ADMIN_APP_VALUE -> { - Timber.d("Received ADMIN_APP from $fromId") val u = AdminProtos.AdminMessage.parseFrom(data.payload) handleReceivedAdmin(packet.from, u) shouldBroadcast = false } Portnums.PortNum.PAXCOUNTER_APP_VALUE -> { - Timber.d("Received PAXCOUNTER_APP from $fromId") val p = PaxcountProtos.Paxcount.parseFrom(data.payload) handleReceivedPaxcounter(packet.from, p) shouldBroadcast = false } Portnums.PortNum.STORE_FORWARD_APP_VALUE -> { - Timber.d("Received STORE_FORWARD_APP from $fromId") val u = StoreAndForwardProtos.StoreAndForward.parseFrom(data.payload) handleReceivedStoreAndForward(dataPacket, u) shouldBroadcast = false } Portnums.PortNum.RANGE_TEST_APP_VALUE -> { - Timber.d("Received RANGE_TEST_APP from $fromId") if (!moduleConfig.rangeTest.enabled) return val u = dataPacket.copy(dataType = Portnums.PortNum.TEXT_MESSAGE_APP_VALUE) rememberDataPacket(u) @@ -867,7 +927,7 @@ class MeshService : Service() { } } - else -> Timber.d("No custom processing needed for ${data.portnumValue} from $fromId") + else -> Timber.d("No custom processing needed for ${data.portnumValue}") } // We always tell other apps when new data packets arrive @@ -973,7 +1033,10 @@ class MeshService : Service() { if (myNodeNum == fromNum && p.latitudeI == 0 && p.longitudeI == 0) { Timber.d("Ignoring nop position update for the local node") } else { - updateNodeInfo(fromNum) { it.setPosition(p, (defaultTime / 1000L).toInt()) } + updateNodeInfo(fromNum) { + Timber.d("update position: ${it.longName?.toPIIString()} with ${p.toPIIString()}") + it.setPosition(p, (defaultTime / 1000L).toInt()) + } } } @@ -1040,7 +1103,79 @@ class MeshService : Service() { updateNodeInfo(fromNum) { it.paxcounter = p } } + /** + * Ask the connected radio to replay any packets it buffered while the client was offline. + * + * Radios deliver history via the Store & Forward protocol regardless of transport, so we piggyback on that + * mechanism after BLE/Wi‑Fi reconnects. + */ + private fun requestHistoryReplay(trigger: String) { + val address = activeDeviceAddress() + val failure = + when { + address == null -> "no_active_address" + myNodeNum == null -> "no_my_node" + else -> null + } + if (failure != null) { + historyLog { "requestHistory skipped trigger=$trigger reason=$failure" } + return + } + + val safeAddress = address!! + val myNum = myNodeNum!! + val storeForwardConfig = moduleConfig.storeForward + val lastRequest = meshPrefs.getStoreForwardLastRequest(safeAddress) + val (window, max) = + resolveHistoryRequestParameters(storeForwardConfig.historyReturnWindow, storeForwardConfig.historyReturnMax) + val windowSource = if (storeForwardConfig.historyReturnWindow > 0) "config" else "default" + val maxSource = if (storeForwardConfig.historyReturnMax > 0) "config" else "default" + val sourceSummary = "window=$window($windowSource) max=$max($maxSource)" + val request = + buildStoreForwardHistoryRequest( + lastRequest = lastRequest, + historyReturnWindow = window, + historyReturnMax = max, + ) + val logContext = "trigger=$trigger transport=${currentTransport(safeAddress)} addr=$safeAddress" + historyLog { "requestHistory $logContext lastRequest=$lastRequest $sourceSummary" } + + runCatching { + packetHandler.sendToRadio( + newMeshPacketTo(myNum).buildMeshPacket(priority = MeshPacket.Priority.BACKGROUND) { + portnumValue = Portnums.PortNum.STORE_FORWARD_APP_VALUE + payload = ByteString.copyFrom(request.toByteArray()) + }, + ) + } + .onFailure { ex -> historyLog(Log.WARN, ex) { "requestHistory failed $logContext" } } + } + + private fun updateStoreForwardLastRequest(source: String, lastRequest: Int) { + if (lastRequest <= 0) return + val address = activeDeviceAddress() ?: return + val current = meshPrefs.getStoreForwardLastRequest(address) + val transport = currentTransport(address) + val logContext = "source=$source transport=$transport address=$address" + if (lastRequest != current) { + meshPrefs.setStoreForwardLastRequest(address, lastRequest) + historyLog { "historyMarker updated $logContext from=$current to=$lastRequest" } + } else { + historyLog(Log.DEBUG) { "historyMarker unchanged $logContext value=$lastRequest" } + } + } + private fun handleReceivedStoreAndForward(dataPacket: DataPacket, s: StoreAndForwardProtos.StoreAndForward) { + Timber.d("StoreAndForward: ${s.variantCase} ${s.rr} from ${dataPacket.from}") + val transport = currentTransport() + val lastRequest = + if (s.variantCase == StoreAndForwardProtos.StoreAndForward.VariantCase.HISTORY) { + s.history.lastRequest + } else { + 0 + } + val baseContext = "transport=$transport from=${dataPacket.from}" + historyLog { "rxStoreForward $baseContext variant=${s.variantCase} rr=${s.rr} lastRequest=$lastRequest" } when (s.variantCase) { StoreAndForwardProtos.StoreAndForward.VariantCase.STATS -> { val u = @@ -1052,6 +1187,11 @@ class MeshService : Service() { } StoreAndForwardProtos.StoreAndForward.VariantCase.HISTORY -> { + val history = s.history + val historySummary = + "routerHistory $baseContext messages=${history.historyMessages} " + + "window=${history.window} lastRequest=${history.lastRequest}" + historyLog(Log.DEBUG) { historySummary } val text = """ Total messages: ${s.history.historyMessages} @@ -1065,12 +1205,17 @@ class MeshService : Service() { dataType = Portnums.PortNum.TEXT_MESSAGE_APP_VALUE, ) rememberDataPacket(u) + updateStoreForwardLastRequest("router_history", s.history.lastRequest) } StoreAndForwardProtos.StoreAndForward.VariantCase.TEXT -> { if (s.rr == StoreAndForwardProtos.StoreAndForward.RequestResponse.ROUTER_TEXT_BROADCAST) { dataPacket.to = DataPacket.ID_BROADCAST } + val textLog = + "rxText $baseContext id=${dataPacket.id} ts=${dataPacket.time} " + + "to=${dataPacket.to} decision=remember" + historyLog(Log.DEBUG) { textLog } val u = dataPacket.copy(bytes = s.text.toByteArray(), dataType = Portnums.PortNum.TEXT_MESSAGE_APP_VALUE) rememberDataPacket(u) @@ -1080,29 +1225,59 @@ class MeshService : Service() { } } + private val earlyReceivedPackets = ArrayDeque() + // If apps try to send packets when our radio is sleeping, we queue them here instead private val offlineSentPackets = mutableListOf() // Update our model and resend as needed for a MeshPacket we just received from the radio private fun handleReceivedMeshPacket(packet: MeshPacket) { - Timber.d("[packet]: ${packet.toOneLineString()}") + val preparedPacket = + packet + .toBuilder() + .apply { + // If the rxTime was not set by the device, update with current time + if (packet.rxTime == 0) setRxTime(currentSecond()) + } + .build() + if (haveNodeDB) { - processReceivedMeshPacket( - packet - .toBuilder() - .apply { - // If the rxTime was not set by the device, update with current time - if (packet.rxTime == 0) setRxTime(currentSecond()) + processReceivedMeshPacket(preparedPacket) + return + } + + val queueSize = earlyReceivedPackets.size + if (queueSize >= MAX_EARLY_PACKET_BUFFER) { + val dropped = earlyReceivedPackets.removeFirst() + historyLog(Log.WARN) { + val portLabel = + if (dropped.hasDecoded()) { + Portnums.PortNum.forNumber(dropped.decoded.portnumValue)?.name + ?: dropped.decoded.portnumValue.toString() + } else { + "unknown" } - .build(), - ) - } else { - Timber.w("Ignoring early received packet: ${packet.toOneLineString()}") - // earlyReceivedPackets.add(packet) - // logAssert(earlyReceivedPackets.size < 128) // The max should normally be about 32, - // but if the device is - // messed up it might try to send forever + "dropEarlyPacket bufferFull size=$queueSize id=${dropped.id} port=$portLabel" + } } + + earlyReceivedPackets.addLast(preparedPacket) + val portLabel = + if (preparedPacket.hasDecoded()) { + Portnums.PortNum.forNumber(preparedPacket.decoded.portnumValue)?.name + ?: preparedPacket.decoded.portnumValue.toString() + } else { + "unknown" + } + historyLog { "queueEarlyPacket size=${earlyReceivedPackets.size} id=${preparedPacket.id} port=$portLabel" } + } + + private fun flushEarlyReceivedPackets(reason: String) { + if (earlyReceivedPackets.isEmpty()) return + val packets = earlyReceivedPackets.toList() + earlyReceivedPackets.clear() + historyLog { "replayEarlyPackets reason=$reason count=${packets.size}" } + packets.forEach(::processReceivedMeshPacket) } private fun sendNow(p: DataPacket) { @@ -1150,6 +1325,12 @@ class MeshService : Service() { // Update our model and resend as needed for a MeshPacket we just received from the radio private fun processReceivedMeshPacket(packet: MeshPacket) { val fromNum = packet.from + + // FIXME, perhaps we could learn our node ID by looking at any to packets the radio + // decided to pass through to us (except for broadcast packets) + // val toNum = packet.to + + // Timber.d("Received: $packet") if (packet.hasDecoded()) { val packetToSave = MeshLog( @@ -1240,6 +1421,7 @@ class MeshService : Service() { private var connectTimeMsec = 0L // Called when we gain/lose connection to our radio + @Suppress("CyclomaticComplexMethod") private fun onConnectionChanged(c: ConnectionState) { Timber.d("onConnectionChanged: ${connectionStateHolder.getState()} -> $c") @@ -1278,7 +1460,6 @@ class MeshService : Service() { } fun startDisconnect() { - Timber.d("Starting disconnect") packetHandler.stopPacketQueue() stopLocationRequests() stopMqttClientProxy() @@ -1291,7 +1472,10 @@ class MeshService : Service() { } fun startConnect() { - Timber.d("Starting connect") + historyLog { + val address = meshPrefs.deviceAddress ?: "null" + "onReconnect transport=${currentTransport()} node=$address" + } try { connectTimeMsec = System.currentTimeMillis() startConfigOnly() @@ -1359,6 +1543,7 @@ class MeshService : Service() { private val packetHandlers: Map Unit)> by lazy { PayloadVariantCase.entries.associateWith { variant: PayloadVariantCase -> + Timber.d("PacketHandler - handling $variant") when (variant) { PayloadVariantCase.PACKET -> { proto: MeshProtos.FromRadio -> handleReceivedMeshPacket(proto.packet) } @@ -1367,11 +1552,9 @@ class MeshService : Service() { } PayloadVariantCase.MY_INFO -> { proto: MeshProtos.FromRadio -> handleMyInfo(proto.myInfo) } - PayloadVariantCase.NODE_INFO -> { proto: MeshProtos.FromRadio -> handleNodeInfo(proto.nodeInfo) } PayloadVariantCase.CHANNEL -> { proto: MeshProtos.FromRadio -> handleChannel(proto.channel) } - PayloadVariantCase.CONFIG -> { proto: MeshProtos.FromRadio -> handleDeviceConfig(proto.config) } PayloadVariantCase.MODULECONFIG -> { proto: MeshProtos.FromRadio -> @@ -1383,7 +1566,6 @@ class MeshService : Service() { } PayloadVariantCase.METADATA -> { proto: MeshProtos.FromRadio -> handleMetadata(proto.metadata) } - PayloadVariantCase.MQTTCLIENTPROXYMESSAGE -> { proto: MeshProtos.FromRadio -> handleMqttProxyMessage(proto.mqttClientProxyMessage) } @@ -1393,22 +1575,22 @@ class MeshService : Service() { } PayloadVariantCase.FILEINFO -> { proto: MeshProtos.FromRadio -> handleFileInfo(proto.fileInfo) } - PayloadVariantCase.CLIENTNOTIFICATION -> { proto: MeshProtos.FromRadio -> handleClientNotification(proto.clientNotification) } - PayloadVariantCase.LOG_RECORD -> { proto: MeshProtos.FromRadio -> handleLogRecord(proto.logRecord) } + PayloadVariantCase.LOG_RECORD -> { proto: MeshProtos.FromRadio -> handleLogReord(proto.logRecord) } PayloadVariantCase.REBOOTED -> { proto: MeshProtos.FromRadio -> handleRebooted(proto.rebooted) } - PayloadVariantCase.XMODEMPACKET -> { proto: MeshProtos.FromRadio -> handleXmodemPacket(proto.xmodemPacket) } // Explicitly handle default/unwanted cases to satisfy the exhaustive `when` PayloadVariantCase.PAYLOADVARIANT_NOT_SET -> { proto -> - Timber.d("Received variant PayloadVariantUnset: Full FromRadio proto: ${proto.toPIIString()}") + Timber.e("Unexpected or unrecognized FromRadio variant: ${proto.payloadVariantCase}") + // Additional debug: log raw bytes if possible (can't access bytes here) and full proto + Timber.d("Full FromRadio proto: $proto") } } } @@ -1418,33 +1600,22 @@ class MeshService : Service() { packetHandlers[this.payloadVariantCase]?.invoke(this) } - /** - * Parses and routes incoming data from the radio. - * - * This function first attempts to parse the data as a `FromRadio` protobuf message. If that fails, it then tries to - * parse it as a `LogRecord` for debugging purposes. - */ private fun onReceiveFromRadio(bytes: ByteArray) { - runCatching { MeshProtos.FromRadio.parseFrom(bytes) } - .onSuccess { proto -> proto.route() } - .onFailure { primaryException -> - runCatching { - val logRecord = MeshProtos.LogRecord.parseFrom(bytes) - handleLogRecord(logRecord) - } - .onFailure { _ -> - val packet = bytes.toHexString() - Timber.e( - primaryException, - "Failed to parse radio packet (len=${bytes.size} contents=$packet). Not a valid FromRadio or LogRecord.", - ) - } + try { + val proto = MeshProtos.FromRadio.parseFrom(bytes) + if (proto.payloadVariantCase == PayloadVariantCase.PAYLOADVARIANT_NOT_SET) { + Timber.w( + "Received FromRadio with PAYLOADVARIANT_NOT_SET. rawBytes=${bytes.joinToString(",") { b -> + String.format("0x%02x", b) + }} proto=$proto", + ) } + proto.route() + } catch (ex: InvalidProtocolBufferException) { + Timber.e("Invalid Protobuf from radio, len=${bytes.size}", ex) + } } - /** Extension function to convert a ByteArray to a hex string for logging. Example output: "0x0a,0x1f,0x..." */ - private fun ByteArray.toHexString(): String = this.joinToString(",") { byte -> String.format("0x%02x", byte) } - // A provisional MyNodeInfo that we will install if all of our node config downloads go okay private var newMyNodeInfo: MyNodeEntity? = null @@ -1456,7 +1627,7 @@ class MeshService : Service() { private var nodeInfoNonce: Int = DEFAULT_NODE_INFO_NONCE private fun handleDeviceConfig(config: ConfigProtos.Config) { - Timber.d("[deviceConfig] ${config.toPIIString()}") + Timber.d("Received config ${config.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1472,7 +1643,7 @@ class MeshService : Service() { } private fun handleModuleConfig(config: ModuleConfigProtos.ModuleConfig) { - Timber.d("[moduleConfig] ${config.toPIIString()}") + Timber.d("Received moduleConfig ${config.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1488,7 +1659,7 @@ class MeshService : Service() { } private fun handleChannel(ch: ChannelProtos.Channel) { - Timber.d("[channel] ${ch.toPIIString()}") + Timber.d("Received channel ${ch.index}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1546,7 +1717,13 @@ class MeshService : Service() { } private fun handleNodeInfo(info: MeshProtos.NodeInfo) { - Timber.d("[nodeInfo] ${info.toPIIString()}") + Timber.d( + "Received nodeinfo num=${info.num}," + + " hasUser=${info.hasUser()}," + + " hasPosition=${info.hasPosition()}," + + " hasDeviceMetrics=${info.hasDeviceMetrics()}", + ) + val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1611,7 +1788,6 @@ class MeshService : Service() { /** Update MyNodeInfo (called from either new API version or the old one) */ private fun handleMyInfo(myInfo: MeshProtos.MyNodeInfo) { - Timber.d("[myInfo] ${myInfo.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1635,7 +1811,7 @@ class MeshService : Service() { /** Update our DeviceMetadata */ private fun handleMetadata(metadata: MeshProtos.DeviceMetadata) { - Timber.d("[deviceMetadata] ${metadata.toPIIString()}") + Timber.d("Received deviceMetadata ${metadata.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1651,7 +1827,6 @@ class MeshService : Service() { /** Publish MqttClientProxyMessage (fromRadio) */ private fun handleMqttProxyMessage(message: MeshProtos.MqttClientProxyMessage) { - Timber.d("[mqttClientProxyMessage] ${message.toPIIString()}") with(message) { when (payloadVariantCase) { MeshProtos.MqttClientProxyMessage.PayloadVariantCase.TEXT -> { @@ -1668,25 +1843,16 @@ class MeshService : Service() { } private fun handleClientNotification(notification: MeshProtos.ClientNotification) { - Timber.d("[clientNotification] ${notification.toPIIString()}") + Timber.d("Received clientNotification ${notification.toOneLineString()}") serviceRepository.setClientNotification(notification) serviceNotifications.showClientNotification(notification) // if the future for the originating request is still in the queue, complete as unsuccessful // for now packetHandler.removeResponse(notification.replyId, complete = false) - val packetToSave = - MeshLog( - uuid = UUID.randomUUID().toString(), - message_type = "ClientNotification", - received_date = System.currentTimeMillis(), - raw_message = notification.toString(), - fromRadio = fromRadio { this.clientNotification = notification }, - ) - insertMeshLog(packetToSave) } private fun handleFileInfo(fileInfo: MeshProtos.FileInfo) { - Timber.d("[fileInfo] ${fileInfo.toPIIString()}") + Timber.d("Received fileInfo ${fileInfo.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1698,8 +1864,8 @@ class MeshService : Service() { insertMeshLog(packetToSave) } - private fun handleLogRecord(logRecord: MeshProtos.LogRecord) { - Timber.d("[logRecord] ${logRecord.toPIIString()}") + private fun handleLogReord(logRecord: MeshProtos.LogRecord) { + Timber.d("Received logRecord ${logRecord.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1712,7 +1878,7 @@ class MeshService : Service() { } private fun handleRebooted(rebooted: Boolean) { - Timber.d("[rebooted] $rebooted") + Timber.d("Received rebooted ${rebooted.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1725,7 +1891,7 @@ class MeshService : Service() { } private fun handleXmodemPacket(xmodemPacket: XmodemProtos.XModem) { - Timber.d("[xmodemPacket] ${xmodemPacket.toPIIString()}") + Timber.d("Received XmodemPacket ${xmodemPacket.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1738,7 +1904,7 @@ class MeshService : Service() { } private fun handleDeviceUiConfig(deviceuiConfig: DeviceUIProtos.DeviceUIConfig) { - Timber.d("[deviceuiConfig] ${deviceuiConfig.toPIIString()}") + Timber.d("Received deviceUIConfig ${deviceuiConfig.toOneLineString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1773,16 +1939,24 @@ class MeshService : Service() { } private fun onHasSettings() { + packetHandler.sendToRadio(newMeshPacketTo(myNodeNum).buildAdminPacket { setTimeOnly = currentSecond() }) processQueuedPackets() startMqttClientProxy() serviceBroadcasts.broadcastConnection() sendAnalytics() reportConnection() - packetHandler.sendToRadio(newMeshPacketTo(myNodeNum).buildAdminPacket { setTimeOnly = currentSecond() }) + historyLog { + val ports = + rememberDataType.joinToString(",") { port -> Portnums.PortNum.forNumber(port)?.name ?: port.toString() } + "subscribePorts afterReconnect ports=$ports" + } + requestHistoryReplay("onHasSettings") } private fun handleConfigComplete(configCompleteId: Int) { - Timber.d("[configCompleteId]: ${configCompleteId.toPIIString()}") + Timber.d( + "handleConfigComplete called with id=$configCompleteId, configOnly=$configOnlyNonce, nodeInfo=$nodeInfoNonce", + ) when (configCompleteId) { configOnlyNonce -> handleConfigOnlyComplete() nodeInfoNonce -> handleNodeInfoComplete() @@ -1849,6 +2023,7 @@ class MeshService : Service() { newNodes.clear() serviceScope.handledLaunch { nodeRepository.installConfig(myNodeInfo!!, nodeDBbyNodeNum.values.toList()) } haveNodeDB = true + flushEarlyReceivedPackets("node_info_complete") sendAnalytics() onHasSettings() } @@ -2038,12 +2213,24 @@ class MeshService : Service() { Timber.d( "SetDeviceAddress: Device address changed from ${currentAddr.anonymize} to ${deviceAddr.anonymize}", ) + val currentLabel = currentAddr ?: "null" + val nextLabel = deviceAddr ?: "null" + val nextTransport = currentTransport(deviceAddr) + historyLog { "dbSwitch request current=$currentLabel next=$nextLabel transportNext=$nextTransport" } meshPrefs.deviceAddress = deviceAddr serviceScope.handledLaunch { // Clear only in-memory caches to avoid cross-device bleed discardNodeDB() // Switch active on-disk DB to device-specific database databaseManager.switchActiveDatabase(deviceAddr) + val activeAddress = databaseManager.currentAddress.value + val activeLabel = activeAddress ?: "null" + val transportLabel = currentTransport() + val meshAddress = meshPrefs.deviceAddress ?: "null" + val nodeId = myNodeInfo?.myNodeNum?.toString() ?: "unknown" + val dbSummary = + "dbSwitch activeAddress=$activeLabel nodeId=$nodeId transport=$transportLabel addr=$meshAddress" + historyLog { dbSummary } // Do not clear packet DB here; messages are per-device and should persist clearNotifications() } diff --git a/app/src/test/java/com/geeksville/mesh/service/StoreForwardHistoryRequestTest.kt b/app/src/test/java/com/geeksville/mesh/service/StoreForwardHistoryRequestTest.kt new file mode 100644 index 0000000000..52f6b16708 --- /dev/null +++ b/app/src/test/java/com/geeksville/mesh/service/StoreForwardHistoryRequestTest.kt @@ -0,0 +1,67 @@ +/* + * Copyright (c) 2025 Meshtastic LLC + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ + +package com.geeksville.mesh.service + +import org.junit.Assert.assertEquals +import org.junit.Test +import org.meshtastic.proto.StoreAndForwardProtos + +class StoreForwardHistoryRequestTest { + + @Test + fun `buildStoreForwardHistoryRequest copies positive parameters`() { + val request = + MeshService.buildStoreForwardHistoryRequest( + lastRequest = 42, + historyReturnWindow = 15, + historyReturnMax = 25, + ) + + assertEquals(StoreAndForwardProtos.StoreAndForward.RequestResponse.CLIENT_HISTORY, request.rr) + assertEquals(42, request.history.lastRequest) + assertEquals(15, request.history.window) + assertEquals(25, request.history.historyMessages) + } + + @Test + fun `buildStoreForwardHistoryRequest omits non-positive parameters`() { + val request = + MeshService.buildStoreForwardHistoryRequest(lastRequest = 0, historyReturnWindow = -1, historyReturnMax = 0) + + assertEquals(StoreAndForwardProtos.StoreAndForward.RequestResponse.CLIENT_HISTORY, request.rr) + assertEquals(0, request.history.lastRequest) + assertEquals(0, request.history.window) + assertEquals(0, request.history.historyMessages) + } + + @Test + fun `resolveHistoryRequestParameters uses config values when positive`() { + val (window, max) = MeshService.resolveHistoryRequestParameters(window = 30, max = 10) + + assertEquals(30, window) + assertEquals(10, max) + } + + @Test + fun `resolveHistoryRequestParameters falls back to defaults when non-positive`() { + val (window, max) = MeshService.resolveHistoryRequestParameters(window = 0, max = -5) + + assertEquals(1440, window) + assertEquals(100, max) + } +} diff --git a/core/prefs/src/main/kotlin/org/meshtastic/core/prefs/mesh/MeshPrefs.kt b/core/prefs/src/main/kotlin/org/meshtastic/core/prefs/mesh/MeshPrefs.kt index a0499a7e6b..fb121a692d 100644 --- a/core/prefs/src/main/kotlin/org/meshtastic/core/prefs/mesh/MeshPrefs.kt +++ b/core/prefs/src/main/kotlin/org/meshtastic/core/prefs/mesh/MeshPrefs.kt @@ -21,6 +21,7 @@ import android.content.SharedPreferences import androidx.core.content.edit import org.meshtastic.core.prefs.NullableStringPrefDelegate import org.meshtastic.core.prefs.di.MeshSharedPreferences +import java.util.Locale import javax.inject.Inject import javax.inject.Singleton @@ -30,6 +31,10 @@ interface MeshPrefs { fun shouldProvideNodeLocation(nodeNum: Int?): Boolean fun setShouldProvideNodeLocation(nodeNum: Int?, value: Boolean) + + fun getStoreForwardLastRequest(address: String?): Int + + fun setStoreForwardLastRequest(address: String?, value: Int) } @Singleton @@ -43,7 +48,30 @@ class MeshPrefsImpl @Inject constructor(@MeshSharedPreferences private val prefs prefs.edit { putBoolean(provideLocationKey(nodeNum), value) } } + override fun getStoreForwardLastRequest(address: String?): Int = prefs.getInt(storeForwardKey(address), 0) + + override fun setStoreForwardLastRequest(address: String?, value: Int) { + prefs.edit { + if (value <= 0) { + remove(storeForwardKey(address)) + } else { + putInt(storeForwardKey(address), value) + } + } + } + private fun provideLocationKey(nodeNum: Int?) = "provide-location-$nodeNum" + + private fun storeForwardKey(address: String?): String = "store-forward-last-request-${normalizeAddress(address)}" + + private fun normalizeAddress(address: String?): String { + val raw = address?.trim()?.takeIf { it.isNotEmpty() } + return when { + raw == null -> "DEFAULT" + raw.equals(NO_DEVICE_SELECTED, ignoreCase = true) -> "DEFAULT" + else -> raw.uppercase(Locale.US).replace(":", "") + } + } } private const val NO_DEVICE_SELECTED = "n" From 24729ba3e4f7a1296f8fee15e8521bd976d6dfcd Mon Sep 17 00:00:00 2001 From: Mac DeCourcy Date: Thu, 13 Nov 2025 17:25:22 -0800 Subject: [PATCH 2/6] merge conflicts --- .../geeksville/mesh/service/MeshService.kt | 20 ++++++++++++------- 1 file changed, 13 insertions(+), 7 deletions(-) diff --git a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt index d8707c7605..2438b041de 100644 --- a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt +++ b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt @@ -124,6 +124,7 @@ import org.meshtastic.proto.telemetry import org.meshtastic.proto.user import timber.log.Timber import java.util.ArrayDeque +import java.util.Locale import java.util.UUID import java.util.concurrent.ConcurrentHashMap import javax.inject.Inject @@ -865,6 +866,7 @@ class MeshService : Service() { } Portnums.PortNum.ROUTING_APP_VALUE -> { + Timber.d("Received ROUTING_APP from $fromId") // We always send ACKs to other apps, because they might care about the // messages they sent shouldBroadcast = true @@ -879,24 +881,28 @@ class MeshService : Service() { } Portnums.PortNum.ADMIN_APP_VALUE -> { + Timber.d("Received ADMIN_APP from $fromId") val u = AdminProtos.AdminMessage.parseFrom(data.payload) handleReceivedAdmin(packet.from, u) shouldBroadcast = false } Portnums.PortNum.PAXCOUNTER_APP_VALUE -> { + Timber.d("Received PAXCOUNTER_APP from $fromId") val p = PaxcountProtos.Paxcount.parseFrom(data.payload) handleReceivedPaxcounter(packet.from, p) shouldBroadcast = false } Portnums.PortNum.STORE_FORWARD_APP_VALUE -> { + Timber.d("Received STORE_FORWARD_APP from $fromId") val u = StoreAndForwardProtos.StoreAndForward.parseFrom(data.payload) handleReceivedStoreAndForward(dataPacket, u) shouldBroadcast = false } Portnums.PortNum.RANGE_TEST_APP_VALUE -> { + Timber.d("Received RANGE_TEST_APP from $fromId") if (!moduleConfig.rangeTest.enabled) return val u = dataPacket.copy(dataType = Portnums.PortNum.TEXT_MESSAGE_APP_VALUE) rememberDataPacket(u) @@ -927,7 +933,7 @@ class MeshService : Service() { } } - else -> Timber.d("No custom processing needed for ${data.portnumValue}") + else -> Timber.d("No custom processing needed for ${data.portnumValue} from $fromId") } // We always tell other apps when new data packets arrive @@ -1604,11 +1610,8 @@ class MeshService : Service() { try { val proto = MeshProtos.FromRadio.parseFrom(bytes) if (proto.payloadVariantCase == PayloadVariantCase.PAYLOADVARIANT_NOT_SET) { - Timber.w( - "Received FromRadio with PAYLOADVARIANT_NOT_SET. rawBytes=${bytes.joinToString(",") { b -> - String.format("0x%02x", b) - }} proto=$proto", - ) + val formattedBytes = bytes.joinToString(",") { byte -> String.format(Locale.US, "0x%02x", byte) } + Timber.w("Received FromRadio with PAYLOADVARIANT_NOT_SET. rawBytes=$formattedBytes proto=$proto") } proto.route() } catch (ex: InvalidProtocolBufferException) { @@ -1955,7 +1958,10 @@ class MeshService : Service() { private fun handleConfigComplete(configCompleteId: Int) { Timber.d( - "handleConfigComplete called with id=$configCompleteId, configOnly=$configOnlyNonce, nodeInfo=$nodeInfoNonce", + "handleConfigComplete id=%d configOnly=%d nodeInfo=%d", + configCompleteId, + configOnlyNonce, + nodeInfoNonce, ) when (configCompleteId) { configOnlyNonce -> handleConfigOnlyComplete() From 28f4144107bba561731350fd76bf363b2d19dbe1 Mon Sep 17 00:00:00 2001 From: Mac DeCourcy Date: Thu, 13 Nov 2025 18:33:27 -0800 Subject: [PATCH 3/6] im sorry what i said while i was rebasing --- .../geeksville/mesh/service/MeshService.kt | 58 ++++++++++++++----- 1 file changed, 43 insertions(+), 15 deletions(-) diff --git a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt index 2438b041de..b1ad5648bf 100644 --- a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt +++ b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt @@ -830,6 +830,7 @@ class MeshService : Service() { } Portnums.PortNum.WAYPOINT_APP_VALUE -> { + Timber.d("Received WAYPOINT_APP from $fromId") val u = MeshProtos.Waypoint.parseFrom(data.payload) // Validate locked Waypoints from the original sender if (u.lockedTo != 0 && u.lockedTo != packet.from) return @@ -837,6 +838,7 @@ class MeshService : Service() { } Portnums.PortNum.POSITION_APP_VALUE -> { + Timber.d("Received POSITION_APP from $fromId") val u = MeshProtos.Position.parseFrom(data.payload) // Timber.d("position_app ${packet.from} ${u.toOneLineString()}") if (data.wantResponse && u.latitudeI == 0 && u.longitudeI == 0) { @@ -848,6 +850,7 @@ class MeshService : Service() { Portnums.PortNum.NODEINFO_APP_VALUE -> if (!fromUs) { + Timber.d("Received NODEINFO_APP from $fromId") val u = MeshProtos.User.parseFrom(data.payload).copy { if (isLicensed) clearPublicKey() @@ -858,6 +861,7 @@ class MeshService : Service() { // Handle new telemetry info Portnums.PortNum.TELEMETRY_APP_VALUE -> { + Timber.d("Received TELEMETRY_APP from $fromId") val u = TelemetryProtos.Telemetry.parseFrom(data.payload).copy { if (time == 0) time = (dataPacket.time / 1000L).toInt() @@ -1466,6 +1470,7 @@ class MeshService : Service() { } fun startDisconnect() { + Timber.d("Starting disconnect") packetHandler.stopPacketQueue() stopLocationRequests() stopMqttClientProxy() @@ -1478,6 +1483,7 @@ class MeshService : Service() { } fun startConnect() { + Timber.d("Starting connect") historyLog { val address = meshPrefs.deviceAddress ?: "null" "onReconnect transport=${currentTransport()} node=$address" @@ -1585,7 +1591,7 @@ class MeshService : Service() { handleClientNotification(proto.clientNotification) } - PayloadVariantCase.LOG_RECORD -> { proto: MeshProtos.FromRadio -> handleLogReord(proto.logRecord) } + PayloadVariantCase.LOG_RECORD -> { proto: MeshProtos.FromRadio -> handleLogRecord(proto.logRecord) } PayloadVariantCase.REBOOTED -> { proto: MeshProtos.FromRadio -> handleRebooted(proto.rebooted) } PayloadVariantCase.XMODEMPACKET -> { proto: MeshProtos.FromRadio -> @@ -1594,9 +1600,7 @@ class MeshService : Service() { // Explicitly handle default/unwanted cases to satisfy the exhaustive `when` PayloadVariantCase.PAYLOADVARIANT_NOT_SET -> { proto -> - Timber.e("Unexpected or unrecognized FromRadio variant: ${proto.payloadVariantCase}") - // Additional debug: log raw bytes if possible (can't access bytes here) and full proto - Timber.d("Full FromRadio proto: $proto") + Timber.d("Received variant PayloadVariantUnset: Full FromRadio proto: ${proto.toPIIString()}") } } } @@ -1607,18 +1611,33 @@ class MeshService : Service() { } private fun onReceiveFromRadio(bytes: ByteArray) { - try { - val proto = MeshProtos.FromRadio.parseFrom(bytes) - if (proto.payloadVariantCase == PayloadVariantCase.PAYLOADVARIANT_NOT_SET) { - val formattedBytes = bytes.joinToString(",") { byte -> String.format(Locale.US, "0x%02x", byte) } - Timber.w("Received FromRadio with PAYLOADVARIANT_NOT_SET. rawBytes=$formattedBytes proto=$proto") - } - proto.route() - } catch (ex: InvalidProtocolBufferException) { - Timber.e("Invalid Protobuf from radio, len=${bytes.size}", ex) - } + runCatching { MeshProtos.FromRadio.parseFrom(bytes) } + .onSuccess { proto -> + if (proto.payloadVariantCase == PayloadVariantCase.PAYLOADVARIANT_NOT_SET) { + Timber.w( + "Received FromRadio with PAYLOADVARIANT_NOT_SET. rawBytes=${bytes.toHexString()} proto=$proto", + ) + } + proto.route() + } + .onFailure { primaryException -> + runCatching { + val logRecord = MeshProtos.LogRecord.parseFrom(bytes) + handleLogRecord(logRecord) + } + .onFailure { _ -> + Timber.e( + primaryException, + "Failed to parse radio packet (len=${bytes.size} contents=${bytes.toHexString()}). " + + "Not a valid FromRadio or LogRecord.", + ) + } + } } + /** Extension function to convert a ByteArray to a hex string for logging. Example output: "0x0a,0x1f,0x..." */ + private fun ByteArray.toHexString(): String = this.joinToString(",") { byte -> String.format(Locale.US, "0x%02x", byte) } + // A provisional MyNodeInfo that we will install if all of our node config downloads go okay private var newMyNodeInfo: MyNodeEntity? = null @@ -1852,6 +1871,15 @@ class MeshService : Service() { // if the future for the originating request is still in the queue, complete as unsuccessful // for now packetHandler.removeResponse(notification.replyId, complete = false) + val packetToSave = + MeshLog( + uuid = UUID.randomUUID().toString(), + message_type = "ClientNotification", + received_date = System.currentTimeMillis(), + raw_message = notification.toString(), + fromRadio = fromRadio { this.clientNotification = notification }, + ) + insertMeshLog(packetToSave) } private fun handleFileInfo(fileInfo: MeshProtos.FileInfo) { @@ -1867,7 +1895,7 @@ class MeshService : Service() { insertMeshLog(packetToSave) } - private fun handleLogReord(logRecord: MeshProtos.LogRecord) { + private fun handleLogRecord(logRecord: MeshProtos.LogRecord) { Timber.d("Received logRecord ${logRecord.toOneLineString()}") val packetToSave = MeshLog( From 1fcae3bd3dbc5e4f0f711224faafd8f7bb24554a Mon Sep 17 00:00:00 2001 From: Mac DeCourcy Date: Thu, 13 Nov 2025 18:46:41 -0800 Subject: [PATCH 4/6] im sorry what i said while i was rebasing --- .../main/java/com/geeksville/mesh/service/MeshService.kt | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt index b1ad5648bf..d47bae2ae8 100644 --- a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt +++ b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt @@ -1610,6 +1610,12 @@ class MeshService : Service() { packetHandlers[this.payloadVariantCase]?.invoke(this) } + /** + * Parses and routes incoming data from the radio. + * + * This function first attempts to parse the data as a `FromRadio` protobuf message. If that fails, it then tries to + * parse it as a `LogRecord` for debugging purposes. + */ private fun onReceiveFromRadio(bytes: ByteArray) { runCatching { MeshProtos.FromRadio.parseFrom(bytes) } .onSuccess { proto -> From 15c7c13e093322304c48ab9d879e8562da0d4297 Mon Sep 17 00:00:00 2001 From: Mac DeCourcy Date: Thu, 13 Nov 2025 18:51:54 -0800 Subject: [PATCH 5/6] im sorry for what i said after I pushed without running detekt and spotless again --- app/src/main/java/com/geeksville/mesh/service/MeshService.kt | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt index d47bae2ae8..929ae38ef6 100644 --- a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt +++ b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt @@ -1642,7 +1642,8 @@ class MeshService : Service() { } /** Extension function to convert a ByteArray to a hex string for logging. Example output: "0x0a,0x1f,0x..." */ - private fun ByteArray.toHexString(): String = this.joinToString(",") { byte -> String.format(Locale.US, "0x%02x", byte) } + private fun ByteArray.toHexString(): String = + this.joinToString(",") { byte -> String.format(Locale.US, "0x%02x", byte) } // A provisional MyNodeInfo that we will install if all of our node config downloads go okay private var newMyNodeInfo: MyNodeEntity? = null From 68bf77cd9c4c826fcbede6681681beb8aba4f61f Mon Sep 17 00:00:00 2001 From: James Rich <2199651+jamesarich@users.noreply.github.com> Date: Thu, 13 Nov 2025 13:53:37 -0600 Subject: [PATCH 6/6] feat(ble): Add support for LogRadio characteristic, enhance logs (#3691) Signed-off-by: James Rich <2199651+jamesarich@users.noreply.github.com> --- .../geeksville/mesh/service/MeshService.kt | 62 ++++++++----------- 1 file changed, 25 insertions(+), 37 deletions(-) diff --git a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt index 929ae38ef6..2a8dca5a16 100644 --- a/app/src/main/java/com/geeksville/mesh/service/MeshService.kt +++ b/app/src/main/java/com/geeksville/mesh/service/MeshService.kt @@ -384,6 +384,9 @@ class MeshService : Service() { } .onEach(::onReceiveFromRadio) .launchIn(serviceScope) + radioInterfaceService.connectionError + .onEach { error -> Timber.e("BLE Connection Error: ${error.message}") } + .launchIn(serviceScope) radioConfigRepository.localConfigFlow.onEach { localConfig = it }.launchIn(serviceScope) radioConfigRepository.moduleConfigFlow.onEach { moduleConfig = it }.launchIn(serviceScope) radioConfigRepository.channelSetFlow.onEach { channelSet = it }.launchIn(serviceScope) @@ -840,7 +843,6 @@ class MeshService : Service() { Portnums.PortNum.POSITION_APP_VALUE -> { Timber.d("Received POSITION_APP from $fromId") val u = MeshProtos.Position.parseFrom(data.payload) - // Timber.d("position_app ${packet.from} ${u.toOneLineString()}") if (data.wantResponse && u.latitudeI == 0 && u.longitudeI == 0) { Timber.d("Ignoring nop position update from position request") } else { @@ -1043,10 +1045,7 @@ class MeshService : Service() { if (myNodeNum == fromNum && p.latitudeI == 0 && p.longitudeI == 0) { Timber.d("Ignoring nop position update for the local node") } else { - updateNodeInfo(fromNum) { - Timber.d("update position: ${it.longName?.toPIIString()} with ${p.toPIIString()}") - it.setPosition(p, (defaultTime / 1000L).toInt()) - } + updateNodeInfo(fromNum) { it.setPosition(p, (defaultTime / 1000L).toInt()) } } } @@ -1250,7 +1249,7 @@ class MeshService : Service() { if (packet.rxTime == 0) setRxTime(currentSecond()) } .build() - + Timber.d("[packet]: ${packet.toOneLineString()}") if (haveNodeDB) { processReceivedMeshPacket(preparedPacket) return @@ -1335,12 +1334,6 @@ class MeshService : Service() { // Update our model and resend as needed for a MeshPacket we just received from the radio private fun processReceivedMeshPacket(packet: MeshPacket) { val fromNum = packet.from - - // FIXME, perhaps we could learn our node ID by looking at any to packets the radio - // decided to pass through to us (except for broadcast packets) - // val toNum = packet.to - - // Timber.d("Received: $packet") if (packet.hasDecoded()) { val packetToSave = MeshLog( @@ -1555,7 +1548,6 @@ class MeshService : Service() { private val packetHandlers: Map Unit)> by lazy { PayloadVariantCase.entries.associateWith { variant: PayloadVariantCase -> - Timber.d("PacketHandler - handling $variant") when (variant) { PayloadVariantCase.PACKET -> { proto: MeshProtos.FromRadio -> handleReceivedMeshPacket(proto.packet) } @@ -1564,9 +1556,11 @@ class MeshService : Service() { } PayloadVariantCase.MY_INFO -> { proto: MeshProtos.FromRadio -> handleMyInfo(proto.myInfo) } + PayloadVariantCase.NODE_INFO -> { proto: MeshProtos.FromRadio -> handleNodeInfo(proto.nodeInfo) } PayloadVariantCase.CHANNEL -> { proto: MeshProtos.FromRadio -> handleChannel(proto.channel) } + PayloadVariantCase.CONFIG -> { proto: MeshProtos.FromRadio -> handleDeviceConfig(proto.config) } PayloadVariantCase.MODULECONFIG -> { proto: MeshProtos.FromRadio -> @@ -1578,6 +1572,7 @@ class MeshService : Service() { } PayloadVariantCase.METADATA -> { proto: MeshProtos.FromRadio -> handleMetadata(proto.metadata) } + PayloadVariantCase.MQTTCLIENTPROXYMESSAGE -> { proto: MeshProtos.FromRadio -> handleMqttProxyMessage(proto.mqttClientProxyMessage) } @@ -1587,6 +1582,7 @@ class MeshService : Service() { } PayloadVariantCase.FILEINFO -> { proto: MeshProtos.FromRadio -> handleFileInfo(proto.fileInfo) } + PayloadVariantCase.CLIENTNOTIFICATION -> { proto: MeshProtos.FromRadio -> handleClientNotification(proto.clientNotification) } @@ -1594,6 +1590,7 @@ class MeshService : Service() { PayloadVariantCase.LOG_RECORD -> { proto: MeshProtos.FromRadio -> handleLogRecord(proto.logRecord) } PayloadVariantCase.REBOOTED -> { proto: MeshProtos.FromRadio -> handleRebooted(proto.rebooted) } + PayloadVariantCase.XMODEMPACKET -> { proto: MeshProtos.FromRadio -> handleXmodemPacket(proto.xmodemPacket) } @@ -1656,7 +1653,7 @@ class MeshService : Service() { private var nodeInfoNonce: Int = DEFAULT_NODE_INFO_NONCE private fun handleDeviceConfig(config: ConfigProtos.Config) { - Timber.d("Received config ${config.toOneLineString()}") + Timber.d("[deviceConfig] ${config.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1672,7 +1669,7 @@ class MeshService : Service() { } private fun handleModuleConfig(config: ModuleConfigProtos.ModuleConfig) { - Timber.d("Received moduleConfig ${config.toOneLineString()}") + Timber.d("[moduleConfig] ${config.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1688,7 +1685,7 @@ class MeshService : Service() { } private fun handleChannel(ch: ChannelProtos.Channel) { - Timber.d("Received channel ${ch.index}") + Timber.d("[channel] ${ch.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1746,13 +1743,7 @@ class MeshService : Service() { } private fun handleNodeInfo(info: MeshProtos.NodeInfo) { - Timber.d( - "Received nodeinfo num=${info.num}," + - " hasUser=${info.hasUser()}," + - " hasPosition=${info.hasPosition()}," + - " hasDeviceMetrics=${info.hasDeviceMetrics()}", - ) - + Timber.d("[nodeInfo] ${info.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1817,6 +1808,7 @@ class MeshService : Service() { /** Update MyNodeInfo (called from either new API version or the old one) */ private fun handleMyInfo(myInfo: MeshProtos.MyNodeInfo) { + Timber.d("[myInfo] ${myInfo.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1840,7 +1832,7 @@ class MeshService : Service() { /** Update our DeviceMetadata */ private fun handleMetadata(metadata: MeshProtos.DeviceMetadata) { - Timber.d("Received deviceMetadata ${metadata.toOneLineString()}") + Timber.d("[deviceMetadata] ${metadata.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1856,6 +1848,7 @@ class MeshService : Service() { /** Publish MqttClientProxyMessage (fromRadio) */ private fun handleMqttProxyMessage(message: MeshProtos.MqttClientProxyMessage) { + Timber.d("[mqttClientProxyMessage] ${message.toPIIString()}") with(message) { when (payloadVariantCase) { MeshProtos.MqttClientProxyMessage.PayloadVariantCase.TEXT -> { @@ -1872,7 +1865,7 @@ class MeshService : Service() { } private fun handleClientNotification(notification: MeshProtos.ClientNotification) { - Timber.d("Received clientNotification ${notification.toOneLineString()}") + Timber.d("[clientNotification] ${notification.toPIIString()}") serviceRepository.setClientNotification(notification) serviceNotifications.showClientNotification(notification) // if the future for the originating request is still in the queue, complete as unsuccessful @@ -1890,7 +1883,7 @@ class MeshService : Service() { } private fun handleFileInfo(fileInfo: MeshProtos.FileInfo) { - Timber.d("Received fileInfo ${fileInfo.toOneLineString()}") + Timber.d("[fileInfo] ${fileInfo.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1903,7 +1896,7 @@ class MeshService : Service() { } private fun handleLogRecord(logRecord: MeshProtos.LogRecord) { - Timber.d("Received logRecord ${logRecord.toOneLineString()}") + Timber.d("[logRecord] ${logRecord.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1916,7 +1909,7 @@ class MeshService : Service() { } private fun handleRebooted(rebooted: Boolean) { - Timber.d("Received rebooted ${rebooted.toOneLineString()}") + Timber.d("[rebooted] $rebooted") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1929,7 +1922,7 @@ class MeshService : Service() { } private fun handleXmodemPacket(xmodemPacket: XmodemProtos.XModem) { - Timber.d("Received XmodemPacket ${xmodemPacket.toOneLineString()}") + Timber.d("[xmodemPacket] ${xmodemPacket.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1942,7 +1935,7 @@ class MeshService : Service() { } private fun handleDeviceUiConfig(deviceuiConfig: DeviceUIProtos.DeviceUIConfig) { - Timber.d("Received deviceUIConfig ${deviceuiConfig.toOneLineString()}") + Timber.d("[deviceuiConfig] ${deviceuiConfig.toPIIString()}") val packetToSave = MeshLog( uuid = UUID.randomUUID().toString(), @@ -1977,7 +1970,6 @@ class MeshService : Service() { } private fun onHasSettings() { - packetHandler.sendToRadio(newMeshPacketTo(myNodeNum).buildAdminPacket { setTimeOnly = currentSecond() }) processQueuedPackets() startMqttClientProxy() serviceBroadcasts.broadcastConnection() @@ -1989,15 +1981,11 @@ class MeshService : Service() { "subscribePorts afterReconnect ports=$ports" } requestHistoryReplay("onHasSettings") + packetHandler.sendToRadio(newMeshPacketTo(myNodeNum).buildAdminPacket { setTimeOnly = currentSecond() }) } private fun handleConfigComplete(configCompleteId: Int) { - Timber.d( - "handleConfigComplete id=%d configOnly=%d nodeInfo=%d", - configCompleteId, - configOnlyNonce, - nodeInfoNonce, - ) + Timber.d("[configCompleteId]: ${configCompleteId.toPIIString()}") when (configCompleteId) { configOnlyNonce -> handleConfigOnlyComplete() nodeInfoNonce -> handleNodeInfoComplete()