Uploaded image for project: 'Code Tools'
  1. Code Tools
  2. CODETOOLS-7903470

jtreg AgentServer log() does not flush

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Fixed
    • Icon: P4 P4
    • jtreg7.3
    • None
    • tools
    • None

      The code in AgentServer.java is responsible for controlling the agents executing actual tests. When created, AgentServers are passed a logFile to write their log output to. These files are usually called "agentServer.$ID.trace" where $ID is the id of the agent. The contents of these files can be important in troubleshooting issues with jtreg itself, especially when unusual error conditions cause the execution of jtreg testing to fail somehow, or when there are issues in the communication between jtreg and its agents.

      Agents log to their log files with the log() method in AgentServer.java.
      log() calls logWriter.printf(), where logWriter is an instance of PrintWriter initialized with
        pw = new PrintWriter(new FileWriter(logFile));
      According to the PrintWriter documentation, this way of constructing it leaves auto-flushing disabled by default. This in turn means that calls to printf() are NOT guaranteed to flush the output, but might instead buffer it for quite some time.

      I've also observed this experimentally. When running a passing test, a normal agent.2.trace contains for example:

      [2023-05-08 13:56:04,031] AgentServer[2]: Started
      [2023-05-08 13:56:04,048] AgentServer[2]: Listening on port 35677
      [2023-05-08 13:56:04,091] AgentServer[2]: Running
      [2023-05-08 13:56:04,093] AgentServer[2]: Test.java: starting execution of Test
      [2023-05-08 13:56:04,162] AgentServer[2]: Test.java: finished execution of Test
      [2023-05-08 13:56:04,195] AgentServer[2]: Exiting
       
      Now, if the test instead sleeps indefinitely, and we kill jtreg a few seconds into the sleeping, we want to see the following:
       
      [2023-05-08 13:56:04,031] AgentServer[2]: Started
      [2023-05-08 13:56:04,048] AgentServer[2]: Listening on port 35677
      [2023-05-08 13:56:04,091] AgentServer[2]: Running
      [2023-05-08 13:56:04,093] AgentServer[2]: Test.java: starting execution of Test
       
       However, instead agent.2.trace is just empty.
      I've built jtreg myself, added a "flush()" call, and run the above experiment again, and this time agent.2.trace does contain all the output logged up to that point as it should be.

      So I'm proposing to add a "flush()" call to log() in AgentServer.java.

            lujaniuk Ludvig Janiuk
            lujaniuk Ludvig Janiuk
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: