Crash: audit log call #111

Closed
opened 2023-07-24 12:19:23 +02:00 by jost · 5 comments
jost commented 2023-07-24 12:19:23 +02:00 (Migrated from gitlab.uniworx.de)

Die Applikation stürzt seit 27.5.8 öfters mit folgender Fehlermeldung ab:

CallStack (from HasCallStack):
  audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 11445}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 11406}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-08-15, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Handler/Utils/Qualification.hs:103:9 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Handler.Utils.Qualification @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "o96oq4zz"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 12330}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.004593 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "x5x5zp5v"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 21708}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.01069 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "75q3fafp"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 3436}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.013683 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "45y4psri"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 4898}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:05.998378 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#LMS] Processed 16 LMS results @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS src/Jobs/Handler/LMS.hs:299:9)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "zs2isbxa"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 11445}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.001495 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 12330}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 12291}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-08-30, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Handler/Utils/Qualification.hs:103:9 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Handler.Utils.Qualification @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 19571}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 19532}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-08-30, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))
CallStack (from HasCallStack):
  audit, called at src/Handler/Utils/Qualification.hs:103:9 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Handler.Utils.Qualification @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3)
2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 21708}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 21669}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-09-30, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0)))

Die Applikation stürzt seit 27.5.8 öfters mit folgender Fehlermeldung ab: ``` CallStack (from HasCallStack): audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 11445}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 11406}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-08-15, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Handler/Utils/Qualification.hs:103:9 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Handler.Utils.Qualification @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "o96oq4zz"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 12330}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.004593 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "x5x5zp5v"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 21708}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.01069 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "75q3fafp"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 3436}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.013683 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "45y4psri"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 4898}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:05.998378 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#LMS] Processed 16 LMS results @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS src/Jobs/Handler/LMS.hs:299:9) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionLmsSuccess {transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionLmsIdent = LmsIdent {getLmsIdent = "zs2isbxa"}, transactionLmsDay = 2023-07-24, transactionLmsUser = Just (UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 11445}}), transactionNote = Nothing, transactionReceived = 2023-07-24 10:01:06.001495 UTC},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Jobs/Handler/LMS.hs:290:11 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs.Handler.LMS @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 12330}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 12291}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-08-30, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Handler/Utils/Qualification.hs:103:9 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Handler.Utils.Qualification @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 19571}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 19532}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-08-30, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) CallStack (from HasCallStack): audit, called at src/Handler/Utils/Qualification.hs:103:9 in uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Handler.Utils.Qualification @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Audit src/Audit.hs:113:3) 2023-07-24 10:01:07 +0000 [Info#Audit] (TransactionQualificationUserEdit {transactionUser = UserKey {unUserKey = SqlBackendKey {unSqlBackendKey = 21708}}, transactionQualificationUser = QualificationUserKey {unQualificationUserKey = SqlBackendKey {unSqlBackendKey = 21669}}, transactionQualification = QualificationKey {unQualificationKey = SqlBackendKey {unSqlBackendKey = 1}}, transactionQualificationValidUntil = 2025-09-30, transactionQualificationScheduleRenewal = Nothing},Nothing,Just (IPv6 (ip6FromWords 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0))) ```
jost commented 2023-07-24 12:27:58 +02:00 (Migrated from gitlab.uniworx.de)

changed title from Crash: audit log call{-es-} to Crash: audit log call

changed title from **Crash: audit log call{-es-}** to **Crash: audit log call**
jost commented 2023-07-24 15:13:14 +02:00 (Migrated from gitlab.uniworx.de)

mentioned in issue #2

mentioned in issue #2
jost commented 2023-07-25 16:48:26 +02:00 (Migrated from gitlab.uniworx.de)

Beschreibung zeigt normaler Call-Stack im Audit-Debug Message.

Stattdessen:

