SB 5.1 - OCI - Errors in registry service

[subhashchandrab]

We used the release tags mentioned in the documentation https://ed.sunbird.org/use/installing-ed-platform/release-5.1.0/build to build and deploy registry service.

1. Build/Sunbird-RC/Registry -

• github_release_tag: release-5.1.0
• dockerhub_image_source: dockerhub/sunbird-rc-core:v0.0.13
• https://github.com/project-sunbird/sunbird-devops

2. Deploy/Sunbird-RC/Registry

• release-5.1.0
• https://github.com/project-sunbird/sunbird-devops
  The registry service is throwing the following exception during the startup. Is it due to any missing configurations? Will it have any functional impact

11:32:32.012 [main] ERROR d.s.r.config.MinioClientConfig:39 - Minio initialization failed: Failed to connect to localhost/127.0.0.1:9000
java.net.ConnectException: Failed to connect to localhost/127.0.0.1:9000
        at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:297)
        at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:207)
        at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.kt:226)
        at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:106)
        at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.kt:74)
        at okhttp3.internal.connection.RealCall.initExchange$okhttp(RealCall.kt:255)
        at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:32)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
        at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
        at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
        at io.minio.S3Base.execute(S3Base.java:532)
        at io.minio.S3Base.getRegion(S3Base.java:694)
        at io.minio.S3Base.execute(S3Base.java:470)
        at io.minio.S3Base.executeHead(S3Base.java:728)
        at io.minio.MinioClient.bucketExists(MinioClient.java:1135)
        at dev.sunbirdrc.registry.config.MinioClientConfig.minioClient(MinioClientConfig.java:32)
        at dev.sunbirdrc.registry.config.MinioClientConfig$$EnhancerBySpringCGLIB$$84ca89ac.CGLIB$minioClient$0(<generated>)
        at dev.sunbirdrc.registry.config.MinioClientConfig$$EnhancerBySpringCGLIB$$84ca89ac$$FastClassBySpringCGLIB$$c035491d.invoke(<generated>)
...........
........
Caused by: java.net.ConnectException: Connection refused (Connection refused)
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:589)
        at okhttp3.internal.platform.Platform.connectSocket(Platform.kt:120)
        at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:295)

[subhashchandrab]

We also noticed the pod keeps logging the below exception continuously and the pod is getting restarted frequently.

11:32:40.127 [http-nio-8081-exec-1] INFO  d.s.elastic.ElasticServiceImpl:125 - resthighclient obj:org.elasticsearch.client.RestHighLevelClient@797f97e3
11:32:40.205 [http-nio-8081-exec-1] ERROR dev.sunbirdrc.pojos.RequestWrapper:39 - Can't read from http stream. Set body empty
11:32:40.206 [http-nio-8081-exec-1] ERROR dev.sunbirdrc.pojos.APIMessage:44 - Can't read request body
com.fasterxml.jackson.databind.exc.MismatchedInputException: No content to map due to end-of-input
 at [Source: (String)""; line: 1, column: 0]
        at com.fasterxml.jackson.databind.exc.MismatchedInputException.from(MismatchedInputException.java:59)
        at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:4668)
        at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4513)
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3468)
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3436)
        at dev.sunbirdrc.pojos.APIMessage.<init>(APIMessage.java:42)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:204)
        at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:117)
        at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:310)
        at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:295)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBe
................
      at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:676)
        at dev.sunbirdrc.pojos.APIMessage$$EnhancerBySpringCGLIB$$8befab85.getUserID(<generated>)
        at dev.sunbirdrc.registry.service.ElasticSearchService.search(ElasticSearchService.java:92)
        at dev.sunbirdrc.registry.helper.RegistryHelper.searchEntity(RegistryHelper.java:334)
        at dev.sunbirdrc.registry.helper.RegistryHelper$$FastClassBySpringCGLIB$$9ae85a6b.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
        at dev.sunbirdrc.registry.helper.RegistryHelper$$EnhancerBySpringCGLIB$$8ec6d165.searchEntity(<generated>)
        at dev.sunbirdrc.registry.controller.RegistryEntityController.searchEntity(RegistryEntityController.java:160)

[vinukumar-vs]

@reshmi-nair Any suggestion, what can be the issue of the above log?

@rhwarrier @Krishnaj20

[chitranshu-keshav]

@reshmi-nair awaiting you inputs on the above. Can you pls check the issue and get back

@rhwarrier @Krishnaj20 @vinukumar-vs

[reshmi-nair]

@subhashchandrab As we discussed last week, this is not a blocker for certificate generation. This has to be checked by RC team ad they had said they will fix it in their future release. Please raise a thread in Sunbird-RC on this.

@chitranshu-keshav @vinukumar-vs @rhwarrier @Krishnaj20

[chitranshu-keshav]

@subhashchandrab can you please add the RC thread link here and mark this thread as answered

[chitranshu-keshav]

@gandham-santhosh Can you please get back on this

[subhashchandrab]

13:24:34.502 [main] INFO  d.s.elastic.ElasticServiceImpl:125 - resthighclient obj:org.elasticsearch.client.RestHighLevelClient@29aa4bc9
13:24:34.660 [main] ERROR d.s.r.service.ElasticSearchService:95 - Exception while auditing org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'scopedTarget.apiMessage': Scope 'request' is not active for the current thread; consider defining a scoped proxy for this bean if you intend to refer to it from a singleton; nested exception is java.lang.IllegalStateException: No thread-bound request found: Are you referring to request attributes outside of an actual web request, or processing a request outside of the originally receiving thread? If you are actually operating within a web request and still receive this message, your code is probably running outside of DispatcherServlet: In this case, use RequestContextListener or RequestContextFilter to expose the current request.
13:24:34.660 [main] INFO  d.s.registry.config.SchemaLoader:63 - Loaded 0 schema from DB

