kartverket / NGIS-OpenAPI

Tjenestebasert grensesnitt mot NGIS, basert på OpenAPI og REST.
3 stars 9 forks source link

Ar5 og tom respons body knyttet til lang respons tid ? #127

Closed larsop closed 11 months ago

larsop commented 1 year ago

F.eks UpdateFeature så funket ikke det i Sør Norge som er det største arkivet for AR5 når vi testet i Mai.

Man la så på noen indekser og så funket det. Det ble også testet å ta vekk indeksene da kom problemmet tilbake.

Problemmet i prod nå er at dette skjer bare noen ganger og det gjør det vanskelig å debugge.

Vi dekker over feilen i klienten nå , fordi selv vi får en tom response så blir endringen utført i basen ser det ut som.

2023-07-31 11:16:44,773 [pool-61-thread-1] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:587) 587 - URI: https://openapi-13.kartverket.no/nibio/v1/datasets/7131d84a-9da4-4a74-b899-1ed7b48aeeb4/features/7c8b3da2-ab8d-4fde-abf6-e703fad358dc/attributes - 
2023-07-31 11:16:44,773 [pool-61-thread-1] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:588) 588 - HTTP Method: PUT - 
.
.
2023-07-31 11:17:39,385 [pool-61-thread-1] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:595) 595 - HTTP Status Code: 200, timeused sec. 0 - 
2023-07-31 11:17:39,385 [pool-61-thread-1] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:596) 596 - Status Text: OK - 
2023-07-31 11:17:39,385 [pool-61-thread-1] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:597) 597 - HTTP Headers: Server=[nginx/1.20.1],Date=[Mon, 31 Jul 2023 09:17:39 GMT],Content-Type=[application/vnd.kartverket.ngis.attributes+json; version=1.0],Content-Length=[475],Connec>
2023-07-31 11:17:39,385 [pool-61-thread-1] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:598) 598 - Response Body:  - 

Være er det med requester som https://openapi-13.kartverket.no/nibio/v1/datasets som også kan få en tom liste tilbake fordi da kan vi ikke slippe inn brukeren, fordi da vet vi ikke hvilke arkiver bruker er har skrive tilgang til. Se også issue

Vi har også hatt det samme problemmet for updatefeatures, men der er det lenge siden jeg jeg har sett det problemmet nå, se issue

De viker som det internt I QMS er "feature" som gjør at det ved høy last/"lang" reponse så blir respons body skal sendes til klienten borte, mens status forsatt er 200 og OK.

larsop commented 1 year ago

Her ser vi et annet eksempel på lang respons tid det i henter en user lock. Det vi ser noen ganger er ting bare feiler til slutt og så prøver brukeren neste dag akkurat det samme og da går det bra igjen.

2023-08-01 13:25:48,957 [ajp-nio-127.0.0.1-8009-exec-234] DEBUG NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler.doUserLockIfNeeedAndUpdatePGWithlatestNgisData(NgisJobHandler.java:698) 698 - waiting for new user lock BD69D2A6324D685ED6C95CEDE7B818C3 for bbox POLYGON ((10.266027369280856 62.90317147347229, 10.266123240302369 62.9053939838435, 10.273077555052
417 62.905331402763736, 10.272981157794948 62.90310889835239, 10.266027369280856 62.90317147347229)) for job with uuid 2820c4dc-6283-4096-aa17-a4bd75c4ac64 - 

2023-08-01 13:27:52,339 [ajp-nio-127.0.0.1-8009-exec-234] DEBUG NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler.doUserLockIfNeeedAndUpdatePGWithlatestNgisData(NgisJobHandler.java:787) 787 - leave BD69D2A6324D685ED6C95CEDE7B818C3 for bbox POLYGON ((10.266027369280856 62.90317147347229, 10.266123240302369 62.9053939838435, 10.273077555052417 62.905331402763736, 10.272981157794948 62.90310889835239, 10.266027369280856 62.90317147347229))
larsop commented 1 year ago

