Mantis Bug Tracker
Main | My View | View Issues | Change Log | Roadmap | Summary | My Account
  

View Issue Details [ Jump to Notes ] [ Issue History ] [ Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0007764opensim[REGION] OpenSim Corepublic2015-11-26 04:242015-12-03 09:35
Reporteraiaustin 
Assigned Toaiaustin 
PrioritynormalSeverityminorReproducibilityalways
StatusclosedResolutionfixed 
PlatformPCOperating SystemWindowsOperating System Version10
Product Versionmaster (dev code) 
Target Versionmaster (dev code)Fixed in Versionmaster (dev code) 
Summary0007764: ENTITY TRANSFER child agent handling incorrect?
DescriptionCould a dev with knowledge of the new cross region and child agent in adjacent take a look at the example OpenSAim.exe console trace below... as I am seeing a large number of yellow warnings of these types since the avination code merge...

[Assets]: Upload failed: 00000000-0000-0000-0000-000000000000 - Requeuing asset for another run.

[LLUDPSERVER]: No packets received from child agent of ... for 60000ms in .... Disconnecting

After the avatar logs off one region, 12 minutes later (i.e. more than 60000ms) we get another batch of warnings with timeouts for all adjacent regions.

It looks like some tidying up is not being done correctly on avatar logoff?

16:51:13 - [ENTITY TRANSFER STATE MACHINE]: SetInTransit. agent=7e111df9-31a6-43ee-8d64-0e5a329730a1, newState=Preparing
16:51:13 - [ENTITY TRANSFER STATE MACHINE]: UpdateInTransit. agent=7e111df9-31a6-43ee-8d64-0e5a329730a1, newState=Transferring
16:51:13 - [CrossAgentIntoNewRegionMain]: ok, time 188ms
16:51:13 - [ENTITY TRANSFER MODULE]: Sending new CAPS seed url http://virtual3.aiai.ed.ac.uk:9000/CAPS/162ab796-12a4-4da9-bb82-0f977ed170190000/ [^] to client 7e111df9-31a6-43ee-8d64-0e5a329730a1
16:51:13 - [ENTITY TRANSFER STATE MACHINE]: UpdateInTransit. agent=7e111df9-31a6-43ee-8d64-0e5a329730a1, newState=ReceivedAtDestination
16:51:13 - [ENTITY TRANSFER STATE MACHINE]: UpdateInTransit. agent=7e111df9-31a6-43ee-8d64-0e5a329730a1, newState=CleaningUp
16:51:13 - [SCENE PRESENCE]: Closing child agents. Checking 9 regions in Sandbox
16:51:13 - [SCENE PRESENCE]: Making Billy.Bradshaw @hg.viewtwo.net:8600 a child agent in Sandbox from root region 9949480722061568
16:51:13 - [ENTITY TRANSFER STATE MACHINE]: Agent 7e111df9-31a6-43ee-8d64-0e5a329730a1 cleared from transit in Sandbox
16:51:13 - [ENTITY TRANSFER MODULE]: Crossing agent Billy.Bradshaw @hg.viewtwo.net:8600 completed.
16:51:23 - [Assets]: Upload failed: 00000000-0000-0000-0000-000000000000 - Requeuing asset for another run.


17:04:12 - [LLUDPSERVER]: No packets received from child agent of Billy.Bradshaw @hg.viewtwo.net:8600 for 60000ms in Vue-Port. Disconnecting.
17:04:12 - [CLIENT]: Close has been called for Billy.Bradshaw @hg.viewtwo.net:8600 attached to scene Vue-Port
17:04:12 - [SCENE]: Removing child agent Billy.Bradshaw @hg.viewtwo.net:8600 7e111df9-31a6-43ee-8d64-0e5a329730a1 from Vue-Port
17:04:12 - [CAPS]: Remove caps for agent 7e111df9-31a6-43ee-8d64-0e5a329730a1 in region Vue-Port
17:04:12 - [Scene]: The avatar has left the building
17:04:12 - [LLUDPSERVER]: No packets received from child agent of Billy.Bradshaw @hg.viewtwo.net:8600 for 60000ms in Sandbox. Disconnecting.
17:04:12 - [CLIENT]: Close has been called for Billy.Bradshaw @hg.viewtwo.net:8600 attached to scene Sandbox
17:04:12 - [SCENE]: Removing child agent Billy.Bradshaw @hg.viewtwo.net:8600 7e111df9-31a6-43ee-8d64-0e5a329730a1 from Sandbox
17:04:12 - [CAPS]: Remove caps for agent 7e111df9-31a6-43ee-8d64-0e5a329730a1 in region Sandbox
17:04:12 - [Scene]: The avatar has left the building
17:04:13 - [LLUDPSERVER]: No packets received from child agent of Billy.Bradshaw @hg.viewtwo.net:8600 for 60000ms in Openvue. Disconnecting.
17:04:13 - [CLIENT]: Close has been called for Billy.Bradshaw @hg.viewtwo.net:8600 attached to scene Openvue
17:04:13 - [SCENE]: Removing child agent Billy.Bradshaw @hg.viewtwo.net:8600 7e111df9-31a6-43ee-8d64-0e5a329730a1 from Openvue
17:04:13 - [CAPS]: Remove caps for agent 7e111df9-31a6-43ee-8d64-0e5a329730a1 in region Openvue
17:04:13 - [HG INVENTORY CONNECTOR]: Removed http://hg.viewtwo.net:8600 [^] from the cache of inventory URLs
17:04:13 - [Scene]: The avatar has left the building
17:04:14 - [LLUDPSERVER]: No packets received from child agent of Billy.Bradshaw @hg.viewtwo.net:8600 for 60000ms in OpenVCE. Disconnecting.
17:04:14 - [CLIENT]: Close has been called for Billy.Bradshaw @hg.viewtwo.net:8600 attached to scene OpenVCE
17:04:14 - [SCENE]: Removing child agent Billy.Bradshaw @hg.viewtwo.net:8600 7e111df9-31a6-43ee-8d64-0e5a329730a1 from OpenVCE
17:04:14 - [CAPS]: Remove caps for agent 7e111df9-31a6-43ee-8d64-0e5a329730a1 in region OpenVCE
17:04:14 - [Scene]: The avatar has left the building
TagsNo tags attached.
Git Revision or version number
Run Mode Grid (Multiple Regions per Sim)
Physics EngineBulletSim
Script Engine
Environment.NET / Windows64
Mono VersionNone
ViewerN/A
Attached Filestxt file icon 2015-12-01-Openvue-Complete-Login-Logoff-Trace-Showing-Upload-Failed.txt [^] (18,349 bytes) 2015-12-01 00:45 [Show Content]
jpg file icon 2015-12-02-Openvue-Map.jpg [^] (324,848 bytes) 2015-12-02 06:10

- Relationships

-  Notes
(0029705)
UbitUmarov (administrator)
2015-11-26 18:59

 On that log I don't see a "legal" avatar logout, or tp away. Did the viewer crash?
(0029714)
aiaustin (developer)
2015-11-27 01:17
edited on: 2015-11-27 03:09

 I don't think so, but it was a HG visitor so I cannot say in this instance. This is just the end of the logging for this user after they had gone home I believe. I was simply extracting the end bit of the log to show the messages of this form for each adjacent (child agent) region involved...

[LLUDPSERVER]: No packets received from child agent of Billy.Bradshaw @hg.viewtwo.net:8600 for 60000ms in OpenVCE. Disconnecting.

I see these, I think, on HG visitor log off or TP away from my grids for all child regions adjacent to the one the avatar was on. I can see if I can get a complete log on and log off trace followed by what happens in next 5 minutes as time outs occur if that would help.
(0029719)
UbitUmarov (administrator)
2015-11-27 07:09

 16:51:13 - [ENTITY TRANSFER MODULE]: Crossing agent Billy.Bradshaw @hg.viewtwo.net:8600 completed.
was the last movement on the log, no teleports, no logout.
the timeouts are a consequence of that.
(0029765)
aiaustin (developer)
2015-12-01 00:40
edited on: 2015-12-01 00:45

 I continue to see instances of this warning...

[Assets] Upload failed: 00000000-0000-0000-0000-000000000000 - Requeuing asset for another run

They definitely only started after the avination code merge. But were there when that merge first took place, ad had not been seen on a dev master version that was not long before the merge date.

The UUID involved is always reported as 00000000-0000-0000-0000-000000000000.

I attach the complete OpenSim.log trace from login to log off. It shows quite a few of the upload failed messages.

2015-12-01-Openvue-Complete-Login-Logoff-Trace-Showing-Upload-Failed.txt

I cannot see anything unsual in the longer OpenSim.log file. Anyone else seeing this or can spot a pattern or cause?
(0029766)
UbitUmarov (administrator)
2015-12-01 01:20
edited on: 2015-12-02 05:59

 From the log that seems related to a attachment or wearable asset...
or a viewer auxiliary script...
(0029770)
aiaustin (developer)
2015-12-01 04:12
edited on: 2015-12-01 04:12

 Okay... interesting. I wonder if "Billy.Bradshaw @hg.viewtwo.net:8600" sees these Mantis entries or wants to comment? I will point him to this if I see him in world. I sometimes overlap with him.
(0029780)
aiaustin (developer)
2015-12-02 05:52
edited on: 2015-12-02 05:56

 Just a note that I think as of today with dev master (opensim-0.9.0-143-gd5e21a0.zip) I seem to be seeing less of this form of message...

[LLUDPSERVER]: No packets received from child agent of Ai Austin for 60000ms in Vue-Port. Disconnecting.

But I see just one now that is exactly ONE minute after my own avatar logs off, so I am sure it was a clean logoff. Its a local avatar not a HG visitor. The region is two 256x256m regions away and one I just teleported from a few minutes earlier. I am not exactly sure that is relevant, but its NOT the region I am on at logoff. I will see if I can more exactly pin this down now I know I can see this message with a local avatar that is my own.
(0029781)
aiaustin (developer)
2015-12-02 06:10
edited on: 2015-12-02 06:24

 I think I can see the pattern. Note in these tests I am on Openvue grid on opensim-0.9.0-143-gd5e21a0.zip. Openvue has only 256mx256m regions and always has had. I was using Firestorm 4.7.5 on Windows 10, and OpenSim server is also Windows 10. Viewer draw distance is set to my usual 512m not the more extreme longer distance that Firestorm allows. See 2015-12-02-Openvue-map.jpg for the layout.

I am on a region with adjacent regions. I teleport at least two regions away. I log off.

I get the following message for each REGIONNAME for a region that is adjacent to (or maybe within draw distance of) the original source region but that is NOT within draw distance (512m or two regions here) of the destination after the teleport. Hence why I sometimes see one and sometimes more than one of these yellow warnings.

[LLUDPSERVER]: No packets received from child agent of Ai Austin for 60000ms in REGIONNAME. Disconnecting.

It looks like its the child agents in the surroundings of the SOURCE of a teleport on a grid that is not cleaning up correctly when the child agent regions are NOT in the set of child agents for the destination of the TP. This may also occur on logoff though I am not sure of that.

A specific example.. referring to the map attached as 2015-12-02-Openvue-map.jpg

I am on Far North on Login. I let things settle. I teleport to Sandbox (4 regions away, its on another physical region server, but that seems not to matter)) and again let things settle, and then log off.

