Creating Logs Using a Configuration File

Using the ARM interface, the SAS logging facility, and a configuration file, the following two logs are created:

<?xml version=”1.0”?> 
<logging:configuration xmlns:log4sas="http://www.sas.com/xml/logging/1.0/"

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

<appender class="FileAppender" name="ARM4LOG">
          <param name="File" value="logs/arm4.log"/>
          <param name="Append" value="false"/>
          <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 class="ARMAppender" name="ARM">
          <param name="GetTimes" value="TRUE"/>
          <appender-ref ref="ARM4LOG"/>
 </appender>

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

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

</logging:configuration>

The ARM4.LOG file and TRACE.LOG file are created by the configuration file:

ARM4.LOG

2008-04-14T12:39:04,972 | SAS | USERID |  | INIT |  |  |  |  |  | 
2008-04-14T12:39:04,972 | SAS | USERID | SAS | REGISTER |  |  |  |  |  | 
2008-04-14T12:39:04,972 | SAS | USERID | SAS | START |  | 
        ACj/ADExOUUzQkI3LUJGQTgtNDlBOS04RTg1LUVDOTJCRTQ2RTY4OA== |  |
        1523810344.972000 |  | 
2008-04-14T12:39:04,972 | SAS | USERID | PROCEDURE | REGISTER |  |  |  |  |  | 
2008-04-14T12:39:05,565 | OpenCodeARMGTID_test_w/_user_metrics | 
        USERID |  | INIT |  |  |  |  |  | 
2008-04-14T12:39:05,690 | OpenCodeARMGTID_test_w/_user_metrics |
        USERID | OpenCode02 | REGISTER |  |  |  |  |  | 
2008-04-14T12:39:05,830 | OpenCodeARMGTID_test_w/_user_metrics | 
        USERID | OpenCode02 | START | ACj/
        ADExOUUzQkI3LUJGQTgtNDlBOS04RTg1LUVDOTJCRTQ2RTY4OA== | 
        ACj/AEY3MjJDNDJCLTAxNkEtNDMxNy1BNzc4LTc2OTA5Mjg1QzRGNQ== |  |
        1523810345.831000 |  | 
2008-04-14T12:39:05,847 | SAS | USERID | PROCEDURE | START | 
        ACj/AEY3MjJDNDJCLTAxNkEtNDMxNy1BNzc4LTc2OTA5Mjg1QzRGNQ== | 
        ACj/AERGNDc3OEFELTlCNzItNEE3NC1CNjNFLTU5OTI2QTFERTQ4Ng== |  | 
        1523810345.847000 |  | 
2008-04-14T12:39:05,955 | SAS | USERID | PROCEDURE | STOP | 
        ACj/AEY3MjJDNDJCLTAxNkEtNDMxNy1BNzc4LTc2OTA5Mjg1QzRGNQ== | 
        ACj/AERGNDc3OEFELTlCNzItNEE3NC1CNjNFLTU5OTI2QTFERTQ4Ng== | 
        GOOD | 1523810345.847000 | 1523810345.956000 | 0.109000
2008-04-14T12:39:05,972 | SAS | USERID | PROCEDURE | START | 
        ACj/AEY3MjJDNDJCLTAxNkEtNDMxNy1BNzc4LTc2OTA5Mjg1QzRGNQ== | 
        ACj/AEQ5QkY3MkE3LTVBMzQtNDg1Qi05MUQyLUI0MjZDMzE2MDk0NA== |  | 
        1523810345.972000 |  | 
2008-04-14T12:39:06,128 | SAS | USERID | PROCEDURE | STOP | 
        ACj/AEY3MjJDNDJCLTAxNkEtNDMxNy1BNzc4LTc2OTA5Mjg1QzRGNQ== | 
        ACj/AEQ5QkY3MkE3LTVBMzQtNDg1Qi05MUQyLUI0MjZDMzE2MDk0NA== | 
        GOOD | 1523810345.972000 | 1523810346.128000 | 0.156000
