Aus meinem Arbeit bei DroidSolutions GmbH/KULDIG!
Drüben bei KULDIG haben wir ein eigenes MDM System für Android gebaut, das speziell für unsere Kunden im Kulturbereich designed wurde und einige spezielle Anforderungen erfüllen muss.
Eine dieser Herausforderungen sind die Blackbox-Netzwerke, in denen die MDM-Geräte deployed werden. Diese sind für Dienstleister schwer greifbar, nicht dokumentiert und ein Debugging ist nur äußerst schwer machbar.
Das MDM Backend selbst ist eine SaaS-Anwendung und läuft auf KULDIG-Servern.
Problembeschreibung
Diese Woche standen wir vor einem unerwarteten Problem: Ein geplantes App-Update konnte auf den Geräten in einem Museum nicht installiert werden. Nach vier Jahren reibungslosen Betriebs war dies das erste Mal, dass wir auf ein solches Problem stießen. Trotz korrekter Verlinkung und Signatur der APK verweigerte das System das Update.
Diagnose
Um das Problem zu lösen, gingen wir die üblichen Verdächtigen durch:
- Internetverbindung prüfen: Fast alle Geräte waren online, das Monitoring meldete sie als aktiv.
- APK-Verlinkung und Signatur: Die Verlinkung und die Signatur der vorherigen und aktuellen APK stimmten überein. Das ist eine übliche Fehlerquelle
>keytool -printcert --jarfile alte_version.apk
- Installationsstatus überprüfen: Das interne Monitoring meldete die veraltete Version, das Update wurde also nicht durchgeführt.
- Neustart: Alle Geräte wurden mehrfach neu gestartet. Leider brachte auch das keine Lösung.
- MDM-App: Sentry meldet keine Abstürze, auch hier alles in Ordnung.
- Laborumgebung: Auf einem zurückgesetzten Testgerät funktionierte alles einwandfrei, die Updates werden installiert.
Lösungssuche
Da alle offensichtlichen Lösungen ausgeschöpft waren, vermutete ich ein Problem in der Netzwerkkonfiguration. Um eine 500km Dienstreise zu vermeiden und das Problem näher zu untersuchen, entschied ich mich, detailliertes Remote-Logging zu implementieren. Dafür nutzte ich android-logback in Kombination mit einem Loki-Logback-Appender.
Aber wie kam ich auf diesen Lösungsansatz, ohne zuvor etwas Ähnliches implementiert zu haben?
Remote-Logging nachrüsten
Nach einer schnellen Google-Suche gibt es einige Ansätze, um Logging zu zentralisieren. Im Java-Umfeld wird Logback genutzt. Damit hab ich nie gearbeitet, aber es gibt eine android-logback Variante, die gut aussieht. Das default-logback ist für Java-Anwendungen und kann nicht (ohne weiteres?) in Android-Apps genutzt werden.
Android-Logback integrieren
Also „schnell“ eingebaut, Abhängigkeiten angepasst und eine kleine Wrapper-Class gebaut. Ein erster Test sagt, passt. Der Test-Log wird im richtigen Format geloggt und landet im Logcat und in einer Datei.
LoggerContext loggerContext = (LoggerContext)LoggerFactory.getILoggerFactory();
loggerContext.stop();
// encoder konfigurieren und deviceId als Test
PatternLayoutEncoder encoder = new PatternLayoutEncoder();
encoder.setContext(loggerContext);
encoder.setPattern("[%thread] %-5level - " + deviceId + " - %msg%n");
encoder.start();
// logcat-appender aktivieren
LogcatAppender logcatAppender = new LogcatAppender();
logcatAppender.setContext(lc);
logcatAppender.setEncoder(encoder);
logcatAppender.start();
// alles verlinken
ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
root.addAppender(logcatAppender);
//fertig, nun kann mit LoggerFactory.getLogger(c) auf den Logger zugegriffen werden.
Ok, aber das ist immer noch lokal. Wie bekomm ich die Daten zu mir?
Android-Logback hat ein paar Appender, SQLite, File, Logcat, SMTP. Überzeugt mich alles nicht, denn SMTP möchte ich für so etwas nicht nutzen und eine Log-Datei irgendwo hochladen ist nun auch nichts, das ich machen würde.
Im Backend stellen wir gerade alles Logging auf Grafana Loki um, warum nicht eigentlich auch hier? Wie es der Zufall so will, gibt es sogar einen logback-loki-appender auf Github, der aber auch auf Java-Anwendungen abzielt, nicht auf Android.
Also habe ich Abhängigkeit installiert und Fehler behoben, indem unter anderem eine transitive Abhängigkeit entfernt werden mussten. Sonst kommen die üblichen „duplicate class found“-Fehler.
implementation 'org.slf4j:slf4j-api:2.0.7'
implementation 'com.github.tony19:logback-android:3.0.0'
implementation('com.github.loki4j:loki-logback-appender:1.5.2') {
exclude group: 'ch.qos.logback'
}
Sehr schön, es die App baut wieder und wir können an die Integration gehen.
Loki-Logback-Appender und Android-Logback verbinden
Als erstes habe ich versucht, den Appender genau so zu konfigurieren, wie Logcat und die üblichen Konfigurationen für Push-URL etc. zu setzen. Dies funktioniert auch wunderbar und die App kann gebaut und installiert werden.
Leider rennt man sehr schnell in einen Runtime-Error, denn – wer hätte es gedacht – loki-logback-appender nutzt java.net.http, was es bei Android nicht gibt. Auch den alternativen ApacheHttpSender habe ich nicht zum Laufen bekommen. Android liefert die Library zwar als Legacy-Library aus, aber dort fehlten 2 Abhängigkeiten, immer zum Absturz führten.
Um nicht mehr Zeit zu verschwenden, entschied ich mich, einen eigenen HTTP-Sender zu implementieren und diesen zu Konfigurieren. Loki-Logback-Appender hatte dafür zum Glück alle Interfaces und setter vorbereitet, sodass ich keinen Fork benötigte.
Für die Implementierung hab ich mich für OkHttp entschieden – eine sehr verbreitete Bibliothek für HTTP-Calls unter Android.
Für die Implementierung hab ich mich stark an den Klassen für die ApacheHttpSender-Implementierung orientiert und nur das nötigste umgebaut.
package droidsolutions.mdm.app.general.utils.errors.loki;
import com.github.loki4j.client.http.HttpConfig;
import com.github.loki4j.client.http.Loki4jHttpClient;
import com.github.loki4j.client.pipeline.PipelineConfig;
import com.github.loki4j.logback.AbstractHttpSender;
import java.util.function.Function;
/**
* A configurator for {@link com.github.loki4j.client.http.ApacheHttpClient ApacheHttpClient}
*/
public class OkHttpHttpSender extends AbstractHttpSender {
/**
* Maximum number of HTTP connections setting for HttpClient
*/
private int maxConnections = 1;
/**
* A duration of time which the connection can be safely kept
* idle for later reuse. This value should not be greater than
* server.http-idle-timeout in your Loki config
*/
private long connectionKeepAliveMs = 120_000;
public void setMaxConnections(int maxConnections) {
this.maxConnections = maxConnections;
}
public void setConnectionKeepAliveMs(long connectionKeepAliveMs) {
this.connectionKeepAliveMs = connectionKeepAliveMs;
}
@Override
public Function<HttpConfig, Loki4jHttpClient> getHttpClientFactory() {
return Loki4jOkHttpClient::new;
}
@Override
public HttpConfig.Builder getConfig() {
return PipelineConfig
.apache(maxConnections, connectionKeepAliveMs)
.fill(this::fillHttpConfig);
}
}
package droidsolutions.mdm.app.general.utils.errors.loki;
import static java.sql.DriverManager.println;
import com.github.loki4j.client.http.HttpConfig;
import com.github.loki4j.client.http.HttpHeader;
import com.github.loki4j.client.http.Loki4jHttpClient;
import com.github.loki4j.client.http.LokiResponse;
import java.nio.ByteBuffer;
import java.nio.charset.StandardCharsets;
import java.util.function.Supplier;
import okhttp3.MediaType;
import okhttp3.OkHttpClient;
import okhttp3.Request;
import okhttp3.RequestBody;
import okhttp3.Response;
public final class Loki4jOkHttpClient implements Loki4jHttpClient {
private final HttpConfig conf;
private final okhttp3.OkHttpClient client;
private final Supplier<Request.Builder> requestBuilder;
public Loki4jOkHttpClient(HttpConfig conf) {
this.conf = conf;
client = new OkHttpClient();
requestBuilder = () -> {
Request.Builder requestBuilder = new Request.Builder()
.url(conf.pushUrl)
.addHeader(HttpHeader.CONTENT_TYPE, conf.contentType);
conf.tenantId.ifPresent(tenant -> requestBuilder.addHeader(HttpHeader.X_SCOPE_ORGID, tenant));
conf.basicAuthToken().ifPresent(token -> requestBuilder.addHeader(HttpHeader.AUTHORIZATION, "Basic " + token));
return requestBuilder;
};
}
@Override
public void close() throws Exception {
//client.;
//noop
}
@Override
public LokiResponse send(ByteBuffer batch) throws Exception {
Request.Builder builder = requestBuilder.get();
byte[] bodyBuffer = new byte[batch.remaining()];
batch.get(bodyBuffer, 0, bodyBuffer.length);
println(new String(bodyBuffer, StandardCharsets.UTF_8));
RequestBody body = RequestBody.create(MediaType.parse( conf.contentType), bodyBuffer);
builder.post(body);
Request request = builder.build();
try (Response response = client.newCall(request).execute()) {
assert response.body() != null;
String respBody = response.body().string();
println(
"Response code: " + response.code() + "\n" +
"Response body: " + respBody
);
return new LokiResponse(
response.code(),
respBody
);
}
}
@Override
public HttpConfig getConfig() {
return conf;
}
}
// setup LokiAppender
AbstractHttpSender.BasicAuth auth = new AbstractHttpSender.BasicAuth();
auth.setUsername("-username-");
auth.setPassword("-password-");
OkHttpHttpSender lokiSender = new OkHttpHttpSender();
lokiSender.setUrl("http://loki.local:3100/loki/api/v1/push");
lokiSender.setAuth(auth);
AbstractLoki4jEncoder.LabelCfg labelCfg = new AbstractLoki4jEncoder.LabelCfg();
labelCfg.setPattern("level=%level,hw_id="+deviceId);
LokiJsonEncoder lokiEncoder = new LokiJsonEncoder();
lokiEncoder.setContext(lc);
lokiEncoder.setLabel(labelCfg);
Loki4jAppender lokiAppender = new Loki4jAppender();
lokiAppender.setContext(lc);
lokiAppender.setHttp(lokiSender);
lokiAppender.setFormat(lokiEncoder);
lokiAppender.setVerbose(false);
lokiAppender.start();
// ...
root.addAppender(lokiAppender);
Alles konfiguriert, und schon erhalte kann ich die Logs im Grafana sehen! Großartig.
Jetzt noch die bisherigen Log.d()/Log.i()/Log.d() Statements durch den neuen Logger ersetzen und alles testen.
Lokaler Test und Test auf einem Beta-Gerät beim Kunden
Nachdem die ich die Änderungen implementiert, einige Bugs behoben und Logs noch etwas spezifiziert habe, wurde eine Produktivversion per Gitlab-CI gebaut und auf dem lokalen Testgerät mehrere Stunden ausgeführt. Dabei wollte ich vor Allem vermeiden, dass irgendetwas nach einigen Stunden die MDM-App zum Absturz bringt. Aber alles lief gut und auch die Ressourcenverbräuche haben sich nicht negativ entwickelt.
Nun wird es Zeit, die App remote auszuführen und mir Logs aus 500km Entfernung zuschicken zu lassen.
Also die Produktivversion im MDM als neue Ziel-Version angegeben und gehofft…
2 Minuten später sehe ich die ersten Logs im Grafana auftauchen! Yeay! Und was sehe ich?
- download started…
- download finished with status -1 (failed)
- retrying…
Gut, die App kann also einfach nicht heruntergeladen werden. Das bestätigt meine Netzwerk-Vermutung und nun muss ich nur noch herausfinden, wie ich das umgehe oder was das Problem ist.
Finale
Obwohl das Problem sich letztlich von selbst gelöst hat, hat uns diese Erfahrung wertvolle Erkenntnisse gebracht. Mit dem neuen Remote-Logging-Setup sind wir nun besser gerüstet, um ähnliche Probleme in Zukunft schneller und effizienter zu diagnostizieren und zu beheben. Die nächsten Schritte umfassen weitere Tests und Optimierungen, um das System noch robuster zu machen.