Skip to content
This repository has been archived by the owner on Mar 28, 2024. It is now read-only.

[BUG-11929] Appearance update is STILL broken after recent changes in 4.0.4 (314579) #2039

Open
3 tasks
sl-service-account opened this issue May 11, 2016 · 3 comments

Comments

@sl-service-account
Copy link

sl-service-account commented May 11, 2016

The release of the recent maintenance update 4.0.4 (314579) included some fixes for avatar appearance updates, that should fix stale appearance update requests. These don't appear to have any effect though, as appearance updates are still broken due to version mismatches of the local COF version and the COF version the server expects.

Original cause is still the handling of attachments being rezzed during login, leading to a COF version mismatch. These will consequently produce appearance update failures and the log gets spammed with according error messages, as the appearance update request coroutine appears to get invoked multiple times (for each attachment rezzed):

2016-05-11T09:11:42Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Appearance Failure. server responded with "Cof Version Mismatch: 27350 != 27359"
2016-05-11T09:11:42Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Server expected 27359 as COF version
2016-05-11T09:11:42Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Bake retry count exceeded!
2016-05-11T09:11:42Z INFO:#LLCoros LLCoros::generateDistinctName: LLCoros: launching coroutine serverAppearanceUpdateCoro
2016-05-11T09:11:42Z INFO:#LLCoros LLCoros::cleanup: LLCoros: cleaning up coroutine serverAppearanceUpdateCoro2
2016-05-11T09:11:42Z INFO:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting COF version 27360 (Last Received:27316) (Last Requested:27350)
2016-05-11T09:11:42Z INFO: LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting bake for COF version 27360
2016-05-11T09:11:43Z INFO: LLAvatarRenderInfoAccountant::idle: LRI: Scanning all regions and checking for render info updates
2016-05-11T09:11:45Z WARNING:#CoreHttp LLCore::HttpPolicy::stageAfterCompletion: HTTP request 24C10B80 failed after 0 retries.  Reason:  Bad Request (Http_400)
2016-05-11T09:11:45Z WARNING: LLCoreHttpUtil::HttpCoroHandler::onCompleted: 
--------------------------------------------------------------------------
 Error[Http_400] cannot access url 'https://sim10114.agni.lindenlab.com:12043/cap/68fe816e-0c56-ffd0-1933-636a0aef8769' because Bad Request
--------------------------------------------------------------------------
2016-05-11T09:11:45Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Appearance Failure. server responded with "Cof Version Mismatch: 27360 != 27365"
2016-05-11T09:11:45Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Server expected 27365 as COF version
2016-05-11T09:11:45Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Bake retry #1 in 1.000000 seconds.
2016-05-11T09:11:46Z INFO:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting COF version 27360 (Last Received:27316) (Last Requested:27360)
2016-05-11T09:11:46Z INFO: LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting bake for COF version 27360
2016-05-11T09:11:47Z INFO: display_stats: FPS: 62.90
2016-05-11T09:11:48Z INFO: LLAvatarRenderInfoAccountant::idle: LRI: Scanning all regions and checking for render info updates
2016-05-11T09:11:48Z INFO:#LLCoros LLCoros::generateDistinctName: LLCoros: launching coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro
2016-05-11T09:11:48Z INFO:#AvatarRenderInfoAccountant LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro: LRI: Sending avatar render info to region Windcross from https://sim10114.agni.lindenlab.com:12043/cap/7cfdfbc5-e6a5-42b9-752f-bf0073193928
2016-05-11T09:11:48Z INFO: LLVOAvatar::calculateUpdateRenderCost: local_texture: head_tattoo: 4b109111-d5f1-b2c2-c6be-479b3b64fd3a
2016-05-11T09:11:48Z INFO:#AvatarRenderInfoAccountant LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro: LRI: Sending avatar render info for c36d0839-d3f9-41a4-a747-9dba3cd18fb7: {'weight':i115003}
2016-05-11T09:11:48Z INFO:#AvatarRenderInfoAccountant LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro: LRI: other info geometry 3172352, area 76.292328
2016-05-11T09:11:48Z INFO: LLAvatarRenderInfoAccountant::getRenderInfoFromRegion: LRI: Requesting avatar render info for region Windcross from https://sim10114.agni.lindenlab.com:12043/cap/7cfdfbc5-e6a5-42b9-752f-bf0073193928
2016-05-11T09:11:48Z INFO:#LLCoros LLCoros::generateDistinctName: LLCoros: launching coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoGetCoro
2016-05-11T09:11:49Z WARNING:#CoreHttp LLCore::HttpPolicy::stageAfterCompletion: HTTP request 24C0F258 failed after 0 retries.  Reason:  Bad Request (Http_400)
2016-05-11T09:11:49Z WARNING: LLCoreHttpUtil::HttpCoroHandler::onCompleted: 
--------------------------------------------------------------------------
 Error[Http_400] cannot access url 'https://sim10114.agni.lindenlab.com:12043/cap/68fe816e-0c56-ffd0-1933-636a0aef8769' because Bad Request
