Skip to content

Commit

Permalink
webview: Better code for logging inbound events to Sentry.
Browse files Browse the repository at this point in the history
See 523b307 (reverted in a recent commit) for an earlier attempt
at this. It was done quickly to debug a problem with minimal delay;
this is the better-organized version of it, informed by Greg's
suggestions [1].

[1]: zulip#4180 (comment)
  • Loading branch information
chrisbobbe committed Jul 21, 2020
1 parent 0dc6f5d commit 35de7d2
Show file tree
Hide file tree
Showing 3 changed files with 348 additions and 0 deletions.
159 changes: 159 additions & 0 deletions src/webview/js/InboundEventLogger.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,159 @@
/* @flow strict-local */
import type {
WebViewUpdateEvent as WebViewInboundEvent,
WebViewUpdateEventContent as WebViewInboundEventContent,
WebViewUpdateEventFetching as WebViewInboundEventFetching,
WebViewUpdateEventTyping as WebViewInboundEventTyping,
WebViewUpdateEventReady as WebViewInboundEventReady,
WebViewUpdateEventMessagesRead as WebViewInboundEventMessagesRead,
} from '../webViewHandleUpdates';
import type { JSONable } from '../../utils/jsonable';
import sendMessage from './sendMessage';
import { ensureUnreachable } from '../../types';

// TODO: Make exact (see note in jsonable.js).
type Scrub<E: WebViewInboundEvent> = { [key: $Keys<E>]: JSONable };

type ScrubbedInboundEvent =
| Scrub<WebViewInboundEventContent>
| Scrub<WebViewInboundEventFetching>
| Scrub<WebViewInboundEventTyping>
| Scrub<WebViewInboundEventReady>
| Scrub<WebViewInboundEventMessagesRead>;

type ScrubbedInboundEventItem = {|
timestamp: number,
type: 'inbound',
scrubbedEvent: ScrubbedInboundEvent,
|};

/**
* Grab interesting but not privacy-sensitive message-loading state.
*
* Takes the "content" from an inbound WebView event, an HTML string,
* and returns the opening div#message-loading tag, so we know whether
* it's visible.
*/
const placeholdersDivTagFromContent = (content: string): string | null => {
const match = new RegExp('<div id="message-loading" class="(?:hidden)?">').exec(content);
return match !== null ? match[0] : null;
};

