diff --git a/Cargo.lock b/Cargo.lock index 93c24d2..9cefa21 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -64,6 +64,12 @@ dependencies = [ "pkg-config", ] +[[package]] +name = "android_log-sys" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "85965b6739a430150bdd138e2374a98af0c3ee0d030b3bb7fc3bddff58d0102e" + [[package]] name = "android_system_properties" version = "0.1.5" @@ -5821,6 +5827,17 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-android" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "12612be8f868a09c0ceae7113ff26afe79d81a24473a393cb9120ece162e86c0" +dependencies = [ + "android_log-sys", + "tracing", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.31" @@ -7099,6 +7116,7 @@ dependencies = [ "thiserror 2.0.18", "tokio", "tracing", + "tracing-android", "tracing-subscriber", "wzp-codec", "wzp-crypto", diff --git a/android/app/src/main/AndroidManifest.xml b/android/app/src/main/AndroidManifest.xml index 0eea970..166014a 100644 --- a/android/app/src/main/AndroidManifest.xml +++ b/android/app/src/main/AndroidManifest.xml @@ -29,5 +29,15 @@ android:name="com.wzp.service.CallService" android:foregroundServiceType="microphone" android:exported="false" /> + + + + diff --git a/android/app/src/main/java/com/wzp/audio/AudioPipeline.kt b/android/app/src/main/java/com/wzp/audio/AudioPipeline.kt index 40e93e3..7126f66 100644 --- a/android/app/src/main/java/com/wzp/audio/AudioPipeline.kt +++ b/android/app/src/main/java/com/wzp/audio/AudioPipeline.kt @@ -8,10 +8,19 @@ import android.media.AudioFormat import android.media.AudioRecord import android.media.AudioTrack import android.media.MediaRecorder +import android.media.audiofx.AcousticEchoCanceler +import android.media.audiofx.NoiseSuppressor import android.util.Log import androidx.core.content.ContextCompat import com.wzp.engine.WzpEngine +import java.io.BufferedOutputStream +import java.io.File +import java.io.FileOutputStream +import java.io.OutputStreamWriter +import java.nio.ByteBuffer +import java.nio.ByteOrder import kotlin.math.pow +import kotlin.math.sqrt /** * Audio pipeline that captures mic audio and plays received audio using @@ -43,9 +52,17 @@ class AudioPipeline(private val context: Context) { /** Capture (mic) gain in dB. 0 = unity. */ @Volatile var captureGainDb: Float = 0f + /** Whether to attach hardware AEC. Must be set before start(). */ + var aecEnabled: Boolean = true + /** Enable debug recording of PCM + RMS histogram to cache dir. */ + var debugRecording: Boolean = true private var captureThread: Thread? = null private var playoutThread: Thread? = null + private val debugDir: File by lazy { + File(context.cacheDir, "wzp_debug").also { it.mkdirs() } + } + fun start(engine: WzpEngine) { if (running) return running = true @@ -89,6 +106,15 @@ class AudioPipeline(private val context: Context) { } } + private fun computeRms(pcm: ShortArray, count: Int): Int { + var sumSq = 0.0 + for (i in 0 until count) { + val s = pcm[i].toDouble() + sumSq += s * s + } + return sqrt(sumSq / count).toInt() + } + private fun parkThread() { try { Thread.sleep(Long.MAX_VALUE) @@ -127,25 +153,86 @@ class AudioPipeline(private val context: Context) { return } + // Attach hardware AEC if available and enabled in settings + var aec: AcousticEchoCanceler? = null + var ns: NoiseSuppressor? = null + if (aecEnabled) { + if (AcousticEchoCanceler.isAvailable()) { + try { + aec = AcousticEchoCanceler.create(recorder.audioSessionId) + aec?.enabled = true + Log.i(TAG, "AEC enabled (session=${recorder.audioSessionId})") + } catch (e: Exception) { + Log.w(TAG, "AEC init failed: ${e.message}") + } + } else { + Log.w(TAG, "AEC not available on this device") + } + + // Attach hardware noise suppressor if available + if (NoiseSuppressor.isAvailable()) { + try { + ns = NoiseSuppressor.create(recorder.audioSessionId) + ns?.enabled = true + Log.i(TAG, "NoiseSuppressor enabled") + } catch (e: Exception) { + Log.w(TAG, "NoiseSuppressor init failed: ${e.message}") + } + } + } else { + Log.i(TAG, "AEC disabled by user setting") + } + recorder.startRecording() - Log.i(TAG, "capture started: ${SAMPLE_RATE}Hz mono, buf=$bufSize") + Log.i(TAG, "capture started: ${SAMPLE_RATE}Hz mono, buf=$bufSize, aec=${aec?.enabled}, ns=${ns?.enabled}") val pcm = ShortArray(FRAME_SAMPLES) + // Debug: PCM file + RMS CSV + var pcmOut: BufferedOutputStream? = null + var rmsCsv: OutputStreamWriter? = null + val byteConv = ByteBuffer.allocate(FRAME_SAMPLES * 2).order(ByteOrder.LITTLE_ENDIAN) + var frameIdx = 0L + if (debugRecording) { + try { + pcmOut = BufferedOutputStream(FileOutputStream(File(debugDir, "capture.pcm")), 65536) + rmsCsv = OutputStreamWriter(FileOutputStream(File(debugDir, "capture_rms.csv"))) + rmsCsv.write("frame,time_ms,rms\n") + } catch (e: Exception) { + Log.w(TAG, "debug recording init failed: ${e.message}") + } + } try { while (running) { val read = recorder.read(pcm, 0, FRAME_SAMPLES) if (read > 0) { applyGain(pcm, read, captureGainDb) engine.writeAudio(pcm) + + // Debug: write raw PCM + RMS + if (pcmOut != null) { + byteConv.clear() + for (i in 0 until read) byteConv.putShort(pcm[i]) + pcmOut.write(byteConv.array(), 0, read * 2) + } + if (rmsCsv != null) { + val rms = computeRms(pcm, read) + val timeMs = frameIdx * FRAME_SAMPLES * 1000L / SAMPLE_RATE + rmsCsv.write("$frameIdx,$timeMs,$rms\n") + } + frameIdx++ } else if (read < 0) { Log.e(TAG, "AudioRecord.read error: $read") break } } } finally { + pcmOut?.close() + rmsCsv?.close() recorder.stop() + aec?.release() + ns?.release() recorder.release() - Log.i(TAG, "capture stopped") + Log.i(TAG, "capture stopped (frames=$frameIdx)") } } @@ -181,24 +268,57 @@ class AudioPipeline(private val context: Context) { Log.i(TAG, "playout started: ${SAMPLE_RATE}Hz mono, buf=$bufSize") val pcm = ShortArray(FRAME_SAMPLES) - val silence = ShortArray(FRAME_SAMPLES) // pre-allocated silence + val silence = ShortArray(FRAME_SAMPLES) + // Debug: PCM file + RMS CSV for playout + var pcmOut: BufferedOutputStream? = null + var rmsCsv: OutputStreamWriter? = null + val byteConv = ByteBuffer.allocate(FRAME_SAMPLES * 2).order(ByteOrder.LITTLE_ENDIAN) + var frameIdx = 0L + if (debugRecording) { + try { + pcmOut = BufferedOutputStream(FileOutputStream(File(debugDir, "playout.pcm")), 65536) + rmsCsv = OutputStreamWriter(FileOutputStream(File(debugDir, "playout_rms.csv"))) + rmsCsv.write("frame,time_ms,rms\n") + } catch (e: Exception) { + Log.w(TAG, "debug playout recording init failed: ${e.message}") + } + } try { while (running) { val read = engine.readAudio(pcm) if (read >= FRAME_SAMPLES) { applyGain(pcm, read, playoutGainDb) track.write(pcm, 0, read) + + // Debug: write raw PCM + RMS + if (pcmOut != null) { + byteConv.clear() + for (i in 0 until read) byteConv.putShort(pcm[i]) + pcmOut.write(byteConv.array(), 0, read * 2) + } + if (rmsCsv != null) { + val rms = computeRms(pcm, read) + val timeMs = frameIdx * FRAME_SAMPLES * 1000L / SAMPLE_RATE + rmsCsv.write("$frameIdx,$timeMs,$rms\n") + } + frameIdx++ } else { - // Not enough decoded audio — write silence to keep stream alive track.write(silence, 0, FRAME_SAMPLES) - // Sleep briefly to avoid busy-spinning + // Log silence frames to RMS as 0 + if (rmsCsv != null) { + val timeMs = frameIdx * FRAME_SAMPLES * 1000L / SAMPLE_RATE + rmsCsv.write("$frameIdx,$timeMs,0\n") + } + frameIdx++ Thread.sleep(5) } } } finally { + pcmOut?.close() + rmsCsv?.close() track.stop() track.release() - Log.i(TAG, "playout stopped") + Log.i(TAG, "playout stopped (frames=$frameIdx)") } } } diff --git a/android/app/src/main/java/com/wzp/data/SettingsRepository.kt b/android/app/src/main/java/com/wzp/data/SettingsRepository.kt index 2d2162c..28c41e9 100644 --- a/android/app/src/main/java/com/wzp/data/SettingsRepository.kt +++ b/android/app/src/main/java/com/wzp/data/SettingsRepository.kt @@ -27,6 +27,7 @@ class SettingsRepository(context: Context) { private const val KEY_CAPTURE_GAIN = "capture_gain_db" private const val KEY_PREFER_IPV6 = "prefer_ipv6" private const val KEY_IDENTITY_SEED = "identity_seed_hex" + private const val KEY_AEC_ENABLED = "aec_enabled" } // --- Servers --- @@ -112,6 +113,11 @@ class SettingsRepository(context: Context) { fun savePreferIPv6(prefer: Boolean) { prefs.edit().putBoolean(KEY_PREFER_IPV6, prefer).apply() } fun loadPreferIPv6(): Boolean = prefs.getBoolean(KEY_PREFER_IPV6, false) + // --- AEC --- + + fun saveAecEnabled(enabled: Boolean) { prefs.edit().putBoolean(KEY_AEC_ENABLED, enabled).apply() } + fun loadAecEnabled(): Boolean = prefs.getBoolean(KEY_AEC_ENABLED, true) + // --- Identity seed --- /** diff --git a/android/app/src/main/java/com/wzp/debug/DebugReporter.kt b/android/app/src/main/java/com/wzp/debug/DebugReporter.kt new file mode 100644 index 0000000..02d6e25 --- /dev/null +++ b/android/app/src/main/java/com/wzp/debug/DebugReporter.kt @@ -0,0 +1,198 @@ +package com.wzp.debug + +import android.content.Context +import android.util.Log +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.withContext +import java.io.BufferedOutputStream +import java.io.ByteArrayOutputStream +import java.io.File +import java.io.FileInputStream +import java.io.FileOutputStream +import java.nio.ByteBuffer +import java.nio.ByteOrder +import java.text.SimpleDateFormat +import java.util.Date +import java.util.Locale +import java.util.zip.ZipEntry +import java.util.zip.ZipOutputStream + +/** + * Collects call debug data (audio recordings, logs, histograms, stats) + * into a zip file for email sharing. + */ +class DebugReporter(private val context: Context) { + + companion object { + private const val TAG = "DebugReporter" + private const val SAMPLE_RATE = 48000 + } + + /** + * Build a zip with all debug data. + * Returns the zip File on success, or null on failure. + */ + suspend fun collectZip( + callDurationSecs: Double, + finalStatsJson: String, + aecEnabled: Boolean, + alias: String, + server: String, + room: String + ): File? = withContext(Dispatchers.IO) { + try { + val debugDir = File(context.cacheDir, "wzp_debug") + val timestamp = SimpleDateFormat("yyyyMMdd_HHmmss", Locale.US).format(Date()) + val zipFile = File(context.cacheDir, "wzp_debug_${timestamp}.zip") + + ZipOutputStream(BufferedOutputStream(FileOutputStream(zipFile))).use { zos -> + // 1. Call metadata + val meta = buildString { + appendLine("=== WZ Phone Debug Report ===") + appendLine("Timestamp: $timestamp") + appendLine("Alias: $alias") + appendLine("Server: $server") + appendLine("Room: $room") + appendLine("Duration: ${"%.1f".format(callDurationSecs)}s") + appendLine("AEC: ${if (aecEnabled) "ON" else "OFF"}") + appendLine("Device: ${android.os.Build.MANUFACTURER} ${android.os.Build.MODEL}") + appendLine("Android: ${android.os.Build.VERSION.RELEASE} (API ${android.os.Build.VERSION.SDK_INT})") + appendLine() + appendLine("=== Final Stats ===") + appendLine(finalStatsJson) + } + addTextEntry(zos, "meta.txt", meta) + + // 2. Logcat — WZP-related tags + val logcat = collectLogcat() + addTextEntry(zos, "logcat.txt", logcat) + + // 3. Capture audio (mic) → WAV + val captureRaw = File(debugDir, "capture.pcm") + if (captureRaw.exists() && captureRaw.length() > 0) { + addWavEntry(zos, "capture.wav", captureRaw) + Log.i(TAG, "capture.pcm: ${captureRaw.length()} bytes -> WAV") + } + + // 4. Playout audio (speaker) → WAV + val playoutRaw = File(debugDir, "playout.pcm") + if (playoutRaw.exists() && playoutRaw.length() > 0) { + addWavEntry(zos, "playout.wav", playoutRaw) + Log.i(TAG, "playout.pcm: ${playoutRaw.length()} bytes -> WAV") + } + + // 5. RMS histogram CSV + val captureHist = File(debugDir, "capture_rms.csv") + if (captureHist.exists()) addFileEntry(zos, "capture_rms.csv", captureHist) + val playoutHist = File(debugDir, "playout_rms.csv") + if (playoutHist.exists()) addFileEntry(zos, "playout_rms.csv", playoutHist) + } + + Log.i(TAG, "zip created: ${zipFile.length()} bytes (${zipFile.length() / 1024}KB)") + + // Clean up raw debug files (keep zip) + debugDir.listFiles()?.forEach { it.delete() } + + zipFile + } catch (e: Exception) { + Log.e(TAG, "debug report failed", e) + null + } + } + + /** Clean up any leftover debug files from a previous session. */ + fun prepareForCall() { + val debugDir = File(context.cacheDir, "wzp_debug") + if (debugDir.exists()) { + debugDir.listFiles()?.forEach { it.delete() } + } + debugDir.mkdirs() + // Also clean up old zip files + context.cacheDir.listFiles()?.filter { it.name.startsWith("wzp_debug_") }?.forEach { it.delete() } + } + + private fun collectLogcat(): String { + return try { + val process = Runtime.getRuntime().exec( + arrayOf( + "logcat", "-d", + "-t", "5000", + "--format", "threadtime" + ) + ) + val output = process.inputStream.bufferedReader().readText() + process.waitFor() + output.lines() + .filter { line -> + line.contains("wzp", ignoreCase = true) || + line.contains("WzpEngine") || + line.contains("AudioPipeline") || + line.contains("WzpCall") || + line.contains("CallService") || + line.contains("AudioTrack") || + line.contains("AudioRecord") || + line.contains("AcousticEchoCanceler") || + line.contains("NoiseSuppressor") || + line.contains("FATAL") || + line.contains("ANR") || + line.contains("AudioFlinger") || + line.contains("DebugReporter") || + line.contains("QUIC") || + line.contains("quinn") || + line.contains("send task") || + line.contains("recv task") || + line.contains("send stats") || + line.contains("recv stats") || + line.contains("send_media") || + line.contains("FEC block") || + line.contains("recv gap") || + line.contains("frames_dropped") || + line.contains("opus") + } + .joinToString("\n") + } catch (e: Exception) { + "Failed to collect logcat: ${e.message}" + } + } + + private fun addWavEntry(zos: ZipOutputStream, name: String, pcmFile: File) { + val dataSize = pcmFile.length().toInt() + val byteRate = SAMPLE_RATE * 1 * 16 / 8 + val blockAlign = 1 * 16 / 8 + + zos.putNextEntry(ZipEntry(name)) + + // Write WAV header (44 bytes) + val header = ByteBuffer.allocate(44).order(ByteOrder.LITTLE_ENDIAN) + header.put("RIFF".toByteArray()) + header.putInt(36 + dataSize) + header.put("WAVE".toByteArray()) + header.put("fmt ".toByteArray()) + header.putInt(16) + header.putShort(1) // PCM + header.putShort(1) // mono + header.putInt(SAMPLE_RATE) + header.putInt(byteRate) + header.putShort(blockAlign.toShort()) + header.putShort(16) // bits per sample + header.put("data".toByteArray()) + header.putInt(dataSize) + zos.write(header.array()) + + // Stream PCM data directly (avoids loading entire file into memory) + FileInputStream(pcmFile).use { it.copyTo(zos) } + zos.closeEntry() + } + + private fun addTextEntry(zos: ZipOutputStream, name: String, content: String) { + zos.putNextEntry(ZipEntry(name)) + zos.write(content.toByteArray()) + zos.closeEntry() + } + + private fun addFileEntry(zos: ZipOutputStream, name: String, file: File) { + zos.putNextEntry(ZipEntry(name)) + FileInputStream(file).use { it.copyTo(zos) } + zos.closeEntry() + } +} diff --git a/android/app/src/main/java/com/wzp/engine/CallStats.kt b/android/app/src/main/java/com/wzp/engine/CallStats.kt index d4e4f41..17ac4cb 100644 --- a/android/app/src/main/java/com/wzp/engine/CallStats.kt +++ b/android/app/src/main/java/com/wzp/engine/CallStats.kt @@ -54,7 +54,7 @@ data class CallStats( val o = arr.getJSONObject(i) RoomMember( fingerprint = o.optString("fingerprint", ""), - alias = o.optString("alias", null) + alias = if (o.isNull("alias")) null else o.optString("alias", null) ) } } @@ -92,5 +92,6 @@ data class RoomMember( ) { /** Short display name: alias if set, otherwise first 8 chars of fingerprint. */ val displayName: String - get() = alias ?: fingerprint.take(8) + get() = alias?.takeIf { it.isNotBlank() } + ?: fingerprint.take(8).ifEmpty { "unknown" } } diff --git a/android/app/src/main/java/com/wzp/ui/call/CallActivity.kt b/android/app/src/main/java/com/wzp/ui/call/CallActivity.kt index a2e46a9..f651ae2 100644 --- a/android/app/src/main/java/com/wzp/ui/call/CallActivity.kt +++ b/android/app/src/main/java/com/wzp/ui/call/CallActivity.kt @@ -1,8 +1,10 @@ package com.wzp.ui.call import android.Manifest +import android.content.Intent import android.content.pm.PackageManager import android.os.Bundle +import android.util.Log import android.widget.Toast import androidx.activity.ComponentActivity import androidx.activity.compose.setContent @@ -21,7 +23,12 @@ import androidx.compose.runtime.remember import androidx.compose.runtime.setValue import androidx.compose.ui.platform.LocalContext import androidx.core.content.ContextCompat +import androidx.core.content.FileProvider +import androidx.lifecycle.Lifecycle +import androidx.lifecycle.lifecycleScope +import androidx.lifecycle.repeatOnLifecycle import com.wzp.ui.settings.SettingsScreen +import kotlinx.coroutines.launch /** * Main activity hosting the in-call Compose UI. @@ -31,6 +38,10 @@ import com.wzp.ui.settings.SettingsScreen */ class CallActivity : ComponentActivity() { + companion object { + private const val TAG = "CallActivity" + } + private val viewModel: CallViewModel by viewModels() private val audioPermissionLauncher = registerForActivityResult( @@ -69,6 +80,45 @@ class CallActivity : ComponentActivity() { ) { audioPermissionLauncher.launch(Manifest.permission.RECORD_AUDIO) } + + // Watch for debug zip ready → launch email intent + lifecycleScope.launch { + repeatOnLifecycle(Lifecycle.State.STARTED) { + viewModel.debugZipReady.collect { zipFile -> + if (zipFile != null && zipFile.exists()) { + Log.i(TAG, "debug zip ready: ${zipFile.absolutePath} (${zipFile.length()} bytes)") + launchEmailIntent(zipFile) + viewModel.onDebugReportSent() + } + } + } + } + } + + private fun launchEmailIntent(zipFile: java.io.File) { + try { + val authority = "${applicationContext.packageName}.fileprovider" + Log.i(TAG, "FileProvider authority: $authority, file: ${zipFile.absolutePath}") + val uri = FileProvider.getUriForFile(this, authority, zipFile) + Log.i(TAG, "FileProvider URI: $uri") + + val intent = Intent(Intent.ACTION_SEND).apply { + type = "message/rfc822" + putExtra(Intent.EXTRA_EMAIL, arrayOf("manwefarm@gmail.com")) + putExtra(Intent.EXTRA_SUBJECT, "WZ Phone Debug Report - ${zipFile.name}") + putExtra( + Intent.EXTRA_TEXT, + "Debug report attached.\n\nContains: call recordings (WAV), RMS histograms (CSV), logcat, stats." + ) + putExtra(Intent.EXTRA_STREAM, uri) + addFlags(Intent.FLAG_GRANT_READ_URI_PERMISSION) + } + startActivity(Intent.createChooser(intent, "Send debug report")) + Log.i(TAG, "email intent launched") + } catch (e: Exception) { + Log.e(TAG, "email intent failed", e) + Toast.makeText(this, "Failed to launch email: ${e.message}", Toast.LENGTH_LONG).show() + } } override fun onDestroy() { diff --git a/android/app/src/main/java/com/wzp/ui/call/CallViewModel.kt b/android/app/src/main/java/com/wzp/ui/call/CallViewModel.kt index e2b28f2..30bd7e4 100644 --- a/android/app/src/main/java/com/wzp/ui/call/CallViewModel.kt +++ b/android/app/src/main/java/com/wzp/ui/call/CallViewModel.kt @@ -7,6 +7,7 @@ import androidx.lifecycle.viewModelScope import com.wzp.audio.AudioPipeline import com.wzp.audio.AudioRouteManager import com.wzp.data.SettingsRepository +import com.wzp.debug.DebugReporter import com.wzp.engine.CallStats import com.wzp.service.CallService import com.wzp.engine.WzpCallback @@ -18,6 +19,7 @@ import kotlinx.coroutines.flow.StateFlow import kotlinx.coroutines.flow.asStateFlow import kotlinx.coroutines.isActive import kotlinx.coroutines.launch +import java.io.File import java.net.Inet4Address import java.net.Inet6Address import java.net.InetAddress @@ -33,6 +35,10 @@ class CallViewModel : ViewModel(), WzpCallback { private var audioStarted = false private var appContext: Context? = null private var settings: SettingsRepository? = null + private var debugReporter: DebugReporter? = null + private var lastStatsJson: String = "{}" + private var lastCallDuration: Double = 0.0 + private var lastCallServer: String = "" private val _callState = MutableStateFlow(0) val callState: StateFlow get() = _callState.asStateFlow() @@ -76,6 +82,21 @@ class CallViewModel : ViewModel(), WzpCallback { private val _seedHex = MutableStateFlow("") val seedHex: StateFlow = _seedHex.asStateFlow() + private val _aecEnabled = MutableStateFlow(true) + val aecEnabled: StateFlow = _aecEnabled.asStateFlow() + + /** True when a call just ended and debug report can be sent. */ + private val _debugReportAvailable = MutableStateFlow(false) + val debugReportAvailable: StateFlow = _debugReportAvailable.asStateFlow() + + /** Status: null=idle, "Preparing..."=in progress, "ready"=zip ready, "Error:..."=failed */ + private val _debugReportStatus = MutableStateFlow(null) + val debugReportStatus: StateFlow = _debugReportStatus.asStateFlow() + + /** The zip file ready to be emailed. Set by sendDebugReport, consumed by Activity. */ + private val _debugZipReady = MutableStateFlow(null) + val debugZipReady: StateFlow = _debugZipReady.asStateFlow() + private var statsJob: Job? = null companion object { @@ -96,6 +117,9 @@ class CallViewModel : ViewModel(), WzpCallback { if (audioRouteManager == null) { audioRouteManager = AudioRouteManager(appCtx) } + if (debugReporter == null) { + debugReporter = DebugReporter(appCtx) + } if (settings == null) { settings = SettingsRepository(appCtx) loadSettings() @@ -114,6 +138,7 @@ class CallViewModel : ViewModel(), WzpCallback { _playoutGainDb.value = s.loadPlayoutGain() _captureGainDb.value = s.loadCaptureGain() _seedHex.value = s.getOrCreateSeedHex() + _aecEnabled.value = s.loadAecEnabled() } fun selectServer(index: Int) { @@ -149,6 +174,14 @@ class CallViewModel : ViewModel(), WzpCallback { } } + /** Batch-apply servers and selection from Settings draft state. */ + fun applyServers(servers: List, selected: Int) { + _servers.value = servers + _selectedServer.value = selected.coerceIn(0, servers.lastIndex) + settings?.saveServers(servers) + settings?.saveSelectedServer(_selectedServer.value) + } + fun setRoomName(name: String) { _roomName.value = name settings?.saveRoom(name) @@ -176,6 +209,11 @@ class CallViewModel : ViewModel(), WzpCallback { settings?.saveSeedHex(hex) } + fun setAecEnabled(enabled: Boolean) { + _aecEnabled.value = enabled + settings?.saveAecEnabled(enabled) + } + /** * Resolve DNS hostname to IP address on the Kotlin/Android side, * since Rust's DNS resolution may not work on Android. @@ -214,6 +252,7 @@ class CallViewModel : ViewModel(), WzpCallback { /** Tear down engine and audio. Pass stopService=true to also stop the foreground service. */ private fun teardown(stopService: Boolean = true) { Log.i(TAG, "teardown: stopping audio, stopService=$stopService") + val hadCall = audioStarted CallService.onStopFromNotification = null stopAudio() stopStatsPolling() @@ -223,6 +262,9 @@ class CallViewModel : ViewModel(), WzpCallback { engine = null engineInitialized = false _callState.value = 0 + if (hadCall) { + _debugReportAvailable.value = true + } if (stopService) { try { appContext?.let { CallService.stop(it) } } catch (_: Exception) {} } @@ -233,6 +275,10 @@ class CallViewModel : ViewModel(), WzpCallback { val serverEntry = _servers.value[_selectedServer.value] val room = _roomName.value Log.i(TAG, "startCall: server=${serverEntry.address} room=$room") + _debugReportAvailable.value = false + _debugReportStatus.value = null + lastCallServer = serverEntry.address + debugReporter?.prepareForCall() try { // Teardown previous call but don't stop the service (we're about to restart it) teardown(stopService = false) @@ -297,6 +343,40 @@ class CallViewModel : ViewModel(), WzpCallback { fun clearError() { _errorMessage.value = null } + fun sendDebugReport() { + val reporter = debugReporter ?: return + _debugReportStatus.value = "Preparing debug report..." + viewModelScope.launch(kotlinx.coroutines.Dispatchers.IO) { + val zipFile = reporter.collectZip( + callDurationSecs = lastCallDuration, + finalStatsJson = lastStatsJson, + aecEnabled = _aecEnabled.value, + alias = _alias.value, + server = lastCallServer, + room = _roomName.value + ) + if (zipFile != null) { + _debugZipReady.value = zipFile + _debugReportStatus.value = "ready" + } else { + _debugReportStatus.value = "Error: failed to create zip" + } + _debugReportAvailable.value = false + } + } + + /** Called by Activity after email intent is launched. */ + fun onDebugReportSent() { + _debugZipReady.value = null + _debugReportStatus.value = null + } + + fun dismissDebugReport() { + _debugReportAvailable.value = false + _debugReportStatus.value = null + _debugZipReady.value = null + } + // WzpCallback override fun onCallStateChanged(state: Int) { _callState.value = state } override fun onQualityTierChanged(tier: Int) { _qualityTier.value = tier } @@ -310,6 +390,7 @@ class CallViewModel : ViewModel(), WzpCallback { audioPipeline = AudioPipeline(ctx).also { it.playoutGainDb = _playoutGainDb.value it.captureGainDb = _captureGainDb.value + it.aecEnabled = _aecEnabled.value it.start(e) } audioRouteManager?.register() @@ -334,7 +415,9 @@ class CallViewModel : ViewModel(), WzpCallback { val json = engine?.getStats() ?: "{}" if (json.isNotEmpty()) { Log.d(TAG, "raw: $json") + lastStatsJson = json val s = CallStats.fromJson(json) + lastCallDuration = s.durationSecs _stats.value = s if (s.state != 0) { _callState.value = s.state diff --git a/android/app/src/main/java/com/wzp/ui/call/InCallScreen.kt b/android/app/src/main/java/com/wzp/ui/call/InCallScreen.kt index 66311e3..0bf6260 100644 --- a/android/app/src/main/java/com/wzp/ui/call/InCallScreen.kt +++ b/android/app/src/main/java/com/wzp/ui/call/InCallScreen.kt @@ -24,7 +24,6 @@ import androidx.compose.material3.ButtonDefaults import androidx.compose.material3.FilledIconButton import androidx.compose.material3.FilledTonalIconButton import androidx.compose.material3.IconButtonDefaults -import androidx.compose.material3.LinearProgressIndicator import androidx.compose.material3.MaterialTheme import androidx.compose.material3.OutlinedButton import androidx.compose.material3.OutlinedTextField @@ -69,6 +68,8 @@ fun InCallScreen( val preferIPv6 by viewModel.preferIPv6.collectAsState() val playoutGainDb by viewModel.playoutGainDb.collectAsState() val captureGainDb by viewModel.captureGainDb.collectAsState() + val debugReportAvailable by viewModel.debugReportAvailable.collectAsState() + val debugReportStatus by viewModel.debugReportStatus.collectAsState() var showAddServerDialog by remember { mutableStateOf(false) } @@ -228,6 +229,17 @@ fun InCallScreen( color = MaterialTheme.colorScheme.error ) } + + // Debug report card — shown after call ends + if (debugReportAvailable || debugReportStatus != null) { + Spacer(modifier = Modifier.height(24.dp)) + DebugReportCard( + available = debugReportAvailable, + status = debugReportStatus, + onSend = { viewModel.sendDebugReport() }, + onDismiss = { viewModel.dismissDebugReport() } + ) + } } else { // In-call UI Spacer(modifier = Modifier.height(16.dp)) @@ -239,13 +251,17 @@ fun InCallScreen( QualityIndicator(qualityTier, stats.qualityLabel) if (stats.roomParticipantCount > 0) { + // Dedup by fingerprint — same key = same person, even if + // relay hasn't cleaned up stale entries yet. + val unique = stats.roomParticipants + .distinctBy { it.fingerprint.ifEmpty { it.displayName } } Spacer(modifier = Modifier.height(8.dp)) Text( - text = "${stats.roomParticipantCount} in room", + text = "${unique.size} in room", style = MaterialTheme.typography.bodySmall, color = MaterialTheme.colorScheme.onSurfaceVariant ) - stats.roomParticipants.forEach { member -> + unique.forEach { member -> Text( text = member.displayName, style = MaterialTheme.typography.labelSmall, @@ -438,15 +454,20 @@ private fun AudioLevelBar(audioLevel: Int) { color = MaterialTheme.colorScheme.onSurfaceVariant ) Spacer(modifier = Modifier.height(4.dp)) - LinearProgressIndicator( - progress = level, + Box( modifier = Modifier .fillMaxWidth(0.6f) .height(6.dp) - .clip(RoundedCornerShape(3.dp)), - color = MaterialTheme.colorScheme.primary, - trackColor = MaterialTheme.colorScheme.surfaceVariant, - ) + .clip(RoundedCornerShape(3.dp)) + .background(MaterialTheme.colorScheme.surfaceVariant) + ) { + Box( + modifier = Modifier + .fillMaxWidth(level) + .height(6.dp) + .background(MaterialTheme.colorScheme.primary) + ) + } } } @@ -598,3 +619,70 @@ private fun StatItem(label: String, value: String) { ) } } + +@Composable +private fun DebugReportCard( + available: Boolean, + status: String?, + onSend: () -> Unit, + onDismiss: () -> Unit +) { + Surface( + modifier = Modifier.fillMaxWidth(), + color = MaterialTheme.colorScheme.surfaceVariant.copy(alpha = 0.7f), + shape = RoundedCornerShape(12.dp) + ) { + Column( + modifier = Modifier.padding(16.dp), + horizontalAlignment = Alignment.CenterHorizontally + ) { + Text( + text = "Debug Report", + style = MaterialTheme.typography.titleSmall.copy(fontWeight = FontWeight.Bold), + color = MaterialTheme.colorScheme.onSurface + ) + Spacer(modifier = Modifier.height(4.dp)) + Text( + text = "Email call recordings, logs & stats for analysis", + style = MaterialTheme.typography.bodySmall, + color = MaterialTheme.colorScheme.onSurfaceVariant, + textAlign = TextAlign.Center + ) + + Spacer(modifier = Modifier.height(12.dp)) + + when { + status != null && status.startsWith("Error") -> { + Text( + text = status, + style = MaterialTheme.typography.bodySmall, + color = MaterialTheme.colorScheme.error + ) + Spacer(modifier = Modifier.height(8.dp)) + Row(horizontalArrangement = Arrangement.spacedBy(8.dp)) { + OutlinedButton(onClick = onSend) { Text("Retry") } + TextButton(onClick = onDismiss) { Text("Dismiss") } + } + } + status != null && status != "ready" -> { + // Preparing zip... + Text( + text = status, + style = MaterialTheme.typography.bodySmall, + color = MaterialTheme.colorScheme.onSurfaceVariant + ) + } + available -> { + Row(horizontalArrangement = Arrangement.spacedBy(8.dp)) { + Button(onClick = onSend) { + Text("Email Report") + } + TextButton(onClick = onDismiss) { + Text("Skip") + } + } + } + } + } + } +} diff --git a/android/app/src/main/java/com/wzp/ui/settings/SettingsScreen.kt b/android/app/src/main/java/com/wzp/ui/settings/SettingsScreen.kt index 769c2ec..6a083c2 100644 --- a/android/app/src/main/java/com/wzp/ui/settings/SettingsScreen.kt +++ b/android/app/src/main/java/com/wzp/ui/settings/SettingsScreen.kt @@ -21,9 +21,9 @@ import androidx.compose.foundation.verticalScroll import androidx.compose.material3.AlertDialog import androidx.compose.material3.Button import androidx.compose.material3.ButtonDefaults +import androidx.compose.material3.Divider import androidx.compose.material3.FilledTonalButton import androidx.compose.material3.FilledTonalIconButton -import androidx.compose.material3.Divider import androidx.compose.material3.IconButtonDefaults import androidx.compose.material3.MaterialTheme import androidx.compose.material3.OutlinedButton @@ -36,9 +36,12 @@ import androidx.compose.material3.TextButton import androidx.compose.runtime.Composable import androidx.compose.runtime.collectAsState import androidx.compose.runtime.getValue +import androidx.compose.runtime.mutableFloatStateOf +import androidx.compose.runtime.mutableIntStateOf import androidx.compose.runtime.mutableStateOf import androidx.compose.runtime.remember import androidx.compose.runtime.setValue +import androidx.compose.runtime.toMutableStateList import androidx.compose.ui.Alignment import androidx.compose.ui.Modifier import androidx.compose.ui.graphics.Color @@ -47,6 +50,7 @@ import androidx.compose.ui.text.font.FontFamily import androidx.compose.ui.text.font.FontWeight import androidx.compose.ui.unit.dp import com.wzp.ui.call.CallViewModel +import com.wzp.ui.call.ServerEntry @OptIn(ExperimentalLayoutApi::class) @Composable @@ -55,14 +59,39 @@ fun SettingsScreen( onBack: () -> Unit ) { val context = LocalContext.current - val servers by viewModel.servers.collectAsState() - val selectedServer by viewModel.selectedServer.collectAsState() - val roomName by viewModel.roomName.collectAsState() - val preferIPv6 by viewModel.preferIPv6.collectAsState() - val playoutGainDb by viewModel.playoutGainDb.collectAsState() - val captureGainDb by viewModel.captureGainDb.collectAsState() - val alias by viewModel.alias.collectAsState() - val seedHex by viewModel.seedHex.collectAsState() + + // Snapshot current values into local draft state + val currentAlias by viewModel.alias.collectAsState() + val currentSeedHex by viewModel.seedHex.collectAsState() + val currentServers by viewModel.servers.collectAsState() + val currentSelectedServer by viewModel.selectedServer.collectAsState() + val currentRoomName by viewModel.roomName.collectAsState() + val currentPreferIPv6 by viewModel.preferIPv6.collectAsState() + val currentPlayoutGain by viewModel.playoutGainDb.collectAsState() + val currentCaptureGain by viewModel.captureGainDb.collectAsState() + val currentAecEnabled by viewModel.aecEnabled.collectAsState() + + // Draft state — initialized from current values + var draftAlias by remember { mutableStateOf(currentAlias) } + var draftSeedHex by remember { mutableStateOf(currentSeedHex) } + val draftServers = remember { currentServers.toMutableStateList() } + var draftSelectedServer by remember { mutableIntStateOf(currentSelectedServer) } + var draftRoomName by remember { mutableStateOf(currentRoomName) } + var draftPreferIPv6 by remember { mutableStateOf(currentPreferIPv6) } + var draftPlayoutGain by remember { mutableFloatStateOf(currentPlayoutGain) } + var draftCaptureGain by remember { mutableFloatStateOf(currentCaptureGain) } + var draftAecEnabled by remember { mutableStateOf(currentAecEnabled) } + + // Track if anything changed + val hasChanges = draftAlias != currentAlias || + draftSeedHex != currentSeedHex || + draftServers.toList() != currentServers || + draftSelectedServer != currentSelectedServer || + draftRoomName != currentRoomName || + draftPreferIPv6 != currentPreferIPv6 || + draftPlayoutGain != currentPlayoutGain || + draftCaptureGain != currentCaptureGain || + draftAecEnabled != currentAecEnabled var showAddServerDialog by remember { mutableStateOf(false) } var showRestoreKeyDialog by remember { mutableStateOf(false) } @@ -94,8 +123,24 @@ fun SettingsScreen( color = MaterialTheme.colorScheme.primary ) Spacer(modifier = Modifier.weight(1f)) - // Balance the back button - Spacer(modifier = Modifier.width(64.dp)) + // Save button — only enabled when changes exist + Button( + onClick = { + viewModel.setAlias(draftAlias) + if (draftSeedHex != currentSeedHex) viewModel.restoreSeed(draftSeedHex) + viewModel.applyServers(draftServers.toList(), draftSelectedServer) + viewModel.setRoomName(draftRoomName) + viewModel.setPreferIPv6(draftPreferIPv6) + viewModel.setPlayoutGainDb(draftPlayoutGain) + viewModel.setCaptureGainDb(draftCaptureGain) + viewModel.setAecEnabled(draftAecEnabled) + Toast.makeText(context, "Settings saved", Toast.LENGTH_SHORT).show() + onBack() + }, + enabled = hasChanges + ) { + Text("Save") + } } Spacer(modifier = Modifier.height(24.dp)) @@ -104,8 +149,8 @@ fun SettingsScreen( SectionHeader("Identity") OutlinedTextField( - value = alias, - onValueChange = { viewModel.setAlias(it) }, + value = draftAlias, + onValueChange = { draftAlias = it }, label = { Text("Display Name") }, singleLine = true, modifier = Modifier.fillMaxWidth() @@ -114,7 +159,7 @@ fun SettingsScreen( Spacer(modifier = Modifier.height(16.dp)) // Fingerprint display - val fingerprint = if (seedHex.length >= 16) seedHex.take(16).uppercase() else "Not generated" + val fingerprint = if (draftSeedHex.length >= 16) draftSeedHex.take(16).uppercase() else "Not generated" Text( text = "Fingerprint", style = MaterialTheme.typography.labelSmall, @@ -134,7 +179,7 @@ fun SettingsScreen( Row(horizontalArrangement = Arrangement.spacedBy(8.dp)) { FilledTonalButton(onClick = { val clipboard = context.getSystemService(Context.CLIPBOARD_SERVICE) as ClipboardManager - clipboard.setPrimaryClip(ClipData.newPlainText("WZP Key", seedHex)) + clipboard.setPrimaryClip(ClipData.newPlainText("WZP Key", draftSeedHex)) Toast.makeText(context, "Key copied to clipboard", Toast.LENGTH_SHORT).show() }) { Text("Copy Key") @@ -153,16 +198,39 @@ fun SettingsScreen( GainSlider( label = "Voice Volume", - gainDb = playoutGainDb, - onGainChange = { viewModel.setPlayoutGainDb(it) } + gainDb = draftPlayoutGain, + onGainChange = { draftPlayoutGain = Math.round(it).toFloat() } ) Spacer(modifier = Modifier.height(4.dp)) GainSlider( label = "Mic Gain", - gainDb = captureGainDb, - onGainChange = { viewModel.setCaptureGainDb(it) } + gainDb = draftCaptureGain, + onGainChange = { draftCaptureGain = Math.round(it).toFloat() } ) + Spacer(modifier = Modifier.height(12.dp)) + + Row( + verticalAlignment = Alignment.CenterVertically, + modifier = Modifier.fillMaxWidth() + ) { + Column(modifier = Modifier.weight(1f)) { + Text( + text = "Echo Cancellation (AEC)", + style = MaterialTheme.typography.bodyMedium + ) + Text( + text = "Disable if audio sounds distorted", + style = MaterialTheme.typography.bodySmall, + color = MaterialTheme.colorScheme.onSurfaceVariant + ) + } + Switch( + checked = draftAecEnabled, + onCheckedChange = { draftAecEnabled = it } + ) + } + Spacer(modifier = Modifier.height(24.dp)) Divider() Spacer(modifier = Modifier.height(16.dp)) @@ -175,11 +243,11 @@ fun SettingsScreen( horizontalArrangement = Arrangement.Start, verticalArrangement = Arrangement.spacedBy(4.dp) ) { - servers.forEachIndexed { idx, entry -> - val isSelected = selectedServer == idx + draftServers.forEachIndexed { idx, entry -> + val isSelected = draftSelectedServer == idx Row(verticalAlignment = Alignment.CenterVertically) { FilledTonalIconButton( - onClick = { viewModel.selectServer(idx) }, + onClick = { draftSelectedServer = idx }, modifier = Modifier .padding(end = 2.dp) .height(36.dp) @@ -203,7 +271,12 @@ fun SettingsScreen( // Show remove button for non-default servers if (idx >= 2) { TextButton( - onClick = { viewModel.removeServer(idx) }, + onClick = { + draftServers.removeAt(idx) + if (draftSelectedServer >= draftServers.size) { + draftSelectedServer = 0 + } + }, modifier = Modifier.height(36.dp) ) { Text("X", color = MaterialTheme.colorScheme.error) @@ -224,7 +297,7 @@ fun SettingsScreen( // Show selected server address Spacer(modifier = Modifier.height(8.dp)) Text( - text = "Default: ${servers.getOrNull(selectedServer)?.address ?: "none"}", + text = "Default: ${draftServers.getOrNull(draftSelectedServer)?.address ?: "none"}", style = MaterialTheme.typography.bodySmall, color = MaterialTheme.colorScheme.onSurfaceVariant ) @@ -246,8 +319,8 @@ fun SettingsScreen( modifier = Modifier.weight(1f) ) Switch( - checked = preferIPv6, - onCheckedChange = { viewModel.setPreferIPv6(it) } + checked = draftPreferIPv6, + onCheckedChange = { draftPreferIPv6 = it } ) } @@ -259,8 +332,8 @@ fun SettingsScreen( SectionHeader("Room") OutlinedTextField( - value = roomName, - onValueChange = { viewModel.setRoomName(it) }, + value = draftRoomName, + onValueChange = { draftRoomName = it }, label = { Text("Default Room") }, singleLine = true, modifier = Modifier.fillMaxWidth() @@ -274,7 +347,7 @@ fun SettingsScreen( AddServerDialog( onDismiss = { showAddServerDialog = false }, onAdd = { host, port, label -> - viewModel.addServer("$host:$port", label) + draftServers.add(ServerEntry("$host:$port", label)) showAddServerDialog = false } ) @@ -284,9 +357,9 @@ fun SettingsScreen( RestoreKeyDialog( onDismiss = { showRestoreKeyDialog = false }, onRestore = { hex -> - viewModel.restoreSeed(hex) + draftSeedHex = hex showRestoreKeyDialog = false - Toast.makeText(context, "Key restored", Toast.LENGTH_SHORT).show() + Toast.makeText(context, "Key staged — press Save to apply", Toast.LENGTH_SHORT).show() } ) } @@ -316,7 +389,7 @@ private fun GainSlider(label: String, gainDb: Float, onGainChange: (Float) -> Un ) Slider( value = gainDb, - onValueChange = { onGainChange(Math.round(it).toFloat()) }, + onValueChange = onGainChange, valueRange = -20f..20f, steps = 0, modifier = Modifier.fillMaxWidth() diff --git a/android/app/src/main/res/xml/file_paths.xml b/android/app/src/main/res/xml/file_paths.xml new file mode 100644 index 0000000..45fce9e --- /dev/null +++ b/android/app/src/main/res/xml/file_paths.xml @@ -0,0 +1,4 @@ + + + + diff --git a/crates/wzp-android/Cargo.toml b/crates/wzp-android/Cargo.toml index 3fcd32b..c13e3f2 100644 --- a/crates/wzp-android/Cargo.toml +++ b/crates/wzp-android/Cargo.toml @@ -28,6 +28,7 @@ libc = "0.2" jni = { version = "0.21", default-features = false } rand = { workspace = true } rustls = { version = "0.23", default-features = false, features = ["ring"] } +tracing-android = "0.2" [build-dependencies] cc = "1" diff --git a/crates/wzp-android/src/engine.rs b/crates/wzp-android/src/engine.rs index 08ec63e..ea20fb6 100644 --- a/crates/wzp-android/src/engine.rs +++ b/crates/wzp-android/src/engine.rs @@ -67,6 +67,9 @@ pub(crate) struct EngineState { pub playout_ring: AudioRing, /// Current audio level (RMS) for UI display, updated by capture path. pub audio_level_rms: AtomicU32, + /// QUIC transport handle — stored so stop_call() can close it immediately, + /// triggering relay-side leave + RoomUpdate broadcast. + pub quic_transport: Mutex>>, } pub struct WzpEngine { @@ -87,6 +90,7 @@ impl WzpEngine { capture_ring: AudioRing::new(), playout_ring: AudioRing::new(), audio_level_rms: AtomicU32::new(0), + quic_transport: Mutex::new(None), }); Self { state, @@ -144,12 +148,25 @@ impl WzpEngine { } pub fn stop_call(&mut self) { + info!("stop_call: setting running=false"); self.state.running.store(false, Ordering::Release); + // Close QUIC connection — this wakes up all blocked recv/send futures + // inside block_on(run_call(...)) on the JNI thread. run_call will then + // wait up to 500ms for the peer to acknowledge the close before returning. + if let Some(transport) = self.state.quic_transport.lock().unwrap().take() { + info!("stop_call: closing QUIC connection"); + transport.close_now(); + } let _ = self.state.command_tx.send(EngineCommand::Stop); + // Note: the runtime is still blocked in block_on(run_call(...)) on the + // start_call thread. Once run_call exits (triggered by running=false + + // connection close above), block_on returns and stores the runtime in + // self.tokio_runtime. We don't need to shut it down here. if let Some(rt) = self.tokio_runtime.take() { - rt.shutdown_background(); + rt.shutdown_timeout(std::time::Duration::from_millis(100)); } self.call_start = None; + info!("stop_call: done"); } pub fn set_mute(&self, muted: bool) { @@ -223,6 +240,9 @@ async fn run_call( let transport = Arc::new(wzp_transport::QuinnTransport::new(conn)); + // Store transport handle so stop_call() can close the connection immediately + *state.quic_transport.lock().unwrap() = Some(transport.clone()); + // Crypto handshake let mut kx = WarzoneKeyExchange::from_identity_seed(identity_seed); let ephemeral_pub = kx.generate_ephemeral(); @@ -301,8 +321,18 @@ async fn run_call( let mut block_id: u8 = 0; // Send task: capture ring → Opus encode → FEC → MediaPackets + // + // IMPORTANT: send_media() uses quinn's send_datagram() which is + // synchronous and returns Err(Blocked) when the congestion window + // is full. We MUST NOT break on send errors — that would kill the + // entire call. Instead we drop the packet and keep going. let send_task = async { info!("send task started (Opus + RaptorQ FEC)"); + let mut send_errors: u64 = 0; + let mut last_send_error_log = Instant::now(); + let mut last_stats_log = Instant::now(); + let mut frames_sent: u64 = 0; + let mut frames_dropped: u64 = 0; loop { if !state.running.load(Ordering::Relaxed) { break; @@ -319,6 +349,12 @@ async fn run_call( continue; } + // Mute: zero out the buffer so Opus encodes silence. + // We still read from the ring to prevent it from filling up. + if state.muted.load(Ordering::Relaxed) { + capture_buf.fill(0); + } + // AGC: normalize capture volume before encoding capture_agc.process_frame(&mut capture_buf); @@ -354,11 +390,24 @@ async fn run_call( quality_report: None, }; - // Send source packet + // Send source packet — drop on error, never break if let Err(e) = transport.send_media(&source_pkt).await { - error!("send error: {e}"); - break; + send_errors += 1; + frames_dropped += 1; + // Log first few errors, then throttle to once per second + if send_errors <= 3 || last_send_error_log.elapsed().as_secs() >= 1 { + warn!( + seq = s, + send_errors, + frames_dropped, + "send_media error (dropping packet): {e}" + ); + last_send_error_log = Instant::now(); + } + // Don't feed to FEC either — the source is lost + continue; } + frames_sent += 1; // Feed encoded frame to FEC encoder if let Err(e) = fec_enc.add_source_symbol(encoded) { @@ -392,9 +441,11 @@ async fn run_call( payload: Bytes::from(repair_data), quality_report: None, }; - if let Err(e) = transport.send_media(&repair_pkt).await { - error!("send repair error: {e}"); - break; + // Drop repair packets on error — never break + if let Err(_e) = transport.send_media(&repair_pkt).await { + send_errors += 1; + frames_dropped += 1; + // Don't log every repair failure — source error log covers it } } if repair_count > 0 && (block_id % 50 == 0 || block_id == 0) { @@ -416,10 +467,21 @@ async fn run_call( frame_in_block = 0; } - if s % 500 == 0 { - info!(seq = s, block_id, frame_in_block, "sending"); + // Periodic stats every 5 seconds + if last_stats_log.elapsed().as_secs() >= 5 { + info!( + seq = s, + block_id, + frames_sent, + frames_dropped, + send_errors, + ring_avail = state.capture_ring.available(), + "send stats" + ); + last_stats_log = Instant::now(); } } + info!(frames_sent, frames_dropped, send_errors, "send task ended"); }; // Pre-allocate decode buffer @@ -429,6 +491,10 @@ async fn run_call( let recv_task = async { let mut frames_decoded: u64 = 0; let mut fec_recovered: u64 = 0; + let mut recv_errors: u64 = 0; + let mut last_recv_instant = Instant::now(); + let mut max_recv_gap_ms: u64 = 0; + let mut last_stats_log = Instant::now(); info!("recv task started (Opus + RaptorQ FEC)"); loop { if !state.running.load(Ordering::Relaxed) { @@ -436,6 +502,21 @@ async fn run_call( } match transport_recv.recv_media().await { Ok(Some(pkt)) => { + // Track recv gaps — large gaps indicate network or relay issues + let recv_gap_ms = last_recv_instant.elapsed().as_millis() as u64; + last_recv_instant = Instant::now(); + if recv_gap_ms > max_recv_gap_ms { + max_recv_gap_ms = recv_gap_ms; + } + if recv_gap_ms > 500 { + warn!( + recv_gap_ms, + seq = pkt.header.seq, + is_repair = pkt.header.is_repair, + "large recv gap — possible network stall" + ); + } + let is_repair = pkt.header.is_repair; let pkt_block = pkt.header.fec_block; let pkt_symbol = pkt.header.fec_symbol; @@ -452,7 +533,6 @@ async fn run_call( if !is_repair { match decoder.decode(&pkt.payload, &mut decode_buf) { Ok(samples) => { - // AGC on playout — normalizes received audio volume playout_agc.process_frame(&mut decode_buf[..samples]); state.playout_ring.write(&decode_buf[..samples]); frames_decoded += 1; @@ -467,13 +547,8 @@ async fn run_call( } } - // Try FEC recovery for this block - // (useful when source packets were lost but repair arrived) + // Try FEC recovery if let Ok(Some(recovered_frames)) = fec_dec.try_decode(pkt_block) { - // FEC recovered the block — any previously missing frames - // are now available. In a full jitter buffer implementation, - // we'd insert recovered frames at the right position. - // For now, log recovery for telemetry. fec_recovered += recovered_frames.len() as u64; if fec_recovered % 50 == 1 { info!( @@ -490,24 +565,45 @@ async fn run_call( fec_dec.expire_before(pkt_block.wrapping_sub(3)); } - if frames_decoded == 1 || frames_decoded % 500 == 0 { - info!(frames_decoded, fec_recovered, "recv stats"); - } - let mut stats = state.stats.lock().unwrap(); stats.frames_decoded = frames_decoded; stats.fec_recovered = fec_recovered; + drop(stats); + + // Periodic stats every 5 seconds + if last_stats_log.elapsed().as_secs() >= 5 { + info!( + frames_decoded, + fec_recovered, + recv_errors, + max_recv_gap_ms, + playout_avail = state.playout_ring.available(), + "recv stats" + ); + max_recv_gap_ms = 0; + last_stats_log = Instant::now(); + } } Ok(None) => { - info!("relay disconnected"); + info!(frames_decoded, fec_recovered, "relay disconnected (stream ended)"); break; } Err(e) => { - error!("recv error: {e}"); - break; + recv_errors += 1; + // Transient errors: log and keep going + let msg = e.to_string(); + if msg.contains("closed") || msg.contains("reset") { + error!(recv_errors, "recv fatal: {e}"); + break; + } + // Non-fatal: log throttled + if recv_errors <= 3 || recv_errors % 50 == 0 { + warn!(recv_errors, "recv error (continuing): {e}"); + } } } } + info!(frames_decoded, fec_recovered, recv_errors, "recv task ended"); }; // Stats task — polls path quality + quinn RTT every 500ms @@ -569,12 +665,22 @@ async fn run_call( }; tokio::select! { - _ = send_task => {} - _ = recv_task => {} - _ = stats_task => {} - _ = signal_task => {} + _ = send_task => info!("send task ended"), + _ = recv_task => info!("recv task ended"), + _ = stats_task => info!("stats task ended"), + _ = signal_task => info!("signal task ended"), } - transport.close().await.ok(); + // Send CONNECTION_CLOSE and wait up to 500ms for the peer to acknowledge. + // This ensures the relay sees the close even if the first packet is lost. + info!("closing QUIC connection..."); + transport.close_now(); + match tokio::time::timeout( + std::time::Duration::from_millis(500), + transport.connection().closed(), + ).await { + Ok(_) => info!("QUIC connection closed cleanly"), + Err(_) => info!("QUIC close timed out (relay may not have ack'd)"), + } Ok(()) } diff --git a/crates/wzp-android/src/jni_bridge.rs b/crates/wzp-android/src/jni_bridge.rs index 2c728fc..54e8614 100644 --- a/crates/wzp-android/src/jni_bridge.rs +++ b/crates/wzp-android/src/jni_bridge.rs @@ -1,6 +1,7 @@ //! JNI bridge for Android — thin layer between Kotlin and the WzpEngine. use std::panic; +use std::sync::Once; use jni::objects::{JClass, JObject, JString}; use jni::sys::{jboolean, jint, jlong, jstring}; @@ -28,12 +29,27 @@ fn profile_from_int(value: jint) -> QualityProfile { } } +static INIT_LOGGING: Once = Once::new(); + +/// Initialize tracing → Android logcat (tag "wzp_android"). +/// Safe to call multiple times — only the first call takes effect. +fn init_logging() { + INIT_LOGGING.call_once(|| { + use tracing_subscriber::layer::SubscriberExt; + use tracing_subscriber::util::SubscriberInitExt; + if let Ok(layer) = tracing_android::layer("wzp_android") { + let _ = tracing_subscriber::registry().with(layer).try_init(); + } + }); +} + #[unsafe(no_mangle)] pub unsafe extern "system" fn Java_com_wzp_engine_WzpEngine_nativeInit( _env: JNIEnv, _class: JClass, ) -> jlong { let result = panic::catch_unwind(|| { + init_logging(); let handle = Box::new(EngineHandle { engine: WzpEngine::new(), }); diff --git a/crates/wzp-client/src/featherchat.rs b/crates/wzp-client/src/featherchat.rs index 91a202e..322ca96 100644 --- a/crates/wzp-client/src/featherchat.rs +++ b/crates/wzp-client/src/featherchat.rs @@ -126,6 +126,7 @@ mod tests { ephemeral_pub: [2u8; 32], signature: vec![3u8; 64], supported_profiles: vec![QualityProfile::GOOD], + alias: None, }; let encoded = encode_call_payload(&signal, Some("relay.example.com:4433"), Some("myroom")); @@ -143,6 +144,7 @@ mod tests { ephemeral_pub: [0; 32], signature: vec![], supported_profiles: vec![], + alias: None, }; assert!(matches!(signal_to_call_type(&offer), CallSignalType::Offer)); diff --git a/crates/wzp-relay/src/room.rs b/crates/wzp-relay/src/room.rs index 73b7891..a57ef57 100644 --- a/crates/wzp-relay/src/room.rs +++ b/crates/wzp-relay/src/room.rs @@ -10,7 +10,7 @@ use std::time::Duration; use bytes::Bytes; use tokio::sync::Mutex; -use tracing::{error, info, warn}; +use tracing::{debug, error, info, trace, warn}; use wzp_proto::packet::TrunkFrame; use wzp_proto::MediaTransport; @@ -406,7 +406,7 @@ async fn run_participant_plain( ) { let addr = transport.connection().remote_address(); - // Media forwarding task + // Media forwarding task (with debug logging from Android fixes) let media_room_mgr = room_mgr.clone(); let media_room_name = room_name.clone(); let media_transport = transport.clone(); @@ -414,50 +414,102 @@ async fn run_participant_plain( let media_session_id = session_id.to_string(); let media_task = async move { let mut packets_forwarded = 0u64; + let mut last_recv_instant = std::time::Instant::now(); + let mut max_recv_gap_ms = 0u64; + let mut max_forward_ms = 0u64; + let mut send_errors = 0u64; + let mut last_log_instant = std::time::Instant::now(); + + info!( + room = %media_room_name, + participant = participant_id, + %addr, + session = %media_session_id, + "forwarding loop started (plain)" + ); + loop { let pkt = match media_transport.recv_media().await { Ok(Some(pkt)) => pkt, Ok(None) => { - info!(%addr, participant = participant_id, "disconnected"); + info!(%addr, participant = participant_id, forwarded = packets_forwarded, "disconnected (stream ended)"); break; } Err(e) => { let msg = e.to_string(); if msg.contains("timed out") || msg.contains("reset") || msg.contains("closed") { - info!(%addr, participant = participant_id, "connection closed: {e}"); + info!(%addr, participant = participant_id, forwarded = packets_forwarded, "connection closed: {e}"); } else { - error!(%addr, participant = participant_id, "recv error: {e}"); + error!(%addr, participant = participant_id, forwarded = packets_forwarded, "recv error: {e}"); } break; } }; + let recv_gap_ms = last_recv_instant.elapsed().as_millis() as u64; + last_recv_instant = std::time::Instant::now(); + if recv_gap_ms > max_recv_gap_ms { + max_recv_gap_ms = recv_gap_ms; + } + if recv_gap_ms > 200 { + warn!( + room = %media_room_name, + participant = participant_id, + recv_gap_ms, + seq = pkt.header.seq, + "large recv gap" + ); + } + if let Some(ref report) = pkt.quality_report { media_metrics.update_session_quality(&media_session_id, report); } + let lock_start = std::time::Instant::now(); let others = { let mgr = media_room_mgr.lock().await; mgr.others(&media_room_name, participant_id) }; + let lock_ms = lock_start.elapsed().as_millis() as u64; + if lock_ms > 10 { + warn!(room = %media_room_name, participant = participant_id, lock_ms, "slow room_mgr lock"); + } + let fwd_start = std::time::Instant::now(); let pkt_bytes = pkt.payload.len() as u64; for other in &others { match other { ParticipantSender::Quic(t) => { - let _ = t.send_media(&pkt).await; + if let Err(e) = t.send_media(&pkt).await { + send_errors += 1; + if send_errors <= 5 || send_errors % 100 == 0 { + warn!( + room = %media_room_name, + participant = participant_id, + peer = %t.connection().remote_address(), + total_send_errors = send_errors, + "send_media error: {e}" + ); + } + } } ParticipantSender::WebSocket(_) => { let _ = other.send_raw(&pkt.payload).await; } } } + let fwd_ms = fwd_start.elapsed().as_millis() as u64; + if fwd_ms > max_forward_ms { max_forward_ms = fwd_ms; } + if fwd_ms > 50 { + warn!(room = %media_room_name, participant = participant_id, fwd_ms, fan_out = others.len(), "slow forward"); + } let fan_out = others.len() as u64; media_metrics.packets_forwarded.inc_by(fan_out); media_metrics.bytes_forwarded.inc_by(pkt_bytes * fan_out); packets_forwarded += 1; - if packets_forwarded % 500 == 0 { + + if last_log_instant.elapsed() >= Duration::from_secs(5) { let room_size = { let mgr = media_room_mgr.lock().await; mgr.room_size(&media_room_name) @@ -466,9 +518,12 @@ async fn run_participant_plain( room = %media_room_name, participant = participant_id, forwarded = packets_forwarded, - room_size, + room_size, fan_out, max_recv_gap_ms, max_forward_ms, send_errors, "participant stats" ); + max_recv_gap_ms = 0; + max_forward_ms = 0; + last_log_instant = std::time::Instant::now(); } } }; @@ -533,6 +588,19 @@ async fn run_participant_trunked( let addr = transport.connection().remote_address(); let mut packets_forwarded = 0u64; + let mut last_recv_instant = std::time::Instant::now(); + let mut max_recv_gap_ms = 0u64; + let mut max_forward_ms = 0u64; + let mut send_errors = 0u64; + let mut last_log_instant = std::time::Instant::now(); + + info!( + room = %room_name, + participant = participant_id, + %addr, + session = session_id, + "forwarding loop started (trunked)" + ); // Per-peer TrunkedForwarders, keyed by the raw pointer of the peer // transport (stable for the Arc's lifetime). We use the remote address @@ -554,24 +622,50 @@ async fn run_participant_trunked( let pkt = match result { Ok(Some(pkt)) => pkt, Ok(None) => { - info!(%addr, participant = participant_id, "disconnected"); + info!(%addr, participant = participant_id, forwarded = packets_forwarded, "disconnected (stream ended)"); break; } Err(e) => { - error!(%addr, participant = participant_id, "recv error: {e}"); + error!(%addr, participant = participant_id, forwarded = packets_forwarded, "recv error: {e}"); break; } }; + let recv_gap_ms = last_recv_instant.elapsed().as_millis() as u64; + last_recv_instant = std::time::Instant::now(); + if recv_gap_ms > max_recv_gap_ms { + max_recv_gap_ms = recv_gap_ms; + } + if recv_gap_ms > 200 { + warn!( + room = %room_name, + participant = participant_id, + recv_gap_ms, + seq = pkt.header.seq, + "large recv gap (trunked)" + ); + } + if let Some(ref report) = pkt.quality_report { metrics.update_session_quality(session_id, report); } + let lock_start = std::time::Instant::now(); let others = { let mgr = room_mgr.lock().await; mgr.others(&room_name, participant_id) }; + let lock_ms = lock_start.elapsed().as_millis() as u64; + if lock_ms > 10 { + warn!( + room = %room_name, + participant = participant_id, + lock_ms, + "slow room_mgr lock (trunked)" + ); + } + let fwd_start = std::time::Instant::now(); let pkt_bytes = pkt.payload.len() as u64; for other in &others { match other { @@ -581,21 +675,44 @@ async fn run_participant_trunked( .entry(peer_addr) .or_insert_with(|| TrunkedForwarder::new(t.clone(), sid_bytes)); if let Err(e) = fwd.send(&pkt).await { - let _ = e; + send_errors += 1; + if send_errors <= 5 || send_errors % 100 == 0 { + warn!( + room = %room_name, + participant = participant_id, + peer = %peer_addr, + total_send_errors = send_errors, + "trunked send error: {e}" + ); + } } } ParticipantSender::WebSocket(_) => { - // WS clients bypass trunking — send raw payload directly let _ = other.send_raw(&pkt.payload).await; } } } + let fwd_ms = fwd_start.elapsed().as_millis() as u64; + if fwd_ms > max_forward_ms { + max_forward_ms = fwd_ms; + } + if fwd_ms > 50 { + warn!( + room = %room_name, + participant = participant_id, + fwd_ms, + fan_out = others.len(), + "slow forward (trunked)" + ); + } let fan_out = others.len() as u64; metrics.packets_forwarded.inc_by(fan_out); metrics.bytes_forwarded.inc_by(pkt_bytes * fan_out); packets_forwarded += 1; - if packets_forwarded % 500 == 0 { + + // Periodic stats every 5 seconds + if last_log_instant.elapsed() >= Duration::from_secs(5) { let room_size = { let mgr = room_mgr.lock().await; mgr.room_size(&room_name) @@ -605,15 +722,30 @@ async fn run_participant_trunked( participant = participant_id, forwarded = packets_forwarded, room_size, + fan_out, + max_recv_gap_ms, + max_forward_ms, + send_errors, "participant stats (trunked)" ); + max_recv_gap_ms = 0; + max_forward_ms = 0; + last_log_instant = std::time::Instant::now(); } } _ = flush_interval.tick() => { for fwd in forwarders.values_mut() { if let Err(e) = fwd.flush().await { - let _ = e; + send_errors += 1; + if send_errors <= 5 || send_errors % 100 == 0 { + warn!( + room = %room_name, + participant = participant_id, + total_send_errors = send_errors, + "trunk flush error: {e}" + ); + } } } } diff --git a/crates/wzp-transport/src/quic.rs b/crates/wzp-transport/src/quic.rs index 68fddb2..40c0cea 100644 --- a/crates/wzp-transport/src/quic.rs +++ b/crates/wzp-transport/src/quic.rs @@ -33,6 +33,12 @@ impl QuinnTransport { &self.connection } + /// Close the QUIC connection immediately (synchronous, no async needed). + /// The relay will detect the close and remove this participant from the room. + pub fn close_now(&self) { + self.connection.close(quinn::VarInt::from_u32(0), b"hangup"); + } + /// Feed an external RTT observation (e.g. from QUIC path stats) into the path monitor. pub fn feed_rtt(&self, rtt_ms: u32) { self.path_monitor.lock().unwrap().observe_rtt(rtt_ms); diff --git a/crates/wzp-web/src/main.rs b/crates/wzp-web/src/main.rs index f669383..a89b3a2 100644 --- a/crates/wzp-web/src/main.rs +++ b/crates/wzp-web/src/main.rs @@ -272,7 +272,7 @@ async fn handle_ws(socket: WebSocket, room: String, state: AppState) { // Crypto handshake with relay let handshake_start = std::time::Instant::now(); let bridge_seed = wzp_crypto::Seed::generate(); - match wzp_client::handshake::perform_handshake(&*transport, &bridge_seed.0).await { + match wzp_client::handshake::perform_handshake(&*transport, &bridge_seed.0, None).await { Ok(_session) => { let elapsed = handshake_start.elapsed().as_secs_f64(); state.metrics.handshake_latency.observe(elapsed); diff --git a/crates/wzp-web/static/wasm/package.json b/crates/wzp-web/static/wasm/package.json new file mode 100644 index 0000000..2df13f1 --- /dev/null +++ b/crates/wzp-web/static/wasm/package.json @@ -0,0 +1,16 @@ +{ + "name": "wzp-wasm", + "type": "module", + "description": "WarzonePhone WASM bindings — FEC (RaptorQ) + crypto (ChaCha20-Poly1305, X25519)", + "version": "0.1.0", + "files": [ + "wzp_wasm_bg.wasm", + "wzp_wasm.js", + "wzp_wasm.d.ts" + ], + "main": "wzp_wasm.js", + "types": "wzp_wasm.d.ts", + "sideEffects": [ + "./snippets/*" + ] +} \ No newline at end of file diff --git a/crates/wzp-web/static/wasm/wzp_wasm.d.ts b/crates/wzp-web/static/wasm/wzp_wasm.d.ts new file mode 100644 index 0000000..977b519 --- /dev/null +++ b/crates/wzp-web/static/wasm/wzp_wasm.d.ts @@ -0,0 +1,169 @@ +/* tslint:disable */ +/* eslint-disable */ + +/** + * Symmetric encryption session using ChaCha20-Poly1305. + * + * Mirrors `wzp-crypto::session::ChaChaSession` for WASM. Nonce derivation + * and key setup are identical so WASM and native peers interoperate. + */ +export class WzpCryptoSession { + free(): void; + [Symbol.dispose](): void; + /** + * Decrypt a media payload with AAD. + * + * Returns plaintext on success, or throws on auth failure. + */ + decrypt(header_aad: Uint8Array, ciphertext: Uint8Array): Uint8Array; + /** + * Encrypt a media payload with AAD (typically the 12-byte MediaHeader). + * + * Returns `ciphertext || poly1305_tag` (plaintext.len() + 16 bytes). + */ + encrypt(header_aad: Uint8Array, plaintext: Uint8Array): Uint8Array; + /** + * Create from a 32-byte shared secret (output of `WzpKeyExchange.derive_shared_secret`). + */ + constructor(shared_secret: Uint8Array); + /** + * Current receive sequence number (for diagnostics / UI stats). + */ + recv_seq(): number; + /** + * Current send sequence number (for diagnostics / UI stats). + */ + send_seq(): number; +} + +export class WzpFecDecoder { + free(): void; + [Symbol.dispose](): void; + /** + * Feed a received symbol. + * + * Returns the decoded block (concatenated original frames, unpadded) if + * enough symbols have been received to recover the block, or `undefined`. + */ + add_symbol(block_id: number, symbol_idx: number, _is_repair: boolean, data: Uint8Array): Uint8Array | undefined; + /** + * Create a new FEC decoder. + * + * * `block_size` — expected number of source symbols per block. + * * `symbol_size` — padded byte size of each symbol (must match encoder). + */ + constructor(block_size: number, symbol_size: number); +} + +export class WzpFecEncoder { + free(): void; + [Symbol.dispose](): void; + /** + * Add a source symbol (audio frame). + * + * Returns encoded packets (all source + repair) when the block is complete, + * or `undefined` if the block is still accumulating. + * + * Each returned packet carries the 3-byte header: + * `[block_id][symbol_idx][is_repair]` followed by `symbol_size` bytes. + */ + add_symbol(data: Uint8Array): Uint8Array | undefined; + /** + * Force-flush the current (possibly partial) block. + * + * Returns all source + repair symbols with headers, or empty vec if no + * symbols have been accumulated. + */ + flush(): Uint8Array; + /** + * Create a new FEC encoder. + * + * * `block_size` — number of source symbols (audio frames) per FEC block. + * * `symbol_size` — padded byte size of each symbol (default 256). + */ + constructor(block_size: number, symbol_size: number); +} + +/** + * X25519 key exchange: generate ephemeral keypair and derive shared secret. + * + * Usage from JS: + * ```js + * const kx = new WzpKeyExchange(); + * const ourPub = kx.public_key(); // Uint8Array(32) + * // ... send ourPub to peer, receive peerPub ... + * const secret = kx.derive_shared_secret(peerPub); // Uint8Array(32) + * const session = new WzpCryptoSession(secret); + * ``` + */ +export class WzpKeyExchange { + free(): void; + [Symbol.dispose](): void; + /** + * Derive a 32-byte session key from the peer's public key. + * + * Raw DH output is expanded via HKDF-SHA256 with info="warzone-session-key", + * matching `wzp-crypto::handshake::WarzoneKeyExchange::derive_session`. + */ + derive_shared_secret(peer_public: Uint8Array): Uint8Array; + /** + * Generate a new random X25519 keypair. + */ + constructor(); + /** + * Our public key (32 bytes). + */ + public_key(): Uint8Array; +} + +export type InitInput = RequestInfo | URL | Response | BufferSource | WebAssembly.Module; + +export interface InitOutput { + readonly memory: WebAssembly.Memory; + readonly __wbg_wzpcryptosession_free: (a: number, b: number) => void; + readonly __wbg_wzpfecdecoder_free: (a: number, b: number) => void; + readonly __wbg_wzpfecencoder_free: (a: number, b: number) => void; + readonly __wbg_wzpkeyexchange_free: (a: number, b: number) => void; + readonly wzpcryptosession_decrypt: (a: number, b: number, c: number, d: number, e: number) => [number, number, number, number]; + readonly wzpcryptosession_encrypt: (a: number, b: number, c: number, d: number, e: number) => [number, number, number, number]; + readonly wzpcryptosession_new: (a: number, b: number) => [number, number, number]; + readonly wzpcryptosession_recv_seq: (a: number) => number; + readonly wzpcryptosession_send_seq: (a: number) => number; + readonly wzpfecdecoder_add_symbol: (a: number, b: number, c: number, d: number, e: number, f: number) => [number, number]; + readonly wzpfecdecoder_new: (a: number, b: number) => number; + readonly wzpfecencoder_add_symbol: (a: number, b: number, c: number) => [number, number]; + readonly wzpfecencoder_flush: (a: number) => [number, number]; + readonly wzpfecencoder_new: (a: number, b: number) => number; + readonly wzpkeyexchange_derive_shared_secret: (a: number, b: number, c: number) => [number, number, number, number]; + readonly wzpkeyexchange_new: () => number; + readonly wzpkeyexchange_public_key: (a: number) => [number, number]; + readonly __wbindgen_exn_store: (a: number) => void; + readonly __externref_table_alloc: () => number; + readonly __wbindgen_externrefs: WebAssembly.Table; + readonly __wbindgen_malloc: (a: number, b: number) => number; + readonly __externref_table_dealloc: (a: number) => void; + readonly __wbindgen_free: (a: number, b: number, c: number) => void; + readonly __wbindgen_start: () => void; +} + +export type SyncInitInput = BufferSource | WebAssembly.Module; + +/** + * Instantiates the given `module`, which can either be bytes or + * a precompiled `WebAssembly.Module`. + * + * @param {{ module: SyncInitInput }} module - Passing `SyncInitInput` directly is deprecated. + * + * @returns {InitOutput} + */ +export function initSync(module: { module: SyncInitInput } | SyncInitInput): InitOutput; + +/** + * If `module_or_path` is {RequestInfo} or {URL}, makes a request and + * for everything else, calls `WebAssembly.instantiate` directly. + * + * @param {{ module_or_path: InitInput | Promise }} module_or_path - Passing `InitInput` directly is deprecated. + * + * @returns {Promise} + */ +export default function __wbg_init (module_or_path?: { module_or_path: InitInput | Promise } | InitInput | Promise): Promise; diff --git a/crates/wzp-web/static/wasm/wzp_wasm_bg.wasm.d.ts b/crates/wzp-web/static/wasm/wzp_wasm_bg.wasm.d.ts new file mode 100644 index 0000000..41d7644 --- /dev/null +++ b/crates/wzp-web/static/wasm/wzp_wasm_bg.wasm.d.ts @@ -0,0 +1,27 @@ +/* tslint:disable */ +/* eslint-disable */ +export const memory: WebAssembly.Memory; +export const __wbg_wzpcryptosession_free: (a: number, b: number) => void; +export const __wbg_wzpfecdecoder_free: (a: number, b: number) => void; +export const __wbg_wzpfecencoder_free: (a: number, b: number) => void; +export const __wbg_wzpkeyexchange_free: (a: number, b: number) => void; +export const wzpcryptosession_decrypt: (a: number, b: number, c: number, d: number, e: number) => [number, number, number, number]; +export const wzpcryptosession_encrypt: (a: number, b: number, c: number, d: number, e: number) => [number, number, number, number]; +export const wzpcryptosession_new: (a: number, b: number) => [number, number, number]; +export const wzpcryptosession_recv_seq: (a: number) => number; +export const wzpcryptosession_send_seq: (a: number) => number; +export const wzpfecdecoder_add_symbol: (a: number, b: number, c: number, d: number, e: number, f: number) => [number, number]; +export const wzpfecdecoder_new: (a: number, b: number) => number; +export const wzpfecencoder_add_symbol: (a: number, b: number, c: number) => [number, number]; +export const wzpfecencoder_flush: (a: number) => [number, number]; +export const wzpfecencoder_new: (a: number, b: number) => number; +export const wzpkeyexchange_derive_shared_secret: (a: number, b: number, c: number) => [number, number, number, number]; +export const wzpkeyexchange_new: () => number; +export const wzpkeyexchange_public_key: (a: number) => [number, number]; +export const __wbindgen_exn_store: (a: number) => void; +export const __externref_table_alloc: () => number; +export const __wbindgen_externrefs: WebAssembly.Table; +export const __wbindgen_malloc: (a: number, b: number) => number; +export const __externref_table_dealloc: (a: number) => void; +export const __wbindgen_free: (a: number, b: number, c: number) => void; +export const __wbindgen_start: () => void; diff --git a/debug/INCIDENT-2026-04-06-playout-ring-desync.md b/debug/INCIDENT-2026-04-06-playout-ring-desync.md new file mode 100644 index 0000000..9a95279 --- /dev/null +++ b/debug/INCIDENT-2026-04-06-playout-ring-desync.md @@ -0,0 +1,166 @@ +# Incident Report: Playout Ring Buffer Cursor Desync — Bidirectional Audio Loss + +**Date:** 2026-04-06 +**Severity:** Critical — causes 10-16 seconds of complete bidirectional silence mid-call +**Status:** Root-caused, fix pending +**Affects:** All clients using `AudioRing` (Android, potentially desktop) + +## Summary + +Both participants in a call experience simultaneous, prolonged audio silence (10-16 seconds) despite the QUIC transport, relay, and Rust codec pipeline all functioning normally. The root cause is a cursor desynchronization in the lock-free SPSC ring buffer (`AudioRing`) that transfers decoded PCM from the Rust recv task to the Kotlin AudioTrack playout thread. + +## How We Know It's the Ring Buffer + +### Evidence that eliminates other components + +| Component | Evidence it's healthy | Source | +|-----------|----------------------|--------| +| **QUIC send path** | `frames_dropped=0, send_errors=0` on both clients | Engine send stats log | +| **QUIC recv path** | `max_recv_gap_ms=82, recv_errors=0` — no gaps >82ms | Engine recv stats log | +| **Relay forwarding** | `max_forward_ms=0, send_errors=0` in previous relay-instrumented test | Relay debug logging | +| **Opus codec** | `frames_decoded=2442` over 51.9s = 47 frames/sec (correct for 20ms) | Final stats JSON | +| **FEC** | `fec_recovered=4870` — FEC working normally | Final stats JSON | +| **Audio capture** | Pixel 6 capture has 0% silence; Nothing has gaps but those are expected mic pauses | capture_rms.csv | + +### Evidence pointing to the ring buffer + +1. **Both clients go silent at the exact same wall-clock moment (26.66s into call)** — rules out per-device issues; the common factor is the relay, but the relay was proven healthy in prior tests. + +2. **`playout_avail=8640` at stats dump time** — the playout ring reports 8640 samples available (180ms, nearly full at the 9600 capacity). The recv task believes it has successfully written data into the ring. But the AudioTrack playout thread is reading silence (RMS=0 for 12+ seconds). + +3. **Recv task continued receiving packets with no gaps** — `max_recv_gap_ms=82` across the entire call. The decoded audio was written to the ring continuously. + +4. **Silence starts and ends cleanly** — the transition from audio → silence happens within a single 20ms frame (frame 1332: rms=101, frame 1333: rms=0). This is not network degradation (which shows gradual quality loss). It's a discrete state change — the reader suddenly stops seeing data. + +5. **Recovery is also discrete** — at ~38.8s (Sharp Hawk) and ~42.7s (Pixel 6), audio snaps back with high-energy frames (rms=3296+). Not a gradual reconnection. + +## The Ring Buffer Code + +**File:** `crates/wzp-android/src/audio_ring.rs` + +```rust +const RING_CAPACITY: usize = 960 * 10; // 9600 samples = 200ms at 48kHz + +pub struct AudioRing { + buf: Box<[i16; RING_CAPACITY]>, + write_pos: AtomicUsize, // monotonically increasing, wraps at usize::MAX + read_pos: AtomicUsize, // monotonically increasing, wraps at usize::MAX +} +``` + +### `available()` — how many samples can be read +```rust +pub fn available(&self) -> usize { + let w = self.write_pos.load(Ordering::Acquire); + let r = self.read_pos.load(Ordering::Acquire); + w.wrapping_sub(r) // relies on usize wrapping arithmetic +} +``` + +### `write()` — producer (Rust recv task thread, inside tokio block_on) +```rust +pub fn write(&self, samples: &[i16]) -> usize { + let w = self.write_pos.load(Ordering::Relaxed); + let count = samples.len().min(RING_CAPACITY); + // ... write samples at (w + i) % RING_CAPACITY ... + self.write_pos.store(w.wrapping_add(count), Ordering::Release); + + // If we overwrote unread data, advance read_pos + if self.available() > RING_CAPACITY { + let new_read = self.write_pos.load(Ordering::Relaxed).wrapping_sub(RING_CAPACITY); + self.read_pos.store(new_read, Ordering::Release); + } +} +``` + +### `read()` — consumer (Kotlin AudioTrack JVM thread, via JNI) +```rust +pub fn read(&self, out: &mut [i16]) -> usize { + let avail = self.available(); + let count = out.len().min(avail); + let r = self.read_pos.load(Ordering::Relaxed); + // ... read samples at (r + i) % RING_CAPACITY ... + self.read_pos.store(r.wrapping_add(count), Ordering::Release); + count +} +``` + +## Suspected Failure Modes + +### 1. Writer advances `read_pos` while reader is mid-read (data race) + +The `write()` method at lines 68-72 modifies `read_pos` from the writer thread when it detects overflow. But the `read()` method on the consumer thread also modifies `read_pos`. This violates the SPSC contract — `read_pos` is supposed to be owned by the consumer. + +**Scenario:** +1. Reader loads `read_pos = R` (line 82) +2. Writer detects overflow, stores `read_pos = R'` (line 71) where `R' > R` +3. Reader finishes reading, stores `read_pos = R + count` (line 88) — **overwrites** the writer's `R'` with a stale, smaller value + +After step 3, the ring's `read_pos` has gone backwards. Now `available()` returns `write_pos.wrapping_sub(old_read_pos)` which is larger than `RING_CAPACITY`. Every subsequent `write()` call hits the overflow branch and keeps advancing `read_pos`, but the reader keeps overwriting it back. The ring is in a corrupted state where the reader and writer are fighting over `read_pos`. + +### 2. `wrapping_sub` returns astronomically large values + +`available()` uses `w.wrapping_sub(r)`. On a 64-bit platform, if due to the race above `r > w`, `wrapping_sub` returns `usize::MAX - (r - w) + 1` — an enormous number. The `read()` method caps this with `out.len().min(avail)` so it reads `out.len()` samples. But those samples are from indices calculated as `(r + i) % RING_CAPACITY` which wraps correctly. The samples read would be whatever was in the buffer at those positions — potentially stale/old data, or zeros from initialization. + +However, the playout RMS CSV shows clean zeros (RMS=0), not garbage. This suggests the ring is returning the zeroed-out initial buffer contents, meaning `read_pos` has jumped far ahead of `write_pos`, pointing to memory that was never written to (or was written long ago and has since been zeroed by the overflow advance logic). + +### 3. Why silence lasts exactly 12-16 seconds + +After the desync, each `write()` call (every 20ms when a packet is decoded) enters the overflow branch and resets `read_pos`. But the reader immediately overwrites it back in its next `read()` call. This tug-of-war continues until one of two things happens: +- The cursors happen to realign through wrapping arithmetic +- A timing coincidence where the writer's store to `read_pos` happens to "win" the race + +The 12-16 second duration is non-deterministic and depends on exact thread scheduling and cursor values. + +## Reproduction Pattern + +The bug manifests after roughly 25-30 seconds of a call. This timing is suspicious: +- At 48kHz mono, 20ms frames = 50 frames/sec +- Each decoded frame writes 960 samples to the ring +- After 25 seconds: `write_pos ≈ 25 * 50 * 960 = 1,200,000` +- The ring capacity is 9600, so `write_pos` has wrapped around `RING_CAPACITY` about 125 times + +The wrapping of the monotonic cursors past certain thresholds, combined with the reader/writer `read_pos` race, likely triggers the desync at this scale. + +## Data Files + +All data from two independent test sessions (3 calls total) is in `/workspace/wzp/debug/`: + +| File | Contents | +|------|----------| +| `wzp_debug_20260406_120546.zip` | Sharp Hawk (Nothing A059) — 51.9s call | +| `wzp_debug_20260406_120549.zip` | Bright Viper (Pixel 6) — 51.9s call | +| `wzp_debug_20260406_111733.zip` | Sharp Hawk — earlier 72.0s call, same pattern | +| `wzp_debug_20260406_111735.zip` | Bright Viper — earlier 72.0s call, same pattern | +| `wzp_debug_20260406_105858.zip` | First session (pre-logging fix), 39.8s call | +| `wzp_debug_20260406_105900.zip` | First session, 39.7s call | + +### Key fields in each zip + +- `meta.txt` — device, duration, final stats JSON +- `playout_rms.csv` — per-frame (20ms) RMS of AudioTrack output; silence = RMS 0 +- `capture_rms.csv` — per-frame RMS of AudioRecord input +- `logcat.txt` — Android logcat filtered to WZP + audio tags + +### How to reproduce the analysis + +```python +import csv +with open("playout_rms.csv") as f: + for row in csv.DictReader(f): + if int(row['rms']) == 0 and int(row['time_ms']) > 2000: + print(f"SILENCE at {row['time_ms']}ms") +``` + +## Affected Code + +- `crates/wzp-android/src/audio_ring.rs` — the `AudioRing` struct, specifically the `write()` method's overflow handling that mutates `read_pos` from the producer thread +- Any client using `AudioRing` for playout (currently only Android; desktop uses `cpal` directly) + +## Constraints for the Fix + +1. Must remain lock-free — AudioTrack thread runs at `Thread.MAX_PRIORITY` and cannot block +2. Must handle overflow gracefully — if the reader falls behind, old audio should be dropped, not cause a desync +3. The writer (Rust recv task) and reader (Kotlin AudioTrack via JNI) run on different threads with different scheduling priorities +4. Ring capacity is 200ms which is tight — any fix must not increase latency significantly +5. The `write_pos` and `read_pos` are the only synchronization mechanism (no mutex, no condvar) diff --git a/debug/INCIDENT-2026-04-06-send-task-crash.md b/debug/INCIDENT-2026-04-06-send-task-crash.md new file mode 100644 index 0000000..79950a0 --- /dev/null +++ b/debug/INCIDENT-2026-04-06-send-task-crash.md @@ -0,0 +1,123 @@ +# Incident Report: Send Task Fatal Exit on QUIC Congestion + +**Date:** 2026-04-06 +**Severity:** High — causes complete audio loss mid-call +**Status:** Fixed in Android client, **pending fix in desktop client and web client** + +## Summary + +A QUIC congestion event causes `send_datagram()` to return `Err(Blocked)`. The send task treats this as a fatal error and exits, which kills the entire call via `tokio::select!`. Audio becomes one-way (recv still works briefly) then dies completely. + +## Root Cause + +In the engine's send loop (`run_call` function), `transport.send_media()` errors were handled with `break`: + +```rust +// BEFORE (broken) +if let Err(e) = transport.send_media(&source_pkt).await { + error!("send error: {e}"); + break; // <-- kills send task, which kills everything +} +``` + +Quinn's `send_datagram()` is synchronous and returns `Err(SendDatagramError::Blocked)` when the QUIC congestion window is full. This is a **transient condition** — the window opens again once ACKs arrive. But the `break` kills the send task, and since all tasks run under `tokio::select!`, the recv task, stats task, and signal task all die too. + +### Why it manifests as "intermittent disconnections" + +- Mobile networks have brief congestion spikes (cell tower handoff, WiFi interference) +- A single spike fills the QUIC congestion window +- One `Blocked` error → send task exits → `select!` cancels recv → complete silence +- The QUIC connection stays open (no error logged), so stats polling continues showing stale data +- From the user's perspective: audio drops for 5-20 seconds then "maybe comes back" (it doesn't — they're hearing cached playout ring drain) + +### Evidence from debug reports + +**Relay logs** confirmed the relay was healthy: +- `max_forward_ms=0` — relay forwards instantly +- `send_errors=0` — no relay-side failures +- The relay saw `large recv gap` warnings on participant 1 (Nothing A059): 722ms → 814ms → 1778ms → 3500ms → 6091ms — the client progressively stopped sending + +**Client stats** confirmed: +- `frames_encoded` kept incrementing (Opus encoder running) +- `frames_decoded` froze at a fixed value (recv task died) +- `fec_recovered` froze simultaneously +- RTT, loss, jitter all frozen (stats task died) + +## Fix Applied + +### Android client (`crates/wzp-android/src/engine.rs`) + +```rust +// AFTER (fixed) +if let Err(e) = transport.send_media(&source_pkt).await { + send_errors += 1; + frames_dropped += 1; + if send_errors <= 3 || last_send_error_log.elapsed().as_secs() >= 1 { + warn!(seq = s, send_errors, frames_dropped, + "send_media error (dropping packet): {e}"); + last_send_error_log = Instant::now(); + } + continue; // <-- drop packet, keep going +} +``` + +Same pattern applied to FEC repair packet sends. + +Recv task also hardened: transient errors (non-closed/reset) are now logged and survived rather than causing exit. + +Added periodic health logging to both tasks (5-second intervals): +- Send: `frames_sent`, `frames_dropped`, `send_errors`, `ring_avail` +- Recv: `frames_decoded`, `fec_recovered`, `recv_errors`, `max_recv_gap_ms`, `playout_avail` + +### Relay (`crates/wzp-relay/src/room.rs`) + +Added debug logging to both plain and trunked forwarding loops: +- Per-recv gap tracking (warns on >200ms gaps) +- Room manager lock contention tracking (warns on >10ms) +- Forward latency tracking (warns on >50ms) +- Send error counting with peer identification +- 5-second periodic stats with all above metrics + +## Affected Clients — FIX REQUIRED + +### Desktop client (`crates/wzp-client/src/cli.rs`) + +**Lines 345-348:** +```rust +if let Err(e) = transport.send_media(pkt).await { + error!("send error: {e}"); + break; // <-- SAME BUG +} +``` + +**Lines 431-434:** +```rust +if let Err(e) = send_transport.send_media(pkt).await { + error!("send error: {e}"); + return; // <-- SAME BUG +} +``` + +Both need the same continue-on-error pattern. + +### Web client (`crates/wzp-web/src/main.rs`) + +Needs audit — WebSocket transport may have different error semantics but same pattern should be checked. + +## Testing + +After fix, a congestion event will: +1. Log warnings with packet counts: `send_media error (dropping packet): Blocked` +2. Drop affected packets (brief audio glitch — ~20-100ms) +3. Resume normal sending once congestion window opens +4. FEC on the receiver side will recover most dropped packets +5. Call continues uninterrupted + +## Timeline + +- 10:37 — First crash observed (LinearProgressIndicator compose bug masked investigation) +- 10:58 — Debug reports collected, decoded stall pattern identified +- 11:16 — Relay debug logging deployed, confirmed relay is clean +- 11:17 — Second debug reports collected, send gaps correlated with relay recv gaps +- 11:30 — Root cause identified: `break` on `send_media` error in send task +- 11:45 — Fix applied and deployed