[1858] Random refresh with error message about blue privates

[ianwilson156]

https://18xx.games/game/183151

OR4.1 MZA bought the first 6H, and discarded a 2H. The A was also over train limit, but when I tried to discard a 2H, an error message flashed up briefly (something about blue privates?) and the program refreshed.
After a couple more tries, it accepted the discard.
Looks like something from Switzerland has interfered with the base game.

[ianwilson156]

Now it's doing it later on in A's turn (placing tokens etc). It's taking 2-3 attempts to do anything!

Message is something like "blue_privates_available".

[ollybh]

I'm not able to reproduce this error. And I've checked the code and can't see how anything about blue privates would be showing up in the 1858 base game, all that code is confined to the 1858 Switzerland directory. Weird.

Has the game been working since you got past this step?

[ianwilson156]

Both myself and others have seen this problem in multiple games.
We played a live game yesterday
https://18xx.games/game/187319
where it was happening frequently, but seemingly at random.
Sometimes redoing the action was enough, sometimes it took up to 4 times to get it to accept the action.
It only seems to happen once one is some way into the game - phase 6H? That would make sense, since it is complaining about the blue privates.
It seems to happen at any action too.

[ianwilson156]

https://18xx.games/game/187319
We've got to SR5, and I'm trying to buy a ZPB share, but the bug won't let me - even after many attempts!
The error message says: "The server did not accept this action due to: undefined method 'event_blue_privates_available!' for Engine:Game:G1858:Game - 1858[<usernames.].....

but if I try something different first (i.e. writing a comment!) it then progresses normally!
This is some weird bug.

[ianwilson156]

https://18xx.games/game/183151
We're also in SR5, and it won't let me pass!
Again, if I write a comment, it seems to fix the problem.

[ianwilson156]

https://18xx.games/game/187319
We've now got to SR6 - in phase 7 - and it's still doing it!

[ianwilson156]

https://18xx.games/game/187319
I have cloned this game, and replayed OR4.1, OR4.2, and SR5 in hotseat mode.
At no point did the bug appear - it only happens when running multi-player, not in hotseat mode.
Speaking as an engineer with experience of tracking down (hardware) bugs, I'd say this is a Clue.

[ianwilson156]

Further note: I tried just taking my moves on my iphone, but the bug happens there as well.

[ollybh]

I'm still failing to be able to reproduce this error, either in hotseat mode, or in multi-player mode on my development server. This is more than a little annoying.

[ianwilson156]

Should we play a test game on the main server?
#189055

[fanman80]

This has been a problem for quite a while in https://18xx.games/game/186978

It seemed to start at or shortly before https://18xx.games/game/186978?action=496

The problem has persisted throughout the game so far.

This has been a problem on my laptop (Dell running Windows 11) and Android phone, LG V30, and other players in the game are experiencing it too.

[philcampeau]

It's also happening in https://18xx.games/game/186045 (reported here.

[philcampeau]

This actually reminds me a lot of the bug I'm dealing with in the 1849 Bonds variant. There error there is a variation on this:

and like this issue, I can't reproduce it either in hotseat mode or on my local dev server. I'm mentioning it here because I suspect that when we find the solution for one of these issues, it'll also inform us on the solution for the other.

[ollybh]

I've finally managed to capture a backtrace from the server for when this error occurs. Unfortunately it doesn't tell me anything that I hadn't already guessed.