2023-07-24 09:07:22 +0000 [Error#Job-Executor 15] PersistException: PersistMarshalError "selectSourceRes: Couldn't parse field `cardNo` from table `user_avs_card`. Encoding of AvsFullCardNo is invalid: 00130991, vals: [PersistInt64 5,PersistInt64 569873,PersistText \"00130991\",PersistByteString \"{\\\"Firm\\\": \\\"AVN-AR\\\", \\\"Valid\\\": \\\"True\\\", \\\"CardNo\\\": \\\"00130991\\\", \\\"ValidTo\\\": \\\"2023-06-21\\\", \\\"CardAreas\\\": \\\"\\\", \\\"CardColor\\\": \\\"Gelb\\\", \\\"IssueDate\\\": \\\"2019-07-08\\\", \\\"VersionNo\\\": \\\"1\\\"}\",PersistUTCTime 2023-01-16 10:24:25.068383 UTC]"JOB: JobCtlPerform (QueuedJobKey {unQueuedJobKey = SqlBackendKey {unSqlBackendKey = 1089243}}) @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs src/Jobs.hs:483:33)
Beschreibung zeigt normaler Call-Stack im Audit-Debug Message. Stattdessen: ``` 2023-07-24 09:07:22 +0000 [Error#Job-Executor 15] PersistException: PersistMarshalError "selectSourceRes: Couldn't parse field `cardNo` from table `user_avs_card`. Encoding of AvsFullCardNo is invalid: 00130991, vals: [PersistInt64 5,PersistInt64 569873,PersistText \"00130991\",PersistByteString \"{\\\"Firm\\\": \\\"AVN-AR\\\", \\\"Valid\\\": \\\"True\\\", \\\"CardNo\\\": \\\"00130991\\\", \\\"ValidTo\\\": \\\"2023-06-21\\\", \\\"CardAreas\\\": \\\"\\\", \\\"CardColor\\\": \\\"Gelb\\\", \\\"IssueDate\\\": \\\"2019-07-08\\\", \\\"VersionNo\\\": \\\"1\\\"}\",PersistUTCTime 2023-01-16 10:24:25.068383 UTC]"JOB: JobCtlPerform (QueuedJobKey {unQueuedJobKey = SqlBackendKey {unSqlBackendKey = 1089243}}) @(uniworx-27.4.18-2qWAdF4eDDRtDa2whQPKb:Jobs src/Jobs.hs:483:33) ```
jost commented 2023-07-26 09:20:09 +02:00 (Migrated from gitlab.uniworx.de)

In Blick in die Datenbank offenbarte 3 Fehler in Tabelle "user_avs_card" mit inkorrekten Formaten. Die betroffenen Benutzer waren alle FRADrive Admins, welche ganz am Anfang angelegt wurden. Offenbar wurde hier eine DB Migration vergessen.

Wie dem auch sei, dass Problem ist damit vermutlich gelöst.

Allerdings funktionierte das manuelle Anstoßen eines AVS-Background-Synchs trotzdem nicht, weshalb #7 wieder neu eröffnet wurde.

In Blick in die Datenbank offenbarte 3 Fehler in Tabelle "user_avs_card" mit inkorrekten Formaten. Die betroffenen Benutzer waren alle FRADrive Admins, welche ganz am Anfang angelegt wurden. Offenbar wurde hier eine DB Migration vergessen. Wie dem auch sei, dass Problem ist damit vermutlich gelöst. Allerdings funktionierte das manuelle Anstoßen eines AVS-Background-Synchs trotzdem nicht, weshalb #7 wieder neu eröffnet wurde.
jost (Migrated from gitlab.uniworx.de) closed this issue 2023-07-26 09:20:11 +02:00
jost commented 2023-07-26 09:24:46 +02:00 (Migrated from gitlab.uniworx.de)

mentioned in issue #7

mentioned in issue #7
This repo is archived. You cannot comment on issues.
No Milestone
No project
No Assignees
1 Participants
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: fraport/fradrive-old#111
No description provided.