search

peimanja / artifactory_exporter

JFrog Artifactory Prometheus Exporter written in Go
Apache License 2.0
141 stars 37 forks source link

Artifactory AQL error message with version 7.90.6 #146

Open jingmxu opened 2 months ago

jingmxu commented 2 months ago

Overview of the Issue

Artifactory exporter1.140 used to work fine with Artifactory7.71.8. but after upgrading Artifactory to 7.90.6, there are many AQL error messages in Artifactory logs regarding the POST request from Artifactory exporter, There is a AQL change in Artifactory7.84 https://jfrog.com/help/r/jfrog-release-information/artifactory-7.84?tocId=l5ivPW3bmp3socHkO6OTTA

not sure if it is related to this.

Reproduction Steps

Artifactory upgrade from 7.71.8 to 7.90.6

Operating system and Environment details

RHEL8.8 , Artifactory exporter1.140, Artifactory7.90.6

Logs

Log output of exporter when running and you try to get metrics from the metric path.

2024-08-12T05:44:18.311Z [jfrt ] [ERROR] [4e92f2fa52d2cf21] [o.a.a.r.AqlRestResult:135 ] [ttp-nio-8081-exec-10] - AQL minimal field expectation error: repo, path and name

java.lang.reflect.UndeclaredThrowableException: null

            at jdk.proxy3/jdk.proxy3.$Proxy14.getString(Unknown Source)

            at org.artifactory.aql.result.AqlRestResult.canRead(AqlRestResult.java:70)

            at org.artifactory.aql.result.AqlJsonLocalStreamer.inflateRow(AqlJsonLocalStreamer.java:127)

            at org.artifactory.aql.result.AqlJsonLocalStreamer.getNewRowFromDb(AqlJsonLocalStreamer.java:257)

            at org.artifactory.aql.result.AqlJsonLocalStreamer.read(AqlJsonLocalStreamer.java:207)

            at org.artifactory.aql.result.AqlJsonLocalStreamer.read(AqlJsonLocalStreamer.java:186)

            at org.artifactory.storage.db.aql.service.AqlServiceImpl.read(AqlServiceImpl.java:282)

            at org.artifactory.storage.db.aql.service.AqlServiceImpl.lambda$streamResponse$0(AqlServiceImpl.java:266)

            at org.glassfish.jersey.message.internal.StreamingOutputProvider.writeTo(StreamingOutputProvider.java:55)

            at org.glassfish.jersey.message.internal.StreamingOutputProvider.writeTo(StreamingOutputProvider.java:37)

            at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.invokeWriteTo(WriterInterceptorExecutor.java:242)

            at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.aroundWriteTo(WriterInterceptorExecutor.java:227)

            at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:139)

            at org.artifactory.rest.interceptor.ClientAbortWriterInterceptor.aroundWriteTo(ClientAbortWriterInterceptor.java:23)

            at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:139)

            at org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor.aroundWriteTo(JsonWithPaddingInterceptor.java:85)

            at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:139)

            at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:61)

            at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:139)

            at org.glassfish.jersey.message.internal.MessageBodyFactory.writeTo(MessageBodyFactory.java:1116)

            at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:649)

            at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:380)

            at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:370)

            at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:259)

            at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)

            at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)

            at org.glassfish.jersey.internal.Errors.process(Errors.java:292)

            at org.glassfish.jersey.internal.Errors.process(Errors.java:274)

            at org.glassfish.jersey.internal.Errors.process(Errors.java:244)

            at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)

            at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:235)

            at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684)

            at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394)

            at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)

            at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:359)

            at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:312)

            at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:199)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.RepoFilter.execute(RepoFilter.java:227)

            at org.artifactory.webapp.servlet.RepoFilter.doFilter(RepoFilter.java:124)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.AccessFilter.useAuthentication(AccessFilter.java:597)

            at org.artifactory.webapp.servlet.AccessFilter.authenticateAndExecute(AccessFilter.java:451)

            at org.artifactory.webapp.servlet.AccessFilter.doFilterInternal(AccessFilter.java:302)

            at org.artifactory.webapp.servlet.AccessFilter.doFilter(AccessFilter.java:220)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.ArtifactoryProbesFilter.doFilter(ArtifactoryProbesFilter.java:46)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.RequestFilter.lambda$doFilter$0(RequestFilter.java:118)

            at org.artifactory.throttling.qrl.service.QueryRateLimiterServiceImpl.wrapRequestWithLowPriority(QueryRateLimiterServiceImpl.java:367)

            at org.artifactory.webapp.servlet.RequestFilter.doFilter(RequestFilter.java:118)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.ArtifactoryCsrfFilter.doFilter(ArtifactoryCsrfFilter.java:96)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:164)

            at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:80)

            at org.artifactory.webapp.servlet.SessionFilter.doFilter(SessionFilter.java:67)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.ArtifactoryFilter.doFilter(ArtifactoryFilter.java:129)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.artifactory.webapp.servlet.ArtifactoryTracingFilter.doFilter(ArtifactoryTracingFilter.java:42)

            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:168)

            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)

            at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:168)

            at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)

            at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:481)

            at org.apache.catalina.valves.rewrite.RewriteValve.invoke(RewriteValve.java:281)

            at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130)

            at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)

            at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)

            at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:346)

            at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:388)

            at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)

            at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:936)

            at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1791)

            at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)

            at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190)

            at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)

            at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63)

            at java.base/java.lang.Thread.run(Thread.java:840)

