Configuring ARM Logging in a Configuration File

Using the ARM interface, the SAS logging facility, and a configuration file, one or more logs can be created. Each log is a file appender that contains pattern layouts. The file appender is defined in the configuration file. The following syntax creates a file appender:
<appender class="FileAppender" name="LOG">
          <param name="File" value="logs/trace.log"/>
          <param name="Append" value="false"/>
          <param name="ImmediateFlush" value="true"/>
          <layout>
               <param name="ConversionPattern" 
                         value="%d %-5p [%t] %c (%F:%L) - %m"/>
          </layout>
</appender>
For more information about the configuration parameters in the file appender syntax, see ARM Appender Configuration Parameters.
A pattern layout is needed to create the output message format.
    <layout>
              <param name="ConversionPattern"
                    value="%d,
                     %X{App.Name},
                     %X{ARM.GroupName},
                     %X{ARM.TranName},
                     %X{ARM.TranState},
                     %X{ARM.ParentCorrelator},
                     %X{ARM.CurrentCorrelator},
                     %X{ARM.TranStatus},
                     %X{ARM.TranStart.Time},
                     %X{ARM.TranStop.Time},
                     %X{ARM.TranResp.Time}
               "/>
          </layout>
For more information about pattern layouts, see ARM Appender Pattern Layouts for ARM Messages.
The following configuration file creates three logs:
-
<?xml version=”1.0”?> 
<logging:configuration modify="false" xmlns:log4sas=
 "http://www.sas.com/xml/logging/1.0/"

<appender name="LOG" class="FileAppender">
          <param name="File" value="Logs/trace.log"/>
          <param name="Append" value="false"/>
          <param name="ImmediateFlush" value="true"/>
          <layout>
               <param name="ConversionPattern" 
                         value="%d %-5p [%t] %c (%F:%L) - %m"/>
          </layout>
</appender>

<appender name="ARM2LOG" class="FileAppender">
          <param name="File" value="Logs/arm2.log"/>
          <param name="Append" value="false"/>
          <param name="ImmediateFlush" value="true"/>
          <layout>
               <param name="ConversionPattern"
                          value="%X{ARM2.Record}"/>
          </layout>
</appender>

<appender name="ARM4LOG” class="FileAppender">
          <param name="File" value="Logs/arm4.log"/>
          <param name="Append" value="false"/>
          <param name="ImmediateFlush" value="true"/>
          <layout>
              <param name="ConversionPattern"
                    value="%d,
                     %X{App.Name},
                     %X{ARM.GroupName},
                     %X{ARM.TranName},
                     %X{ARM.TranState},
                     %X{ARM.ParentCorrelator},
                     %X{ARM.CurrentCorrelator},
                     %X{ARM.TranStatus},
                     %X{ARM.TranStart.Time},
                     %X{ARM.TranStop.Time},
                     %X{ARM.TranResp.Time}
               "/>
          </layout>
</appender>

<appender name="ARM" class="ARMAppender">
          <param name="GetTimes" value="TRUE"/>
          <appender-ref ref="ARM4LOG"/>
          <appender-ref ref="ARM2LOG"/>
</appender>

<logger name="Perf.ARM" additivity="true">
<level value="all"/>
<appender-ref ref="ARM"/>
</logger>

<root>
<level value="info"/>
<appender-ref ref="LOG"/>
</root>

</logging:configuration>
Here are the three logs that are created by the configuration file (ARM2.LOG, ARM4.LOG, and TRACE.LOG):
ARM2.LOG
I,1665424437.821000,1,0.046875,0.062500,SAS,sasjwg@CARYNT
G,1665424437.837000,1,1,SAS,MVA SAS session,GROUP_NAME,ShortStr,_IOCOUNT_,Count64,_MEMHIGH_,Gauge64,
  HOST_NAME,LongStr
S,1665424437.837000,1,1,1,0.046875,0.062500,sasjwg@C,1948209,3375104,d21423                          
G,1665424437.837000,1,2,MVA_DSIO.OPEN_CLOSE,DATA SET OPEN/CLOSE,LIBNAME,ShortStr,MEMTYPE,ShortStr,
  NOBS,Count64,NVAR,Count64,NOBSREAD,Count64,MEMNAME,LongStr
