Closed ArjenR49 closed 3 years ago
Does it represent 'reality'?
it does not. I had to make a choice keeping i2c communication, extra CPU load etc. at a reasonable level. the lack of precision by the discrete sampling will be greater for short lasting high current events. however, looking at the battery voltage, I see that the UPS is not discharging the batteries in the long term with AC power applied.
looking at the battery voltage, I see that the UPS is not discharging the batteries in the long term
True. Overnight with the Pi4 mostly idling, the charge % went up one point ... Battery Voltage is steady at 4,22 V when there's no battery sampling event going on. The voltage is high enough already, so momentary charging currents are at about 50-70 mA except when battery sampling is going on. Everything is fine and dandy in that respect.
UPS has not frozen since I last took the batteries out. Some time ago I reset to factory settings. Perhaps I should run down the batteries a few more times and hope the UPS doesn't freeze while off AC power ...
Perhaps I should run down the batteries a few more times and hope the UPS doesn't freeze while off AC power ... Running f/w v.9 and frtz13's fanShutDownUps.py.
I have now cut AC power twice and waited for the UPS to shutdown the Pi. The intention was to make the UPS learn about the battery capacity whatever it learns this way.
I can't remember what happened the first time, but last night I cut AC power a second time and sure enough, the Pi wasn't running any longer in the morning. However, its red power led was on. The red and first blue led of the UPS were on as well. I couldn't get the Pi to start again by use of the UPS button, so eventually I had to take the batteries out .... again. The syslog at the moment the batteries ran out:
Aug 3 05:13:02 RPI-HUB /fanShutDownUps.py: UPS on battery. Battery voltage: 3.400 V. Shutdown at 3.400 V Aug 3 05:13:04 RPI-HUB 9de3dc433467[729]: Aug 3 05:14:04 RPI-HUB /fanShutDownUps.py: UPS on battery. Battery voltage: 3.388 V. Shutdown at 3.400 V Aug 3 05:14:04 RPI-HUB /fanShutDownUps.py: UPS battery voltage below threshold of 3.400 V. Shutting down. Aug 3 05:14:06 RPI-HUB systemd[1]: Stopped target Graphical Interface. Aug 3 05:14:06 RPI-HUB systemd[1]: Stopping watchdog daemon... and a whole lot of other stopping, stopped messages
However, at some point within the same minute the log started to show starting, started messages, as if the Pi was starting up again:
Aug 3 05:14:07 RPI-HUB systemd[1]: Stopping Make remote CUPS printers available locally... Aug 3 05:14:07 RPI-HUB systemd[1]: Stopping dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 3 05:14:07 RPI-HUB systemd[1]: Stopping rng-tools.service... Aug 3 05:14:17 RPI-HUB systemd-modules-load[118]: Inserted module 'i2c_dev' Aug 3 05:14:17 RPI-HUB systemd-fsck[119]: e2fsck 1.44.5 (15-Dec-2018) Aug 3 05:14:17 RPI-HUB systemd-fsck[119]: rootfs: clean, 250729/7201152 files, 2022223/29238646 blocks Aug 3 05:14:17 RPI-HUB systemd[1]: Started File System Check on Root Device. Aug 3 05:14:17 RPI-HUB systemd[1]: Starting Remount Root and Kernel File Systems... Aug 3 05:14:17 RPI-HUB systemd[1]: Started Set the console keyboard layout. Aug 3 05:14:17 RPI-HUB systemd[1]: Started Remount Root and Kernel File Systems. Aug 3 05:14:17 RPI-HUB systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
This is around the time that the Pi stopped writing to the syslog the last message being '[services.d] done'. ... and then started writing again hours later when I got the Pi starting up by removing and replacing the batteries:
Aug 3 05:14:48 RPI-HUB 15f56b5dfbff[704]: [services.d] starting services Aug 3 05:14:48 RPI-HUB 9de3dc433467[704]: #033[32m21-08-03 05:14:48 INFO (SyncWorker_0) [supervisor.docker.interface] Attaching to homeassistant/armv7-hassio-multicast with version 2021.04.0#033[0m Aug 3 05:14:48 RPI-HUB hassio-supervisor[1349]: #033[32m21-08-03 05:14:48 INFO (SyncWorker_0) [supervisor.docker.interface] Attaching to homeassistant/armv7-hassio-multicast with version 2021.04.0#033[0m Aug 3 05:14:48 RPI-HUB hassio-supervisor[1349]: #033[32m21-08-03 05:14:48 INFO (MainThread) [supervisor.plugins.multicast] Starting Multicast plugin#033[0m Aug 3 05:14:48 RPI-HUB 9de3dc433467[704]: #033[32m21-08-03 05:14:48 INFO (MainThread) [supervisor.plugins.multicast] Starting Multicast plugin#033[0m Aug 3 05:14:48 RPI-HUB 9de3dc433467[704]: #033[32m21-08-03 05:14:48 INFO (SyncWorker_0) [supervisor.docker.interface] Cleaning hassio_multicast application#033[0m Aug 3 05:14:48 RPI-HUB hassio-supervisor[1349]: #033[32m21-08-03 05:14:48 INFO (SyncWorker_0) [supervisor.docker.interface] Cleaning hassio_multicast application#033[0m Aug 3 05:14:48 RPI-HUB 15f56b5dfbff[704]: [services.d] done. Aug 3 11:19:24 RPI-HUB systemd[602]: var-lib-docker-overlay2-2bb47ae6a71b75d0b5623d8b0b40a0e6566c3fbea2106c3a49595c9194eea695\x2dinit-merged.mount: Succeeded. Aug 3 11:19:24 RPI-HUB systemd[1]: var-lib-docker-overlay2-2bb47ae6a71b75d0b5623d8b0b40a0e6566c3fbea2106c3a49595c9194eea695\x2dinit-merged.mount: Succeeded. Aug 3 11:19:24 RPI-HUB systemd-timesyncd[316]: Synchronized to time server for the first time 213.154.236.182:123 (2.debian.pool.ntp.org). Aug 3 11:19:24 RPI-HUB systemd[1]: Starting Daily apt download activities... Aug 3 11:19:24 RPI-HUB 6f412ce77c9c[704]: [s6-init] making user provided files available at /var/run/s6/etc...exited 0. Aug 3 11:19:24 RPI-HUB 15f56b5dfbff[704]: W: [pulseaudio] main.c: Running in system mode, but --disallow-module-loading not set. Aug 3 11:19:24 RPI-HUB 15f56b5dfbff[704]: D: [pulseaudio] core-rtclock.c: Timer slack is set to 50 us.
As it is the UPS is not really useful. When the batteries are 'fully run down' (currently set at 3.4 V) the Pi will 'stop', but the power is still on (red led) and so it will not start simply by reconnecting AC.
I think that at one time this worked - on a previous old version of the f/w. It seems the features and the way this UPS is supposed to be used change with every new version of the f/w.
If somebody could have a look at the log excerpts and comment on the events, I would be very grateful. In particular the fact that the Pi is logging starting all kinds of things after first stopping all kinds of services as if shutting down riddles me. It cannot be normal. Of course the Pi/UPS was without AC power all the time until many hours later (9 a.m. or some such time).
fanShutDownUps.py has written to the log what can be expected from it based on the code. Apparently the writes to back-to-ac and shutdown timer registers have been successful, since there is no error message concerning these as coded.
Even odder: At 12.01 apparently the Pi rebooted. I had a VNC session to it open on the screen of my laptop. I noticed it coming up again, and when I checked the VNC session, all previously open windows had disappeared. Excerpt from the syslog makes me believe it really did start again, but possibly the update to Home Assistant caused it .... can that be?
Aug 3 11:49:49 RPI-HUB hassio-supervisor[1349]: #033[32m21-08-03 11:49:49 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token#033[0m Aug 3 11:54:10 RPI-HUB 9de3dc433467[704]: Aug 3 11:59:11 RPI-HUB 9de3dc433467[704]: Aug 3 12:01:00 RPI-HUB systemd-modules-load[121]: Inserted module 'i2c_dev' Aug 3 12:01:00 RPI-HUB systemd-fsck[116]: e2fsck 1.44.5 (15-Dec-2018) Aug 3 12:01:00 RPI-HUB systemd-fsck[116]: rootfs: clean, 250760/7201152 files, 2023349/29238646 blocks Aug 3 12:01:00 RPI-HUB systemd[1]: Started File System Check on Root Device. Aug 3 12:01:00 RPI-HUB systemd[1]: Starting Remount Root and Kernel File Systems... Aug 3 12:01:00 RPI-HUB systemd[1]: Started Set the console keyboard layout. Aug 3 12:01:00 RPI-HUB systemd[1]: Started Remount Root and Kernel File Systems. A
I did a third test. This time with the immediate shutdown activated: TIMER_BIAS_AT_STARTUP = 0 SHUTDOWN_IMMEDIATELY_WHEN_ON_BATTERY = 1
Pulled the power supply ... The Pi took its time, but eventually shut down (green led blinks 10 or 11 times). Then the UPS cut the power to the Pi (red led off) and still a little more later the UPS switched its blue leds off so everything was dark. Reconnecting AC started the Pi up and everything back to normal ... IMO this is what the UPS is supposed to do.
Suggestion: there could be an *.ini setting to shut the Pi down after a chosen amount of minutes after a failure of AC power. Perhaps that could circumvent the problem I experienced when the batteries were run down. It's all very odd.
When doing the quick test with the two special options as above, the syslog doesn't show any starting/started type of lines in continuation of the stopping/stopped related to the shutdown. And the Pi comes back on every time as soon as AC power is restored. This is normal behaviour.
However, in case the batteries are allowed (by the control script fanShutDownUps.py) to run down and the Pi is shut down as a result of that - even though it happens the same way as coded in fanShutDownUps.py compared to the special quick test - there is SOMETHING FISHY going on after the actual shutting down as per the syslog lines in the post a few posts before this one.
Suggestion: there could be an *.ini setting to shut the Pi down after a chosen amount of minutes after a failure of AC power. Perhaps that could circumvent the problem I experienced when the batteries were run down.
the PROTECTION_VOLTAGE_MARGIN_mV setting should allow not to get too close to some "empty battery" reaction of the UPS.
Thank you for pointing that out! I suppose you have run into that the hard way yourself.
It did occur to me that something like that might be the cause of the misbehaviour.
So I raised the protection voltage to 3500 mV and started a new test. It got me almost 2,5 hours on an idling Pi with a running fancy lights Ice Tower fan before shutting down. (The fan really is largely just for show as the CPU temperature doesn't rise very high on full 4x100% CPU load even when the fan isn't running ... and it isn't even very cold here.)
This time the Pi started up when I plugged the PS in again and the syslog revealed that it had shut down cleanly and not tried to start again immediately after shutting down as previously when the protection voltage was at 3200 mV. The margin has been at 200 mV all the time.
So somewhere between 3400 and 3700 mV there seems to be a limit that the UPS applies of its own accord below which it doesn't react appropriately. After all according to the syslog the Pi attempted to start again right after it had been shutting down as initiated by the control script fanShutDownUps.py. The only responsible for the restart attempt must have been the UPS f/w. Since the UPS can't write to the syslog, there's no confirmation of who does what and why. Anyway the reaction of attempting to start up right away seems quite wrong when the batteries are empty and there's no AC.
If this is so, it also may explain why the default limit is set so oddly high, 3700 mV (with or without 200 mV margin included, I forgot). You're not supposed to allow maximum runtime off AC utilizing the full capacity of the batteries.
I haven't noticed any such hard and rather high lower limit documented, have you?
Op 03-08-2021 om 22:52 schreef frtz13:
Suggestion: there could be an *.ini setting to shut the Pi down after a chosen amount of minutes after a failure of AC power. Perhaps that could circumvent the problem I experienced when the batteries were run down.
the PROTECTION_VOLTAGE_MARGIN_mV setting should allow not to get too close to some "empty battery" reaction of the UPS.
— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/frtz13/UPSPlus_mqtt/issues/15#issuecomment-892157764, or unsubscribe https://github.com/notifications/unsubscribe-auth/ANCBKNUKSYTKEFI6UMVB7Q3T3BJI5ANCNFSM5BLO5ZHQ. Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&utm_campaign=notification-email.
Oh well, there's the 'empty voltage' at 0x0F-0x10, of course, which is set by the UPS itself. A partially learned value as it is also influenced by what you set as the 'protection voltage' at 0x11-0x12.
Now that I set the protection voltage to 3500 mV, the 'empty voltage' had gone up to the same value, at least after my most recent test running down the batteries. Op 03-08-2021 om 22:52 schreef frtz13:
Suggestion: there could be an *.ini setting to shut the Pi down after a chosen amount of minutes after a failure of AC power. Perhaps that could circumvent the problem I experienced when the batteries were run down.
the PROTECTION_VOLTAGE_MARGIN_mV setting should allow not to get too close to some "empty battery" reaction of the UPS.
— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/frtz13/UPSPlus_mqtt/issues/15#issuecomment-892157764, or unsubscribe https://github.com/notifications/unsubscribe-auth/ANCBKNUKSYTKEFI6UMVB7Q3T3BJI5ANCNFSM5BLO5ZHQ. Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&utm_campaign=notification-email.
Gradually lowering the protection voltage from 3500 mV by 100 mV at a time I ran down the batteries every time by disconnecting AC until the Pi finally shut down by fanShutDownUps.py, I am now back at 3200 mV. All tests succeeded in the sense that the Pi started up upon reconnection of AC.
At every test run the UPS adjusted the empty voltage down a little until it is now at 3330 mV. I have no clue as to how it decides the new value, nor how the empty voltage value affects operation (during a blackout).
I started this series of tests with 3200 mV for the protection voltage and with its settings and register values at that time the UPS didn't start the Pi after AC was restored again. Now I'm back at 3200 mV and the UPS worked as intended. It looks like it 'learned' something ... more than just the 'learned' value of empty voltage. I got 225 minutes of running time off AC on two batteries (supposedly good quality Sanyo/Panasonic of 3400 mAh a piece). The Pi is just running the Ice Tower fan, the fanShutDownUps.py script, Home Assistant stuff plus whatever it runs by default. Highest CPU use by pulseaudio. (I haven't even ever used sound on any of my Pi's ...)
I made the following experience, starting with fully charged batteries, firmware 9. no automatic shutdown script running. Battery protection voltage set to 3600mV. removed the batteries to restart the firmware, reset the UPS (set register 0x1B to 1). this made drop the battery remaining capacity to 1%. Full battery voltage went to 4.27V, battery empty voltage to approx. 4.1V. Switched off the charger, RPi running. over time, with decreasing battery voltage, the Battery empty voltage decreased, always stayed some 10s of mV below the battery voltage. when the battery empty voltage reached the protection voltage, I did not go any lower. when the battery voltage reached the protection voltage, the UPS switched off (RPi off, all lights off). as you observed, there is some empty battery voltage learning going on during the discharge process. one thing I can't make sense of, are the accumulated running/charging time values. during the whole discharging period, the accumulated charging time value increased.
In the past few days I have conducted a few tests very similar to yours. Thanks for providing the impetus.
I set battery protection voltage to 3200 mV instead of your 3600 mV. During the tests my UPS behaved just like yours.
I start to think that this is the best way to (re)train this UPS as long as you don't mind that the OS on the SD-card or SSD might sustain damage (which is usually easy to repair; I have not had any trouble with my SSD on this Pi.).
Don't run a control script for training/learning. After all the main and foremost function of the control script itself is to protect the OS from getting damaged because of a blackout. All other UPS functionality is in the UPS f/w. This is also the reason for the 200 mV margin, viz. to stay well away from the hard limit imposed by the UPS a.k.a. empty voltage. It prevents the UPS from suddenly cutting the power to the Pi, when the battery voltage suddenly swings low because of a peak in the load current combined with high internal resistance of a poor battery. It does make sense. The script needs to stay ahead of such a mishap.
At the discharge end of the battery voltage range there is no ultimate protection for the batteries unless the UPS itself imposes one. It does so in the form of the empty voltage value which is pushed down bit by bit as the actual battery voltage approaches the protection voltage set by the user without interference by a control script. The UPS adjusts its notion of when to ultimately stop providing power to the load. The user can choose this level according to the characteristics of the batteries and preference about how low to go.
At the high end it is the batteries themselves that impose a limit in close cooperation with the logic of the charging controller on the UPS board. As the charging current tapers off and goes below 50-100 mA, the batteries have reached their highest voltage while charging. The upper voltage limit gets adjusted a bit upwards in a similar fashion as the empty voltage limit. There is nothing to choose and set for the user at the high end. Writing to the corresponding registers leads to no change. One would need to study the specs and application notes of the charging control IC used to gain a better understanding. It is all automatic, however, so nothing to worry about.
During my tests the minute counts looked indeed unreliable. After a few times of running down the batteries straight until the UPS itself cut the power to the load, i.e. the Pi, my UPS now has an empty voltage value of 3200 mV equaling the protection voltage, and the minute counts start to look more like they could actually reflect reality.
After this initial 'training' of the UPS one can just set the protection voltage at a higher value if preferred.
Battery capacity percentages seems indicative, but not the absolute truth. Immediately after disconnecting the charger, the indicated capacity remaining goes down a few tens of percents.
All in all this UPS can be made to behave properly on f/w v.9. I ran several tests with your control script fanShutDownUps.py before and the results were quite OK. I think I described that in an earlier post.
Because I have implemented a simple BJT driver circuit from GPIO 18 to the fan (no PWM wire), the fan doesn't run at all if I disable fan control in the *.ini file. That would actually be OK, as the passive cooling of the Ice Tower is quite sufficient, but there's no point having fancy lights and then not run the fan. So I just sabotaged handleFan in the control script to always run the fan at 100% duty cycle ;-)
Op 06-08-2021 om 23:07 schreef frtz13:
I made the following experience, starting with fully charged batteries, firmware 9. no automatic shutdown script running. Battery protection voltage set to 3600mV. removed the batteries to restart the firmware, reset the UPS (set register 0x1B to 1). this made drop the battery remaining capacity to 1%. Full battery voltage went to 4.27V, battery empty voltage to approx. 4.1V. Switched off the charger, RPi running. over time, with decreasing battery voltage, the Battery empty voltage decreased, always stayed some 10s of mV below the battery voltage. when the battery empty voltage reached the protection voltage, I did not go any lower. when the battery voltage reached the protection voltage, the UPS switched off (RPi off, all lights off). as you observed, there is some empty battery voltage learning going on during the discharge process. one thing I can't make sense of, are the accumulated running/charging time values. during the whole discharging period, the accumulated charging time value increased.
— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/frtz13/UPSPlus_mqtt/issues/15#issuecomment-894518510, or unsubscribe https://github.com/notifications/unsubscribe-auth/ANCBKNQO3RS4JWE34NW5WSTT3RFIFANCNFSM5BLO5ZHQ. Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&utm_campaign=notification-email.
If you charge the UPS batteries in an external charger right before putting them in the UPS, the batteries full voltage will start out higher than what you would get by starting the UPS learning with partially empty batteries. My UPS used to have a full voltage of close to 4350 mV. After training with the same batteries that have been used a long time now in the UPS, the recent learning process settled at a full voltage of 4290 mV.
So I just sabotaged handleFan in the control script to always run the fan at 100% duty cycle
no need for sabotage. just set the desired temperature to a cold value.
I admit having changed the name of the values and even the units (I prefer A), but essentially the values mentioned in the title are as produced by fanShutDownUps.py.
The Battery Current value is often negative meaning that this momentary current is charging the battery. Fine. However, at the same time the average current remains mostly slightly positive, meaning that on the average the batteries are discharging. I have not been able to change this substantially by varying the charging method (an official Pi4 power supply or a PD charger (5V/2A or 9V/1,67A), nor by varying the CPU activity (either doing nothing much, or a stress test of all 4 CPU's at near 100%). The high current discharging which takes place at each sampling event during a number of seconds is probably responsible for the average current to be on the discharging side (in the order of tens of mA).
Therefore I I also tried to lengthen the sampling interval to as much as 30 minutes. No essential change, though.
Rarely the average battery current changes sign indicating batteries are being charged on average.
I have seen the batteries discharging from 97% to 94%, so it may be true. I haven't seen it going below 94%, but then I may not have waited long enough. As far as I have been able to see from the python code, the current average is calculated from 120 single values (2 x 60 seconds).
I have ordered a 20 W PD charger in the hope it will be able to charge fast enough to assure the charge to remain at near 100% for ever even if the CPU's are always running at 100% ...
My question for frtz13: how good an indication of the batteries being charged or discharges is the average battery current as calculated by the script fanShutDownUps.py in your opinion and experience? Does it represent 'reality'?
The official PS can deliver 3 A, afaik. The Pi/UPS only have an SSD connected. The PS voltage is stable. Should be powerful enough despite voltage converter losses here and there.