[BUG-7623] Background inventory fetch stuck in a loop after opening Places floater #15307
Comments
Whirly Fizzle commented at 2014-10-26T00:16:19Z I can reproduce this 100% of tries on 2 different accounts (Whirly Fizzle with 105k inventory & Kippy Adored with 10k inventory).
Observed: Second Life 3.7.18 (295539) Oct 16 2014 09:21:29 (Second Life Release)
Release Notes
You are at 115.0, 94.0, 21.8 in Testylvania Sandbox located at sim10708.agni.lindenlab.com (216.82.53.70:13008)
SLURL: http://maps.secondlife.com/secondlife/Testylvania%20Sandbox/115/94/22
(global coordinates 332,659.0, 306,270.0, 21.8)
Second Life RC Snack 14.10.17.295641
Retrieving...
CPU: Intel(R) Core(TM) i7-4770K CPU @ 3.50GHz (3491.94 MHz)
Memory: 16268 MB
OS Version: Microsoft Windows 7 64-bit Service Pack 1 (Build 7601)
Graphics Card Vendor: NVIDIA Corporation
Graphics Card: GeForce GTX 750/PCIe/SSE2
Windows Graphics Driver Version: 9.18.0013.4448
OpenGL Version: 4.4.0 NVIDIA 344.48
libcurl Version: libcurl/7.37.0 OpenSSL/1.0.1h zlib/1.2.8
J2C Decoder Version: KDU v7.0
Audio Driver Version: FMOD Ex 4.44.31
Qt Webkit Version: 4.7.1 (version number hard-coded)
Voice Server Version: Vivox 4.6.0009.20030
Built with MSVC version 1600
Packets Lost: 112/7,655 (1.5%) |
Whirly Fizzle commented at 2014-10-26T00:18:42Z Does not reproduce on Second Life 3.2.8 (248931) Feb 9 2012 09:04:17 (PRE-CHUI) |
Whirly Fizzle commented at 2014-10-26T00:37:01Z Also to note: When this repro is done on default release, Second Life 3.7.18 (295539) Oct 16 2014 09:21:29 (Second Life Release), there is no excessive log spam generated while the inventory is stuck in a constantly fetching state. However, performing the above repro on the HTTP RC viewer, Second Life 3.7.19 (295700) Oct 20 2014 13:37:20 (Second Life Release), triggers many hundreds of lines of log spam that do not stop until you relog. <SNIP>
2014-10-26T00:34:57Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:58Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:34:59Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
2014-10-26T00:35:00Z INFO: LLInventoryModelBackgroundFetch::setAllFoldersFetched: Inventory background fetch completed
<SNIP> Attached Whirly_HTTP_log.log Second Life 3.7.19 (295700) Oct 20 2014 13:37:20 (Second Life Release)
Release Notes
You are at 115.0, 94.0, 21.8 in Testylvania Sandbox located at sim10708.agni.lindenlab.com (216.82.53.70:13008)
SLURL: http://maps.secondlife.com/secondlife/Testylvania%20Sandbox/115/94/22
(global coordinates 332,659.0, 306,270.0, 21.8)
Second Life RC Snack 14.10.17.295641
Release Notes
CPU: Intel(R) Core(TM) i7-4770K CPU @ 3.50GHz (3491.94 MHz)
Memory: 16268 MB
OS Version: Microsoft Windows 7 64-bit Service Pack 1 (Build 7601)
Graphics Card Vendor: NVIDIA Corporation
Graphics Card: GeForce GTX 750/PCIe/SSE2
Windows Graphics Driver Version: 9.18.0013.4448
OpenGL Version: 4.4.0 NVIDIA 344.48
libcurl Version: libcurl/7.38.0 OpenSSL/1.0.1h zlib/1.2.8
J2C Decoder Version: KDU v7.0
Audio Driver Version: FMOD Ex 4.44.31
Qt Webkit Version: 4.7.1 (version number hard-coded)
Voice Server Version: Vivox 4.6.0009.20030
Built with MSVC version 1600
Packets Lost: 0/4,264 (0.0%) |
Whirly Fizzle commented at 2014-10-26T01:05:04Z I wonder if this repro was the cause for VWR-28897 all along? |
Monty Linden commented at 2014-10-26T05:44:31Z Hmmm, I was worried about spam on this message but never encountered a situation that ran away like this. With a pre-HTTP viewer (one without inventory changes), if you perform the reproducing actions, do you get continuous inventory activity? Without the spam but inventory never seems to settle? The workaround for this may be to use an LL_INFOS_ONCE() logger. It doesn't fix the underlying problem with inventory running forever due to whatever is going on with Places. |
Monty Linden commented at 2014-10-26T05:51:22Z Ah, reading email more carefully, I see this does reproduce (without spam) on release. I'd say -28897 is related, how many experience this? |
Cinder Roxley commented at 2014-10-26T15:24:55Z The issue doesn't cause any additional network activity between the viewer and the simulator. Quelling the log spam would be good except that this can also cause a noticeable frame rate drop, and the user sees their mouse cursor rapidly switching between busy indicator and normal when hovering over any inventory panel (Inventory floater, landmarks panel, received items, etc) along with the false indication that inventory fetching is taking place. I've narrowed the issue further to LLLandmarksPanel. If the Landmarks panel is removed from the Places panel, this issue cannot be reproduced. Landmarks panel doesn't seem to have gotten much love since it was first released in V2 and is rife with code duplication from V2 svn days. My assumption is that during the many rounds of inventory improvement, LLLandmarksPanel was left out of the fun and is no longer doing the right thing. (Such as starting a background inventory fetch when expanding it's panels which should no longer be necessary with AIS3, I would think.) |
Cinder Roxley commented at 2014-10-26T15:26:31Z Not sure how broadly this is experienced. I assume that anybody opening the Places panel and receives new inventory is affected. |
Monty Linden commented at 2014-10-26T16:21:52Z I hope there's no additional network activity. I can imagine the viewer issuing empty inventory fetch requests as fast as possible. :-) Real problem is in the landmarks panel (and possibly elsewhere if it was copied). But I am curious if just killing the log spam improves things. LLLog has always been expensive. In the inventory work, I unified a bunch of cut-n-paste logging into a single one central to all paths. This was a side-effect when one of those paths originally didn't log but spun madly. |
Whirly Fizzle commented at 2014-10-26T17:17:07Z, updated at 2014-10-26T17:20:42Z On my system (same sysinfo as above) the performance drop when this bug is triggered is the same on default release as on the HTTP RC viewer. Default release Second Life 3.7.18 (295539) Oct 16 2014 09:21:29 (Second Life Release)
|
Whirly Fizzle commented at 2014-10-26T17:21:31Z If HTTP Inventory is disabled, I cannot reproduce the inventory ever getting into this constantly fetching state. |
Monty Linden commented at 2014-10-26T17:40:05Z So logging doesn't subjectively make it worse, it's just a huge sign post in the log files? Well, that's one way to draw attention to a two-year-old bug report... |
Whirly Fizzle commented at 2014-10-26T17:51:18Z lol
|
ObviousAltIsObvious commented at 2014-10-26T18:45:07Z Well, this is kind of annoying. I can't reproduce this places floater thing on four different accounts today, but did have inventory stuck in forever-loading twice earlier in the week (can't remember if places floater was up or not at the time). |
Cinder Roxley commented at 2014-10-26T19:10:22Z, updated at 2014-10-26T19:10:53Z Places floater doesn't need to be up to repro, the landmark panel just needs to have been created. Now I'm thinking it might have something to do with the zany and creative way filtering works in the Landmarks panel, but that's just a guess. I haven't been able to pinpoint exactly what functions are causing this. The FPS drop is due to gIdleCallbacks running in the main thread. Once the Landmarks panel gets inventory stuck in this constant fetching state, so many addition function calls end up running in the main thread. |
Whirly Fizzle commented at 2014-10-26T19:19:04Z, updated at 2014-10-26T19:27:47Z Looks like this does somewhat depend on the account. I cannot reproduce this at all on account "FizzleFire Resident" which is pretty much default noob .. no custom inventory items, no Landmarks at all apart from the ones in the Library, no friends, no groups. However, the bug triggered on this account by simply adding 1 single landmark to inventory. Original bug is now repeatable easily on this account after logging in with 1 single custom landmark. |
ObviousAltIsObvious commented at 2014-10-27T09:30:46Z Reproduces reliably now, after a settings enema. This may not be exactly the same as VWR-28897, the grinding on this case with the landmarks seems much more intensive than with other times this has popped up. |
Steps to Reproduce
We've been trying to track down this bug for a few days, finally have it narrowed to the Places floater.
Steps to reproduce (note this doesn't happen on EVERY account, but DOES happen on my account, at least at the time I filed this)
Open Places floater
Rezzed Silly Cannon! object
Open Silly Cannon!
Copy to Inventory
It creates Silly Cannon! folder with a ToS notecard in inventory
Inventory gets stuck in background fetch.
Actual Behavior
Inventory is stuck in a constant state of background fetching. The Inventory floater indicates "28,645 items Fetching..." while the cursor flashes with a Busy indicator when hovering over Inventory. The debug log spits out:
INFO: setAllFoldersFetched: Inventory background fetch completed
FPS is affected by this as well. Note that this happens after the Places floater is closed too, it is just trigged only after Places floater has been opened at least once.
Expected Behavior
Expected that Inventory would create the folder and one notecard and fetch it as it does when Places floater has NOT been opened.
Other information
I really need a diet coke right now.
Attachments
Links
Duplicates
Original Jira Fields
The text was updated successfully, but these errors were encountered: