diff --git a/api/admin.py b/api/admin.py index 50a1edf87..7d059cae3 100644 --- a/api/admin.py +++ b/api/admin.py @@ -10,7 +10,7 @@ from api.logics import Logics from api.models import Currency, LNPayment, MarketTick, OnchainPayment, Order, Robot -from api.utils import objects_to_hyperlinks +from api.utils import render_order_logs from api.tasks import send_notification admin.site.unregister(Group) @@ -130,16 +130,7 @@ class OrderAdmin(AdminChangeLinksMixin, admin.ModelAdmin): readonly_fields = ("reference", "_logs") def _logs(self, obj): - if not obj.logs: - return format_html("No logs were recorded") - with_hyperlinks = objects_to_hyperlinks(obj.logs) - try: - html_logs = format_html( - f'{with_hyperlinks}
' - ) - except Exception as e: - html_logs = f"An error occurred while formatting the parsed logs as HTML. Exception {e}" - return html_logs + return format_html(render_order_logs(obj.logs)) actions = [ "cancel_public_order", diff --git a/api/lightning/cln.py b/api/lightning/cln.py index b005d4ece..d2907cfc3 100755 --- a/api/lightning/cln.py +++ b/api/lightning/cln.py @@ -656,7 +656,7 @@ def handle_response(): order.save(update_fields=["expires_at"]) order.log( - f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) succeeded" + f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) **succeeded**" ) results = {"succeded": True} @@ -710,7 +710,7 @@ def handle_response(): f"Order: {order.id} FAILED. Hash: {hash} Reason: {cls.payment_failure_context[status_code]}" ) order.log( - f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) failed. Failure reason: {cls.payment_failure_context[status_code]}" + f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) **failed**. Failure reason: {cls.payment_failure_context[status_code]}" ) return { @@ -747,7 +747,7 @@ def handle_response(): order.save(update_fields=["expires_at"]) order.log( - f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) had expired" + f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) **had expired**" ) results = { diff --git a/api/lightning/lnd.py b/api/lightning/lnd.py index e43e11b7d..9765b502f 100644 --- a/api/lightning/lnd.py +++ b/api/lightning/lnd.py @@ -199,7 +199,7 @@ def pay_onchain(cls, onchainpayment, queue_code=5, on_mempool_code=2): onchainpayment.broadcasted = True onchainpayment.save(update_fields=["txid", "broadcasted"]) onchainpayment.order_paid_TX.log( - f"TX OnchainPayment({onchainpayment.id},{response.txid}) in mempool" + f"TX OnchainPayment({onchainpayment.id},{response.txid}) in **mempool**" ) return True @@ -608,7 +608,7 @@ def handle_response(response, was_in_transit=False): f"Order: {order.id} FAILED. Hash: {hash} Reason: {str_failure_reason}" ) order.log( - f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) failed. Failure reason: {str_failure_reason})" + f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) **failed**. Failure reason: {str_failure_reason})" ) return { @@ -632,7 +632,7 @@ def handle_response(response, was_in_transit=False): order.save(update_fields=["expires_at"]) order.log( - f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) succeeded" + f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) **succeeded**" ) results = {"succeded": True} @@ -678,7 +678,7 @@ def handle_response(response, was_in_transit=False): order.save(update_fields=["expires_at"]) order.log( - f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) had expired" + f"Payment LNPayment({lnpayment.payment_hash},{str(lnpayment)}) **had expired**" ) results = { diff --git a/api/logics.py b/api/logics.py index 87fa8bf3a..99e12a56c 100644 --- a/api/logics.py +++ b/api/logics.py @@ -324,7 +324,7 @@ def order_expires(cls, order): send_notification.delay(order_id=order.id, message="order_expired_untaken") order.log("Order expired while public or paused") - order.log("Maker bond was unlocked") + order.log("Maker bond was **unlocked**") return True @@ -344,8 +344,8 @@ def order_expires(cls, order): order.log( "Order expired while waiting for both buyer invoice and seller escrow" ) - order.log("Maker bond was settled") - order.log("Taker bond was settled") + order.log("Maker bond was **settled**") + order.log("Taker bond was **settled**") return True @@ -367,8 +367,8 @@ def order_expires(cls, order): cls.add_slashed_rewards(order, order.maker_bond, order.taker_bond) order.log("Order expired while waiting for escrow of the maker/seller") - order.log("Maker bond was settled") - order.log("Taker bond was unlocked") + order.log("Maker bond was **settled**") + order.log("Taker bond was **unlocked**") return True @@ -387,7 +387,7 @@ def order_expires(cls, order): cls.add_slashed_rewards(order, taker_bond, order.maker_bond) order.log("Order expired while waiting for escrow of the taker/seller") - order.log("Taker bond was settled") + order.log("Taker bond was **settled**") return True @@ -408,8 +408,8 @@ def order_expires(cls, order): cls.add_slashed_rewards(order, order.maker_bond, order.taker_bond) order.log("Order expired while waiting for invoice of the maker/buyer") - order.log("Maker bond was settled") - order.log("Taker bond was unlocked") + order.log("Maker bond was **settled**") + order.log("Taker bond was **unlocked**") return True @@ -424,7 +424,7 @@ def order_expires(cls, order): cls.add_slashed_rewards(order, taker_bond, order.maker_bond) order.log("Order expired while waiting for invoice of the taker/buyer") - order.log("Taker bond was settled") + order.log("Taker bond was **settled**") return True @@ -487,8 +487,8 @@ def automatic_dispute_resolution(cls, order): cls.settle_bond(order.taker_bond) order.update_status(Order.Status.DIS) - order.log("Maker bond was settled") - order.log("Taker bond was settled") + order.log("Maker bond was **settled**") + order.log("Taker bond was **settled**") order.log( "No robot wrote in the chat, the dispute cannot be solved automatically" ) @@ -500,10 +500,10 @@ def automatic_dispute_resolution(cls, order): order.update_status(Order.Status.MLD) cls.add_slashed_rewards(order, order.maker_bond, order.taker_bond) - order.log("Maker bond was settled") - order.log("Taker bond was unlocked") + order.log("Maker bond was **settled**") + order.log("Taker bond was **unlocked**") order.log( - "The dispute was solved automatically: 'Maker lost dispute', the maker did not write in the chat" + "**The dispute was solved automatically:** 'Maker lost dispute', the maker did not write in the chat" ) elif num_messages_taker == 0: @@ -513,10 +513,10 @@ def automatic_dispute_resolution(cls, order): order.update_status(Order.Status.TLD) cls.add_slashed_rewards(order, order.taker_bond, order.maker_bond) - order.log("Maker bond was unlocked") - order.log("Taker bond was settled") + order.log("Maker bond was **unlocked**") + order.log("Taker bond was **settled**") order.log( - "The dispute was solved automatically: 'Taker lost dispute', the maker did not write in the chat" + "**The dispute was solved automatically:** 'Taker lost dispute', the maker did not write in the chat" ) else: return False @@ -581,8 +581,8 @@ def open_dispute(cls, order, user=None): order.log( f"Dispute was opened {f'by Robot({user.robot.id},{user.username})' if user else ''}" ) - order.log("Maker bond was settled") - order.log("Taker bond was settled") + order.log("Maker bond was **settled**") + order.log("Taker bond was **settled**") return True, None @@ -1060,11 +1060,11 @@ def cancel_order(cls, order, user, cancel_status=None): order.update_status(Order.Status.UCA) order.log("Order cancelled by maker while public or paused") - order.log("Maker bond was unlocked") + order.log("Maker bond was **unlocked**") take_orders_queryset = TakeOrder.objects.filter(order=order) for idx, take_order in enumerate(take_orders_queryset): - order.log("Pretaker bond was unlocked") + order.log("Pretaker bond was **unlocked**") cls.take_order_expires(take_order) send_notification.delay( @@ -1113,8 +1113,8 @@ def cancel_order(cls, order, user, cancel_status=None): cls.add_slashed_rewards(order, order.maker_bond, order.taker_bond) order.log("Maker cancelled before escrow was locked") - order.log("Maker bond was settled") - order.log("Taker bond was unlocked") + order.log("Maker bond was **settled**") + order.log("Taker bond was **unlocked**") nostr_send_order_event.delay(order_id=order.id) @@ -1137,8 +1137,8 @@ def cancel_order(cls, order, user, cancel_status=None): cls.add_slashed_rewards(order, taker_bond, order.maker_bond) order.log("Taker cancelled before escrow was locked") - order.log("Taker bond was settled") - order.log("Maker bond was unlocked") + order.log("Taker bond was **settled**") + order.log("Maker bond was **unlocked**") nostr_send_order_event.delay(order_id=order.id) @@ -1191,7 +1191,7 @@ def cancel_order(cls, order, user, cancel_status=None): return True, None order.log( - f"Cancel request was sent by Robot({user.robot.id},{user.username}) on an invalid status {order.status}: {Order.Status(order.status).label}" + f"Cancel request was sent by Robot({user.robot.id},{user.username}) on an invalid status {order.status}: *{Order.Status(order.status).label}*" ) return False, new_error(1021) @@ -1210,9 +1210,9 @@ def collaborative_cancel(cls, order): nostr_send_order_event.delay(order_id=order.id) order.log("Order was collaboratively cancelled") - order.log("Maker bond was unlocked") - order.log("Taker bond was unlocked") - order.log("Trade escrow was unlocked") + order.log("Maker bond was **unlocked**") + order.log("Taker bond was **unlocked**") + order.log("Trade escrow was **unlocked**") return @@ -1390,7 +1390,7 @@ def finalize_contract(cls, take_order): nostr_send_order_event.delay(order_id=order.id) order.log( - f"Contract formalized. Maker: Robot({order.maker.robot.id},{order.maker}). Taker: Robot({order.taker.robot.id},{order.taker}). API median price {order.currency.exchange_rate} {dict(Currency.currency_choices)[order.currency.currency]}/BTC. Premium is {order.premium}%. Contract size {order.last_satoshis} Sats" + f"**Contract formalized.** Maker: Robot({order.maker.robot.id},{order.maker}). Taker: Robot({order.taker.robot.id},{order.taker}). API median price {order.currency.exchange_rate} {dict(Currency.currency_choices)[order.currency.currency]}/BTC. Premium is {order.premium}%. Contract size {order.last_satoshis} Sats" ) return True @@ -1570,7 +1570,7 @@ def settle_escrow(order): if LNNode.settle_hold_invoice(order.trade_escrow.preimage): order.trade_escrow.status = LNPayment.Status.SETLED order.trade_escrow.save(update_fields=["status"]) - order.log("Trade escrow was settled") + order.log("Trade escrow was **settled**") return True def settle_bond(bond): @@ -1585,7 +1585,7 @@ def return_escrow(order): if LNNode.cancel_return_hold_invoice(order.trade_escrow.payment_hash): order.trade_escrow.status = LNPayment.Status.RETNED order.trade_escrow.save(update_fields=["status"]) - order.log("Trade escrow was unlocked") + order.log("Trade escrow was **unlocked**") return True def cancel_escrow(order): @@ -1594,7 +1594,7 @@ def cancel_escrow(order): if LNNode.cancel_return_hold_invoice(order.trade_escrow.payment_hash): order.trade_escrow.status = LNPayment.Status.CANCEL order.trade_escrow.save(update_fields=["status"]) - order.log("Trade escrow was cancelled") + order.log("Trade escrow was **cancelled**") return True def return_bond(bond): @@ -1622,7 +1622,7 @@ def cancel_onchain_payment(order): order.payout_tx.save(update_fields=["status"]) order.log( - f"Onchain payment OnchainPayment({order.payout_tx.id},{str(order.payout_tx)}) was cancelled" + f"Onchain payment OnchainPayment({order.payout_tx.id},{str(order.payout_tx)}) was **cancelled**" ) return True @@ -1662,7 +1662,7 @@ def pay_buyer(cls, order): order.save(update_fields=["contract_finalization_time"]) send_notification.delay(order_id=order.id, message="trade_successful") - order.log("Paying buyer invoice") + order.log("**Paying buyer invoice**") return True # Pay onchain to address @@ -1679,7 +1679,7 @@ def pay_buyer(cls, order): order.save(update_fields=["contract_finalization_time"]) send_notification.delay(order_id=order.id, message="trade_successful") - order.log("Paying buyer onchain address") + order.log("**Paying buyer onchain address**") return True @classmethod @@ -1722,8 +1722,8 @@ def confirm_fiat(cls, order, user): # RETURN THE BONDS cls.return_bond(order.taker_bond) cls.return_bond(order.maker_bond) - order.log("Taker bond was unlocked") - order.log("Maker bond was unlocked") + order.log("Taker bond was **unlocked**") + order.log("Maker bond was **unlocked**") # !!! KEY LINE - PAYS THE BUYER INVOICE !!! cls.pay_buyer(order) diff --git a/api/management/commands/follow_invoices.py b/api/management/commands/follow_invoices.py index 58d953a75..24e212bce 100644 --- a/api/management/commands/follow_invoices.py +++ b/api/management/commands/follow_invoices.py @@ -228,7 +228,7 @@ def update_order_status(self, lnpayment): # It is a maker bond => Publish order. if hasattr(lnpayment, "order_made"): self.stderr.write("Updating order with new Locked bond from maker") - lnpayment.order_made.log("Maker bond locked") + lnpayment.order_made.log("Maker bond **locked**") Logics.publish_order(lnpayment.order_made) send_notification.delay( order_id=lnpayment.order_made.id, message="order_published" @@ -242,7 +242,7 @@ def update_order_status(self, lnpayment): self.stderr.write( "Updating order with new Locked bond from taker" ) - lnpayment.take_order.order.log("Taker bond locked") + lnpayment.take_order.order.log("Taker bond **locked**") Logics.finalize_contract(lnpayment.take_order) else: # It there was another taker already locked => cancel bond. @@ -250,7 +250,7 @@ def update_order_status(self, lnpayment): "Expiring take_order because order was already taken" ) lnpayment.take_order.order.log( - "Another taker bond is already locked, Cancelling" + "Another taker bond is already locked, **Cancelling**" ) Logics.take_order_expires(lnpayment.take_order) @@ -259,7 +259,7 @@ def update_order_status(self, lnpayment): # It is a trade escrow => move foward order status. elif hasattr(lnpayment, "order_escrow"): self.stderr.write("Updating order with new Locked escrow") - lnpayment.order_escrow.log("Trade escrow locked") + lnpayment.order_escrow.log("Trade escrow **locked**") Logics.trade_escrow_received(lnpayment.order_escrow) return diff --git a/api/models/order.py b/api/models/order.py index 612486fdd..ef46a7d94 100644 --- a/api/models/order.py +++ b/api/models/order.py @@ -1,4 +1,5 @@ # We use custom seeded UUID generation during testing +import json import uuid from decimal import Decimal @@ -340,21 +341,21 @@ def t_to_expire(self, status): return t_to_expire[status] def log(self, event="empty event", level="INFO"): - """ - log() adds a new line to the Order.log field. We wrap it all in a - try/catch block since this function is called inside the main request->response - pipe and any error here would lead to a 500 response. - """ if config("DISABLE_ORDER_LOGS", cast=bool, default=True): return try: - timestamp = timezone.now().replace(microsecond=0).isoformat() - level_in_tag = "" if level == "INFO" else "" - level_out_tag = "" if level == "INFO" else "" - self.logs = ( - self.logs - + f"{timestamp}{level_in_tag}{level}{level_out_tag}{event}" + try: + entries = json.loads(self.logs) + except (json.JSONDecodeError, TypeError): + entries = [] + entries.append( + { + "timestamp": timezone.now().replace(microsecond=0).isoformat(), + "level": level, + "event": str(event), + } ) + self.logs = json.dumps(entries) self.save(update_fields=["logs"]) except Exception: pass diff --git a/api/tests/test_utils.py b/api/tests/test_utils.py index 16d171944..8869930e6 100644 --- a/api/tests/test_utils.py +++ b/api/tests/test_utils.py @@ -19,7 +19,7 @@ get_session, hex_to_base91, is_valid_token, - objects_to_hyperlinks, + render_order_logs, validate_onchain_address, validate_pgp_keys, verify_signed_message, @@ -292,9 +292,35 @@ def test_is_valid_token(self): self.assertFalse(is_valid_token(invalid_token_2)) self.assertFalse(is_valid_token(invalid_token_3)) - def test_objects_to_hyperlinks(self): - logs = "Robot(1, robot_name)" - linked_logs = objects_to_hyperlinks(logs) - self.assertEqual( - linked_logs, 'robot_name' + def test_render_order_logs(self): + import json + + raw = json.dumps( + [ + { + "timestamp": "2026-01-01T00:00:00+00:00", + "level": "INFO", + "event": "Pre-Taken by Robot(1, robot_name) for 100 fiat units", + } + ] + ) + html_out = render_order_logs(raw) + self.assertIn( + 'robot_name', html_out + ) + + def test_render_order_logs_escapes_html(self): + import json + + raw = json.dumps( + [ + { + "timestamp": "2026-01-01T00:00:00+00:00", + "level": "INFO", + "event": "", + } + ] ) + html_out = render_order_logs(raw) + self.assertNotIn("