Caused by: java.lang.reflect.InvocationTargetException: null

            at jdk.internal.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)

            at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

            at java.base/java.lang.reflect.Method.invoke(Method.java:568)

            at org.jfrog.storage.wrapper.ResultSetWrapper.invoke(ResultSetWrapper.java:85)

            ... 88 common frames omitted

Caused by: org.postgresql.util.PSQLException: The column name itemPath was not found in this ResultSet.

            at org.postgresql.jdbc.PgResultSet.findColumn(PgResultSet.java:3085)

            at org.postgresql.jdbc.PgResultSet.getString(PgResultSet.java:2921)

            at com.zaxxer.hikari.pool.HikariProxyResultSet.getString(HikariProxyResultSet.java)

            ... 92 common frames omitted
peimanja commented 2 months ago

Hi @jingmxu thanks for reporting this. Can you try with the canary tag of the exporter and if possible attach the full logs with debug mode enabled.

jingmxu commented 2 months ago

Hi @peimanja, we don't use docker image so no canary build can be tested, I enabled debug log to find that the following query caused the error:

time=2024-08-13T11:42:48.297+08:00 level=DEBUG msg="Finding all artifacts" period=1minutes queryType=created

time=2024-08-13T11:42:48.297+08:00 level=DEBUG msg="Running AQL query" path=https://artifactory1.hkintegrationlab.com:443/artifactory/api/search/aql

time=2024-08-13T11:42:48.313+08:00 level=DEBUG msg="Finding all artifacts" period=5minutes queryType=created

time=2024-08-13T11:42:48.313+08:00 level=DEBUG msg="Running AQL query" path=https://artifactory1.hkintegrationlab.com:443/artifactory/api/search/aql

time=2024-08-13T11:42:48.327+08:00 level=DEBUG msg="Finding all artifacts" period=15minutes queryType=created

time=2024-08-13T11:42:48.327+08:00 level=DEBUG msg="Running AQL query" path=https://artifactory1.hkintegrationlab.com:443/artifactory/api/search/aql

time=2024-08-13T11:42:48.343+08:00 level=DEBUG msg="Finding all artifacts" period=1minutes queryType=downloaded

time=2024-08-13T11:42:48.343+08:00 level=DEBUG msg="Running AQL query" path=https://artifactory1.hkintegrationlab.com:443/artifactory/api/search/aql

time=2024-08-13T11:42:48.348+08:00 level=DEBUG msg="Finding all artifacts" period=5minutes queryType=downloaded

time=2024-08-13T11:42:48.348+08:00 level=DEBUG msg="Running AQL query" path=https://artifactory1.hkintegrationlab.com:443/artifactory/api/search/aql

time=2024-08-13T11:42:48.353+08:00 level=DEBUG msg="Finding all artifacts" period=15minutes queryType=downloaded

time=2024-08-13T11:42:48.353+08:00 level=DEBUG msg="Running AQL query" path=https://artifactory1.hkintegrationlab.com:443/artifactory/api/search/aql

Can you share the new create or downloaded in 1 minutes AQL query command? so that we may file a bug to Jfrog.

peimanja commented 2 months ago

Queries can be found here. https://github.com/peimanja/artifactory_exporter/blob/56a1722fa3ce5e62edf602ef7d263d18e302fe27/collector/artifacts.go#L20-L30

Unfortunately I cannot test against that version for now but I'll see if I get a chance to test the queries.

jingmxu commented 2 months ago

Thanks @peimanja , Jfrog has reproduced the issue, will keep you updated!

critchtionary commented 2 months ago

I also encountered this issue when upgrading from 7.84.20 to 7.90.8. The issue still occurs with the canary tag, although the frequency of the errors seem slightly different.

Debug logs:

time=2024-08-29T08:25:14.205Z level=DEBUG msg="Finding all artifacts" period=1minutes queryType=created
time=2024-08-29T08:25:14.205Z level=DEBUG msg="Running AQL query" path=http://artifactory.artifactory.svc:8081/artifactory/api/search/aql
time=2024-08-29T08:25:14.212Z level=DEBUG msg="Finding all artifacts" period=5minutes queryType=created
time=2024-08-29T08:25:14.212Z level=DEBUG msg="Running AQL query" path=http://artifactory.artifactory.svc:8081/artifactory/api/search/aql
time=2024-08-29T08:25:14.219Z level=DEBUG msg="Finding all artifacts" period=15minutes queryType=created
time=2024-08-29T08:25:14.219Z level=DEBUG msg="Running AQL query" path=http://artifactory.artifactory.svc:8081/artifactory/api/search/aql
time=2024-08-29T08:25:14.227Z level=DEBUG msg="Finding all artifacts" period=1minutes queryType=downloaded
time=2024-08-29T08:25:14.227Z level=DEBUG msg="Running AQL query" path=http://artifactory.artifactory.svc:8081/artifactory/api/search/aql
time=2024-08-29T08:25:14.228Z level=DEBUG msg="Finding all artifacts" period=5minutes queryType=downloaded
time=2024-08-29T08:25:14.228Z level=DEBUG msg="Running AQL query" path=http://artifactory.artifactory.svc:8081/artifactory/api/search/aql
time=2024-08-29T08:25:14.230Z level=DEBUG msg="Finding all artifacts" period=15minutes queryType=downloaded
time=2024-08-29T08:25:14.230Z level=DEBUG msg="Running AQL query" path=http://artifactory.artifactory.svc:8081/artifactory/api/search/aql
matthias-reiff commented 2 months ago

We also encounter the issue after updating from Artifactory 7.84.12 to 7.90.6.