Artifactory AQL error message with version 7.90.6 #146

jingmxu · 2024-08-12T05:58:07Z

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

The text was updated successfully, but these errors were encountered:

peimanja · 2024-08-12T21:10:47Z

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 · 2024-08-13T12:38:09Z

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 · 2024-08-13T15:46:36Z

Queries can be found here.

artifactory_exporter/collector/artifacts.go

Lines 20 to 30 in 56a1722

    
           func (e *Exporter) findArtifacts(period string, queryType string) (artifactQueryResult, error) { 
        
           	var query string 
        
           	artifacts := artifactQueryResult{} 
        
           	e.logger.Debug( 
        
           		"Finding all artifacts", 
        
           		"period", period, 
        
           		"queryType", queryType, 
        
           	) 
        
           	switch queryType { 
        
           	case "created": 
        
           		query = fmt.Sprintf("items.find({\"modified\" : {\"$last\" : \"%s\"}}).include(\"name\", \"repo\")", period)

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

jingmxu · 2024-08-15T01:12:03Z

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

critchtionary · 2024-08-29T08:27:39Z

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 · 2024-08-29T12:33:12Z

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

critchtionary · 2024-12-13T16:54:45Z

I believe this has been fixed on the JFrog side https://jfrog.atlassian.net/browse/RTFACT-30709

I no longer get the error on Artifactory 7.98.10

peimanja added the keep-open Make stale action ignore the Issue/PR label Aug 12, 2024

peimanja mentioned this issue Sep 12, 2024

Not getting the metrics created and downloaded of an Artifactory SAAS environment #147

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Artifactory AQL error message with version 7.90.6 #146

Artifactory AQL error message with version 7.90.6 #146

jingmxu commented Aug 12, 2024

peimanja commented Aug 12, 2024

jingmxu commented Aug 13, 2024

peimanja commented Aug 13, 2024

jingmxu commented Aug 15, 2024

critchtionary commented Aug 29, 2024

matthias-reiff commented Aug 29, 2024

critchtionary commented Dec 13, 2024

Artifactory AQL error message with version 7.90.6 #146

Artifactory AQL error message with version 7.90.6 #146

Comments

jingmxu commented Aug 12, 2024

Overview of the Issue

Reproduction Steps

Operating system and Environment details

Logs

peimanja commented Aug 12, 2024

jingmxu commented Aug 13, 2024

peimanja commented Aug 13, 2024

jingmxu commented Aug 15, 2024

critchtionary commented Aug 29, 2024

matthias-reiff commented Aug 29, 2024

critchtionary commented Dec 13, 2024