odpi / egeria

Egeria core
https://egeria-project.org
Apache License 2.0
806 stars 260 forks source link

Server starts even if graph repo fails to initialize due to incorrect metadata collection id #3451

Closed planetf1 closed 3 years ago

planetf1 commented 4 years ago

If a server is configured with the graph repo (the only configuration done is to enable the graph repository), but it fails to start due to a preexisting metadata collection id, it still seems as if the server is started, but doesn't work properly.

From the log at https://gist.github.com/0252f24c24611fcd4946321260a9fe87

It goes wrong in startup:

Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMRS-AUDIT-0064 The Open Metadata Repository Services (OMRS) has initialized the audit log for Metadata Server called servergraph
Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMAG-ADMIN-0001 The servergraph server is configured with a max page size of 1000
Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMRS-AUDIT-0001 The Open Metadata Repository Services (OMRS) is initializing the subsystems to support a metadata server
Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMRS-AUDIT-0002 Enterprise access through the Enterprise Repository Services is initializing
Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMRS-AUDIT-0003 The local repository is initializing the metadata collection named servergraph with an id of 578477d2-cb92-4177-b533-e1d56cdf5799
Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMRS-AUDIT-0029 The local repository outbound event manager is initializing
Wed Aug 05 10:48:22 BST 2020 servergraph Startup OMRS-AUDIT-0030 Registering the Local Repository to Enterprise event consumer with the local repository outbound event manager
10:48:23.898 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  o.j.g.i.UniqueInstanceIdRetriever - Generated unique-instance-id=0a09002866307-planetf1mac1
10:48:24.023 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.janusgraph.diskstorage.Backend - Configuring index [search]
10:48:24.242 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.janusgraph.diskstorage.Backend - Initiated backend operations thread pool of size 16
10:48:24.405 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  o.j.diskstorage.log.kcvs.KCVSLog - Loaded unidentified ReadMarker start time 2020-08-05T09:48:24.405115Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@4c0419cc
10:48:24.775 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] ERROR o.o.o.a.r.g.r.GraphOMRSGraphFactory - checkAndUpdateControlInformation The graph database for repository servergraph has metadataCollectionId 5fc44583-7124-476f-bb3c-14ab13e25ff1, and cannot be opened using metadataCollectionId 578477d2-cb92-4177-b533-e1d56cdf5799 
Wed Aug 05 10:48:24 BST 2020 servergraph Exception OMRS-GRAPH-REPOSITORY-0002 The OMRS Graph Database servergraph contains a metadataCollectionId 5fc44583-7124-476f-bb3c-14ab13e25ff1 that does not match the repositorys metadataCollectionId {2}.
10:48:24.778 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] ERROR o.o.o.a.r.g.r.GraphOMRSGraphFactory - open Check and update of control vertex failed, exception OMRS-GRAPH-REPOSITORY-400-022 It is not possible to open the graph database with metadataCollectionId checkAndUpdateControlInformation, because the repository connector has metadataCollectionId org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSGraphFactory
10:48:24.778 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] ERROR o.o.o.a.r.g.r.GraphOMRSMetadataStore - GraphOMRSMetadataStore Could not open graph database
10:48:24.778 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] ERROR o.o.o.a.r.g.r.GraphOMRSMetadataCollection - GraphOMRSMetadataCollection could not create graph metadata collection for repository name servergraph

but we then continue to load the types:

Wed Aug 05 10:48:24 BST 2020 servergraph Information OMRS-AUDIT-0050 The Open Metadata Repository Services (OMRS) is about to process open metadata archive Open Metadata Types

This works until we try and persist something and get an exception:

