My five minute updates are randomly missing since 1:25pm 26-05-2021

Hi pvoutput.org server administrator,

I am hoping that you can help me with an ongoing problem for me that started around 1:25pm 26-05-2021?

I have been successfuly uploading my five minute data (HTTP POSTs) from 28/12/2017 09:05 uploading values to pvoutput.org

  • from my alienware Laptop on MyRepublic ISP Chorus UFB fibre link

The last fully succesful day was on the 25-05-2021 where all DATA POSTs are all
OK with no missing data.


Then from 26-05-2021 1:25PM was the last completed five minute update

  • then pvoutput.org starts randomly missing some of my five minute updates.

The issue appears to be that sometimes pvoutput.org is not receiving my
initial HTTP port 80 [SYN] to start a new connection; or it does receive it
and ignores it; or it responds with a correct SYN ACK, but I never receive
it.

I am using a Linux system using a home grown set of BASH scripts which use
curl to POST the five minute data to pvoutput.org - code snippet as follows:

now using this version for uploading averages to pvoutput.org from 02/12/2017 13:05

if [ $enasolarOutputPower -gt 0 ]; then
/bin/echo -e “inside if $enasolarOutputPower is -gt 0”
curl -s -d “d=”$yyyymmdd -d “t=”$hhmmtime -d “v2=”$enasolarOutputPower -d “v4=”$housepower -d “v5=”$temperature -H "X-Pvoutput-Apikey: "$APIKEY -H "X-Pvoutput-SystemId: "$SYSID http://pvoutput.org/service/r2/addstatus.jsp
else
/bin/echo -e “inside if $enasolarOutputPower not -gt 0”
curl -s -d “d=”$yyyymmdd -d “t=”$hhmmtime -d “v4=”$housepower -d “v5=”$temperature -H "X-Pvoutput-Apikey: "$APIKEY -H "X-Pvoutput-SystemId: "$SYSID http://pvoutput.org/service/r2/addstatus.jsp
fi

I am in Upper Hutt, Wellington New Zealand.

I am hoping that a pvoutput.org server administrator can run some checks for me
please, using tshark / wireshark to confirm that they are seeing my five minute HTTP POSTs,
and that the pvoutput.org server is responding correctly.

From what I can gather from my testing is that pvoutput.org is hosted by linode in
LAX USA. (as seen from the mtr traceroutes to pvoutput.org shown below)

I have attached a text file with a packet capture also showning the missing
data as in the repeated SYN retries ([TCP Retransmission] 40550 → 80 [SYN] )
that I am seeing in my traffic capture. (file also attached)

The following shows the results of 27-05-2021 between 13:00 and 15:41 my results from the
pvoutput.org web site for my HTTP POSTs showing randomly missing data (the gaps show the missing data).

https://pvoutput.org/intraday.jsp?id=22129&sid=XXXXXX&dt=20210526&gs=0&m=1

Gemstone-Birchville 3.710kW Compare: Tips

Date Time Energy Efficiency Power Average Normalised Temperature Voltage Energy Used Power Used

27/05/21 3:50PM 11.883kWh 3.203kWh/kW 476W 480W 0.129kW/kW 12.8C - 9.759kWh 548W
27/05/21 3:45PM 11.843kWh 3.192kWh/kW 580W 576W 0.155kW/kW 13.0C - 9.713kWh 270W
27/05/21 3:40PM 11.795kWh 3.179kWh/kW 418W 420W 0.113kW/kW 13.0C - 9.690kWh 196W

27/05/21 3:25PM 11.690kWh 3.151kWh/kW 403W 408W 0.110kW/kW 13.5C - 9.641kWh 312W
27/05/21 3:20PM 11.656kWh 3.142kWh/kW 274W - - 13.7C - 9.615kWh 197W

27/05/21 3:00PM 11.587kWh 3.123kWh/kW 1,572W 1,572W 0.424kW/kW 13.9C - 9.566kWh 365W
27/05/21 2:55PM 11.456kWh 3.088kWh/kW 1,758W 1,758W 0.474kW/kW 14.0C - 9.536kWh 209W

