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
