I'm not sure what the repercussions of this are since i didn't test it in the sandbox, but debug mode doesn't trigger any experiment complete status... it stays at AssignmentSubmitted. This could just be a Hotair recruiter thing but i recall it working in the original GU.
/ / / / __ `/ / / / __ \/ __ `/ _ \/ ___/
/ /_/ / /_/ / / / / / / / /_/ / __/ /
/_____/\__,_/_/_/_/_/ /_/\__, /\___/_/
/____/
v5.0.0
Laboratory automation for
the behavioral and social sciences.
❯❯ Experiment id is 0743d93d-ca0a-8ba6-92bc-e887a16112d9
/var/folders/nl/x76v620n2kb98pz4c0kr2hzh0000gn/T/tmphu55kw26/0743d93d-ca0a-8ba6-92bc-e887a16112d9
❯❯ Starting up the server...
▸ heroku-cli: update available from 6.13.17 to 6.99.0-ec9edad
[WARN] No ENV file found
7:07:17 AM worker.1 | 2018-11-27 07:07:17,925 Registering birth of worker dt.94539
7:07:17 AM worker.1 | 2018-11-27 07:07:17,941 RQ GEVENT worker (Greenlet pool size=20) 'rq:worker:dt.94539' started, version 0.12.0
7:07:17 AM worker.1 | 2018-11-27 07:07:17,942 Sent heartbeat to prevent worker timeout. Next one should arrive within 420 seconds.
7:07:17 AM worker.1 | 2018-11-27 07:07:17,943 Cleaning registries for queue: high
7:07:17 AM worker.1 | 2018-11-27 07:07:17,944 Cleaning registries for queue: default
7:07:17 AM worker.1 | 2018-11-27 07:07:17,944 Cleaning registries for queue: low
7:07:17 AM worker.1 | 2018-11-27 07:07:17,946 Sent heartbeat to prevent worker timeout. Next one should arrive within 420 seconds.
7:07:17 AM web.1 | [2018-11-27 07:07:17 -0800] [94538] [DEBUG] Current configuration:
7:07:17 AM web.1 | config: None
7:07:17 AM web.1 | bind: ['0.0.0.0:5000']
7:07:17 AM web.1 | backlog: 2048
7:07:17 AM web.1 | workers: 13
7:07:17 AM web.1 | worker_class: geventwebsocket.gunicorn.workers.GeventWebSocketWorker
7:07:17 AM web.1 | threads: 1
7:07:17 AM web.1 | worker_connections: 1000
7:07:17 AM web.1 | max_requests: 0
7:07:17 AM web.1 | max_requests_jitter: 0
7:07:17 AM web.1 | timeout: 30
7:07:17 AM web.1 | graceful_timeout: 30
7:07:17 AM web.1 | keepalive: 2
7:07:17 AM web.1 | limit_request_line: 0
7:07:17 AM web.1 | limit_request_fields: 100
7:07:17 AM web.1 | limit_request_field_size: 8190
7:07:17 AM web.1 | reload: False
7:07:17 AM web.1 | reload_engine: auto
7:07:17 AM web.1 | reload_extra_files: []
7:07:17 AM web.1 | spew: False
7:07:17 AM web.1 | check_config: False
7:07:17 AM web.1 | preload_app: False
7:07:17 AM web.1 | sendfile: None
7:07:17 AM web.1 | reuse_port: False
7:07:17 AM web.1 | chdir: /private/var/folders/nl/x76v620n2kb98pz4c0kr2hzh0000gn/T/tmphu55kw26/0743d93d-ca0a-8ba6-92bc-e887a16112d9
7:07:17 AM web.1 | daemon: False
7:07:17 AM web.1 | raw_env: []
7:07:17 AM web.1 | pidfile: None
7:07:17 AM web.1 | worker_tmp_dir: None
7:07:17 AM web.1 | user: 501
7:07:17 AM web.1 | group: 20
7:07:17 AM web.1 | umask: 0
7:07:17 AM web.1 | initgroups: False
7:07:17 AM web.1 | tmp_upload_dir: None
7:07:17 AM web.1 | secure_scheme_headers: {'X-FORWARDED-PROTOCOL': 'ssl', 'X-FORWARDED-PROTO': 'https', 'X-FORWARDED-SSL': 'on'}
7:07:17 AM web.1 | forwarded_allow_ips: ['127.0.0.1']
7:07:17 AM web.1 | accesslog: -
7:07:17 AM web.1 | disable_redirect_access_to_syslog: False
7:07:17 AM web.1 | access_log_format: %(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"
7:07:17 AM web.1 | errorlog: -
7:07:17 AM web.1 | loglevel: debug
7:07:17 AM web.1 | capture_output: False
7:07:17 AM web.1 | logger_class: gunicorn.glogging.Logger
7:07:17 AM web.1 | logconfig: None
7:07:17 AM web.1 | logconfig_dict: {}
7:07:17 AM web.1 | syslog_addr: unix:///var/run/syslog
7:07:17 AM web.1 | syslog: False
7:07:17 AM web.1 | syslog_prefix: None
7:07:17 AM web.1 | syslog_facility: user
7:07:17 AM web.1 | enable_stdio_inheritance: False
7:07:17 AM web.1 | statsd_host: None
7:07:17 AM web.1 | statsd_prefix:
7:07:17 AM web.1 | proc_name: dallinger_experiment_server
7:07:17 AM web.1 | default_proc_name: gunicorn
7:07:17 AM web.1 | pythonpath: None
7:07:17 AM web.1 | paste: None
7:07:17 AM web.1 | on_starting: <function OnStarting.on_starting at 0x104449d90>
7:07:17 AM web.1 | on_reload: <function OnReload.on_reload at 0x104449ea0>
7:07:17 AM web.1 | when_ready: <function when_ready at 0x10270cf28>
7:07:17 AM web.1 | pre_fork: <function Prefork.pre_fork at 0x104468158>
7:07:17 AM web.1 | post_fork: <function Postfork.post_fork at 0x104468268>
7:07:17 AM web.1 | post_worker_init: <function PostWorkerInit.post_worker_init at 0x104468378>
7:07:17 AM web.1 | worker_int: <function WorkerInt.worker_int at 0x104468488>
7:07:17 AM web.1 | worker_abort: <function WorkerAbort.worker_abort at 0x104468598>
7:07:17 AM web.1 | pre_exec: <function PreExec.pre_exec at 0x1044686a8>
7:07:17 AM web.1 | pre_request: <function PreRequest.pre_request at 0x1044687b8>
7:07:17 AM web.1 | post_request: <function PostRequest.post_request at 0x104468840>
7:07:17 AM web.1 | child_exit: <function ChildExit.child_exit at 0x104468950>
7:07:17 AM web.1 | worker_exit: <function WorkerExit.worker_exit at 0x104468a60>
7:07:17 AM web.1 | nworkers_changed: <function NumWorkersChanged.nworkers_changed at 0x104468b70>
7:07:17 AM web.1 | on_exit: <function OnExit.on_exit at 0x104468c80>
7:07:17 AM web.1 | proxy_protocol: False
7:07:17 AM web.1 | proxy_allow_ips: ['127.0.0.1']
7:07:17 AM web.1 | keyfile: None
7:07:17 AM web.1 | certfile: None
7:07:17 AM web.1 | ssl_version: 2
7:07:17 AM web.1 | cert_reqs: 0
7:07:17 AM web.1 | ca_certs: None
7:07:17 AM web.1 | suppress_ragged_eofs: True
7:07:17 AM web.1 | do_handshake_on_connect: False
7:07:17 AM web.1 | ciphers: TLSv1
7:07:17 AM web.1 | raw_paste_global_conf: []
7:07:17 AM web.1 | [2018-11-27 07:07:17 -0800] [94538] [INFO] Starting gunicorn 19.9.0
7:07:17 AM web.1 | [2018-11-27 07:07:17 -0800] [94538] [DEBUG] Arbiter booted
7:07:17 AM web.1 | [2018-11-27 07:07:17 -0800] [94538] [INFO] Listening at: http://0.0.0.0:5000 (94538)
7:07:17 AM web.1 | [2018-11-27 07:07:17 -0800] [94538] [INFO] Using worker: geventwebsocket.gunicorn.workers.GeventWebSocketWorker
7:07:17 AM web.1 | 2018-11-27 07:07:17,990 Ready.
7:07:18 AM web.1 | [2018-11-27 07:07:17 -0800] [94547] [INFO] Booting worker with pid: 94547
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94548] [INFO] Booting worker with pid: 94548
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94549] [INFO] Booting worker with pid: 94549
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94550] [INFO] Booting worker with pid: 94550
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94551] [INFO] Booting worker with pid: 94551
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94552] [INFO] Booting worker with pid: 94552
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94553] [INFO] Booting worker with pid: 94553
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94554] [INFO] Booting worker with pid: 94554
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94556] [INFO] Booting worker with pid: 94556
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94557] [INFO] Booting worker with pid: 94557
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94558] [INFO] Booting worker with pid: 94558
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94559] [INFO] Booting worker with pid: 94559
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94560] [INFO] Booting worker with pid: 94560
7:07:18 AM web.1 | [2018-11-27 07:07:18 -0800] [94538] [DEBUG] 13 workers
❯❯ Server is running on http://0.0.0.0:5000. Press Ctrl+C to exit.
❯❯ Launching the experiment...
❯❯ Initial recruitment list:
http://0.0.0.0:5000/ad?recruiter=hotair&assignmentId=MC1XXW&hitId=YFF8PJ&workerId=D2PENG&mode=debug
http://0.0.0.0:5000/ad?recruiter=hotair&assignmentId=DC4L4O&hitId=PMRFKL&workerId=39DHSD&mode=debug
http://0.0.0.0:5000/ad?recruiter=hotair&assignmentId=12PXHN&hitId=XC5P89&workerId=CI2IH8&mode=debug
Additional details:
Recruitment requests will open browser windows automatically.
7:07:28 AM web.1 | 2018-11-27 07:07:28,760 Initializing WebSocket
7:07:28 AM web.1 | 2018-11-27 07:07:28,760 Validating WebSocket request
7:07:28 AM web.1 | 2018-11-27 07:07:28,761 Can only upgrade connection if using GET method.
7:07:28 AM web.1 | >>>> ----- Launching experiment...
7:07:28 AM web.1 | 2018-11-27 07:07:28,877 Initializing HotAirRecruiter...
7:07:28 AM web.1 | 2018-11-27 07:07:28,877 Opening HotAir recruitment for 3 participants
7:07:28 AM web.1 | 2018-11-27 07:07:28,878 Recruiting 3 CLI participants
7:07:28 AM web.1 | 2018-11-27 07:07:28,878 New participant requested: http://0.0.0.0:5000/ad?recruiter=hotair&assignmentId=MC1XXW&hitId=YFF8PJ&workerId=D2PENG&mode=debug
❯❯ new recruitment request!
7:07:28 AM web.1 | 2018-11-27 07:07:28,879 New participant requested: http://0.0.0.0:5000/ad?recruiter=hotair&assignmentId=DC4L4O&hitId=PMRFKL&workerId=39DHSD&mode=debug
❯❯ new recruitment request!
7:07:28 AM web.1 | 2018-11-27 07:07:28,879 New participant requested: http://0.0.0.0:5000/ad?recruiter=hotair&assignmentId=12PXHN&hitId=XC5P89&workerId=CI2IH8&mode=debug
❯❯ new recruitment request!
7:07:28 AM web.1 | 2018-11-27 07:07:28,880 Closing Dallinger DB session at flask request end
7:07:28 AM web.1 | 2018-11-27 07:07:28,881 127.0.0.1 - - [2018-11-27 07:07:28] "POST /launch HTTP/1.1" 200 565 0.121113
7:07:30 AM web.1 | 2018-11-27 07:07:30,189 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,190 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,342 Initializing HotAirRecruiter...
7:07:30 AM web.1 | 2018-11-27 07:07:30,367 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,369 127.0.0.1 - - [2018-11-27 07:07:30] "GET /ad?recruiter=hotair&assignmentId=MC1XXW&hitId=YFF8PJ&workerId=D2PENG&mode=debug HTTP/1.1" 200 3908 0.179334
7:07:30 AM web.1 | 2018-11-27 07:07:30,380 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,381 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,383 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,384 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,396 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,398 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,399 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/css/dallinger.css HTTP/1.1" 200 671 0.016469
7:07:30 AM web.1 | 2018-11-27 07:07:30,399 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/css/bootstrap.min.css HTTP/1.1" 200 100269 0.016969
7:07:30 AM web.1 | 2018-11-27 07:07:30,400 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,400 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,407 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,409 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/images/logo.png HTTP/1.1" 200 1297 0.008844
7:07:30 AM web.1 | 2018-11-27 07:07:30,584 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,585 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,587 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,587 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,588 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,588 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/scripts/reqwest.min.js HTTP/1.1" 200 9648 0.003299
7:07:30 AM web.1 | 2018-11-27 07:07:30,590 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,590 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,590 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,591 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/scripts/reconnecting-websocket.js HTTP/1.1" 200 4539 0.003128
7:07:30 AM web.1 | 2018-11-27 07:07:30,591 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,591 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,592 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,592 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,592 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,593 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/scripts/spin.min.js HTTP/1.1" 200 4583 0.002936
7:07:30 AM web.1 | 2018-11-27 07:07:30,600 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,601 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,601 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/scripts/store+json2.min.js HTTP/1.1" 200 7089 0.009986
7:07:30 AM web.1 | 2018-11-27 07:07:30,602 127.0.0.1 - - [2018-11-27 07:07:30] "GET /static/scripts/dallinger2.js HTTP/1.1" 200 21143 0.010884
7:07:30 AM web.1 | 2018-11-27 07:07:30,789 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,790 Validating WebSocket request
7:07:30 AM web.1 | 2018-11-27 07:07:30,791 Closing Dallinger DB session at flask request end
7:07:30 AM web.1 | 2018-11-27 07:07:30,793 127.0.0.1 - - [2018-11-27 07:07:30] "GET /favicon.ico HTTP/1.1" 200 4581 0.002863
7:07:30 AM web.1 | 2018-11-27 07:07:30,856 Initializing WebSocket
7:07:30 AM web.1 | 2018-11-27 07:07:30,857 Validating WebSocket request
7:07:31 AM web.1 | 2018-11-27 07:07:31,027 Initializing HotAirRecruiter...
7:07:31 AM web.1 | 2018-11-27 07:07:31,050 Closing Dallinger DB session at flask request end
7:07:31 AM web.1 | 2018-11-27 07:07:31,051 127.0.0.1 - - [2018-11-27 07:07:31] "GET /ad?recruiter=hotair&assignmentId=DC4L4O&hitId=PMRFKL&workerId=39DHSD&mode=debug HTTP/1.1" 200 3908 0.194383
7:07:31 AM web.1 | 2018-11-27 07:07:31,528 Initializing WebSocket
7:07:31 AM web.1 | 2018-11-27 07:07:31,528 Validating WebSocket request
7:07:31 AM web.1 | 2018-11-27 07:07:31,709 Initializing HotAirRecruiter...
7:07:31 AM web.1 | 2018-11-27 07:07:31,734 Closing Dallinger DB session at flask request end
7:07:31 AM web.1 | 2018-11-27 07:07:31,735 127.0.0.1 - - [2018-11-27 07:07:31] "GET /ad?recruiter=hotair&assignmentId=12PXHN&hitId=XC5P89&workerId=CI2IH8&mode=debug HTTP/1.1" 200 3908 0.206757
7:07:36 AM web.1 | 2018-11-27 07:07:36,838 Initializing WebSocket
7:07:36 AM web.1 | 2018-11-27 07:07:36,838 Validating WebSocket request
7:07:36 AM web.1 | 2018-11-27 07:07:36,947 Closing Dallinger DB session at flask request end
7:07:36 AM web.1 | 2018-11-27 07:07:36,948 127.0.0.1 - - [2018-11-27 07:07:36] "GET /consent?recruiter=hotair&hit_id=XC5P89&assignment_id=12PXHN&worker_id=CI2IH8&workerId=CI2IH8&mode=debug HTTP/1.1" 200 4505 0.110386
7:07:38 AM web.1 | 2018-11-27 07:07:38,084 Initializing WebSocket
7:07:38 AM web.1 | 2018-11-27 07:07:38,084 Validating WebSocket request
7:07:38 AM web.1 | 2018-11-27 07:07:38,090 Closing Dallinger DB session at flask request end
7:07:38 AM web.1 | 2018-11-27 07:07:38,091 127.0.0.1 - - [2018-11-27 07:07:38] "GET /instructions/instruct-ready?hit_id=XC5P89&assignment_id=12PXHN&worker_id=CI2IH8&mode=debug HTTP/1.1" 200 1835 0.006658
7:07:38 AM web.1 | 2018-11-27 07:07:38,785 Initializing WebSocket
7:07:38 AM web.1 | 2018-11-27 07:07:38,785 Validating WebSocket request
7:07:38 AM web.1 | 2018-11-27 07:07:38,786 Can only upgrade connection if using GET method.
7:07:38 AM web.1 | 2018-11-27 07:07:38,807 Initializing HotAirRecruiter...
7:07:38 AM web.1 | 2018-11-27 07:07:38,818 Closing Dallinger DB session at flask request end
7:07:38 AM web.1 | 2018-11-27 07:07:38,819 127.0.0.1 - - [2018-11-27 07:07:38] "POST /participant/CI2IH8/XC5P89/12PXHN/debug?fingerprint_hash=747e621f1065f5203f7ad722f0e485fc&recruiter=undefined HTTP/1.1" 200 520 0.033485
7:07:39 AM web.1 | 2018-11-27 07:07:39,107 Initializing WebSocket
7:07:39 AM web.1 | 2018-11-27 07:07:39,107 Validating WebSocket request
7:07:39 AM web.1 | 2018-11-27 07:07:39,119 Closing Dallinger DB session at flask request end
7:07:39 AM web.1 | 2018-11-27 07:07:39,120 127.0.0.1 - - [2018-11-27 07:07:39] "GET /experiment?participant_id=1 HTTP/1.1" 200 6639 0.013149
7:07:39 AM web.1 | 2018-11-27 07:07:39,139 Initializing WebSocket
7:07:39 AM web.1 | 2018-11-27 07:07:39,140 Validating WebSocket request
7:07:39 AM web.1 | 2018-11-27 07:07:39,141 Initializing WebSocket
7:07:39 AM web.1 | 2018-11-27 07:07:39,142 Validating WebSocket request
7:07:39 AM web.1 | 2018-11-27 07:07:39,150 Closing Dallinger DB session at flask request end
7:07:39 AM web.1 | 2018-11-27 07:07:39,151 127.0.0.1 - - [2018-11-27 07:07:39] "GET /static/css/main.css HTTP/1.1" 200 20915 0.011869
7:07:39 AM web.1 | 2018-11-27 07:07:39,154 Closing Dallinger DB session at flask request end
7:07:39 AM web.1 | 2018-11-27 07:07:39,158 127.0.0.1 - - [2018-11-27 07:07:39] "GET /static/scripts/acsg-dist.js HTTP/1.1" 200 415574 0.016338
7:07:39 AM web.1 | 2018-11-27 07:07:39,238 Initializing WebSocket
7:07:39 AM web.1 | 2018-11-27 07:07:39,239 Validating WebSocket request
7:07:39 AM web.1 | 2018-11-27 07:07:39,240 Closing Dallinger DB session at flask request end
7:07:39 AM web.1 | 2018-11-27 07:07:39,241 127.0.0.1 - - [2018-11-27 07:07:39] "GET /static/css/fonts/clear-sans.css HTTP/1.1" 200 1383 0.002142
7:07:39 AM web.1 | 2018-11-27 07:07:39,253 Initializing WebSocket
7:07:39 AM web.1 | 2018-11-27 07:07:39,254 Validating WebSocket request
7:07:39 AM web.1 | 2018-11-27 07:07:39,254 Can only upgrade connection if using GET method.
7:07:39 AM web.1 | 2018-11-27 07:07:39,263 Initializing WebSocket
7:07:39 AM web.1 | 2018-11-27 07:07:39,263 Validating WebSocket request
7:07:39 AM web.1 | 2018-11-27 07:07:39,265 Closing Dallinger DB session at flask request end
7:07:39 AM web.1 | 2018-11-27 07:07:39,266 127.0.0.1 - - [2018-11-27 07:07:39] "GET /static/css/fonts/ClearSans-Light-webfont.woff HTTP/1.1" 200 28994 0.003193
7:07:39 AM web.1 | >>>> 1 1 networks out of 1 available
7:07:39 AM web.1 | >>>> 1 No practice networks available.Assigning participant to experiment network 1
7:07:39 AM web.1 | 2018-11-27 07:07:39,394 Closing Dallinger DB session at flask request end
7:07:39 AM web.1 | 2018-11-27 07:07:39,395 127.0.0.1 - - [2018-11-27 07:07:39] "POST /node/1 HTTP/1.1" 200 385 0.141381
7:07:51 AM web.1 | 2018-11-27 07:07:51,565 Initializing WebSocket
7:07:51 AM web.1 | 2018-11-27 07:07:51,566 Validating WebSocket request
7:07:51 AM web.1 | 2018-11-27 07:07:51,585 Closing Dallinger DB session at flask request end
7:07:51 AM web.1 | 2018-11-27 07:07:51,586 127.0.0.1 - - [2018-11-27 07:07:51] "GET /consent?recruiter=hotair&hit_id=PMRFKL&assignment_id=DC4L4O&worker_id=39DHSD&workerId=39DHSD&mode=debug HTTP/1.1" 200 4505 0.020239
7:07:52 AM web.1 | 2018-11-27 07:07:52,500 Initializing WebSocket
7:07:52 AM web.1 | 2018-11-27 07:07:52,500 Validating WebSocket request
7:07:52 AM web.1 | 2018-11-27 07:07:52,506 Closing Dallinger DB session at flask request end
7:07:52 AM web.1 | 2018-11-27 07:07:52,507 127.0.0.1 - - [2018-11-27 07:07:52] "GET /instructions/instruct-ready?hit_id=PMRFKL&assignment_id=DC4L4O&worker_id=39DHSD&mode=debug HTTP/1.1" 200 1835 0.007004
7:07:52 AM web.1 | 2018-11-27 07:07:52,770 Initializing WebSocket
7:07:52 AM web.1 | 2018-11-27 07:07:52,771 Validating WebSocket request
7:07:52 AM web.1 | 2018-11-27 07:07:52,772 Can only upgrade connection if using GET method.
7:07:52 AM web.1 | 2018-11-27 07:07:52,787 Initializing HotAirRecruiter...
7:07:52 AM web.1 | 2018-11-27 07:07:52,794 Closing Dallinger DB session at flask request end
7:07:52 AM web.1 | 2018-11-27 07:07:52,795 127.0.0.1 - - [2018-11-27 07:07:52] "POST /participant/39DHSD/PMRFKL/DC4L4O/debug?fingerprint_hash=68afa849e4f38b7e96dcb5e6daf26ac2&recruiter=undefined HTTP/1.1" 200 520 0.024031
7:07:53 AM web.1 | 2018-11-27 07:07:53,925 Initializing WebSocket
7:07:53 AM web.1 | 2018-11-27 07:07:53,925 Validating WebSocket request
7:07:53 AM web.1 | 2018-11-27 07:07:53,936 Closing Dallinger DB session at flask request end
7:07:53 AM web.1 | 2018-11-27 07:07:53,937 127.0.0.1 - - [2018-11-27 07:07:53] "GET /experiment?participant_id=2 HTTP/1.1" 200 6639 0.012378
7:07:54 AM web.1 | 2018-11-27 07:07:54,072 Initializing WebSocket
7:07:54 AM web.1 | 2018-11-27 07:07:54,072 Validating WebSocket request
7:07:54 AM web.1 | 2018-11-27 07:07:54,072 Can only upgrade connection if using GET method.
7:07:54 AM web.1 | >>>> 2 1 networks out of 1 available
7:07:54 AM web.1 | >>>> 2 No practice networks available.Assigning participant to experiment network 1
7:07:54 AM web.1 | 2018-11-27 07:07:54,103 Closing Dallinger DB session at flask request end
7:07:54 AM web.1 | 2018-11-27 07:07:54,104 127.0.0.1 - - [2018-11-27 07:07:54] "POST /node/2 HTTP/1.1" 200 385 0.031702
7:07:56 AM web.1 | 2018-11-27 07:07:56,098 Initializing WebSocket
7:07:56 AM web.1 | 2018-11-27 07:07:56,098 Validating WebSocket request
7:07:56 AM web.1 | 2018-11-27 07:07:56,103 Closing Dallinger DB session at flask request end
7:07:56 AM web.1 | 2018-11-27 07:07:56,104 127.0.0.1 - - [2018-11-27 07:07:56] "GET /consent?recruiter=hotair&hit_id=YFF8PJ&assignment_id=MC1XXW&worker_id=D2PENG&workerId=D2PENG&mode=debug HTTP/1.1" 200 4505 0.005517
7:07:56 AM web.1 | 2018-11-27 07:07:56,993 Initializing WebSocket
7:07:56 AM web.1 | 2018-11-27 07:07:56,993 Validating WebSocket request
7:07:56 AM web.1 | 2018-11-27 07:07:56,997 Closing Dallinger DB session at flask request end
7:07:56 AM web.1 | 2018-11-27 07:07:56,998 127.0.0.1 - - [2018-11-27 07:07:56] "GET /instructions/instruct-ready?hit_id=YFF8PJ&assignment_id=MC1XXW&worker_id=D2PENG&mode=debug HTTP/1.1" 200 1835 0.004350
7:07:57 AM web.1 | 2018-11-27 07:07:57,279 Initializing WebSocket
7:07:57 AM web.1 | 2018-11-27 07:07:57,280 Validating WebSocket request
7:07:57 AM web.1 | 2018-11-27 07:07:57,280 Can only upgrade connection if using GET method.
7:07:57 AM web.1 | 2018-11-27 07:07:57,285 Same browser fingerprint detected.
7:07:57 AM web.1 | 2018-11-27 07:07:57,293 Initializing HotAirRecruiter...
7:07:57 AM web.1 | 2018-11-27 07:07:57,300 Closing Dallinger DB session at flask request end
7:07:57 AM web.1 | 2018-11-27 07:07:57,301 127.0.0.1 - - [2018-11-27 07:07:57] "POST /participant/D2PENG/YFF8PJ/MC1XXW/debug?fingerprint_hash=68afa849e4f38b7e96dcb5e6daf26ac2&recruiter=undefined HTTP/1.1" 200 520 0.021435
7:07:57 AM web.1 | 2018-11-27 07:07:57,850 Initializing WebSocket
7:07:57 AM web.1 | 2018-11-27 07:07:57,850 Validating WebSocket request
7:07:57 AM web.1 | 2018-11-27 07:07:57,855 Closing Dallinger DB session at flask request end
7:07:57 AM web.1 | 2018-11-27 07:07:57,856 127.0.0.1 - - [2018-11-27 07:07:57] "GET /experiment?participant_id=3 HTTP/1.1" 200 6639 0.005715
7:07:57 AM web.1 | 2018-11-27 07:07:57,993 Initializing WebSocket
7:07:57 AM web.1 | 2018-11-27 07:07:57,994 Validating WebSocket request
7:07:57 AM web.1 | 2018-11-27 07:07:57,994 Can only upgrade connection if using GET method.
7:07:58 AM web.1 | >>>> 3 1 networks out of 1 available
7:07:58 AM web.1 | >>>> 3 No practice networks available.Assigning participant to experiment network 1
7:07:58 AM web.1 | 2018-11-27 07:07:58,024 Closing Dallinger DB session at flask request end
7:07:58 AM web.1 | 2018-11-27 07:07:58,024 127.0.0.1 - - [2018-11-27 07:07:58] "POST /node/3 HTTP/1.1" 200 385 0.030973
7:10:12 AM web.1 | 2018-11-27 07:10:12,048 Initializing WebSocket
7:10:12 AM web.1 | 2018-11-27 07:10:12,049 Validating WebSocket request
7:10:12 AM web.1 | 2018-11-27 07:10:12,049 Can only upgrade connection if using GET method.
7:10:12 AM web.1 | 2018-11-27 07:10:12,067 Initializing WebSocket
7:10:12 AM web.1 | 2018-11-27 07:10:12,067 Validating WebSocket request
7:10:12 AM web.1 | 2018-11-27 07:10:12,068 Can only upgrade connection if using GET method.
7:10:12 AM web.1 | 2018-11-27 07:10:12,093 Closing Dallinger DB session at flask request end
7:10:12 AM web.1 | 2018-11-27 07:10:12,094 127.0.0.1 - - [2018-11-27 07:10:12] "POST /info/1 HTTP/1.1" 200 1558 0.045580
7:10:12 AM web.1 | 2018-11-27 07:10:12,105 Initializing WebSocket
7:10:12 AM web.1 | 2018-11-27 07:10:12,106 Validating WebSocket request
7:10:12 AM web.1 | 2018-11-27 07:10:12,107 Can only upgrade connection if using GET method.
7:10:12 AM web.1 | 2018-11-27 07:10:12,107 Initializing WebSocket
7:10:12 AM web.1 | 2018-11-27 07:10:12,107 Validating WebSocket request
7:10:12 AM web.1 | 2018-11-27 07:10:12,134 Closing Dallinger DB session at flask request end
7:10:12 AM web.1 | 2018-11-27 07:10:12,135 127.0.0.1 - - [2018-11-27 07:10:12] "POST /info/2 HTTP/1.1" 200 1604 0.067399
7:10:12 AM web.1 | 2018-11-27 07:10:12,149 Initializing WebSocket
7:10:12 AM web.1 | 2018-11-27 07:10:12,150 Validating WebSocket request
7:10:12 AM web.1 | 2018-11-27 07:10:12,169 Closing Dallinger DB session at flask request end
7:10:12 AM web.1 | 2018-11-27 07:10:12,171 Closing Dallinger DB session at flask request end
7:10:12 AM web.1 | 2018-11-27 07:10:12,172 127.0.0.1 - - [2018-11-27 07:10:12] "POST /info/3 HTTP/1.1" 200 2077 0.066140
7:10:12 AM web.1 | 2018-11-27 07:10:12,171 127.0.0.1 - - [2018-11-27 07:10:12] "GET /questionnaire?participant_id=2 HTTP/1.1" 200 4488 0.020979
7:10:12 AM web.1 | 2018-11-27 07:10:12,187 Initializing WebSocket
7:10:12 AM web.1 | 2018-11-27 07:10:12,188 Validating WebSocket request
7:10:12 AM web.1 | 2018-11-27 07:10:12,202 Closing Dallinger DB session at flask request end
7:10:12 AM web.1 | 2018-11-27 07:10:12,203 127.0.0.1 - - [2018-11-27 07:10:12] "GET /questionnaire?participant_id=3 HTTP/1.1" 200 4488 0.015460
7:10:12 AM web.1 | 2018-11-27 07:10:12,328 Closing Dallinger DB session at flask request end
7:10:12 AM web.1 | 2018-11-27 07:10:12,330 127.0.0.1 - - [2018-11-27 07:10:12] "GET /questionnaire?participant_id=1 HTTP/1.1" 200 4488 0.222516
7:10:16 AM web.1 | 2018-11-27 07:10:16,972 Initializing WebSocket
7:10:16 AM web.1 | 2018-11-27 07:10:16,972 Validating WebSocket request
7:10:16 AM web.1 | 2018-11-27 07:10:16,972 Can only upgrade connection if using GET method.
7:10:16 AM web.1 | 2018-11-27 07:10:16,985 Initializing HotAirRecruiter...
7:10:16 AM web.1 | 2018-11-27 07:10:16,994 Closing Dallinger DB session at flask request end
7:10:16 AM web.1 | 2018-11-27 07:10:16,995 127.0.0.1 - - [2018-11-27 07:10:16] "POST /question/3 HTTP/1.1" 200 129 0.022617
7:10:17 AM web.1 | 2018-11-27 07:10:17,000 Initializing WebSocket
7:10:17 AM web.1 | 2018-11-27 07:10:17,001 Validating WebSocket request
7:10:17 AM web.1 | 2018-11-27 07:10:17,004 Closing Dallinger DB session at flask request end
7:10:17 AM web.1 | 2018-11-27 07:10:17,005 127.0.0.1 - - [2018-11-27 07:10:17] "GET /participant/3 HTTP/1.1" 200 520 0.004175
7:10:17 AM web.1 | 2018-11-27 07:10:17,010 Initializing WebSocket
7:10:17 AM web.1 | 2018-11-27 07:10:17,010 Validating WebSocket request
7:10:17 AM web.1 | 2018-11-27 07:10:17,010 Running worker worker_complete in scoped DB session
7:10:17 AM web.1 | 2018-11-27 07:10:17,017 Initializing HotAirRecruiter...
7:10:17 AM web.1 | 2018-11-27 07:10:17,017 Initializing HotAirRecruiter...
7:10:17 AM web.1 | 2018-11-27 07:10:17,018 Running worker worker_function in scoped DB session
7:10:17 AM web.1 | 2018-11-27 07:10:17,018 Debug worker_function called synchronously
7:10:17 AM web.1 | >>>> ----- Received an AssignmentSubmitted notification for assignment MC1XXW, participant 3
7:10:17 AM web.1 | 2018-11-27 07:10:17,029 Initializing HotAirRecruiter...
7:10:17 AM web.1 | 2018-11-27 07:10:17,030 Assignment MC1XXW has been marked for approval
7:10:17 AM web.1 | >>>> ----- Bonus = 0: NOT paying bonus
7:10:17 AM web.1 | >>>> ----- All checks passed.
7:10:17 AM web.1 | 2018-11-27 07:10:17,034 Session complete, db session closed
7:10:17 AM web.1 | 2018-11-27 07:10:17,035 Session complete, db session closed
7:10:17 AM web.1 | 2018-11-27 07:10:17,035 Closing Dallinger DB session at flask request end
7:10:17 AM web.1 | 2018-11-27 07:10:17,036 127.0.0.1 - - [2018-11-27 07:10:17] "GET /worker_complete?participant_id=3 HTTP/1.1" 200 129 0.026204
7:10:17 AM web.1 | 2018-11-27 07:10:17,042 Initializing WebSocket
7:10:17 AM web.1 | 2018-11-27 07:10:17,042 Validating WebSocket request
7:10:17 AM web.1 | 2018-11-27 07:10:17,048 Closing Dallinger DB session at flask request end
7:10:17 AM web.1 | 2018-11-27 07:10:17,049 127.0.0.1 - - [2018-11-27 07:10:17] "GET /complete HTTP/1.1" 200 1832 0.006463
7:10:17 AM web.1 | 2018-11-27 07:10:17,181 Initializing WebSocket
7:10:17 AM web.1 | 2018-11-27 07:10:17,182 Validating WebSocket request
7:10:17 AM web.1 | 2018-11-27 07:10:17,221 Initializing HotAirRecruiter...
7:10:17 AM web.1 | 2018-11-27 07:10:17,228 Closing Dallinger DB session at flask request end
7:10:17 AM web.1 | 2018-11-27 07:10:17,228 127.0.0.1 - - [2018-11-27 07:10:17] "GET /ad?recruiter=hotair&assignmentId=MC1XXW&hitId=YFF8PJ&workerId=D2PENG&mode=debug HTTP/1.1" 200 2959 0.047209
7:10:18 AM web.1 | 2018-11-27 07:10:18,390 Initializing WebSocket
7:10:18 AM web.1 | 2018-11-27 07:10:18,390 Validating WebSocket request
7:10:18 AM web.1 | 2018-11-27 07:10:18,391 Can only upgrade connection if using GET method.
7:10:18 AM web.1 | 2018-11-27 07:10:18,400 Initializing HotAirRecruiter...
7:10:18 AM web.1 | 2018-11-27 07:10:18,405 Closing Dallinger DB session at flask request end
7:10:18 AM web.1 | 2018-11-27 07:10:18,405 127.0.0.1 - - [2018-11-27 07:10:18] "POST /question/1 HTTP/1.1" 200 129 0.015095
7:10:18 AM web.1 | 2018-11-27 07:10:18,410 Initializing WebSocket
7:10:18 AM web.1 | 2018-11-27 07:10:18,411 Validating WebSocket request
7:10:18 AM web.1 | 2018-11-27 07:10:18,414 Closing Dallinger DB session at flask request end
7:10:18 AM web.1 | 2018-11-27 07:10:18,414 127.0.0.1 - - [2018-11-27 07:10:18] "GET /participant/1 HTTP/1.1" 200 520 0.003928
7:10:18 AM web.1 | 2018-11-27 07:10:18,420 Initializing WebSocket
7:10:18 AM web.1 | 2018-11-27 07:10:18,421 Validating WebSocket request
7:10:18 AM web.1 | 2018-11-27 07:10:18,421 Running worker worker_complete in scoped DB session
7:10:18 AM web.1 | 2018-11-27 07:10:18,427 Initializing HotAirRecruiter...
7:10:18 AM web.1 | 2018-11-27 07:10:18,428 Initializing HotAirRecruiter...
7:10:18 AM web.1 | 2018-11-27 07:10:18,428 Running worker worker_function in scoped DB session
7:10:18 AM web.1 | 2018-11-27 07:10:18,428 Debug worker_function called synchronously
7:10:18 AM web.1 | >>>> ----- Received an AssignmentSubmitted notification for assignment 12PXHN, participant 1
7:10:18 AM web.1 | 2018-11-27 07:10:18,438 Initializing HotAirRecruiter...
7:10:18 AM web.1 | 2018-11-27 07:10:18,438 Assignment 12PXHN has been marked for approval
7:10:18 AM web.1 | >>>> ----- Bonus = 0: NOT paying bonus
7:10:18 AM web.1 | >>>> ----- All checks passed.
7:10:18 AM web.1 | 2018-11-27 07:10:18,441 Session complete, db session closed
7:10:18 AM web.1 | 2018-11-27 07:10:18,442 Session complete, db session closed
7:10:18 AM web.1 | 2018-11-27 07:10:18,442 Closing Dallinger DB session at flask request end
7:10:18 AM web.1 | 2018-11-27 07:10:18,443 127.0.0.1 - - [2018-11-27 07:10:18] "GET /worker_complete?participant_id=1 HTTP/1.1" 200 129 0.022355
7:10:18 AM web.1 | 2018-11-27 07:10:18,450 Initializing WebSocket
7:10:18 AM web.1 | 2018-11-27 07:10:18,450 Validating WebSocket request
7:10:18 AM web.1 | 2018-11-27 07:10:18,453 Closing Dallinger DB session at flask request end
7:10:18 AM web.1 | 2018-11-27 07:10:18,454 127.0.0.1 - - [2018-11-27 07:10:18] "GET /complete HTTP/1.1" 200 1832 0.003643
7:10:18 AM web.1 | 2018-11-27 07:10:18,585 Initializing WebSocket
7:10:18 AM web.1 | 2018-11-27 07:10:18,586 Validating WebSocket request
7:10:18 AM web.1 | 2018-11-27 07:10:18,596 Initializing HotAirRecruiter...
7:10:18 AM web.1 | 2018-11-27 07:10:18,601 Closing Dallinger DB session at flask request end
7:10:18 AM web.1 | 2018-11-27 07:10:18,602 127.0.0.1 - - [2018-11-27 07:10:18] "GET /ad?recruiter=hotair&assignmentId=12PXHN&hitId=XC5P89&workerId=CI2IH8&mode=debug HTTP/1.1" 200 2959 0.017064
7:10:19 AM web.1 | 2018-11-27 07:10:19,950 Initializing WebSocket
7:10:19 AM web.1 | 2018-11-27 07:10:19,950 Validating WebSocket request
7:10:19 AM web.1 | 2018-11-27 07:10:19,950 Can only upgrade connection if using GET method.
7:10:19 AM web.1 | 2018-11-27 07:10:19,960 Initializing HotAirRecruiter...
7:10:19 AM web.1 | 2018-11-27 07:10:19,964 Closing Dallinger DB session at flask request end
7:10:19 AM web.1 | 2018-11-27 07:10:19,965 127.0.0.1 - - [2018-11-27 07:10:19] "POST /question/2 HTTP/1.1" 200 129 0.015430
7:10:19 AM web.1 | 2018-11-27 07:10:19,971 Initializing WebSocket
7:10:19 AM web.1 | 2018-11-27 07:10:19,971 Validating WebSocket request
7:10:19 AM web.1 | 2018-11-27 07:10:19,974 Closing Dallinger DB session at flask request end
7:10:19 AM web.1 | 2018-11-27 07:10:19,975 127.0.0.1 - - [2018-11-27 07:10:19] "GET /participant/2 HTTP/1.1" 200 520 0.003900
7:10:19 AM web.1 | 2018-11-27 07:10:19,980 Initializing WebSocket
7:10:19 AM web.1 | 2018-11-27 07:10:19,981 Validating WebSocket request
7:10:19 AM web.1 | 2018-11-27 07:10:19,981 Running worker worker_complete in scoped DB session
7:10:19 AM web.1 | 2018-11-27 07:10:19,988 Initializing HotAirRecruiter...
7:10:19 AM web.1 | 2018-11-27 07:10:19,988 Initializing HotAirRecruiter...
7:10:19 AM web.1 | 2018-11-27 07:10:19,988 Running worker worker_function in scoped DB session
7:10:19 AM web.1 | 2018-11-27 07:10:19,989 Debug worker_function called synchronously
7:10:19 AM web.1 | >>>> ----- Received an AssignmentSubmitted notification for assignment DC4L4O, participant 2
7:10:19 AM web.1 | 2018-11-27 07:10:19,998 Initializing HotAirRecruiter...
7:10:19 AM web.1 | 2018-11-27 07:10:19,998 Assignment DC4L4O has been marked for approval
7:10:19 AM web.1 | >>>> ----- Bonus = 0: NOT paying bonus
7:10:20 AM web.1 | >>>> ----- All checks passed.
7:10:20 AM web.1 | 2018-11-27 07:10:20,002 Session complete, db session closed
7:10:20 AM web.1 | 2018-11-27 07:10:20,002 Session complete, db session closed
7:10:20 AM web.1 | 2018-11-27 07:10:20,002 Closing Dallinger DB session at flask request end
7:10:20 AM web.1 | 2018-11-27 07:10:20,003 127.0.0.1 - - [2018-11-27 07:10:20] "GET /worker_complete?participant_id=2 HTTP/1.1" 200 129 0.022640
7:10:20 AM web.1 | 2018-11-27 07:10:20,010 Initializing WebSocket
7:10:20 AM web.1 | 2018-11-27 07:10:20,010 Validating WebSocket request
7:10:20 AM web.1 | 2018-11-27 07:10:20,014 Closing Dallinger DB session at flask request end
7:10:20 AM web.1 | 2018-11-27 07:10:20,015 127.0.0.1 - - [2018-11-27 07:10:20] "GET /complete HTTP/1.1" 200 1832 0.004685
7:10:20 AM web.1 | 2018-11-27 07:10:20,148 Initializing WebSocket
7:10:20 AM web.1 | 2018-11-27 07:10:20,149 Validating WebSocket request
7:10:20 AM web.1 | 2018-11-27 07:10:20,159 Initializing HotAirRecruiter...
7:10:20 AM web.1 | 2018-11-27 07:10:20,163 Closing Dallinger DB session at flask request end
7:10:20 AM web.1 | 2018-11-27 07:10:20,164 127.0.0.1 - - [2018-11-27 07:10:20] "GET /ad?recruiter=hotair&assignmentId=DC4L4O&hitId=PMRFKL&workerId=39DHSD&mode=debug HTTP/1.1" 200 2959 0.015165
7:10:47 AM web.1 | 2018-11-27 07:10:47,278 Initializing WebSocket
7:10:47 AM web.1 | 2018-11-27 07:10:47,278 Validating WebSocket request
7:10:47 AM web.1 | 2018-11-27 07:10:47,370 Closing Dallinger DB session at flask request end
7:10:47 AM web.1 | 2018-11-27 07:10:47,371 127.0.0.1 - - [2018-11-27 07:10:47] "GET /grid?participant_id=2 HTTP/1.1" 404 342 0.092771
7:10:47 AM web.1 | 2018-11-27 07:10:47,526 Initializing WebSocket
7:10:47 AM web.1 | 2018-11-27 07:10:47,526 Validating WebSocket request
7:10:47 AM web.1 | 2018-11-27 07:10:47,623 Closing Dallinger DB session at flask request end
7:10:47 AM web.1 | 2018-11-27 07:10:47,624 127.0.0.1 - - [2018-11-27 07:10:47] "GET /consent?hit_id=2O4D2Y&assignment_id=967XLO&worker_id=WTSZF5&workerId=WTSZF5 HTTP/1.1" 200 4505 0.098227
7:10:47 AM web.1 | 2018-11-27 07:10:47,637 Initializing WebSocket
7:10:47 AM web.1 | 2018-11-27 07:10:47,637 Validating WebSocket request
7:10:47 AM web.1 | 2018-11-27 07:10:47,638 Initializing WebSocket
7:10:47 AM web.1 | 2018-11-27 07:10:47,638 Validating WebSocket request
7:10:47 AM web.1 | 2018-11-27 07:10:47,639 Closing Dallinger DB session at flask request end
7:10:47 AM web.1 | 2018-11-27 07:10:47,640 127.0.0.1 - - [2018-11-27 07:10:47] "GET /static/css/dallinger.css HTTP/1.1" 200 671 0.002152
7:10:47 AM web.1 | 2018-11-27 07:10:47,644 Closing Dallinger DB session at flask request end
7:10:47 AM web.1 | 2018-11-27 07:10:47,645 127.0.0.1 - - [2018-11-27 07:10:47] "GET /static/css/bootstrap.min.css HTTP/1.1" 200 100269 0.007479
7:10:47 AM web.1 | 2018-11-27 07:10:47,811 Initializing WebSocket
7:10:47 AM web.1 | 2018-11-27 07:10:47,812 Validating WebSocket request
7:10:47 AM web.1 | 2018-11-27 07:10:47,817 Closing Dallinger DB session at flask request end
7:10:47 AM web.1 | 2018-11-27 07:10:47,818 127.0.0.1 - - [2018-11-27 07:10:47] "GET /grid?participant_id=1 HTTP/1.1" 404 342 0.006362
7:10:47 AM web.1 | 2018-11-27 07:10:47,961 Initializing WebSocket
7:10:47 AM web.1 | 2018-11-27 07:10:47,962 Validating WebSocket request
7:10:48 AM web.1 | 2018-11-27 07:10:48,062 Closing Dallinger DB session at flask request end
7:10:48 AM web.1 | 2018-11-27 07:10:48,062 127.0.0.1 - - [2018-11-27 07:10:48] "GET /consent?hit_id=ATRXVC&assignment_id=30T891&worker_id=DV3F1I&workerId=DV3F1I HTTP/1.1" 200 4505 0.101218
7:10:48 AM web.1 | 2018-11-27 07:10:48,074 Initializing WebSocket
7:10:48 AM web.1 | 2018-11-27 07:10:48,075 Validating WebSocket request
7:10:48 AM web.1 | 2018-11-27 07:10:48,075 Initializing WebSocket
7:10:48 AM web.1 | 2018-11-27 07:10:48,075 Validating WebSocket request
7:10:48 AM web.1 | 2018-11-27 07:10:48,076 Closing Dallinger DB session at flask request end
7:10:48 AM web.1 | 2018-11-27 07:10:48,077 127.0.0.1 - - [2018-11-27 07:10:48] "GET /static/css/dallinger.css HTTP/1.1" 200 671 0.001787
7:10:48 AM web.1 | 2018-11-27 07:10:48,081 Closing Dallinger DB session at flask request end
7:10:48 AM web.1 | 2018-11-27 07:10:48,082 127.0.0.1 - - [2018-11-27 07:10:48] "GET /static/css/bootstrap.min.css HTTP/1.1" 200 100269 0.008008
7:10:48 AM web.1 | 2018-11-27 07:10:48,242 Initializing WebSocket
7:10:48 AM web.1 | 2018-11-27 07:10:48,242 Validating WebSocket request
7:10:48 AM web.1 | 2018-11-27 07:10:48,250 Closing Dallinger DB session at flask request end
7:10:48 AM web.1 | 2018-11-27 07:10:48,251 127.0.0.1 - - [2018-11-27 07:10:48] "GET /consent?hit_id=RCENXM&assignment_id=COIRAS&worker_id=FB5F2C&workerId=FB5F2C HTTP/1.1" 200 4505 0.008742
7:10:48 AM web.1 | 2018-11-27 07:10:48,260 Initializing WebSocket
7:10:48 AM web.1 | 2018-11-27 07:10:48,260 Validating WebSocket request
7:10:48 AM web.1 | 2018-11-27 07:10:48,261 Closing Dallinger DB session at flask request end
7:10:48 AM web.1 | 2018-11-27 07:10:48,261 Initializing WebSocket
7:10:48 AM web.1 | 2018-11-27 07:10:48,262 Validating WebSocket request
7:10:48 AM web.1 | 2018-11-27 07:10:48,262 127.0.0.1 - - [2018-11-27 07:10:48] "GET /static/css/bootstrap.min.css HTTP/1.1" 200 100269 0.002349
7:10:48 AM web.1 | 2018-11-27 07:10:48,269 Closing Dallinger DB session at flask request end
7:10:48 AM web.1 | 2018-11-27 07:10:48,269 127.0.0.1 - - [2018-11-27 07:10:48] "GET /static/css/dallinger.css HTTP/1.1" 200 671 0.007906
post7:13:17 AM worker.1 | 2018-11-27 07:13:17,967 Sent heartbeat to prevent worker timeout. Next one should arrive within 420 seconds.
7:19:18 AM worker.1 | 2018-11-27 07:19:18,065 Sent heartbeat to prevent worker timeout. Next one should arrive within 420 seconds.
^C
❯❯ Completed debugging of experiment with id 0743d93d-ca0a-8ba6-92bc-e887a16112d9
I'm not sure what the repercussions of this are since i didn't test it in the sandbox, but debug mode doesn't trigger any experiment complete status... it stays at AssignmentSubmitted. This could just be a Hotair recruiter thing but i recall it working in the original GU.