SanchoGGP / ggp-base

The General Game Playing Base Package
8 stars 4 forks source link

Frequently reporting negative simulations/second #159

Closed arr28 closed 10 years ago

arr28 commented 10 years ago

For example...

13:19:41.222 - -136248 simulations/second performed - setting rollout sample size to 8

I think this is a recent regression (i.e. since I went on holiday).

SteveDraper commented 10 years ago

Nothing has changed in hat area (in the branch we merged anyway) apart from using larger divisor at the end. Do you have a full log of the nmetagaming? The timestamps might provide some clues.

On Mon, Jul 28, 2014 at 7:41 AM, Andrew Rose notifications@github.com wrote:

For example...

13:19:41.222 - -136248 simulations/second performed - setting rollout sample size to 8

I think this is a recent regression (i.e. since I went on holiday).

— Reply to this email directly or view it on GitHub https://github.com/SteveDraper/ggp-base/issues/159.

arr28 commented 10 years ago

I had several instances, so I'm guessing it's readily reproducible. I was generally testing puzzles with 60s/15s timings. Here's an example of a match of Pearls.

2014-07-28 13:19:29,007 INFO  RequestFactory                 ======================================================
2014-07-28 13:19:29,008 INFO  RequestFactory                 Beginning new game: Base.pearls.1406549968907
2014-07-28 13:19:29,008 INFO  RequestFactory                 Logs available at:  http://localhost:9199/localview/Base.pearls.1406549968907
2014-07-28 13:19:29,024 WARN  GDLTranslator                  Unrecognised game.  Created new game directory: data\games\1406549969024
( role robot )
( init p1 )
( <= ( legal robot a ) ( true p1 ) )
( <= ( legal robot a ) ( true p2 ) )
( <= ( legal robot a ) ( true p5 ) )
( <= ( legal robot a ) ( true p6 ) )
( <= ( legal robot a ) ( true p9 ) )
( <= ( legal robot a ) ( true p10 ) )
( <= ( legal robot a ) ( true p13 ) )
( <= ( legal robot a ) ( true p14 ) )
( <= ( legal robot b ) ( true p1 ) )
( <= ( legal robot b ) ( true p3 ) )
( <= ( legal robot b ) ( true p5 ) )
( <= ( legal robot b ) ( true p7 ) )
( <= ( legal robot b ) ( true p9 ) )
( <= ( legal robot b ) ( true p11 ) )
( <= ( legal robot b ) ( true p13 ) )
( <= ( legal robot b ) ( true p15 ) )
( <= ( legal robot c ) ( true p4 ) )
( <= ( legal robot c ) ( true p8 ) )
( <= ( legal robot c ) ( true p12 ) )
( <= ( next p2 ) ( does robot a ) ( true p1 ) )
( <= ( next p3 ) ( does robot b ) ( true p1 ) )
( <= ( next p4 ) ( does robot a ) ( true p2 ) )
( <= ( next p4 ) ( does robot b ) ( true p3 ) )
( <= ( next p5 ) ( does robot c ) ( true p4 ) )
( <= ( next p6 ) ( does robot a ) ( true p5 ) )
( <= ( next p7 ) ( does robot b ) ( true p5 ) )
( <= ( next p8 ) ( does robot a ) ( true p6 ) )
( <= ( next p8 ) ( does robot b ) ( true p7 ) )
( <= ( next p9 ) ( does robot c ) ( true p8 ) )
( <= ( next p10 ) ( does robot a ) ( true p9 ) )
( <= ( next p11 ) ( does robot b ) ( true p9 ) )
( <= ( next p12 ) ( does robot a ) ( true p10 ) )
( <= ( next p12 ) ( does robot b ) ( true p11 ) )
( <= ( next p13 ) ( does robot c ) ( true p12 ) )
( <= ( next p14 ) ( does robot a ) ( true p13 ) )
( <= ( next p15 ) ( does robot b ) ( true p13 ) )
( <= ( next p16 ) ( does robot a ) ( true p14 ) )
( <= ( next p16 ) ( does robot b ) ( true p15 ) )
( <= ( goal robot 90 ) ( true p16 ) )
( <= ( goal robot 0 ) ( not ( true p16 ) ) )
( <= terminal ( true p16 ) )

