Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rework logging #300

Draft
wants to merge 2 commits into
base: master
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 5 additions & 5 deletions tinytuya/BulbDevice.py
Original file line number Diff line number Diff line change
Expand Up @@ -242,7 +242,7 @@ def set_version(self, version): # pylint: disable=W0621
else:
# response has no dps
self.bulb_type = "B"
log.debug("bulb type set to %s", self.bulb_type)
self.log.debug("bulb type set to %s", self.bulb_type)

def turn_on(self, switch=0, nowait=False):
"""Turn the device on"""
Expand Down Expand Up @@ -312,7 +312,7 @@ def set_colour(self, r, g, b, nowait=False):
nowait(bool): True to send without waiting for response.
"""
if not self.has_colour:
log.debug("set_colour: Device does not appear to support color.")
self.log.debug("set_colour: Device does not appear to support color.")
# return error_json(ERR_FUNCTION, "set_colour: Device does not support color.")
if not 0 <= r <= 255:
return error_json(
Expand Down Expand Up @@ -353,7 +353,7 @@ def set_hsv(self, h, s, v, nowait=False):
nowait(bool): True to send without waiting for response.
"""
if not self.has_colour:
log.debug("set_hsv: Device does not appear to support color.")
self.log.debug("set_hsv: Device does not appear to support color.")
# return error_json(ERR_FUNCTION, "set_hsv: Device does not support color.")
if not 0 <= h <= 1.0:
return error_json(
Expand Down Expand Up @@ -519,7 +519,7 @@ def set_brightness(self, brightness, nowait=False):
if state["mode"] == "white":
# for white mode use DPS for brightness
if not self.has_brightness:
log.debug("set_brightness: Device does not appear to support brightness.")
self.log.debug("set_brightness: Device does not appear to support brightness.")
# return error_json(ERR_FUNCTION, "set_brightness: Device does not support brightness.")
payload = self.generate_payload(
CONTROL, {self.DPS_INDEX_BRIGHTNESS[self.bulb_type]: brightness}
Expand Down Expand Up @@ -569,7 +569,7 @@ def set_colourtemp(self, colourtemp, nowait=False):
nowait(bool): True to send without waiting for response.
"""
if not self.has_colourtemp:
log.debug("set_colourtemp: Device does not appear to support colortemp.")
self.log.debug("set_colourtemp: Device does not appear to support colortemp.")
# return error_json(ERR_FUNCTION, "set_colourtemp: Device does not support colortemp.")
if self.bulb_type == "A" and not 0 <= colourtemp <= 255:
return error_json(
Expand Down
31 changes: 16 additions & 15 deletions tinytuya/Cloud.py
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,7 @@ def __init__(self, apiRegion=None, apiKey=None, apiSecret=None, apiDeviceID=None
self.new_sign_algorithm = new_sign_algorithm
self.server_time_offset = 0
self.use_old_device_list = False
self.log = log.getChild('Cloud')

if (not apiKey) or (not apiSecret):
try:
Expand Down Expand Up @@ -205,24 +206,24 @@ def _tuyaplatform(self, uri, action='GET', post=None, ver='v1.0', recursive=Fals
# Send Request to Cloud and Get Response
if action == 'GET':
response = requests.get(url, headers=headers)
log.debug(
self.log.debug(
"GET: URL=%s HEADERS=%s response code=%d text=%s token=%s", url, headers, response.status_code, response.text, self.token
)
else:
log.debug(
self.log.debug(
"POST: URL=%s HEADERS=%s DATA=%s", url, headers, body,
)
response = requests.post(url, headers=headers, data=body)

# Check to see if token is expired
if "token invalid" in response.text:
if recursive is True:
log.debug("Failed 2nd attempt to renew token - Aborting")
self.log.debug("Failed 2nd attempt to renew token - Aborting")
return None
log.debug("Token Expired - Try to renew")
self.log.debug("Token Expired - Try to renew")
self._gettoken()
if not self.token:
log.debug("Failed to renew token")
self.log.debug("Failed to renew token")
return None
else:
return self._tuyaplatform(uri, action, post, ver, True)
Expand Down Expand Up @@ -258,7 +259,7 @@ def _gettoken(self):
# round it to 2 minutes to try and factor out any processing delays
self.server_time_offset = round( ((response_dict['t'] / 1000.0) - time.time()) / 120 )
self.server_time_offset *= 120
log.debug("server_time_offset: %r", self.server_time_offset)
self.log.debug("server_time_offset: %r", self.server_time_offset)

self.token = response_dict['result']['access_token']
return self.token
Expand All @@ -280,7 +281,7 @@ def _getuid(self, deviceid=None):
response_dict['code'] = -1
if 'msg' not in response_dict:
response_dict['msg'] = 'Unknown Error'
log.debug(
self.log.debug(
"Error from Tuya Cloud: %r", response_dict['msg'],
)
return error_json(
Expand Down Expand Up @@ -322,10 +323,10 @@ def _get_all_devices(self):
has_more = False

if type(result) == dict:
log.debug( 'Cloud response:' )
log.debug( json.dumps( result, indent=2 ) )
self.log.debug( 'Cloud response:' )
self.log.debug( json.dumps( result, indent=2 ) )
else:
log.debug( 'Cloud response: %r', result )
self.log.debug( 'Cloud response: %r', result )

# format it the same as before, basically just moves result->devices into result
for i in result:
Expand Down Expand Up @@ -381,7 +382,7 @@ def _get_hw_addresses( self, maclist, devices ):
# returns id, mac, uuid (and sn if available)
uri = 'devices/factory-infos?device_ids=%s' % (",".join(devices[:50]))
result = self._tuyaplatform(uri)
log.debug( json.dumps( result, indent=2 ) )
self.log.debug( json.dumps( result, indent=2 ) )
if 'result' in result:
for dev in result['result']:
if 'id' in dev:
Expand Down Expand Up @@ -438,7 +439,7 @@ def _getdevice(self, param='status', deviceid=None):
response_dict = self._tuyaplatform(uri)

if not response_dict['success']:
log.debug(
self.log.debug(
"Error from Tuya Cloud: %r", response_dict['msg'],
)
return response_dict
Expand Down Expand Up @@ -476,7 +477,7 @@ def getdps(self, deviceid=None):
response_dict = self._tuyaplatform(uri, ver='v1.1')

if not response_dict['success']:
log.debug(
self.log.debug(
"Error from Tuya Cloud: %r", response_dict['msg'],
)
return response_dict
Expand All @@ -496,7 +497,7 @@ def sendcommand(self, deviceid=None, commands=None):
response_dict = self._tuyaplatform(uri,action='POST',post=commands)

if not response_dict['success']:
log.debug(
self.log.debug(
"Error from Tuya Cloud: %r", response_dict['msg'],
)
return response_dict
Expand All @@ -516,7 +517,7 @@ def getconnectstatus(self, deviceid=None):
response_dict = self._tuyaplatform(uri, ver='v1.0')

if not response_dict['success']:
log.debug("Error from Tuya Cloud: %r", response_dict['msg'])
self.log.debug("Error from Tuya Cloud: %r", response_dict['msg'])
return(response_dict["result"]["online"])

def getdevicelog(self, deviceid=None, start=None, end=None, evtype=None, size=0, max_fetches=50, start_row_key=None, params=None):
Expand Down
38 changes: 20 additions & 18 deletions tinytuya/Contrib/IRRemoteControlDevice.py
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,8 @@

from ..core import Device, log, CONTROL

classlog = log.getChild('IRRemoteControlDevice')

class IRRemoteControlDevice(Device):
CMD_SEND_KEY_CODE = "send_ir" # Command to start sending a key
DP_SEND_IR = "201" # ir_send, send and report (read-write)
Expand Down Expand Up @@ -188,17 +190,17 @@ def detect_control_type( self ):
if status and 'dps' in status:
# original devices using DPS 201/202
if self.DP_SEND_IR in status['dps']:
log.debug( 'Detected control type 1' )
self.log.debug( 'Detected control type 1' )
self.control_type = 1
break
# newer devices using DPS 1-13
elif self.DP_MODE in status['dps']:
log.debug( 'Detected control type 2' )
self.log.debug( 'Detected control type 2' )
self.control_type = 2
break
status = self._send_receive(None)
if not self.control_type:
log.warning( 'Detect control type failed! control_type= must be set manually' )
self.log.warning( 'Detect control type failed! control_type= must be set manually' )
elif status:
# try and make sure no data is waiting to be read
status = self._send_receive(None)
Expand Down Expand Up @@ -245,7 +247,7 @@ def study_end( self ):
self.send_command( 'study_exit' )

def receive_button( self, timeout=30 ):
log.debug("Receiving button")
self.log.debug("Receiving button")
# Exit study mode in case it's enabled
self.study_end()
# Enable study mode
Expand All @@ -264,14 +266,14 @@ def receive_button( self, timeout=30 ):
if timeo < 1: timeo = 1
self.set_socketTimeout(timeo)

log.debug("Waiting for button...")
self.log.debug("Waiting for button...")
response = self._send_receive(None)
if response == None:
# Nothing received
log.debug("Timeout")
self.log.debug("Timeout")
elif type(response) != dict or "dps" not in response:
# Some unexpected result
log.debug("Unexpected response: %r", response)
self.log.debug("Unexpected response: %r", response)
response_code = response # Some error message? Pass it.
break
elif self.DP_LEARNED_ID in response["dps"]:
Expand All @@ -285,7 +287,7 @@ def receive_button( self, timeout=30 ):
break
else:
# Unknown DPS
log.debug("Unknown DPS in response: %r", response)
self.log.debug("Unknown DPS in response: %r", response)
response_code = response # Pass it if we do not get a response we like
# try again
finally:
Expand All @@ -301,12 +303,12 @@ def receive_button( self, timeout=30 ):
return response_code

def send_button( self, base64_code ):
log.debug( 'Sending Learned Button: ' + base64_code)
self.log.debug( 'Sending Learned Button: ' + base64_code)
self.print_pulses( base64_code )
return self.send_command( 'send', {'base64_code': base64_code} )

def send_key( self, head, key ):
log.debug( 'Sending Key: %r / %r', head, key )
self.log.debug( 'Sending Key: %r / %r', head, key )
return self.send_command( 'send', { 'head': head, 'key': key } )

@staticmethod
Expand Down Expand Up @@ -346,8 +348,8 @@ def print_pulses( base64_code, use_log=None ):
else:
pulses = IRRemoteControlDevice.base64_to_pulses(base64_code)
message = "Pulses and gaps (microseconds): " + ' '.join([f'{"p" if i % 2 == 0 else "g"}{pulses[i]}' for i in range(len(pulses))])
if log.getEffectiveLevel() <= logging.DEBUG:
log.debug( message )
if classlog.getEffectiveLevel() <= logging.DEBUG:
classlog.debug( message )
return message

@staticmethod
Expand Down Expand Up @@ -496,7 +498,7 @@ def head_key_to_pulses( head, key ):

@staticmethod
def pulses_to_head_key( pulses, fudge=0.1, freq=38 ):
mylog = log.getChild( 'pulses_to_head_key' )
mylog = classlog.getChild( 'pulses_to_head_key' )

if len(pulses) < 2:
return None
Expand Down Expand Up @@ -1070,10 +1072,10 @@ def width_encoded_to_pulses( uint32, start_mark=9000, start_space=4500, pulse_on
def pulses_to_width_encoded( pulses, start_mark=None, start_space=None, pulse_threshold=None, space_threshold=None ):
ret = [ ]
if len(pulses) < 68:
log.debug('Length of pulses must be a multiple of 68! (2 start + 64 data + 2 trailing)')
classlog.debug('Length of pulses must be a multiple of 68! (2 start + 64 data + 2 trailing)')
return ret
if (pulse_threshold is None) and (space_threshold is None):
log.debug('"pulse_threshold" and/or "space_threshold" must be supplied!')
classlog.debug('"pulse_threshold" and/or "space_threshold" must be supplied!')
return ret

if start_mark is not None:
Expand All @@ -1083,11 +1085,11 @@ def pulses_to_width_encoded( pulses, start_mark=None, start_space=None, pulse_th
while( len(pulses) >= 68 ):
if start_mark is not None:
if pulses[0] < (start_mark * 0.75) or pulses[0] > (start_mark * 1.25):
log.debug('The start mark is not the correct length')
classlog.debug('The start mark is not the correct length')
return ret
if start_space is not None:
if pulses[1] < (start_space * 0.75) or pulses[1] > (start_space * 1.25):
log.debug('The start space is not the correct length')
classlog.debug('The start space is not the correct length')
return ret

pulses = pulses[2:]
Expand All @@ -1109,7 +1111,7 @@ def pulses_to_width_encoded( pulses, start_mark=None, start_space=None, pulse_th

if (pulse_match is not None) and (space_match is not None):
if pulse_match != space_match:
log.debug('Both "pulse_threshold" and "space_threshold" are supplied and bit %d conflicts with both!' % i)
classlog.debug('Both "pulse_threshold" and "space_threshold" are supplied and bit %d conflicts with both!' % i)
return ret
res = space_match
elif pulse_match is None:
Expand Down
23 changes: 12 additions & 11 deletions tinytuya/Contrib/ThermostatDevice.py
Original file line number Diff line number Diff line change
Expand Up @@ -215,7 +215,7 @@
import struct
import base64

from ..core import Device, log, HEART_BEAT, DP_QUERY, CONTROL
from ..core import Device, HEART_BEAT, DP_QUERY, CONTROL

class ThermostatDevice(Device):
"""
Expand Down Expand Up @@ -379,7 +379,7 @@ def parseValue( self, key, val ):
break

if not dps:
log.warn( 'Requested key %r not found!' % key )
self.log.warn( 'Requested key %r not found!' % key )
return False

ddata = self.dps_data[dps]
Expand All @@ -392,7 +392,7 @@ def parseValue( self, key, val ):

if 'enum' in ddata:
if val not in ddata['enum']:
log.warn( 'Requested value %r for key %r/%r not in enum list %r ! Setting anyway...' % (val, dps, key, ddata['enum']) )
self.log.warn( 'Requested value %r for key %r/%r not in enum list %r ! Setting anyway...' % (val, dps, key, ddata['enum']) )

if 'base64' in ddata:
val = base64.b64encode( val ).decode('ascii')
Expand Down Expand Up @@ -455,7 +455,7 @@ def _process_response( self, data ):
for k in self.dps_data:
if k in data['dps'] and 'high_resolution' in self.dps_data[k]:
self.high_resolution = self.dps_data[k]['high_resolution']
log.info('ThermostatDevice: high-resolution is now %r' % self.high_resolution)
self.log.info('ThermostatDevice: high-resolution is now %r' % self.high_resolution)
break

for k in data['dps']:
Expand Down Expand Up @@ -491,7 +491,7 @@ def _process_response( self, data ):

if 'enum' in self.dps_data[k]:
if val not in self.dps_data[k]['enum']:
log.warn( 'Received value %r for key %r/%r not in enum list %r ! Perhaps enum list needs to be updated?' % (val, k, name, self.dps_data[k]['enum']) )
self.log.warn( 'Received value %r for key %r/%r not in enum list %r ! Perhaps enum list needs to be updated?' % (val, k, name, self.dps_data[k]['enum']) )

if 'alt' in self.dps_data[k]:
data['changed'].append( self.dps_data[k]['alt'] )
Expand Down Expand Up @@ -616,7 +616,8 @@ def __bytes__( self ):
coolto -= coolmod
if coolmod >= 25: coolto += 50

log.info( 'CF is: %r %r %r cool: %r %r %r', cf, self.heatto, heatto / 100, self.coolto, coolto / 100, self.time )
# FIXME: make a logger available here
#log.info( 'CF is: %r %r %r cool: %r %r %r', cf, self.heatto, heatto / 100, self.coolto, coolto / 100, self.time )
Comment on lines +619 to +620
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FIXME - I'm sure you know, just adding to my review

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I'm not sure what I'm going to do about that one, it's buried like 3 classes deep. I may just remove it, though having a logger available there for debugging may be needed at some point.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sortof gross, but possibly define a global scoped log (glog) to use for this one?


# if self.time is a string then it needs to be in 24-hour HH:MM[:SS] format!
if isinstance( self.time, str ):
Expand Down Expand Up @@ -773,7 +774,7 @@ def setPeriod( self, day, period, **kwargs ):

if self.day_data[day][period][0] > 3 and self.day_data[day][period][1] < 1440:
if self.day_data[day][period][0] != 0xFF:
log.warn('Selected participation flag is out of range, setting to %d', period)
self.parent.log.warn('Selected participation flag is out of range, setting to %d', period)
jasonacox marked this conversation as resolved.
Show resolved Hide resolved
self.day_data[day][period][0] = period & 3

def setCF( self, cf ):
Expand All @@ -783,7 +784,7 @@ def update( self, data ):
self.have_data = False

if len(data) % 7 != 0:
log.warn( 'Schedule data is in an unknown format, ignoring schedule' )
self.parent.log.warn( 'Schedule data is in an unknown format, ignoring schedule' )
return False

cf = self.parent.getCF( self.cf )
Expand All @@ -793,7 +794,7 @@ def update( self, data ):
day = data[offset:offset+daylen]

if len(day) % 7 != 0:
log.warn( 'Schedule day data for day %d is in an unknown format, ignoring schedule' % dow )
self.parent.log.warn( 'Schedule day data for day %d is in an unknown format, ignoring schedule' % dow )
return False

periods = len(day) / 7
Expand All @@ -804,7 +805,7 @@ def update( self, data ):
perioddata = day[dayoffset:dayoffset+7]

if len(perioddata) != 7:
log.warn( 'Schedule period data for period %d on day %d is in an unknown format, ignoring schedule' % (period, dow) )
self.parent.log.warn( 'Schedule period data for period %d on day %d is in an unknown format, ignoring schedule' % (period, dow) )
return False

newdata = struct.unpack( '>BHhh', perioddata )
Expand Down Expand Up @@ -1143,6 +1144,6 @@ def __bytes__( self ):
try:
return struct.pack( self.struct_format, *(getattr(self, k) for k in self.keys) )
except:
log.exception( 'Error while attempting to pack %s with %r/%r/%r/%r/%r/%r/%r/%r/%r/%r/%r/%r', self.struct_format, *(getattr(self, k) for k in self.keys) )
self.parent_sensorlist.parent_device.log.exception( 'Error while attempting to pack %s with %r/%r/%r/%r/%r/%r/%r/%r/%r/%r/%r/%r', self.struct_format, *(getattr(self, k) for k in self.keys) )
raise

Loading