Request for useful event log messages - they're currently bad

Tuesday, November 14, 2023
Avatar

I've been chasing down a Jira to Spira sync issue now for weeks, months even.

In the last week I have spent at least three full days work on it.

Most of that time is wasted time caused by Spira's event logs failing to provide the crucial information required to identify the EXACT nature of the problem AND communicate it clearly to Spira support.

It's wasting all our time...not just mine.

I've been in the IT game since the early 1980s and I am still surprised by how poorly exception handling and logging is done most of the time.

As mentioned the problem I am having is that the Spira to Jira BUG/ISSUE sync is not working.

I've got a long way do the path. Most things are happening but I am still getting two errors in the log every time something changes (I will include details later).

These aren't trivial issues for me. Data is being clobbered and as a result I can't trust the process AT ALL at the moment.

Details aside, for Spira to be getting an error on a synchronisation, I would expect it to be comparing one or more "things"/fields to in fact even know there's an error?
So why not tell us, exactly, what they are?
Because the event log simply DOESN'T tell us which FIELD and WHAT data (on either side of the sync) is causing the error.
Why not?

Laziness is my guess.

Some programmer has said "This will never happen. Let's just dump it to the log"...and here we are.
 

I'm not asking for help or answers to my problem here. This post is about getting better event log messages.

So with that in mind below is just one of the errors I get that is a) enormous and b) almost completely unhelpful. 

Here's one of the errors:

ErrorData SynchronizationError Updating SpiraTeam Incident to JIRA: Web Exception Error calling JIRA REST API: 'The remote server returned an error: (400) Bad Request.' Details: {"errorMessages":[],"errors":{"rankBeforeIssue":"expected Object","rankAfterIssue":"expected Object"}}

...and here's it's details...

