I am not sure I follow what the question is.
If a remote device “Paused” us local device, is it possible that REST API (system/connections) would report it as connected for a brief lap of time at the moment we (local) try to establish a connection? That’s what I suspect because I gave 2~3 manual tests and they seemed to work:
remote Paused us => local REST returns "connected": false,
remote Resumed us => local REST returns "connected": true,
Although it seems false status isn’t stable when I hope it should… but maybe my script is badly designed.
Paused effectively means we’ll drop the connection as they come in, so it’s possible it will show up as connected for some time before it gets dropped.
Hi Audrius
I think my reply was missleading, as local & remote was reversed related to the OP (as I said “…remote headless…”). I’d like to be sure I do make me unambiguous, so: the script runs in the RasPi and queries the local ST instance (RasPi). Remote is my Home instance, the one that pauses the RasPi device. When RasPi wakes up at 3A.M. it tries to contact Home. Raspi yet being paused at Home side, I’d expect Home won’t try to start a connection.
So do you mean (…connections as they come in…) that initial handshake (very first reply from Home to Raspi) immediately triggers a "connected:" true, status before later/latest reply (kind of “The guy here at Home paused you since hours and for hours, so I don’t speak to you anymore until different directions.”)?
If so, I believe I have a solution: I just have to check 2 successive "connected:" true, inside my 5s loop. Do you feel it would be enough?
The device with the paused remote closes the connection, and that close message first needs to arrive and be processed by the device you are querying - that’s the interval of connected you are seeing. Hoping that 5s is enough for this to happen seems pretty fragile, while it may work.
As to what might be a better way I don’t know, because I don’t understand what your try to do here.
Timestamp [PI_ID] Time INFO: Connection to Home_ID at PI_IP:Port-Home_IP:Port/tcp-client/TLS1.3-TLS_AES_128_GCM_SHA256 closed: reading length: EOF
That’s not good though, it should get a nice “device is paused” error, unless you’re on an old version.
And please don’t redact the timestamp (?).
Sorry Simon, it was to make the code block easier to read. I understand in this matter I should not have redacted that. All time stamps were the same 09:01:06, that’s why I was puzzled, but I understand now that the risk is high that one of my 5s rate queries matches the moment when the device polls the pausing one. I can’t leave this as is.
Both are 1.5.0. And during all my tests and manual queries to the REST API, I never saw such a status for “connected”: only false, or true,. Although “paused” (false, or true,) is available at the pausing side, which is of none interest here (see why below), and I’m not fan with querying the remote API.
The device (RasPi) running the script never pauses the other (Home). Raspi device boots at 3 A.M. (and starts ST as a service, and cron runs the script, */15 * * * ) for 1/4h (hardware power mains clock driven, minimum step). The goal of the script is to give enough time to fetch files from Home (even more than 1/4h if ever needed), then once done (until $needF falls to 0), shutdown its own host (again RasPi) whose then falling auxiliary supply voltage (3V3) will release the relay that shorted the contacts of the clock since boot time (this is a tweak of my own), which in turn removes the wallet from mains (because the clock contact went opened 1/4h after boot), then allowing RasPi to boot again 24h later (minus the bigger of 1/4h or the time required to fetch files+1/4h max*) once the mains clock wakes RasPi up again. This is the only way to deal with lack of WoL on Pi devices (they must fully loose power on shutdown to be able to restart without a human plus an optional push-button). A remote IP plug would defeat the additional goal of minimum power consumption (far over the hardware clock one, and more prone to own failure).
The until ...Home connected; do sleep 5; done loop was a real pain in the ass for me to build so you guess I’m a poor coder. But now it does the job perfectly well, that is wait for Home to be connected (in the rare cases of failure, or mains or network outage, ST Home crashed or stopped, or any other reason that would match with what I have in my mind when I think “not-connected”)… at least that’s what I thought until now while writing. It appears there are circumstances when Home shows as connected, spikes at RasPi side and I didn’t thought it would. I could not figure this because mainly Home was always ~really~ connected (read up and ready to gently reply “Ready to sync” to Raspi)
Home (assumed up & running ST 24/24) may occasionally pause Raspi to prevent it to be shutdown by the script running over there (e.g. for maintenance purpose). In fact this is only a “bonus” 
feature I imagined in the end when I finished building the loop.
Tonight I’ll test to stop Home ST (instead of pause RasPi) and see if Raspi remains awaken. This will answer the question I have in mind if ST assumes peers are connected before polling them. But I can’t simply replace “Pause Raspi” by “Stop Home” for this now additional requirement… second because this is not elegant, first because Home must remain up to deal with other folders and devices 
* to be optimized with an until loop to drop this +1/4h max to 0.
Thank you Simon for your reply that drove me to think a bit more on my own. And many thanks to the team for this great project.
[EDIT], @imsodin the day after: I ran the test above this night, i.e. Home stopped. As hoped this morning Raspi was still up. I’d dare to say query (5s rate) to local REST API /system/connections for Home_ID "connected": false is reliable on the long run: no true happened which had triggered the querying device to shutdown. I may also say that ST won’t assume a peer is connected before checking. Sorry I can’t be more affirmative since I can’t understand the Go language.
ATM I’m running the ~opposite~ test intended to show that "connected": true is not reliable on the long run, same querying 5s rate, for the case when remote device paused us.
Simon, if this second test shows what I call unreliable, is it worth I fill a bug @github, or does ST already deals with that internally and REST API is only an unsupported bonus kindly offered as is?
Bye again, hope I’ll read from you
1 Like
So whenever connected is not true, it’s false. So I am not sure what insight you expect from your second test?
And this is not an API problem, it’s that we do not initially exchange information on device “pausedness”, therefore a connection gets established just to be closed by the pausing device. And the not pausing device will continue to try to connect to the other one, which probably triggers those intermittent connected states regularly. From Syncthing’s point of view there’s nothing wrong with that, but of course for your specific use it’s annoying. Keeping a device awake isn’t Syncthings job though, so jumping a few hoops (like requiring connected state for longer than 5s as you do currently) seems not too bad.
Thank you Simon. But my whole work seems bad to me now, because the way I wrote it takes immediate action on first match with "connected": true status when it should check this status is stable for at least 2 polls. I will try to copy the loop so that it is ran twice… hmmmm, not good. after a “disconnected” following a “connected” the script should return to the first loop. I guess I have something to learn to reach this.
I ran the test against a pausing device at home today, and after ~4500*5s run there was no “connected” status…
I found something like a workaround. I’ll post in a moment. ATM I’m gathering informations.
Hi @pinknemo13
First of all, here is the script I use, tweaked to spit each step to syslog. I don’t know what your goal is (BTW, is it a Raspberry Pi?), mine is to mainly shutdown or sometimes keep the device ON based on ST status. All the war below is for the “Keep ON” purpose (for this I “Pause” the Raspi from Home device). I set a threshold for consecutive same "connected": true, status to try to get a reliable status of ST from REST/API. This afternoon I changed it from 2 to 3, i.e. $CmptCntd -gt 2, and I got the weird behaviour only once after 5 hours running, while when set to 2 (successive "connected": true,) I got it after 1/4 ~ 1/2 hour. ST starts as a service for pi user and cron starts the script:
*/15 * * * * /home/pi/Documents/AutoOff.sh >/dev/null 2>&1
Here is the script. Please be lenient, I’m only hobbyist
#!/bin/bash
# AutoOff.sh
#Script to detect no trafic for ST and shutdown Raspberry Pi.
#Do no move, or change scheduler (see below) accordingly.
#Start rate is managed by cron and set with "sudo crontab -e -u root" which
#edits /var/spool/cron/crontabs/root file.
#No need more than one myself instance as long as I am well coded ;-)
if [ `pgrep -c AutoOff.sh` -gt 1 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L10) Exit, yet running" &>>/var/log/syslog; exit 0
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L11) Start waiting ST to run" &>>/var/log/syslog
#Give ST time to start if started very close to me :
while [ `pgrep -c syncthing` -lt 2 ]; do
echo `date +'%B %-d %T'` "AutoOff.sh (L14) ST not running, sleep 5" &>>/var/log/syslog; sleep 5
done; echo `date +'%B %-d %T'` "AutoOff.sh (L15) ST running, set vars to check Home device connection status" &>>/var/log/syslog
#Wait for connection to Home
Conf="/home/pi/.config/syncthing/config.xml"
Port=$(awk -F'[:<]' '/<gui en/,/gui>/{if($0~/address/){print$3}}' $Conf)
APIKey=$(awk -F'[><]' '/apikey/{print $3}' $Conf)
REST="curl -ksH X-API-Key:$APIKey https://localhost:$Port/rest"
KnoxID=$(awk -F\" '/Home/{print $2}' $Conf)
# Counter for successive connections
while :; do echo `date +'%B %-d %T'` "AutoOff.sh (L24) enter wait for successive connections loop" &>>/var/log/syslog
if [[ `$REST/system/connections|awk -v HID=$HomeID '$0~HID,/}/ {if ($0~/connected/) print}'|grep '"connected": true,'` ]]; then ((++CmptCntd)); echo `date +'%B %-d %T'` "AutoOff.sh (L25) ST connected. Increased counter by 1:" $CmptCntd &>>/var/log/syslog
if [ $CmptCntd -gt 2 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L26) ST connected threshold reached:" $CmptCntd ": so break" &>>/var/log/syslog; break 1
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L27) ST was sense connected for only (current count):" $CmptCntd " time. Sleep5 and continue" &>>/var/log/syslog; sleep 5; continue 1
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L28) Test connected failed. Counter:" $CmptCntd &>>/var/log/syslog; CmptCntd=0; echo `date +'%B %-d %T'` "AutoOff.sh (L28) counter was reset to:" $CmptCntd ". I will sleep15" &>>/var/log/syslog; sleep 15
done
echo `date +'%B %-d %T'` "AutoOff.sh (L30) exited loop" &>>/var/log/syslog
#Suicide if some ssh connection active and come back in 1/4h (cron)
if [ `pgrep -c sshd` -gt 1 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L32) SSH found: goodbye cruel world" &>>/var/log/syslog; exit 0
fi
#Does ST needs new files:
until $REST/db/status?folder=folder-idhere|grep -m1 needFiles|grep -oe ' 0,'; do echo `date +'%B %-d %T'` "AutoOff.sh (L36) Needing file" &>>/var/log/syslog
echo `date +'%B %-d %T'` "AutoOff.sh (L37) I will sleep5" &>>/var/log/syslog; sleep 5
done; echo `date +'%B %-d %T'` "AutoOff.sh (L38) No file needed" &>>/var/log/syslog
echo `date +'%B %-d %T'` "AutoOff.sh (L39) I will sleep 60" &>>/var/log/syslog; sleep 60
#Si not shutdown Raspi :
echo `date +'%B %-d %T'` "AutoOff.sh Go shutdown" &>>/var/log/syslog
/sbin/shutdown &>>/var/log/syslog
#/sbin/shutdown -cAnd here are the logs
1st when set with 2 successive "connected": true,
This one, the pi just rebooted, there is garbage/jump with timestamps because of the lack of CMOS clock (it uses fake-hwclock). Latest shutdown was on Jun 8 23:17:07. This is not an error, see below how fake-hwclock helps retreive a roughly coherent date/time on boot by recording to disk date/time of latest shutdown… at least, better than epoch. Real boot time was Jun 8 ~3H33. The script was triggered at 3h45 by cron and could keep Raspi alive for ~20mn:
Jun 8 23:17:29 Raspi systemd-modules-load[119]: Inserted module 'i2c_dev'
Jun 8 23:17:29 Raspi kernel: [ 0.000000] Booting Linux on physical CPU 0x0
Jun 8 23:17:29 Raspi kernel: [ 0.000000] Linux version 4.19.75-v7l+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1270 SMP Tue Sep 24 18:51:41 BST 2019
Jun 8 23:17:29 Raspi kernel: [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
Jun 8 23:17:29 Raspi fake-hwclock[99]: lundi 8 juin 2020, 21:17:08 (UTC+0000)
Jun 8 23:17:29 Raspi kernel: [ 0.000000] CPU: div instructions available: patching division code
Jun 8 23:17:29 Raspi systemd-fsck[135]: e2fsck 1.44.5 (15-Dec-2018)
...
Jun 8 23:17:30 Raspi systemd[1]: Reached target Network.
...
Jun 8 23:17:30 Raspi systemd[1]: Started Syncthing - Open Source Continuous File Synchronization for pi.
...
Jun 8 23:17:30 Raspi syncthing[523]: [start] INFO: syncthing v1.6.1 "Fermium Flea" (go1.14.4 linux-arm) deb@build.syncthing.net 2020-06-02 09:49:22 UTC
Jun 8 23:17:30 Raspi dhcpcd[479]: eth0: waiting for carrier
...
Jun 8 23:17:30 Raspi syncthing[523]: [SHORT] INFO: My ID: SHORT-AAAAAAA-BBBBBBB-CCCCCCC-DDDDDDD-EEEEEEE-FFFFFFF-GGGGGGG
...
Jun 8 23:17:31 Raspi kernel: [ 27.991680] bcmgenet fd580000.genet eth0: Link is Down
...
Jun 8 23:17:36 Raspi dhcpcd[479]: eth0: rebinding lease of RAS.PI.IP.V4
...
Jun 8 23:17:47 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6%eth0]:45856-[IP::V6%eth0]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 8 23:17:47 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at [IP::V6f%eth0]:45856-[IP::V6%eth0]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 8 23:17:47 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6%eth0]:45856-[IP::V6%eth0]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
Jun 9 03:33:48 Raspi systemd-timesyncd[369]: Synchronized to time server for the first time [2001:41d0:401:3100::402d]:123 (2.debian.pool.ntp.org).
Jun 9 03:33:48 Raspi systemd[1]: Started Run anacron jobs.
...
Jun 9 03:34:25 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:54168-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:34:25 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at [IP::V6]:54168-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:34:25 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:54168-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
Jun 9 03:34:37 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48254-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:34:37 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:48254-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:34:37 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48254-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
...
Jun 9 03:37:26 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:54204-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:37:26 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at [IP::V6]:54204-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:37:26 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:54204-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
Jun 9 03:37:38 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48288-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:37:38 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:48288-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:37:38 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48288-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: read tcp RAS.PI.IP.V4:48288->HOM.E.IP.V4:HomePort: read: connection reset by peer
...
Jun 9 03:44:42 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48380-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:44:42 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:48380-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:44:42 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48380-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
Jun 9 03:45:01 Raspi CRON[897]: (root) CMD (/home/pi/Documents/AutoOff.sh >/dev/null 2>&1)
juin 9 03:45:01 AutoOff.sh (L11) Start waiting ST to run
juin 9 03:45:01 AutoOff.sh (L15) ST running, set vars to check Knox connection status
juin 9 03:45:01 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 03:45:01 AutoOff.sh (L28) Test connected failed. Counter:
juin 9 03:45:01 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
...
juin 9 03:45:16 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 03:45:16 AutoOff.sh (L28) Test connected failed. Counter: 0
juin 9 03:45:16 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
Jun 9 03:45:29 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:54312-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:45:29 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at [IP::V6]:54312-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:45:29 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:54312-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
juin 9 03:45:31 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 03:45:32 AutoOff.sh (L28) Test connected failed. Counter: 0
juin 9 03:45:32 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
Jun 9 03:45:43 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48402-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:45:43 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:48402-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:45:43 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:48402-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
juin 9 03:45:47 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 03:45:47 AutoOff.sh (L28) Test connected failed. Counter: 0
juin 9 03:45:47 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
juin 9 03:46:02 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 03:46:02 AutoOff.sh (L28) Test connected failed. Counter: 0
juin 9 03:46:02 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
...
juin 9 03:59:59 AutoOff.sh (L24) enter wait for successive connections loop
Jun 9 03:59:59 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:49374-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:59:59 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:49374-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 03:59:59 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:49374-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
juin 9 04:00:00 AutoOff.sh (L28) Test connected failed. Counter: 0
juin 9 04:00:00 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
Jun 9 04:00:01 Raspi CRON[1483]: (root) CMD (/home/pi/Documents/AutoOff.sh >/dev/null 2>&1)
juin 9 04:00:01 AutoOff.sh (L10) Exit, yet running
juin 9 04:00:15 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 04:00:15 AutoOff.sh (L28) Test connected failed. Counter: 0
juin 9 04:00:15 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
...
Jun 9 04:03:38 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:34812-95.168.192.49:22067/relay-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 04:03:38 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:34812-95.168.192.49:22067/relay-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
juin 9 04:03:48 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 04:03:48 AutoOff.sh (L25) ST connected. Increased counter by 1: 1
juin 9 04:03:48 AutoOff.sh (L27) ST was sense connected for only (current count): 1 time. Sleep5 and continue
juin 9 04:03:53 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 04:03:53 AutoOff.sh (L25) ST connected. Increased counter by 1: 2
juin 9 04:03:53 AutoOff.sh (L26) ST connected threshold reached: 2 : so break
juin 9 04:03:53 AutoOff.sh (L30) exited loop
juin 9 04:03:53 AutoOff.sh (L38). No file needed
juin 9 04:03:53 AutoOff.sh (L39). I will sleep 60
Jun 9 04:04:02 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:49498-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 04:04:02 Raspi syncthing[523]: [SHORT] INFO: Replacing old connection RAS.PI.IP.V4:34812-95.168.192.49:22067/relay-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 with RAS.PI.IP.V4:49498-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 for HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID
Jun 9 04:04:02 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:34812-95.168.192.49:22067/relay-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: replacing connection
Jun 9 04:04:02 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at RAS.PI.IP.V4:49498-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 04:04:02 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at RAS.PI.IP.V4:49498-HOM.E.IP.V4:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
...
Jun 9 04:04:37 Raspi syncthing[523]: [SHORT] INFO: Established secure connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:55426-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 04:04:37 Raspi syncthing[523]: [SHORT] INFO: Device HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID client is "syncthing v1.6.1" named "Home" at [IP::V6]:55426-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
Jun 9 04:04:37 Raspi syncthing[523]: [SHORT] INFO: Connection to HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6]:55426-[IP::V6]:HomePort/tcp-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF
juin 9 04:04:53 AutoOff.sh (L41) Go shutdown
Shutdown scheduled for Tue 2020-06-09 04:05:53 CEST, use 'shutdown -c' to cancel.Another shoot with same setting gave keep alive for 2 hours. The 2 runs in the end are coincidence (ssh was active so the script exited and shutdown didn’t happen, and cron restarted it some seconds later because */15 … and we see even with these some additional seconds, the 2 following runs of the loop, delayed 5s from each other, aren’t enough to let either the connection be reported false or the connection die) :
Jun 9 11:15:01 Raspi CRON[1045]: (root) CMD (/home/pi/Documents/AutoOff.sh >/dev/null 2>&1)
juin 9 11:15:01 AutoOff.sh (L11) Start waiting ST to run
juin 9 11:15:01 AutoOff.sh (L15) ST running, set vars to check Knox connection status
juin 9 11:15:01 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 11:15:01 AutoOff.sh (L28) Test connected failed. Counter:
juin 9 11:15:01 AutoOff.sh (L28) counter was reset to: 0 . I will sleep15
...
Jun 9 13:14:45 Raspi syncthing[534]: [SHORT] INFO: Failed to exchange Hello messages with HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID-HOMEDID at [IP::V6%eth0]:RaspiPort-[IP::V6%eth0]:55771/tcp-server/TLS1.3-TLS_CHACHA20_POLY1305_SHA256: write tcp [IP::V6%eth0]:RaspiPort->[IP:V6%eth0]:55771: write: connection reset by peer
juin 9 13:14:51 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 13:14:51 AutoOff.sh (L25) ST connected. Increased counter by 1: 1
juin 9 13:14:51 AutoOff.sh (L27) ST was sense connected for only (current count): 1 time. Sleep5 and continue
juin 9 13:14:56 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 13:14:56 AutoOff.sh (L25) ST connected. Increased counter by 1: 2
juin 9 13:14:56 AutoOff.sh (L26) ST connected threshold reached: 2 : so break
juin 9 13:14:56 AutoOff.sh (L30) exited loop
juin 9 13:14:56 AutoOff.sh (L32). SSH found: goodbye cruel world
Jun 9 13:15:02 Raspi CRON[5811]: (root) CMD (/home/pi/Documents/AutoOff.sh >/dev/null 2>&1)
juin 9 13:15:02 AutoOff.sh (L11) Start waiting ST to run
juin 9 13:15:02 AutoOff.sh (L15) ST running, set vars to check Knox connection status
juin 9 13:15:02 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 13:15:02 AutoOff.sh (L25) ST connected. Increased counter by 1: 1
juin 9 13:15:02 AutoOff.sh (L27) ST was sense connected for only (current count): 1 time. Sleep5 and continue
juin 9 13:15:07 AutoOff.sh (L24) enter wait for successive connections loop
juin 9 13:15:07 AutoOff.sh (L25) ST connected. Increased counter by 1: 2
juin 9 13:15:07 AutoOff.sh (L26) ST connected threshold reached: 2 : so break
juin 9 13:15:07 AutoOff.sh (L30) exited loop
juin 9 13:15:07 AutoOff.sh (L32). SSH found: goodbye cruel world
At this point the device would shutdown at 13:16:56 (1mn delay in the script, plus 1mn default delay for shutdown command).
3rd when script set with 3 successive "connected": true,
Weird "connected": true, happened 8 times yesterday
cat syslog |grep -B3 world
juin 10 01:08:44 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 01:08:44 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 01:08:44 AutoOff.sh (L30) exited loop
juin 10 01:08:45 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 02:08:46 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 02:08:46 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 02:08:46 AutoOff.sh (L30) exited loop
juin 10 02:08:46 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 05:19:02 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 05:19:02 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 05:19:02 AutoOff.sh (L30) exited loop
juin 10 05:19:02 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 05:48:59 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 05:48:59 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 05:48:59 AutoOff.sh (L30) exited loop
juin 10 05:48:59 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 08:29:04 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 08:29:04 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 08:29:04 AutoOff.sh (L30) exited loop
juin 10 08:29:04 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 08:39:06 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 08:39:06 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 08:39:06 AutoOff.sh (L30) exited loop
juin 10 08:39:06 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 13:59:30 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 13:59:30 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 13:59:30 AutoOff.sh (L30) exited loop
juin 10 13:59:30 AutoOff.sh (L32) SSH found: good bye cruel world
--
juin 10 18:19:35 AutoOff.sh (L25) ST connected. Increased counter by 1: 3
juin 10 18:19:35 AutoOff.sh (L26) ST connected threshold reached: 3 : so break
juin 10 18:19:35 AutoOff.sh (L30) exited loop
juin 10 18:19:35 AutoOff.sh (L32) SSH found: good bye cruel worldFascinating as this is I’m not sure what conclusions you want us to draw from these things, or what input you’re looking for?
Hi Jakob
I didn’t known until now, I just thought about some pseudo-random timeout on failed connections. Now I get a track : it seems ST uses kind of protocols round-robin when connections fails, e.g. tcp4 tcp6 quic … and the culprit seems to be connections type relay-client, which makes sense. I have to check back this assertion from previous logs/posts.
I’m glad, I think I can go on 
I got rid off false positive connections (read unstable, spurious connected status) by tweaking my script this way (increased probes number to 4 and sleep in between to 17s - 17 instead of a multiple of 5 lowers the risks of regular sync between connections and probes), which gives enough time to the long ones among relay-client connections to drop or be replaced by higher rate and quicker failure-responsive new tcp-client ones. This seems the minimal tradeoff:
...
# Counter for successive connections
while :; do echo `date +'%B %-d %T'` "AutoOff.sh (L24) enter wait for successive connections loop" &>>/var/log/syslog
if [[ `$REST/system/connections|awk -v HID=$HomeID '$0~HID,/}/ {if ($0~/connected/) print}'|grep '"connected": true,'` ]]; then ((++CmptCntd)); echo `date +'%B %-d %T'` "AutoOff.sh (L25) ST connected. Increased counter by 1:" $CmptCntd &>>/var/log/syslog
if [ $CmptCntd -ge 4 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L26) ST connected threshold reached:" $CmptCntd ": so break" &>>/var/log/syslog; break 1
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L27) ST was sense connected for only (current count):" $CmptCntd " time. Sleep17 and continue" &>>/var/log/syslog; sleep 17; continue 1
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L28) Test connected failed. Counter:" $CmptCntd &>>/var/log/syslog; CmptCntd=0; echo `date +'%B %-d %T'` "AutoOff.sh (L28) counter was reset to:" $CmptCntd ". I will sleep15" &>>/var/log/syslog; sleep 15
done
echo `date +'%B %-d %T'` "AutoOff.sh (L30) exited loop" &>>/var/log/syslog
...Extra bonus, I found a solution to prevent " Syncthing floods my syslog " for the ones with rsyslog:
sudo nano /etc/rsyslog.d/10-ush-syncthing.conf
:programname, isequal, "syncthing" /dev/null
& stop
then
sudo service syslog restart
I feel this is important for the ones that let their raspberry run from the SDCard which will quickly be overworn by such a verbosity. For me, I moved all rootfs to a ssd.
@cosas Did I put your parts together like this correctly?
#!/bin/bash
# AutoOff.sh
#
## */15 * * * * /home/pi/Documents/AutoOff.sh >/dev/null 2>&1
#
#Script to detect no trafic for ST and shutdown Raspberry Pi.
#Do no move, or change scheduler (see below) accordingly.
#Start rate is managed by cron and set with "sudo crontab -e -u root" which
#edits /var/spool/cron/crontabs/root file.
#
#No need more than one myself instance as long as I am well coded ;-)
if [ `pgrep -c AutoOff.sh` -gt 1 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L10) Exit, yet running" &>>/var/log/syslog; exit 0
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L11) Start waiting ST to run" &>>/var/log/syslog
#Give ST time to start if started very close to me :
while [ `pgrep -c syncthing` -lt 2 ]; do
echo `date +'%B %-d %T'` "AutoOff.sh (L14) ST not running, sleep 5" &>>/var/log/syslog; sleep 5
done; echo `date +'%B %-d %T'` "AutoOff.sh (L15) ST running, set vars to check Home device connection status" &>>/var/log/syslog
#Wait for connection to Home
Conf="/home/pi/.config/syncthing/config.xml"
Port=$(awk -F'[:<]' '/<gui en/,/gui>/{if($0~/address/){print$3}}' $Conf)
APIKey=$(awk -F'[><]' '/apikey/{print $3}' $Conf)
REST="curl -ksH X-API-Key:$APIKey https://localhost:$Port/rest"
KnoxID=$(awk -F\" '/Home/{print $2}' $Conf)
#
# Counter for successive connections
while :; do echo `date +'%B %-d %T'` "AutoOff.sh (L24) enter wait for successive connections loop" &>>/var/log/syslog
if [[ `$REST/system/connections|awk -v HID=$HomeID '$0~HID,/}/ {if ($0~/connected/) print}'|grep '"connected": true,'` ]]; then ((++CmptCntd)); echo `date +'%B %-d %T'` "AutoOff.sh (L25) ST connected. Increased counter by 1:" $CmptCntd &>>/var/log/syslog
if [ $CmptCntd -ge 4 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L26) ST connected threshold reached:" $CmptCntd ": so break" &>>/var/log/syslog; break 1
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L27) ST was sense connected for only (current count):" $CmptCntd " time. Sleep17 and continue" &>>/var/log/syslog; sleep 17; continue 1
fi; echo `date +'%B %-d %T'` "AutoOff.sh (L28) Test connected failed. Counter:" $CmptCntd &>>/var/log/syslog; CmptCntd=0; echo `date +'%B %-d %T'` "AutoOff.sh (L28) counter was reset to:" $CmptCntd ". I will sleep15" &>>/var/log/syslog; sleep 15
done
echo `date +'%B %-d %T'` "AutoOff.sh (L30) exited loop" &>>/var/log/syslog
#
#Suicide if some ssh connection active and come back in 1/4h (cron)
if [ `pgrep -c sshd` -gt 1 ]; then echo `date +'%B %-d %T'` "AutoOff.sh (L32) SSH found: goodbye cruel world" &>>/var/log/syslog; exit 0
fi
#
#Does ST needs new files:
until $REST/db/status?folder=folder-idhere|grep -m1 needFiles|grep -oe ' 0,'; do echo `date +'%B %-d %T'` "AutoOff.sh (L36) Needing file" &>>/var/log/syslog
echo `date +'%B %-d %T'` "AutoOff.sh (L37) I will sleep5" &>>/var/log/syslog; sleep 5
done; echo `date +'%B %-d %T'` "AutoOff.sh (L38) No file needed" &>>/var/log/syslog
echo `date +'%B %-d %T'` "AutoOff.sh (L39) I will sleep 60" &>>/var/log/syslog; sleep 60
#Si not shutdown Raspi :
echo `date +'%B %-d %T'` "AutoOff.sh Go shutdown" &>>/var/log/syslog
/sbin/shutdown &>>/var/log/syslog
#/sbin/shutdown -cSorry CatFriend, I can’t tell you ATM: I’m a casual coder and every script is for me a kickass. But please have a test on your own and report issues, I’ll try to give my PoV. ATM the pi I did this for is at a friend’s and I have no way to have a look to check the job is still well running without disturbing the friend. Some days ago I saw a thread about changes to REST API and was afraid they would break my job, but after reading the changes I think they won’t. Did you understand the 4th line was a reminder for me that there is a cron job and what it is? You speak of my “parts”: please tell me what they are as I have courage to decode your question. And are you aware you need a way to wake the pi up again after shutdown? I have no courage to re-read the whole thread to search if I said the way I do (external hardware tweak I posted details on french raspberry forum).
1 Like