Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

What makes loading a javacpp library relatively slow on Android? #287

Closed
fhucho opened this issue Mar 4, 2019 · 15 comments
Closed

What makes loading a javacpp library relatively slow on Android? #287

fhucho opened this issue Mar 4, 2019 · 15 comments

Comments

@fhucho
Copy link

fhucho commented Mar 4, 2019

After converting to javacpp, the System.loadLibrary() call takes 30 to 200 ms. It's an Android project with a simple single-function native library at this point. Without javacpp, the native library loads in just a few ms. What is happening during the load that takes so long, is there a way to make it faster?

@saudet
Copy link
Member

saudet commented Mar 4, 2019

Set the "org.bytedeco.javacpp.logger.debug" system property to "true", and check the log to make sure it's not trying to load libraries you don't need.

@fhucho
Copy link
Author

fhucho commented Mar 5, 2019

I added -DCMAKE_BUILD_TYPE=Release flag to cmake and -Ofast -g0 to the compiler and now it got down to just 5 to 30 ms. I guess the slow stuff is happening in JNI_OnLoad() which is presumably called during library load.

@saudet
Copy link
Member

saudet commented Mar 7, 2019

I suppose we could add options to let users have more control over what gets called in JNI_OnLoad(). Please feel free to make a contribution! Let me know if you encounter any problems and I will help.

@saudet
Copy link
Member

saudet commented Apr 2, 2019

As @rajib3hasan found out in issue bytedeco/javacv#1168, it looks like loading classes on Android is pretty expensive, even when they are already loaded. This is something else we should look at.

@ZeroOneZeroR
Copy link

It takes time to load library classes while creating Instance for the first time. Then it takes usual time. Here is the log i have found ...

