Resource Optimization

[paulobreim]

I have a computer with good configuration where I am indexing a case with 35 cell phones and it has already been running for more than 100 hours and should still take another 100.
Looking at the task manager, I'm using 8% CPU and 30% memory. I have 3 SSDs (read, write and index) all with 0%. The biggest time spent on the IPED is AudioTranscription task at 97%, as expected.

I would like to know if I can start another case on this same machine.

[wladimirleite]

What audio transcription implementation are you using? (Vosk, Wav2Vec2 etc.)

[paulobreim]

I started installing some Java stuff and IPED died, probably Java had some anomaly because when I restarted IPED, it started to take up the entire CPU and the number of files processed in the audio transcription task accelerated a lot.
I'll keep an eye out to see if it happens again.

Tanks for help

[wladimirleite]

Hi @paulobreim! How is the processing going?
Thinking about this later, one hypothesis that I considered was that somehow Vosk entered in a loop or some race condition. It uses native code, so it may have shared resources outside the JVM. I never saw a similar situation, but in theory it is possible.
Not sure, but I think that there is no timeout control in the call to Vosk audio transcription.
If that was the case, some of the IPED workers could have been stuck in the same audio file.
So if it happens again, besides running jstack as @lfcnassif suggested, it would be interesting to scroll the processing window to the right, so the file names become visible, and see if after a few seconds it is changing to another file or not.

Not directly related to this, but when I made some visual changes in the processing window, I considered adding another narrow column, with the time spent so far in that item/task. So if some items are taking longer (or even stuck), that would be easier to spot.

[wladimirleite]

I think I managed to reproduce the situation described by @paulobreim, in which all workers are running AudioTranscriptTask, but CPU usage is low (and almost no I/O and no memory contention).

Processing a lot of OPUS audios (using Vosk), the process started using ~100% of CPU, which is the expected behavior.
After 40 minutes or so, the average CPU usage fell to ~50%.
Now, after 8 hours, it is around 20-25%.

There are no workers "frozen"/"trapped in a loop" as audio files keep changing after some time (I added the column that I mentioned before that makes it easier to spot how long each item has been in the current task).
So the conclusion is that some kind of internal lock/synchronized code is getting slower after processing a lot of audio files, and adding a timeout control won't help.
I will try to investigate a bit more, and see if I can find a solution (or at least a workaround).
It is not critical because it only happened when I processed a lot of audio files, so in most scenarios this "slow down" won't happen.

10 minutes

40 minutes

8 hours

[lfcnassif]

That's really weird, thanks @tc-wleite for dedicating time to reproduce. If you could take a thread dump with jstack, it may help to investigate, if the issue is in the java code side...

[paulobreim]

Very good.
Exactly the same behavior here. It starts at 100% and decreases.
After 4 hours it is at 25% CPU.
Since it now takes about 1 hour to get to where it was, if I restart, I don't know whether to restart or let it continue. I think I'll leave it to see where this CPU goes.

[lfcnassif]

Not sure, but I think that there is no timeout control in the call to Vosk audio transcription.

That's correct. Actually just the mplayer conversion has a timeout, the Vosk transcription itself no. When implementing, since Vosk receives raw WAV data, I thought it would be unlikely to enter in a loop inside Vosk, but @tc-wleite is right, it is possible in theory, and IPED multithreading might trigger race condition issues in Vosk, if they exist.

[paulobreim]

Hi @lfcnassif

There are 2 java.exe. Here is 2 jstack
jstack.zip

Tks

[lfcnassif]

There are 2 java.exe

Yes, one is the application loader, the other is the main application itself, thanks.

