Skip to content

Commit 682bf97

Browse files
committed
added logging for skpi
1 parent ae71107 commit 682bf97

1 file changed

Lines changed: 164 additions & 7 deletions

File tree

Framework/Built_In_Automation/Sequential_Actions/common_functions.py

Lines changed: 164 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -5897,15 +5897,63 @@ def data_store_read(data_set):
58975897

58985898
sModuleInfo = inspect.currentframe().f_code.co_name + " : " + MODULE_NAME
58995899

5900+
import logging
5901+
from datetime import datetime
5902+
from settings import ZEUZ_NODE_ARTIFACTS_DIR
5903+
5904+
log_dir = ZEUZ_NODE_ARTIFACTS_DIR / "data_store_logs"
5905+
log_dir.mkdir(parents=True, exist_ok=True)
5906+
5907+
current_time = datetime.now()
5908+
log_filename = f"data_store_read_{current_time.strftime('%Y-%m-%d_%H')}.log"
5909+
log_file = log_dir / log_filename
5910+
5911+
logger = logging.getLogger(f"data_store_read_{current_time.strftime('%Y%m%d%H')}")
5912+
logger.setLevel(logging.DEBUG)
5913+
5914+
# Remove existing handlers to avoid duplicate logs
5915+
if logger.handlers:
5916+
logger.handlers.clear()
5917+
5918+
handler = logging.FileHandler(str(log_file), mode='a')
5919+
handler.setFormatter(logging.Formatter(
5920+
'%(asctime)s - %(name)s - %(levelname)s - %(message)s'
5921+
))
5922+
logger.addHandler(handler)
5923+
5924+
logger.info("="*80)
5925+
logger.info(f"Function data_store_read called")
5926+
logger.info(f"Module Info: {sModuleInfo}")
5927+
logger.info(f"Received data_set: {data_set}")
5928+
5929+
5930+
59005931
try:
5932+
test_id = None
5933+
node_id = sr.Get_Shared_Variables("node_id") or None
5934+
action_no = CommonUtil.current_action_no
5935+
step_no = CommonUtil.current_step_no
5936+
if sr.Test_Shared_Variables("zeuz_current_tc"):
5937+
current_tc = sr.Get_Shared_Variables("zeuz_current_tc")
5938+
if isinstance(current_tc, dict) and "testcase_no" in current_tc:
5939+
test_id = current_tc["testcase_no"]
59015940
table_name = columns = var_name = ""
5902-
params = {}
5941+
params = {
5942+
'test_id': test_id,
5943+
'node_id': node_id,
5944+
'action_no': action_no,
5945+
'step_no': step_no
5946+
}
5947+
logger.debug("Starting to parse data_set")
59035948
for left, mid, right in data_set:
5949+
logger.debug(f"Processing row: left='{left}', mid='{mid}', right='{right}'")
59045950
if left.strip() == 'table name':
59055951
table_name = right.strip()
59065952
params['table_name'] = table_name
5953+
logger.info(f"Table name set to: {table_name}")
59075954
if left.strip() == 'where':
59085955
q = right.strip()
5956+
logger.info(f"Processing WHERE clause: {q}")
59095957
# q = re.sub(r"\band\b",",",q)
59105958
# q = re.sub(r"\bor\b",",",q)
59115959
logic=[]
@@ -5914,10 +5962,12 @@ def data_store_read(data_set):
59145962
logic.append('and')
59155963
elif s=='or':
59165964
logic.append('or')
5965+
logger.debug(f"Detected logic operators: {logic}")
59175966
q = right.strip()
59185967
q = re.sub(r"\band\b",",",q)
59195968
q = re.sub(r"\bor\b",",",q)
59205969
temp= q.split(',')
5970+
logger.debug(f"Split WHERE clause into: {temp}")
59215971
t = temp[0].split('=')
59225972
params['and_' + t[0].strip()] = [t[1].strip()]
59235973
i = 1
@@ -5938,26 +5988,54 @@ def data_store_read(data_set):
59385988

