Thursday, March 26, 2015
TFS4JIRA Synchronization Filters
TFS4JIRA, our second best-selling plugin, has just been released with new, highly requested feature - Synchronization Filters. We got feedback from many of our clients that they want to somehow limit which issues and work items are synchronized and now they are able to do that. Typical use case for Filters feature are situation where given issue is marked with some label - only issues with this label will be synchronized. Detailed information about how to use Filters can be found in TFS4JIRA documentation.
Along with new Filters feature we introduced also new design for TFS screens. We named it using super-fancy abbreviation: "TUI" (TFS4JIRA User Interface). Profile Wizard and Synchronization Filters are the first screens created with this new layout but eventually all screens will be using it.
Thursday, March 5, 2015
The goal of this blog post is to share experiences regarding analyzing and debugging concurrency issues that occured after integrating JIRA Plugin with Atmosphere library. Perhaps a few tricks might be useful for casual developer, perhaps some of them could be avoided or replaced with better techniques. Anyway, the audience of this blogpost is the developers, so expect
I'm a part of the team that develops a new plugin from scratch for the JIRA Agile application. The plugin main functionality is to allow people placing estimations on the issues - in the realtime! So whenever you're participating in the planning session you could instantly see in your JIRA what are the estimations from your colleagues - all that without the need of bringing those passé poker cards to the session, or without using external application for managing the voting. Anyway, one of the non trivial development tasks was to implement the 'real-time' communication between different web browsers - for example if user A place a vote we would like to transmit that information to the user B and show him the vote (without refreshing the page). Technically we could implement all the stuff (frontend, backend) by ourselves, but being a
Unfortunately for us, after managing to integrate with the aforementioned library in our JIRA plugin we started to experience very UNSTABLE webdriver test runs on our build server. Yes, I know, webdriver tests are destined to be unstable, but nearly all of the tests were failing/erroring out with unpredictable scheme. That's not acceptable! So after a bit of astonishment (our plugin seemed to be OK when manually tested) we needed to admit that there is something sinister happening. In the end it turned out to be a concurrency issue: in a non-deterministic condition two threads were writing over the same object, while they shouldn't do that. Quite a trivial issue, but due to the complexity of involved components (Tomcat, Atmosphere, JIRA, our plugin) it took me a few weeks to nail down the problem. And so I decided to share you a few of my experiences.
Ok, so as I said before, the initial symptom was that our webdriver tests were failing. After inspecting build logs and screenshots from the failed tests, these fact became obvious:
1) the browser usually failed to load the page completely - in the screenshots we could see white (empty) space, without any html loaded.
2) sometimes the browser failed with the following screenshot:
Yuck, not very much informative.
3) build logs revealed that something wrong was happening with the http communication, as following exceptions were observed in the logs:
12-sty-2015 19:13:40 [INFO] http-bio-2990-exec-1 ERROR admin 1153x85x1 8a9ocx 127.0.0.1 /secure/RapidBoard.jspa [com.atlassian.velocity.DefaultVelocityManager] Exception getting message body from Velocity: 12-sty-2015 19:13:40 [INFO] java.lang.IllegalStateException: getOutputStream() has already been called for this response 12-sty-2015 19:13:40 [INFO] at org.apache.catalina.connector.Response.getWriter(Response.java:639)
org.apache.catalina.*internals. Not good.
Ok, so the initial observation was that something is corrupting Tomcat (org.apache.catalina.*) Response objects - but who and why?
Let's debug.To make things worse the problem appeared to be very tentative - it manifested itself nearly on each build run (where all the test are executed), ok, good, but locally you wouldn't have such luck - there was no steps to reproduce the issue in a deterministic way. So, what were the options? I concluded that it might be good idea to attach IDEA debugger to a running application and run the tests in a loop. I hoped that at some run the exception will occur and I will be able to inspect things a bit with debugger. Ok, so the first task was to put breakpoints at the right code lines. The logs from the builds contained the relevant code parts, so it should be as simple as doing CTRL+N CTRL+N and entering, for example, "org.apache.catalina.connector.Response" and go to line 639 (see the first log I've attached above). So simple.
Unfortunately, the Tomcat code (org.apache.catalina.*) is not used explicitly by our plugin - of course, eventually the plugin runs in the JIRA environment, which in turn uses Tomcat as a servlet container, but IDEA debugger has no idea of it! So we need to add proper dependency in our project's pom.xml for making things obvious to IDEA: first we deduct which version of Tomcat is used:
...then, we might add a special maven profile in our pom.xml and enable it on our devbox:
With above directives IDEA is now able to see Tomcat sources. We can place breakpoints in the exception triggering places and start looping webdriver tests. Whew. A few coffees later breakpoint triggers: the JVM threads are frozen and we can inspect the situation prior to throwing IllegalStateException. As one might expect - there is nothing interesting: after inspecting the Response object (I'll spare the details) we can clearly see that it is 'committed' - whatever that means, but there is no trace of who did that. Let's check how Response.setCommitted() looks like (this is the only place where 'commited' flag is changed):
A simple setter. If only we could see the trace of who was executing last time this setter. Fortunately, IDEA breakpoints have nice functionalities - let's exert them! We do right click on the breakpoint:
...and there we can:
1) turn off thread suspension - because we don't want the application to stop on each "setCommitted" operation - there are thousands of them being correct while usually only one is wrong. We don't know upfront which one.
2) log evaluated expression - where we can execute one-line java expression, so we can start logging something like:
or we can even use existing object structures and methods to keep IDEA console clean:
And later retrieve the stacktrace of the offending thread via the debugger, when the IllegalStateException does occur again:
...and reformat it in whatever text editor:
This allows to see what did commit the Response object - it is actually some code of the Atmosphere library (org.atmosphere.cpr.*), which we call during processing http request in our plugin (com.spartez.pokerng.atmosphere.SpartezAtmoshpereFilter). However, analyzing the relevant code of those classes leads to no conclusion. We need more data.
At this moment I didn't understand clearly which threads were involved. I knew which thread was throwing the IllegalStateException, because I could see it clearly in the debugger:
System.out.println(Thread.currentThread().getName() + " " + System.identityHashCode(someObject)
Thread.currentThread().getName()is enough to give the answer for the "which thread" question, while
System.identityHashCode(obj)is enough to give the answer for the "which object" question. Not going into details of how I've chosen where to put those statements, let's just say that after some trial & error I've had quite a decent activity logs, like the example below:
1) new request has come from the web browser (via TCP) and Tomcat should handle that
2) a thread is waking up from the pool - in the example above these threads are named "http-bio-2990-exec-X", and I've logged wake up with the "obudzil sie" message written to the System.out.
3) a thread is handling the request - it passes it to the underlying servlet (JIRA side) or whatever, and it uses Tomcat's org.apache.coyote.Response to deliver http content back to the web browser.
3.1) in the example above you can see that http-bio-* threads are serving the headers (sendHeaders()) which result in setting committed flag. I weren't logging other activity as I wasn't interested in it.
4) after finishing processing the request - the relevant resources (in our example: Response object) are recycled and the thread goes to the pool ("skonczyl sie" message)
// org.apache.coyote.Response code from tomcat 7.0.40. Lines 511-527:
locale = DEFAULT_LOCALE;
characterEncoding = Constants.DEFAULT_CHARACTER_ENCODING;
contentLength = -
// update counters
Completing asynchronous request.
1) the stacktrace in the moment of calling asyncContext.complete()
2) the stacktrace in the moment of committing the Response
made the webdriver tests to run stable. Whoa. Could it be that Atmosphere authors didn't know that you can't manipulate Response objects after completing asynchronous operations? Perhaps the problem only manifest itself in the JIRA/Tomcat7 environment - I guess Atmosphere is used occasionally on such a combo. So perhaps nobody have this problem yet, because other containers have different (contention-proof) recycling mechanisms. Or maybe no recycling mechanisms at all. I dunno.
Fixing the problem should be quite easy now - for example one might modify Atmosphere code and get rid of these unnecessary .close() actions. Another one could raise an issue in the Atmosphere Github repository and wait till authors fix the issue. Another one can wrap the Response objects with own wrapper that will be able to cut any action after the asyncContext.complete() is called. Another one might find yet another creative solution.
Anyway, that's a different story. In this blog post I wanted to focus on analyzing concurrency issues and as we finally got into the root cause of the problem - I think we can finish the story here. I hope you enjoyed it, thanks for reading.
Oh, and by the way: if you are active JIRA Agile user and you do estimating of story points for your issues (or plan to add that step to your development process) you might be interested in checking out our new add-on available on the Atlassian Marketplace: Agile Estimates. It's a tool for collaborative estimating within JIRA Agile directly, and incidentally also the product that made me write this blog post in the first place. :)
Wednesday, March 4, 2015
The problem appeared that there was no mechanism to ensure that developer included JIRA issue key in his check-in comment. If there is no such key, then obviously such a check-in is not shown in JIRA. We decided to create an open source TFS check-in policy plugin that will enforce developers to include at least one valid JIRA issue key. It's already available on the Visual Studio Gallery.
How custom TFS check-in policy works internallyCustom check-in policy is a plugin to Visual Studio installed by each developer separately, but its configuration is stored globally in TFS Server. To see what it means let's first take a look at the diagram below:
Let's assume the following:
- Team Lead installed and configured custom policy in his Visual Studio.
- Developer A installed custom policy plugin in his Visual Studio.
- Developer B did not install custom policy plugin in his Visual Studio.
Creating custom check-in policyA good place to start developing custom check-in policy is this tutorial (remember to install Visual Studio SDK before you dive in). It explains the basics well but during development of our custom check-in policy we had to solve some interesting problems that weren't covered there:
Custom check-in policy created for one version of Visual Studio will not work with other versions. That's because the version of assembly Microsoft.TeamFoundation.VersionControl.Client referenced from your plugin has to match version of target Visual Studio. That's why we've created separate packages for VS 2010, 2012 and 2013 that reference the Core project with business logic. Taking into account the fact that for each VS you need a separate VSIX package the structure of our plugin looks as follows:
Plugin projects are just very thin wrappers for Core. The code looks exactly the same for VS 2010, 2012 and 2013 so we took advantage from Add as Link functionality in Visual Studio to have only one copy of source files.
Initially we configured assembly name for projects 'Plugin for VS 2010', 'Plugin for VS 2012' and 'Plugin for VS 2013' in the following way:
- 'Plugin for VS 2010' produced an assembly called CheckinPolicyVS2010.dll,
- 'Plugin for VS 2012' produced an assembly called CheckinPolicyVS2012.dll,
- 'Plugin for VS 2013' produced an assembly called CheckinPolicyVS2013.dll.
Now let's assume that the Team Leader has installed and configured our custom check-in policy using Visual Studio 2010. The problem is that TFS stores assembly name in which custom check-in policy is defined (in this case CheckinPolicyVS2010.dll) in central TFS server. So the custom policy will work for team members using VS 2010 but not for these using VS 2012 and VS 2013 (Because they don't have CheckinPolicyVS2010.dll). The solution is to set the same assembly name for all three mentioned projects.
Our custom policy connects with JIRA so we need to store somewhere connection credentials. Of course central TFS server is not a good place for such data so we decided to use Data Protection API (DPAPI) to encrypt them and store locally for each developer. We used the great EasySec nuget package to work in DPAPI. It gives you a very convinient API to encrypt and decrypt data:
var encryptor = new EasySec.Encryption.DPAPIEncryptor(); var stringToEncrypt = "stringToEncrypt"; var encryptedString = encryptor.Encrypt(stringToEncrypt); var decryptedString = encryptor.Decrypt(encryptedString);
Source codeYou can find the source code for our plugin on Bitbucket. Feel free to comment and contribute.
Monday, July 28, 2014
Although the holiday season is taking a toll on our team (sunny skies outside and the proximity of the beach seem to have something to do with this...) we're always cooking comething in our Spartez lab.
Probably deserving the highest praise in this regard are Quick Notes, formerly known as “kwik!”. Having recently gone a thorough makeover in terms of general appearance and functionalities, followed by a series of new releases with significant bugfixes, this clever little plugin is now improved and perfect for taking notes while browsing Confluence pages, just as you would use Post-It for annotating the content of a physical piece of paper.
Agile Cards have also made it to the new release delivery box. The series of recent usability improvements and bugfixes includes a few changes regarding the card templates. The cards’ print settings have been moved to templates; print templates can now be selected when printing from JIRA Agile boards. Also, templates are no longer linked to individual projects and are now sorted alphabetically in the "Select template" screen.
Coming up soon is a new release of TFS4JIRA with lots of new synchronization features.
In the meantime we’re slipping on our geeky flip-flops on, grabbing a handful of wifi and making our way over to the beach to continue summer’s developments… See you in the sun!
Thursday, May 15, 2014
Now that the our Ephor standalone asset management system is out and about, we’ve recently launched a Service Desk-integrable Ephor4JIRA app.
Here is a small preview:
If you don't have JIRA, or if you want to have a separate asset management server that is not hosted in JIRA (but can talk to JIRA, delegating asset workflows to it) - use Ephor standalone.