Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Not getting a 201 on POST and loosing data #641

Closed
neilh10 opened this issue Feb 13, 2023 · 3 comments
Closed

Not getting a 201 on POST and loosing data #641

neilh10 opened this issue Feb 13, 2023 · 3 comments

Comments

@neilh10
Copy link

neilh10 commented Feb 13, 2023

For a number of systems that I am monitoring closely,
on a POST, I am not getting an ACK 201 though the data is mostly showing in the downloaded data.

Before [2023-02-02 10:45:39] I was getting reliable ACK 201

For the following posts, all timing out after 15seconds, the first two - the sequence or "Sampling number" makes it into the database
"6e5516fc-cdcf-46a6-9c30-d96f3a016b0d":122
and 123.

and the second two 124 and 125 are missing from the download data.

https://monitormywatershed.org/sites/tu_rcru_test06/

[2023-02-11 22:20:15] Waiting up to 15000 ms for Digi XBee3 Cellular LTE-M to respond to AT commands...
[2023-02-11 22:20:16] Connecting to the Internet with Digi XBee3 Cellular LTE-M
[2023-02-11 22:20:24]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-11 22:20:32]  WATCHDOG ISR barksUntilReset 73 <--WatchDogAVR
[2023-02-11 22:20:40]  WATCHDOG ISR barksUntilReset 72 <--WatchDogAVR
[2023-02-11 22:20:44] Connected Internet
[2023-02-11 22:20:44] ... Watchdog low barksUntilReset 72  expected 75
[2023-02-11 22:20:44] 
[2023-02-11 22:20:44] pubDQTR Sending data to [ 0 ] monitormywatershed.org:80
[2023-02-11 22:20:44] POST /api/data-stream/ HTTP/1.1
[2023-02-11 22:20:44] Host: monitormywatershed.org
[2023-02-11 22:20:44] TOKEN: 5083cf3d-69cd-46fa-8d3a-0e3ba0b9e8fd
[2023-02-11 22:20:44] Content-Length: 409
[2023-02-11 22:20:44] Content-Type: application/json
[2023-02-11 22:20:44] 
[2023-02-11 22:20:44] {"sampling_feature":"939d54e3-b92f-4e8d-bae5-1a5b4ae29193","timestamp":"2023-02-11T22:05:00-08:00","6e5516fc-cdcf-46a6-9c30-d96f3a016b0d":122,"fe4b74dd-598a-440d-b7d2-db0119584d5d":3.927,"5cbc0f3a-1b41-43cc-822f-374513de1899":6.30,"41330794-27cf-4130-b2b0-a1cffefe8ba2":0.0716,"941ba4ed-f7d5-4c71-8356-591899ec6e1a":66.41,"d5f4c4dc-421d-436b-9989-99cb94ebc50a":6.26,"ffdc5b73-b800-4957-ab19-b25feba69dde":-57}
[2023-02-11 22:20:44] 
[2023-02-11 22:20:52]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-11 22:21:00]  WATCHDOG ISR barksUntilReset 73 <--WatchDogAVR
[2023-02-11 22:21:01] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-02-11 22:21:01] ... Watchdog low barksUntilReset 73  expected 75
[2023-02-11 22:21:01] POST /api/data-stream/ HTTP/1.1
[2023-02-11 22:21:01] Host: monitormywatershed.org
[2023-02-11 22:21:01] TOKEN: 5083cf3d-69cd-46fa-8d3a-0e3ba0b9e8fd
[2023-02-11 22:21:01] Content-Length: 409
[2023-02-11 22:21:01] Content-Type: application/json
[2023-02-11 22:21:01] 
[2023-02-11 22:21:01] {"sampling_feature":"939d54e3-b92f-4e8d-bae5-1a5b4ae29193","timestamp":"2023-02-11T22:10:00-08:00","6e5516fc-cdcf-46a6-9c30-d96f3a016b0d":123,"fe4b74dd-598a-440d-b7d2-db0119584d5d":3.927,"5cbc0f3a-1b41-43cc-822f-374513de1899":6.24,"41330794-27cf-4130-b2b0-a1cffefe8ba2":0.0713,"941ba4ed-f7d5-4c71-8356-591899ec6e1a":67.13,"d5f4c4dc-421d-436b-9989-99cb94ebc50a":6.00,"ffdc5b73-b800-4957-ab19-b25feba69dde":-57}
[2023-02-11 22:21:01] 
[2023-02-11 22:21:09]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-11 22:21:17]  WATCHDOG ISR barksUntilReset 73 <--WatchDogAVR
[2023-02-11 22:21:17] -- Response Code -- 504 waited  15009 mS Timeout 15000
[2023-02-11 22:21:17] ... Watchdog low barksUntilReset 73  expected 75
[2023-02-11 22:21:18] POST /api/data-stream/ HTTP/1.1
[2023-02-11 22:21:18] Host: monitormywatershed.org
[2023-02-11 22:21:18] TOKEN: 5083cf3d-69cd-46fa-8d3a-0e3ba0b9e8fd
[2023-02-11 22:21:18] Content-Length: 409
[2023-02-11 22:21:18] Content-Type: application/json
[2023-02-11 22:21:18] 
[2023-02-11 22:21:18] {"sampling_feature":"939d54e3-b92f-4e8d-bae5-1a5b4ae29193","timestamp":"2023-02-11T22:15:00-08:00","6e5516fc-cdcf-46a6-9c30-d96f3a016b0d":124,"fe4b74dd-598a-440d-b7d2-db0119584d5d":3.927,"5cbc0f3a-1b41-43cc-822f-374513de1899":6.17,"41330794-27cf-4130-b2b0-a1cffefe8ba2":0.0713,"941ba4ed-f7d5-4c71-8356-591899ec6e1a":67.01,"d5f4c4dc-421d-436b-9989-99cb94ebc50a":6.02,"ffdc5b73-b800-4957-ab19-b25feba69dde":-57}
[2023-02-11 22:21:18] 
[2023-02-11 22:21:25]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-11 22:21:34]  WATCHDOG ISR barksUntilReset 73 <--WatchDogAVR
[2023-02-11 22:21:34] -- Response Code -- 504 waited  15000 mS Timeout 15000
[2023-02-11 22:21:34] ... Watchdog low barksUntilReset 73  expected 75
[2023-02-11 22:21:34] POST /api/data-stream/ HTTP/1.1
[2023-02-11 22:21:34] Host: monitormywatershed.org
[2023-02-11 22:21:34] TOKEN: 5083cf3d-69cd-46fa-8d3a-0e3ba0b9e8fd
[2023-02-11 22:21:34] Content-Length: 409
[2023-02-11 22:21:34] Content-Type: application/json
[2023-02-11 22:21:34] 
[2023-02-11 22:21:34] {"sampling_feature":"939d54e3-b92f-4e8d-bae5-1a5b4ae29193","timestamp":"2023-02-11T22:20:00-08:00","6e5516fc-cdcf-46a6-9c30-d96f3a016b0d":125,"fe4b74dd-598a-440d-b7d2-db0119584d5d":3.927,"5cbc0f3a-1b41-43cc-822f-374513de1899":6.11,"41330794-27cf-4130-b2b0-a1cffefe8ba2":0.0709,"941ba4ed-f7d5-4c71-8356-591899ec6e1a":67.62,"d5f4c4dc-421d-436b-9989-99cb94ebc50a":5.81,"ffdc5b73-b800-4957-ab19-b25feba69dde":-57}
[2023-02-11 22:21:34] 
[2023-02-11 22:21:42]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-11 22:21:50]  WATCHDOG ISR barksUntilReset 73 <--WatchDogAVR
[2023-02-11 22:21:51] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-02-11 22:21:51] ... Watchdog low barksUntilReset 73  expected 75
[2023-02-11 22:21:51] Sent 4 readings in 66.53 sec. Queued readings= 6619

For a 2nd system that was being monitored till [2023-02-08 18:14:01],

it was reliable until the following POST, and then seemed to get a lot less reliable.
https://monitormywatershed.org/sites/tu_rcru_test07/

[2023-02-02 10:35:40] pubDQTR Sending data to [ 0 ] monitormywatershed.org:80
[2023-02-02 10:35:40] POST /api/data-stream/ HTTP/1.1
[2023-02-02 10:35:40] Host: monitormywatershed.org
[2023-02-02 10:35:40] TOKEN: cc8c415a-b35a-44c8-85c2-cf2311eca30e
[2023-02-02 10:35:40] Content-Length: 410
[2023-02-02 10:35:40] Content-Type: application/json
[2023-02-02 10:35:40] 
[2023-02-02 10:35:40] {"sampling_feature":"95072e6b-9796-4fee-b686-80bd3a355826","timestamp":"2023-02-02T10:30:00-08:00","74a1fed5-7829-4e88-9560-fc136411efcd":8496,"d282772a-0ca4-492c-8e8d-ad7137ddecc1":4.154,"61fff54d-ecb2-4c04-8961-14ff14837ae3":5.63,"58d5b96d-8f5d-45ab-a310-a44ffa68ec0e":0.0560,"d3271afd-c1c5-4375-9841-bbc93b5917ce":71.39,"fef0a40d-6954-4a7d-9087-de5c66b57f83":5.19,"e2199c70-ac6b-495d-b514-9850e21b6423":-57}
[2023-02-02 10:35:40] 
[2023-02-02 10:35:48]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-02 10:35:48] -- Response Code -- 504 waited  7000 mS Timeout 7000
[2023-02-02 10:35:48] ... Watchdog low barksUntilReset 74  expected 75
[2023-02-02 10:35:49] POST /api/data-stream/ HTTP/1.1
[2023-02-02 10:35:49] Host: monitormywatershed.org
[2023-02-02 10:35:49] TOKEN: cc8c415a-b35a-44c8-85c2-cf2311eca30e
[2023-02-02 10:35:49] Content-Length: 410
[2023-02-02 10:35:49] Content-Type: application/json
[2023-02-02 10:35:49] 
[2023-02-02 10:35:49] {"sampling_feature":"95072e6b-9796-4fee-b686-80bd3a355826","timestamp":"2023-02-02T10:35:00-08:00","74a1fed5-7829-4e88-9560-fc136411efcd":8497,"d282772a-0ca4-492c-8e8d-ad7137ddecc1":4.154,"61fff54d-ecb2-4c04-8961-14ff14837ae3":5.74,"58d5b96d-8f5d-45ab-a310-a44ffa68ec0e":0.0556,"d3271afd-c1c5-4375-9841-bbc93b5917ce":72.19,"fef0a40d-6954-4a7d-9087-de5c66b57f83":5.04,"e2199c70-ac6b-495d-b514-9850e21b6423":-57}
[2023-02-02 10:35:49] 
[2023-02-02 10:35:56]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-02 10:35:57] -- Response Code -- 201 waited  6914 mS Timeout 7000
[2023-02-02 10:35:57] ... Watchdog low barksUntilReset 74  expected 75
[2023-02-02 10:35:58] Sent 2 readings in 18.59 sec. Queued readings= 1
[2023-02-02 10:36:00] POST /api/data-stream/ HTTP/1.1
[2023-02-02 10:36:00] Host: monitormywatershed.org
[2023-02-02 10:36:00] TOKEN: cc8c415a-b35a-44c8-85c2-cf2311eca30e
[2023-02-02 10:36:00] Content-Length: 410
[2023-02-02 10:36:00] Content-Type: application/json
[2023-02-02 10:36:00] 
[2023-02-02 10:36:00] {"sampling_feature":"95072e6b-9796-4fee-b686-80bd3a355826","timestamp":"2023-02-02T10:30:00-08:00","74a1fed5-7829-4e88-9560-fc136411efcd":8496,"d282772a-0ca4-492c-8e8d-ad7137ddecc1":4.154,"61fff54d-ecb2-4c04-8961-14ff14837ae3":5.63,"58d5b96d-8f5d-45ab-a310-a44ffa68ec0e":0.0560,"d3271afd-c1c5-4375-9841-bbc93b5917ce":71.39,"fef0a40d-6954-4a7d-9087-de5c66b57f83":5.19,"e2199c70-ac6b-495d-b514-9850e21b6423":-57}
[2023-02-02 10:36:00] 
[2023-02-02 10:36:04] -- Response Code -- 201 waited  2687 mS Timeout 7000
[2023-02-02 10:36:04] seQCF Que for next pass unsent records 0