04-02 10:46:05.178 7527-7527/com.example.app D/FFmpeg log: log starts...........................................
04-02 10:46:05.469 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:05.484 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:05.555 7527-7527/com.example.app I/System.out: Loading library avutil
04-02 10:46:05.631 7527-7527/com.example.app I/System.out: Loading library jniavutil
04-02 10:46:05.631 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniavutil.so: unused DT entry: type 0x1d arg 0x1d8dd
04-02 10:46:05.814 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:05.814 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:05.822 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:05.822 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:05.965 7527-7527/com.example.app I/System.out: Loading library swresample
04-02 10:46:06.040 7527-7527/com.example.app I/System.out: Loading library jniswresample
04-02 10:46:06.041 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniswresample.so: unused DT entry: type 0x1d arg 0x3cf2
04-02 10:46:06.268 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:06.268 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:06.268 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:06.279 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:06.279 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:06.280 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:06.480 7527-7527/com.example.app I/System.out: Loading library avcodec
04-02 10:46:06.559 7527-7527/com.example.app I/System.out: Loading library jniavcodec
04-02 10:46:06.560 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniavcodec.so: unused DT entry: type 0x1d arg 0x1d16f
04-02 10:46:06.882 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:06.882 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:06.882 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:06.882 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:06.896 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:06.896 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:06.896 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:06.896 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:07.163 7527-7527/com.example.app I/System.out: Loading library avformat
04-02 10:46:07.242 7527-7527/com.example.app I/System.out: Loading library jniavformat
04-02 10:46:07.243 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniavformat.so: unused DT entry: type 0x1d arg 0x19eb8
04-02 10:46:07.626 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:07.626 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swscale
04-02 10:46:07.634 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:07.634 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swscale
04-02 10:46:07.768 7527-7527/com.example.app I/System.out: Loading library swscale
04-02 10:46:07.843 7527-7527/com.example.app I/System.out: Loading library jniswscale
04-02 10:46:07.844 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniswscale.so: unused DT entry: type 0x1d arg 0x4cf6
04-02 10:46:08.093 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:08.093 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:08.094 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:08.094 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:08.094 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.postproc
04-02 10:46:08.102 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:08.102 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.postproc
04-02 10:46:08.237 7527-7527/com.example.app I/System.out: Loading library postproc
04-02 10:46:08.308 7527-7527/com.example.app I/System.out: Loading library jnipostproc
04-02 10:46:08.309 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjnipostproc.so: unused DT entry: type 0x1d arg 0x3780
04-02 10:46:08.323 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swscale
04-02 10:46:08.323 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avfilter
04-02 10:46:08.349 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:08.350 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:08.350 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:08.350 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:08.350 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.postproc
04-02 10:46:08.350 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swscale
04-02 10:46:08.350 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avfilter
04-02 10:46:08.819 7527-7527/com.example.app I/System.out: Loading library avfilter
04-02 10:46:08.899 7527-7527/com.example.app I/System.out: Loading library jniavfilter
04-02 10:46:08.900 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniavfilter.so: unused DT entry: type 0x1d arg 0xb5c4
04-02 10:46:08.922 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avdevice
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.postproc
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swscale
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avfilter
04-02 10:46:08.949 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avdevice
04-02 10:46:09.488 7527-7527/com.example.app I/System.out: Loading library avdevice
04-02 10:46:09.560 7527-7527/com.example.app I/System.out: Loading library jniavdevice
04-02 10:46:09.561 7527-7527/com.example.app W/linker: /data/app/com.example.app-1/lib/arm/libjniavdevice.so: unused DT entry: type 0x1d arg 0x55b2
04-02 10:46:10.196 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:10.196 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:10.196 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:10.465 7527-7527/com.example.app I/System.out: Registering org.bytedeco.javacv.FFmpegLockCallback$1[address=0xabc2d358,position=0,limit=1,capacity=1,deallocator=org.bytedeco.javacpp.Pointer$NativeDeallocator[ownerAddress=0xabc2d358,deallocatorAddress=0xd71d8558]]
04-02 10:46:10.479 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:10.479 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:10.479 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:10.479 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:10.814 7527-7527/com.example.app I/System.out: Registering org.bytedeco.javacv.FFmpegFrameGrabber$ReadCallback[address=0xabc76fe8,position=0,limit=1,capacity=1,deallocator=org.bytedeco.javacpp.Pointer$NativeDeallocator[ownerAddress=0xabc76fe8,deallocatorAddress=0xd70e66fc]]
04-02 10:46:10.827 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:10.827 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:10.827 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:10.827 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:11.163 7527-7527/com.example.app I/System.out: Registering org.bytedeco.javacv.FFmpegFrameGrabber$SeekCallback[address=0xabd8bfe8,position=0,limit=1,capacity=1,deallocator=org.bytedeco.javacpp.Pointer$NativeDeallocator[ownerAddress=0xabd8bfe8,deallocatorAddress=0xd70e587c]]
04-02 10:46:11.178 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:11.178 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:11.178 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:11.178 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:11.523 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:11.523 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:11.523 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:11.791 7527-7527/com.example.app I/System.out: Registering org.bytedeco.javacpp.avcodec$AVPacket[address=0xac059e88,position=0,limit=1,capacity=1,deallocator=org.bytedeco.javacpp.Pointer$NativeDeallocator[ownerAddress=0xac059e88,deallocatorAddress=0xd720cfd4]]
04-02 10:46:11.791 7527-7527/com.example.app I/System.out: Registering org.bytedeco.javacpp.avcodec$AVPacket[address=0xac059ed8,position=0,limit=1,capacity=1,deallocator=org.bytedeco.javacpp.Pointer$NativeDeallocator[ownerAddress=0xac059ed8,deallocatorAddress=0xd720cfd4]]
04-02 10:46:11.811 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:11.811 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:11.811 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:11.811 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:12.194 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:12.194 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:12.194 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:12.194 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avformat
04-02 10:46:12.546 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:12.546 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:12.546 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:12.832 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:12.832 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:12.833 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:13.119 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:13.119 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.swresample
04-02 10:46:13.119 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avcodec
04-02 10:46:13.416 7527-7527/com.example.app I/System.out: Loading class org.bytedeco.javacpp.avutil
04-02 10:46:13.555 7527-7527/com.example.app D/FFmpeg log: log ends...................................... 

time: 8376

@saudet
Copy link
Member

saudet commented Apr 8, 2019

@rajib3hasan Can you do the same with JavaCPP 1.4.2?

@saudet saudet changed the title What makes loading a javacpp library relatively slow? What makes loading a javacpp library relatively slow on Android? Jun 12, 2019
@saudet
Copy link
Member

saudet commented Dec 15, 2019

