clevermicro/amq-adapter-python
14
0
Fork 0
Code Issues 16 Pull Requests 4 Actions Packages Projects Releases Wiki Activity

feat/#1 - improve error logging and fix the file upload to support also the native multipart message

Browse Source
This commit is contained in:
Stanislav Hejny
2025-04-18 22:52:34 +01:00
parent a8d82b1e3d
commit 04977e5ccc
15 changed files with 168 additions and 118 deletions
Download Patch File Download Diff File Expand all files Collapse all files
amqp/adapter/amq_route_factory.py
+5 -4
View File
@@ -1,5 +1,6 @@
import logging
from amqp.adapter.logging_utils import logging_error
from amqp.model.model import AMQRoute
# record separator
@@ -50,14 +51,14 @@ class AMQRouteFactory:
timeout=_timeout,
valid_until=_valid_until
)
logging.error(
" [E] AMQRoute incorrect format. AMQRoute expects input as: "
logging_error(
"AMQRoute incorrect format. AMQRoute expects input as: "
"'Component-Name:AMQExchange-Name:Queue-Name:Routing-Key:Timeout:Valid-Until', "
"got: ['%s']", data
)
except Exception as err:
logging.error(
" [E] %s: AMQRoute incorrect format. AMQRoute expects input as: "
logging_error(
"%s: AMQRoute incorrect format. AMQRoute expects input as: "
"'Component-Name:AMQExchange-Name:Queue-Name:Routing-Key:Timeout:Valid-Until', "
"got: ['%s']", err, data
)
amqp/adapter/cleverthis_service_adapter.py
+26 -14
View File
@@ -20,6 +20,7 @@ from fastapi import HTTPException
from starlette.responses import FileResponse
from amqp.adapter.data_response_factory import DataResponseFactory
from amqp.adapter.logging_utils import logging_error
from amqp.config.amq_configuration import AMQConfiguration
from amqp.model.model import DataMessage, DataResponse
from amqp.adapter.multipart_parser import CleverMultiPartParser, process_form_data
@@ -90,8 +91,7 @@ def parse_request_body(message: DataMessage):
try:
return json.loads(message.body())
except json.JSONDecodeError as e:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {_tb.filename}, line {_tb.lineno}, function '{_tb.name}': {e}")
logging_error(f"Invalid JSON: {e}")
raise ValueError(f"Invalid JSON: {e}")
# Parse URL-encoded form data
@@ -104,8 +104,7 @@ def parse_request_body(message: DataMessage):
_form_data = process_form_data(_form_data)
return _form_data
except Exception as e:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {_tb.filename}, line {_tb.lineno}, function '{_tb.name}': {e}")
logging_error(f"Invalid URL-encoded form data: {e}")
raise ValueError(f"Invalid URL-encoded form data: {e}")
# Parse multipart/form-data
@@ -114,8 +113,7 @@ def parse_request_body(message: DataMessage):
parser: CleverMultiPartParser = CleverMultiPartParser(message)
return parser.form_data
except Exception as e:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {_tb.filename}, line {_tb.lineno}, function '{_tb.name}': {e}")
logging_error(f"Invalid multipart/form-data: {e}")
raise ValueError(f"Invalid multipart/form-data: {e}")
# Parse plain text
@@ -180,6 +178,13 @@ async def _convert_file_response(
})
def is_likely_json(text: str) -> bool:
""" Quick test to see if should convert the response string to JSON format. """
_text = text.strip()
return (_text.startswith('{') and _text.endswith('}')) or \
(_text.startswith('[') and _text.endswith(']'))
async def call_cleverthis_api(
message: AMQMessage,
args: Any,
@@ -209,6 +214,8 @@ async def call_cleverthis_api(
_verified_args[arg.name] = int(args[arg.name])
elif arg.annotation == float:
_verified_args[arg.name] = float(args[arg.name])
elif arg.annotation == bool:
_verified_args[arg.name] = bool(args[arg.name])
# TODO: more?
else:
_verified_args[arg.name] = args[arg.name]
@@ -235,14 +242,19 @@ async def call_cleverthis_api(
logging.info(f" [x] ALL DONE in call_cleverthis_api id:{message.id}, resp code:{success_code}")
return DataResponseFactory.of(message.id, success_code, _content_type, _binary_result, message.trace_info)
except HTTPException as http_error:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {_tb.filename}, line {_tb.lineno}, function '{_tb.name}': {http_error}")
return DataResponseFactory.of(message.id, http_error.status_code, "text/plain",
str(http_error.detail).encode('utf-8'), message.trace_info)
_content = str(http_error.detail)
if not is_likely_json(_content):
_content = '{"error": "' + _content + '"}'
logging_error(f"Service REST endpoint invocation failed: {http_error}")
return DataResponseFactory.of(message.id, http_error.status_code, "application/json",
_content.encode('utf-8'), message.trace_info)
except Exception as error:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {_tb.filename}, line {_tb.lineno}, function '{_tb.name}': {error}")
return DataResponseFactory.of(message.id, 500, "text/plain", str(error).encode('utf-8'), message.trace_info)
logging_error(f"Service endpoint invocation failed: {error}")
_content = str(error)
if not is_likely_json(_content):
_content = '{"error": "' + _content + '"}'
return DataResponseFactory.of(message.id, 500, "application/json",
_content.encode('utf-8'), message.trace_info)
# ============= CleverThisServiceAdapter =============
@@ -310,7 +322,7 @@ class CleverThisServiceAdapter:
logging.warn(f'Token: {token}')
_auth_user = await self.get_current_user(token)
except Exception as error:
logging.error(f" [E] on_message: Error getting user: {error}")
logging_error(f"on_message: Error getting user: {error}")
if _auth_user or not self.require_authenticated_user or message.path.endswith('/login'):
method = message.method.lower()
amqp/adapter/file_downloader.py
+59 -60
View File
@@ -5,13 +5,15 @@ implements the file downloader for the amqp adapter, where file is sent in chunk
import asyncio
import json
import os
import sys
import traceback
import logging
from asyncio import Future
from collections import defaultdict
from typing import Any
from aio_pika import connect_robust
from aio_pika.abc import AbstractIncomingMessage, AbstractRobustChannel, AbstractRobustQueue, AbstractQueue
from aio_pika.abc import AbstractIncomingMessage, AbstractRobustChannel, AbstractQueue
from amqp.adapter.logging_utils import logging_error
# Global dictionary to track completed downloads
download_locations = defaultdict(str)
@@ -72,41 +74,40 @@ async def download_file(loop, rabbitmq_url, file_info, message_data, output_dir)
filename = os.path.basename(filepath) # if a new version was created, ensure to use that new version
file_info['filename'] = filename
eof = IN_PROGRESS
fsize = 0
logging.info(f"Downloading file: {filename} (size: {size} bytes) from stream: {stream_name}:{queue_name} to {filepath}")
async def wrap_rabbit_mq_calls() -> tuple[int, int] | None:
connection = await connect_robust(rabbitmq_url, loop=loop)
try:
_file_size = 0
_eof = IN_PROGRESS
channel: AbstractRobustChannel = await connection.channel()
queue: AbstractQueue = await channel.get_queue(queue_name, ensure=False)
logging.info(f"Awaiting all file chunks being downloaded for {filename}")
async with queue.iterator() as queue_iter:
async for message in queue_iter:
async with message.process():
with open(filepath, 'ab') as f:
f.write(message.body)
_file_size = _file_size + message.body_size
_eof = int(message.headers.get('eof', END_OF_FILE))
if _eof != IN_PROGRESS:
break
except Exception as e:
logging_error(f"File download failed: {e}")
finally:
await connection.close()
return _file_size, _eof
if queue_name:
async def wrap_rabbit_mq_calls():
connection = await connect_robust(rabbitmq_url, loop=loop)
try:
channel: AbstractRobustChannel = await connection.channel()
queue: AbstractQueue = await channel.get_queue(queue_name, ensure=False)
logging.info(f"Awaiting all file chunks being downloaded for {filename}")
async with queue.iterator() as queue_iter:
async for message in queue_iter:
async with message.process():
with open(filepath, 'ab') as f:
f.write(message.body)
fsize = fsize + message.body_size
eof = message.headers.get('eof', END_OF_FILE)
if eof != IN_PROGRESS:
break
except Exception as e:
logging.error(f"Error downloading file: {e}")
tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {tb.filename}, line {tb.lineno}, function '{tb.name}': {e}")
finally:
await connection.close()
return fsize, eof
_future: Future = asyncio.run_coroutine_threadsafe(wrap_rabbit_mq_calls(), loop=loop)
while not _future.done():
await asyncio.sleep(0.05)
fsize, eof = _future.result()
return (fsize, eof)
_local_file_size, _local_eof = _future.result()
return _local_file_size, _local_eof
return 0, CANCELLED
async def download_buffer(loop, rabbitmq_url, queue_name) -> (bytearray, int):
"""
@@ -117,37 +118,36 @@ async def download_buffer(loop, rabbitmq_url, queue_name) -> (bytearray, int):
rabbitmq_url: The RabbitMQ connection URL.
queue_name (str): The directory where the file should be saved.
"""
res = bytearray()
eof = IN_PROGRESS
logging.info(f"Downloading buffer from stream: {queue_name}")
if queue_name:
async def wrap_rabbit_mq_calls() -> int:
connection = await connect_robust(rabbitmq_url, loop=loop)
async def wrap_rabbit_mq_calls() -> tuple[bytearray, int]:
_connection = await connect_robust(rabbitmq_url, loop=loop)
_eof = IN_PROGRESS
_res = bytearray()
try:
channel: AbstractRobustChannel = await connection.channel()
channel: AbstractRobustChannel = await _connection.channel()
queue: AbstractQueue = await channel.get_queue(queue_name, ensure=False)
logging.info(f"Awaiting all buffer chunks being downloaded for {queue_name}")
async with queue.iterator() as queue_iter:
async for message in queue_iter:
async with message.process():
res.extend(message.body)
eof = message.headers.get('eof', END_OF_FILE)
if eof != IN_PROGRESS:
_res.extend(message.body)
_eof = message.headers.get('eof', END_OF_FILE)
if _eof != IN_PROGRESS:
break
logging.info(f"Finished downloading buffer {queue_name}")
except Exception as e:
logging.error(f"Error downloading buffer: {e}")
tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error in {tb.filename}, line {tb.lineno}, function '{tb.name}': {e}")
logging_error(f"Downloading buffer: {e}")
await connection.close()
return eof
await _connection.close()
return _res, _eof
_future: Future = asyncio.run_coroutine_threadsafe(wrap_rabbit_mq_calls(), loop=loop)
while not _future.done():
await asyncio.sleep(0.05)
eof = _future.result()
return (res, eof)
_local_res, _local_eof = _future.result()
return _local_res, _local_eof
return 0, CANCELLED
async def on_message(
@@ -166,16 +166,16 @@ async def on_message(
"""
global download_locations
try:
message_data = json.loads(message.body.decode())
amq_message_data = json.loads(json_data.decode())
_message_data = json.loads(message.body.decode())
_amq_message_data = json.loads(json_data.decode())
files_to_download = []
for key, file_type in amq_message_data['files'].items():
if len(file_type) > 0:
files_info = file_type[0]
for _key, _file_type in _amq_message_data['files'].items():
if len(_file_type) > 0:
files_info = _file_type[0]
stream_name = files_info['streamName']
files_info['queue_name'] = message_data.get(stream_name, "") if stream_name else ""
files_info['key'] = key
files_info['queue_name'] = _message_data.get(stream_name, "") if stream_name else ""
files_info['key'] = _key
files_to_download.append(files_info)
if not files_to_download:
@@ -184,13 +184,13 @@ async def on_message(
return False
# Create a task for each file download
tasks = []
_tasks = []
for file_info in files_to_download:
logging.info(f" [{message.delivery_tag}] about to create task for {file_info}")
task = asyncio.create_task(download_file(loop, rabbitmq_url, file_info, message_data, output_dir))
tasks.append(task)
_task = asyncio.create_task(download_file(loop, rabbitmq_url, file_info, _message_data, output_dir))
_tasks.append(_task)
logging.info(f" [{message.delivery_tag}] Waiting for all files to download...gather(*tasks)")
await asyncio.gather(*tasks) # Wait for all downloads to complete
await asyncio.gather(*_tasks) # Wait for all downloads to complete
# After all files are downloaded, acknowledge the original message
logging.info(f"All files downloaded. d-tag: {message.delivery_tag}")
@@ -198,8 +198,7 @@ async def on_message(
#await message.ack()
#logging.info(f"Message d-tag: {message.delivery_tag} acknowledged.")
except Exception as e:
tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] Error building DataMessage, {tb.filename}, line {tb.lineno}, function '{tb.name}': {e}")
logging_error(f"Building DataMessage: {e}")
asyncio.run_coroutine_threadsafe(message.ack(), loop=loop) # ACK -> ignore the message (do not redeliver)
return download_locations
amqp/adapter/file_uploader.py
+4 -3
View File
@@ -6,15 +6,16 @@ import asyncio
import os
from pathlib import Path
from aio_pika.abc import AbstractRobustChannel, AbstractRobustExchange
from aio_pika.abc import AbstractRobustChannel, AbstractRobustExchange, AbstractExchange
from aio_pika import Message, DeliveryMode
from amqp.adapter.file_downloader import IN_PROGRESS, END_OF_FILE
from amqp.adapter.logging_utils import logging_debug
from amqp.router.router_base import AMQ_REPLY_TO_EXCHANGE
async def publish_file_to_rabbitmq(
exchange: AbstractRobustExchange,
exchange: AbstractExchange,
file_path: Path,
routing_key: str,
loop: AbstractEventLoop,
@@ -73,5 +74,5 @@ async def publish_file_to_rabbitmq(
_offset += len(_chunk)
logging.debug(f"Published chunk {_offset}/{_file_size} to {exchange.name}:{routing_key}")
print(f"File {file_path} published to RabbitMQ exchange {exchange.name}, queue {routing_key}")
logging_debug(f"File {file_path} published to RabbitMQ exchange {exchange.name}, queue {routing_key}")
return routing_key, _file_size
amqp/adapter/logging_utils.py
+21 -2
View File
@@ -10,5 +10,24 @@ def logging_error(msg: str, *args) -> None:
Args:
msg (str): The error message to log.
"""
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] module '{_tb.filename}', line {_tb.lineno}, function '{_tb.name}': {msg}", *args)
_exec_info = sys.exc_info()[2]
if _exec_info:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.error(f" [E] '{msg}' ---> '{_tb.filename}': {_tb.lineno}, func: '{_tb.name}'", *args)
else:
logging.error(f" [E] {msg}", *args)
def logging_debug(msg: str, *args) -> None:
"""
Log a debug message according to current logging for 'DEBUG' level.
Add module name, line and function name where the print occurred, on single line.
Args:
msg (str): The error message to log.
"""
_exec_info = sys.exc_info()[2]
if _exec_info:
_tb = traceback.extract_tb(sys.exc_info()[2])[-1]
logging.debug(f" [DBG] '{msg}' ---> '{_tb.filename}': {_tb.lineno}, func: '{_tb.name}'", *args)
else:
logging.debug(f" [DBG] {msg}", *args)
amqp/adapter/multipart_parser.py
+19 -8
View File
@@ -7,6 +7,7 @@ from fastapi import UploadFile
from python_multipart import multipart
from python_multipart.multipart import Field, File
from amqp.adapter.logging_utils import logging_error, logging_debug
from amqp.model.model import DataMessage
@@ -59,28 +60,38 @@ class CleverMultiPartParser:
"application/x-www-form-urlencoded",
"application/x-url-encoded"]:
try:
python_multipart.parse_form(headers, io.BytesIO(message.body()), self.on_field, self.on_file)
self.is_multipart = True
if hasattr(message, 'extra_data') and isinstance(message.extra_data, dict) and len(message.extra_data) > 0:
try:
self.form_data = json.loads(message.body())
self.is_json = True
if self.form_data['files'] and self.form_data['form']:
self.form_data = process_form_data(self.form_data)
except Exception as jsonerror:
logging_error(f"Parsing JSON: {jsonerror}")
self.is_valid = False
else:
python_multipart.parse_form(headers, io.BytesIO(message.body()), self.on_field, self.on_file)
self.is_multipart = True
except Exception as e:
logging.error(f"Error parsing multipart/form-data: {e}. Trying parsing as JSON.")
logging_error(f"Error parsing multipart/form-data: {e}. Trying parsing as JSON.")
try:
self.form_data = json.loads(message.body())
self.is_json = True
if self.form_data['files'] and self.form_data['form']:
self.form_data = process_form_data(self.form_data)
except Exception as jsonerror:
logging.error(f"Error parsing JSON: {jsonerror}")
logging_error(f"Parsing JSON: {jsonerror}")
self.is_valid = False
else:
self.form_data = message.body()
def on_field(self, field: Field):
print(field)
logging_debug(field)
self.form_data[field.field_name.decode('utf-8')] = field.value
print(self.form_data)
logging_debug(self.form_data)
def on_file(self, file: File):
print(file)
logging_debug(file)
self.form_data[file.field_name.decode('utf-8')] = \
UploadFile(file.file_object, size=file.size, filename=file.file_name)
print(self.form_data)
logging_debug(self.form_data)
amqp/adapter/pydantic_serializer.py
+4 -2
View File
@@ -9,6 +9,8 @@ from typing import Dict, Any
from pydantic import BaseModel
from urllib.parse import urlparse, parse_qs
from amqp.adapter.logging_utils import logging_debug
def serialize_object(obj: BaseModel) -> str:
"""
@@ -72,10 +74,10 @@ def deserialize_object(data: str) -> BaseModel:
v = v.strip() # important
obj_dict[k] = _convert_value(v)
print(f"Deserialized object: {class_name}")
logging_debug(f"Deserialized object: {class_name}")
if '[' in class_name:
class_name = class_name.split('[')[0]
print(f"trying object: {class_name}")
logging_debug(f"trying object: {class_name}")
cls = globals().get(class_name)
if cls is None:
raise ValueError(f"Unknown class: {class_name}")
amqp/adapter/service_message_factory.py
+2 -1
View File
@@ -2,6 +2,7 @@ import base64
import logging
from amqp.adapter.data_message_factory import DataMessageFactory
from amqp.adapter.logging_utils import logging_error
from amqp.adapter.trace_info_adapter import TraceInfoAdapter
from amqp.model.model import ServiceMessage
from amqp.model.service_message_type import ServiceMessageType
@@ -106,7 +107,7 @@ class ServiceMessageFactory:
message=base64.b64decode(message).decode() if payload_type & 0x80 else message
)
except Exception as e:
logging.error(
logging_error(
"Unexpected ServiceMessage format. Expected 6 tokens separated by '|' in format: "
"[ID(64bit number)|MessageType(8bit number)|RecipientName(String)|"
"ReplyTo(String)|TraceInfo|Payload(String or Base64)], got: "