Starting with this Sequence Number=9907 "74a1fed5-7829-4e88-9560-fc136411efcd":9907
it is also not having the data appear in the database.

[2023-02-07 09:51:09] {"sampling_feature":"95072e6b-9796-4fee-b686-80bd3a355826","timestamp":"2023-02-07T09:50:00-08:00","74a1fed5-7829-4e88-9560-fc136411efcd":9907,"d282772a-0ca4-492c-8e8d-ad7137ddecc1":4.154,"61fff54d-ecb2-4c04-8961-14ff14837ae3":6.92,"58d5b96d-8f5d-45ab-a310-a44ffa68ec0e":0.0615,"d3271afd-c1c5-4375-9841-bbc93b5917ce":81.01,"fef0a40d-6954-4a7d-9087-de5c66b57f83":7.16,"e2199c70-ac6b-495d-b514-9850e21b6423":-57}
[2023-02-07 09:51:09] 
[2023-02-07 09:51:17]  WATCHDOG ISR barksUntilReset 74 <--WatchDogAVR
[2023-02-07 09:51:17] -- Response Code -- 504 waited  7000 mS Timeout 7000
[2023-02-07 09:51:17] ... Watchdog low barksUntilReset 74  expected 75
[2023-02-07 09:51:17] Sent 4 readings in 34.51 sec. Queued readings= 407

This seems similar
#542

#547
@neilh10
Copy link
Author

neilh10 commented Mar 3, 2023

well just to have a conversation with myself, the response times have improved, so data is being accepted.
Times are from 0.9 to 3.7Secs
[2023-03-02 16:40:44] -- Response Code -- 201 waited 915 mS Timeout 15000
[2023-03-02 16:40:51] -- Response Code -- 201 waited 3699 mS Timeout 15000
[2023-03-02 17:00:54] -- Response Code -- 201 waited 9372 mS Timeout 15000
with an occasional
[2023-03-02 17:30:58] -- Response Code -- 504 waited 15009 mS Timeout 15000

For some 6000 readings, they all eventually uploaded over about two weeks.
https://monitormywatershed.org/sites/tu_rcru_test06/ running with Mayfly release over an Digi LTE
https://github.com/neilh10/ModularSensors/releases/tag/v0.34.1-aba-release1_221227

For the two months starting at January 3 ending Feb 28th, some 16177 readings all uploaded successfully, no data loss

Seems to be fixed after this
#635 (comment)
or maybe something was rebooted and is still lurking.

@neilh10 neilh10 closed this as completed Mar 3, 2023
@ptomasula
Copy link
Member

Hey @neilh10, sorry for the delayed response to this. I'm glad to hear that response times have improved recently.

Our work on #635, is presently only on the staging, so I'm not sure that explains the sudden change in performance. I did reboot the database server in response to #642 on 02/24/2023. The CPU utilization on our production database server seemed to be steadily creeping up over the past few months and based on #642 looks to have crossed a critical threshold about 2-3 weeks ago.

@neilh10
Copy link
Author

neilh10 commented Mar 4, 2023

Hi @ptomasula thanks for the reboot - or whatever it was speeding it up. I'm just reflecting what I see. It started working good enough. Some systems reboot regularly.

I try and spread the IoT load,
#485

I get a pretty interesting pattern of a timeout 504, usually on the hour 00 or 30. This setup POST two readings every 10minutes.


$ grep " Response Code " ttyUSB0_2302272110.txt
[2023-03-03 03:00:58] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-03-03 03:01:01] -- Response Code -- 201 waited  927 mS Timeout 15000
[2023-03-03 03:01:08] -- Response Code -- 201 waited  3169 mS Timeout 15000
[2023-03-03 03:10:45] -- Response Code -- 201 waited  1375 mS Timeout 15000
[2023-03-03 03:10:52] -- Response Code -- 201 waited  3444 mS Timeout 15000
[2023-03-03 03:20:44] -- Response Code -- 201 waited  964 mS Timeout 15000
[2023-03-03 03:20:50] -- Response Code -- 201 waited  3556 mS Timeout 15000
[2023-03-03 03:30:57] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-03-03 03:31:02] -- Response Code -- 201 waited  2916 mS Timeout 15000
[2023-03-03 03:31:09] -- Response Code -- 201 waited  2445 mS Timeout 15000
[2023-03-03 03:40:45] -- Response Code -- 201 waited  1001 mS Timeout 15000
[2023-03-03 03:40:51] -- Response Code -- 201 waited  3444 mS Timeout 15000
[2023-03-03 03:50:44] -- Response Code -- 201 waited  1387 mS Timeout 15000
[2023-03-03 03:50:51] -- Response Code -- 201 waited  3783 mS Timeout 15000
[2023-03-03 04:00.58] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-03-03 04:01:02] -- Response Code -- 201 waited  2011 mS Timeout 15000
[2023-03-03 04:01:08] -- Response Code -- 201 waited  2446 mS Timeout 15000
[2023-03-03 04:10:44] -- Response Code -- 201 waited  881 mS Timeout 15000
[2023-03-03 04:10:51] -- Response Code -- 201 waited  3951 mS Timeout 15000
[2023-03-03 04:20:44] -- Response Code -- 201 waited  1011 mS Timeout 15000
[2023-03-03 04:20:50] -- Response Code -- 201 waited  3423 mS Timeout 15000
[2023-03-03 04:30:58] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-03-03 04:31:01] -- Response Code -- 201 waited  965 mS Timeout 15000
[2023-03-03 04:31:07] -- Response Code -- 201 waited  2529 mS Timeout 15000
[2023-03-03 04:40:47] -- Response Code -- 201 waited  4155 mS Timeout 15000
[2023-03-03 04:40:53] -- Response Code -- 201 waited  3469 mS Timeout 15000
[2023-03-03 04:50:58] -- Response Code -- 504 waited  15009 mS Timeout 15000
[2023-03-03 04:51:14] -- Response Code -- 504 waited  15000 mS Timeout 15000
[2023-03-03 05:00:58] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-03-03 05:01:15] -- Response Code -- 504 waited  15000 mS Timeout 15000
[2023-03-03 05:20:58] -- Response Code -- 504 waited  15000 mS Timeout 15000
[2023-03-03 05:21:01] -- Response Code -- 201 waited  1445 mS Timeout 15000
[2023-03-03 05:21:08] -- Response Code -- 201 waited  4108 mS Timeout 15000
[2023-03-03 05:21:15] -- Response Code -- 201 waited  3795 mS Timeout 15000
[2023-03-03 05:21:21] -- Response Code -- 201 waited  2470 mS Timeout 15000
[2023-03-03 05:21:28] -- Response Code -- 201 waited  3770 mS Timeout 15000
[2023-03-03 05:21:35] -- Response Code -- 201 waited  3506 mS Timeout 15000
[2023-03-03 05:21:41] -- Response Code -- 201 waited  3494 mS Timeout 15000
[2023-03-03 05:21:47] -- Response Code -- 201 waited  3447 mS Timeout 15000
[2023-03-03 05:30:58] -- Response Code -- 504 waited  15000 mS Timeout 15000
[2023-03-03 05:31:15] -- Response Code -- 504 waited  15012 mS Timeout 15000
[2023-03-03 05:40:58] -- Response Code -- 504 waited  15010 mS Timeout 15000
[2023-03-03 05:41:02] -- Response Code -- 201 waited  1229 mS Timeout 15000
[2023-03-03 05:41:08] -- Response Code -- 201 waited  2758 mS Timeout 15000
[2023-03-03 05:41:15] -- Response Code -- 201 waited  3795 mS Timeout 15000
[2023-03-03 05:41:22] -- Response Code -- 201 waited  3795 mS Timeout 15000
[2023-03-03 05:50:52] -- Response Code -- 201 waited  7385 mS Timeout 15000
[2023-03-03 05:50:58] -- Response Code -- 201 waited  3867 mS Timeout 15000
[2023-03-03 06:00:58] -- Response Code -- 504 waited  15012 mS Timeout 15000
[2023-03-03 06:01:08] -- Response Code -- 201 waited  7866 mS Timeout 15000
[2023-03-03 06:01:15] -- Response Code -- 201 waited  3085 mS Timeout 15000
[2023-03-03 06:10:51] -- Response Code -- 201 waited  7529 mS Timeout 15000
[2023-03-03 06:10:58] -- Response Code -- 201 waited  3866 mS Timeout 15000
[2023-03-03 06:20:53] -- Response Code -- 201 waited  9384 mS Timeout 15000
[2023-03-03 06:20:59] -- Response Code -- 201 waited  3709 mS Timeout 15000
[2023-03-03 06:30:58] -- Response Code -- 504 waited  15012 mS Timeout 15000

@neilh10 neilh10 mentioned this issue Mar 17, 2023
Merged
@neilh10 neilh10 mentioned this issue Sep 21, 2023
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@neilh10 @ptomasula