59395989
i += 1
59405990
j+=1
5991+
logger.info(f"Final WHERE params: {params}")
59415992
if mid.strip() == "action":
59425993
var_name = right.strip()
5994+
logger.info(f"Variable name set to: {var_name}")
5995+
5996+
logger.info(f"Final table_name: {table_name}")
5997+
logger.info(f"Final params: {params}")
5998+
logger.info(f"Final var_name: {var_name}")
5999+
6000+
logger.debug("Preparing request headers")
59436001
headers = RequestFormatter.add_api_key_to_headers({})
59446002
headers['headers']['content-type'] = 'application/json'
59456003
headers['headers']['X-API-KEY'] = ConfigModule.get_config_value("Authentication", "api-key")
6004+
logger.debug(f"Headers prepared (API key masked)")
6005+
6006+
logger.info(f"Making GET request to data_store/data_store/custom_operation/")
6007+
logger.debug(f"Request params: {json.dumps(params)}")
6008+
59466009
res = RequestFormatter.request("get",
59476010
RequestFormatter.form_uri('data_store/data_store/custom_operation/'),
59486011
params=json.dumps(params),
59496012
verify=False,
59506013
**headers
59516014
)
6015+
6016+
logger.info(f"Response status code: {res.status_code}")
6017+
logger.debug(f"Response text: {res.text}")
6018+
59526019
if res.status_code == 200:
59536020
response_json = json.loads(res.text)
59546021
response_json = response_json["data"]
5955-
return sr.Set_Shared_Variables(var_name, response_json, pretty=True)
6022+
logger.info(f"Successfully retrieved {len(response_json) if isinstance(response_json, (list, dict)) else 'N/A'} items from datastore")
6023+
logger.debug(f"Response data: {response_json}")
6024+
result = sr.Set_Shared_Variables(var_name, response_json, pretty=True)
6025+
logger.info(f"Data stored in variable '{var_name}' successfully")
6026+
logger.info("="*80)
6027+
return result
59566028
else:
59576029
CommonUtil.ExecLog(sModuleInfo, "No data found, please check your dataset", 1)
6030+
logger.warning("No data found in datastore, please check your dataset")
6031+
logger.info("="*80)
6032+
return "zeuz_failed"
59586033
return "passed"
59596034

5960-
except Exception:
6035+
except Exception as e:
6036+
logger.error(f"Exception occurred: {str(e)}", exc_info=True)
6037+
logger.error(f"Traceback: {traceback.format_exc()}")
6038+
logger.info("="*80)
59616039
return CommonUtil.Exception_Handler(sys.exc_info())
59626040

59636041
def data_store_get_data(data_set):
@@ -6060,16 +6138,62 @@ def data_store_write(data_set):
60606138

60616139
sModuleInfo = inspect.currentframe().f_code.co_name + " : " + MODULE_NAME
60626140

6141+
import logging
6142+
from datetime import datetime
6143+
from settings import ZEUZ_NODE_ARTIFACTS_DIR
6144+
6145+
log_dir = ZEUZ_NODE_ARTIFACTS_DIR / "data_store_logs"
6146+
log_dir.mkdir(parents=True, exist_ok=True)
6147+
6148+
current_time = datetime.now()
6149+
log_filename = f"data_store_write_{current_time.strftime('%Y-%m-%d_%H')}.log"
6150+
log_file = log_dir / log_filename
6151+
6152+
logger = logging.getLogger(f"data_store_write_{current_time.strftime('%Y%m%d%H')}")
6153+
logger.setLevel(logging.DEBUG)
6154+
6155+
# Remove existing handlers to avoid duplicate logs
6156+
if logger.handlers:
6157+
logger.handlers.clear()
6158+
6159+
handler = logging.FileHandler(str(log_file), mode='a')
6160+
handler.setFormatter(logging.Formatter(
6161+
'%(asctime)s - %(name)s - %(levelname)s - %(message)s'
6162+
))
6163+
logger.addHandler(handler)
6164+
6165+
logger.info("="*80)
6166+
logger.info("Function data_store_write called")
6167+
logger.info(f"Module Info: {sModuleInfo}")
6168+
logger.info(f"Received data_set: {data_set}")
6169+
60636170
try:
6171+
test_id = None
6172+
node_id = sr.Get_Shared_Variables("node_id") or None
6173+
action_no = CommonUtil.current_action_no
6174+
step_no = CommonUtil.current_step_no
6175+
if sr.Test_Shared_Variables("zeuz_current_tc"):
6176+
current_tc = sr.Get_Shared_Variables("zeuz_current_tc")
6177+
if isinstance(current_tc, dict) and "testcase_no" in current_tc:
6178+
test_id = current_tc["testcase_no"]
60646179
table_name = columns = var_name = ""
6065-
params = {}
6180+
params = {
6181+
'test_id': test_id,
6182+
'node_id': node_id,
6183+
'action_no': action_no,
6184+
'step_no': step_no
6185+
}
60666186
data={}
6187+
logger.debug("Starting to parse data_set")
60676188
for left, mid, right in data_set:
6189+
logger.debug(f"Processing row: left='{left}', mid='{mid}', right='{right}'")
60686190
if left.strip() == 'table name':
60696191
table_name = right.strip()
60706192
params['table_name'] = table_name
6193+
logger.info(f"Table name set to: {table_name}")
60716194
if left.strip() == 'where':
60726195
q = right.strip()
6196+
logger.info(f"Processing WHERE clause: {q}")
60736197
# q = re.sub(r"\band\b",",",q)
60746198
# q = re.sub(r"\bor\b",",",q)
60756199
logic=[]
@@ -6078,10 +6202,12 @@ def data_store_write(data_set):
60786202
logic.append('and')
60796203
elif s=='or':
60806204
logic.append('or')
6205+
logger.debug(f"Detected logic operators: {logic}")
60816206
q = right.strip()
60826207
q = re.sub(r"\band\b",",",q)
60836208
q = re.sub(r"\bor\b",",",q)
60846209
temp= q.split(',')
6210+
logger.debug(f"Split WHERE clause into: {temp}")
60856211
t = temp[0].split('=')
60866212
params['and_' + t[0].strip()] = [t[1].strip()]
60876213
i = 1
@@ -6102,40 +6228,71 @@ def data_store_write(data_set):
61026228

