diff --git a/broker/events/eventmodels.go b/broker/events/eventmodels.go index fcbf369c..f96d8955 100644 --- a/broker/events/eventmodels.go +++ b/broker/events/eventmodels.go @@ -45,6 +45,8 @@ const ( EventNameConfirmSupplierMsg EventName = "confirm-supplier-msg" EventNameInvokeAction EventName = "invoke-action" EventNamePatronRequestMessage EventName = "patron-request-message" + EventNameLmsRequesterMessage EventName = "lms-requester-message" + EventNameLmsSupplierMessage EventName = "lms-supplier-message" ) type Signal string diff --git a/broker/lms/lms_adapter.go b/broker/lms/lms_adapter.go index 4fae1489..78ccef4b 100644 --- a/broker/lms/lms_adapter.go +++ b/broker/lms/lms_adapter.go @@ -1,8 +1,12 @@ package lms +import "github.com/indexdata/crosslink/broker/ncipclient" + // LmsAdapter is an interface defining methods for interacting with a Library Management System (LMS) // https://github.com/openlibraryenvironment/mod-rs/blob/master/service/src/main/groovy/org/olf/rs/lms/HostLMSActions.groovy type LmsAdapter interface { + SetLogFunc(logFunc ncipclient.NcipLogFunc) + LookupUser(patron string) (string, error) AcceptItem( diff --git a/broker/lms/lms_adapter_manual.go b/broker/lms/lms_adapter_manual.go index 746fe1f7..cdf4820b 100644 --- a/broker/lms/lms_adapter_manual.go +++ b/broker/lms/lms_adapter_manual.go @@ -1,8 +1,13 @@ package lms +import "github.com/indexdata/crosslink/broker/ncipclient" + type LmsAdapterManual struct { } +func (l *LmsAdapterManual) SetLogFunc(logFunc ncipclient.NcipLogFunc) { +} + func (l *LmsAdapterManual) LookupUser(patron string) (string, error) { return patron, nil } diff --git a/broker/lms/lms_adapter_ncip.go b/broker/lms/lms_adapter_ncip.go index 34d42cf6..ffc80689 100644 --- a/broker/lms/lms_adapter_ncip.go +++ b/broker/lms/lms_adapter_ncip.go @@ -52,6 +52,10 @@ func CreateLmsAdapterNcip(lmsConfig directory.LmsConfig) (LmsAdapter, error) { return l, nil } +func (l *LmsAdapterNcip) SetLogFunc(logFunc ncipclient.NcipLogFunc) { + l.ncipClient.SetLogFunc(logFunc) +} + func (l *LmsAdapterNcip) LookupUser(patron string) (string, error) { if l.config.LookupUserEnabled != nil && !*l.config.LookupUserEnabled { return patron, nil // could even be empty diff --git a/broker/lms/lms_adapter_test.go b/broker/lms/lms_adapter_test.go index 0e656983..14348ee9 100644 --- a/broker/lms/lms_adapter_test.go +++ b/broker/lms/lms_adapter_test.go @@ -366,6 +366,10 @@ type ncipClientMock struct { lastRequest any } +func (n *ncipClientMock) SetLogFunc(logFunc ncipclient.NcipLogFunc) { + // no-op +} + func (n *ncipClientMock) LookupUser(lookup ncip.LookupUser) (*ncip.LookupUserResponse, error) { n.lastRequest = lookup if lookup.UserId != nil { diff --git a/broker/migrations/017_add_lms_events.down.sql b/broker/migrations/017_add_lms_events.down.sql new file mode 100644 index 00000000..0881a2f6 --- /dev/null +++ b/broker/migrations/017_add_lms_events.down.sql @@ -0,0 +1,3 @@ +DELETE FROM event_config WHERE event_name ='lms-requester-message'; +DELETE FROM event_config WHERE event_name ='lms-supplier-message'; + diff --git a/broker/migrations/017_add_lms_events.up.sql b/broker/migrations/017_add_lms_events.up.sql new file mode 100644 index 00000000..2c1c6cbe --- /dev/null +++ b/broker/migrations/017_add_lms_events.up.sql @@ -0,0 +1,4 @@ +INSERT INTO event_config (event_name, event_type, retry_count) +VALUES ('lms-requester-message', 'NOTICE', 1); +INSERT INTO event_config (event_name, event_type, retry_count) +VALUES ('lms-supplier-message', 'NOTICE', 1); diff --git a/broker/ncipclient/ncipclient.go b/broker/ncipclient/ncipclient.go index 0a0820bc..1a85027b 100644 --- a/broker/ncipclient/ncipclient.go +++ b/broker/ncipclient/ncipclient.go @@ -2,7 +2,11 @@ package ncipclient import "github.com/indexdata/crosslink/ncip" +type NcipLogFunc func(outgoing []byte, incoming []byte, err error) + type NcipClient interface { + SetLogFunc(logFunc NcipLogFunc) + LookupUser(arg ncip.LookupUser) (*ncip.LookupUserResponse, error) AcceptItem(arg ncip.AcceptItem) (*ncip.AcceptItemResponse, error) diff --git a/broker/ncipclient/ncipclient_impl.go b/broker/ncipclient/ncipclient_impl.go index a24ec915..f35286da 100644 --- a/broker/ncipclient/ncipclient_impl.go +++ b/broker/ncipclient/ncipclient_impl.go @@ -4,6 +4,7 @@ import ( "encoding/xml" "fmt" "net/http" + "reflect" "github.com/indexdata/crosslink/httpclient" "github.com/indexdata/crosslink/ncip" @@ -15,6 +16,7 @@ type NcipClientImpl struct { fromAgency string toAgency string fromAgencyAuthentication string + logFunc NcipLogFunc } func NewNcipClient(client *http.Client, address string, fromAgency string, toAgency string, fromAgencyAuthentication string) NcipClient { @@ -27,6 +29,10 @@ func NewNcipClient(client *http.Client, address string, fromAgency string, toAge } } +func (n *NcipClientImpl) SetLogFunc(logFunc NcipLogFunc) { + n.logFunc = logFunc +} + func (n *NcipClientImpl) LookupUser(lookup ncip.LookupUser) (*ncip.LookupUserResponse, error) { lookup.InitiationHeader = n.prepareHeader(lookup.InitiationHeader) @@ -188,8 +194,29 @@ func (n *NcipClientImpl) sendReceiveMessage(message *ncip.NCIPMessage) (*ncip.NC message.Version = ncip.NCIP_V2_02_XSD var respMessage ncip.NCIPMessage + err := httpclient.NewClient().RequestResponse(n.client, http.MethodPost, []string{httpclient.ContentTypeApplicationXml}, n.address, message, &respMessage, xml.Marshal, xml.Unmarshal) + if n.logFunc != nil { + hideSensitive(message) + var outgoing []byte + var err1 error + outgoing, err1 = xml.MarshalIndent(message, "", " ") + + hideSensitive(&respMessage) + var incoming []byte + var err2 error + incoming, err2 = xml.MarshalIndent(&respMessage, "", " ") + + logErr := err + if logErr == nil { + logErr = err1 + } + if logErr == nil { + logErr = err2 + } + n.logFunc(outgoing, incoming, logErr) + } if err != nil { return nil, fmt.Errorf("NCIP message exchange failed: %s", err.Error()) } @@ -201,3 +228,57 @@ func (n *NcipClientImpl) sendReceiveMessage(message *ncip.NCIPMessage) (*ncip.NC } return &respMessage, nil } + +func hideSensitive(message *ncip.NCIPMessage) { + traverse(reflect.ValueOf(message), 0) +} + +// removes values from the FromAgencyAuthentication and FromSystemAuthentication fields +// as well as AuthenticationInput fields except if type is "username" +func traverse(v reflect.Value, level int) { + if level > 20 { + return + } + level = level + 1 + if !v.IsValid() { + return + } + if v.Kind() == reflect.Ptr { + if v.IsNil() { + return + } + traverse(v.Elem(), level) + return + } + if v.Kind() == reflect.Slice { + if v.IsNil() { + return + } + for i := 0; i < v.Len(); i++ { + traverse(v.Index(i), level) + } + return + } + if v.Kind() != reflect.Struct { + return + } + t := v.Type() + if t == reflect.TypeOf(ncip.AuthenticationInput{}) { + ncipAuthenticationInput := v.Interface().(ncip.AuthenticationInput) + exclude := ncipAuthenticationInput.AuthenticationInputType.Text != "username" + if exclude { + ncipAuthenticationInput.AuthenticationInputData = "***" + v.Set(reflect.ValueOf(ncipAuthenticationInput)) + } + return + } + for i := 0; i < t.NumField(); i++ { + field := t.Field(i) + if field.Type.Kind() == reflect.String && + (field.Name == "FromAgencyAuthentication" || field.Name == "FromSystemAuthentication") { + v.Field(i).SetString("***") + } else { + traverse(v.Field(i), level) + } + } +} diff --git a/broker/ncipclient/ncipclient_test.go b/broker/ncipclient/ncipclient_test.go index 578605a3..57ce4d78 100644 --- a/broker/ncipclient/ncipclient_test.go +++ b/broker/ncipclient/ncipclient_test.go @@ -5,6 +5,7 @@ import ( "net/http" "net/http/httptest" "os" + "reflect" "strconv" "testing" @@ -184,6 +185,16 @@ func TestEmptyNcipResponse(t *testing.T) { ncipClient.fromAgencyAuthentication = "pass" ncipClient.toAgency = "ILL-MOCK" ncipClient.address = server.URL + var logOutgoing []byte + var logIncoming []byte + var logError error + + ncipClient.SetLogFunc(func(outgoing []byte, incoming []byte, err error) { + logOutgoing = outgoing + logIncoming = incoming + logError = err + }) + lookup := ncip.LookupUser{ UserId: &ncip.UserId{ UserIdentifierValue: "validuser", @@ -192,6 +203,9 @@ func TestEmptyNcipResponse(t *testing.T) { _, err := ncipClient.LookupUser(lookup) assert.Error(t, err) assert.Equal(t, "invalid NCIP response: missing LookupUserResponse", err.Error()) + assert.NotNil(t, logOutgoing) + assert.NotNil(t, logIncoming) + assert.Nil(t, logError) accept := ncip.AcceptItem{ RequestId: ncip.RequestId{ @@ -442,3 +456,72 @@ func TestCreateUserFiscalTransactionOK(t *testing.T) { assert.NoError(t, err) assert.NotNil(t, res) } + +func TestHideSensitive(t *testing.T) { + sampleMessage := &ncip.NCIPMessage{ + Version: ncip.NCIP_V2_02_XSD, + LookupUser: &ncip.LookupUser{ + InitiationHeader: &ncip.InitiationHeader{ + ToAgencyId: ncip.ToAgencyId{AgencyId: ncip.SchemeValuePair{Text: "ILL-MOCK"}}, + FromAgencyAuthentication: "supersecret", + FromSystemAuthentication: "othersecret", + }, + UserId: &ncip.UserId{ + UserIdentifierValue: "validuser", + }, + AuthenticationInput: []ncip.AuthenticationInput{ + { + AuthenticationInputType: ncip.SchemeValuePair{Text: "PIN"}, + AuthenticationInputData: "1234", + }, + { + AuthenticationInputType: ncip.SchemeValuePair{Text: "username"}, + AuthenticationInputData: "myuser", + }, + }, + }, + } + hideSensitive(sampleMessage) + assert.Equal(t, "ILL-MOCK", sampleMessage.LookupUser.InitiationHeader.ToAgencyId.AgencyId.Text) + assert.Equal(t, "***", sampleMessage.LookupUser.InitiationHeader.FromAgencyAuthentication) + assert.Equal(t, "***", sampleMessage.LookupUser.InitiationHeader.FromSystemAuthentication) + assert.Equal(t, "validuser", sampleMessage.LookupUser.UserId.UserIdentifierValue) + assert.Equal(t, "***", sampleMessage.LookupUser.AuthenticationInput[0].AuthenticationInputData) + assert.Equal(t, "myuser", sampleMessage.LookupUser.AuthenticationInput[1].AuthenticationInputData) +} + +func TestHideSensitiveLevel(t *testing.T) { + sampleMessage := &ncip.NCIPMessage{} + traverse(reflect.ValueOf(sampleMessage), 30) +} + +func TestHideSensitiveInvalid(t *testing.T) { + invalid := reflect.Value{} + traverse(invalid, 0) +} + +func TestSetLogFunc(t *testing.T) { + ncipClient := createTestClient() + var logOutgoing []byte + var logIncoming []byte + + ncipClient.SetLogFunc(func(outgoing []byte, incoming []byte, err error) { + logOutgoing = outgoing + logIncoming = incoming + }) + + userMessage := ncip.LookupUser{ + InitiationHeader: &ncip.InitiationHeader{ + FromAgencyAuthentication: "supersecret", + }, + UserId: &ncip.UserId{ + UserIdentifierValue: "validuser", + }, + } + + _, err := ncipClient.LookupUser(userMessage) + assert.NoError(t, err) + assert.NotNil(t, logOutgoing) + assert.NotNil(t, logIncoming) + assert.Contains(t, string(logOutgoing), "***") +} diff --git a/broker/patron_request/service/action.go b/broker/patron_request/service/action.go index 60100cfc..03e0edfe 100644 --- a/broker/patron_request/service/action.go +++ b/broker/patron_request/service/action.go @@ -130,6 +130,20 @@ func (a *PatronRequestActionService) handleBorrowingAction(ctx common.ExtendedCo if err != nil { return events.LogErrorAndReturnResult(ctx, "failed to create LMS adapter", err) } + lmsAdapter.SetLogFunc(func(outgoing []byte, incoming []byte, err error) { + status := events.EventStatusSuccess + if err != nil { + status = events.EventStatusError + } + var customData = make(map[string]any) + customData["lmsOutgoingMessage"] = string(outgoing) + customData["lmsIncomingMessage"] = string(incoming) + eventData := events.EventData{CustomData: customData} + _, createErr := a.eventBus.CreateNotice(pr.ID, events.EventNameLmsRequesterMessage, eventData, status, events.EventDomainPatronRequest) + if createErr != nil { + ctx.Logger().Error("failed to create LMS log event", "error", createErr) + } + }) switch action { case BorrowerActionValidate: return a.validateBorrowingRequest(ctx, pr, lmsAdapter) @@ -162,6 +176,20 @@ func (a *PatronRequestActionService) handleLenderAction(ctx common.ExtendedConte if err != nil { return events.LogErrorAndReturnResult(ctx, "failed to create LMS adapter", err) } + lms.SetLogFunc(func(outgoing []byte, incoming []byte, err error) { + status := events.EventStatusSuccess + if err != nil { + status = events.EventStatusError + } + var customData = make(map[string]any) + customData["lmsOutgoingMessage"] = string(outgoing) + customData["lmsIncomingMessage"] = string(incoming) + eventData := events.EventData{CustomData: customData} + _, createErr := a.eventBus.CreateNotice(pr.ID, events.EventNameLmsSupplierMessage, eventData, status, events.EventDomainPatronRequest) + if createErr != nil { + ctx.Logger().Error("failed to create LMS log event", "error", err) + } + }) switch action { case LenderActionValidate: return a.validateLenderRequest(ctx, pr, lms) diff --git a/broker/patron_request/service/action_test.go b/broker/patron_request/service/action_test.go index fb932373..cc8596fd 100644 --- a/broker/patron_request/service/action_test.go +++ b/broker/patron_request/service/action_test.go @@ -12,6 +12,7 @@ import ( "github.com/indexdata/crosslink/broker/events" "github.com/indexdata/crosslink/broker/handler" "github.com/indexdata/crosslink/broker/lms" + "github.com/indexdata/crosslink/broker/ncipclient" pr_db "github.com/indexdata/crosslink/broker/patron_request/db" "github.com/indexdata/crosslink/iso18626" "github.com/jackc/pgx/v5/pgtype" @@ -776,6 +777,9 @@ func createLmsAdapterMockFail() lms.LmsAdapter { type MockLmsAdapterFail struct { } +func (l *MockLmsAdapterFail) SetLogFunc(logFunc ncipclient.NcipLogFunc) { +} + func (l *MockLmsAdapterFail) LookupUser(patron string) (string, error) { return "", errors.New("LookupUser failed") } diff --git a/broker/patron_request/service/message-handler.go b/broker/patron_request/service/message-handler.go index 0158eb4e..5fc20c2e 100644 --- a/broker/patron_request/service/message-handler.go +++ b/broker/patron_request/service/message-handler.go @@ -4,6 +4,9 @@ import ( "encoding/json" "errors" "fmt" + "strings" + "time" + "github.com/google/uuid" "github.com/indexdata/crosslink/broker/common" "github.com/indexdata/crosslink/broker/events" @@ -13,8 +16,6 @@ import ( "github.com/indexdata/go-utils/utils" "github.com/jackc/pgx/v5" "github.com/jackc/pgx/v5/pgtype" - "strings" - "time" ) var SUPPLIER_PATRON_PATTERN = utils.GetEnv("SUPPLIER_PATRON_PATTERN", "%v_user")