Data lost when using add a feature

Question

GeoEventers,

A colleague and I are seeing behavior where messages seem to be getting "dropped" when using the "Add a feature" output.  Whether or not this is what's really going on is unknown, as we don't know the specific location of the "droppage" (GEP not sending all data to AGS? AGS not committing all data sent to it? SQL Server?, etc).  We do not see any errors in either GEP's logs or ArcGIS Server's logs.  Here are details:

We're using a TCP/text input to receive csv data.  The geometry in the messages is POLYGON data in json format.  We have one geoevent service with this input that flows through a filter to only allow one message type through, then outputs to a feature service.  We have another service that's identical, but has a processor after the filter, before the output.  The feature service is on an ArcGIS Server instance on the same machine, and is pointing to a feature layer hosted in SQL Server 2008 R2 (64-bit) on a different machine.  The layer is POLYGON, not point - very important to note this (as I suspect 99.99% of GEP instances are working with points).

We are using the simulator packaged with GEP to send the same record to GEP over and over, just to test throughput.  The message definition is pretty ordinary - about 20 fields or so, all string except for a date and geometry field.  One of the string fields is tagged with TrackID, the date field is tagged with TIME_END and TIME_START, and the geometry field as GEOMETRY.

For each test, we truncated the SQL Server table, reset statistics in GEP Manager's Monitor page, and started the simulator(s).  In the table below, I list how many simulators were used, and at what rate messages were sent ("Simulator Settings"), the data flow ("GEP Settings"), how many features Monitor displayed as processed ("GEP Monitor"), number of records written to the database after the simulators were stopped ("DB Records") and the number of messages not successfully written to the database table ("LOSS"... the difference between GEP Monitor and DB Records).  Incidentally, Monitor reported the same number of messages processed for the TCP Input, the GE Service, and the feature service output.  So the number in the column for "GEP Monitor" is the same for input count, service in/out, and output count as displayed in Monitor.

Here are the specs and results on each test:
Simulator SettingsGEP SettingsGEP MonitorDB recordsLOSS2 simulators, 5 msgs/sectcp->filter->processor->fs output 1 sec insert2070 features206552 simulators, 5 msgs/sectcp->filter->processor->fs output 1 sec insert2690 features2678122 simulators, 5 msgs/sectcp->filter->processor->fs output 1 sec insert3395338692 simulators, 5 msgs/sectcp->filter->processor->fs output 3 sec insert2125212322 simulators, 5 msgs/sectcp->filter->processor->fs output 3 sec insert2655265142 simulators, 5 msgs/sectcp->filter->processor->fs output 3 sec insert3475346962 simulators, 5 msgs/sectcp->filter->processor->fs output 6 sec insert2045204052 simulators, 25 msgs/sectcp->filter->fs output 6 sec insert2225222052 simulators, 5 msgs/sectcp->filter->fs output 6 sec insert2690268822 simulators, 25 msgs/sectcp->filter->fs output 12 sec insert22502235152 simulators, 25 msgs/sectcp->filter->fs output 12 sec insert2425241962 simulators, 25 msgs/sectcp->filter->fs output 3 sec insert2300229371 sumulator, 25 msgs/sectcp->filter->fs output 1 sec insert2075206510

Based on these numbers, there's no real pattern easily noticeable.  One might deduce that a 3 to 6 second feature service output update may be the best but a) we really can't definitively say this but more importantly, b) we're still losing records in these scenarios.  As far as just GEP is concerned, based on what Monitor is reporting, GEP has received, processed, and output everything just fine.

So...

Is there a definitive way to confirm GEP is successfully receiving/processing/outputting everything, other than what Monitor is reporting?  
Or is Monitor a very trustworthy tool for determining that GEP has received/processed/output everything sent to it?  
What ways exist to track down where the message "dropping" is occurring (especially given there are no errors in GEP or AGS logs)? 
Is it possible that GEP is successfully passing on everything, but ArcGIS Server is not successfully writing all records?
Could this be a SQL Server thing?
What other places in the entire cosmos of this data flow (not just within GEP) are potential suspects?
Is there any flaw in our methodology that could explain the discrepancy between what GEP reports and what's written to the DB?

JordanGottlieb · Answer

RJ, thank you for the prompt and thorough response, much appreciated!

Bumping Mark Bramer's post was the result of finally getting stuck on a somewhat involved GEP performance and tuning experiment. I've been hammering on the GEP in order to discover and improve the maximum workloads achievable via configuration using our sandbox hardware. After trying dozens of configuration and simulation rate combinations, I have yet to discover one that doesn't vanish expected output into the ether after 50 or more simulated events per second.

Some of the configuration setting variables I've been experimenting with are a feature service's number of instances, service timeouts and process isolation settings, and varying the number of feature services being used to simulate new events as well as the number of Geo Fences my GEP Services have to consider. Before each sample-gathering test run, the relevant feature service DB tables have been truncated, the GEP Manager Services Monitor stats have been reset and the relevant GEP Services, inputs and outputs have been restarted.
How many events per second is the GeoEvent Simulator you are using sending to GeoEvent Processor?

I've executed each test configuration at 1, 5, 10, 25, 50, 100 and 200 simulated events per second for a duration of 5 minutes at each rate while measuring system resources, throughput and various logs. At each rate, all configuration tests were repeated with events being published to a single feature service with no filtering or processing:

TCP -> FS1

...and with the events evenly spread out over multiple feature services:

TCP -> FS1, FS2, FS3, FS4, FS5

In the latter case one simulated event to the TCP input would be output to five feature services, so I'd simulate 20 events per second to get 100 total events per second.

As mentioned, expected output is lost very consistently at or above a rate of 50/sec, and somewhat consistently at or above ~25/sec.
Are you using the Update a Feature or the Add a feature outbound connector to update the feature service?

Add a feature only.
Updating features can be expensive if the target feature service contains many thousands of features.

Either way, the data sources for the feature services have been truncated prior to each test run, though some of my tests have generated tens of thousands of rows... actually one generated 600K... had to restart the ArcGIS server after that one. =]
There are a couple of things you might try to help narrow the scope of the problem:*  Reduce the number of events being sent to see if the problem is with data rate.

With the best configuration I've found, 10/10 5-minute runs at 20 events/sec to a single feature service ran without dropping expected output.*  Switch to use the Add a feature outbound connector to see the problem is with adding records vs. updating records.

That's all we've been using.*  Specify a smaller number (50, 10, or even 1) for the outbound connector's Maximum Features Per Transaction parameter to see if updating the feature service with smaller batches helps.

I'll try that, the default of 500 may be overwhelming the FS... Good one!*  Check to make sure that there are no errors with the event data, such as a string which exceeds the maximum length allowed by the feature service or an integer value being sent which exceeds the range of the feature service's target field.

The event data consists of 100 duplicates of a few valid, tested events, differing only by time stamp.
You might also use the GeoEvent Processor's log to see how many milliseconds (or seconds) elaspse between GeoEvent Processor's POST to retrieve information and its POST to update the features. If there are any errors in these transactions, you might also find them in the log.

I've been monitoring the Server and GEP logs but not with your deeper logger setting... I'll try a few more test runs with your logger setting.
Hope this information is helpful -RJ

Sure is, thanks! ~Jordan

RJSunderman · Answer

Hello Jordan -

How many events per second is the GeoEvent Simulator you are using sending to GeoEvent Processor? Are you using the Update a Feature or the Add a feature outbound connector to update the feature service?

Updating features can be expensive if the target feature service contains many thousands of features. This is because GeoEvent Processor must identify the feature to be updated by performing a full table scan querying for the feature's unique identifier to obtain the ObjectID of the table row before it can POST the update.

There are a couple of things you might try to help narrow the scope of the problem:*  Reduce the number of events being sent to see if the problem is with data rate.
*  Switch to use the Add a feature outbound connector to see the problem is with adding records vs. updating records.
*  Specify a smaller number (50, 10, or even 1) for the outbound connector's Maximum Features Per Transaction parameter to see if updating the feature service with smaller batches helps.
*  Check to make sure that there are no errors with the event data, such as a string which exceeds the maximum length allowed by the feature service or an integer value being sent which exceeds the range of the feature service's target field.

You might also use the GeoEvent Processor's log to see how many milliseconds (or seconds) elaspse between GeoEvent Processor's POST to retrieve information and its POST to update the features. If there are any errors in these transactions, you might also find them in the log.

First, from GEP Manager, navigate to the Logs page and click �??Settings�??. Select 'Debug' and enter the following logger item to debug: com.esri.ges.transport.featureService.FeatureServiceOutboundTransport. Don�??t forget to set this logger item back to ERROR, especially if you have thousands of events being sent to GeoEvent Processor. The logging statements generated at this level have the potential to produce log files which are quite large.

If you edit the C:\Program Files\ArcGIS\Server\GeoEventProcessor\etc\org.ops4j.pax.logging.cfg configuration file you will see this logging setting persisted. If you have trouble using the GeoEvent Processor's Logging utility, you can always edit the configuration file directly (as an admin, since its under Program Files) to reset the logging level. Also, you might find it easier to view the log in a text editor. Look for the log file in the C:\Program Files\ArcGIS\Server\GeoEventProcessor\data\log folder.

When reviewing the logs, you are looking for lines with the following logger entry:  com.esri.ges.framework.transport.featureservice-transport. Key phrases you will be looking for include:*  querying for missing track id 
*  Posting to url 
*  Response was

At the debug level you should get a copy of exactly what is being sent/posted to the server. The query to get the object identifiers, for example, will look something like:   Posting to url : http:// �?� FeatureServer/0/query with parameters ... FlightNumber IN ('SWA1568','SWA510' �?�

You should be able to see the JSON being sent to Server by each GEP transaction. You may need to copy/paste it into something like http://jsonlint.com/ to format it so you can read it. You can look at the timestamps on each log entry to get a feel for how long the different transactions with Server are taking.

The illustration below is an example of what you want to dee in the logfile. Notice the latency in the last two DEBUG statements is about 325 milliseconds. If GeoEvent Processor is being fed a large number of events every second, it may be that transactions are taking to long and Server simply cannot keep up with the data being fed to it from GeoEvent Processor.

[ATTACH=CONFIG]33629[/ATTACH]

Hope this information is helpful -
RJ

UpdateFeatureService - KarafLog.png

JordanGottlieb · Answer

I'm having the same issue with data generated by the simulator being 'lost' in transport, TCP in -> Feature Service out.