NaN Error in updating AIS Record into MySQL

[albhardy]

Encountered NaN error using GGSimulator to pump NmeaAis data to GGServer.

NmeaAis Simulator Config for GGSimulator

var MyDispatcher =
      { debug   : 9                      // debug 0-9
      , verbose : true                   // provide a copy of outgoing message on console
      , srvmod  : true                   // move to false for client connect mode
      , host    : 'localhost'            // only useful in client connect mode
      , port    : 8800                  // tcp port for client to connect
      , dumpfile: "/tmp/simulator.dump"  // send a copy of outgoing packet to a dumpfile
      };
 // instanciate one or multiple simulators to process one/many gpxfile(s)
 var simu1  = new GGsimulator.Simulator(MyBoat1);  // parse GPX route and compute position
 var  simu2  = new GGsimulator.Simulator(MyBoat2);

var dispatcher  = new GGsimulator.Dispatcher (MyDispatcher); // dispatch message to tcp clients
dispatcher.SetEncoder(GGsimulator.NmeaAisEncoder); // register presentation encoder
dispatcher.SetListener(simu1); // register simulator position/statics events
dispatcher.SetListener(simu2);

MySqlDb-Config for GGServer

 { debug    : 4
        , Telnet   : {info: "Telnet Console"  , adapter: "TelnetConsole" , port: PortBase}
        , Httpd    : {info: "Minimalist HTTPd", adapter: "HttpAjax"      , port:PortBase +80, debug:9}
        , AisTcp2   : {info: "Ais Hub Feed 2"    , adapter: "AisTcpFeed"    , hostname: "mydomain.com"  , remport:8800, timeout:60, mindist:2}      
},

GGServer Console Log

Gateway Start: DummyDemo
-- 4 [no trace] -- "MySQL creating connection [mysql:ggserver@localhost/ggserver
]"
-- 1 [DevAdapter] -- "adapter:telnet//4000"
-1- HttpAjax-adapter.js/DevAdapter:69 [adapter:httpdajax//4080 rootdir=c:\ggserv
erorig\node_modules\www]
-- 1 [DevAdapter] -- "DevAdapter: adapter:aisfeed@scc.boedaya.com:8800"
-- 3 [TcpSvrListenOk] -- "TcpServer [TcpServer://TelnetConsole:4000] listening"
-- 3 [TcpSvrListenOk] -- "TcpServer [HttpServer://HttpAjax:4080] listening"
-- 4 [TcpClientConnect] -- "[TcpClient://AisTcpFeed:8800] connected"
-5- MySqlDb-backend.js/null:54 [MySQL Connect Done [mysql:ggserver@localhost/ggs
erver]]
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:0 mmsi:159847387 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:1 mmsi:123456789 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:2 mmsi:159847387 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:3 mmsi:123456789 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:4 mmsi:159847387 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:5 mmsi:159847387 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:6 mmsi:123456789 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:7 mmsi:159847387 type:18 [not
 logged]"
