Add a log viewer to Spinner.

This is more of a proof-of-concept/demo for using a websocket with
Spinner. Gives an example of how we could push live updates to the
webapp.

Also, the logger is actually nice. Guaranteed to never get cluttered
with system logs. Looks basically identical to our other log viewers.
Filtering is basic but fast. And we could build much better tooling on
top of this.
This commit is contained in:
Greyson Parrelli
2023-09-25 09:24:42 -04:00
committed by Cody Henthorne
parent c314918c6b
commit 6a974c48ef
16 changed files with 647 additions and 15 deletions

View File

@@ -5,7 +5,7 @@ html, body {
width: 100%;
}
select, input {
select, input, button {
font-family: 'Roboto Mono', monospace;
font-variant-ligatures: none;
font-size: 1rem;

View File

@@ -0,0 +1,290 @@
<html>
{{> partials/head title="Home" }}
<link href="https://fonts.googleapis.com/css2?family=JetBrains+Mono&display=swap" rel="stylesheet">
<style type="text/css">
html, body {
overflow: hidden;
}
h1.collapse-header {
font-size: 1.35rem;
}
h2.collapse-header {
font-size: 1.15rem;
}
#log-container {
width: calc(100% - 32px);
height: calc(100% - 325px);
overflow-y: scroll;
overflow-x: auto;
border: 1px solid black;
resize: vertical;
white-space: pre;
font-family: 'JetBrains Mono', monospace;
background-color: #2b2b2b;
margin-top: 8px;
border-radius: 5px;
border: 1px solid black;
padding: 8px;
}
#logs {
width: 100%;
}
.log-verbose {
color: #8a8a8a;
}
.log-debug {
color: #5ca72b;
}
.log-info{
color: #46bbb9;
}
.log-warn{
color: #d6cb37;
}
.log-error{
color: #ff6b68;
}
#follow-button.enabled {
opacity: 0.5;
}
#toolbar {
width: calc(100% - 14px);
display: flex;
flex-direction: row;
flex-wrap: nowrap;
justify-content: flex-start;
}
#toolbar #filter-text {
flex-grow: 1;
margin-left: 8px;
}
#socket-status {
width: 16px;
height: 16px;
border-radius: 16px;
margin: 3px 0 3px 3px;
border: 1px solid black;
}
#socket-status.connected {
background-color: #5ca72b;
}
#socket-status.connecting {
background-color: #d6cb37;
}
#socket-status.disconnected {
background-color: #cc0000;
}
</style>
<body>
{{> partials/prefix isLogs=true}}
<div id="toolbar">
<button onclick="onFollowClicked()" id="follow-button">Follow</button>
<input type="text" id="filter-text" placeholder="Filter..." />
<div id="socket-status"></div>
</div>
<div id="log-container"></div>
{{> partials/suffix }}
<script>
const logs = []
const logTable = document.getElementById('logs')
const logContainer = document.getElementById('log-container')
const followButton = document.getElementById('follow-button')
const filterText = document.getElementById('filter-text')
const statusOrb = document.getElementById('socket-status')
let followLogs = false
let programaticScroll = false
let filter = null
function main() {
initWebSocket()
setFollowState(true)
logContainer.innerHTML = ''
filterText.addEventListener('input', onFilterChanged)
logContainer.addEventListener('scroll', () => {
if (programaticScroll) {
programaticScroll = false
} else {
setFollowState(false)
}
})
}
function onFollowClicked() {
setFollowState(true)
scrollToBottom()
}
function onFilterChanged(event) {
filter = event.target.value
logContainer.innerHTML = ''
logs
.filter(it => logMatches(it, filter))
.map(it => logToDiv(it))
.forEach(it => logContainer.appendChild(it))
setFollowState(true)
scrollToBottom()
}
function initWebSocket() {
const websocket = new WebSocket(`ws://${window.location.host}/logs/websocket`)
let keepAliveTimer = null
statusOrb.className = 'connecting'
websocket.onopen = () => {
console.log("[open] Connection established");
console.log("Sending to server");
statusOrb.className = 'connected'
keepAliveTimer = setInterval(() => websocket.send('keepalive'), 1000)
}
websocket.onclose = () => {
console.log('[close] Closed!')
statusOrb.className = 'disconnected'
if (keepAliveTimer != null) {
clearInterval(keepAliveTimer)
keepAliveTimer = null
}
setTimeout(() => initWebSocket(), 1000)
}
websocket.onmessage = onWebSocketMessage
}
function onWebSocketMessage(event) {
const log = JSON.parse(event.data)
logs.push(log)
if (logs.length > 5_000) {
logs.shift()
}
if (filter == null || logMatches(log, filter)) {
logContainer.appendChild(logToDiv(log))
}
if (followLogs) {
scrollToBottom()
}
}
function logToDiv(log) {
const div = document.createElement('div')
const linePrefix = `[${log.thread}] ${log.time} ${log.tag} ${log.level} `
let stackTraceString = log.stackTrace
if (stackTraceString != null) {
stackTraceString = ' \n' + stackTraceString
}
let textContent = `${linePrefix}${log.message || ''}${stackTraceString || ''}`
textContent = indentOverflowLines(textContent, linePrefix.length)
div.textContent = textContent
div.classList.add(levelToClass(log.level))
return div
}
function levelToClass(level) {
switch (level) {
case 'V': return 'log-verbose'
case 'D': return 'log-debug'
case 'I': return 'log-info'
case 'W': return 'log-warn'
case 'E': return 'log-error'
default: return ''
}
}
function setFollowState(value) {
if (followLogs === value) {
return
}
followLogs = value
if (followLogs) {
followButton.classList.add('enabled')
followButton.disabled = true
} else {
followButton.classList.remove('enabled')
followButton.disabled = false
}
}
function scrollToBottom() {
programaticScroll = true
logContainer.scrollTop = logContainer.scrollHeight
}
function indentOverflowLines(text, indent) {
const lines = text.split('\n')
if (lines.length > 1) {
const spaces = ' '.repeat(indent)
const overflow = lines.slice(1)
const indented = overflow.map(it => spaces + it).join('\n')
return lines[0] + '\n' + indented
} else {
return text
}
}
function logMatches(log, filter) {
if (log.tag != null && log.tag.indexOf(filter) >= 0) {
return true
}
if (log.message != null && log.message.indexOf(filter) >= 0) {
return true
}
if (log.stackTrace != null && log.stackTrace.indexOf(filter) >= 0) {
return true
}
return false
}
main()
</script>
</body>
</html>

