Closed jryd closed 8 years ago
I've the same problem. I also noticed an increased walking speed. as you can see in the log above he makes roughly 10 Meter in 2 seconds. this should be ~ 18 km/h
I do have my walk_speed
set to 12 - which explains the speed the bot walks at. However it reaches a point and just does the above. If I restart the bot it woks fine for another ~30 minutes.
Confirmed here, After a while bot just wanders between stops and doesnt catch any pokemon at all.
Could it be because of the walking speed? I have noticed this in PoGo app also. If walking speed is high then app doesn't show any pokestops after a while and keeps refreshing.
I got same problem. Restart the process work again, but same problem happen again after the process keep running for 30 min.
Actually an error occurs before this issue presents; whereby there is an account log out. The automatic re-login appears to be incorrect causing reported issue.
2016-08-07 18:12:03,379 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop New York Yacht Club - 0.06km (attraction of lure 0.06km) Traceback (most recent call last): File "/usr/lib/python2.7/logging/__init__.py", line 859, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/__init__.py", line 732, in format return fmt.format(record) File "/usr/lib/python2.7/logging/__init__.py", line 471, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/__init__.py", line 335, in getMessage msg = msg % self.args TypeError: not all arguments converted during string formatting Logged from file __init__.py, line 547 2016-08-07 18:12:16,192 [PokemonGoBot] [INFO] [login_started] Login procedure started. 2016-08-07 18:12:18,421 [PokemonGoBot] [INFO] [login_successful] Login successful. 2016-08-07 18:12:20,043 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop New York Yacht Club - 0.05km (attraction of lure 0.05km) 2016-08-07 18:12:33,789 [CatchLuredPokemon] [INFO] [lured_pokemon_found] Lured pokemon at fort Literary Landmark (7f8ec0dba12f439ca7233aee3ec23148.16) 2016-08-07 18:12:39,566 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop New York Yacht Club - 0.04km (attraction of lure 0.04km) 2016-08-07 18:12:42,978 [CatchLuredPokemon] [INFO] [lured_pokemon_found] Lured pokemon at fort Literary Landmark (7f8ec0dba12f439ca7233aee3ec23148.16) 2016-08-07 18:12:49,303 [ SpinFort] [INFO] [pokestop_out_of_range] Pokestop New York Yacht Club out of range. 2016-08-07 18:12:49,304 [ SpinFort] [INFO] [pokestop_searching_too_often] Possibly searching too often, take a rest. 2016-08-07 18:12:49,385 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Harvard Club - 0.05km (attraction of lure
0.05km)`
I noticed that just before this keeps happening, there's a traceback pointing to __init__.py
line 547.
File "/usr/lib/python2.7/logging/__init__.py", line 328, in getMessage
msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file __init__.py, line 547
It seems like the deprecated logger call is not working correctly. If you look here, you will see that before re-logging in, the api object is reset. My thinking is that because of the exception, part of this code isn't able to run correctly and reset the session properly. I haven't run the code through a debugger to confirm this.
#self.logger.info("Session stale, re-logging in", 'yellow')
position = self.position
self.api = ApiWrapper()
self.position = position
self.login()
However, I have included a diff output below where I've replaced deprecated logger code with an event emit. Still waiting to confirm if this is a fix.
--- ../PokemonGo-Bot.orig/pokemongo_bot/__init__.py 2016-08-06 20:52:25.896366550 -0700
+++ pokemongo_bot/__init__.py 2016-08-07 01:22:26.240089388 -0700
@@ -544,7 +544,13 @@ class PokemonGoBot(object):
self.api._auth_provider._ticket_expire / 1000 - time.time()
if remaining_time < 60:
- self.logger.info("Session stale, re-logging in", 'yellow')
+ self.event_manager.emit(
+ 'session_stale',
+ sender=self,
+ level='info',
+ formatted='Session stale, re-logging in.'
+ )
+ #self.logger.info("Session stale, re-logging in", 'yellow')
position = self.position
self.api = ApiWrapper()
Spot the error (spelling)
bot.event_manager.emit( 'api_error', sender=bot, level='info', formmated='Log logged in, reconnecting in {:s}'.format(wait_time) )
I just saw the error now:
Traceback (most recent call last):
File "/usr/lib/python2.7/logging/__init__.py", line 859, in emit
msg = self.format(record)
File "/usr/lib/python2.7/logging/__init__.py", line 732, in format
return fmt.format(record)
File "/usr/lib/python2.7/logging/__init__.py", line 471, in format
record.message = record.getMessage()
File "/usr/lib/python2.7/logging/__init__.py", line 335, in getMessage
msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file __init__.py, line 547
I've done a fix for ^ above issue.. testing.. just the logging issue
Doing another test run now. Definitely fixed the exception that was being thrown. But I'm still waiting to confirm this fixes the "searching too often" issue.
I manually pulled your change and did not fix anything. However I agree the fix is still ok
Doesn't seem like fixing the logging exception actually prevents the main issue here... The only thing I can see if that api.activate_signature()
is called during a normal login, but not during check_session
.
I have added this to the end of check_session
:
self.login()
+ self.api.activate_signature("encrypt.so")
Seems like this function will set ApiRpc._signature_gen
, which in turn will cause the encrypted hashes to be regenerated on new RPC requests.
This is beyond my knowledge, so not yet sure if this will work, but it does make sense that some part of the requests is incorrect after the re-login, so this might do the trick.
Hard to tell if this helps... Getting conflicting results. Initially my log shows the same issue after a session reset:
2016-08-07 02:56:07,193 [PokemonGoBot] [INFO] [bot_start] Starting bot...
2016-08-07 02:56:08,185 [PokemonGoBot] [INFO] [api_error] Session stale, re-logging in.
2016-08-07 02:56:08,186 [PokemonGoBot] [INFO] [login_started] Login procedure started.
2016-08-07 02:56:09,616 [PokemonGoBot] [INFO] [login_successful] Login successful.
2016-08-07 02:56:10,014 [CollectLevelUpReward] [INFO] [level_up_reward] Received level up reward: []
2016-08-07 02:56:10,015 [IncubateEggs] [INFO] [next_egg_incubates] Next egg incubates in 0.70 km
2016-08-07 02:56:11,513 [ SpinFort] [INFO] [pokestop_searching_too_often] Possibly searching too often, take a rest.
2016-08-07 02:56:11,875 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Martin Pl Watertower - 0.08km (attraction of lure 0.08km)
2016-08-07 02:56:20,143 [PokemonGoBot] [INFO] [api_error] Session stale, re-logging in.
2016-08-07 02:56:20,143 [PokemonGoBot] [INFO] [login_started] Login procedure started.
2016-08-07 02:56:22,789 [PokemonGoBot] [INFO] [login_successful] Login successful.
2016-08-07 02:56:24,571 [ SpinFort] [INFO] [pokestop_searching_too_often] Possibly searching too often, take a rest.
2016-08-07 02:56:24,591 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Martin Pl Watertower - 0.07km (attraction of lure 0.07km)
Then later, it seems to fix itself NOTE this is after several session resets, as I forced it to happen regularly for debugging. Not happy to call it fixed yet, but will have to wait and see.
2016-08-07 02:58:01,321 [PokemonGoBot] [INFO] [api_error] Session stale, re-logging in.
2016-08-07 02:58:01,321 [PokemonGoBot] [INFO] [login_started] Login procedure started.
2016-08-07 02:58:02,815 [PokemonGoBot] [INFO] [login_successful] Login successful.
2016-08-07 02:58:03,551 [CatchLuredPokemon] [INFO] [lured_pokemon_found] Lured pokemon at fort Martin Pl Watertower (9a4e741d4cbf420e83ae3fcd2c6393ef.12)
2016-08-07 02:58:03,964 [PokemonCatchWorker] [INFO] [pokemon_appeared] A wild Pidgey appeared! [CP 183] [Potential 0.58] [S/A/D 3/10/13]
2016-08-07 02:58:06,939 [PokemonCatchWorker] [INFO] [threw_pokeball] Used Pokeball, with chance 45.14 (16 left)
2016-08-07 02:58:07,880 [PokemonCatchWorker] [INFO] [pokemon_caught] Captured Pidgey! [CP 183] [Potential 0.58] [3/10/13] [+210 exp]
2016-08-07 02:58:13,423 [ SpinFort] [INFO] [spun_pokestop] Spun pokestop Martin Pl Watertower. Experience awarded: 50. Items awarded: {u'Razz Berry': 1, u'Pokeball': 1, u'Revive': 1}
2016-08-07 02:58:16,151 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Twisted Yellow Sculpture - 0.05km (attraction of lure 0.05km)
Guess it could not be the walking speed that caused this, because even though I set speed to 6 and the problem still appears.
Looks to me like adding activate_signature
does fix the issue. Can someone else verify/confirm? See log output:
2016-08-07 03:27:50,978 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Martin Pl Watertower - 0.09km (attraction of lure 0.09km)
2016-08-07 03:27:59,521 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Martin Pl Watertower - 0.09km (attraction of lure 0.09km)
***
2016-08-07 03:28:07,364 [PokemonGoBot] [INFO] [api_error] Session stale, re-logging in.
***
2016-08-07 03:28:07,364 [PokemonGoBot] [INFO] [login_started] Login procedure started.
2016-08-07 03:28:09,044 [PokemonGoBot] [INFO] [login_successful] Login successful.
2016-08-07 03:28:09,831 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Martin Pl Watertower - 0.08km (attraction of lure 0.08km)
2016-08-07 03:28:18,026 [CatchLuredPokemon] [INFO] [lured_pokemon_found] Lured pokemon at fort Twisted Yellow Sculpture (38e2366011de46909c7dc39a41db6f40.16)
2016-08-07 03:28:18,462 [PokemonCatchWorker] [INFO] [pokemon_appeared] A wild Pidgey appeared! [CP 201] [Potential 0.27] [S/A/D 3/3/6]
2016-08-07 03:28:21,136 [PokemonCatchWorker] [INFO] [threw_pokeball] Used Pokeball, with chance 41.52 (18 left)
2016-08-07 03:28:21,916 [PokemonCatchWorker] [INFO] [pokemon_caught] Captured Pidgey! [CP 201] [Potential 0.27] [3/3/6] [+210 exp]
2016-08-07 03:28:26,934 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Twisted Yellow Sculpture - 0.04km (attraction of lure 0.04km)
2016-08-07 03:28:35,979 [TransferPokemon] [INFO] [future_pokemon_release] Releasing Pidgey (CP 201/IV 0.27) based on rule: CP < 237 AND IV < 0.8
2016-08-07 03:28:36,453 [TransferPokemon] [INFO] [pokemon_release] Exchanged Pidgey [CP 201] [IV 0.27] for candy.
***
2016-08-07 03:28:41,051 [ SpinFort] [INFO] [spun_pokestop] Spun pokestop Twisted Yellow Sculpture. Experience awarded: 50. Items awarded: {u'Razz Berry': 1, u'Pokeball': 1, u'Revive': 1}
***
2016-08-07 03:28:43,440 [MoveToFort] [INFO] [moving_to_lured_fort] Moving towards pokestop Martin Pl Watertower - 0.07km (attraction of lure 0.07km)
speed is walk right?
What do you mean with adding activate_signature ?
activate_signature is a reference to the loading of 'encrypt.so'
I agree after I fixed all of the logging issues it appear the stale session state does not re-initalise correctly (position I'm guessing) hence always considered to far from pokespot. In otherwords the walker and API are de-sync'd. Perhaps we need to set the position again after stale state.
@geek-man I'm testing change.
See the commit to my branch (https://github.com/geek-man/PokemonGo-Bot/commit/cb5491593ffe30a028629b9261b545abf4d1a8fc).
I added a call to self.api.activate_signature()
. By doing this, you will see in there self._signature_gen = True
. If you look around in the same file (rpc_api.py), you will see what when an RPC request is made, if signature_gen = True
then the signature hashes for the RPC request is regenerated during that request.
Yes, encryption.so is reloaded (but this is not important). The important bit is that signature_gen is changed back to True.
I think this is correct because:
activate_signature
needs to be executed after a login (which is already happening). And all we are doing during check_session
is essentially logging out and logging back in.Seems to be working for me.
Thanks, adding that line to init.py solved it for me it seems.
I'm going to issue a pull request for this. I feel pretty good about the fix. I just hit my 2nd consecutive 30-minute block and both times I successfully did a re-login and was able to spin fort and catch pokemon.
Works fine after the 30min disconnects.
Works here, too.
I've been running smoothly and continuously for hours so far, thanks for your great help! @geek-man 💯
what do i have to do to fix this im not good at coding and need a guide
My pokemon bag is full and I am getting this. Is transferpokemon working?
Please help me what do I need to do? just add that one line to init.py?
@krishven it doesn't fix it anyway
Line 547 to 559
self.event_manager.emit(
'api_error',
sender=self,
level='info',
formatted='Session stale, re-logging in.'
)
position = self.position
self.api = ApiWrapper()
self.position = position
self.login()
self.api.activate_signature("encrypt.so")
@staticmethod
Still seeing this every 30 mins or so, then nothing gets caught and I need to restart
Python: Traceback (most recent call last):
File "/usr/local/Cellar/python/2.7.12/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/__init__.py", line 861, in emit
Python: msg = self.format(record)
File "/usr/local/Cellar/python/2.7.12/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/__init__.py", line 734, in format
return fmt.format(record)
File "/usr/local/Cellar/python/2.7.12/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/__init__.py", line 465, in format
Python: record.message = record.getMessage()
File "/usr/local/Cellar/python/2.7.12/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/__init__.py", line 329, in getMessage
msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file __init__.py, line 547
I confirm this works: before @geek-man's fix, I had the issue, now I don't anymore. Many thanks!
Expected Behavior
Bot locates a fort, walks to it and collects loot along with any nearby pokemon.
Actual Behavior
Bot begins walking to fort and then emits
Possibly searching too often, take a rest.
and then picks a new fort to walk to.It then does this over and over again, see dump below:
Steps to Reproduce
Run bot as normal, after about 30 minutes this starts to happen for me.
Other Information
OS: Debian 8 Git Commit: c81666d751b9ca8cd338760fdf920194fabf4ee4 Python Version: Python 2.7.9