search

errbotio / errbot

Errbot is a chatbot, a daemon that connects to your favorite chat service and bring your tools and some fun into the conversation.
http://errbot.io
GNU General Public License v3.0
3.14k stars 615 forks source link

Store getting corrupted after !shutdown #1125

Closed nicoddemus closed 5 years ago

nicoddemus commented 7 years ago

Hi,

First of all thanks for the excellent work on this bot, I'm loving its intuitive interface and ease of use! 😁

I'm writing because I'm having a problem: the store gets corrupted after shutdown.

I'm using this unofficial backed for RocketChat: https://github.com/cardoso/errbot-rocketchat

Seems similar to #44, but I looked over at the code for the backend and it appears to be calling shutdown at the appropriate place, but when sending !shutdown --confirm to the bot self.shutdown() apparently is not called, based on the logs.

Here are the relevant logs for the !shutdown command:

15:41:18 DEBUG    aoikrocketchaterrbot      # ----- Call `callback_message` -----
15:41:18 DEBUG    errbot.core               *** frm = bruno
15:41:18 DEBUG    errbot.core               *** username = bruno
15:41:18 DEBUG    errbot.core               *** text = !shutdown --confirm
15:41:18 DEBUG    errbot.plugins.ACLs       Check shutdown for ACLs.
15:41:18 INFO     errbot.plugins.ACLs       Matching ACL {} against username bruno for command Health:shutdown
15:41:18 INFO     errbot.plugins.ACLs       Check if shutdown is admin only command.
15:41:18 INFO     errbot.core               Processing command 'shutdown' with parameters '--confirm' from bruno
15:41:18 DEBUG    errbot.flow               Test if the command shutdown is a trigger for an inflight flow ...
15:41:18 DEBUG    errbot.flow               None matched.

I would expect to see this log message if self.shutdown() was called appropriately:

self._log_debug('# ===== serve_forever =====')

After this, when I try to open errbot again I get this error:

λ python -m errbot.cli
Starting errbot with a default system encoding other than 'utf-8' might cause you a heap of troubles. Your current encoding is set at 'cp1252'
15:41:22 INFO     errbot.specific_plugin_ma storage search paths {'C:\\Users\\bruno\\errbot-esss\\.env35\\lib\\site-packages\\errbot\\storage'}
15:41:22 INFO     errbot.specific_plugin_ma Found those plugings available:
15:41:22 INFO     errbot.specific_plugin_ma         Memory  (C:\Users\bruno\errbot-esss\.env35\lib\site-packages\errbot\storage\memory.py)
15:41:22 INFO     errbot.specific_plugin_ma          Shelf  (C:\Users\bruno\errbot-esss\.env35\lib\site-packages\errbot\storage\shelf.py)
15:41:22 INFO     errbot.bootstrap          Found Storage plugin: 'Shelf'
Description: This is the storage plugin for the traditional shelf store for errbot.
15:41:22 DEBUG    errbot.specific_plugin_ma Refilter the plugins...
15:41:22 WARNING  yapsy                     Plugin candidate 'C:\Users\bruno\errbot-esss\.env35\lib\site-packages\errbot\storage\memory.plug'  rejected by strategy 'SpecificBackendLocator'
15:41:22 DEBUG    errbot.specific_plugin_ma Load the one remaining...
15:41:22 DEBUG    errbot.specific_plugin_ma Class to load ShelfStoragePlugin
15:41:22 DEBUG    errbot.storage            Opening storage 'repomgr'
15:41:22 DEBUG    errbot.storage.shelf      Open shelf storage ./bot_data\repomgr.db
15:41:22 DEBUG    errbot.storage            Opening storage 'core'
15:41:22 DEBUG    errbot.storage.shelf      Open shelf storage ./bot_data\core.db

I'm using errbot 5.1.3 and Python 3.5.

Any hints or suggestions on how I can fix this problem? Thanks!

nicoddemus commented 7 years ago

Actually I just noticed the exact same problem happens in plain errbot when in text mode, without any additional back-end installed.

To reproduce:

> py -3.6 -m venv .env36
...
> .env36\scripts\activate 
> pip install errbot
> errbot -T

While in chat, configure the Webserver plugin:

!plugin config Webserver 
{'HOST': '0.0.0.0',
 'PORT': 3141,
 'SSL': {'certificate': '',
         'enabled': False,
         'host': '127.0.0.1',
         'key': '',
         'port': 3142}}

And then quit:

> !shutdown --confirm

When opening the bot again it raises the same error.

I didn't mention but I'm on Windows, perhaps it is related to that?

zoni commented 7 years ago

