На старте запускаются два потока:
Thread(target=self.input_event).start()
Thread(target=self.read_input).start()
Первый - читает поток от ВК и сохраняет некоторые данные при входящих сообщениях:
Код первого потокаfor event in self.long_poll.listen():
if event.type == VkBotEventType.MESSAGE_NEW:
if len(event.object.attachments) > 0:
user_id = event.object.from_id
for pos in range(len(event.object.attachments[0].get('photo').get('sizes'))):
if event.object.attachments[0].get('photo').get('sizes')[pos].get('type', None) == 'w':
img_source = event.object.attachments[0].get('photo').get('sizes')[pos].get('url')
elif event.object.attachments[0].get('photo').get('sizes')[pos].get('type', None) is 'z':
img_source = event.object.attachments[0].get('photo').get('sizes')[pos].get('url')
split_url = img_source
split_url = split_url.split("/")[-1:][0].split(".")[0]
attachments = {'user_id': user_id, 'img_source': img_source, 'split_url': split_url}
logging.info(self.send_message(user_id, 'Отлично! Что вы хотите сделать с изображением?'))
USER_ATTACHMENTS.append(attachments)
logging.info('Received image: ' + str(attachments))
else:
user_id = event.object.from_id
username = self.vk_api.users.get(user_id=user_id)[0]['first_name']
text = event.object.text
data = {'user_id': user_id, 'username': username, 'text': text}
INPUT_EVENTS.append(data)
logging.info('Received message: ' + str(data))
Второй поток ищет в этих данных ключевые слова и, в случае нахождения он создает для пользователя новый поток с нужной функцией:
Код второго потокаfor main_loop in range(len(INPUT_EVENTS)):
if COMMANDS.get(INPUT_EVENTS[main_loop].get('text', None).lower(), None) is not None:
if COMMANDS.get(INPUT_EVENTS[main_loop].get('text', None).lower(), None) == 1:
index_list = main_loop
user_id = INPUT_EVENTS[main_loop].get('user_id', None)
Thread(target=self.command_start, args=(index_list, user_id)).start()
del INPUT_EVENTS[main_loop]
Логирование инициализировано:
logging.basicConfig(filename="log.log",
level=logging.DEBUG,
format="%(asctime)s:%(levelname)s:%(message)s")
В логах, помимо входящих сообщений и выполненных команд все время отображается примерно следующее:
Лог08:28:53,954:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19492&wait=25 HTTP/1.1" 200 381
08:28:53,956:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19492&wait=25 HTTP/1.1" 200 381
08:29:18,966:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19494&wait=25 HTTP/1.1" 200 29
08:29:18,969:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19494&wait=25 HTTP/1.1" 200 29
08:29:18,972:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19494&wait=25 HTTP/1.1" 200 29
08:29:18,974:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19494&wait=25 HTTP/1.1" 200 29
08:29:38,768:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19494&wait=25 HTTP/1.1" 200 148
08:29:38,769:DEBUG:https://lp.vk.com:443 "GET /wh119339221?act=a_check&key=KEY&ts=19494&wait=25 HTTP/1.1" 200 148
Очень часто (бывает раз в 15 минут, а бывает и каждые несколько минут) происходит следующее:
08:28:49,852:DEBUG:Resetting dropped connection: lp.vk.com
Практически перед каждым действием пользователя в логах:
08:24:27,128:DEBUG:Starting new HTTPS connection (1): pp.userapi.com
Иногда бот просто прекращает получать от ВК какие либо-сообщения, т.е. в логах абсолютно такие-же HTTP запросы, но при этом если писать боту, то он просто не принимает эти сообщения, т.е. строк типа logging.info('Received message: ' + str(data)) нет вообще. При этом никаких ошибок нет вообще. По всему коду утыканы logging.info, практически все функции обернуты блоком tr-except, к примеру вот блок, внутри которого работает первый поток:
try:
...
except requests.exceptions.Timeout as e:
logging.error(e)
os.kill(os.getpid(), signal.SIGINT)
except requests.exceptions.TooManyRedirects as e:
logging.error(e)
os.kill(os.getpid(), signal.SIGINT)
except requests.exceptions.RequestException as e:
Thread(target=self.read_input).join()
logging.error(e)
os.kill(os.getpid(), signal.SIGINT)
Но все-равно, бот просто "зависает" и ничего не делает, хотя в логах ни единой ошибки.
Так-же ночью был наплыв пользователей и в логах творилось примерно следующее:
2019-05-09 00:20:38,701:WARNING:Connection pool is full, discarding connection: lp.vk.com
2019-05-09 00:20:38,717:DEBUG:Starting new HTTPS connection (242): lp.vk.com
Хотя это было единожды и не думаю, что связано с "зависаниями" бота.
Сам бот работает как сервис через systemd, и в моменты "зависания" systemctl status говорит, что с сервисом все хорошо.
Перерыл уже все, что можно было, может у кого тут какие-то идеи найдутся.
UPD.
В рабочем состоянии systemctl status отображает 3 процесса, но иногда обращал внимание, что их 2, по всей видимости как раз когда отваливается поток input_event. Есть идея сделать все создаваемые потоки демонами, кроме input_event, тогда, по идеи, если этот поток отвалится приложение должно прекратить свою работу, а systemd сразу его перезапустить. Я-же ведь правильно понимаю логику, что если в программе остаются только потоки-демоны, то она прекращает свою работу?
