Versions Compared

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

Distributionen af Cprindlæseren foregår som et Docker image der er bygget på NSP platform Docker imaget (registry.nspop.dk/platform/nsp)

Monitoreringssnitflader

Alle CprIndlæsere overvåges via en simpel statusservice. (Se evt. https://www.nspop.dk/display/public/web/Husregler+for+udvikling+til+NSP#HusreglerforudviklingtilNSP-Snitfladetilmonitorering(gl4.4)).


Placering af filer

Tabel over datafilens placering i forhold til de servere og komponenter der findes på siden Cpr Indlæser - Design- og Arkitekturbeskrivelse:

Fase

Directory

Bemærkning

Input<path_to_input_files>:/tmp/cpr/inputDatafiler der skal indlæses skal placeres her.
backup<path_to_backup_files>:/tmp/cpr/input/.doneEfter datafilen er blevet indlæst placeres den her.

Monitoreringssnitflader

Alle CprIndlæsere overvåges via en simpel statusservice. (Se evt. https://www.nspop.dk/display/public/web/Husregler+for+udvikling+til+NSP#HusreglerforudviklingtilNSP-Snitfladetilmonitorering(gl4.4)).

Denne statusservice bliver overvåget ved at den polles hver 10. sekund for en ny status (200 ok og 500 fejl pr default HTTP). Ved 500 er det tegn på, at en supporter skal igang med at kigge på problemet.

...

Den modtagne fil tjekkes for om filnavnet opfylder et bestemt mønster (Se Cpr Indlæser - Guide til udviklere#Fils%C3%A6tvalideringudviklere). Desuden tjekkes format og konsistens og derefter påbegyndes indlæsningen af de data der findes i den modtagne fil.

...

Data indlæses både som enkeltstående rækker i Cpr registerdatabasen og som Cprevents, hvor den enkelte event samler en Person med dens relaterede entiteter, i en event tabel.

Desuden sendes notifikationer til NAS på CPR-nummer. 

Efter endt håndtering Efter endt håndtering vil data, enten som enkeltrækker eller som events kunne hentes via SKRS grænsefladen.

Håndtering af fejlsituationer

Når statusservicen svarer med en http 500 skal der igangsættes support til hhv.

  • Afklaring af fejl på database eller SFTP forbindelse og efterfølgende re-etablering
  • Ved fejl i filsæt validering og manglende eller for afvigende filsæt, skal der tages kontakt til Praksys, som leverer filsættet for at afklare fejlen og bede dem om at igangsætte handlinger, der retter fejlen.

Beskrivelse af logs

Cprindlæseren skriver til 4 forskellige log filer, der alle er placeret lokalt i Docker containeren i Wildfly standard log folderen: /pack/wildfly8/standalone/log 

NSP SLA log

Denne log ligger i filen nsputil-sla.log og indeholder NSP SLA logninger på formen

Overvågning

Overvågningsservicen giver udslag på sin statusservice i følgende situationer, hvilket vil sætte supporter igang

  • En filsæt validering fejler - dvs. at den senest modtagne fil er afvist som helhed
  • En event-validering fejler - dvs. at enkelte events i en modtagen fil ikke opfylder validitets-regler.
  • Afhængighedsproblemer (fx. ingen forbindelse til databasen)
  • Der er gået uforholdsmæssigt lang tid siden vi har fået sidste fil (kan konfigureres)
  • Anden processeringsfejl

Registrering af fejl

De ovenstående fejlscenarier er knyttet til indlæsningerne, og da CprIndlæseren godt kan slukkes og startes, bliver evt. fejltilstande holdt i databasen i tabellerne CPR_dataset, CPR_datasetlog, CPR_registerstatus og CPR_registerfejl.

Tabellerne CPR_dataset og CPR_datasetlog er i bund og grund en database log over fejl der er opstået under processering af en fil. Disse tabeller udtrykker derfor hvordan processering af den seneste fil er foregået.

Tabellerne CPR_registerstatus og CPR_registerfejl beskriver den akkumulerede status for et givent register (her cprregisteret) og holder derfor styr på, om f.eks. en fejl i en given event stadig er forekommende, selvom der er modtaget stamdata filer efter at fejlen optrådte første gang.

Det er tabellerne CPR_registerstatus og CPR_registerfejl der danner grundlaget for visningen i overvågningsservicen, da vi her ønsker at se den akkumulerede status for det pågældende register.

Bemærk, at for CprIndlæseren, som kun indlæser fulde indlæsninger, vil den akkumulerede status altid svare til status for den senest modtagne fil.

Da overvågningsservicen polles hvert 10 sekund er der et krav til at den er letvægts. I den nuværende overvågningsservice i CprIndlæseren er det kun hvis databasen er nede at det kan tage et par sekunder, hvorfor CprIndlæseren venter et par sekunder før den giver op.


Håndtering af fejlsituationer

Når statusservicen svarer med en http 500 skal der igangsættes support til hhv.

  • Der vil stå en fejlbeskeder i tabellerne CPR_datasetlog og CPR_registerfejl. Det er kun status for seneste kørsel der står her.
  • Afklaring af fejl på database eller SFTP forbindelse og efterfølgende re-etablering
  • Ved fejl i filsæt validering og manglende eller for afvigende filsæt, skal der tages kontakt til CPR-kontoret, som leverer filsættet for at afklare fejlen og bede dem om at igangsætte handlinger, der retter fejlen.
  • Når CPR-kontoret har sendt en ny fil uden fejl, så skal den indlæses igen. Man skal ikke gøre noget for at nulstille den seneste kørsel - det sker automatisk.

Beskrivelse af logs

Cprindlæseren skriver til 4 forskellige log filer, der alle er placeret lokalt i Docker containeren i Wildfly standard log folderen: /pack/wildfly8/standalone/log 

NSP SLA log

Denne log ligger i filen nsputil-sla.log og indeholder NSP SLA logninger på formen


Code Block
16-02-2021 20:08:36,023 [Camel (camel-1) thread #3 - sftp://foo@cprsftp:22/praksys] INFO  dk.sdsd.nsp.slalogdata - LogPoint="LoggerBean" LogPointUniqId="LoggerBean" StartTime="2021-02-16 20:08:36.023" EndTime="2021-02-16 20:08:36.023" Duration="5 microseconds" MessageId="a143da18-8e5e-4b72-8140-cf1797ce946b" RequestSize=0 ReplySize=0 Result=OK ClientIP="<empty>" SOAPOperation="DataSet fetched" SOAPEndpoint="<empty>" SOAPAction="<empty>" TargetSOAPOperation="<empty>" TargetSOAPEndpoint="<empty>" GenericCallParms(1)= { ("Input","D100325.L431101") }
16-02-2021 20:08:36,179 [Camel (camel-1) thread #4 - file:///tmp/cpr/input
Code Block
16-02-2021 20:08:36,023 [Camel (camel-1) thread #3 - sftp://foo@cprsftp:22/praksys] INFO  dk.sdsd.nsp.slalogdata - LogPoint="LoggerBean" LogPointUniqId="LoggerBean" StartTime="2021-02-16 20:08:36.023" EndTime="2021-02-16 20:08:36.023" Duration="5 microseconds" MessageId="a143da1854715aa1-8e5e4d34-4b724805-8140be60-cf1797ce946b70ba79abef6c" RequestSize=0 ReplySize=0 Result=OK ClientIP="<empty>" SOAPOperation="DataSet fetchedreceived" SOAPEndpoint="<empty>" SOAPAction="<empty>" TargetSOAPOperation="<empty>" TargetSOAPEndpoint="<empty>" GenericCallParms(1)= { ("Input","D100325.L431101") }
16-02-2021 20:08:3637,179118 [Camel (camel-1) thread #4 - file:///tmp/cpr/input#1 - AggregateTimeoutChecker] INFO  dk.sdsd.nsp.slalogdata - LogPoint="LoggerBean" LogPointUniqId="LoggerBean" StartTime="2021-02-16 20:08:36.023" EndTime="2021-02-16 20:08:3637.023118" Duration="51095289 microseconds" MessageId="54715aa1-4d34-4805-be60-70ba79abef6c" RequestSize=0 ReplySize=0 Result=OK ClientIP="<empty>" SOAPOperation="DataSet received" SOAPEndpoint="<empty>" SOAPAction="<empty>" TargetSOAPOperation="<empty>" TargetSOAPEndpoint="<empty>" GenericCallParms(1)= { ("Input","D100325.L431101") }
16-02-2021 20:08:37,118 [Camel (camel-1) thread #1 - AggregateTimeoutChecker] INFO  dk.sdsd.nsp.slalogdata - LogPoint="LoggerBean" LogPointUniqId="LoggerBean" StartTime="2021-02-16 20:08:36.023" EndTime ClientIP="<empty>" SOAPOperation="DataSet completed" SOAPEndpoint="<empty>" SOAPAction="<empty>" TargetSOAPOperation="<empty>" TargetSOAPEndpoint="<empty>" GenericCallParms(1)= { ("Input","D100325.L431101") }


Audit log

Denne log ligger i filen cprAudit.log og indeholder overordnet logning af Cprindlæserens aktivitet

Code Block
timestamp="2021-02-16 20:08:36,183" priority="WARN" class="dk.nsp.indlaeser.cpr.bean.CprValidatorBean" message="Didn't find any previous versions of CPR. Asuming an initial import and skipping sequence checks."
timestamp="2021-02-16 20:08:37.11836,188" Durationpriority="1095289 microsecondsINFO" MessageId="54715aa1-4d34-4805-be60-70ba79abef6c" RequestSize=0 ReplySize=0 Result=OK ClientIP="<empty>" SOAPOperation="DataSet completed" SOAPEndpoint="<empty>" SOAPAction="<empty>" TargetSOAPOperation="<empty>" TargetSOAPEndpoint="<empty>" GenericCallParms(1)= { ("Input","D100325.L431101") }

Audit log

Denne log ligger i filen cprAudit.log og indeholder overordnet logning af Cprindlæserens aktivitet

Code Block
class="dk.nsp.indlaeser.cpr.bean.LoggerBean" message="The file D100325.L431101 has been preparsed"
timestamp="2021-02-16 20:08:36,204" priority="INFO" class="EksternCompleteRoute" message="inside ekstern completion"
timestamp="2021-02-16 20:08:36,183204" priority="WARNINFO" class="dk.nsp.indlaeser.cpr.bean.CprValidatorBeanEksternDistributeRoute" message="Didn't find any previous versions of CPR. Asuming an initial import and skipping sequence checks.Done distribution"
timestamp="2021-02-16 20:08:36,188207" priority="INFO" class="dk.nsp.indlaeser.cpr.bean.LoggerBean" message="The file D100325.L431101 has been preparsedparsed and splitted"
timestamp="2021-02-16 20:08:3637,204118" priority="INFO" class="EksternCompleteRoutedk.nsp.indlaeser.cpr.bean.LoggerBean" message="inside ekstern completion"
The file D100325.L431101 has been completed with status Completed"


Application log

Denne log ligger i filen cprApplication.log og indeholder detaljeret logning af Cprindlæserens aktivitet

Code Block
timestamp="2021-02-16 20:08:36,204" priority="DEBUG"INFO" class="EksternDistributeRoute" class="org.apache.camel.component.file.GenericFileOnCompletion" message="Done distribution processing file: GenericFile[/tmp/cpr/input_ekstern/D100325.L431101] using exchange: Exchange[c1e864f1-f7d8-4d4b-81c4-c0f237d5997a]"
timestamp="2021-02-16 20:08:36,207204" priority="INFODEBUG" class="dkorg.apache.nspcamel.indlaesercomponent.cprfile.beanstrategy.LoggerBeanGenericFileRenameProcessStrategy" message="TheRenaming file: GenericFile[/tmp/cpr/input_ekstern/D100325.L431101] has been parsed and splittedto: GenericFile[.done/D100325-20210216-200836.204.L431101]"
timestamp="2021-02-16 20:08:3736,118204" priority="INFODEBUG" class="dk.nsporg.indlaeserapache.cprcamel.beanutil.LoggerBeanFileUtil" message="TheTried 1 to rename file: /tmp/cpr/input_ekstern/D100325.L431101 has been completedto: /tmp/cpr/input_ekstern/.done/D100325-20210216-200836.204.L431101 with statusresult: Completedtrue"

Application log

Denne log ligger i filen cprApplication.log og indeholder detaljeret logning af Cprindlæserens aktivitet

Code Block
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.componentutil.file.GenericFileOnCompletionFileUtil" message="Done processingRetrying attempt 0 to delete file: GenericFile[/tmp/cpr/input_ekstern/D100325.L431101] using exchange: Exchange[c1e864f1-f7d8-4d4b-81c4-c0f237d5997a]input_ekstern/D100325.L431101.camelLock"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.component.file.strategy.GenericFileRenameProcessStrategyutil.FileUtil" message="RenamingTried 1 to delete file: GenericFile[/tmp/cpr/input_ekstern/D100325.L431101] to: GenericFile[.done/D100325-20210216-200836.204.L431101].camelLock with result: true"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apachespringframework.cameljdbc.utilcore.FileUtilJdbcTemplate" message="Tried 1 to rename file: /tmp/cpr/input_ekstern/D100325.L431101 to: /tmp/cpr/input_ekstern/.done/D100325-20210216-200836.204.L431101 with result: true"Executing prepared SQL update"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.util.FileUtil" message="Retrying attempt 0 to delete file: /tmp/cpr/input_ekstern/D100325.L431101.camelLock"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.util.FileUtil" message="Tried 1 to delete file: /tmp/cpr/input_ekstern/D100325.L431101.camelLock with result: truespringframework.jdbc.core.JdbcTemplate" message="Executing prepared SQL statement [UPDATE CPR_dataset SET Register = ?, FileName = ?, DatasetStatus = ?, DataReceived = ?, CprCount = ?, Datahandled = ?, DataReady = ?, DataProcessingStart = ?, DataProcessingEnd = ? WHERE UUID = ?]"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.springframework.jdbc.coredatasource.JdbcTemplateDataSourceUtils" message="ExecutingFetching JDBC preparedConnection SQLfrom updateDataSource"
timestamp="2021-02-16 20:08:36,204205" priority="DEBUG" class="org.springframework.jdbc.core.JdbcTemplateStatementCreatorUtils" message="ExecutingJDBC preparedgetParameterType SQLcall statementfailed [UPDATE CPR_dataset SET Register = ?, FileName = ?, DatasetStatus = ?, DataReceived = ?, CprCount = ?, Datahandled = ?, DataReady = ?, DataProcessingStart = ?, DataProcessingEnd = ? WHERE UUID = ?]- using fallback method instead: java.sql.SQLException: Parameter metadata not available for the given statement"
timestamp="2021-02-16 20:08:36,207" priority="INFO" class="dk.nsp.indlaeser.cpr.bean.LoggerBean" message="The file D100325.L431101 has been parsed and splitted"
timestamp="2021-02-16 20:08:36,204207" priority="DEBUG" class="org.apache.springframeworkcamel.jdbccomponent.datasourcefile.DataSourceUtilsGenericFileOnCompletion" message="Fetching JDBC Connection from DataSource="Done processing file: GenericFile[/tmp/cpr/input/D100325.L431101] using exchange: Exchange[54715aa1-4d34-4805-be60-70ba79abef6c]"
timestamp="2021-02-16 20:08:36,205207" priority="DEBUG" class="org.apache.camel.springframeworkcomponent.jdbcfile.corestrategy.StatementCreatorUtilsGenericFileRenameProcessStrategy" message="JDBCRenaming getParameterType call failed - using fallback method instead: java.sql.SQLException: Parameter metadata not available for the given statementfile: GenericFile[/tmp/cpr/input/D100325.L431101] to: GenericFile[.done/D100325-54715aa1-4d34-4805-be60-70ba79abef6c.L431101]"
timestamp="2021-02-16 20:08:36,207" priority="INFODEBUG" class="dk.nsporg.indlaeserapache.cprcamel.beanutil.LoggerBeanFileUtil" message="TheRetrying attempt 1 to rename file from: /tmp/cpr/input/D100325.L431101 has been parsed and splitted"
timestamp="2021-02-16 20:08:36,207" priority="DEBUG" class="org.apache.camel.component.file.GenericFileOnCompletion" message="Done processing file: GenericFile[/tmp/cpr/input/D100325.L431101] using exchange: Exchange[54715aa1-4d34-4805-be60-70ba79abef6c]"
timestamp=to: /tmp/cpr/input/.done/D100325-54715aa1-4d34-4805-be60-70ba79abef6c.L431101"


Stat log

Denne log ligger i filen cprStat.log og indeholder statistik logning af Cprindlæserens aktivitet

Code Block
{"Time to preparse":"PT0.004S","Time to parse":"PT0.009S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:36,207" priority="DEBUG" class="org.apache.camel.component.file.strategy.GenericFileRenameProcessStrategy" message="Renaming file: GenericFile[/tmp/cpr/input/D100325.L431101] to: GenericFile[.done/D100325-54715aa1-4d34-4805-be60-70ba79abef6c.L431101]"
timestamp="2021-02-16 20:08:36,207" priority="DEBUG" class="org.apache.camel.util.FileUtil" message="Retrying attempt 1 to rename file from: /tmp/cpr/input/D100325.L431101 to: /tmp/cpr/input/.done/D100325-54715aa1-4d34-4805-be60-70ba79abef6c.L431101"

Stat log

Denne log ligger i filen cprStat.log og indeholder statistik logning af Cprindlæserens aktivitet

Code Block
14,720","Processing Time":"PT447746H56M32.226S","ExchangeId":"cbc46c58-be53-403f-9fd9-acf18b1b4173"}
{"Time to preparse":"PT0.009S","Time to parse":"PT0.031S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:20,891","Processing Time":"PT447746H56M38.392S","ExchangeId":"df7b2648-a4ad-4d0d-95a5-c8ffcd73755e"}
{"Time to preparse":"PT0.004S015S","Time to parse":"PT0.009S032S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:1426,720061","Processing Time":"PT447746H56M32PT447746H56M43.226S557S","ExchangeId":"cbc46c58e5f58941-be533493-403f48a5-9fd9882b-acf18b1b417328176b83a62b"}
{"Time to preparse":"PT0.009S005S","Time to parse":"PT0.031S009S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:2032,891091","Processing Time":"PT447746H56M38PT447746H56M49.392S581S","ExchangeId":"df7b2648985fbbb7-a4adb1f2-4d0d412d-95a59663-c8ffcd73755ea8ca05d6ac87"}
{"Time to preparse":"PT0.015S006S","Time to parse":"PT0.032S012S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:26,061","Processing Time":"PT447746H56M43.557S","ExchangeId":"e5f58941-3493-48a5-882b-28176b83a62b"}
{"Time to preparse":"PT0.005S","Time to parse":"PT0.009S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:32,091","Processing Time":"PT447746H56M49.581S","ExchangeId":"985fbbb7-b1f2-412d-9663-a8ca05d6ac87"}
{"Time to preparse":"PT0.006S","Time to parse":"PT0.012S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08:37,118","Processing Time":"PT447746H56M54.602S","ExchangeId":"54715aa1-4d34-4805-be60-70ba79abef6c":37,118","Processing Time":"PT447746H56M54.602S","ExchangeId":"54715aa1-4d34-4805-be60-70ba79abef6c"}



Statistiklogning

Som en del af den almindelige applikationslog foretages en række logninger særligt beregnet til udtræk til statistik og ledelsesinformation.

Følgende logningspunkter til statistik er defineret:

Logningspunkt

Komponent

Eksempel på message fra applikationsloggen

(formatteret så det er lettere at læse i denne vejledning)

Ved oprettelsen af NAS-klienten logges det, hvorvidt den er oprettet med eller uden DGWS.

CprConfig

STATISTIK: 
{
"action":"dgwsService",
"info":{"All STS variables are available. Starting NAS client with DGWS."}
},
{
"action":"dgwsService",
"info":{"One or more STS variables are not available. Starting NAS client without DGWS."}
}