The following examples show how to interpret the Spatial Server log files that have full logging (level "4"). For information on changing the logging level, see Enabling full verbose logging. The examples below are all based on the "log" format. For information on other log formats, see aimsserver.cfg reference for logging settings.

All log files start with some initialization information. This information includes the ArcIMS version number, platform information, and the log mode.

[Jan 15, 2006 1:59:42 PM][3032 2216 INFO1] Begin Request [Jan 15, 2006 1:59:42 PM][1804 1352 INIT] ESRI ArcIMS Version 9.2.0 Build 401 [Jan 15, 2006 1:59:42 PM][1804 1352 INIT] Platform: Windows Server 2003, build 3790, Intel [Jan 15, 2006 1:59:42 PM][1804 1352 INIT] Log mode: all

• Image Server log file - requests
• ArcMap Image Server log file - requests
• Query and Feature Server log files - requests
• Extract Server log file - requests
• Geocode Server log file - requests
• Image, Query, Feature, Extract, and Geocode Server log files - adding a service
• ArcMap Image Server log file - adding a service

Image Server log file - requests

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 1:59:42 PM][3032 2216 INFO1] Begin Request

The request received from the ArcIMS Application Server.

[Jan 15, 2006 1:59:42 PM][3032 2216 INFO3] REQUEST: <GET_IMAGE> <PROPERTIES> <ENVELOPE minx="-180" miny="-90" maxx="180" maxy="90" /> <IMAGESIZE width="800" height="600"/> </PROPERTIES>

Request type (GET_IMAGE or GET_RASTER_INFO) and the name of the service (canada).

[Jan 15, 2006 1:59:42 PM][3032 2216 INFO1] GET_IMAGE: canada

Time needed to parse the request in seconds.

[Jan 15, 2006 1:59:42 PM][3032 2216 STAT2] AXL Parse Time: 0.000001s

Time needed to allocate space for drawing the image.

[Jan 15, 2006 1:59:42 PM][3032 2216 STAT2] RENDERER SETUP: 0.000000s

Name of the layer being processed.

[Jan 15, 2006 1:59:42 PM][3032 2216 INFO2] FEATURE LAYER: provinces (id=0)

Time to create and send a query to the data source.

[Jan 15, 2006 1:59:42 PM][3032 2216 STAT2] DATA SEARCH TIME: 0.016000s

Number of features processed for the layer.

• SR - SIMPLERENDERER
• VMR - VALUMEMAPRENDERER
• SLR - SIMPLELABELRENDERER
• VMLR - VALUEMAPLABELRENDERER

[Jan 15, 2006 1:59:42 PM][3032 2216 INFO2] SR FEATURES PROCESSED: 12

Time to process and fetch features.

[Jan 15, 2006 1:59:42 PM][3032 2216 STAT2] DATA RETRIEVAL TIME: 0.063000s

Time to draw all labels.

[Jan 15, 2006 1:59:42 PM][3032 2216 STAT2] LABEL ENGINE TIME: 0.000000s

Total time after the request has been parsed until labels are drawn. Note that this total time is not usually exactly equal to the sum of renderer setup, data search time, data retrieval time, and label engine time.

[Jan 15, 2006 1:59:42 PM][3032 2216 STAT2] TOTAL PROCESSING TIME: 0.079000s

Time to generate the image.

[Jan 15, 2006 1:59:43 PM][3032 2216 STAT2] OUTPUT TIME: 0.078000s

Time to generate any separate layer images, if they are requested.

[Jan 15, 2006 1:59:43 PM][3032 2216 STAT2] SEPARATE LAYERS PROCESSING TIME: 0.000000s

Response sent to the Application Server.

[Jan 15, 2006 1:59:43 PM][3032 2216 INFO3] RESPONSE: <?xml version="1.0" encoding="UTF-8"?> <ARCXML version="1.1"> <RESPONSE> <IMAGE> <ENVELOPE minx="-180" miny="-135" maxx="180" maxy="135" /> <OUTPUT url="http://mymachine/output/canada_MYMACHINE3032221613.jpg" /> </IMAGE> </RESPONSE> </ARCXML>

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 1:59:43 PM][3032 2216 STAT1] Total Request Time: 0.188000s

Request is fully processed.

[Jan 15, 2006 1:59:43 PM][3032 2216 INFO1] End Request

ArcMap Server log file - requests

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 3:24:20 PM][3252 3952 INFO1] Begin Request

Request received from the ArcIMS Application Server.

[Jan 15, 2006 3:24:20 PM][3252 3952 INFO3] REQUEST: <GET_IMAGE> <PROPERTIES> <ENVELOPE minx="-180" miny="-90" maxx="180" maxy="90" /> <IMAGESIZE width="800" height="600"/> </PROPERTIES> </GET_IMAGE>

