vircadia / vircadia-native-core

Vircadia open source agent-based metaverse ecosystem.
https://vircadia.com/
Other
533 stars 174 forks source link

Two crashes on Linux #1378

Open Penguin-Guru opened 2 years ago

Penguin-Guru commented 2 years ago

I upgraded various software on my system and have since experienced multiple issues with Vircadia-x86_64_v2021.1.3-Eos.AppImage. I won't bother mentioning the ones that I think can be solved on my end but...

Here is an excerpt from one instance where I tried to run the program. It quickly crashed, producing that output. I ran it again and no issue occurred. Seemed worth mentioning:

[09/29 19:37:13] [DEBUG] [hifi.networking] unreasonable sequence number: 18 (possible duplicate) [09/29 19:37:13] [DEBUG] [hifi.networking] unreasonable sequence number: 19 (possible duplicate) [09/29 19:37:13] [DEBUG] [hifi.interface.deadlock] DEADLOCK WATCHDOG WARNING: lastHeartbeatAge: 178575 elapsedMovingAverage: 3819 maxElapsed: 17863938 PREVIOUS maxElapsedAverage: 3812 NEW maxElapsedAverage: 3819 NEW MAX ELAPSED AVERAGE samples: 2443 [09/29 19:37:15] [DEBUG] [hifi.audioclient] getAvailableDevices Default device not found in list: "" Setting Default to: "default" [Previous message was repeated 7 times] [09/29 19:37:28] [DEBUG] [hifi.scriptengine] Found script in cache: "sitClient.js" [Previous message was repeated 1 times] [09/29 19:37:28] [DEBUG] [hifi.scriptengine] "Retrying script request [4 / 5]" [09/29 19:37:28] [DEBUG] [hifi.networking] Error loading: NotFound resource: "https://cdn-1.vircadia.com/us-e-1/Bazaar/Avatars/Woody/mannequin.fst" [09/29 19:37:28] [WARNING] [hifi.avatars.rendering] Using default after failing to load Avatar model, after 0 attempts. [09/29 19:37:28] [WARNING] [hifi.image] Failed to load: (Invalid Format) [09/29 19:37:28] [DEBUG] [hifi.networking] Error loading: NotFound resource: "atp:/Models/LandAnchor.fbx" [09/29 19:37:28] [WARNING] [hifi.image] Failed to load: (Invalid Format) [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found 7f61614835c71cb270ab6ab5152ccd3a [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found 395149f03b294a82ae20254cb94b4fa8 [09/29 19:37:28] [DEBUG] [hifi.networking] Error loading: NotFound resource: "https://files.tivolicloud.com/dave_k/models/stripes.gif" [09/29 19:37:28] [DEBUG] [hifi.networking] Error loading: NotFound resource: "https://files.tivolicloud.com/dave_k/models/in use.psd" [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found e8689f88eada692f6080f4747c9fba5e [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found cc8e27a0c69565e704a3d787a3b5010a [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found 4f860f81b82f223d28b863447c279ac0 [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found 301b1b40805369f3fa95864de141b253 [09/29 19:37:28] [DEBUG] [hifi.avatars] Removed avatar with UUID "8daa071c-e0ea-4024-ab0c-a1f1706baeec" from AvatarHashMap 1 [09/29 19:37:28] [CRITICAL] [hifi.scriptengine] [FloofChat.js] [UncaughtException signalHandlerException] Error: Result of expression 'AvatarManager.getPalData([sessionID]).data[0]' [undefined] is not an object. in file:///tmp/.mount_VircadjMtwtH/vircadia/interface/scripts/communityScripts/chat/FloofChat.js:668 [09/29 19:37:28] [CRITICAL] [hifi.scriptengine] [Backtrace] [09/29 19:37:28] [CRITICAL] [hifi.scriptengine] avatarLeavesDomain(sessionID = '{8daa071c-e0ea-4024-ab0c-a1f1706baeec}') at file:///tmp/.mount_VircadjMtwtH/vircadia/interface/scripts/communityScripts/chat/FloofChat.js:668 [09/29 19:37:28] [CRITICAL] [hifi.scriptengine] () at -1 [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found ad25598152ca09ba53d1e022163bbc6f [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found 66aa74bff131f77ab178a4cc69ddbe1b [09/29 19:37:28] [DEBUG] [hifi.file_cache] [ktx_cache] Found 11544e252de5734c8c4a10309ca62c35

I'm going to attach a (much) longer log of all output from a different run attempt. In this case, I ran the program, waited for things to load somewhat, then tried to go somewhere with the Explore app. Nothing happened. I tried a few more times and got no results. I then tried to go somewhere else using Explore. This did eventually work, but there was a lengthy delay and then The Hub began to load much slower than the several times I've loaded it before. Even after everything seemed to have fully loaded, the program lagged significantly. My processor utilisation was around 75% just running Vircadia (usually it's about 45%...). This issue occurred the previous time I tried to run the program too. Not sure if it will continue. vircadia.log

Feel free to close this issue if you're aware of the causes.

Penguin-Guru commented 2 years ago

Here's another one. I ran the program, waited a while, opened the Explore app, then switched virtual desktops to do something. A minute or so later, I heard the audio connection sound; then maybe 3-10 seconds of normal background audio for my initial spawn location (The Hub). I switched back to see what was going on and the application had crashed. Last several lines of output below.

[09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "material_16_3577" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "material123577" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "material_15___3577" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "glassEdge" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "clearGlass" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "stipple" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Material.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "glass" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Stipple-light" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Metal-1" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Stipple-dark" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Glass.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Glow" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Material" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "(217, 217, 217)" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Grass" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "ArmFabric.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "LowerStockingsOld.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "LowerStockings.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Fishnet.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] OBJSerializer material library "Courtyard-COLL.mtl" [09/30 16:48:27] [DEBUG] [hifi.entities] kinematic timestep = 266394 truncated to 1 [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Fabric.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "String.001" [09/30 16:48:27] [DEBUG] [hifi.modelformat] fbx material Name: "Metal.001" Vircadia-x86_64_v2021.1.3-Eos.AppImage: /home/motofckr9k/Vircadia/source/libraries/render-utils/src/Model.cpp:298: virtual bool Model::updateGeometry(): Assertion `_meshStates.empty()' failed.

Penguin-Guru commented 2 years ago

I successfully connected to Hayashi. A few seconds later, without having moved or even looked around, my client crashed. Output below.

[10/01 13:59:43] [DEBUG] [hifi.audioclient] getAvailableDevices Default device not found in list: "" Setting Default to: "default" [10/01 13:59:44] [DEBUG] [hifi.interface.deadlock] DEADLOCK WATCHDOG WARNING: lastHeartbeatAge: 64196 elapsedMovingAverage: 3479 maxElapsed: 2062306 PREVIOUS maxElapsedAverage: 3474 NEW maxElapsedAverage: 3479 NEW MAX ELAPSED AVERAGE samples: 10541 [10/01 13:59:45] [DEBUG] [hifi.interface.deadlock] DEADLOCK WATCHDOG WARNING: lastHeartbeatAge: 96097 elapsedMovingAverage: 3484 maxElapsed: 2062306 PREVIOUS maxElapsedAverage: 3479 NEW maxElapsedAverage: 3484 NEW MAX ELAPSED AVERAGE samples: 10551 [10/01 13:59:45] [DEBUG] [hifi.audioclient] getAvailableDevices Default device not found in list: "" Setting Default to: "default" [10/01 13:59:45] [DEBUG] [hifi.interface] No matching url "" [10/01 13:59:45] [WARNING] [default] Use of deprecated not tread-safe setter, use setUrlRequestInterceptor instead. [Previous message was repeated 1 times] [10/01 13:59:45] [DEBUG] [hifi.scriptengine] [defaultScripts.js] PEOPLE connecting function fromQml() { [10/01 13:59:45] [DEBUG] [hifi.scriptengine] [native code] [10/01 13:59:45] [DEBUG] [hifi.scriptengine] } [10/01 13:59:45] [DEBUG] [hifi.controllers] Attempting to enable mapping "file:///tmp/.mount_Vircad3cTUQb/vircadia/interface/scripts/system/pal.js-click" [10/01 13:59:45] [DEBUG] [hifi.controllers] Attempting to enable mapping "file:///tmp/.mount_Vircad3cTUQb/vircadia/interface/scripts/system/pal.js-press" [10/01 13:59:45] [DEBUG] [hifi.networking] Sending packet to get username/fingerprint/admin status of node "ebf92401-7844-4414-8a15-0f93185ef8a3" [10/01 13:59:45] [WARNING] [default] qrc:/qml/hifi/Pal.qml:1396:5: QML Connections: Implicitly defined onFoo properties in Connections are deprecated. Use this syntax instead: function onFoo() { ... } [10/01 13:59:45] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] PAL data: {"profileUrl":"","displayName":"Nova","userName":"","connection":"","sessionId":"{ebf92401-7844-4414-8a15-0f93185ef8a3}","audioLevel":0,"avgAudioLevel":0,"admin":false,"personalMute":false,"ignore":false,"isPresent":true,"isReplicated":false} [10/01 13:59:45] [DEBUG] [hifi.networking] Sending packet to get username/fingerprint/admin status of node "9d8779eb-8f94-45ac-93a4-9d8ad0d6d0e2" [10/01 13:59:45] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] PAL data: {"profileUrl":"","displayName":"Kenneth Rougeau","userName":"","connection":"","sessionId":"{9d8779eb-8f94-45ac-93a4-9d8ad0d6d0e2}","audioLevel":0,"avgAudioLevel":0,"admin":false,"personalMute":false,"ignore":false,"isPresent":true,"isReplicated":false} [10/01 13:59:45] [DEBUG] [hifi.networking] Sending packet to get username/fingerprint/admin status of node "00000000-0000-0000-0000-000000000000" [10/01 13:59:45] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] PAL data: {"profileUrl":"","displayName":"Newby","userName":"Unknown user","connection":"","sessionId":"","audioLevel":0,"avgAudioLevel":0,"admin":false,"personalMute":false,"ignore":false,"isPresent":true,"isReplicated":false} [10/01 13:59:45] [WARNING] [default] qrc:/qml/hifi/Pal.qml:697:13: QML Connections: Implicitly defined onFoo properties in Connections are deprecated. Use this syntax instead: function onFoo() { ... } [10/01 13:59:45] [WARNING] [default] qrc:/qml/hifi/Pal.qml:85:5: QML Connections: Implicitly defined onFoo properties in Connections are deprecated. Use this syntax instead: function onFoo() { ... } [10/01 13:59:45] [WARNING] [default] qrc:/qml/controls/+webengine/FlickableWebViewCore.qml:21:5: Unable to assign [undefined] to bool [10/01 13:59:45] [DEBUG] [hifi.audioclient] getAvailableDevices Default device not found in list: "" Setting Default to: "default" [10/01 13:59:46] [DEBUG] [hifi.networking] Got username "" and machine fingerprint "{00000000-0000-0000-0000-000000000000}" for node "{ebf92401-7844-4414-8a15-0f93185ef8a3}" . isAdmin: true [10/01 13:59:46] [DEBUG] [hifi.networking] Got username "" and machine fingerprint "{00000000-0000-0000-0000-000000000000}" for node "{9d8779eb-8f94-45ac-93a4-9d8ad0d6d0e2}" . isAdmin: true [10/01 13:59:46] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] Error: unable to get request failure [10/01 13:59:46] [DEBUG] [hifi.interface.deadlock] DEADLOCK WATCHDOG WARNING: lastHeartbeatAge: 291241 elapsedMovingAverage: 3487 maxElapsed: 2062306 PREVIOUS maxElapsedAverage: 3484 NEW maxElapsedAverage: 3487 NEW MAX ELAPSED AVERAGE samples: 10559 [10/01 13:59:46] [DEBUG] [hifi.ui] setKeyboardRaised: DefaultFrame_QMLTYPE_24(0x55f812d667b0, name = "Frame") , raised: false , numeric: false , password: false [10/01 13:59:46] [DEBUG] [hifi.networking] Got username "" and machine fingerprint "{c0230150-fc0f-4269-db49-345680f012be}" for node "{69a8f360-7cee-4dd3-95b0-653c800e5365}" . isAdmin: false [10/01 13:59:46] [DEBUG] [hifi.modelformat] fbx material Name: "mat.avatar-hover" [10/01 13:59:46] [DEBUG] [hifi.modelformat] fbx material Name: "mat.avatar-active" [10/01 13:59:46] [DEBUG] [hifi.modelformat] fbx material Name: "mat.avatar-idle" [10/01 13:59:46] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] PAL update: {"sessionId":"{ebf92401-7844-4414-8a15-0f93185ef8a3}","userName":"","admin":true} [10/01 13:59:46] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] PAL update: {"sessionId":"{9d8779eb-8f94-45ac-93a4-9d8ad0d6d0e2}","userName":"","admin":true} [10/01 13:59:46] [DEBUG] [hifi.scriptengine.script] [defaultScripts.js] PAL update: {"sessionId":"","userName":"","admin":false} [10/01 13:59:46] [DEBUG] [hifi.file_cache] [ktx_cache] Found d6fcf3d90d6c13dae449a44334d6030f [10/01 13:59:46] [DEBUG] [hifi.file_cache] [ktx_cache] Found 095f537a58b6bf61a95df4d7faabd354 [10/01 13:59:46] [DEBUG] [hifi.file_cache] [ktx_cache] Found c977bf0e318a4b5d71eacb726f266ace [10/01 13:59:46] [DEBUG] [hifi.file_cache] [ktx_cache] Found 86c218b2fc0a15c6bde3ec9d7af0f12d [10/01 13:59:46] [DEBUG] [hifi.file_cache] [ktx_cache] Found a833bd3280e245c53f59d6221c6d0824 [10/01 13:59:46] [DEBUG] [hifi.file_cache] [ktx_cache] Found 3f4cf309cff94581688744751b850a77 [10/01 13:59:46] [DEBUG] [hifi.entitiesrenderer] Autoresizing "file:///tmp/.mount_Vircad3cTUQb/vircadia/interface/scripts/system/assets/models/Avatar-Overlay-v1.fbx" from mesh extents [10/01 13:59:46] [DEBUG] [hifi.modelformat] fbx material Name: "Material" [10/01 13:59:46] [DEBUG] [hifi.modelformat] fbx material Name: "Material.001" [10/01 13:59:46] [DEBUG] [hifi.entitiesrenderer] Autoresizing "file:///tmp/.mount_Vircad3cTUQb/vircadia/interface/scripts/system/assets/models/Avatar-Overlay-v1.fbx" from mesh extents Segmentation fault

daleglass commented 2 years ago

One of those is #958

Penguin-Guru commented 2 years ago

I ran the same AppImage as always and it crashed about when my avatar would normally appear.

[10/09 10:57:52] [DEBUG] [hifi.modelformat] fbx material Name: "Glass-Conf" [10/09 10:57:52] [DEBUG] [hifi.audioclient] getAvailableDevices Default device not found in list: "" Setting Default to: "default" [10/09 10:57:52] [DEBUG] [hifi.modelformat] root node "2051765072384" has discarded parent "2052646062464" [10/09 10:57:52] [DEBUG] [hifi.interface.deadlock] DEADLOCK WATCHDOG WARNING: lastHeartbeatAge: 53137 elapsedMovingAverage: 700 maxElapsed: 488257 PREVIOUS maxElapsedAverage: 694 NEW maxElapsedAverage: 700 NEW MAX ELAPSED AVERAGE samples: 46 [10/09 10:57:52] [DEBUG] [hifi.modelformat] fbx material Name: "01 - Default" [10/09 10:57:52] [DEBUG] [hifi.entities] Entity types must start with an uppercase letter. Please change the type "shape" [Previous message was repeated 2 times] [10/09 10:57:52] [DEBUG] [hifi.entities] script failed to add new Entity to local Octree [10/09 10:57:52] [DEBUG] [hifi.modelformat] fbx material Name: "Material.002" [10/09 10:57:52] [DEBUG] [hifi.controllers] Creating new Mapping "file:///tmp/.mount_VircadfN8aJe/vircadia/interface/scripts/system/create/entitySelectionTool/entitySelectionTool.js-click" [10/09 10:57:52] [DEBUG] [hifi.controllers] Creating new Mapping "file:///tmp/.mount_VircadfN8aJe/vircadia/interface/scripts/system/create/entitySelectionTool/entitySelectionTool.js-press" [10/09 10:57:52] [DEBUG] [hifi.controllers] Creating new Route builder proxy from "270663680" [10/09 10:57:52] [DEBUG] [hifi.controllers] Completing route "function (clicked) { // Don't allow both hands to trigger at the same time if (that.triggered() && hand !== that.triggeredHand) { return; } if (!that.triggered() && clicked && !pointingAtDesktopWindowOrTablet(hand)) { that.triggeredHand = hand; that.mousePressEvent({}); } else if (that.triggered() && !clicked) { that.triggeredHand = NO_HAND; that.mouseReleaseEvent({}); } }" [10/09 10:57:52] [DEBUG] [hifi.controllers] Creating new Route builder proxy from "270008320" [10/09 10:57:52] [DEBUG] [hifi.controllers] Completing route "function (clicked) { // Don't allow both hands to trigger at the same time if (that.triggered() && hand !== that.triggeredHand) { return; } if (!that.triggered() && clicked && !pointingAtDesktopWindowOrTablet(hand)) { that.triggeredHand = hand; that.mousePressEvent({}); } else if (that.triggered() && !clicked) { that.triggeredHand = NO_HAND; that.mouseReleaseEvent({}); } }" [10/09 10:57:52] [DEBUG] [hifi.entities] kinematic timestep = 722432 truncated to 1 [10/09 10:57:52] [DEBUG] [hifi.controllers] Creating new Route builder proxy from "537198592" [10/09 10:57:52] [DEBUG] [hifi.controllers] Completing route "function (value) { if (value >= TRIGGER_ON_VALUE && !that.triggered() && !pointingAtDesktopWindowOrTablet(hand)) { that.pressedHand = hand; that.updateHighlight({}); } else { that.pressedHand = NO_HAND; that.resetPreviousHandleColor(); } }" [10/09 10:57:52] [DEBUG] [hifi.controllers] Creating new Route builder proxy from "537133056" [10/09 10:57:52] [DEBUG] [hifi.controllers] Completing route "function (value) { if (value >= TRIGGER_ON_VALUE && !that.triggered() && !pointingAtDesktopWindowOrTablet(hand)) { that.pressedHand = hand; that.updateHighlight({}); } else { that.pressedHand = NO_HAND; that.resetPreviousHandleColor(); } }" [10/09 10:57:52] [DEBUG] [hifi.entities] kinematic timestep = 722432 truncated to 1 [Previous message was repeated 1 times] [10/09 10:57:52] [DEBUG] [hifi.scriptengine.module] ScriptEngine::require( "./modules/createWindow.js" ) [10/09 10:57:52] [DEBUG] [hifi.scriptengine.module] newModule "" [10/09 10:57:52] [DEBUG] [hifi.scriptengine.module] require.fetchModuleSource: "createWindow.js" QThread(0x557ff54cdf30, name = "js:defaultScripts.js") [10/09 10:57:52] [DEBUG] [hifi.audio] Processing sound file "confirmation.mp3" [10/09 10:57:52] [DEBUG] [hifi.audio] Processing sound file "rejection.mp3" [10/09 10:57:52] [DEBUG] [hifi.audio] Decoding MP3 with bitrate = 128000 sample rate = 44100 channels = 2 [Previous message was repeated 1 times] [10/09 10:57:52] [DEBUG] [hifi.scriptengine.module] "require.instantiateModule: createWindow.js / 5081 bytes" [10/09 10:57:52] [DEBUG] [hifi.scriptengine.module] //ScriptEngine::require( "./modules/createWindow.js" ) [10/09 10:57:52] [DEBUG] [vircadia.networking.external_resource] Requested URL for bucket ExternalResource::Bucket::Assets , path "Bazaar/Assets/Textures/Defaults/Interface/default_image.jpg" [10/09 10:57:52] [DEBUG] [vircadia.networking.external_resource] External resource resolved to QUrl("https://cdn-1.vircadia.com/us-e-1/Bazaar/Assets/Textures/Defaults/Interface/default_image.jpg") [10/09 10:57:52] [DEBUG] [vircadia.networking.external_resource] Requested URL for bucket ExternalResource::Bucket::Assets , path "Bazaar/Assets/Textures/Defaults/Interface/default_particle.png" [10/09 10:57:52] [DEBUG] [vircadia.networking.external_resource] External resource resolved to QUrl("https://cdn-1.vircadia.com/us-e-1/Bazaar/Assets/Textures/Defaults/Interface/default_particle.png") Vircadia-x86_64_v2021.1.3-Eos.AppImage: /home/motofckr9k/Vircadia/source/libraries/render-utils/src/Model.cpp:298: virtual bool Model::updateGeometry(): Assertion `_meshStates.empty()' failed. Aborted

stale[bot] commented 2 years ago

Hello! Is this still an issue?