27/05/21 2:45PM 11.163kWh 3.009kWh/kW 1,878W 1,878W 0.506kW/kW 14.2C - 9.501kWh 315W

27/05/21 2:35PM 10.850kWh 2.925kWh/kW 1,335W 1,336W 0.360kW/kW 13.5C - 9.448kWh 2,161W

27/05/21 2:20PM 10.516kWh 2.835kWh/kW 1,825W 1,824W 0.492kW/kW 13.8C - 8.908kWh 348W
27/05/21 2:15PM 10.364kWh 2.794kWh/kW 2,137W 2,136W 0.576kW/kW 13.8C - 8.879kWh 227W
27/05/21 2:10PM 10.186kWh 2.746kWh/kW 2,196W - - 13.9C - 8.860kWh 242W

27/05/21 1:45PM 9.637kWh 2.598kWh/kW 2,360W 2,364W 0.637kW/kW 13.6C - 8.799kWh 216W
27/05/21 1:40PM 9.440kWh 2.544kWh/kW 2,390W 2,388W 0.644kW/kW 13.6C - 8.781kWh 355W
27/05/21 1:35PM 9.241kWh 2.491kWh/kW 2,416W 2,412W 0.650kW/kW 13.7C - 8.751kWh 365W
27/05/21 1:30PM 9.040kWh 2.437kWh/kW 2,441W 2,436W 0.657kW/kW 13.8C - 8.721kWh 224W
27/05/21 1:25PM 8.837kWh 2.382kWh/kW 2,459W 2,460W 0.663kW/kW 13.8C - 8.702kWh 228W

27/05/21 1:10PM 8.222kWh 2.216kWh/kW 2,526W 2,532W 0.682kW/kW 13.7C - 8.645kWh 2,163W
27/05/21 1:05PM 8.011kWh 2.159kWh/kW 2,553W 2,556W 0.689kW/kW 13.6C - 8.465kWh 3,573W
27/05/21 1:00PM 7.798kWh 2.102kWh/kW 2,555W - - 13.7C - 8.167kWh 3,551W

27/05/21 12:40PM 7.159kWh 1.930kWh/kW 2,533W 2,532W 0.682kW/kW 13.7C - 7.279kWh 4,404W


Testing to pvoutput.org as follows:

mtr (traceroute & PING) from me 158.140.231.55 from alienware Laptop on MyRepublic ISP
on Chorus UFB fibre 1G link to pvoutput.org 45.56.66.169

adrian@alienware:~/sh$ date ; mtr -c 1 -rn -oLDSRNBAWVGJMXI pvoutput.org ; date
Thu May 27 16:08:04 NZST 2021
Start: 2021-05-27T16:08:04+1200
HOST: alienware Loss% Drop Snt Rcv Last Best Avg Wrst StDev Gmean Jttr Javg Jmax Jint
1.|-- 101.100.136.2 0.0% 0 1 1 10.8 10.8 10.8 10.8 0.0 10.8 0.0 0.0 0.0 0.0
2.|-- 175.45.93.173 0.0% 0 1 1 11.6 11.6 11.6 11.6 0.0 11.6 0.0 0.0 0.0 0.0
3.|-- 114.31.202.36 0.0% 0 1 1 136.7 136.7 136.7 136.7 0.0 136.7 0.0 0.0 0.0 0.0
4.|-- 114.31.199.72 0.0% 0 1 1 135.5 135.5 135.5 135.5 0.0 135.5 0.0 0.0 0.0 0.0
5.|-- ??? 100.0 1 1 0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
6.|-- 45.79.12.3 0.0% 0 1 1 169.1 169.1 169.1 169.1 0.0 169.1 0.0 0.0 0.0 0.0
7.|-- 45.56.66.169 0.0% 0 1 1 167.9 167.9 167.9 167.9 0.0 167.9 0.0 0.0 0.0 0.0
Thu May 27 16:08:10 NZST 2021
adrian@alienware:~/sh$

adrian@alienware:~/sh$ date ; mtr -c 1 -r -oLDSRNBAWVGJMXI pvoutput.org ; date
Thu May 27 16:14:27 NZST 2021
Start: 2021-05-27T16:14:27+1200
HOST: alienware Loss% Drop Snt Rcv Last Best Avg Wrst StDev Gmean Jttr Javg Jmax Jint
1.|-- 101-100-136-2.myrepublic. 0.0% 0 1 1 10.4 10.4 10.4 10.4 0.0 10.4 0.0 0.0 0.0 0.0
2.|-- ten-1-2-0-399.bdr01.akl05 0.0% 0 1 1 11.8 11.8 11.8 11.8 0.0 11.8 0.0 0.0 0.0 0.0
3.|-- be13.cor01.alb01.akl.nz.v 0.0% 0 1 1 136.4 136.4 136.4 136.4 0.0 136.4 0.0 0.0 0.0 0.0
4.|-- be200.bdr04.lax01.ca.us.v 0.0% 0 1 1 135.1 135.1 135.1 135.1 0.0 135.1 0.0 0.0 0.0 0.0
5.|-- ??? 100.0 1 1 0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
6.|-- if-3-6.csw2-rin1.linode.c 0.0% 0 1 1 169.1 169.1 169.1 169.1 0.0 169.1 0.0 0.0 0.0 0.0
7.|-- li916-169.members.linode. 0.0% 0 1 1 168.0 168.0 168.0 168.0 0.0 168.0 0.0 0.0 0.0 0.0
Thu May 27 16:14:33 NZST 2021
adrian@alienware:~/sh$


1000 mtr/PING test to pvoutput.org

adrian@alienware:~/sh$ date ; mtr -c 1000 -r -oLDSRNBAWVGJMXI pvoutput.org ; date
Thu May 27 16:44:13 NZST 2021
Start: 2021-05-27T16:44:13+1200
HOST: alienware Loss% Drop Snt Rcv Last Best Avg Wrst StDev Gmean Jttr Javg Jmax Jint
1.|-- 101-100-136-2.myrepublic. 1.0% 10 1000 990 10.3 10.0 10.2 11.9 0.3 10.2 0.5 0.3 1.7 4.9
2.|-- ten-1-2-0-399.bdr01.akl05 0.0% 0 1000 1000 11.9 11.0 11.9 37.1 2.1 11.8 0.5 1.0 18.4 8.8
3.|-- be13.cor01.alb01.akl.nz.v 0.0% 0 1000 1000 136.4 135.9 136.1 137.3 0.3 136.1 0.1 0.3 1.0 3.2
4.|-- be200.bdr04.lax01.ca.us.v 22.9% 229 1000 771 135.1 134.9 135.2 142.5 0.6 135.2 0.1 0.4 7.4 5.6
5.|-- ??? 100.0 1000 1000 0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
6.|-- if-3-6.csw2-rin1.linode.c 0.1% 1 1000 999 169.0 168.6 169.0 195.7 1.3 169.0 0.8 0.7 26.5 14.9
7.|-- li916-169.members.linode. 0.0% 0 1000 1000 168.1 167.2 167.6 178.6 0.6 167.6 0.0 0.5 10.9 5.6
Thu May 27 17:00:58 NZST 2021
adrian@alienware:~/sh$


data from my log showing each correct five minute data bewteen 12:30 and 16:00:

less /home/adrian/sh/pvoutput-processing/pvoutput-5min-average-upload-values.log

20210527,12:30,2541,3945,13.5
20210527,12:35,2542,3680,13.4
20210527,12:40,2533,4404,13.7
20210527,12:45,2526,3750,13.7
20210527,12:50,2545,3834,13.8
20210527,12:55,2564,3721,13.7
20210527,13:00,2555,3551,13.7
20210527,13:05,2553,3573,13.6
20210527,13:10,2526,2163,13.7
20210527,13:15,2505,399,13.7
20210527,13:20,2478,296,13.8
20210527,13:25,2459,228,13.8
20210527,13:30,2441,224,13.8
20210527,13:35,2416,365,13.7
20210527,13:40,2390,355,13.6
20210527,13:45,2360,216,13.6
20210527,13:50,2303,214,13.6
20210527,13:55,2269,304,13.6
20210527,14:00,2232,352,13.6
20210527,14:05,2197,265,13.8
20210527,14:10,2196,242,13.9
20210527,14:15,2137,227,13.8
20210527,14:20,1825,348,13.8
20210527,14:25,1694,696,13.8
20210527,14:30,1456,1472,13.7
20210527,14:35,1335,2161,13.5
20210527,14:40,2055,825,13.6
20210527,14:45,1878,315,14.2
20210527,14:50,1724,209,14.2
20210527,14:55,1758,209,14.0
20210527,15:00,1572,365,13.9
20210527,15:05,1538,759,13.7
20210527,15:10,1581,324,13.6
20210527,15:15,1060,196,13.7
20210527,15:20,274,197,13.7
20210527,15:25,403,312,13.5
20210527,15:30,527,333,13.2
20210527,15:35,1421,205,12.9
20210527,15:40,418,196,13.0
20210527,15:45,580,270,13.0
20210527,15:50,476,548,12.8
20210527,15:55,212,540,12.8
20210527,16:00,94,540,12.8

Kind regards, Adrian Smith

I can send you a full traffic capture file showing the problems; but here is a sample as follows:

a failing update
470 2021-05-27 15:15:32.011976358 158.140.231.55 → 45.56.66.169 TCP 74 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055836488 TSecr=0 WS=128
471 2021-05-27 15:15:33.036389956 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055837512 TSecr=0 WS=128
472 2021-05-27 15:15:35.048416677 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055839524 TSecr=0 WS=128
473 2021-05-27 15:15:39.144379817 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055843620 TSecr=0 WS=128
474 2021-05-27 15:15:47.336374214 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055851812 TSecr=0 WS=128
475 2021-05-27 15:16:03.468397951 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055867945 TSecr=0 WS=128
476 2021-05-27 15:16:36.744377564 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 45012 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1055901222 TSecr=0 WS=128

a successful update
477 2021-05-27 15:20:31.438146533 158.140.231.55 → 45.56.66.169 TCP 74 45198 → 80 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=1056135921 TSecr=0 WS=128
478 2021-05-27 15:20:31.622753971 45.56.66.169 → 158.140.231.55 TCP 74 80 → 45198 [SYN, ACK] Seq=0 Ack=1 Win=7240 Len=0 MSS=1460 SACK_PERM=1 TSval=704332017 TSecr=1056135921 WS=4
479 2021-05-27 15:20:31.622810001 158.140.231.55 → 45.56.66.169 TCP 66 45198 → 80 [ACK] Seq=1 Ack=1 Win=64256 Len=0 TSval=1056136106 TSecr=704332017
480 2021-05-27 15:20:31.622909915 158.140.231.55 → 45.56.66.169 HTTP 365 POST /service/r2/addstatus.jsp HTTP/1.1 (application/x-www-form-urlencoded)
481 2021-05-27 15:20:31.808380489 45.56.66.169 → 158.140.231.55 HTTP 335 HTTP/1.1 200 OK (text/plain)
482 2021-05-27 15:20:31.808562298 158.140.231.55 → 45.56.66.169 TCP 66 45198 → 80 [FIN, ACK] Seq=300 Ack=271 Win=64128 Len=0 TSval=1056136291 TSecr=704332202
483 2021-05-27 15:20:31.993060641 45.56.66.169 → 158.140.231.55 TCP 66 80 → 45198 [ACK] Seq=271 Ack=301 Win=6944 Len=0 TSval=704332387 TSecr=1056136291