--------------------------------------------------------------------------
2016-05-11T09:11:49Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Appearance Failure. server responded with "Cof Version Mismatch: 27360 != 27365"
2016-05-11T09:11:49Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Server expected 27365 as COF version
2016-05-11T09:11:49Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Bake retry #2 in 3.000000 seconds.
2016-05-11T09:11:49Z INFO: LLAvatarRenderInfoAccountant::avatarRenderInfoGetCoro: LRI:  Agent c36d0839-d3f9-41a4-a747-9dba3cd18fb7: {'weight':i93238}
2016-05-11T09:11:49Z INFO:#LLCoros LLCoros::cleanup: LLCoros: cleaning up coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoGetCoro
2016-05-11T09:11:49Z INFO:#AvatarRenderInfoAccountant LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro: LRI: Result for avatar weights POST for region Windcross: {'http_result':{'headers':{},'message':'','status':i0,'success':1,'type':i200,'url':'https://sim10114.agni.lindenlab.com:12043/cap/7cfdfbc5-e6a5-42b9-752f-bf0073193928'}}
2016-05-11T09:11:49Z INFO:#LLCoros LLCoros::cleanup: LLCoros: cleaning up coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro
2016-05-11T09:11:50Z INFO: LLCircuitData::dumpResendCountAndReset: Circuit: 216.82.48.180:13017 resent 2 packets
2016-05-11T09:11:52Z INFO:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting COF version 27360 (Last Received:27316) (Last Requested:27360)
2016-05-11T09:11:52Z INFO: LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting bake for COF version 27360
2016-05-11T09:11:53Z INFO: LLAvatarRenderInfoAccountant::idle: LRI: Scanning all regions and checking for render info updates
2016-05-11T09:11:53Z WARNING:#CoreHttp LLCore::HttpPolicy::stageAfterCompletion: HTTP request 24C0F258 failed after 0 retries.  Reason:  Bad Request (Http_400)
2016-05-11T09:11:53Z WARNING: LLCoreHttpUtil::HttpCoroHandler::onCompleted: 
--------------------------------------------------------------------------
 Error[Http_400] cannot access url 'https://sim10114.agni.lindenlab.com:12043/cap/68fe816e-0c56-ffd0-1933-636a0aef8769' because Bad Request