Her er en listen over siste 2 uker der vi får tom response til ved UpdateFeature

grep -c -a 'Cannot invoke "Object.getClass()" because "uf"' /usr/java/tomcat/logs/ar5_update_ws.*|sort

/usr/java/tomcat/logs/ar5_update_ws.2023-07-18.log:18 /usr/java/tomcat/logs/ar5_update_ws.2023-07-19.log:24 /usr/java/tomcat/logs/ar5_update_ws.2023-07-20.log:45 /usr/java/tomcat/logs/ar5_update_ws.2023-07-21.log:34 /usr/java/tomcat/logs/ar5_update_ws.2023-07-24.log:61 /usr/java/tomcat/logs/ar5_update_ws.2023-07-25.log:274 /usr/java/tomcat/logs/ar5_update_ws.2023-07-26.log:61 /usr/java/tomcat/logs/ar5_update_ws.2023-07-27.log:0 /usr/java/tomcat/logs/ar5_update_ws.2023-07-28.log:94 /usr/java/tomcat/logs/ar5_update_ws.2023-07-31.log:83 /usr/java/tomcat/logs/ar5_update_ws.2023-08-01.log:173 /usr/java/tomcat/logs/ar5_update_ws.2023-08-02.log:169 /usr/java/tomcat/logs/ar5_update_ws.2023-08-03.log:227 /usr/java/tomcat/logs/ar5_update_ws.2023-08-04.log:233

larsop commented 1 year ago

Her en oversikt over problemmer med hente liste over dataset for innlogget bruker

grep -a -c 'no write db found list for datasetNamedList' ar5_update_*|sort

ar5_update_ws.2023-07-11.log:0 ar5_update_ws.2023-07-12.log:0 ar5_update_ws.2023-07-13.log:0 ar5_update_ws.2023-07-14.log:0 ar5_update_ws.2023-07-17.log:34 ar5_update_ws.2023-07-18.log:0 ar5_update_ws.2023-07-19.log:6 ar5_update_ws.2023-07-20.log:2 ar5_update_ws.2023-07-21.log:0 ar5_update_ws.2023-07-24.log:34 ar5_update_ws.2023-07-25.log:0 ar5_update_ws.2023-07-26.log:0 ar5_update_ws.2023-07-27.log:8 ar5_update_ws.2023-07-28.log:8 ar5_update_ws.2023-07-31.log:48 ar5_update_ws.2023-08-01.log:0 ar5_update_ws.2023-08-02.log:0 ar5_update_ws.2023-08-03.log:0 ar5_update_ws.2023-08-04.log:0

larsop commented 11 months ago

Her vi en update starter 14:19:22 og er ferdig 14:25:46

