[VB.net] log bestand parser optimaliseren

[Damic]

Mijn vraag
ik heb een stuk code en dat gaat door een log bestand en doet per lijn checks (indexof) of iets op die lijn staat of niet.

Nu heb ik gemerkt met hele grote logs (>100.000 lijnen) dat het langer en langer duurt om daar door te gaan en ik heb ook gemerkt dat de thread dat er aan werkt wat verspringt door naar taakbeheer te zien.

Relevante software en hardware die ik gebruik
VS 2022 Community

Wat ik al gevonden of geprobeerd heb
Heb al 2 stukken van de code dat dan behandeld word gewijzigd zodoende dat ze op hun eigen tempo kunnen worden afgewerkt maar de rest van het stuk code weet ik niet hoe ik dat moet doen, vermits de lijnen in volgorde moeten blijven staan. Iemand een idee wat ik daarmee kan doen.

Het code stuk dat door de vele lijnen gaat:

Visual Basic:

Try
    Dim Var As Long
    For s As Integer = 0 To LogFileContents.Length - 1
        If LogFileContents(s).Length <= 10 Then Continue For
#Region "Total su todo day"
        If LogFileContents(s).IndexOf(BuffIn) > -1 Then
            Var = Get_Stats_Units(LogFileContents(s - 1))
            If Var > CLng(sParse(29)) Then sParse(29) = Var
            GoTo add_line
        End If
#End Region
#Region "read cpu :)"
        If LogFileContents(s).IndexOf("Automatic processor") > -1 AndAlso LogFileContents(s).IndexOf("did not") = -1 AndAlso LogFileContents(s).IndexOf("tag:") = -1 Then
            iStart = LogFileContents(s).IndexOf("Automatic processor") + 26
            sParse(7) = LogFileContents(s).Substring(iStart, LogFileContents(s).IndexOf(" processor") - iStart) '-cpu/gpu info :)
            GoTo add_line
        End If
#End Region
#Region "read flushed wu's + stats units >> sparse(23)"
        If LogFileContents(s).IndexOf("Sent") > -1 AndAlso LogFileContents(s).IndexOf(ProjectType) > -1 AndAlso LogFileContents(s).IndexOf("packets") > -1 Then
            '-check if its not already added
            sTmp = LogFileContents(s).Substring(1, 19)
            If Array.IndexOf(aFlush, sTmp) = -1 Then
                ReDim Preserve aFlush(aFlush.Length)
                aFlush(aFlush.Length - 1) = sTmp
                sParse(23) = CLng(sParse(23)) + Get_Stats_Units(LogFileContents(s))
                sParse(14) = CLng(sParse(14)) + Get_Packets(LogFileContents(s))
                sParse(15) += 1
            End If
            GoTo add_line
        End If
#End Region
#Region "read fetched wu's + stats units >> sparse(24)"
        If LogFileContents(s).IndexOf("Retrieved") > -1 AndAlso LogFileContents(s).IndexOf(ProjectType) > -1 AndAlso LogFileContents(s).IndexOf("packets") > -1 Then
            '-check if its not already added
            sTmp = LogFileContents(s).Substring(1, 19)
            If Array.IndexOf(aFetch, sTmp) = -1 Then
                ReDim Preserve aFetch(aFetch.Length)
                aFetch(aFetch.Length - 1) = sTmp
                sParse(24) = CLng(sParse(24)) + Get_Stats_Units(LogFileContents(s))
                sParse(18) = CLng(sParse(18)) + Get_Packets(LogFileContents(s))
                sParse(19) += 1
            End If
            GoTo add_line
        End If
#End Region
        '-read cruncher(s)
        If LogFileContents(s).IndexOf("cruncher") > -1 AndAlso LogFileContents(s).IndexOf("Loading") = -1 Then
            sParse(16) = LogFileContents(s).Substring(LogFileContents(s).IndexOf("cruncher") - 2, 1)
            'regex maybe if sparse(16)>1
        End If
