>>> Result: Jun 16 12:06:59.920248 INFO run is queued with ID: c34uioqa4c9rtptre1p0 >>> Server output: Jun 16 12:07:00.044882 INFO performing build for groups {"plan": "whitenoise", "groups": ["sender", "receiver"], "builder": "exec:go"} Jun 16 12:07:03.403736 INFO build succeeded {"plan": "whitenoise", "groups": ["sender", "receiver"], "builder": "exec:go", "artifact": "/datadrive/testground/data/work/exec-go--whitenoise-a7ddc8119f23 "} Jun 16 12:07:03.403846 INFO performing healthcheck on runner Jun 16 12:07:03.408431 INFO healthcheck: ok Jun 16 12:07:03.408482 INFO starting run {"run_id": "c34uioqa4c9rtptre1p0", "plan": "whitenoise", "case": "transfer", "runner": "local:exec", "instances": 2} Jun 16 12:07:03.408619 INFO starting test case instance {"plan": "whitenoise", "group": "sender", "number": 0, "total": 1} Jun 16 12:07:03.408869 INFO starting test case instance {"plan": "whitenoise", "group": "receiver", "number": 0, "total": 2} Jun 16 12:07:03.418908 INFO 0.0103s MESSAGE << sender[000] >> registering default http handler at: http://[::]:6060/ (pprof: http://[::]:6060/debug/pprof/) Jun 16 12:07:03.418995 INFO 0.0103s START << sender[000] >> {"plan":"whitenoise","case":"transfer","run":"c34uioqa4c9rtptre1p0","outputs_path":"/datadrive/testground/data/outputs/local_exec/white noise/c34uioqa4c9rtptre1p0/sender/0","instances":2,"params":{"inmembstore":"true","interrupt":"0/0","linkshape":"null","size":"4GiB"},"group":"sender","group_instances":1,"network":"127.1.0.0/16","start_t ime":"0001-01-01T00:00:00Z"} Jun 16 12:07:03.419018 INFO 0.0105s OTHER << sender[000] >> {"ts":1623845223418930361,"msg":"writing cpu profile","group_id":"sender","run_id":"c34uioqa4c9rtptre1p0"} Jun 16 12:07:03.419067 INFO 0.0104s MESSAGE << receiver[000] >> registering default http handler at: http://[::]:36581/ (pprof: http://[::]:36581/debug/pprof/) Jun 16 12:07:03.419124 INFO 0.0105s START << receiver[000] >> {"plan":"whitenoise","case":"transfer","run":"c34uioqa4c9rtptre1p0","outputs_path":"/datadrive/testground/data/outputs/local_exec/whi tenoise/c34uioqa4c9rtptre1p0/receiver/0","instances":2,"params":{"inmembstore":"true","interrupt":"0/0","linkshape":"null","size":"32MiB"},"group":"receiver","group_instances":1,"network":"127.1.0.0/16"," start_time":"0001-01-01T00:00:00Z"} Jun 16 12:07:03.419146 INFO 0.0106s OTHER << receiver[000] >> {"ts":1623845223419042035,"msg":"writing heap profile every 5s","group_id":"receiver","run_id":"c34uioqa4c9rtptre1p0"} Jun 16 12:07:03.419162 INFO 0.0107s OTHER << receiver[000] >> {"ts":1623845223419049796,"msg":"writing cpu profile","group_id":"receiver","run_id":"c34uioqa4c9rtptre1p0"} Jun 16 12:07:03.419184 INFO 0.0107s OTHER << sender[000] >> {"ts":1623845223419067839,"msg":"writing heap profile every 5s","group_id":"sender","run_id":"c34uioqa4c9rtptre1p0"} Jun 16 12:07:03.420313 INFO 0.0117s MESSAGE << sender[000] >> waiting for network to initialize Jun 16 12:07:03.420423 INFO 0.0119s MESSAGE << receiver[000] >> waiting for network to initialize Jun 16 12:07:03.420539 INFO 0.0120s MESSAGE << sender[000] >> network initialisation successful Jun 16 12:07:03.420637 INFO 0.0121s MESSAGE << sender[000] >> network initialization complete Jun 16 12:07:03.420660 INFO 0.0121s MESSAGE << receiver[000] >> network initialisation successful Jun 16 12:07:03.420735 INFO 0.0122s MESSAGE << receiver[000] >> network initialization complete Jun 16 12:07:03.420758 INFO 0.0122s MESSAGE << sender[000] >> claimed sequence numbers; global=1, group(sender)=1 Jun 16 12:07:03.420778 INFO 0.0122s MESSAGE << sender[000] >> Running transfer with Graphsync v0.7 Jun 16 12:07:03.420860 INFO 0.0123s MESSAGE << receiver[000] >> claimed sequence numbers; global=2, group(receiver)=1 Jun 16 12:07:03.420879 INFO 0.0123s MESSAGE << receiver[000] >> Running transfer with Graphsync v0.7 Jun 16 12:07:03.476117 INFO 0.0675s MESSAGE << receiver[000] >> creating in-memory blockstore Jun 16 12:07:03.476283 INFO 0.0677s MESSAGE << receiver[000] >> data transfer manager initialized Jun 16 12:07:03.609495 INFO 0.2009s MESSAGE << sender[000] >> creating in-memory blockstore Jun 16 12:07:03.609646 INFO 0.2011s MESSAGE << sender[000] >> data transfer manager initialized Jun 16 12:07:03.610628 INFO 0.2021s MESSAGE << receiver[000] >> one other peer found Jun 16 12:07:03.610657 INFO 0.2021s MESSAGE << receiver[000] >> interruptor loop started Jun 16 12:07:03.610681 INFO 0.2021s MESSAGE << receiver[000] >> we are the receiver Jun 16 12:07:03.610829 INFO 0.2023s MESSAGE << sender[000] >> one other peer found Jun 16 12:07:03.610870 INFO 0.2023s MESSAGE << sender[000] >> interruptor loop started Jun 16 12:07:03.610899 INFO 0.2023s MESSAGE << sender[000] >> we are the sender Jun 16 12:07:37.939994 INFO 34.5313s MESSAGE << sender[000] >> import took: 34.328935725s Jun 16 12:07:37.943915 INFO 34.5354s MESSAGE << sender[000] >> opening the push data channel Jun 16 12:07:38.944800 INFO 35.5362s MESSAGE << sender[000] >> channel state: Ongoing (sent 332750159) Jun 16 12:07:39.945320 INFO 36.5367s MESSAGE << sender[000] >> channel state: Ongoing (sent 665749353) Jun 16 12:07:40.945844 INFO 37.5372s MESSAGE << sender[000] >> channel state: Ongoing (sent 989048701) Jun 16 12:07:41.946275 INFO 38.5377s MESSAGE << sender[000] >> channel state: Ongoing (sent 1318377683) Jun 16 12:07:42.946885 INFO 39.5383s MESSAGE << sender[000] >> channel state: Ongoing (sent 1660560769) Jun 16 12:07:43.948370 INFO 40.5397s MESSAGE << sender[000] >> channel state: Ongoing (sent 1993559963) Jun 16 12:07:44.948319 INFO 41.5396s MESSAGE << sender[000] >> channel state: Ongoing (sent 2326821315) Jun 16 12:07:45.948347 INFO 42.5397s MESSAGE << sender[000] >> channel state: Ongoing (sent 2660615345) Jun 16 12:07:46.949018 INFO 43.5403s MESSAGE << sender[000] >> channel state: Ongoing (sent 2995187487) Jun 16 12:07:47.949518 INFO 44.5409s MESSAGE << sender[000] >> channel state: Ongoing (sent 3336321941) Jun 16 12:07:48.950280 INFO 45.5416s MESSAGE << sender[000] >> channel state: Ongoing (sent 3673253505) Jun 16 12:07:49.950709 INFO 46.5420s MESSAGE << sender[000] >> channel state: Ongoing (sent 4010447227) Jun 16 12:07:50.951085 INFO 47.5425s MESSAGE << sender[000] >> channel state: TransferFinished (sent 4295988814) Jun 16 12:07:50.951150 INFO 47.5425s MESSAGE << sender[000] >> transfer took (from sender's perspective): 13.007142456s Jun 16 12:07:50.951531 INFO 47.5430s OK << sender[000] >> Jun 16 12:07:51.611643 INFO 48.2030s OK << receiver[000] >> Jun 16 12:07:51.905082 INFO run finished successfully {"run_id": "c34uioqa4c9rtptre1p0", "plan": "whitenoise", "case": "transfer", "runner": "local:exec", "instances": 2} >>> Result: Jun 16 12:07:54.448428 INFO finished run with ID: c34uioqa4c9rtptre1p0 >>> Result: Jun 16 12:07:54.703055 INFO created file: c34uioqa4c9rtptre1p0.tgz