sikuli-driver team mailing list archive

Thread
Date
[Bug 810754] Re: X-1.0rc2: IDE: crashes on rerun when using logging module

To: sikuli-driver@xxxxxxxxxxxxxxxxxxx
From: RaiMan <rmhdevelop@xxxxxx>
Date: Fri, 15 Jul 2011 08:16:14 -0000
Reply-to: Bug 810754 <810754@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Description changed:

+ *** Windows and Mac
+ (even for rc3 and Jython 2.5.2)
+ 
+ When rerunning a script in the IDE that uses the Python logging feature,
+ the script terminates with ...sikuli-
+ script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O
+ operation on closed file
+ 
+ Running the script from command line works, since at rerun we have a
+ clean startup.
+ 
+ ----------------------------------------------------------------
+ 
  I am developing a test infrastructure and want a library to setup logging to a file.
- In Sikuli, I created a script with the code below.  Every time I test my module within the IDE, the specified log file 
+ In Sikuli, I created a script with the code below.  Every time I test my module within the IDE, the specified log file
  gets updated, but the Sikuli IDE goes away, and I have one more "javaw.exe" running on the system
  
  - use code below to create TestLogging.sikuli in the IDE
  - Change pathname to be valid on your host
  - Run in the IDE
  
  # Module to set up logging and reporting
  import os
  import logging
  
  TestLog = 0
  
  def setupLogging(path, debug = 0):
- 	global TestLog
+  global TestLog
  
- 	if debug:
- 		levelLog = logging.DEBUG
- 	else:
- 		levelLog = logging.INFO
- 	logging.basicConfig(filename=path,level=levelLog)
- 	TestLog = logging.getLogger()
+  if debug:
+   levelLog = logging.DEBUG
+  else:
+   levelLog = logging.INFO
+  logging.basicConfig(filename=path,level=levelLog)
+  TestLog = logging.getLogger()
  
  if __name__ == "__main__":
- 	setupLogging("C:\\Users\\bgriffin.AMD\\TestLog", debug=1)
+  setupLogging("C:\\Users\\bgriffin.AMD\\TestLog", debug=1)
  
- 	TestLog.error("Test Error Log")
- 	TestLog.warning("Test Warning Log")
- 	TestLog.info("Test Info Log")
- 	TestLog.debug("Test Debug Log")
+  TestLog.error("Test Error Log")
+  TestLog.warning("Test Warning Log")
+  TestLog.info("Test Info Log")
+  TestLog.debug("Test Debug Log")
  
  When I import my module into a different script, I see different
  behavior in the IDE between runs.  The first run appears to work fine,
  with messages going to the IDE Message window until I configure the log
  file.  The logfile only contains my explicit messages.  After editing
  the script below to configure a different log level, I get error
  messages in the IDE message window unrelated to my script (which runs
  fine).  I have the script first, then the Message window text.
  
  - Create VisualStudioIDE.sikuli from the code below
  - you may need to modify sys.path depending on where you created TestLogging.sikuli
  - change pathnames to be valid on your host
  - Run in IDE
  - Edit script, adding ", debug=1" to the setupLogging() call.
  - Run
  - DO NOT EXIT IDE IN BETWEEN RUNS
  
  # Start Visual Studio using command line or a solution
  import os
  from sikuli.Sikuli import *
  import subprocess
  myPath = os.path.dirname(getBundlePath())
  myParent = os.path.dirname(myPath)
  if not myPath in sys.path: sys.path.append(myPath)
  if not myParent in sys.path: sys.path.append(myParent)
  import TestLogging # name for module with above code
  
  VISUAL_STUDIO_IDE = "C:\\Program Files (x86)\\Microsoft Visual Studio 10.0\\Common7\\IDE\\devenv.exe"
  VSApp = 0
  
+ def startVisualStudio(solution = 0):
+  global VSApp
+  VSApp = App(VISUAL_STUDIO_IDE)
+  VSApp.open()
+  wait(10) # wait for the process to start up
  
- def startVisualStudio(solution = 0):
- 	global VSApp
- 	VSApp = App(VISUAL_STUDIO_IDE)
- 	VSApp.open()
- 	wait(10) # wait for the process to start up
+  if not VSApp:
+   # add logging of failure
+   TestLogging.TestLog.error("Unable to start Microsoft Visual Studio")
+   TestLogging.TestLog.error("Executable: " + VISUAL_STUDIO_IDE)
+   return 0
+  VSApp.focus( "Start Page - Microsoft Visual Studio" )
  