Error Updating SpiraTeam Incident to JIRA: Web Exception Error calling JIRA REST API: 'The remote server returned an error: (400) Bad Request.' Details: {"errorMessages":[],"errors":{"rankBeforeIssue":"expected Object","rankAfterIssue":"expected Object"}}Error Updating SpiraTeam Incident to JIRA: Web Exception Error calling JIRA REST API: 'The remote server returned an error: (400) Bad Request.' Details: {"errorMessages":[],"errors":{"rankBeforeIssue":"expected Object","rankAfterIssue":"expected Object"}}at Inflectra.SpiraTest.PlugIns.JiraCloudDataSync.JiraClient.JiraManager.RunQuery(JiraResource resource, String argument, String data, String method)at Inflectra.SpiraTest.PlugIns.JiraCloudDataSync.JiraClient.JiraManager.SaveIssue(JiraIssue jiraIssue, Boolean statusChanged)at Inflectra.SpiraTest.PlugIns.JiraCloudDataSync.DataSync.ProcessUpdatedIncident(Int32 projectId, SoapServiceClient spiraImportExport, RemoteIncident remoteIncident, List`1 newReleaseMappings, Dictionary`2 customPropertyMappingList, Dictionary`2 customPropertyValueMappingList, RemoteCustomProperty[] incidentCustomProperties, RemoteDataMapping[] incidentMappings, JiraProject jiraProject, JiraManager jiraManager, String productName, RemoteDataMapping[] severityMappings, RemoteDataMapping[] priorityMappings, RemoteDataMapping[] statusMappings, RemoteDataMapping[] typeMappings, RemoteDataMapping[] userMappings, RemoteDataMapping[] releaseMappings, RemoteDataMapping[] incidentComponentMappings, List`1 recentlyUpdatedFromJira)at Inflectra.SpiraTest.PlugIns.JiraCloudDataSync.DataSync.Execute(Nullable`1 lastSyncDate, DateTime serverDateTime)

 

I've looked at hundreds of messages like this, in Spira, for this problem.

Other people, including Spira support, have looked at these messages...a lot.

So I have reasonable confidence that this isn't just me. No-one can point me in the right direction. I've been going around and around.

So, in the Event logs, Why can't we see:

1) A date and time stamp in the details (because when you view the details among this many events it is hard to tell which one you are looking at)

2) The field names that caused the error? I've looked and looked. I can't see that information. There are things named, but they seem irrelevant.


3) The actual data that caused the error? Really? Just why-the-hell-not? If I could enter unique and identifiable data in bug fields I could see which one was at fault but...

4) Why not report an IDs of the records, or BUGS/Incidents etc. The data must be there at the sync's fingertips to be able to know there's a problem. Just fricken tell us!!

5) Which direction the data was trying to go? With the lag in the sync process itself and the subsequent logs it is quite annoying to not be able to "just see" in the log which directions was at fault. I've had to derive this information from hours of "changing one thing" and waiting for "at least three minutes" to see what happens...and even then things get logged a few minutes after I expect them to be.

These are just 5 things off the top of my head that would make Spira's event logs not just better, but actually useful.

 

Here's another idea to make event logs better... perhaps make the amount of detailed displayed in the log adjustable - less for everyday, more for when troubleshooting.


I realise that when dealing with third party products things can be out of Spira's and my control.

My issue may well come down to something I can't change in Jira.

These logs, and many of the things Spira USERS are required to do to make this Sync work, fail to realise that many of us live within the constraints of IT departments with access policies of their own.

They deny us what Spira tells us we need AND are slow, unresponsive and intractable in themselves.

Information is power.

If Spira and Spira support think it isn't their fault, then show us the information.

Give us event logs that log useful information...for US, the USERS/victims of all this.

 

7 Replies
Tuesday, November 14, 2023
Avatar
re: David_Moore Tuesday, November 14, 2023

Here are some more real examples from my Spira System Event log;

--

Unable to locate requested user

Nothing

--

Unable to locate mapping entry for Jira user 63f2fb17ce6f37e5ed92b83b so ignoring the assignee change

Unable to locate mapping entry for Jira user 63f2fb17ce6f37e5ed92b83b so ignoring the assignee change

--

Object reference not set to an instance of an object.

In APPLICATION.Web.UserControls.WebParts.MyPage.PendingTestRuns::grdSavedTestRuns_RowCommand:Messages:Object reference not set to an instance of an object. [System.NullReferenceException {0x80004003}]Stack Trace:at APPLICATION.Web.UserControls.WebParts.MyPage.PendingTestRuns.grdSavedTestRuns_RowDataBound(Object sender, GridViewRowEventArgs e)

--

 

Tuesday, November 14, 2023
Avatar
re: David_Moore Tuesday, November 14, 2023

Thanks for taking the time to explain the issues you have had with our Jira data sync. I appreciate that it has been frustrating to resolve the sync issue and that it has taken a lot of your time. Hopefully our support team will be able to help get the specific problem you are facing resolved.

Taking a step back, as you have done in this helpful post, error handling and logging is difficult to get right. As you say, it is, however, critical to troubleshooting - either for you as the end user or with our support team.

Our data sync team tries to strike a balance between clear error messages and logging, without overwhelming users. In some areas we can definitely improve things, in others we have to rely on error messages from the third party application (in this case Jira). The team are working on an update to the Jira data sync that should be released this quarter. This updated will include a number of enhancements specifically related to logging. We will share this thread with them to see if there is anything more they can do based on your insights that will help you and other customers.

Finally, I believe there are ways to increase the amount of logging to help with troubleshooting. This depends on how you are syncing with us. If you would like more help with that please contact our support team.

Sunday, November 19, 2023
Avatar
re: inflectra.clark Tuesday, November 14, 2023

Thanks Clark.

At present I have had to give up on making the sync work the way we'd like.

Instead I've had to develop a work-around and document it for my team (in-progress).

It's far from ideal but I've spent too much time on making this work when I need to be actually doing test activities for the project.

David

Thursday, November 23, 2023
Avatar
re: David_Moore Tuesday, November 14, 2023

"Most of that time is wasted time caused by Spira's event logs failing to provide the crucial information required to identify the EXACT nature of the problem AND communicate it clearly to Spira support."

Unfortunately, I have to agree. Currently my event log has hundreds of copies of the following message:

"Nullable object must have a value.In APPLICATION.Web.Services.Ajax.TasksService::Task_RetrieveProgress:Messages:Nullable object must have a value. [System.InvalidOperationException {0x80131509}]Stack Trace:at System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)at APPLICATION.Web.Services.Ajax.TasksService.Task_RetrieveProgress(Int32 projectId, Nullable`1 releaseId)"

Hardly useful, and nobody seems to know what the issue is.

Sunday, November 26, 2023
Avatar
re: johnd Wednesday, November 22, 2023

That message means that when displaying a tooltip on the task progress bar, there was a null value.

It is most likely a message that is logged and then caught and not displayed to the end user.

So it can be ignored. Those messages are useful for our product team, but we have code in place to catch them and not cause an issue to the end user.

Monday, November 27, 2023
Avatar
re: David_Moore Tuesday, November 14, 2023

I also struggle to make sense of the context of the logs. context and better filtering controls would be a big help.

Wednesday, December 6, 2023
Avatar
re: johnd Wednesday, November 22, 2023

Thanks for that John.
Good to know (kind of) that I'm not on my own and going mad.

I must confess, I have also wondered why Spira upport don't have access to our logs?

...or maybe they do, but I feel I have had to spend a lot of time copy messages from the log into support tickets.

It would nice to be able to just flag the messages in question, raise a ticket, and say "refer flagged log messages".
Most other systems I've had the need to get help with have pretty much verified who I am and then gone straing to my instance of the thing and looked right at what I am seeing.

Anyway, another one for the enhancements list.

I am actually talking to Adam Sandman tomorrow morning :-)
So 11 points out of 10 for escalation Spira. I've been heard all the way to the top.
Thanks.
David
 

Spira Helps You Deliver Quality Software, Faster and With Lower Risk

And if you have any questions, please email or call us at +1 (202) 558-6885

 

Statistics
  • Started: Tuesday, November 14, 2023
  • Last Reply: Wednesday, April 3, 2024
  • Replies: 7
  • Views: 521