Add full log config. Fixes #166

.gitignore

@@ -7,6 +7,7 @@ __pycache__
 
 config.yaml
 registration.yaml
+logs/
 *.db
 *.session
 *.json

example-config.yaml

@@ -34,9 +34,6 @@ appservice:
         # implicitly.
         external: https://example.com/public
 
-    # Whether or not to enable debug messages in the console.
-    debug: true
-
     # The unique ID of this appservice.
     id: telegram
     # Username of the appservice bot.
@@ -194,3 +191,31 @@ telegram:
     api_hash: tjyd5yge35lbodk1xwzw2jstp90k55qz
     # (Optional) Create your own bot at https://t.me/BotFather
     bot_token: disabled
+
+# Python logging configuration.
+#
+# See section 16.7.2 of the Python documentation for more info:
+# https://docs.python.org/3.6/library/logging.config.html#configuration-dictionary-schema
+logging:
+    version: 1
+    formatters:
+        precise:
+            format: "[%(asctime)s] [%(levelname)s@%(name)s] %(message)s"
+    handlers:
+        file:
+            class: logging.handlers.RotatingFileHandler
+            formatter: precise
+            filename: ./mautrix-telegram.log
+            maxBytes: 10485760
+            backupCount: 10
+        console:
+            class: logging.StreamHandler
+            formatter: precise
+    loggers:
+        mau:
+            level: DEBUG
+        telethon:
+            level: DEBUG
+    root:
+        level: DEBUG
+        handlers: [file, console]

mautrix_telegram/__main__.py

@@ -17,6 +17,7 @@
 import argparse
 import sys
 import logging
+import logging.config
 import asyncio
 
 import sqlalchemy as sql
@@ -29,6 +30,7 @@ from .base import Base
 from .config import Config
 from .matrix import MatrixHandler
 
+from . import __version__
 from .db import init as init_db
 from .abstract_user import init as init_abstract_user
 from .user import init as init_user, User
@@ -39,12 +41,6 @@ from .formatter import init as init_formatter
 from .public import PublicBridgeWebsite
 from .context import Context
 
-log = logging.getLogger("mau")
-time_formatter = logging.Formatter("[%(asctime)s] [%(levelname)s@%(name)s] %(message)s")
-handler = logging.StreamHandler()
-handler.setFormatter(time_formatter)
-log.addHandler(handler)
-
 parser = argparse.ArgumentParser(
     description="A Matrix-Telegram puppeting bridge.",
     prog="python -m mautrix-telegram")
@@ -69,14 +65,11 @@ if args.generate_registration:
     print(f"Registration generated and saved to {config.registration_path}")
     sys.exit(0)
 
-if config["appservice.debug"]:
+logging.config.dictConfig(config["logging"])
-    telethon_log = logging.getLogger("telethon")
+log = logging.getLogger("mau.init")
-    telethon_log.addHandler(handler)
+log.debug(f"Initializing mautrix-telegram {__version__}")
-    telethon_log.setLevel(logging.DEBUG)
-    log.setLevel(logging.DEBUG)
-    log.debug("Debug messages enabled.")
 
-db_engine = sql.create_engine(config.get("appservice.database", "sqlite:///mautrix-telegram.db"))
+db_engine = sql.create_engine(config["appservice.database"] or "sqlite:///mautrix-telegram.db")
 db_factory = orm.sessionmaker(bind=db_engine)
 db_session = orm.scoping.scoped_session(db_factory)
 Base.metadata.bind = db_engine
@@ -112,9 +105,13 @@ with appserv.run(config["appservice.hostname"], config["appservice.port"]) as st
         startup_actions.append(context.bot.start())
 
     try:
+        log.debug("Initialization complete, running startup actions")
         loop.run_until_complete(asyncio.gather(*startup_actions, loop=loop))
+        log.debug("Startup actions complete, now running forever")
         loop.run_forever()
     except KeyboardInterrupt:
-        for user in User.by_tgid.values():
+        log.debug("Keyboard interrupt received, stopping clients")
-            user.stop()
+        loop.run_until_complete(
+            asyncio.gather(*[user.stop() for user in User.by_tgid.values()], loop=loop))
+        log.debug("Clients stopped, shutting down")
         sys.exit(0)

mautrix_telegram/abstract_user.py

@@ -118,8 +118,8 @@ class AbstractUser:
             await self.start(delete_unless_authenticated=not even_if_no_session)
         return self
 
-    def stop(self):
+    async def stop(self):
-        self.client.disconnect()
+        await self.client.disconnect()
         self.client = None
 
     # region Telegram update handling

mautrix_telegram/config.py

@@ -154,8 +154,6 @@ class Config(DictWithRecursion):
         copy("appservice.public.prefix")
         copy("appservice.public.external")
 
-        copy("appservice.debug")
-
         copy("appservice.id")
         copy("appservice.bot_username")
         copy("appservice.bot_displayname")
@@ -218,6 +216,14 @@ class Config(DictWithRecursion):
         copy("telegram.api_hash")
         copy("telegram.bot_token")
 
+        if "appservice.debug" in self and "logging" not in self:
+            level = "DEBUG" if self["appservice.debug"] else "INFO"
+            base["logging.root.level"] = level
+            base["logging.loggers.mau.level"] = level
+            base["logging.loggers.telethon.level"] = level
+        else:
+            copy("logging")
+
         self._data = base._data
         self.save()
 

mautrix_telegram/user.py

@@ -145,7 +145,7 @@ class User(AbstractUser):
             asyncio.ensure_future(self.post_login(), loop=self.loop)
         elif delete_unless_authenticated:
             self.log.debug(f"Unauthenticated user {self.name} start()ed, deleting session...")
-            self.client.disconnect()
+            await self.client.disconnect()
             self.client.session.delete()
         return self