Debugging Client Connections

This article demonstrates detailed debugging of an NTRIP Client Connections using SNIP’s filter controls to reduced the console log to meaningful content.

Background

One of the most common issues for a Caster operator is assisting your user community to get connected.  Users have many issues, but here we will consider how the filter can be used to determine why a client connection is not being achieved.  We will not consider other common issues like not being able find your caster in the first place (internet connectivity), bad software and misconfiguration settings elsewhere in the overall flow of data (often NTRIP client issues), or what the user may do or fail to do with the data once they have it.

We approach these examples with both an OPEN caster (where any party may log on and obtain data) and a CLOSED one (where a client account is required to log on). SNIP can be operated in either mode.  Instructions on how to manage your users, add users, and control if you Caster is open or closed can be found here.

Presumptions

We presume the reader is familiar with basic SNIP caster operations, in particular the ability to manage users, and the Caster and Clients Tab display where the Display New User Connection Details check-box is found.

We also presume you have created a user account.  In this example there is a fake user called “User1” with a password of “none”  – of course you should not use these values in your own machine.  Recall that these, like a mountPt, are case sensitive values!  In this example we use a caster called “SCSC”  (all capital letters) for the connections.

How to Filter it.

Whenever a new NTRIP Client connects to SNIP, it sends a simple request message with the mountPt it is seeking.  If this mountPt is part of the caster’s holding (unless it is hidden it will appear in the caster table) and IF the user is allowed to connect to it (typically because they have a suitable account).  When all is well, this is a routine event and all you will see in the console log are lines like:

[SCSC]:  Client #C01 from 69.75.31.227:59455 connected to SCSC at 2016/05/16 10:29:23 AM (local)

This lists the mountPt (SCSC), the client id (a rolling number), the source IP and port of the connection.  When the client eventually disconnects, a similar log entry showing the data served is created:

[SCSC]:  Client #C01 Disconnected from SCSC , 89 Bytes in, 91.02 KB out, connected: 04:40.490 minutes

Before continuing, consider the above console entries for moment.  Note that the default log shows the data stream, not the client slot (or the local log time).  When debugging client connections it is often helpful to display the slot ID assigned to the client as well, as this allows you to see if the client has started multiple connection dialogs.  The revised display (below) shows that this was connection “C01” and represents the lifetime of a single exchange between your caster and that client.

[C01]:[SCSC]:  Client #C01 from 69.75.31.227:59455 connected to SCSC at 2016/05/16 10:29:23 AM (local)
[C01]:[SCSC]:  Client #C01 Disconnected from SCSC , 89 Bytes in, 91.02 KB out, connected: 04:40.490 minutes

But it is likely that this is cluttered up with other interspersed log entries.   You remove these by using the console filter.  In this case, use the types control to disable displaying any type EXCEPT for the type Client Details.  You will now see only the client connections, but will see these for EVERY client. Use the data stream control to first remove all data streams, and then to enable only the SCSC stream (the stream the user is attempting to connect to).  With these settings you will see a very terse log showing only client attempts to connect to the selected mountPt.

How to see Connection Details

Hint: When an individual NTRIP Client is having connection issues, always check the Display New User Connection.  Your first action should then be to check to see what they are sending to your Caster. If you do not see the client, it is likely they are unable to find you on the internet. Use tools like PING to confirm connectivity.

The above demonstrated how to reduce the console display to see only the connection process of interest.  But often additional data is needed to debug problems.  That is the primary purpose of the Display New User Connection Details check box found on the Caster and Clients Tab.  Enable it now, and have the NTRIP Client attempt the connection again.    Be sure the Log Threshold is also set to “Minor (Show All)” as well.   These settings will enable you to see the protocol from the NTRIP Client and easily spot common errors.

Hint:  If you just restarted a SNIP Caster to try this, it is also likely these settings will produce no actual displayed entries at start up.  SNIP provides a simple nag screen warning if this occurs, but once any entries are present they will be displayed.

A typical successful connection exchange with all these details shown looks like this:

[C01]:[C01]:  Client [#C01] appears to an NTRIP Client connecting with:
[C01]:[C01]:  An NTRIP Client sent: ======================
[C01][C01]:
GET /SCSC HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Authorization: Basic VXNlcjpub25l
[C01]:[C01]:     ======================
[C01]:[SCSC]:  Mount Pt [ SCSC ] is a match – allow connection.
[C01]:[SCSC]:  Client #C01 from 69.75.31.227:61825 connected to SCSC at 2016/05/16 11:12:27 AM (local)

In the above you can see that a real mountPt was selected “GET /SCSC” for use.  You can also see the author used an NTRIP client from RTKLIB to make the connection.  And you can see the base64 encoded Authorization string “VXNlcjpub25l” holding the user name and password.  Note that many clients will send authorization credentials in this form regardless of whether the caster is open or closed.

This is a typical working example.  Now let’s consider when things do not work as desired.  We will use the same filter setting for these examples.  In these examples we have removed the console highlights to give emphasis to the key error details. The error is in bold and the key reply is underlined with some use of bold.

A Client with a bad mountPt

Repeating the connection, but adding “xxx” to the mountPt (creating a mountPt that does not exist) produces:

[C03]:[C03]: Client [#C03] appears to an NTRIP Client connecting with:
[C03]:[C03]: An NTRIP Client sent: ======================
[C03][C03]:
GET /SCSCxxx HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Authorization: Basic VXNlcjpub25l
[C03]:[C03]: ======================
[C03]:[SCSCxxx]: No matching mount point, requested: [SCSCxxx], sending caster table and disconnecting.
[C03]:[SCSCxxx]: Client #C03 Disconnected (tried to mount SCSCxxx, but not in table), 92 Bytes in, 0 Bytes out, connected: 007 mSec

Note the highlighted lines showing the error (bold) and then the reply (underlined).  Note how the requested false mountPt is also used in the log classification system [SCSCxxx].

A Client with a bad Capitalization

Repeating the connection, but changing “SCSC” to be “SCsc” results in a failure because all mountPt are case sensitive.  But we can at least detect and warn of such an event.

[C04]:[C04]: Client [#C04] appears to an NTRIP Client connecting with:
[C04]:[C04]: An NTRIP Client sent: ======================
[C04][C04]:
GET /SCsc HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Authorization: Basic VXNlcjpub25l
[C04]:[C04]: ======================
[C04]:[SCsc]: No matching mount point, requested: [SCsc], sending caster table and disconnecting.
[C04]:[SCsc]: Note: The mountPt requested: [SCsc], almost matches an entry but differs in capitalization.
[C04]:[SCsc]: Client #C04 Disconnected (tried to mount SCsc, but not in table), 89 Bytes in, 0 Bytes out, connected: 011 mSec

A Client with no mountPt

The basic NTRIP protocol is to reply with the caster table when a bad mountPt or when nothing is requested. A request for nothing simply indicates that the other party wants your current caster table.

[C13]:[C13]: Client [#C13] appears to an NTRIP Client connecting with:
[C13]:[C13]: An NTRIP Client sent: ======================
[C13][C13]:
GET / HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Accept: */*
Connection: close
[C13]:[C13]: ======================
[C13]:[C13]: No mount point requested, sending caster table and disconnecting.
[C13]:[C13]: Client #C13 Disconnected (NO mountPt was provided), 82 Bytes in, 0 Bytes out, connected: 010 mSec

Modern browsers will also try and request a favorite icon these days.  All of these sorts of requests result in the current table being returned.  As a further note, any device that pings your Caster for a base page will look much like this or like the above request.  If there is in fact no mountPt present, the report will note this and suggest it could have been a ping.

[C08]:[C08]: Client [#C08] appears to an NTRIP Client connecting with:
[C08]:[C08]: An NTRIP Client sent: ======================
[C08][C08]:
GET /favicon.ico HTTP/1.1
Host: 69.75.31.227:2101
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:39.0) Gecko/20100101 Firefox/39.0
Accept: image/png,image/*;q=0.8,*/*;q=0.5
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
[C08]:[C08]: ======================
[C08]:[favicon.ico]: No matching mount point, requested: [favicon.ico], sending caster table and disconnecting.
[C08]:[favicon.ico]: Client #C08 Disconnected (tried to mount favicon.ico, but not in table), 280 Bytes in, 0 Bytes out, connected: 018 mSec

A Client with a bad user account

Here is an example where the NTRIP Client has presented NO user data to a closed caster.  This will not work when the Caster is closed. You can tell that there is no user/password present due to the absence of the lines marked “Authorization: Basic” in the request.  Note also the ping detection logic.

[C03]: Client [#C03] appears to an NTRIP Client connecting with:
[C03]: An NTRIP Client sent: ======================
[C03]:
GET /SCSC HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Accept: */*
Connection: close
[C03]: ======================
[SCSC]: Mount Pt [ SCSC ] is a match – allow connection IF credentials match a user entry.
[SCSC]: No credentials were extracted from request
[SCSC]: Client #C03 Disconnected from Empty (was this a ping?), 86 Bytes in, 0 Bytes out, connected: 009 mSec

Here is the same request but using an incorrect user/password set.  Note that a decode of the presented user credentials is provided in an analysis string to assist you. The analysis will detect various possible error combinations including incorrect user&password sets and the correct user with an incorrect password.  You can change the user’s password in the Registered Users dialog if there is a need to do so.

[C05]:[C05]: Client [#C05] appears to an NTRIP Client connecting with:
[C05]:[C05]: An NTRIP Client sent: ======================
[C05][C05]:
GET /SCSC HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Authorization: Basic RmFrZVVzZXI6QmFkUGFzc3dvcmQ=
[C05]:[C05]: ======================
[C05]:[SCSC]: Mount Pt [ SCSC ] is a match – allow connection IF credentials match a user entry.
[C05]:[SCSC]: Credentials for user did not match an entry, details follow:
[C05]:[SCSC]:
Analysis of User: FakeUser and PW: ****** is:
The user: FakeUser is NOT a Valid Entry in the tables (unknown user)
[C05]:[SCSC]: Client #C05 Disconnected from Empty (was this a ping?), 105 Bytes in, 0 Bytes out, connected: 016 mSec

Finally, here is the same request but, using a correct user/password set, the connection is simply made.

[C04]: Client [#C04] appears to an NTRIP Client connecting with:
[C04]: An NTRIP Client sent: ======================
[C04]:
GET /SCSC HTTP/1.0
User-Agent: NTRIP RTKLIB/2.4.2
Authorization: Basic VXNlcjE6bm9uZQ==
[C04]: ======================
[SCSC]: Mount Pt [ SCSC ] is a match – allow connection IF credentials match a user entry.
[SCSC]: Client #C04 from 69.75.31.227:50975 connected to SCSC at 2016/05/16 12:51:57 PM (local)

A Client with too many connections

SNIP allows limiting the number of simultaneous connections which each account can have.  It is often easier to allow a user to have ten such connections than to create ten separate user accounts.  We recommend that you allow your users 5 connections as a minimum to avoid this problem.  Reasons for needing more than one account vary, but often small survey teams in the field are best supported in this way.    When an account has reached its allowed limit, the reply from SNIP is as follows:

[C12]:[SCSC]: Mount Pt [ SCSC] is a match – allow connection IF credentials match a user entry.
[C12]:[SCSC]: Credentials for user did not match an entry, details follow:
[C12]:[SCSC]:
Analysis of User: User1 and PW: ****** is:
The user: User1 is a valid entry in the tables
The password: ****** is the valid for this user
This account currently has 2 connections, and is allowed as many as 2
This account is currently using all its allowed connections
[C12]:[SCSC]: Client #C12 Disconnected from Empty (was this a ping?), 97 Bytes in, 0 Bytes out, connected: 025 mSec

This article has served to provide a practical example of using the filter controls as well as showing how to resolve several common client connection issues.  When done filtering for such a debugging need, be sure to resend the log filter so that other more general log events will again be seen.  The “Reset All Log Filters” menu item is useful for this.

Related Articles