001: /*
002:
003: Derby - Class org.apache.derby.diag.StatementDuration
004:
005: Licensed to the Apache Software Foundation (ASF) under one or more
006: contributor license agreements. See the NOTICE file distributed with
007: this work for additional information regarding copyright ownership.
008: The ASF licenses this file to You under the Apache License, Version 2.0
009: (the "License"); you may not use this file except in compliance with
010: the License. You may obtain a copy of the License at
011:
012: http://www.apache.org/licenses/LICENSE-2.0
013:
014: Unless required by applicable law or agreed to in writing, software
015: distributed under the License is distributed on an "AS IS" BASIS,
016: WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
017: See the License for the specific language governing permissions and
018: limitations under the License.
019:
020: */
021:
022: package org.apache.derby.diag;
023:
024: import java.io.BufferedReader;
025: import java.io.FileNotFoundException;
026: import java.io.InputStream;
027: import java.io.InputStreamReader;
028: import java.io.FileInputStream;
029:
030: import java.util.Hashtable;
031: import java.util.Enumeration;
032: import java.util.Properties;
033: import java.sql.ResultSetMetaData;
034: import java.sql.SQLException;
035: import java.sql.Timestamp;
036: import java.sql.Types;
037: import org.apache.derby.vti.VTITemplate;
038: import org.apache.derby.iapi.sql.ResultColumnDescriptor;
039: import org.apache.derby.impl.jdbc.EmbedResultSetMetaData;
040: import org.apache.derby.iapi.reference.Limits;
041: import org.apache.derby.iapi.util.StringUtil;
042:
043: /**
044:
045:
046: StatementDuration is a virtual table which
047: can be used to analyze the execution duration of the statements
048: of "interest" in db2j.<!-- -->log or a specified file when
049: db2j.<!-- -->language.<!-- -->logStatementText=true.
050:
051:
052: <P>A limitation is that, for each transaction ID,
053: a row will not be returned for the last statement with that
054: transaction id. (Transaction IDs change within a connection after
055: a commit or rollback, if the transaction that just ended modified data.)
056:
057: <P>The execution duration is the time between the beginning of
058: execution of two successive statements. There are a number of reasons
059: why this time may not be accurate. The duration could include time
060: spent in the application waiting for user input, doing other work, etc.
061: It may also only include a portion of the actual execution time, if
062: the application executes a new statement before draining the previous
063: open ResultSet. StatementDuration can be used to get a rough sense of
064: where the bottlenecks in an application's JDBC code are.
065:
066: <P>The StatementDuration virtual table has the following columns:
067: <UL><LI>TS varchar(26) - not nullable. The timestamp of the statement.</LI>
068: <LI>THREADID varchar(80) - not nullable. The thread name.</LI>
069: <LI>XID varchar(15) - not nullable. The transaction ID.</LI>
070: <LI>LOGTEXT long varchar - nullable. Text of the statement or commit or rollback.</LI>
071: <LI>DURATION varchar(10) - not nullable. Duration, in milliseconds, of the statement.</LI>
072: </UL>
073:
074: */
075: public class StatementDuration extends VTITemplate {
076: /*
077: ** private
078: */
079: private boolean gotFile;
080: private InputStreamReader inputFileStreamReader;
081: private InputStream inputStream;
082: private BufferedReader bufferedReader;
083: private String inputFileName;
084: private Hashtable hashTable;
085:
086: // Variables for current row
087: private String line;
088: private int gmtIndex;
089: private int threadIndex;
090: private int xidIndex;
091: private int lccidIndex;
092: private String[] currentRow;
093:
094: private static final String GMT_STRING = " GMT";
095: private static final String BEGIN_THREAD_STRING = "[";
096: private static final String END_THREAD_STRING = "]";
097: private static final String BEGIN_XID_STRING = "= ";
098: private static final String END_XID_STRING = ")";
099: private static final String BEGIN_EXECUTING_STRING = "Executing prepared";
100: private static final String END_EXECUTING_STRING = " :End prepared";
101:
102: /**
103: StatementDuration() accesses the error log in
104: derby.system.home, if set, otherwise it looks in the current directory.
105: StatementDuration('filename') will access the specified
106: file name.
107: */
108: public StatementDuration() {
109: String home = System.getProperty("derby.system.home");
110:
111: inputFileName = "derby.log";
112:
113: if (home != null) {
114: inputFileName = home + "/" + inputFileName;
115: }
116: }
117:
118: public StatementDuration(String inputFileName) {
119: this .inputFileName = inputFileName;
120: }
121:
122: /**
123: @see java.sql.ResultSet#getMetaData
124: */
125: public ResultSetMetaData getMetaData() {
126: return metadata;
127: }
128:
129: /**
130: @see java.sql.ResultSet#next
131: @exception SQLException If database access error occurs.
132: */
133: public boolean next() throws SQLException {
134: if (!gotFile) {
135: gotFile = true;
136: try {
137: inputFileStreamReader = new InputStreamReader(
138: new FileInputStream(inputFileName));
139: bufferedReader = new BufferedReader(
140: inputFileStreamReader, 32 * 1024);
141: } catch (FileNotFoundException ex) {
142: throw new SQLException(ex.getMessage());
143: }
144:
145: hashTable = new Hashtable();
146: }
147:
148: while (true) {
149: try {
150: line = bufferedReader.readLine();
151: } catch (java.io.IOException ioe) {
152: throw new SQLException(ioe.getMessage());
153: }
154:
155: if (line == null) {
156: return false;
157: }
158:
159: gmtIndex = line.indexOf(GMT_STRING);
160: threadIndex = line.indexOf(BEGIN_THREAD_STRING);
161: xidIndex = line.indexOf(BEGIN_XID_STRING);
162: lccidIndex = line.indexOf(BEGIN_XID_STRING, xidIndex + 1);
163:
164: if (gmtIndex != -1 && threadIndex != -1) {
165: /* Build a row */
166: String[] newRow = new String[6];
167: for (int index = 1; index <= 5; index++) {
168: newRow[index - 1] = setupColumn(index);
169: }
170:
171: /* NOTE: We need to use the LCCID as the key
172: */
173: Object previousRow = hashTable.put(newRow[3], newRow);
174: if (previousRow == null) {
175: continue;
176: }
177:
178: currentRow = (String[]) previousRow;
179:
180: /* Figure out the duration. */
181: Timestamp endTs = Timestamp.valueOf(newRow[0]);
182: long end = endTs.getTime() + endTs.getNanos() / 1000000;
183: Timestamp startTs = Timestamp.valueOf(currentRow[0]);
184: long start = startTs.getTime() + startTs.getNanos()
185: / 1000000;
186: currentRow[5] = Long.toString(end - start);
187:
188: return true;
189: }
190: }
191: }
192:
193: /**
194: @see java.sql.ResultSet#close
195: */
196: public void close() {
197: if (bufferedReader != null) {
198: try {
199: bufferedReader.close();
200: inputFileStreamReader.close();
201: } catch (java.io.IOException ioe) {
202: // eat exceptions during close;
203: } finally {
204: bufferedReader = null;
205: inputFileStreamReader = null;
206: }
207: }
208: }
209:
210: /**
211: All columns in StatementDuration VTI have String data types.
212: @see java.sql.ResultSet#getString
213: @exception SQLException If database access error occurs.
214: */
215: public String getString(int columnNumber) throws SQLException {
216: return currentRow[columnNumber - 1];
217: }
218:
219: private String setupColumn(int columnNumber) throws SQLException {
220: switch (columnNumber) {
221: case 1:
222: return line.substring(0, gmtIndex);
223:
224: case 2:
225: return line.substring(threadIndex + 1, line
226: .indexOf(END_THREAD_STRING));
227:
228: case 3:
229: return line.substring(xidIndex + 2, line.indexOf(
230: END_XID_STRING, xidIndex));
231:
232: case 4:
233: return line.substring(lccidIndex + 2, line.indexOf(
234: END_XID_STRING, lccidIndex));
235:
236: case 5:
237: /* Executing prepared statement is a special case as
238: * it could span multiple lines
239: */
240: String output;
241: if (line.indexOf(BEGIN_EXECUTING_STRING) == -1) {
242: output = line.substring(line.indexOf(END_XID_STRING,
243: lccidIndex) + 3);
244: } else {
245:
246: /* We need to build string until we find the end of the text */
247: int endIndex = line.indexOf(END_EXECUTING_STRING,
248: lccidIndex);
249: if (endIndex == -1) {
250: output = line.substring(line.indexOf(
251: END_XID_STRING, lccidIndex) + 3);
252: } else {
253: output = line.substring(line.indexOf(
254: END_XID_STRING, lccidIndex) + 3, endIndex);
255: }
256:
257: while (endIndex == -1) {
258: try {
259: line = bufferedReader.readLine();
260: } catch (java.io.IOException ioe) {
261: throw new SQLException("Error reading file "
262: + ioe);
263: }
264: endIndex = line.indexOf(END_EXECUTING_STRING);
265: if (endIndex == -1) {
266: output = output + line;
267: } else {
268: output = output + line.substring(0, endIndex);
269: }
270: }
271: }
272:
273: output = StringUtil.truncate(output,
274: Limits.DB2_VARCHAR_MAXWIDTH);
275:
276: return output;
277:
278: default:
279: return null;
280: }
281: }
282:
283: /**
284: @see java.sql.ResultSet#wasNull
285: */
286: public boolean wasNull() {
287: return false;
288: }
289:
290: /*
291: ** Metadata
292: */
293: private static final ResultColumnDescriptor[] columnInfo = {
294:
295: EmbedResultSetMetaData.getResultColumnDescriptor("TS",
296: Types.VARCHAR, false, 26),
297: EmbedResultSetMetaData.getResultColumnDescriptor(
298: "THREADID", Types.VARCHAR, false, 80),
299: EmbedResultSetMetaData.getResultColumnDescriptor("XID",
300: Types.VARCHAR, false, 15),
301: EmbedResultSetMetaData.getResultColumnDescriptor("LCCID",
302: Types.VARCHAR, false, 10),
303: EmbedResultSetMetaData.getResultColumnDescriptor("LOGTEXT",
304: Types.VARCHAR, true, Limits.DB2_VARCHAR_MAXWIDTH),
305: EmbedResultSetMetaData.getResultColumnDescriptor(
306: "DURATION", Types.VARCHAR, false, 10), };
307:
308: private static final ResultSetMetaData metadata = new EmbedResultSetMetaData(
309: columnInfo);
310: }
|