Mantis Bug Tracker

View Issue Details Jump to Notes ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0006990opensim[REGION] OpenSim Corepublic2014-02-01 13:422015-08-18 09:35
Reporterkenvc 
Assigned Tokenvc 
PriorityhighSeverityminorReproducibilityalways
StatusclosedResolutionfixed 
PlatformDual Xeon quad core 32gbOSWindowsOS VersionServer 2012 64
Product Versionmaster (dev code) 
Target VersionFixed in Versionmaster (dev code) 
Summary0006990: OpenSim.Region.Framework.Scenes.SceneGraph [SCENEGRAPH]: Problem processing action in ForEachSOG
DescriptionWith latest dev master, getting these warnings on startup from almost every sim in every instance. Log file is attached that contains the typical messages that come from one of the instances.

WARN - OpenSim.Region.Framework.Scenes.SceneGraph [SCENEGRAPH]: Problem processing action in ForEachSOG: Error while reading bit stream header or parsing packets.
Steps To ReproduceUse latest dev master and watch console for yellow warning messages as the sim is starting.
Additional InformationSee attached log file
TagsNo tags attached.
Git Revision or version numberr24323
Run Mode Grid (Multiple Regions per Sim)
Physics EngineBulletSim
Environment.NET / Windows64
Mono VersionNone
ViewerN/A
Attached Filestxt file icon Opensim.log.txt [^] (5,533 bytes) 2014-02-01 13:46 [Show Content]
txt file icon Opensim.log.2.txt [^] (4,355 bytes) 2014-02-20 15:57 [Show Content]
txt file icon OpenSim.log.3.txt [^] (56,545 bytes) 2014-02-20 16:14 [Show Content]
log file icon mata.log [^] (34,988 bytes) 2014-02-21 18:10
log file icon mata2.log [^] (68,683 bytes) 2014-02-22 05:01

- Relationships
related to 0006984closed [Map] RenderMeshes=true - Failed to decode mesh asset: Could not load file or assembly 'zlib.net, 
has duplicate 0007026closedMata Hari Error thrown on every sim startup [SCENEGRAPH] 
related to 0007271closedaiaustin Reappearance of [SCENEGRAPH]: Problem processing action in ForEachSOG 

-  Notes
(0025106)
kenvc (reporter)
2014-02-01 15:22
edited on: 2014-02-10 20:01

Just converted a mega to a varregion using the latest dev master. Getting tons of these same warning messages just like when starting a normal sim, but just many more of them now.

(0025160)
kenvc (reporter)
2014-02-10 16:22
edited on: 2014-02-20 13:03

This message is really creating a lot of yellow spam in the console. Does anyone know if this indicates a problem? If so what is it related to?

(0025242)
kenvc (reporter)
2014-02-20 15:50

If Warp3D is turned off, this problem goes away.
If Warp3D is on and DrawPrimOnMapTile = false, the problem also goes away.
(0025243)
kenvc (reporter)
2014-02-20 16:16

Just attached Opensim.log.3.txt that contains the entire startup log created after Justin's changes to add more detail about Warp3D errors. The problem appears to be from Warp3D's inability to decode a texture when making the maptiles.
(0025252)
Mata Hari (reporter)
2014-02-21 06:06

I'm experiencing this as well and my guess would be that the decode problem is with mesh "textures" (not the actual texture but the mesh shape itself). If I disable my main region which contains a *lot* of mesh and only load my "workshop" region that contains no mesh on the ground at all the total load time for the simulator is the usual 20-30 seconds I used to have and no [SCENEGRAPH] messages appear. If I disable that region and enable my main, load time becomes 5+ minutes and I (eventually) get the [SCENGRAPH] error.

I wonder if this might also be related to 0007004 since it's related to a fetch method and seems to somehow get <file unknown> in the path.
(0025255)
kenvc (reporter)
2014-02-21 07:55

I have not noticed the startup delay Mata i9s having, but all other symptoms are the same. I am running Windows 2012 Server, and I think she is running Linux., but I may be wrong.
(0025263)
justincc (administrator)
2014-02-21 15:19

Mata. So if you dump the information on the asset UUIDs reported as problematic it turns out these are actually meshes rather than normal image textures?
(0025265)
Mata Hari (reporter)
2014-02-21 18:09
edited on: 2014-02-21 18:12

My log doesn't contain any asset UUIDs (this using the OSG build which is before you added the new logging stuff so maybe that's why). It just hangs for 0000004:0000005 minutes with no log entries, then spits out the yellow [SCENEGRAPH] message, then finishes the start-up process. Sometimes it will spit out another identical message again another 5 minutes later but by that time logins are enabled and regions are up and running. Switching off DrawPrimOnMapTile as per Ken's suggestion above completely eliminates the problem.

This occurs on both my linux-Ubuntu13.10 (mono 2.10.x) install that hosts my 2 regions on OSG. I'll try building and installing your more recent patch on my Win64/.NET4.0 install but I need to do a complete DB backup, etc first.

I'll attach the complete log of starting this up, letting it just sit there for 0000006:0000010 minutes, then shutting it down again. Note that at 20:48 it starts [SCENE] Loading land assets and then promptly does *nothing* for 5 minutes 10 seconds, then spits out the [SCENEGRAPH ] error. Also note that the same error repeats at 20:59, almost exactly 5 minutes after the regions finish starting scripts. Neither reverences a UUID....both reference <file unknown>....it's almost like it's on a 300 second timer and is sitting there doing nothing because it's been given a NULL filename.

Edit: the reason I think this might be tied to mesh is that it doesn't happen if I disable Paramour (which has a lot of mesh in it) and only load Paramour Workshop which has no mesh at all on the ground. If I enable Paramour and disable Paramour Workshop it happens every single time I launch. I can't be sure that's the reason though, because the workshop has a lot less content overall.

(0025266)
Mata Hari (reporter)
2014-02-21 18:59

Applied r/34374 to my standalone Win64/.NET4.0 and ran with DrawPrimOnMap enabled...started perfectly with no hangs or error messages, loading 6 pretty full regions with lots of mesh in 0000114:0000070 seconds which is pretty much on par with my average load times in the past. I guess next step is to apply the same patch to my linux install and see what it does.
(0025267)
Mata Hari (reporter)
2014-02-21 19:49

Install the identical r/34374 build to my linux install and started simulator. More than 40 minutes later it is *still* attempting to start up. Every 5 minutes I get a pair of [SynchronousRestObjectRequester] messages in the console...first one says "Invalid XML frin GET http://assets.osgrid.org/assets/<a [^] uuid> OpenSim.Framework.AssetBase" and the second one is "Slow request <a request number> http://assets.osgrid.org/assets/<the [^] same uuid> took <x>ms, 0ms writing. (where <x>ms is slightly over 300000.

So far in 40+ minutes of doing this it is at request 0000200 and I think there are around 2000 objects in the region so I guess I'll let this continue to try to load overnight and then paste the log here in the morning (assuming it's even finished loading by then).
(0025269)
Mata Hari (reporter)
2014-02-22 05:01
edited on: 2014-02-22 05:04

Apparently the start-up didn't take that much longer..."only" about an hour. I've attached the log.