As Damon Horrell found out in the following thread, this doesn't affect only Android:
https://groups.google.com/forum/#!topic/javacpp-project/GDT2FAG0c40
The issue appears to be that the time taken to load and initialize a given class increases with the amount of classes, even unrelated ones, found in the class path. To fix this for good, JavaCPP would probably need to be redesigned such that it doesn't require all classes containing native methods to be initialized at load time.

saudet added a commit that referenced this issue Dec 17, 2019
@saudet
Copy link
Member

saudet commented Dec 17, 2019

Actually, it looks like calls to Loader.findLibrary() make Class.forName() really slow for some reason, so I've added a cache for the former and it's super fast now. Please give it a try with the snapshots and let me know if you're still have issues with slow loading time: http://bytedeco.org/builds/

/cc @caaiofarias

@saudet
Copy link
Member

saudet commented Apr 15, 2020

Loading should now be fast with JavaCPP 1.5.3 on all platforms, but please let me know if anyone is still having issues with this. Thanks for the feedback!

@saudet saudet closed this as completed Apr 15, 2020
@calvertdw
Copy link

calvertdw commented Mar 21, 2023

We have at least 40,000+ classes on our classpath when launching some of our larger apps. Bytedeco Loader.load can take a really long time (5- 30 seconds) depending on the speed of the computer and how the application is running.

Loading Bytedeco OpenCV...
Bytedeco OpenCV loaded.
Loading took 7822ms

Code

long startMs = System.currentTimeMillis();
System.out.println("Loading Bytedeco OpenCV...");
Loader.load(opencv_core.class);
System.out.println("Bytedeco OpenCV loaded.");
long endMs = System.currentTimeMillis();
System.out.println("Loading took " + (endMs - startMs) + "ms");

When I load this up in YourKit, to see what's going on, it takes longer, presumably because YourKit injects a lot onto the classpath.

[YourKit Java Profiler 2022.9-b177] Log file: /home/duncan/.yjp/log/NadiaRDXOperatorUI-10725.log
Loading Bytedeco OpenCV...
Bytedeco OpenCV loaded.
Loading took 31690ms

image

We are running javacpp-1.5.9-20230222.151859-137.jar.

I did a search for how many classes are on the classpath for our application:

Classes in us.* 8243
Classes in com.* 8497
Classes in org.* 23525

Code:

ClassLoader cl = NadiaRDXOperatorUI.class.getClassLoader();
Set<ClassPath.ClassInfo> classesInPackage = ClassPath.from(cl).getTopLevelClassesRecursive("us");
System.out.println("Classes in us.* " + classesInPackage.size());
Set<ClassPath.ClassInfo> classesInCom = ClassPath.from(cl).getTopLevelClassesRecursive("com");
System.out.println("Classes in com.* " + classesInCom.size());
Set<ClassPath.ClassInfo> classesInStar = ClassPath.from(cl).getTopLevelClassesRecursive("org");
System.out.println("Classes in org.* " + classesInStar.size());

@saudet
Copy link
Member

saudet commented Mar 21, 2023

Looks like something wrong with your JVM? Class.forName() is taking almost 100% of the time. What's going on in there?

@saudet
Copy link
Member

saudet commented Apr 10, 2023

@calvertdw Most of the calls to Class.forName() probably happen in Loader.putMemberOffset(), to fill the map for Loader.offsetof() and sizeof(). You may be able to skip that, depending on what your application needs. Can you try to comment out the Class.forName() in Loader.putMemberOffset() and see what happens? If it works for your case, we can add a system property to let users disable that at runtime, or add a cache or something.

@calvertdw
Copy link

Hi Samuel, thanks for the help. I got swamped with other stuff, we'll give this a shot.

By the way I was using OpenJDK above. I didn't get to test with other JDKs yet. Are large classpaths working okay for some other JVM?

@saudet
Copy link
Member

saudet commented Apr 10, 2023

I don't know, the only issue that I know about had to do with Loader.findLibrary() as above, not Class.forName() directly.

@saudet
Copy link
Member

saudet commented Apr 16, 2023

@calvertdw Actually, thinking about it some more, I'm guessing one of the libraries that you're using is making Class.forName() slow, just like Loader.findLibrary() used to make Class.forName() slow. Either way, if you can afford to skip Loader.putMemberOffset(), that's a fine workaround.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants