search

datakaveri / iudx-resource-server

IUDX Data publication and subscription portal
https://rs.iudx.org.in/apis/
Apache License 2.0
6 stars 28 forks source link

Issues related to metering #239

Closed abhi4578 closed 2 years ago

abhi4578 commented 2 years ago

  1. Not able to get consumer audit details for open resource with open token: curl --location --request GET 'https://rs.iudx.org.in/ngsi-ld/v1/consumer/audit?id=datakaveri.org/04a15c9960ffda227e9546f3f46e629e1fe4132b/rs.iudx.org.in/pune-env-aqm/184ba502-22a8-ad15-a8f1-c966cd3aa7a7&timerel=during&time=2022-03-10T14:20:00Z&endtime=2022-03-16T14:20:00Z' --header 'token: <open-resource-token>' --header 'options: count' curl response: {"type":"urn:dx:rs:invalidAuthorizationToken","title":"Not Authorized","detail":"Not Authorized"}

    The failure logs at the resource server :

      2022-05-02 11:52:23   
time=2022-05-02T06:22:23+0000 level="ERROR" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="error : {"401":"no access provided to endpoint"}" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:52:23   
time=2022-05-02T06:22:23+0000 level="ERROR" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="failed - no access provided to endpoint" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:52:23   
time=2022-05-02T06:22:23+0000 level="INFO" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="endPoint : /ngsi-ld/v1/consumer/audit" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:52:23   
time=2022-05-02T06:22:23+0000 level="INFO" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="strategy : ConsumerAuthStrategy" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:52:23   
time=2022-05-02T06:22:23+0000 level="ERROR" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="cache call result : [fail] (RECIPIENT_FAILURE,-1) No entry for given key" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:52:23   
time=2022-05-02T06:22:23+0000 level="ERROR" loggerName=iudx.resource.server.apiserver.handlers.AuthHandler message="Error : Authentication Failure" source=rs sourceUrl=rs.iudx.org.in  exception=""

  2. With secure token with "/api" access for a secure resource, the metering api fails in production. The curl 

    curl --location --request GET 'https://rs.iudx.org.in/ngsi-ld/v1/consumer/audit?id=datakaveri.org/fb0924bef803e220e0d0bc8ceaf0a1f999442f32/rs.iudx.org.in/bengaluru-emergency-vehicles/ambulance-live&timerel=during&time=2022-03-10T14:20:00Z&endtime=2022-03-16T14:20:00Z' \
--header 'token: <secure-token>' --header 'options: count'

    curl response {"type":"urn:dx:rs:backend","title":"Bad Request","detail":"Bad Request"}

    The failure logs:

    
time=2022-05-02T06:11:02+0000 level="ERROR" loggerName=iudx.resource.server.apiserver.ApiServerVerticle message="ERROR : Expecting Json from backend service [ jsonFormattingException ]" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:41:02   
time=2022-05-02T06:11:02+0000 level="ERROR" loggerName=iudx.resource.server.apiserver.ApiServerVerticle message="Table reading failed." source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:41:02   
time=2022-05-02T06:11:02+0000 level="ERROR" loggerName=iudx.resource.server.apiserver.ApiServerVerticle message="Fail msg Timed out after waiting 30000(ms) for a reply. address: __vertx.reply.fcbe896a-4539-4bf0-9d5b-8484938927d9, repliedAddress: iudx.rs.metering.service" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:40:34   
time=2022-05-02T06:10:34+0000 level="ERROR" loggerName=io.vertx.core.impl.ContextImpl message="Unhandled exception" source=rs sourceUrl=rs.iudx.org.in  exception=" java.util.NoSuchElementException: Column (metering.rsauditingtable.col0) does not exist|    at io.vertx.sqlclient.Row.getInteger(Row.java:110) ~[fatjar.jar:?]| at iudx.resource.server.metering.MeteringServiceImpl.lambda$executeCountQuery$5(MeteringServiceImpl.java:195) ~[fatjar.jar:?]|  at io.vertx.core.impl.future.FutureImpl$1.onSuccess(FutureImpl.java:90) ~[fatjar.jar:?]|    at io.vertx.core.impl.future.FutureImpl$ListenerArray.onSuccess(FutureImpl.java:230) ~[fatjar.jar:?]|   at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:62) ~[fatjar.jar:?]|    at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:179) ~[fatjar.jar:?]|   at io.vertx.core.impl.future.Composition$1.onSuccess(Composition.java:62) ~[fatjar.jar:?]|  at io.vertx.core.impl.future.FutureImpl$ListenerArray.onSuccess(FutureImpl.java:230) ~[fatjar.jar:?]|   at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54) ~[fatjar.jar:?]|   at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:83) ~[fatjar.jar:?]|   at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:199) ~[fatjar.jar:?]|    at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:51) ~[fatjar.jar:?]|    at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:179) ~[fatjar.jar:?]|   at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23) ~[fatjar.jar:?]|  at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:102) ~[fatjar.jar:?]| at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:35) ~[fatjar.jar:?]|  at io.vertx.core.Promise.complete(Promise.java:66) ~[fatjar.jar:?]| at io.vertx.core.Promise.handle(Promise.java:51) ~[fatjar.jar:?]|   at io.vertx.core.Promise.handle(Promise.java:29) ~[fatjar.jar:?]|   at io.vertx.sqlclient.impl.command.CommandResponse.fire(CommandResponse.java:46) ~[fatjar.jar:?]|   at io.vertx.sqlclient.impl.SocketConnectionBase.handleMessage(SocketConnectionBase.java:258) ~[fatjar.jar:?]|   at io.vertx.pgclient.impl.PgSocketConnection.handleMessage(PgSocketConnection.java:94) ~[fatjar.jar:?]| at io.vertx.sqlclient.impl.SocketConnectionBase.lambda$init$0(SocketConnectionBase.java:96) ~[fatjar.jar:?]|    at io.vertx.core.net.impl.NetSocketImpl.lambda$new$1(NetSocketImpl.java:97) ~[fatjar.jar:?]|    at io.vertx.core.streams.impl.InboundBuffer.handleEvent(InboundBuffer.java:240) ~[fatjar.jar:?]|    at io.vertx.core.streams.impl.InboundBuffer.write(InboundBuffer.java:130) ~[fatjar.jar:?]|  at io.vertx.core.net.impl.NetSocketImpl.lambda$handleMessage$9(NetSocketImpl.java:390) ~[fatjar.jar:?]| at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:52) ~[fatjar.jar:?]|  at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:294) ~[fatjar.jar:?]|   at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:24) ~[fatjar.jar:?]|  at io.vertx.core.net.impl.NetSocketImpl.handleMessage(NetSocketImpl.java:389) ~[fatjar.jar:?]|  at io.vertx.core.net.impl.ConnectionBase.read(ConnectionBase.java:153) ~[fatjar.jar:?]| at io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:154) ~[fatjar.jar:?]|  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[fatjar.jar:?]|    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[fatjar.jar:?]|    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[fatjar.jar:?]|  at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ~[fatjar.jar:?]|    at io.vertx.pgclient.impl.codec.PgEncoder.lambda$write$0(PgEncoder.java:88) ~[fatjar.jar:?]|    at io.vertx.pgclient.impl.codec.PgCommandCodec.handleReadyForQuery(PgCommandCodec.java:139) ~[fatjar.jar:?]|    at io.vertx.pgclient.impl.codec.PgDecoder.decodeReadyForQuery(PgDecoder.java:235) ~[fatjar.jar:?]|  at io.vertx.pgclient.impl.codec.PgDecoder.channelRead(PgDecoder.java:95) ~[fatjar.jar:?]|   at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) ~[fatjar.jar:?]|    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[fatjar.jar:?]|    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[fatjar.jar:?]|    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[fatjar.jar:?]|  at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[fatjar.jar:?]|   at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[fatjar.jar:?]|    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[fatjar.jar:?]|    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[fatjar.jar:?]|    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) ~[fatjar.jar:?]| at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719) ~[fatjar.jar:?]| at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) ~[fatjar.jar:?]|   at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) ~[fatjar.jar:?]|    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) ~[fatjar.jar:?]|    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[fatjar.jar:?]|    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[fatjar.jar:?]|   at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[fatjar.jar:?]|   at java.lang.Thread.run(Unknown Source) [?:?]|"

