search

Xceptance / testsuite-nocoding

A test suite setup for XLT that does not require coding, it just runs based on CSV or YAML definition files. Apache licensed.
Apache License 2.0
12 stars 11 forks source link

testsuite seems to not set cookie header for subsequent requests #6

Closed chrbayer84 closed 10 years ago

chrbayer84 commented 10 years ago

I'm trying to run a test case where I have to login to a web site, get a cookie and only then be able to do 'privileged' actions. This is very much like the pebble example, but it doesn't seem to work for my test app, which is a cakephp app. I forked and pushed a code example here: https://github.com/chrbayer84/testsuite-nocoding From the debug output I see that the actual login call succeeds, gets a 302 and gets redirected to the privileged action page. But a simple subsequent GET request on that page after the login fails. I sniffed the HTTP headers in a browser and would expect the following headers to be set:

Accept  text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Encoding gzip,deflate,sdch
Accept-Language en-US,en;q=0.8,de-DE;q=0.6,de;q=0.4
Cookie  CAKEPHP=894f3ed8fa4a2c83520ac79808460b5d

... where the cookie header is probably the main thing. This header is missing from the htmlunit-issued request it seems:

[19:17:04,218] INFO  [TURL-0] - Loading page from: http://mysterious-brook-1311.herokuapp.com//tasks
[19:17:04,218] DEBUG [TURL-0] - Get page for window named '', using WebRequest[<url="http://mysterious-brook-1311.herokuapp.com//tasks", GET, EncodingType[name=application/x-www-form-urlencoded], [], {Accept-Encoding=gzip, deflate, Accept=*/*}, null>]

... and redirects back to the login page:

[19:17:04,218] INFO  [TURL-0] - Loading http://mysterious-brook-1311.herokuapp.com//tasks
[19:17:04,218] DEBUG [TURL-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com//tasks
[19:17:04,293] INFO  [TURL-0] - GET - 302 - 74 ms - http://mysterious-brook-1311.herokuapp.com//tasks []
[19:17:04,294] DEBUG [TURL-0] - Got a redirect status code [302] new location = [http://mysterious-brook-1311.herokuapp.com/users/login]

Looks like the test suite does not set the cookie header correctly when running against XLT 4.3.6. This ticket in htmlunit might or might not be related: http://sourceforge.net/p/htmlunit/mailman/message/23571686/ Here is the full debug log:

log4j:WARN No appenders could be found for logger (org.apache.commons.vfs2.impl.StandardFileSystemManager).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
[19:17:01,104] INFO  [main] - Logging property file location automatically set: /dw/xlt/testsuite-nocoding/config/dev-log4j.properties
[19:17:01,105] INFO  [main] - Trying to load property file 'file:///dw/xlt/testsuite-nocoding/config/default.properties'.
[19:17:01,105] INFO  [main] - Loading properties from file: file:///dw/xlt/testsuite-nocoding/config/default.properties
[19:17:01,109] INFO  [main] - Trying to load property file 'file:///dw/xlt/testsuite-nocoding/config/project.properties'.
[19:17:01,109] INFO  [main] - Loading properties from file: file:///dw/xlt/testsuite-nocoding/config/project.properties
[19:17:01,115] INFO  [main] - Trying to load property file 'file:///dw/xlt/testsuite-nocoding/config/test.properties'.
[19:17:01,115] INFO  [main] - Loading properties from file: file:///dw/xlt/testsuite-nocoding/config/test.properties
[19:17:01,115] INFO  [main] - Trying to load property file 'file:///dw/xlt/testsuite-nocoding/config/dev.properties'.
[19:17:01,115] INFO  [main] - Loading properties from file: file:///dw/xlt/testsuite-nocoding/config/dev.properties
[19:17:01,115] DEBUG [main] - ----------------------------------------------------------------
[19:17:01,117] DEBUG [main] - | TAuthor.filename = tauthor.csv
[19:17:01,117] DEBUG [main] - | TLWAuthor.filename = tauthor-lw.csv
[19:17:01,117] DEBUG [main] - | TLWBrowser.filename = tbrowse-lw.csv
[19:17:01,117] DEBUG [main] - | TLWVisitorAndStaticContent.filename = thomepage-plus-static-content-lw.csv
[19:17:01,117] DEBUG [main] - | TVisitorAndStaticContent.filename = thomepage-plus-static-content.csv
[19:17:01,117] DEBUG [main] - | awt.toolkit = sun.awt.X11.XToolkit
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.abortLongRunningTransactions = false
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.api.validators.XHTMLValidator.enabled = false
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.browser = FF
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.common.tests.TLWURL.filename = tbrowse-lw.csv
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.common.tests.TURL.filename = tauthor.csv
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.css.cache.size = 100
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.css.download.images = always
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.cssEnabled = true
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.data.directory = ./config/data
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.http.filter.exclude = 
[19:17:01,118] DEBUG [main] - | com.xceptance.xlt.http.filter.include = 
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.http.gzip = true
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.http.keepAlive = true
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.http.keepAlive.staleConnectionCheck = true
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.javaScriptEnabled = true
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.js.cache.size = 100
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.js.debugger.enabled = false
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.js.takeMeasurements = true
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.loadStaticContent = true
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.loadtests = TVisitorAndStaticContent
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.loadtests.TAuthor.class = com.xceptance.xlt.common.tests.TURL
[19:17:01,119] DEBUG [main] - | com.xceptance.xlt.loadtests.TAuthor.users = 1
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWAuthor.class = com.xceptance.xlt.common.tests.TLWURL
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWAuthor.users = 1
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWBrowser.class = com.xceptance.xlt.common.tests.TLWURL
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWBrowser.users = 1
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWURL.class = com.xceptance.xlt.common.tests.TLWURL
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWURL.users = 1
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWVisitorAndStaticContent.class = com.xceptance.xlt.common.tests.TLWURL
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TLWVisitorAndStaticContent.users = 1
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TURL.class = com.xceptance.xlt.common.tests.TURL
[19:17:01,120] DEBUG [main] - | com.xceptance.xlt.loadtests.TURL.users = 5
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.loadtests.TVisitorAndStaticContent.class = com.xceptance.xlt.common.tests.TURL
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.loadtests.TVisitorAndStaticContent.users = 1
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.loadtests.default.measurementPeriod = 3m
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.loadtests.default.rampUpPeriod = 1m
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.loadtests.default.shutdownPeriod = 30s
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.maxErrors = 1000
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.maximumTransactionRunTime = 900000
[19:17:01,121] DEBUG [main] - | com.xceptance.xlt.output2disk = always
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.output2disk.onError.dumpMode = finalPagesOnly
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.output2disk.size = 3
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.proxy = false
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.proxy.host = 127.0.0.1
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.proxy.port = 8888
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.random.initValue = 42
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.0.contentTypePattern = 
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.0.namePattern = ^([^\.]*)(\.[0-9]+)+$
[19:17:01,122] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.0.newName = {n:1}
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.0.statusCodePattern = 
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.0.stopOnMatch = false
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.0.urlPattern = 
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.1.contentTypePattern = 
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.1.namePattern = [^.]+
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.1.newName = {n:0} JS
[19:17:01,123] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.1.statusCodePattern = 
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.1.stopOnMatch = false
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.1.urlPattern = \.js$
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.10.contentTypePattern = 
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.10.namePattern = .*
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.10.newName = {n:0} [{s:0}]
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.10.statusCodePattern = 30[0-9]+
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.10.stopOnMatch = false
[19:17:01,124] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.10.urlPattern = 
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.3.contentTypePattern = 
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.3.namePattern = [^.]+
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.3.newName = {n:0} Images
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.3.statusCodePattern = 
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.3.stopOnMatch = false
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.3.urlPattern = \.(gif|png|jpg|ico)$
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.5.contentTypePattern = 
[19:17:01,125] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.5.namePattern = [^.]+
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.5.newName = {n:0} CSS
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.5.statusCodePattern = 
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.5.stopOnMatch = false
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.5.urlPattern = \.css$
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.9.namePattern = .*
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.9.newName = {n:0} - {u:1}
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.9.stopOnMatch = false
[19:17:01,126] DEBUG [main] - | com.xceptance.xlt.reportgenerator.requestMergeRules.9.urlPattern = ^http[s]?://([^/]+)
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.result-dir = ./results
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.ssl.easyMode = true
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.staticContent.downloadThreads = 4
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.staticContentCache = true
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.staticContentCache.size = 1000
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.stopTestOnHttpErrors.embedded = false
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.stopTestOnHttpErrors.page = true
[19:17:01,127] DEBUG [main] - | com.xceptance.xlt.stopTestOnJavaScriptErrors = false
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.testPropertiesFile = test.properties
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.thinktime.action = 100
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.thinktime.action.deviation = 50
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.thinktime.transaction = 0
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.thinktime.transaction.deviation = 0
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.timeout = 30000
[19:17:01,128] DEBUG [main] - | com.xceptance.xlt.useHighPrecisionTimer = true
[19:17:01,128] DEBUG [main] - | file.encoding = UTF-8
[19:17:01,129] DEBUG [main] - | file.encoding.pkg = sun.io
[19:17:01,129] DEBUG [main] - | file.separator = /
[19:17:01,129] DEBUG [main] - | host = http://mysterious-brook-1311.herokuapp.com/
[19:17:01,129] DEBUG [main] - | java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
[19:17:01,129] DEBUG [main] - | java.awt.printerjob = sun.print.PSPrinterJob
[19:17:01,129] DEBUG [main] - | java.class.path = /dw/xlt/testsuite-nocoding/classes:/dw/xlt/testsuite-nocoding/lib/bsh-2.1b5.jar:/dw/xlt/testsuite-nocoding/lib/commons-csv-1.0-20130408.212056-191.jar:/dw/xlt/xlt-4.3.6/lib/aws-java-sdk-1.3.2.jar:/dw/xlt/xlt-4.3.6/lib/commons-cli-1.2.jar:/dw/xlt/xlt-4.3.6/lib/commons-codec-1.6.jar:/dw/xlt/xlt-4.3.6/lib/commons-collections-3.2.1.jar:/dw/xlt/xlt-4.3.6/lib/commons-configuration-1.8.jar:/dw/xlt/xlt-4.3.6/lib/commons-exec-1.1.jar:/dw/xlt/xlt-4.3.6/lib/commons-io-2.4.jar:/dw/xlt/xlt-4.3.6/lib/commons-lang3-3.1.jar:/dw/xlt/xlt-4.3.6/lib/commons-lang-2.6.jar:/dw/xlt/xlt-4.3.6/lib/commons-logging-1.1.1.jar:/dw/xlt/xlt-4.3.6/lib/commons-math-2.2.jar:/dw/xlt/xlt-4.3.6/lib/commons-vfs2-2.0.jar:/dw/xlt/xlt-4.3.6/lib/cssparser-0.9.9.jar:/dw/xlt/xlt-4.3.6/lib/guava-15.0.jar:/dw/xlt/xlt-4.3.6/lib/hamcrest-core-1.1.jar:/dw/xlt/xlt-4.3.6/lib/hessian-4.0.7.jar:/dw/xlt/xlt-4.3.6/lib/htmlunit-core-js-2.12.jar:/dw/xlt/xlt-4.3.6/lib/httpclient-4.2.2.jar:/dw/xlt/xlt-4.3.6/lib/httpcore-4.2.2.jar:/dw/xlt/xlt-4.3.6/lib/httpmime-4.2.2.jar:/dw/xlt/xlt-4.3.6/lib/jackson-core-asl-1.9.11.jar:/dw/xlt/xlt-4.3.6/lib/jackson-mapper-asl-1.9.11.jar:/dw/xlt/xlt-4.3.6/lib/javax.servlet-3.0.0.v201112011016.jar:/dw/xlt/xlt-4.3.6/lib/jaxen-1.1.6.jar:/dw/xlt/xlt-4.3.6/lib/jcommon-1.0.17.jar:/dw/xlt/xlt-4.3.6/lib/jetty-continuation-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-http-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-io-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-security-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-server-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-servlet-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-util-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jetty-websocket-8.1.11.v20130520.jar:/dw/xlt/xlt-4.3.6/lib/jfreechart-1.0.14.jar:/dw/xlt/xlt-4.3.6/lib/jna-3.4.0.jar:/dw/xlt/xlt-4.3.6/lib/json-20080701.jar:/dw/xlt/xlt-4.3.6/lib/junit-4.10.jar:/dw/xlt/xlt-4.3.6/lib/log4j-1.2.16.jar:/dw/xlt/xlt-4.3.6/lib/nekohtml-1.9.18.jar:/dw/xlt/xlt-4.3.6/lib/netty-3.5.2.Final.jar:/dw/xlt/xlt-4.3.6/lib/phantomjsdriver-1.0.4.jar:/dw/xlt/xlt-4.3.6/lib/platform-3.4.0.jar:/dw/xlt/xlt-4.3.6/lib/sac-1.3.jar:/dw/xlt/xlt-4.3.6/lib/selenium-android-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-api-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-chrome-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-firefox-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-htmlunit-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-ie-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-iphone-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-java-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-remote-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-safari-driver-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/selenium-support-2.39.0.jar:/dw/xlt/xlt-4.3.6/lib/serializer-2.7.1.jar:/dw/xlt/xlt-4.3.6/lib/slf4j-api-1.6.4.jar:/dw/xlt/xlt-4.3.6/lib/slf4j-log4j12-1.6.4.jar:/dw/xlt/xlt-4.3.6/lib/webbit-0.4.14.jar:/dw/xlt/xlt-4.3.6/lib/xalan-2.7.1.jar:/dw/xlt/xlt-4.3.6/lib/xercesImpl-2.10.0.jar:/dw/xlt/xlt-4.3.6/lib/xlt-4.3.6.jar:/dw/xlt/xlt-4.3.6/lib/xml-apis-1.4.01.jar:/dw/xlt/xlt-4.3.6/lib/xmlpull-1.1.3.1.jar:/dw/xlt/xlt-4.3.6/lib/xpp3_min-1.1.4c.jar:/dw/xlt/xlt-4.3.6/lib/xstream-1.4.2.jar:/opt/eclipse/configuration/org.eclipse.osgi/bundles/908/1/.cp/:/opt/eclipse/configuration/org.eclipse.osgi/bundles/907/1/.cp/
[19:17:01,130] DEBUG [main] - | java.class.version = 51.0
[19:17:01,130] DEBUG [main] - | java.endorsed.dirs = /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/endorsed
[19:17:01,130] DEBUG [main] - | java.ext.dirs = /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/ext:/usr/java/packages/lib/ext
[19:17:01,130] DEBUG [main] - | java.home = /usr/lib/jvm/java-7-openjdk-amd64/jre
[19:17:01,130] DEBUG [main] - | java.io.tmpdir = /tmp
[19:17:01,130] DEBUG [main] - | java.library.path = /usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
[19:17:01,130] DEBUG [main] - | java.runtime.name = OpenJDK Runtime Environment
[19:17:01,130] DEBUG [main] - | java.runtime.version = 1.7.0_65-b32
[19:17:01,131] DEBUG [main] - | java.specification.name = Java Platform API Specification
[19:17:01,131] DEBUG [main] - | java.specification.vendor = Oracle Corporation
[19:17:01,131] DEBUG [main] - | java.specification.version = 1.7
[19:17:01,131] DEBUG [main] - | java.vendor = Oracle Corporation
[19:17:01,131] DEBUG [main] - | java.vendor.url = http://java.oracle.com/
[19:17:01,131] DEBUG [main] - | java.vendor.url.bug = http://bugreport.sun.com/bugreport/
[19:17:01,131] DEBUG [main] - | java.version = 1.7.0_65
[19:17:01,131] DEBUG [main] - | java.vm.info = mixed mode
[19:17:01,132] DEBUG [main] - | java.vm.name = OpenJDK 64-Bit Server VM
[19:17:01,132] DEBUG [main] - | java.vm.specification.name = Java Virtual Machine Specification
[19:17:01,132] DEBUG [main] - | java.vm.specification.vendor = Oracle Corporation
[19:17:01,132] DEBUG [main] - | java.vm.specification.version = 1.7
[19:17:01,132] DEBUG [main] - | java.vm.vendor = Oracle Corporation
[19:17:01,132] DEBUG [main] - | java.vm.version = 24.65-b04
[19:17:01,132] DEBUG [main] - | line.separator = 
[19:17:01,132] DEBUG [main] - | os.arch = amd64
[19:17:01,132] DEBUG [main] - | os.name = Linux
[19:17:01,133] DEBUG [main] - | os.version = 3.13.0-35-generic
[19:17:01,133] DEBUG [main] - | path.separator = :
[19:17:01,133] DEBUG [main] - | sun.arch.data.model = 64
[19:17:01,133] DEBUG [main] - | sun.boot.class.path = /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/resources.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/rt.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/sunrsasign.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/jsse.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/jce.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/charsets.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/rhino.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/lib/jfr.jar:/usr/lib/jvm/java-7-openjdk-amd64/jre/classes
[19:17:01,133] DEBUG [main] - | sun.boot.library.path = /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64
[19:17:01,133] DEBUG [main] - | sun.cpu.endian = little
[19:17:01,133] DEBUG [main] - | sun.cpu.isalist = 
[19:17:01,133] DEBUG [main] - | sun.io.unicode.encoding = UnicodeLittle
[19:17:01,133] DEBUG [main] - | sun.java.command = org.eclipse.jdt.internal.junit.runner.RemoteTestRunner -version 3 -port 33804 -testLoaderClass org.eclipse.jdt.internal.junit4.runner.JUnit4TestLoader -loaderpluginname org.eclipse.jdt.junit4.runtime -classNames com.xceptance.xlt.common.tests.TURL
[19:17:01,134] DEBUG [main] - | sun.java.launcher = SUN_STANDARD
[19:17:01,134] DEBUG [main] - | sun.jnu.encoding = UTF-8
[19:17:01,134] DEBUG [main] - | sun.management.compiler = HotSpot 64-Bit Tiered Compilers
[19:17:01,134] DEBUG [main] - | sun.os.patch.level = unknown
[19:17:01,134] DEBUG [main] - | user.country = US
[19:17:01,134] DEBUG [main] - | user.dir = /dw/xlt/testsuite-nocoding
[19:17:01,134] DEBUG [main] - | user.home = /home/cbayer
[19:17:01,134] DEBUG [main] - | user.language = en
[19:17:01,134] DEBUG [main] - | user.name = cbayer
[19:17:01,134] DEBUG [main] - | user.timezone = America/New_York
[19:17:01,134] DEBUG [main] - | userAgent.UID = true
[19:17:01,134] DEBUG [main] - ----------------------------------------------------------------
[19:17:01,167] DEBUG [main] - Registering data set provider 'com.xceptance.xlt.engine.data.CsvDataSetProvider' for file extension 'csv'
[19:17:01,168] DEBUG [main] - Registering data set provider 'com.xceptance.xlt.engine.data.DomXmlDataSetProvider' for file extension 'xml'
[19:17:01,169] DEBUG [main] - Registering data set provider 'com.xceptance.xlt.engine.data.JdbcDataSetProvider' for file extension 'sql'
[19:17:01,210] INFO  [main] - ####### Test 'com.xceptance.xlt.common.tests.TURL' started
[19:17:01,228] INFO  [TURL-0] - ### Login constructed...
[19:17:01,939] DEBUG [TURL-0] - # Login - preValidate()
[19:17:01,940] DEBUG [TURL-0] - # Login - preValidate() finished after 0 ms
[19:17:01,940] DEBUG [TURL-0] - # Login - execute()
[19:17:01,950] INFO  [TURL-0] - Loading page from: http://mysterious-brook-1311.herokuapp.com//users/login
[19:17:01,960] DEBUG [TURL-0] - Get page for window named '', using WebRequest[<url="http://mysterious-brook-1311.herokuapp.com//users/login", POST, EncodingType[name=application/x-www-form-urlencoded], [data[User][username]=bla@de.de, data[User][password]=egal], {Accept-Encoding=gzip, deflate, Accept=*/*}, null>]
[19:17:01,960] INFO  [TURL-0] - Loading http://mysterious-brook-1311.herokuapp.com//users/login
[19:17:01,962] DEBUG [TURL-0] - Load response for POST http://mysterious-brook-1311.herokuapp.com//users/login
[19:17:02,693] INFO  [TURL-0] - POST - 302 - 729 ms - http://mysterious-brook-1311.herokuapp.com//users/login [data[User][username]=bla@de.de, data[User][password]=egal]
[19:17:02,706] DEBUG [TURL-0] - Got a redirect status code [302] new location = [http://mysterious-brook-1311.herokuapp.com/tasks]
[19:17:02,707] DEBUG [TURL-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/tasks
[19:17:03,247] INFO  [TURL-0] - GET - 200 - 541 ms - http://mysterious-brook-1311.herokuapp.com/tasks []
[19:17:03,253] DEBUG [TURL-0] - Encoding found in HTTP headers: 'UTF-8'.
[19:17:03,273] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/css/cfsnavbar.css
[19:17:03,274] INFO  [TURL-0-pool-1] - Loading http://mysterious-brook-1311.herokuapp.com/img/buzzer_start.png
[19:17:03,274] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/favicon.ico
[19:17:03,274] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/cfsnavbar.css
[19:17:03,274] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/css/datepicker.css
[19:17:03,274] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/favicon.ico
[19:17:03,274] DEBUG [TURL-0-pool-1] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/buzzer_start.png
[19:17:03,275] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/datepicker.css
[19:17:03,317] INFO  [TURL-0-pool-0] - GET - 200 - 42 ms - http://mysterious-brook-1311.herokuapp.com/css/cfsnavbar.css []
[19:17:03,332] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/css/buzzer.css
[19:17:03,332] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/buzzer.css
[19:17:03,351] INFO  [TURL-0-pool-2] - GET - 200 - 75 ms - http://mysterious-brook-1311.herokuapp.com/css/datepicker.css []
[19:17:03,352] INFO  [TURL-0-pool-3] - GET - 200 - 76 ms - http://mysterious-brook-1311.herokuapp.com/favicon.ico []
[19:17:03,361] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/img/cake.power.gif
[19:17:03,362] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/cake.power.gif
[19:17:03,363] INFO  [TURL-0-pool-1] - GET - 200 - 88 ms - http://mysterious-brook-1311.herokuapp.com/img/buzzer_start.png []
[19:17:03,364] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/js/liveclock.js
[19:17:03,364] INFO  [TURL-0-pool-1] - Loading http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css
[19:17:03,365] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/js/liveclock.js
[19:17:03,365] DEBUG [TURL-0-pool-1] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css
[19:17:03,372] INFO  [TURL-0-pool-0] - GET - 200 - 40 ms - http://mysterious-brook-1311.herokuapp.com/css/buzzer.css []
[19:17:03,374] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/img/cake.icon.png
[19:17:03,374] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/cake.icon.png
[19:17:03,398] INFO  [TURL-0-pool-3] - GET - 200 - 37 ms - http://mysterious-brook-1311.herokuapp.com/img/cake.power.gif []
[19:17:03,401] INFO  [TURL-0-pool-2] - GET - 200 - 36 ms - http://mysterious-brook-1311.herokuapp.com/js/liveclock.js []
[19:17:03,401] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/img/bg_header.jpg
[19:17:03,402] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/bg_header.jpg
[19:17:03,403] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/img/cal.gif
[19:17:03,404] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/cal.gif
[19:17:03,405] INFO  [TURL-0-pool-1] - GET - 200 - 40 ms - http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css []
[19:17:03,412] INFO  [TURL-0-pool-1] - Loading http://mysterious-brook-1311.herokuapp.com/img/backstripes.gif
[19:17:03,413] DEBUG [TURL-0-pool-1] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/backstripes.gif
[19:17:03,416] INFO  [TURL-0-pool-0] - GET - 200 - 41 ms - http://mysterious-brook-1311.herokuapp.com/img/cake.icon.png []
[19:17:03,418] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/img/gradient-e5e5e5-ffffff.gif
[19:17:03,419] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/gradient-e5e5e5-ffffff.gif
[19:17:03,443] INFO  [TURL-0-pool-3] - GET - 200 - 41 ms - http://mysterious-brook-1311.herokuapp.com/img/bg_header.jpg []
[19:17:03,444] INFO  [TURL-0-pool-2] - GET - 200 - 39 ms - http://mysterious-brook-1311.herokuapp.com/img/cal.gif []
[19:17:03,446] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/img/bullet2.gif
[19:17:03,446] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/bullet2.gif
[19:17:03,447] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png
[19:17:03,448] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png
[19:17:03,463] INFO  [TURL-0-pool-0] - GET - 200 - 44 ms - http://mysterious-brook-1311.herokuapp.com/img/gradient-e5e5e5-ffffff.gif []
[19:17:03,463] INFO  [TURL-0-pool-1] - GET - 200 - 50 ms - http://mysterious-brook-1311.herokuapp.com/img/backstripes.gif []
[19:17:03,484] INFO  [TURL-0-pool-3] - GET - 200 - 37 ms - http://mysterious-brook-1311.herokuapp.com/img/bullet2.gif []
[19:17:03,870] INFO  [TURL-0-pool-2] - GET - 404 - 422 ms - http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png []
[19:17:03,874] WARN  [TURL-0-pool-2] - EVENT: TURL - Failed to download resource - '[404] http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png'
[19:17:03,893] DEBUG [TURL-0] - setEnclosedPage: HtmlPage(http://mysterious-brook-1311.herokuapp.com/tasks)@800779952|<TopLevelWindow>
[19:17:03,893] DEBUG [TURL-0] - destroyChildren
[19:17:03,966] DEBUG [TURL-0] - Encoding found in HTTP headers: 'UTF-8'.
[19:17:03,976] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDirectory to HTMLDirectoryElement
[19:17:03,976] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeTile to SVGFETileElement
[19:17:03,976] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgSet to SVGSetElement
[19:17:03,976] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlButton to HTMLButtonElement
[19:17:03,976] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeFuncA to SVGFEFuncAElement
[19:17:03,976] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeComponentTransfer to SVGFEComponentTransferElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgAltGlyph to SVGAltGlyphElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBackgroundSound to HTMLBGSoundElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBaseFont to HTMLBaseFontElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeFuncG to SVGFEFuncGElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeSpecularLighting to SVGFESpecularLightingElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeMerge to SVGFEMergeElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlOption to HTMLOptionElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeComposite to SVGFECompositeElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgSwitch to SVGSwitchElement
[19:17:03,977] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeFuncR to SVGFEFuncRElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomCharacterData to CharacterDataImpl
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgMpath to SVGMpathElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlFrame to HTMLFrameElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgElement to SVGElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgSvg to SVGSVGElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeMorphology to SVGFEMorphologyElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlInlineFrame to HTMLIFrameElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgLinearGradient to SVGLinearGradientElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomCDataSection to CDATASection
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableRow to HTMLTableRowElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlStyle to HTMLStyleElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgStyle to SVGStyleElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgDesc to SVGDescElement
[19:17:03,978] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgPattern to SVGPatternElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlScript to HTMLScriptElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeSpotLight to SVGFESpotLightElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgAnimateMotion to SVGAnimateMotionElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeOffset to SVGFEOffsetElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHead to HTMLHeadElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgAnimateTransform to SVGAnimateTransformElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlCanvas to HTMLCanvasElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgLine to SVGLineElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgDefs to SVGDefsElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDivision to HTMLDivElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlMarquee to HTMLDivElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlNoEmbed to HTMLDivElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlNoFrames to HTMLDivElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlNoScript to HTMLDivElement
[19:17:03,979] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgForeignObject to SVGForeignObjectElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSpacer to HTMLSpacerElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFePointLight to SVGFEPointLightElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlMeter to HTMLMeterElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgScript to SVGScriptElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBreak to HTMLBRElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomDocumentType to DocumentType
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlForm to HTMLFormElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlLink to HTMLLinkElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeGaussianBlur to SVGFEGaussianBlurElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgTSpan to SVGTSpanElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgUse to SVGUseElement
[19:17:03,980] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlObject to HTMLObjectElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgAnimate to SVGAnimateElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgTextPath to SVGTextPathElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgMask to SVGMaskElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlApplet to HTMLAppletElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgSymbol to SVGSymbolElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTable to HTMLTableElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlPreformattedText to HTMLPreElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgEllipse to SVGEllipseElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlInsertedText to HTMLInsElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgTitle to SVGTitleElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgGroup to SVGGElement
[19:17:03,981] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgText to SVGTextElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTitle to HTMLTitleElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlFieldSet to HTMLFieldSetElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableBody to HTMLTableSectionElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableHeader to HTMLTableSectionElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableFooter to HTMLTableSectionElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeTurbulence to SVGFETurbulenceElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSelect to HTMLSelectElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlAnchor to HTMLAnchorElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHeading1 to HTMLHeadingElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHeading2 to HTMLHeadingElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHeading3 to HTMLHeadingElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHeading4 to HTMLHeadingElement
[19:17:03,982] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHeading5 to HTMLHeadingElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHeading6 to HTMLHeadingElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTextArea to HTMLTextAreaElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomDocumentFragment to DocumentFragment
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlEmbed to HTMLEmbedElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomComment to Comment
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgImage to SVGImageElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlElement to HTMLElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgClipPath to SVGClipPathElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeFlood to SVGFEFloodElement
[19:17:03,983] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlOptionGroup to HTMLOptGroupElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeConvolveMatrix to SVGFEConvolveMatrixElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeDisplacementMap to SVGFEDisplacementMapElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHorizontalRule to HTMLHRElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableColumn to HTMLTableColElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableColumnGroup to HTMLTableColElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeBlend to SVGFEBlendElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgMetadata to SVGMetadataElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlMenu to HTMLMenuElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlUnknownElement to HTMLUnknownElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlImage to HTMLImageElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgStop to SVGStopElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTableCell to HTMLTableCellElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlAbbreviated to HTMLSpanElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlAcronym to HTMLSpanElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlAddress to HTMLSpanElement
[19:17:03,984] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBidirectionalOverride to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBig to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBold to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBlink to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlCenter to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlCitation to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlCode to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDefinition to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDefinitionDescription to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDefinitionTerm to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlEmphasis to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlItalic to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlKeyboard to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlListing to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlMultiColumn to HTMLSpanElement
[19:17:03,985] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlNoBreak to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlPlainText to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlS to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSample to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSmall to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSpan to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlStrike to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlStrong to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSubscript to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSuperscript to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlTeletype to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlUnderlined to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlVariable to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlExample to HTMLSpanElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlProgress to HTMLProgressElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeDistantLight to SVGFEDistantLightElement
[19:17:03,986] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlInput to HTMLInputElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlFont to HTMLFontElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDeletedText to HTMLDelElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlMeta to HTMLMetaElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeColorMatrix to SVGFEColorMatrixElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgRect to SVGRectElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlCaption to HTMLTableCaptionElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlDefinitionList to HTMLDListElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlFrameSet to HTMLFrameSetElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlSource to HTMLSourceElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomProcessingInstruction to ProcessingInstruction
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomElement to Element
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomAttr to Attr
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlHtml to HTMLHtmlElement
[19:17:03,987] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBase to HTMLBaseElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlParameter to HTMLParamElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlParagraph to HTMLParagraphElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeFuncB to SVGFEFuncBElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlOrderedList to HTMLOListElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgAnchor to SVGAElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgPolyline to SVGPolylineElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlAudio to HTMLAudioElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlListItem to HTMLLIElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlMap to HTMLMapElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgRadialGradient to SVGRadialGradientElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFilter to SVGFilterElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeMergeNode to SVGFEMergeNodeElement
[19:17:03,988] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlLabel to HTMLLabelElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgCircle to SVGCircleElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeDiffuseLighting to SVGFEDiffuseLightingElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlLegend to HTMLLegendElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlInlineQuotation to HTMLQuoteElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBlockQuote to HTMLQuoteElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgPolygon to SVGPolygonElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlArea to HTMLAreaElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlIsIndex to HTMLIsIndexElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlVideo to HTMLVideoElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlBody to HTMLBodyElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgFeImage to SVGFEImageElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgPath to SVGPathElement
[19:17:03,989] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.DomText to Text
[19:17:03,990] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.svg.SvgMarker to SVGMarkerElement
[19:17:03,990] DEBUG [TURL-0] - Mapping com.gargoylesoftware.htmlunit.html.HtmlUnorderedList to HTMLUListElement
[19:17:03,995] DEBUG [TURL-0] - Encoding found in HTTP headers: 'UTF-8'.
[19:17:03,996] DEBUG [TURL-0] - Script node added: <script type="text/javascript" src="/js/liveclock.js">
</script>

[19:17:03,996] DEBUG [TURL-0] - Loading external JavaScript: /js/liveclock.js
[19:17:04,048] DEBUG [TURL-0] - Compilation of script 'http://mysterious-brook-1311.herokuapp.com/js/liveclock.js' took 49.65 ms
[19:17:04,051] DEBUG [TURL-0] - Execution of script 'http://mysterious-brook-1311.herokuapp.com/js/liveclock.js' took 2.51 ms
[19:17:04,052] DEBUG [TURL-0] - Script node added: <script type="text/javascript">

//<![CDATA[

        /*
        Live Clock Script-
        By Mark Plachetta (astro@bigpond.net.au©) based on code from DynamicDrive.com
        For full source code, 100s more DHTML scripts, and Terms Of Use,
        visit http://www.dynamicdrive.com
        */

//]]>

</script>

[19:17:04,053] DEBUG [TURL-0] - Compilation of script 'script in http://mysterious-brook-1311.herokuapp.com/tasks from (7, 33) to (18, 10)' took 0.17 ms
[19:17:04,053] DEBUG [TURL-0] - Execution of script 'script in http://mysterious-brook-1311.herokuapp.com/tasks from (7, 33) to (18, 10)' took 0.04 ms
[19:17:04,071] DEBUG [TURL-0] - Unable to download image for tag HtmlImage[<img src="/img/cake.power.gif" alt="CakePHP: the rapid development php framework" border="0">]; not firing onload event.
[19:17:04,072] DEBUG [TURL-0] - Firing Event DOMContentLoaded (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,072] DEBUG [TURL-0] - Firing Event load (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,073] DEBUG [TURL-0] - Executing load handler for HtmlPage(http://mysterious-brook-1311.herokuapp.com/tasks)@800779952|<TopLevelWindow>
[19:17:04,080] DEBUG [TURL-0] - job added to queue
[19:17:04,080] DEBUG [TURL-0] -     window is: TopLevelWindow[name=""]
[19:17:04,080] DEBUG [TURL-0] -     added job: JavaScript Execution Job 1 (in TopLevelWindow[name=""]): window.setTimeout(show_clock(), 1000)
[19:17:04,080] DEBUG [TURL-0] - after adding job to the queue, the queue is: 
[19:17:04,081] DEBUG [TURL-0] - ------ printing JavaScript job queue -----
[19:17:04,081] DEBUG [TURL-0] -   number of jobs on the queue: 1
[19:17:04,081] DEBUG [TURL-0] -   1)  Job target execution time: 1410045425080
[19:17:04,081] DEBUG [TURL-0] -       job to string: JavaScript Execution Job 1 (in TopLevelWindow[name=""]): window.setTimeout(show_clock(), 1000)
[19:17:04,081] DEBUG [TURL-0] -       job id: 1
[19:17:04,081] DEBUG [TURL-0] - ------------------------------------------
[19:17:04,081] DEBUG [TURL-0] - Execution of function 'unknown@0' took 8.36 ms
[19:17:04,083] DEBUG [TURL-0] - Waiting at most 0 ms for all background jobs in all web windows.
[19:17:04,083] WARN  [TURL-0] - 1 background job(s) still running in web window 'TopLevelWindow[name=""]'. Check your JavaScript code. You may also increase the waiting time (currently: 0 ms).
[19:17:04,119] DEBUG [TURL-0] - XPATH Perf 35 ms - //input[@type='image']
[19:17:04,121] DEBUG [TURL-0] - XPATH Perf 2 ms - //link
[19:17:04,123] DEBUG [TURL-0] - XPATH Perf 1 ms - //style
[19:17:04,125] DEBUG [TURL-0] - XPATH Perf 2 ms - //@style
[19:17:04,125] DEBUG [TURL-0] - XPATH Perf 0 ms - /html/head/base
[19:17:04,127] DEBUG [TURL-0] - # Login - execute() finished after 2188 ms
[19:17:04,128] DEBUG [TURL-0] - # Login - postValidate()
[19:17:04,128] DEBUG [TURL-0] - # Login - postValidate() finished after 0 ms
[19:17:04,129] INFO  [TURL-0] - Executing action think time wait (56 ms)...
[19:17:04,215] DEBUG [TURL-0] - Transformation took: 5ms [URL-Rewriting: 2ms].
[19:17:04,217] INFO  [TURL-0] - ### Task constructed...
[19:17:04,217] DEBUG [TURL-0] - # Task - preValidate()
[19:17:04,217] DEBUG [TURL-0] - # Task - preValidate() finished after 0 ms
[19:17:04,217] DEBUG [TURL-0] - # Task - execute()
[19:17:04,218] INFO  [TURL-0] - Loading page from: http://mysterious-brook-1311.herokuapp.com//tasks
[19:17:04,218] DEBUG [TURL-0] - Firing Event beforeunload (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,218] DEBUG [TURL-0] - Get page for window named '', using WebRequest[<url="http://mysterious-brook-1311.herokuapp.com//tasks", GET, EncodingType[name=application/x-www-form-urlencoded], [], {Accept-Encoding=gzip, deflate, Accept=*/*}, null>]
[19:17:04,218] INFO  [TURL-0] - Loading http://mysterious-brook-1311.herokuapp.com//tasks
[19:17:04,218] DEBUG [TURL-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com//tasks
[19:17:04,293] INFO  [TURL-0] - GET - 302 - 74 ms - http://mysterious-brook-1311.herokuapp.com//tasks []
[19:17:04,294] DEBUG [TURL-0] - Got a redirect status code [302] new location = [http://mysterious-brook-1311.herokuapp.com/users/login]
[19:17:04,294] DEBUG [TURL-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/users/login
[19:17:04,422] INFO  [TURL-0] - GET - 200 - 128 ms - http://mysterious-brook-1311.herokuapp.com/users/login []
[19:17:04,424] DEBUG [TURL-0] - Encoding found in HTTP headers: 'UTF-8'.
[19:17:04,430] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/css/cfsnavbar.css
[19:17:04,431] INFO  [TURL-0-pool-1] - Loading http://mysterious-brook-1311.herokuapp.com/favicon.ico
[19:17:04,431] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/cfsnavbar.css
[19:17:04,431] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/css/buzzer.css
[19:17:04,430] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/css/datepicker.css
[19:17:04,432] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/buzzer.css
[19:17:04,432] INFO  [TURL-0-pool-0] - Return cached response for http://mysterious-brook-1311.herokuapp.com/css/cfsnavbar.css
[19:17:04,431] DEBUG [TURL-0-pool-1] - Load response for GET http://mysterious-brook-1311.herokuapp.com/favicon.ico
[19:17:04,432] INFO  [TURL-0-pool-3] - Return cached response for http://mysterious-brook-1311.herokuapp.com/css/buzzer.css
[19:17:04,432] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/datepicker.css
[19:17:04,433] INFO  [TURL-0-pool-1] - Return cached response for http://mysterious-brook-1311.herokuapp.com/favicon.ico
[19:17:04,434] INFO  [TURL-0-pool-1] - Loading http://mysterious-brook-1311.herokuapp.com/img/cake.power.gif
[19:17:04,434] INFO  [TURL-0-pool-2] - Return cached response for http://mysterious-brook-1311.herokuapp.com/css/datepicker.css
[19:17:04,434] DEBUG [TURL-0-pool-1] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/cake.power.gif
[19:17:04,434] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/img/cake.icon.png
[19:17:04,434] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css
[19:17:04,435] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/cake.icon.png
[19:17:04,435] INFO  [TURL-0-pool-1] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/cake.power.gif
[19:17:04,436] INFO  [TURL-0-pool-3] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/cake.icon.png
[19:17:04,436] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css
[19:17:04,436] INFO  [TURL-0-pool-1] - Loading http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png
[19:17:04,437] INFO  [TURL-0-pool-0] - Return cached response for http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css
[19:17:04,437] DEBUG [TURL-0-pool-1] - Load response for GET http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png
[19:17:04,438] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/img/bg_header.jpg
[19:17:04,438] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/bg_header.jpg
[19:17:04,439] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/img/cal.gif
[19:17:04,439] INFO  [TURL-0-pool-3] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/bg_header.jpg
[19:17:04,439] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/cal.gif
[19:17:04,439] INFO  [TURL-0-pool-3] - Loading http://mysterious-brook-1311.herokuapp.com/img/gradient-e5e5e5-ffffff.gif
[19:17:04,439] INFO  [TURL-0-pool-2] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/cal.gif
[19:17:04,439] INFO  [TURL-0-pool-0] - Loading http://mysterious-brook-1311.herokuapp.com/img/backstripes.gif
[19:17:04,440] INFO  [TURL-0-pool-2] - Loading http://mysterious-brook-1311.herokuapp.com/img/bullet2.gif
[19:17:04,440] DEBUG [TURL-0-pool-0] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/backstripes.gif
[19:17:04,439] DEBUG [TURL-0-pool-3] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/gradient-e5e5e5-ffffff.gif
[19:17:04,440] INFO  [TURL-0-pool-0] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/backstripes.gif
[19:17:04,440] DEBUG [TURL-0-pool-2] - Load response for GET http://mysterious-brook-1311.herokuapp.com/img/bullet2.gif
[19:17:04,440] INFO  [TURL-0-pool-3] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/gradient-e5e5e5-ffffff.gif
[19:17:04,441] INFO  [TURL-0-pool-2] - Return cached response for http://mysterious-brook-1311.herokuapp.com/img/bullet2.gif
[19:17:04,549] INFO  [TURL-0-pool-1] - GET - 404 - 110 ms - http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png []
[19:17:04,552] WARN  [TURL-0-pool-1] - EVENT: TURL - Failed to download resource - '[404] http://mysterious-brook-1311.herokuapp.com/css/grfx/g3_buzzer.png'
[19:17:04,552] DEBUG [TURL-0] - Firing Event unload (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,553] DEBUG [TURL-0] - setEnclosedPage: HtmlPage(http://mysterious-brook-1311.herokuapp.com/users/login)@1953971603|<TopLevelWindow>
[19:17:04,553] DEBUG [TURL-0] - destroyChildren
[19:17:04,576] DEBUG [TURL-0] - Encoding found in HTTP headers: 'UTF-8'.
[19:17:04,582] DEBUG [TURL-0] - Unable to download image for tag HtmlImage[<img src="/img/cake.power.gif" alt="CakePHP: the rapid development php framework" border="0">]; not firing onload event.
[19:17:04,582] DEBUG [TURL-0] - Firing Event DOMContentLoaded (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,583] DEBUG [TURL-0] - Firing Event load (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,583] DEBUG [TURL-0] - Waiting at most 0 ms for all background jobs in all web windows.
[19:17:04,584] DEBUG [TURL-0] - XPATH Perf 1 ms - //input[@type='image']
[19:17:04,585] DEBUG [TURL-0] - XPATH Perf 1 ms - //link
[19:17:04,585] DEBUG [TURL-0] - XPATH Perf 1 ms - //style
[19:17:04,586] DEBUG [TURL-0] - XPATH Perf 0 ms - //@style
[19:17:04,586] DEBUG [TURL-0] - XPATH Perf 0 ms - /html/head/base
[19:17:04,589] DEBUG [TURL-0] - # Task - execute() finished after 371 ms
[19:17:04,589] DEBUG [TURL-0] - # Task - postValidate()
[19:17:04,590] DEBUG [TURL-0] - XPATH Perf 1 ms - /html/body/div/div[2]/form/fieldset/legend
[19:17:04,802] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [328:62] Error in expression. (Invalid token "from(". Was expecting one of: <S>, <NUMBER>, <IDENT>, <STRING>, <PLUS>, <COMMA>, <URI>, "-", "=", ")".)
[19:17:04,802] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [328:90] Error in style rule. (Invalid token "\n\t". Was expecting one of: <EOF>, "}", ";".)
[19:17:04,803] WARN  [TURL-0] - CSS warning: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [328:90] Ignoring the following declarations in this rule.
[19:17:04,804] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [336:62] Error in expression. (Invalid token "from(". Was expecting one of: <S>, <NUMBER>, <IDENT>, <STRING>, <PLUS>, <COMMA>, <URI>, "-", "=", ")".)
[19:17:04,804] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [336:90] Error in style rule. (Invalid token "\n\t". Was expecting one of: <EOF>, "}", ";".)
[19:17:04,804] WARN  [TURL-0] - CSS warning: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [336:90] Ignoring the following declarations in this rule.
[19:17:04,808] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [411:62] Error in expression. (Invalid token "from(". Was expecting one of: <S>, <NUMBER>, <IDENT>, <STRING>, <PLUS>, <COMMA>, <URI>, "-", "=", ")".)
[19:17:04,808] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [411:90] Error in style rule. (Invalid token "\n\t". Was expecting one of: <EOF>, "}", ";".)
[19:17:04,808] WARN  [TURL-0] - CSS warning: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [411:90] Ignoring the following declarations in this rule.
[19:17:04,809] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [426:62] Error in expression. (Invalid token "from(". Was expecting one of: <S>, <NUMBER>, <IDENT>, <STRING>, <PLUS>, <COMMA>, <URI>, "-", "=", ")".)
[19:17:04,809] WARN  [TURL-0] - CSS error: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [426:90] Error in style rule. (Invalid token "\n". Was expecting one of: <EOF>, "}", ";".)
[19:17:04,809] WARN  [TURL-0] - CSS warning: 'http://mysterious-brook-1311.herokuapp.com/css/cake.generic.css' [426:90] Ignoring the following declarations in this rule.
[19:17:04,848] ERROR [TURL-0] - Postvalidation step failed (user: 'TURL-0', output: '1410045421211'): Text does not match. Expected:<Arbeitszeit eintragen> but was:<Login>
java.lang.AssertionError: Text does not match. Expected:<Arbeitszeit eintragen> but was:<Login>
    at org.junit.Assert.fail(Assert.java:93)
    at org.junit.Assert.assertTrue(Assert.java:43)
    at org.junit.Assert.assertNotNull(Assert.java:526)
    at com.xceptance.xlt.common.actions.SimpleURL.postValidate(SimpleURL.java:144)
    at com.xceptance.xlt.api.actions.AbstractAction.run(AbstractAction.java:337)
    at com.xceptance.xlt.api.actions.AbstractWebAction.run(AbstractWebAction.java:136)
    at com.xceptance.xlt.api.actions.AbstractHtmlPageAction.run(AbstractHtmlPageAction.java:125)
    at com.xceptance.xlt.common.tests.TURL.testURLs(TURL.java:77)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:30)
    at com.xceptance.xlt.engine.util.XltTestRunner$StatementWrapper.evaluate(XltTestRunner.java:58)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
[19:17:04,849] DEBUG [TURL-0] - # Task - postValidate() finished after 261 ms
[19:17:04,854] DEBUG [TURL-0] - Transformation took: 1ms [URL-Rewriting: 1ms].
[19:17:04,855] INFO  [TURL-0] - ####### Test 'com.xceptance.xlt.common.tests.TURL' finished after 3644 ms
[19:17:04,856] INFO  [TURL-0] - Cleaning up ...
[19:17:04,856] DEBUG [TURL-0] - Firing Event beforeunload (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,856] DEBUG [TURL-0] - Firing Event unload (Current Target: HTMLElement for HtmlHtml[<html xmlns="http://www.w3.org/1999/xhtml">]);
[19:17:04,857] DEBUG [TURL-0] - destroyChildren
rschwietzke commented 10 years ago

While I look into that, can you please try XLT 4.4? I contains the latest htmlunit,

rschwietzke commented 10 years ago

Found it. Set the dynamic user agent feature to false (project.properties). The app binds the session to the user agent string (very oldschool) for secuity reasons. So a new agent string, because we set a new uuid, does not work and sees all the time something incorrect.

# Activate the user agent based unique ID per request, will turn a user agent into
# something like:
# Mozilla/5.0 (Windows NT 6.1; rv:17.0; Xceptance LoadTest 4.3.0) Gecko/20100101 Firefox/17.0 UID/ad228c44-f6a8-458e-93d1-e6c4cde46870
userAgent.UID=false
chrbayer84 commented 10 years ago

That works! Thanks!