Appium log for iOS 7 sample app

gistfile1.txt

debug: Appium request initiated at /wd/hub/session
debug: Request received with params: {"sessionId":null,"desiredCapabilities":{"name":"Appium Android Test","app":"/Users/malugus/code/appium/appium-workshop/python/ios/../../apps/CollectionViewTransition.app.zip","platform":"Mac 10.8","version":"6.1","newCommandTimeout":60,"device":"iPhone Simulator"}}
info: Using local zip from desiredCaps: /Users/malugus/code/appium/appium-workshop/python/ios/../../apps/CollectionViewTransition.app.zip
info: Copying local zip to tmp dir
info: /Users/malugus/code/appium/appium-workshop/python/ios/../../apps/CollectionViewTransition.app.zip copied to /var/folders/51/rklg31md11q937m11mv1hykm0000gn/T/appium-app113511-17453-15uqhqj.zip
info: Unzipping /var/folders/51/rklg31md11q937m11mv1hykm0000gn/T/appium-app113511-17453-15uqhqj.zip
info: Testing zip archive: /var/folders/51/rklg31md11q937m11mv1hykm0000gn/T/appium-app113511-17453-15uqhqj.zip
info: Zip archive tested clean
info: Unzip successful
info: Using locally extracted app: /var/folders/51/rklg31md11q937m11mv1hykm0000gn/T/CollectionViewTransition.app
info: Creating new appium session ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe
info: Cleaned up instruments socket /tmp/instruments_sock
info: Forcing use of iphone
info: Parsed app Info.plist
info: Wrote new app Info.plist with device type
debug: No device id or app, not installing to real device.
debug: Creating instruments
info: instruments is: /Applications/Xcode5-DP.app/Contents/Developer/usr/bin/instruments
info: [INSTSERVER] Instruments socket server started at /tmp/instruments_sock
info: Spawning instruments with command: /Applications/Xcode5-DP.app/Contents/Developer/usr/bin/instruments -t /Users/malugus/code/appium/appium/app/uiauto/Automation.tracetemplate /var/folders/51/rklg31md11q937m11mv1hykm0000gn/T/CollectionViewTransition.app -e UIASCRIPT /Users/malugus/code/appium/appium/app/uiauto/bootstrap.js -e UIARESULTSPATH /tmp/fc3a18ba-13a2-4873-9141-2ed605024004
info: And extra without-delay env: {}
info: [INST STDERR] 2013-06-11 09:48:13.817 instruments[17487:707] pid 2 = 17491

info: [INST STDERR] 2013-06-11 09:48:13.818 instruments[17487:707] pid 2 = 17490
2013-06-11 09:48:13.818 instruments[17487:707] pid 2 = 17488
2013-06-11 09:48:13.818 instruments[17487:707] pid 2 = 17487

info: [INST STDERR] 2013-06-11 09:48:13.819 instruments[17487:707] pid 2 = 17483

info: [INST STDERR] 2013-06-11 09:48:13.819 instruments[17487:707] pid 2 = 17458

info: [INST STDERR] 2013-06-11 09:48:13.819 instruments[17487:707] pid 2 = 17457

info: [INST STDERR] 2013-06-11 09:48:13.820 instruments[17487:707] pid 2 = 17456

info: [INST STDERR] 2013-06-11 09:48:13.820 instruments[17487:707] pid 2 = 17454

info: [INST STDERR] 2013-06-11 09:48:13.821 instruments[17487:707] pid 2 = 17453

info: [INST STDERR] 2013-06-11 09:48:13.821 instruments[17487:707] pid 2 = 17443

info: [INST STDERR] 2013-06-11 09:48:13.821 instruments[17487:707] pid 2 = 17438

info: [INST STDERR] 2013-06-11 09:48:13.822 instruments[17487:707] pid 2 = 17430

info: [INST STDERR] 2013-06-11 09:48:13.822 instruments[17487:707] pid 2 = 17404