-6- MySqlDb-backend.js/BackendStorage.LoginDev:245 [Login MySQL device:sockclien
t//TcpAis/remote:50.23.126.218:8800 devid=159847387]
-9- MySqlDb-backend.js/null:253 [sqlQuery {"id":3,"devid":"159847387","devname":
"gpsdemodevice2","callsign":"gps2","model":"gpsmodel2","track":"T_159847387","al
arm":"A_159847387","obd":"O_159847387","date":"2015-02-04T14:03:58.000Z"}]
-6- MySqlDb-backend.js/BackendStorage.UpdateAlarmDev:311 [Updating Alarm MySQL d
evid=159847387]
-0- MySqlDb-backend.js/null:320 [MySql ERROR LookupDev INSERT INTO A_159847387 s
et ? err=Error: ER_BAD_FIELD_ERROR: Unknown column 'NaN' in 'field list']
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:8 mmsi:123456789 type:18 [not
 logged]"
-6- MySqlDb-backend.js/BackendStorage.UpdateAlarmDev:311 [Updating Alarm MySQL d
evid=159847387]
-0- MySqlDb-backend.js/null:320 [MySql ERROR LookupDev INSERT INTO A_159847387 s
et ? err=Error: ER_BAD_FIELD_ERROR: Unknown column 'NaN' in 'field list']
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:9 mmsi:123456789 type:18 [not
 logged]"
-6- MySqlDb-backend.js/BackendStorage.UpdateAlarmDev:311 [Updating Alarm MySQL d
evid=159847387]
-0- MySqlDb-backend.js/null:320 [MySql ERROR LookupDev INSERT INTO A_159847387 s
et ? err=Error: ER_BAD_FIELD_ERROR: Unknown column 'NaN' in 'field list']
-6- MySqlDb-backend.js/BackendStorage.UpdateAlarmDev:311 [Updating Alarm MySQL d
evid=159847387]
-0- MySqlDb-backend.js/null:320 [MySql ERROR LookupDev INSERT INTO A_159847387 s
et ? err=Error: ER_BAD_FIELD_ERROR: Unknown column 'NaN' in 'field list']

It may be caused by following code:

AisTcpFeed-adapter.js line 117

data.cmd= TrackerCmd.GetFrom.TRACKER; should be data.cmd=TrackerCmd.GetFrom.TRACK;

and _TcpClient.js line 171 may need to add data.valid = "";

 case TrackerCmd.GetFrom.TRACK:

            var update = true; // default is do the update

            // compute distance only update backend is distance is greater than xxxm
            if (this.stamp !== undefined) {
                var moved =  parseInt (this.Distance (this.stamp, data));

                // compute elapse time since last update
                var elapse  = parseInt ((data.date.getTime() - this.stamp.date.getTime()) / 1000); // in seconds
                var speedms = parseInt (moved/elapse);         // NEED TO BE KNOWN: with short tic speed is quicky overestimated by 100% !!!

                // usefull human readable info for control console
                data.moved   = moved;
                data.elapse  = elapse;
                data.valid = "";
               // if moved less than mindist or faster than maxspeed check maxtime value
                if (moved < this.controller.svcopts.mindist || speedms > this.controller.svcopts.maxspeed) {
                    this.Debug(2,"%s Dev %s Data ignored moved %dm<%dm ?", this.count, this.devid, moved, this.controller.svcopts.mindist);
                    // should we force a DB update because maxtime ?
                    if (elapse <  this.controller.svcopts.maxtime) update = false;
                }
             } else {
                data.moved  = 0;
                data.elapse = 0;
                data.valid = "";
           }

[fulup-bzh]

I'm not sure what's happening here. Your AIS packet is view as an alarm packet. This should never happen !!!

The data.valid=''" you add does not hurt, but it should not solve the issue.

The call must be originated from _TcpClient line 167 the question is how your data.cmd may have a value different from TrackerCmd.GetFrom.LOGIN or TrackerCmd.GetFrom.TRACKER as it is the two only value set into AisTcpFeed.

Nevertheless one thing is WRONG in lib/TcpClient at line:164. Case value should be "SPEEDON" and not "SPEED_ON". Because of the '' the value is undefined. Under Linux the error does not hurt but we may have a different comportment on Windows.

CONCLUSION: Could you remove the "_" and write ""SPEEDON", hopefully this is the issue. If it still fails place a breakpoint in _TcpClient:164 and check for "data" value. If you do not know how to operate "nodejs" source debugger, then place console.log before the call to UpdateAlarmDev.

Thank you for your support in debuging my code on Windows. I did not expect to many side effect when moving node.js from Linux to M$.

[albhardy]

Just fixing SPEEDON still gives following error

c:\ggserverorig2\node_modules\ggserver>node bin/GeoGateServer.js --debug=9 --con
fig=OrigMySqlDb
Adapter: AisTcpFeed Registered file=c:\ggserverorig2\node_modules\ggserver\lib/.
./adapters/AisTcpFeed-adapter.js
Adapter: Gps103Tk102 Registered file=c:\ggserverorig2\node_modules\ggserver\lib/
../adapters/Gps103Tk102-adapter.js
Adapter: GtcGprmcDroid Registered file=c:\ggserverorig2\node_modules\ggserver\li
b/../adapters/GtcGprmcDroid-adapter.js
Adapter: HttpAjax Registered file=c:\ggserverorig2\node_modules\ggserver\lib/../
adapters/HttpAjax-adapter.js
Adapter: NmeaTcpFeed Registered file=c:\ggserverorig2\node_modules\ggserver\lib/
../adapters/NmeaTcpFeed-adapter.js
Adapter: TelnetConsole Registered file=c:\ggserverorig2\node_modules\ggserver\li
b/../adapters/TelnetConsole-adapter.js
Adapter: WebSockTraffic Registered file=c:\ggserverorig2\node_modules\ggserver\l
ib/../adapters/WebSockTraffic-adapter.js
Backend: Dummy Registered file: c:\ggserverorig2\node_modules\ggserver\lib/../ba
ckends/Dummy-backend.js
Backend: MongoDB Registered file: c:\ggserverorig2\node_modules\ggserver\lib/../
backends/MongoDB-backend.js
Backend: MySqlDb Registered file: c:\ggserverorig2\node_modules\ggserver\lib/../
backends/MySqlDb-backend.js
Config: DummyBackend Registered file: c:\ggserverorig2\node_modules\ggserver\lib
/../config/DummyBackend-config.js
Config: MongoDb Registered file: c:\ggserverorig2\node_modules\ggserver\lib/../c
onfig/MongoDb-config.js
Config: MySqlDb Registered file: c:\ggserverorig2\node_modules\ggserver\lib/../c
onfig/MySqlDb-config.js
Config: OrigMySqlDb Registered file: c:\ggserverorig2\node_modules\ggserver\lib/
../config/OrigMySqlDb-config.js

Gateway Start: DummyDemo
-- 4 [no trace] -- "MySQL creating connection [mysql:ggserver@localhost/ggserver
]"
-- 1 [DevAdapter] -- "adapter:telnet//4000"
-1- HttpAjax-adapter.js/DevAdapter:69 [adapter:httpdajax//4080 rootdir=c:\ggserv
erorig2\node_modules\www]
-- 1 [DevAdapter] -- "DevAdapter: adapter:aisfeed@scc.boedaya.com:8800"
-- 3 [TcpSvrListenOk] -- "TcpServer [TcpServer://TelnetConsole:4000] listening"
-- 3 [TcpSvrListenOk] -- "TcpServer [HttpServer://HttpAjax:4080] listening"
-- 4 [TcpClientConnect] -- "[TcpClient://AisTcpFeed:8800] connected"
-5- MySqlDb-backend.js/null:54 [MySQL Connect Done [mysql:ggserver@localhost/ggs
erver]]
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:0 mmsi:159847387 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:1 mmsi:123456789 type:18 [not
 logged]"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:2 mmsi:159847387 type:18 [not
 logged]"
### TcpClient.prototype.ProcessData - data:
{ devid: 159847387,
  cmd: 1,
  name: undefined,
  model: undefined,
  call: undefined }
-6- MySqlDb-backend.js/BackendStorage.LoginDev:245 [Login MySQL device:sockclien
t//TcpAis/remote:50.23.126.218:8800 devid=159847387]
-9- MySqlDb-backend.js/null:253 [sqlQuery {"id":3,"devid":"159847387","devname":
"gpsdemodevice2","callsign":"gps2","model":"gpsmodel2","track":"T_159847387","al
arm":"A_159847387","obd":"O_159847387","date":"2015-02-04T14:03:58.000Z"}]
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:3 mmsi:123456789 type:18 [not
 logged]"
### TcpClient.prototype.ProcessData - data:
{ devid: 159847387,
  lat: 1.38972,
  lon: 103.85779333333333,
  sog: 51.986944444444454,
  cog: 176.20000000000002,
  alt: 0,
  date: Thu Feb 05 2015 09:38:29 GMT-0600 (Central Standard Time),
  cmd: undefined,
  count: 6 }
-- 2 [TcpClient.ProcessData] -- "Notice: [sockclient//TcpAis/remote:50.23.126.21
8:8800] Unknown command=[undefined] Ignored"
### TcpClient.prototype.ProcessData - data:
{ devid: 159847387,
  lat: 1.3896066666666667,
  lon: 103.8578,
  sog: 65.88444444444445,
  cog: 177.8,
  alt: 0,
  date: Thu Feb 05 2015 09:38:32 GMT-0600 (Central Standard Time),
  cmd: undefined,
  count: 7 }
-- 2 [TcpClient.ProcessData] -- "Notice: [sockclient//TcpAis/remote:50.23.126.21
8:8800] Unknown command=[undefined] Ignored"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:4 mmsi:123456789 type:18 [not
 logged]"
### TcpClient.prototype.ProcessData - data:
{ devid: 159847387,
  lat: 1.3893816666666667,
  lon: 103.85781166666666,
  sog: 55.075277777777785,
  cog: 174.60000000000002,
  alt: 0,
  date: Thu Feb 05 2015 09:38:34 GMT-0600 (Central Standard Time),
  cmd: undefined,
  count: 9 }
-- 2 [TcpClient.ProcessData] -- "Notice: [sockclient//TcpAis/remote:50.23.126.21
8:8800] Unknown command=[undefined] Ignored"
### TcpClient.prototype.ProcessData - data:
{ devid: 159847387,
  lat: 1.3891566666666666,
  lon: 103.85782333333333,
  sog: 70.00222222222223,
  cog: 176.70000000000002,
  alt: 0,
  date: Thu Feb 05 2015 09:38:36 GMT-0600 (Central Standard Time),
  cmd: undefined,
  count: 10 }