S,1665424438.165000,1,2,2,0.109375,0.125000,PERM    ,DATA    ,0,0,0,DSET_50   
U,1665424438.165000,1,2,2,0.109375,0.125000,2,VAR(2,name),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(1,age),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(1,grade),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(2,region),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(2,city),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(2,state),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(2,country),DEF
U,1665424438.181000,1,2,2,0.109375,0.125000,2,VAR(1,i),DEF
P,1665424438.243000,1,2,2,0.109375,0.125000,0,PERM    ,DATA    ,50,8,0,DSET_50 
S,1665424438.275000,1,2,3,0.109375,0.140625,PERM    ,DATA    ,50,8,0,DSET_50   
S,1665424438.306000,1,2,4,0.109375,0.140625,PERM    ,DATA    ,0,0,0,SORT_50  
U,1665424438.306000,1,2,3,0.109375,0.140625,2,VAR(2,city),SEL
U,1665424438.306000,1,2,3,0.109375,0.140625,2,VAR(1,age),SEL
U,1665424438.306000,1,2,3,0.109375,0.140625,2,VAR(2,name),SEL
U,1665424438.306000,1,2,3,0.109375,0.140625,2,VAR(1,grade),SEL
U,1665424438.306000,1,2,3,0.109375,0.140625,2,VAR(2,region),SEL
U,1665424438.306000,1,2,3,0.109375,0.140625,2,VAR(2,state),SEL
U,1665424438.321000,1,2,3,0.109375,0.140625,2,VAR(2,country),SEL
U,1665424438.321000,1,2,3,0.109375,0.140625,2,VAR(1,i),SEL
U,1665424438.321000,1,2,4,0.109375,0.140625,2,VAR(2,name),DEF
U,1665424438.321000,1,2,4,0.109375,0.140625,2,VAR(1,age),DEF
U,1665424438.321000,1,2,4,0.109375,0.140625,2,VAR(1,grade),DEF
U,1665424438.321000,1,2,4,0.109375,0.140625,2,VAR(2,region),DEF
U,1665424438.321000,1,2,4,0.109375,0.140625,2,VAR(2,city),DEF
U,1665424438.321000,1,2,4,0.109375,0.140625,2,VAR(2,state),DEF
U,1665424438.337000,1,2,4,0.109375,0.140625,2,VAR(2,country),DEF
U,1665424438.337000,1,2,4,0.109375,0.140625,2,VAR(1,i),DEF
P,1665424438.353000,1,2,3,0.109375,0.140625,0,PERM    ,DATA    ,50,8,50,DSET_50 
P,1665424438.353000,1,2,4,0.109375,0.140625,0,PERM    ,DATA    ,50,8,0,SORT_50 
P,1665424438.368000,1,1,1,0.109375,0.140625,0,sasjwg@C,2513019,4947968,d21423  
E,1665424438.384000,1,0.109375,0.156250

ARM4.LOG
2012-10-09T13:53:57,820,SAS,sasID,    ,  INIT,  ,  ,  ,  ,  ,
2012-10-09T13:53:57,836,SAS,sasID,  SAS,  REGISTER,  ,  ,  ,  ,  , 
2012-10-09T13:53:57,836,SAS,sasID,  SAS,  START,  ,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  ,
        1665424437.837000,  ,
2012-10-09T13:53:57,836,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  REGISTER,  ,  ,  ,  ,  ,
2012-10-09T13:53:58,164,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  START,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  , 
2012-10-09T13:53:58,164,SAS,sasID,,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,180,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  ,  1665424438.165000,  ,
2012-10-09T13:53:58,242,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  STOP,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/AEY3N0UzNUE4LTg5NjktNDIxMi04RjY5LUZFMEFDQjA3M0I3Rg==,  GOOD,  1665424438.165000,  
        1665424438.243000,  0.078000                
2012-10-09T13:53:58,274,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  START,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  START,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,

2012-10-09T13:53:58,305,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  ,  1665424438.275000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,320,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,336,SAS,sasID,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,336,SAS,sasID,,  MVA_DSIO.OPEN_CLOSE,  UPDATE,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  ,  1665424438.306000,  ,
2012-10-09T13:53:58,352,SAS,sasID,,  MVA_DSIO.OPEN_CLOSE,  STOP,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  GOOD,  1665424438.275000,  
        1665424438.353000,  0.078000                