61036229
i += 1
61046230
j+=1
6231+
logger.info(f"Final WHERE params: {params}")
61056232
if left.strip() == 'data':
61066233
temp = [right.strip()]
6234+
logger.debug(f"Processing data field: {temp}")
61076235
print(temp)
61086236
for t in temp:
61096237
tt = t.split('=', 1)
6238+
logger.debug(f"Split data into: {tt}")
61106239
print(tt)
61116240
data[tt[0].strip()]=tt[1].strip()
6241+
logger.debug(f"Data field '{tt[0].strip()}' = '{tt[1].strip()}'")
61126242
print(data[tt[0].strip()])
6243+
logger.info(f"Complete data dict: {data}")
61136244
if mid.strip() == "action":
61146245
var_name = right.strip()
6246+
logger.info(f"Variable name set to: {var_name}")
61156247

6248+
logger.info(f"Final table_name: {table_name}")
6249+
logger.info(f"Final params: {params}")
6250+
logger.info(f"Final data: {data}")
6251+
logger.info(f"Final var_name: {var_name}")
61166252

6253+
logger.debug("Preparing request headers")
61176254
headers = RequestFormatter.add_api_key_to_headers({})
61186255
headers['headers']['content-type'] = 'application/json'
61196256
headers['headers']['X-API-KEY'] = ConfigModule.get_config_value("Authentication", "api-key")
6257+
logger.debug("Headers prepared (API key masked)")
6258+
6259+
logger.info("Making PATCH request to data_store/data_store/custom_operation/")
6260+
logger.debug(f"Request params: {json.dumps(params)}")
6261+
logger.debug(f"Request data: {json.dumps(data)}")
6262+
61206263
res = requests.patch(
61216264
RequestFormatter.form_uri('data_store/data_store/custom_operation/'),
61226265
params=json.dumps(params),
61236266
data=json.dumps(data),
61246267
verify=False,
61256268
**headers
61266269
)
6270+
6271+
logger.info(f"Response status code: {res.status_code}")
6272+
logger.debug(f"Response text: {res.text}")
61276273
#
61286274

61296275
# print(res.text)
61306276
if res.status_code == 200:
61316277
# CommonUtil.ExecLog(sModuleInfo, f"Captured following output:\n{res.text}", 1)
6132-
6133-
return sr.Set_Shared_Variables(var_name, json.loads(res.text),pretty=True)
6278+
response_json = json.loads(res.text)
6279+
logger.info(f"Successfully updated datastore")
6280+
logger.debug(f"Response data: {response_json}")
6281+
result = sr.Set_Shared_Variables(var_name, response_json, pretty=True)
6282+
logger.info(f"Response stored in variable '{var_name}' successfully")
6283+
logger.info("="*80)
6284+
return result
61346285
else:
61356286
CommonUtil.ExecLog(sModuleInfo, "No data found to update , please check your dataset", 1)
6287+
logger.warning("No data found to update in datastore, please check your dataset")
6288+
logger.info("="*80)
6289+
return "zeuz_failed"
61366290
return "passed"
61376291

6138-
except Exception:
6292+
except Exception as e:
6293+
logger.error(f"Exception occurred: {str(e)}", exc_info=True)
6294+
logger.error(f"Traceback: {traceback.format_exc()}")
6295+
logger.info("="*80)
61396296
return CommonUtil.Exception_Handler(sys.exc_info())
61406297

61416298

0 commit comments

Comments
 (0)