search

fabianonline / OctoPrint-Telegram

Plugin for octoprint to send status messages and receive commands via Telegram messenger.
311 stars 114 forks source link

Problem creating gif #360

Open EddieGreen opened 3 years ago

EddieGreen commented 3 years ago

With Send gif enabled and Zchange message settings including Send with Gif... /status responds with two identical messages in Telegram - "Problem creating gif, please check log file.

Gifs stopped working following an update to the plugin a while ago, where it's possible this configuration setting was added or changed by default to be off. I've finally gotten round to trying to restore gifs and htis is where I'm at.

In case it helps track the issue down, I run on a non-standard port for HTTP requests. My octoprint webcam settings are default and are working, as are the timelapse settings.

2021-05-17 15:18:18,674 - octoprint.plugins.telegram - DEBUG - self.tmsg = <octoprint_telegram.telegramNotifications.TMSG object at 0xa5c7a5f0>
2021-05-17 15:18:18,686 - octoprint.plugins.telegram - DEBUG - Testing token 111111111:AAAAAaaaAAaA1AA1aAAaA1a111aAaAAAa1A
2021-05-17 15:18:20,242 - octoprint.plugins.telegram - DEBUG - Saving data: {'chats': {'319682336': {'accept_commands': True, 'allow_users': False, 'commands': {'/abort': True, '/con': True, '/ctrl': True, '/dontshutup': True, '/filament': True, '/files': True, '/gif': True, '/help': False, '/print': True, '/settings': True, '/shutup': True, '/status': True, '/supergif': True, '/sys': True, '/test': False, '/togglepause': True, '/tune': True, '/upload': True, '/user': True, 'No': False, 'Yes': False}, 'id': '319682336', 'image': '/plugin/telegram/img/static/default.jpg', 'new': False, 'newUsr': False, 'notifications': {'PrintDone': True, 'PrintFailed': True, 'PrintPaused': True, 'PrintResumed': True, 'PrintStarted': True, 'PrinterShutdown': True, 'PrinterStart': True, 'StatusNotPrinting': False, 'StatusPrinting': False, 'ZChange': True, 'plugin_pause_for_user_event_notify': True}, 'private': True, 'send_notifications': True, 'title': '****** - ****** - @************', 'type': 'PRIVATE'}}}
2021-05-17 15:18:21,244 - octoprint.plugins.telegram - DEBUG - self.tmsg = <octoprint_telegram.telegramNotifications.TMSG object at 0xa5c7a5f0>
2021-05-17 15:18:29,344 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 509395537...
2021-05-17 15:18:45,466 - octoprint.plugins.telegram - DEBUG - self.tmsg = <octoprint_telegram.telegramNotifications.TMSG object at 0xa5c7a5f0>
2021-05-17 15:18:59,450 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 509395537...
2021-05-17 15:19:29,595 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 509395537...
2021-05-17 15:19:51,869 - octoprint.plugins.telegram.listener - DEBUG - Updating update_offset from 509395537 to 509395538
2021-05-17 15:19:51,869 - octoprint.plugins.telegram.listener - DEBUG - MESSAGE: {'update_id': 509395537, 'message': {'message_id': 6227, 'from': {'id': 319682336, 'is_bot': False, 'first_name': '******', 'last_name': '******', 'username': '************', 'language_code': 'en'}, 'chat': {'id': 319682336, 'first_name': '******', 'last_name': '******', 'username': '************', 'type': 'private'}, 'date': 1621261191, 'text': '/status', 'entities': [{'offset': 0, 'length': 7, 'type': 'bot_command'}]}}
2021-05-17 15:19:51,870 - octoprint.plugins.telegram.listener - DEBUG - Not changing update_offset - otherwise would reduce it from 509395538 to 509395538
2021-05-17 15:19:51,871 - octoprint.plugins.telegram.listener - INFO - Got a command: '/status' with parameter: '' in chat 319682336
2021-05-17 15:19:52,179 - octoprint.plugins.telegram - DEBUG - self.tmsg = <octoprint_telegram.telegramNotifications.TMSG object at 0xa5c7a5f0>
2021-05-17 15:19:52,181 - octoprint.plugins.telegram - DEBUG - Got an event: StatusNotPrinting Payload: {}
2021-05-17 15:19:52,182 - octoprint.plugins.telegram.TMSG - DEBUG - event :StatusNotPrinting
2021-05-17 15:19:52,184 - octoprint.plugins.telegram.TMSG - DEBUG - send_gif = True and this message would send gif = True
2021-05-17 15:19:52,185 - octoprint.plugins.telegram.TMSG - DEBUG - Printer Status{'state': {'text': 'Operational', 'flags': {'operational': True, 'printing': False, 'cancelling': False, 'pausing': False, 'resuming': False, 'finishing': False, 'closedOrError': False, 'error': False, 'paused': False, 'ready': True, 'sdReady': False}, 'error': ''}, 'job': {'file': {'name': 'King_SaturnV.gcode', 'path': 'King_SaturnV.gcode', 'display': 'King_SaturnV.gcode', 'origin': 'local', 'size': 14582301, 'date': 1621215745}, 'estimatedPrintTime': 13769.181594886491, 'averagePrintTime': 15027.752457905008, 'lastPrintTime': 15027.752457905008, 'filament': {'tool0': {'length': 7495.716599227882, 'volume': 18.02931127929287}}, 'user': '****** ******'}, 'currentZ': 5.0, 'progress': {'completion': 100.0, 'filepos': 14582301, 'printTime': 15027, 'printTimeLeft': 0, 'printTimeLeftOrigin': None}, 'offsets': {}, 'resends': {'count': 0, 'transmitted': 658939, 'ratio': 0}}
2021-05-17 15:19:52,185 - octoprint.plugins.telegram.TMSG - DEBUG - TEMPS - {'tool0': {'actual': 25.1, 'target': 0.0, 'offset': 0}, 'tool1': {'actual': 25.3, 'target': 0.0, 'offset': 0}, 'bed': {'actual': 25.5, 'target': 0.0, 'offset': 0}, 'chamber': {'actual': None, 'target': None, 'offset': 0}}
2021-05-17 15:19:52,186 - octoprint.plugins.telegram - DEBUG - get_current_layers api key=4D7997109D4249CF9E14EF133078DBEF
2021-05-17 15:19:52,210 - octoprint.plugins.telegram - DEBUG - get_current_layers : r=<Response [200]>
2021-05-17 15:19:52,211 - octoprint.plugins.telegram.TMSG - DEBUG - Layers - {'currentFilename': 'King_SaturnV.gcode', 'fanSpeed': 'Off', 'feedrate': '5000', 'feedrateG0': '-', 'feedrateG1': '5000', 'height': {'current': '85.15', 'currentFormatted': '85.2', 'total': '80.1500015258789', 'totalFormatted': '80.2'}, 'layer': {'averageLayerDuration': '0h:00m:01s', 'averageLayerDurationInSeconds': 1, 'current': '800', 'lastLayerDuration': '0h:00m:00s', 'lastLayerDurationInSeconds': 0, 'total': '800'}, 'print': {'changeFilamentCount': 0, 'changeFilamentTimeLeft': '-', 'changeFilamentTimeLeftInSeconds': 0, 'estimatedChangedFilamentTime': '-', 'estimatedEndTime': '15:18', 'm73progress': '', 'printerState': 'operational', 'progress': '0', 'timeLeft': '0s', 'timeLeftInSeconds': 0}}
2021-05-17 15:19:52,212 - octoprint.plugins.telegram - DEBUG - printTime=11:11:00
2021-05-17 15:19:52,212 - octoprint.plugins.telegram.TMSG - DEBUG - VARS - {'self': <octoprint_telegram.telegramNotifications.TMSG object at 0xa5c7a5f0>, 'payload': {}, 'kwargs': {'chatID': '319682336', 'event': 'StatusNotPrinting', 'with_image': True, 'with_gif': True, 'silent': False, 'thumbnail': None}, 'status': {'state': {'text': 'Operational', 'flags': {'operational': True, 'printing': False, 'cancelling': False, 'pausing': False, 'resuming': False, 'finishing': False, 'closedOrError': False, 'error': False, 'paused': False, 'ready': True, 'sdReady': False}, 'error': ''}, 'job': {'file': {'name': 'King_SaturnV.gcode', 'path': 'King_SaturnV.gcode', 'display': 'King_SaturnV.gcode', 'origin': 'local', 'size': 14582301, 'date': 1621215745}, 'estimatedPrintTime': 13769.181594886491, 'averagePrintTime': 15027.752457905008, 'lastPrintTime': 15027.752457905008, 'filament': {'tool0': {'length': 7495.716599227882, 'volume': 18.02931127929287}}, 'user': '****** ******'}, 'currentZ': 5.0, 'progress': {'completion': 100.0, 'filepos': 14582301, 'printTime': 15027, 'printTimeLeft': 0, 'printTimeLeftOrigin': None}, 'offsets': {}, 'resends': {'count': 0, 'transmitted': 658939, 'ratio': 0}}, 'event': 'StatusNotPrinting', 'z': 5.0, 'temps': {'tool0': {'actual': 25.1, 'target': 0.0, 'offset': 0}, 'tool1': {'actual': 25.3, 'target': 0.0, 'offset': 0}, 'bed': {'actual': 25.5, 'target': 0.0, 'offset': 0}, 'chamber': {'actual': None, 'target': None, 'offset': 0}}, 'bed_temp': 25.5, 'bed_target': 0.0, 'e1_temp': 25.1, 'e1_target': 0.0, 'e2_temp': 25.3, 'e2_target': 0.0, 'percent': 100, 'Layers': {'currentFilename': 'King_SaturnV.gcode', 'fanSpeed': 'Off', 'feedrate': '5000', 'feedrateG0': '-', 'feedrateG1': '5000', 'height': {'current': '85.15', 'currentFormatted': '85.2', 'total': '80.1500015258789', 'totalFormatted': '80.2'}, 'layer': {'averageLayerDuration': '0h:00m:01s', 'averageLayerDurationInSeconds': 1, 'current': '800', 'lastLayerDuration': '0h:00m:00s', 'lastLayerDurationInSeconds': 0, 'total': '800'}, 'print': {'changeFilamentCount': 0, 'changeFilamentTimeLeft': '-', 'changeFilamentTimeLeftInSeconds': 0, 'estimatedChangedFilamentTime': '-', 'estimatedEndTime': '15:18', 'm73progress': '', 'printerState': 'operational', 'progress': '0', 'timeLeft': '0s', 'timeLeftInSeconds': 0}}, 'currentLayer': '800', 'totalLayer': '800', 'time_done': '04:10:27', 'time_left': '00:00:00', 'time_finish': '', 'file': 'King_SaturnV.gcode', 'path': 'King_SaturnV.gcode'}
2021-05-17 15:19:52,213 - octoprint.plugins.telegram.TMSG - DEBUG - Sending Notification: Ready to print
2021-05-17 15:19:52,214 - octoprint.plugins.telegram - DEBUG - start _send_msg
2021-05-17 15:19:52,214 - octoprint.plugins.telegram - DEBUG - PreImgMethod None
2021-05-17 15:19:52,219 - octoprint.plugins.telegram - DEBUG - Sending image...
2021-05-17 15:19:52,219 - octoprint.plugins.telegram - DEBUG - start _send_msg
2021-05-17 15:19:52,221 - octoprint.plugins.telegram - DEBUG - PreImgMethod None
2021-05-17 15:19:52,222 - octoprint.plugins.telegram - DEBUG - log instead log sending message 
2021-05-17 15:19:52,224 - octoprint.plugins.telegram - ERROR - Caught an exception trying send gif: 'event'
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint_telegram/__init__.py", line 1274, in _send_msg
    if kwargs['event'] == "MovieDone":
