[stats-collector] if any deserialization error encountered dump to error stream

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<EventLine>()
     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<EventLine>) {
         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<EventLine>, isValidSession: Boolean) {
+    open protected fun dumpSession(session: List<EventLine>, 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
     }
     
 }

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<String>()
-
-        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<List<String>, Int>? {
+        val items = mutableListOf<String>()
+        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<String>
 ) {
 
-    val isOk: Boolean
-      get() = unknownEventFields.isEmpty() || absentEventFields.isEmpty()
+    val isFailed: Boolean
+      get() = unknownEventFields.isNotEmpty() || absentEventFields.isNotEmpty()
 
 }

plugins/stats-collector/log-events/test/com/intellij/stats/events/completion/RealTextValidator.kt

@@ -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<com.intellij.stats.events.completion.EventLine>, 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++
-        }
-    }
-}

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<String, Boolean>()
+
+    override fun dumpSession(session: List<EventLine>, isValidSession: Boolean) {
+        val sessionUid = session.first().event.sessionUid
+        sessionsStatus[sessionUid] = isValidSession
+    }
+
+}

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"}
+

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)