-- 2 [TcpClient.ProcessData] -- "Notice: [sockclient//TcpAis/remote:50.23.126.21
8:8800] Unknown command=[undefined] Ignored"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:5 mmsi:123456789 type:18 [not
 logged]"
### TcpClient.prototype.ProcessData - data:
{ devid: 159847387,
  lat: 1.38893,
  lon: 103.85783666666667,
  sog: 49.41333333333334,
  cog: 175.4,
  alt: 0,
  date: Thu Feb 05 2015 09:38:38 GMT-0600 (Central Standard Time),
  cmd: undefined,
  count: 12 }
-- 2 [TcpClient.ProcessData] -- "Notice: [sockclient//TcpAis/remote:50.23.126.21
8:8800] Unknown command=[undefined] Ignored"
-- 3 [DevAdapter.ParseLine] -- "Ignoring AIS count:6 mmsi:123456789 type:18 [not
 logged]"
^C

I noticed that you use TRACK : 2 in _TrackerCmd.js not TRACKER thus I suspect typo in AisTcpFeed-adapter is the problem. Also I read trying to insert NaN as values will trigger MySQL errors [https://www.npmjs.com/package/mysql] thus some null/empty value initialization seems required.
Thought a quick screencast may illustrate this better:
http://screencast-o-matic.com/watch/conhDeegi9

[fulup-bzh]

As you can see in the debug you have "cmd: undefined" and this should be the error. As command is invalid _TcpClient select the wrong backend option, witch lead to impossible error.

Replacing TRACKER by TRACK should fix this.

[albhardy]

Yup, it solves the issue. Will close it :)

[fulup-bzh]

Thank you for helping finding this error, that was a real breakdown in the AIS code.