Wed Aug 05 10:48:24 BST 2020 servergraph Types OMRS-AUDIT-0301 The local server has added a new type called SolutionPortDirection with a unique identifier of 4879c96e-26c7-48af-ba92-8277632be733 and a version number of 1 from ODPi Egeria (1.8)
Wed Aug 05 10:48:24 BST 2020 servergraph Exception OMRS-AUDIT-9019 The type definition event processor for the ODPi Egeria (1.8) service caught an unexpected exception java.lang.NullPointerException with message null
Wed Aug 05 10:48:24 BST 2020 servergraph Exception OMRS-AUDIT-9019 Supplementary information: log record id f195f8a0-9030-4d52-9b8c-4317b6c6de08 java.lang.NullPointerException returned message of null and stacktrace of 
java.lang.NullPointerException
    at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSMetadataCollection.verifyTypeDef(GraphOMRSMetadataCollection.java:130)
    at org.odpi.openmetadata.repositoryservices.localrepository.repositoryconnector.LocalOMRSMetadataCollection.verifyTypeDef(LocalOMRSMetadataCollection.java:835)
    at org.odpi.openmetadata.repositoryservices.localrepository.repositorycontentmanager.OMRSRepositoryContentManager.processNewTypeDefEvent(OMRSRepositoryContentManager.java:2443)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.processTypeDefStore(OMRSArchiveManager.java:300)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.processOpenMetadataArchive(OMRSArchiveManager.java:211)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.processOpenMetadataTypes(OMRSArchiveManager.java:139)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.setLocalRepository(OMRSArchiveManager.java:102)
    at org.odpi.openmetadata.repositoryservices.admin.OMRSOperationalServices.initializeCohortMember(OMRSOperationalServices.java:430)
    at org.odpi.openmetadata.adminservices.OMAGServerOperationalServices.activateWithSuppliedConfig(OMAGServerOperationalServices.java:316)
    at org.odpi.openmetadata.adminservices.OMAGServerOperationalServices.activateWithStoredConfig(OMAGServerOperationalServices.java:152)
    at org.odpi.openmetadata.adminservices.spring.OperationalServicesResource.activateWithStoredConfig(OperationalServicesResource.java:59)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:564)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:878)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:792)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:652)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Thread.java:832)

Wed Aug 05 10:48:24 BST 2020 servergraph Exception OMRS-AUDIT-9019 The type definition event processor for the ODPi Egeria (1.8) service caught an unexpected exception java.lang.NullPointerException with message null
Wed Aug 05 10:48:24 BST 2020 servergraph Exception OMRS-AUDIT-9019 Supplementary information: log record id e3b8da3c-6d21-4552-b1a3-bf0c8557d570 java.lang.NullPointerException returned message of null and stacktrace of 
java.lang.NullPointerException
    at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSMetadataCollection.verifyTypeDef(GraphOMRSMetadataCollection.java:130)
    at org.odpi.openmetadata.repositoryservices.localrepository.repositoryconnector.LocalOMRSMetadataCollection.verifyTypeDef(LocalOMRSMetadataCollection.java:835)
    at org.odpi.openmetadata.repositoryservices.localrepository.repositorycontentmanager.OMRSRepositoryContentManager.processNewTypeDefEvent(OMRSRepositoryContentManager.java:2443)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.processTypeDefStore(OMRSArchiveManager.java:300)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.processOpenMetadataArchive(OMRSArchiveManager.java:211)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.processOpenMetadataTypes(OMRSArchiveManager.java:139)
    at org.odpi.openmetadata.repositoryservices.archivemanager.OMRSArchiveManager.setLocalRepository(OMRSArchiveManager.java:102)
    at org.odpi.openmetadata.repositoryservices.admin.OMRSOperationalServices.initializeCohortMember(OMRSOperationalServices.java:430)
    at org.odpi.openmetadata.adminservices.OMAGServerOperationalServices.activateWithSuppliedConfig(OMAGServerOperationalServices.java:316)
    at org.odpi.openmetadata.adminservices.OMAGServerOperationalServices.activateWithStoredConfig(OMAGServerOperationalServices.java:152)
    at org.odpi.openmetadata.adminservices.spring.OperationalServicesResource.activateWithStoredConfig(OperationalServicesResource.java:59)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:564)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:878)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:792)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:652)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Thread.java:832)

There are many of these.. but then finally:

Wed Aug 05 10:48:24 BST 2020 servergraph Information OMRS-AUDIT-0053 The Open Metadata Repository Services (OMRS) has processed 548 types and 0 instances from open metadata archive Open Metadata Types
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0040 An enterprise OMRS connector has been created for the Repository REST Services
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0041 The enterprise OMRS connector for the Repository REST Services has started
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0031 The local repository outbound event manager is starting with 1 type definition event consumer(s) and 1 instance event consumer(s)
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0032 The local repository outbound event manager is sending out the 53 type definition events that were generated and buffered during server initialization
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0007 The Open Metadata Repository Services (OMRS) has initialized
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0040 An enterprise OMRS connector has been created for the Connected Asset Services
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0041 The enterprise OMRS connector for the Connected Asset Services has started
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OCF-METADATA-MANAGEMENT-0001 The Open Connector Framework (OCF) Metadata Management Service is initializing a new server instance
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OCF-METADATA-MANAGEMENT-0003 The Open Connector Framework (OCF) Metadata Management Service has initialized a new instance for server servergraph
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMAG-ADMIN-0010 The Open Metadata Access Services (OMASs) are starting
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0040 An enterprise OMRS connector has been created for the Subject Area OMAS
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMRS-AUDIT-0041 The enterprise OMRS connector for the Subject Area OMAS has started
Wed Aug 05 10:48:24 BST 2020 servergraph Startup OMAS-SUBJECT_AREA-0001 The Subject Area Open Metadata Access Service (OMAS) is initializing a new server instance
10:48:24.959 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.reflections.Reflections - Reflections took 20 ms to scan 4 urls, producing 63 keys and 350 values 
10:48:24.986 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.reflections.Reflections - Reflections took 22 ms to scan 4 urls, producing 63 keys and 350 values 
10:48:25.007 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.reflections.Reflections - Reflections took 19 ms to scan 4 urls, producing 63 keys and 350 values 
10:48:25.034 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.reflections.Reflections - Reflections took 25 ms to scan 4 urls, producing 63 keys and 350 values 
10:48:25.056 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.reflections.Reflections - Reflections took 20 ms to scan 4 urls, producing 63 keys and 350 values 
10:48:25.084 [REST:OMAG Server Operational Services:activateWithSuppliedConfig] INFO  org.reflections.Reflections - Reflections took 25 ms to scan 4 urls, producing 63 keys and 350 values 
Wed Aug 05 10:48:25 BST 2020 servergraph Startup OMAS-SUBJECT_AREA-0003 The Subject Area Open Metadata Access Service (OMAS) has initialized a new instance for server servergraph
Wed Aug 05 10:48:25 BST 2020 servergraph Startup OMAG-ADMIN-0012 1 out of 1 configured Open Metadata Access Services (OMASs) have started.
Wed Aug 05 10:48:25 BST 2020 servergraph Startup OMRS-AUDIT-0019 An OMRS Topic Connector has registered with an event bus connector for topic servergraph.openmetadata.repositoryservices.enterprise.servergraph.OMRSTopic
Wed Aug 05 10:48:25 BST 2020 servergraph Startup OMRS-AUDIT-0020 An OMRS Topic Connector is ready to send and receive events on topic servergraph.openmetadata.repositoryservices.enterprise.servergraph.OMRSTopic
Wed Aug 05 10:48:25 BST 2020 servergraph Startup OMAG-ADMIN-0004 The servergraph server has successfully completed start up.  The following services are running: [Open Metadata Repository Services (OMRS), Connected Asset Services, Subject Area OMAS]
Wed Aug 05 10:48:25 BST 2020 servergraph Startup OMRS-AUDIT-0015 The listener thread for an OMRS Topic Connector for topic servergraph.openmetadata.repositoryservices.enterprise.servergraph.OMRSTopic has started

At this point the server seems ready, but of course any interaction with subject area will then fail ie:

