defmodule DaProductApp.Switch.EnhancedProtocol do @moduledoc """ Enhanced Ranch protocol that integrates with IncomingMessageProcessor. This protocol: 1. Receives raw TCP messages from devices 2. Unpacks using configured channel packager 3. Passes ISOMsg to IncomingMessageProcessor 4. Handles responses and sends back to device Pure ISOMsg flow throughout the pipeline. Phase 2.2: TCP Layer Immediate Reversal - Executes immediate reversal when response send fails to device - Integrates with existing immediate reversal pattern from acquirer.ex """ @behaviour :ranch_protocol require Logger alias DaProductApp.MercuryISO8583.Packagers.ISOMsg alias DaProductApp.Switch.{IncomingMessageProcessor, ChannelManager} alias DaProductApp.MercuryISO8583.Headers.{HeaderFactory, HeaderBehaviour, BaseHeader, HeaderProcessor} alias DaProductApp.Acquirer alias DaProductApp.Acquirer.Schemas.PosTempTransaction alias DaProductApp.Repo import Ecto.Query def start_link(ref, transport, opts) do pid = spawn_link(__MODULE__, :init, [ref, transport, opts]) {:ok, pid} end def init(ref, transport, _opts) do {:ok, socket} = :ranch.handshake(ref) # Get port from socket to determine channel configuration {:ok, {_ip, port}} = transport.sockname(socket) Logger.info("New connection on port #{port}") case ChannelManager.create_channel_context(port, %{socket: socket, transport: transport}) do {:ok, channel_context} -> Logger.info("Channel context created for port #{port}: #{channel_context.name}") loop(socket, transport, channel_context) {:error, reason} -> Logger.error("Failed to create channel context for port #{port}: #{inspect(reason)}") transport.close(socket) end end defp loop(socket, transport, channel_context) do case transport.recv(socket, 2, 30_000) do {:ok, <>} -> case transport.recv(socket, length, 30_000) do {:ok, data} -> Logger.debug("Received #{byte_size(data)} bytes on port #{channel_context.port}") case process_incoming_data(data, channel_context) do {:ok, response_data} -> send_response(socket, transport, response_data, channel_context) loop(socket, transport, channel_context) {:error, reason} -> Logger.error("Message processing failed: #{inspect(reason)}") # Continue listening for more messages loop(socket, transport, channel_context) end {:error, reason} -> Logger.info("Connection closed or error receiving data: #{inspect(reason)}") transport.close(socket) end {:error, reason} -> Logger.info("Connection closed or error receiving length: #{inspect(reason)}") transport.close(socket) end end defp process_incoming_data(data, channel_context) do Logger.debug("Processing incoming data with channel packager") #print the hex dump of the data Logger.debug("Received Data (hex): #{Base.encode16(data)}") try do # Unpack using channel-specific packager (handles headers internally) case unpack_with_channel_packager(data, channel_context) do {:ok, iso_message} -> Logger.info("Successfully unpacked message MTI: #{ISOMsg.get_mti(iso_message)}") # Process through IncomingMessageProcessor case IncomingMessageProcessor.process_message(iso_message, channel_context) do {:ok, response_message} -> # Pack response using channel packager pack_with_channel_packager(response_message, channel_context) {:error, reason} -> Logger.error("Message processing failed: #{inspect(reason)}") {:error, reason} end {:error, reason} -> Logger.error("Message unpacking failed: #{inspect(reason)}") {:error, reason} end rescue exception -> Logger.error("Exception in process_incoming_data: #{inspect(exception)}") {:error, {:processing_exception, exception}} end end defp unpack_with_channel_packager(data, channel_context) do # Extract headers first, then unpack ISO message case extract_channel_headers(data, channel_context) do {:ok, iso_data, extracted_header} -> # Store extracted header for response reuse enhanced_context = if extracted_header do Map.put(channel_context, :extracted_header, extracted_header) else channel_context end # Unpack ISO message case unpack_iso_message(iso_data, enhanced_context) do {:ok, iso_message} -> Logger.info("ISO Message dump:") ISOMsg.dump_iso(iso_message,"incoming") {:ok, iso_message} {:error, reason} -> {:error, reason} end {:error, reason} -> Logger.error("Header extraction failed: #{inspect(reason)}") {:error, {:header_extraction_failed, reason}} end end defp extract_channel_headers(data, channel_context) do header_config = Map.get(channel_context, :header_config) case HeaderProcessor.process_message(data, header_config, :inbound) do {:ok, {iso_data, header_info}} -> Logger.debug("Successfully extracted channel header using HeaderProcessor") if header_info do Logger.debug("Header info: #{inspect(header_info)}") end {:ok, iso_data, header_info} {:error, reason} -> Logger.error("Header extraction failed: #{inspect(reason)}") {:error, {:header_extraction_failed, reason}} end end defp unpack_iso_message(data, channel_context) do packager = Map.get(channel_context, :packager) # Use default packager if none configured if is_nil(packager) do Logger.warn("Channel packager is nil, defaulting to ISO87BPackager") packager = DaProductApp.MercuryISO8583.Packagers.ISO87BPackager end Logger.debug("Using packager: #{inspect(packager)}") Logger.debug("Unpacking ISO data of size: #{byte_size(data)} bytes") Logger.debug("Data (hex): #{Base.encode16(data)}") case packager.unpack(data) do {:ok, iso_message} -> Logger.debug("ISO message unpacked successfully") {:ok, iso_message} {:error, reason} -> Logger.error("Failed to unpack ISO message: #{inspect(reason)}") {:error, {:iso_unpack_failed, reason}} end end defp pack_with_channel_packager(iso_message, channel_context) do # Ensure the message uses the channel packager packager = Map.get(channel_context, :packager) message_with_packager = ISOMsg.set_packager(iso_message, packager) ISOMsg.dump_iso(iso_message) # Delegate to channel-specific packing (like BCD channel pattern) case pack_message_with_channel(message_with_packager, channel_context) do {:ok, packed_data} -> Logger.debug("Message packed with channel: #{byte_size(packed_data)} bytes") {:ok, packed_data} {:error, reason} -> Logger.error("Failed to pack message with channel: #{inspect(reason)}") {:error, {:channel_pack_failed, reason}} end end defp pack_message_with_channel(iso_message, channel_context) do # Use channel-specific packing that handles headers internally # This follows the BCD channel pattern where headers are handled in pack_message packager = Map.get(channel_context, :packager) if packager do case packager.pack(iso_message) do {:ok, packed_iso_data} -> # Add channel-specific framing (headers/TPDU) if configured add_channel_framing(packed_iso_data, channel_context) {:error, reason} -> {:error, {:packager_failed, reason}} end else {:error, :no_packager} end end defp add_channel_framing(packed_iso_data, channel_context) do header_config = Map.get(channel_context, :header_config) case HeaderProcessor.process_message(packed_iso_data, header_config, :outbound) do {:ok, framed_message} -> Logger.debug("Successfully added channel header using HeaderProcessor") {:ok, framed_message} {:error, reason} -> Logger.error("Header addition failed: #{inspect(reason)}") {:error, {:header_add_failed, reason}} end end defp send_response(socket, transport, response_data, channel_context) when is_binary(response_data) do # Send with length prefix (length includes headers + ISO data) total_length = byte_size(response_data) message = <> <> response_data Logger.debug("Sending response - Total length: #{total_length} bytes") Logger.debug("Length prefix: #{Base.encode16(<>)}") Logger.debug("Response Data (hex): #{Base.encode16(response_data)}") Logger.debug("Full message (hex): #{Base.encode16(message)}") case transport.send(socket, message) do :ok -> Logger.debug("Response sent successfully - Total: #{byte_size(message)} bytes (#{total_length} + 2 length prefix)") :ok {:error, reason} -> Logger.error("🔴 Failed to send response to device: #{inspect(reason)} - executing immediate reversal") # Execute immediate reversal for downstream send failure execute_immediate_reversal_for_send_failure(channel_context, reason) {:error, reason} end end # Phase 2.2: Execute immediate reversal for downstream send failure defp execute_immediate_reversal_for_send_failure(channel_context, send_error) do # Extract temp transaction context from channel context case Map.get(channel_context, :temp_transaction_context) do %{s_tid: s_tid, s_mid: s_mid, s_tid_stan: s_tid_stan} = temp_txn_context -> Logger.warning("🔴 Executing immediate reversal for send failure - Port: #{Map.get(channel_context, :port)}") # Find temp transaction and execute immediate reversal case Acquirer.get_temp_transaction_by_switch_ids(s_tid, s_mid, s_tid_stan) do %DaProductApp.Acquirer.Schemas.PosTempTransaction{} = temp_txn -> reason = "DOWNSTREAM_SEND_FAILED_#{inspect(send_error)}" Logger.warning("Found temp txn #{temp_txn.id} - executing immediate reversal for: #{reason}") # Use existing immediate reversal pattern from Phase 2.1 case DaProductApp.Acquirer.ReversalOrchestrator.create_automatic_reversal(temp_txn, reason) do {:ok, reversal} -> Logger.info("✅ Downstream send failure reversal #{reversal.id} created successfully for temp txn #{temp_txn.id}") {:error, reversal_error} -> Logger.error("🔴 Downstream send failure reversal FAILED for temp txn #{temp_txn.id}: #{inspect(reversal_error)}") # Mark temp txn for cleanup worker to retry mark_temp_txn_for_cleanup_retry(temp_txn, reason, reversal_error) end nil -> Logger.warning("⚠️ No temp transaction found for send failure reversal: #{inspect(temp_txn_context)}") end nil -> Logger.warning("⚠️ No temp transaction context available for send failure reversal") invalid_context -> Logger.warning("⚠️ Invalid temp transaction context for send failure reversal: #{inspect(invalid_context)}") end rescue exception -> Logger.error("🔴 Exception in send failure reversal: #{inspect(exception)}") end # Mark temp transaction for cleanup worker to retry reversal defp mark_temp_txn_for_cleanup_retry(temp_txn, reason, error) do from(t in PosTempTransaction, where: t.id == ^temp_txn.id) |> Repo.update_all( set: [ status: "REVERSAL_FAILED", reversal_initiated_reason: reason, error_message: "Reversal failed: #{inspect(error)}", last_reversal_attempt_at: DateTime.utc_now(), updated_at: DateTime.utc_now() ] ) Logger.warning("Marked temp txn #{temp_txn.id} as REVERSAL_FAILED - cleanup worker will retry") end end