-
Bug
-
Resolution: Fixed
-
Medium
-
4.2.0, 4.6.0
-
None
Problem
Deleting a Mirror via the Admin UI and then setting it up again from scratch with identical name and URL can lead to a mirror which doesn't synchronize with its upstream or display its configuration page correctly in the Admin UI.
The atlassian-bitbucket.log file on the upstream (primary) instance shows errors similar to the following:
2016-05-05 04:53:21,934 WARN [http-nio-7990-exec-7] cszmajda_admin *1HTRSCYx293x1202x0 w12con 172.22.44.144,172.25.1.50 "GET /rest/mirroring/latest/mirrorServers/B2TJ-LZYC-PNL8-COFF/webPanels/config HTTP/1.1" c.a.p.c.p.DelegatingConnectAddonInformationProvider Value in plugin settings: Optional[JWT] does not match value in applinks: Optional.empty when calling method getAuthenticationType. Returning value from applinks because feature flag connect.no-applinks is false. See https://ecosystem.atlassian.net/browse/ACDEV-1581
2016-05-05 04:53:21,948 ERROR [http-nio-7990-exec-7] cszmajda_admin *1HTRSCYx293x1202x0 w12con 172.22.44.144,172.25.1.50 "GET /rest/mirroring/latest/mirrorServers/B2TJ-LZYC-PNL8-COFF/webPanels/config HTTP/1.1" c.a.s.i.r.e.DefaultUnhandledExceptionMapperHelper Unhandled exception while processing REST request: "GET /rest/mirroring/latest/mirrorServers/B2TJ-LZYC-PNL8-COFF/webPanels/config HTTP/1.1"
java.lang.IllegalStateException: No valid authentication method found for Atlassian Bitbucket Mirror - AU Mirror (Dev).
This was probably caused by a data restore from a different instance.
Please refer this instance to the Atlassian Connect developer on support for remediation.
DO NOT simply re-install the affected add-ons; this can cause data loss for some add-ons.
See https://ecosystem.atlassian.net/browse/AC-1528
at com.atlassian.plugin.connect.plugin.request.DefaultRemotablePluginAccessorFactoryImpl.create(DefaultRemotablePluginAccessorFactoryImpl.java:230) ~[na:na]
at com.atlassian.plugin.connect.plugin.request.DefaultRemotablePluginAccessorFactoryImpl.create(DefaultRemotablePluginAccessorFactoryImpl.java:198) ~[na:na]
at com.atlassian.plugin.connect.plugin.request.DefaultRemotablePluginAccessorFactoryImpl.get(DefaultRemotablePluginAccessorFactoryImpl.java:127) ~[na:na]
at com.atlassian.plugin.connect.plugin.request.DefaultRemotablePluginAccessorFactoryImpl.get(DefaultRemotablePluginAccessorFactoryImpl.java:114) ~[na:na]
at com.atlassian.plugin.connect.plugin.web.iframe.ConnectAddonUriBuilderImpl$InitializedBuilderImpl.build(ConnectAddonUriBuilderImpl.java:146) ~[na:na]
at com.atlassian.plugin.connect.plugin.web.iframe.IFrameRenderStrategyBuilderImpl$IFrameRenderStrategyImpl.buildUrl(IFrameRenderStrategyBuilderImpl.java:361) ~[na:na]
at com.atlassian.plugin.connect.plugin.web.iframe.IFrameRenderStrategyBuilderImpl$IFrameRenderStrategyImpl.render(IFrameRenderStrategyBuilderImpl.java:319) ~[na:na]
at com.atlassian.plugin.connect.plugin.web.panel.ConnectIFrameWebPanel.writeHtml(ConnectIFrameWebPanel.java:36) ~[na:na]
at com.atlassian.plugin.connect.plugin.web.panel.ConnectIFrameWebPanel.getHtml(ConnectIFrameWebPanel.java:47) ~[na:na]
at com.atlassian.bitbucket.internal.mirroring.upstream.rest.WebPanelResource.lambda$getPanelHtmlFor$1(WebPanelResource.java:70) ~[bitbucket-mirroring-upstream-4.7.0-SNAPSHOT.jar:na]
at java.util.Optional.map(Optional.java:215) ~[na:1.8.0_60]
at com.atlassian.bitbucket.internal.mirroring.upstream.rest.WebPanelResource.getPanelHtmlFor(WebPanelResource.java:70) ~[bitbucket-mirroring-upstream-4.7.0-SNAPSHOT.jar:na]
at java.util.Optional.flatMap(Optional.java:241) ~[na:1.8.0_60]
at com.atlassian.bitbucket.internal.mirroring.upstream.rest.WebPanelResource.get(WebPanelResource.java:58) ~[bitbucket-mirroring-upstream-4.7.0-SNAPSHOT.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_60]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_60]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_60]
at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_60]
at com.atlassian.plugins.rest.common.interceptor.impl.DispatchProviderHelper$ResponseOutInvoker$1.invoke(DispatchProviderHelper.java:192) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugins.rest.common.interceptor.impl.DispatchProviderHelper$1.intercept(DispatchProviderHelper.java:83) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugins.rest.common.interceptor.impl.DefaultMethodInvocation.invoke(DefaultMethodInvocation.java:53) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugins.rest.common.expand.interceptor.ExpandInterceptor.intercept(ExpandInterceptor.java:34) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugins.rest.common.interceptor.impl.DefaultMethodInvocation.invoke(DefaultMethodInvocation.java:53) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugins.rest.common.interceptor.impl.DispatchProviderHelper.invokeMethodWithInterceptors(DispatchProviderHelper.java:110) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugins.rest.common.interceptor.impl.DispatchProviderHelper$ResponseOutInvoker._dispatch(DispatchProviderHelper.java:190) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) ~[atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469) ~[na:na]
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400) ~[na:na]
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349) ~[na:na]
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339) ~[na:na]
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416) ~[na:na]
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537) ~[na:na]
at com.atlassian.plugins.rest.module.RestDelegatingServletFilter$JerseyOsgiServletContainer.doFilter(RestDelegatingServletFilter.java:154) [atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.sun.jersey.spi.container.servlet.ServletContainer.doFilter(ServletContainer.java:795) ~[na:na]
at com.atlassian.plugins.rest.module.RestDelegatingServletFilter.doFilter(RestDelegatingServletFilter.java:68) [atlassian-rest-module-3.0.12_1462419120000.jar:na]
at com.atlassian.plugin.servlet.filter.DelegatingPluginFilter.doFilter(DelegatingPluginFilter.java:64) [atlassian-plugins-servlet-4.1.8.jar:na]
at com.atlassian.plugin.servlet.filter.IteratingFilterChain.doFilter(IteratingFilterChain.java:37) [atlassian-plugins-servlet-4.1.8.jar:na]
at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:70) [atlassian-plugins-servlet-4.1.8.jar:na]
at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:58) [atlassian-plugins-servlet-4.1.8.jar:na]
Other related log messages include:
2016-05-05 05:20:52,780 WARN [http-nio-7990-exec-10] *Z8S4ZIx320x836x0 1aizs2e 10.116.236.71,172.25.1.228 "GET /mvc/error401 HTTP/1.1" c.a.p.c.p.DefaultConnectAddonRegistry No settings found for listed connect add-on 'bitbucket.mirror.b2tj-lzyc-pnl8-coff' 2016-05-05 05:28:01,457 WARN [http-nio-7990-exec-1] *Z8S4ZIx328x1438x0 1q1p7ae 10.116.236.71,172.25.1.228 "POST /rest/ssh/latest/keys HTTP/1.1" c.a.a.c.DefaultApplicationLinkService Couldn't find type id for application link with id 2a013f24-c0a2-3636-ba7e-cefd45739afd. Link is corrupted 2016-05-05 05:20:17,975 WARN [http-nio-7990-exec-7] *Z8S4ZIx320x792x0 imneip 10.116.236.71,172.25.1.228 "DELETE /rest/ssh/latest/keys HTTP/1.1" c.a.p.c.p.a.u.ThreeLeggedAuthFilter No user key stored for add-on 'bitbucket.mirror.b2tj-lzyc-pnl8-coff'. Incoming requests from this issuer will be authenticated as an anonymous request.
The expected applink for the mirror also does not appear in the Application links page.
Clicking the Support Tools link for the mirror displays the 500 skull and crossbones.
Attempting to delete the mirror in the Admin UI may fail with the same error.
Workaround
Restarting the upstream (primary) instance should resolve this issue automatically.
- relates to
-
-
- Closed
-
| Form Name | |||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|
[BSERV-8731] java.lang.IllegalStateException: No valid authentication method found for Atlassian Bitbucket Mirror
I've managed to reproduce the issue with the following steps:
- Delete Mirror
- Stop mirror
- Create new home for mirror
- Start mirror
- Setup mirror
- Start mirorring
- 401’s
- Restart Mirror
- 401’s
- (Disable mirror auto deploy)
- (set up mirror debug logging)
- (wait for stash.dev deployment)
- Upstream restarted
- 200’s
Will begin looking into what could cause this behaviour. The fact that it starts working after restarting the upstream seems to indicate some kind of caching issue. The applinks key seems to be generated by some combination of link name and base URL, so potentially there's an issue there.
I just attached a full debug log that shows the behaviour during (cause of?) this failure. ( primary.log
)
Here's how to reproduce reliably:
Note that if you shut down the mirror before deleting it from the upstream, everything will work as expected.
This seems to be due to the SELECT in DELETE /rest/ssh/latest/keys causing Hibernate to cache the applinks.application.5b290c20-615a-3b5e-b3ca-d174b0d29aa6.user.key ID.
This row is removed shortly after (should actually be removed before, I'm not sure why the SELECT returns a result) and Hibernate's cache of the ID is not invalidated. All subsequent calls that cause a SELECT for this plugin setting cause Hibernate to construct the following query:
where the ID is substituted by a cached, but stale value.
It seems like the DELETE /rest/mirroring/latest/mirrorServers/BZ1O-DDC6-2YKY-LN0N transaction is taking too long, and doesn't commit before DELETE /rest/ssh/latest/keys accesses the plugin setting.
Not sure what the fix would be to be honest.