View File

@@ -23,6 +23,7 @@
<li {{#if isBrowse}}class="active"{{/if}}><a href="/browse?db={{database}}">Browse</a></li>
<li {{#if isQuery}}class="active"{{/if}}><a href="/query?db={{database}}">Query</a></li>
<li {{#if isRecent}}class="active"{{/if}}><a href="/recent?db={{database}}">Recent</a></li>
<li {{#if isLogs}}class="active"{{/if}}><a href="/logs?db={{database}}">Logs</a></li>
{{#each plugins}}
<li {{#if (eq name activePlugin.name)}}class="active"{{/if}}><a href="{{path}}">{{name}}</a></li>
{{/each}}

View File

@@ -68,6 +68,10 @@ object Spinner {
server.onSql(dbName, queryString)
}
internal fun log(item: SpinnerLogItem) {
server.onLog(item)
}
private fun replaceQueryArgs(query: String, args: Array<Any>?): String {
if (args == null) {
return query

View File

@@ -0,0 +1,55 @@
/*
* Copyright 2023 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.signal.spinner
import android.util.Log
import org.json.JSONObject
import org.signal.core.util.ExceptionUtil
import java.text.SimpleDateFormat
import java.util.Date
import java.util.Locale
internal data class SpinnerLogItem(
val level: Int,
val time: Long,
val thread: String,
val tag: String,
val message: String?,
val throwable: Throwable?
) {
fun serialize(): String {
val stackTrace: String? = throwable?.let { ExceptionUtil.convertThrowableToString(throwable) }
val formattedTime = dateFormat.format(Date(time))
val paddedTag: String = when {
tag.length > 23 -> tag.substring(0, 23)
tag.length < 23 -> tag.padEnd(23)
else -> tag
}
val levelString = when (level) {
Log.VERBOSE -> "V"
Log.DEBUG -> "D"
Log.INFO -> "I"
Log.WARN -> "W"
Log.ERROR -> "E"
else -> "?"
}
val out = JSONObject()
out.put("level", levelString)
out.put("time", formattedTime)
out.put("thread", thread)
out.put("tag", paddedTag)
message?.let { out.put("message", it) }
stackTrace?.let { out.put("stackTrace", it) }
return out.toString(0)
}
companion object {
private val dateFormat = SimpleDateFormat("HH:mm:ss.SSS", Locale.US)
}
}

View File

@@ -0,0 +1,96 @@
/*
* Copyright 2023 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.signal.spinner
import android.annotation.SuppressLint
import android.util.Log
import fi.iki.elonen.NanoHTTPD
import fi.iki.elonen.NanoWSD
import fi.iki.elonen.NanoWSD.WebSocket
import java.io.IOException
import java.util.LinkedList
import java.util.Queue
import java.util.concurrent.locks.ReentrantLock
import kotlin.concurrent.withLock
@SuppressLint("LogNotSignal")
internal class SpinnerLogWebSocket(handshakeRequest: NanoHTTPD.IHTTPSession) : WebSocket(handshakeRequest) {
companion object {
private val TAG = "SpinnerLogWebSocket"
private const val MAX_LOGS = 5_000
private val logs: Queue<SpinnerLogItem> = LinkedList()
private val openSockets: MutableList<SpinnerLogWebSocket> = mutableListOf()
private val lock = ReentrantLock()
private val condition = lock.newCondition()
private val logThread: LogThread = LogThread().also { it.start() }
fun onLog(item: SpinnerLogItem) {
lock.withLock {
logs += item
if (logs.size > MAX_LOGS) {
logs.remove()
}
condition.signal()
}
}
}
override fun onOpen() {
Log.d(TAG, "onOpen()")
lock.withLock {
openSockets += this
condition.signal()
}
}
override fun onClose(code: NanoWSD.WebSocketFrame.CloseCode, reason: String?, initiatedByRemote: Boolean) {
Log.d(TAG, "onClose()")
lock.withLock {
openSockets -= this
}
}
override fun onMessage(message: NanoWSD.WebSocketFrame) {
Log.d(TAG, "onMessage()")
}
override fun onPong(pong: NanoWSD.WebSocketFrame) {
Log.d(TAG, "onPong()")
}
override fun onException(exception: IOException) {
Log.d(TAG, "onException()", exception)
}
private class LogThread : Thread("SpinnerLog") {
override fun run() {
while (true) {
val (sockets, log) = lock.withLock {
while (logs.isEmpty() || openSockets.isEmpty()) {
condition.await()
}
openSockets.toList() to logs.remove()
}
sockets.forEach { socket ->
try {
socket.send(log.serialize())
} catch (e: IOException) {
Log.w(TAG, "Failed to send a log to the socket!", e)
}
}
}
}
}
}

View File

@@ -0,0 +1,98 @@
/*
* Copyright 2023 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.signal.spinner
import android.os.Looper
import android.util.Log
import org.signal.core.util.logging.Log.Logger
class SpinnerLogger : Logger() {
private val cachedThreadString: ThreadLocal<String> = ThreadLocal()
override fun v(tag: String, message: String?, t: Throwable?, keepLonger: Boolean) {
Spinner.log(
SpinnerLogItem(
level = Log.VERBOSE,
time = System.currentTimeMillis(),
thread = getThreadString(),
tag = tag,
message = message,
throwable = t
)
)
}
override fun d(tag: String, message: String?, t: Throwable?, keepLonger: Boolean) {
Spinner.log(
SpinnerLogItem(
level = Log.DEBUG,
time = System.currentTimeMillis(),
thread = getThreadString(),
tag = tag,
message = message,
throwable = t
)
)
}
override fun i(tag: String, message: String?, t: Throwable?, keepLonger: Boolean) {
Spinner.log(
SpinnerLogItem(
level = Log.INFO,
time = System.currentTimeMillis(),
thread = getThreadString(),
tag = tag,
message = message,
throwable = t
)
)
}
override fun w(tag: String, message: String?, t: Throwable?, keepLonger: Boolean) {
Spinner.log(
SpinnerLogItem(
level = Log.WARN,
time = System.currentTimeMillis(),
thread = getThreadString(),
tag = tag,
message = message,
throwable = t
)
)
}
override fun e(tag: String, message: String?, t: Throwable?, keepLonger: Boolean) {
Spinner.log(
SpinnerLogItem(
level = Log.ERROR,
time = System.currentTimeMillis(),
thread = getThreadString(),
tag = tag,
message = message,
throwable = t
)
)
}
override fun flush() = Unit
fun getThreadString(): String {
var threadString = cachedThreadString.get()
if (cachedThreadString.get() == null) {
threadString = if (Looper.myLooper() == Looper.getMainLooper()) {
"main "
} else {
String.format("%-5s", Thread.currentThread().id)
}
cachedThreadString.set(threadString)
}
return threadString!!
}
}

View File

@@ -7,12 +7,14 @@ import com.github.jknack.handlebars.Handlebars
import com.github.jknack.handlebars.Template
import com.github.jknack.handlebars.helper.ConditionalHelpers
import fi.iki.elonen.NanoHTTPD
import fi.iki.elonen.NanoWSD
import org.signal.core.util.ExceptionUtil
import org.signal.core.util.ForeignKeyConstraint
import org.signal.core.util.getForeignKeys
import org.signal.core.util.logging.Log
import org.signal.spinner.Spinner.DatabaseConfig
import java.lang.IllegalArgumentException
import java.security.NoSuchAlgorithmException
import java.text.SimpleDateFormat
import java.util.Date
import java.util.Locale
@@ -33,7 +35,7 @@ internal class SpinnerServer(
deviceInfo: Map<String, () -> String>,
private val databases: Map<String, DatabaseConfig>,
private val plugins: Map<String, Plugin>
) : NanoHTTPD(5000) {
) : NanoWSD(5000) {
companion object {
private val TAG = Log.tag(SpinnerServer::class.java)
@@ -69,6 +71,8 @@ internal class SpinnerServer(
session.method == Method.GET && session.uri == "/query" -> getQuery(dbParam)
session.method == Method.POST && session.uri == "/query" -> postQuery(dbParam, dbConfig, session)
session.method == Method.GET && session.uri == "/recent" -> getRecent(dbParam)
session.method == Method.GET && session.uri == "/logs" -> getLogs(dbParam)
isWebsocketRequested(session) && session.uri == "/logs/websocket" -> getLogWebSocket(session)
else -> {
val plugin = plugins[session.uri]
if (plugin != null && session.method == Method.GET) {
@@ -84,6 +88,10 @@ internal class SpinnerServer(
}
}
override fun openWebSocket(handshake: IHTTPSession): WebSocket {
return SpinnerLogWebSocket(handshake)
}
fun onSql(dbName: String, sql: String) {
val commands: Queue<QueryItem> = recentSql[dbName] ?: ConcurrentLinkedQueue()
@@ -95,6 +103,10 @@ internal class SpinnerServer(
recentSql[dbName] = commands
}
fun onLog(item: SpinnerLogItem) {
SpinnerLogWebSocket.onLog(item)
}
private fun getIndex(dbName: String, db: SupportSQLiteDatabase): Response {
return renderTemplate(
"overview",
@@ -205,6 +217,38 @@ internal class SpinnerServer(
)
}
private fun getLogs(dbName: String): Response {
return renderTemplate(
"logs",
LogsPageModel(
environment = environment,
deviceInfo = deviceInfo.resolve(),
database = dbName,
databases = databases.keys.toList(),
plugins = plugins.values.toList()
)
)
}
private fun getLogWebSocket(session: IHTTPSession): Response {
val headers = session.headers
val webSocket = openWebSocket(session)
val handshakeResponse = webSocket.handshakeResponse
try {
handshakeResponse.addHeader(HEADER_WEBSOCKET_ACCEPT, makeAcceptKey(headers[HEADER_WEBSOCKET_KEY]))
} catch (e: NoSuchAlgorithmException) {
return newFixedLengthResponse(Response.Status.INTERNAL_ERROR, NanoHTTPD.MIME_PLAINTEXT, "The SHA-1 Algorithm required for websockets is not available on the server.")
}
if (headers.containsKey(HEADER_WEBSOCKET_PROTOCOL)) {
handshakeResponse.addHeader(HEADER_WEBSOCKET_PROTOCOL, headers[HEADER_WEBSOCKET_PROTOCOL]!!.split(",")[0])
}
return webSocket.handshakeResponse
}
private fun postQuery(dbName: String, dbConfig: DatabaseConfig, session: IHTTPSession): Response {
val action: String = session.parameters["action"]?.get(0).toString()
val rawQuery: String = session.parameters["query"]?.get(0).toString()
@@ -448,6 +492,14 @@ internal class SpinnerServer(
val recentSql: List<RecentQuery>?
) : PrefixPageData
data class LogsPageModel(
override val environment: String,
override val deviceInfo: Map<String, String>,
override val database: String,
override val databases: List<String>,
override val plugins: List<Plugin>
) : PrefixPageData
data class PluginPageModel(
override val environment: String,
override val deviceInfo: Map<String, String>,