Error: failed to read message from connection after response

[sufuk]

I'm encountering an issue where the server logs show an error after sending a response to the client. The error message is:
Error: failed to read message from connection

Although the client successfully receives a response (MTI: 0110), the server logs an error right after writing the response. The connection is then closed.

Is there something I might be missing in how I'm handling the communication? Any insights or fixes would be appreciated.

Thanks!
Client Log:

2025/02/14 14:26:39 Connected to server  
2025/02/14 14:26:39 Connection established  
2025/02/14 14:26:39 Length header written: 107 bytes  
2025/02/14 14:26:39 Length header read: 109 bytes  
2025/02/14 14:26:39 Received response with MTI: 0110  

Server Log:

2025/02/14 14:26:39 New connection established  
2025/02/14 14:26:39 Length header read: 107 bytes  
2025/02/14 14:26:39 Inbound message received  
2025/02/14 14:26:39 Received Message: {MTI:0100 PAN:4242424242424242 Amount:1000 TransactionDatetime:250214142639 Currency:840 CVV:7890 ExpirationDate:2512 AcceptorInformation:0x14000182080 STAN:000001}  
2025/02/14 14:26:39 Length header written: 109 bytes  
2025/02/14 14:26:39 Error: failed to read message from connection  
2025/02/14 14:26:39 Connection closed 

Server Code:

package main

import (
	"encoding/binary"
	"fmt"
	"github.com/moov-io/iso8583/sort"
	"io"
	"log"
	"net"
	"time"

	"github.com/moov-io/iso8583"
	"github.com/moov-io/iso8583-connection"
	"github.com/moov-io/iso8583-connection/server"
	"github.com/moov-io/iso8583/encoding"
	"github.com/moov-io/iso8583/field"
	"github.com/moov-io/iso8583/padding"
	"github.com/moov-io/iso8583/prefix"
)