2008-04-14T12:39:06,190 | OpenCodeARMGTID_test_w/_user_metrics | 
        USERID | OpenCode02 | STOP | 
        ACj/ADExOUUzQkI3LUJGQTgtNDlBOS04RTg1LUVDOTJCRTQ2RTY4OA== | 
        ACj/AEY3MjJDNDJCLTAxNkEtNDMxNy1BNzc4LTc2OTA5Mjg1QzRGNQ== | 
        GOOD | 1523810345.831000 | 1523810346.191000 | 0.360000
2008-04-14T12:39:06,237 | OpenCodeARMGTID_test_w/_user_metrics | 
        USERID |  | TERM |  |  |  |  |  | 
2008-04-14T12:39:06,284 | SAS | USERID | SAS | STOP |  | 
        ACj/ADExOUUzQkI3LUJGQTgtNDlBOS04RTg1LUVDOTJCRTQ2RTY4OA== | 
        GOOD | 1523810344.972000 | 1523810346.285000 | 1.313000
2008-04-14T12:39:06,299 | SAS | USERID |  | TERM |  |  |  |  |  |

TRACE.LOG

2008-04-14T12:39:04,924 DEBUG [00000003] Logging (l4sasutil.c:830) - 
        Loading the tk4afile support extension (1.0.0).
2008-04-14T12:39:04,924 DEBUG [00000003] Logging.Appender.File 
        (tk4afile.c:1082) - Creating FileAppender LOG
2008-04-14T12:39:04,924 DEBUG [00000003] Logging.Appender.File 
        (tk4afile.c:1082) - Creating FileAppender ARM2LOG
2008-04-14T12:39:04,924 DEBUG [00000003] Logging.Appender.File 
        (tk4afile.c:1082) - Creating FileAppender ARM4LOG
2008-04-14T12:39:04,955 DEBUG [00000003] Logging (l4sasutil.c:830) - 
        Loading the tk4aarm4 support extension (1.0.0).
2008-04-14T12:39:04,955 DEBUG [00000003] Logging.Appender.ARM 
        (tk4aarm4.c:1192) - Creating ARM Appender ARM
2008-04-14T12:39:04,955 DEBUG [00000003] Logging.Appender.ARM 
        (tk4aarm4.c:1345) - Created ARM Appender ARM (0x1fa5f40)
2008-04-14T12:39:04,955 DEBUG [00000003] Logging.Appender.ARM 
        (tk4aarm4.c:947) - ARM Appender SetOption(GetTimes, TRUE)
2008-04-14T12:39:04,972 INFO  [00000003] Perf.ARM.SAS.APPL 
        (tka_api.c:275) - INIT SAS 13eec00 I,1523810344.972000,1,0.062500,
        0.453125,SAS,
2008-04-14T12:39:04,972 INFO  [00000003] Perf.ARM.SAS.APPL 
        (tka_2api.c:576) - REGISTER SAS 13eee58 G,1523810344.972000,1,1,
        SAS,MVA SAS session
2008-04-14T12:39:04,972 INFO  [00000003] Perf.ARM.SAS.APPL 
        (tka_api.c:1107) - START SAS 13eee58 0 S,1523810344.972000,1,1,1,
        0.062500,0.453125
2008-04-14T12:39:04,972 INFO  [00000003] Perf.ARM.SAS.PROC 
        (tka_2api.c:576) - REGISTER PROCEDURE 13ef148 G,1523810344.972000,
        1,2,PROCEDURE,PROC START/STOP,PROC_NAME,ShortStr,
        PROC_IO,Count64,PROC_MEM,Count64,PROC_LABEL,LongStr
2008-04-14T12:39:05,299 INFO  [00000008] App.Program (ynl4sas.c:123) - 1  
         The SAS System               12:39 Monday, April 14, 2008
2008-04-14T12:39:05,299 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:05,299 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: Copyright (c) 2002-2008 by SAS Institute Inc., Cary, NC, USA. 
2008-04-14T12:39:05,299 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: SAS (r) Proprietary Software 9.3 (TS2B0) 
2008-04-14T12:39:05,299 INFO  [00000008] App.Program (ynl4sas.c:123) -      
         Licensed to SAS Institute Inc., Site 0000000001.