I tried searching for the various UUIDs shown in the various error messages but either my search query was wrong (which is entirely possible since I'm not that proficient with MySQL) or those UUIDs are only stored in OSG's asset server's database. If they're supposed to be somewhere in my database could you supply me with a query to locate them.

I also noticed this morning that there is another new OSG release [r/24377] so I installed this and ran it (with DrawPrimOnMapTile=true) and the start-up went extremely smoothly with no [SCENEGRAPH] message at all. It still took about 2 minutes which is about double the normal time, but at least it didn't take an hour. This is a little mystifying because the only commits between the one I ran last night and this one are the 3 Diva added and I can't see how they'd have any effect on this.

EDIT: just realized that's not 100% true...I used the default opensim.exe.config on last night's Win64 and linux tests but used the optional one this morning with r24377

(0025282)
kenvc (reporter)
2014-02-23 11:04

In Windows, the message text has changed with yesterday's dev master, but many yellow messages still appear. Most of these are at startup, but they sometime appear as long as 2 hours after startup and with no one on the sim the whole time as in the examples included from the log below. Note the last 2 error messages are different than the rest:

10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture a62809e3-d8a1
-49f7-b4ea-718a3808644f (6600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture d9074035-cbe4
-4c88-a017-a7cdaf11abd4 (3600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture 50c03a21-c5df
-415e-8c12-26778b4f1b43 (6600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture fa03551a-fd2b
-4d39-8b49-ab76d92443f9 (3600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture 2222c492-6db3
-4ef2-8792-5e55fac2805d (12600 bytes): Error while reading bit stream header or
parsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture 80c566d6-5e02
-486e-a411-189a4be1ef78 (6600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture dd69a706-b4f0
-4511-8739-5fde250d9e60 (4600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture 24afad1e-3b79
-4ea4-b22a-6bb28cff1d52 (6600 bytes): Error while reading bit stream header or p
arsing packets.
10:07:51 - [WARP 3D IMAGE MODULE]: Error decoding JPEG2000 texture c36cb830-1ab5
-4e5c-9de8-4d518291f104 (25600 bytes): Error while reading bit stream header or
parsing packets.
10:08:11 - [WARP 3D IMAGE MODULE]: Failed to decode asset 5c7dd770-b245-4c9f-872
b-0310f1c613ff, exception System.ApplicationException: Error while reading bit
stream header or parsing packets. ---> System.IO.IOException: Position beyond EO
F
12:08:32 - [WARP 3D IMAGE MODULE]: Failed to decode asset 5c7dd770-b245-4c9f-872
b-0310f1c613ff, exception System.ApplicationException: Error while reading bit
stream header or parsing packets. ---> System.IO.IOException: Position beyond EO
F
(0025297)
justincc (administrator)
2014-02-24 12:00

It might be worth trying d6837f5 (r/24379) since this fixed a Warp3D issue with Mantis 6984. However, looking further I suspect that it's probably unrelated.
(0025306)
aiaustin (developer)
2014-02-24 13:43
edited on: 2014-02-24 13:44

6984 was a problem on normal regions unrelated to mega or varregions. But worth testing on the new omv libraries to confirm if the issue here persists past r/24379

(0025369)
kenvc (reporter)
2014-03-05 21:05

Justin, here is something that showed up today on startup in system log:


2014-03-05 23:00:35,919 WARN - OpenSim.Region.CoreModules.World.Warp3DMap.Warp3DImageModule [WARP 3D IMAGE MODULE]: Failed to decode asset 5c7dd770-b245-4c9f-872b-0310f1c613ff, exception
System.ApplicationException: Error while reading bit stream header or parsing packets. ---> System.IO.IOException: Position beyond EOF
   at CSJ2K.j2k.util.ISRandomAccessIO.read()
   at CSJ2K.j2k.util.ISRandomAccessIO.readShort()
   at CSJ2K.j2k.codestream.reader.FileBitstreamReaderAgent..ctor(HeaderDecoder hd, RandomAccessIO ehs, DecoderSpecs decSpec, ParameterList pl, Boolean cdstrInfo, HeaderInfo hi)
   at CSJ2K.j2k.codestream.reader.BitstreamReaderAgent.createInstance(RandomAccessIO in_Renamed, HeaderDecoder hd, ParameterList pl, DecoderSpecs decSpec, Boolean cdstrInfo, HeaderInfo hi)
   at CSJ2K.J2kImage.FromStream(Stream stream)
   --- End of inner exception stack trace ---
   at CSJ2K.J2kImage.FromStream(Stream stream)
   at OpenSim.Region.CoreModules.Agent.TextureSender.J2KDecoderModule.DecodeToImage(Byte[] j2kData) in c:\Users\Administrator\Desktop\Opensim\Opensim Dev Master\OpenSim\Region\CoreModules\Agent\TextureSender\J2KDecoderModule.cs:line 189
   at OpenSim.Region.CoreModules.World.Warp3DMap.Warp3DImageModule.GetTexture(UUID id) in c:\Users\Administrator\Desktop\Opensim\Opensim Dev Master\OpenSim\Region\CoreModules\World\Warp3DMap\Warp3DImageModule.cs:line 646
(0025397)
Mata Hari (reporter)
2014-03-09 18:28

Still seeing this on a regular basis, including with r/24408. There doesn't seem to be anything in particular that is causing it either since there had be absolute no activity at all on the sim for 0000009:0000003 hours after I had logged out.

Below are two consecutive lines from the console

17:14:59 - [CLIENT]: Got a logout request for Mata Hari in Paramour
20:13:28 - [SCENEGRAPH]: Problem processing action in ForEachSOG: The operation has timed out. at System.Net.ConnectStream.Read(Byte[] buffer, Int32 offset, Int32 size)
(0026183)
kenvc (reporter)
2014-05-26 21:56

Have not noticed this issue in a while, but not sure if it is resolved. Has anyone else seen this since the last report from Mata 2 months ago?
(0026185)
Mata Hari (reporter)
2014-05-27 03:59

I haven't seen it either in the last month or so but I have no idea which commit might have fixed it.
(0026201)
AliciaRaven (manager)
2014-05-28 04:38

I had a ForEachSOG error yesterday (27th) but for me it was triggered by Flotsam cache. Maybe its related or just a one off clitch.

27/05/2014 - 09:07: WARN [FLOTSAM ASSET CACHE]: Failed to get file ./assetcache/574/5748decc-f629-461c-9a36-a35a221fe21f for asset 5748decc-f629-461c-9a36-a35a221fe21f. Exception Sharing violation on path /srv/os/assetcache/574/5748decc-f629-461c-9a36-a35a221fe21f at System.IO.FileStream..ctor (System.String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean anonymous, FileOptions options) [0x00000] in <filename unknown>:0
27/05/2014 - 09:07: WARN [SCENEGRAPH]: Problem processing action in ForEachSOG: Sharing violation on path ./assetcache/62b/62b9bf6f-47c5-40e9-b1cc-12ceacdb688a at System.IO.File.SetLastAccessTime (System.String path, DateTime lastAccessTime) [0x00000] in <filename unknown>:0
(0026445)
kenvc (reporter)
2014-07-06 15:01

This issue appears to have gone away, although we have no idea which revision fixed it. Closing this issue because it appears to be resolved, but please reopen or create a new mantis if it comes back up.
(0029259)
aiaustin (developer)
2015-08-18 09:35

Resolved issue marked as closed. Please open a new issue and refer to this one if problems arise.

- Issue History
Date Modified Username Field Change
2014-02-01 13:42 kenvc New Issue
2014-02-01 13:46 kenvc File Added: Opensim.log.txt
2014-02-01 15:22 kenvc Note Added: 0025106
2014-02-05 22:28 kenvc Note Added: 0025129
2014-02-05 22:28 kenvc Status new => confirmed
2014-02-10 16:22 kenvc Note Added: 0025160
2014-02-10 16:23 kenvc Note Deleted: 0025129
2014-02-10 18:13 kenvc Note Edited: 0025160 View Revisions
2014-02-10 20:01 kenvc Note Edited: 0025106 View Revisions
2014-02-13 19:16 kenvc Note Added: 0025182
2014-02-13 19:17 kenvc Note Added: 0025183
2014-02-20 13:02 kenvc Note Deleted: 0025182
2014-02-20 13:02 kenvc Note Deleted: 0025183
2014-02-20 13:03 kenvc Note Edited: 0025160 View Revisions
2014-02-20 15:50 kenvc Note Added: 0025242
2014-02-20 15:57 kenvc File Added: Opensim.log.2.txt
2014-02-20 16:14 kenvc File Added: OpenSim.log.3.txt
2014-02-20 16:16 kenvc Note Added: 0025243
2014-02-21 05:56 Mata Hari Relationship added related to 0007026
2014-02-21 05:56 Mata Hari Relationship replaced has duplicate 0007026
2014-02-21 06:06 Mata Hari Note Added: 0025252
2014-02-21 07:55 kenvc Note Added: 0025255
2014-02-21 15:19 justincc Note Added: 0025263
2014-02-21 18:09 Mata Hari Note Added: 0025265
2014-02-21 18:10 Mata Hari File Added: mata.log
2014-02-21 18:12 Mata Hari Note Edited: 0025265 View Revisions
2014-02-21 18:59 Mata Hari Note Added: 0025266
2014-02-21 19:49 Mata Hari Note Added: 0025267
2014-02-22 05:01 Mata Hari Note Added: 0025269
2014-02-22 05:01 Mata Hari File Added: mata2.log
2014-02-22 05:04 Mata Hari Note Edited: 0025269 View Revisions
2014-02-23 11:04 kenvc Note Added: 0025282
2014-02-24 11:58 justincc Relationship added related to 0006984
2014-02-24 12:00 justincc Note Added: 0025297
2014-02-24 13:43 aiaustin Note Added: 0025306
2014-02-24 13:44 aiaustin Note Edited: 0025306 View Revisions
2014-02-24 13:44 aiaustin Note Edited: 0025306 View Revisions
2014-03-05 21:05 kenvc Note Added: 0025369
2014-03-09 18:28 Mata Hari Note Added: 0025397
2014-05-26 21:56 kenvc Note Added: 0026183
2014-05-27 03:59 Mata Hari Note Added: 0026185
2014-05-28 04:38 AliciaRaven Note Added: 0026201
2014-07-06 15:01 kenvc Note Added: 0026445
2014-07-06 15:01 kenvc Status confirmed => resolved
2014-07-06 15:01 kenvc Fixed in Version => master (dev code)
2014-07-06 15:01 kenvc Resolution open => fixed
2014-07-06 15:01 kenvc Assigned To => kenvc
2014-07-18 03:29 aiaustin Relationship added related to 0007271
2015-08-18 09:35 aiaustin Note Added: 0029259
2015-08-18 09:35 aiaustin Status resolved => closed


Copyright © 2000 - 2012 MantisBT Group
Powered by Mantis Bugtracker