2022-05-02 11:40:32   
time=2022-05-02T06:10:32+0000 level="INFO" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="User access is allowed." source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:40:32   
time=2022-05-02T06:10:32+0000 level="INFO" loggerName=iudx.resource.server.authenticator.authorization.ConsumerAuthStrategy message="allowed access : ["api","sub","file"]" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:40:32   
time=2022-05-02T06:10:32+0000 level="INFO" loggerName=iudx.resource.server.authenticator.authorization.ConsumerAuthStrategy message="authorization request for : /ngsi-ld/v1/consumer/audit with method : GET" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:40:32   
time=2022-05-02T06:10:32+0000 level="INFO" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="endPoint : /ngsi-ld/v1/consumer/audit" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:40:32   
time=2022-05-02T06:10:32+0000 level="INFO" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="strategy : ConsumerAuthStrategy" source=rs sourceUrl=rs.iudx.org.in  exception=""

2022-05-02 11:40:32   
time=2022-05-02T06:10:32+0000 level="ERROR" loggerName=iudx.resource.server.authenticator.JwtAuthenticationServiceImpl message="cache call result : [fail] (RECIPIENT_FAILURE,-1) No entry for given key" source=rs sourceUrl=rs.iudx.org.in  exception=""

    Reason: In production, the rs uses different immudb db than metering. possible solution: In the code it has to take the db name from config https://github.com/datakaveri/iudx-resource-server/blob/850a287159127d0645e636e19cc00679bb461000/configs/config-example.json#L118 to form exact column name . See at https://github.com/datakaveri/iudx-resource-server/blob/850a287159127d0645e636e19cc00679bb461000/src/main/java/iudx/resource/server/metering/util/Constants.java#L65

    1. If the consumer want to get auditiing details of other rs servers like gis, di from resource access server apis https://rs.iudx.org.in/apis#operation/consumer%20search .
      The current logic in the code would not allow that i feel. Because the gis inserts audit data to a different table called gisauditingtable https://github.com/datakaveri/iudx-gis-interface/blob/71888173aadf6a7f25e7fcf8702c26648c5a4249/src/main/java/iudx/gis/server/metering/util/Constants.java#L25 and resource access server consumer/provider search audit api just reads data from rsauditingtable . Similarly for di https://github.com/datakaveri/iudx-data-ingestion-server/blob/5d17699c39faf5d23aac7e6681607ac99fd76b95/src/main/java/iudx/data/ingestion/server/metering/util/Constants.java#L20.
abhi4578 commented 2 years ago

whereas file-server inserts audit to rsaduitingtable https://github.com/datakaveri/iudx-file-server/blob/4687733ced40f957dc493bccef18d02373a847dd/src/main/java/iudx/file/server/auditing/util/Constants.java#L25 and so its api-calls audit can be obtained from resource access server apis https://rs.iudx.org.in/apis#operation/consumer%20search .

kailash commented 2 years ago

Issue patched with :

241 for master branch &

243 for 3.5.0 branch

deployed image ghcr.io/datakaveri/rs-depl:3.5.0-6613e6b in rs-test server