var spec *iso8583.MessageSpec = &iso8583.MessageSpec{
	Name: "ISO 8583 CardFlow Playground ASCII Specification",
	Fields: map[int]field.Field{
		0: field.NewString(&field.Spec{
			Length:      4,
			Description: "Message Type Indicator",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		1: field.NewBitmap(&field.Spec{
			Length:      8,
			Description: "Bitmap",
			Enc:         encoding.Binary,
			Pref:        prefix.Binary.Fixed,
		}),
		2: field.NewString(&field.Spec{
			Length:      19,
			Description: "Primary Account Number (PAN)",
			Enc:         encoding.BCD,
			Pref:        prefix.ASCII.LL,
		}),
		3: field.NewString(&field.Spec{
			Length:      6,
			Description: "Amount",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
			Pad:         padding.Left('0'),
		}),
		4: field.NewString(&field.Spec{
			Length:      12,
			Description: "Transmission Date & Time", // YYMMDDHHMMSS
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		5: field.NewString(&field.Spec{
			Length:      2,
			Description: "Approval Code",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		6: field.NewString(&field.Spec{
			Length:      6,
			Description: "Authorization Code",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		7: field.NewString(&field.Spec{
			Length:      3,
			Description: "Currency",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		8: field.NewString(&field.Spec{
			Length:      4,
			Description: "Card Verification Value (CVV)",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		9: field.NewString(&field.Spec{
			Length:      4,
			Description: "Card Expiration Date",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		10: field.NewComposite(&field.Spec{
			Length:      999,
			Description: "Acceptor Information",
			Pref:        prefix.ASCII.LLL,
			Tag: &field.TagSpec{
				Length: 2,
				Enc:    encoding.ASCII,
				Sort:   sort.StringsByInt,
			},
			Subfields: map[string]field.Field{
				"01": field.NewString(&field.Spec{
					Length:      99,
					Description: "Merchant Name",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.LL,
				}),
				"02": field.NewString(&field.Spec{
					Length:      4,
					Description: "Merchant Category Code (MCC)",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.Fixed,
				}),
				"03": field.NewString(&field.Spec{
					Length:      10,
					Description: "Merchant Postal Code",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.LL,
				}),
				"04": field.NewString(&field.Spec{
					Length:      299,
					Description: "Merchant Website",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.LLL,
				}),
			},
		}),
		11: field.NewString(&field.Spec{
			Length:      6,
			Description: "Systems Trace Audit Number (STAN)",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		39: field.NewString(&field.Spec{
			Length:      2,
			Description: "Response Code",
			Enc:         encoding.ASCII,
			Pref:        prefix.ASCII.Fixed,
		}),
	},
}

type AcceptorInformation struct {
	MerchantName         string `iso8583:"01"`
	MerchantCategoryCode string `iso8583:"02"`
	MerchantPostalCode   string `iso8583:"03"`
	MerchantWebsite      string `iso8583:"04"`
}

type AuthorizationRequest struct {
	MTI                 string               `iso8583:"0"`
	PAN                 string               `iso8583:"2"`
	Amount              int64                `iso8583:"3"`
	TransactionDatetime string               `iso8583:"4"`
	Currency            string               `iso8583:"7"`
	CVV                 string               `iso8583:"8"`
	ExpirationDate      string               `iso8583:"9"`
	AcceptorInformation *AcceptorInformation `iso8583:"10"`
	STAN                string               `iso8583:"11"`
}

type AuthorizationResponse struct {
	MTI                 string               `iso8583:"0"`
	PAN                 string               `iso8583:"2"`
	Amount              int64                `iso8583:"3"`
	TransactionDatetime string               `iso8583:"4"`
	Currency            string               `iso8583:"7"`
	CVV                 string               `iso8583:"8"`
	ExpirationDate      string               `iso8583:"9"`
	AcceptorInformation *AcceptorInformation `iso8583:"10"`
	STAN                string               `iso8583:"11"`
	ResponseCode        string               `iso8583:"39"`
}

// LengthHeaderReader reads the length header from the connection
func LengthHeaderReader(r io.Reader) (int, error) {
	var length uint16
	if err := binary.Read(r, binary.BigEndian, &length); err != nil {
		return 0, fmt.Errorf("failed to read length header: %w", err)
	}
	log.Printf("Length header read: %d bytes", length)
	return int(length), nil
}

// LengthHeaderWriter writes the length header to the connection
func LengthHeaderWriter(w io.Writer, length int) (int, error) {
	if err := binary.Write(w, binary.BigEndian, uint16(length)); err != nil {
		return 0, fmt.Errorf("failed to write length header: %w", err)
	}
	log.Printf("Length header written: %d bytes", length)
	return 2, nil // 2 bytes for uint16
}

func PingHandler(c *connection.Connection) {
	log.Printf("Ping request received")
}

func ReadTimeoutHandler(c *connection.Connection) {
	log.Printf("Read timeout request received")
}
func ConnectionEstablishedHandler(c *connection.Connection) {
	log.Printf("Connection established")
}
func ErrorHandler(err error) {
	log.Printf("Error: %v", err)
}

func main() {
	// Create a new ISO 8583 server
	s := server.New(spec, LengthHeaderReader, LengthHeaderWriter)

	// Set up a custom connection factory
	err := s.SetOptions(server.WithConnectionFactory(func(conn net.Conn) (*connection.Connection, error) {
		log.Println("New connection established")
		return connection.NewFrom(conn, spec, LengthHeaderReader, LengthHeaderWriter,
			connection.InboundMessageHandler(inboundMessageHandler),
			connection.ConnectionClosedHandler(connectionClosedHandler),
			connection.PingHandler(PingHandler),
			connection.ReadTimeoutHandler(ReadTimeoutHandler),
			connection.ConnectionEstablishedHandler(ConnectionEstablishedHandler),
			connection.ErrorHandler(ErrorHandler),
		)
	}))
	if err != nil {
		log.Fatalf("Failed to set up server: %v", err)
		return
	}

	// Start the server on port 5000
	if err := s.Start("127.0.0.1:5000"); err != nil {
		log.Fatalf("Failed to start server: %v", err)
	}
	defer s.Close()

	log.Println("ISO 8583 Server is running on port 5000...")

	// Keep the server running
	select {}
}

// inboundMessageHandler processes incoming messages
func inboundMessageHandler(c *connection.Connection, message *iso8583.Message) {
	log.Println("Inbound message received")

	// Unmarshal the incoming message into a struct
	var request AuthorizationRequest
	if err := message.Unmarshal(&request); err != nil {
		log.Printf("Failed to unmarshal message: %v", err)
		return
	}

	// Print the received message fields
	log.Printf("Received Message: %+v", request)

	// Create a response message
	responseMessage := iso8583.NewMessage(spec)
	response := AuthorizationResponse{
		MTI:                 "0110", // Response MTI
		PAN:                 request.PAN,
		Amount:              request.Amount,
		TransactionDatetime: time.Now().Format("060102150405"),
		Currency:            request.Currency,
		CVV:                 request.CVV,
		ExpirationDate:      request.ExpirationDate,
		AcceptorInformation: request.AcceptorInformation,
		STAN:                request.STAN,
		ResponseCode:        "00", // Approved
	}

	// Marshal the response into the message
	if err := responseMessage.Marshal(&response); err != nil {
		log.Printf("Failed to marshal response: %v", err)
		return
	}

	// Send the response back to the client
	if err := c.Reply(responseMessage); err != nil {
		log.Printf("Failed to send response: %v", err)
	}
}

// connectionClosedHandler handles connection closure
func connectionClosedHandler(c *connection.Connection) {
	log.Println("Connection closed")
}

Client Code:

package main

import (
	"encoding/binary"
	"fmt"
	"github.com/moov-io/iso8583/sort"
	"io"
	"log"
	"time"

	"github.com/moov-io/iso8583"
	"github.com/moov-io/iso8583-connection"
	"github.com/moov-io/iso8583/encoding"
	"github.com/moov-io/iso8583/field"
	"github.com/moov-io/iso8583/padding"
	"github.com/moov-io/iso8583/prefix"
)

var spec *iso8583.MessageSpec = &iso8583.MessageSpec{
	Name: "ISO 8583 CardFlow Playground ASCII Specification",
	Fields: map[int]field.Field{
		0: field.NewString(&field.Spec{
			Length:      4,
			Description: "Message Type Indicator",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		1: field.NewBitmap(&field.Spec{
			Length:      8,
			Description: "Bitmap",
			Enc:         encoding.Binary,
			Pref:        prefix.Binary.Fixed,
		}),
		2: field.NewString(&field.Spec{
			Length:      19,
			Description: "Primary Account Number (PAN)",
			Enc:         encoding.BCD,
			Pref:        prefix.ASCII.LL,
		}),
		3: field.NewString(&field.Spec{
			Length:      6,
			Description: "Amount",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
			Pad:         padding.Left('0'),
		}),
		4: field.NewString(&field.Spec{
			Length:      12,
			Description: "Transmission Date & Time", // YYMMDDHHMMSS
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		5: field.NewString(&field.Spec{
			Length:      2,
			Description: "Approval Code",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		6: field.NewString(&field.Spec{
			Length:      6,
			Description: "Authorization Code",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		7: field.NewString(&field.Spec{
			Length:      3,
			Description: "Currency",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		8: field.NewString(&field.Spec{
			Length:      4,
			Description: "Card Verification Value (CVV)",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		9: field.NewString(&field.Spec{
			Length:      4,
			Description: "Card Expiration Date",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		10: field.NewComposite(&field.Spec{
			Length:      999,
			Description: "Acceptor Information",
			Pref:        prefix.ASCII.LLL,
			Tag: &field.TagSpec{
				Length: 2,
				Enc:    encoding.ASCII,
				Sort:   sort.StringsByInt,
			},
			Subfields: map[string]field.Field{
				"01": field.NewString(&field.Spec{
					Length:      99,
					Description: "Merchant Name",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.LL,
				}),
				"02": field.NewString(&field.Spec{
					Length:      4,
					Description: "Merchant Category Code (MCC)",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.Fixed,
				}),
				"03": field.NewString(&field.Spec{
					Length:      10,
					Description: "Merchant Postal Code",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.LL,
				}),
				"04": field.NewString(&field.Spec{
					Length:      299,
					Description: "Merchant Website",
					Enc:         encoding.ASCII,
					Pref:        prefix.ASCII.LLL,
				}),
			},
		}),
		11: field.NewString(&field.Spec{
			Length:      6,
			Description: "Systems Trace Audit Number (STAN)",
			Enc:         encoding.BCD,
			Pref:        prefix.BCD.Fixed,
		}),
		39: field.NewString(&field.Spec{
			Length:      2,
			Description: "Response Code",
			Enc:         encoding.ASCII,
			Pref:        prefix.ASCII.Fixed,
		}),
	},
}

// LengthHeaderReader reads the length header from the connection
func LengthHeaderReader(r io.Reader) (int, error) {
	var length uint16
	if err := binary.Read(r, binary.BigEndian, &length); err != nil {
		return 0, fmt.Errorf("failed to read length header: %w", err)
	}
	log.Printf("Length header read: %d bytes", length)
	return int(length), nil
}

// LengthHeaderWriter writes the length header to the connection
func LengthHeaderWriter(w io.Writer, length int) (int, error) {
	if err := binary.Write(w, binary.BigEndian, uint16(length)); err != nil {
		return 0, fmt.Errorf("failed to write length header: %w", err)
	}
	log.Printf("Length header written: %d bytes", length)
	return 2, nil // 2 bytes for uint16
}

func PingHandler(c *connection.Connection) {
	log.Printf("Ping request received")
}

func ReadTimeoutHandler(c *connection.Connection) {
	log.Printf("Read timeout request received")
}
func ConnectionEstablishedHandler(c *connection.Connection) {
	log.Printf("Connection established")
}
func ErrorHandler(err error) {
	log.Printf("Error: %v", err)
}

type AcceptorInformation struct {
	MerchantName         string `iso8583:"01"`
	MerchantCategoryCode string `iso8583:"02"`
	MerchantPostalCode   string `iso8583:"03"`
	MerchantWebsite      string `iso8583:"04"`
}

type AuthorizationRequest struct {
	MTI                 string               `iso8583:"0"`
	PAN                 string               `iso8583:"2"`
	Amount              int64                `iso8583:"3"`
	TransactionDatetime string               `iso8583:"4"`
	Currency            string               `iso8583:"7"`
	CVV                 string               `iso8583:"8"`
	ExpirationDate      string               `iso8583:"9"`
	AcceptorInformation *AcceptorInformation `iso8583:"10"`
	STAN                string               `iso8583:"11"`
}

func main() {
	// Server address
	serverAddr := "127.0.0.1:5000"

	// Create a new connection
	conn, err := connection.New(
		serverAddr,
		spec,
		LengthHeaderReader,
		LengthHeaderWriter,
		connection.ConnectTimeout(5*time.Second),
		connection.SendTimeout(5*time.Second),
		connection.ConnectionClosedHandler(connectionClosedHandler),
		connection.PingHandler(PingHandler),
		connection.ReadTimeoutHandler(ReadTimeoutHandler),
		connection.ConnectionEstablishedHandler(ConnectionEstablishedHandler),
		connection.ErrorHandler(ErrorHandler),
	)
	if err != nil {
		log.Fatalf("Failed to create connection: %v", err)
	}

	// Connect to the server
	if err := conn.Connect(); err != nil {
		log.Fatalf("Failed to connect to server: %v", err)
	}
	defer conn.Close()

	log.Println("Connected to server")

	requestMessage := iso8583.NewMessage(spec)
	// Set the message fields
	err = requestMessage.Marshal(&AuthorizationRequest{
		MTI:                 "0100",
		PAN:                 "4242424242424242",
		Amount:              1000,
		TransactionDatetime: time.Now().Format("060102150405"),
		Currency:            "840",
		CVV:                 "7890",
		ExpirationDate:      "2512",
		AcceptorInformation: &AcceptorInformation{
			MerchantName:         "Merchant Name",
			MerchantCategoryCode: "1234",
			MerchantPostalCode:   "1234567890",
			MerchantWebsite:      "https://www.merchant.com",
		},
		STAN: "000001",
	})

	// Send the message
	response, err := conn.Send(requestMessage)
	if err != nil {
		log.Fatalf("Failed to send message: %v", err)
	}

	conn.Close()

	// Process the response
	mti, err := response.GetMTI()
	if err != nil {
		log.Fatalf("Failed to get MTI from response: %v", err)
	}
	log.Printf("Received response with MTI: %s\n", mti)
}

// connectionClosedHandler handles connection closure
func connectionClosedHandler(c *connection.Connection) {
	log.Println("Connection closed")
}

[alovak]

What you see here is the normal error: server is waiting for a message from client, but client closes the connection.The error message is confusing in some sense. In the production setup client session is long-lived. You don't close connection after each message. In your main() you connect, send and close. Server is constantly waiting for a message and when connection is closed it shows the error.

[sufuk]

What you see here is the normal error: server is waiting for a message from client, but client closes the connection.The error message is confusing in some sense. In the production setup client session is long-lived. You don't close connection after each message. In your main() you connect, send and close. Server is constantly waiting for a message and when connection is closed it shows the error.

Even if you close connection after response it shouldn't give error its confusing and there are some scenarios you just do that like POS connects sends non-emv transaction (like MSR) waits for response then closes the connection, or end of day messages can be handled with single request and response (if there is no unmatched transactions). How can we differentiate a "real error" and those scenarios? Maybe this not needed when an acquirer and issuers communicates but its definetly needed when a pos device communicates with acquirer.