Merge pull request #25 from jonatan1609/log

Add: add logs and better error handling

bot/__init__.py

@@ -5,14 +5,19 @@
 from pyrogram.session import Session
 from dynaconf import Dynaconf
 from os import environ
+from loguru import logger
 from .cache import Cache
 
 
 __version__ = "1.0.8"
 Session.notice_displayed = True
 futures = {}
+logger.info(f'Loading config file from '
+            f'{environ.get("CONFIG_FILE", "config.toml")!r}')
 config = Dynaconf(settings_files=[environ.get("CONFIG_FILE", "config.toml")])
+logger.info("Loading strings file from 'strings.toml'")
 strings = Dynaconf(settings_files=["strings.toml"])
+logger.info("Initializing Pyrogram client")
 client = Client(**config.pyrogram)
 cache = Cache(
     60 * 60 * 24,
@@ -28,8 +33,10 @@ def remove_future(future, key=None, ban_func: callable = None):
         del futures[key]
     client.loop.create_task(client.delete_messages(key[0], key[-1]))
     if (future.done() and not future.result()) or not future.done():
+        logger.info(f"Banning user {key[1]}")
         client.loop.create_task(ban_func())
     elif future.done() and future.result():
+        logger.info(f"Removing restriction for user {key[1]}")
         client.loop.create_task(
             client.restrict_chat_member(
                 key[0],

bot/__main__.py

@@ -1,11 +1,8 @@
 from . import __version__, client
 from .set_bot_commands import main
+from loguru import logger
 
-print(
-    '\u001b[38;5;208m\033[1m'
-    'GroupManagerBot is running.. version {}'
-    '\033[0m'.format(__version__)
-)
+logger.info('GroupManagerBot is running.. version {}'.format(__version__))
 
 client.loop.run_until_complete(main())
 client.run()

bot/cache.py

@@ -1,5 +1,7 @@
 from asyncio import get_running_loop, get_event_loop
 from functools import partial
+from loguru import logger
+from .utils import shorten
 
 
 class Cache(dict):
@@ -18,7 +20,11 @@ def insert(self, key, value, ttl: int = -1):
             ttl = self.default_time
 
         self[key] = value
+        logger.info(f"Key - {shorten(key)!r}, "
+                    f"Value - {shorten(value)!r} "
+                    f"was inserted to cache for {ttl} seconds")
         self.loop.call_later(ttl, partial(self.delete, key))
 
     def delete(self, key):
         del self[key]
+        logger.info(f"Key - {shorten(key)!r} was deleted from cache")

bot/handlers/ChangeLanguage.py

@@ -4,21 +4,26 @@
 from ..database import Group, User
 from .. import strings, config
 from .start import keyboard
+from loguru import logger
 
 
 @Client.on_callback_query(change_language_callback)
 async def change_language_callback(_: Client, callback: types.CallbackQuery):
     language, _, group = callback.data.split("=")[1].partition(';')
     with db_session:
         if callback.data[4] == "s":
-            group = Group.get(id=int(group))
-            if group and group.default_language != language:
-                group.default_language = language
+            db_group = Group.get(id=int(group))
+            if db_group and db_group.default_language != language:
+                db_group.default_language = language
+            elif not db_group:
+                logger.debug(f"Group {group} not found")
             await callback.answer(getattr(strings, language).language_has_been_changed)
             await callback.message.edit_text(getattr(strings, language).welcome_to_panel)
         else:
             user = User.get(id=callback.from_user.id)
             if not user:
+                logger.debug(f"User {callback.from_user.id} not found,"
+                             f" adding to database")
                 user = User(
                     id=callback.from_user.id,
                     first_name=callback.from_user.first_name,

bot/handlers/VerifyButtons.py

@@ -3,6 +3,7 @@
 from .. import futures, strings
 from ..database import Group
 from pony.orm import db_session
+from loguru import logger
 
 
 @Client.on_callback_query(human)
@@ -15,7 +16,9 @@ async def i_am_a_human(_: Client, callback: types.CallbackQuery):
         )
     )
     with db_session:
-        group = Group[callback.message.chat.id]
+        group = Group.get(id=callback.message.chat.id)
+        if not group:
+            logger.error(f"Group {callback.message.chat.id} not found!")
     if future:
         future.set_result(True)
     else:
@@ -34,7 +37,9 @@ async def i_am_a_bot(_: Client, callback: types.CallbackQuery):
         )
     )
     with db_session:
