| ARM Interface and SAS Logging Facility |
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.2 (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 seconds2008-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
 |
|
Copyright © 2010 by SAS Institute Inc., Cary, NC, USA. All rights reserved.