I see this ONE MINUTE after the original logoff... where the three regions are within 512m draw distance of the Far North source region before the teleport (in the case of Vue South, only just from corner to corner), but are not within the 512m draw distance of the destination region.


14:14:34 - [LLUDPSERVER]: No packets received from child agent of Ai Austin for 60000ms in Vue South. Disconnecting.
14:14:34 - [CLIENT]: Close has been called for Ai Austin attached to scene Vue South
14:14:34 - [SCENE]: Removing child agent Ai Austin e24a9015-f5ca-452b-8c95-d32e34cb9d64 from Vue South
14:14:34 - [CAPS]: Remove caps for agent e24a9015-f5ca-452b-8c95-d32e34cb9d64 in region Vue South
14:14:34 - [Scene]: The avatar has left the building
14:14:37 - [LLUDPSERVER]: No packets received from child agent of Ai Austin for 60000ms in Vue. Disconnecting.
14:14:37 - [CLIENT]: Close has been called for Ai Austin attached to scene Vue
14:14:37 - [SCENE]: Removing child agent Ai Austin e24a9015-f5ca-452b-8c95-d32e34cb9d64 from Vue
14:14:37 - [CAPS]: Remove caps for agent e24a9015-f5ca-452b-8c95-d32e34cb9d64 in region Vue
14:14:37 - [Scene]: The avatar has left the building
14:14:38 - [LLUDPSERVER]: No packets received from child agent of Ai Austin for 60000ms in Vue North. Disconnecting.
14:14:38 - [CLIENT]: Close has been called for Ai Austin attached to scene Vue North
14:14:38 - [SCENE]: Removing child agent Ai Austin e24a9015-f5ca-452b-8c95-d32e34cb9d64 from Vue North
14:14:38 - [CAPS]: Remove caps for agent e24a9015-f5ca-452b-8c95-d32e34cb9d64 in region Vue North
14:14:38 - [Scene]: The avatar has left the building
(0029784)
UbitUmarov (administrator)
2015-12-02 17:29

 ok there was a 1m difference in the regions view range estimations
