Java > Open Source Codes > org > netbeans > modules > j2ee > jboss4 > ide > JBLogWriter


1 /*
2  * The contents of this file are subject to the terms of the Common Development
3  * and Distribution License (the License). You may not use this file except in
4  * compliance with the License.
5  *
6  * You can obtain a copy of the License at http://www.netbeans.org/cddl.html
7  * or http://www.netbeans.org/cddl.txt.
8  *
9  * When distributing Covered Code, include this CDDL Header Notice in each file
10  * and include the License file at http://www.netbeans.org/cddl.txt.
11  * If applicable, add the following below the CDDL Header, with the fields
12  * enclosed by brackets [] replaced by your own identifying information:
13  * "Portions Copyrighted [year] [name of copyright owner]"
14  *
15  * The Original Software is NetBeans. The Initial Developer of the Original
16  * Software is Sun Microsystems, Inc. Portions Copyright 1997-2006 Sun
17  * Microsystems, Inc. All Rights Reserved.
18  */
19 package org.netbeans.modules.j2ee.jboss4.ide;
20
21
22 import java.io.BufferedReader ;
23 import java.io.File ;
24 import java.io.FileNotFoundException ;
25 import java.io.FileReader ;
26 import java.io.IOException ;
27 import java.io.InputStreamReader ;
28 import java.util.HashMap ;
29 import javax.enterprise.deploy.shared.ActionType ;
30 import javax.enterprise.deploy.shared.CommandType ;
31 import javax.enterprise.deploy.shared.StateType ;
32 import org.netbeans.modules.j2ee.deployment.profiler.api.ProfilerSupport;
33 import org.openide.ErrorManager;
34 import org.openide.util.NbBundle;
35 import org.openide.util.RequestProcessor;
36 import org.openide.util.RequestProcessor.Task;
37 import org.openide.windows.InputOutput;
38 import org.openide.windows.OutputWriter;
39
40 /**
41  *
42  * @author Libor Kotouc
43  */
44 public final class JBLogWriter {
45     
46     public static final boolean VERBOSE =
47         System.getProperty ("netbeans.serverplugins.jboss4.logging") != null;
48     
49     private final static int DELAY = 500;
50     private static final int START_TIMEOUT = 900000;
51     
52     /**
53      * Lock used to avoid a reader switching while the reader is used
54      */
55     private final Object READER_LOCK = new Object ();
56
57     /**
58      * Lock used for synchronizing a server startup thread and
59      * a logger thread checking for the server to start
60      */
61     private final Object START_LOCK = new Object ();
62     
63     //enumeration of the source types the reader can read from
64 private static enum LOGGER_TYPE { PROCESS, FILE };
65     
66     //indicates the type of source the reader is reading from
67 private LOGGER_TYPE type;
68
69     private static final String THREAD_NAME = "JBoss Log Writer"; // NOI18N
70 private static final String STOPPER_THREAD_NAME = "JBoss Log Writer Stopper"; //NOI18N
71
72     private JBStartServer.ACTION_STATUS actionStatus = JBStartServer.ACTION_STATUS.UNKNOWN;
73
74     JBStartServer startServer;
75             
76     //output pane's writer
77 private final OutputWriter out;
78     //server output reader
79 volatile private BufferedReader reader;
80     //server instance name
81 private final String instanceName;
82     //server process
83 private Process process;
84     //server log file
85 private File logFile;
86     
87     //the thread currently reading from the server output and writing into the output pane.
88 //there is at most one thread for one JBLogWriter instance (i.e. for each server instance running)
89 Thread logWriterThread;
90     
91     //stores the JBLogWriter instance for each server instance for which the server output has been shown
92 private static HashMap <String , JBLogWriter> instances = new HashMap <String , JBLogWriter>();
93     
94     //the log writer sets the value to true to indicate that it is running
95 //it can be used to stop the log writer thread when it is set to false
96 private boolean read;
97     
98     //used to remember the last part of the output read from the server process
99 //the part is used in the subsequent reading as the beginning of the line, see the issue #81951
100 private String trailingLine = "";
101     
102     
103     private JBLogWriter(InputOutput io, String instanceName) {
104         this.out = (io != null ? io.getOut() : null);
105         this.instanceName = instanceName;
106     }
107     
108     synchronized public static JBLogWriter createInstance(InputOutput io, String instanceName) {
109         JBLogWriter instance = getInstance(instanceName);
110         if (instance == null) {
111             instance = new JBLogWriter(io, instanceName);
112             instances.put(instanceName, instance);
113         }
114         return instance;
115     }
116     
117     synchronized public static JBLogWriter getInstance(String instanceName) {
118         return instances.get(instanceName);
119     }
120
121     /**
122      * Starts reading of the server log file and writing its content into the output console
123      */
124     public void start(File logFile) {
125         try {
126             this.logFile = logFile;
127             this.reader = new BufferedReader (new FileReader (logFile));
128         } catch (FileNotFoundException ioe) {
129             ErrorManager.getDefault().notify(ErrorManager.INFORMATIONAL, ioe);
130         }
131         
132         //start the logging thread
133 startWriter(new LineProcessor() {
134             //only lines with the 'INFO' level severity are written into the output pane
135 public void processLine(String line) {
136                 if (out != null) {
137                     if (line != null && line.indexOf(" INFO ") != -1) {
138                         out.println(line);
139                     }
140                 }
141             }
142         }, LOGGER_TYPE.FILE);
143     }
144     
145     /**
146      * Starts reading data piped from standard output stream of the server process.
147      * It is expected that the this method is called during the server startup. The startup progress
148      * is currently done by checking the outgoing messages for some keywords occurence.
149      *
150      * The calling thread is blocked waiting until it is notified when the server startup has finished.
151      *
152      * @return true when the server startup was succesfull, false otherwise
153      */
154     JBStartServer.ACTION_STATUS start(Process process, final JBStartServer startServer) {
155         this.process = process;
156         this.startServer = startServer;
157         this.reader = new BufferedReader (new InputStreamReader (process.getInputStream()));
158         
159         //start the logging thread
160 startWriter(new LineProcessor() {
161             
162             //flag saying whether the the startup progress must be checked or not
163 //it is set to false after the server is started or if the server startup is not successfull
164 private boolean checkStartProgress = true;
165
166             public void processLine(String line) {
167                 //all lines are written to the output pane
168 if (line != null) {
169                     if (out != null) {
170                         out.println(line);
171                     }
172                     if (checkStartProgress) {
173                         checkStartProgress(line);
174                     }
175                 }
176             }
177             
178             /**
179              * Fires the progress events when the server startup process begins and finishes
180              * (either sucessfully or not)
181              */
182             private void checkStartProgress(String line) {
183
184                 if (line.indexOf("Starting JBoss (MX MicroKernel)") > -1 || // JBoss 4.x message // NOI18N
185 line.indexOf("Starting JBoss (Microcontainer)") > -1) // JBoss 5.0 message // NOI18N
186 {
187                     if (VERBOSE) {
188                         System.out.println("STARTING message fired"); // NOI18N
189 }
190                     fireStartProgressEvent(StateType.RUNNING, createProgressMessage("MSG_START_SERVER_IN_PROGRESS")); // NOI18N
191 }
192                 else
193                 if ((line.indexOf("JBoss (MX MicroKernel)") > -1 || // JBoss 4.x message // NOI18N
194 line.indexOf("JBoss (Microcontainer)") > -1) && // JBoss 5.0 message // NOI18N
195 line.indexOf("Started in") > -1) // NOI18N
196 {
197                     if (VERBOSE) {
198                         System.out.println("STARTED message fired"); // NOI18N
199 }
200                     checkStartProgress = false;
201                     actionStatus = JBStartServer.ACTION_STATUS.SUCCESS;
202                     notifyStartupThread();
203                 }
204                 else
205                 if (line.indexOf("Shutdown complete") > -1) { // NOI18N
206 checkStartProgress = false;
207                     actionStatus = JBStartServer.ACTION_STATUS.FAILURE;
208                     notifyStartupThread();
209                 }
210             }
211             
212         }, LOGGER_TYPE.PROCESS);
213         
214         try {
215             synchronized (START_LOCK) {
216                 long start = System.currentTimeMillis();
217                 //the calling thread is blocked until the server startup has finished or START_TIMEOUT millis has elapsed
218 START_LOCK.wait(START_TIMEOUT);
219                 if (System.currentTimeMillis() - start >= START_TIMEOUT) {
220                     if (VERBOSE) {
221                         System.out.println("Startup thread TIMEOUT EXPIRED");
222                     }
223                     actionStatus = JBStartServer.ACTION_STATUS.UNKNOWN;
224                 }
225                 else {
226                     if (VERBOSE) {
227                         System.out.println("Startup thread NOTIFIED");
228                     }
229                 }
230             }
231         } catch (InterruptedException ex) {
232             //noop
233 }
234         
235         return actionStatus;
236     }
237
238     private void notifyStartupThread() {
239         synchronized (START_LOCK) {
240             START_LOCK.notify();
241         }
242     }
243
244     private void fireStartProgressEvent(StateType stateType, String msg) {
245         startServer.fireHandleProgressEvent(null, new JBDeploymentStatus(ActionType.EXECUTE, CommandType.START, stateType, msg));
246     }
247     
248     private String createProgressMessage(final String resName) {
249         return NbBundle.getMessage(JBLogWriter.class, resName, instanceName);
250     }
251     
252     /**
253      * Common interface for processing the line read from the server output
254      */
255     private interface LineProcessor {
256         void processLine(String line);
257     }
258     
259     /**
260      * Starts the log writer thread. If the old thread is still running then the old thread is interrupted.
261      * The old thread is running when is of LOGGER_TYPE.FILE type and the server is stopped outside of the IDE
262      * because there is no way how to check the server process status when we don't have access to the server process.
263      *
264      * The thread reading from the server process (LOGGER_TYPE.PROCESS type) is periodically checking
265      * the server process exit value and finishes when the server process has exited.
266      *
267      * The thread reading from the server log file periodically checks the server log file size to ensure that
268      * the input stream is valid, i.e. reading from the same file as the server process log file.
269      * JBoss seems to be deleting the log file upon each start thus the file reader is never ready for the reading
270      * although the server process is running and logging. Resetting the reader doesn't help thus closing the old one
271      * and creating of a new one is needed.
272      *
273      * The method is also responsible for the correct switching between the threads with different LOGGER_TYPE
274      */
275     private void startWriter(final LineProcessor lineProcessor, final LOGGER_TYPE type) {
276         
277         if (isRunning()) {
278             //logger reading the log file is not stopped when the server is stopped outside of the IDE
279 logWriterThread.interrupt();
280             if (VERBOSE) {
281                 System.out.println("************INTERRUPT thread " + logWriterThread.getId());
282             }
283         }
284         
285         this.type = type;
286         
287         logWriterThread = new Thread (THREAD_NAME) {
288             public void run() {
289                 if (VERBOSE) {
290                     System.out.println("************START thread " + Thread.currentThread().getId());
291                 }
292                 read = true;
293                 boolean interrupted = false;
294                 long lastFileSize = -1;
295                 boolean checkProfiler = (startServer != null && startServer.getMode() == JBStartServer.MODE.PROFILE);
296                 while (read) {
297                     // if in profiling mode, server startup (incl. blocked for Profiler direct attach)
298 // is checked by determining Profiler agent status using ProfilerSupport.getState()
299 // STATE_INACTIVE means that Profiler agent failed to start, which also breaks server VM
300 if (checkProfiler) {
301                         int state = ProfilerSupport.getState();
302                         if (state == ProfilerSupport.STATE_BLOCKING ||
303                             state == ProfilerSupport.STATE_RUNNING ||
304                             state == ProfilerSupport.STATE_PROFILING) {
305                             fireStartProgressEvent(StateType.COMPLETED, createProgressMessage("MSG_PROFILED_SERVER_STARTED"));
306                             checkProfiler = false;
307                             notifyStartupThread();
308                         }
309                         else
310                         if (state == ProfilerSupport.STATE_INACTIVE) {
311                             fireStartProgressEvent(StateType.FAILED, createProgressMessage("MSG_START_PROFILED_SERVER_FAILED"));
312                             process.destroy();
313                             notifyStartupThread();
314                             break;
315                         }
316                     }
317
318                     boolean ready = processInput(lineProcessor, type);
319                     if (type == LOGGER_TYPE.FILE) {
320                         if (ready) { // some input was read, remember the file size
321 lastFileSize = logFile.length();
322                         }
323                         // nothing was read, compare the current file size with the remembered one
324 else if (lastFileSize != logFile.length()) {
325                             // file size has changed nevertheless there is nothing to read -> refresh needed
326 if (VERBOSE) {
327                                 System.out.println("!!!!!!!!!DIFFERENCE found");
328                             }
329                             refresh();
330                         }
331                     }
332                     else {
333                         try {
334                             process.exitValue();
335                             //reaching this line means that the process already exited
336 break;
337                         }
338                         catch (IllegalThreadStateException itse) {
339                             //noop process has not exited yet
340 }
341                     }
342                     try {
343                         Thread.sleep(DELAY); // give the server some time to write the output
344 } catch (InterruptedException e) {
345                         interrupted = true;
346                         break;
347                     }
348                 }
349                 
350                 //print the remaining message from the server process after it has stopped, see the issue #81951
351 lineProcessor.processLine(trailingLine);
352                 
353                 if (VERBOSE) {
354                     System.out.println("************FINISH thread " + Thread.currentThread().getId());
355                 }
356                 if (!interrupted) {
357                     //reset the read flag and remove instance from the map when the thread exiting is 'natural',
358 //i.e. caused by a server process exiting or by calling stop() on the instance.
359 //the thread interruption means that another thread is going to start execution
360 read = false;
361                     instances.remove(instanceName);
362                 }
363             }
364         };
365         logWriterThread.start();
366         
367     }
368     
369     /**
370      * Sets the read flag to false to announce running thread that is must stop running.
371      */
372     void stop() {
373         read = false;
374     }
375     
376     boolean isRunning(){
377         return read;
378     }
379
380     /**
381      * If the logger is of type FILE then closes the current reader, resets the output pane
382      * and creates new input reader.
383      */
384     public void refresh() {
385         if (type == LOGGER_TYPE.PROCESS || logFile == null) {
386             return;
387         }
388
389         synchronized (READER_LOCK) {
390             if (reader != null) {
391                 try {
392                     reader.close();
393                 } catch (IOException e) {
394                     ErrorManager.getDefault().notify(ErrorManager.INFORMATIONAL, e);
395                 }
396             }
397             try {
398                 if (out != null) {
399                     out.reset();
400                 }
401                 if (VERBOSE) {
402                     System.out.println("REFRESHING the output pane");
403                 }
404                 reader = new BufferedReader (new FileReader (logFile));
405             } catch (IOException e) {
406                 ErrorManager.getDefault().notify(ErrorManager.INFORMATIONAL, e);
407             }
408         }
409     }
410     
411     /**
412      * The method is reading the lines from the reader until no input is avalable.
413      * @return true if at least one line was available on the input, false otherwise
414      */
415     private boolean processInput(LineProcessor lineProcessor, final LOGGER_TYPE type) {
416         synchronized (READER_LOCK) {
417             boolean ready = false;
418             try {
419                 if (type == LOGGER_TYPE.PROCESS) {
420                     while (reader.ready()) {
421                         //reader.readLine() was hanging on Windows, thus replaced by own readLine() method
422 //see issue #81951
423 ready = readLine(lineProcessor);
424                     }
425                 }
426                 else {
427                     while (reader.ready()) {
428                         String line = reader.readLine();
429                         lineProcessor.processLine(line);
430                         ready = true;
431                     }
432                 }
433             } catch (IOException e) {
434                 ErrorManager.getDefault().notify(ErrorManager.INFORMATIONAL, e);
435             }
436             return ready;
437         }
438     }
439     
440     /**
441      * According to the issue #81951, the BefferedReader.read() method must be used
442      * instead of the BefferedReader.readLine() method, otherwise it hangs on Windows
443      * in the underlying native method call after the server process has been stopped.
444      * On Linux the BefferedReader.readLine() method correctly returns.
445      *
446      * Parsing is done manually to simulate behavior of the BefferedReader.readLine() method.
447      * According to this, a line is considered to be terminated by any one
448      * of a line feed ('\n'), a carriage return ('\r'), or a carriage return
449      * followed immediately by a line feed.
450      *
451      * The method is processing each line read using the given LineProcessor. The remaining text
452      * (following the last line) is remembered for the next reading in the instance variable.
453      *
454      * The method is not able to discover whether there will be some additional reading or not, thus
455      * theoretically there are several events when the remaining text might not be processed.
456      * The first kind of event is when the server process has been started or some other event has occured
457      * (e.g. deploying) which causes the server process to log but not to stop.
458      * It is not possible to discover that no other input will be read and if the last logged line
459      * is not ended by the 'new-line' character(s) then the remaing text is printed out not until
460      * the next input is read.
461      * The second kind of event is when the server process has been stopped. The log writer thread
462      * is finished in this case and has opportunity to write out the remaing text.
463      * Actually it seems that the JBoss server is logging the whole lines only so the reading is working well
464      * in all cases.
465      */
466     private boolean readLine(LineProcessor lineProcessor) throws IOException {
467         char[] cbuf = new char[128];
468         int size = -1;
469         if ((size = reader.read(cbuf)) != -1) {
470             //prepend the text from the last reading to the text actually read
471 String lines = (trailingLine != null ? trailingLine : "");
472             lines += new String (cbuf, 0, size);
473             int tlLength = (trailingLine != null ? trailingLine.length() : 0);
474             int start = 0;
475             for (int i = 0; i < size; i++) {//going through the text read and searching for the new line
476 //we see '\n' or '\r', *not* '\r\n'
477 if (cbuf[i] == '\r' && (i+1 == size || cbuf[i+1] != '\n') || cbuf[i] == '\n') {
478                     String line = lines.substring(start, tlLength + i);
479                     //move start to the character right after the new line
480 start = tlLength + (i + 1);
481                     lineProcessor.processLine(line);
482                 }
483                 else //we see '\r\n'
484 if (cbuf[i] == '\r' && (i+1 < size) && cbuf[i+1] == '\n') {
485                     String line = lines.substring(start, tlLength + i);
486                     //skip the '\n' character
487 i += 1;
488                     //move start to the character right after the new line
489 start = tlLength + (i + 1);
490                     lineProcessor.processLine(line);
491                 }
492             }
493             if (start < lines.length()) {
494                 //new line was not found at the end of the input, the remaing text is stored for the next reading
495 trailingLine = lines.substring(start);
496             }
497             else {
498                 //null and not empty string to indicate that there is no valid input to write out;
499 //an empty string means that a new line character may be written out according
500 //to the LineProcessor implementation
501 trailingLine = null;
502             }
503             return true;
504         }
505         return false;
506     }
507     
508     /**
509      * The method is used to either for blocking a caller until the server process has exited
510      * (when the logger is of PROCESS type) or sleeps some piece of time to allow the logging thread
511      * to finish its work.
512      * After returning from this call the caller may expect that no other input is going to be read
513      * and is safe to stop the logger by calling stop() method.
514      *
515      * @param milliseconds the time the caller is blocked waiting for the server process to exit,
516      * otherwise the waiting is terminated. It may help when the process has not exited exists
517      * in some non-defined state
518      */
519     void waitForServerProcessFinished(long milliseconds) {
520         Task t = new RequestProcessor(STOPPER_THREAD_NAME, 1, true).post(new Runnable () {
521             public void run() {
522                 try {
523                     if (VERBOSE) {
524                         System.out.println(STOPPER_THREAD_NAME + ": WAITING for the server process to stop");
525                     }
526                     if (type == LOGGER_TYPE.PROCESS) {
527                         process.waitFor();
528                     }
529                     else {
530                         Thread.sleep(2000);
531                     }
532                 } catch (InterruptedException ex) {
533                     //noop
534 }
535             }
536         });
537         try {
538             t.waitFinished(milliseconds);
539         } catch (InterruptedException ex) {
540             //noop
541 }
542         finally {
543             t.cancel();
544         }
545     }
546  
547 }
548

A to Z: JavaDoc & Examples

---

Daily Java News & Articles

---

Open Source Projects

---

Open Source Codes

---

Free Computer Books

---

Remove Frame

---

Popular Tags