another failing update
484 2021-05-27 15:25:25.629235682 158.140.231.55 → 45.56.66.169 TCP 74 36296 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=3702875210 TSecr=0 WS=128
485 2021-05-27 15:25:25.880028585 158.140.231.55 → 45.56.66.169 TCP 74 36298 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=3702875461 TSecr=0 WS=128
486 2021-05-27 15:25:26.636555332 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 36296 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=3702876217 TSecr=0 WS=128
487 2021-05-27 15:25:26.893598473 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 36298 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=3702876473 TSecr=0 WS=128
488 2021-05-27 15:25:28.653631172 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 36296 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=3702878233 TSecr=0 WS=128
489 2021-05-27 15:25:28.908606823 158.140.231.55 → 45.56.66.169 TCP 74 [TCP Retransmission] 36298 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 SACK_PERM=1 TSval=3702878489 TSecr=0 WS=128

Please use the secure endpoint instead https://pvoutput.org/service/r2/addstatus.jsp

Plain http support will be dropped in the future.

The client code should be handling any network failures and retrying at the next attempt.

Thanks bankstownbloke; good advice.

My client is currently doing six retries (as shown in the sample packet trace in my original probblem description), but then my client gives up; so I will try to modify my code to check for a returned HTTP/1.1 200 OK status, and keep retrying the POST until it succeeds for that particular interval.

I will also try to change from HTTP to HTTPS as you suggest.

I have found that my problem is just not with pvoutput.org, but I am getting similar issues with other US sites; here is another test that I ran to pvoutput.org showing the problem:


below the httping test to pvoutput.org is showing random “connect time out”

adrian@alienware:~/info$ date ; httping pvoutput.org -c 20 ; date
Sun May 30 17:22:58 NZST 2021
PING pvoutput.org:80 (/):
connect time out

connected to 45.56.66.169:80 (109 bytes), seq=1 time=339.34 ms
connected to 45.56.66.169:80 (109 bytes), seq=2 time=338.07 ms
connected to 45.56.66.169:80 (109 bytes), seq=3 time=338.06 ms
connect time out

connected to 45.56.66.169:80 (109 bytes), seq=5 time=338.40 ms
connected to 45.56.66.169:80 (109 bytes), seq=6 time=344.85 ms
connected to 45.56.66.169:80 (109 bytes), seq=7 time=337.30 ms
connected to 45.56.66.169:80 (109 bytes), seq=8 time=339.23 ms
connected to 45.56.66.169:80 (109 bytes), seq=9 time=337.66 ms
connected to 45.56.66.169:80 (109 bytes), seq=10 time=341.43 ms
connect time out

connect time out

connected to 45.56.66.169:80 (109 bytes), seq=13 time=338.02 ms
connect time out

connect time out

connected to 45.56.66.169:80 (109 bytes), seq=16 time=337.79 ms
connected to 45.56.66.169:80 (109 bytes), seq=17 time=339.95 ms
connected to 45.56.66.169:80 (109 bytes), seq=18 time=337.57 ms
connected to 45.56.66.169:80 (109 bytes), seq=19 time=346.38 ms
http://pvoutput.org/ ping statistics —

20 connects, 14 ok, 30.00% failed, time 204927ms

round-trip min/avg/max = 337.3/339.6/346.4 ms
Sun May 30 17:26:23 NZST 2021
adrian@alienware:~/info$

I reported the problem to my ISP (MyRepublic) last night; and I have now received an email from them advising of an issue they are investigating as follows:

Upstream issue with some US destinations

New incident: Identified

We’re currently investigating an issue with traffic reaching some destinations within the United States, and have the upstream providers involved looking for a fix for this issue. We apologize for any inconvenience this may be causing with US server reachability, but will provide further updates as they become available

Time posted

May 31, 10:20 NZST

Components affected

Fibre - National VDSL - National

Thanks again for your help.

Kind regards, Adrian Smith

Thanks - please follow up with the ISP