-        group = Group[callback.message.chat.id]
+        group = Group.get(id=callback.message.chat.id)
+        if not group:
+            logger.error(f"Group {callback.message.chat.id} not found!")
     if future:
         future.set_result(False)
     else:

bot/handlers/configBotInPM.py

@@ -4,6 +4,7 @@
 from ..database import Group
 from pyrogram import Client, types
 from pony.orm import db_session
+from loguru import logger
 
 
 def split(array: list, group: int) -> list:
@@ -18,9 +19,12 @@ def split(array: list, group: int) -> list:
 async def start_config(client: Client, message: types.Message):
     group = int(message.command[-1])
     with db_session:
-        group_db_obj = Group[group]
-        allowed_admin = message.from_user.id in [x.id for x in (*group_db_obj.administrators, group_db_obj.owner)]
-    if allowed_admin:
+        group_db_obj = Group.get(id=group)
+        if not group_db_obj:
+            logger.error(f"Group {group} is not in database")
+            return  # todo: tell the user to re-add the bot to his group
+        is_allowed_admin = message.from_user.id in [x.id for x in (*group_db_obj.administrators, group_db_obj.owner)]
+    if is_allowed_admin:
         await client.send_message(
             message.chat.id,
             strings.choose_language.format(message.from_user.first_name),

bot/handlers/deleteServiceMessages.py

@@ -1,7 +1,12 @@
-from pyrogram import Client
+from pyrogram import Client, errors
+from loguru import logger
 from ..filters import service
 
 
 @Client.on_message(service)
 async def delete_service_messages(_, message):
-    await message.delete()
+    try:
+        logger.info("Deleting a service message")
+        await message.delete()
+    except errors.RPCError:
+        logger.error("Could not delete message")

bot/handlers/memberJoined.py

@@ -6,17 +6,19 @@
 from pony.orm import db_session
 from ..database import Group, User
 from ..utils import fetch_admins, is_member
+from loguru import logger
 
 
 @Client.on_chat_member_updated(group)
 async def member_has_joined(client: Client, member: types.ChatMemberUpdated):
-
     if is_member(member):
         if member.new_chat_member.user.is_self:
             with db_session:
                 creator, administrators = await fetch_admins(client, member.chat.id)
                 user = User.get(id=creator[0])
                 if not user:
+                    logger.debug(f"User {creator[0]} not found,"
+                                 f" adding to database")
                     user = User(
                         id=creator[0] or -1,
                         first_name=creator[1] or "Deleted account",
@@ -27,6 +29,8 @@ async def member_has_joined(client: Client, member: types.ChatMemberUpdated):
                         User.get(id=x[0]) or User(id=x[0], first_name=x[1] or "Deleted Account", last_name=x[2] or "")
                         for x in administrators
                     ]
+                    logger.debug(f"Group {member.chat.id} not found,"
+                                 f" adding to database")
                     Group(
                         id=member.chat.id,
                         owner=user,
@@ -42,12 +46,16 @@ async def member_has_joined(client: Client, member: types.ChatMemberUpdated):
                     )]
                 ])
             )
+        with db_session:
+            group = Group.get(id=member.chat.id)
+            if not group:
+                logger.error(f"Group {member.chat.id} is not in database")
+                return  # todo: tell the user to re-add the bot to his group
+        logger.info(f"Restricting user {member.new_chat_member.user.id}")
         await member.chat.restrict_member(
             member.new_chat_member.user.id,
             banned_permissions
         )