10:48:53.291 [https-jsse-nio-10443-exec-9] ERROR o.a.c.c.C.[.[.[.[dispatcherServlet] - Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.NullPointerException] with root cause java.lang.NullPointerException: null at org.odpi.openmetadata.accessservices.subjectarea.utilities.OMRSAPIHelper.getTypeDefGUID(OMRSAPIHelper.java:911) at org.odpi.openmetadata.accessservices.subjectarea.utilities.OMRSAPIHelper.findEntitiesByPropertyValue(OMRSAPIHelper.java:813) at org.odpi.openmetadata.accessservices.subjectarea.utilities.OMRSAPIHelper.findEntitiesByPropertyValue(OMRSAPIHelper.java:788) at org.odpi.openmetadata.accessservices.subjectarea.handlers.SubjectAreaHandler.findEntities(SubjectAreaHandler.java:109) at org.odpi.openmetadata.accessservices.subjectarea.handlers.SubjectAreaGlossaryHandler.findGlossary(SubjectAreaGlossaryHandler.java:148) at org.odpi.openmetadata.accessservices.subjectarea.server.services.SubjectAreaGlossaryRESTServices.findGlossary(SubjectAreaGlossaryRESTServices.java:145) at org.odpi.openmetadata.accessservices.subjectarea.server.spring.SubjectAreaGlossaryRESTResource.findGlossary(SubjectAreaGlossaryRESTResource.java:123) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:878) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:792) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) at javax.servlet.http.HttpServlet.service(HttpServlet.java:626) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.base/java.lang.Thread.run(Thread.java:832)



it seems as if the failure during start is not being detected. Instead we would expect a failure audit log message (note the logs above were taken with debug=info) and for the server to not start. Rather than to service requests and fail

