Merge remote-tracking branch 'ha-public/master' into wip-LatitudeReSetup-20230620wip-LatitudeReSetup-20230620

1 files changed, 252 insertions, 0 deletions

diff --git a/src/main/lua/paisa-logs/DigHoustonLogs.lua b/src/main/lua/paisa-logs/DigHoustonLogs.lua
new file mode 100644
index 0000000..92ef035
--- /dev/null
+++ b/src/main/lua/paisa-logs/DigHoustonLogs.lua
@@ -0,0 +1,252 @@
+#!/usr/bin/env lua
+--[====================================================================[
+
+  projDir='/c/path/to/proj/root'
+  export LUA_PATH="${projDir:?}/src/main/lua/paisa-logs/?.lua"
+  lua -W "${projDir:?}/src/main/lua/paisa-logs/DigHoustonLogs.lua"
+
+  ]====================================================================]
+
+local PaisaLogParser = require("PaisaLogParser")
+local normalizeIsoDateTime = require("PaisaLogParser").normalizeIsoDateTime
+local LOGDBG = function(msg)io.stderr:write(msg)end
+
+local main, onLogEntry, isWorthToPrint, loadFilters, initFilters
+
+
+function main()
+    local that = {
+        logPattern = "DATE STAGE SERVICE LEVEL FILE - MSG", -- Since 2021-09-24 on prod
+        printRaw = true,
+        filters = false,
+    }
+    loadFilters(that)
+    initFilters(that)
+    local parser = PaisaLogParser.newLogParser({
+        cls = that,
+        patternV1 = that.logPattern,
+        onLogEntry = onLogEntry,
+    })
+    parser:tryParseLogs();
+end
+
+
+function loadFilters( that )
+    assert(not that.filters)
+    that.filters = {
+        -- General: Append new rules AT END if not closely related to another one.
+
+--        { action = "drop", beforeDate = "2024-10-18 03:00:00.000", },
+--        { action = "drop", afterDate  = "2024-01-31 23:59:59.999", },
+
+        { action = "drop", level = "TRACE" },
+        { action = "drop", level = "DEBUG" },
+        { action = "drop", level = "INFO" },
+        --{ action = "drop", level = "WARN" },
+
+        -- FUCK those damn nonsense spam logs!!!
+        { action = "drop", file = "Forwarder" },
+        { action = "drop", level = "ERROR", file = "HttpClientRequestImpl" },
+        { action = "drop", level = "ERROR", file = "BisectClient" },
+
+        -- Seen:  2024-04-10 prod.
+        -- Reported 20240410 via "https://github.com/swisspost/vertx-redisques/pull/166"
+        { action = "drop", file = "RedisQues", level = "WARN",
+            msgPattern = "^Registration for queue .- has changed to .-$", },
+
+        -- Reported:  SDCISA-13717
+        -- Seen:  2024-01-05 prod, 2023-10-18 prod
+        {   action = "drop", file = "LocalHttpServerResponse", level = "ERROR",
+            msgPattern = "^non%-proper HttpServerResponse occured\r?\n"
+                .."java.lang.IllegalStateException:"
+                .." You must set the Content%-Length header to be the total size of the message body BEFORE sending any data if you are not using"
+                .." HTTP chunked encoding.", },
+
+        -- Reported:  <none>
+        -- Seen:  2024-01-05 prod, 2023-10-18 prod
+        { action = "drop", file = "ContextImpl", level = "ERROR",
+            msgPattern = "Unhandled exception\n"
+                .."java.lang.IllegalStateException: You must set the Content%-Length header to be the total size of the message body BEFORE sending"
+                .." any data if you are not using HTTP chunked encoding.", },
+
+        -- Seen: 2023-10-18
+        -- Happens all the time as gateleens error reporting is broken-by-desing.
+        { action = "drop", file = "Forwarder", level = "WARN",
+            msgPattern = "^..... ................................ Problem to request /from%-houston/[0-9]+/eagle/nsync/v1/push/trillian%-phonebooks"
+                .."%-affiliated%-planning%-area%-[0-9]+%-vehicles: io.netty.channel.ConnectTimeoutException: connection timed out:"
+                .." eddie[0-9]+.pnet.ch/[0-9]+:7012", },
+        -- Seen:  2023-10-18
+        -- Nearly same as above but on ERROR level instead.
+        { action = "drop", file = "Forwarder", level = "ERROR",
+            msgPattern = "^%%%w+ %x+ http://eddie%d+:7012/from.houston/%d+/eagle/nsync/v1/push/trillian.phonebooks.affiliated.planning.area.%d+.vehicles"
+                .." The timeout period of 30000ms has been exceeded while executing POST /from.houston/%d+/eagle/nsync/v1/push/"
+                .."trillian.phonebooks.affiliated.planning.area.%d+.vehicles for server eddie%d+:7012", },
+        -- Seen:  2023-10-18 prod
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+"
+            .." http://localhost:9089/houston/vehicles/%d+/vehicle/backup/v1/executions/%d+/backup.zip The timeout period of 30000ms has been exceeded"
+            .." while executing PUT /houston/vehicles/%d+/vehicle/backup/v1/executions/%d+/backup.zip for server localhost:9089", },
+        -- Seen:  2023-10-18 prod
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+"
+            .." http://localhost:9089/houston/vehicles/%d+/vehicle/backup/v1/executions/%d+/backup.zip Timeout$" },
+
+        -- Seen:  2024-04-10 prod, 2023-10-18 prod
+        { action = "drop", file = "ConnectionBase", level = "ERROR", msgEquals = "Connection reset by peer", },
+
+        -- Seen:  2024-04-10 prod, 2023-10-18 prod
+        { action = "drop", file = "EventBusBridgeImpl", level = "ERROR", msgEquals = "SockJSSocket exception\nio.vertx.core.VertxException: Connection was closed", },
+
+        -- Seen:  2024-04-10 prod, 2024-01-05 prod, 2023-10-18 prod
+        -- Reported:  TODO link existing issue here
+        { action = "drop", file = "HttpHeaderUtil", level = "ERROR",
+            msgPattern = "Keep%-Alive%} values do not match timeout=42 != timeout=120 for request /googleplex/.*", },
+
+        -- Seen:  2024-01-05 prod
+        -- Reported:  <unknown>
+        { action = "drop", file = "Utils", level = "ERROR",
+            msgPattern = "^Exception occurred\njava.lang.Exception: %(TIMEOUT,%-1%) Timed out after waiting 30000%(ms%) for a reply. address: __vertx.reply.%d+, repliedAddress: nsync%-[re]+gister%-sync",
+            stackPattern = "^"
+            .."%s-at org.swisspush.nsync.NSyncHandler.lambda.onPutClientSyncBody.%d+"
+            .."%(NSyncHandler.java:%d+%) ..nsync.-at io.vertx.core.impl.future.FutureImpl.%d+.onFailure%(FutureImpl.java:%d+%)"
+            ..".-"
+            .."Caused by: io.vertx.core.eventbus.ReplyException: Timed out after waiting 30000%(ms%) for a reply."
+            .." address: __vertx.reply.%d+, repliedAddress: nsync%-[re]+gister%-sync"
+            },
+
+        -- WELL_KNOWN: I guess happens when vehicle looses connection. Seen 2023-10-18 prod.
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+"
+            .." http://eddie%d+:7012/from.houston/%d+/eagle/vending/accounting/v1/users/%d+/years/%d+/months/%d%d/account Connection was closed$", },
+        -- WELL_KNOWN: I guess happens when vehicle looses connection. Seen 2023-10-18 prod.
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+"
+            .." http://eddie%d+:7012/from.houston/%d+/eagle/nsync/v1/push/trillian.phonebooks.affiliated.planning.area.%d+.vehicles Connection was closed$", },
+        -- Seen  2024-01-10 prod
+        -- WELL_KNOWN: I guess happens when vehicle looses connection. Seen 2023-10-18 prod.
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+"
+            .." http://eddie%d+:7012/from.houston/%d+/eagle/nsync/v1/query.index The timeout period of 30000ms has been exceeded while executing"
+            .." POST /from.houston/%d+/eagle/nsync/v1/query-index for server eddie%d+:7012$", },
+        -- WELL_KNOWN: I guess happens when vehicle looses connection. Seen 2023-10-18 prod.
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+"
+            .." http://eddie%d+:7012/from.houston/%d+/eagle/timetable/notification/v1/planningareas/%d+/notifications/%x+ Connection was closed$", },
+        -- WELL_KNOWN: I guess happens when vehicle looses connection. Seen 2023-10-18 prod.
+        { action = "drop", file = "Forwarder", level = "ERROR", msgPattern = "^%%%w+ %x+ http://eddie%d+:7012/from.houston/%d+/eagle/nsync/v1/push/trillian.phonebooks.affiliated.planning.area.%d+.vehicles Connection reset by peer$", },
+
+        -- Reported:  SDCISA-9574
+        -- TODO rm when resolved
+        -- Seen:  2021-09-17 2022-06-20, 2022-08-30 prod,
+        { action = "drop", file = "Utils", level = "ERROR",
+            msgPattern = "%(RECIPIENT_FAILURE,500%) Sync failed.\n{.+}", },
+
+        -- TODO analyze
+        -- Seen 2024-03-20 prod
+        { action = "drop", file = "ContextImpl", level = "ERROR",
+            msgPattern = "^Unhandled exception\njava.lang.IllegalStateException: Response head already sent", },
+
+        -- Seen:  2024-04-10 prod.
+        {   action = "drop", level = "ERROR", file = "HttpClientRequestImpl",
+            msgEquals = "Connection reset by peer\njava.io.IOException: Connection reset by peer",
+            stackPattern = "^"
+            .."%s-at sun.nio.ch.FileDispatcherImpl.read0%(.-\n"
+            .."%s-at sun.nio.ch.SocketDispatcher.read%(.-\n"
+            .."%s-at sun.nio.ch.IOUtil.readIntoNativeBuffer%(.-\n"
+            .."%s-at sun.nio.ch.IOUtil.read%(.-\n"
+            .."%s-at sun.nio.ch.IOUtil.read%(.-\n"
+            .."%s-at sun.nio.ch.SocketChannelImpl.read%(.-\n"
+            .."%s-at io.netty.buffer.PooledByteBuf.setBytes%(.-\n"
+            .."%s-at io.netty.buffer.AbstractByteBuf.writeBytes%(.-\n"
+            .."%s-at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes%(.-\n"
+            .."%s-at io.netty.channel.nio.AbstractNioByteChannel.NioByteUnsafe.read%(.-\n"
+            .."%s-at io.netty.channel.nio.NioEventLoop.processSelectedKey%(.-\n"
+            .."%s-at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized%(.-\n"
+            .."%s-at io.netty.channel.nio.NioEventLoop.processSelectedKeys%(.-\n"
+            .."%s-at io.netty.channel.nio.NioEventLoop.run%(.-\n"
+            .."%s-at io.netty.util.concurrent.SingleThreadEventExecutor.%d+.run%(.-\n"
+            .."%s-at io.netty.util.internal.ThreadExecutorMap.%d+.run%(.-\n"
+            .."%s-at io.netty.util.concurrent.FastThreadLocalRunnable.run%(.-\n"
+            .."%s-at java.lang.Thread.run%(.-", },
+
+        -- Seen:  2024-04-10 prod.
+        {   action = "drop", file = "ContextImpl", level = "ERROR",
+            msgEquals = "Unhandled exception\njava.lang.IllegalStateException: null",
+            stackPattern = "^"
+            ..".-io.vertx.-%.HttpClientResponseImpl.checkEnded%(.-\n"
+            ..".-io.vertx.-%.HttpClientResponseImpl.endHandler%(.-\n"
+            ..".-gateleen.routing.Forwarder.-\n", },
+
+        -- Seen:  2024-04-10 prod.
+        -- TODO get rid of this silly base class.
+        {   action = "drop", file = "ContextImpl", level = "ERROR",
+            msgEquals = "Unhandled exception\njava.lang.UnsupportedOperationException: Do override this method to mock expected behaviour.", },
+
+        -- Seen:  2024-04-10 prod.
+        -- TODO get rid of this silly base class.
+        {   action = "drop", file = "ContextImpl", level = "ERROR",
+            msgEquals = "Unhandled exception\njava.lang.UnsupportedOperationException: null", },
+
+    }
+end
+
+
+function initFilters( that )
+    for iF = 1, #(that.filters) do
+        local descr = that.filters[iF]
+        local beforeDate = descr.beforeDate and normalizeIsoDateTime(descr.beforeDate)
+        local afterDate = descr.afterDate and normalizeIsoDateTime(descr.afterDate)
+        local file, level, msgPattern, msgEquals = descr.file, descr.level, descr.msgPattern, descr.msgEquals
+        local rawPattern, stackPattern = descr.rawPattern, descr.stackPattern
+        local stackStartsWith = descr.stackStartsWith
+        local filter = { action = descr.action, matches = false, }
+        local hasAnyCondition = (beforeDate or afterDate or file or level or msgPattern or rawPattern or stackPattern or stackStartsWith);
+        if not hasAnyCondition then
+            filter.matches = function( that, log ) --[[LOGDBG("match unconditionally\n")]] return true end
+        else
+            filter.matches = function( that, log )
+                local match, mismatch = true, false
+                if not log.date then log:debugPrint() end
+                if level and level ~= log.level then --[[LOGDBG("level mismatch: \"".. level .."\" != \"".. log.level .."\"\n")]] return mismatch end
+                if file and file ~= log.file then --[[LOGDBG("file mismatch: \"".. file .."\" != \"".. log.file .."\"\n")]] return mismatch end
+                local logDate = normalizeIsoDateTime(log.date)
+                local isBeforeDate = (not beforeDate or logDate <  beforeDate);
+                local isAfterDate  = (not afterDate  or logDate >= afterDate);
+                if not isBeforeDate then --[[LOGDBG("not before: \"".. tostring(beforeDate) .."\", \"".. logDate .."\"\n")]] return mismatch end
+                if not isAfterDate  then --[[LOGDBG("not after:  \"".. tostring(afterDate) .."\", \"".. logDate .."\"\n")]] return mismatch end
+                if msgEquals and log.msg ~= msgEquals then return mismatch end
+                if stackStartsWith and log.stack and log.stack:sub(1, #stackStartsWith) ~= stackStartsWith then return mismatch end
+                if msgPattern and not log.msg:find(msgPattern) then --[[LOGDBG("match: msgPattern\n")]] return mismatch end
+                if stackPattern and log.stack and not log.stack:find(stackPattern) then return mismatch end
+                if rawPattern and not log.raw:find(rawPattern) then return mismatch end
+                --LOGDBG("DEFAULT match\n")
+                return match
+            end
+        end
+        that.filters[iF] = filter
+    end
+end
+
+
+function onLogEntry( log, that )
+    local isWorthIt = isWorthToPrint(that, log)
+    if isWorthIt then
+        if that.printRaw then
+            print(log.raw)
+        else
+            log:debugPrint()
+        end
+    end
+end
+
+
+function isWorthToPrint( that, log )
+    local pass, drop = true, false
+    for iF = 1, #(that.filters) do
+        local filter = that.filters[iF]
+        if filter.matches(that, log) then
+            if filter.action == "drop" then return drop end
+            if filter.action == "keep" then return pass end
+            error("Unknown filter.action: \"".. filter.action .."\"");
+        end
+    end
+    return pass
+end
+
+
+main()
+