--------------------------------------------------------------------------
2016-05-11T09:11:53Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Appearance Failure. server responded with "Cof Version Mismatch: 27360 != 27365"
2016-05-11T09:11:53Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Server expected 27365 as COF version
2016-05-11T09:11:53Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Bake retry #3 in 7.000000 seconds.
2016-05-11T09:11:57Z INFO: display_stats: FPS: 53.00
2016-05-11T09:11:58Z INFO: LLAvatarRenderInfoAccountant::idle: LRI: Scanning all regions and checking for render info updates
2016-05-11T09:11:58Z INFO:#LLCoros LLCoros::generateDistinctName: LLCoros: launching coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro
2016-05-11T09:11:58Z INFO:#AvatarRenderInfoAccountant LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro: LRI: Sending avatar render info to region Lucy Lu from https://sim10269.agni.lindenlab.com:12043/cap/074a04d4-2299-f5e2-22d6-29eae949e9a0
2016-05-11T09:11:58Z INFO: LLAvatarRenderInfoAccountant::getRenderInfoFromRegion: LRI: Requesting avatar render info for region Lucy Lu from https://sim10269.agni.lindenlab.com:12043/cap/074a04d4-2299-f5e2-22d6-29eae949e9a0
2016-05-11T09:11:58Z INFO:#LLCoros LLCoros::generateDistinctName: LLCoros: launching coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoGetCoro
2016-05-11T09:11:58Z INFO:#LLCoros LLCoros::cleanup: LLCoros: cleaning up coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoReportCoro
2016-05-11T09:11:59Z INFO:#LLCoros LLCoros::cleanup: LLCoros: cleaning up coroutine LLAvatarRenderInfoAccountant::avatarRenderInfoGetCoro
2016-05-11T09:12:00Z INFO:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting COF version 27360 (Last Received:27316) (Last Requested:27360)
2016-05-11T09:12:00Z INFO: LLAppearanceMgr::serverAppearanceUpdateCoro: Requesting bake for COF version 27360
2016-05-11T09:12:02Z WARNING:#CoreHttp LLCore::HttpPolicy::stageAfterCompletion: HTTP request 24C10DB0 failed after 0 retries.  Reason:  Bad Request (Http_400)
2016-05-11T09:12:02Z WARNING: LLCoreHttpUtil::HttpCoroHandler::onCompleted: 
--------------------------------------------------------------------------
 Error[Http_400] cannot access url 'https://sim10114.agni.lindenlab.com:12043/cap/68fe816e-0c56-ffd0-1933-636a0aef8769' because Bad Request
--------------------------------------------------------------------------
2016-05-11T09:12:02Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Appearance Failure. server responded with "Cof Version Mismatch: 27360 != 27365"
2016-05-11T09:12:02Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Server expected 27365 as COF version
2016-05-11T09:12:02Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Bake retry #4 in 15.000000 seconds.

Above excerpt from the viewer log file was from a session when I logged in my avatar with the Second Life viewer for the first time. At the end, I tried to detach a wearable item, which of course didn't produce any visible effect -> appearance was stuck.

