Indledning

Nærværende dokument udgør driftsvejledningen for Cprindlæseren. Cprindlæseren er en stamdataindlæser som vedligeholder data fra CPR-kontoret.

Cprindlæseren er en webapplikation der deployer på en Wildfly applikationsserver.

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

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/input	Datafiler der skal indlæses skal placeres her.
backup	<path_to_backup_files>:/tmp/cpr/input/.done	Efter 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.

Statusservicen giver udslag i følgende situationer, som vil sætte support igang

En filsæt validering fejler - dvs. at den senest modtagne fil er afvist som helhed
En CprEvent-validering fejler - dvs. at enkelte CprEvents i en modtagen fil ikke opfylder validitets-regler.
Hvis en CprEvent er fejlet i et load, så vil fejl markeringen først blive fjernet når der er modtaget et nyt load hvor den pågældende CprEvent er indlæst med succes.
Afhængighedsproblemer (fx. ingen forbindelse til databasen eller SFTP server)
Der er gået uforholdsmæssigt lang tid siden vi har fået sidste fil (kan konfigureres)

Generelle overvågningssnitflader

Ingen - ud over den beskrevne statusservice.

Service snitflader

Ingen - de data der indlæses i registret via Cprindlæseren stilles til rådighed via SKRS, men Cprindlæseren selv udstiller ikke nogen services.

Hvordan agerer Cprindlæseren

Cprindlæseren poller en SFTP server for nye filer uden at filtrere på extension, og når der dukker en fil op, hentes den ind til Cprindlæseren og slettes fra SFTP serveren.

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

Cprindlæseren vil indlæse så meget som muligt af de modtagne data, mens data som det ikke er muligt at indlæse logges til fejlbehandling.

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 vil data, enten som enkeltrækker eller som events kunne hentes via SKRS grænsefladen.

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

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] 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="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="2021-02-16 20:08:37.118" Duration="1095289 microseconds" 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

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:36,188" priority="INFO" 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,204" priority="INFO" class="EksternDistributeRoute" message="Done distribution"
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:37,118" priority="INFO" class="dk.nsp.indlaeser.cpr.bean.LoggerBean" message="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

timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.component.file.GenericFileOnCompletion" message="Done processing file: GenericFile[/tmp/cpr/input_ekstern/D100325.L431101] using exchange: Exchange[c1e864f1-f7d8-4d4b-81c4-c0f237d5997a]"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.component.file.strategy.GenericFileRenameProcessStrategy" message="Renaming file: GenericFile[/tmp/cpr/input_ekstern/D100325.L431101] to: GenericFile[.done/D100325-20210216-200836.204.L431101]"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.apache.camel.util.FileUtil" 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"
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: true"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.springframework.jdbc.core.JdbcTemplate" message="Executing prepared SQL update"
timestamp="2021-02-16 20:08:36,204" priority="DEBUG" class="org.springframework.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.datasource.DataSourceUtils" message="Fetching JDBC Connection from DataSource"
timestamp="2021-02-16 20:08:36,205" priority="DEBUG" class="org.springframework.jdbc.core.StatementCreatorUtils" message="JDBC getParameterType call failed - 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,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="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

{"Time to preparse":"PT0.004S","Time to parse":"PT0.009S","Application":"CprIndlæser","Timestamp":"2021-02-16 20:08: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.015S","Time to parse":"PT0.032S","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"}

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."}
}