I have a suspicion that this is Windows-specific, but I do think there's a more general problem going on with persistence. Unfortunately, the shelve module (used by the default persistence method) is a somewhat opaque abstraction on top of a family of DBM libraries (most notably gdbm and berkdb) and I further suspect this affects one but not the other.

nicoddemus commented 7 years ago

@zoni thanks for the response. If you cannot reproduce this on Linux then definitely seems to be Windows specific, in which case it might not be a big deal because in general the bot is deployed in Linux, with Windows being used just for development/playing around.

sijis commented 5 years ago

Unable to reproduce with the latest version of errbot (6.1.0)

[@sijis ➡ @errbot] >>> !plugin config Webserver {'HOST': '0.0.0.0', 'PORT': 3141, 'SSL': {'certificate': '', 'enabled': False, 'host': '127.0.0.1', 'key': '', 'port': 3142}}
Plugin configuration done.

[@sijis ➡ @errbot] >>> !shutdown --confirm
Roger that. I am shutting down.
$ errbot
23:13:55 INFO     errbot.bootstrap          Found Storage plugin: Shelf.
23:13:55 INFO     errbot.bootstrap          Found Backend plugin: Text
23:13:55 INFO     errbot                    webhooks:  Flag to bind /echo to echo
23:13:55 INFO     errbot                    webhooks:  Flag to bind /testWeb to testWeb
────────────────────────────────────────────────────────────────────────────────
 You start as a bot admin in a one-on-one conversation with the bot.

    Context of the chat

• Use !inroom to switch to a room conversation.
• Use !inperson to switch back to a one-on-one conversation.
• Use !asuser to talk as a normal user.
• Use !asadmin to switch back as a bot admin.

    Preferences

• Use !ml to flip on/off the multiline mode (Enter twice at the end to send).
────────────────────────────────────────────────────────────────────────────────

[@sijis ➡ @errbot] >>>

The logs are clean too