add_line:
        'Packet was from a different user/core/client cpu/os/build.
        '-fetched/flushed/restarted not add to lstbox
        If LogFileContents(s).IndexOf("The") = -1 AndAlso LogFileContents(s).IndexOf("Connected") = -1 AndAlso
                LogFileContents(s).IndexOf("Retrieved") = -1 AndAlso LogFileContents(s).IndexOf("*Break*") = -1 AndAlso
                LogFileContents(s).IndexOf("Shutdown") = -1 AndAlso LogFileContents(s).IndexOf("Paused") = -1 AndAlso
                LogFileContents(s).IndexOf("Running") = -1 AndAlso LogFileContents(s).IndexOf("cruncher") = -1 AndAlso
                LogFileContents(s).IndexOf("dnetc") = -1 AndAlso LogFileContents(s).IndexOf("Using") = -1 AndAlso
                LogFileContents(s).IndexOf("Sent") AndAlso LogFileContents(s).IndexOf("from a different") = -1 AndAlso LogFileContents(s).IndexOf("size_t") = -1 Then

            lstBox.Add(lstBox.LongCount, LogFileContents(s))
            '-this is prolly a new start for stage 2
            If LogFileContents(s).IndexOf("[") = 0 AndAlso LogFileContents(s).IndexOf(ProjectType) > -1 AndAlso (LogFileContents(s).IndexOf("Completed") > -1 Or LogFileContents(s).IndexOf("Saved") > -1) Then iFFLines = lstBox.LongCount - 1
        Else
            If LogFileContents(s).IndexOf("Shutdown") > -1 AndAlso Process.GetProcessesByName(dNet_Exe_Name).Count = 0 Then
                sParse(12) = 2
            ElseIf LogFileContents(s).IndexOf("Paused") > -1 AndAlso Process.GetProcessesByName(dNet_Exe_Name).Count > 0 Then
                sParse(12) = 1
            ElseIf LogFileContents(s).IndexOf("Running") > -1 Or LogFileContents(s).IndexOf("Restarting") > -1 Then
                sParse(12) = 0
            End If
        End If
    Next
Catch ex As Exception
    Debug.WriteLine(Date.Now & " modDnetcLogParser :: Parser :: First Stage #" & Err.Number & " " & ex.ToString)
    MsgBox(ex.Message, MsgBoxStyle.Exclamation, "modDnetcLogParser :: Parser :: First stage")
End Try

LogFileContents is een string array gevuld door en lstBox is een woordenboek

Visual Basic:

LogFileContents = File.ReadAllLines(Path.Combine(DNETC_Pathname, LogFile))
Dim lstBox As New Dictionary(Of Integer, String)

[ Voor 85% gewijzigd door RobIII op 27-12-2022 16:51 . Reden: Code leesbaarder gemaakt door indentation minder te maken ]

[RobIII]

Damic schreef op dinsdag 27 december 2022 @ 16:24:
Nu heb ik gemerkt met hele grote logs (>100.000 lijnen) dat het langer en langer duurt om daar door te gaan

Uh, ja, dat lijkt me vrij logisch; grotere bestanden = meer werk. De vraag is of je functie lineair is of bijv. exponentieel. Ik zie zo, op 't oog, geen reden om aan te nemen dat 't niet lineair zou zijn.

Maar je code is wel echt een enorme spaghetti. Waarom zet je delen ervan (bijvoorbeeld de "regions" die je nu hebt) niet in functies om 't geheel veel duidelijker te maken? En dan kun je ook meteen van die GOTO's af

Damic schreef op dinsdag 27 december 2022 @ 16:24:
Heb al 2 stukken van de code dat dan behandeld word gewijzigd zodoende dat ze op hun eigen tempo kunnen worden afgewerkt

Kun je aangeven wat/waar je dat doet of waar je het over hebt? Want hier kan ik geen kaas van maken.

Tot slot: i.p.v. overal if foo.IndexOf("bar") > -1 ... kun je gewoon if foo.Contains("bar")...) gebruiken; dat leest al zoveel prettiger en doet (intern) exact hetzelfde.

[ Voor 37% gewijzigd door RobIII op 27-12-2022 17:04 ]

[Damic]

Ja goto's zijn oud en ik zag niet direct hoe functies kunnen helpen, maar na even de code in kleur te hebben bekeken zien ik het volgens mij wel.

Elke goto kan naar de eind functie wijzen, maarja dan moet het nog altijd in volgorde blijven.

Zo ziet een deel van het log eruit

code:

[Dec 26 23:01:21 UTC] RC5-72: Completed 2C:6914FF00:00000000 (256.00 stats units)
                      0.00:00:48.29 - [22,765,629,910 keys/s]
[Dec 26 23:01:21 UTC] RC5-72: Loaded 2C:6821EC00:00000000:256*2^32
[Dec 26 23:01:21 UTC] RC5-72: Summary: 16681 packets (2195080.00 stats units)
                      5.00:31:11.79 - [21.73 Gkeys/s]
[Dec 26 23:01:21 UTC] RC5-72: 40 packets (9763.00 stats units) remain in
                      buff-in.r72
                      Projected ideal time to completion: 0.02:42:43.00
[Dec 26 23:01:21 UTC] RC5-72: 1118 packets (235611.00 stats units) are in
                      buff-out.r72
[Dec 26 23:02:10 UTC] RC5-72: Completed 2C:6821EC00:00000000 (256.00 stats units)
                      0.00:00:48.31 - [22,758,561,595 keys/s]
[Dec 26 23:02:10 UTC] RC5-72: Loaded 2C:6821ED0F:00000000:241*2^32
[Dec 26 23:02:10 UTC] RC5-72: Summary: 16682 packets (2195336.00 stats units)
                      5.00:32:00.11 - [21.73 Gkeys/s]
[Dec 26 23:02:10 UTC] RC5-72: 39 packets (9522.00 stats units) remain in
                      buff-in.r72
                      Projected ideal time to completion: 0.02:38:42.00
[Dec 26 23:02:10 UTC] RC5-72: 1119 packets (235867.00 stats units) are in
                      buff-out.r72

[RobIII]

Damic schreef op dinsdag 27 december 2022 @ 16:57:
Ja goto's zijn oud

Dus? Je kunt ze er toch gewoon uit refactoren?

Damic schreef op dinsdag 27 december 2022 @ 16:57:
Elke goto kan naar de eind functie wijzen, maarja dan moet het nog altijd in volgorde blijven.

Daarom is 't veel beter om deze functie op te splitsen een aantal kleinere functies; een functie die bijna 80 regels lang is (en dan zien we de rest eromheen nog niet dus potentieel nog veel langer) is zelden een goed idee of echt nodig.

Ik snap ook niet wat je bedoelt met "code in kleur bekeken hebben"?

Overigens, die add_line zal met 't toenemen van 't aantal items in de listbox ook steeds trager worden. Ik zou al eens beginnen met de functie zo refactoren dat je gewoon netjes elke regel die je wil toevoegen yield returned (hop, weg goto's als bonus) en je functie dus IEnumerable maakt. Daarna kun je je listbox in 1 klap vullen met AddRange. Ik heb geen idee of daar dé traagheid vandaan komt, maar allicht wel een deel ervan. Intern zal de listbox met regelmaat een resize van de interne list moeten doen om de extra items te accommoderen en dat zal naarmate 't aantal items groeit steeds langer duren. Ik heb geen idee hoeveel items er in de listbox komen en zolang 't er minder dan een paar tiental of paar honderd zijn zal 't wel meevallen. Bij honderden of duizenden ga je 't wel merken. Maar dan kun je je ook afvragen waarom je überhaupt zo veel items in een listbox zet en of dat de gebruiker wel ten goede komt. Ik zou dan toch eens overwegen of er geen betere manieren zijn. Een alternatief, als je er toch op staat vele duizenden items in je UI te dumpen, is je listbox vervangen door een listview en die virtualizen.

Hoe dan ook, je functie doet véél te veel (lezen, zoeken, dingen aan je UI toevoegen, iets met "sParse" doen (geen idee wat 't is / wat 't doet / waarom / waarvoor), etc. etc.). Los dat eerst op. Je variabele namen zijn overigens ook matig gekozen; zo is "sParse" niet duidelijk wat 't is, heb je een variable Var , een iterator s (ipv een gangbare i), klinkt LogFileContents(s) als een functie (waarom niet een variable CurrentLine ofzo maken?), gebruik je hungarian notation maar niet consequent (en volgens wordt 't zelfs in VB.Net al zeker een decennium, als het er geen twee zijn, afgeraden) en zo zijn er nog wel wat dingetjes.

