UDT Hostnames and IP Address stopped working

anything in the logfiles (particularly udt.businesslayer.log)?

You might have to push the logging level up to 'debug'

RichardLetts where would I find that log file ?

My searches are turning up the following:

neither of which are logs.

I have done some investigation into my network and found that my core switch\router has valid ARP entries

IP Address       MAC Address        Interface       Type      Age
---------------  -----------------  --------------  --------  -----------
192.168.9.11     1803.7325.969F     Vl20            Dynamic    0h  4m  2s
192.168.9.13     F01F.AF66.A0C7     Vl20            Dynamic    0h  6m 34s
192.168.9.14     0026.B986.4A00     Vl20            Dynamic    0h  4m  2s
192.168.10.1     D067.E5A5.7FF0     Vl30            Local         n/a
192.168.10.2     0050.568E.2829     Vl30            Gateway    0h  0m  0s
192.168.10.61    0050.568E.2827     Vl30            Dynamic    0h  1m  5s
192.168.10.67    0050.568E.2829     Vl30            Dynamic    0h  7m  1s
192.168.10.74    0050.568E.2829     Vl30            Dynamic    0h  7m  1s
192.168.13.1     D067.E5A5.7FF0     Vl50            Local         n/a
192.168.13.55    2477.03B3.4B38     Vl50            Dynamic    0h  5m 46s
192.168.13.58    0CEE.E6E1.58BB     Vl50            Dynamic    0h  0m  0s
192.168.13.59    3CA9.F483.2194     Vl50            Dynamic    0h  1m  5s
192.168.13.63    1803.7325.4F27     Vl50            Dynamic    0h  4m 33s
192.168.14.1     D067.E5A5.7FF0     Vl60            Local         n/a
--More-- or (q)uit
192.168.15.1     D067.E5A5.7FF0     Vl70            Local         n/a

IP Address       MAC Address        Interface       Type      Age
---------------  -----------------  --------------  --------  -----------
192.168.15.10    D067.E5B9.005A     Vl70            Dynamic    0h 14m 39s
192.168.15.12    5C26.0AE1.FC04     Vl70            Dynamic    0h 17m 39s
192.168.15.13    0019.B998.1711     Vl70            Dynamic    0h  0m 41s

The vlans are correct in the router, however, UDT doesn't report the vlans correctly

is there a configuration setting in UDT that determines where it checks for its ARP info?

C:\ProgramData\Solarwinds\Logs\Orion

the logging levels are altered using the 'LogAdjuster'

the ARP settings are the 'L3' UDT settings on the node page:

this is the sort of thing I am seeing in my logfiles:

2014-04-10 10:55:08,163 [ 18] DEBUG   - { UpdateNodeData(): N:91|Layer3 (xxxxx)                   [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor]

2014-04-10 10:55:08,163 [ 18] DEBUG   -   ARP: New: '0' Old: '0' Same: '27'                                               [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor]

2014-04-10 10:55:08,163 [ 18] ERROR   -   Error while processing job '[N:91|Layer3]' (ffac1045-4c42-4ffe-9ab9-6a740b5b92fa)  [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor]

System.InvalidOperationException: The requested operation cannot be completed because the connection has been broken.

   at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransaction(TransactionRequest transactionRequest, String name, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)

   at System.Data.SqlClient.SqlInternalConnection.BeginSqlTransaction(IsolationLevel iso, String transactionName)

   at System.Data.SqlClient.SqlConnection.BeginTransaction(IsolationLevel iso, String transactionName)

   at SolarWinds.UDT.BusinessLayer.DAL.TransactionHelper.ExeInTransactionScope(Int32 deadlockPriority, IsolationLevel isolationLevel, Action`1 method)

   at SolarWinds.UDT.BusinessLayer.DAL.TransactionHelper.ExeInTransactionScope(Action`1 method)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor.UpdateNodeData(UDTNode currNode, UDTArpTable prevArpTable)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor.<>c__DisplayClass8.<UpdateNodeData>b__5(UDTNode node)

   at SolarWinds.UDT.BusinessLayer.Cache.UDTNodeCache.UpdateNode[T](Int32 nodeID, Func`2 handler)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor.UpdateNodeData(UDTJobResult jobResult, UDTSnmpJobResult snmpResults)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor.DoProcessing(UDTJobResult jobResult)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultProcessorBase.Process(UDTJobResult jobResult)

2014-04-10 10:55:08,163 [ 18] ERROR   -   Error while post-processing job '[N:91|Layer3]' (ffac1045-4c42-4ffe-9ab9-6a740b5b92fa)  [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor]

System.InvalidOperationException: The requested operation cannot be completed because the connection has been broken.

   at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransaction(TransactionRequest transactionRequest, String name, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)

   at System.Data.SqlClient.SqlInternalConnection.BeginSqlTransaction(IsolationLevel iso, String transactionName)

   at System.Data.SqlClient.SqlConnection.BeginTransaction(IsolationLevel iso, String transactionName)

   at SolarWinds.UDT.BusinessLayer.DAL.TransactionHelper.ExeInTransactionScope(Int32 deadlockPriority, IsolationLevel isolationLevel, Action`1 method)

   at SolarWinds.UDT.BusinessLayer.DAL.TransactionHelper.ExeInTransactionScope(Action`1 method)

   at SolarWinds.UDT.BusinessLayer.DAL.PollingDAL.UpdateStateOnJobProcessed(UDTJobInfo jobInfo, TimeSpan duration)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultProcessorBase.DoPostProcessing(UDTJobResult jobResult)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultProcessorBase.Process(UDTJobResult jobResult)

2014-04-10 10:55:08,163 [ 18] DEBUG   - } Process() (755ms, [N:91|Layer3],xxxxx)                 [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer3ResultProcessor]

Admittedly this is running 3.0.2, but I upgraded to that version on the advise of support to fix the same bugs in 3.0.1

RichardLetts, many thanks for your suggestions.

I have checked the UDT polling intervals:

my logs were defaulted on Debug

I checked the udt.buisnesslayer.log as you have suggested - wow there is a lot in there ! ! !

this is what I am seeing:

2014-04-10 07:16:55,788 [  3] ERROR   -   Error while processing job '[N:85|Layer2]' (0e235b77-1c1c-4828-806a-1448775d340f)  [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor]

System.InvalidOperationException: The requested operation cannot be completed because the connection has been broken.

   at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransaction(TransactionRequest transactionRequest, String name, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)

   at System.Data.SqlClient.SqlDelegatedTransaction.Initialize()

   at System.Transactions.TransactionStatePSPEOperation.PSPEInitialize(InternalTransaction tx, IPromotableSinglePhaseNotification promotableSinglePhaseNotification)

   at System.Transactions.TransactionStateActive.EnlistPromotableSinglePhase(InternalTransaction tx, IPromotableSinglePhaseNotification promotableSinglePhaseNotification, Transaction atomicTransaction)

   at System.Transactions.Transaction.EnlistPromotableSinglePhase(IPromotableSinglePhaseNotification promotableSinglePhaseNotification)

   at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)

   at System.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)

   at System.Data.SqlClient.SqlInternalConnection.EnlistTransaction(Transaction transaction)

   at System.Data.SqlClient.SqlConnection.EnlistTransaction(Transaction transaction)

   at SolarWinds.UDT.BusinessLayer.DAL.TransactionHelper.ExeInTransactionScope(Int32 deadlockPriority, IsolationLevel isolationLevel, Action`1 method)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.UpdateNodeData(UDTNode currNode, UDTPortCollection prevPorts)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.<>c__DisplayClass7.<UpdateNodeData>b__4(UDTNode cachedNode)

   at SolarWinds.UDT.BusinessLayer.Cache.UDTNodeCache.UpdateNode[T](Int32 nodeID, Func`2 handler)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.UpdateNodeData(UDTNode currNode)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.DoProcessing(UDTJobResult jobResult)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultProcessorBase.Process(UDTJobResult jobResult)

2014-04-10 07:17:00,780 [  3] ERROR   -   Error while processing job '[N:81|Layer2]' (e660ec88-b3af-46c6-a1b5-e83e6b31ebf1)  [SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor]

System.InvalidOperationException: The requested operation cannot be completed because the connection has been broken.

   at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransaction(TransactionRequest transactionRequest, String name, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)

   at System.Data.SqlClient.SqlDelegatedTransaction.Initialize()

   at System.Transactions.TransactionStatePSPEOperation.PSPEInitialize(InternalTransaction tx, IPromotableSinglePhaseNotification promotableSinglePhaseNotification)

   at System.Transactions.TransactionStateActive.EnlistPromotableSinglePhase(InternalTransaction tx, IPromotableSinglePhaseNotification promotableSinglePhaseNotification, Transaction atomicTransaction)

   at System.Transactions.Transaction.EnlistPromotableSinglePhase(IPromotableSinglePhaseNotification promotableSinglePhaseNotification)

   at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)

   at System.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)

   at System.Data.SqlClient.SqlInternalConnection.EnlistTransaction(Transaction transaction)

   at System.Data.SqlClient.SqlConnection.EnlistTransaction(Transaction transaction)

   at SolarWinds.UDT.BusinessLayer.DAL.TransactionHelper.ExeInTransactionScope(Int32 deadlockPriority, IsolationLevel isolationLevel, Action`1 method)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.UpdateNodeData(UDTNode currNode, UDTPortCollection prevPorts)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.<>c__DisplayClass7.<UpdateNodeData>b__4(UDTNode cachedNode)

   at SolarWinds.UDT.BusinessLayer.Cache.UDTNodeCache.UpdateNode[T](Int32 nodeID, Func`2 handler)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.UpdateNodeData(UDTNode currNode)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTLayer2ResultProcessor.DoProcessing(UDTJobResult jobResult)

   at SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultProcessorBase.Process(UDTJobResult jobResult)

2014-04-10 07:35:52,359 [ 53] ERROR   -   Job finished with error [N:17|RemoteEventLog]                                   [SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultManager]

2014-04-10 08:05:51,776 [ 45] ERROR   -   Job finished with error [N:17|RemoteEventLog]                                   [SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultManager]

2014-04-10 08:35:53,584 [ 52] ERROR   -   Job finished with error [N:17|RemoteEventLog]                                   [SolarWinds.UDT.BusinessLayer.Polling.UDTJobResultManager]

Not sure if all this is normal.

My L3 enviroment hasn't changed - one core switch that is my router (L3) and all other switches work at L2

It is not normal, and it means that your UDT is not writing some of the data into the database.

This looks like the same error that I am getting.

UDT doesn't surface critical errors anywhere you can see them, it's only when it stops writing the data into the database and only when starts to look funky do you begin to look in the logs.

Open a support case; you might want to reference case#588173

[I am somewhat glad this is not only me, and as an aside there are two bugs here:

a) the UDT business layer is not re-establishing the database connections when they get broken leading to a thread that will never work.

b) there are deadlocks in the SQLserver stored procedures that case database connections to be broken when the deadlock protection selects a process to be killed

]

If you restart the ModuleEngine then it'll begin processing UDT tasks again until the deadlock kills a thread...

RichardLetts thank your for the reply

I too am also somewhat glad that this isn't happening only with me.

Seems a likely situation with your analysis.

I am not sure exactly how UDT matches info from the L3 device arp tables to MAC addresses found on L2-only devices, but I believe that somewhere UDT keeps its own master database of MAC & IP addresses and displays the relevant info for each node.

Seem like in our case, the UDT database is not updating with the L3 data retrieved from the L3 device

or

UDT isn't doing proper lookups on MAC addresses found on L2 devices to its master database, so it isn't getting L3 data for the MAC's

I have Case #592725 opened for this. Tech Support are currently reviewing my diagnostic files.

Lets see what they uncover

Did the v3.0.2 provide any relief to your situation? even if temporary?

So I was able to clarify with Tech Support, UDT's IP to MAC lookup process.

UDT will reach out to the L3 device [my L3 device DELL PCT8132F] and poll it for it's port information and ARP tables, then add that to the database [UDT Database]. For IPs it's simply a matter of polling the ipNetToMediaTable [on L3 Device, in my case the DELL PCT8132F] and ipNetToPhysicalTable [on DELL PCT8132F] OIDs to gather the arp entries. Once it has that, it drops it in the IP table [UDT IP Table], then correlates the MAC information it got from there [my L3 DELL PCT8132F] against the MAC table [my L2 DELL PCT6248’s] and ties them together.

Essentially as follows: 

1. UDT polls my L3 device for the arp tables
2. stores the IP addresses and MAC addresses in UDT’s database.
3. UDT polls my L2 devices for MAC addresses
4. UDT references the L2 device MAC address to the MAC addresses in the UDT database
5. Matches IP address from UDT database to the MAC address on the L2 device

UDT does in fact keep its own database of MAC and IP addresses.

I hope this helps to explain the way UDT works so we can use it in troubleshooting future issues.

I have referenced your case RichardLetts. Many thanks

Update on this

Tech Support was able to validate that the problem is similar to yours RichardLetts

The issue originates in the UDT database. UDT isn't able to poll the OID that matches the MAC addresses discovered in the L2 devices to the MAC addresses discovered in the L3 device. The OID is present, but the UDT job that does the polling seems to have stalled.

There seems to be a bug in UDT

Coincidentally, I had stopped all the Solarwinds services using the Orion Service Manager in an attempt to resolve another issue that I was having with NCM and the IP addresses started to display soon afterwards. Seems like restarting the services would have restarted the job that is responsible for this polling.

Not sure why a server restart didn't work equivalently, maybe because I had left the services shutdown for about 2 hrs before restarting them ?

The case (592725) is still open as the development team digs deeper.

So far the IP addresses are still displayed, so I would consider this problem solved.