Originally found in #3446
github-actions[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

grahamwallis commented 4 years ago

I have created a fix for this.

The behaviour now, when a mismatch occurs between the requested (random or otherwise) metadataCollectionId and the metadataCollecitonId found in the control vertex of the graph database, is as follows:

Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Exception OMRS-GRAPH-REPOSITORY-0002 The OMRS Graph Database Metadata_Server2 contains a metadataCollectionId fcc0e6d9-3c8a-4135-a5a0-295393e57cb3 that does not match the requested metadataCollectionId abc0e6d9-3c8a-4135-a5a0-295393e57cb3. Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Exception OMRS-AUDIT-0034 The connector to the local repository failed with a org.odpi.openmetadata.repositoryservices.ffdc.exception.OMRSLogicErrorException exception and the following error message: OMRS-REPOSITORY-400-025 Local metadata repository has not initialized correctly because it has a null metadata collection. Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Exception OMRS-AUDIT-0034 Supplementary information: log record id 6e8fff18-c5c7-40ca-b846-f8cbc4d260a8 org.odpi.openmetadata.repositoryservices.ffdc.exception.OMRSLogicErrorException returned message of OMRS-REPOSITORY-400-025 Local metadata repository has not initialized correctly because it has a null metadata collection. and stacktrace of OMRSRuntimeException{reportedHTTPCode=400, reportingClassName='org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSRepositoryConnector', reportingActionDescription='setMetadataCollectionId', reportedErrorMessage='OMRS-REPOSITORY-400-025 Local metadata repository has not initialized correctly because it has a null metadata collection.', reportedErrorMessageId='OMRS-REPOSITORY-400-025', reportedErrorMessageParameters=[null], reportedSystemAction='The system is unable to process requests for this repository.', reportedUserAction='Verify that the repository connector is correctly configured in the OMAG server.', reportedCaughtException=OCFCheckedExceptionBase{reportedHTTPCode=400, reportingClassName='org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSGraphFactory', reportingActionDescription='checkAndUpdateControlInformation', reportedErrorMessage='OMRS-GRAPH-REPOSITORY-400-022 It is not possible to open the graph database with metadataCollectionId fcc0e6d9-3c8a-4135-a5a0-295393e57cb3, because the repository connector has metadataCollectionId abc0e6d9-3c8a-4135-a5a0-295393e57cb3', reportedErrorMessageId='OMRS-GRAPH-REPOSITORY-400-022', reportedErrorMessageParameters=[fcc0e6d9-3c8a-4135-a5a0-295393e57cb3, abc0e6d9-3c8a-4135-a5a0-295393e57cb3], reportedSystemAction='The system was unable to open the graph repository graph database', reportedUserAction='Please check the configuration of the repository connection and update it if necessary.', reportedCaughtException=null, reportedCaughtExceptionClassName='null', relatedProperties=null}, reportedCaughtExceptionClassName='org.odpi.openmetadata.repositoryservices.ffdc.exception.RepositoryErrorException', relatedProperties=null, errorMessage='OMRS-REPOSITORY-400-025 Local metadata repository has not initialized correctly because it has a null metadata collection.'} at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSRepositoryConnector.setMetadataCollectionId(GraphOMRSRepositoryConnector.java:55) at org.odpi.openmetadata.repositoryservices.localrepository.repositoryconnector.LocalOMRSRepositoryConnector.setMetadataCollectionId(LocalOMRSRepositoryConnector.java:352) at org.odpi.openmetadata.repositoryservices.admin.OMRSOperationalServices.getLocalOMRSConnector(OMRSOperationalServices.java:1132) at org.odpi.openmetadata.repositoryservices.admin.OMRSOperationalServices.initializeLocalRepository(OMRSOperationalServices.java:717) at org.odpi.openmetadata.repositoryservices.admin.OMRSOperationalServices.initializeCohortMember(OMRSOperationalServices.java:402) at org.odpi.openmetadata.adminservices.OMAGServerOperationalServices.activateWithSuppliedConfig(OMAGServerOperationalServices.java:318) at org.odpi.openmetadata.adminservices.OMAGServerOperationalServices.activateWithStoredConfig(OMAGServerOperationalServices.java:153) at org.odpi.openmetadata.adminservices.spring.OperationalServicesResource.activateWithStoredConfig(OperationalServicesResource.java:59) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:878) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:792) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909) at javax.servlet.http.HttpServlet.service(HttpServlet.java:652) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Caused by: OCFCheckedExceptionBase{reportedHTTPCode=400, reportingClassName='org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSGraphFactory', reportingActionDescription='checkAndUpdateControlInformation', reportedErrorMessage='OMRS-GRAPH-REPOSITORY-400-022 It is not possible to open the graph database with metadataCollectionId fcc0e6d9-3c8a-4135-a5a0-295393e57cb3, because the repository connector has metadataCollectionId abc0e6d9-3c8a-4135-a5a0-295393e57cb3', reportedErrorMessageId='OMRS-GRAPH-REPOSITORY-400-022', reportedErrorMessageParameters=[fcc0e6d9-3c8a-4135-a5a0-295393e57cb3, abc0e6d9-3c8a-4135-a5a0-295393e57cb3], reportedSystemAction='The system was unable to open the graph repository graph database', reportedUserAction='Please check the configuration of the repository connection and update it if necessary.', reportedCaughtException=null, reportedCaughtExceptionClassName='null', relatedProperties=null} at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSGraphFactory.checkAndUpdateControlInformation(GraphOMRSGraphFactory.java:907) at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSGraphFactory.open(GraphOMRSGraphFactory.java:207) at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSMetadataStore.(GraphOMRSMetadataStore.java:134) at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSMetadataCollection.(GraphOMRSMetadataCollection.java:101) at org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSRepositoryConnector.setMetadataCollectionId(GraphOMRSRepositoryConnector.java:48)

And the server is automatically shut down...

Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Shutdown OMAG-ADMIN-0005 The Metadata_Server2 server has begun the shutdown process Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Shutdown OMRS-AUDIT-0010 The Open Metadata Repository Services (OMRS) is disconnecting the open metadata repositories Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Shutdown OMRS-AUDIT-0021 The OMRS Topic Listener has disconnected the event bus connectors for topic Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Shutdown OMRS-AUDIT-0011 The Open Metadata Repository Services (OMRS) has disconnected from the open metadata repositories Mon Oct 26 17:39:04 GMT 2020 Metadata_Server2 Shutdown OMAG-ADMIN-0006 The Metadata_Server2 server has completed shutdown

I would quite like to not include the stacktrace as there is possibly enough error reporting in the associated messages.

grahamwallis commented 4 years ago

Created a DRAFT PR at #3963

github-actions[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

grahamwallis commented 3 years ago

Fixed by #3963