search

fabianonline / OctoPrint-Telegram

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

Bug sending same message unlimited times #110

Open tal1991 opened 6 years ago

tal1991 commented 6 years ago

Hi,

I did a typing mistake and the server continue to send the same message again and again. I attached the screen shot to show the case that cause this bug,

whatsapp image 2018-01-26 at 23 05 48

Hope the image will help solve the bug, if you have any question about my Octopi server fell free to ask.

Tal

battlezone100 commented 6 years ago

I am suddenly having the same issue.

McFly99 commented 6 years ago

Same here, having the same issue after restarting a chat. /start caused a never ending message pattern.

Hywelmartin commented 6 years ago

I have had this issue as well, at x-mas time, I showed the communication to my brother(to impress him). fortunately the printer was 200 km away at my work. So I had to send out a security guard to pull the plug to the printer... I have encountered this behavior at my home printer as well for a couple of months ago..

the command I sent was "/status"

dnlbauer commented 6 years ago

This problem still exists.. Just happend to me when sending /shutup... It will do the opposite of shutup for the next 4h because im mid-print and cant restart now.. >.>

pnixon-cartera commented 5 years ago

I've been running into this as well. Currently one of my printers has sent 600ish messages in the last 15 minutes. What information is needed to troubleshoot this?

sferris commented 5 years ago

Add 2 more reports for this issue. Happened to me this morning, as well with my brother while testing if it was just me, or a general issue.

fabianonline commented 5 years ago

I spent some time looking at the code without finding a way for this bug to happen. Can you more or less reliable reproduce the error? Do you happen to have a debug log of the octoprint-telegram plugin from when this bug happened?

I made a few changes to the code to hopefully catch this bug, but without knowing how it exactly happens, I'm kinda fishing in muddy waters.

tal1991 commented 5 years ago

I will try to reproduce the error on my system. If i succeed what files/info you want me to upload/send you?

fabianonline commented 5 years ago

In Octoprint configuration > Logging > Logginglevel add a row for octoprint.plugins.telegram.listener, level DEBUG. Afterwards please send me your octoprint.log. Possibly directly to me, cause the logfile could contain sensitive info you wouldn't want all world to see.

fabianonline commented 5 years ago

If you can reproduce this bug by doing certain steps, that information would also be helpful.

sferris commented 5 years ago

I will do what I can tonight also.. I don't recall doing anything special though. I know I'd used the command feature before, but this particular time, I think I just did /status, and it went into an infinite loop. From there, any command I issued, also went into an infinite loop. (behaved as if I continually sent the same command myself) When I told my brother, he did the same thing, and his behaved the same way. We both ended up rebuilding our octopi's and creating new tokens.

On Tue, Mar 26, 2019 at 5:49 AM Fabian Schlenz notifications@github.com wrote:

If you can reproduce this bug by doing certain steps, that information would also be helpful.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/fabianonline/OctoPrint-Telegram/issues/110#issuecomment-476591417, or mute the thread https://github.com/notifications/unsubscribe-auth/ABI5tGPs2gJlDY0qmY21LId05SBSOsGLks5vagk0gaJpZM4Ru4ZO .

mark7wenning commented 5 years ago

The bug is pretty random unfortunately. I looked at the code a long time ago and didn't see anything. It feels like the input buffer is not being cleared, either in the plugin itself or Octoprint. Perhaps a workaround is to make sure the buffer is clear and then wait, say 30 seconds before reading it again? At the very least this would slow it down ;-)

On Wed, Mar 27, 2019 at 9:58 AM sferris notifications@github.com wrote:

I will do what I can tonight also.. I don't recall doing anything special though. I know I'd used the command feature before, but this particular time, I think I just did /status, and it went into an infinite loop. From there, any command I issued, also went into an infinite loop. (behaved as if I continually sent the same command myself) When I told my brother, he did the same thing, and his behaved the same way. We both ended up rebuilding our octopi's and creating new tokens.

On Tue, Mar 26, 2019 at 5:49 AM Fabian Schlenz notifications@github.com wrote:

If you can reproduce this bug by doing certain steps, that information would also be helpful.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub < https://github.com/fabianonline/OctoPrint-Telegram/issues/110#issuecomment-476591417 , or mute the thread < https://github.com/notifications/unsubscribe-auth/ABI5tGPs2gJlDY0qmY21LId05SBSOsGLks5vagk0gaJpZM4Ru4ZO

.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/fabianonline/OctoPrint-Telegram/issues/110#issuecomment-477194184, or mute the thread https://github.com/notifications/unsubscribe-auth/AcwqphQEHKd1o6v2VW__q_yAgT9rQeMSks5va4b6gaJpZM4Ru4ZO .

--

Mark W. Wenning mark7wenning@gmail.com mark.wenning@xflowresearch.com 512-876-5024

"What we fear doing most is usually what we most need to do." -- Timothy Ferriss

