diff --git a/battle_srv/models/room.go b/battle_srv/models/room.go index 0b5b399..1c91f63 100644 --- a/battle_srv/models/room.go +++ b/battle_srv/models/room.go @@ -407,6 +407,9 @@ func (pR *Room) rdfIdToActuallyUsedInputString() string { } fireballsStrBldr := make([]string, 0, len(rdf.FireballBullets)) for _, fireball := range rdf.FireballBullets { + if 0 > fireball.BattleAttr.BulletLocalId { + break + } fireballsStrBldr = append(fireballsStrBldr, pR.fireballDownsyncStr(fireball)) } s = append(s, fmt.Sprintf("rdfId:%d\nplayers:[%v]\nfireballs:[%v]\nactuallyUsedinputList:{%v}", rdfId, strings.Join(playersStrBldr, ","), strings.Join(fireballsStrBldr, ","), pR.inputFrameDownsyncStr(pR.rdfIdToActuallyUsedInput[rdfId]))) @@ -805,7 +808,7 @@ func (pR *Room) OnDismissed() { pR.RenderFrameBuffer = resolv.NewRingBuffer(pR.RenderCacheSize) pR.InputsBuffer = resolv.NewRingBuffer((pR.RenderCacheSize >> 1) + 1) pR.rdfIdToActuallyUsedInput = make(map[int32]*pb.InputFrameDownsync) - pR.allowUpdateInputFrameInPlaceUponDynamics = true + pR.allowUpdateInputFrameInPlaceUponDynamics = false pR.LastIndividuallyConfirmedInputFrameId = make([]int32, pR.Capacity) for i := 0; i < pR.Capacity; i++ { pR.LastIndividuallyConfirmedInputFrameId[i] = MAGIC_LAST_SENT_INPUT_FRAME_ID_NORMAL_ADDED @@ -1305,15 +1308,18 @@ func (pR *Room) forceConfirmationIfApplicable(prevRenderFrameId int32) uint64 { panic(fmt.Sprintf("inputFrameId=%v doesn't exist for roomId=%v! InputsBuffer=%v", j, pR.Id, pR.InputsBufferString(false))) } inputFrameDownsync := tmp.(*battle.InputFrameDownsync) - if pR.allowUpdateInputFrameInPlaceUponDynamics { - battle.UpdateInputFrameInPlaceUponDynamics(j, pR.Capacity, inputFrameDownsync.ConfirmedList, inputFrameDownsync.InputList, pR.LastIndividuallyConfirmedInputFrameId, pR.LastIndividuallyConfirmedInputList, int32(MAGIC_JOIN_INDEX_INVALID)) - } + /* + // [WARN] Frame logging showed that using "battle.UpdateInputFrameInPlaceUponDynamics" here would CONTAMINATE "all-confirmed inputs already sent & recognized by the frontends", root cause remains to be invesitgated! + if pR.allowUpdateInputFrameInPlaceUponDynamics { + battle.UpdateInputFrameInPlaceUponDynamics(j, pR.Capacity, inputFrameDownsync.ConfirmedList, inputFrameDownsync.InputList, pR.LastIndividuallyConfirmedInputFrameId, pR.LastIndividuallyConfirmedInputList, int32(MAGIC_JOIN_INDEX_INVALID)) + } + */ unconfirmedMask |= (allConfirmedMask ^ inputFrameDownsync.ConfirmedList) inputFrameDownsync.ConfirmedList = allConfirmedMask pR.onInputFrameDownsyncAllConfirmed(inputFrameDownsync, -1) } if 0 < unconfirmedMask { - Logger.Info(fmt.Sprintf("[type#1 forceConfirmation] For roomId=%d@renderFrameId=%d, curDynamicsRenderFrameId=%d, LatestPlayerUpsyncedInputFrameId:%d, oldLastAllConfirmedInputFrameId:%d, newLastAllConfirmedInputFrameId:%d, InputFrameUpsyncDelayTolerance:%d, unconfirmedMask=%d; there's a slow ticker suspect, forcing all-confirmation", pR.Id, pR.RenderFrameId, pR.CurDynamicsRenderFrameId, pR.LatestPlayerUpsyncedInputFrameId, oldLastAllConfirmedInputFrameId, pR.LastAllConfirmedInputFrameId, pR.InputFrameUpsyncDelayTolerance, unconfirmedMask)) + Logger.Info(fmt.Sprintf("[type#1 forceConfirmation] For roomId=%d@renderFrameId=%d, curDynamicsRenderFrameId=%d, LatestPlayerUpsyncedInputFrameId:%d, LastAllConfirmedInputFrameId:%d -> %d, InputFrameUpsyncDelayTolerance:%d, unconfirmedMask=%d; there's a slow ticker suspect, forcing all-confirmation", pR.Id, pR.RenderFrameId, pR.CurDynamicsRenderFrameId, pR.LatestPlayerUpsyncedInputFrameId, oldLastAllConfirmedInputFrameId, pR.LastAllConfirmedInputFrameId, pR.InputFrameUpsyncDelayTolerance, unconfirmedMask)) } } else { // Type#2 helps resolve the edge case when all players are disconnected temporarily @@ -1602,9 +1608,10 @@ func (pR *Room) downsyncToSinglePlayer(playerId int32, player *Player, refRender pbRefRenderFrame := toPbRoomDownsyncFrame(refRenderFrame) pbRefRenderFrame.SpeciesIdList = pR.SpeciesIdList pR.sendSafely(pbRefRenderFrame, toSendInputFrameDownsyncsSnapshot, DOWNSYNC_MSG_ACT_FORCED_RESYNC, playerId, false, MAGIC_JOIN_INDEX_DEFAULT) - //Logger.Warn(fmt.Sprintf("Sent refRenderFrameId=%v & inputFrameIds [%d, %d), for roomId=%v, playerId=%d, playerJoinIndex=%d, renderFrameId=%d, curDynamicsRenderFrameId=%d, playerLastSentInputFrameId=%d: InputsBuffer=%v", refRenderFrameId, toSendInputFrameIdSt, toSendInputFrameIdEd, pR.Id, playerId, player.JoinIndex, pR.RenderFrameId, pR.CurDynamicsRenderFrameId, player.LastSentInputFrameId, pR.InputsBufferString(false))) if shouldResync1 || shouldResync3 { - Logger.Debug(fmt.Sprintf("Sent refRenderFrameId=%v & inputFrameIds [%d, %d), for roomId=%v, playerId=%d, playerJoinIndex=%d, renderFrameId=%d, curDynamicsRenderFrameId=%d, playerLastSentInputFrameId=%d: shouldResync1=%v, shouldResync2=%v, shouldResync3=%v, playerBattleState=%d", refRenderFrameId, toSendInputFrameIdSt, toSendInputFrameIdEd, pR.Id, playerId, player.JoinIndex, pR.RenderFrameId, pR.CurDynamicsRenderFrameId, player.LastSentInputFrameId, shouldResync1, shouldResync2, shouldResync3, playerBattleState)) + Logger.Info(fmt.Sprintf("Sent refRenderFrameId=%v & inputFrameIds [%d, %d), for roomId=%v, playerId=%d, playerJoinIndex=%d, renderFrameId=%d, curDynamicsRenderFrameId=%d, playerLastSentInputFrameId=%d: shouldResync1=%v, shouldResync2=%v, shouldResync3=%v, playerBattleState=%d", refRenderFrameId, toSendInputFrameIdSt, toSendInputFrameIdEd, pR.Id, playerId, player.JoinIndex, pR.RenderFrameId, pR.CurDynamicsRenderFrameId, player.LastSentInputFrameId, shouldResync1, shouldResync2, shouldResync3, playerBattleState)) + } else { + Logger.Debug(fmt.Sprintf("Sent refRenderFrameId=%v & inputFrameIds [%d, %d), for roomId=%v, playerId=%d, playerJoinIndex=%d, renderFrameId=%d, curDynamicsRenderFrameId=%d, playerLastSentInputFrameId=%d: InputsBuffer=%v", refRenderFrameId, toSendInputFrameIdSt, toSendInputFrameIdEd, pR.Id, playerId, player.JoinIndex, pR.RenderFrameId, pR.CurDynamicsRenderFrameId, player.LastSentInputFrameId, pR.InputsBufferString(false))) } } else { pR.sendSafely(nil, toSendInputFrameDownsyncsSnapshot, DOWNSYNC_MSG_ACT_INPUT_BATCH, playerId, false, MAGIC_JOIN_INDEX_DEFAULT) diff --git a/frontend/assets/scripts/Map.js b/frontend/assets/scripts/Map.js index 2d8b251..f4978e3 100644 --- a/frontend/assets/scripts/Map.js +++ b/frontend/assets/scripts/Map.js @@ -714,6 +714,11 @@ cc.Class({ shouldForceDumping2 = false; shouldForceResync = false; self.othersForcedDownsyncRenderFrameDict.set(rdfId, rdf); + if (CC_DEBUG) { + console.warn(`Someone else is forced to resync! renderFrameId=${rdf.GetId()} +backendUnconfirmedMask=${pbRdf.backendUnconfirmedMask} +accompaniedInputFrameDownsyncBatchRange=[${null == accompaniedInputFrameDownsyncBatch ? null : accompaniedInputFrameDownsyncBatch[0].inputFrameId}, ${null == accompaniedInputFrameDownsyncBatch ? null : accompaniedInputFrameDownsyncBatch[accompaniedInputFrameDownsyncBatch.length - 1].inputFrameId}]`); + } } /* TODO @@ -744,10 +749,15 @@ cc.Class({ // In fact, not having "window.RING_BUFF_CONSECUTIVE_SET == dumpRenderCacheRet" should already imply that "self.renderFrameId <= rdfId", but here we double check and log the anomaly if (window.MAGIC_ROOM_DOWNSYNC_FRAME_ID.BATTLE_START == rdfId) { - console.log('On battle started! renderFrameId=', rdfId); + console.log(`On battle started! renderFrameId=${rdfId}`); } else { self.hideFindingPlayersGUI(); - console.warn('On battle resynced! renderFrameId=', rdf.GetId()); + if (CC_DEBUG) { + console.warn(`On battle resynced! renderFrameId=${rdf.GetId()} +accompaniedInputFrameDownsyncBatchRange=[${accompaniedInputFrameDownsyncBatch[0].inputFrameId}, ${accompaniedInputFrameDownsyncBatch[accompaniedInputFrameDownsyncBatch.length - 1].inputFrameId}]`); + } else { + console.warn(`On battle resynced! renderFrameId=${rdf.GetId()}`); + } } self.renderFrameId = rdfId; @@ -872,12 +882,12 @@ cc.Class({ while (self.recentInputCache.GetStFrameId() <= candidateInputFrameId && candidateInputFrameId < self.recentInputCache.GetEdFrameId()) { const inputFrameDownsync = gopkgs.GetInputFrameDownsync(self.recentInputCache, candidateInputFrameId); if (null == inputFrameDownsync) break; - if (self._allConfirmed(inputFrameDownsync.GetConfirmedList())) break; + if (false == self._allConfirmed(inputFrameDownsync.GetConfirmedList())) break; ++candidateInputFrameId; ++newAllConfirmedCnt; } if (0 < newAllConfirmedCnt) { - self.lastAllConfirmedInputFrameId = candidateInputFrameId; + self.lastAllConfirmedInputFrameId = candidateInputFrameId - 1; } return newAllConfirmedCnt; }, @@ -904,6 +914,7 @@ cc.Class({ continue; } // [WARNING] Now that "inputFrameDownsyncId > self.lastAllConfirmedInputFrameId", we should make an update immediately because unlike its backend counterpart "Room.LastAllConfirmedInputFrameId", the frontend "mapIns.lastAllConfirmedInputFrameId" might inevitably get gaps among discrete values due to "either type#1 or type#2 forceConfirmation" -- and only "onInputFrameDownsyncBatch" can catch this! + self.lastAllConfirmedInputFrameId = inputFrameDownsyncId; const localInputFrame = gopkgs.GetInputFrameDownsync(self.recentInputCache, inputFrameDownsyncId); if (null != localInputFrame && @@ -1000,8 +1011,8 @@ fromUDP=${fromUDP}`); } const peerJoinIndexMask = (1 << (peerJoinIndex - 1)); self.getOrPrefabInputFrameUpsync(inputFrameId, false); // Make sure that inputFrame exists locally - const existingInputFrame = self.recentInputCache.GetByFrameId(inputFrameId); - if (0 < (existingInputFrame.ConfirmedList & peerJoinIndexMask)) { + const existingInputFrame = gopkgs.GetInputFrameDownsync(self.recentInputCache, inputFrameId); + if (0 < (existingInputFrame.GetConfirmedList() & peerJoinIndexMask)) { continue; } if (inputFrameId > self.lastIndividuallyConfirmedInputFrameId[peerJoinIndex - 1]) { @@ -1010,9 +1021,9 @@ fromUDP=${fromUDP}`); } effCnt += 1; // the returned "gopkgs.NewInputFrameDownsync.InputList" is immutable, thus we can only modify the values in "newInputList" and "newConfirmedList"! - let newInputList = existingInputFrame.InputList.slice(); + let newInputList = existingInputFrame.GetInputList().slice(); newInputList[peerJoinIndex - 1] = peerEncodedInput; - let newConfirmedList = (existingInputFrame.ConfirmedList | peerJoinIndexMask); + let newConfirmedList = (existingInputFrame.GetConfirmedList() | peerJoinIndexMask); const newInputFrameDownsyncLocal = gopkgs.NewInputFrameDownsync(inputFrameId, newInputList, newConfirmedList); //console.log(`Updated encoded input of peerJoinIndex=${peerJoinIndex} to ${peerEncodedInput} for inputFrameId=${inputFrameId}/renderedInputFrameIdUpper=${renderedInputFrameIdUpper} from ${JSON.stringify(inputFrame)}; newInputFrameDownsyncLocal=${self.gopkgsInputFrameDownsyncStr(newInputFrameDownsyncLocal)}; existingInputFrame=${self.gopkgsInputFrameDownsyncStr(existingInputFrame)}`); self.recentInputCache.SetByFrameId(newInputFrameDownsyncLocal, inputFrameId); @@ -1164,9 +1175,11 @@ fromUDP=${fromUDP}`); const delayedInputFrameId = gopkgs.ConvertToDelayedInputFrameId(rdf.GetId()); const othersForcedDownsyncRenderFrame = self.othersForcedDownsyncRenderFrameDict.get(rdf.GetId()); if (self.lastAllConfirmedInputFrameId >= delayedInputFrameId && !self.equalRoomDownsyncFrames(othersForcedDownsyncRenderFrame, rdf)) { - console.warn(`Mismatched render frame@rdf.id=${rdf.GetId()} w/ inputFrameId=${delayedInputFrameId}: -rdf=${JSON.stringify(rdf)} -othersForcedDownsyncRenderFrame=${JSON.stringify(othersForcedDownsyncRenderFrame)}`); + if (CC_DEBUG) { + console.warn(`Mismatched render frame@rdf.id=${rdf.GetId()} w/ inputFrameId=${delayedInputFrameId}: +rdf=${self._stringifyGopkgRdfForFrameDataLogging(rdf)} +othersForcedDownsyncRenderFrame=${self._stringifyGopkgRdfForFrameDataLogging(othersForcedDownsyncRenderFrame)}`); + } rdf = othersForcedDownsyncRenderFrame; self.othersForcedDownsyncRenderFrameDict.delete(rdf.GetId()); } @@ -1423,8 +1436,11 @@ othersForcedDownsyncRenderFrame=${JSON.stringify(othersForcedDownsyncRenderFrame const j = gopkgs.ConvertToDelayedInputFrameId(i); const delayedInputFrame = gopkgs.GetInputFrameDownsync(self.recentInputCache, j); + const allowUpdateInputFrameInPlaceUponDynamics = (!isChasing); + const renderRes = gopkgs.ApplyInputFrameDownsyncDynamicsOnSingleRenderFrameJs(self.recentInputCache, i, collisionSys, collisionSysMap, self.spaceOffsetX, self.spaceOffsetY, self.chConfigsOrderedByJoinIndex, self.recentRenderCache, self.collisionHolder, self.effPushbacks, self.hardPushbackNormsArr, self.jumpedOrNotList, self.dynamicRectangleColliders, self.lastIndividuallyConfirmedInputFrameId, self.lastIndividuallyConfirmedInputList, allowUpdateInputFrameInPlaceUponDynamics, self.selfPlayerInfo.joinIndex); if (self.frameDataLoggingEnabled) { - const actuallyUsedInputClone = delayedInputFrame.GetInputList(); + // [WARNING] The "inputList" of "delayedInputFrame" could be mutated in "ApplyInputFrameDownsyncDynamicsOnSingleRenderFrameJs", thus should clone after dynamics is applied! + const actuallyUsedInputClone = delayedInputFrame.GetInputList().slice(); const inputFrameDownsyncClone = { inputFrameId: j, inputList: actuallyUsedInputClone, @@ -1432,8 +1448,6 @@ othersForcedDownsyncRenderFrame=${JSON.stringify(othersForcedDownsyncRenderFrame }; self.rdfIdToActuallyUsedInput.set(i, inputFrameDownsyncClone); } - const allowUpdateInputFrameInPlaceUponDynamics = (!isChasing); - const renderRes = gopkgs.ApplyInputFrameDownsyncDynamicsOnSingleRenderFrameJs(self.recentInputCache, i, collisionSys, collisionSysMap, self.spaceOffsetX, self.spaceOffsetY, self.chConfigsOrderedByJoinIndex, self.recentRenderCache, self.collisionHolder, self.effPushbacks, self.hardPushbackNormsArr, self.jumpedOrNotList, self.dynamicRectangleColliders, self.lastIndividuallyConfirmedInputFrameId, self.lastIndividuallyConfirmedInputList, allowUpdateInputFrameInPlaceUponDynamics, self.selfPlayerInfo.joinIndex); const nextRdf = gopkgs.GetRoomDownsyncFrame(self.recentRenderCache, i + 1); if (true == isChasing) { @@ -1549,34 +1563,41 @@ othersForcedDownsyncRenderFrame=${JSON.stringify(othersForcedDownsyncRenderFrame if (null == inputFrameDownsync) return "{}"; const self = this; let s = []; - s.push(`InputFrameId:${inputFrameDownsync.InputFrameId}`); + s.push(`InputFrameId:${inputFrameDownsync.GetInputFrameId()}`); let ss = []; for (let k = 0; k < window.boundRoomCapacity; ++k) { - ss.push(`"${inputFrameDownsync.InputList[k]}"`); + ss.push(`"${inputFrameDownsync.GetInputList()[k]}"`); } s.push(`InputList:[${ss.join(',')}]`); - s.push(`ConfirmedList:${inputFrameDownsync.ConfirmedList}`); + s.push(`ConfirmedList:${inputFrameDownsync.GetConfirmedList()}`); return `{${s.join(',')}}`; }, + _stringifyGopkgRdfForFrameDataLogging(rdf) { + const playersStrBldr = []; + for (let k = 0; k < window.boundRoomCapacity; k++) { + playersStrBldr.push(this.playerDownsyncStr(gopkgs.GetPlayer(rdf, k))); + } + const fireballsStrBldr = []; + for (let k = 0;; k++) { + const fireball = gopkgs.GetFireballBullet(rdf, k); + if (null == fireball) break; + fireballsStrBldr.push(this.fireballDownsyncStr(fireball)); + } + return `rdfId:${rdf.GetId()} +players:[${playersStrBldr.join(',')}] +fireballs:[${fireballsStrBldr.join(',')}]`; + }, + _stringifyRdfIdToActuallyUsedInput() { const self = this; let s = []; for (let i = self.recentRenderCache.GetStFrameId(); i < self.recentRenderCache.GetEdFrameId(); i++) { const actuallyUsedInputClone = self.rdfIdToActuallyUsedInput.get(i); - const rdf = self.recentRenderCache.GetByFrameId(i); - const playersStrBldr = []; - for (let k in rdf.GetPlayersArr()) { - playersStrBldr.push(self.playerDownsyncStr(rdf.GetPlayersArr()[k])); - } - const fireballsStrBldr = []; - for (let k in rdf.FireballBullets) { - fireballsStrBldr.push(self.fireballDownsyncStr(rdf.FireballBullets[k])); - } - s.push(`rdfId:${i} -players:[${playersStrBldr.join(',')}] -fireballs:[${fireballsStrBldr.join(',')}] + const rdf = gopkgs.GetRoomDownsyncFrame(self.recentRenderCache, i); + const rdfStr = self._stringifyGopkgRdfForFrameDataLogging(rdf); + s.push(`${rdfStr} actuallyUsedinputList:{${self.inputFrameDownsyncStr(actuallyUsedInputClone)}}`); }