def HandleSecondaryServerCon(self, summonConnectUrl, summonMethod): # Run the secondary connection for until the RunFor time limit. Note RunFor will account for user activity. self.Logger.info("Starting a secondary connection to " + str(summonConnectUrl) + " method " + str(summonMethod)) try: # Never allow the lowest latency server to be used for secondary connection, since it won't connect to where it needs to be. serverCon = self.createOctoServerCon( summonConnectUrl, False, False, None, self.SecondaryConnectionRunForTimeSec, summonMethod) serverCon.RunBlocking() except Exception as e: Sentry.Exception("Exception in HandleSecondaryServerCon function.", e) # Since this is a secondary connection, when RunBlocking() returns we want to be done. with self.SecondaryServerConsLock: try: # Check if we already have a secondary connection to this server. if summonConnectUrl in self.SecondaryServerCons: del self.SecondaryServerCons[summonConnectUrl] else: self.Logger.error( "Secondary ended but there's not an ref of it in the map?" ) except Exception as _: Sentry.Exception( "Exception when removing secondary connection from map.", e) self.Logger.info("Secondary connection to " + str(summonConnectUrl) + " has ended")
def RunBlocking(self): # This is the main thread for the entire plugin, and it hosts the primary connection. # This connection should always be active, so we run it in a while loop that never exits and # catch any exceptions that occur. while 1: try: # Create the primary connection. # Allow this connection to use the lowest latency server if possible. serverCon = self.createOctoServerCon( self.Endpoint, True, True, self.StatusChangeHandler, self.PrimaryConnectionRunForTimeSec, SummonMethods.SummonMethods.Unknown) serverCon.RunBlocking() except RuntimeError as e: # From telemetry, we have seen that this error can fire very often for some users when there are too many threads running. # To try to fix this, we will dump the thread info to the log and then fire the exception, so the log message will show up. #msg = str(e) #if "can't start new thread" in msg: ThreadDebug.DoThreadDumpLogout(self.Logger) Sentry.Exception( "RuntimeError in OctoEverywhere's main RunBlocking function.", e) # Sleep for a long time, since this can't be recovered from easily. time.sleep(60 * 60 * 2) except Exception as e: Sentry.Exception( "Exception in OctoEverywhere's main RunBlocking function.", e) # Sleep for just a bit and try again. time.sleep(5)
def CloseAllWebStreamsAndDisable(self): # The streams will remove them selves from the map when they close, so all we need to do is ask them # to close. localWebStreamList = [] with self.ActiveWebStreamsLock: # Close them all. self.Logger.info("Closing all open web stream sockets ("+str(len(self.ActiveWebStreams))+")") # Set the flag to indicate we aren't accepting any more self.IsAcceptingStreams = False # Copy all of the streams locally. # pylint: disable=consider-using-dict-items for streamId in self.ActiveWebStreams: localWebStreamList.append(self.ActiveWebStreams[streamId]) # Try catch all of this so we don't leak exceptions. # Use our local web stream list to tell them all to close. try: for webStream in localWebStreamList: try: webStream.Close() except Exception as e: Sentry.Exception("Exception thrown while closing web streamId", e) except Exception as ex: Sentry.Exception("Exception thrown while closing all web streams.", ex)
def _UpdateCacheThread(self, delayMs): try: # We only need one refresh running at once. with self.Lock: if self.IsRefreshing: self.Logger.info( "Slipstream ignoring refresh request, a refresh is already running." ) return # Important! We must clear this! self.IsRefreshing = True # If we want to delay this update, do that delay now. # This is useful to defer the index refresh until after a portal load, to reduce noise. if delayMs > 0: time.sleep(delayMs / 1000) # Do work self._GetAndProcessIndex() except Exception as e: Sentry.Exception("Slipstream failed to update cache.", e) finally: with self.Lock: # It's important we always clear this flag. self.IsRefreshing = False
def GetEncryptedChallenge(self): try: publicKey = rsa.PublicKey.load_pkcs1(ServerAuthHelper.c_ServerPublicKey) return rsa.encrypt(self.Challenge.encode('utf8'), publicKey) except Exception as e: Sentry.Exception("GetEncryptedChallenge failed.", e) return None
def HandleClientNotification(self, msg): try: # Handles a notification notificationMsg = OctoNotification.OctoNotification() notificationMsg.Init(msg.Context().Bytes, msg.Context().Pos) title = OctoStreamMsgBuilder.BytesToString(notificationMsg.Title()) text = OctoStreamMsgBuilder.BytesToString(notificationMsg.Text()) msgType = notificationMsg.Type() autoHide = notificationMsg.AutoHide() # Validate if title is None or text is None or len(title) == 0 or len(text) == 0: self.Logger.error("Octo notification is missing a title or text.") return # Convert type typeStr = "notice" if msgType == OctoNotificationTypes.OctoNotificationTypes.Success: typeStr = "success" elif msgType == OctoNotificationTypes.OctoNotificationTypes.Info: typeStr = "info" elif msgType == OctoNotificationTypes.OctoNotificationTypes.Error: typeStr = "error" # Send it to the UI self.UiPopupInvoker.ShowUiPopup(title, text, typeStr, autoHide) except Exception as e: Sentry.Exception("Failed to handle octo notification message.", e)
def Disconnect(self): # If we have already gotten the disconnect signal, ignore future requests. # This can happen because disconnecting might case proxy socket errors, for example # if we closed all of the sockets locally and then the server tries to close one. if self.IsDisconnecting is True: self.Logger.info( "Ignoring the session disconnect command because we are already working on it." ) return self.IsDisconnecting = True # Try to close all of the sockets before we disconnect, so we send the messages. # It's important to try catch this logic to ensure we always end up calling close on the current websocket. try: if self.OctoSession: self.OctoSession.CloseAllWebStreamsAndDisable() except Exception as e: Sentry.Exception( "Exception when calling CloseAllWebStreamsAndDisable from Disconnect.", e) # Close the websocket, which will cause the run loop to spin and reconnect. self.Logger.info("OctoServerCon websocket close start") if self.Ws: self.Ws.Close() self.Logger.info("OctoServerCon disconnect complete.")
def UpdateCache(self, delayMs): try: th = threading.Thread(target=self._UpdateCacheThread, args=(delayMs, )) th.start() except Exception as e: Sentry.Exception( "Slipstream failed to start index refresh thread. ", e)
def run(self): try: self.mainThread() except Exception as e: Sentry.Exception( "Exception in web stream [" + str(self.Id) + "] connect loop.", e) traceback.print_exc() self.OctoSession.OnSessionError(0)
def GetPrintTimeRemainingEstimateInSeconds(self): # If the printer object isn't set, we can't get an estimate. if self.OctoPrintPrinterObject is None: return -1 # Try to get the progress object from the current data. This is at least set by things like PrintTimeGenius and is more accurate. try: currentData = self.OctoPrintPrinterObject.get_current_data() if "progress" in currentData: if "printTimeLeft" in currentData["progress"]: # When the print is just starting, the printTimeLeft will be None. printTimeLeftSec = currentData["progress"]["printTimeLeft"] if printTimeLeftSec is not None: printTimeLeft = int( float(currentData["progress"]["printTimeLeft"])) return printTimeLeft except Exception as e: Sentry.Exception( "Failed to find progress object in printer current data.", e) # If that fails, try to use the default OctoPrint estimate. try: jobData = self.OctoPrintPrinterObject.get_current_job() if "estimatedPrintTime" in jobData: # When the print is first starting and there is no known time, this can be none. # In that case, return -1, unknown. if jobData["estimatedPrintTime"] is None: return -1 printTimeEstSec = int(jobData["estimatedPrintTime"]) # Compute how long this print has been running and subtract # Sanity check the duration isn't longer than the ETA. currentDurationSec = int(self._getCurrentDurationSecFloat()) if currentDurationSec > printTimeEstSec: return 0 return printTimeEstSec - currentDurationSec except Exception as e: Sentry.Exception("Failed to find time estimate from OctoPrint. ", e) # We failed. return -1
def _updateToKnownDuration(self, durationSecStr): # If the string is empty return. if len(durationSecStr) == 0: return # If we fail this logic don't kill the event. try: self.CurrentPrintStartTime = time.time() - float(durationSecStr) except Exception as e: Sentry.ExceptionNoSend("_updateToKnownDuration exception", e)
def HandleMessage(self, msgBytes): # Decode the message. msg = None try: msg = self.DecodeOctoStreamMessage(msgBytes) except Exception as e: Sentry.Exception("Failed to decode message local request.", e) self.OnSessionError(0) return # Handle it. try: # If this is a handshake ack, handle it. if msg.ContextType() == MessageContext.MessageContext.HandshakeAck: self.HandleHandshakeAck(msg) return # Handle web stream messages if msg.ContextType() == MessageContext.MessageContext.WebStreamMsg: self.HandleWebStreamMessage(msg) return # Handle notifications if msg.ContextType() == MessageContext.MessageContext.OctoNotification: self.HandleClientNotification(msg) return # Handle summon notifications if msg.ContextType() == MessageContext.MessageContext.OctoSummon: self.HandleSummonRequest(msg) return # We don't know what this is, probably a new message we don't understand. self.Logger.info("Unknown message type received, ignoring.") return except Exception as e: # If anything throws, we consider it a protocol failure. traceback.print_exc() Sentry.Exception("Failed to handle octo message.", e) self.OnSessionError(0) return
def OnFirstRunLatencyDataComplete(self): try: self.Logger.info( "First run latency callback fired, disconnecting primary OctoStream to reconnect to most ideal latency server. Current: " + self.GetConnectionString() + ".") self.NoWaitReconnect = True self.Disconnect() except Exception as e: Sentry.Exception( "Exception in OnFirstRunLatencyDataComplete during disconnect. " + self.GetConnectionString() + ".", e)
def OnRunForTimerCallback(self): if self.IsRunForTimeComplete(): try: self.Logger.info( "Server con " + self.GetConnectionString() + " RunFor is complete and will be disconnected.") self.Disconnect() except Exception as e: Sentry.Exception( "Exception in OnRunForTimerCallback during disconnect. " + self.GetConnectionString() + ".", e)
def run(self): # Loop while the event isn't set and the thread is still alive. while not self.stopEvent.wait( self.intervalSec) and self.is_alive() and self.running: try: # Ensure we don't fire the callback if we were asked not to. if self.running is not True: return self.callback() except Exception as e: Sentry.Exception("Exception in RepeatTimer thread.", e) self.logger.info("RepeatTimer thread exit")
def HandleSummonRequest(self, msg): try: summonMsg = OctoSummon.OctoSummon() summonMsg.Init(msg.Context().Bytes, msg.Context().Pos) serverConnectUrl = OctoStreamMsgBuilder.BytesToString(summonMsg.ServerConnectUrl()) summonMethod = summonMsg.SummonMethod() if serverConnectUrl is None or len(serverConnectUrl) == 0: self.Logger.error("Summon notification is missing a server url.") return # Process it! self.OctoStream.OnSummonRequest(self.SessionId, serverConnectUrl, summonMethod) except Exception as e: Sentry.Exception("Failed to handle summon request ", e)
def OnMsg(self, ws, msg): # When we get any message, consider it user activity. self.LastUserActivityTime = datetime.now() if self.OctoSession: # Grab the session id now, since it can change by the time this call is done. # For example, if this call creates an error that ends up shutting down the ws. localSessionId = self.ActiveSessionId try: self.OctoSession.HandleMessage(msg) except Exception as e: Sentry.Exception( "Exception in OctoSession.HandleMessage " + self.GetConnectionString() + ".", e) self.OnSessionError(localSessionId, 0)
def Close(self): # Check the state and set the flag. Only allow this code to run # once. localHttpHelper = None localWsHelper = None with self.StateLock: # If we are already closed, there's nothing to do. if self.IsClosed is True: return # We will close now, so set the flag. self.IsClosed = True # While under lock, exists, and if so, has it been closed. # Note it's possible that this helper is being crated on a different # thread and will be set just after we exit the lock. In that case # the creator logic will notice that the stream is closed and call close on it. # So if the http helper doesn't exist yet, we can't set the isClosed flag to false. if self.HttpHelper is not None or self.WsHelper is not None: if self.IsHelperClosed is False: self.IsHelperClosed = True localHttpHelper = self.HttpHelper localWsHelper = self.WsHelper # Remove ourselves from the session map self.OctoSession.WebStreamClosed(self.Id) # Put an empty message on the queue to wake it up to exit. self.MsgQueue.put(None) # Ensure we have sent the close message self.ensureCloseMessageSent() # If this was high pri, clear the state if self.IsHighPriStream: self.highPriStreamEnded() # If we got a ref to the helper, we need to call close on it. try: if localHttpHelper is not None: localHttpHelper.Close() if localWsHelper is not None: localWsHelper.Close() except Exception as e: Sentry.Exception( "Web stream " + str(self.Id) + " helper threw an exception during close", e)
def GetLowestLatencyServerSub(self): # Do this in a thread safe way, if we fail, just return None. try: stats = self.Stats if stats is None: return None if OctoPingPong.LowestLatencyServerSubKey not in stats: return None lowestLatencyServerSub = stats[OctoPingPong.LowestLatencyServerSubKey] if lowestLatencyServerSub is None: return None if self.IsDisablePrimaryOverride: self.Logger.info("OctoPingPong IsDisablePrimaryOverride - not returning lowest latency server sub: "+lowestLatencyServerSub) return None return lowestLatencyServerSub except Exception as e: Sentry.Exception("Exception in OctoPingPong GetLowestLatencyServerSub.", e) return None
def GetCurrentZOffset(self): if self.OctoPrintPrinterObject is None: return -1 # Try to get the current value from the data. try: # We have seen in client logs sometimes this value doesn't exist, # and sometime it does, but it's just None. currentData = self.OctoPrintPrinterObject.get_current_data() if "currentZ" in currentData and currentData[ "currentZ"] is not None: currentZ = float(currentData["currentZ"]) return currentZ except Exception as e: Sentry.Exception("Failed to find current z offset.", e) # Failed to find it. return -1
def SendToOctoStream(self, buffer, isCloseFlagSet=False, silentlyFail=False): # Make sure we aren't closed. If we are, don't allow the message to be sent. with self.StateLock: if self.IsClosed is True: # The only reason we are allowed to send after a close is if we are sending the # close flag message. if isCloseFlagSet is False: self.Logger.info("Web Stream " + str(self.Id) + " tried to send a message after close.") return else: # We can only send one close flag, so only allow this to send if we haven't sent yet. if self.HasSentCloseMessage: if silentlyFail is False: self.Logger.warn( "Web Stream " + str(self.Id) + " tried to send a close message after a close message was already sent" ) return # No matter what, if the close flag is set, set the has sent now. if isCloseFlagSet: self.HasSentCloseMessage = True # Send now try: self.OctoSession.Send(buffer) except Exception as e: Sentry.Exception( "Web stream " + str(self.Id) + " failed to send a message to the OctoStream.", e) # If this was the close message, set the has set flag back to false so we send again. # (this mostly won't matter, since the entire connection will go down anyways) self.HasSentCloseMessage = False # If we fail, close the entire connection. self.OctoSession.OnSessionError(0) # Return since things are going down. return
def _WorkerThread(self): oneHourOfSeconds = 60 * 60 while True: try: # Compute how long it's been since the last update. # Since this is written to disk, it's stays across boots / restarts. lastWorkTime = 0 if OctoPingPong.LastWorkTimeKey in self.Stats: lastWorkTime = int(self.Stats[OctoPingPong.LastWorkTimeKey]) secondsSinceLastWork = time.time() - lastWorkTime # Compute how long until we should do work, this will be negative if the time has passed. timeUntilNextWorkSec = (oneHourOfSeconds * 30) - secondsSinceLastWork # If lastWorkTime is 0, the file was just created, so this is the first time the plugin has ran. if lastWorkTime == 0: self.Logger.info("PingPong has detected a first time run. Updating latency stats now.") timeUntilNextWorkSec = 0 # Since the first run will be a little after OctoPrint or device boot, we need to wait a bit before for things to settle. # For reference, it takes slipstream about 20 seconds to get the full index cache after OctoPrint boot. time.sleep(30) # If it's not time to work, sleep until it is time. if timeUntilNextWorkSec > 0: time.sleep(timeUntilNextWorkSec) # It's time to work, first update the time we are working is now. # Also write to disk to ensure it's known and we don't get in a tight loop of working. self.Stats[OctoPingPong.LastWorkTimeKey] = time.time() self._SaveStatsToFile() # Update now self._UpdateStats() # Only for the very first time this runs after the plugin is installed, fire this callback # which might reconnect the main OctoSocket connection to the best possible server. if lastWorkTime == 0 and self.GetLowestLatencyServerSub() is not None: callback = self.PluginFirstRunLatencyCompleteCallback if callback is not None: self.PluginFirstRunLatencyCompleteCallback() except Exception as e: Sentry.Exception("Exception in OctoPingPong thread.", e)
def ensureCloseMessageSent(self): # Since the send function does the checking to ensure only one close message # gets sent, we will always try to create and send a message. try: builder = OctoStreamMsgBuilder.CreateBuffer(200) WebStreamMsg.Start(builder) WebStreamMsg.AddStreamId(builder, self.Id) WebStreamMsg.AddIsControlFlagsOnly(builder, True) WebStreamMsg.AddIsCloseMsg(builder, True) webStreamMsgOffset = WebStreamMsg.End(builder) outputBuf = OctoStreamMsgBuilder.CreateOctoStreamMsgAndFinalize( builder, MessageContext.MessageContext.WebStreamMsg, webStreamMsgOffset) # Set the flag to silently fail, since the message might have already been sent by the helper. self.SendToOctoStream(outputBuf, True, True) except Exception as e: # This is bad, log it and kill the stream. Sentry.Exception( "Exception thrown while trying to send close message for web stream " + str(self.Id), e) self.OctoSession.OnSessionError(0)
def StartHandshake(self, summonMethod): # Send the handshakesyn try: # Get our unique challenge rasChallenge = self.ServerAuth.GetEncryptedChallenge() if rasChallenge is None: raise Exception("Rsa challenge generation failed.") rasChallengeKeyVerInt = ServerAuthHelper.c_ServerAuthKeyVersion # Build the message buf = OctoStreamMsgBuilder.BuildHandshakeSyn(self.PrinterId, self.PrivateKey, self.isPrimarySession, self.PluginVersion, OctoHttpRequest.GetLocalHttpProxyPort(), LocalIpHelper.TryToGetLocalIp(), rasChallenge, rasChallengeKeyVerInt, SnapshotHelper.Get().GetWebcamFlipH(), SnapshotHelper.Get().GetWebcamFlipV(), SnapshotHelper.Get().GetWebcamRotate90(), summonMethod) # Send! self.OctoStream.SendMsg(buf) except Exception as e: Sentry.Exception("Failed to send handshake syn.", e) self.OnSessionError(0) return
def _getCurrentProgressFloat(self): # OctoPrint updates us with a progress int, but it turns out that's not the same progress as shown in the web UI. # The web UI computes the progress % based on the total print time and ETA. Thus for our notifications to have accurate %s that match # the web UIs, we will also try to do the same. try: # Try to get the print time remaining, which will use smart ETA plugins if possible. ptrSec = self.GetPrintTimeRemainingEstimateInSeconds() # If we can't get the ETA, default to OctoPrint's value. if ptrSec == -1: return float(self.OctoPrintReportedProgressInt) # Compute the total print time (estimated) and the time thus far currentDurationSecFloat = self._getCurrentDurationSecFloat() totalPrintTimeSec = currentDurationSecFloat + ptrSec # Sanity check for / 0 if totalPrintTimeSec == 0: return float(self.OctoPrintReportedProgressInt) # Compute the progress printProgressFloat = float(currentDurationSecFloat) / float( totalPrintTimeSec) * float(100.0) # Bounds check printProgressFloat = max(printProgressFloat, 0.0) printProgressFloat = min(printProgressFloat, 100.0) # Return the computed value. return printProgressFloat except Exception as e: Sentry.ExceptionNoSend( "_getCurrentProgressFloat failed to compute progress.", e) # On failure, default to what OctoPrint has reported. return float(self.OctoPrintReportedProgressInt)
def __init__(self, logger, pluginDataFolderPath, printerId): self.Logger = logger self.PrinterId = printerId self.StatsFilePath = os.path.join(pluginDataFolderPath, "PingPongDataV2.json") self.PluginFirstRunLatencyCompleteCallback = None self.IsDisablePrimaryOverride = False # Try to load past stats from the file. self.Stats = None self._LoadStatsFromFile() # If failed, just make a new stats obj. if self.Stats is None: self._ResetStats() # Start a new thread to do the occasional work. try: th = threading.Thread(target=self._WorkerThread) # pylint: disable=deprecated-method # This is deprecated in PY3.10 th.setDaemon(True) th.start() except Exception as e: Sentry.Exception("Failed to start OctoPingPong Thread.", e)
def onWsData(self, ws, buffer, msgType): # Only handle callbacks for the current websocket. if self.Ws is not None and self.Ws != ws: return try: # Figure out the data type # TODO - we should support the OPCODE_CONT type at some point. But it's not needed right now. sendType = WebSocketDataTypes.WebSocketDataTypes.None_ if msgType == websocket.ABNF.OPCODE_BINARY: sendType = WebSocketDataTypes.WebSocketDataTypes.Binary elif msgType == websocket.ABNF.OPCODE_TEXT: sendType = WebSocketDataTypes.WebSocketDataTypes.Text # If the buffer is text, we need to encode it as bytes. buffer = buffer.encode() else: raise Exception( "Web stream ws helper got a message type that's not supported. " + str(msgType)) # Some messages are large, so compression helps. # We also don't consider the message type, since binary messages can very easily be # text as well, and the cost of compression in terms of CPU is low. usingCompression = len(buffer) > 200 originalDataSize = 0 if usingCompression: # See notes about the quality and such in the readContentFromBodyAndMakeDataVector. originalDataSize = len(buffer) buffer = zlib.compress(buffer, 3) # Send the message along! builder = OctoStreamMsgBuilder.CreateBuffer(len(buffer) + 200) # Note its ok to have an empty buffer, we still want to send the ping. dataOffset = None if len(buffer) > 0: dataOffset = builder.CreateByteVector(buffer) # Setup the message to send. WebStreamMsg.Start(builder) WebStreamMsg.AddStreamId(builder, self.Id) WebStreamMsg.AddIsControlFlagsOnly(builder, False) WebStreamMsg.AddWebsocketDataType(builder, sendType) if usingCompression: WebStreamMsg.AddDataCompression( builder, DataCompression.DataCompression.Zlib) WebStreamMsg.AddOriginalDataSize(builder, originalDataSize) if dataOffset is not None: WebStreamMsg.AddData(builder, dataOffset) webStreamMsgOffset = WebStreamMsg.End(builder) outputBuf = OctoStreamMsgBuilder.CreateOctoStreamMsgAndFinalize( builder, MessageContext.MessageContext.WebStreamMsg, webStreamMsgOffset) # Send it! self.WebStream.SendToOctoStream(outputBuf) except Exception as e: Sentry.Exception( self.getLogMsgPrefix() + " got an error while trying to forward websocket data to the service.", e) self.WebStream.Close()
def _sendEventThreadWorker(self, event, args=None, progressOverwriteFloat=None): try: # For notifications, if possible, we try to resize any image to be less than 720p. # This scale will preserve the aspect ratio and won't happen if the image is already less than 720p. # The scale might also fail if the image lib can't be loaded correctly. snapshotResizeParams = SnapshotResizeParams( 1080, True, False, False) # Build the common even args. requestArgs = self.BuildCommonEventArgs(event, args, progressOverwriteFloat, snapshotResizeParams) # Handle the result indicating we don't have the proper var to send yet. if requestArgs is None: self.Logger.info( "NotificationsHandler didn't send the " + str(event) + " event because we don't have the proper id and key yet.") return False # Break out the response args = requestArgs[0] files = requestArgs[1] # Setup the url eventApiUrl = self.ProtocolAndDomain + "/api/printernotifications/printerevent" # Attempt to send the notification twice. If the first time fails, # we will wait a bit and try again. It's really unlikely for a notification to fail, the biggest reason # would be if the server is updating, there can be a ~20 second window where the call might fail attempts = 0 while attempts < 2: attempts += 1 # Make the request. r = None try: # Since we are sending the snapshot, we must send a multipart form. # Thus we must use the data and files fields, the json field will not work. r = requests.post(eventApiUrl, data=args, files=files) # Check for success. if r.status_code == 200: self.Logger.info( "NotificationsHandler successfully sent '" + event + "'") return True except Exception as e: # We must try catch the connection because sometimes it will throw for some connection issues, like DNS errors. self.Logger.warn( "Failed to send notification due to a connection error, trying again. " + str(e)) # On failure, log the issue. self.Logger.error( "NotificationsHandler failed to send event " + str(event) + ". Code:" + str(r.status_code) + "; Body:" + r.content.decode()) # If the error is in the 400 class, don't retry since these are all indications there's something # wrong with the request, which won't change. if r.status_code < 500: return False # If the error is a 500 error, we will try again. Sleep for about 30 seconds to give the server time # to boot and be ready again. We would rather wait too long but succeeded, rather than not wait long # enough and fail again. time.sleep(30) except Exception as e: Sentry.Exception( "NotificationsHandler failed to send event code " + str(event), e) return False
def _timerCallback(self): try: # Before we do anything, update the timer interval to the default, incase there's some error # and we don't update it properly. In all cases either an error should update this or the response # from the inspect call. lastIntervalSec = self._getTimerInterval() self._updateTimerInterval(Gadget.c_defaultIntervalSec) # Check to ensure we should still be running. If the state is anything other than printing, we shouldn't be running # We will be restarted on a new print starting or when resume is called. if self.NotificationHandler.ShouldPrintingTimersBeRunning() is False: self.Logger.warn("Gadget timer is running but the print state is not printing, so the timer is topping.") self.StopWatching() return # If we have any resize args set by the server, apply them now. # Remember these are best effort, so they might not be applied to the output image. # These values must be greater than 1 or the SnapshotResizeParams can't take them. snapshotResizeParams = None if self.ImageScaleCenterCropSize > 1: # If this is set, it takes priority over any other options. # Request a center crop square of the image scaled to the desired factor. snapshotResizeParams = SnapshotResizeParams(self.ImageScaleCenterCropSize, False, False, True) elif self.ImageScaleMaxHeight > 1: # Request a max height of the desired size. If the image is smaller than this it will be ignored. snapshotResizeParams = SnapshotResizeParams(self.ImageScaleMaxHeight, True, False, False) # Now, get the common event args, which will include the snapshot. requestData = self.NotificationHandler.BuildCommonEventArgs("inspect", None, None, snapshotResizeParams) # Handle the result indicating we don't have the proper var to send yet. if requestData is None: self.Logger.info("Gadget didn't send because we don't have the proper id and key yet.") self._updateTimerInterval(Gadget.c_defaultIntervalSec) return # Break out the args args = requestData[0] files = requestData[1] # Add the last interval, so the server knows args["LastIntervalSec"] = lastIntervalSec # Next, check if there's a valid snapshot image. if len(files) == 0: # If not, update our interval to be the default no snapshot interval and return. self._updateTimerInterval(Gadget.c_defaultIntervalSec_NoSnapshot) return jsonResponse = None try: # Setup the url. gadgetApiUrl = self.ProtocolAndDomain + "/api/gadget/inspect" # Since we are sending the snapshot, we must send a multipart form. # Thus we must use the data and files fields, the json field will not work. r = requests.post(gadgetApiUrl, data=args, files=files) # Check for success. Anything but a 200 we will consider a connection failure. if r.status_code != 200: raise Exception("Bad response code "+str(r.status_code)) # Get the response jsonResponse = r.json() if jsonResponse is None: raise Exception("No json response found.") except Exception as e: # For any connection based error, either we fail to connect or we get back not a 200, # We will handle it with out logging too much. This can happen if we need to load shed, so we # dont need to log about it much. if self.FailedConnectionAttempts % 20 == 0: self.Logger.info("Failed to send gadget inspection due to a connection error. "+str(e)) self.FailedConnectionAttempts += 1 # Update our timer interval for the failure and return. # We back off the retry time so we can make a few faster attempts, but then fall back to longer term attempts. # Also add some random-ness to the retry, to prevent all clients coming back at once. nextIntervalSec = max(1, min(self.FailedConnectionAttempts, 10)) * Gadget.c_defaultIntervalSec_ConnectionErrorBackoffBase nextIntervalSec += random.randint(10, 30) self._updateTimerInterval(nextIntervalSec) return # Handle the json response. We should find an int telling us how long we should wait before sending the next # inspection report. if "Result" not in jsonResponse: self.Logger.warn("Gadget inspection result had no Result object") self._updateTimerInterval(Gadget.c_defaultIntervalSec) return resultObj = jsonResponse["Result"] if "NextInspectIntervalSec" not in resultObj: self.Logger.warn("Gadget inspection result had no NextInspectIntervalSec field") self._updateTimerInterval(Gadget.c_defaultIntervalSec) return # Update the next interval time according to what gadget is requesting. nextIntervalSec = int(resultObj["NextInspectIntervalSec"]) self._updateTimerInterval(nextIntervalSec) # Parse the optional image resizing params. If these fail to parse, just default them. if "IS_CCSize" in resultObj: try: newValue = int(resultObj["IS_CCSize"]) if newValue != self.ImageScaleCenterCropSize: self.Logger.info("Gadget ImageScaleCenterCropSize set to: "+str(newValue)) self.ImageScaleCenterCropSize = newValue except Exception as e: self.Logger.warn("Gadget failed to parse IS_CCSize from response. "+str(e)) self.ImageScaleCenterCropSize = 0 if "IS_MH" in resultObj: try: newValue = int(resultObj["IS_MH"]) if newValue != self.ImageScaleMaxHeight: self.Logger.info("Gadget ImageScaleMaxHeight set to: "+str(newValue)) self.ImageScaleMaxHeight = newValue except Exception as e: self.Logger.warn("Gadget failed to parse IS_MH from response."+str(e)) self.ImageScaleMaxHeight = 0 # Check if we have a log object in response. If so, the server wants us to log information into the local log file. if "Log" in resultObj and resultObj["Log"] is not None: try: # Stringify the object sent back from the server. logStr = json.dumps(resultObj["Log"]) self.Logger.info("Gadget Server Log: "+str(self.NotificationHandler.GetPrintId())+" "+str(nextIntervalSec)+" - "+logStr) except Exception as e: self.Logger.warn("Gadget failed to parse Log from response."+str(e)) # Reset the failed attempts counter self.FailedConnectionAttempts = 0 except Exception as e: Sentry.Exception("Exception in gadget timer", e)
def getSnapshot(self, snapshotResizeParams=None): try: # Use the snapshot helper to get the snapshot. This will handle advance logic like relative and absolute URLs # as well as getting a snapshot directly from a mjpeg stream if there's no snapshot URL. octoHttpResponse = SnapshotHelper.Get().GetSnapshot() # Check for a valid response. if octoHttpResponse is None or octoHttpResponse.Result is None or octoHttpResponse.Result.status_code != 200: return None # There are two options here for a result buffer, either # 1) it will be already read for us # 2) we need to read it out of the http response. snapshot = None if octoHttpResponse.FullBodyBuffer is not None: snapshot = octoHttpResponse.FullBodyBuffer else: # Since we use Stream=True, we have to wait for the full body to download before getting it snapshot = RequestsUtils.ReadAllContentFromStreamResponse( octoHttpResponse.Result) if snapshot is None: self.Logger.error( "Notification snapshot failed, snapshot is None") return None # Ensure the snapshot is a reasonable size. If it's not, try to resize it if there's not another resize planned. # If this fails, the size will be checked again later and the image will be thrown out. if len(snapshot) > NotificationsHandler.MaxSnapshotFileSizeBytes: if snapshotResizeParams is None: # Try to limit the size to be 1080 tall. snapshotResizeParams = SnapshotResizeParams( 1080, True, False, False) # Manipulate the image if needed. flipH = SnapshotHelper.Get().GetWebcamFlipH() flipV = SnapshotHelper.Get().GetWebcamFlipV() rotate90 = SnapshotHelper.Get().GetWebcamRotate90() if rotate90 or flipH or flipV or snapshotResizeParams is not None: try: if Image is not None: # We noticed that on some under powered or otherwise bad systems the image returned # by mjpeg is truncated. We aren't sure why this happens, but setting this flag allows us to sill # manipulate the image even though we didn't get the whole thing. Otherwise, we would use the raw snapshot # buffer, which is still an incomplete image. # Use a try catch incase the import of ImageFile failed try: ImageFile.LOAD_TRUNCATED_IMAGES = True except Exception as _: pass # Update the image # Note the order of the flips and the rotates are important! # If they are reordered, when multiple are applied the result will not be correct. didWork = False pilImage = Image.open(io.BytesIO(snapshot)) if flipH: pilImage = pilImage.transpose( Image.FLIP_LEFT_RIGHT) didWork = True if flipV: pilImage = pilImage.transpose( Image.FLIP_TOP_BOTTOM) didWork = True if rotate90: pilImage = pilImage.rotate(90) didWork = True # # Now apply any resize operations needed. # if snapshotResizeParams is not None: # First, if we want to scale and crop to center, we will use the resize operation to get the image # scale (preserving the aspect ratio). We will use the smallest side to scale to the desired outcome. if snapshotResizeParams.CropSquareCenterNoPadding: # We will only do the crop resize if the source image is smaller than or equal to the desired size. if pilImage.height >= snapshotResizeParams.Size and pilImage.width >= snapshotResizeParams.Size: if pilImage.height < pilImage.width: snapshotResizeParams.ResizeToHeight = True snapshotResizeParams.ResizeToWidth = False else: snapshotResizeParams.ResizeToHeight = False snapshotResizeParams.ResizeToWidth = True # Do any resizing required. resizeHeight = None resizeWidth = None if snapshotResizeParams.ResizeToHeight: if pilImage.height > snapshotResizeParams.Size: resizeHeight = snapshotResizeParams.Size resizeWidth = int( (float(snapshotResizeParams.Size) / float(pilImage.height)) * float(pilImage.width)) if snapshotResizeParams.ResizeToWidth: if pilImage.width > snapshotResizeParams.Size: resizeHeight = int( (float(snapshotResizeParams.Size) / float(pilImage.width)) * float(pilImage.height)) resizeWidth = snapshotResizeParams.Size # If we have things to resize, do it. if resizeHeight is not None and resizeWidth is not None: pilImage = pilImage.resize( (resizeWidth, resizeHeight)) didWork = True # Now if we want to crop square, use the resized image to crop the remaining side. if snapshotResizeParams.CropSquareCenterNoPadding: left = 0 upper = 0 right = 0 lower = 0 if snapshotResizeParams.ResizeToHeight: # Crop the width - use floor to ensure if there's a remainder we float left. centerX = math.floor( float(pilImage.width) / 2.0) halfWidth = math.floor( float(snapshotResizeParams.Size) / 2.0) upper = 0 lower = snapshotResizeParams.Size left = centerX - halfWidth right = (snapshotResizeParams.Size - halfWidth) + centerX else: # Crop the height - use floor to ensure if there's a remainder we float left. centerY = math.floor( float(pilImage.height) / 2.0) halfHeight = math.floor( float(snapshotResizeParams.Size) / 2.0) upper = centerY - halfHeight lower = (snapshotResizeParams.Size - halfHeight) + centerY left = 0 right = snapshotResizeParams.Size # Sanity check bounds if left < 0 or left > right or right > pilImage.width or upper > 0 or upper > lower or lower > pilImage.height: self.Logger.error( "Failed to crop image. height: " + str(pilImage.height) + ", width: " + str(pilImage.width) + ", size: " + str(snapshotResizeParams.Size)) else: pilImage = pilImage.crop( (left, upper, right, lower)) didWork = True # # If we did some operation, save the image buffer back to a jpeg and overwrite the # current snapshot buffer. If we didn't do work, keep the original, to preserve quality. # if didWork: buffer = io.BytesIO() pilImage.save(buffer, format="JPEG", quality=95) snapshot = buffer.getvalue() buffer.close() else: self.Logger.warn( "Can't manipulate image because the Image rotation lib failed to import." ) except Exception as ex: # Note that in the case of an exception we don't overwrite the original snapshot buffer, so something can still be sent. Sentry.ExceptionNoSend( "Failed to manipulate image for notifications", ex) # Ensure in the end, the snapshot is a reasonable size. if len(snapshot) > NotificationsHandler.MaxSnapshotFileSizeBytes: self.Logger.error( "Snapshot size if too large to send. Size: " + len(snapshot)) return None # Return the image return snapshot except Exception as _: # Don't log here, because for those users with no webcam setup this will fail often. # TODO - Ideally we would log, but filter out the expected errors when snapshots are setup by the user. #self.Logger.info("Snapshot http call failed. " + str(e)) pass # On failure return nothing. return None