"main" #1 prio=5 os_prio=0 cpu=13477093.75ms elapsed=14894.02s tid=0x0000000002d7f800 nid=0x16bc runnable [0x0000000000bee000]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes([email protected]/Native Method)
at java.io.FileOutputStream.write([email protected]/Unknown Source)
at java.io.BufferedOutputStream.flushBuffer([email protected]/Unknown Source)
at java.io.BufferedOutputStream.write([email protected]/Unknown Source)
- locked <0x0000000745e7b5d8> (a java.io.BufferedOutputStream)
at java.io.ObjectOutputStream$BlockDataOutputStream.drain([email protected]/Unknown Source)
at java.io.ObjectOutputStream$BlockDataOutputStream.write([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeArray([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeObject0([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeObject([email protected]/Unknown Source)
at java.util.ArrayList.writeObject([email protected]/Unknown Source)
at jdk.internal.reflect.GeneratedMethodAccessor566.invoke([email protected]/Unknown Source)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke([email protected]/Unknown Source)
at java.lang.reflect.Method.invoke([email protected]/Unknown Source)
at java.io.ObjectStreamClass.invokeWriteObject([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeSerialData([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeOrdinaryObject([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeObject0([email protected]/Unknown Source)
at java.io.ObjectOutputStream.defaultWriteFields([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeSerialData([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeOrdinaryObject([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeObject0([email protected]/Unknown Source)
at java.io.ObjectOutputStream.writeObject([email protected]/Unknown Source)
at iped.engine.util.Util.writeObject(Util.java:287)
at iped.engine.data.Bookmarks.saveState(Bookmarks.java:436)
- locked <0x000000013daa3de8> (a iped.engine.data.Bookmarks)
at iped.engine.data.Bookmarks.saveState(Bookmarks.java:417)
at iped.engine.task.P2PBookmarker.createBookmarksForSharedFiles(P2PBookmarker.java:132)
at iped.engine.core.Manager.process(Manager.java:296)
at iped.app.processing.Main.startManager(Main.java:178)
at iped.app.processing.Main.execute(Main.java:240)
at iped.app.processing.Main.main(Main.java:308)

Seems it is taking too long to create bookmarks for files/medias shared by communication apps.

[paulobreim]

hmmm is that bookmark that says: probably shared on whatsapp?
It really makes sense.

[lfcnassif]

Probably, can be from another chat app too.

[paulobreim]

I finally finished processing.
there were 38 cell phones/tablets and 18 notebooks (but only a few folders of them)
Total of just over 50 million records.

Those 4 cell phones that gave OOM, did not give any problems when processed alone.

The only problem I think could be thought of is the last step when it takes a long time to create bookmarks for files/media shared by communication applications.
This happens due to the number of phones and reprocessing them one by one.
Although the default situation is to generate quickly, I think you could put IPEDConfig.txt to generate or not, and by default it would be true.

I intend to redo this entire test in a few days, in fact I already did the last reprocessing in the last version.

Thanks to you both.

[wladimirleite]

I created a separated issue (#1909) about the Vosk audio transcription slow down, as there are other topics in this discussion.

[paulobreim]

New interesting information.
After restarting, it didn't freeze but it gave me an out of memory and then I did the following:
enableExternalParsing = true
externalParsingMaxMem = 1024M
iped -Xms30G -Xmx30G --portable --continue.....
The .ufdr that gave the error before went through without any problems.
I also had the impression that it processed faster.
Below is the screen of processes per task, where half of them have CPU usage.

After some time, the next ufdr gave an out of memory with some messages in the console, and also some processes appearing in the task manager, which I believe should not be there. Look how interesting.

Can this fix #1910 be used now? If yes, how do I do this?
And what is your opinion on using --append parameter?

tks
Paulo

[wladimirleite]

Not a recommendation by any means, but what I do in my own cases is first try to process all evidences in a single command.
If there is any trouble, I add one by one using --append option. And --continue if there is still issues.

[lfcnassif]

Those messages on the Console are related to an imminent OOM situation. In the Actions section (next to Discussions section) you can find the last snapshot with the VOSK slowdown fix. It's fine to use --append, but if the evidences (disks) came from the same computer (or cellphone), --append can produce a little different results with a few modules depending on the order of evidences in the command line. For example, about WhatsApp processing, if the message database is in the first processed evidence (a cellphone) and if media files attached to chats are in the second processed evidence (a SD card for example) using --append, when the database is processed firstly, the medias in the second evidence wouldn't be available/found, so not linked to chats. Processing the SD card first then appending the main evidence would be a better processing order in this situation.

[paulobreim]

Well, it got to the point where it's giving OOM, but I don't know in which file.
So I'm splitting it one by one and running with --continue, since everyone has had most of it processed.

[lfcnassif]

I tried running 4.2-snapshot and although OCR is disabled, the log is showing this:
2023-10-01 16:16:43 [INFO] [app.processing.Main] Indexador e Processador de Evidências Digitais 4.2-snapshot
2023-10-01 16:16:43 [INFO] [engine.config.Configuration] Loading configuration from C:\iped-4.2-snapshot\iped-4.2-snapshot
Warning: Nashorn engine is planned to be removed from a future JDK release
ModuleNotFoundError: No module named 'numpy'
ModuleNotFoundError: No module named 'numpy'
ModuleNotFoundError: No module named 'numpy'
java.lang.RuntimeException: OCRConfig must be loaded before ParsingTaskConfig
at iped.engine.config.ParsingTaskConfig.processProperties(ParsingTaskConfig.java:65)
at iped.engine.config.AbstractTaskPropertiesConfig.processTaskConfig(AbstractTaskPropertiesConfig.java:29)
at iped.engine.config.AbstractTaskConfig.processConfig(AbstractTaskConfig.java:42)
at iped.configuration.Configurable.processConfigs(Configurable.java:40)
at iped.engine.config.ConfigurationManager.loadConfig(ConfigurationManager.java:63)
at iped.engine.config.ConfigurationManager.loadConfigs(ConfigurationManager.java:56)
at iped.engine.config.Configuration.loadConfigurables(Configuration.java:218)
at iped.app.processing.Main.main(Main.java:304)

@paulobreim just to let you know I just fixed this in 4.2-snapshot. It was being caused by conflicts between config files of different IPED versions.

[paulobreim]

Ahh thanks for the information.
Taking advantage, let me tell you something that I'm not sure would be some kind of adjustment to be made.
After I started processing file by file, in all cases, at the end of the process, the program took a reasonable amount of time in the task of checking messages that may have been shared. As I was testing a case with more than 40 images and needed to process some more, I decided to remove images that had already been finished from the folder. However, at a certain point, during this task, IPED complained that a file was missing, which was precisely the one I had already processed. This led me to conclude that the task of checking whether a message has been shared performs this check on all files rather than the single file it was processing. This would explain why this time is increasing more and more.
I don't know if this is really how it does it, but in my understanding, sharing would only have to be checked on the file that is being processed.
Does this make sense to you?

[lfcnassif]

Yes, it makes sense and the P2PBookmarker class checks for shared files in all processed evidences indeed, not just into the one being processed. This usually is very fast, but in your case it is being a bottle neck. It is possible to optimize it in the future, indeed.

[paulobreim]

I understand. I thought that in the WhatsApp database, it was recorded when a file was shared, which would make it much easier.
Thank you for the explanation.