feat(logging): Replace Timber with Kermit for multiplatform logging (#4083)

Signed-off-by: James Rich <2199651+jamesarich@users.noreply.github.com>
This commit is contained in:
James Rich 2025-12-28 08:30:15 -06:00 committed by GitHub
parent a927481e4d
commit 0776e029f3
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
92 changed files with 727 additions and 957 deletions

View file

@ -22,6 +22,7 @@ import android.app.Application
import android.bluetooth.BluetoothAdapter
import androidx.lifecycle.Lifecycle
import androidx.lifecycle.coroutineScope
import co.touchlab.kermit.Logger
import com.geeksville.mesh.repository.radio.BleConstants.BLE_NAME_PATTERN
import com.geeksville.mesh.repository.radio.BleConstants.BTM_SERVICE_UUID
import com.geeksville.mesh.util.registerReceiverCompat
@ -42,7 +43,6 @@ import no.nordicsemi.kotlin.ble.core.Manager
import org.meshtastic.core.common.hasBluetoothPermission
import org.meshtastic.core.di.CoroutineDispatchers
import org.meshtastic.core.di.ProcessLifecycle
import timber.log.Timber
import javax.inject.Inject
import javax.inject.Singleton
import kotlin.time.Duration.Companion.seconds
@ -112,7 +112,7 @@ constructor(
.onStart { _isScanning.value = true }
.onCompletion { _isScanning.value = false }
.catch { ex ->
Timber.w(ex, "Bluetooth scan failed")
Logger.w(ex) { "Bluetooth scan failed" }
_isScanning.value = false
}
.collect { peripheral ->
@ -158,7 +158,7 @@ constructor(
)
_state.emit(newState)
Timber.d("Detected our bluetooth access=$newState")
Logger.d { "Detected our bluetooth access=$newState" }
}
@SuppressLint("MissingPermission")

View file

@ -17,6 +17,7 @@
package com.geeksville.mesh.repository.network
import co.touchlab.kermit.Logger
import com.geeksville.mesh.util.ignoreException
import com.google.protobuf.ByteString
import kotlinx.coroutines.channels.awaitClose
@ -36,7 +37,6 @@ import org.meshtastic.core.data.repository.RadioConfigRepository
import org.meshtastic.core.model.util.subscribeList
import org.meshtastic.proto.MeshProtos.MqttClientProxyMessage
import org.meshtastic.proto.mqttClientProxyMessage
import timber.log.Timber
import java.net.URI
import java.security.SecureRandom
import javax.inject.Inject
@ -70,7 +70,7 @@ constructor(
private var mqttClient: MqttAsyncClient? = null
fun disconnect() {
Timber.i("MQTT Disconnected")
Logger.i { "MQTT Disconnected" }
mqttClient?.apply {
ignoreException { disconnect() }
close(true)
@ -110,7 +110,7 @@ constructor(
val callback =
object : MqttCallbackExtended {
override fun connectComplete(reconnect: Boolean, serverURI: String) {
Timber.i("MQTT connectComplete: $serverURI reconnect: $reconnect")
Logger.i { "MQTT connectComplete: $serverURI reconnect: $reconnect" }
channelSet.subscribeList
.ifEmpty {
return
@ -123,7 +123,7 @@ constructor(
}
override fun connectionLost(cause: Throwable) {
Timber.i("MQTT connectionLost cause: $cause")
Logger.i { "MQTT connectionLost cause: $cause" }
if (cause is IllegalArgumentException) close(cause)
}
@ -138,7 +138,7 @@ constructor(
}
override fun deliveryComplete(token: IMqttDeliveryToken?) {
Timber.i("MQTT deliveryComplete messageId: ${token?.messageId}")
Logger.i { "MQTT deliveryComplete messageId: ${token?.messageId}" }
}
}
@ -161,15 +161,15 @@ constructor(
private fun subscribe(topic: String) {
mqttClient?.subscribe(topic, DEFAULT_QOS)
Timber.i("MQTT Subscribed to topic: $topic")
Logger.i { "MQTT Subscribed to topic: $topic" }
}
fun publish(topic: String, data: ByteArray, retained: Boolean) {
try {
val token = mqttClient?.publish(topic, data, DEFAULT_QOS, retained)
Timber.i("MQTT Publish messageId: ${token?.messageId}")
Logger.i { "MQTT Publish messageId: ${token?.messageId}" }
} catch (ex: Exception) {
Timber.e("MQTT Publish error: ${ex.message}")
Logger.e { "MQTT Publish error: ${ex.message}" }
}
}
}

View file

@ -21,6 +21,7 @@ import android.annotation.SuppressLint
import android.net.nsd.NsdManager
import android.net.nsd.NsdServiceInfo
import android.os.Build
import co.touchlab.kermit.Logger
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.ExperimentalCoroutinesApi
import kotlinx.coroutines.asExecutor
@ -30,7 +31,6 @@ import kotlinx.coroutines.flow.Flow
import kotlinx.coroutines.flow.callbackFlow
import kotlinx.coroutines.flow.mapLatest
import kotlinx.coroutines.suspendCancellableCoroutine
import timber.log.Timber
import java.util.concurrent.CopyOnWriteArrayList
import kotlin.coroutines.resume
@ -54,22 +54,22 @@ private fun NsdManager.discoverServices(
}
override fun onDiscoveryStarted(serviceType: String) {
Timber.d("NSD Service discovery started")
Logger.d { "NSD Service discovery started" }
}
override fun onDiscoveryStopped(serviceType: String) {
Timber.d("NSD Service discovery stopped")
Logger.d { "NSD Service discovery stopped" }
close()
}
override fun onServiceFound(serviceInfo: NsdServiceInfo) {
Timber.d("NSD Service found: $serviceInfo")
Logger.d { "NSD Service found: $serviceInfo" }
serviceList += serviceInfo
trySend(serviceList)
}
override fun onServiceLost(serviceInfo: NsdServiceInfo) {
Timber.d("NSD Service lost: $serviceInfo")
Logger.d { "NSD Service lost: $serviceInfo" }
serviceList.removeAll { it.serviceName == serviceInfo.serviceName }
trySend(serviceList)
}
@ -102,7 +102,7 @@ private suspend fun NsdManager.resolveService(serviceInfo: NsdServiceInfo): NsdS
try {
unregisterServiceInfoCallback(this)
} catch (e: IllegalArgumentException) {
Timber.w(e, "Already unregistered")
Logger.w(e) { "Already unregistered" }
}
}
}
@ -112,7 +112,7 @@ private suspend fun NsdManager.resolveService(serviceInfo: NsdServiceInfo): NsdS
try {
unregisterServiceInfoCallback(this)
} catch (e: IllegalArgumentException) {
Timber.w(e, "Already unregistered")
Logger.w(e) { "Already unregistered" }
}
}
@ -125,7 +125,7 @@ private suspend fun NsdManager.resolveService(serviceInfo: NsdServiceInfo): NsdS
try {
unregisterServiceInfoCallback(callback)
} catch (e: IllegalArgumentException) {
Timber.w(e, "Already unregistered")
Logger.w(e) { "Already unregistered" }
}
}
} else {

View file

@ -17,6 +17,7 @@
package com.geeksville.mesh.repository.radio
import co.touchlab.kermit.Logger
import com.geeksville.mesh.concurrent.handledLaunch
import com.geeksville.mesh.model.getInitials
import com.google.protobuf.ByteString
@ -38,7 +39,6 @@ import org.meshtastic.proto.config
import org.meshtastic.proto.deviceMetadata
import org.meshtastic.proto.fromRadio
import org.meshtastic.proto.queueStatus
import timber.log.Timber
import kotlin.random.Random
private val defaultLoRaConfig =
@ -71,7 +71,7 @@ constructor(
private val packetIdSequence = generateSequence { currentPacketId++ }.iterator()
init {
Timber.i("Starting the mock interface")
Logger.i { "Starting the mock interface" }
service.onConnect() // Tell clients they can use the API
}
@ -86,7 +86,7 @@ constructor(
data != null && data.portnum == Portnums.PortNum.ADMIN_APP ->
handleAdminPacket(pr, AdminProtos.AdminMessage.parseFrom(data.payload))
pr.hasPacket() && pr.packet.wantAck -> sendFakeAck(pr)
else -> Timber.i("Ignoring data sent to mock interface $pr")
else -> Logger.i { "Ignoring data sent to mock interface $pr" }
}
}
@ -108,12 +108,12 @@ constructor(
}
}
else -> Timber.i("Ignoring admin sent to mock interface $d")
else -> Logger.i { "Ignoring admin sent to mock interface $d" }
}
}
override fun close() {
Timber.i("Closing the mock interface")
Logger.i { "Closing the mock interface" }
}
// / Generate a fake text message from a node
@ -297,7 +297,7 @@ constructor(
}
private fun sendConfigResponse(configId: Int) {
Timber.d("Sending mock config response")
Logger.d { "Sending mock config response" }
// / Generate a fake node info entry
@Suppress("MagicNumber")

View file

@ -18,6 +18,7 @@
package com.geeksville.mesh.repository.radio
import android.annotation.SuppressLint
import co.touchlab.kermit.Logger
import com.geeksville.mesh.repository.radio.BleConstants.BTM_FROMNUM_CHARACTER
import com.geeksville.mesh.repository.radio.BleConstants.BTM_FROMRADIO_CHARACTER
import com.geeksville.mesh.repository.radio.BleConstants.BTM_LOGRADIO_CHARACTER
@ -52,7 +53,6 @@ import no.nordicsemi.kotlin.ble.client.android.Peripheral
import no.nordicsemi.kotlin.ble.core.CharacteristicProperty
import no.nordicsemi.kotlin.ble.core.ConnectionState
import no.nordicsemi.kotlin.ble.core.WriteType
import timber.log.Timber
import java.util.UUID
import kotlin.uuid.ExperimentalUuidApi
import kotlin.uuid.toKotlinUuid
@ -79,12 +79,12 @@ constructor(
) : IRadioInterface {
private val exceptionHandler = CoroutineExceptionHandler { _, throwable ->
Timber.e(throwable, "[$address] Uncaught exception in connectionScope")
Logger.e(throwable) { "[$address] Uncaught exception in connectionScope" }
serviceScope.launch {
try {
peripheral?.disconnect()
} catch (e: Exception) {
Timber.e(e, "[$address] Failed to disconnect in exception handler")
Logger.e(e) { "[$address] Failed to disconnect in exception handler" }
}
}
service.onDisconnect(BleError.from(throwable))
@ -118,7 +118,7 @@ constructor(
val packet =
fromRadioCharacteristic?.read()?.takeIf { it.isNotEmpty() }
?: run {
Timber.d("[$address] fromRadio queue drain complete (read empty/null)")
Logger.d { "[$address] fromRadio queue drain complete (read empty/null)" }
break
}
send(packet)
@ -128,14 +128,14 @@ constructor(
private fun dispatchPacket(packet: ByteArray) {
packetsReceived++
bytesReceived += packet.size
Timber.d(
Logger.d {
"[$address] Dispatching packet to service.handleFromRadio() - " +
"Packet #$packetsReceived, ${packet.size} bytes (Total: $bytesReceived bytes)",
)
"Packet #$packetsReceived, ${packet.size} bytes (Total: $bytesReceived bytes)"
}
try {
service.handleFromRadio(p = packet)
} catch (t: Throwable) {
Timber.e(t, "[$address] Failed to execute service.handleFromRadio()")
Logger.e(t) { "[$address] Failed to execute service.handleFromRadio()" }
}
}
@ -145,13 +145,13 @@ constructor(
fromRadioPacketFlow()
.onEach { packet ->
drainedCount++
Timber.d("[$address] Read packet from queue (${packet.size} bytes)")
Logger.d { "[$address] Read packet from queue (${packet.size} bytes)" }
dispatchPacket(packet)
}
.catch { ex -> Timber.w(ex, "[$address] Exception while draining packet queue") }
.catch { ex -> Logger.w(ex) { "[$address] Exception while draining packet queue" } }
.onCompletion {
if (drainedCount > 0) {
Timber.d("[$address] Drained $drainedCount packets from packet queue")
Logger.d { "[$address] Drained $drainedCount packets from packet queue" }
}
}
.collect()
@ -168,19 +168,19 @@ constructor(
connectionScope.launch {
try {
connectionStartTime = System.currentTimeMillis()
Timber.i("[$address] BLE connection attempt started at $connectionStartTime")
Logger.i { "[$address] BLE connection attempt started at $connectionStartTime" }
peripheral = retryCall { findAndConnectPeripheral() }
peripheral?.let {
val connectionTime = System.currentTimeMillis() - connectionStartTime
Timber.i("[$address] BLE peripheral connected in ${connectionTime}ms")
Logger.i { "[$address] BLE peripheral connected in ${connectionTime}ms" }
onConnected()
observePeripheralChanges()
discoverServicesAndSetupCharacteristics(it)
}
} catch (e: Exception) {
val failureTime = System.currentTimeMillis() - connectionStartTime
Timber.e(e, "[$address] Failed to connect to peripheral after ${failureTime}ms")
Logger.e(e) { "[$address] Failed to connect to peripheral after ${failureTime}ms" }
service.onDisconnect(BleError.from(e))
}
}
@ -200,27 +200,27 @@ constructor(
try {
peripheral?.let { p ->
val rssi = retryCall { p.readRssi() }
Timber.d("[$address] Connection established. RSSI: $rssi dBm")
Logger.d { "[$address] Connection established. RSSI: $rssi dBm" }
val phyInUse = retryCall { p.readPhy() }
Timber.d("[$address] PHY in use: $phyInUse")
Logger.d { "[$address] PHY in use: $phyInUse" }
}
} catch (e: Exception) {
Timber.w(e, "[$address] Failed to read initial connection properties")
Logger.w(e) { "[$address] Failed to read initial connection properties" }
}
}
private fun observePeripheralChanges() {
peripheral?.let { p ->
p.phy.onEach { phy -> Timber.i("[$address] BLE PHY changed to $phy") }.launchIn(connectionScope)
p.phy.onEach { phy -> Logger.i { "[$address] BLE PHY changed to $phy" } }.launchIn(connectionScope)
p.connectionParameters
.onEach { params -> Timber.i("[$address] BLE connection parameters changed to $params") }
.onEach { params -> Logger.i { "[$address] BLE connection parameters changed to $params" } }
.launchIn(connectionScope)
p.state
.onEach { state ->
Timber.i("[$address] BLE connection state changed to $state")
Logger.i { "[$address] BLE connection state changed to $state" }
if (state is ConnectionState.Disconnected) {
val uptime =
if (connectionStartTime > 0) {
@ -228,19 +228,19 @@ constructor(
} else {
0
}
Timber.w(
Logger.w {
"[$address] BLE disconnected - Reason: ${state.reason}, " +
"Uptime: ${uptime}ms, " +
"Packets RX: $packetsReceived ($bytesReceived bytes), " +
"Packets TX: $packetsSent ($bytesSent bytes)",
)
"Packets TX: $packetsSent ($bytesSent bytes)"
}
service.onDisconnect(BleError.Disconnected(reason = state.reason))
}
}
.launchIn(connectionScope)
}
centralManager.state
.onEach { state -> Timber.i("[$address] CentralManager state changed to $state") }
.onEach { state -> Logger.i { "[$address] CentralManager state changed to $state" } }
.launchIn(connectionScope)
}
@ -268,35 +268,35 @@ constructor(
it != null
}
) {
Timber.d(
"[$address] Found toRadio: ${toRadioCharacteristic?.uuid}, ${toRadioCharacteristic?.instanceId}",
)
Timber.d(
"[$address] Found fromNum: ${fromNumCharacteristic?.uuid}, ${fromNumCharacteristic?.instanceId}",
)
Timber.d(
"[$address] Found fromRadio: ${fromRadioCharacteristic?.uuid}, ${fromRadioCharacteristic?.instanceId}",
)
Timber.d(
"[$address] Found logRadio: ${logRadioCharacteristic?.uuid}, ${logRadioCharacteristic?.instanceId}",
)
Logger.d {
"[$address] Found toRadio: ${toRadioCharacteristic?.uuid}, ${toRadioCharacteristic?.instanceId}"
}
Logger.d {
"[$address] Found fromNum: ${fromNumCharacteristic?.uuid}, ${fromNumCharacteristic?.instanceId}"
}
Logger.d {
"[$address] Found fromRadio: ${fromRadioCharacteristic?.uuid}, ${fromRadioCharacteristic?.instanceId}"
}
Logger.d {
"[$address] Found logRadio: ${logRadioCharacteristic?.uuid}, ${logRadioCharacteristic?.instanceId}"
}
setupNotifications()
service.onConnect()
} else {
Timber.w("[$address] Discovery failed: missing required characteristics")
Logger.w { "[$address] Discovery failed: missing required characteristics" }
service.onDisconnect(BleError.DiscoveryFailed("One or more characteristics not found"))
}
} else {
Timber.w("[$address] Discovery failed: Meshtastic service not found")
Logger.w { "[$address] Discovery failed: Meshtastic service not found" }
service.onDisconnect(BleError.DiscoveryFailed("Meshtastic service not found"))
}
}
.catch { e ->
Timber.e(e, "[$address] Service discovery failed")
Logger.e(e) { "[$address] Service discovery failed" }
try {
peripheral.disconnect()
} catch (e2: Exception) {
Timber.e(e2, "[$address] Failed to disconnect in discovery catch")
Logger.e(e2) { "[$address] Failed to disconnect in discovery catch" }
}
service.onDisconnect(BleError.from(e))
}
@ -309,29 +309,29 @@ constructor(
@OptIn(ExperimentalUuidApi::class)
private suspend fun setupNotifications() {
retryCall { fromNumCharacteristic?.subscribe() }
?.onStart { Timber.d("[$address] Subscribing to fromNumCharacteristic") }
?.onStart { Logger.d { "[$address] Subscribing to fromNumCharacteristic" } }
?.onEach { notifyBytes ->
Timber.d("[$address] FromNum Notification (${notifyBytes.size} bytes), draining queue")
Logger.d { "[$address] FromNum Notification (${notifyBytes.size} bytes), draining queue" }
connectionScope.launch { drainPacketQueueAndDispatch() }
}
?.catch { e ->
Timber.e(e, "[$address] Error subscribing to fromNumCharacteristic")
Logger.e(e) { "[$address] Error subscribing to fromNumCharacteristic" }
service.onDisconnect(BleError.from(e))
}
?.onCompletion { cause -> Timber.d("[$address] fromNum sub flow completed, cause=$cause") }
?.onCompletion { cause -> Logger.d { "[$address] fromNum sub flow completed, cause=$cause" } }
?.launchIn(scope = connectionScope)
retryCall { logRadioCharacteristic?.subscribe() }
?.onStart { Timber.d("[$address] Subscribing to logRadioCharacteristic") }
?.onStart { Logger.d { "[$address] Subscribing to logRadioCharacteristic" } }
?.onEach { notifyBytes ->
Timber.d("[$address] LogRadio Notification (${notifyBytes.size} bytes), dispatching packet")
Logger.d { "[$address] LogRadio Notification (${notifyBytes.size} bytes), dispatching packet" }
dispatchPacket(notifyBytes)
}
?.catch { e ->
Timber.e(e, "[$address] Error subscribing to logRadioCharacteristic")
Logger.e(e) { "[$address] Error subscribing to logRadioCharacteristic" }
service.onDisconnect(BleError.from(e))
}
?.onCompletion { cause -> Timber.d("[$address] logRadio sub flow completed, cause=$cause") }
?.onCompletion { cause -> Logger.d { "[$address] logRadio sub flow completed, cause=$cause" } }
?.launchIn(scope = connectionScope)
}
@ -345,14 +345,13 @@ constructor(
} catch (e: Exception) {
currentAttempt++
if (currentAttempt >= RETRY_COUNT) {
Timber.e(e, "[$address] BLE operation failed after $RETRY_COUNT attempts, giving up")
Logger.e(e) { "[$address] BLE operation failed after $RETRY_COUNT attempts, giving up" }
throw e
}
Timber.w(
e,
Logger.w(e) {
"[$address] BLE operation failed (attempt $currentAttempt/$RETRY_COUNT), " +
"retrying in ${RETRY_DELAY_MS}ms...",
)
"retrying in ${RETRY_DELAY_MS}ms..."
}
delay(RETRY_DELAY_MS)
}
}
@ -368,7 +367,7 @@ constructor(
override fun handleSendToRadio(p: ByteArray) {
toRadioCharacteristic?.let { characteristic ->
if (peripheral == null) {
Timber.w("[$address] BLE peripheral is null, cannot send packet")
Logger.w { "[$address] BLE peripheral is null, cannot send packet" }
return@let
}
connectionScope.launch {
@ -383,24 +382,23 @@ constructor(
retryCall {
packetsSent++
bytesSent += p.size
Timber.d(
Logger.d {
"[$address] Writing packet #$packetsSent to toRadioCharacteristic with $writeType - " +
"${p.size} bytes (Total TX: $bytesSent bytes)",
)
"${p.size} bytes (Total TX: $bytesSent bytes)"
}
characteristic.write(p, writeType = writeType)
}
drainPacketQueueAndDispatch()
} catch (e: Exception) {
Timber.e(
e,
Logger.e(e) {
"[$address] Failed to write packet to toRadioCharacteristic after " +
"$packetsSent successful writes",
)
"$packetsSent successful writes"
}
service.onDisconnect(BleError.from(e))
}
}
}
} ?: Timber.w("[$address] toRadio characteristic unavailable, can't send data")
} ?: Logger.w { "[$address] toRadio characteristic unavailable, can't send data" }
}
/** Closes the connection to the device. */
@ -412,12 +410,12 @@ constructor(
} else {
0
}
Timber.i(
Logger.i {
"[$address] BLE close() called - " +
"Uptime: ${uptime}ms, " +
"Packets RX: $packetsReceived ($bytesReceived bytes), " +
"Packets TX: $packetsSent ($bytesSent bytes)",
)
"Packets TX: $packetsSent ($bytesSent bytes)"
}
connectionScope.cancel()
peripheral?.disconnect()
service.onDisconnect(true)

View file

@ -17,9 +17,9 @@
package com.geeksville.mesh.repository.radio
import co.touchlab.kermit.Logger
import com.geeksville.mesh.repository.bluetooth.BluetoothRepository
import org.meshtastic.core.model.util.anonymize
import timber.log.Timber
import javax.inject.Inject
/** Bluetooth backend implementation. */
@ -35,7 +35,7 @@ constructor(
override fun addressValid(rest: String): Boolean {
val allPaired = bluetoothRepository.state.value.bondedDevices.map { it.address }.toSet()
return if (!allPaired.contains(rest)) {
Timber.w("Ignoring stale bond to ${rest.anonymize}")
Logger.w { "Ignoring stale bond to ${rest.anonymize}" }
false
} else {
true

View file

@ -21,6 +21,7 @@ import android.app.Application
import android.provider.Settings
import androidx.lifecycle.Lifecycle
import androidx.lifecycle.coroutineScope
import co.touchlab.kermit.Logger
import com.geeksville.mesh.BuildConfig
import com.geeksville.mesh.android.BinaryLogFile
import com.geeksville.mesh.android.BuildUtils
@ -50,7 +51,6 @@ import org.meshtastic.core.model.util.anonymize
import org.meshtastic.core.prefs.radio.RadioPrefs
import org.meshtastic.core.service.ConnectionState
import org.meshtastic.proto.MeshProtos
import timber.log.Timber
import javax.inject.Inject
import javax.inject.Singleton
@ -141,7 +141,7 @@ constructor(
fun keepAlive(now: Long = System.currentTimeMillis()) {
if (now - lastHeartbeatMillis > HEARTBEAT_INTERVAL_MILLIS) {
if (radioIf is SerialInterface) {
Timber.i("Sending ToRadio heartbeat")
Logger.i { "Sending ToRadio heartbeat" }
val heartbeat =
MeshProtos.ToRadio.newBuilder().setHeartbeat(MeshProtos.Heartbeat.getDefaultInstance()).build()
handleSendToRadio(heartbeat.toByteArray())
@ -206,7 +206,7 @@ constructor(
}
private fun broadcastConnectionChanged(newState: ConnectionState) {
Timber.d("Broadcasting connection state change to $newState")
Logger.d { "Broadcasting connection state change to $newState" }
processLifecycle.coroutineScope.launch(dispatchers.default) { _connectionState.emit(newState) }
}
@ -223,7 +223,7 @@ constructor(
receivedPacketsLog.write(p)
receivedPacketsLog.flush()
} catch (t: Throwable) {
Timber.w(t, "Failed to write receive log in handleFromRadio")
Logger.w(t) { "Failed to write receive log in handleFromRadio" }
}
}
@ -231,13 +231,13 @@ constructor(
keepAlive(System.currentTimeMillis())
}
// ignoreException { Timber.d("FromRadio: ${MeshProtos.FromRadio.parseFrom(p)}") }
// ignoreException { Logger.d { "FromRadio: ${MeshProtos.FromRadio.parseFrom(p }}" } }
try {
processLifecycle.coroutineScope.launch(dispatchers.io) { _receivedData.emit(p) }
emitReceiveActivity()
} catch (t: Throwable) {
Timber.e(t, "RadioInterfaceService.handleFromRadio failed while emitting data")
Logger.e(t) { "RadioInterfaceService.handleFromRadio failed while emitting data" }
}
}
@ -262,13 +262,13 @@ constructor(
/** Start our configured interface (if it isn't already running) */
private fun startInterface() {
if (radioIf !is NopInterface) {
Timber.w("Can't start interface - $radioIf is already running")
Logger.w { "Can't start interface - $radioIf is already running" }
} else {
val address = getBondedDeviceAddress()
if (address == null) {
Timber.w("No bonded mesh radio, can't start interface")
Logger.w { "No bonded mesh radio, can't start interface" }
} else {
Timber.i("Starting radio ${address.anonymize}")
Logger.i { "Starting radio ${address.anonymize}" }
isStarted = true
if (logSends) {
@ -285,7 +285,7 @@ constructor(
private fun stopInterface() {
val r = radioIf
Timber.i("stopping interface $r")
Logger.i { "stopping interface $r" }
isStarted = false
radioIf = interfaceFactory.nopInterface
r.close()
@ -314,7 +314,7 @@ constructor(
*/
private fun setBondedDeviceAddress(address: String?): Boolean =
if (getBondedDeviceAddress() == address && isStarted && _connectionState.value == ConnectionState.Connected) {
Timber.w("Ignoring setBondedDevice ${address.anonymize}, because we are already using that device")
Logger.w { "Ignoring setBondedDevice ${address.anonymize}, because we are already using that device" }
false
} else {
// Record that this use has configured a new radio
@ -325,7 +325,7 @@ constructor(
// The device address "n" can be used to mean none
Timber.d("Setting bonded device to ${address.anonymize}")
Logger.d { "Setting bonded device to ${address.anonymize}" }
// Stores the address if non-null, otherwise removes the pref
radioPrefs.devAddr = address
@ -366,14 +366,14 @@ constructor(
// Use tryEmit for SharedFlow as it's non-blocking
val emitted = _meshActivity.tryEmit(MeshActivity.Send)
if (!emitted) {
Timber.d("MeshActivity.Send event was not emitted due to buffer overflow or no collectors")
Logger.d { "MeshActivity.Send event was not emitted due to buffer overflow or no collectors" }
}
}
private fun emitReceiveActivity() {
val emitted = _meshActivity.tryEmit(MeshActivity.Receive)
if (!emitted) {
Timber.d("MeshActivity.Receive event was not emitted due to buffer overflow or no collectors")
Logger.d { "MeshActivity.Receive event was not emitted due to buffer overflow or no collectors" }
}
}
}

View file

@ -17,12 +17,12 @@
package com.geeksville.mesh.repository.radio
import co.touchlab.kermit.Logger
import com.geeksville.mesh.repository.usb.SerialConnection
import com.geeksville.mesh.repository.usb.SerialConnectionListener
import com.geeksville.mesh.repository.usb.UsbRepository
import dagger.assisted.Assisted
import dagger.assisted.AssistedInject
import timber.log.Timber
import java.util.concurrent.atomic.AtomicReference
/** An interface that assumes we are talking to a meshtastic device via USB serial */
@ -48,10 +48,10 @@ constructor(
override fun connect() {
val device = serialInterfaceSpec.findSerial(address)
if (device == null) {
Timber.e("[$address] Serial device not found at address")
Logger.e { "[$address] Serial device not found at address" }
} else {
val connectStart = System.currentTimeMillis()
Timber.i("[$address] Opening serial device: $device")
Logger.i { "[$address] Opening serial device: $device" }
var packetsReceived = 0
var bytesReceived = 0L
@ -60,7 +60,7 @@ constructor(
val onConnect: () -> Unit = {
connectionStartTime = System.currentTimeMillis()
val connectionTime = connectionStartTime - connectStart
Timber.i("[$address] Serial device connected in ${connectionTime}ms")
Logger.i { "[$address] Serial device connected in ${connectionTime}ms" }
super.connect()
}
@ -69,9 +69,9 @@ constructor(
device,
object : SerialConnectionListener {
override fun onMissingPermission() {
Timber.e(
"[$address] Serial connection failed - missing USB permissions for device: $device",
)
Logger.e {
"[$address] Serial connection failed - missing USB permissions for device: $device"
}
}
override fun onConnected() {
@ -81,10 +81,10 @@ constructor(
override fun onDataReceived(bytes: ByteArray) {
packetsReceived++
bytesReceived += bytes.size
Timber.d(
Logger.d {
"[$address] Serial received packet #$packetsReceived - " +
"${bytes.size} byte(s) (Total RX: $bytesReceived bytes)",
)
"${bytes.size} byte(s) (Total RX: $bytesReceived bytes)"
}
bytes.forEach(::readChar)
}
@ -95,13 +95,15 @@ constructor(
} else {
0
}
thrown?.let { e -> Timber.e(e, "[$address] Serial error after ${uptime}ms: ${e.message}") }
Timber.w(
thrown?.let { e ->
Logger.e(e) { "[$address] Serial error after ${uptime}ms: ${e.message}" }
}
Logger.w {
"[$address] Serial device disconnected - " +
"Device: $device, " +
"Uptime: ${uptime}ms, " +
"Packets RX: $packetsReceived ($bytesReceived bytes)",
)
"Packets RX: $packetsReceived ($bytesReceived bytes)"
}
onDeviceDisconnect(false)
}
},
@ -116,10 +118,10 @@ constructor(
override fun sendBytes(p: ByteArray) {
val conn = connRef.get()
if (conn != null) {
Timber.d("[$address] Serial sending ${p.size} bytes")
Logger.d { "[$address] Serial sending ${p.size} bytes" }
conn.sendBytes(p)
} else {
Timber.w("[$address] Serial connection not available, cannot send ${p.size} bytes")
Logger.w { "[$address] Serial connection not available, cannot send ${p.size} bytes" }
}
}
}

View file

@ -17,7 +17,7 @@
package com.geeksville.mesh.repository.radio
import timber.log.Timber
import co.touchlab.kermit.Logger
/**
* An interface that assumes we are talking to a meshtastic device over some sort of stream connection (serial or TCP
@ -41,7 +41,7 @@ abstract class StreamInterface(protected val service: RadioInterfaceService) : I
private var packetLen = 0
override fun close() {
Timber.d("Closing stream for good")
Logger.d { "Closing stream for good" }
onDeviceDisconnect(true)
}
@ -90,7 +90,7 @@ abstract class StreamInterface(protected val service: RadioInterfaceService) : I
when (val c = b.toInt().toChar()) {
'\r' -> {} // ignore
'\n' -> {
Timber.d("DeviceLog: $debugLineBuf")
Logger.d { "DeviceLog: $debugLineBuf" }
debugLineBuf.clear()
}
else -> debugLineBuf.append(c)
@ -104,7 +104,7 @@ abstract class StreamInterface(protected val service: RadioInterfaceService) : I
var nextPtr = ptr + 1
fun lostSync() {
Timber.e("Lost protocol sync")
Logger.e { "Lost protocol sync" }
nextPtr = 0
}

View file

@ -17,6 +17,7 @@
package com.geeksville.mesh.repository.radio
import co.touchlab.kermit.Logger
import com.geeksville.mesh.concurrent.handledLaunch
import com.geeksville.mesh.repository.network.NetworkRepository
import com.geeksville.mesh.util.Exceptions
@ -25,7 +26,6 @@ import dagger.assisted.AssistedInject
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.delay
import kotlinx.coroutines.withContext
import timber.log.Timber
import java.io.BufferedInputStream
import java.io.BufferedOutputStream
import java.io.IOException
@ -67,12 +67,12 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
override fun sendBytes(p: ByteArray) {
packetsSent++
bytesSent += p.size
Timber.d("[$address] TCP sending packet #$packetsSent - ${p.size} bytes (Total TX: $bytesSent bytes)")
Logger.d { "[$address] TCP sending packet #$packetsSent - ${p.size} bytes (Total TX: $bytesSent bytes)" }
outStream.write(p)
}
override fun flushBytes() {
Timber.d("[$address] TCP flushing output stream")
Logger.d { "[$address] TCP flushing output stream" }
outStream.flush()
}
@ -85,13 +85,13 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
} else {
0
}
Timber.w(
Logger.w {
"[$address] TCP disconnecting - " +
"Uptime: ${uptime}ms, " +
"Packets RX: $packetsReceived ($bytesReceived bytes), " +
"Packets TX: $packetsSent ($bytesSent bytes), " +
"Timeout events: $timeoutEvents",
)
"Timeout events: $timeoutEvents"
}
s.close()
socket = null
}
@ -110,7 +110,7 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
} else {
0
}
Timber.e(ex, "[$address] TCP IOException after ${uptime}ms - ${ex.message}")
Logger.e(ex) { "[$address] TCP IOException after ${uptime}ms - ${ex.message}" }
onDeviceDisconnect(false)
} catch (ex: Throwable) {
val uptime =
@ -119,38 +119,38 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
} else {
0
}
Timber.e(ex, "[$address] TCP exception after ${uptime}ms - ${ex.message}")
Logger.e(ex) { "[$address] TCP exception after ${uptime}ms - ${ex.message}" }
Exceptions.report(ex, "Exception in TCP reader")
onDeviceDisconnect(false)
}
if (retryCount > MAX_RETRIES_ALLOWED) {
Timber.e("[$address] TCP max retries ($MAX_RETRIES_ALLOWED) exceeded, giving up")
Logger.e { "[$address] TCP max retries ($MAX_RETRIES_ALLOWED) exceeded, giving up" }
break
}
Timber.i(
Logger.i {
"[$address] TCP reconnect attempt #$retryCount in ${backoffDelay / 1000}s " +
"(backoff: ${backoffDelay}ms)",
)
"(backoff: ${backoffDelay}ms)"
}
delay(backoffDelay)
retryCount++
backoffDelay = minOf(backoffDelay * 2, MAX_BACKOFF_MILLIS)
}
Timber.i("[$address] TCP reader exiting")
Logger.i { "[$address] TCP reader exiting" }
}
}
// Create a socket to make the connection with the server
private suspend fun startConnect() = withContext(Dispatchers.IO) {
val attemptStart = System.currentTimeMillis()
Timber.i("[$address] TCP connection attempt starting...")
Logger.i { "[$address] TCP connection attempt starting..." }
val (host, port) =
address.split(":", limit = 2).let { it[0] to (it.getOrNull(1)?.toIntOrNull() ?: SERVICE_PORT) }
Timber.d("[$address] Resolving host '$host' and connecting to port $port...")
Logger.d { "[$address] Resolving host '$host' and connecting to port $port..." }
Socket(InetAddress.getByName(host), port).use { socket ->
socket.tcpNoDelay = true
@ -159,10 +159,10 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
val connectTime = System.currentTimeMillis() - attemptStart
connectionStartTime = System.currentTimeMillis()
Timber.i(
Logger.i {
"[$address] TCP socket connected in ${connectTime}ms - " +
"Local: ${socket.localSocketAddress}, Remote: ${socket.remoteSocketAddress}",
)
"Local: ${socket.localSocketAddress}, Remote: ${socket.remoteSocketAddress}"
}
BufferedOutputStream(socket.getOutputStream()).use { outputStream ->
outStream = outputStream
@ -178,7 +178,9 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
try { // close after 90s of inactivity
val c = inputStream.read()
if (c == -1) {
Timber.w("[$address] TCP got EOF on stream after $packetsReceived packets received")
Logger.w {
"[$address] TCP got EOF on stream after $packetsReceived packets received"
}
break
} else {
timeoutCount = 0
@ -190,20 +192,20 @@ class TCPInterface @AssistedInject constructor(service: RadioInterfaceService, @
timeoutCount++
timeoutEvents++
if (timeoutCount % TIMEOUT_LOG_INTERVAL == 0) {
Timber.d(
Logger.d {
"[$address] TCP socket timeout count: $timeoutCount/$SOCKET_RETRIES " +
"(total timeouts: $timeoutEvents)",
)
"(total timeouts: $timeoutEvents)"
}
}
// Ignore and start another read
}
}
if (timeoutCount >= SOCKET_RETRIES) {
val inactivityMs = SOCKET_RETRIES * SOCKET_TIMEOUT
Timber.w(
Logger.w {
"[$address] TCP closing connection due to $SOCKET_RETRIES consecutive timeouts " +
"(${inactivityMs}ms of inactivity)",
)
"(${inactivityMs}ms of inactivity)"
}
}
}
}

View file

@ -18,11 +18,11 @@
package com.geeksville.mesh.repository.usb
import android.hardware.usb.UsbManager
import co.touchlab.kermit.Logger
import com.geeksville.mesh.util.ignoreException
import com.hoho.android.usbserial.driver.UsbSerialDriver
import com.hoho.android.usbserial.driver.UsbSerialPort
import com.hoho.android.usbserial.util.SerialInputOutputManager
import timber.log.Timber
import java.util.concurrent.CountDownLatch
import java.util.concurrent.TimeUnit
import java.util.concurrent.atomic.AtomicBoolean
@ -40,7 +40,7 @@ internal class SerialConnectionImpl(
override fun sendBytes(bytes: ByteArray) {
ioRef.get()?.let {
Timber.d("writing ${bytes.size} byte(s)")
Logger.d { "writing ${bytes.size} byte(s }" }
it.writeAsync(bytes)
}
}
@ -54,7 +54,7 @@ internal class SerialConnectionImpl(
// Allow a short amount of time for the manager to quit (so the port can be cleanly closed)
if (waitForStopped) {
Timber.d("Waiting for USB manager to stop...")
Logger.d { "Waiting for USB manager to stop..." }
closedLatch.await(1, TimeUnit.SECONDS)
}
}
@ -80,7 +80,7 @@ internal class SerialConnectionImpl(
port.dtr = true
port.rts = true
Timber.d("Starting serial reader thread")
Logger.d { "Starting serial reader thread" }
val io =
SerialInputOutputManager(
port,

View file

@ -23,9 +23,9 @@ import android.content.Intent
import android.content.IntentFilter
import android.hardware.usb.UsbDevice
import android.hardware.usb.UsbManager
import co.touchlab.kermit.Logger
import com.geeksville.mesh.util.exceptionReporter
import com.geeksville.mesh.util.getParcelableExtraCompat
import timber.log.Timber
import javax.inject.Inject
/** A helper class to call onChanged when bluetooth is enabled or disabled or when permissions are changed. */
@ -44,15 +44,15 @@ class UsbBroadcastReceiver @Inject constructor(private val usbRepository: UsbRep
when (intent.action) {
UsbManager.ACTION_USB_DEVICE_DETACHED -> {
Timber.d("USB device '$deviceName' was detached")
Logger.d { "USB device '$deviceName' was detached" }
usbRepository.refreshState()
}
UsbManager.ACTION_USB_DEVICE_ATTACHED -> {
Timber.d("USB device '$deviceName' was attached")
Logger.d { "USB device '$deviceName' was attached" }
usbRepository.refreshState()
}
UsbManager.EXTRA_PERMISSION_GRANTED -> {
Timber.d("USB device '$deviceName' was granted permission")
Logger.d { "USB device '$deviceName' was granted permission" }
usbRepository.refreshState()
}
}