poke-env
poke-env copied to clipboard
Published
20 hours ago •
hsahovic
hsahovic
Time taken per N battles increases progressively
Hi Some context: I want to study the winrates/pickrates of Pokemon across a large number of battles. I'm using the Teambuilder to set up teams on the fly by generating some M teams every N battles and randomly sampling a team for every new battle.
I'm encountering a bit of a weird issue here in that the amount of time taken seems to be increasing significantly the more battles I play. For instance, I'm trying to play 100k battles wherein I generate ~2.5k teams every 1000 battles. I'm timing each component separately. Generating the teams takes ~5 seconds. Tracking wins/picks is negligible as well. However the time taken to play those 1000 battles increases significantly over time. In the start it takes about 70-100s to complete 1k battles. This remains true until around the 2900 battles mark. At which point the time taken almost doubles - 160s, 518s, 1175s, 2705s. This is really weird and I suspect that there's a bottleneck somewhere, though I don't know what.
I also tried the same scenario where I do 10k battles before generating teams. It took 1433s for the first 10k, 2402s for the next 10k and 4+ hours for the next 10k.
I also thought that it could be an issue with my team generation so I tried disabling that and just doing random battles. But that didn't change anything either.
~I'll post a stripped down version of my code in the next comment.~ See code below. This doesn't use the teambuilder or my own agent.
Okay update. I stripped out all extra parts and just used a random agent as well. I've run it multiple times and every time the time taken starts to increase drastically.
import asyncio
import numpy as np
import random
import time
import torch
from poke_env.player.random_player import RandomPlayer
from poke_env.player_configuration import PlayerConfiguration
async def play_battles(player1, player2, n_battles):
await player1.battle_against(player2, n_battles=n_battles)
if __name__ == "__main__":
# Total num. battles to simulate
num_battles_to_simulate = 100000
# Num. battles between generating new teams
team_generation_interval = 1000
# Num. teams generated
num_teams_to_generate = 2500
# Set random seed for reproducible results
random_seed = 42
player1 = RandomPlayer(
battle_format="gen8randombattle",
max_concurrent_battles=25,
start_timer_on_battle_start=True,
player_configuration=PlayerConfiguration("Battle_Agent_1", None),
)
player2 = RandomPlayer(
battle_format="gen8randombattle",
max_concurrent_battles=25,
start_timer_on_battle_start=True,
player_configuration=PlayerConfiguration("Battle_Agent_2", None),
)
# Use random seeds
random.seed(random_seed)
np.random.seed(random_seed)
_ = torch.manual_seed(random_seed)
start_time = time.time()
for i in range(num_battles_to_simulate // team_generation_interval):
print(f"Epoch {i+1}")
# Play battles
print("Battling")
start = time.time()
asyncio.run(
play_battles(
player1=player1,
player2=player2,
n_battles=team_generation_interval,
)
)
end = time.time()
print(f"Battles Completed: {team_generation_interval}")
print(f"Time Taken: {end - start}s")
# Reset trackers so we don't count battles twice
player1.reset_battles()
player2.reset_battles()
end_time = time.time()
print(f"Simulation Time Taken: {end_time - start_time:.4f}")
Example output log:
Epoch 15
Battling
Battles Completed: 1000
Time Taken: 155.8295464515686s
Epoch 16
Battling
Battles Completed: 1000
Time Taken: 181.3100483417511s
Epoch 17
Battling
Battles Completed: 1000
Time Taken: 289.30181765556335s
Epoch 18
Battling
Battles Completed: 1000
Time Taken: 502.67641592025757s
Epoch 19
Battling
Battles Completed: 1000
Time Taken: 993.1844747066498s
Epoch 20
Battling
Battles Completed: 1000
Time Taken: 1755.9275789260864s
Okay so this doesn't seem like it's restricted to just the general API either. Same issue on the Gym API. Times over 10 "epochs": 912.204, 843.306, 854.991, 996.165, 1855.084, 2998.612, 2181.692, 2392.389, 2735.754, 3727.633, 4213.733
This also means that the problem is not with the battle_against function either.
import asyncio
import numpy as np
import random
import time
import torch
from threading import Thread
from agents import simple_agent
from poke_env.player_configuration import PlayerConfiguration
gpu = torch.cuda.is_available()
device = torch.device("cuda" if gpu else "cpu")
def get_action(player, state, actor_critic=False):
if actor_critic:
with torch.no_grad():
predictions, _ = player.model(state.to(device))
else:
with torch.no_grad():
predictions = player.model(state.to(device))
return predictions.cpu()
async def battle_handler(player1, player2, num_challenges):
await asyncio.gather(
player1.agent.accept_challenges(player2.username, num_challenges),
player2.agent.send_challenges(player1.username, num_challenges),
)
def play_battles(player, num_battles):
is_actor_critic = "ActorCritic" in str(player.model)
for _ in range(num_battles):
done = False
state = player.reset()
while not done:
action_mask = player.action_masks()
# Get action
predictions = get_action(player, state, is_actor_critic)
# Use policy
action = np.argmax(predictions + action_mask)
# Play move
state, reward, done, _ = player.step(action)
def play_battles_wrapper(player1, player2, n_battles):
# Make Two Threads; one per player
t1 = Thread(target=lambda: play_battles(player1, n_battles))
t1.start()
t2 = Thread(target=lambda: play_battles(player2, n_battles))
t2.start()
# On the network side, send & accept N battles
asyncio.run(battle_handler(player1, player2, n_battles))
# Wait for thread completion
t1.join()
t2.join()
player1.close(purge=False)
player2.close(purge=False)
if __name__ == "__main__":
# Total num. battles to simulate
num_battles_to_simulate = 100000
# Num. battles between generating new teams
team_generation_interval = 1000
# Num. teams generated
num_teams_to_generate = 2500
# Set random seed for reproducible results
random_seed = 42
# Create our battle agents
player1_kwargs = {}
player2_kwargs = {}
player1 = simple_agent.SimpleRLPlayerTesting(
battle_format="gen8randombattle",
model=player1_model,
start_timer_on_battle_start=True,
player_configuration=PlayerConfiguration("Battle_Agent_1", None),
opponent=None,
start_challenging=False,
**player1_kwargs,
)
player2 = simple_agent.SimpleRLPlayerTesting(
battle_format="gen8randombattle",
model=player2_model,
start_timer_on_battle_start=True,
player_configuration=PlayerConfiguration("Battle_Agent_2", None),
opponent=None,
start_challenging=False,
**player2_kwargs,
)
# Use random seeds
random.seed(random_seed)
np.random.seed(random_seed)
_ = torch.manual_seed(random_seed)
start_time = time.time()
for i in range(num_battles_to_simulate // team_generation_interval):
print(f"Epoch {i+1}")
# Play battles
print("Battling")
start = time.time()
play_battles_wrapper(
player1=player1,
player2=player2,
n_battles=team_generation_interval,
)
end = time.time()
print(f"Battles Completed: {team_generation_interval}")
print(f"Time Taken: {end - start}s")
end_time = time.time()
print(f"Simulation Time Taken: {end_time - start_time:.4f}")
It seems to be running fine if I do multiple small runs (run for 10k battles. Stop. Run again for 10k battles). But if I run for a larger number it's a lot more likely that I have this issue.
I think this might be due to a memory leak somewhere?
[slow battle] 1027ms - >p1 move flamethrower
[slow battle] 1030ms - >p2 move blizzard
[slow battle] 1015ms - >p1 switch weavile
[slow battle] 1047ms - >p1 switch froslass
[slow battle] 1079ms - >p2 move earthquake
[slow battle] 1053ms - >p2 move bodypress
[slow battle] 1065ms - >p1 move playrough
[slow battle] 1056ms - >p2 move dracometeor
[slow battle] 1036ms - >p1 switch sawk
[slow battle] 1099ms - >p2 move scald
[slow battle] 1088ms - >p2 switch pumpkaboo
[slow battle] 1075ms - >p2 move solarbeam
[slow battle] 1061ms - >p2 move rockslide
[slow battle] 1088ms - >p2 move protect
[slow battle] 1079ms - >p2 move fleurcannon
[slow battle] 1057ms - >p2 move endeavor
[slow battle] 1094ms - >p2 move sludgebomb
[slow battle] 1092ms - >p2 move focusblast
[slow battle] 1063ms - >p2 move waterspout
[slow battle] 1082ms - >p2 move weatherball
[slow battle] 1063ms - >player p1 {"name":"8000Agent1","avatar":"169","team":"Persian|PersianAlola|HeavyDutyBoots|FurCoat|KnockOff,PartingShot,Toxic,FoulPlay|Jolly|252,,4,,,252|||||]Bewear||ChopleBerry|Fluffy|SwordsDance,DoubleEdge,DrainPunch,DarkestLariat|Jolly|,252,,,4,252|||||]Dugtrio||ChoiceScarf|ArenaTrap|Earthquake,StoneEdge,Memento,Toxic|Adamant|,244,,,140,124|||||]Mantine||HeavyDutyBoots|WaterAbsorb|Scald,Roost,Defog,Toxic|Bold|252,,252,,4,|||||]Appletun||Leftovers|ThickFat|AppleAcid,LeechSeed,Recover,DragonPulse|Calm|248,,,8,252,|||||]Suicune||Leftovers|Pressure|CalmMind,Scald,Rest,SleepTalk|Bold|252,,252,,4,|N||||","rating":0}
[slow battle] 1089ms - >p2 switch walrein
[slow battle] 1072ms - >p2 switch dottler
[slow battle] 1095ms - >p1 switch calyrexshadow [616/9892][slow battle] 1066ms - >p2 move taunt
[slow battle] 1104ms - >p2 switch carbink
[slow battle] 1070ms - >p1 move iciclespear
[slow battle] 1068ms - >p2 move crunch
[slow battle] 1077ms - >p1 move encore
[slow battle] 1079ms - >p2 move earthpower
[slow battle] 1086ms - >p1 move defog
[slow battle] 1079ms - >p2 move protect
[slow battle] 1102ms - >p2 move futuresight
[slow battle] 1071ms - >p2 move closecombat
[slow battle] 1077ms - >p2 move gunkshot
[slow battle] 1075ms - >p1 move substitute
[slow battle] 1078ms - >p2 move thunderbolt
[slow battle] 1092ms - >p2 move gigadrain
<--- Last few GCs --->
[1252:0x47b2dd0] 3548016 ms: Scavenge 1864.4 (2065.5) -> 1849.2 (2066.2) MB, 9.5 / 0.0 ms (average mu = 0.341, current mu = 0.425) allocation failure
[1252:0x47b2dd0] 3548162 ms: Scavenge 1866.2 (2066.2) -> 1851.1 (2067.0) MB, 10.5 / 0.0 ms (average mu = 0.341, current mu = 0.425) allocation failure
[1252:0x47b2dd0] 3549389 ms: Mark-sweep 1867.9 (2067.0) -> 1846.1 (2066.7) MB, 1087.3 / 0.0 ms (average mu = 0.346, current mu = 0.353) allocation failure scavenge might not succeed
<--- JS stacktrace ---> [590/9892]
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
1: 0xa38bc0 node::Abort() [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
2: 0xa38ff9 node::OnFatalError(char const*, char const*) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
3: 0xb93a8e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
4: 0xb93d1d v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
5: 0xd09905 [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
6: 0xd099e7 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
7: 0xd1b7f6 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
8: 0xd1c4d8 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
9: 0xd1e7cd v8::internal::Heap::AllocateRawWithLightRetrySlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
10: 0xd1e835 v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
11: 0xce8d4b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
12: 0xfd96f2 v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
13: 0x12f44d9 [/cvmfs/soft.computecanada.ca/easybuild/software/2017/avx2/Compiler/gcc7.3/nodejs/14.4.0/bin/node]
CRASH: Error: Process room-battle.ts 1252 crashed and had to be restarted
at StreamProcessManager.releaseCrashed (/localscratch/akash3.44532037.0/pokemon-showdown/lib/process-manager.ts:474:4)
at ChildProcess.<anonymous> (/localscratch/akash3.44532037.0/pokemon-showdown/lib/process-manager.ts:515:47)
at ChildProcess.emit (events.js:315:20)
at ChildProcess.EventEmitter.emit (domain.js:485:12)
at finish (internal/child_process.js:891:14)
at processTicksAndRejections (internal/process/task_queues.js:79:11)
I get this same issue when I ran for around 200k steps. First 50k were great but every progressive epoch took longer and longer. Eventually the time per epoch was over 10k the first epoch.