Request type (GET_IMAGE or GET_RASTER_INFO) and the name of the service (world).

[Jan 15, 2006 3:24:20 PM][3252 3952 INFO1] GET_IMAGE: world

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 3:24:21 PM][3252 3952 STAT1] Total Request Time: 0.766000s

Request is fully processed.

[Jan 15, 2006 3:24:21 PM][3252 3952 INFO1] End Request

Note: the ArcMap Server log files do not include the response even when logging is fully enabled. You can view the responses in the Application Server debug log. To turn this log file on, see Enabling full verbose logging.

Query and Feature Server log files - requests

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 2:48:10 PM][3032 2320 INFO1] Begin Request

Request received from the ArcIMS Application Server.

[Jan 15, 2006 2:48:10 PM][3032 2320 INFO3] REQUEST: <GET_FEATURES featurelimit="25" beginrecord="0" outputmode="xml" geometry="false" envelope="true" compact="true"> <LAYER id="0"> </LAYER> <SPATIALQUERY subfields="#ALL#" where="NAME = 'Alberta'" > </SPATIALQUERY> </GET_FEATURES>

Request type (GET_FEATURES) and the name of the service (canada).

[Jan 15, 2006 2:48:10 PM][3032 2320 INFO1] GET_FEATURES: canada

Notification that the processing is beginning.

[Jan 15, 2006 2:48:10 PM][3032 2320 INFO2] <GET_FEATURES> QS start processing...

Time to process and fetch features.

[Jan 15, 2006 2:48:10 PM]][ 3032 2320 STAT2] DATA RETRIEVAL TIME: 0.047000s

Number of features processed in query.

[Jan 15, 2006 2:48:10 PM][3032 2320 INFO2] Features sent: 1

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 2:48:10 PM][3032 2320 STAT1] Total Request Time: 0.172000s

Request is fully processed.

[Jan 15, 2006 2:48:10 PM][3032 2320 INFO1] End Request

Note: the Query Server log files do not include the response even when logging is fully enabled. You can view the responses in the Application Server debug log. To turn this log file on, see Enabling full verbose logging.

Extract Server log file - requests

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 2:54:37 PM][3032 2324 INFO1] Begin Request

Request received from the ArcIMS Application Server.

[Jan 15, 2006 2:54:37 PM][3032 2324 INFO3] REQUEST: <GET_EXTRACT> <PROPERTIES> <ENVELOPE minx="-130" miny="30" maxx="-90" maxy="60" /> </PROPERTIES> </GET_EXTRACT>

Request type (GET_EXTRACT) and the name of the service (canada). Note that ADDSERVICE is a misprint and should be GET_EXTRACT.

[Jan 15, 2006 2:54:37 PM][3032 2324 INFO1] ADDSERVICE: canada

Time needed to parse the request in seconds.

[Jan 15, 2006 2:54:37 PM][3032 2324 STAT2] AXL Parse Time: 0.000000s

Name of the layer being processed.

[Jan 15, 2006 2:54:37 PM][3032 2324 INFO2] Feature Layer: Provinces (id=0)

Time to create and send a query to the data source.

[Jan 15, 2006 2:54:37 PM][3032 2324 STAT2] Search Time: 0.062000s

Number of features processed.

[Jan 15, 2006 2:54:37 PM][3032 2324 INFO2] Features Extracted: 7

Time to process all features from the data source and generate a shape file.

[Jan 15, 2006 2:54:37 PM][3032 2324 STAT2] Retrieval Time: 0.110000s

Response sent to the Application Server.

[Jan 15, 2006 2:54:38 PM][3032 2324 INFO3] RESPONSE: <?xml version="1.0" encoding="UTF-8"?> <ARCXML version="1.1"> <RESPONSE> <EXTRACT> <ENVELOPE minx="-130" miny="30" maxx="-90" maxy="60" /> <OUTPUT url="http://mymachine/output/canada_mymachine303223241.zip" /> </EXTRACT> </RESPONSE> </ARCXML>

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 2:54:38 PM][3032 2324 STAT1] Total Request Time: 0.672000s

Request is fully processed.

[Jan 15, 2006 2:54:38 PM][3032 2324 INFO1] End Request

Geocode Server log file - requests

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 3:13:28 PM][3032 2316 INFO1] Begin Request

Request received from the ArcIMS Application Server.

[Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] REQUEST: <GET_GEOCODE maxcandidates="25" minscore="60"> <LAYER id="4"> </LAYER> <ADDRESS> <GCTAG id="STREET" value="200 Medford St"/> <GCTAG id="Zone" value="02129"/> <GCTAG id="CrossStreet" value=""/> </ADDRESS> </GET_GEOCODE>

Details on the geocoding match process.

[Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Styles dir - C:\Program Files\ArcGIS\ArcIMS\Server\ext/GeocodeServer/Styles [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] STN file - C:\Program Files\ArcGIS\ArcIMS\Server\ext/GeocodeServer/Styles\us_addr.stn [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Match key name - us_addr [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Proceed to parse input address... [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] ...completed. Input string - 200 MEDFORD ST [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Init matching Service [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Load match rules - C:\Program Files\ArcGIS\ArcIMS\Server\ext/GeocodeServer/Styles\us_addr1.mat. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Create list of candidates. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Get Index Service [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Build index query. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Search for candidates. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Fill candidate list. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Match candidates. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Get the best candidates. [Jan 15, 2006 3:13:28 PM][3032 2316 INFO3] Close MTCH.

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 3:13:28 PM][3032 2316 STAT1] Total Request Time: 0.500000s

Request is fully processed.

[Jan 15, 2006 3:13:28 PM][3032 2316 INFO1] End Request

Note: the Geocode Server log files do not include the response even when logging is fully enabled. You can view the responses in the Application Server debug log. To turn this log file on, see Enabling full verbose logging.

Image, Query, Feature, Extract, and Geocode Server log files - adding a service

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO1] Begin Request

The next lines show the map configuration file content for a service named 'Canada'.

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO3] REQUEST: <ADDSERVICE name="canada"> <IMAGE url="http://mymachine/output" path="C:/ArcIMS/Output" type="JPG" pixelcount="1048576" /> <CONFIG> <ENVIRONMENT> <LOCALE language="en" country="US" /> <UIFONT name="Arial" color="0,0,0" size="12" style="regular" /> <SEPARATORS cs=" " ts=";"/> </ENVIRONMENT> <MAP> <PROPERTIES> <ENVELOPE minx="-141.003005981445" miny="41.9133186340332" maxx="-52.6202812194824" maxy="83.1083221435546" name="Initial_Extent" /> <MAPUNITS units="decimal_degrees" /> </PROPERTIES> <WORKSPACES> <SHAPEWORKSPACE directory="C:\ESRIDATA\CANADA" name="shp_ws-0"/> </WORKSPACES> <LAYER type="featureclass" name="province" id="0" visible="true"> <DATASET name="province" type="polygon" workspace="shp_ws-0" > </DATASET> <SIMPLERENDERER> <SIMPLEPOLYGONSYMBOL fillcolor="127,127,127" /> </SIMPLERENDERER> </LAYER> </MAP> </CONFIG> </ADDSERVICE>

The next line reports that a service named 'canada' was added or removed. You may see the following service administration tags:

• ADDSERVICE - a service was added
• REMOVESERVICE - service was removed

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO1] ADDSERVICE: Canada

Notification that the Spatial Server is beginning to process a layer.

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO3] Begin creating layer 0.

Notification that the layer was processed properly. In the event of an error, this line is omitted, and the error is listed instead.

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO3] Layer 0 was created successfully.

Time needed to parse the request in seconds.

[Jan 15, 2006 1:59:33 PM][3032 1236 STAT2] AXL Parse Time: 0.015000s

Response returned by the Spatial Server and sent to the Application Server.

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO3] RESPONSE: <?xml version="1.0" encoding="UTF-8"?> <ARCXML version="1.1"> <RESPONSE> <OK /> </RESPONSE> </ARCXML>

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 1:59:33 PM][3032 1236 STAT1] Total Request Time: 0.062000s

Request is fully processed.

[Jan 15, 2006 1:59:33 PM][3032 1236 INFO1] End Request

ArcMap Server log file - adding a service

All requests start with a 'Begin Request' notification.

[Jan 15, 2006 12:00:34 PM][3116 3000 INFO1] Begin Request

The next lines show supporting ArcXML for a service named 'world'. The input files are map documents (*.mxd or *.pmf). The content of these documents is not included.

[Jan 15, 2006 12:00:34 PM][3116 3000 INFO3] REQUEST: <ADDSERVICE name="world"> <IMAGE url="http://mymachine/output" path="c:\arcims\output" type="PNG" pixelcount="2097152" /> <CONFIG type="bin" ext="mxd"> </CONFIG> </ADDSERVICE>

A service named 'world' was added. You may see the following service administration tags:

• ADDSERVICE - a service was added
• REMOVESERVICE - service was removed

[Jan 15, 2006 12:00:34 PM][3116 3000 INFO1] ADDSERVICE: world

Notification that the service has been added successfully.

[Jan 15, 2006 12:00:36 PM][3116 3000 INFO2] ArcIMS Service world has been successfully added.

Time spent for all processing starting with 'Begin Request' and ending with 'End Request'.

[Jan 15, 2006 12:00:36 PM][3116 3000 STAT1] Total Request Time: 2.390000s

Request is fully processed.

[Jan 15, 2006 12:00:36 PM][3116 3000 INFO1] End Request