2019-06-19 23:13:38,714 INFO     errbot.core               Processing command "plugin_config" with parameters "Webserver {'HOST': '0.0.0.0', 'PORT': 3141, 'SSL': {'certificate': '', 'enabled': False, 'host': '127.0.0.1', 'key': '', 'port': 3142}}" from @sijis
2019-06-19 23:13:38,779 INFO     errbot.plugins.Webserver  Shutting down the internal webserver.
2019-06-19 23:13:39,067 INFO     errbot.plugins.Webserver  Waiting for the webserver thread to quit.
2019-06-19 23:13:39,068 INFO     errbot.plugins.Webserver  Webserver shut down correctly.
2019-06-19 23:13:39,071 INFO     errbot.plugins.Webserver  Starting the webserver on 0.0.0.0:3141
2019-06-19 23:13:39,074 INFO     errbot.core_plugins.wsview Checking Webserver for webhooks
2019-06-19 23:13:39,075 INFO     errbot.core_plugins.wsview Webhook routing echo
2019-06-19 23:13:51,979 INFO     errbot.plugins.ACLs       Matching ACL {} against username @sijis for command Health:shutdown.
2019-06-19 23:13:51,979 INFO     errbot.plugins.ACLs       Check if shutdown is admin only command.
2019-06-19 23:13:51,979 INFO     errbot.core               Processing command "shutdown" with parameters "--confirm" from @sijis
2019-06-19 23:13:52,032 INFO     errbot.core               Disconnect callback, deactivating all the plugins.
2019-06-19 23:13:52,068 INFO     errbot.plugins.Webserver  Shutting down the internal webserver.
2019-06-19 23:13:52,113 INFO     errbot.plugins.Webserver  Waiting for the webserver thread to quit.
2019-06-19 23:13:52,114 INFO     errbot.plugins.Webserver  Webserver shut down correctly.
2019-06-19 23:13:52,125 INFO     errbot.plugin_manager     Shutdown.
2019-06-19 23:13:52,126 INFO     errbot.plugin_manager     Bye.
2019-06-19 23:13:52,127 INFO     errbot.cli                Process exiting
2019-06-19 23:13:55,412 INFO     errbot.bootstrap          Found Storage plugin: Shelf.
2019-06-19 23:13:55,415 INFO     errbot.bootstrap          Found Backend plugin: Text
2019-06-19 23:13:55,553 INFO     errbot                    webhooks:  Flag to bind /echo to echo
2019-06-19 23:13:55,589 INFO     errbot                    webhooks:  Flag to bind /testWeb to testWeb
2019-06-19 23:13:55,590 INFO     errbot.core               Activate internal commands
2019-06-19 23:13:55,590 INFO     errbot.plugin_manager     Activate bot plugins...
2019-06-19 23:13:55,590 INFO     errbot.plugin_manager     Activate plugin: CommandNotFoundFilter.
2019-06-19 23:13:55,591 INFO     errbot.core_plugins.wsview Checking CommandNotFoundFilter for webhooks
2019-06-19 23:13:55,591 INFO     errbot.plugin_manager     Activate plugin: Help.
2019-06-19 23:13:55,591 INFO     errbot.core_plugins.wsview Checking Help for webhooks
2019-06-19 23:13:55,591 INFO     errbot.plugin_manager     Activate plugin: Plugins.
2019-06-19 23:13:55,592 INFO     errbot.core_plugins.wsview Checking Plugins for webhooks
2019-06-19 23:13:55,592 INFO     errbot.plugin_manager     Activate plugin: Health.
2019-06-19 23:13:55,593 INFO     errbot.core_plugins.wsview Checking Health for webhooks
2019-06-19 23:13:55,593 INFO     errbot.plugin_manager     Activate plugin: Webserver.
2019-06-19 23:13:55,593 INFO     errbot.plugins.Webserver  Starting the webserver on 0.0.0.0:3141
2019-06-19 23:13:55,593 INFO     errbot.core_plugins.wsview Checking Webserver for webhooks
2019-06-19 23:13:55,594 INFO     errbot.core_plugins.wsview Webhook routing echo
2019-06-19 23:13:55,594 INFO     errbot.plugin_manager     Activate plugin: Backup.
2019-06-19 23:13:55,594 INFO     errbot.core_plugins.wsview Checking Backup for webhooks
2019-06-19 23:13:55,594 INFO     errbot.plugin_manager     Activate plugin: ACLs.
2019-06-19 23:13:55,595 INFO     errbot.core_plugins.wsview Checking ACLS for webhooks
2019-06-19 23:13:55,595 INFO     errbot.plugin_manager     Activate plugin: Flows.
2019-06-19 23:13:55,596 INFO     errbot.core_plugins.wsview Checking Flows for webhooks
2019-06-19 23:13:55,596 INFO     errbot.plugin_manager     Activate plugin: VersionChecker.
2019-06-19 23:13:55,596 INFO     errbot.plugins.VersionChecker Skip version checking under text mode.
2019-06-19 23:13:55,596 INFO     errbot.core_plugins.wsview Checking VersionChecker for webhooks
2019-06-19 23:13:55,597 INFO     errbot.plugin_manager     Activate plugin: ChatRoom.
2019-06-19 23:13:55,597 INFO     errbot.core_plugins.wsview Checking ChatRoom for webhooks
2019-06-19 23:13:55,598 INFO     errbot.plugins.ChatRoom   Callback_connect
2019-06-19 23:13:55,598 INFO     errbot.plugin_manager     Activate plugin: Utils.
2019-06-19 23:13:55,598 INFO     errbot.core_plugins.wsview Checking Utils for webhooks
2019-06-19 23:13:55,598 INFO     errbot.plugin_manager     Activate plugin: TextCmds.
2019-06-19 23:13:55,599 INFO     errbot.core_plugins.wsview Checking TextModeCmds for webhooks
2019-06-19 23:13:55,599 INFO     errbot.plugin_manager     Activate plugin: HelloWorld.
2019-06-19 23:13:55,599 INFO     errbot.core_plugins.wsview Checking HelloWorld for webhooks
2019-06-19 23:13:55,600 INFO     errbot.plugin_manager     Activate plugin: Example.
2019-06-19 23:13:55,600 INFO     errbot.core_plugins.wsview Checking Example for webhooks
2019-06-19 23:13:55,600 INFO     errbot.core_plugins.wsview Webhook routing testWeb
2019-06-19 23:13:55,600 INFO     errbot.core               
2019-06-19 23:13:55,600 INFO     errbot.core               Notifying connection to all the plugins...
2019-06-19 23:13:55,601 INFO     errbot.plugins.ChatRoom   Callback_connect
2019-06-19 23:13:55,601 INFO     errbot.core               Plugin activation done.
2019-06-19 23:19:15,773 INFO     errbot.core               Disconnect callback, deactivating all the plugins.
2019-06-19 23:19:15,780 INFO     errbot.plugins.Webserver  Shutting down the internal webserver.
2019-06-19 23:19:15,995 INFO     errbot.plugins.Webserver  Waiting for the webserver thread to quit.
2019-06-19 23:19:15,996 INFO     errbot.plugins.Webserver  Webserver shut down correctly.
2019-06-19 23:19:16,009 INFO     errbot.plugin_manager     Shutdown.
2019-06-19 23:19:16,009 INFO     errbot.plugin_manager     Bye.
2019-06-19 23:19:16,010 INFO     errbot.cli                Process exiting