2012-10-09T13:53:58,352,SAS,sasID,,  MVA_DSIO.OPEN_CLOSE,  STOP,  
        ACj/ADAzN0M4QUM4LUEwMEUtNDdCQy05N0ZGLTE5NEQ1RTE2MzhERQ==,  
        ACj/AEE4QUYxQkM5LUQ0NjktNEQ4QS04NUJBLTZDQzg0OTI5RTJDQg==,  GOOD,  1665424438.306000,  
        1665424438.353000,  0.047000                
2012-10-09T13:53:58,367,SAS,sasID,  SAS,  STOP,  ,  
        ACj/ADA2MjQ5RDQ0LTczRjAtNEI2My1CNTFELTczNzkwOERCMDI2OQ==,  GOOD,  
        1665424437.837000,  1665424438.368000,  0.531000                
2012-10-09T13:53:58,383,SAS,sasID,  ,  TERM,  ,  ,  ,  ,  ,  

TRACE.LOG
2012-10-09T13:53:57,820 INFO  [00000003] Perf.ARM.SAS.SAS.APPL (tka_api.c:299) - INIT SAS 
        11f63ac 11f63a0 I,1665424437.821000,1,0.046875,0.062500,SAS,sasjwg@CARYNT
2012-10-09T13:53:57,836 INFO  [00000003] Perf.ARM.SAS.SAS.APPL (tka_2api.c:589) - REGISTER SAS 
        11f63ac 11f65f8 G,1665424437.837000,1,1,SAS,MVA SAS session,GROUP_NAME,ShortStr,_IOCOUNT_,
        Count64,_MEMHIGH_,Gauge64,HOST_NAME,LongStr
2012-10-09T13:53:57,836 INFO  [00000003] Perf.ARM.SAS.SAS.APPL (tka_api.c:1201) - START SAS 261de64 
        11f65f8 0 S,1665424437.837000,1,1,1,0.046875,0.062500,sasjwg@C,1948209,3375104,d21423      
2012-10-09T13:53:57,836 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:650) - REGISTER 
        MVA_DSIO.OPEN_CLOSE 11f63ac 11f8308 G,1665424437.837000,1,2,MVA_DSIO.OPEN_CLOSE,DATA SET 
        OPEN/CLOSE,LIBNAME,ShortStr,MEMTYPE,ShortStr,NOBS,Count64,NVAR,Count64,NOBSREAD,Count64,
        MEMNAME,LongStr
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - 1    
                         The SAS System            13:53 Tuesday, October 9, 2012
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: Copyright (c) 
        2002-2012 by SAS Institute Inc., Cary, NC, USA. 
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: SAS (r) Proprietary 
        Software 9.4 (TS1B0) 
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) -       Licensed to SAS 
        Institute Inc., Site 1.
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: This session is 
        executing on the XP_PRO  platform.
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,039 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: Updated analytical 
        products:
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -       
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -       
        SAS/STAT 12.3 (maintenance)
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -       
        SAS/ETS 12.3 (maintenance)
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -       
        SAS/OR 12.3 (maintenance)
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -       
        SAS/IML 12.3 (maintenance)
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -       
        SAS/QC 12.3 (maintenance)
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: Additional host 
        information:
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) -  XP_PRO DNTHOST 5.1.2600 
        Service Pack 3 Workstation
2012-10-09T13:53:58,055 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,055 INFO  [00000003] Admin.Session (yaxbtch.c:578) - SAH231999I Batch, State, 
        started, Startup command-line is: "C:\SASv9\sasgen\dev\mva-v940\sas_dvd\com\dntno\sas.exe" 
        dset.sas -config "C:\SASv9\tmp\SASv9-2748.cfg" -sashost "C:\SASv9\sashost.dll" 
        -armsubsys "(ARM_DSIO)" -logconfigloc "u:\sas\dev\mva-v940\tests\log4sasarm.xml"
2012-10-09T13:53:58,070 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: SAS initialization used:
2012-10-09T13:53:58,070 INFO  [00000008] App.Program (ynl4sas.c:134) -
        real time           0.37 seconds
2012-10-09T13:53:58,070 INFO  [00000008] App.Program (ynl4sas.c:134) -
        cpu time            0.18 seconds
