Closed SSzretter closed 2 years ago
Thanks for reporting.
So this failing one tests experimental write-back feature. You can work around it by simply skipping tests:
mvn clean install -DskipTests
But this is likely indication of (too) slow db write operation. The test waits for 1 second for 20k positions to be updated, that's supposed to result in two write operations.
How much memory and cores do you have?
Would you help me test it further? E.g. change line 484 in DBTest.java: waitFor(1000); increase it to 10 seconds (10000) or more, and then look for timing in the output, e.g. mvn clean install 2>&1 | less I'm interested in these three lines that DBTest outputs, like
2022-01-18 08:40:00.153 INFO 11576 --- [ main] org.vrspace.server.core.DBTest : Started DBTest in 14.553 seconds (JVM running for 16.036) 2022-01-18 08:40:03.411 DEBUG 11576 --- [ WriteBack] org.vrspace.server.core.WriteBack : Wrote 1 in 471 ms update rate 21052.63157894737/s, writes 3
That would give me an idea what performance to expect on AWS servers.
This is a small instance as I am just checking it out initially. It doesnt even seem like its getting that far - I made the change you mention to DBTest.java but I do not see any lines mentioning 'Wrote' or update rate or anything like that. I see this line 2022-01-18 19:27:04.906 INFO 11903 --- [ main] org.vrspace.server.core.DBTest : Started DBTest in 27.45 seconds (JVM running for 34.96)
Then similar output as what I posted before - except this time it took 45 minutes instead of 30 minutes to fail.
Anyway when I use the skip tests it quickly compiles just fine and I can run it and it seems to be working - I can get in through a web browser just like your demo site.
On Tue, Jan 18, 2022 at 4:06 AM Josip Almasi @.***> wrote:
Thanks for reporting.
So this failing one tests experimental write-back feature. You can work around it by simply skipping tests:
mvn clean install -DskipTests
But this is likely indication of (too) slow db write operation. The test waits for 1 second for 20k positions to be updated, that's supposed to result in two write operations.
How much memory and cores do you have?
Would you help me test it further? E.g. change line 484 in DBTest.java: waitFor(1000); increase it to 10 seconds (10000) or more, and then look for timing in the output, e.g. mvn clean install 2>&1 | less I'm interested in these three lines that DBTest outputs, like
2022-01-18 08:40:00.153 INFO 11576 --- [ main] org.vrspace.server.core.DBTest : Started DBTest in 14.553 seconds (JVM running for 16.036) 2022-01-18 08:40:03.411 DEBUG 11576 --- [ WriteBack] org.vrspace.server.core.WriteBack : Wrote 1 in 471 ms update rate 21052.63157894737/s, writes 3
That would give me an idea what performance to expect on AWS servers.
— Reply to this email directly, view it on GitHub https://github.com/jalmasi/vrspace/issues/5#issuecomment-1015205103, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABQK4ZXOH3UAZ4N2FVUVIDUWUUSJANCNFSM5MFWYFIQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.
You are receiving this because you authored the thread.Message ID: @.***>
Thanks for trying. Small instance has 1 vCPU and 2 G, right? If that's the case, I'm (pleasantly) surprised it works at all. Reasonable minimum is 2 cores and 4 gigs. So this has nothing to do with debian, updating the title. (FTR vrspace.org server is also debian buster) Looking through you build output again, it looks that embedded Neo4j did not start at all. There is 'starting' part at the beginning, but there's no shut down part after tests are executed. This is end of tests is supposed to look like:
2022-01-19 10:37:45.812 INFO 14977 --- [ionShutdownHook] org.vrspace.server.core.WriteBack : Writeback stopping 2022-01-19 10:37:45.814 INFO 14977 --- [ionShutdownHook] org.vrspace.server.config.NeoConfig : Database shutting down... 2022-01-19 10:37:51.087 INFO 14977 --- [ionShutdownHook] org.vrspace.server.config.NeoConfig : Database shutting down complete 2022-01-19 10:37:51.087 INFO 14977 --- [ionShutdownHook] org.vrspace.server.config.NeoConfig : Deleting database directory /opt/vrspace/server/vrspace-test.db 2022-01-19 10:37:51.094 INFO 14977 --- [ionShutdownHook] org.neo4j.driver.Driver : Closing driver instance 1844648639 2022-01-19 10:37:51.095 INFO 14977 --- [ionShutdownHook] org.neo4j.driver.ConnectionPool : Closing connection pool towards localhost:7688
But since this wasn't executed, server/vrspace-test.db/logs should be there, and may contain additional info on whatever happened with the database.
Thanks for that - I did confirm on a different machine witch much more ram and cores that the normal mvn clean install works. The AWS EC2 instance is actually a nano so only 1 core and 1 gig. Even though the tests do not work it compiled fine without tests and it seemed to work fine - I could connect in, move around to different worlds and even created my own world. Do you have any other support sites? I see the forum - do you have a discord? I would like to ask some other questions. Thanks
No discord yet. Look me up on linkedin for a private chat, contact link is at the bottom of the home page. Alright, thanks for confirmation and info, closing the ticket.
Hoping to get help building - this is brand new aws ec2 debian 10 instance and after spinning up the clean instance I ran apt update, installed git, nodejs and maven. Cloned the repo and it fails in the spring section during the DBTest (which takes quite a while to run) - here is the command andd the output:
`admin:~/vrspace$ mvn clean install WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by com.google.inject.internal.cglib.core.$ReflectUtils$1 (file:/usr/share/maven/lib/guice.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[] ,int,int,java.security.ProtectionDomain) WARNING: Please consider reporting this to the maintainers of com.google.inject.internal.cglib.core.$ReflectUtils$1 WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release [INFO] Scanning for projects... [INFO] ------------------------------------------------------------------------ [INFO] Reactor Build Order: [INFO] [INFO] VRSpace parent file [pom] [INFO] server [jar] [INFO] babylon [pom] [INFO] content [jar] [INFO] web [jar] [INFO] [INFO] -------------------------< org.vrspace:parent >------------------------- [INFO] Building VRSpace parent file 0.4.3-SNAPSHOT [1/5] [INFO] --------------------------------[ pom ]--------------------------------- [INFO] [INFO] --- maven-clean-plugin:3.1.0:clean (default-clean) @ parent --- [INFO] [INFO] --- maven-install-plugin:2.5.2:install (default-install) @ parent --- [INFO] Installing /home/admin/vrspace/pom.xml to /home/admin/.m2/repository/org/vrspace/parent/0.4.3-SNAPSHOT/parent-0.4.3-SNAPSHOT.pom [INFO] [INFO] -------------------------< org.vrspace:server >------------------------- [INFO] Building server 0.4.3-SNAPSHOT [2/5] [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] --- maven-clean-plugin:3.1.0:clean (default-clean) @ server --- [INFO] Deleting /home/admin/vrspace/server/target [INFO] [INFO] --- git-commit-id-plugin:4.0.5:revision (default) @ server --- [INFO] dotGitDirectory /home/admin/vrspace/.git [INFO] Collected git.branch with value master [INFO] --always = true [INFO] --dirty = -dirty [INFO] --abbrev = 7 [INFO] Tag refs [[]] [INFO] Created map: [{}] [INFO] evalCommit is [0960f269ac882eec23812067e474b49ca93e3682] [INFO] Collected git.commit.id.describe with value 0960f26 [INFO] Collected git.commit.id.describe-short with value 0960f26 [INFO] Collected git.commit.id.full with value 0960f269ac882eec23812067e474b49ca93e3682 [INFO] Collected git.commit.id.abbrev with value 0960f26 [INFO] Collected git.dirty with value false [INFO] Collected git.commit.message.full with value drag and drop to chat [INFO] Collected git.commit.message.short with value drag and drop to chat [INFO] Collected git.commit.time with value 2022-01-16T14:30:18+0000 [INFO] Collected git.commit.author.time with value 2022-01-16T14:30:18+0000 [INFO] Collected git.commit.committer.time with value 2022-01-16T14:30:18+0000 [INFO] Collected git.remote.origin.url with value https://github.com/jalmasi/vrspace [INFO] Collected git.tags with value [INFO] evalCommit is [0960f269ac882eec23812067e474b49ca93e3682] [INFO] Tag refs [[]] [INFO] Created map: [{}] [INFO] Collected git.closest.tag.name with value [INFO] evalCommit is [0960f269ac882eec23812067e474b49ca93e3682] [INFO] Tag refs [[]] [INFO] Created map: [{}] [INFO] Collected git.closest.tag.commit.count with value [INFO] Collected git.total.commit.count with value 371 [INFO] Collected git.local.branch.ahead with value 0 [INFO] Collected git.local.branch.behind with value 0 [INFO] Collected git.build.time with value 2022-01-17T21:54:09+0000 [INFO] Collected git.build.version with value 0.4.3-SNAPSHOT [INFO] Collected git.build.host with value ip-172-31-53-93 [INFO] including property git.tags in results [INFO] including property git.closest.tag.commit.count in results [INFO] including property git.build.version in results [INFO] including property git.commit.id.abbrev in results [INFO] including property git.branch in results [INFO] including property git.build.host in results [INFO] including property git.commit.id.describe-short in results [INFO] including property git.total.commit.count in results [INFO] including property git.commit.id.describe in results [INFO] including property git.commit.message.short in results [INFO] including property git.commit.committer.time in results [INFO] including property git.commit.id.full in results [INFO] including property git.closest.tag.name in results [INFO] including property git.local.branch.ahead in results [INFO] including property git.commit.time in results [INFO] including property git.commit.author.time in results [INFO] including property git.local.branch.behind in results [INFO] including property git.build.time in results [INFO] including property git.dirty in results [INFO] including property git.commit.message.full in results [INFO] including property git.remote.origin.url in results [INFO] Writing properties file to [/home/admin/vrspace/server/target/classes/git.properties] (for module server)... [INFO] [INFO] --- git-commit-id-plugin:4.0.5:revision (get-the-git-infos) @ server --- [INFO] dotGitDirectory /home/admin/vrspace/.git [INFO] Collected git.branch with value master [INFO] --always = true [INFO] --dirty = -dirty [INFO] --abbrev = 7 [INFO] Tag refs [[]] [INFO] Created map: [{}] [INFO] evalCommit is [0960f269ac882eec23812067e474b49ca93e3682] [INFO] Collected git.commit.id.describe with value 0960f26 [INFO] Collected git.commit.id.describe-short with value 0960f26 [INFO] Collected git.commit.id.full with value 0960f269ac882eec23812067e474b49ca93e3682 [INFO] Collected git.commit.id.abbrev with value 0960f26 [INFO] Collected git.dirty with value false [INFO] Collected git.commit.message.full with value drag and drop to chat [INFO] Collected git.commit.message.short with value drag and drop to chat [INFO] Collected git.commit.time with value 2022-01-16T14:30:18+0000 [INFO] Collected git.commit.author.time with value 2022-01-16T14:30:18+0000 [INFO] Collected git.commit.committer.time with value 2022-01-16T14:30:18+0000 [INFO] Collected git.remote.origin.url with value https://github.com/jalmasi/vrspace [INFO] Collected git.tags with value [INFO] evalCommit is [0960f269ac882eec23812067e474b49ca93e3682] [INFO] Tag refs [[]] [INFO] Created map: [{}] [INFO] Collected git.closest.tag.name with value [INFO] evalCommit is [0960f269ac882eec23812067e474b49ca93e3682] [INFO] Tag refs [[]] [INFO] Created map: [{}] [INFO] Collected git.closest.tag.commit.count with value [INFO] Collected git.total.commit.count with value 371 [INFO] Collected git.local.branch.ahead with value 0 [INFO] Collected git.local.branch.behind with value 0 [INFO] Collected git.build.time with value 2022-01-17T21:54:09+0000 [INFO] Collected git.build.version with value 0.4.3-SNAPSHOT [INFO] Collected git.build.host with value ip-172-31-53-93 [INFO] including property git.tags in results [INFO] including property git.closest.tag.commit.count in results [INFO] including property git.build.version in results [INFO] including property git.commit.id.abbrev in results [INFO] including property git.branch in results [INFO] including property git.build.host in results [INFO] including property git.commit.id.describe-short in results [INFO] including property git.total.commit.count in results [INFO] including property git.commit.id.describe in results [INFO] including property git.commit.message.short in results [INFO] including property git.commit.committer.time in results [INFO] including property git.commit.id.full in results [INFO] including property git.closest.tag.name in results [INFO] including property git.local.branch.ahead in results [INFO] including property git.commit.time in results [INFO] including property git.commit.author.time in results [INFO] including property git.local.branch.behind in results [INFO] including property git.build.time in results [INFO] including property git.dirty in results [INFO] including property git.commit.message.full in results [INFO] including property git.remote.origin.url in results [INFO] Reading existing properties file [/home/admin/vrspace/server/target/classes/git.properties] (for module server)... [INFO] Properties file [/home/admin/vrspace/server/target/classes/git.properties] is up-to-date (for module server)... [INFO] [INFO] --- maven-resources-plugin:3.2.0:resources (default-resources) @ server --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] Using 'UTF-8' encoding to copy filtered properties files. [INFO] Copying 1 resource [INFO] Copying 5 resources [INFO] [INFO] --- maven-compiler-plugin:3.8.1:compile (default-compile) @ server --- [INFO] Changes detected - recompiling the module! [INFO] Compiling 64 source files to /home/admin/vrspace/server/target/classes [INFO] [INFO] --- maven-resources-plugin:3.2.0:testResources (default-testResources) @ server --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] Using 'UTF-8' encoding to copy filtered properties files. [INFO] Copying 2 resources [INFO] [INFO] --- maven-compiler-plugin:3.8.1:testCompile (default-testCompile) @ server --- [INFO] Changes detected - recompiling the module! [INFO] Compiling 15 source files to /home/admin/vrspace/server/target/test-classes [INFO] [INFO] --- maven-surefire-plugin:2.22.2:test (default-test) @ server --- [INFO] [INFO] ------------------------------------------------------- [INFO] T E S T S [INFO] ------------------------------------------------------- [INFO] Running org.vrspace.server.core.SceneTest SLF4J: Class path contains multiple SLF4J bindings. SLF4J: Found binding in [jar:file:/home/admin/.m2/repository/ch/qos/logback/logback-classic/1.2.6/logback-classic-1.2.6.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: Found binding in [jar:file:/home/admin/.m2/repository/org/slf4j/slf4j-nop/1.7.32/slf4j-nop-1.7.32.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder] 2022-01-17 21:54:29.148 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 0 2022-01-17 21:54:29.157 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 2 Add(objects=[VRObject(super=Entity(id=1), children=[VRObject(super=Entity(id=11), children=[], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=true, mes h=null, script=null, properties=null, streamId=null, listeners={ID(className=Client$MockitoMock$140161194, id=0)=client})], world=null, position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=nul l, permanent=null, temporary=null, active=true, mesh=null, script=null, properties=null, streamId=null, listeners={ID(className=Client$MockitoMock$140161194, id=0)=client}), VRObject(super=Entity(i d=2), children=[], world=null, position=Point(x=1.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=false, mesh=null, script=null, properties=null, streamId=null, listeners=null)]) 2022-01-17 21:54:29.317 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 2 2022-01-17 21:54:29.318 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 0 Remove(objects=[{VRObject=11}, {VRObject=1}], iterator=null) 2022-01-17 21:54:29.377 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 0 2022-01-17 21:54:29.378 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 2 2022-01-17 21:54:29.403 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 0 2022-01-17 21:54:29.404 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 2 2022-01-17 21:54:29.411 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 1 2022-01-17 21:54:29.415 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 0 2022-01-17 21:54:29.417 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 0 2022-01-17 21:54:29.418 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 1 2022-01-17 21:54:29.433 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 0 2022-01-17 21:54:29.439 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 2 Add(objects=[VRObject(super=Entity(id=1), children=[VRObject(super=Entity(id=11), children=[], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=true, mes h=null, script=null, properties=null, streamId=null, listeners={ID(className=Client$MockitoMock$140161194, id=0)=client})], world=null, position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=nul l, permanent=null, temporary=null, active=true, mesh=null, script=null, properties=null, streamId=null, listeners={ID(className=Client$MockitoMock$140161194, id=0)=client}), VRObject(super=Entity(i d=2), children=[], world=null, position=Point(x=1.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=false, mesh=null, script=null, properties=null, streamId=null, listeners=null)]) 2022-01-17 21:54:29.446 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 3 Remove(objects=[{VRObject=11}, {VRObject=1}, {VRObject=2}], iterator=null) 2022-01-17 21:54:29.458 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 removing 0 2022-01-17 21:54:29.463 DEBUG --- [ main] org.vrspace.server.core.Scene : Scene for 0 adding 2 Add(objects=[VRObject(super=Entity(id=1), children=[VRObject(super=Entity(id=11), children=[], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=true, mes h=null, script=null, properties=null, streamId=null, listeners={ID(className=Client$MockitoMock$140161194, id=0)=client})], world=null, position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=nul l, permanent=null, temporary=null, active=true, mesh=null, script=null, properties=null, streamId=null, listeners={ID(className=Client$MockitoMock$140161194, id=0)=client}), VRObject(super=Entity(i d=2), children=[], world=null, position=Point(x=1.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=false, mesh=null, script=null, properties=null, streamId=null, listeners=null)]) [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.802 s - in org.vrspace.server.core.SceneTest [INFO] Running org.vrspace.server.core.DBTest
. _ _ /\ / '_ () \ \ \ \ ( ( )\ | ' | '| | ' \/ ` | \ \ \ \ \/ _)| |)| | | | | || (| | ) ) ) ) ' |__| .|| ||| |\, | / / / / =========|_|==============|__/=//// :: Spring Boot :: (v2.5.6)
2022-01-17 21:54:31.003 INFO 22628 --- [ main] org.vrspace.server.core.DBTest : Starting DBTest using Java 11.0.13 on ip-172-31-53-93 with PID 22628 (started by admin in /home/ admin/vrspace/server) 2022-01-17 21:54:31.004 DEBUG 22628 --- [ main] org.vrspace.server.core.DBTest : Running with Spring Boot v2.5.6, Spring v5.3.12 2022-01-17 21:54:31.013 INFO 22628 --- [ main] org.vrspace.server.core.DBTest : No active profile set, falling back to default profiles: default 2022-01-17 21:54:35.224 INFO 22628 --- [ main] org.neo4j.driver.Driver : Direct driver instance 475584446 created for server address localhost:7688 2022-01-17 21:54:37.387 INFO 22628 --- [ main] org.vrspace.server.core.WriteBack : Writeback running 2022-01-17 21:54:37.437 INFO 22628 --- [ main] org.vrspace.server.config.NeoConfig : Configured database uri: file:./vrspace-test.db 2022-01-17 21:54:37.440 INFO 22628 --- [ main] org.vrspace.server.config.NeoConfig : Absolute database path: /home/admin/vrspace/server/vrspace-test.db 2022-01-17 21:54:37.441 INFO 22628 --- [ main] org.vrspace.server.config.NeoConfig : Starting database on bolt://localhost:7688 2022-01-17 21:54:53.070 DEBUG 22628 --- [ main] org.vrspace.server.core.ClassUtil : VRSpace home directory: /home/admin/vrspace deduced from location of org/vrspace/server/core/Cla ssUtil.class: file:/home/admin/vrspace/server/target/classes/org/vrspace/server/core/ClassUtil.class 2022-01-17 21:54:55.278 INFO 22628 --- [ main] org.vrspace.server.core.DBTest : Started DBTest in 24.903 seconds (JVM running for 31.022) [VRObject(super=Entity(id=4), children=[], world=World(super=Entity(id=3), name=test, defaultWorld=false), position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary= null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null)] [VRObject(super=Entity(id=4), children=[], world=World(super=Entity(id=3), name=test, defaultWorld=false), position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary= null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null), Client(name=null, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[], sceneProperties=null, token=null, identity=null, session=null, scene=null, mapper=null, guest=false)] [VRObject(super=Entity(id=4), children=[], world=World(super=Entity(id=3), name=test, defaultWorld=false), position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary= null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null), Client(name=null, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[], sceneProperties=null, token=null, identity=null, session=null, scene=null, mapper=null, guest=false), VRObject(super=Entity(id=6), children=[], world=World(super=Entity(id=3), name=test, defaultWorld=false), position=Point(x=10.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners= null)] Client(name=null, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[], sceneProperties=null, token=null, identity=null, session=null, scene=null, mapper= null, guest=false) 2022-01-17 21:57:46.367 DEBUG 22628 --- [ main] org.vrspace.server.obj.EventRecorder : null Recording space event 1642456662905:VREvent(object={Client=null}, changes={something=anythi ng}, timestamp=2022-01-17T21:57:42.905725, className=null, id=null, source=Client(name=null, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=null, scene Properties=null, token=null, identity=null, session=null, scene=null, mapper=null, guest=false), client=null, payload={"something":"anything"}) Point(x=0.0, y=0.0, z=0.0) Point(x=1.0, y=1.0, z=1.0) Point(x=5.0, y=0.0, z=0.0) [Point(x=0.0, y=0.0, z=0.0)] [Point(x=0.0, y=0.0, z=0.0), Point(x=1.0, y=1.0, z=1.0)] [Point(x=0.0, y=0.0, z=0.0), Point(x=1.0, y=1.0, z=1.0), Point(x=5.0, y=0.0, z=0.0)] VRObject(super=Entity(id=26), children=null, world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=nul l, listeners=null) 2022-01-17 21:58:46.250 DEBUG 22628 --- [ WriteBack] org.vrspace.server.core.WriteBack : Wrote 1 in 49532 ms VRObject(super=Entity(id=26), children=[VRObject(super=Entity(id=27), children=null, world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, sc ript=null, properties=null, streamId=null, listeners=null)], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=nu ll, streamId=null, listeners=null) VRObject(super=Entity(id=26), children=[VRObject(super=Entity(id=27), children=[], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, scri pt=null, properties=null, streamId=null, listeners=null)], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null , streamId=null, listeners=null) VRObject(super=Entity(id=27), children=[], world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null) Client(name=client 1, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=null, sceneProperties=null, token=null, identity=null, session=null, scene=null, m apper=null, guest=false) 2022-01-17 21:59:41.838 DEBUG 22628 --- [ WriteBack] org.vrspace.server.core.WriteBack : Wrote 2 in 54814 ms Optional[Client(name=client 1, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[], sceneProperties=null, token=null, identity=null, session=null, scene= null, mapper=null, guest=false)] Client(name=null, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[VRObject(super=Entity(id=41), children=null, world=null, position=null, rotation=null , scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null)], sceneProperties=null, token=null, identity=null, session=null, s cene=null, mapper=null, guest=false) 2022-01-17 22:02:44.146 DEBUG 22628 --- [ main] o.v.server.core.VRObjectRepository : Deleting position Point:43 of Client 40 [class org.vrspace.server.obj.VRObject, class org.vrspace.server.obj.Point, class org.vrspace.server.obj.PersistentEvent, class org.vrspace.server.obj.GltfModel, class org.vrspace.server.obj.Client , class org.vrspace.server.obj.ContentCategory, class org.vrspace.server.obj.Rotation, class org.vrspace.server.obj.World, class org.vrspace.server.obj.EventRecorder] [org.vrspace.server.obj.VRObject, org.vrspace.server.obj.Point, org.vrspace.server.obj.PersistentEvent, org.vrspace.server.obj.Embedded, org.vrspace.server.obj.GltfModel, org.vrspace.server.obj.Cli ent, org.vrspace.server.obj.ContentCategory, org.vrspace.server.obj.Rotation, org.vrspace.server.obj.World, org.vrspace.server.obj.EventRecorder, org.vrspace.server.obj.Entity] [VRObject(super=Entity(id=46), children=[], world=null, position=null, rotation=null, scale=null, permanent=true, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null , listeners=null)] [VRObject(super=Entity(id=47), children=[], world=null, position=null, rotation=null, scale=null, permanent=true, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null , listeners=null)] VRObject(super=Entity(id=48), children=null, world=null, position=null, rotation=Rotation(x=1.0, y=2.0, z=3.0, angle=4.0), scale=null, permanent=null, temporary=null, active=true, mesh=null, script =null, properties=null, streamId=null, listeners=null) VRObject(super=Entity(id=48), children=[], world=null, position=null, rotation=Rotation(x=1.0, y=2.0, z=3.0, angle=4.0), scale=null, permanent=null, temporary=null, active=true, mesh=null, script=n ull, properties=null, streamId=null, listeners=null) [VRObject(super=Entity(id=51), children=[], world=null, position=null, rotation=null, scale=null, permanent=true, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null)] Client(name=clientOne, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=null, sceneProperties=null, token=null, identity=null, session=null, scene=org.vrspace.server.core.Scene@63f48de4, mapper=null, guest=false) Client(name=clientTwo, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=null, sceneProperties=null, token=null, identity=null, session=null, scene=org.vrspace.server.core.Scene@2f045b3c, mapper=null, guest=false) Client(name=clientOne, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[], sceneProperties=null, token=null, identity=null, session=null, scene=null, mapper=null, guest=false) Client(name=clientTwo, leftArmPos=null, rightArmPos=null, leftArmRot=null, rightArmRot=null, userHeight=null, owned=[], sceneProperties=null, token=null, identity=null, session=null, scene=null, mapper=null, guest=false) VRObject(super=Entity(id=57), children=null, world=null, position=null, rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties={string=string, float=1.2, long=1}, streamId=null, listeners=null) [VRObject(super=Entity(id=62), children=[], world=World(super=Entity(id=60), name=test1, defaultWorld=false), position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null)] [VRObject(super=Entity(id=62), children=[], world=World(super=Entity(id=60), name=test1, defaultWorld=false), position=Point(x=0.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null), VRObject(super=Entity(id=64), children=[], world=World(super=Entity(id=60), name=test1, defaultWorld=false), position=Point(x=10.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null)] [] [VRObject(super=Entity(id=66), children=[], world=World(super=Entity(id=61), name=test2, defaultWorld=false), position=Point(x=10.0, y=0.0, z=0.0), rotation=null, scale=null, permanent=null, temporary=null, active=null, mesh=null, script=null, properties=null, streamId=null, listeners=null)] [ERROR] Tests run: 18, Failures: 1, Errors: 0, Skipped: 1, Time elapsed: 1,290.835 s <<< FAILURE! - in org.vrspace.server.core.DBTest [ERROR] testWriteback Time elapsed: 8.043 s <<< FAILURE! org.opentest4j.AssertionFailedError: expected: <0> but was: <20000> at org.vrspace.server.core.DBTest.testWriteback(DBTest.java:495)
[INFO] Running org.vrspace.server.core.SessionManagerTest 2022-01-17 22:17:57.393 DEBUG 22628 --- [ main] org.vrspace.server.core.WorldManager : Login principal: org.vrspace.server.core.SessionManagerTest$1@52742778 headers: null attributes: {local-user-name=tester} 2022-01-17 22:20:46.431 INFO 22628 --- [ main] org.vrspace.server.core.WorldManager : Created default world: World(super=Entity(id=70), name=default, defaultWorld=true) 2022-01-17 22:24:02.471 DEBUG 22628 --- [ main] org.vrspace.server.obj.Client : ID(className=Client, id=68) Received {"Welcome":{"client":{"id":68,"position":{"x":1.0,"y":2.0,"z":3.0},"active":true,"name":"tester","sceneProperties":{"range":2000.0,"resolution":10.0,"size":1000,"timeout":30000}},"timestamp":"2022-01-17T22:21:49.013009000"}} [WARNING] Corrupted STDOUT by directly writing to native stream in forked JVM 1. See FAQ web page and the dump file /home/admin/vrspace/server/target/surefire-reports/2022-01-17T21-54-23_766-jvmRun1.dumpstream [INFO] [INFO] Results: [INFO] [ERROR] Failures: [ERROR] DBTest.testWriteback:495 expected: <0> but was: <20000> [INFO] [ERROR] Tests run: 23, Failures: 1, Errors: 0, Skipped: 1 [INFO] [INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary for VRSpace parent file 0.4.3-SNAPSHOT: [INFO] [INFO] VRSpace parent file ................................ SUCCESS [ 2.449 s] [INFO] server ............................................. FAILURE [30:13 min] [INFO] babylon ............................................ SKIPPED [INFO] content ............................................ SKIPPED [INFO] web ................................................ SKIPPED [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 30:16 min [INFO] Finished at: 2022-01-17T22:24:17Z [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.22.2:test (default-test) on project server: There are test failures. [ERROR] [ERROR] Please refer to /home/admin/vrspace/server/target/surefire-reports for the individual test results. [ERROR] Please refer to dump files (if any exist) [date].dump, [date]-jvmRun[N].dump and [date].dumpstream. [ERROR] The forked VM terminated without properly saying goodbye. VM crash or System.exit called? [ERROR] Command was /bin/sh -c cd /home/admin/vrspace/server && /usr/lib/jvm/java-11-openjdk-amd64/bin/java --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.nio=ALL-UNNAMED --add-opens java.base/java.io=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-opens java.base/sun.nio.ch=ALL-UNNAMED -jar /home/admin/vrspace/server/target/surefire/surefirebooter8993065144439658197.jar /home/admin/vrspace/server/target/surefire 2022-01-17T21-54-23_766-jvmRun1 surefire6826309622887319820tmp surefire_08112807525188641784tmp [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] org.vrspace.server.core.SessionManagerTest [ERROR] org.apache.maven.surefire.booter.SurefireBooterForkException: The forked VM terminated without properly saying goodbye. VM crash or System.exit called? [ERROR] Command was /bin/sh -c cd /home/admin/vrspace/server && /usr/lib/jvm/java-11-openjdk-amd64/bin/java --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.nio=ALL-UNNAMED --add-opens java.base/java.io=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-opens java.base/sun.nio.ch=ALL-UNNAMED -jar /home/admin/vrspace/server/target/surefire/surefirebooter8993065144439658197.jar /home/admin/vrspace/server/target/surefire 2022-01-17T21-54-23_766-jvmRun1 surefire6826309622887319820tmp surefire_08112807525188641784tmp [ERROR] Error occurred in starting fork, check output in log [ERROR] Process Exit Code: 1 [ERROR] Crashed tests: [ERROR] org.vrspace.server.core.SessionManagerTest [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:669) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:282) [ERROR] at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:245) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1183) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1011) [ERROR] at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:857) [ERROR] at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:137) [ERROR] at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:210) [ERROR] at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:156) [ERROR] at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:148) [ERROR] at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117) [ERROR] at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:81) [ERROR] at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:56) [ERROR] at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128) [ERROR] at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:305) [ERROR] at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:192) [ERROR] at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:105) [ERROR] at org.apache.maven.cli.MavenCli.execute(MavenCli.java:956) [ERROR] at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288) [ERROR] at org.apache.maven.cli.MavenCli.main(MavenCli.java:192) [ERROR] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [ERROR] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [ERROR] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [ERROR] at java.base/java.lang.reflect.Method.invoke(Method.java:566) [ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:282) [ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:225) [ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:406) [ERROR] at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:347) [ERROR] [ERROR] -> [Help 1] [ERROR] [ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch. [ERROR] Re-run Maven using the -X switch to enable full debug logging. [ERROR] [ERROR] For more information about the errors and possible solutions, please read the following articles: [ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException [ERROR] [ERROR] After correcting the problems, you can resume the build with the command [ERROR] mvn -rf :server
`