sferris commented 5 years ago

Dang it - I finally just triggered this again, but apparently didn't save the debugging level change. Restarting octopi cleared the infinite messages for the time .. I'll keep trying.. I do keep seeing this, is it normal:

2019-04-22 00:57:26,366 - octoprint.plugins.telegram.listener - INFO - Got a command: 'This is a test' with parameter: '' in chat 462170883 2019-04-22 00:57:26,368 - octoprint.plugins.telegram.listener - WARNING - Previous command was an unknown command. 2019-04-22 00:57:27,224 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110... 2019-04-22 00:57:57,980 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110... 2019-04-22 00:58:28,716 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110... 2019-04-22 00:58:59,532 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110... 2019-04-22 00:59:30,279 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110... 2019-04-22 01:00:01,035 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110... 2019-04-22 01:00:31,792 - octoprint.plugins.telegram.listener - DEBUG - listener: sending request with offset 611009110...

?

garbled1 commented 5 years ago

OK.. So I hit this problem yesterday, during a huge print, finally able to shut it up.. but flipped debug on towards the end. I sent a /status. Then in desperation sent 3 more command, which was a mistake, because it repeated all 4 commands. I notice in the log, it doesn't see the opening /status.....

Start of event: (remember, first command was /status, not help)

2019-04-25 01:40:49,606 - octoprint.server - INFO - -----------------------------------

2019-04-25 01:40:51,336 - octoprint.plugins.telegram.listener - INFO - Got a command: ' /help' with parameter: '' in chat X 2019-04-25 01:40:52,298 - octoprint.plugins.telegram.listener - INFO - Got a command: ' /shutup' with parameter: '' in chat X 2019-04-25 01:40:53,259 - octoprint.plugins.telegram.listener - INFO - Got a command: ' /settings' with parameter: '' in chat X 2019-04-25 01:40:53,262 - octoprint.plugins.telegram.listener - WARNING - Previous comm and was from an unauthorized user.

Now some debug output:

2019-04-25 11:27:02,999 - octoprint.plugins.telegram.listener - INFO - Got a command: '/shutup' with parameter: '' in chat X 2019-04-25 11:27:03,003 - octoprint.plugins.telegram - DEBUG - Sending a message: ð Okay, shutting up until the next print is finished.ð Use /dontshutup to let me talk again before that. with_image=False chatID= X 2019-04-25 11:27:03,007 - octoprint.plugins.telegram - DEBUG - data so far: {'disable_web_page_preview': True} 2019-04-25 11:27:03,012 - octoprint.plugins.telegram - DEBUG - Sending without image.. 580474460 2019-04-25 11:27:04,103 - octoprint.plugins.telegram - DEBUG - Sending finished. 200 2019-04-25 11:27:04,111 - octoprint.plugins.telegram.listener - DEBUG - MESSAGE: {u'message': {u'from': {u'first_name': u'Tim', u'is_bot': False, u'id': X, u'language_code': u'en'}, u'text': u'/settings', u'entities': [{u'length': 9, u'type': u'bot_command', u'offset': 0}], u'chat': {u'first_name': u'Tim', u'type': u'private', u'id': X}, u'date': 1556117240, u'message_id': 523}, u'update_id': 746598387} 2019-04-25 11:27:04,114 - octoprint.plugins.telegram.listener - INFO - Got a command: '/settings' with parameter: '' in chat 580474460 2019-04-25 11:27:04,119 - octoprint.plugins.telegram.listener - WARNING - Previous command was from an unauthorized user. 2019-04-25 11:27:04,122 - octoprint.plugins.telegram - DEBUG - Sending a message: You are not allowed to do this! ð ¹ The following commands are known:\n\n/abort - Aborts the currently running print. A confirmation is required.\n/shutup - Disables automatic notifications till the next print ends.\n/dontshutup - The opposite of /shutup - Makes the bot talk again.\n/status - Sends the current status including a current photo.\n/settings - Displays the current notification settings and allows you to change them.\n/files - Lists all the files available for printing.\n/print - Lets you start a print. A confirmation is required.\n/togglepause - Pause/Resume current Print.\n/con - Connect/disconnect printer.\n/upload - You can just send me a gcode file to save it to my library.\n/sys - Execute Octoprint System Comamnds.\n/ctrl - Use self defined controls from Octoprint.\n/tune - Set feed- and flowrate. Control temperatures.\n/user - get user info.\n/help - show this help message. with_image=False chatID= X 2019-04-25 11:27:11,604 - octoprint.plugins.telegram - DEBUG - data so far: {'parse_mode': 'Markdown', 'disable_web_page_preview': True} 2019-04-25 11:27:11,604 - octoprint.plugins.telegram - DEBUG - Sending without image.. X 2019-04-25 11:27:13,081 - octoprint.plugins.telegram - DEBUG - Sending finished. 200 2019-04-25 11:27:13,090 - octoprint.plugins.telegram.listener - DEBUG - MESSAGE: {u'message': {u'from': {u'first_name': u'Tim', u'is_bot': False, u'id': X, u'language_code': u'en'}, u'text': u'/shutup', u'entities': [{u'length': 7, u'type': u'bot_command', u'offset': 0}], u'chat': {u'first_name': u'Tim', u'type': u'private', u'id': X}, u'date': 1556117099, u'message_id': 451}, u'update_id': 746598386} 2019-04-25 11:27:13,097 - octoprint.plugins.telegram.listener - INFO - Got a command: '/shutup' with parameter: '' in chat 580474460 2019-04-25 11:27:13,102 - octoprint.plugins.telegram - DEBUG - Sending a message: ð Okay, shutting up until the next print is finished.ð Use /dontshutup to let me talk again before that. with_image=False chatID= X 2019-04-25 11:27:13,104 - octoprint.plugins.telegram - DEBUG - data so far: {'disable_web_page_preview': True} 2019-04-25 11:27:13,107 - octoprint.plugins.telegram - DEBUG - Sending without image.. X 2019-04-25 11:27:14,963 - octoprint.plugins.telegram - DEBUG - Sending finished. 200 2019-04-25 11:27:14,971 - octoprint.plugins.telegram.listener - DEBUG - MESSAGE: {u'message': {u'from': {u'first_name': u'Tim', u'is_bot': False, u'id': X, u'language_code': u'en'}, u'text': u'/settings', u'entities': [{u'length': 9, u'type': u'bot_command', u'offset': 0}], u'chat': {u'first_name': u'Tim', u'type': u'private', u'id': X}, u'date': 1556117240, u'message_id': 523}, u'update_id': 746598387} 2019-04-25 11:27:14,976 - octoprint.plugins.telegram.listener - INFO - Got a command: '/settings' with parameter: '' in chat X 2019-04-25 11:27:14,977 - octoprint.plugins.telegram.listener - WARNING - Previous command was from an unauthorized user. 2019-04-25 11:27:14,982 - octoprint.plugins.telegram - DEBUG - Sending a message: You are not allowed to do this!