2023-09-14 14:19:22,660 [pool-121-thread-3] DEBUG NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1427) 1427 - ngis UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 update datalayer 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 with new attributes object c19db436-3d84-4792-b2c3-01b9f5e138c8 - 
2023-09-14 14:19:22,660 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:19:22,660 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:19:57,036 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:19:57,536 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:19:57,537 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:20:31,900 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:20:32,400 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:20:32,400 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:21:08,841 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:21:09,341 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:21:09,341 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:21:45,512 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:21:46,013 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:21:46,013 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:22:20,641 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:22:21,141 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:22:21,142 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:22:53,454 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:22:53,955 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:22:53,955 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:23:27,120 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:23:27,621 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:23:27,621 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:24:01,099 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:24:01,600 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:24:01,600 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:24:35,062 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:24:35,562 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:24:35,563 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:25:11,115 [pool-121-thread-3] WARN  NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1465) 1465 - failed when calling UpadteDatasetFeatureAttribute job for session_id D36547E891C572D9D89C2B9B599404F2 with job uuid cab02f43-7004-4f6b-b94c-05a65bc73007 and dataset uuid 35cb23fb-db00-4ba5-818c-b1eee9c7efd9 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:25:11,615 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:809) 809 - enter - 
2023-09-14 14:25:11,616 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http://data.geonorge.no/SFKB/FKB-AR5/so","versjonId":"2023-09-14 14:19:22.634508000"},"oppdateringsdato":"2023-04-30T11:36:56","verifiseringsdato":"2023-09-14","registreringsversjon":"2022-01-01","klassifiseringsmetode":"sOrto"} - 
2023-09-14 14:25:46,602 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:850) 850 - For openApi: https://openapi-13.kartverket.no/nibio/v1java.util.LinkedHashMap - 
2023-09-14 14:25:46,602 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:855) 855 - leave, ms. used:34987 lokalId c19db436-3d84-4792-b2c3-01b9f5e138c8 - 
2023-09-14 14:25:46,602 [pool-121-thread-3] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:859) 859 - Longtime upadteDatasetFeatureAttribute bigger > log_time_logger_value 34987ms. than 2000 - 
2023-09-14 14:25:46,603 [pool-121-thread-3] DEBUG NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler.removeJobNrFromQueue(NgisJobHandler.java:1783) 1783 - Ngishandler blockingQueue done UpadteDatasetFeatureAttribute blockingQueue + [cab02f43-7004-4f6b-b94c-05a65bc73007] size 1 job for session_id D36547E891C572D9D89C2B9B599404F2 with uuid cab02f43-7004-4f6b-b94c-05a65bc73007 registered at Thu Sep 14 14:19:22 CEST 2023 - 
2023-09-14 14:25:46,603 [pool-121-thread-3] INFO  ResultFileAndStatLogger_UpdateAttributes no.skogoglandskap.topo.client.ResultFileAndStatLogger_UpdateAttributes.logResultsGetData(ResultFileAndStatLogger_UpdateAttributes.java:111) 111 - log_updateAttribute_20230914-141922__D36547E891C572D9D89C2B9B599404F2_5027_olnann_
2023-09-14 14:25:46,603 [pool-121-thread-3] DEBUG NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1514) 1514 - leave with decrementAndGet 1 - 

Det vi gjør her er prøver på nytt inntil det går bra.

Her et eksempel på når det ikke funker og vi ser at body er tom

2023-09-14 14:22:53,955 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:587) 587 - URI: https://openapi-13.kartverket.no/nibio/v1/datasets/35cb23fb-db00-4ba5-818c-b1eee9c7efd9/features/c19db436-3d84-4792-b2c3-01b9f5e138c8/attributes - 
2023-09-14 14:22:53,956 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:588) 588 - HTTP Method: PUT - 
2023-09-14 14:22:53,956 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:589) 589 - HTTP Headers: Accept=[application/vnd.kartverket.ngis.attributes+json],Content-Type=[application/vnd.kartverket.ngis.attributes+json],X-Client-Product-Version=[ar5_java_web],/Authorization=[????>
2023-09-14 14:22:53,956 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:590) 590 - Request Body: {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-14","identifikasjon":{"l>
2023-09-14 14:23:27,120 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:595) 595 - HTTP Status Code: 200, timeused sec. 0 - 
2023-09-14 14:23:27,120 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:596) 596 - Status Text: OK - 
2023-09-14 14:23:27,120 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:597) 597 - HTTP Headers: Server=[nginx/1.20.1],Date=[Thu, 14 Sep 2023 12:23:26 GMT],Content-Type=[application/vnd.kartverket.ngis.attributes+json; version=1.0],Content-Length=[475],Connection=[keep-alive],Access->
2023-09-14 14:23:27,120 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:598) 598 - Response Body:  - 

og så noen minutter seinere går det bra


