From 2f37539d4db34892975e60199b6fa8e004287adf Mon Sep 17 00:00:00 2001 From: Yaroslav Lepenkin Date: Tue, 16 May 2017 11:52:04 +0300 Subject: [PATCH] [stats-collector] if any deserialization error encountered dump to error stream --- .../events/completion/EventStreamValidator.kt | 25 +++++-- .../events/completion/LogEventSerializer.kt | 33 ++++++--- .../events/completion/RealTextValidator.kt | 74 ------------------- .../stats/events/completion/ValidatorTest.kt | 72 ++++++++++++++++++ .../testResources/data/validation_data | 21 ++++++ .../stats/completion/CompletionLoggerImpl.kt | 1 + 6 files changed, 135 insertions(+), 91 deletions(-) delete mode 100644 plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/RealTextValidator.kt create mode 100644 plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/ValidatorTest.kt create mode 100644 plugins/stats-collector/log-events/testResources/data/validation_data diff --git a/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/EventStreamValidator.kt b/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/EventStreamValidator.kt index 80a000f19384..c8b7bc515065 100644 --- a/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/EventStreamValidator.kt +++ b/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/EventStreamValidator.kt @@ -29,16 +29,25 @@ open class SessionsInputSeparator(input: InputStream, var session = mutableListOf() var currentSessionUid = "" + var hasDeserializationErrors = false fun processInput() { var line: String? = inputReader.readLine() - + while (line != null) { - val event: LogEvent? = LogEventSerializer.fromString(line)?.event - //if there is any unknown or absent fields we should fail here + if (line.isEmpty()) { + line = inputReader.readLine() + continue + } + + val event = LogEventSerializer.fromString(line)?.let { + hasDeserializationErrors = hasDeserializationErrors || it.isFailed + it.event + } if (event == null) { handleNullEvent(line) + line = inputReader.readLine() continue } @@ -60,9 +69,12 @@ open class SessionsInputSeparator(input: InputStream, private fun processCompletionSession(session: List) { if (session.isEmpty()) return + if (hasDeserializationErrors) { + dumpSession(session, false) + return + } var isValidSession = false - val initial = session.first() if (initial.event is CompletionStartedEvent) { val state = CompletionValidationState(initial.event) @@ -70,10 +82,10 @@ open class SessionsInputSeparator(input: InputStream, isValidSession = state.isFinished && state.isValid } - onSessionProcessingFinished(session, isValidSession) + dumpSession(session, isValidSession) } - open protected fun onSessionProcessingFinished(session: List, isValidSession: Boolean) { + open protected fun dumpSession(session: List, isValidSession: Boolean) { val writer = if (isValidSession) outputWriter else errorWriter session.forEach { writer.write(it.line) @@ -92,6 +104,7 @@ open class SessionsInputSeparator(input: InputStream, private fun reset() { session.clear() currentSessionUid = "" + hasDeserializationErrors = false } } diff --git a/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/LogEventSerializer.kt b/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/LogEventSerializer.kt index 401d06aeeae5..f0a4b6cd2b10 100644 --- a/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/LogEventSerializer.kt +++ b/plugins/stats-collector/log-events/src/com/intellij/stats/events/completion/LogEventSerializer.kt @@ -61,15 +61,9 @@ object LogEventSerializer { fun fromString(line: String): DeserializedLogEvent? { - val items = mutableListOf() - - var start = -1 - for (i in 0..4) { - val nextSpace = line.indexOf('\t', start + 1) - val newItem = line.substring(start + 1, nextSpace) - items.add(newItem) - start = nextSpace - } + val pair = tabSeparatedValues(line) ?: return null + val items = pair.first + val start = pair.second val timestamp = items[0].toLong() val recorderId = items[1] @@ -93,6 +87,23 @@ object LogEventSerializer { return DeserializedLogEvent(event, result.unknownFields, result.absentFields) } + private fun tabSeparatedValues(line: String): Pair, Int>? { + val items = mutableListOf() + var start = -1 + try { + for (i in 0..4) { + val nextSpace = line.indexOf('\t', start + 1) + val newItem = line.substring(start + 1, nextSpace) + items.add(newItem) + start = nextSpace + } + return Pair(items, start) + } + catch (e: Exception) { + return null + } + } + } @@ -102,7 +113,7 @@ class DeserializedLogEvent( val absentEventFields: Set ) { - val isOk: Boolean - get() = unknownEventFields.isEmpty() || absentEventFields.isEmpty() + val isFailed: Boolean + get() = unknownEventFields.isNotEmpty() || absentEventFields.isNotEmpty() } \ No newline at end of file diff --git a/plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/RealTextValidator.kt b/plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/RealTextValidator.kt deleted file mode 100644 index a695f4d421c6..000000000000 --- a/plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/RealTextValidator.kt +++ /dev/null @@ -1,74 +0,0 @@ -package com.intellij.stats.events.completion - -import org.assertj.core.api.Assertions -import org.junit.Test - -class RealTextValidator { - - - @Test - fun test_NegativeIndexToErrChannel() { - val file = getFile("data/completion_data.txt") - val output = java.io.ByteArrayOutputStream() - val err = java.io.ByteArrayOutputStream() - val separator = com.intellij.stats.events.completion.SessionsInputSeparator(java.io.FileInputStream(file), output, err) - separator.processInput() - } - - private fun getFile(path: String): java.io.File { - return java.io.File(javaClass.classLoader.getResource(path).file) - } - - @Test - fun test0() { - val file = getFile("data/0") - val output = java.io.ByteArrayOutputStream() - val err = java.io.ByteArrayOutputStream() - val separator = com.intellij.stats.events.completion.SessionsInputSeparator(java.io.FileInputStream(file), output, err) - separator.processInput() - - Assertions.assertThat(err.size()).isEqualTo(0) - } - - @Test - fun testError0() { - val file = getFile("data/1") - val output = java.io.ByteArrayOutputStream() - val err = java.io.ByteArrayOutputStream() - val separator = com.intellij.stats.events.completion.SessionsInputSeparator(java.io.FileInputStream(file), output, err) - separator.processInput() - - Assertions.assertThat(err.size()).isEqualTo(0) - } - -} - - -class ErrorSessionDumper(input: java.io.InputStream, output: java.io.OutputStream, error: java.io.OutputStream) : com.intellij.stats.events.completion.SessionsInputSeparator(input, output, error) { - var totalFailedSessions = 0 - var totalSuccessSessions = 0 - private val dir = java.io.File("errors") - - init { - dir.mkdir() - } - - override fun onSessionProcessingFinished(session: List, isValidSession: Boolean) { - if (!isValidSession) { - val file = java.io.File(dir, totalFailedSessions.toString()) - if (file.exists()) { - file.delete() - } - file.createNewFile() - - session.forEach { - file.appendText(it.line) - file.appendText("\n") - } - totalFailedSessions++ - } - else { - totalSuccessSessions++ - } - } -} \ No newline at end of file diff --git a/plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/ValidatorTest.kt b/plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/ValidatorTest.kt new file mode 100644 index 000000000000..78611c5e27c0 --- /dev/null +++ b/plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/ValidatorTest.kt @@ -0,0 +1,72 @@ +package com.intellij.stats.events.completion + +import org.assertj.core.api.Assertions +import org.assertj.core.api.Assertions.assertThat +import org.junit.Test +import java.io.* + +class ValidatorTest { + + + @Test + fun test_NegativeIndexToErrChannel() { + val file = getFile("data/completion_data.txt") + val output = ByteArrayOutputStream() + val err = ByteArrayOutputStream() + val separator = SessionsInputSeparator(FileInputStream(file), output, err) + separator.processInput() + } + + private fun getFile(path: String): java.io.File { + return File(javaClass.classLoader.getResource(path).file) + } + + @Test + fun test0() { + val file = getFile("data/0") + val output = ByteArrayOutputStream() + val err = ByteArrayOutputStream() + val separator = SessionsInputSeparator(FileInputStream(file), output, err) + separator.processInput() + + Assertions.assertThat(err.size()).isEqualTo(0) + } + + @Test + fun testError0() { + val file = getFile("data/1") + val output = ByteArrayOutputStream() + val err = ByteArrayOutputStream() + val separator = SessionsInputSeparator(FileInputStream(file), output, err) + separator.processInput() + + Assertions.assertThat(err.size()).isEqualTo(0) + } + + @Test + fun testDataWithDeserializationErrors() { + val file = getFile("data/validation_data") + val output = ByteArrayOutputStream() + val err = ByteArrayOutputStream() + val separator = TestSessionSeparator(FileInputStream(file), output, err) + separator.processInput() + + val statuses = separator.sessionsStatus + assertThat(statuses["36de626e4ea1"]).isFalse() + assertThat(statuses["56de626e4ea1"]).isTrue() + assertThat(statuses["76de626e4ea1"]).isFalse() + } + +} + + +class TestSessionSeparator(input: InputStream, output: OutputStream, error: OutputStream) : SessionsInputSeparator(input, output, error) { + + val sessionsStatus = mutableMapOf() + + override fun dumpSession(session: List, isValidSession: Boolean) { + val sessionUid = session.first().event.sessionUid + sessionsStatus[sessionUid] = isValidSession + } + +} \ No newline at end of file diff --git a/plugins/stats-collector/log-events/testResources/data/validation_data b/plugins/stats-collector/log-events/testResources/data/validation_data new file mode 100644 index 000000000000..217da971300b --- /dev/null +++ b/plugins/stats-collector/log-events/testResources/data/validation_data @@ -0,0 +1,21 @@ +1470911998827 completion-stats cd1f9318cd9f 36de626e4ea1 COMPLETION_STARTED {"new_strange_field_exists": 1, "completionListLength":1,"performExperiment":true,"experimentVersion":2,"completionListIds":[0],"newCompletionListItems":[{"id":0,"length":4,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"false","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"-1133","kind":"localOrParameter","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d2, explicitlyImported\u003d300, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dtrue, sameDirectory\u003dtrue, sameLogicalRoot\u003dtrue, sameModule\u003d2, knownElement\u003d0, inResolveScope\u003dtrue, sdkOrLibrary\u003dfalse]","sameWords":"0","shorter":"0","grouping":"0"}}],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999199 completion-stats cd1f9318cd9f 36de626e4ea1 TYPE {"completionListIds":[1,2],"newCompletionListItems":[{"id":1,"length":14,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"true","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"29","kind":"expectedTypeMethod","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d0, explicitlyImported\u003d0, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dfalse, sameDirectory\u003dfalse, sameLogicalRoot\u003dfalse, sameModule\u003d0, knownElement\u003d2, inResolveScope\u003dtrue, sdkOrLibrary\u003dtrue]","sameWords":"0","shorter":"0","grouping":"0"}},{"id":2,"length":14,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"true","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"29","kind":"expectedTypeMethod","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d0, explicitlyImported\u003d0, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dfalse, sameDirectory\u003dfalse, sameLogicalRoot\u003dfalse, sameModule\u003d0, knownElement\u003d2, inResolveScope\u003dtrue, sdkOrLibrary\u003dtrue]","sameWords":"0","shorter":"0","grouping":"0"}}],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999357 completion-stats cd1f9318cd9f 36de626e4ea1 BACKSPACE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999420 completion-stats cd1f9318cd9f 36de626e4ea1 TYPE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999700 completion-stats cd1f9318cd9f 36de626e4ea1 TYPE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999700 completion-stats cd1f9318cd9f 36de626e4ea1 TYPED_SELECT {"selectedId":0,"userUid":"cd1f9318cd9f"} + +1470911998827 completion-stats cd1f9318cd9f 56de626e4ea1 COMPLETION_STARTED {"completionListLength":1,"performExperiment":true,"experimentVersion":2,"completionListIds":[0],"newCompletionListItems":[{"id":0,"length":4,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"false","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"-1133","kind":"localOrParameter","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d2, explicitlyImported\u003d300, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dtrue, sameDirectory\u003dtrue, sameLogicalRoot\u003dtrue, sameModule\u003d2, knownElement\u003d0, inResolveScope\u003dtrue, sdkOrLibrary\u003dfalse]","sameWords":"0","shorter":"0","grouping":"0"}}],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999199 completion-stats cd1f9318cd9f 56de626e4ea1 TYPE {"completionListIds":[1,2],"newCompletionListItems":[{"id":1,"length":14,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"true","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"29","kind":"expectedTypeMethod","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d0, explicitlyImported\u003d0, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dfalse, sameDirectory\u003dfalse, sameLogicalRoot\u003dfalse, sameModule\u003d0, knownElement\u003d2, inResolveScope\u003dtrue, sdkOrLibrary\u003dtrue]","sameWords":"0","shorter":"0","grouping":"0"}},{"id":2,"length":14,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"true","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"29","kind":"expectedTypeMethod","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d0, explicitlyImported\u003d0, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dfalse, sameDirectory\u003dfalse, sameLogicalRoot\u003dfalse, sameModule\u003d0, knownElement\u003d2, inResolveScope\u003dtrue, sdkOrLibrary\u003dtrue]","sameWords":"0","shorter":"0","grouping":"0"}}],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999357 completion-stats cd1f9318cd9f 56de626e4ea1 BACKSPACE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999420 completion-stats cd1f9318cd9f 56de626e4ea1 TYPE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999700 completion-stats cd1f9318cd9f 56de626e4ea1 TYPE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999700 completion-stats cd1f9318cd9f 56de626e4ea1 TYPED_SELECT {"selectedId":0,"userUid":"cd1f9318cd9f"} + +1470911998827 completion-stats cd1f9318cd9f 76de626e4ea1 COMPLETION_STARTED {"performExperiment":true,"experimentVersion":2,"completionListIds":[0],"newCompletionListItems":[{"id":0,"length":4,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"false","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"-1133","kind":"localOrParameter","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d2, explicitlyImported\u003d300, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dtrue, sameDirectory\u003dtrue, sameLogicalRoot\u003dtrue, sameModule\u003d2, knownElement\u003d0, inResolveScope\u003dtrue, sdkOrLibrary\u003dfalse]","sameWords":"0","shorter":"0","grouping":"0"}}],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999199 completion-stats cd1f9318cd9f 76de626e4ea1 TYPE {"completionListIds":[1,2],"newCompletionListItems":[{"id":1,"length":14,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"true","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"29","kind":"expectedTypeMethod","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d0, explicitlyImported\u003d0, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dfalse, sameDirectory\u003dfalse, sameLogicalRoot\u003dfalse, sameModule\u003d0, knownElement\u003d2, inResolveScope\u003dtrue, sdkOrLibrary\u003dtrue]","sameWords":"0","shorter":"0","grouping":"0"}},{"id":2,"length":14,"relevance":{"frozen":"true","sorter":"1","liftShorterClasses":"false","templates":"false","middleMatching":"true","liftShorter":"false","priority":"0.0","methodsChains":"00_0_2147483647","com.jetbrains.python.codeInsight.completion.PythonCompletionWeigher@5731acb0":"0","stats":"0","prefix":"29","kind":"expectedTypeMethod","expectedType":"expected","recursion":"normal","nameEnd":"0","nonGeneric":"0","accessible":"NORMAL","simple":"0","explicitProximity":"0","proximity":"[referenceList\u003dunknown, samePsiMember\u003d0, explicitlyImported\u003d0, javaInheritance\u003dnull, groovyReferenceListWeigher\u003dunknown, openedInEditor\u003dfalse, sameDirectory\u003dfalse, sameLogicalRoot\u003dfalse, sameModule\u003d0, knownElement\u003d2, inResolveScope\u003dtrue, sdkOrLibrary\u003dtrue]","sameWords":"0","shorter":"0","grouping":"0"}}],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999357 completion-stats cd1f9318cd9f 76de626e4ea1 BACKSPACE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999420 completion-stats cd1f9318cd9f 76de626e4ea1 TYPE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999700 completion-stats cd1f9318cd9f 76de626e4ea1 TYPE {"completionListIds":[0],"newCompletionListItems":[],"currentPosition":0,"userUid":"cd1f9318cd9f"} +1470911999700 completion-stats cd1f9318cd9f 76de626e4ea1 TYPED_SELECT {"selectedId":0,"userUid":"cd1f9318cd9f"} + diff --git a/plugins/stats-collector/src/com/intellij/stats/completion/CompletionLoggerImpl.kt b/plugins/stats-collector/src/com/intellij/stats/completion/CompletionLoggerImpl.kt index d6e9e4783a9a..0e9c1cd15b09 100644 --- a/plugins/stats-collector/src/com/intellij/stats/completion/CompletionLoggerImpl.kt +++ b/plugins/stats-collector/src/com/intellij/stats/completion/CompletionLoggerImpl.kt @@ -60,6 +60,7 @@ class CompletionFileLogger(private val installationUID: String, return elementToId[itemString] } + //sout here to debug private fun logEvent(event: LogEvent) { val line = LogEventSerializer.toString(event) logFileManager.println(line)