2008-04-14T12:39:05,299 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: This session is executing on the XP_PRO  platform.
2008-04-14T12:39:05,315 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:05,315 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:05,315 INFO  [00000008] App.Program (ynl4sas.c:123) -
2008-04-14T12:39:05,315 INFO  [00000003] Admin.Session (yaxbtch.c:555) - 
        SAH231999I Batch, State, started, Startup command-line is:
         "C:\SASv9\sasgen\dev\mva-v920\sas_dvd\com\dntnd\sas.exe" test1.sas 
        -config "C:\SASv9\tmp\SASv9-832.cfg" -
        sashost "C:\SASv9\sasgen\dev\mva-v920\sas_dvd\com\dntnd\sashost.dll" 
        -logconfigloc ./log4sasarm.xml -armsubsys "(arm_proc)" -armagent log4sas
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: SAS initialization used:
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) -
        real time           0.79 seconds
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) -
        cpu time            0.78 seconds
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) -       
2008-04-14T12:39:05,393 INFO  [00000008] App.Program (ynl4sas.c:123) - 1
        %let _armexec = 1;
2008-04-14T12:39:05,393 INFO  [00000008] App.Program (ynl4sas.c:123) - 2        
 
        %let _armacro = 1;
2008-04-14T12:39:05,455 INFO  [00000008] App.Program (ynl4sas.c:123) - 3        
 
2008-04-14T12:39:05,455 INFO  [00000008] App.Program (ynl4sas.c:123) - 4        
 
        %arminit(appname="OpenCodeARMGTID test w/ user metrics");

2008-04-14T12:39:05,565 INFO  [00000003] 
        Perf.ARM.OpenCodeARMGTID_test_w/_user_metrics.APPL (tka_api.c:275) - 
        INIT OpenCodeARMGTID_test_w/_user_metrics 13f01e0 I,1523810345.566000,2,
        0.203125,0.734375,OpenCodeARMGTID test w/ user metrics,*
2008-04-14T12:39:05,565 INFO  [00000008] App.Program (ynl4sas.c:123) - 5        
 
        %armgtid(txnname="OpenCode02",txnidvar=txn1,
2008-04-14T12:39:05,597 INFO  [00000008] App.Program (ynl4sas.c:123) - 6        
    
         metrNam1="ShtStr",
2008-04-14T12:39:05,612 INFO  [00000008] App.Program (ynl4sas.c:123) - 7        
     
        metrDef1=short,
2008-04-14T12:39:05,612 INFO  [00000008] App.Program (ynl4sas.c:123) - 8        
   
          metrNam2="cnt32",
2008-04-14T12:39:05,612 INFO  [00000008] App.Program (ynl4sas.c:123) - 9        
    
         metrDef2=count32);
2008-04-14T12:39:05,690 INFO  [00000003] 
        Perf.ARM.OpenCodeARMGTID_test_w/_user_metrics.APPL (tka_api.c:632) - 
        REGISTER OpenCode02 13f0438 G,1523810345.691000,2,3,OpenCode02,,
        ShtStr,ShortStr,cnt32,Count32
2008-04-14T12:39:05,690 INFO  [00000008] App.Program (ynl4sas.c:123) - 10       
 
2008-04-14T12:39:05,705 INFO  [00000008] App.Program (ynl4sas.c:123) - 11       

         %put SYSPARM=&sysparm
2008-04-14T12:39:05,705 INFO  [00000008] App.Program (ynl4sas.c:123) - 
         SYSPARM=
2008-04-14T12:39:05,705 INFO  [00000008] App.Program (ynl4sas.c:123) - 12       
 
        %armstrt(txnidvar=txn1,metrval1=&sysparm);
2008-04-14T12:39:05,830 INFO  [00000003] 
        Perf.ARM.OpenCodeARMGTID_test_w/_user_metrics.APPL (tka_api.c:1120) - 
        START OpenCode02 13f0438 0 S,1523810345.831000,2,3,2,0.359375,0.828125
2008-04-14T12:39:05,830 INFO  [00000008] App.Program (ynl4sas.c:123) - 13       
 
2008-04-14T12:39:05,847 INFO  [00000003] Perf.ARM.SAS.PROC (tka_api.c:1107) - 
        START PROCEDURE 13ef148 0 S,1523810345.847000,1,2,3,0.359375,0.828125,
        DATASTEP,0,0,
