use logging for console output

This commit is contained in:
Frank Becker 2020-02-08 22:16:19 +01:00
parent 4337bae47a
commit 77d8fdaac1
13 changed files with 111 additions and 101 deletions

96
bot.py
View File

@ -9,6 +9,7 @@ import re
import sys
import traceback
import urllib.parse
import logging
from importlib import reload
import requests
@ -28,14 +29,30 @@ class CommandRequiresOwner(Exception):
class Bot:
appid = 'org.vranki.hemppa'
version = '1.2'
client = None
join_on_invite = False
modules = dict()
pollcount = 0
poll_task = None
owners = []
def __init__(self):
self.appid = 'org.vranki.hemppa'
self.version = '1.2'
self.client = None
self.join_on_invite = False
self.modules = dict()
self.pollcount = 0
self.poll_task = None
self.owners = []
self.debug = os.getenv("DEBUG")
self.initializeLogger()
self.logger = logging.getLogger("hemppa")
self.logger.debug("Initialized")
def initializeLogger(self):
log_format = '%(levelname)s - %(name)s - %(message)s'
if self.debug:
logging.root.setLevel(logging.DEBUG)
else:
logging.root.setLevel(logging.INFO)
logging.basicConfig(format=log_format)
async def send_text(self, room, body):
msg = {
@ -126,11 +143,10 @@ class Bot:
except CommandRequiresOwner:
await self.send_text(room, f'Sorry, only bot owner can run that command.')
except Exception:
await self.send_text(room,
f'Module {command} experienced difficulty: {sys.exc_info()[0]} - see log for details')
await self.send_text(room, f'Module {command} experienced difficulty: {sys.exc_info()[0]} - see log for details')
traceback.print_exc(file=sys.stderr)
else:
print(f"Unknown command: {command}")
self.logger.error(f"Unknown command: {command}")
await self.send_text(room, f"Sorry. I don't know what to do. Execute !help to get a list of available commands.")
@ -142,30 +158,28 @@ class Bot:
for attempt in range(3):
result = await self.client.join(room.room_id)
if type(result) == JoinError:
print(f"Error joining room {room.room_id} (attempt %d): %s",
attempt, result.message,
)
self.logger.error(f"Error joining room %s (attempt %d): %s", room.room_id, attempt, result.message)
else:
print(f"joining room '{room.display_name}'({room.room_id}) invited by '{event.sender}'")
self.logger.info(f"joining room '{room.display_name}'({room.room_id}) invited by '{event.sender}'")
break
else:
print(f'Received invite event, but not joining as sender is not owner or bot not configured to join on invite. {event}')
self.logger.warning(f'Received invite event, but not joining as sender is not owner or bot not configured to join on invite. {event}')
def load_module(self, modulename):
try:
print("load module: " + modulename)
self.logger.info(f'load module: {modulename}')
module = importlib.import_module('modules.' + modulename)
module = reload(module)
cls = getattr(module, 'MatrixModule')
return cls(modulename)
except ModuleNotFoundError:
print('Module ', modulename, ' failed to load!')
self.logger.error(f'Module {modulename} failed to load!')
traceback.print_exc(file=sys.stderr)
return None
def reload_modules(self):
for modulename in bot.modules:
print('Reloading', modulename, '..')
self.logger.info(f'Reloading {modulename} ..')
self.modules[modulename] = self.load_module(modulename)
self.load_settings(self.get_account_data())
@ -202,7 +216,7 @@ class Bot:
self.__handle_error_response(response)
if response.status_code != 200:
print('Setting account data failed:', response, response.json())
self.logger.error('Setting account data failed. response: %s json: %s', response, response.json())
def get_account_data(self):
userid = urllib.parse.quote(self.matrix_user)
@ -214,14 +228,13 @@ class Bot:
if response.status_code == 200:
return response.json()
print(
f'Getting account data failed: {response} {response.json()} - this is normal if you have not saved any settings yet.')
self.logger.error(f'Getting account data failed: {response} {response.json()} - this is normal if you have not saved any settings yet.')
return None
def __handle_error_response(self, response):
if response.status_code == 401:
print("ERROR: access token is invalid or missing")
print("NOTE: check MATRIX_ACCESS_TOKEN or set MATRIX_PASSWORD")
self.logger.error("access token is invalid or missing")
self.logger.info("NOTE: check MATRIX_ACCESS_TOKEN or set MATRIX_PASSWORD")
sys.exit(2)
def init(self):
@ -235,11 +248,11 @@ class Bot:
if matrix_server and self.matrix_user and bot_owners:
self.client = AsyncClient(matrix_server, self.matrix_user)
self.client.access_token = access_token
self.client.access_token = access_token
if self.client.access_token is None:
if self.matrix_pass is None:
print("Either MATRIX_ACCESS_TOKEN or MATRIX_PASSWORD need to be set")
self.logger.error("Either MATRIX_ACCESS_TOKEN or MATRIX_PASSWORD need to be set")
sys.exit(1)
self.join_on_invite = join_on_invite is not None
@ -247,14 +260,14 @@ class Bot:
self.get_modules()
else:
print("The environment variables MATRIX_SERVER, MATRIX_USER and BOT_OWNERS are mandatory")
self.logger.error("The environment variables MATRIX_SERVER, MATRIX_USER and BOT_OWNERS are mandatory")
sys.exit(1)
def start(self):
self.load_settings(self.get_account_data())
enabled_modules = [module for module_name, module in self.modules.items() if module.enabled]
print(f'Starting {len(enabled_modules)} modules..')
self.logger.info(f'Starting {len(enabled_modules)} modules..')
for modulename, moduleobject in self.modules.items():
if moduleobject.enabled:
try:
@ -263,7 +276,7 @@ class Bot:
traceback.print_exc(file=sys.stderr)
def stop(self):
print(f'Stopping {len(self.modules)} modules..')
self.logger.info(f'Stopping {len(self.modules)} modules..')
for modulename, moduleobject in self.modules.items():
try:
moduleobject.matrix_stop(bot)
@ -275,18 +288,18 @@ class Bot:
login_response = await self.client.login(self.matrix_pass)
if isinstance(login_response, LoginError):
print(f"Failed to login: {login_response.message}")
self.logger.error(f"Failed to login: {login_response.message}")
return
last_16 = self.client.access_token[-16:]
print(f"Logged in with password, access token: ...{last_16}")
self.logger.info(f"Logged in with password, access token: ...{last_16}")
await self.client.sync()
for roomid, room in self.client.rooms.items():
print(f"Bot is on '{room.display_name}'({roomid}) with {len(room.users)} users")
self.logger.info(f"Bot is on '{room.display_name}'({roomid}) with {len(room.users)} users")
if len(room.users) == 1:
print(f'Room {roomid} has no other users - leaving it.')
print(await self.client.room_leave(roomid))
self.logger.info(f'Room {roomid} has no other users - leaving it.')
self.logger.info(await self.client.room_leave(roomid))
self.start()
@ -298,12 +311,12 @@ class Bot:
self.client.add_event_callback(self.invite_cb, (InviteEvent,))
if self.join_on_invite:
print('Note: Bot will join rooms if invited')
print('Bot running as', self.client.user, ', owners', self.owners)
self.logger.info('Note: Bot will join rooms if invited')
self.logger.info('Bot running as %s, owners %s', self.client.user, self.owners)
self.bot_task = asyncio.create_task(self.client.sync_forever(timeout=30000))
await self.bot_task
else:
print('Client was not able to log in, check env variables!')
self.logger.error('Client was not able to log in, check env variables!')
async def shutdown(self):
@ -311,19 +324,20 @@ class Bot:
logout = await self.client.logout()
if isinstance(logout, LogoutResponse):
print("Logout successful")
self.logger.info("Logout successful")
try:
await self.client.close()
print("Connection closed")
self.logger.info("Connection closed")
except Exception as e:
print("error while closing client", e)
self.logger.error("error while closing client: %s", e)
else:
logout: LogoutError
print(f"Logout unsuccessful. msg: {logout.message}")
self.logger.error(f"Logout unsuccessful. msg: {logout.message}")
else:
await self.client.client_session.close()
bot = Bot()
bot.init()
try:

View File

@ -1,4 +1,5 @@
from datetime import datetime
from modules.common.module import BotModule
@ -41,7 +42,7 @@ class MatrixModule(BotModule):
async def leave(self, bot, room, event):
bot.must_be_admin(room, event)
print(f'{event.sender} asked bot to leave room {room.room_id}')
self.logger.info(f'{event.sender} asked bot to leave room {room.room_id}')
await bot.send_text(room, f'By your command.')
await bot.client.room_leave(room.room_id)
@ -82,12 +83,12 @@ class MatrixModule(BotModule):
async def quit(self, bot, room, event):
bot.must_be_admin(room, event)
await bot.send_text(room, f'Quitting, as requested')
print(f'{event.sender} commanded bot to quit, so quitting..')
self.logger.info(f'{event.sender} commanded bot to quit, so quitting..')
bot.bot_task.cancel()
async def enable_module(self, bot, room, event, module_name):
bot.must_be_admin(room, event)
print(f"asked to enable {module_name}")
self.logger.info(f"asked to enable {module_name}")
if bot.modules.get(module_name):
module = bot.modules.get(module_name)
module.enable()
@ -99,7 +100,7 @@ class MatrixModule(BotModule):
async def disable_module(self, bot, room, event, module_name):
bot.must_be_admin(room, event)
print(f"asked to disable {module_name}")
self.logger.info(f"asked to disable {module_name}")
if bot.modules.get(module_name):
module = bot.modules.get(module_name)
module.disable()

View File

@ -1,4 +1,6 @@
import logging
from abc import ABC, abstractmethod
from nio import RoomMessageText, MatrixRoom
@ -28,6 +30,7 @@ class BotModule(ABC):
def __init__(self, name):
self.enabled = False
self.name = name
self.logger = logging.getLogger("module " + self.name)
def matrix_start(self, bot):
"""Called once on startup
@ -35,7 +38,7 @@ class BotModule(ABC):
:param bot: a reference to the bot
:type bot: Bot
"""
print('Starting', self.name, '..')
self.logger.info('Starting..')
@abstractmethod
async def matrix_message(self, bot, room, event):
@ -56,7 +59,7 @@ class BotModule(ABC):
:param bot: a reference to the bot
:type bot: Bot
"""
print('Stopping', self.name, '..')
self.logger.info('Stopping..')
async def matrix_poll(self, bot, pollcount):
"""Called every 10 seconds

View File

@ -33,7 +33,7 @@ class PollingService(BotModule):
for account in accounts:
await self.poll_account(bot, account, roomid, send_messages)
else:
print(f'Bot is no longer in room {roomid} - deleting it from {self.service_name} room list')
self.logger.warning(f'Bot is no longer in room {roomid} - deleting it from {self.service_name} room list')
delete_rooms.append(roomid)
for roomid in delete_rooms:
self.account_rooms.pop(roomid, None)
@ -62,7 +62,7 @@ class PollingService(BotModule):
f"Next poll in this room at {self.next_poll_time.get(room.room_id)} - in {self.next_poll_time.get(room.room_id) - datetime.now()}")
elif args[1] == 'poll':
bot.must_be_owner(event)
print(f'{self.service_name} force polling requested by {event.sender}')
self.logger.info(f'{self.service_name} force polling requested by {event.sender}')
# Faking next poll times to force poll
for roomid in self.account_rooms:
self.next_poll_time[roomid] = datetime.now() - timedelta(hours=1)
@ -77,7 +77,7 @@ class PollingService(BotModule):
bot.must_be_admin(room, event)
account = args[2]
print(f'Adding {self.service_name} account {account} to room id {room.room_id}')
self.logger.info(f'Adding {self.service_name} account {account} to room id {room.room_id}')
if self.account_rooms.get(room.room_id):
if account not in self.account_rooms[room.room_id]:
@ -94,14 +94,12 @@ class PollingService(BotModule):
bot.must_be_admin(room, event)
account = args[2]
print(
f'Removing {self.service_name} account {account} from room id {room.room_id}')
self.logger.info(f'Removing {self.service_name} account {account} from room id {room.room_id}')
if self.account_rooms.get(room.room_id):
self.account_rooms[room.room_id].remove(account)
print(
f'{self.service_name} accounts now for this room {self.account_rooms.get(room.room_id)}')
self.logger.info(f'{self.service_name} accounts now for this room {self.account_rooms.get(room.room_id)}')
bot.save_settings()
await bot.send_text(room, f'Removed {self.service_name} account from this room')