[subhashchandrab]

11:32:39.425 [main] INFO  d.s.registry.util.EntityParenter:103 - On loadDefinitionIndex for Shard:shard1 definition: ProjectCertificate updated index to true
11:32:39.425 [main] INFO  d.s.registry.util.EntityParenter:103 - On loadDefinitionIndex for Shard:shard1 definition: PublicKey updated index to true
11:32:39.425 [main] INFO  d.s.registry.util.EntityParenter:103 - On loadDefinitionIndex for Shard:shard1 definition: Schema updated index to false
11:32:39.425 [main] INFO  d.s.registry.util.EntityParenter:103 - On loadDefinitionIndex for Shard:shard1 definition: Signatory updated index to false
11:32:39.425 [main] INFO  d.s.registry.util.EntityParenter:103 - On loadDefinitionIndex for Shard:shard1 definition: Recipient updated index to false
11:32:39.425 [main] INFO  d.s.registry.util.EntityParenter:103 - On loadDefinitionIndex for Shard:shard1 definition: RevokedCredential updated index to true
11:32:39.427 [main] INFO  d.s.registry.util.EntityParenter:232 - Adding index to shard: shard1 for definition: Training
11:32:39.428 [main] INFO  d.s.registry.sink.SqlgProvider:88 - Could not create unique index for empty properties
11:32:39.627 [main] ERROR d.s.registry.util.EntityParenter:271 - No value present
11:32:39.628 [main] ERROR d.s.registry.util.EntityParenter:272 - Failed Transaction creating index Training
11:32:39.628 [main] INFO  d.s.registry.util.EntityParenter:232 - Adding index to shard: shard1 for definition: Issuer
11:32:39.628 [main] INFO  d.s.registry.sink.SqlgProvider:88 - Could not create unique index for empty properties
11:32:39.823 [main] ERROR d.s.registry.util.EntityParenter:271 - No value present
11:32:39.823 [main] ERROR d.s.registry.util.EntityParenter:272 - Failed Transaction creating index Issuer
11:32:39.823 [main] INFO  d.s.registry.util.EntityParenter:232 - Adding index to shard: shard1 for definition: Schema
11:32:39.901 [http-nio-8081-exec-1] INFO  o.a.c.c.C.[Tomcat].[localhost].[/]:173 - Initializing Spring DispatcherServlet 'dispatcherServlet'
11:32:39.901 [http-nio-8081-exec-1] INFO  o.s.web.servlet.DispatcherServlet:525 - Initializing Servlet 'dispatcherServlet'
11:32:39.913 [http-nio-8081-exec-1] INFO  o.s.web.servlet.DispatcherServlet:547 - Completed initialization in 12 ms
11:32:40.080 [main] ERROR d.s.registry.util.EntityParenter:271 - No value present
11:32:40.098 [main] ERROR d.s.registry.util.EntityParenter:272 - Failed Transaction creating index Schema
11:32:40.098 [main] INFO  d.s.registry.util.EntityParenter:232 - Adding index to shard: shard1 for definition: Signatory
11:32:40.099 [main] INFO  d.s.registry.sink.SqlgProvider:88 - Could not create unique index for empty properties
11:32:40.126 [http-nio-8081-exec-1] WARN  d.s.registry.service.ISearchService:69 - Populates SearchQuery for limit/offset(optional): null
11:32:40.126 [http-nio-8081-exec-1] INFO  d.s.elastic.ElasticServiceImpl:121 - connection info: index:trainingcertificate connectioninfo:10.90.8.21:9200,10.90.8.22:9200,10.90.8.23:9200
11:32:40.127 [http-nio-8081-exec-1] INFO  d.s.elastic.ElasticServiceImpl:125 - resthighclient obj:org.elasticsearch.client.RestHighLevelClient@797f97e3
11:32:40.205 [http-nio-8081-exec-1] ERROR dev.sunbirdrc.pojos.RequestWrapper:39 - Can't read from http stream. Set body empty
11:32:40.206 [http-nio-8081-exec-1] ERROR dev.sunbirdrc.pojos.APIMessage:44 - Can't read request body
com.fasterxml.jackson.databind.exc.MismatchedInputException: No content to map due to end-of-input
 at [Source: (String)""; line: 1, column: 0]
        at com.fasterxml.jackson.databind.exc.MismatchedInputException.from(MismatchedInputException.java:59)
        at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:4668)
        at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4513)
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3468)
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3436)
        at dev.sunbirdrc.pojos.APIMessage.<init>(APIMessage.java:42)

[Krishnaj20]

@subhashchandrab @chitranshu-keshav - Let us know if there are any open queries to be addressed as part of this thread?

[subhashchandrab]

The continuous restart of the registry service issue is resolved now after rebuilding and redeploying certificatesign service as per the latest 5.1 documentation. Still the ES related exception is being logged continuously. As per @reshmi-nair , this seems to be a knowns issue in SunbirdRC and it's being tracker separately in the thread https://github.com/orgs/Sunbird-RC/discussions/672