From f45ba33ff828bc21330ea4055353a4de5a5007ca Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Fri, 9 Oct 2020 16:18:19 +0100 Subject: SL-14081 - more detailed logging of teleport process --- indra/newview/llagent.cpp | 147 ++++++++++++++++++++++++++++++++++---- indra/newview/llagent.h | 4 ++ indra/newview/llviewerdisplay.cpp | 8 +++ indra/newview/llviewermessage.cpp | 14 +++- 4 files changed, 158 insertions(+), 15 deletions(-) diff --git a/indra/newview/llagent.cpp b/indra/newview/llagent.cpp index 166c2d67c8..04b89399b0 100644 --- a/indra/newview/llagent.cpp +++ b/indra/newview/llagent.cpp @@ -137,6 +137,10 @@ public: EStatus getStatus() const {return mStatus;}; void setStatus(EStatus pStatus) {mStatus = pStatus;}; + static std::map sTeleportStatusName; + static const std::string& statusName(EStatus status); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport() = 0; @@ -148,12 +152,45 @@ private: EStatus mStatus; }; +std::map LLTeleportRequest::sTeleportStatusName = { { kPending, "kPending" }, + { kStarted, "kStarted" }, + { kFailed, "kFailed" }, + { kRestartPending, "kRestartPending"} }; + +// TODO this enum -> name idiom should be in a common class rather than repeated various places. +const std::string& LLTeleportRequest::statusName(EStatus status) +{ + static std::string invalid_status_str("INVALID"); + auto iter = LLTeleportRequest::sTeleportStatusName.find(status); + if (iter != LLTeleportRequest::sTeleportStatusName.end()) + { + return iter->second; + } + else + { + return invalid_status_str; + } +} + +std::ostream& operator<<(std::ostream& os, const LLTeleportRequest& req) +{ + req.toOstream(os); + return os; +} + +void LLTeleportRequest::toOstream(std::ostream& os) const +{ + os << "status " << statusName(mStatus) << "(" << mStatus << ")"; +} + class LLTeleportRequestViaLandmark : public LLTeleportRequest { public: LLTeleportRequestViaLandmark(const LLUUID &pLandmarkId); virtual ~LLTeleportRequestViaLandmark(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -172,6 +209,8 @@ public: LLTeleportRequestViaLure(const LLUUID &pLureId, BOOL pIsLureGodLike); virtual ~LLTeleportRequestViaLure(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -189,6 +228,8 @@ public: LLTeleportRequestViaLocation(const LLVector3d &pPosGlobal); virtual ~LLTeleportRequestViaLocation(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -208,6 +249,8 @@ public: LLTeleportRequestViaLocationLookAt(const LLVector3d &pPosGlobal); virtual ~LLTeleportRequestViaLocationLookAt(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -2629,6 +2672,7 @@ void LLAgent::handlePreferredMaturityResult(U8 pServerMaturity) else { mMaturityPreferenceNumRetries = 0; + LL_WARNS() << "Too many retries for maturity preference" << LL_ENDL; reportPreferredMaturityError(); } } @@ -2680,6 +2724,7 @@ void LLAgent::reportPreferredMaturityError() mIsMaturityRatingChangingDuringTeleport = false; if (hasPendingTeleportRequest()) { + LL_WARNS("Teleport") << "Teleport failing due to preferred maturity error" << LL_ENDL; setTeleportState(LLAgent::TELEPORT_NONE); } @@ -3775,7 +3820,7 @@ void LLAgent::clearVisualParams(void *data) // protected bool LLAgent::teleportCore(bool is_local) { - LL_INFOS("Teleport") << "In teleport core!" << LL_ENDL; + LL_DEBUGS("Teleport") << "In teleport core" << LL_ENDL; if ((TELEPORT_NONE != mTeleportState) && (mTeleportState != TELEPORT_PENDING)) { LL_WARNS() << "Attempt to teleport when already teleporting." << LL_ENDL; @@ -3841,11 +3886,13 @@ bool LLAgent::teleportCore(bool is_local) add(LLStatViewer::TELEPORT, 1); if (is_local) { + LL_INFOS("Teleport") << "Setting teleport state to TELEPORT_LOCAL" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_LOCAL ); } else { gTeleportDisplay = TRUE; + LL_INFOS("Teleport") << "Non-local, setting teleport state to TELEPORT_START" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_START ); //release geometry from old location @@ -3912,6 +3959,7 @@ void LLAgent::startTeleportRequest() if (!isMaturityPreferenceSyncedWithServer()) { gTeleportDisplay = TRUE; + LL_INFOS("Teleport") << "Maturity preference not synced yet, setting teleport state to TELEPORT_PENDING" << LL_ENDL; setTeleportState(TELEPORT_PENDING); } else @@ -4009,8 +4057,8 @@ void LLAgent::teleportRequest( LLViewerRegion* regionp = getRegion(); if (regionp && teleportCore(region_handle == regionp->getHandle())) { - LL_INFOS("") << "TeleportLocationRequest: '" << region_handle << "':" - << pos_local << LL_ENDL; + LL_INFOS("Teleport") << "Sending TeleportLocationRequest: '" << region_handle << "':" + << pos_local << LL_ENDL; LLMessageSystem* msg = gMessageSystem; msg->newMessage("TeleportLocationRequest"); msg->nextBlockFast(_PREHASH_AgentData); @@ -4041,6 +4089,11 @@ void LLAgent::doTeleportViaLandmark(const LLUUID& landmark_asset_id) LLViewerRegion *regionp = getRegion(); if(regionp && teleportCore()) { + LL_INFOS("Teleport") << "Sending TeleportLandmarkRequest. Current region handle " << regionp->getHandle() + << " region id " << regionp->getRegionID() + << " requested landmark id " << landmark_asset_id + << LL_ENDL; + LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_TeleportLandmarkRequest); msg->nextBlockFast(_PREHASH_Info); @@ -4073,6 +4126,11 @@ void LLAgent::doTeleportViaLure(const LLUUID& lure_id, BOOL godlike) teleport_flags |= TELEPORT_FLAGS_VIA_LURE; } + LL_INFOS("Teleport") << "Sending TeleportLureRequest." + << " Current region handle " << regionp->getHandle() + << " region id " << regionp->getRegionID() + << " lure id " << lure_id + << LL_ENDL; // send the message LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_TeleportLureRequest); @@ -4095,6 +4153,8 @@ void LLAgent::teleportCancel() LLViewerRegion* regionp = getRegion(); if(regionp) { + LL_INFOS("Teleport") << "Sending TeleportCancel" << LL_ENDL; + // send the message LLMessageSystem* msg = gMessageSystem; msg->newMessage("TeleportCancel"); @@ -4107,13 +4167,14 @@ void LLAgent::teleportCancel() } clearTeleportRequest(); gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); - gPipeline.resetVertexBuffers(); + gPipeline.resetVertexBuffers(); } void LLAgent::restoreCanceledTeleportRequest() { if (mTeleportCanceled != NULL) { + LL_INFOS() << "Restoring canceled teleport request, setting state to TELEPORT_REQUESTED" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_REQUESTED ); mTeleportRequest = mTeleportCanceled; mTeleportCanceled.reset(); @@ -4151,7 +4212,6 @@ void LLAgent::doTeleportViaLocation(const LLVector3d& pos_global) else if(regionp && teleportCore(regionp->getHandle() == to_region_handle_global((F32)pos_global.mdV[VX], (F32)pos_global.mdV[VY]))) { - LL_WARNS() << "Using deprecated teleportlocationrequest." << LL_ENDL; // send the message LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_TeleportLocationRequest); @@ -4171,6 +4231,14 @@ void LLAgent::doTeleportViaLocation(const LLVector3d& pos_global) msg->addVector3Fast(_PREHASH_Position, pos); pos.mV[VX] += 1; msg->addVector3Fast(_PREHASH_LookAt, pos); + + LL_WARNS("Teleport") << "Sending deprecated(?) TeleportLocationRequest." + << " pos_global " << pos_global + << " region_x " << region_x + << " region_y " << region_y + << " region_handle " << region_handle + << LL_ENDL; + sendReliableMessage(); } } @@ -4212,7 +4280,11 @@ void LLAgent::setTeleportState(ETeleportState state) " for previously failed teleport. Ignore!" << LL_ENDL; return; } - LL_DEBUGS("Teleport") << "Setting teleport state to " << state << " Previous state: " << mTeleportState << LL_ENDL; + LL_DEBUGS("Teleport") << "Setting teleport state to " + << LLAgent::teleportStateName(state) << "(" << state << ")" + << " Previous state: " + << teleportStateName(mTeleportState) << "(" << mTeleportState << ")" + << LL_ENDL; mTeleportState = state; if (mTeleportState > TELEPORT_NONE && gSavedSettings.getBOOL("FreezeTime")) { @@ -4549,6 +4621,34 @@ void LLAgent::observeFriends() } } +std::map LLAgent::sTeleportStateName = { { TELEPORT_NONE, "TELEPORT_NONE" }, + { TELEPORT_START, "TELEPORT_START" }, + { TELEPORT_REQUESTED, "TELEPORT_REQUESTED" }, + { TELEPORT_MOVING, "TELEPORT_MOVING" }, + { TELEPORT_START_ARRIVAL, "TELEPORT_START_ARRIVAL" }, + { TELEPORT_ARRIVING, "TELEPORT_ARRIVING" }, + { TELEPORT_LOCAL, "TELEPORT_LOCAL" }, + { TELEPORT_PENDING, "TELEPORT_PENDING" } }; + +const std::string& LLAgent::teleportStateName(S32 state) +{ + static std::string invalid_state_str("INVALID"); + auto iter = LLAgent::sTeleportStateName.find(state); + if (iter != LLAgent::sTeleportStateName.end()) + { + return iter->second; + } + else + { + return invalid_state_str; + } +} + +const std::string& LLAgent::getTeleportStateName() const +{ + return teleportStateName(getTeleportState()); +} + void LLAgent::parseTeleportMessages(const std::string& xml_filename) { LLXMLNodePtr root; @@ -4675,37 +4775,41 @@ void LLTeleportRequest::restartTeleport() //----------------------------------------------------------------------------- // LLTeleportRequestViaLandmark //----------------------------------------------------------------------------- - LLTeleportRequestViaLandmark::LLTeleportRequestViaLandmark(const LLUUID &pLandmarkId) : LLTeleportRequest(), mLandmarkId(pLandmarkId) { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark created." << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark created, " << *this << LL_ENDL; } LLTeleportRequestViaLandmark::~LLTeleportRequestViaLandmark() { - LL_INFOS("Teleport") << "~LLTeleportRequestViaLandmark" << LL_ENDL; + LL_INFOS("Teleport") << "~LLTeleportRequestViaLandmark, " << *this << LL_ENDL; +} + +void LLTeleportRequestViaLandmark::toOstream(std::ostream& os) const +{ + os << "landmark " << mLandmarkId << " "; + LLTeleportRequest::toOstream(os); } bool LLTeleportRequestViaLandmark::canRestartTeleport() { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::canRestartTeleport? -> true" << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::canRestartTeleport? -> true, " << *this << LL_ENDL; return true; } void LLTeleportRequestViaLandmark::startTeleport() { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::startTeleport" << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::startTeleport, " << *this << LL_ENDL; gAgent.doTeleportViaLandmark(getLandmarkId()); } void LLTeleportRequestViaLandmark::restartTeleport() { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::restartTeleport" << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::restartTeleport, " << *this << LL_ENDL; gAgent.doTeleportViaLandmark(getLandmarkId()); } - //----------------------------------------------------------------------------- // LLTeleportRequestViaLure //----------------------------------------------------------------------------- @@ -4722,6 +4826,12 @@ LLTeleportRequestViaLure::~LLTeleportRequestViaLure() LL_INFOS("Teleport") << "~LLTeleportRequestViaLure" << LL_ENDL; } +void LLTeleportRequestViaLure::toOstream(std::ostream& os) const +{ + os << "mIsLureGodLike " << (S32) mIsLureGodLike << " "; + LLTeleportRequestViaLandmark::toOstream(os); +} + bool LLTeleportRequestViaLure::canRestartTeleport() { // stinson 05/17/2012 : cannot restart a teleport via lure because of server-side restrictions @@ -4762,6 +4872,12 @@ LLTeleportRequestViaLocation::~LLTeleportRequestViaLocation() LL_INFOS("Teleport") << "~LLTeleportRequestViaLocation" << LL_ENDL; } +void LLTeleportRequestViaLocation::toOstream(std::ostream& os) const +{ + os << "mPosGlobal " << mPosGlobal << " "; + LLTeleportRequest::toOstream(os); +} + bool LLTeleportRequestViaLocation::canRestartTeleport() { LL_INFOS("Teleport") << "LLTeleportRequestViaLocation::canRestartTeleport -> true" << LL_ENDL; @@ -4795,6 +4911,11 @@ LLTeleportRequestViaLocationLookAt::~LLTeleportRequestViaLocationLookAt() LL_INFOS("Teleport") << "~LLTeleportRequestViaLocationLookAt" << LL_ENDL; } +void LLTeleportRequestViaLocationLookAt::toOstream(std::ostream& os) const +{ + LLTeleportRequestViaLocation::toOstream(os); +} + bool LLTeleportRequestViaLocationLookAt::canRestartTeleport() { LL_INFOS("Teleport") << "LLTeleportRequestViaLocationLookAt::canRestartTeleport -> true" << LL_ENDL; diff --git a/indra/newview/llagent.h b/indra/newview/llagent.h index 88cce0b911..5a00d39068 100644 --- a/indra/newview/llagent.h +++ b/indra/newview/llagent.h @@ -619,6 +619,10 @@ public: TELEPORT_PENDING = 7 }; + static std::map sTeleportStateName; + static const std::string& teleportStateName(S32); + const std::string& getTeleportStateName() const; + public: static void parseTeleportMessages(const std::string& xml_filename); const void getTeleportSourceSLURL(LLSLURL& slurl) const; diff --git a/indra/newview/llviewerdisplay.cpp b/indra/newview/llviewerdisplay.cpp index caf79edfe4..8a7a87445b 100644 --- a/indra/newview/llviewerdisplay.cpp +++ b/indra/newview/llviewerdisplay.cpp @@ -423,6 +423,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) if( (gAgent.getTeleportState() != LLAgent::TELEPORT_START) && (teleport_percent > 100.f) ) { // Give up. Don't keep the UI locked forever. + LL_WARNS("Teleport") << "Giving up on teleport, teleport_percent is " << teleport_percent << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); gAgent.setTeleportMessage(std::string()); } @@ -444,6 +445,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) gTeleportDisplayTimer.reset(); gViewerWindow->setShowProgress(TRUE); gViewerWindow->setProgressPercent(llmin(teleport_percent, 0.0f)); + LL_INFOS("Teleport") << "Teleport request of some kind has been sent, setting state to TELEPORT_REQUESTED" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_REQUESTED ); gAgent.setTeleportMessage( LLAgent::sTeleportProgressMessages["requesting"]); @@ -468,6 +470,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) gTeleportArrivalTimer.reset(); gViewerWindow->setProgressCancelButtonVisible(FALSE, LLTrans::getString("Cancel")); gViewerWindow->setProgressPercent(75.f); + LL_INFOS("Teleport") << "Changing state to TELEPORT_ARRIVING" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_ARRIVING ); gAgent.setTeleportMessage( LLAgent::sTeleportProgressMessages["arriving"]); @@ -484,6 +487,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) { arrival_fraction = 1.f; //LLFirstUse::useTeleport(); + LL_INFOS("Teleport") << "arrival_fraction is " << arrival_fraction << " changing state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } gViewerWindow->setProgressCancelButtonVisible(FALSE, LLTrans::getString("Cancel")); @@ -499,6 +503,10 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) if( gTeleportDisplayTimer.getElapsedTimeF32() > teleport_local_delay() ) { //LLFirstUse::useTeleport(); + LL_INFOS("Teleport") << "State is local and gTeleportDisplayTimer " << gTeleportDisplayTimer.getElapsedTimeF32() + << " exceeds teleport_local_delete " << teleport_local_delay + << "; setting state to TELEPORT_NONE" + << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } } diff --git a/indra/newview/llviewermessage.cpp b/indra/newview/llviewermessage.cpp index ea9dba3c4e..ac66e61d85 100644 --- a/indra/newview/llviewermessage.cpp +++ b/indra/newview/llviewermessage.cpp @@ -2877,7 +2877,7 @@ BOOL LLPostTeleportNotifiers::tick() // We're going to pretend to be a new agent void process_teleport_finish(LLMessageSystem* msg, void**) { - LL_DEBUGS("Messaging") << "Got teleport location message" << LL_ENDL; + LL_DEBUGS("Teleport","Messaging") << "Got teleport location message" << LL_ENDL; LLUUID agent_id; msg->getUUIDFast(_PREHASH_Info, _PREHASH_AgentID, agent_id); if (agent_id != gAgent.getID()) @@ -2892,12 +2892,13 @@ void process_teleport_finish(LLMessageSystem* msg, void**) { // Server either ignored teleport cancel message or did not receive it in time. // This message can't be ignored since teleport is complete at server side + LL_INFOS("Teleport") << "Restoring canceled teleport request" << LL_ENDL; gAgent.restoreCanceledTeleportRequest(); } else { // Race condition? Make sure all variables are set correctly for teleport to work - LL_WARNS("Messaging") << "Teleport 'finish' message without 'start'" << LL_ENDL; + LL_WARNS("Teleport","Messaging") << "Teleport 'finish' message without 'start'. Setting state to TELEPORT_REQUESTED" << LL_ENDL; gTeleportDisplay = TRUE; LLViewerMessage::getInstance()->mTeleportStartedSignal(); gAgent.setTeleportState(LLAgent::TELEPORT_REQUESTED); @@ -2989,6 +2990,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) msg->addUUIDFast(_PREHASH_ID, gAgent.getID()); msg->sendReliable(sim_host); + LL_INFOS("Teleport") << "Calling send_complete_agent_movement() and setting state to TELEPORT_MOVING" << LL_ENDL; send_complete_agent_movement(sim_host); gAgent.setTeleportState( LLAgent::TELEPORT_MOVING ); gAgent.setTeleportMessage(LLAgent::sTeleportProgressMessages["contacting"]); @@ -3108,6 +3110,7 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) gAgentCamera.slamLookAt(look_at); gAgentCamera.updateCamera(); + LL_INFOS("Teleport") << "Agent movement complete, setting state to TELEPORT_START_ARRIVAL" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_START_ARRIVAL ); if (isAgentAvatarValid()) @@ -3121,6 +3124,8 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) else { // This is initial log-in or a region crossing + LL_INFOS("Teleport") << "State is not TELEPORT_MOVING, so this is initial log-in or region crossing. " + << "Setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); if(LLStartUp::getStartupState() < STATE_STARTED) @@ -6001,6 +6006,7 @@ void process_teleport_failed(LLMessageSystem *msg, void**) { if( gAgent.getTeleportState() != LLAgent::TELEPORT_NONE ) { + LL_WARNS("Teleport") << "called handle_teleport_access_blocked, setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } return; @@ -6028,6 +6034,8 @@ void process_teleport_failed(LLMessageSystem *msg, void**) if( gAgent.getTeleportState() != LLAgent::TELEPORT_NONE ) { + LL_WARNS("Teleport") << "End of process_teleport_failed(). Reason message arg is " << args["REASON"] + << ". Setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } } @@ -6062,6 +6070,8 @@ void process_teleport_local(LLMessageSystem *msg,void**) } else { + LL_WARNS("Teleport") << "State is not TELEPORT_LOCAL: " << gAgent.getTeleportStateName() + << ", setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } } -- cgit v1.2.3 From d95d9713dd09d9608c1e1d2e426a776bcd0b9b71 Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Tue, 13 Oct 2020 21:24:02 +0100 Subject: SL-14081 - more teleport logging --- indra/newview/llagent.cpp | 80 ++++++++++++++++++++++++++------------- indra/newview/llviewerdisplay.cpp | 2 +- indra/newview/llviewermessage.cpp | 60 +++++++++++++++++++---------- indra/newview/llviewerregion.cpp | 5 ++- 4 files changed, 97 insertions(+), 50 deletions(-) diff --git a/indra/newview/llagent.cpp b/indra/newview/llagent.cpp index 04b89399b0..4bc7663300 100644 --- a/indra/newview/llagent.cpp +++ b/indra/newview/llagent.cpp @@ -157,32 +157,6 @@ std::map LLTeleportRequest::sTeleportStatusName = { { kPending { kFailed, "kFailed" }, { kRestartPending, "kRestartPending"} }; -// TODO this enum -> name idiom should be in a common class rather than repeated various places. -const std::string& LLTeleportRequest::statusName(EStatus status) -{ - static std::string invalid_status_str("INVALID"); - auto iter = LLTeleportRequest::sTeleportStatusName.find(status); - if (iter != LLTeleportRequest::sTeleportStatusName.end()) - { - return iter->second; - } - else - { - return invalid_status_str; - } -} - -std::ostream& operator<<(std::ostream& os, const LLTeleportRequest& req) -{ - req.toOstream(os); - return os; -} - -void LLTeleportRequest::toOstream(std::ostream& os) const -{ - os << "status " << statusName(mStatus) << "(" << mStatus << ")"; -} - class LLTeleportRequestViaLandmark : public LLTeleportRequest { public: @@ -910,7 +884,12 @@ void LLAgent::setRegion(LLViewerRegion *regionp) if (mRegionp != regionp) { - LL_INFOS("AgentLocation") << "Moving agent into region: " << regionp->getName() << LL_ENDL; + LL_INFOS("AgentLocation","Teleport") << "Moving agent into region: handle " << regionp->getHandle() + << " id " << regionp->getRegionID() + << " name " << regionp->getName() + << " previous region " + << (mRegionp ? mRegionp->getRegionID() : LLUUID::null) + << LL_ENDL; if (mRegionp) { // We've changed regions, we're now going to change our agent coordinate frame. @@ -4003,10 +3982,19 @@ void LLAgent::handleTeleportFinished() { if (mRegionp->capabilitiesReceived()) { + LL_DEBUGS("Teleport") << "capabilities have been received for region handle " + << mRegionp->getHandle() + << " id " << mRegionp->getRegionID() + << ", calling onCapabilitiesReceivedAfterTeleport()" + << LL_ENDL; onCapabilitiesReceivedAfterTeleport(); } else { + LL_DEBUGS("Teleport") << "Capabilities not yet received for region handle " + << mRegionp->getHandle() + << " id " << mRegionp->getRegionID() + << LL_ENDL; mRegionp->setCapabilitiesReceivedCallback(boost::bind(&LLAgent::onCapabilitiesReceivedAfterTeleport)); } } @@ -4044,6 +4032,18 @@ void LLAgent::handleTeleportFailed() /*static*/ void LLAgent::onCapabilitiesReceivedAfterTeleport() { + if (gAgent.getRegion()) + { + LL_DEBUGS("Teleport") << "running after capabilities received callback has been triggered, agent region " + << gAgent.getRegion()->getHandle() + << " id " << gAgent.getRegion()->getRegionID() + << " name " << gAgent.getRegion()->getName() + << LL_ENDL; + } + else + { + LL_WARNS("Teleport") << "called when agent region is null!" << LL_ENDL; + } check_merchant_status(); } @@ -4772,6 +4772,32 @@ void LLTeleportRequest::restartTeleport() llassert(0); } +// TODO this enum -> name idiom should be in a common class rather than repeated various places. +const std::string& LLTeleportRequest::statusName(EStatus status) +{ + static std::string invalid_status_str("INVALID"); + auto iter = LLTeleportRequest::sTeleportStatusName.find(status); + if (iter != LLTeleportRequest::sTeleportStatusName.end()) + { + return iter->second; + } + else + { + return invalid_status_str; + } +} + +std::ostream& operator<<(std::ostream& os, const LLTeleportRequest& req) +{ + req.toOstream(os); + return os; +} + +void LLTeleportRequest::toOstream(std::ostream& os) const +{ + os << "status " << statusName(mStatus) << "(" << mStatus << ")"; +} + //----------------------------------------------------------------------------- // LLTeleportRequestViaLandmark //----------------------------------------------------------------------------- diff --git a/indra/newview/llviewerdisplay.cpp b/indra/newview/llviewerdisplay.cpp index 8a7a87445b..fd283fe21b 100644 --- a/indra/newview/llviewerdisplay.cpp +++ b/indra/newview/llviewerdisplay.cpp @@ -445,7 +445,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) gTeleportDisplayTimer.reset(); gViewerWindow->setShowProgress(TRUE); gViewerWindow->setProgressPercent(llmin(teleport_percent, 0.0f)); - LL_INFOS("Teleport") << "Teleport request of some kind has been sent, setting state to TELEPORT_REQUESTED" << LL_ENDL; + LL_INFOS("Teleport") << "A teleport request has been sent, setting state to TELEPORT_REQUESTED" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_REQUESTED ); gAgent.setTeleportMessage( LLAgent::sTeleportProgressMessages["requesting"]); diff --git a/indra/newview/llviewermessage.cpp b/indra/newview/llviewermessage.cpp index ac66e61d85..4f96838181 100644 --- a/indra/newview/llviewermessage.cpp +++ b/indra/newview/llviewermessage.cpp @@ -406,6 +406,7 @@ void give_money(const LLUUID& uuid, LLViewerRegion* region, S32 amount, BOOL is_ void send_complete_agent_movement(const LLHost& sim_host) { + LL_DEBUGS("Teleport", "Messaging") << "Sending CompleteAgentMovement to sim_host " << sim_host << LL_ENDL; LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_CompleteAgentMovement); msg->nextBlockFast(_PREHASH_AgentData); @@ -2877,12 +2878,12 @@ BOOL LLPostTeleportNotifiers::tick() // We're going to pretend to be a new agent void process_teleport_finish(LLMessageSystem* msg, void**) { - LL_DEBUGS("Teleport","Messaging") << "Got teleport location message" << LL_ENDL; + LL_DEBUGS("Teleport","Messaging") << "Received TeleportFinish message" << LL_ENDL; LLUUID agent_id; msg->getUUIDFast(_PREHASH_Info, _PREHASH_AgentID, agent_id); if (agent_id != gAgent.getID()) { - LL_WARNS("Messaging") << "Got teleport notification for wrong agent!" << LL_ENDL; + LL_WARNS("Teleport","Messaging") << "Got teleport notification for wrong agent " << agent_id << " expected " << gAgent.getID() << ", ignoring!" << LL_ENDL; return; } @@ -2907,7 +2908,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) } else if (gAgent.getTeleportState() == LLAgent::TELEPORT_MOVING) { - LL_WARNS("Messaging") << "Teleport message in the middle of other teleport" << LL_ENDL; + LL_WARNS("Teleport","Messaging") << "Teleport message in the middle of other teleport" << LL_ENDL; } // Teleport is finished; it can't be cancelled now. @@ -2935,11 +2936,18 @@ void process_teleport_finish(LLMessageSystem* msg, void**) msg->getU64Fast(_PREHASH_Info, _PREHASH_RegionHandle, region_handle); U32 teleport_flags; msg->getU32Fast(_PREHASH_Info, _PREHASH_TeleportFlags, teleport_flags); - - + std::string seedCap; msg->getStringFast(_PREHASH_Info, _PREHASH_SeedCapability, seedCap); + LL_DEBUGS("Teleport") << "TeleportFinish message params are:" + << " sim_ip " << sim_ip + << " sim_port " << sim_port + << " region_handle " << region_handle + << " teleport_flags " << teleport_flags + << " seedCap " << seedCap + << LL_ENDL; + // update home location if we are teleporting out of prelude - specific to teleporting to welcome area if((teleport_flags & TELEPORT_FLAGS_SET_HOME_TO_TARGET) && (!gAgent.isGodlike())) @@ -2981,7 +2989,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) gAgent.standUp(); // now, use the circuit info to tell simulator about us! - LL_INFOS("Messaging") << "process_teleport_finish() Enabling " + LL_INFOS("Teleport","Messaging") << "process_teleport_finish() sending UseCircuitCode to enable sim_host " << sim_host << " with code " << msg->mOurCircuitCode << LL_ENDL; msg->newMessageFast(_PREHASH_UseCircuitCode); msg->nextBlockFast(_PREHASH_CircuitCode); @@ -2995,7 +3003,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) gAgent.setTeleportState( LLAgent::TELEPORT_MOVING ); gAgent.setTeleportMessage(LLAgent::sTeleportProgressMessages["contacting"]); - LL_DEBUGS("CrossingCaps") << "Calling setSeedCapability from process_teleport_finish(). Seed cap == " + LL_DEBUGS("CrossingCaps") << "Calling setSeedCapability(). Seed cap == " << seedCap << LL_ENDL; regionp->setSeedCapability(seedCap); @@ -3028,6 +3036,8 @@ void process_avatar_init_complete(LLMessageSystem* msg, void**) void process_agent_movement_complete(LLMessageSystem* msg, void**) { + LL_DEBUGS("Teleport","Messaging") << "Received ProcessAgentMovementComplete" << LL_ENDL; + gShiftFrame = true; gAgentMovementCompleted = true; @@ -3037,13 +3047,13 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) msg->getUUIDFast(_PREHASH_AgentData, _PREHASH_SessionID, session_id); if((gAgent.getID() != agent_id) || (gAgent.getSessionID() != session_id)) { - LL_WARNS("Messaging") << "Incorrect id in process_agent_movement_complete()" - << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "Incorrect agent or session id in process_agent_movement_complete()" + << " agent " << agent_id << " expected " << gAgent.getID() + << " session " << session_id << " expected " << gAgent.getSessionID() + << ", ignoring" << LL_ENDL; return; } - LL_DEBUGS("Messaging") << "process_agent_movement_complete()" << LL_ENDL; - // *TODO: check timestamp to make sure the movement compleation // makes sense. LLVector3 agent_pos; @@ -3060,7 +3070,7 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) { // Could happen if you were immediately god-teleported away on login, // maybe other cases. Continue, but warn. - LL_WARNS("Messaging") << "agent_movement_complete() with NULL avatarp." << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "agent_movement_complete() with NULL avatarp." << LL_ENDL; } F32 x, y; @@ -3070,19 +3080,21 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) { if (gAgent.getRegion()) { - LL_WARNS("Messaging") << "current region " << gAgent.getRegion()->getOriginGlobal() << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "current region origin " + << gAgent.getRegion()->getOriginGlobal() << " id " << gAgent.getRegion()->getRegionID() << LL_ENDL; } - LL_WARNS("Messaging") << "Agent being sent to invalid home region: " - << x << ":" << y - << " current pos " << gAgent.getPositionGlobal() - << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "Agent being sent to invalid home region: " + << x << ":" << y + << " current pos " << gAgent.getPositionGlobal() + << ", calling forceDisconnect()" + << LL_ENDL; LLAppViewer::instance()->forceDisconnect(LLTrans::getString("SentToInvalidRegion")); return; } - LL_INFOS("Messaging") << "Changing home region to " << x << ":" << y << LL_ENDL; + LL_INFOS("Teleport","Messaging") << "Changing home region to region id " << regionp->getRegionID() << " handle " << region_handle << " == x,y " << x << "," << y << LL_ENDL; // set our upstream host the new simulator and shuffle things as // appropriate. @@ -5960,6 +5972,8 @@ std::string formatted_time(const time_t& the_time) void process_teleport_failed(LLMessageSystem *msg, void**) { + LL_WARNS("Teleport","Messaging") << "Received TeleportFailed message" << LL_ENDL; + std::string message_id; // Tag from server, like "RegionEntryAccessBlocked" std::string big_reason; // Actual message to display LLSD args; @@ -5978,6 +5992,7 @@ void process_teleport_failed(LLMessageSystem *msg, void**) // Nothing found in the map - use what the server returned in the original message block msg->getStringFast(_PREHASH_Info, _PREHASH_Reason, big_reason); } + LL_WARNS("Teleport") << "AlertInfo message_id " << message_id << " reason: " << big_reason << LL_ENDL; LLSD llsd_block; std::string llsd_raw; @@ -5987,10 +6002,11 @@ void process_teleport_failed(LLMessageSystem *msg, void**) std::istringstream llsd_data(llsd_raw); if (!LLSDSerialize::deserialize(llsd_block, llsd_data, llsd_raw.length())) { - LL_WARNS() << "process_teleport_failed: Attempted to read alert parameter data into LLSD but failed:" << llsd_raw << LL_ENDL; + LL_WARNS("Teleport") << "process_teleport_failed: Attempted to read alert parameter data into LLSD but failed:" << llsd_raw << LL_ENDL; } else { + LL_WARNS("Teleport") << "AlertInfo llsd block received: " << llsd_block << LL_ENDL; if(llsd_block.has("REGION_NAME")) { std::string region_name = llsd_block["REGION_NAME"].asString(); @@ -6029,6 +6045,7 @@ void process_teleport_failed(LLMessageSystem *msg, void**) args["REASON"] = message_id; } } + LL_WARNS("Teleport") << "Displaying CouldNotTeleportReason string, REASON= " << args["REASON"] << LL_ENDL; LLNotificationsUtil::add("CouldNotTeleportReason", args); @@ -6042,11 +6059,13 @@ void process_teleport_failed(LLMessageSystem *msg, void**) void process_teleport_local(LLMessageSystem *msg,void**) { + LL_INFOS("Teleport","Messaging") << "Received TeleportLocal message" << LL_ENDL; + LLUUID agent_id; msg->getUUIDFast(_PREHASH_Info, _PREHASH_AgentID, agent_id); if (agent_id != gAgent.getID()) { - LL_WARNS("Messaging") << "Got teleport notification for wrong agent!" << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "Got teleport notification for wrong agent " << agent_id << " expected " << gAgent.getID() << ", ignoring!" << LL_ENDL; return; } @@ -6058,6 +6077,7 @@ void process_teleport_local(LLMessageSystem *msg,void**) msg->getVector3Fast(_PREHASH_Info, _PREHASH_LookAt, look_at); msg->getU32Fast(_PREHASH_Info, _PREHASH_TeleportFlags, teleport_flags); + LL_INFOS("Teleport") << "Message params are location_id " << location_id << " teleport_flags " << teleport_flags << LL_ENDL; if( gAgent.getTeleportState() != LLAgent::TELEPORT_NONE ) { if( gAgent.getTeleportState() == LLAgent::TELEPORT_LOCAL ) diff --git a/indra/newview/llviewerregion.cpp b/indra/newview/llviewerregion.cpp index a30c5156fa..5c99e693d2 100644 --- a/indra/newview/llviewerregion.cpp +++ b/indra/newview/llviewerregion.cpp @@ -291,6 +291,7 @@ void LLViewerRegionImpl::requestBaseCapabilitiesCoro(U64 regionHandle) LL_INFOS("AppInit", "Capabilities") << "Requesting seed from " << url << " region name " << regionp->getName() + << " handle " << regionp->getHandle() << " (attempt #" << mSeedCapAttempts + 1 << ")" << LL_ENDL; LL_DEBUGS("AppInit", "Capabilities") << "Capabilities requested: " << capabilityNames << LL_ENDL; @@ -350,9 +351,9 @@ void LLViewerRegionImpl::requestBaseCapabilitiesCoro(U64 regionHandle) log_capabilities(mCapabilities); #endif + LL_DEBUGS("AppInit", "Capabilities", "Teleport") << "received caps for handle " << regionHandle + << " region name " << regionp->getName() << LL_ENDL; regionp->setCapabilitiesReceived(true); - LL_DEBUGS("AppInit", "Capabilities") << "received caps for handle " << regionHandle - << " region name " << regionp->getName() << LL_ENDL; if (STATE_SEED_GRANTED_WAIT == LLStartUp::getStartupState()) { -- cgit v1.2.3 From d8168fa720287b779cc74d518e8cedb4174ab9dd Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Wed, 14 Oct 2020 14:52:36 +0100 Subject: SL-14081 - detail on viewer-initiated timeout --- indra/newview/llviewerdisplay.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/indra/newview/llviewerdisplay.cpp b/indra/newview/llviewerdisplay.cpp index fd283fe21b..d314b1477a 100644 --- a/indra/newview/llviewerdisplay.cpp +++ b/indra/newview/llviewerdisplay.cpp @@ -423,7 +423,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) if( (gAgent.getTeleportState() != LLAgent::TELEPORT_START) && (teleport_percent > 100.f) ) { // Give up. Don't keep the UI locked forever. - LL_WARNS("Teleport") << "Giving up on teleport, teleport_percent is " << teleport_percent << LL_ENDL; + LL_WARNS("Teleport") << "Giving up on teleport. elapsed time " << teleport_elapsed << " exceeds max time " << teleport_save_time << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); gAgent.setTeleportMessage(std::string()); } -- cgit v1.2.3 From d06db587b2c22b5dac94f4bb60d5c8c300161682 Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Fri, 9 Oct 2020 16:18:19 +0100 Subject: SL-14081 - more detailed logging of teleport process --- indra/newview/llagent.cpp | 147 ++++++++++++++++++++++++++++++++++---- indra/newview/llagent.h | 4 ++ indra/newview/llviewerdisplay.cpp | 8 +++ indra/newview/llviewermessage.cpp | 14 +++- 4 files changed, 158 insertions(+), 15 deletions(-) diff --git a/indra/newview/llagent.cpp b/indra/newview/llagent.cpp index 166c2d67c8..04b89399b0 100644 --- a/indra/newview/llagent.cpp +++ b/indra/newview/llagent.cpp @@ -137,6 +137,10 @@ public: EStatus getStatus() const {return mStatus;}; void setStatus(EStatus pStatus) {mStatus = pStatus;}; + static std::map sTeleportStatusName; + static const std::string& statusName(EStatus status); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport() = 0; @@ -148,12 +152,45 @@ private: EStatus mStatus; }; +std::map LLTeleportRequest::sTeleportStatusName = { { kPending, "kPending" }, + { kStarted, "kStarted" }, + { kFailed, "kFailed" }, + { kRestartPending, "kRestartPending"} }; + +// TODO this enum -> name idiom should be in a common class rather than repeated various places. +const std::string& LLTeleportRequest::statusName(EStatus status) +{ + static std::string invalid_status_str("INVALID"); + auto iter = LLTeleportRequest::sTeleportStatusName.find(status); + if (iter != LLTeleportRequest::sTeleportStatusName.end()) + { + return iter->second; + } + else + { + return invalid_status_str; + } +} + +std::ostream& operator<<(std::ostream& os, const LLTeleportRequest& req) +{ + req.toOstream(os); + return os; +} + +void LLTeleportRequest::toOstream(std::ostream& os) const +{ + os << "status " << statusName(mStatus) << "(" << mStatus << ")"; +} + class LLTeleportRequestViaLandmark : public LLTeleportRequest { public: LLTeleportRequestViaLandmark(const LLUUID &pLandmarkId); virtual ~LLTeleportRequestViaLandmark(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -172,6 +209,8 @@ public: LLTeleportRequestViaLure(const LLUUID &pLureId, BOOL pIsLureGodLike); virtual ~LLTeleportRequestViaLure(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -189,6 +228,8 @@ public: LLTeleportRequestViaLocation(const LLVector3d &pPosGlobal); virtual ~LLTeleportRequestViaLocation(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -208,6 +249,8 @@ public: LLTeleportRequestViaLocationLookAt(const LLVector3d &pPosGlobal); virtual ~LLTeleportRequestViaLocationLookAt(); + virtual void toOstream(std::ostream& os) const; + virtual bool canRestartTeleport(); virtual void startTeleport(); @@ -2629,6 +2672,7 @@ void LLAgent::handlePreferredMaturityResult(U8 pServerMaturity) else { mMaturityPreferenceNumRetries = 0; + LL_WARNS() << "Too many retries for maturity preference" << LL_ENDL; reportPreferredMaturityError(); } } @@ -2680,6 +2724,7 @@ void LLAgent::reportPreferredMaturityError() mIsMaturityRatingChangingDuringTeleport = false; if (hasPendingTeleportRequest()) { + LL_WARNS("Teleport") << "Teleport failing due to preferred maturity error" << LL_ENDL; setTeleportState(LLAgent::TELEPORT_NONE); } @@ -3775,7 +3820,7 @@ void LLAgent::clearVisualParams(void *data) // protected bool LLAgent::teleportCore(bool is_local) { - LL_INFOS("Teleport") << "In teleport core!" << LL_ENDL; + LL_DEBUGS("Teleport") << "In teleport core" << LL_ENDL; if ((TELEPORT_NONE != mTeleportState) && (mTeleportState != TELEPORT_PENDING)) { LL_WARNS() << "Attempt to teleport when already teleporting." << LL_ENDL; @@ -3841,11 +3886,13 @@ bool LLAgent::teleportCore(bool is_local) add(LLStatViewer::TELEPORT, 1); if (is_local) { + LL_INFOS("Teleport") << "Setting teleport state to TELEPORT_LOCAL" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_LOCAL ); } else { gTeleportDisplay = TRUE; + LL_INFOS("Teleport") << "Non-local, setting teleport state to TELEPORT_START" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_START ); //release geometry from old location @@ -3912,6 +3959,7 @@ void LLAgent::startTeleportRequest() if (!isMaturityPreferenceSyncedWithServer()) { gTeleportDisplay = TRUE; + LL_INFOS("Teleport") << "Maturity preference not synced yet, setting teleport state to TELEPORT_PENDING" << LL_ENDL; setTeleportState(TELEPORT_PENDING); } else @@ -4009,8 +4057,8 @@ void LLAgent::teleportRequest( LLViewerRegion* regionp = getRegion(); if (regionp && teleportCore(region_handle == regionp->getHandle())) { - LL_INFOS("") << "TeleportLocationRequest: '" << region_handle << "':" - << pos_local << LL_ENDL; + LL_INFOS("Teleport") << "Sending TeleportLocationRequest: '" << region_handle << "':" + << pos_local << LL_ENDL; LLMessageSystem* msg = gMessageSystem; msg->newMessage("TeleportLocationRequest"); msg->nextBlockFast(_PREHASH_AgentData); @@ -4041,6 +4089,11 @@ void LLAgent::doTeleportViaLandmark(const LLUUID& landmark_asset_id) LLViewerRegion *regionp = getRegion(); if(regionp && teleportCore()) { + LL_INFOS("Teleport") << "Sending TeleportLandmarkRequest. Current region handle " << regionp->getHandle() + << " region id " << regionp->getRegionID() + << " requested landmark id " << landmark_asset_id + << LL_ENDL; + LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_TeleportLandmarkRequest); msg->nextBlockFast(_PREHASH_Info); @@ -4073,6 +4126,11 @@ void LLAgent::doTeleportViaLure(const LLUUID& lure_id, BOOL godlike) teleport_flags |= TELEPORT_FLAGS_VIA_LURE; } + LL_INFOS("Teleport") << "Sending TeleportLureRequest." + << " Current region handle " << regionp->getHandle() + << " region id " << regionp->getRegionID() + << " lure id " << lure_id + << LL_ENDL; // send the message LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_TeleportLureRequest); @@ -4095,6 +4153,8 @@ void LLAgent::teleportCancel() LLViewerRegion* regionp = getRegion(); if(regionp) { + LL_INFOS("Teleport") << "Sending TeleportCancel" << LL_ENDL; + // send the message LLMessageSystem* msg = gMessageSystem; msg->newMessage("TeleportCancel"); @@ -4107,13 +4167,14 @@ void LLAgent::teleportCancel() } clearTeleportRequest(); gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); - gPipeline.resetVertexBuffers(); + gPipeline.resetVertexBuffers(); } void LLAgent::restoreCanceledTeleportRequest() { if (mTeleportCanceled != NULL) { + LL_INFOS() << "Restoring canceled teleport request, setting state to TELEPORT_REQUESTED" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_REQUESTED ); mTeleportRequest = mTeleportCanceled; mTeleportCanceled.reset(); @@ -4151,7 +4212,6 @@ void LLAgent::doTeleportViaLocation(const LLVector3d& pos_global) else if(regionp && teleportCore(regionp->getHandle() == to_region_handle_global((F32)pos_global.mdV[VX], (F32)pos_global.mdV[VY]))) { - LL_WARNS() << "Using deprecated teleportlocationrequest." << LL_ENDL; // send the message LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_TeleportLocationRequest); @@ -4171,6 +4231,14 @@ void LLAgent::doTeleportViaLocation(const LLVector3d& pos_global) msg->addVector3Fast(_PREHASH_Position, pos); pos.mV[VX] += 1; msg->addVector3Fast(_PREHASH_LookAt, pos); + + LL_WARNS("Teleport") << "Sending deprecated(?) TeleportLocationRequest." + << " pos_global " << pos_global + << " region_x " << region_x + << " region_y " << region_y + << " region_handle " << region_handle + << LL_ENDL; + sendReliableMessage(); } } @@ -4212,7 +4280,11 @@ void LLAgent::setTeleportState(ETeleportState state) " for previously failed teleport. Ignore!" << LL_ENDL; return; } - LL_DEBUGS("Teleport") << "Setting teleport state to " << state << " Previous state: " << mTeleportState << LL_ENDL; + LL_DEBUGS("Teleport") << "Setting teleport state to " + << LLAgent::teleportStateName(state) << "(" << state << ")" + << " Previous state: " + << teleportStateName(mTeleportState) << "(" << mTeleportState << ")" + << LL_ENDL; mTeleportState = state; if (mTeleportState > TELEPORT_NONE && gSavedSettings.getBOOL("FreezeTime")) { @@ -4549,6 +4621,34 @@ void LLAgent::observeFriends() } } +std::map LLAgent::sTeleportStateName = { { TELEPORT_NONE, "TELEPORT_NONE" }, + { TELEPORT_START, "TELEPORT_START" }, + { TELEPORT_REQUESTED, "TELEPORT_REQUESTED" }, + { TELEPORT_MOVING, "TELEPORT_MOVING" }, + { TELEPORT_START_ARRIVAL, "TELEPORT_START_ARRIVAL" }, + { TELEPORT_ARRIVING, "TELEPORT_ARRIVING" }, + { TELEPORT_LOCAL, "TELEPORT_LOCAL" }, + { TELEPORT_PENDING, "TELEPORT_PENDING" } }; + +const std::string& LLAgent::teleportStateName(S32 state) +{ + static std::string invalid_state_str("INVALID"); + auto iter = LLAgent::sTeleportStateName.find(state); + if (iter != LLAgent::sTeleportStateName.end()) + { + return iter->second; + } + else + { + return invalid_state_str; + } +} + +const std::string& LLAgent::getTeleportStateName() const +{ + return teleportStateName(getTeleportState()); +} + void LLAgent::parseTeleportMessages(const std::string& xml_filename) { LLXMLNodePtr root; @@ -4675,37 +4775,41 @@ void LLTeleportRequest::restartTeleport() //----------------------------------------------------------------------------- // LLTeleportRequestViaLandmark //----------------------------------------------------------------------------- - LLTeleportRequestViaLandmark::LLTeleportRequestViaLandmark(const LLUUID &pLandmarkId) : LLTeleportRequest(), mLandmarkId(pLandmarkId) { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark created." << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark created, " << *this << LL_ENDL; } LLTeleportRequestViaLandmark::~LLTeleportRequestViaLandmark() { - LL_INFOS("Teleport") << "~LLTeleportRequestViaLandmark" << LL_ENDL; + LL_INFOS("Teleport") << "~LLTeleportRequestViaLandmark, " << *this << LL_ENDL; +} + +void LLTeleportRequestViaLandmark::toOstream(std::ostream& os) const +{ + os << "landmark " << mLandmarkId << " "; + LLTeleportRequest::toOstream(os); } bool LLTeleportRequestViaLandmark::canRestartTeleport() { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::canRestartTeleport? -> true" << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::canRestartTeleport? -> true, " << *this << LL_ENDL; return true; } void LLTeleportRequestViaLandmark::startTeleport() { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::startTeleport" << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::startTeleport, " << *this << LL_ENDL; gAgent.doTeleportViaLandmark(getLandmarkId()); } void LLTeleportRequestViaLandmark::restartTeleport() { - LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::restartTeleport" << LL_ENDL; + LL_INFOS("Teleport") << "LLTeleportRequestViaLandmark::restartTeleport, " << *this << LL_ENDL; gAgent.doTeleportViaLandmark(getLandmarkId()); } - //----------------------------------------------------------------------------- // LLTeleportRequestViaLure //----------------------------------------------------------------------------- @@ -4722,6 +4826,12 @@ LLTeleportRequestViaLure::~LLTeleportRequestViaLure() LL_INFOS("Teleport") << "~LLTeleportRequestViaLure" << LL_ENDL; } +void LLTeleportRequestViaLure::toOstream(std::ostream& os) const +{ + os << "mIsLureGodLike " << (S32) mIsLureGodLike << " "; + LLTeleportRequestViaLandmark::toOstream(os); +} + bool LLTeleportRequestViaLure::canRestartTeleport() { // stinson 05/17/2012 : cannot restart a teleport via lure because of server-side restrictions @@ -4762,6 +4872,12 @@ LLTeleportRequestViaLocation::~LLTeleportRequestViaLocation() LL_INFOS("Teleport") << "~LLTeleportRequestViaLocation" << LL_ENDL; } +void LLTeleportRequestViaLocation::toOstream(std::ostream& os) const +{ + os << "mPosGlobal " << mPosGlobal << " "; + LLTeleportRequest::toOstream(os); +} + bool LLTeleportRequestViaLocation::canRestartTeleport() { LL_INFOS("Teleport") << "LLTeleportRequestViaLocation::canRestartTeleport -> true" << LL_ENDL; @@ -4795,6 +4911,11 @@ LLTeleportRequestViaLocationLookAt::~LLTeleportRequestViaLocationLookAt() LL_INFOS("Teleport") << "~LLTeleportRequestViaLocationLookAt" << LL_ENDL; } +void LLTeleportRequestViaLocationLookAt::toOstream(std::ostream& os) const +{ + LLTeleportRequestViaLocation::toOstream(os); +} + bool LLTeleportRequestViaLocationLookAt::canRestartTeleport() { LL_INFOS("Teleport") << "LLTeleportRequestViaLocationLookAt::canRestartTeleport -> true" << LL_ENDL; diff --git a/indra/newview/llagent.h b/indra/newview/llagent.h index 88cce0b911..5a00d39068 100644 --- a/indra/newview/llagent.h +++ b/indra/newview/llagent.h @@ -619,6 +619,10 @@ public: TELEPORT_PENDING = 7 }; + static std::map sTeleportStateName; + static const std::string& teleportStateName(S32); + const std::string& getTeleportStateName() const; + public: static void parseTeleportMessages(const std::string& xml_filename); const void getTeleportSourceSLURL(LLSLURL& slurl) const; diff --git a/indra/newview/llviewerdisplay.cpp b/indra/newview/llviewerdisplay.cpp index caf79edfe4..8a7a87445b 100644 --- a/indra/newview/llviewerdisplay.cpp +++ b/indra/newview/llviewerdisplay.cpp @@ -423,6 +423,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) if( (gAgent.getTeleportState() != LLAgent::TELEPORT_START) && (teleport_percent > 100.f) ) { // Give up. Don't keep the UI locked forever. + LL_WARNS("Teleport") << "Giving up on teleport, teleport_percent is " << teleport_percent << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); gAgent.setTeleportMessage(std::string()); } @@ -444,6 +445,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) gTeleportDisplayTimer.reset(); gViewerWindow->setShowProgress(TRUE); gViewerWindow->setProgressPercent(llmin(teleport_percent, 0.0f)); + LL_INFOS("Teleport") << "Teleport request of some kind has been sent, setting state to TELEPORT_REQUESTED" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_REQUESTED ); gAgent.setTeleportMessage( LLAgent::sTeleportProgressMessages["requesting"]); @@ -468,6 +470,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) gTeleportArrivalTimer.reset(); gViewerWindow->setProgressCancelButtonVisible(FALSE, LLTrans::getString("Cancel")); gViewerWindow->setProgressPercent(75.f); + LL_INFOS("Teleport") << "Changing state to TELEPORT_ARRIVING" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_ARRIVING ); gAgent.setTeleportMessage( LLAgent::sTeleportProgressMessages["arriving"]); @@ -484,6 +487,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) { arrival_fraction = 1.f; //LLFirstUse::useTeleport(); + LL_INFOS("Teleport") << "arrival_fraction is " << arrival_fraction << " changing state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } gViewerWindow->setProgressCancelButtonVisible(FALSE, LLTrans::getString("Cancel")); @@ -499,6 +503,10 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) if( gTeleportDisplayTimer.getElapsedTimeF32() > teleport_local_delay() ) { //LLFirstUse::useTeleport(); + LL_INFOS("Teleport") << "State is local and gTeleportDisplayTimer " << gTeleportDisplayTimer.getElapsedTimeF32() + << " exceeds teleport_local_delete " << teleport_local_delay + << "; setting state to TELEPORT_NONE" + << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } } diff --git a/indra/newview/llviewermessage.cpp b/indra/newview/llviewermessage.cpp index ea9dba3c4e..ac66e61d85 100644 --- a/indra/newview/llviewermessage.cpp +++ b/indra/newview/llviewermessage.cpp @@ -2877,7 +2877,7 @@ BOOL LLPostTeleportNotifiers::tick() // We're going to pretend to be a new agent void process_teleport_finish(LLMessageSystem* msg, void**) { - LL_DEBUGS("Messaging") << "Got teleport location message" << LL_ENDL; + LL_DEBUGS("Teleport","Messaging") << "Got teleport location message" << LL_ENDL; LLUUID agent_id; msg->getUUIDFast(_PREHASH_Info, _PREHASH_AgentID, agent_id); if (agent_id != gAgent.getID()) @@ -2892,12 +2892,13 @@ void process_teleport_finish(LLMessageSystem* msg, void**) { // Server either ignored teleport cancel message or did not receive it in time. // This message can't be ignored since teleport is complete at server side + LL_INFOS("Teleport") << "Restoring canceled teleport request" << LL_ENDL; gAgent.restoreCanceledTeleportRequest(); } else { // Race condition? Make sure all variables are set correctly for teleport to work - LL_WARNS("Messaging") << "Teleport 'finish' message without 'start'" << LL_ENDL; + LL_WARNS("Teleport","Messaging") << "Teleport 'finish' message without 'start'. Setting state to TELEPORT_REQUESTED" << LL_ENDL; gTeleportDisplay = TRUE; LLViewerMessage::getInstance()->mTeleportStartedSignal(); gAgent.setTeleportState(LLAgent::TELEPORT_REQUESTED); @@ -2989,6 +2990,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) msg->addUUIDFast(_PREHASH_ID, gAgent.getID()); msg->sendReliable(sim_host); + LL_INFOS("Teleport") << "Calling send_complete_agent_movement() and setting state to TELEPORT_MOVING" << LL_ENDL; send_complete_agent_movement(sim_host); gAgent.setTeleportState( LLAgent::TELEPORT_MOVING ); gAgent.setTeleportMessage(LLAgent::sTeleportProgressMessages["contacting"]); @@ -3108,6 +3110,7 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) gAgentCamera.slamLookAt(look_at); gAgentCamera.updateCamera(); + LL_INFOS("Teleport") << "Agent movement complete, setting state to TELEPORT_START_ARRIVAL" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_START_ARRIVAL ); if (isAgentAvatarValid()) @@ -3121,6 +3124,8 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) else { // This is initial log-in or a region crossing + LL_INFOS("Teleport") << "State is not TELEPORT_MOVING, so this is initial log-in or region crossing. " + << "Setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); if(LLStartUp::getStartupState() < STATE_STARTED) @@ -6001,6 +6006,7 @@ void process_teleport_failed(LLMessageSystem *msg, void**) { if( gAgent.getTeleportState() != LLAgent::TELEPORT_NONE ) { + LL_WARNS("Teleport") << "called handle_teleport_access_blocked, setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } return; @@ -6028,6 +6034,8 @@ void process_teleport_failed(LLMessageSystem *msg, void**) if( gAgent.getTeleportState() != LLAgent::TELEPORT_NONE ) { + LL_WARNS("Teleport") << "End of process_teleport_failed(). Reason message arg is " << args["REASON"] + << ". Setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } } @@ -6062,6 +6070,8 @@ void process_teleport_local(LLMessageSystem *msg,void**) } else { + LL_WARNS("Teleport") << "State is not TELEPORT_LOCAL: " << gAgent.getTeleportStateName() + << ", setting state to TELEPORT_NONE" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); } } -- cgit v1.2.3 From 6cbb59e13a0143125d401700a3582d0ad2a66107 Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Tue, 13 Oct 2020 21:24:02 +0100 Subject: SL-14081 - more teleport logging --- indra/newview/llagent.cpp | 80 ++++++++++++++++++++++++++------------- indra/newview/llviewerdisplay.cpp | 2 +- indra/newview/llviewermessage.cpp | 60 +++++++++++++++++++---------- indra/newview/llviewerregion.cpp | 5 ++- 4 files changed, 97 insertions(+), 50 deletions(-) diff --git a/indra/newview/llagent.cpp b/indra/newview/llagent.cpp index 04b89399b0..4bc7663300 100644 --- a/indra/newview/llagent.cpp +++ b/indra/newview/llagent.cpp @@ -157,32 +157,6 @@ std::map LLTeleportRequest::sTeleportStatusName = { { kPending { kFailed, "kFailed" }, { kRestartPending, "kRestartPending"} }; -// TODO this enum -> name idiom should be in a common class rather than repeated various places. -const std::string& LLTeleportRequest::statusName(EStatus status) -{ - static std::string invalid_status_str("INVALID"); - auto iter = LLTeleportRequest::sTeleportStatusName.find(status); - if (iter != LLTeleportRequest::sTeleportStatusName.end()) - { - return iter->second; - } - else - { - return invalid_status_str; - } -} - -std::ostream& operator<<(std::ostream& os, const LLTeleportRequest& req) -{ - req.toOstream(os); - return os; -} - -void LLTeleportRequest::toOstream(std::ostream& os) const -{ - os << "status " << statusName(mStatus) << "(" << mStatus << ")"; -} - class LLTeleportRequestViaLandmark : public LLTeleportRequest { public: @@ -910,7 +884,12 @@ void LLAgent::setRegion(LLViewerRegion *regionp) if (mRegionp != regionp) { - LL_INFOS("AgentLocation") << "Moving agent into region: " << regionp->getName() << LL_ENDL; + LL_INFOS("AgentLocation","Teleport") << "Moving agent into region: handle " << regionp->getHandle() + << " id " << regionp->getRegionID() + << " name " << regionp->getName() + << " previous region " + << (mRegionp ? mRegionp->getRegionID() : LLUUID::null) + << LL_ENDL; if (mRegionp) { // We've changed regions, we're now going to change our agent coordinate frame. @@ -4003,10 +3982,19 @@ void LLAgent::handleTeleportFinished() { if (mRegionp->capabilitiesReceived()) { + LL_DEBUGS("Teleport") << "capabilities have been received for region handle " + << mRegionp->getHandle() + << " id " << mRegionp->getRegionID() + << ", calling onCapabilitiesReceivedAfterTeleport()" + << LL_ENDL; onCapabilitiesReceivedAfterTeleport(); } else { + LL_DEBUGS("Teleport") << "Capabilities not yet received for region handle " + << mRegionp->getHandle() + << " id " << mRegionp->getRegionID() + << LL_ENDL; mRegionp->setCapabilitiesReceivedCallback(boost::bind(&LLAgent::onCapabilitiesReceivedAfterTeleport)); } } @@ -4044,6 +4032,18 @@ void LLAgent::handleTeleportFailed() /*static*/ void LLAgent::onCapabilitiesReceivedAfterTeleport() { + if (gAgent.getRegion()) + { + LL_DEBUGS("Teleport") << "running after capabilities received callback has been triggered, agent region " + << gAgent.getRegion()->getHandle() + << " id " << gAgent.getRegion()->getRegionID() + << " name " << gAgent.getRegion()->getName() + << LL_ENDL; + } + else + { + LL_WARNS("Teleport") << "called when agent region is null!" << LL_ENDL; + } check_merchant_status(); } @@ -4772,6 +4772,32 @@ void LLTeleportRequest::restartTeleport() llassert(0); } +// TODO this enum -> name idiom should be in a common class rather than repeated various places. +const std::string& LLTeleportRequest::statusName(EStatus status) +{ + static std::string invalid_status_str("INVALID"); + auto iter = LLTeleportRequest::sTeleportStatusName.find(status); + if (iter != LLTeleportRequest::sTeleportStatusName.end()) + { + return iter->second; + } + else + { + return invalid_status_str; + } +} + +std::ostream& operator<<(std::ostream& os, const LLTeleportRequest& req) +{ + req.toOstream(os); + return os; +} + +void LLTeleportRequest::toOstream(std::ostream& os) const +{ + os << "status " << statusName(mStatus) << "(" << mStatus << ")"; +} + //----------------------------------------------------------------------------- // LLTeleportRequestViaLandmark //----------------------------------------------------------------------------- diff --git a/indra/newview/llviewerdisplay.cpp b/indra/newview/llviewerdisplay.cpp index 8a7a87445b..fd283fe21b 100644 --- a/indra/newview/llviewerdisplay.cpp +++ b/indra/newview/llviewerdisplay.cpp @@ -445,7 +445,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) gTeleportDisplayTimer.reset(); gViewerWindow->setShowProgress(TRUE); gViewerWindow->setProgressPercent(llmin(teleport_percent, 0.0f)); - LL_INFOS("Teleport") << "Teleport request of some kind has been sent, setting state to TELEPORT_REQUESTED" << LL_ENDL; + LL_INFOS("Teleport") << "A teleport request has been sent, setting state to TELEPORT_REQUESTED" << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_REQUESTED ); gAgent.setTeleportMessage( LLAgent::sTeleportProgressMessages["requesting"]); diff --git a/indra/newview/llviewermessage.cpp b/indra/newview/llviewermessage.cpp index ac66e61d85..4f96838181 100644 --- a/indra/newview/llviewermessage.cpp +++ b/indra/newview/llviewermessage.cpp @@ -406,6 +406,7 @@ void give_money(const LLUUID& uuid, LLViewerRegion* region, S32 amount, BOOL is_ void send_complete_agent_movement(const LLHost& sim_host) { + LL_DEBUGS("Teleport", "Messaging") << "Sending CompleteAgentMovement to sim_host " << sim_host << LL_ENDL; LLMessageSystem* msg = gMessageSystem; msg->newMessageFast(_PREHASH_CompleteAgentMovement); msg->nextBlockFast(_PREHASH_AgentData); @@ -2877,12 +2878,12 @@ BOOL LLPostTeleportNotifiers::tick() // We're going to pretend to be a new agent void process_teleport_finish(LLMessageSystem* msg, void**) { - LL_DEBUGS("Teleport","Messaging") << "Got teleport location message" << LL_ENDL; + LL_DEBUGS("Teleport","Messaging") << "Received TeleportFinish message" << LL_ENDL; LLUUID agent_id; msg->getUUIDFast(_PREHASH_Info, _PREHASH_AgentID, agent_id); if (agent_id != gAgent.getID()) { - LL_WARNS("Messaging") << "Got teleport notification for wrong agent!" << LL_ENDL; + LL_WARNS("Teleport","Messaging") << "Got teleport notification for wrong agent " << agent_id << " expected " << gAgent.getID() << ", ignoring!" << LL_ENDL; return; } @@ -2907,7 +2908,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) } else if (gAgent.getTeleportState() == LLAgent::TELEPORT_MOVING) { - LL_WARNS("Messaging") << "Teleport message in the middle of other teleport" << LL_ENDL; + LL_WARNS("Teleport","Messaging") << "Teleport message in the middle of other teleport" << LL_ENDL; } // Teleport is finished; it can't be cancelled now. @@ -2935,11 +2936,18 @@ void process_teleport_finish(LLMessageSystem* msg, void**) msg->getU64Fast(_PREHASH_Info, _PREHASH_RegionHandle, region_handle); U32 teleport_flags; msg->getU32Fast(_PREHASH_Info, _PREHASH_TeleportFlags, teleport_flags); - - + std::string seedCap; msg->getStringFast(_PREHASH_Info, _PREHASH_SeedCapability, seedCap); + LL_DEBUGS("Teleport") << "TeleportFinish message params are:" + << " sim_ip " << sim_ip + << " sim_port " << sim_port + << " region_handle " << region_handle + << " teleport_flags " << teleport_flags + << " seedCap " << seedCap + << LL_ENDL; + // update home location if we are teleporting out of prelude - specific to teleporting to welcome area if((teleport_flags & TELEPORT_FLAGS_SET_HOME_TO_TARGET) && (!gAgent.isGodlike())) @@ -2981,7 +2989,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) gAgent.standUp(); // now, use the circuit info to tell simulator about us! - LL_INFOS("Messaging") << "process_teleport_finish() Enabling " + LL_INFOS("Teleport","Messaging") << "process_teleport_finish() sending UseCircuitCode to enable sim_host " << sim_host << " with code " << msg->mOurCircuitCode << LL_ENDL; msg->newMessageFast(_PREHASH_UseCircuitCode); msg->nextBlockFast(_PREHASH_CircuitCode); @@ -2995,7 +3003,7 @@ void process_teleport_finish(LLMessageSystem* msg, void**) gAgent.setTeleportState( LLAgent::TELEPORT_MOVING ); gAgent.setTeleportMessage(LLAgent::sTeleportProgressMessages["contacting"]); - LL_DEBUGS("CrossingCaps") << "Calling setSeedCapability from process_teleport_finish(). Seed cap == " + LL_DEBUGS("CrossingCaps") << "Calling setSeedCapability(). Seed cap == " << seedCap << LL_ENDL; regionp->setSeedCapability(seedCap); @@ -3028,6 +3036,8 @@ void process_avatar_init_complete(LLMessageSystem* msg, void**) void process_agent_movement_complete(LLMessageSystem* msg, void**) { + LL_DEBUGS("Teleport","Messaging") << "Received ProcessAgentMovementComplete" << LL_ENDL; + gShiftFrame = true; gAgentMovementCompleted = true; @@ -3037,13 +3047,13 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) msg->getUUIDFast(_PREHASH_AgentData, _PREHASH_SessionID, session_id); if((gAgent.getID() != agent_id) || (gAgent.getSessionID() != session_id)) { - LL_WARNS("Messaging") << "Incorrect id in process_agent_movement_complete()" - << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "Incorrect agent or session id in process_agent_movement_complete()" + << " agent " << agent_id << " expected " << gAgent.getID() + << " session " << session_id << " expected " << gAgent.getSessionID() + << ", ignoring" << LL_ENDL; return; } - LL_DEBUGS("Messaging") << "process_agent_movement_complete()" << LL_ENDL; - // *TODO: check timestamp to make sure the movement compleation // makes sense. LLVector3 agent_pos; @@ -3060,7 +3070,7 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) { // Could happen if you were immediately god-teleported away on login, // maybe other cases. Continue, but warn. - LL_WARNS("Messaging") << "agent_movement_complete() with NULL avatarp." << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "agent_movement_complete() with NULL avatarp." << LL_ENDL; } F32 x, y; @@ -3070,19 +3080,21 @@ void process_agent_movement_complete(LLMessageSystem* msg, void**) { if (gAgent.getRegion()) { - LL_WARNS("Messaging") << "current region " << gAgent.getRegion()->getOriginGlobal() << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "current region origin " + << gAgent.getRegion()->getOriginGlobal() << " id " << gAgent.getRegion()->getRegionID() << LL_ENDL; } - LL_WARNS("Messaging") << "Agent being sent to invalid home region: " - << x << ":" << y - << " current pos " << gAgent.getPositionGlobal() - << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "Agent being sent to invalid home region: " + << x << ":" << y + << " current pos " << gAgent.getPositionGlobal() + << ", calling forceDisconnect()" + << LL_ENDL; LLAppViewer::instance()->forceDisconnect(LLTrans::getString("SentToInvalidRegion")); return; } - LL_INFOS("Messaging") << "Changing home region to " << x << ":" << y << LL_ENDL; + LL_INFOS("Teleport","Messaging") << "Changing home region to region id " << regionp->getRegionID() << " handle " << region_handle << " == x,y " << x << "," << y << LL_ENDL; // set our upstream host the new simulator and shuffle things as // appropriate. @@ -5960,6 +5972,8 @@ std::string formatted_time(const time_t& the_time) void process_teleport_failed(LLMessageSystem *msg, void**) { + LL_WARNS("Teleport","Messaging") << "Received TeleportFailed message" << LL_ENDL; + std::string message_id; // Tag from server, like "RegionEntryAccessBlocked" std::string big_reason; // Actual message to display LLSD args; @@ -5978,6 +5992,7 @@ void process_teleport_failed(LLMessageSystem *msg, void**) // Nothing found in the map - use what the server returned in the original message block msg->getStringFast(_PREHASH_Info, _PREHASH_Reason, big_reason); } + LL_WARNS("Teleport") << "AlertInfo message_id " << message_id << " reason: " << big_reason << LL_ENDL; LLSD llsd_block; std::string llsd_raw; @@ -5987,10 +6002,11 @@ void process_teleport_failed(LLMessageSystem *msg, void**) std::istringstream llsd_data(llsd_raw); if (!LLSDSerialize::deserialize(llsd_block, llsd_data, llsd_raw.length())) { - LL_WARNS() << "process_teleport_failed: Attempted to read alert parameter data into LLSD but failed:" << llsd_raw << LL_ENDL; + LL_WARNS("Teleport") << "process_teleport_failed: Attempted to read alert parameter data into LLSD but failed:" << llsd_raw << LL_ENDL; } else { + LL_WARNS("Teleport") << "AlertInfo llsd block received: " << llsd_block << LL_ENDL; if(llsd_block.has("REGION_NAME")) { std::string region_name = llsd_block["REGION_NAME"].asString(); @@ -6029,6 +6045,7 @@ void process_teleport_failed(LLMessageSystem *msg, void**) args["REASON"] = message_id; } } + LL_WARNS("Teleport") << "Displaying CouldNotTeleportReason string, REASON= " << args["REASON"] << LL_ENDL; LLNotificationsUtil::add("CouldNotTeleportReason", args); @@ -6042,11 +6059,13 @@ void process_teleport_failed(LLMessageSystem *msg, void**) void process_teleport_local(LLMessageSystem *msg,void**) { + LL_INFOS("Teleport","Messaging") << "Received TeleportLocal message" << LL_ENDL; + LLUUID agent_id; msg->getUUIDFast(_PREHASH_Info, _PREHASH_AgentID, agent_id); if (agent_id != gAgent.getID()) { - LL_WARNS("Messaging") << "Got teleport notification for wrong agent!" << LL_ENDL; + LL_WARNS("Teleport", "Messaging") << "Got teleport notification for wrong agent " << agent_id << " expected " << gAgent.getID() << ", ignoring!" << LL_ENDL; return; } @@ -6058,6 +6077,7 @@ void process_teleport_local(LLMessageSystem *msg,void**) msg->getVector3Fast(_PREHASH_Info, _PREHASH_LookAt, look_at); msg->getU32Fast(_PREHASH_Info, _PREHASH_TeleportFlags, teleport_flags); + LL_INFOS("Teleport") << "Message params are location_id " << location_id << " teleport_flags " << teleport_flags << LL_ENDL; if( gAgent.getTeleportState() != LLAgent::TELEPORT_NONE ) { if( gAgent.getTeleportState() == LLAgent::TELEPORT_LOCAL ) diff --git a/indra/newview/llviewerregion.cpp b/indra/newview/llviewerregion.cpp index a30c5156fa..5c99e693d2 100644 --- a/indra/newview/llviewerregion.cpp +++ b/indra/newview/llviewerregion.cpp @@ -291,6 +291,7 @@ void LLViewerRegionImpl::requestBaseCapabilitiesCoro(U64 regionHandle) LL_INFOS("AppInit", "Capabilities") << "Requesting seed from " << url << " region name " << regionp->getName() + << " handle " << regionp->getHandle() << " (attempt #" << mSeedCapAttempts + 1 << ")" << LL_ENDL; LL_DEBUGS("AppInit", "Capabilities") << "Capabilities requested: " << capabilityNames << LL_ENDL; @@ -350,9 +351,9 @@ void LLViewerRegionImpl::requestBaseCapabilitiesCoro(U64 regionHandle) log_capabilities(mCapabilities); #endif + LL_DEBUGS("AppInit", "Capabilities", "Teleport") << "received caps for handle " << regionHandle + << " region name " << regionp->getName() << LL_ENDL; regionp->setCapabilitiesReceived(true); - LL_DEBUGS("AppInit", "Capabilities") << "received caps for handle " << regionHandle - << " region name " << regionp->getName() << LL_ENDL; if (STATE_SEED_GRANTED_WAIT == LLStartUp::getStartupState()) { -- cgit v1.2.3 From 9edb2fb6a758bc01125e3fd1b2cedbdaef725f22 Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Wed, 14 Oct 2020 14:52:36 +0100 Subject: SL-14081 - detail on viewer-initiated timeout --- indra/newview/llviewerdisplay.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/indra/newview/llviewerdisplay.cpp b/indra/newview/llviewerdisplay.cpp index fd283fe21b..d314b1477a 100644 --- a/indra/newview/llviewerdisplay.cpp +++ b/indra/newview/llviewerdisplay.cpp @@ -423,7 +423,7 @@ void display(BOOL rebuild, F32 zoom_factor, int subfield, BOOL for_snapshot) if( (gAgent.getTeleportState() != LLAgent::TELEPORT_START) && (teleport_percent > 100.f) ) { // Give up. Don't keep the UI locked forever. - LL_WARNS("Teleport") << "Giving up on teleport, teleport_percent is " << teleport_percent << LL_ENDL; + LL_WARNS("Teleport") << "Giving up on teleport. elapsed time " << teleport_elapsed << " exceeds max time " << teleport_save_time << LL_ENDL; gAgent.setTeleportState( LLAgent::TELEPORT_NONE ); gAgent.setTeleportMessage(std::string()); } -- cgit v1.2.3 From 3866b6270021630bdf759402a448ff17fc0c2550 Mon Sep 17 00:00:00 2001 From: "Brad Payne (Vir Linden)" Date: Wed, 14 Oct 2020 20:50:13 +0100 Subject: SL-14081 - changed debug level for one message --- indra/newview/llviewermessage.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/indra/newview/llviewermessage.cpp b/indra/newview/llviewermessage.cpp index 4f96838181..34d5dd5663 100644 --- a/indra/newview/llviewermessage.cpp +++ b/indra/newview/llviewermessage.cpp @@ -3036,7 +3036,7 @@ void process_avatar_init_complete(LLMessageSystem* msg, void**) void process_agent_movement_complete(LLMessageSystem* msg, void**) { - LL_DEBUGS("Teleport","Messaging") << "Received ProcessAgentMovementComplete" << LL_ENDL; + LL_INFOS("Teleport","Messaging") << "Received ProcessAgentMovementComplete" << LL_ENDL; gShiftFrame = true; gAgentMovementCompleted = true; -- cgit v1.2.3