2012-10-09T13:53:58,070 INFO  [00000008] App.Program (ynl4sas.c:134) -       
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 
        1          options fullstimer;
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 2          
        libname perm "data";

2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - NOTE: Libref PERM was 
        successfully assigned as follows: 
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) -       Engine:        V9 
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) -       Physical Name: 
        U:\sas\dev\mva-v940\tests\data
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 3          %macro bld(obno);
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 4          data 
        perm.dset_&obno. (label='foobar');
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 5          
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 6             format name 
        $50. age 8. grade 5.2 region $50.
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 7                    city $50. 
        state $2. country $100.;
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 8          
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 9             do i=1 to &obno.
2012-10-09T13:53:58,102 INFO  [00000008] App.Program (ynl4sas.c:134) - 10               state='NC';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 11               
        if mod(i,2) = 0 then do;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 12                  name='Joe';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 13                  age=47;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 14                  grade=3.75;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 15                  
        region='SouthEast';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 16                  
        city='Raleigh';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 17                  
        country='United States of America';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 18                  end;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 19               else do;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 20                  name='Joe';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 21                  age=32;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 22                  grade=3.35;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 23                  
        region='SouthEast';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 24                  city='Cary';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 25                  
        country='United States of America';
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 26                  end;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 27               output;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 2                
                         The SAS System            13:53 Tuesday, October 9, 2012
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 28               end;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 29         run;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 30         
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 31         proc sort 
        data=perm.dset_&obno. out=perm.sort_&obno.
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 32            by city age;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 33         run;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 34         %mend;
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 35         
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 36         
2012-10-09T13:53:58,117 INFO  [00000008] App.Program (ynl4sas.c:134) - 37         %bld(50);
2012-10-09T13:53:58,133 INFO  [00000009] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,164 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1216) - START 
        MVA_DSIO.OPEN_CLOSE 32ee454 11f8308 0 S,1665424438.165000,1,2,2,0.109375,0.125000,
        PERM    ,DATA    ,0,0,0,DSET_50     
2012-10-09T13:53:58,164 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.165000,1,2,2,0.109375,0.125000,2,
        VAR(2,name),DEF
2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(1,age),DEF

2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(1,grade),DEF
2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(2,region),DEF
2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(2,city),DEF
2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(2,state),DEF
2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(2,country),DEF
2012-10-09T13:53:58,180 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.181000,1,2,2,0.109375,0.125000,2,
        VAR(1,i),DEF
2012-10-09T13:53:58,195 INFO  [00000009] App.Program (ynl4sas.c:134) - 
        NOTE: The data set PERM.DSET_50 has 50 observations and 8 variables.
2012-10-09T13:53:58,242 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:2014) - STOP 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 GOOD P,1665424438.243000,1,2,2,0.109375,0.125000,0,
        PERM    ,DATA    ,50,8,0,DSET_50     
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) - 
        NOTE: DATA statement used 
        (Total process time):
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       real time           0.10 seconds
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       user cpu time       0.00 seconds
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       system cpu time     0.00 seconds
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       memory              303.74k
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       OS Memory           4576.00k
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       Timestamp           10/ 9/2012 01:53:58 PM
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) 
        -       Step Count    1  Switch Count  0
2012-10-09T13:53:58,242 INFO  [00000009] App.Program (ynl4sas.c:134) -       
2012-10-09T13:53:58,242 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,274 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1216) - START 
        MVA_DSIO.OPEN_CLOSE 371d8cc 11f8308 0 S,1665424438.275000,1,2,3,0.109375,0.140625,
        PERM    ,DATA    ,50,8,0,DSET_50     
2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1216) - START 
        MVA_DSIO.OPEN_CLOSE 371d8cc 11f8308 0 S,1665424438.306000,1,2,4,0.109375,0.140625,
        PERM    ,DATA    ,0,0,0,SORT_50     
2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.306000,1,2,3,0.109375,0.140625,2,
        VAR(2,city),SEL
2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.306000,1,2,3,0.109375,0.140625,2,
        VAR(1,age),SEL
2012-10-09T13:53:58,305 INFO  [00000010] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.306000,1,2,3,0.109375,0.140625,2,
        VAR(2,name),SEL
