Dynamics GP – Odd issue using a DNS Alias for the SQL Server resulting in the error – No Obligations found on VAT Return

A colleague and I worked on a very interesting support ticket today. A client reported that when logging into Dynamics GP using their own Dynamics GP User ID they received the error “No Obligations Found” when retrieving the obligations for the VAT Return however it worked fine when logged in as “sa”.

**Please note there has been a service pack to correct this exact issue however this has been applied to the clients system so it can’t be causing this issue**.

As this worked with “sa” we checked the SQL Error log and surprisingly we found the following messages recorded at the time the routine had been ran:

As you can see the error log is scattered with “Login failed for user” messages for the user in the question.

The next part of the investigation was to setup a SQL Profile Trace to see what SQL statements were running just prior to the login failed message and we found the following:

As you can see the SQL statement “select SERVERPROPERTY(‘ServerName’)” runs just prior to the login failed errors.

My colleague then recalled they are using a DNS Alias for the SQL server name in the ODBC connection rather than the actual SQL server name.

We therefore ran “select SERVERPROPERTY(‘ServerName’)” on the server and, as expected, this returns the actual SQL server name rather than the alias name that is used in the server name in the ODBC connection on the clients PC.

Intrigued that the issue could somehow be related to how GP encrypts passwords using the SQL server name we setup the following test:

  1. Created an additional ODBC connection on the clients PC pointing to the actual SQL server name rather than DNS Alias name.
  2. Logged into Dynamics GP as “sa” using this new ODBC and created a new GP user, copying the security of the existing user. (so the password gets encrypted using the actual SQL server name)
  3. Finally, we logged into GP using the new ODBC and the new GP user.

After successfully logging in using the new user, and the ODBC pointing at the actual SQL server name, we walked through retrieving the obligations and the whole process worked. We also checked the SQL error log and there were no “Login Failed” error messages for the user.

I have to admit at this point I’m guessing as to what is going on however based on the results of this isolated test I can only assume that somehow during this process the users Dynamics GP credentials are being re-submitted to SQL using the actual SQL server name, and as the users password is encrypted with the SQL server DNS Alias name, its failing with “Login failed”. This works when logged in as “sa” because this is the only User ID that doesn’t have its password encrypted by GP. (its not encrypted because its the SQL System Administrator account)

Therefore although using a DNS alias can help with server changes (ironically because of how GP encrypts the password), this has got us thinking that using a DNS Alias for the SQL server could be causing other issues with GP that we don’t know about, so we may avoid this in the future if we can.

After discovering this little oddity I’d be interested if anyone else has any other experience of issues when using a DNS Alias for the SQL server.

Disclaimer :- I’d usually attempt to recreate this type of issue on my own system before documenting and sharing however I can’t in this instance as I don’t have an account with HMRC to complete the full process. However given how interesting this does seem I thought it worthwhile sharing anyway.

Thanks for reading.

Dynamics NAV – The Warehouse Request does not exist when posting an Inventory Pick

I recently came across the following error when trying to post an Inventory Pick in Dynamics NAV 2018

On investigation this is being caused because although the Inventory Pick had been created from the Sales Order, the Sales Order had subsequently been shipped and invoiced directly from the Sales Order screen rather than via the Inventory Pick. (this surprised me as I assumed the system would prevent the Sales Order from being shipped and invoiced from the Sales Order if an unposted Inventory Pick existed for it)

For clarity, as I understand things when a location has the “Require Pick” option ticked in the location setup (important to note “Require Shipment” isn’t ticked) the usual process for shipping and invoicing a Sales Order would be:

  1. Create the Sales Order.
  2. Release the Sales Order.
  3. Create the Inventory Pick in a push or pull fashion from the Sales Order.
  4. Post the shipment from the Inventory Pick.
  5. Post the Invoice from the Sales Order.

It seems that somewhere between point 3 and 4 someone had opened the Sales Order and clicked “Post” and selected “Shipment and Invoice” even though the Inventory Pick was still unposted.

On investigation this removes the internal “Warehouse Request” from the warehouse request table and when you try and post the Inventory Pick you are presented with the error “The Warehouse Request does not exist”.

As far I can see the only option here is to delete the Inventory Pick as it can’t be progressed. (I also assume the goods have been shipped)

I’ve tested this same process on a version of Dynamics 365 Business Central and it seems to prevent the Sales Order being shipped and invoiced if an Inventory Pick exists for it. When you do try you get the message below:

This does make more sense to me, I’m just surprised Dynamics NAV doesn’t prevent it.

As with all issues I did learn something new and also had fun looking at the importance of the internal Warehouse Request with all this. This is something I’m hoping to look at it more depth in future.

Thanks for reading!

Dynamics GP – All rows mysteriously deleted from SOP Distribution Work\History (SOP10102)

This week I dealt with a very bizarre issue affecting all Sales Order Processing Transactions that I thought was worth documenting. It started with a simple support request explaining that Sales Order Processing Invoice transactions weren’t posting due to missing distributions. See below

Missing SOP Distributions

When I connected to investigate further I found the Sales Order Processing Distribution Work\History table (SOP10102) was, with the exception of a hand full of rows, completely blank. (and those rows related to the most recently added SOP transactions)