2008-04-14T12:39:05,878 INFO  [00000009] App.Program (ynl4sas.c:123) - 14       
 
        data x;
2008-04-14T12:39:05,878 INFO  [00000009] App.Program (ynl4sas.c:123) - 15       
  
        do i=1 to 10000;
2008-04-14T12:39:05,878 INFO  [00000009] App.Program (ynl4sas.c:123) - 16       
  
        x=i; y=0-i;
2008-04-14T12:39:05,878 INFO  [00000009] App.Program (ynl4sas.c:123) - 17       
  
        output;
2008-04-14T12:39:05,878 INFO  [00000009] App.Program (ynl4sas.c:123) - 18       
 
         end; run;
2008-04-14T12:39:05,878 INFO  [00000009] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:05,940 INFO  [00000009] App.Program (ynl4sas.c:123) - 
        NOTE: The data set WORK.X has 10000 observations and 3 variables.
2008-04-14T12:39:05,955 DEBUG [00000003] App.Program (yaktksri.c:418) - 
        Remove appenders in a reb.
2008-04-14T12:39:05,315 INFO  [00000003] Admin.Session (yaxbtch.c:555) - 
        SAH231999I Batch, State, started, Startup command-line is:
         "C:\SASv9\sasgen\dev\mva-v920\sas_dvd\com\dntnd\sas.exe" test1.sas 
        -config "C:\SASv9\tmp\SASv9-832.cfg" -
        sashost "C:\SASv9\sasgen\dev\mva-v920\sas_dvd\com\dntnd\sashost.dll" 
        -logconfigloc ./log4sasarm.xml -armsubsys "(arm_proc)" -armagent log4sas
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: SAS initialization used:
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) -
        real time           0.79 seconds
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) -
        cpu time            0.78 seconds
2008-04-14T12:39:05,362 INFO  [00000008] App.Program (ynl4sas.c:123) -       
2008-04-14T12:39:05,393 INFO  [00000008] App.Program (ynl4sas.c:123) - 1
        %let _armexec = 1;
2008-04-14T12:39:05,393 INFO  [00000008] App.Program (ynl4sas.c:123) - 2        
 
        %let _armacro = 1;
2008-04-14T12:39:05,455 INFO  [00000008] App.Program (ynl4sas.c:123) - 3        
 
2008-04-14T12:39:05,455 INFO  [00000008] App.Program (ynl4sas.c:123) - 4        
 
        %arminit(appname="OpenCodeARMGTID test w/ user metrics");

2008-04-14T12:39:05,955 INFO  [00000003] Perf.ARM.SAS.PROC 
        (tka_api.c:1750) - STOP PROCEDURE 13ef148 0 P,1523810345.956000,1,2,
        3,0.375000,0.890625,0,DATASTEP,311110,283296,
2008-04-14T12:39:05,955 INFO  [00000009] App.Program (ynl4sas.c:123) - 
        NOTE: DATA statement used (Total process time):
2008-04-14T12:39:05,955 INFO  [00000009] App.Program (ynl4sas.c:123) -      
         real time           0.10 seconds
2008-04-14T12:39:05,955 INFO  [00000009] App.Program (ynl4sas.c:123) -       
        cpu time            0.07 seconds
2008-04-14T12:39:05,955 INFO  [00000009] App.Program (ynl4sas.c:123) -       
2008-04-14T12:39:05,955 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:05,955 INFO  [00000008] App.Program (ynl4sas.c:123) - 19       
 
2008-04-14T12:39:05,972 INFO  [00000003] Perf.ARM.SAS.PROC 
        (tka_api.c:1107) - START PROCEDURE 13ef148 0 S,1523810345.972000,1,
        2,4,0.375000,0.890625,SORT    ,0,0,
2008-04-14T12:39:05,972 INFO  [00000010] App.Program (ynl4sas.c:123) - 
        20         proc sort  data=x threads; by y;  run;
2008-04-14T12:39:05,972 INFO  [00000010] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:06,065 INFO  [00000010] App.Program (ynl4sas.c:123) - 
        NOTE: There were 10000 observations read from the data set WORK.X.