KeyError: 'event'
2021-05-17 15:19:52,226 - octoprint.plugins.telegram - DEBUG - start _send_msg
2021-05-17 15:19:52,227 - octoprint.plugins.telegram - DEBUG - log instead log sending message 
2021-05-17 15:19:52,227 - octoprint.plugins.telegram - DEBUG - data so far: {'disable_web_page_preview': True, 'chat_id': '319682336', 'disable_notification': False}
2021-05-17 15:19:52,227 - octoprint.plugins.telegram - DEBUG - Sending without image.. 319682336
2021-05-17 15:19:52,360 - octoprint.plugins.telegram - DEBUG - Sending finished. 200
2021-05-17 15:19:52,362 - octoprint.plugins.telegram - DEBUG - PostImgMethod None
2021-05-17 15:19:52,363 - octoprint.plugins.telegram - DEBUG - Sending text...
2021-05-17 15:19:52,363 - octoprint.plugins.telegram - DEBUG - start _send_msg
2021-05-17 15:19:52,364 - octoprint.plugins.telegram - DEBUG - PreImgMethod None
2021-05-17 15:19:52,364 - octoprint.plugins.telegram - DEBUG - log instead log sending message 
2021-05-17 15:19:52,365 - octoprint.plugins.telegram - ERROR - Caught an exception trying send gif: 'event'
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint_telegram/__init__.py", line 1274, in _send_msg
    if kwargs['event'] == "MovieDone":