ERROR -- : undefined method `event_blue_privates_available!' for Engine::Game::G1858::Game - 1858 ["c_sharper", "plinkb", "Bundyman", "Pitchfork", "ollybh"]:Engine::Game::G1858::Game

/18xx/lib/engine/phase.rb:26:in `block in buying_train!'
/18xx/lib/engine/phase.rb:25:in `each'
/18xx/lib/engine/phase.rb:25:in `buying_train!'
/18xx/lib/engine/step/train.rb:107:in `buy_train_action'
/18xx/lib/engine/step/buy_train.rb:69:in `process_buy_train'
/18xx/lib/engine/game/g_1858/step/buy_train.rb:84:in `process_buy_train'
/18xx/lib/engine/round/base.rb:93:in `process_action'
/18xx/lib/engine/game/base.rb:825:in `process_single_action'
/18xx/lib/engine/game/base.rb:785:in `process_action'
/18xx/lib/engine/game/base.rb:941:in `block in process_to_action'
/18xx/lib/engine/game/base.rb:935:in `each'
/18xx/lib/engine/game/base.rb:935:in `with_index'
/18xx/lib/engine/game/base.rb:935:in `process_to_action'
/18xx/lib/engine/game/base.rb:763:in `initialize_actions'
/18xx/lib/engine/game/base.rb:626:in `initialize'
/18xx/lib/engine/game/base.rb:79:in `new'
/18xx/lib/engine/game/base.rb:79:in `load'
/18xx/routes/game.rb:98:in `block (6 levels) in <class:Api>'
/usr/local/bundle/gems/sequel-pg_advisory_lock-0.1.2/lib/sequel/extensions/pg_advisory_lock.rb:51:in `block in with_advisory_lock'
/usr/local/bundle/gems/sequel-5.55.0/lib/sequel/connection_pool/threaded.rb:92:in `hold'
/usr/local/bundle/gems/sequel-5.55.0/lib/sequel/database/connecting.rb:269:in `synchronize'
/usr/local/bundle/gems/sequel-pg_advisory_lock-0.1.2/lib/sequel/extensions/pg_advisory_lock.rb:48:in `with_advisory_lock'
/18xx/routes/game.rb:55:in `block (5 levels) in <class:Api>'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_optimized_matching.rb:140:in `block in _is1'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/request.rb:497:in `always'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_optimized_matching.rb:140:in `_is1'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_optimized_matching.rb:25:in `is'
/18xx/routes/game.rb:50:in `block (4 levels) in <class:Api>'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/request.rb:497:in `always'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_optimized_matching.rb:124:in `_verb'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/request.rb:243:in `post'
/18xx/routes/game.rb:18:in `block (3 levels) in <class:Api>'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_optimized_matching.rb:57:in `block in on'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/request.rb:497:in `always'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_optimized_matching.rb:57:in `on'
/18xx/routes/game.rb:7:in `block (2 levels) in <class:Api>'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/hash_routes.rb:438:in `block in hash_branches'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/request.rb:497:in `always'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/hash_routes.rb:438:in `hash_branches'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/hash_routes.rb:460:in `hash_routes'
/18xx/api.rb:99:in `block (2 levels) in <class:Api>'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/hash_routes.rb:438:in `block in hash_branches'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/request.rb:497:in `always'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/hash_routes.rb:438:in `hash_branches'
/18xx/api.rb:121:in `block in <class:Api>'
/usr/local/bundle/gems/roda-3.55.0/lib/roda.rb:518:in `_roda_run_main_route'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/_before_hook.rb:27:in `_roda_run_main_route'
/18xx/lib/instrumentation.rb:18:in `block in _roda_run_main_route'
/usr/local/bundle/gems/newrelic_rpm-8.6.0/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:377:in `perform_action_with_newrelic_trace'
/18xx/lib/instrumentation.rb:18:in `_roda_run_main_route'
/usr/local/bundle/gems/roda-3.55.0/lib/roda.rb:496:in `block in _roda_handle_main_route'
/usr/local/bundle/gems/roda-3.55.0/lib/roda.rb:494:in `catch'
/usr/local/bundle/gems/roda-3.55.0/lib/roda.rb:494:in `_roda_handle_main_route'
/usr/local/bundle/gems/roda-3.55.0/lib/roda/plugins/error_handler.rb:88:in `_roda_handle_main_route'
/usr/local/bundle/gems/roda-3.55.0/lib/roda.rb:380:in `block in base_rack_app_callable'
/usr/local/bundle/gems/message_bus-4.2.0/lib/message_bus/rack/middleware.rb:60:in `call'
/usr/local/bundle/gems/unicorn-6.1.0/lib/unicorn/http_server.rb:634:in `process_client'
/usr/local/bundle/gems/unicorn-worker-killer-0.4.5/lib/unicorn/worker_killer.rb:53:in `process_client'
/usr/local/bundle/gems/unicorn-worker-killer-0.4.5/lib/unicorn/worker_killer.rb:93:in `process_client'
/usr/local/bundle/gems/unicorn-6.1.0/lib/unicorn/http_server.rb:739:in `worker_loop'
/usr/local/bundle/gems/unicorn-6.1.0/lib/unicorn/http_server.rb:547:in `spawn_missing_workers'
/usr/local/bundle/gems/unicorn-6.1.0/lib/unicorn/http_server.rb:561:in `maintain_worker_count'
/usr/local/bundle/gems/unicorn-6.1.0/lib/unicorn/http_server.rb:294:in `join'
/usr/local/bundle/gems/unicorn-6.1.0/bin/unicorn:128:in `<top (required)>'
/usr/local/bundle/bin/unicorn:25:in `load'
/usr/local/bundle/bin/unicorn:25:in `<top (required)>'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/cli.rb:455:in `exec'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/vendor/thor/lib/thor/command.rb:28:in `run'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/vendor/thor/lib/thor.rb:527:in `dispatch'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/cli.rb:35:in `dispatch'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/vendor/thor/lib/thor/base.rb:584:in `start'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/cli.rb:29:in `start'
/usr/local/bundle/gems/bundler-2.5.13/exe/bundle:28:in `block in <top (required)>'
/usr/local/bundle/gems/bundler-2.5.13/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
/usr/local/bundle/gems/bundler-2.5.13/exe/bundle:20:in `<top (required)>'
/usr/local/bundle/bin/bundle:25:in `load'
/usr/local/bundle/bin/bundle:25:in `<main>'

[ollybh]

For future reference: I eventually worked out that I could reproduce this bug in my development environment by running the validate_all script for both 1858 and 1858 Switzerland. Games of 1858 loaded after a game of 1858 Switzerland were showing this error.

[ollybh]

@philcampeau It might be worth trying this script to see if your 1849 bug gets exposed this way.