export default class InboundEventLogger {
_captureStartTime: number | void;
_captureEndTime: number | void;
_isCapturing: boolean;
_capturedInboundEventItems: ScrubbedInboundEventItem[];

/**
* Minimally transform an inbound event to remove sensitive data.
*/
static scrubInboundEvent(event: WebViewInboundEvent): ScrubbedInboundEvent {
// Don't spread the event (e.g., `...event`); instead, rebuild it.
// That way, a new property, when added, won't automatically be
// sent to Sentry un-scrubbed.
switch (event.type) {
case 'content': {
return {
type: event.type,
scrollMessageId: event.scrollMessageId,
auth: 'redacted',
content: placeholdersDivTagFromContent(event.content),
updateStrategy: event.updateStrategy,
};
}
case 'fetching': {
return {
type: event.type,
showMessagePlaceholders: event.showMessagePlaceholders,
fetchingOlder: event.fetchingOlder,
fetchingNewer: event.fetchingNewer,
};
}
case 'typing': {
return {
type: event.type,
// Empty if no one is typing; otherwise, has avatar URLs.
content: event.content !== '',
};
}
case 'ready': {
return {
type: event.type,
};
}
case 'read': {
return {
type: event.type,
messageIds: event.messageIds,
};
}
default: {
ensureUnreachable(event);
return {
type: event.type,
};
}
}
}

constructor() {
this._isCapturing = false;
this._capturedInboundEventItems = [];
}

startCapturing() {
if (this._isCapturing) {
throw new Error('InboundEventLogger: Tried to call startCapturing while already capturing.');
} else if (this._capturedInboundEventItems.length > 0 || this._captureEndTime !== undefined) {
throw new Error('InboundEventLogger: Tried to call startCapturing before resetting.');
}
this._isCapturing = true;
this._captureStartTime = Date.now();
}

stopCapturing() {
if (!this._isCapturing) {
throw new Error('InboundEventLogger: Tried to call stopCapturing while not capturing.');
}
this._isCapturing = false;
this._captureEndTime = Date.now();
}

send() {
if (this._isCapturing) {
throw new Error('InboundEventLogger: Tried to send captured events while still capturing.');
}
sendMessage({
type: 'warn',
details: {
startTime: this._captureStartTime ?? null,
endTime: this._captureEndTime ?? null,
inboundEventItems: this._capturedInboundEventItems,
},
});
}

reset() {
this._captureStartTime = undefined;
this._captureEndTime = undefined;
this._capturedInboundEventItems = [];
this._isCapturing = false;
}

maybeCaptureInboundEvent(event: WebViewInboundEvent) {
if (this._isCapturing) {
const item = {
type: 'inbound',
timestamp: Date.now(),
// Scrubbing up front, rather than just before sending, means
// it might be a waste of work -- we may never send. But it's
// not a *ton* of work, and it's currently the case that
// scrubbed events are much lighter than unscrubbed ones
// (unscrubbed events can have very long `content` strings).
scrubbedEvent: InboundEventLogger.scrubInboundEvent(event),
};
this._capturedInboundEventItems.push(item);
}
}
}
173 changes: 173 additions & 0 deletions src/webview/js/generatedEs3.js
Original file line number Diff line number Diff line change
Expand Up @@ -46,10 +46,169 @@ var compiledWebviewJs = (function (exports) {
});
};
function _classCallCheck(instance, Constructor) {
if (!(instance instanceof Constructor)) {
throw new TypeError("Cannot call a class as a function");
}
}
function _defineProperties(target, props) {
for (var i = 0; i < props.length; i++) {
var descriptor = props[i];
descriptor.enumerable = descriptor.enumerable || false;
descriptor.configurable = true;
if ("value" in descriptor) descriptor.writable = true;
Object.defineProperty(target, descriptor.key, descriptor);
}
}
function _createClass(Constructor, protoProps, staticProps) {
if (protoProps) _defineProperties(Constructor.prototype, protoProps);
if (staticProps) _defineProperties(Constructor, staticProps);
return Constructor;
}
var sendMessage = (function (msg) {
window.ReactNativeWebView.postMessage(JSON.stringify(msg));
});
var placeholdersDivTagFromContent = function placeholdersDivTagFromContent(content) {
var match = new RegExp('<div id="message-loading" class="(?:hidden)?">').exec(content);
return match !== null ? match[0] : null;
};
var InboundEventLogger = function () {
_createClass(InboundEventLogger, null, [{
key: "scrubInboundEvent",
value: function scrubInboundEvent(event) {
switch (event.type) {
case 'content':
{
return {
type: event.type,
scrollMessageId: event.scrollMessageId,
auth: 'redacted',
content: placeholdersDivTagFromContent(event.content),
updateStrategy: event.updateStrategy
};
}
case 'fetching':
{
return {
type: event.type,
showMessagePlaceholders: event.showMessagePlaceholders,
fetchingOlder: event.fetchingOlder,
fetchingNewer: event.fetchingNewer
};
}
case 'typing':
{
return {
type: event.type,
content: event.content !== ''
};
}
case 'ready':
{
return {
type: event.type
};
}
case 'read':
{
return {
type: event.type,
messageIds: event.messageIds
};
}
default:
{
return {
type: event.type
};
}
}
}
}]);
function InboundEventLogger() {
_classCallCheck(this, InboundEventLogger);
this._isCapturing = false;
this._capturedInboundEventItems = [];
}
_createClass(InboundEventLogger, [{
key: "startCapturing",
value: function startCapturing() {
if (this._isCapturing) {
throw new Error('InboundEventLogger: Tried to call startCapturing while already capturing.');
} else if (this._capturedInboundEventItems.length > 0 || this._captureEndTime !== undefined) {
throw new Error('InboundEventLogger: Tried to call startCapturing before resetting.');
}
this._isCapturing = true;
this._captureStartTime = Date.now();
}
}, {
key: "stopCapturing",
value: function stopCapturing() {
if (!this._isCapturing) {
throw new Error('InboundEventLogger: Tried to call stopCapturing while not capturing.');
}
this._isCapturing = false;
this._captureEndTime = Date.now();
}
}, {
key: "send",
value: function send() {
var _this$_captureStartTi, _this$_captureEndTime;
if (this._isCapturing) {
throw new Error('InboundEventLogger: Tried to send captured events while still capturing.');
}
sendMessage({
type: 'warn',
details: {
startTime: (_this$_captureStartTi = this._captureStartTime) !== null && _this$_captureStartTi !== void 0 ? _this$_captureStartTi : null,
endTime: (_this$_captureEndTime = this._captureEndTime) !== null && _this$_captureEndTime !== void 0 ? _this$_captureEndTime : null,
inboundEventItems: this._capturedInboundEventItems
}
});
}
}, {
key: "reset",
value: function reset() {
this._captureStartTime = undefined;
this._captureEndTime = undefined;
this._capturedInboundEventItems = [];
this._isCapturing = false;
}
}, {
key: "maybeCaptureInboundEvent",
value: function maybeCaptureInboundEvent(event) {
if (this._isCapturing) {
var item = {
type: 'inbound',
timestamp: Date.now(),
scrubbedEvent: InboundEventLogger.scrubInboundEvent(event)
};
this._capturedInboundEventItems.push(item);
}
}
}]);
return InboundEventLogger;
}();
if (!Array.from) {
Array.from = function from(arr) {
return Array.prototype.slice.call(arr);
Expand Down Expand Up @@ -127,6 +286,19 @@ var compiledWebviewJs = (function (exports) {
return true;
};
var eventLogger = new InboundEventLogger();
eventLogger.startCapturing();
setTimeout(function () {
var placeholdersDiv = document.getElementById('message-loading');
eventLogger.stopCapturing();
if (placeholdersDiv && !placeholdersDiv.classList.contains('hidden')) {
eventLogger.send();
}
eventLogger.reset();
}, 10000);
var showHideElement = function showHideElement(elementId, show) {
var element = document.getElementById(elementId);
Expand Down Expand Up @@ -478,6 +650,7 @@ var compiledWebviewJs = (function (exports) {
var decodedData = decodeURIComponent(escape(window.atob(e.data)));
var updateEvents = JSON.parse(decodedData);
updateEvents.forEach(function (uevent) {
eventLogger.maybeCaptureInboundEvent(uevent);
eventUpdateHandlers[uevent.type](uevent);
});
scrollEventsDisabled = false;
Expand Down
16 changes: 16 additions & 0 deletions src/webview/js/js.js
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import type {
} from '../webViewHandleUpdates';

import rewriteImageUrls from './rewriteImageUrls';
import InboundEventLogger from './InboundEventLogger';
import sendMessage from './sendMessage';

/*
Expand Down Expand Up @@ -152,6 +153,20 @@ window.onerror = (message: string, source: string, line: number, column: number,
return true;
};

const eventLogger = new InboundEventLogger();
eventLogger.startCapturing();
// After 10 seconds, if the loading placeholders are *still* visible,
// we want to know all the inbound events that were received in that
// time (with sensitive info redacted, of course).
setTimeout(() => {
const placeholdersDiv = document.getElementById('message-loading');
eventLogger.stopCapturing();
if (placeholdersDiv && !placeholdersDiv.classList.contains('hidden')) {
eventLogger.send();
}
eventLogger.reset();
}, 10000);

const showHideElement = (elementId: string, show: boolean) => {
const element = document.getElementById(elementId);
if (element) {
Expand Down Expand Up @@ -603,6 +618,7 @@ const handleMessageEvent: MessageEventListener = e => {
const decodedData = decodeURIComponent(escape(window.atob(e.data)));
const updateEvents: WebViewUpdateEvent[] = JSON.parse(decodedData);
updateEvents.forEach((uevent: WebViewUpdateEvent) => {
eventLogger.maybeCaptureInboundEvent(uevent);
// $FlowFixMe
eventUpdateHandlers[uevent.type](uevent);
});
Expand Down

0 comments on commit 35de7d2

Please sign in to comment.