As this table contains the distributions for both Work and History documents all distributions on posted Sales Order Processing transactions had been lost as well.

Before I even considered how this could have happened I set about trying to find out which user could have done this, and when it happened, so I could recover the missing data.

The first clue for when this could have happened lay with the SQL transaction log backups. As this table would have had hundreds of thousands of rows, I suspected this would have generated lots of SQL transaction log, so I checked the size of the transaction log backups and this highlighted a larger than normal LOG backup at midday (I could do this as the SQL database is in FULL recovery model and the client performs hourly transaction log backups)

Large transaction log backup at midday

I now suspected the issue had arose between 11am and midday so I set about querying the contents of this SQL transaction log backup file looking for transactions with deletes on the SOP10102 table using the query below.

(As usual I’m standing on the shoulders of giants for this one by using this excellent blog post by SQL guru Paul Randal as the basis of the query https://www.sqlskills.com/blogs/paul/using-fn_dblog-fn_dump_dblog-and-restoring-with-stopbeforemark-to-an-lsn/. As a side note this website is an awesome SQL resource!)

select	
	[begin time] as BeginTime,
	[End Time] as EndTime,
	SUSER_SNAME ([transaction sid]) as UserID, 
	object_name(object_id) as TableName, *
FROM fn_dump_dblog 
	(NULL, NULL, N'DISK', 1, N'D:\...\backup_2019_10_07_120002_5428125.TRN', 
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT) as log1
left join sys.partitions part 
	 on part.partition_id=log1.partitionid
where  
	[transaction id] IN
(select 
	[transaction id]
 FROM fn_dump_dblog 
	(NULL, NULL, N'DISK', 1, N'D:\...\backup_2019_10_07_120002_5428125.TRN',
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT) as log1
left join sys.partitions part 
	on part.partition_id=log1.partitionid
where 
	operation = 'LOP_DELETE_ROWS' and 
	object_name(object_id) in ('SOP10102')) 
order by [Transaction ID]

I scanned through the results and found the transaction id below which was logging lots of deletes on the SOP10102 table

Transaction showing deletes on SOP10102

I then took this Transaction ID and ran the following SQL query to get full details on this SQL Transaction

select 
	[begin time] as BeginTime, 
	[End Time] as EndTime,
	SUSER_SNAME ([transaction sid]) as UserID, 
	object_name(object_id) as TableName, *
FROM fn_dump_dblog 
	(NULL, NULL, N'DISK', 1, N'D:\...\backup_2019_10_07_120002_5428125.TRN', 
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
	 DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT) as log1
left join sys.partitions part 
	on part.partition_id=log1.partitionid
where  [transaction id] IN ('0000:088fba17')

This query returned 1,466,128 rows all of which are deletes to SOP10102. (this is more than the number of rows in the table which is likely because of the additional deletes on the SQL non clustered indexes that also need maintaining)

Lots of deletes on SOP10102 table

Following on from this I’m now know the user who has caused the deletes, and the exact time it happened. I also know this SQL Login ID relates to a GP user which means this has to have happened inadvertently while using GP. (you can’t use a Dynamics GP SQL Login to access the data via any tool other than Dynamics GP as the password is encrypted)

I asked the user in question if they noticed anything strange at this time like GP crashing or hanging but unfortunately they don’t recall. Therefore this is still a total mystery I’m afraid.

To recover the data I restored the backup to a new database right up to the point of the data going missing i.e. I restored the FULL SQL backup and all LOG backups with NORECOVERY with the exception of the last LOG backup which I restored as per below

I then copied the data back using the SQL query below

INSERT INTO LIVEDB..SOP10102
(SOPTYPE, SOPNUMBE, SEQNUMBR, DISTTYPE, DistRef,
ACTINDX, DEBITAMT, ORDBTAMT, CRDTAMNT, ORCRDAMT,
CURRNIDX, TRXSORCE, POSTED, Contract_Exchange_Rate)
SELECT
A.SOPTYPE,
A.SOPNUMBE,
A.SEQNUMBR,
A.DISTTYPE,
A.DistRef,
A.ACTINDX,
A.DEBITAMT,
A.ORDBTAMT,
A.CRDTAMNT,
A.ORCRDAMT,
A.CURRNIDX,
A.TRXSORCE,
A.POSTED,
A.Contract_Exchange_Rate
FROM RESTOREDDB..SOP10102 A
LEFT JOIN LIVEDB..SOP10102 b
on a.SOPNUMBE=b.SOPNUMBE and a.SOPTYPE=b.SOPTYPE
WHERE
B.SOPNUMBE IS NULL

After running the INSERT query the client confirmed that all the data had been recovered.

I’d be interested to know if anyone else has seen anything similar in the past. Unfortunately I’ve also seen this happen on the Purchase Order Processing side but it was before my blogging days. I’ve also found this Microsoft blog which documents a similar issue that Microsoft support dealt with https://blogs.msdn.microsoft.com/developingfordynamicsgp/2010/04/08/pop-distributions-randomly-being-deleted/

Although I didn’t get to the bottom of the missing POP data I did have my suspicions however there are no related third parties that could have caused this issue with SOP10102.

Unfortunately I suspect this will also remain an unsolved mystery I just hope it doesn’t happen again.

Thanks for reading