2008-04-14T12:39:06,128 INFO  [00000010] App.Program (ynl4sas.c:123) - 
        NOTE: The data set WORK.X has 10000 observations and 3 variables.
2008-04-14T12:39:06,128 DEBUG [00000003] App.Program (yaktksri.c:418) - 
        Remove appenders in a reb.
2008-04-14T12:39:06,128 INFO  [00000003] Perf.ARM.SAS.PROC 
        (tka_api.c:1750) - STOP PROCEDURE 13ef148 0 P,1523810346.128000,
        1,2,4,0.421875,0.953125,0,SORT    ,532806,2103048,
2008-04-14T12:39:06,128 INFO  [00000010] App.Program (ynl4sas.c:123) - 
        NOTE: PROCEDURE SORT used (Total process time):
2008-04-14T12:39:06,128 INFO  [00000010] App.Program (ynl4sas.c:123) -      
         real time           0.15 seconds
2008-04-14T12:39:06,128 INFO  [00000010] App.Program (ynl4sas.c:123) -       
        cpu time            0.10 seconds
2008-04-14T12:39:06,128 INFO  [00000010] App.Program (ynl4sas.c:123) -       
2008-04-14T12:39:06,128 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:06,143 INFO  [00000008] App.Program (ynl4sas.c:123) - 21       
 
2008-04-14T12:39:06,143 INFO  [00000008] App.Program (ynl4sas.c:123) - 22       

         %armstop;
2008-04-14T12:39:06,190 INFO  [00000003] 
        Perf.ARM.OpenCodeARMGTID_test_w/_user_metrics.APPL (tka_api.c:1761) - 
        STOP OpenCode02 13f0438 0 P,1523810346.191000,2,3,2,0.453125,0.984375,0
2008-04-14T12:39:06,205 INFO  [00000008] App.Program (ynl4sas.c:123) - 23       
 
        %armend;
2008-04-14T12:39:06,237 INFO  [00000003] 
        Perf.ARM.OpenCodeARMGTID_test_w/_user_metrics.APPL (tka_api.c:1927) - 
        END OpenCodeARMGTID_test_w/_user_metrics 13f01e0 E,1523810346.238000,
        2,0.468750,1.000000
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:06,237 INFO  [00000003] Admin.Session (yaxbtch.c:886) - 
        SAH239999I Batch, State, stopped
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: SAS Institute Inc., SAS Campus Drive, Cary, NC USA 27513-2414
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) - 
        NOTE: The SAS System used:
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) - 2
         The SAS System                               12:39 Monday, April 14,
2008
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) - 
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) -       
        real time           1.67 seconds
2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) -      
         cpu time            1.46 seconds

2008-04-14T12:39:06,237 INFO  [00000008] App.Program (ynl4sas.c:123) -       
2008-04-14T12:39:06,253 DEBUG [00000003] App.Program (yaktksri.c:418) - 
        Remove appenders in a reb.
2008-04-14T12:39:06,268 DEBUG [00000003] Logging.Appender.FileRef 
        (tk4afref.c:1072) - FileRef appender factory is being destroyed
2008-04-14T12:39:06,284 INFO  [00000003] Perf.ARM.SAS.APPL 
        (tka_api.c:1750) - STOP SAS 13eee58 0 P,1523810346.285000,1,1,1,
        0.468750,1.015625,0
2008-04-14T12:39:06,299 INFO  [00000003] Perf.ARM.SAS.APPL 
        (tka_api.c:1927) - END SAS 13eec00 E,1523810346.300000,
        1,0.484375,1.015625
2008-04-14T12:39:06,378 DEBUG [00000000] Logging.Appender.Boot 
        (tk4aboot.c:228) - Destroying Boot appender <2008-04-14T12:39:06,
        378 DEBUG [00000000] Logging.Appender.ARM (tk4aarm4.c:797) - 
        Destroying ARMAppender ARM
2008-04-14T12:39:06,378 DEBUG [00000000] Logging.Appender.File 
        (tk4afile.c:562) - Destroying FileAppender ARM2LOG
2008-04-14T12:39:06,378 DEBUG [00000000] Logging.Appender.File (tk4afile.c:562)
- 
        Destroying FileAppender ARM4LOG