uqbar-project / wollok

Wollok Programming Language
GNU General Public License v3.0
60 stars 16 forks source link

Tests are slow #999

Closed flbulgarelli closed 7 years ago

flbulgarelli commented 8 years ago

Running tests is quite slow. I am running a test suite of 40 simple tests that instantiate a few objects and send a few messages with no expensive computations, and it takes around 6 seconds to initialize the test suite, and ~30 seconds to run all them, in a core i7 ubuntu 14.04 machine.

fdodino commented 8 years ago

In an embedded Wollok IDE, I've analyze this method:

    override dispatch evaluate(WTest test) {
        try {
            wollokTestsReporter.testStart(test)  // takes 80 milliseconds
            val x = test.elements.evalAll           // between 1 and 4 milliseconds (no problem at all, fortunately)
            wollokTestsReporter.reportTestOk(test)   // takes 80 milliseconds
            x
        }

I could not reproduce such a slow performance for tests, I can run 40 tests in 10-11 seconds, 5-6 initialization time and 5-6 is "real" testing time. I have a 8GB RAM, i5, Linux Mint machine. But I understand that initial time for tests is slow.

I haven't analyzed initialization code. Maybe we can try to buffer TestReporter until all tests finish, I don't know @tesonep @javierfernandes @npasserini what do you think?

fdodino commented 8 years ago

Oh, by the way, wollokTestsReporter used is WollokRemoteTestReporter. RMI may be the cause of such performance loss.

fdodino commented 8 years ago

Well, I have an intermediate version (I'll push a branch in these days soon) buffering all tests results in a single RMI call. It behaves not so bad, but initial time takes 6 seconds like it was reported. I'll try to generate a second version without RMI calls at all.

Hi @flbulgarelli , could you please send me a link to your project to check its performance? Thanks.

flbulgarelli commented 8 years ago

Please check the following repositories - don't remember now which of them raised this issue:

fdodino commented 8 years ago

Thanks, I will check them on friday.

fdodino commented 8 years ago

Well, last friday I've spent many hours and opened 3 different branches:

wtest-launcher-rmi-buffered advantages: it works! and it condenses all overhead calls to just one RMI call disadvantes: it still uses RMI, so an initial overhead of about 6 seconds is still there, plus 2/3 seconds in a 40 test suite example with 27 errors.

wtest-launcher-no-rmi It doesn't work. Its strategy is to use a WollokLocalTestLauncherDelegate, and replace a WollokRemoteTestResults for a WollokLocalTestResults. But the problem is that objects in wollok.launch can't see wollok.ui.launch project. Too bad, because I think it is a good approach since launcher doesn't take so long (initial 6 seconds is because RMI server is starting)

wtest-no-launcher WollokLauncher doesn't inherit from Java Launcher, instead it tries to read wollok test and interpret it. It doesn't work, because there is a problem in Wollok Checker: classpath:/wollok/lang.wlk isn't recognized. I have a huge mail I'll resume in a few days. But it could be awesome if someone gives me a clue, because it is a known bug in Wollok SDK. I tried to reproduce Wollok Server's behavior but I couldn't get it. There is also a problem when you insert a program, several classpath errors are shown in Wollok project. But still you can execute a program successfully.

fdodino commented 8 years ago

Well, last things I've discovered in branch wtest-no-launcher

If @tesonep or @javierfernandes could give me a clue, "that would be nice... yeaaaah" (see Office Space, in case of doubt)

fdodino commented 8 years ago

I think main problem is in the difference when loading resources in MapBasedWollokGlobalScopeCache:

At start, everything works fine using

Loading platform:/resource/org.uqbar.project.wollok.launch/wollok/mirror.wlk
Handle manifest [classpath:/wollok/lang.wlk, classpath:/wollok/lib.wlk, classpath:/wollok/mirror.wlk, classpath:/wollok/game.wlk, classpath:/wollok/vm.wlk]
Load resource classpath:/wollok/lang.wlk
Load resource classpath:/wollok/lib.wlk
Load resource classpath:/wollok/mirror.wlk
Load resource classpath:/wollok/game.wlk
Load resource classpath:/wollok/vm.wlk

But when I run the test, there is the bug

Loading __synthetic0.wtest
Handle manifest [classpath:/wollok/lang.wlk, classpath:/wollok/lib.wlk, classpath:/wollok/mirror.wlk, classpath:/wollok/game.wlk, classpath:/wollok/vm.wlk]
Load resource classpath:/wollok/lang.wlk
1    [Worker-9] ERROR org.eclipse.xtext.linking.lazy.LazyLinkingResource  - resolution of uriFragment '|0' failed.
java.lang.RuntimeException: Error while loading resource [classpath:/wollok/lang.wlk]
    at org.uqbar.project.wollok.scoping.WollokGlobalScopeProvider.loadResource(WollokGlobalScopeProvider.java:237)
    at org.uqbar.project.wollok.scoping.WollokGlobalScopeProvider.lambda$6(WollokGlobalScopeProvider.java:209)
    at org.eclipse.xtext.xbase.lib.internal.FunctionDelegate.apply(FunctionDelegate.java:42)
fdodino commented 8 years ago

Ok, got it. I used this URI "platform:/resource/project01/src/test.wtest" and now it could reach wollok library files.

But... it was almost impossible to get listeners notified when tests start and complete. I need UI view part (WollokUIRemoteListView), and it is not easy to pass it along all these methods.

So, without a good refactor it won't be easy to get rid of RMI invocations.

fdodino commented 8 years ago

Well. I went back to test with RMI buffered, and clone students repos, @flbulgarelli .

I have 40 tests with wollok objects, it takes 5 seconds to run, even with errors. https://github.com/roavakian/Sims ==> 15.19 seconds to run 65 tests (1 with error) https://github.com/LVictoria/Sims ==> bad Wollok project (compilation errors) https://github.com/JuanManuelSakkal/tp-sims ==> 30 seconds to run 40 tests (1 error).

The problem is not itself with tests, but with solution developed by Juan Manuel Sakkal. If you see this

    method ponerEnRelacion(unSim){
        //unSim.nuevaRelacion(self)
        //unSim.amigos().forEach({amigo => circuloDeAmigos.add(amigo)})
        unSim.nuevoEstadoCivil(enPareja)
        miembros.add(unSim)
    }

I commented two first lines and it took just 18,41 seconds to run 41 tests. So, I can't say RMI invocation doesn't slow testing performance, but I think 65 tests in 15 seconds is not so bad.

For now, I think I will push a PR for branch wtest-launcher-rmi-buffered and continue with UI Wollok Test enhancements.