← Back to team overview

sikuli-driver team mailing list archive

[Bug 810754] [NEW] Windows: Sikuli doesn't work well when using module logging

 

Public bug reported:

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)

** Affects: sikuli
     Importance: Undecided
         Status: New

-- 
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:
  Windows: Sikuli doesn't work well when using module logging

Status in Sikuli:
  New

Bug description:
  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


Follow ups

References