Skipped Turns ... what to know about?
Hmm this is the stripped output of the skipped turn:
[261] 148000 [261][261] 70000 SYSTEM: TassieDevil* (1) skipped turn 262 [262] 9240000 [262][262] 9105000 [263] 143000 [263][263] 69000
round=0 turn=261 energy=202.08677255822562 x=776.13582252718 y=581.8541150752402 bodyHeading=2.973757997491294 gunHeading=3.678005429962749 radarHeading=3.8565206558480885 gunHeat=0.3999999999999998 velocity=-8.0 |
round=0 turn=262 energy=202.08677255822562 x=774.7994399340073 y=589.7417054274748 bodyHeading=2.973757997491294 gunHeading=3.664416366700783 radarHeading=3.057533429188674 gunHeat=0.2999999999999998 velocity=-8.0 |
round=0 turn=263 energy=202.08677255822562 x=773.4630573408346 y=597.6292957797094 bodyHeading=2.973757997491294 gunHeading=3.6510126360667408 radarHeading=3.82952786195208 gunHeat=0.19999999999999982 velocity=-8.0 |
|---|
Yep onStatus(..) is always the first event and holds every state of your robot.
The bug I hit was using the distance between locations from two ticks that had a getTime() difference of 1, so it shouldn't be an issue about moving during skipped turns. Anwyay, bots definitely should still move during skipped turns (or that could really break some physics), they just shouldn't be able to change their heading/velocity/distance remaining.
Thanks for doing all this debugging!
Ah good point. So the table shows almost how it should work. No bodyHeading and gunHeading change but still a radarHeading change. I will make some deeper tests, maybe i find something that brings some light on this.
Cool! So you think the original bug you hit was just "skipped turn message but didn't really skip turn"?
Also, if you called setTurnRight or setGunTurnRight and the command hasn't finished turning, I think those headings would still change on a skipped turn, as they would if you issued no new setXXX commands.
I think i got your bug figured out. Right now i'm to overtired to give you the numbers but i will do this tomorrow.
Basically what it does is the system skips some turns without a skip turn event, it just misses the turns out (happens very frequently). So it looks like this:
- 1 normal turn
- 2 lost turn without any data and no skip event
- 3 normal turn, you try to calculate the enemys x y but you get the wrong bearing from the system, your own values are ok
- 4 normal turn with delta time = 1, you calculate the enemys x y with the right values but if you calculate the distance to the last (wrong) x,y you get some distance that is way out of line
You can check this very easy if you just put the follow in onStatus(...)
if ((getTime() - lastTime) > 1)
{
System.out.format("blabla...\n");
}
lastTime = getTime();blabla should print out without a skipped turn event or console message.
Buahh 3:00am ... i have to sleep :) take care
Well this is what i got so far:
- robots get skipped turn events but actually never skip the turn (happens only by one turn skips)
- robots skip turns but get no skipped turn events
- after a skipped turn(s) the robot gets the wrong enemy bearing/distance and can not calculate the right x,y position of the enemy
- it also happens that the robot gets 2 scan events in a 1vs1 match with time differences out of order
- minor - the skipped turn message shows the turn number of the last turn and not the actual skipped turn number
- faster client speed causes more skipped turn
To make it replicable i wrote a little BugBot_1.0 which can be downloaded and checked by yourself. The source is included along with some examples for the output of the above issue points. Just put two BugBots against each other and play with the client speed. You can also record the match (1 round is enough) and see what the XML files says about the issues (this is not really necessary the console output shows it quite good).
The bot generate all kind of the above points and can be used to find the robocode bug behind this. If you don't get some of the above output just increase the speed of the client and it should be happen. You can also increase the amount of skipped turns by raising the run variables.
Well i hope this helps a little and hopefully the code is sound.
take care
Wow, awesome! We should definitely file a bug report to Robocode for some of these - I'm sure BugBot will be really helpful in finding these bugs and testing the fixes. I'll check him out this evening too. Cheers!
Thank you for the nice debugging Wompi! I was not aware of these issues. I especially like all the steps and details needed for seeing these issues. It's like a scientific approach. :-) This one will take me some time to fully understand, and I need to examine all the details and the BugBot_1.0 in detail. I also need to be sure that the BugBot is not really containing bugs. ;-) After that I will need to find the root of each issue and fix these. I don't expect this to be an easy task, so bear over with me if it takes some time to do. I will have my first priority to fix. :-)
Ah i missed your response. Yep take your time. I guess it is only fair to do some debug work because you probably have other things do do as well :).
Btw. thanks for taking care of the Robocode engine.
Take Care
This issue took a looong time to fix properly, i.e. without braking other stuff in Robocode and still fix all the observed issues. Sorry for that.
I have made an 1.8.1 Alpha 2 version of Robocode you can try out here: http://robocode.sourceforge.net/files/robocode-1.8.1.0-Alpha-2-setup.jar
Please check this version out and see if all issues regarding skipped turns have been solved properly. :-)
--Fnl 22:59, 22 February 2013 (UTC)
Sure thing, I will give it a try right away and give you a response as fast as I get some results. Thank you Fnl.
Hi mate.
That is an awesome fix you provided there. I tested all kind of stuff related to skipped turns and it works like a charm.
Things I tested so far:
no more hidden skipped turns (very nice)
no more wrong onScannedEvents(..) (I'm most excited :) well done)
right turn number for skipped turn events (nice to have :) )
disable bots if they skip more than 30 turns - just to check if it still works (and it does :))
also gone is the 'skipped turn message but no actually skipped turn' issue (just a minor issue but thanks for fixing this too)
it also looks like the influence of other bots is gone too. If I compare 'all nano' vs 'all general' melee battles,
I got no difference in average skipped turns anymore
I have a quite large code base for skipped turns and I could detect something that looks suspicious. The output is from different battles - all full (10) melee.
This is the output if everything works fine ([x] skip xA - xB is the output within onStatus(), xA - lastStatusTime, xB - currentStatusTime):
SYSTEM: Numbat 2.1* skipped turn 6 [7] skip 5 - 7 SYSTEM: Bonus for killing cs.Grudge 1.0: 17 SYSTEM: Numbat 2.1* skipped turn 156 [157] skip 155 - 157 SYSTEM: Numbat 2.1* skipped turn 404 [405] skip 403 - 405 SYSTEM: Numbat 2.1* skipped turn 728 SYSTEM: Numbat 2.1* skipped turn 729 [730] skip 727 - 730 SYSTEM: Bonus for killing simonton.nano.MeleeSeed 1.8: 4 SYSTEM: Bonus for killing kawigi.nano.Lib 1.0: 3 SYSTEM: wompi.Numbat 2.1* wins the round.
This is the output for some other battles and it looks like the system sends an StatusEvent even if the bot is dead.
Round 8 of 35
=========================
SYSTEM: Bonus for killing radnor.DoctorBob 1.42: 7
[1004] skip 973 - 1004 <------- last status event on 973 and current status event on 1004
no skip events and I'm not having skipped 31 turns (average is 6 per battle)
see following outputs for equally behavior on onDeath
I can't say if I died on 974 and the system just delayed the message,
or if something other happens
[1004] DEAD <-------- output from onDeath()
SYSTEM: wompi.Numbat 2.1* has died
Round 9 of 35
=========================
[244] skip 241 - 244
[0244] DEAD
SYSTEM: wompi.Numbat 2.1* has died
Round 25 of 35
=========================
SYSTEM: Bonus for killing cs.Grudge 1.0: 5
SYSTEM: Bonus for killing radnor.DoctorBob 1.42: 2
[661] skip 649 - 661
[0661] DEAD
SYSTEM: wompi.Numbat 2.1* has died
There is another one, but that should be discussed by the community, I guess. If a bot skips 30 turns within the victory turns he gets the 'no action message':
SYSTEM: wompi.BugBot* (2) wins the round. SYSTEM: BugBot* (2) skipped turn 36 .... SYSTEM: BugBot* (2) skipped turn 83 <-------- way more than 30 turns SYSTEM: BugBot* (2) has not performed any actions in a reasonable amount of time. SYSTEM: No score will be generated.
So the bot gets disabled and (probably - not tested right now)) no score, even if he has won the game at this point. I don't know if this should be handled somehow or if it is a legal response to bots - would be great to get some opinions about this issue.
Anyway, great work and you can be sure all your work on the RoboCode engine is very much appreciated by all community members, I guess.
Take Care
Big thanks Fnl for sorting this out! And also to Wompi for testing it! I saw this yesterday and was wondering if I even remembered how the heck to test this, and was sad Wompi wasn't around, but I guess he is. :-)
You guys rock!
Great work! I'm curious, did this just affect the printing, getTime() and skipped turn notifications, or was Robocode actually doing the skipped turns inconsistently before?
@Skilgannon - Sorry I don't get the question. Is the question related to the two new issues or to the former issues? And who is it you asking :) me or Fnl? It is probably because I'm not a native english speaker but I can not realize what is meant, sorry for that.
@Voidious - thanks, I'm reading the wiki every day but have almost no time/clear mind over the week.
It was directed more at Fnl, but perhaps you can answer. I was wondering if the actual internals of Robocode were also behaving incorrectly, or if it only looked like it from the robot perspective.
