>>> Result: Jun 16 10:31:07.323111 INFO run is queued with ID: c34t5qqa4c9rf0ai6v8g >>> Server output: Jun 16 10:31:08.249746 INFO performing build for groups {"plan": "whitenoise", "groups": ["sender", "receiver"], "builder": "exec:go"} Jun 16 10:31:11.582285 INFO build succeeded {"plan": "whitenoise", "groups": ["sender", "receiver"], "builder": "exec:go", "artifact": "/datadrive/testground/data/work/exec-go--whitenoise-28c9eebe48b2"} Jun 16 10:31:11.582405 INFO performing healthcheck on runner Jun 16 10:31:11.587775 INFO healthcheck: ok Jun 16 10:31:11.587831 INFO starting run {"run_id": "c34t5qqa4c9rf0ai6v8g", "plan": "whitenoise", "case": "transfer", "runner": "local:exec", "instances": 2} Jun 16 10:31:11.587956 INFO starting test case instance {"plan": "whitenoise", "group": "sender", "number": 0, "total": 1} Jun 16 10:31:11.588268 INFO starting test case instance {"plan": "whitenoise", "group": "receiver", "number": 0, "total": 2} Jun 16 10:31:11.598239 INFO 0.0102s MESSAGE << receiver[000] >> registering default http handler at: http://[::]:6060/ (pprof: http://[::]:6060/debug/pprof/) Jun 16 10:31:11.598335 INFO 0.0102s START << receiver[000] >> {"plan":"whitenoise","case":"transfer","run":"c34t5qqa4c9rf0ai6v8g","outputs_path":"/datadrive/testground/data/outputs/local_exec/whitenoise/c34t5qqa4c9rf0ai6v8g/receiver/0","instances":2,"params":{"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 10:31:11.598376 INFO 0.0105s OTHER << receiver[000] >> {"ts":1623839471598130251,"msg":"writing heap profile every 5s","group_id":"receiver","run_id":"c34t5qqa4c9rf0ai6v8g"} Jun 16 10:31:11.598398 INFO 0.0105s OTHER << receiver[000] >> {"ts":1623839471598135311,"msg":"writing cpu profile","group_id":"receiver","run_id":"c34t5qqa4c9rf0ai6v8g"} Jun 16 10:31:11.598439 INFO 0.0102s MESSAGE << sender[000] >> registering default http handler at: http://[::]:33471/ (pprof: http://[::]:33471/debug/pprof/) Jun 16 10:31:11.598478 INFO 0.0103s START << sender[000] >> {"plan":"whitenoise","case":"transfer","run":"c34t5qqa4c9rf0ai6v8g","outputs_path":"/datadrive/testground/data/outputs/local_exec/whitenoise/c34t5qqa4c9rf0ai6v8g/sender/0","instances":2,"params":{"interrupt":"0/0","linkshape":"null","size":"4GiB"},"group":"sender","group_instances":1,"network":"127.1.0.0/16","start_time":"0001-01-01T00:00:00Z"} Jun 16 10:31:11.598503 INFO 0.0106s OTHER << sender[000] >> {"ts":1623839471598174677,"msg":"writing cpu profile","group_id":"sender","run_id":"c34t5qqa4c9rf0ai6v8g"} Jun 16 10:31:11.598529 INFO 0.0107s OTHER << sender[000] >> {"ts":1623839471598319520,"msg":"writing heap profile every 5s","group_id":"sender","run_id":"c34t5qqa4c9rf0ai6v8g"} Jun 16 10:31:11.599504 INFO 0.0116s MESSAGE << sender[000] >> waiting for network to initialize Jun 16 10:31:11.599535 INFO 0.0116s MESSAGE << receiver[000] >> waiting for network to initialize Jun 16 10:31:11.599730 INFO 0.0119s MESSAGE << sender[000] >> network initialisation successful Jun 16 10:31:11.599753 INFO 0.0119s MESSAGE << receiver[000] >> network initialisation successful Jun 16 10:31:11.599816 INFO 0.0119s MESSAGE << sender[000] >> network initialization complete Jun 16 10:31:11.599839 INFO 0.0120s MESSAGE << receiver[000] >> network initialization complete Jun 16 10:31:11.599932 INFO 0.0121s MESSAGE << sender[000] >> claimed sequence numbers; global=1, group(sender)=1 Jun 16 10:31:11.599961 INFO 0.0121s MESSAGE << sender[000] >> Running transfer with Graphsync v0.8 Jun 16 10:31:11.599991 INFO 0.0121s MESSAGE << receiver[000] >> claimed sequence numbers; global=2, group(receiver)=1 Jun 16 10:31:11.600009 INFO 0.0121s MESSAGE << receiver[000] >> Running transfer with Graphsync v0.8 Jun 16 10:31:11.746661 INFO 0.1587s MESSAGE << receiver[000] >> creating badger blockstore Jun 16 10:31:11.759343 INFO 0.1714s MESSAGE << receiver[000] >> data transfer manager initialized Jun 16 10:31:11.763486 INFO 0.1755s MESSAGE << sender[000] >> creating badger blockstore Jun 16 10:31:11.777477 INFO 0.1896s MESSAGE << sender[000] >> data transfer manager initialized Jun 16 10:31:11.777921 INFO 0.1900s MESSAGE << receiver[000] >> one other peer found Jun 16 10:31:11.777944 INFO 0.1901s MESSAGE << receiver[000] >> interruptor loop started Jun 16 10:31:11.777972 INFO 0.1901s MESSAGE << receiver[000] >> we are the receiver Jun 16 10:31:11.778316 INFO 0.1903s MESSAGE << sender[000] >> one other peer found Jun 16 10:31:11.778354 INFO 0.1903s MESSAGE << sender[000] >> interruptor loop started Jun 16 10:31:11.778374 INFO 0.1904s MESSAGE << sender[000] >> we are the sender Jun 16 10:32:46.008185 INFO 94.4201s MESSAGE << sender[000] >> import took: 1m34.229650754s Jun 16 10:32:46.012245 INFO 94.4243s MESSAGE << sender[000] >> opening the push data channel Jun 16 10:32:47.013021 INFO 95.4251s MESSAGE << sender[000] >> channel state: Ongoing (sent 336944687) Jun 16 10:32:48.013880 INFO 96.4259s MESSAGE << sender[000] >> channel state: Ongoing (sent 670992513) Jun 16 10:32:49.013880 INFO 97.4259s MESSAGE << sender[000] >> channel state: Ongoing (sent 1003737911) Jun 16 10:32:50.015012 INFO 98.4270s MESSAGE << sender[000] >> channel state: Ongoing (sent 1325464311) Jun 16 10:32:51.014707 INFO 99.4267s MESSAGE << sender[000] >> channel state: Ongoing (sent 1644306973) Jun 16 10:32:52.015896 INFO 100.4279s MESSAGE << sender[000] >> channel state: Ongoing (sent 1988316803) Jun 16 10:32:53.015351 INFO 101.4274s MESSAGE << sender[000] >> channel state: Ongoing (sent 2300343357) Jun 16 10:32:54.015806 INFO 102.4278s MESSAGE << sender[000] >> channel state: Ongoing (sent 2630983129) Jun 16 10:32:55.016037 INFO 103.4281s MESSAGE << sender[000] >> channel state: Ongoing (sent 2978409375) Jun 16 10:32:56.016566 INFO 104.4286s MESSAGE << sender[000] >> channel state: Ongoing (sent 3288862981) Jun 16 10:32:57.018864 INFO 105.4308s MESSAGE << sender[000] >> channel state: Ongoing (sent 3599308225) Jun 16 10:32:58.017426 INFO 106.4294s MESSAGE << sender[000] >> channel state: Ongoing (sent 3934937361) Jun 16 10:32:59.017915 INFO 107.4300s MESSAGE << sender[000] >> channel state: TransferFinished (sent 4295988814) Jun 16 10:32:59.017978 INFO 107.4300s MESSAGE << sender[000] >> transfer took (from sender's perspective): 13.005742056s Jun 16 10:32:59.018365 INFO 107.4304s OK << sender[000] >> Jun 16 10:32:59.779188 INFO 108.1911s OK << receiver[000] >> Jun 16 10:33:00.494014 INFO run finished successfully {"run_id": "c34t5qqa4c9rf0ai6v8g", "plan": "whitenoise", "case": "transfer", "runner": "local:exec", "instances": 2} >>> Result: Jun 16 10:33:03.386449 INFO finished run with ID: c34t5qqa4c9rf0ai6v8g >>> Result: Jun 16 10:33:03.572080 INFO created file: c34t5qqa4c9rf0ai6v8g.tgz