info: [INST STDERR] 2013-06-11 09:48:13.822 instruments[17487:707] pid 2 = 17390

info: [INST STDERR] 2013-06-11 09:48:13.823 instruments[17487:707] pid 2 = 17362

info: [INST STDERR] 2013-06-11 09:48:13.823 instruments[17487:707] pid 2 = 17252
2013-06-11 09:48:13.823 instruments[17487:707] pid 2 = 17181

info: [INST STDERR] 2013-06-11 09:48:13.824 instruments[17487:707] pid 2 = 17174

info: [INST STDERR] 2013-06-11 09:48:13.824 instruments[17487:707] pid 2 = 17036

info: [INST STDERR] 2013-06-11 09:48:13.824 instruments[17487:707] pid 2 = 16789

info: [INST STDERR] 2013-06-11 09:48:13.825 instruments[17487:707] pid 2 = 16786

info: [INST STDERR] 2013-06-11 09:48:13.825 instruments[17487:707] pid 2 = 16777

info: [INST STDERR] 2013-06-11 09:48:13.826 instruments[17487:707] pid 2 = 16236

info: [INST STDERR] 2013-06-11 09:48:13.826 instruments[17487:707] pid 2 = 16233

info: [INST STDERR] 2013-06-11 09:48:13.826 instruments[17487:707] pid 2 = 16232

info: [INST STDERR] 2013-06-11 09:48:13.827 instruments[17487:707] pid 2 = 16231
2013-06-11 09:48:13.827 instruments[17487:707] pid 2 = 16179
2013-06-11 09:48:13.827 instruments[17487:707] pid 2 = 16178

info: [INST STDERR] 2013-06-11 09:48:13.828 instruments[17487:707] pid 2 = 16173

info: [INST STDERR] 2013-06-11 09:48:13.828 instruments[17487:707] pid 2 = 16172
2013-06-11 09:48:13.828 instruments[17487:707] pid 2 = 16171

info: [INST STDERR] 2013-06-11 09:48:13.829 instruments[17487:707] pid 2 = 16170

info: [INST STDERR] 2013-06-11 09:48:13.829 instruments[17487:707] pid 2 = 16169

info: [INST STDERR] 2013-06-11 09:48:13.829 instruments[17487:707] pid 2 = 16168

info: [INST STDERR] 2013-06-11 09:48:13.830 instruments[17487:707] pid 2 = 16165
2013-06-11 09:48:13.830 instruments[17487:707] pid 2 = 16164
2013-06-11 09:48:13.831 instruments[17487:707] pid 2 = 16163

info: [INST STDERR] 2013-06-11 09:48:13.831 instruments[17487:707] pid 2 = 16162
2013-06-11 09:48:13.831 instruments[17487:707] pid 2 = 16161
2013-06-11 09:48:13.832 instruments[17487:707] pid 2 = 16160
2013-06-11 09:48:13.832 instruments[17487:707] Its me!!!

info: [INST STDERR] 2013-06-11 09:48:15.359 ScriptAgent[17492:2f07] CLTilesManagerClient: initialize, sSharedTilesManagerClient

info: [INST STDERR] 2013-06-11 09:48:15.360 ScriptAgent[17492:2f07] CLTilesManagerClient: init

info: [INST STDERR] 2013-06-11 09:48:15.361 ScriptAgent[17492:2f07] CLTilesManagerClient: reconnecting, 0xa10af70

info: [INSTSERVER] Instruments is ready to receive commands
info: Instruments launched. Starting poll loop for new commands.
info: Pushing command to appium work queue: "au.bundleId()"
debug: Sending command to instruments: au.bundleId()
info: [INSTSERVER] Socket data received (15 bytes)
info: [INSTSERVER] Socket data being routed for 'cmd' event
info: [INSTSERVER] Sending command to instruments: au.bundleId()
info: [INST STDERR] 2013-06-11 09:48:21.416 instruments[17487:707] _msgObj is __NSCFString

info: [INST] 2013-06-11 13:48:21 +0000 Default: Got new command 0 from instruments: au.bundleId()
info: [INST STDERR] 2013-06-11 09:48:21.439 instruments[17487:707] _msgObj is __NSCFString

info: [INST] 2013-06-11 13:48:21 +0000 Default: Result is not protocol compliant, wrapping
info: [INSTSERVER] Socket data received (101 bytes)
info: [INSTSERVER] Socket data being routed for 'cmd' event
info: [INSTSERVER] Got result from instruments: {"status":0,"value":"com.example.apple-samplecode.CollectionViewTransition"}
info: Bundle ID for open app is com.example.apple-samplecode.CollectionViewTransition
info: Setting initial orientation to PORTRAIT
info: Pushing command to appium work queue: "au.setScreenOrientation('PORTRAIT')"
debug: Sending command to instruments: au.setScreenOrientation('PORTRAIT')
info: [INSTSERVER] Sending command to instruments: au.setScreenOrientation('PORTRAIT')
info: [INST STDERR] 2013-06-11 09:48:22.473 instruments[17487:707] _msgObj is __NSCFString

info: [INST] 2013-06-11 13:48:22 +0000 Default: Got new command 1 from instruments: au.setScreenOrientation('PORTRAIT')
info: [INST STDERR] 2013-06-11 09:48:22.483 instruments[17487:707] _msgObj is __NSCFString

info: [INSTSERVER] Socket data received (56 bytes)
info: [INSTSERVER] Socket data being routed for 'cmd' event
info: [INSTSERVER] Got result from instruments: {"status":0,"value":"PORTRAIT"}
info: Appium session started with sessionId ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe
info: Pushing command to appium work queue: "waitForDataTimeout = 60"
debug: Sending command to instruments: waitForDataTimeout = 60
info: [INSTSERVER] Sending command to instruments: waitForDataTimeout = 60
info: [INST STDERR] 2013-06-11 09:48:23.402 instruments[17487:707] _msgObj is __NSCFString

info: [INST] 2013-06-11 13:48:22 +0000 Debug: target.setDeviceOrientation("1")
       2013-06-11 13:48:23 +0000 Default: Got new command 2 from instruments: waitForDataTimeout = 60
info: [INST STDERR] 2013-06-11 09:48:23.415 instruments[17487:707] _msgObj is __NSCFString

info: [INST] 2013-06-11 13:48:23 +0000 Default: Result is not protocol compliant, wrapping
info: [INSTSERVER] Socket data received (48 bytes)
info: [INSTSERVER] Socket data being routed for 'cmd' event
info: [INSTSERVER] Got result from instruments: {"status":0,"value":60}
POST /wd/hub/session 303 12106ms - 9
debug: Appium request initiated at /wd/hub/session/ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe
info: Responding to client with success: {"status":0,"value":{"version":"6.0","webStorageEnabled":false,"locationContextEnabled":false,"browserName":"iOS","platform":"MAC","javascriptEnabled":true,"databaseEnabled":false,"takesScreenshot":true},"sessionId":"ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe"}
GET /wd/hub/session/ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe 200 4ms - 319
debug: Appium request initiated at /wd/hub/session/ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe/timeouts/implicit_wait
debug: Request received with params: {"sessionId":"ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe","ms":30000}
info: Set iOS implicit wait to 30000ms
info: Responding to client with success: {"status":0,"value":null,"sessionId":"ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe"}
POST /wd/hub/session/ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe/timeouts/implicit_wait 200 5ms - 89
debug: Appium request initiated at /wd/hub/session/ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe/element
debug: Request received with params: {"using":"name","sessionId":"ec74dc3c-c2f1-4eee-8c41-c664b8d7cbfe","value":"userName"}
info: Pushing command to appium work queue: "au.getElementByName('userName')"
debug: Sending command to instruments: au.getElementByName('userName')
info: [INSTSERVER] Sending command to instruments: au.getElementByName('userName')
info: [INST STDERR] 2013-06-11 09:48:24.463 instruments[17487:707] _msgObj is __NSCFString