- 	if not VSApp:
- 		# add logging of failure
- 		TestLogging.TestLog.error("Unable to start Microsoft Visual Studio")
- 		TestLogging.TestLog.error("Executable: " + VISUAL_STUDIO_IDE)
- 		return 0
- 	VSApp.focus( "Start Page - Microsoft Visual Studio" )
+  if solution:
+   type("o", KEY_CTRL)
+   wait(2)
+   type(solution)
+   type("\n")
  
- 	if solution:
- 		type("o", KEY_CTRL)
- 		wait(2)
- 		type(solution)
- 		type("\n")
- 
-         return 1
+  return 1
  
  def closeVisualStudio():
- 	global VSApp
- 	if VSApp:
- 		VSApp.close()
- 		VSApp = 0
- 	else:
- 		TestLogging.TestLog.warning("Visual Studio not running.")
+  global VSApp
+  if VSApp:
+   VSApp.close()
+   VSApp = 0
+  else:
+   TestLogging.TestLog.warning("Visual Studio not running.")
  
  def captureVisualStudio():
- 	global VSApp
- 	vsImage = 0
- 	if VSApp:
- 		vs = VSApp.focusedWindow()
- 		vsImage = capture(vs)
- 	else:
- 		TestLogging.TestLog.debug("Visual Studio not running?")
- 	return vsImage
+  global VSApp
+  vsImage = 0
+  if VSApp:
+   vs = VSApp.focusedWindow()
+   vsImage = capture(vs)
+  else:
+   TestLogging.TestLog.debug("Visual Studio not running?")
+  return vsImage
  
  if __name__ == "__main__":
- 	TestLogging.setupLogging("C:\\Users\\bgriffin.AMD\\TestLogVSIDE")
- 	status = startVisualStudio()
- 	wait(5)
- 	if status:
- 		TestLogging.TestLog.info("Started Visual Studio")
+  TestLogging.setupLogging("C:\\Users\\bgriffin.AMD\\TestLogVSIDE")
+  status = startVisualStudio()
+  wait(5)
+  if status:
+   TestLogging.TestLog.info("Started Visual Studio")
  
- 	myVS = captureVisualStudio()
- 	if myVS:
- 		TestLogging.TestLog.info("Image location: " + myVS)
- 	else:
- 		TestLogging.TestLog.error("No Image Captured")
- 	closeVisualStudio()
+  myVS = captureVisualStudio()
+  if myVS:
+   TestLogging.TestLog.info("Image location: " + myVS)
+  else:
+   TestLogging.TestLog.error("No Image Captured")
+  closeVisualStudio()
  