This might also be caused by the fact that the re-request doesn't work as intended. This is the relevant code in llappearancemgr.cpp which handles the case of a bad appearance update request:

            std::string message = (result.has("error")) ? result["error"].asString() : status.toString();
            LL_WARNS("Avatar") << "Appearance Failure. server responded with \"" << message << "\"" << LL_ENDL;

            // We may have requested a bake for a stale COF (especially if the inventory 
            // is still updating.  If that is the case re send the request with the 
            // corrected COF version.  (This may also be the case if the viewer is running 
            // on multiple machines.
            if (result.has("expected"))
            {

                S32 expectedCofVersion = result["expected"].asInteger();
                LL_WARNS("Avatar") << "Server expected " << expectedCofVersion << " as COF version" << LL_ENDL;

                bRetry = true;
                // Wait for a 1/2 second before trying again.  Just to keep from asking too quickly.
                if (++retryCount > BAKE_RETRY_MAX_COUNT)
                {
                    LL_WARNS("Avatar") << "Bake retry count exceeded!" << LL_ENDL;
                    break;
                }
                F32 timeout = pow(BAKE_RETRY_TIMEOUT, static_cast<float>(retryCount)) - 1.0;

                LL_WARNS("Avatar") << "Bake retry #" << retryCount << " in " << timeout << " seconds." << LL_ENDL;

                llcoro::suspendUntilTimeout(timeout); 
                bRetry = true;
                continue;

If you look at the comment, it says the request should be re-send with the corrected COF version. The corrected (= expected) COF version is then extracted from the response and printed out before the re-request is issued. But that is apparently all - there is no correction happening at all. Shouldn't the local COF version (and possibly gAgentAvatarp->mLastUpdateRequestCOFVersion and gAgentAvatarp->mLastUpdateReceivedCOFVersion) get set to the expected version first before issuing the request again?

Attachments

Links

Related

Original Jira Fields
Field Value
Issue BUG-11929
Summary Appearance update is STILL broken after recent changes in 4.0.4 (314579)
Type Bug
Priority Unset
Status Accepted
Resolution Accepted
Reporter Ansariel Hiller (ansariel.hiller)
Created at 2016-05-11T09:13:43Z
Updated at 2016-09-17T19:14:13Z
{
  'Business Unit': ['Platform'],
  'Date of First Response': '2016-05-12T19:35:15.598-0500',
  'ReOpened Count': 0.0,
  'Severity': 'Unset',
  'System': 'SL Viewer',
  'Target Viewer Version': 'viewer-development',
  'What just happened?': 'Filling in...',
  'What were you doing when it happened?': '-',
  'What were you expecting to happen instead?': '-',
}
@sl-service-account
Copy link
Author

Whirly Fizzle commented at 2016-05-13T00:35:16Z

I thought the bake fail bug was fixed for me - but for some reason it's happening to me every login today on the new QuickGraphics-RC Second Life 4.0.5.315117 (Second Life Release).

  • Log attached - Whirly1.log
  • I logged in wearing a saved outfit & saw my log was very unhappy showing constant bake retries which didn't stop.
2016-05-13T00:23:56Z WARNING:#CoreHttp LLCore::HttpPolicy::stageAfterCompletion: HTTP request 172837A0 failed after 0 retries.  Reason:  Bad Request (Http_400)
2016-05-13T00:23:56Z WARNING: LLCoreHttpUtil::HttpCoroHandler::onCompleted: 
--------------------------------------------------------------------------
 Error[Http_400] cannot access url 'https://sim8922.agni.lindenlab.com:12043/cap/3df16ab7-b234-f8af-367f-20a8f87e6080' because Bad Request
--------------------------------------------------------------------------
2016-05-13T00:23:56Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Appearance Failure. server responded with "Cof Version Mismatch: 161259 != 161263"
2016-05-13T00:23:56Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Server expected 161263 as COF version
2016-05-13T00:23:56Z WARNING:#Avatar LLAppearanceMgr::serverAppearanceUpdateCoro: Bake retry count exceeded!
  • I waited a few minutes & it didn't settle down.
  • Then I replaced outfit with default female: Develop -> Avatar -> Character Tests -> Test female.
  • My avatar bake was stuck on the old bake: http://prnt.sc/b3e7qv
  • I had to relog on a different viewer to fix it.
Second Life 4.0.5.315117 (Second Life Release)
Release Notes

You are at 89.9, 115.0, 22.0 in Testylvania Sandbox located at sim8922.agni.lindenlab.com (216.82.41.98:12035)
SLURL: http://maps.secondlife.com/secondlife/Testylvania%20Sandbox/90/115/22
(global coordinates 332,634.0, 306,291.0, 22.0)
Second Life Server 16.04.21.314319
Error fetching server release notes URL.

CPU: Intel(R) Core(TM) i7-4770K CPU @ 3.50GHz (3491.93 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: 10.18.0013.6472
OpenGL Version: 4.5.0 NVIDIA 364.72

J2C Decoder Version: KDU v7.2
Audio Driver Version: FMOD Ex 4.44.31
LLCEFLib/CEF Version: 1.5.3-(CEF-WIN-3.2526.1347-32)
Voice Server Version: Vivox 4.6.0017.22050

Packets Lost: 97/14,022 (0.7%)

I hate this bug :/

@sl-service-account
Copy link
Author

Whirly Fizzle commented at 2016-05-13T00:50:33Z, updated at 2016-05-13T00:53:04Z

  • Attached Whirly2.log
  • I logged out of Second Life 4.0.5.315117 (Second Life Release) wearing the default female avatar.
  • Then I relogged on Second Life 4.0.5.315117 (Second Life Release)
  • I waited a few minutes then changed to the default male avatar.
  • This was the result - failed bake: http://prnt.sc/b3ecjj

@sl-service-account
Copy link
Author

Whirly Fizzle commented at 2016-05-19T21:17:54Z, updated at 2016-05-19T21:19:17Z

Still reproduces on http://automated-builds-secondlife-com.s3.amazonaws.com/hg/repo/clefable/rev/315545/index.html

  • Logged in.

  • Saw in logs the appearance errors right from login.

  • Waited a few mins then changed into default female avatar: Develop -> Avatar -> Character Tests -> Test female.

  • This was the result: http://prnt.sc/b63bpu

  • Bake remained stuck on the old bake & several attachments (shoes, one earing & one mesh eye) from the old outfit were not removed.

  • Log attached - Whirly3.log

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

1 participant