Skip to Content.
Sympa Menu

perfsonar-user - [perfsonar-user] pscheduler throughput test fails to complete after pS software upgrade

Subject: perfSONAR User Q&A and Other Discussion

List archive

[perfsonar-user] pscheduler throughput test fails to complete after pS software upgrade


Chronological Thread 
  • From: "Uhl, George D. (GSFC-423.0)[SGT INC]" <>
  • To: "" <>
  • Subject: [perfsonar-user] pscheduler throughput test fails to complete after pS software upgrade
  • Date: Tue, 5 Mar 2019 19:05:53 +0000
  • Dkim-filter: OpenDKIM Filter v2.11.0 ndjsvnpf103.ndc.nasa.gov C18884030501

Hi,

One of my managed test nodes underwent a perfsonar software upgrade on Saturday morning.  Ever since the upgrade, outbound iperf3 throughput tests fail to complete.  The destination is a no-agent test node which I think might be running a perfsonar 4.0.x release.  

Thanks,
George


# pscheduler task --debug throughput --source esdis-pt1-10g.eosdis.nasa.gov --dest edclxw41.cr.usgs.gov --ip-version 4 

2019-03-05T18:29:32 Debug started

2019-03-05T18:29:32 Assistance is from localhost

2019-03-05T18:29:32 Forcing default slip of PT5M

2019-03-05T18:29:32 Converting to spec via https://localhost/pscheduler/tests/throughput/spec

Submitting task...

2019-03-05T18:29:32 Fetching participant list

2019-03-05T18:29:32 Spec is: {"dest": "edclxw41.cr.usgs.gov", "source": "esdis-pt1-10g.eosdis.nasa.gov", "ip-version": 4, "schema": 1}

2019-03-05T18:29:32 Params are: {'spec': '{"dest": "edclxw41.cr.usgs.gov", "source": "esdis-pt1-10g.eosdis.nasa.gov", "ip-version": 4, "schema": 1}'}

2019-03-05T18:29:32 Got participants: {u'participants': [u'esdis-pt1-10g.eosdis.nasa.gov', u'edclxw41.cr.usgs.gov']}

2019-03-05T18:29:32 Lead is esdis-pt1-10g.eosdis.nasa.gov

2019-03-05T18:29:32 Pinging https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/

2019-03-05T18:29:32 esdis-pt1-10g.eosdis.nasa.gov is up

2019-03-05T18:29:32 Posting task to https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks

2019-03-05T18:29:32 Data is {"test": {"type": "throughput", "spec": {"dest": "edclxw41.cr.usgs.gov", "source": "esdis-pt1-10g.eosdis.nasa.gov", "ip-version": 4, "schema": 1}}, "schema": 1, "schedule": {"slip": "PT5M"}}

Task URL:

https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d

2019-03-05T18:29:40 Posted https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d

2019-03-05T18:29:40 Submission diagnostics:

2019-03-05T18:29:40   Hints:

2019-03-05T18:29:40     requester: 198.118.198.5

2019-03-05T18:29:40     server: 198.118.198.5

2019-03-05T18:29:40   Identified as everybody, local-interfaces

2019-03-05T18:29:40   Classified as default, friendlies

2019-03-05T18:29:40   Application: Hosts we trust to do everything

2019-03-05T18:29:40     Group 1: Limit 'always' passed

2019-03-05T18:29:40     Group 1: Want all, 1/1 passed, 0/1 failed: PASS

2019-03-05T18:29:40     Application PASSES

2019-03-05T18:29:40   Application: Defaults applied to non-friendly hosts

2019-03-05T18:29:40     Group 1: Limit 'innocuous-tests' failed: Passed but inverted

2019-03-05T18:29:40     Group 1: Limit 'throughput-default-tcp' passed

2019-03-05T18:29:40     Group 1: Limit 'throughput-default-udp' failed: UDP testing not allowed

2019-03-05T18:29:40     Group 1: Limit 'idleex-default' failed: Test is not 'idleex'

2019-03-05T18:29:40     Group 1: Want any, 1/4 passed, 3/4 failed: PASS

2019-03-05T18:29:40     Application PASSES

2019-03-05T18:29:40   Proposal meets limits

Running with tool 'iperf3'

Fetching first run...

2019-03-05T18:29:40 Fetching https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d/runs/first

2019-03-05T18:29:41 Handing off: pscheduler watch --first --format text/plain --debug https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d

2019-03-05T18:29:42 Debug started

2019-03-05T18:29:42 Fetching https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d

2019-03-05T18:29:42 Fetching next run from https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d/runs/first


Next scheduled run:

https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d/runs/50a511cf-0899-4d08-a13e-0892c2ea78bf

Starts 2019-03-05T13:29:50-05:00 (~7 seconds)

Ends   2019-03-05T13:30:09-05:00 (~18 seconds)

Waiting for result...


Run did not complete: Failed



Diagnostics from esdis-pt1-10g.eosdis.nasa.gov:

  numactl -N 0 /usr/bin/iperf3 -p 5201 -4 -B esdis-pt1-10g.eosdis.nasa.gov -c edclxw41.cr.usgs.gov -t 10 --json

  

  {

  "start": {

  "connected": [{

  "socket": 5,

  "local_host": "198.118.198.5",

  "local_port": 50999,

  "remote_host": "152.61.6.5",

  "remote_port": 5201

  }],

  "version": "iperf 3.6",

  "system_info": "Linux esdis-ps 3.10.0-957.1.3.el7.x86_64 #1 SMP Thu Nov 29 14:49:43 UTC 2018 x86_64",

  "timestamp": {

  "time": "Tue, 05 Mar 2019 18:29:53 GMT",

  "timesecs": 1551810593

  },

  "connecting_to": {

  "host": "edclxw41.cr.usgs.gov",

  "port": 5201

  },

  "cookie": "u3eidchzggteadvlt6ig3fhiztw5vy6kdhik",

  "tcp_mss_default": 1448,

  "sock_bufsize": 0,

  "sndbuf_actual": 87380,

  "rcvbuf_actual": 87380,

  "test_start": {

  "protocol": "TCP",

  "num_streams": 1,

  "blksize": 131072,

  "omit": 0,

  "duration": 10,

  "bytes": 0,

  "blocks": 0,

  "reverse": 0,

  "tos": 0

  }

  },

  "intervals": [{

  "streams": [{

  "socket": 5,

  "start": 0,

  "end": 1.0000629425048828,

  "seconds": 1.0000629425048828,

  "bytes": 259952056,

  "bits_per_second": 2079485559.9699879,

  "retransmits": 0,

  "snd_cwnd": 46496728,

  "rtt": 33024,

  "rttvar": 157,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 0,

  "end": 1.0000629425048828,

  "seconds": 1.0000629425048828,

  "bytes": 259952056,

  "bits_per_second": 2079485559.9699879,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 1.0000629425048828,

  "end": 2.0000619888305664,

  "seconds": 0.99999904632568359,

  "bytes": 394526720,

  "bits_per_second": 3156216770.0028706,

  "retransmits": 540,

  "snd_cwnd": 11656400,

  "rtt": 32254,

  "rttvar": 29,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 1.0000629425048828,

  "end": 2.0000619888305664,

  "seconds": 0.99999904632568359,

  "bytes": 394526720,

  "bits_per_second": 3156216770.0028706,

  "retransmits": 540,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 2.0000619888305664,

  "end": 3.0000660419464111,

  "seconds": 1.0000040531158447,

  "bytes": 360448000,

  "bits_per_second": 2883572312.5473704,

  "retransmits": 0,

  "snd_cwnd": 11708528,

  "rtt": 32362,

  "rttvar": 137,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 2.0000619888305664,

  "end": 3.0000660419464111,

  "seconds": 1.0000040531158447,

  "bytes": 360448000,

  "bits_per_second": 2883572312.5473704,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 3.0000660419464111,

  "end": 4.000248908996582,

  "seconds": 1.0001828670501709,

  "bytes": 364380160,

  "bits_per_second": 2914508312.4622016,

  "retransmits": 0,

  "snd_cwnd": 11882288,

  "rtt": 32328,

  "rttvar": 158,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 3.0000660419464111,

  "end": 4.000248908996582,

  "seconds": 1.0001828670501709,

  "bytes": 364380160,

  "bits_per_second": 2914508312.4622016,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 4.000248908996582,

  "end": 5.0000598430633545,

  "seconds": 0.99981093406677246,

  "bytes": 370933760,

  "bits_per_second": 2968031233.5950279,

  "retransmits": 0,

  "snd_cwnd": 12202296,

  "rtt": 32255,

  "rttvar": 39,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 4.000248908996582,

  "end": 5.0000598430633545,

  "seconds": 0.99981093406677246,

  "bytes": 370933760,

  "bits_per_second": 2968031233.5950279,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 5.0000598430633545,

  "end": 6.0000588893890381,

  "seconds": 0.99999904632568359,

  "bytes": 384040960,

  "bits_per_second": 3072330610.0027943,

  "retransmits": 0,

  "snd_cwnd": 12672896,

  "rtt": 32323,

  "rttvar": 47,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 5.0000598430633545,

  "end": 6.0000588893890381,

  "seconds": 0.99999904632568359,

  "bytes": 384040960,

  "bits_per_second": 3072330610.0027943,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 6.0000588893890381,

  "end": 7.00006890296936,

  "seconds": 1.0000100135803223,

  "bytes": 398458880,

  "bits_per_second": 3187639120.31963,

  "retransmits": 0,

  "snd_cwnd": 13286848,

  "rtt": 32231,

  "rttvar": 41,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 6.0000588893890381,

  "end": 7.00006890296936,

  "seconds": 1.0000100135803223,

  "bytes": 398458880,

  "bits_per_second": 3187639120.31963,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 7.00006890296936,

  "end": 8.0000648498535156,

  "seconds": 0.99999594688415527,

  "bytes": 420741120,

  "bits_per_second": 3365942602.555295,

  "retransmits": 0,

  "snd_cwnd": 14047048,

  "rtt": 32220,

  "rttvar": 18,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 7.00006890296936,

  "end": 8.0000648498535156,

  "seconds": 0.99999594688415527,

  "bytes": 420741120,

  "bits_per_second": 3365942602.555295,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 8.0000648498535156,

  "end": 9.00016188621521,

  "seconds": 1.0000970363616943,

  "bytes": 446955520,

  "bits_per_second": 3575297226.1651969,

  "retransmits": 0,

  "snd_cwnd": 14943360,

  "rtt": 32307,

  "rttvar": 100,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 8.0000648498535156,

  "end": 9.00016188621521,

  "seconds": 1.0000970363616943,

  "bytes": 446955520,

  "bits_per_second": 3575297226.1651969,

  "retransmits": 0,

  "omitted": false

  }

  }, {

  "streams": [{

  "socket": 5,

  "start": 9.00016188621521,

  "end": 10.000082969665527,

  "seconds": 0.99992108345031738,

  "bytes": 475791360,

  "bits_per_second": 3806631286.2070212,

  "retransmits": 0,

  "snd_cwnd": 15972888,

  "rtt": 32295,

  "rttvar": 73,

  "pmtu": 1500,

  "omitted": false

  }],

  "sum": {

  "start": 9.00016188621521,

  "end": 10.000082969665527,

  "seconds": 0.99992108345031738,

  "bytes": 475791360,

  "bits_per_second": 3806631286.2070212,

  "retransmits": 0,

  "omitted": false

  }

  }],

  "end": {

  "streams": [{

  "sender": {

  "socket": 5,

  "start": 0,

  "end": 10.000082969665527,

  "seconds": 10.000082969665527,

  "bytes": 3876228536,

  "bits_per_second": 3100957100.2626576,

  "retransmits": 540,

  "max_snd_cwnd": 46496728,

  "max_rtt": 33024,

  "min_rtt": 32220,

  "mean_rtt": 32359

  },

  "receiver": {

  "socket": 5,

  "start": 0,

  "end": 10.032367944717407,

  "seconds": 10.000082969665527,

  "bytes": 3870083304,

  "bits_per_second": 3086077644.1420784

  }

  }],

  "sum_sent": {

  "start": 0,

  "end": 10.000082969665527,

  "seconds": 10.000082969665527,

  "bytes": 3876228536,

  "bits_per_second": 3100957100.2626576,

  "retransmits": 540

  },

  "sum_received": {

  "start": 0,

  "end": 10.032367944717407,

  "seconds": 10.032367944717407,

  "bytes": 3870083304,

  "bits_per_second": 3086077644.1420784

  },

  "cpu_utilization_percent": {

  "host_total": 9.4908947095796,

  "host_user": 0.18213711857610748,

  "host_system": 9.3321228039586224,

  "remote_total": 25.824065887899621,

  "remote_user": 0.27289529139099128,

  "remote_system": 25.526253522203135

  },

  "sender_tcp_congestion": "htcp",

  "receiver_tcp_congestion": "htcp"

  }

  }

  


Error from esdis-pt1-10g.eosdis.nasa.gov:

  No error.


Diagnostics from edclxw41.cr.usgs.gov:

  No diagnostics.


Error from edclxw41.cr.usgs.gov:

  iperf3 returned an error: exiting

2019-03-05T18:30:10 Fetching next run from https://esdis-pt1-10g.eosdis.nasa.gov/pscheduler/tasks/388e312e-a378-426e-9da8-523350b9719d/runs/next


No further runs scheduled.


*******************************



The following files were upgraded:

Mar 02 06:59:12 Updated: perfsonar-common.noarch 4.1.6-1.el7

Mar 02 06:59:13 Updated: libperfsonar-perl.noarch 4.1.6-1.el7

Mar 02 06:59:13 Updated: pscheduler-account.noarch 1.1.6-1.el7

Mar 02 06:59:14 Updated: libperfsonar-pscheduler-perl.noarch 4.1.6-1.el7

Mar 02 06:59:15 Updated: libperfsonar-psconfig-perl.noarch 4.1.6-1.el7

Mar 02 06:59:15 Updated: perfsonar-psconfig-utils.noarch 4.1.6-1.el7

Mar 02 06:59:15 Updated: perfsonar-psconfig-pscheduler-devel.noarch 4.1.6-1.el7

Mar 02 06:59:16 Updated: libperfsonar-sls-perl.noarch 4.1.6-1.el7

Mar 02 06:59:16 Updated: libperfsonar-esmond-perl.noarch 4.1.6-1.el7

Mar 02 06:59:17 Updated: pscheduler-jq-library.noarch 1.1.6-1.el7

Mar 02 06:59:20 Updated: python-pscheduler.noarch 1.3.7-1.el7

Mar 02 06:59:21 Updated: pscheduler-core.noarch 1.1.6-1.el7

Mar 02 06:59:28 Updated: pscheduler-server.noarch 1.1.6-2.el7

Mar 02 06:59:30 Updated: pscheduler-test-throughput.noarch 1.1.6-1.el7

Mar 02 06:59:32 Updated: pscheduler-test-trace.noarch 1.1.6-1.el7

Mar 02 06:59:33 Updated: pscheduler-test-idle.noarch 1.1.6-1.el7

Mar 02 06:59:35 Updated: pscheduler-test-latency.noarch 1.1.6-1.el7

Mar 02 06:59:36 Updated: pscheduler-test-rtt.noarch 1.1.6-1.el7

Mar 02 06:59:38 Updated: pscheduler-test-http.noarch 1.1.6-1.el7

Mar 02 06:59:39 Updated: pscheduler-test-latencybg.noarch 1.1.6-1.el7

Mar 02 06:59:41 Updated: pscheduler-test-simplestream.noarch 1.1.6-1.el7

Mar 02 06:59:42 Updated: pscheduler-test-dns.noarch 1.1.6-1.el7

Mar 02 06:59:44 Updated: pscheduler-tool-dnspy.noarch 1.1.6-1.el7

Mar 02 06:59:46 Updated: pscheduler-tool-simplestreamer.noarch 1.1.6-1.el7

Mar 02 06:59:47 Updated: pscheduler-tool-powstream.noarch 1.1.6-1.el7

Mar 02 06:59:49 Updated: pscheduler-tool-psurl.noarch 1.1.6-1.el7

Mar 02 06:59:50 Updated: pscheduler-tool-ping.noarch 1.1.6-1.el7

Mar 02 06:59:52 Updated: pscheduler-tool-owping.noarch 1.1.6-1.el7

Mar 02 06:59:54 Updated: pscheduler-tool-twping.noarch 1.1.6-1.el7

Mar 02 06:59:55 Updated: pscheduler-tool-snooze.noarch 1.1.6-1.el7

Mar 02 06:59:57 Updated: pscheduler-tool-sleep.noarch 1.1.6-1.el7

Mar 02 06:59:58 Updated: pscheduler-tool-psclock.noarch 1.1.6-1.el7

Mar 02 07:00:00 Updated: pscheduler-tool-sleepbgm.noarch 1.1.6-1.el7

Mar 02 07:00:02 Updated: pscheduler-tool-tracepath.noarch 1.1.6-1.el7

Mar 02 07:00:03 Updated: pscheduler-tool-paris-traceroute.noarch 1.1.6-1.el7

Mar 02 07:00:05 Updated: pscheduler-tool-traceroute.noarch 1.1.6-1.el7

Mar 02 07:00:07 Updated: pscheduler-tool-nuttcp.noarch 1.1.6-1.el7

Mar 02 07:00:08 Updated: pscheduler-tool-iperf2.noarch 1.1.6-1.el7

Mar 02 07:00:10 Updated: pscheduler-tool-iperf3.noarch 1.1.6-1.el7

Mar 02 07:00:11 Updated: pscheduler-archiver-failer.noarch 1.1.6-1.el7

Mar 02 07:00:13 Updated: pscheduler-context-linuxnns.noarch 1.1.6-1.el7

Mar 02 07:00:14 Updated: pscheduler-archiver-esmond.noarch 1.1.6-1.el7

Mar 02 07:00:16 Updated: pscheduler-test-idleex.noarch 1.1.6-1.el7





Archive powered by MHonArc 2.6.19.

Top of Page