But this code needs a lot of improvement :(
(0029785)
aiaustin (developer)
2015-12-03 01:39

 I had been starting to think this might be an out by a fraction on the computation of which regions were in the child region set given viewer distances can be set over many regions. At 1024m view range for example on my setup with 256x256 regions that could include 4 regions in each direction! That's a LOT of child agents.
(0029786)
UbitUmarov (administrator)
2015-12-03 01:46

 currently view range is internally limited to 512m (configurable I think)
regions view range will be independent of objects view range, both from user selection but different clamp values.
regions view range also needs to be from avatar position and lot region edge
A 8km side region can have a lot of neighbors.
(0029788)
aiaustin (developer)
2015-12-03 09:32

 As discussed in world and on IRC Ubit... I believe the adjustment for an out by 1 error in commit opensim-0.9.0-144-gc903e3a has fixed the problem for warning being given for regions adjacent to regions an avatar teleports away from.

LLUDPSERVER]: No packets received from child agent ... for 60000ms
(0029789)
aiaustin (developer)
2015-12-03 09:35

 Resolved in commit opensim-0.9.0-144-gc903e3a.zip (2015-12-03 01:13) by UbitUmarov.

We have to get an administrator to add your user name into the list of users who can be selected for "assigned to" in mantis.

- Issue History
Date Modified Username Field Change
2015-11-26 04:24 aiaustin New Issue
2015-11-26 18:59 UbitUmarov Note Added: 0029705
2015-11-27 01:17 aiaustin Note Added: 0029714
2015-11-27 01:17 aiaustin Note Edited: 0029714 View Revisions
2015-11-27 01:18 aiaustin Note Edited: 0029714 View Revisions
2015-11-27 01:19 aiaustin Note Edited: 0029714 View Revisions
2015-11-27 02:44 aiaustin Note Edited: 0029714 View Revisions
2015-11-27 02:45 aiaustin Note Edited: 0029714 View Revisions
2015-11-27 03:09 aiaustin Note Edited: 0029714 View Revisions
2015-11-27 07:09 UbitUmarov Note Added: 0029719
2015-12-01 00:40 aiaustin Note Added: 0029765
2015-12-01 00:40 aiaustin Note Edited: 0029765 View Revisions
2015-12-01 00:44 aiaustin Note Edited: 0029765 View Revisions
2015-12-01 00:44 aiaustin File Added: 2015-12-01-Openvue-Complete-Login-Logoff-Trace-Showing-Uopload-Failed.txt
2015-12-01 00:45 aiaustin File Deleted: 2015-12-01-Openvue-Complete-Login-Logoff-Trace-Showing-Uopload-Failed.txt
2015-12-01 00:45 aiaustin File Added: 2015-12-01-Openvue-Complete-Login-Logoff-Trace-Showing-Upload-Failed.txt
2015-12-01 00:45 aiaustin Note Edited: 0029765 View Revisions
2015-12-01 01:20 UbitUmarov Note Added: 0029766
2015-12-01 01:25 UbitUmarov Note Added: 0029767
2015-12-01 04:12 aiaustin Note Added: 0029770
2015-12-01 04:12 aiaustin Note Edited: 0029770 View Revisions
2015-12-02 05:52 aiaustin Note Added: 0029780
2015-12-02 05:55 aiaustin Note Edited: 0029780 View Revisions
2015-12-02 05:56 aiaustin Note Edited: 0029780 View Revisions
2015-12-02 05:56 aiaustin Note Edited: 0029780 View Revisions
2015-12-02 05:59 aiaustin Note Edited: 0029766 View Revisions
2015-12-02 05:59 aiaustin Note Deleted: 0029767
2015-12-02 06:10 aiaustin Note Added: 0029781
2015-12-02 06:10 aiaustin File Added: 2015-12-02-Openvue-Map.jpg
2015-12-02 06:21 aiaustin Note Edited: 0029781 View Revisions
2015-12-02 06:22 aiaustin Note Edited: 0029781 View Revisions
2015-12-02 06:24 aiaustin Note Edited: 0029781 View Revisions
2015-12-02 17:29 UbitUmarov Note Added: 0029784
2015-12-03 01:39 aiaustin Note Added: 0029785
2015-12-03 01:46 UbitUmarov Note Added: 0029786
2015-12-03 01:48 UbitUmarov Note Added: 0029787
2015-12-03 09:32 aiaustin Note Added: 0029788
2015-12-03 09:32 aiaustin Note Deleted: 0029787
2015-12-03 09:35 aiaustin Note Added: 0029789
2015-12-03 09:35 aiaustin Status new => resolved
2015-12-03 09:35 aiaustin Fixed in Version => master (dev code)
2015-12-03 09:35 aiaustin Resolution open => fixed
2015-12-03 09:35 aiaustin Assigned To => aiaustin
2015-12-03 09:35 aiaustin Status resolved => closed

Copyright © 2000 - 2012 MantisBT Group
Powered by Mantis Bugtracker