KeyError: 'event'
2021-05-17 15:19:52,365 - octoprint.plugins.telegram - DEBUG - start _send_msg
2021-05-17 15:19:52,365 - octoprint.plugins.telegram - DEBUG - log instead log sending message 
2021-05-17 15:19:52,366 - octoprint.plugins.telegram - DEBUG - data so far: {'disable_web_page_preview': True, 'chat_id': '319682336', 'disable_notification': False}
2021-05-17 15:19:52,366 - octoprint.plugins.telegram - DEBUG - Sending without image.. 319682336
2021-05-17 15:19:52,513 - octoprint.plugins.telegram - DEBUG - Sending finished. 200
2021-05-17 15:19:52,515 - octoprint.plugins.telegram - DEBUG - PostImgMethod None
2021-05-17 15:19:52,516 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 509395538...

Sending a /gif command produces the following log:

2021-05-17 16:09:57,207 - octoprint.plugins.telegram.listener - INFO - Got a command: '/gif' with parameter: '' in chat 319682336
2021-05-17 16:09:58,653 - octoprint.plugins.telegram.TCMD - DEBUG - PreImgMethod None
2021-05-17 16:09:58,654 - octoprint.plugins.telegram.TCMD - INFO - Will try to create a gif
2021-05-17 16:09:58,778 - octoprint.plugins.telegram - ERROR - Caught an exception trying clean previous images : [Errno 2] No such file or directory: '/home/pi/.octoprint/data/telegram/tmpgif/gif.mp4'
2021-05-17 16:09:58,779 - octoprint.plugins.telegram - INFO - test if nice exist
2021-05-17 16:09:58,779 - octoprint.plugins.telegram - INFO - test exist program 'nice', '--version'
2021-05-17 16:09:58,800 - octoprint.plugins.telegram - INFO - ret = 0
2021-05-17 16:09:58,801 - octoprint.plugins.telegram - INFO - test if cpulimit exist
2021-05-17 16:09:58,801 - octoprint.plugins.telegram - INFO - test exist program 'cpulimit', '--help'
2021-05-17 16:09:58,822 - octoprint.plugins.telegram - INFO - ret = 1
2021-05-17 16:09:58,823 - octoprint.plugins.telegram - INFO - test if ffmpeg exist
2021-05-17 16:09:58,823 - octoprint.plugins.telegram - INFO - test exist program 'ffmpeg', '-h'
2021-05-17 16:09:59,068 - octoprint.plugins.telegram - INFO - ret = 0
2021-05-17 16:09:59,190 - octoprint.plugins.telegram - INFO - sec=5
2021-05-17 16:09:59,191 - octoprint.plugins.telegram - INFO - timeSec=11:11:05
2021-05-17 16:09:59,191 - octoprint.plugins.telegram - INFO - limit_cpu=130.0 | used_cpu=2.0 | because nb_cpu=4
2021-05-17 16:09:59,192 - octoprint.plugins.telegram - INFO - will now create the video  'nice', '-n', '20', 'cpulimit', '-l', '130.0', '-f', '-z', '--', 'ffmpeg', '-y', '-threads', '2.0', '-i', 'http://localhost/webcam/?action=stream', '-t', '11:11:05', '-pix_fmt', 'yuv420p', '/home/pi/.octoprint/data/telegram/tmpgif/gif.mp4'
2021-05-17 16:09:59,948 - octoprint.plugins.telegram - INFO - Finish the video
2021-05-17 16:10:00,226 - octoprint.plugins.telegram - DEBUG - Caught an exception in send_file(): [Errno 2] No such file or directory: '/home/pi/.octoprint/data/telegram/tmpgif/gif.mp4'
2021-05-17 16:10:00,227 - octoprint.plugins.telegram.TCMD - DEBUG - PostImgMethod None
2021-05-17 16:10:00,228 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 509395545...

In case you are interested, ffmpeg is installed even though this log indicates it is not,

giloser commented 3 years ago

Hi,

are you on windows or other system? can you try launching this command in command line nice -n 20 cpulimit -l 130.0 -f -z -- ffmpeg -y -threads 2.0 -i http://localhost/webcam/?action=stream -t 11:11:05 -pix_fmt yuv420p /home/pi/.octoprint/data/telegram/tmpgif/gif.mp4 and tell what come out?

also can you load the event and add one for your user, save and remove it if you don't want the new one to check if that fix the problem of the part Movies.

thanks a lot