View File

@ -1,5 +1,6 @@
import shlex
from datetime import datetime
from .common.module import BotModule

View File

@ -1,5 +1,6 @@
from geopy.geocoders import Nominatim
from nio import RoomMessageUnknown, AsyncClient
from nio import RoomMessageUnknown
from modules.common.module import BotModule
@ -46,9 +47,9 @@ class MatrixModule(BotModule):
else:
query = event.body[4:]
geolocator = Nominatim(user_agent=bot.appid)
print('loc: looking up', query, '..')
self.logger.info('loc: looking up %s ..', query)
location = geolocator.geocode(query)
print('loc rx', location)
self.logger.info('loc rx %s', location)
if location:
locationmsg = {
"body": str(location.address),

View File

@ -9,7 +9,6 @@ from google.auth.transport.requests import Request
from google_auth_oauthlib.flow import InstalledAppFlow
from googleapiclient.discovery import build
#
# Google calendar notifications
#
@ -37,10 +36,10 @@ class MatrixModule(BotModule):
if os.path.exists('token.pickle'):
with open('token.pickle', 'rb') as token:
creds = pickle.load(token)
print('Loaded existing pickle file')
self.logger.info('Loaded existing pickle file')
# If there are no (valid) credentials available, let the user log in.
if not creds or not creds.valid:
print('No credentials or credentials not valid!')
self.logger.warn('No credentials or credentials not valid!')
if creds and creds.expired and creds.refresh_token:
creds.refresh(Request())
else:
@ -51,19 +50,17 @@ class MatrixModule(BotModule):
# Save the credentials for the next run
with open('token.pickle', 'wb') as token:
pickle.dump(creds, token)
print('Pickle saved')
self.logger.info('Pickle saved')
self.service = build('calendar', 'v3', credentials=creds)
try:
calendar_list = self.service.calendarList().list().execute()[
'items']
print(
f'Google calendar set up successfully with access to {len(calendar_list)} calendars:\n')
calendar_list = self.service.calendarList().list().execute()['items']
self.logger.info(f'Google calendar set up successfully with access to {len(calendar_list)} calendars:\n')
for calendar in calendar_list:
print(calendar['summary'] + ' - ' + calendar['id'])
self.logger.info(f"{calendar['summary']} - + {calendar['id']}")
except Exception:
print('Getting calendar list failed!')
self.logger.error('Getting calendar list failed!')
async def matrix_message(self, bot, room, event):
if not self.service:
@ -76,7 +73,7 @@ class MatrixModule(BotModule):
if len(args) == 2:
if args[1] == 'today':
for calid in calendars:
print('Listing events in cal', calid)
self.logger.info(f'Listing events in cal {calid}')
events = events + self.list_today(calid)
if args[1] == 'list':
await bot.send_text(room, 'Calendars in this room: ' + str(self.calendar_rooms.get(room.room_id)))
@ -87,7 +84,7 @@ class MatrixModule(BotModule):
bot.must_be_admin(room, event)
calid = args[2]
print(f'Adding calendar {calid} to room id {room.room_id}')
self.logger.info(f'Adding calendar {calid} to room id {room.room_id}')
if self.calendar_rooms.get(room.room_id):
if calid not in self.calendar_rooms[room.room_id]:
@ -98,8 +95,7 @@ class MatrixModule(BotModule):
else:
self.calendar_rooms[room.room_id] = [calid]
print(
f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
self.logger.info(f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
bot.save_settings()
@ -110,13 +106,12 @@ class MatrixModule(BotModule):
bot.must_be_admin(room, event)
calid = args[2]
print(f'Removing calendar {calid} from room id {room.room_id}')
self.logger.info(f'Removing calendar {calid} from room id {room.room_id}')
if self.calendar_rooms.get(room.room_id):
self.calendar_rooms[room.room_id].remove(calid)
print(
f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
self.logger.info(f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
bot.save_settings()
@ -125,14 +120,14 @@ class MatrixModule(BotModule):
else:
for calid in calendars:
print('Listing events in cal', calid)
self.logger.info(f'Listing events in cal {calid}')
events = events + self.list_upcoming(calid)
if len(events) > 0:
print(f'Found {len(events)} events')
self.logger.info(f'Found {len(events)} events')
await self.send_events(bot, events, room)
else:
print(f'No events found')
self.logger.info(f'No events found')
await bot.send_text(room, 'No events found, try again later :)')
async def send_events(self, bot, events, room):
@ -152,19 +147,18 @@ class MatrixModule(BotModule):
def list_today(self, calid):
startTime = datetime.utcnow()
startTime = startTime.replace(
hour=0, minute=0, second=0, microsecond=0)
startTime = startTime.replace(hour=0, minute=0, second=0, microsecond=0)
endTime = startTime + timedelta(hours=24)
now = startTime.isoformat() + 'Z'
end = endTime.isoformat() + 'Z'
print('Looking for events between', now, end)
self.logger.info(f'Looking for events between {now} {end}')
events_result = self.service.events().list(calendarId=calid, timeMin=now,
timeMax=end, maxResults=10, singleEvents=True,
orderBy='startTime').execute()
return events_result.get('items', [])
def help(self):
return ('Google calendar. Lists 10 next events by default. today = list today\'s events.')
return 'Google calendar. Lists 10 next events by default. today = list today\'s events.'
def get_settings(self):
data = super().get_settings()

View File

@ -19,7 +19,7 @@ class MatrixModule(PollingService):
async def poll_implementation(self, bot, account, roomid, send_messages):
try:
medias = self.instagram.get_medias(account, 5)
print(f'Polling instagram account {account} for room {roomid} - got {len(medias)} posts.')
self.logger.info(f'Polling instagram account {account} for room {roomid} - got {len(medias)} posts.')
for media in medias:
if send_messages:
if media.identifier not in self.known_ids:
@ -29,12 +29,11 @@ class MatrixModule(PollingService):
self.known_ids.add(media.identifier)
except InstagramNotFoundException:
print('ig error: there is ', account,
' account that does not exist - deleting from room')
self.logger.error(f"{account} does not exist - deleting from room")
self.account_rooms[roomid].remove(account)
bot.save_settings()
except Exception:
print('Polling instagram account failed:')
self.logger.error('Polling instagram account failed:')
traceback.print_exc(file=sys.stderr)
polldelay = timedelta(minutes=30 + randrange(30))

View File

@ -3,7 +3,6 @@ from datetime import datetime
from pyteamup import Calendar
#
# TeamUp calendar notifications
#
@ -48,7 +47,7 @@ class MatrixModule(BotModule):
bot.must_be_admin(room, event)
calid = args[2]
print(f'Adding calendar {calid} to room id {room.room_id}')
self.logger.info(f'Adding calendar {calid} to room id {room.room_id}')
if self.calendar_rooms.get(room.room_id):
if calid not in self.calendar_rooms[room.room_id]:
@ -59,8 +58,7 @@ class MatrixModule(BotModule):
else:
self.calendar_rooms[room.room_id] = [calid]
print(
f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
self.logger.info(f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
bot.save_settings()
self.setup_calendars()
@ -69,13 +67,12 @@ class MatrixModule(BotModule):
bot.must_be_admin(room, event)
calid = args[2]
print(f'Removing calendar {calid} from room id {room.room_id}')
self.logger.info(f'Removing calendar {calid} from room id {room.room_id}')
if self.calendar_rooms.get(room.room_id):
self.calendar_rooms[room.room_id].remove(calid)
print(
f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
self.logger.info(f'Calendars now for this room {self.calendar_rooms.get(room.room_id)}')
bot.save_settings()
self.setup_calendars()

View File

@ -16,7 +16,7 @@ class MatrixModule(PollingService):
async def poll_implementation(self, bot, account, roomid, send_messages):
try:
tweets = query_tweets_from_user(account, limit=1)
print(f'Polling twitter account {account} - got {len(tweets)} tweets')
self.logger.info(f'Polling twitter account {account} - got {len(tweets)} tweets')
for tweet in tweets:
if tweet.tweet_id not in self.known_ids:
if send_messages:
@ -25,5 +25,5 @@ class MatrixModule(PollingService):
f'Twitter {account}: {tweet.text} - https://twitter.com{tweet.tweet_url}')
self.known_ids.add(tweet.tweet_id)
except Exception:
print('Polling twitter account failed:')
self.logger.error('Polling twitter account failed:')
traceback.print_exc(file=sys.stderr)

View File

@ -93,11 +93,11 @@ class MatrixModule(BotModule):
try:
r = httpx.get(url)
except Exception as e:
print(f"Failed fetching url {url}. Error: {e}")
self.logger.error(f"Failed fetching url {url}. Error: {e}")
return (title, description)
if r.status_code != 200:
print(f"Failed fetching url {url}. Status code: {r.status_code}")
self.logger.info(f"Failed fetching url {url}. Status code: {r.status_code}")
return (title, description)
# try parse and get the title
@ -108,7 +108,7 @@ class MatrixModule(BotModule):
if descr_tag:
description = descr_tag.get("content", None)
except Exception as e:
print(f"Failed parsing response from url {url}. Error: {e}")
self.logger.error(f"Failed parsing response from url {url}. Error: {e}")
return (title, description)
return (title, description)
@ -161,4 +161,4 @@ class MatrixModule(BotModule):
def dump(self, obj):
for attr in dir(obj):
print("obj.%s = %r" % (attr, getattr(obj, attr)))
self.logger.info("obj.%s = %r", attr, getattr(obj, attr))

View File

@ -1,5 +1,6 @@
from timeit import default_timer as timer
from urllib.request import urlopen
from modules.common.module import BotModule
@ -12,10 +13,10 @@ class MatrixModule(BotModule):
# check url
if not (url.startswith('http://') or url.startswith('https://')):
# print ("adding trailing https")
self.logger.debug("adding trailing https")
url = "https://" + url
print("ping:", url)
self.logger.info("ping: %s", url)
start = timer()
try:
@ -25,7 +26,7 @@ class MatrixModule(BotModule):
except Exception as e:
await bot.send_text(room, "Ping failed: " + str(e))
print("Error: " + str(e))
self.logger.error(str(e))
return False
end = timer()

View File

@ -1,4 +1,5 @@
import subprocess
from modules.common.module import BotModule