December 16, 2009
The first post in this series introduced Wireshark, demonstrated some of the problems that may be detected with the tool, demonstrated what happens with various fetch array sizes in the presence of configuration problems, and compared a low latency 100Mb connection with a higher latency wireless 802.11G (54Mb) connection from the same client computer during a transfer of database table data.
The connection attempt shown in the screen capture from the previous post was of the computer connecting through the wireless connection to a server during the launch of an ERP package. That connection attempt was slowed a bit by the network latency. That screen shot is shown below.
Why introduce the same screen shot again? Let’s look at what happens sometimes when application versions are upgraded and in the process (sometimes undocumented) features are added to applications. Take, for instance, this ERP program’s connection attempt that required at least 10 seconds to complete on a gigabit connection, when it is able to complete in less than a second on the much slower wireless connection. What changed? Taking a look at a couple of the screen shots of the slow connection attempt will help (the client computer is .185, the database server is .45, and the file server is .40):
In the above we see the client computer searching the file server for a file named DNSAPI.dll that did not exist. Then we see a DNS lookup attempt for a device named TNS.k-mm.com (for those following along, this was caused by the TNS: keyword on the remotedbname= entry in the SQL.INI file). Notice that the timestamp of the request is at 17:25:14.683144. When the client is told by the DNS server for the second time that the name does not exist, the timestamp has advanced to 17:25:14.686069. Next, the client tried to resolve the name TNS first by a direct WINS (NBNS) lookup and then by a WINS broadcast. The timestamp of the next client activity after the WINS lookup is 17:25:16.967553, so roughly 2.3 seconds were wasted. But, that is not the most significant lost time interval.
The above shows the actual connection starting at 17:25:16.988701 and completing at 17:25:17.001425, which is very quick, but are we done yet?
The above screen shot shows the client looking for a file named nethasp.ini on the file server, but is not able to find that file. Important?
The above shows that the client finally gave up looking for the nethasp.ini file at 17:25:17:209969, and at 17:25:17:232671 started sending a series of four full broadcast packets, spaced roughly one second apart, to a destination port number that Wireshark has aliased as tcpnethaspsrv. The client finally started communicating again with the database server at 17:25:21.344038. So, between 17:25:14.686069 and 17:25:21.344038 the client mostly just sat idle waiting for a response that never came. Yes, Wireshark ultimately identified the cause of the problem and helped find a course of action that was fully in place at 05:30:00 the next morning, with the new version of the ERP program starting in less than a second just like the old version.
Notice that the raw packet data appears at the bottom and is expanded into human readable text in the upper pane. Clicking a line in the upper pane (for instance one that shows the destination MAC address) shows that information in the raw packet data at the bottom of the window.