2014-07-28 13:19:29,193 INFO  dDeadReckonPropnetStateMachine Reducing with respect to XSentence: ( true p9 )
2014-07-28 13:19:29,206 INFO  dDeadReckonPropnetStateMachine Num components in goal-less X-net: 62
2014-07-28 13:19:29,206 INFO  dDeadReckonPropnetStateMachine Num components in goal-less O-net: 64
2014-07-28 13:19:29,206 INFO  dDeadReckonPropnetStateMachine Num components in goal net:        5
2014-07-28 13:19:29,208 INFO  MachineSpecificConfiguration   Running with machine-specific properties:
2014-07-28 13:19:29,208 INFO  MachineSpecificConfiguration      SAFETY_MARGIN = 3300
2014-07-28 13:19:29,208 INFO  MachineSpecificConfiguration      DISABLE_LEARNING = true
2014-07-28 13:19:29,220 INFO  Sancho                         Start clock: 60s
2014-07-28 13:19:29,220 INFO  Sancho                         Play clock:  15s
2014-07-28 13:19:29,220 INFO  Sancho                         We are:      robot
2014-07-28 13:19:29,220 INFO  dDeadReckonPropnetStateMachine No positive goal latches
2014-07-28 13:19:29,220 INFO  dDeadReckonPropnetStateMachine No negative goal latches
2014-07-28 13:19:29,314 INFO  ThreadControl                    Bound search thread to vCPU:  0
2014-07-28 13:19:41,221 INFO  CombinedHeuristic              No heuristics enabled
2014-07-28 13:19:41,221 INFO  Sancho                         branchingFactorApproximation = 2.0, averageBranchingFactor = 0.0, choices high water mark = 0
2014-07-28 13:19:41,221 INFO  GameCharacteristics            Game is a pseudo puzzle
2014-07-28 13:19:41,221 INFO  GameCharacteristics            Game is not a simultaneous turn game
2014-07-28 13:19:41,221 INFO  GameCharacteristics            Game is a 1-player puzzle
2014-07-28 13:19:41,221 INFO  Sancho                         Range of lengths of sample games seen: [10,10]
2014-07-28 13:19:41,221 INFO  Sancho                         Average num turns: 10.0
2014-07-28 13:19:41,221 INFO  Sancho                         Std deviation num turns: 0.0
2014-07-28 13:19:41,221 INFO  GameSearcher                   Set explorationBias range to [0.96, 1.44]
2014-07-28 13:19:41,221 INFO  Sancho                         Estimated greedy rollout cost: 0.0
2014-07-28 13:19:41,222 INFO  Sancho                         Puzzle with no observed solution
2014-07-28 13:19:41,222 INFO  Sancho                         Found target state: [( true p16 )]
2014-07-28 13:19:41,222 INFO  Sancho                         Unsuitable target state based on state elimination - ignoring
2014-07-28 13:19:41,222 INFO  Sancho                         Min raw score = 90, max = 90
2014-07-28 13:19:41,222 INFO  Sancho                         multiRoleAverageScoreDiff = 0
2014-07-28 13:19:41,222 INFO  Sancho                         No score discrimination seen during simulation - resetting to [0,100]
2014-07-28 13:19:41,222 INFO  Sancho                         Game is a puzzle so not normalizing scores
2014-07-28 13:19:41,222 INFO  Sancho                         -136248 simulations/second performed - setting rollout sample size to 8
arr28 commented 10 years ago

Here are the games I saw it in.

Base.haystack.1406550062894-9147.txt:197:2014-07-28 13:21:15,338 INFO  Sancho                         -193655 simulations/second performed - setting rollout sample size to 39
Base.multiplebuttonsandlights.1406551157060-9147.txt:209:2014-07-28 13:39:30,055 INFO  Sancho                         -62433 simulations/second performed - setting rollout sample size to 42
Base.pearls.1406549968907-9147.txt:205:2014-07-28 13:19:41,222 INFO  Sancho                         -136248 simulations/second performed - setting rollout sample size to 8
Base.untwistybig.1406549896637-9147.txt:244:2014-07-28 13:18:29,348 INFO  Sancho                         -189397 simulations/second performed - setting rollout sample size to 17
oneshot.rainbow.1406542920075-9147.txt:206:2014-07-28 11:22:12,514 INFO  Sancho                         -161622 simulations/second performed - setting rollout sample size to 7
arr28 commented 10 years ago

Okay - so not a regression. This bug happens for any game where we manage to perform more than 2 million simulations during meta-gaming (max. 10 seconds).

Could cause wildly wrong initial sample size.

Fix is very simple - change the type of a local variable from int to long.

Checked in to negative-simulation-rate feature branch. Please review, consider whether you want to take it and then finish the branch (assuming you do).

SteveDraper commented 10 years ago

Reviewed and merged - we'll play with that fix.

On Tue, Jul 29, 2014 at 7:09 AM, Andrew Rose notifications@github.com wrote:

Okay - so not a regression. This bug happens for any game where we manage to perform more than 2 million simulations during meta-gaming (max. 10 seconds).

Could cause wildly wrong initial sample size.

Fix is very simple - change the type of a local variable from int to long.

Checked in to negative-simulation-rate feature branch. Please review, consider whether you want to take it and then finish the branch (assuming you do).

— Reply to this email directly or view it on GitHub https://github.com/SteveDraper/ggp-base/issues/159#issuecomment-50467424 .