[ Voor 92% gewijzigd door RobIII op 27-12-2022 17:29 ]

[Damic]

285 regels is die sub (inclusief commentaar) nu is dat wel nog met stage 2 en 3 in 1 sub. In een andere versie heb ik die er ook al uitgehaald en in hun eigen sub gestoken.

Anyway: ik snap nog altijd niet als je alles in aparte sub/functie steekt hoe je al de data terug achter mekaar krijgt vermits het de sub/functies op andere tijden klaar kunnen zijn. Ik denk hier dan al wel aan voor elke sub/functie een thread af te schieten of denk ik verkeerd?

Edit: je hebt een edit gemaakt, zal dat eerst eens bekijken

[ Voor 6% gewijzigd door Damic op 27-12-2022 17:32 ]

[RobIII]

Damic schreef op dinsdag 27 december 2022 @ 17:31:
Anyway: ik snap nog altijd niet als je alles in aparte sub/functie steekt hoe je al de data terug achter mekaar krijgt vermits het de sub/functies op andere tijden klaar kunnen zijn. Ik denk hier dan al wel aan voor elke sub/functie een thread af te schieten of denk ik verkeerd?

Ik snap hier echt niet wat je bedoelt? Je code in je topicstart nu is zo lineair als maar zijn kan (even los van de goto's ), hoezo "op andere tijden klaar zijn"? Hoezo voor elke sub/functie een thread afschieten?

[Damic]

Het program dat ik nu aan bezig ben is eind 2003 begonnen (VB6) en altijd uitgebreid en onderweg ergens omgezet naar VB.net en heb het nu terug opgepakt en ben het nu beter aan't maken. Dus de hungarian notation zit nog in vele delen van het programma en hier zit zowel de oude als de nieuwe door elkaar.

Ik snap ook niet wat je bedoelt met "code in kleur bekeken hebben"?

In visual studio zie je rapper alles omdat het in verschillende kleurtjes staat en daardoor beter te begrijpen is (volgens mij).

RobIII schreef op dinsdag 27 december 2022 @ 17:34:
[...]
Ik snap hier echt niet wat je bedoelt? Je code in je topicstart nu is zo lineair als maar zijn kan (even los van de goto's ), hoezo "op andere tijden klaar zijn"? Hoezo voor elke sub/functie een thread afschieten?

Dat is correct maar als ik de code kan optimaliseren dat het niet meer lineair moet zijn en dat ik het gewoon via multi threads kan doen is de parser hopelijk sneller klaar.

RobIII schreef op dinsdag 27 december 2022 @ 17:02:
[...]
Hoe dan ook, je functie doet véél te veel (lezen, zoeken, dingen aan je UI toevoegen, iets met "sParse" doen (geen idee wat 't is / wat 't doet / waarom / waarvoor), etc. etc.). Los dat eerst op. Je variabele namen zijn overigens ook matig gekozen; zo is "sParse" niet duidelijk wat 't is, heb je een variable Var , een iterator s (ipv een gangbare i), klinkt LogFileContents(s) als een functie (waarom niet een variable CurrentLine ofzo maken?), gebruik je hungarian notation maar niet consequent (en volgens wordt 't zelfs in VB.Net al zeker een decennium, als het er geen twee zijn, afgeraden) en zo zijn er nog wel wat dingetjes.

In principe zou deze sub geen UI taken mogen doen.

sParse is een vast array van 30 indexen waar op bepaalde plaatsen de juiste data zit en zal nog even moeten meegaan, de Var heb ik veranderd.
LogFileContents is het hele bestand ingelezen in een string array, in principe zou je elke lijn even kunnen inlezen in een CurrentLine, maar dit gaat ook.

De S-iterator was omdat ik al ergens in dat stuk een i-iterator had gebruikt maar blijkbaar heb ik die er terug al uitgesloopt.

Tot slot: i.p.v. overal if foo.IndexOf("bar") > -1 ... kun je gewoon if foo.Contains("bar")...) gebruiken; dat leest al zoveel prettiger en doet (intern) exact hetzelfde.

Dat is een goede

[RobIII]

Damic schreef op dinsdag 27 december 2022 @ 18:06:
In visual studio zie je rapper alles omdat het in verschillende kleurtjes staat en daardoor beter te begrijpen is (volgens mij).