-        with db_session:
-            group = Group[member.chat.id]
         if message := await client.send_message(
             member.chat.id, getattr(
                     strings, group.default_language

bot/handlers/refresh_admins_list.py

@@ -8,6 +8,7 @@
     select_group__show_admins,
     refresh_admins_list
 )
+from loguru import logger
 
 
 def split(array: list, prefix: str):
@@ -27,19 +28,26 @@ async def show_admins_list(client: Client, message: types.Message):
     groups = []
     with db_session:
         user = User.get(id=message.from_user.id)
-        if user:
-            groups.extend([
-                group.id for group in (
-                        [group for group in user.admin_in_groups] +
-                        [group for group in user.owning_groups]
-                )
-            ])
+        if not user:
+            logger.debug(f"User {message.from_user.id} not found,"
+                         f" adding to database")
+            return await message.reply(
+                getattr(strings, user.language).no_groups
+            )
+        groups.extend([
+            group.id for group in (
+                    [group for group in user.admin_in_groups] +
+                    [group for group in user.owning_groups]
+            )
+        ])
         for group in groups:
             if group not in cache["names"]:
+                logger.info(f"fetching group name for {group}")
                 cache["names"].insert(
                     group, await fetch_group_name(client, group)
                 )
             if group not in cache["admins"]:
+                logger.info(f"Fetching admins list for {group}")
                 cache["admins"].insert(group, await fetch_admins(client, group))
         if groups:
             await message.reply(
@@ -57,10 +65,14 @@ async def show_admins(client: Client, callback: types.CallbackQuery):
     _, _, group = callback.data.partition("=")
     group = int(group)
     if group not in cache["admins"]:
+        logger.info(f"Fetching admins list for {group}")
         cache["admins"].insert(group, await fetch_admins(client, group))
     creator, admins = cache["admins"][group]
     with db_session:
-        user = User[callback.from_user.id]
+        user = User.get(id=callback.from_user.id)
+        if not user:
+            return logger.debug(f"User {callback.from_user.id} not found,"
+                                f" adding to database")
     admins = format_admins(
         creator=creator,
         admins=admins,
@@ -84,6 +96,7 @@ async def show_admins(client: Client, callback: types.CallbackQuery):
 async def refresh_admins_list(client: Client, callback: types.CallbackQuery):
     _, _, group = callback.data.partition('=')
     group = int(group)
+    logger.info(f"Fetching admins list for {group}")
     cache["admins"].insert(group, await fetch_admins(client, group))
     try:
         await show_admins(client, callback)

bot/handlers/start.py

@@ -5,6 +5,8 @@
 from .configBotInPM import split
 from pony.orm import db_session
 from pyrogram import Client, types
+from loguru import logger
+
 
 keyboard = types.InlineKeyboardMarkup(split(LanguagesEnum.map(), -1))
 
@@ -13,6 +15,8 @@
 async def start(_: Client, message: types.Message):
     with db_session:
         if not User.get(id=message.from_user.id):
+            logger.debug(f"User {message.from_user.id} not found,"
+                         f" adding to database")
             User(
                 id=message.from_user.id,
                 first_name=message.from_user.first_name,

bot/set_bot_commands.py

@@ -1,5 +1,6 @@
 from . import client, strings
 from pyrogram import types
+from loguru import logger
 
 
 async def main():
@@ -10,9 +11,13 @@ async def main():
         ] for language in ("Hebrew", "English")
     }
     async with client:
+        languages = commands.keys()
         for language, commands in commands.items():
             await client.set_bot_commands(
                 commands,
                 scope=types.BotCommandScopeAllPrivateChats(),
                 language_code=language[:2].lower()
             )
+    logger.info("Bot commands have been set successfully ({})".format(
+        ", ".join(languages)
+    ))

bot/utils.py

@@ -53,3 +53,11 @@ def is_member(update: ChatMemberUpdated) -> bool:
         if update.new_chat_member.status in {"restricted", "member"}:
             new = True
     return new
+
+
+def shorten(obj) -> str:
+    as_str = str(obj)
+    if len(as_str) > 10:
+        as_str = as_str[:5] + " ... " + as_str[-2:]
+
+    return as_str

requirements.txt

@@ -4,6 +4,7 @@ dynaconf==3.1.7
 Flask==2.0.1
 itsdangerous==2.0.1
 Jinja2==3.0.1
+loguru==0.5.3
 MarkupSafe==2.0.1
 peewee==3.14.4
 pony==0.7.14