- [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(6120) 
- [log] App.focus Start Page - Microsoft Visual Studio(0) #0 
- [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(6120) [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(5184) 
- [log] App.focus Start Page - Microsoft Visual Studio(0) #0 [log] Ctrl+TYPE "o" 
- [log] TYPE "C:\Users\bgriffin.AMD\Desktop\DataTypesVS10\DataTypesVS10.sln" 
- [log] TYPE " " 
- [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(5184) [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(1696) 
- [log] App.focus Start Page - Microsoft Visual Studio(0) #0 
- Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file 
+ [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(6120)
+ [log] App.focus Start Page - Microsoft Visual Studio(0) #0
+ [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(6120) [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(5184)
+ [log] App.focus Start Page - Microsoft Visual Studio(0) #0 [log] Ctrl+TYPE "o"
+ [log] TYPE "C:\Users\bgriffin.AMD\Desktop\DataTypesVS10\DataTypesVS10.sln"
+ [log] TYPE " "
+ [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(5184) [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(1696)
+ [log] App.focus Start Page - Microsoft Visual Studio(0) #0
+ Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file
  [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(1696)

-- 
You received this bug notification because you are a member of Sikuli
Drivers, which is subscribed to Sikuli.
https://bugs.launchpad.net/bugs/810754

Title:
  X-1.0rc2: IDE: crashes on rerun when using logging module

Status in Sikuli:
  Confirmed

Bug description:
  *** Windows and Mac
  (even for rc3 and Jython 2.5.2)

  When rerunning a script in the IDE that uses the Python logging
  feature, the script terminates with ...sikuli-
  script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O
  operation on closed file

  Running the script from command line works, since at rerun we have a
  clean startup.

  ----------------------------------------------------------------

  I am developing a test infrastructure and want a library to setup logging to a file.
  In Sikuli, I created a script with the code below.  Every time I test my module within the IDE, the specified log file
  gets updated, but the Sikuli IDE goes away, and I have one more "javaw.exe" running on the system

  - use code below to create TestLogging.sikuli in the IDE
  - Change pathname to be valid on your host
  - Run in the IDE

  # Module to set up logging and reporting
  import os
  import logging

  TestLog = 0

  def setupLogging(path, debug = 0):
   global TestLog

   if debug:
    levelLog = logging.DEBUG
   else:
    levelLog = logging.INFO
   logging.basicConfig(filename=path,level=levelLog)
   TestLog = logging.getLogger()

  if __name__ == "__main__":
   setupLogging("C:\\Users\\bgriffin.AMD\\TestLog", debug=1)

   TestLog.error("Test Error Log")
   TestLog.warning("Test Warning Log")
   TestLog.info("Test Info Log")
   TestLog.debug("Test Debug Log")

  When I import my module into a different script, I see different
  behavior in the IDE between runs.  The first run appears to work fine,
  with messages going to the IDE Message window until I configure the
  log file.  The logfile only contains my explicit messages.  After
  editing the script below to configure a different log level, I get
  error messages in the IDE message window unrelated to my script (which
  runs fine).  I have the script first, then the Message window text.

  - Create VisualStudioIDE.sikuli from the code below
  - you may need to modify sys.path depending on where you created TestLogging.sikuli
  - change pathnames to be valid on your host
  - Run in IDE
  - Edit script, adding ", debug=1" to the setupLogging() call.
  - Run
  - DO NOT EXIT IDE IN BETWEEN RUNS

  # Start Visual Studio using command line or a solution
  import os
  from sikuli.Sikuli import *
  import subprocess
  myPath = os.path.dirname(getBundlePath())
  myParent = os.path.dirname(myPath)
  if not myPath in sys.path: sys.path.append(myPath)
  if not myParent in sys.path: sys.path.append(myParent)
  import TestLogging # name for module with above code

  VISUAL_STUDIO_IDE = "C:\\Program Files (x86)\\Microsoft Visual Studio 10.0\\Common7\\IDE\\devenv.exe"
  VSApp = 0

  def startVisualStudio(solution = 0):
   global VSApp
   VSApp = App(VISUAL_STUDIO_IDE)
   VSApp.open()
   wait(10) # wait for the process to start up

   if not VSApp:
    # add logging of failure
    TestLogging.TestLog.error("Unable to start Microsoft Visual Studio")
    TestLogging.TestLog.error("Executable: " + VISUAL_STUDIO_IDE)
    return 0
   VSApp.focus( "Start Page - Microsoft Visual Studio" )

   if solution:
    type("o", KEY_CTRL)
    wait(2)
    type(solution)
    type("\n")

   return 1

  def closeVisualStudio():
   global VSApp
   if VSApp:
    VSApp.close()
    VSApp = 0
   else:
    TestLogging.TestLog.warning("Visual Studio not running.")

  def captureVisualStudio():
   global VSApp
   vsImage = 0
   if VSApp:
    vs = VSApp.focusedWindow()
    vsImage = capture(vs)
   else:
    TestLogging.TestLog.debug("Visual Studio not running?")
   return vsImage

  if __name__ == "__main__":
   TestLogging.setupLogging("C:\\Users\\bgriffin.AMD\\TestLogVSIDE")
   status = startVisualStudio()
   wait(5)
   if status:
    TestLogging.TestLog.info("Started Visual Studio")

   myVS = captureVisualStudio()
   if myVS:
    TestLogging.TestLog.info("Image location: " + myVS)
   else:
    TestLogging.TestLog.error("No Image Captured")
   closeVisualStudio()

  [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(6120)
  [log] App.focus Start Page - Microsoft Visual Studio(0) #0
  [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(6120) [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(5184)
  [log] App.focus Start Page - Microsoft Visual Studio(0) #0 [log] Ctrl+TYPE "o"
  [log] TYPE "C:\Users\bgriffin.AMD\Desktop\DataTypesVS10\DataTypesVS10.sln"
  [log] TYPE " "
  [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(5184) [log] App.open C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(1696)
  [log] App.focus Start Page - Microsoft Visual Studio(0) #0
  Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file Traceback (most recent call last):  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit  File "C:\Program Files (x86)\Sikuli X\sikuli-script.jar\Lib\logging\__init__.py", line 750, in emit ValueError: I/O operation on closed file
  [log] App.close C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE\devenv.exe(1696)

To manage notifications about this bug go to:
https://bugs.launchpad.net/sikuli/+bug/810754/+subscriptions
References

[Bug 810754] [NEW] Windows: Sikuli doesn't work well when using module logging
From: Beth Griffin, 2011-07-14