Waar zat je eerst dan in te kijken? Notepad?

Damic schreef op dinsdag 27 december 2022 @ 18:06:
Dat is correct maar als ik de code kan optimaliseren dat het niet meer lineair moet zijn en dat ik het gewoon via multi threads kan doen is de parser hopelijk sneller klaar.

Ik snap niet waarom je denkt dat meerdere threads hier iets aan gaan helpen behalve de zaak compliceren. Ik verwacht dat je function I/O bound is (en zo niet, dan nog gaan meerdere threads hier waarschijnlijk weinig in gaan kunnen betekenen).

Damic schreef op dinsdag 27 december 2022 @ 18:06:
In principe zou deze sub geen UI taken mogen doen.

Maar doet dat dus wél Wat overigens ook een deel van de traagheid zal verklaren; je bent constant je UI aan 't updaten ipv dat je dit 1 keer doet (alle items in 1 batch erin vlammen) tijdens het doorspitten van je logfile.

Wacht... is dit iets dat 'realtime' mee loopt terwijl de logfile geschreven wordt? Lees je die logfile de godganse tijd steeds opnieuw helemaal in? Ik ben nu wel heel benieuwd hoe de rest van die 285 regels er uit ziet (nee, spaar je de moeite, ik wil ze hier niet alle 285 zien tenzij je 't weet te destilleren naar iets < 50 regels relevante(!) code).

[ Voor 7% gewijzigd door RobIII op 27-12-2022 18:15 ]

[Damic]

RobIII schreef op dinsdag 27 december 2022 @ 18:14:
[...]

Waar zat je eerst dan in te kijken? Notepad?


[...]

Ik snap niet waarom je denkt dat meerdere threads hier iets aan gaan helpen behalve de zaak compliceren. Ik verwacht dat je function I/O bound is (en zo niet, dan nog gaan meerdere threads hier waarschijnlijk weinig in gaan kunnen betekenen).


[...]

Maar doet dat dus wél Wat overigens ook een deel van de traagheid zal verklaren; je bent constant je UI aan 't updaten ipv dat je dit 1 keer doet (alle items in 1 batch erin vlammen) tijdens het doorspitten van je logfile.

Wacht... is dit iets dat 'realtime' mee loopt met je logfile? Lees je die logfile de godganse tijd steeds opnieuw helemaal in? Ik ben nu wel heel benieuwd hoe de rest van die 285 regels er uit ziet (nee, spaar je de moeite, ik wil ze hier niet alle 285 zien tenzij je 't weet te destilleren naar iets < 50 regels relevante(!) code).

Nee als je de code hier op het forum bekijkt tegenover VS.

UI zijn toch de zaken dat in je main thread lopen he zoals de forms en controls? Deze sub loopt al in een backgroundworker (aparte thread). Die lstbox is geen listbox maar een lokaal dictionary(of integer, string). Ja naamgeving ik weet het, die is slecht.

Nee niet realtime, maar kan ook geen index bij houden want het bestand kan veranderen als de cleanup wat heeft gevonden dat er niet moet instaan of het is een lopende log met een maximum aantal kB.

En nee ik gaan al die code niet posten anders is er weer een modje niet goed gezind

Zal al eens zien of ik die box kan veranderen.

Edit: heb een hoop code op de schup genomen en de dictionary() niet meer gebruikt en direct de LogFileContents gebruikt en een log bestand van 7.648.641 lijnen doet de parsen nu ongeveer 40 seconden over, ja dat is nog lang maar minder lang dan hoe ik het had gedaan

22:10:12:274 CLF read: 27/12/2022 22:10:12
22:10:32:295 The thread 0x69e4 has exited with code 0 (0x0).
22:10:34:790 The thread 0x59b0 has exited with code 0 (0x0).
22:10:35:290 The thread 0xe14 has exited with code 0 (0x0).
22:10:52:078 CLF Done: 27/12/2022 22:10:51

*Niet op de benaming letten

Ow en heb het log 479MB groot gemaakt geheugen gebruik is nu wat veel (1.3GB) maarja 1x naar een normaler grote logboek zakt het geheugengebruik terug naar +-20MB

[ Voor 17% gewijzigd door Damic op 27-12-2022 22:20 ]