2023-09-14 14:25:17,188 [pool-121-thread-6] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:587) 587 - URI: https://openapi-13.kartverket.no/nibio/v1/datasets/eb48b325-3e0b-4991-a10d-005a2ff232e6/features/a7fce138-52f9-11ee-a391-f7817e1fdca9/attributes - 
2023-09-14 14:25:17,188 [pool-121-thread-6] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:588) 588 - HTTP Method: PUT - 
2023-09-14 14:25:17,188 [pool-121-thread-6] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:589) 589 - HTTP Headers: Accept=[application/vnd.kartverket.ngis.attributes+json],Content-Type=[application/vnd.kartverket.ngis.attributes+json],X-Client-Product-Version=[ar5_java_web],Authorization=[???>
2023-09-14 14:25:17,188 [pool-121-thread-6] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logRequest(ApiClient.java:590) 590 - Request Body: {"opphav":"web","treslag":"98","arealtype":"21","featuretype":"ArealressursFlate","informasjon":"","skogbonitet":"98","grunnforhold":"44","datafangstdato":"2023-09-06","identifikasjon":{"l>
2023-09-14 14:25:46,602 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:595) 595 - HTTP Status Code: 200, timeused sec. 0 - 
2023-09-14 14:25:46,602 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:596) 596 - Status Text: OK - 
2023-09-14 14:25:46,602 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:597) 597 - HTTP Headers: Server=[nginx/1.20.1],Date=[Thu, 14 Sep 2023 12:25:46 GMT],Content-Type=[application/vnd.kartverket.ngis.attributes+json; version=1.0],Content-Length=[475],Connection=[keep-alive],Access->
2023-09-14 14:25:46,602 [pool-121-thread-3] INFO  ApiClientHttpRequestInterceptor ngis.openapi.client.client.invoker.ApiClient$ApiClientHttpRequestInterceptor.logResponse(ApiClient.java:598) 598 - Response Body: {"arealtype":"21","datafangstdato":"2023-09-14","featuretype":"ArealressursFlate","grunnforhold":"44","identifikasjon":{"lokalId":"c19db436-3d84-4792-b2c3-01b9f5e138c8","navnerom":"http:>
larsop commented 11 months ago

Her er nytt eksempel fra i dag, det måtte gjøres mange retry her , så tok det nesten 9 minutter å endre en egenskap og tilbake dataene vi trengte fra NGISOpenAPI

2023-09-22 13:15:54,597 [pool-25-thread-9] DEBUG NgisJobHandler no.skogoglandskap.topo.jobhandler.NgisJobHandler$NgisAr5UpadteDatasetFeatureAttributeImpl.call(NgisJobHandler.java:1427) 1427 - ngis UpadteDatasetFeatureAttribute job for session_id 09E0C94E13764B5849889817>

2023-09-22 13:15:54,598 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:16:30,993 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:17:08,328 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:17:47,038 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:18:26,086 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:19:04,673 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:19:45,157 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:20:29,627 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:21:07,922 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:21:47,240 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:22:25,368 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:23:02,850 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:23:40,738 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:840) 840 - update body+ {"opphav":"web","treslag":"31","arealtype":"30","fe>

2023-09-22 13:24:18,023 [pool-25-thread-9] DEBUG Ar5NgisOpenApiIntergration no.skogoglandskap.topo.client.Ar5NgisOpenApiIntergration.upadteDatasetFeatureAttribute(Ar5NgisOpenApiIntergration.java:855) 855 - leave, ms. used:37284 lokalId 142ddcf6-5938-11ee-b364-7b5b8cf165>
larsop commented 11 months ago

Hoved problemmet her var timouten mellom NGISOpenAPI og QMS i kartverket sine systemmer var feil. Dette førte at vi fikk en tom response tilbake men uten noen feil kode (QMS kuttet req. men forsatte jobben i basen).

Når vi endret til gzip respons fikk vi en feilmelding tilbake og ikke bare en tom respons body. (Dette betyr at vi bør gå over til gzip for alle req.)

Nå er timeout mellom NGIS-OpenApi og QMS satt til 5 minutter for sikre at vi ikke gjøre retry selv QMS skulle bruke mere 1 minutt.

Årsaken til at det tok så lang tid å endre en egenskap var blant knyttet table scan som følge feil bruk av Multicolumn Indexes i QMS databasen.

larsop commented 11 months ago

Ny kode ble lagt ut Kartverket sine systemmer kl 18.00 17.10.2023