And one more with the repeat of the status command:

2019-04-25 11:30:26,170 - octoprint.plugins.telegram.listener - INFO - Got a command: '/status' with parameter: '' in chat X 2019-04-25 11:30:26,171 - octoprint.plugins.telegram - DEBUG - Got an event: StatusNotPrinting Payload: {} 2019-04-25 11:30:26,176 - octoprint.plugins.telegram.TMSG - DEBUG - Printer Status{'progress': {'completion': 100.0, 'printTimeLeftOrigin': None, 'printTime': 61228, 'printTimeLeft': 0, 'filepos': 32291300L}, 'state': {'text': 'Operational', 'flags': {'cancelling': False, 'paused': False, 'operational': True, 'pausing': False, 'printing': False, 'resuming': False, 'sdReady': True, 'error': False, 'ready': True, 'finishing': False, 'closedOrError': False}}, 'currentZ': 0.5, 'job': {'averagePrintTime': 61228.26161313057, 'lastPrintTime': 61228.26161313057, 'user': '_api', 'file': {'origin': 'local', 'name': u'AI3M_ArtifactsInc1cBox.gcode', 'date': 1556109120, 'path': u'AI3M_ArtifactsInc1cBox.gcode', 'display': u'AI3M_ArtifactsInc1cBox.gcode', 'size': 32291300L}, 'estimatedPrintTime': 54541.941707169004, 'filament': {'tool0': {'volume': 0.0, 'length': 54603.04417999999}}}, 'offsets': {'tool0': 5}} 2019-04-25 11:30:26,177 - octoprint.plugins.telegram.TMSG - DEBUG - TEMPS - {'bed': {'actual': 26.4, 'target': 0.0, 'offset': 0}, 'tool0': {'actual': 25.0, 'target': 0.0, 'offset': 0}} 2019-04-25 11:30:26,179 - octoprint.plugins.telegram.TMSG - DEBUG - Sending Notification: Not printing. Bed 26.4/0.0, Extruder 25.0/0.0. 2019-04-25 11:30:26,182 - octoprint.plugins.telegram - DEBUG - Sending a message: Not printing.\nBed 26.4/0.0, Extruder 25.0/0.0. with_image=True chatID= X 2019-04-25 11:30:26,184 - octoprint.plugins.telegram - DEBUG - Snapshot URL: http://127.0.0.1:1111/?action=snapshot 2019-04-25 11:30:26,256 - octoprint.plugins.telegram - DEBUG - data so far: {'disable_web_page_preview': True} 2019-04-25 11:30:26,257 - octoprint.plugins.telegram - DEBUG - Sending with image.. X 2019-04-25 11:30:34,786 - octoprint.plugins.telegram - DEBUG - Sending finished. 200

Hope this helps... so much spam.