2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.306000,1,2,3,0.109375,0.140625,2,
        VAR(1,grade),SEL
2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.306000,1,2,3,0.109375,0.140625,2,
        VAR(2,region),SEL

2012-10-09T13:53:58,305 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.306000,1,2,3,0.109375,0.140625,2,
        VAR(2,state),SEL
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.321000,1,2,3,0.109375,0.140625,2,
        VAR(2,country),SEL
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 U,1665424438.321000,1,2,3,0.109375,0.140625,2,
        VAR(1,i),SEL
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.321000,1,2,4,0.109375,0.140625,2,
        VAR(2,name),DEF
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.321000,1,2,4,0.109375,0.140625,2,
        VAR(1,age),DEF
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.321000,1,2,4,0.109375,0.140625,2,
        VAR(1,grade),DEF
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.321000,1,2,4,0.109375,0.140625,2,
        VAR(2,region),DEF
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.321000,1,2,4,0.109375,0.140625,2,
        VAR(2,city),DEF
2012-10-09T13:53:58,320 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.321000,1,2,4,0.109375,0.140625,2,
        VAR(2,state),DEF
2012-10-09T13:53:58,336 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.337000,1,2,4,0.109375,0.140625,2,
        VAR(2,country),DEF
2012-10-09T13:53:58,336 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:1638) - UPDATE 
        MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 U,1665424438.337000,1,2,4,0.109375,0.140625,2,
        VAR(1,i),DEF
2012-10-09T13:53:58,352 INFO  [00000010] App.Program (ynl4sas.c:134) 
        - NOTE: There were 50 observations read from the data set PERM.DSET_50.
2012-10-09T13:53:58,352 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:2014) 
        - STOP MVA_DSIO.OPEN_CLOSE 1d35de0 11f8308 GOOD P,1665424438.353000,1,2,3,0.109375,
        0.140625,0,PERM    ,DATA    ,50,8,50,DSET_50     
2012-10-09T13:53:58,352 INFO  [00000010] App.Program (ynl4sas.c:134) 
        - NOTE: The data set PERM.SORT_50 has 50 observations and 8 variables.
2012-10-09T13:53:58,352 INFO  [00000003] Perf.ARM.SAS.INTERNAL.DSIO (tka_api.c:2014) 
        - STOP MVA_DSIO.OPEN_CLOSE 32352b0 11f8308 GOOD P,1665424438.353000,1,2,4,0.109375,
        0.140625,0,PERM    ,DATA    ,50,8,0,SORT_50     
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        - NOTE: PROCEDURE SORT used (Total process time):
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       real time           0.09 seconds
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       user cpu time       0.00 seconds
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       system cpu time     0.00 seconds
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       memory              286.82k
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       OS Memory           4832.00k
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       Timestamp           10/ 9/2012 01:53:58 PM
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) 
        -       Step Count                        2  Switch Count  0
2012-10-09T13:53:58,367 INFO  [00000010] App.Program (ynl4sas.c:134) -       
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) - 38         
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) - 
2012-10-09T13:53:58,367 INFO  [00000003] Admin.Session (yaxbtch.c:988) 
        - SAH239999I Batch, State, stopped

2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        - NOTE: SAS Institute Inc., SAS Campus Drive, Cary, NC USA 27513-2414
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        - NOTE: The SAS System used:
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       real time           0.67 seconds
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       user cpu time       0.10 seconds
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       system cpu time     0.14 seconds
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       memory              3847.28k
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       OS Memory           4832.00k
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       Timestamp           10/ 9/2012 01:53:58 PM
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) 
        -       Step Count                        2  Switch Count  0
2012-10-09T13:53:58,367 INFO  [00000008] App.Program (ynl4sas.c:134) -       
2012-10-09T13:53:58,367 INFO  [00000003] Perf.ARM.SAS.SAS.APPL (tka_api.c:1999) 
        - STOP SAS 1d34c70 11f65f8 GOOD P,1665424438.368000,1,1,1,0.109375,0.140625,
        0,sasjwg@C,2513019,4947968,d21423      
2012-10-09T13:53:58,383 INFO  [00000003] Perf.ARM.SAS.SAS.APPL (tka_api.c:2214) 
        - END SAS 1e3b4f0 11f63a0 E,1665424438.384000,1,0.109375,0.156250